MarlinFirmware / Marlin

Marlin is an optimized firmware for RepRap 3D printers based on the Arduino platform. Many commercial 3D printers come with Marlin installed. Check with your vendor if you need source code for your specific machine.
https://marlinfw.org
GNU General Public License v3.0
16.22k stars 19.22k forks source link

ABL compensation not working - BLTOUCH 3.1 #17872

Closed thierryzoller closed 4 years ago

thierryzoller commented 4 years ago

As promised, following the many ABL & BLTouch issues, I proceeded to debug mine.

Configuration.txt Configuration_adv.txt

thierryzoller commented 4 years ago

Issued a G28 :

Log Output ``` 2020-05-04 14:38:01,832 - RECV: >>> G28 2020-05-04 14:38:01,832 - RECV: Machine Type: Cartesian 2020-05-04 14:38:01,842 - RECV: Probe: BLTOUCH 2020-05-04 14:38:01,848 - RECV: Probe Offset X28.00 Y-33.00 Z-3.05 (Right-Front & Below Nozzle) 2020-05-04 14:38:01,848 - RECV: Auto Bed Leveling: BILINEAR (disabled) 2020-05-04 14:38:01,858 - RECV: Raise Z (before homing) to 4.00 2020-05-04 14:38:01,858 - RECV: >>> do_blocking_move_to X0.00 Y0.00 Z4.00 2020-05-04 14:38:01,858 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:02,336 - RECV: >>> homeaxis(X) 2020-05-04 14:38:02,336 - RECV: Home 1 Fast: 2020-05-04 14:38:02,345 - RECV: >>> do_homing_move(X, -465.00, [40.00]) 2020-05-04 14:38:03,398 - SENT: M105 2020-05-04 14:38:03,835 - RECV: echo:busy: processing 2020-05-04 14:38:05,634 - RECV: <<< do_homing_move(X) 2020-05-04 14:38:05,634 - RECV: Move Away: 2020-05-04 14:38:05,644 - RECV: >>> do_homing_move(X, 5.00, [40.00]) 2020-05-04 14:38:05,831 - RECV: echo:busy: processing 2020-05-04 14:38:05,881 - RECV: <<< do_homing_move(X) 2020-05-04 14:38:05,881 - RECV: Home 2 Slow: 2020-05-04 14:38:05,891 - RECV: >>> do_homing_move(X, -10.00, 20.00) 2020-05-04 14:38:06,273 - RECV: <<< do_homing_move(X) 2020-05-04 14:38:06,315 - RECV: >>> set_axis_is_at_home(X) 2020-05-04 14:38:06,361 - RECV: Axis 88 home_offset = 0.00 position_shift = 0.00 2020-05-04 14:38:06,361 - RECV: > home_offset[X] = 0.00 2020-05-04 14:38:06,361 - RECV: current_position= X0.00 Y0.00 Z4.00 : 2020-05-04 14:38:06,374 - RECV: <<< set_axis_is_at_home(X) 2020-05-04 14:38:06,375 - RECV: current_position= X0.00 Y0.00 Z4.00 : sync_plan_position 2020-05-04 14:38:06,375 - RECV: current_position= X0.00 Y0.00 Z4.00 : > AFTER set_axis_is_at_home 2020-05-04 14:38:06,375 - RECV: <<< homeaxis(X) 2020-05-04 14:38:06,375 - RECV: >>> homeaxis(Y) 2020-05-04 14:38:06,375 - RECV: Home 1 Fast: 2020-05-04 14:38:06,385 - RECV: >>> do_homing_move(Y, -465.00, [40.00]) 2020-05-04 14:38:07,835 - RECV: echo:busy: processing 2020-05-04 14:38:09,838 - RECV: echo:busy: processing 2020-05-04 14:38:11,075 - RECV: <<< do_homing_move(Y) 2020-05-04 14:38:11,085 - RECV: Move Away: 2020-05-04 14:38:11,085 - RECV: >>> do_homing_move(Y, 5.00, [40.00]) 2020-05-04 14:38:11,323 - RECV: <<< do_homing_move(Y) 2020-05-04 14:38:11,323 - RECV: Home 2 Slow: 2020-05-04 14:38:11,334 - RECV: >>> do_homing_move(Y, -10.00, 20.00) 2020-05-04 14:38:11,687 - RECV: <<< do_homing_move(Y) 2020-05-04 14:38:11,687 - RECV: >>> set_axis_is_at_home(Y) 2020-05-04 14:38:11,687 - RECV: Axis 89 home_offset = 0.00 position_shift = 0.00 2020-05-04 14:38:11,697 - RECV: > home_offset[Y] = 0.00 2020-05-04 14:38:11,697 - RECV: current_position= X0.00 Y0.00 Z4.00 : 2020-05-04 14:38:11,707 - RECV: <<< set_axis_is_at_home(Y) 2020-05-04 14:38:11,707 - RECV: current_position= X0.00 Y0.00 Z4.00 : sync_plan_position 2020-05-04 14:38:11,716 - RECV: current_position= X0.00 Y0.00 Z4.00 : > AFTER set_axis_is_at_home 2020-05-04 14:38:11,716 - RECV: <<< homeaxis(Y) 2020-05-04 14:38:11,716 - RECV: BLTouch Command :160 2020-05-04 14:38:12,278 - RECV: BLTouch Command :90 2020-05-04 14:38:13,048 - RECV: last_written_mode - 1 2020-05-04 14:38:13,058 - RECV: config mode - BLTOUCH_SET_5V_MODE 2020-05-04 14:38:13,058 - RECV: home_z_safely >>> 2020-05-04 14:38:13,058 - RECV: current_position= X0.00 Y0.00 Z4.00 : sync_plan_position 2020-05-04 14:38:13,073 - RECV: destination= X127.00 Y188.00 Z7.05 : home_z_safely 2020-05-04 14:38:13,073 - RECV: >>> do_blocking_move_to X127.00 Y188.00 Z4.00 2020-05-04 14:38:13,084 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:13,084 - RECV: echo:busy: processing 2020-05-04 14:38:14,937 - RECV: >>> homeaxis(Z) 2020-05-04 14:38:14,944 - RECV: current_position= X127.00 Y188.00 Z4.00 : Probe::set_deployed 2020-05-04 14:38:14,944 - RECV: deploy: 1 2020-05-04 14:38:14,944 - RECV: Probe::move_z(5.00) 2020-05-04 14:38:14,953 - RECV: >>> do_blocking_move_to X127.00 Y188.00 Z8.05 2020-05-04 14:38:14,953 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:15,063 - RECV: echo:busy: processing 2020-05-04 14:38:15,444 - RECV: BLTouch DEPLOY requested 2020-05-04 14:38:15,444 - RECV: BLTouch Command :10 2020-05-04 14:38:16,246 - RECV: bltouch.deploy_proc() end 2020-05-04 14:38:16,246 - RECV: >>> do_blocking_move_to X127.00 Y188.00 Z8.05 2020-05-04 14:38:16,246 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:16,246 - RECV: Home 1 Fast: 2020-05-04 14:38:16,256 - RECV: BLTouch DEPLOY requested 2020-05-04 14:38:16,256 - RECV: BLTouch Command :10 2020-05-04 14:38:17,051 - RECV: bltouch.deploy_proc() end 2020-05-04 14:38:17,051 - RECV: >>> do_homing_move(Z, -570.00, [20.00]) 2020-05-04 14:38:17,061 - RECV: echo:busy: processing 2020-05-04 14:38:18,259 - RECV: <<< do_homing_move(Z) 2020-05-04 14:38:18,269 - RECV: Move Away: 2020-05-04 14:38:18,273 - RECV: >>> do_homing_move(Z, 4.00, 20.00) 2020-05-04 14:38:18,762 - RECV: <<< do_homing_move(Z) 2020-05-04 14:38:18,762 - RECV: Home 2 Slow: 2020-05-04 14:38:18,762 - RECV: >>> do_homing_move(Z, -8.00, 10.00) 2020-05-04 14:38:18,822 - SENT: M105 2020-05-04 14:38:19,062 - RECV: echo:busy: processing 2020-05-04 14:38:19,342 - RECV: <<< do_homing_move(Z) 2020-05-04 14:38:19,361 - RECV: BLTouch STOW requested 2020-05-04 14:38:19,361 - RECV: BLTouch Command :90 2020-05-04 14:38:20,125 - RECV: bltouch.stow_proc() end 2020-05-04 14:38:20,125 - RECV: >>> set_axis_is_at_home(Z) 2020-05-04 14:38:20,125 - RECV: *** Z HOMED WITH PROBE (Z_MIN_PROBE_USES_Z_MIN_ENDSTOP_PIN) *** 2020-05-04 14:38:20,134 - RECV: > probe.offset.z = -3.05 2020-05-04 14:38:20,140 - RECV: Axis 90 home_offset = 0.00 position_shift = 0.00 2020-05-04 14:38:20,140 - RECV: > home_offset[Z] = 0.00 2020-05-04 14:38:20,150 - RECV: current_position= X127.00 Y188.00 Z3.05 : 2020-05-04 14:38:20,150 - RECV: <<< set_axis_is_at_home(Z) 2020-05-04 14:38:20,160 - RECV: current_position= X127.00 Y188.00 Z3.05 : sync_plan_position 2020-05-04 14:38:20,174 - RECV: current_position= X127.00 Y188.00 Z3.05 : > AFTER set_axis_is_at_home 2020-05-04 14:38:20,174 - RECV: current_position= X127.00 Y188.00 Z3.05 : Probe::set_deployed 2020-05-04 14:38:20,174 - RECV: deploy: 0 2020-05-04 14:38:20,184 - RECV: Probe::move_z(5.00) 2020-05-04 14:38:20,184 - RECV: >>> do_blocking_move_to X127.00 Y188.00 Z8.05 2020-05-04 14:38:20,184 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:20,690 - RECV: BLTouch STOW requested 2020-05-04 14:38:20,690 - RECV: BLTouch Command :90 2020-05-04 14:38:21,486 - RECV: bltouch.stow_proc() end 2020-05-04 14:38:21,496 - RECV: >>> do_blocking_move_to X127.00 Y188.00 Z8.05 2020-05-04 14:38:21,496 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:21,496 - RECV: <<< homeaxis(Z) 2020-05-04 14:38:21,496 - RECV: <<< home_z_safely 2020-05-04 14:38:21,506 - RECV: >>> do_blocking_move_to X127.00 Y188.00 Z15.00 2020-05-04 14:38:21,506 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:21,516 - RECV: echo:busy: processing 2020-05-04 14:38:22,144 - RECV: current_position= X127.00 Y188.00 Z15.00 : sync_plan_position 2020-05-04 14:38:22,154 - RECV: X:127.00 Y:188.00 Z:15.00 E:0.00 Count X:10160 Y:15040 Z:6000 2020-05-04 14:38:22,154 - RECV: <<< G28 ```
thierryzoller commented 4 years ago

Issued a G29 :

Log Output ``` 2020-05-04 14:38:34,161 - SENT: G29 2020-05-04 14:38:34,171 - RECV: ok T:20.86 /0.00 B:20.70 /0.00 @:0 B@:0 2020-05-04 14:38:34,171 - RECV: echo:G29 2020-05-04 14:38:34,184 - RECV: current_position= X127.00 Y188.00 Z15.00 : >>> G29 2020-05-04 14:38:34,187 - RECV: Machine Type: Cartesian 2020-05-04 14:38:34,187 - RECV: Probe: BLTOUCH 2020-05-04 14:38:34,197 - RECV: Probe Offset X28.00 Y-33.00 Z-3.05 (Right-Front & Below Nozzle) 2020-05-04 14:38:34,197 - RECV: Auto Bed Leveling: BILINEAR (disabled) 2020-05-04 14:38:34,207 - RECV: current_position= X127.00 Y188.00 Z15.00 : Probe::set_deployed 2020-05-04 14:38:34,207 - RECV: deploy: 1 2020-05-04 14:38:34,207 - RECV: Probe::move_z(5.00) 2020-05-04 14:38:34,220 - RECV: BLTouch DEPLOY requested 2020-05-04 14:38:34,226 - RECV: BLTouch Command :10 2020-05-04 14:38:34,236 - SENT: M105 2020-05-04 14:38:34,980 - RECV: bltouch.deploy_proc() end 2020-05-04 14:38:34,990 - RECV: >>> do_blocking_move_to X127.00 Y188.00 Z15.00 2020-05-04 14:38:34,990 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:35,000 - RECV: >>> Probe::probe_at_point(28.00, 25.00, raise, 0, probe_relative) 2020-05-04 14:38:35,010 - RECV: current_position= X127.00 Y188.00 Z15.00 : 2020-05-04 14:38:35,016 - RECV: >>> do_blocking_move_to X0.00 Y58.00 Z15.00 2020-05-04 14:38:35,016 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:36,167 - RECV: echo:busy: processing 2020-05-04 14:38:36,538 - RECV: current_position= X0.00 Y58.00 Z15.00 : Probe::set_deployed 2020-05-04 14:38:36,538 - RECV: deploy: 1 2020-05-04 14:38:36,548 - RECV: current_position= X0.00 Y58.00 Z15.00 : >>> Probe::run_z_probe 2020-05-04 14:38:36,548 - RECV: current_position= X0.00 Y58.00 Z15.00 : >>> Probe::probe_down_to_z 2020-05-04 14:38:36,558 - RECV: >>> do_blocking_move_to X0.00 Y58.00 Z1.05 2020-05-04 14:38:36,558 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:37,441 - RECV: current_position= X0.00 Y58.00 Z2.99 : sync_plan_position 2020-05-04 14:38:37,503 - RECV: current_position= X0.00 Y58.00 Z2.99 : <<< Probe::probe_down_to_z 2020-05-04 14:38:37,503 - RECV: 1st Probe Z:2.99 2020-05-04 14:38:37,513 - RECV: >>> do_blocking_move_to X0.00 Y58.00 Z7.99 2020-05-04 14:38:37,515 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:37,904 - RECV: current_position= X0.00 Y58.00 Z7.99 : >>> Probe::probe_down_to_z 2020-05-04 14:38:37,917 - RECV: >>> do_blocking_move_to X0.00 Y58.00 Z1.05 2020-05-04 14:38:37,920 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:38,170 - RECV: echo:busy: processing 2020-05-04 14:38:38,561 - RECV: current_position= X0.00 Y58.00 Z2.99 : sync_plan_position 2020-05-04 14:38:38,571 - RECV: current_position= X0.00 Y58.00 Z2.99 : <<< Probe::probe_down_to_z 2020-05-04 14:38:38,571 - RECV: 2nd Probe Z:2.99 Discrepancy:0.00 2020-05-04 14:38:38,585 - RECV: current_position= X0.00 Y58.00 Z2.99 : <<< run_z_probe 2020-05-04 14:38:38,585 - RECV: >>> do_blocking_move_to X0.00 Y58.00 Z6.99 2020-05-04 14:38:38,595 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:39,062 - RECV: <<< Probe::probe_at_point 2020-05-04 14:38:39,072 - RECV: >>> Probe::probe_at_point(70.83, 25.00, raise, 0, probe_relative) 2020-05-04 14:38:39,072 - RECV: current_position= X0.00 Y58.00 Z6.99 : 2020-05-04 14:38:39,088 - RECV: >>> do_blocking_move_to X42.83 Y58.00 Z6.99 2020-05-04 14:38:39,088 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:39,573 - RECV: current_position= X42.83 Y58.00 Z6.99 : Probe::set_deployed 2020-05-04 14:38:39,573 - RECV: deploy: 1 2020-05-04 14:38:39,573 - RECV: current_position= X42.83 Y58.00 Z6.99 : >>> Probe::run_z_probe 2020-05-04 14:38:39,584 - RECV: current_position= X42.83 Y58.00 Z6.99 : >>> Probe::probe_down_to_z 2020-05-04 14:38:39,584 - RECV: >>> do_blocking_move_to X42.83 Y58.00 Z1.05 2020-05-04 14:38:39,594 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:39,990 - RECV: current_position= X42.83 Y58.00 Z2.93 : sync_plan_position 2020-05-04 14:38:40,000 - RECV: current_position= X42.83 Y58.00 Z2.93 : <<< Probe::probe_down_to_z 2020-05-04 14:38:40,000 - RECV: 1st Probe Z:2.93 2020-05-04 14:38:40,000 - RECV: >>> do_blocking_move_to X42.83 Y58.00 Z7.93 2020-05-04 14:38:40,013 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:40,165 - RECV: echo:busy: processing 2020-05-04 14:38:40,539 - RECV: current_position= X42.83 Y58.00 Z7.93 : >>> Probe::probe_down_to_z 2020-05-04 14:38:40,551 - RECV: >>> do_blocking_move_to X42.83 Y58.00 Z1.05 2020-05-04 14:38:40,553 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:41,203 - RECV: current_position= X42.83 Y58.00 Z2.92 : sync_plan_position 2020-05-04 14:38:41,217 - RECV: current_position= X42.83 Y58.00 Z2.92 : <<< Probe::probe_down_to_z 2020-05-04 14:38:41,217 - RECV: 2nd Probe Z:2.92 Discrepancy:0.01 2020-05-04 14:38:41,229 - RECV: current_position= X42.83 Y58.00 Z2.92 : <<< run_z_probe 2020-05-04 14:38:41,229 - RECV: >>> do_blocking_move_to X42.83 Y58.00 Z6.92 2020-05-04 14:38:41,239 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:41,703 - RECV: <<< Probe::probe_at_point 2020-05-04 14:38:41,713 - RECV: >>> Probe::probe_at_point(113.67, 25.00, raise, 0, probe_relative) 2020-05-04 14:38:41,719 - RECV: current_position= X42.83 Y58.00 Z6.92 : 2020-05-04 14:38:41,719 - RECV: >>> do_blocking_move_to X85.67 Y58.00 Z6.92 2020-05-04 14:38:41,719 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:42,167 - RECV: echo:busy: processing 2020-05-04 14:38:42,203 - RECV: current_position= X85.67 Y58.00 Z6.92 : Probe::set_deployed 2020-05-04 14:38:42,203 - RECV: deploy: 1 2020-05-04 14:38:42,219 - RECV: current_position= X85.67 Y58.00 Z6.92 : >>> Probe::run_z_probe 2020-05-04 14:38:42,221 - RECV: current_position= X85.67 Y58.00 Z6.92 : >>> Probe::probe_down_to_z 2020-05-04 14:38:42,232 - RECV: >>> do_blocking_move_to X85.67 Y58.00 Z1.05 2020-05-04 14:38:42,232 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:42,622 - RECV: current_position= X85.67 Y58.00 Z3.00 : sync_plan_position 2020-05-04 14:38:42,622 - RECV: current_position= X85.67 Y58.00 Z3.00 : <<< Probe::probe_down_to_z 2020-05-04 14:38:42,622 - RECV: 1st Probe Z:3.00 2020-05-04 14:38:42,632 - RECV: >>> do_blocking_move_to X85.67 Y58.00 Z8.00 2020-05-04 14:38:42,642 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:43,174 - RECV: current_position= X85.67 Y58.00 Z8.00 : >>> Probe::probe_down_to_z 2020-05-04 14:38:43,177 - RECV: >>> do_blocking_move_to X85.67 Y58.00 Z1.05 2020-05-04 14:38:43,177 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:43,826 - RECV: current_position= X85.67 Y58.00 Z3.00 : sync_plan_position 2020-05-04 14:38:43,835 - RECV: current_position= X85.67 Y58.00 Z3.00 : <<< Probe::probe_down_to_z 2020-05-04 14:38:43,835 - RECV: 2nd Probe Z:3.00 Discrepancy:-0.00 2020-05-04 14:38:43,851 - RECV: current_position= X85.67 Y58.00 Z3.00 : <<< run_z_probe 2020-05-04 14:38:43,855 - RECV: >>> do_blocking_move_to X85.67 Y58.00 Z7.00 2020-05-04 14:38:43,855 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:44,173 - RECV: echo:busy: processing 2020-05-04 14:38:44,331 - RECV: <<< Probe::probe_at_point 2020-05-04 14:38:44,341 - RECV: >>> Probe::probe_at_point(156.50, 25.00, raise, 0, probe_relative) 2020-05-04 14:38:44,345 - RECV: current_position= X85.67 Y58.00 Z7.00 : 2020-05-04 14:38:44,345 - RECV: >>> do_blocking_move_to X128.50 Y58.00 Z7.00 2020-05-04 14:38:44,345 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:44,829 - RECV: current_position= X128.50 Y58.00 Z7.00 : Probe::set_deployed 2020-05-04 14:38:44,829 - RECV: deploy: 1 2020-05-04 14:38:44,845 - RECV: current_position= X128.50 Y58.00 Z7.00 : >>> Probe::run_z_probe 2020-05-04 14:38:44,845 - RECV: current_position= X128.50 Y58.00 Z7.00 : >>> Probe::probe_down_to_z 2020-05-04 14:38:44,855 - RECV: >>> do_blocking_move_to X128.50 Y58.00 Z1.05 2020-05-04 14:38:44,855 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:45,246 - RECV: current_position= X128.50 Y58.00 Z3.00 : sync_plan_position 2020-05-04 14:38:45,256 - RECV: current_position= X128.50 Y58.00 Z3.00 : <<< Probe::probe_down_to_z 2020-05-04 14:38:45,256 - RECV: 1st Probe Z:3.00 2020-05-04 14:38:45,266 - RECV: >>> do_blocking_move_to X128.50 Y58.00 Z8.00 2020-05-04 14:38:45,266 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:45,798 - RECV: current_position= X128.50 Y58.00 Z8.00 : >>> Probe::probe_down_to_z 2020-05-04 14:38:45,811 - RECV: >>> do_blocking_move_to X128.50 Y58.00 Z1.05 2020-05-04 14:38:45,812 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:46,174 - RECV: echo:busy: processing 2020-05-04 14:38:46,463 - RECV: current_position= X128.50 Y58.00 Z3.00 : sync_plan_position 2020-05-04 14:38:46,463 - RECV: current_position= X128.50 Y58.00 Z3.00 : <<< Probe::probe_down_to_z 2020-05-04 14:38:46,473 - RECV: 2nd Probe Z:3.00 Discrepancy:-0.00 2020-05-04 14:38:46,483 - RECV: current_position= X128.50 Y58.00 Z3.00 : <<< run_z_probe 2020-05-04 14:38:46,483 - RECV: >>> do_blocking_move_to X128.50 Y58.00 Z7.01 2020-05-04 14:38:46,483 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:46,967 - RECV: <<< Probe::probe_at_point 2020-05-04 14:38:46,969 - RECV: >>> Probe::probe_at_point(199.33, 25.00, raise, 0, probe_relative) 2020-05-04 14:38:46,969 - RECV: current_position= X128.50 Y58.00 Z7.01 : 2020-05-04 14:38:46,979 - RECV: >>> do_blocking_move_to X171.33 Y58.00 Z7.01 2020-05-04 14:38:46,979 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:47,460 - RECV: current_position= X171.33 Y58.00 Z7.01 : Probe::set_deployed 2020-05-04 14:38:47,470 - RECV: deploy: 1 2020-05-04 14:38:47,470 - RECV: current_position= X171.33 Y58.00 Z7.01 : >>> Probe::run_z_probe 2020-05-04 14:38:47,480 - RECV: current_position= X171.33 Y58.00 Z7.01 : >>> Probe::probe_down_to_z 2020-05-04 14:38:47,480 - RECV: >>> do_blocking_move_to X171.33 Y58.00 Z1.05 2020-05-04 14:38:47,490 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:47,881 - RECV: current_position= X171.33 Y58.00 Z3.04 : sync_plan_position 2020-05-04 14:38:47,891 - RECV: current_position= X171.33 Y58.00 Z3.04 : <<< Probe::probe_down_to_z 2020-05-04 14:38:47,894 - RECV: 1st Probe Z:3.04 2020-05-04 14:38:47,898 - RECV: >>> do_blocking_move_to X171.33 Y58.00 Z8.04 2020-05-04 14:38:47,907 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:48,173 - RECV: echo:busy: processing 2020-05-04 14:38:48,433 - RECV: current_position= X171.33 Y58.00 Z8.04 : >>> Probe::probe_down_to_z 2020-05-04 14:38:48,437 - RECV: >>> do_blocking_move_to X171.33 Y58.00 Z1.05 2020-05-04 14:38:48,437 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:49,095 - RECV: current_position= X171.33 Y58.00 Z3.04 : sync_plan_position 2020-05-04 14:38:49,099 - RECV: current_position= X171.33 Y58.00 Z3.04 : <<< Probe::probe_down_to_z 2020-05-04 14:38:49,099 - RECV: 2nd Probe Z:3.04 Discrepancy:0.00 2020-05-04 14:38:49,109 - RECV: current_position= X171.33 Y58.00 Z3.04 : <<< run_z_probe 2020-05-04 14:38:49,109 - RECV: >>> do_blocking_move_to X171.33 Y58.00 Z7.04 2020-05-04 14:38:49,119 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:49,592 - RECV: <<< Probe::probe_at_point 2020-05-04 14:38:49,602 - RECV: >>> Probe::probe_at_point(242.17, 25.00, raise, 0, probe_relative) 2020-05-04 14:38:49,602 - RECV: current_position= X171.33 Y58.00 Z7.04 : 2020-05-04 14:38:49,612 - RECV: >>> do_blocking_move_to X214.17 Y58.00 Z7.04 2020-05-04 14:38:49,612 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:49,687 - SENT: M105 2020-05-04 14:38:50,095 - RECV: current_position= X214.17 Y58.00 Z7.04 : Probe::set_deployed 2020-05-04 14:38:50,095 - RECV: deploy: 1 2020-05-04 14:38:50,105 - RECV: current_position= X214.17 Y58.00 Z7.04 : >>> Probe::run_z_probe 2020-05-04 14:38:50,115 - RECV: current_position= X214.17 Y58.00 Z7.04 : >>> Probe::probe_down_to_z 2020-05-04 14:38:50,115 - RECV: >>> do_blocking_move_to X214.17 Y58.00 Z1.05 2020-05-04 14:38:50,115 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:50,170 - RECV: echo:busy: processing 2020-05-04 14:38:50,509 - RECV: current_position= X214.17 Y58.00 Z3.15 : sync_plan_position 2020-05-04 14:38:50,509 - RECV: current_position= X214.17 Y58.00 Z3.15 : <<< Probe::probe_down_to_z 2020-05-04 14:38:50,509 - RECV: 1st Probe Z:3.15 2020-05-04 14:38:50,519 - RECV: >>> do_blocking_move_to X214.17 Y58.00 Z8.15 2020-05-04 14:38:50,529 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:51,063 - RECV: current_position= X214.17 Y58.00 Z8.15 : >>> Probe::probe_down_to_z 2020-05-04 14:38:51,063 - RECV: >>> do_blocking_move_to X214.17 Y58.00 Z1.05 2020-05-04 14:38:51,063 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:51,719 - RECV: current_position= X214.17 Y58.00 Z3.16 : sync_plan_position 2020-05-04 14:38:51,729 - RECV: current_position= X214.17 Y58.00 Z3.16 : <<< Probe::probe_down_to_z 2020-05-04 14:38:51,729 - RECV: 2nd Probe Z:3.16 Discrepancy:-0.01 2020-05-04 14:38:51,742 - RECV: current_position= X214.17 Y58.00 Z3.16 : <<< run_z_probe 2020-05-04 14:38:51,743 - RECV: >>> do_blocking_move_to X214.17 Y58.00 Z7.16 2020-05-04 14:38:51,743 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:52,173 - RECV: echo:busy: processing 2020-05-04 14:38:52,223 - RECV: <<< Probe::probe_at_point 2020-05-04 14:38:52,223 - RECV: >>> Probe::probe_at_point(285.00, 25.00, raise, 0, probe_relative) 2020-05-04 14:38:52,233 - RECV: current_position= X214.17 Y58.00 Z7.16 : 2020-05-04 14:38:52,233 - RECV: >>> do_blocking_move_to X257.00 Y58.00 Z7.16 2020-05-04 14:38:52,246 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:52,726 - RECV: current_position= X257.00 Y58.00 Z7.16 : Probe::set_deployed 2020-05-04 14:38:52,726 - RECV: deploy: 1 2020-05-04 14:38:52,726 - RECV: current_position= X257.00 Y58.00 Z7.16 : >>> Probe::run_z_probe 2020-05-04 14:38:52,740 - RECV: current_position= X257.00 Y58.00 Z7.16 : >>> Probe::probe_down_to_z 2020-05-04 14:38:52,740 - RECV: >>> do_blocking_move_to X257.00 Y58.00 Z1.05 2020-05-04 14:38:52,740 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:53,142 - RECV: current_position= X257.00 Y58.00 Z3.13 : sync_plan_position 2020-05-04 14:38:53,142 - RECV: current_position= X257.00 Y58.00 Z3.13 : <<< Probe::probe_down_to_z 2020-05-04 14:38:53,154 - RECV: 1st Probe Z:3.13 2020-05-04 14:38:53,154 - RECV: >>> do_blocking_move_to X257.00 Y58.00 Z8.13 2020-05-04 14:38:53,164 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:53,690 - RECV: current_position= X257.00 Y58.00 Z8.13 : >>> Probe::probe_down_to_z 2020-05-04 14:38:53,700 - RECV: >>> do_blocking_move_to X257.00 Y58.00 Z1.05 2020-05-04 14:38:53,700 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:54,174 - RECV: echo:busy: processing 2020-05-04 14:38:54,349 - RECV: current_position= X257.00 Y58.00 Z3.13 : sync_plan_position 2020-05-04 14:38:54,359 - RECV: current_position= X257.00 Y58.00 Z3.13 : <<< Probe::probe_down_to_z 2020-05-04 14:38:54,359 - RECV: 2nd Probe Z:3.13 Discrepancy:-0.01 2020-05-04 14:38:54,375 - RECV: current_position= X257.00 Y58.00 Z3.13 : <<< run_z_probe 2020-05-04 14:38:54,375 - RECV: >>> do_blocking_move_to X257.00 Y58.00 Z7.13 2020-05-04 14:38:54,375 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:54,851 - RECV: <<< Probe::probe_at_point 2020-05-04 14:38:54,861 - RECV: >>> Probe::probe_at_point(285.00, 67.00, raise, 0, probe_relative) 2020-05-04 14:38:54,861 - RECV: current_position= X257.00 Y58.00 Z7.13 : 2020-05-04 14:38:54,871 - RECV: >>> do_blocking_move_to X257.00 Y100.00 Z7.13 2020-05-04 14:38:54,877 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:55,355 - RECV: current_position= X257.00 Y100.00 Z7.13 : Probe::set_deployed 2020-05-04 14:38:55,355 - RECV: deploy: 1 2020-05-04 14:38:55,359 - RECV: current_position= X257.00 Y100.00 Z7.13 : >>> Probe::run_z_probe 2020-05-04 14:38:55,369 - RECV: current_position= X257.00 Y100.00 Z7.13 : >>> Probe::probe_down_to_z 2020-05-04 14:38:55,369 - RECV: >>> do_blocking_move_to X257.00 Y100.00 Z1.05 2020-05-04 14:38:55,369 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:55,770 - RECV: current_position= X257.00 Y100.00 Z3.13 : sync_plan_position 2020-05-04 14:38:55,780 - RECV: current_position= X257.00 Y100.00 Z3.13 : <<< Probe::probe_down_to_z 2020-05-04 14:38:55,780 - RECV: 1st Probe Z:3.13 2020-05-04 14:38:55,780 - RECV: >>> do_blocking_move_to X257.00 Y100.00 Z8.13 2020-05-04 14:38:55,790 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:56,173 - RECV: echo:busy: processing 2020-05-04 14:38:56,323 - RECV: current_position= X257.00 Y100.00 Z8.13 : >>> Probe::probe_down_to_z 2020-05-04 14:38:56,323 - RECV: >>> do_blocking_move_to X257.00 Y100.00 Z1.05 2020-05-04 14:38:56,323 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:56,976 - RECV: current_position= X257.00 Y100.00 Z3.13 : sync_plan_position 2020-05-04 14:38:56,992 - RECV: current_position= X257.00 Y100.00 Z3.13 : <<< Probe::probe_down_to_z 2020-05-04 14:38:56,992 - RECV: 2nd Probe Z:3.13 Discrepancy:0.01 2020-05-04 14:38:56,992 - RECV: current_position= X257.00 Y100.00 Z3.13 : <<< run_z_probe 2020-05-04 14:38:57,002 - RECV: >>> do_blocking_move_to X257.00 Y100.00 Z7.13 2020-05-04 14:38:57,002 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:57,486 - RECV: <<< Probe::probe_at_point 2020-05-04 14:38:57,492 - RECV: >>> Probe::probe_at_point(242.17, 67.00, raise, 0, probe_relative) 2020-05-04 14:38:57,492 - RECV: current_position= X257.00 Y100.00 Z7.13 : 2020-05-04 14:38:57,502 - RECV: >>> do_blocking_move_to X214.17 Y100.00 Z7.13 2020-05-04 14:38:57,502 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:57,990 - RECV: current_position= X214.17 Y100.00 Z7.13 : Probe::set_deployed 2020-05-04 14:38:57,990 - RECV: deploy: 1 2020-05-04 14:38:57,990 - RECV: current_position= X214.17 Y100.00 Z7.13 : >>> Probe::run_z_probe 2020-05-04 14:38:58,000 - RECV: current_position= X214.17 Y100.00 Z7.13 : >>> Probe::probe_down_to_z 2020-05-04 14:38:58,009 - RECV: >>> do_blocking_move_to X214.17 Y100.00 Z1.05 2020-05-04 14:38:58,009 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:58,165 - RECV: echo:busy: processing 2020-05-04 14:38:58,483 - RECV: current_position= X214.17 Y100.00 Z3.16 : sync_plan_position 2020-05-04 14:38:58,594 - RECV: current_position= X214.17 Y100.00 Z3.16 : <<< Probe::probe_down_to_z 2020-05-04 14:38:58,628 - RECV: 1st Probe Z:3.16 2020-05-04 14:38:58,640 - RECV: >>> do_blocking_move_to X214.17 Y100.00 Z8.15 2020-05-04 14:38:58,640 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:58,957 - RECV: current_position= X214.17 Y100.00 Z8.15 : >>> Probe::probe_down_to_z 2020-05-04 14:38:58,957 - RECV: >>> do_blocking_move_to X214.17 Y100.00 Z1.05 2020-05-04 14:38:58,967 - RECV: <<< do_blocking_move_to 2020-05-04 14:38:59,618 - RECV: current_position= X214.17 Y100.00 Z3.16 : sync_plan_position 2020-05-04 14:38:59,622 - RECV: current_position= X214.17 Y100.00 Z3.16 : <<< Probe::probe_down_to_z 2020-05-04 14:38:59,622 - RECV: 2nd Probe Z:3.16 Discrepancy:0.00 2020-05-04 14:38:59,632 - RECV: current_position= X214.17 Y100.00 Z3.16 : <<< run_z_probe 2020-05-04 14:38:59,632 - RECV: >>> do_blocking_move_to X214.17 Y100.00 Z7.15 2020-05-04 14:38:59,642 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:00,119 - RECV: <<< Probe::probe_at_point 2020-05-04 14:39:00,122 - RECV: >>> Probe::probe_at_point(199.33, 67.00, raise, 0, probe_relative) 2020-05-04 14:39:00,122 - RECV: current_position= X214.17 Y100.00 Z7.15 : 2020-05-04 14:39:00,122 - RECV: >>> do_blocking_move_to X171.33 Y100.00 Z7.15 2020-05-04 14:39:00,122 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:00,167 - RECV: echo:busy: processing 2020-05-04 14:39:00,618 - RECV: current_position= X171.33 Y100.00 Z7.15 : Probe::set_deployed 2020-05-04 14:39:00,618 - RECV: deploy: 1 2020-05-04 14:39:00,628 - RECV: current_position= X171.33 Y100.00 Z7.15 : >>> Probe::run_z_probe 2020-05-04 14:39:00,638 - RECV: current_position= X171.33 Y100.00 Z7.15 : >>> Probe::probe_down_to_z 2020-05-04 14:39:00,638 - RECV: >>> do_blocking_move_to X171.33 Y100.00 Z1.05 2020-05-04 14:39:00,648 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:01,040 - RECV: current_position= X171.33 Y100.00 Z3.04 : sync_plan_position 2020-05-04 14:39:01,053 - RECV: current_position= X171.33 Y100.00 Z3.04 : <<< Probe::probe_down_to_z 2020-05-04 14:39:01,055 - RECV: 1st Probe Z:3.04 2020-05-04 14:39:01,055 - RECV: >>> do_blocking_move_to X171.33 Y100.00 Z8.04 2020-05-04 14:39:01,055 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:01,594 - RECV: current_position= X171.33 Y100.00 Z8.04 : >>> Probe::probe_down_to_z 2020-05-04 14:39:01,605 - RECV: >>> do_blocking_move_to X171.33 Y100.00 Z1.05 2020-05-04 14:39:01,605 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:02,168 - RECV: echo:busy: processing 2020-05-04 14:39:02,255 - RECV: current_position= X171.33 Y100.00 Z3.04 : sync_plan_position 2020-05-04 14:39:02,259 - RECV: current_position= X171.33 Y100.00 Z3.04 : <<< Probe::probe_down_to_z 2020-05-04 14:39:02,259 - RECV: 2nd Probe Z:3.04 Discrepancy:0.00 2020-05-04 14:39:02,269 - RECV: current_position= X171.33 Y100.00 Z3.04 : <<< run_z_probe 2020-05-04 14:39:02,279 - RECV: >>> do_blocking_move_to X171.33 Y100.00 Z7.04 2020-05-04 14:39:02,279 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:02,762 - RECV: <<< Probe::probe_at_point 2020-05-04 14:39:02,762 - RECV: >>> Probe::probe_at_point(156.50, 67.00, raise, 0, probe_relative) 2020-05-04 14:39:02,772 - RECV: current_position= X171.33 Y100.00 Z7.04 : 2020-05-04 14:39:02,772 - RECV: >>> do_blocking_move_to X128.50 Y100.00 Z7.04 2020-05-04 14:39:02,782 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:03,259 - RECV: current_position= X128.50 Y100.00 Z7.04 : Probe::set_deployed 2020-05-04 14:39:03,263 - RECV: deploy: 1 2020-05-04 14:39:03,263 - RECV: current_position= X128.50 Y100.00 Z7.04 : >>> Probe::run_z_probe 2020-05-04 14:39:03,273 - RECV: current_position= X128.50 Y100.00 Z7.04 : >>> Probe::probe_down_to_z 2020-05-04 14:39:03,286 - RECV: >>> do_blocking_move_to X128.50 Y100.00 Z1.05 2020-05-04 14:39:03,289 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:03,674 - RECV: current_position= X128.50 Y100.00 Z3.00 : sync_plan_position 2020-05-04 14:39:03,687 - RECV: current_position= X128.50 Y100.00 Z3.00 : <<< Probe::probe_down_to_z 2020-05-04 14:39:03,690 - RECV: 1st Probe Z:3.00 2020-05-04 14:39:03,690 - RECV: >>> do_blocking_move_to X128.50 Y100.00 Z8.01 2020-05-04 14:39:03,690 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:04,168 - RECV: echo:busy: processing 2020-05-04 14:39:04,229 - RECV: current_position= X128.50 Y100.00 Z8.01 : >>> Probe::probe_down_to_z 2020-05-04 14:39:04,237 - RECV: >>> do_blocking_move_to X128.50 Y100.00 Z1.05 2020-05-04 14:39:04,237 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:04,890 - RECV: current_position= X128.50 Y100.00 Z3.00 : sync_plan_position 2020-05-04 14:39:04,900 - RECV: current_position= X128.50 Y100.00 Z3.00 : <<< Probe::probe_down_to_z 2020-05-04 14:39:04,900 - RECV: 2nd Probe Z:3.00 Discrepancy:0.00 2020-05-04 14:39:04,910 - RECV: current_position= X128.50 Y100.00 Z3.00 : <<< run_z_probe 2020-05-04 14:39:04,910 - RECV: >>> do_blocking_move_to X128.50 Y100.00 Z7.00 2020-05-04 14:39:04,910 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:05,181 - SENT: M105 2020-05-04 14:39:05,388 - RECV: <<< Probe::probe_at_point 2020-05-04 14:39:05,398 - RECV: >>> Probe::probe_at_point(113.67, 67.00, raise, 0, probe_relative) 2020-05-04 14:39:05,407 - RECV: current_position= X128.50 Y100.00 Z7.00 : 2020-05-04 14:39:05,407 - RECV: >>> do_blocking_move_to X85.67 Y100.00 Z7.00 2020-05-04 14:39:05,417 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:05,890 - RECV: current_position= X85.67 Y100.00 Z7.00 : Probe::set_deployed 2020-05-04 14:39:05,900 - RECV: deploy: 1 2020-05-04 14:39:05,900 - RECV: current_position= X85.67 Y100.00 Z7.00 : >>> Probe::run_z_probe 2020-05-04 14:39:05,910 - RECV: current_position= X85.67 Y100.00 Z7.00 : >>> Probe::probe_down_to_z 2020-05-04 14:39:05,910 - RECV: >>> do_blocking_move_to X85.67 Y100.00 Z1.05 2020-05-04 14:39:05,923 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:06,164 - RECV: echo:busy: processing 2020-05-04 14:39:06,315 - RECV: current_position= X85.67 Y100.00 Z3.00 : sync_plan_position 2020-05-04 14:39:06,321 - RECV: current_position= X85.67 Y100.00 Z3.00 : <<< Probe::probe_down_to_z 2020-05-04 14:39:06,321 - RECV: 1st Probe Z:3.00 2020-05-04 14:39:06,331 - RECV: >>> do_blocking_move_to X85.67 Y100.00 Z8.00 2020-05-04 14:39:06,331 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:06,868 - RECV: current_position= X85.67 Y100.00 Z8.00 : >>> Probe::probe_down_to_z 2020-05-04 14:39:06,868 - RECV: >>> do_blocking_move_to X85.67 Y100.00 Z1.05 2020-05-04 14:39:06,878 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:07,522 - RECV: current_position= X85.67 Y100.00 Z3.00 : sync_plan_position 2020-05-04 14:39:07,532 - RECV: current_position= X85.67 Y100.00 Z3.00 : <<< Probe::probe_down_to_z 2020-05-04 14:39:07,532 - RECV: 2nd Probe Z:3.00 Discrepancy:-0.01 2020-05-04 14:39:07,532 - RECV: current_position= X85.67 Y100.00 Z3.00 : <<< run_z_probe 2020-05-04 14:39:07,542 - RECV: >>> do_blocking_move_to X85.67 Y100.00 Z7.00 2020-05-04 14:39:07,542 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:08,023 - RECV: <<< Probe::probe_at_point 2020-05-04 14:39:08,035 - RECV: >>> Probe::probe_at_point(70.83, 67.00, raise, 0, probe_relative) 2020-05-04 14:39:08,045 - RECV: current_position= X85.67 Y100.00 Z7.00 : 2020-05-04 14:39:08,056 - RECV: >>> do_blocking_move_to X42.83 Y100.00 Z7.00 2020-05-04 14:39:08,062 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:08,173 - RECV: echo:busy: processing 2020-05-04 14:39:08,528 - RECV: current_position= X42.83 Y100.00 Z7.00 : Probe::set_deployed 2020-05-04 14:39:08,528 - RECV: deploy: 1 2020-05-04 14:39:08,538 - RECV: current_position= X42.83 Y100.00 Z7.00 : >>> Probe::run_z_probe 2020-05-04 14:39:08,538 - RECV: current_position= X42.83 Y100.00 Z7.00 : >>> Probe::probe_down_to_z 2020-05-04 14:39:08,552 - RECV: >>> do_blocking_move_to X42.83 Y100.00 Z1.05 2020-05-04 14:39:08,552 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:08,950 - RECV: current_position= X42.83 Y100.00 Z2.93 : sync_plan_position 2020-05-04 14:39:08,950 - RECV: current_position= X42.83 Y100.00 Z2.93 : <<< Probe::probe_down_to_z 2020-05-04 14:39:08,960 - RECV: 1st Probe Z:2.93 2020-05-04 14:39:08,960 - RECV: >>> do_blocking_move_to X42.83 Y100.00 Z7.93 2020-05-04 14:39:08,960 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:09,502 - RECV: current_position= X42.83 Y100.00 Z7.93 : >>> Probe::probe_down_to_z 2020-05-04 14:39:09,502 - RECV: >>> do_blocking_move_to X42.83 Y100.00 Z1.05 2020-05-04 14:39:09,515 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:10,155 - RECV: current_position= X42.83 Y100.00 Z2.93 : sync_plan_position 2020-05-04 14:39:10,165 - RECV: current_position= X42.83 Y100.00 Z2.93 : <<< Probe::probe_down_to_z 2020-05-04 14:39:10,165 - RECV: 2nd Probe Z:2.93 Discrepancy:-0.00 2020-05-04 14:39:10,176 - RECV: current_position= X42.83 Y100.00 Z2.93 : <<< run_z_probe 2020-05-04 14:39:10,176 - RECV: >>> do_blocking_move_to X42.83 Y100.00 Z6.93 2020-05-04 14:39:10,186 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:10,190 - RECV: echo:busy: processing 2020-05-04 14:39:10,665 - RECV: <<< Probe::probe_at_point 2020-05-04 14:39:10,665 - RECV: >>> Probe::probe_at_point(28.00, 67.00, raise, 0, probe_relative) 2020-05-04 14:39:10,676 - RECV: current_position= X42.83 Y100.00 Z6.93 : 2020-05-04 14:39:10,676 - RECV: >>> do_blocking_move_to X0.00 Y100.00 Z6.93 2020-05-04 14:39:10,686 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:11,158 - RECV: current_position= X0.00 Y100.00 Z6.93 : Probe::set_deployed 2020-05-04 14:39:11,180 - RECV: deploy: 1 2020-05-04 14:39:11,184 - RECV: current_position= X0.00 Y100.00 Z6.93 : >>> Probe::run_z_probe 2020-05-04 14:39:11,194 - RECV: current_position= X0.00 Y100.00 Z6.93 : >>> Probe::probe_down_to_z 2020-05-04 14:39:11,194 - RECV: >>> do_blocking_move_to X0.00 Y100.00 Z1.05 2020-05-04 14:39:11,203 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:11,584 - RECV: current_position= X0.00 Y100.00 Z2.99 : sync_plan_position 2020-05-04 14:39:11,585 - RECV: current_position= X0.00 Y100.00 Z2.99 : <<< Probe::probe_down_to_z 2020-05-04 14:39:11,585 - RECV: 1st Probe Z:2.99 2020-05-04 14:39:11,595 - RECV: >>> do_blocking_move_to X0.00 Y100.00 Z7.99 2020-05-04 14:39:11,595 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:12,134 - RECV: current_position= X0.00 Y100.00 Z7.99 : >>> Probe::probe_down_to_z 2020-05-04 14:39:12,134 - RECV: >>> do_blocking_move_to X0.00 Y100.00 Z1.05 2020-05-04 14:39:12,134 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:12,170 - RECV: echo:busy: processing 2020-05-04 14:39:12,783 - RECV: current_position= X0.00 Y100.00 Z2.98 : sync_plan_position 2020-05-04 14:39:12,793 - RECV: current_position= X0.00 Y100.00 Z2.98 : <<< Probe::probe_down_to_z 2020-05-04 14:39:12,793 - RECV: 2nd Probe Z:2.98 Discrepancy:0.01 2020-05-04 14:39:12,803 - RECV: current_position= X0.00 Y100.00 Z2.98 : <<< run_z_probe 2020-05-04 14:39:12,803 - RECV: >>> do_blocking_move_to X0.00 Y100.00 Z6.98 2020-05-04 14:39:12,816 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:13,286 - RECV: <<< Probe::probe_at_point 2020-05-04 14:39:13,296 - RECV: >>> Probe::probe_at_point(28.00, 109.00, raise, 0, probe_relative) 2020-05-04 14:39:13,296 - RECV: current_position= X0.00 Y100.00 Z6.98 : 2020-05-04 14:39:13,305 - RECV: >>> do_blocking_move_to X0.00 Y142.00 Z6.98 2020-05-04 14:39:13,305 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:13,789 - RECV: current_position= X0.00 Y142.00 Z6.98 : Probe::set_deployed 2020-05-04 14:39:13,789 - RECV: deploy: 1 2020-05-04 14:39:13,799 - RECV: current_position= X0.00 Y142.00 Z6.98 : >>> Probe::run_z_probe 2020-05-04 14:39:13,799 - RECV: current_position= X0.00 Y142.00 Z6.98 : >>> Probe::probe_down_to_z 2020-05-04 14:39:13,809 - RECV: >>> do_blocking_move_to X0.00 Y142.00 Z1.05 2020-05-04 14:39:13,809 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:14,173 - RECV: echo:busy: processing 2020-05-04 14:39:14,201 - RECV: current_position= X0.00 Y142.00 Z3.02 : sync_plan_position 2020-05-04 14:39:14,213 - RECV: current_position= X0.00 Y142.00 Z3.02 : <<< Probe::probe_down_to_z 2020-05-04 14:39:14,217 - RECV: 1st Probe Z:3.02 2020-05-04 14:39:14,217 - RECV: >>> do_blocking_move_to X0.00 Y142.00 Z8.02 2020-05-04 14:39:14,217 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:14,756 - RECV: current_position= X0.00 Y142.00 Z8.02 : >>> Probe::probe_down_to_z 2020-05-04 14:39:14,756 - RECV: >>> do_blocking_move_to X0.00 Y142.00 Z1.05 2020-05-04 14:39:14,766 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:15,424 - RECV: current_position= X0.00 Y142.00 Z3.02 : sync_plan_position 2020-05-04 14:39:15,545 - RECV: current_position= X0.00 Y142.00 Z3.02 : <<< Probe::probe_down_to_z 2020-05-04 14:39:15,605 - RECV: 2nd Probe Z:3.02 Discrepancy:-0.00 2020-05-04 14:39:15,645 - RECV: current_position= X0.00 Y142.00 Z3.02 : <<< run_z_probe 2020-05-04 14:39:15,645 - RECV: >>> do_blocking_move_to X0.00 Y142.00 Z7.02 2020-05-04 14:39:15,645 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:15,911 - RECV: <<< Probe::probe_at_point 2020-05-04 14:39:15,921 - RECV: >>> Probe::probe_at_point(70.83, 109.00, raise, 0, probe_relative) 2020-05-04 14:39:15,921 - RECV: current_position= X0.00 Y142.00 Z7.02 : 2020-05-04 14:39:15,934 - RECV: >>> do_blocking_move_to X42.83 Y142.00 Z7.02 2020-05-04 14:39:15,934 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:16,165 - RECV: echo:busy: processing 2020-05-04 14:39:16,512 - RECV: current_position= X42.83 Y142.00 Z7.02 : Probe::set_deployed 2020-05-04 14:39:16,536 - RECV: deploy: 1 2020-05-04 14:39:16,637 - RECV: current_position= X42.83 Y142.00 Z7.02 : >>> Probe::run_z_probe 2020-05-04 14:39:16,642 - RECV: current_position= X42.83 Y142.00 Z7.02 : >>> Probe::probe_down_to_z 2020-05-04 14:39:16,642 - RECV: >>> do_blocking_move_to X42.83 Y142.00 Z1.05 2020-05-04 14:39:16,653 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:16,838 - RECV: current_position= X42.83 Y142.00 Z2.96 : sync_plan_position 2020-05-04 14:39:16,842 - RECV: current_position= X42.83 Y142.00 Z2.96 : <<< Probe::probe_down_to_z 2020-05-04 14:39:16,842 - RECV: 1st Probe Z:2.96 2020-05-04 14:39:16,852 - RECV: >>> do_blocking_move_to X42.83 Y142.00 Z7.96 2020-05-04 14:39:16,852 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:17,395 - RECV: current_position= X42.83 Y142.00 Z7.96 : >>> Probe::probe_down_to_z 2020-05-04 14:39:17,398 - RECV: >>> do_blocking_move_to X42.83 Y142.00 Z1.05 2020-05-04 14:39:17,398 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:18,046 - RECV: current_position= X42.83 Y142.00 Z2.96 : sync_plan_position 2020-05-04 14:39:18,055 - RECV: current_position= X42.83 Y142.00 Z2.96 : <<< Probe::probe_down_to_z 2020-05-04 14:39:18,055 - RECV: 2nd Probe Z:2.96 Discrepancy:-0.00 2020-05-04 14:39:18,069 - RECV: current_position= X42.83 Y142.00 Z2.96 : <<< run_z_probe 2020-05-04 14:39:18,075 - RECV: >>> do_blocking_move_to X42.83 Y142.00 Z6.96 2020-05-04 14:39:18,075 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:18,171 - RECV: echo:busy: processing 2020-05-04 14:39:18,549 - RECV: <<< Probe::probe_at_point 2020-05-04 14:39:18,562 - RECV: >>> Probe::probe_at_point(113.67, 109.00, raise, 0, probe_relative) 2020-05-04 14:39:18,565 - RECV: current_position= X42.83 Y142.00 Z6.96 : 2020-05-04 14:39:18,565 - RECV: >>> do_blocking_move_to X85.67 Y142.00 Z6.96 2020-05-04 14:39:18,565 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:19,052 - RECV: current_position= X85.67 Y142.00 Z6.96 : Probe::set_deployed 2020-05-04 14:39:19,052 - RECV: deploy: 1 2020-05-04 14:39:19,068 - RECV: current_position= X85.67 Y142.00 Z6.96 : >>> Probe::run_z_probe 2020-05-04 14:39:19,068 - RECV: current_position= X85.67 Y142.00 Z6.96 : >>> Probe::probe_down_to_z 2020-05-04 14:39:19,078 - RECV: >>> do_blocking_move_to X85.67 Y142.00 Z1.05 2020-05-04 14:39:19,078 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:19,467 - RECV: current_position= X85.67 Y142.00 Z3.03 : sync_plan_position 2020-05-04 14:39:19,480 - RECV: current_position= X85.67 Y142.00 Z3.03 : <<< Probe::probe_down_to_z 2020-05-04 14:39:19,483 - RECV: 1st Probe Z:3.03 2020-05-04 14:39:19,483 - RECV: >>> do_blocking_move_to X85.67 Y142.00 Z8.03 2020-05-04 14:39:19,483 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:20,020 - RECV: current_position= X85.67 Y142.00 Z8.03 : >>> Probe::probe_down_to_z 2020-05-04 14:39:20,025 - RECV: >>> do_blocking_move_to X85.67 Y142.00 Z1.05 2020-05-04 14:39:20,025 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:20,171 - RECV: echo:busy: processing 2020-05-04 14:39:20,601 - SENT: M105 2020-05-04 14:39:20,681 - RECV: current_position= X85.67 Y142.00 Z3.04 : sync_plan_position 2020-05-04 14:39:20,687 - RECV: current_position= X85.67 Y142.00 Z3.04 : <<< Probe::probe_down_to_z 2020-05-04 14:39:20,687 - RECV: 2nd Probe Z:3.04 Discrepancy:-0.00 2020-05-04 14:39:20,697 - RECV: current_position= X85.67 Y142.00 Z3.04 : <<< run_z_probe 2020-05-04 14:39:20,697 - RECV: >>> do_blocking_move_to X85.67 Y142.00 Z7.04 2020-05-04 14:39:20,707 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:21,181 - RECV: <<< Probe::probe_at_point 2020-05-04 14:39:21,181 - RECV: >>> Probe::probe_at_point(156.50, 109.00, raise, 0, probe_relative) 2020-05-04 14:39:21,191 - RECV: current_position= X85.67 Y142.00 Z7.04 : 2020-05-04 14:39:21,191 - RECV: >>> do_blocking_move_to X128.50 Y142.00 Z7.04 2020-05-04 14:39:21,201 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:21,678 - RECV: current_position= X128.50 Y142.00 Z7.04 : Probe::set_deployed 2020-05-04 14:39:21,678 - RECV: deploy: 1 2020-05-04 14:39:21,688 - RECV: current_position= X128.50 Y142.00 Z7.04 : >>> Probe::run_z_probe 2020-05-04 14:39:21,698 - RECV: current_position= X128.50 Y142.00 Z7.04 : >>> Probe::probe_down_to_z 2020-05-04 14:39:21,698 - RECV: >>> do_blocking_move_to X128.50 Y142.00 Z1.05 2020-05-04 14:39:21,709 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:22,098 - RECV: current_position= X128.50 Y142.00 Z3.03 : sync_plan_position 2020-05-04 14:39:22,111 - RECV: current_position= X128.50 Y142.00 Z3.03 : <<< Probe::probe_down_to_z 2020-05-04 14:39:22,112 - RECV: 1st Probe Z:3.03 2020-05-04 14:39:22,112 - RECV: >>> do_blocking_move_to X128.50 Y142.00 Z8.03 2020-05-04 14:39:22,112 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:22,168 - RECV: echo:busy: processing 2020-05-04 14:39:22,651 - RECV: current_position= X128.50 Y142.00 Z8.03 : >>> Probe::probe_down_to_z 2020-05-04 14:39:22,661 - RECV: >>> do_blocking_move_to X128.50 Y142.00 Z1.05 2020-05-04 14:39:22,661 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:23,315 - RECV: current_position= X128.50 Y142.00 Z3.03 : sync_plan_position 2020-05-04 14:39:23,315 - RECV: current_position= X128.50 Y142.00 Z3.03 : <<< Probe::probe_down_to_z 2020-05-04 14:39:23,325 - RECV: 2nd Probe Z:3.03 Discrepancy:-0.01 2020-05-04 14:39:23,325 - RECV: current_position= X128.50 Y142.00 Z3.03 : <<< run_z_probe 2020-05-04 14:39:23,335 - RECV: >>> do_blocking_move_to X128.50 Y142.00 Z7.03 2020-05-04 14:39:23,335 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:23,818 - RECV: <<< Probe::probe_at_point 2020-05-04 14:39:23,821 - RECV: >>> Probe::probe_at_point(199.33, 109.00, raise, 0, probe_relative) 2020-05-04 14:39:23,821 - RECV: current_position= X128.50 Y142.00 Z7.03 : 2020-05-04 14:39:23,832 - RECV: >>> do_blocking_move_to X171.33 Y142.00 Z7.03 2020-05-04 14:39:23,832 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:24,168 - RECV: echo:busy: processing 2020-05-04 14:39:24,319 - RECV: current_position= X171.33 Y142.00 Z7.03 : Probe::set_deployed 2020-05-04 14:39:24,319 - RECV: deploy: 1 2020-05-04 14:39:24,322 - RECV: current_position= X171.33 Y142.00 Z7.03 : >>> Probe::run_z_probe 2020-05-04 14:39:24,332 - RECV: current_position= X171.33 Y142.00 Z7.03 : >>> Probe::probe_down_to_z 2020-05-04 14:39:24,332 - RECV: >>> do_blocking_move_to X171.33 Y142.00 Z1.05 2020-05-04 14:39:24,342 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:24,726 - RECV: current_position= X171.33 Y142.00 Z3.07 : sync_plan_position 2020-05-04 14:39:24,736 - RECV: current_position= X171.33 Y142.00 Z3.07 : <<< Probe::probe_down_to_z 2020-05-04 14:39:24,736 - RECV: 1st Probe Z:3.07 2020-05-04 14:39:24,746 - RECV: >>> do_blocking_move_to X171.33 Y142.00 Z8.07 2020-05-04 14:39:24,753 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:25,285 - RECV: current_position= X171.33 Y142.00 Z8.07 : >>> Probe::probe_down_to_z 2020-05-04 14:39:25,285 - RECV: >>> do_blocking_move_to X171.33 Y142.00 Z1.05 2020-05-04 14:39:25,295 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:25,948 - RECV: current_position= X171.33 Y142.00 Z3.07 : sync_plan_position 2020-05-04 14:39:25,953 - RECV: current_position= X171.33 Y142.00 Z3.07 : <<< Probe::probe_down_to_z 2020-05-04 14:39:25,953 - RECV: 2nd Probe Z:3.07 Discrepancy:0.00 2020-05-04 14:39:25,963 - RECV: current_position= X171.33 Y142.00 Z3.07 : <<< run_z_probe 2020-05-04 14:39:25,963 - RECV: >>> do_blocking_move_to X171.33 Y142.00 Z7.07 2020-05-04 14:39:25,973 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:26,173 - RECV: echo:busy: processing 2020-05-04 14:39:26,480 - RECV: <<< Probe::probe_at_point 2020-05-04 14:39:26,509 - RECV: >>> Probe::probe_at_point(242.17, 109.00, raise, 0, probe_relative) 2020-05-04 14:39:26,516 - RECV: current_position= X171.33 Y142.00 Z7.07 : 2020-05-04 14:39:26,516 - RECV: >>> do_blocking_move_to X214.17 Y142.00 Z7.07 2020-05-04 14:39:26,516 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:26,943 - RECV: current_position= X214.17 Y142.00 Z7.07 : Probe::set_deployed 2020-05-04 14:39:26,953 - RECV: deploy: 1 2020-05-04 14:39:26,953 - RECV: current_position= X214.17 Y142.00 Z7.07 : >>> Probe::run_z_probe 2020-05-04 14:39:26,963 - RECV: current_position= X214.17 Y142.00 Z7.07 : >>> Probe::probe_down_to_z 2020-05-04 14:39:26,973 - RECV: >>> do_blocking_move_to X214.17 Y142.00 Z1.05 2020-05-04 14:39:26,977 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:27,362 - RECV: current_position= X214.17 Y142.00 Z3.17 : sync_plan_position 2020-05-04 14:39:27,362 - RECV: current_position= X214.17 Y142.00 Z3.17 : <<< Probe::probe_down_to_z 2020-05-04 14:39:27,372 - RECV: 1st Probe Z:3.17 2020-05-04 14:39:27,378 - RECV: >>> do_blocking_move_to X214.17 Y142.00 Z8.17 2020-05-04 14:39:27,382 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:27,910 - RECV: current_position= X214.17 Y142.00 Z8.17 : >>> Probe::probe_down_to_z 2020-05-04 14:39:27,920 - RECV: >>> do_blocking_move_to X214.17 Y142.00 Z1.05 2020-05-04 14:39:27,920 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:28,167 - RECV: echo:busy: processing 2020-05-04 14:39:28,569 - RECV: current_position= X214.17 Y142.00 Z3.18 : sync_plan_position 2020-05-04 14:39:28,582 - RECV: current_position= X214.17 Y142.00 Z3.18 : <<< Probe::probe_down_to_z 2020-05-04 14:39:28,585 - RECV: 2nd Probe Z:3.18 Discrepancy:-0.01 2020-05-04 14:39:28,588 - RECV: current_position= X214.17 Y142.00 Z3.18 : <<< run_z_probe 2020-05-04 14:39:28,588 - RECV: >>> do_blocking_move_to X214.17 Y142.00 Z7.18 2020-05-04 14:39:28,598 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:29,076 - RECV: <<< Probe::probe_at_point 2020-05-04 14:39:29,079 - RECV: >>> Probe::probe_at_point(285.00, 109.00, raise, 0, probe_relative) 2020-05-04 14:39:29,081 - RECV: current_position= X214.17 Y142.00 Z7.18 : 2020-05-04 14:39:29,081 - RECV: >>> do_blocking_move_to X257.00 Y142.00 Z7.18 2020-05-04 14:39:29,081 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:29,579 - RECV: current_position= X257.00 Y142.00 Z7.18 : Probe::set_deployed 2020-05-04 14:39:29,582 - RECV: deploy: 1 2020-05-04 14:39:29,585 - RECV: current_position= X257.00 Y142.00 Z7.18 : >>> Probe::run_z_probe 2020-05-04 14:39:29,595 - RECV: current_position= X257.00 Y142.00 Z7.18 : >>> Probe::probe_down_to_z 2020-05-04 14:39:29,595 - RECV: >>> do_blocking_move_to X257.00 Y142.00 Z1.05 2020-05-04 14:39:29,595 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:29,996 - RECV: current_position= X257.00 Y142.00 Z3.14 : sync_plan_position 2020-05-04 14:39:30,006 - RECV: current_position= X257.00 Y142.00 Z3.14 : <<< Probe::probe_down_to_z 2020-05-04 14:39:30,009 - RECV: 1st Probe Z:3.14 2020-05-04 14:39:30,010 - RECV: >>> do_blocking_move_to X257.00 Y142.00 Z8.14 2020-05-04 14:39:30,015 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:30,170 - RECV: echo:busy: processing 2020-05-04 14:39:30,553 - RECV: current_position= X257.00 Y142.00 Z8.14 : >>> Probe::probe_down_to_z 2020-05-04 14:39:30,553 - RECV: >>> do_blocking_move_to X257.00 Y142.00 Z1.05 2020-05-04 14:39:30,553 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:31,203 - RECV: current_position= X257.00 Y142.00 Z3.14 : sync_plan_position 2020-05-04 14:39:31,213 - RECV: current_position= X257.00 Y142.00 Z3.14 : <<< Probe::probe_down_to_z 2020-05-04 14:39:31,220 - RECV: 2nd Probe Z:3.14 Discrepancy:0.00 2020-05-04 14:39:31,220 - RECV: current_position= X257.00 Y142.00 Z3.14 : <<< run_z_probe 2020-05-04 14:39:31,233 - RECV: >>> do_blocking_move_to X257.00 Y142.00 Z7.14 2020-05-04 14:39:31,236 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:31,707 - RECV: <<< Probe::probe_at_point 2020-05-04 14:39:31,717 - RECV: >>> Probe::probe_at_point(285.00, 151.00, raise, 0, probe_relative) 2020-05-04 14:39:31,717 - RECV: current_position= X257.00 Y142.00 Z7.14 : 2020-05-04 14:39:31,732 - RECV: >>> do_blocking_move_to X257.00 Y184.00 Z7.14 2020-05-04 14:39:31,732 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:32,167 - RECV: echo:busy: processing 2020-05-04 14:39:32,206 - RECV: current_position= X257.00 Y184.00 Z7.14 : Probe::set_deployed 2020-05-04 14:39:32,214 - RECV: deploy: 1 2020-05-04 14:39:32,220 - RECV: current_position= X257.00 Y184.00 Z7.14 : >>> Probe::run_z_probe 2020-05-04 14:39:32,223 - RECV: current_position= X257.00 Y184.00 Z7.14 : >>> Probe::probe_down_to_z 2020-05-04 14:39:32,234 - RECV: >>> do_blocking_move_to X257.00 Y184.00 Z1.05 2020-05-04 14:39:32,237 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:32,625 - RECV: current_position= X257.00 Y184.00 Z3.17 : sync_plan_position 2020-05-04 14:39:32,625 - RECV: current_position= X257.00 Y184.00 Z3.17 : <<< Probe::probe_down_to_z 2020-05-04 14:39:32,635 - RECV: 1st Probe Z:3.17 2020-05-04 14:39:32,641 - RECV: >>> do_blocking_move_to X257.00 Y184.00 Z8.17 2020-05-04 14:39:32,644 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:33,180 - RECV: current_position= X257.00 Y184.00 Z8.17 : >>> Probe::probe_down_to_z 2020-05-04 14:39:33,181 - RECV: >>> do_blocking_move_to X257.00 Y184.00 Z1.05 2020-05-04 14:39:33,181 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:33,832 - RECV: current_position= X257.00 Y184.00 Z3.17 : sync_plan_position 2020-05-04 14:39:33,845 - RECV: current_position= X257.00 Y184.00 Z3.17 : <<< Probe::probe_down_to_z 2020-05-04 14:39:33,848 - RECV: 2nd Probe Z:3.17 Discrepancy:-0.00 2020-05-04 14:39:33,851 - RECV: current_position= X257.00 Y184.00 Z3.17 : <<< run_z_probe 2020-05-04 14:39:33,851 - RECV: >>> do_blocking_move_to X257.00 Y184.00 Z7.17 2020-05-04 14:39:33,861 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:34,174 - RECV: echo:busy: processing 2020-05-04 14:39:34,332 - RECV: <<< Probe::probe_at_point 2020-05-04 14:39:34,348 - RECV: >>> Probe::probe_at_point(242.17, 151.00, raise, 0, probe_relative) 2020-05-04 14:39:34,352 - RECV: current_position= X257.00 Y184.00 Z7.17 : 2020-05-04 14:39:34,352 - RECV: >>> do_blocking_move_to X214.17 Y184.00 Z7.17 2020-05-04 14:39:34,352 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:34,842 - RECV: current_position= X214.17 Y184.00 Z7.17 : Probe::set_deployed 2020-05-04 14:39:34,842 - RECV: deploy: 1 2020-05-04 14:39:34,842 - RECV: current_position= X214.17 Y184.00 Z7.17 : >>> Probe::run_z_probe 2020-05-04 14:39:34,851 - RECV: current_position= X214.17 Y184.00 Z7.17 : >>> Probe::probe_down_to_z 2020-05-04 14:39:34,861 - RECV: >>> do_blocking_move_to X214.17 Y184.00 Z1.05 2020-05-04 14:39:34,861 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:35,255 - RECV: current_position= X214.17 Y184.00 Z3.18 : sync_plan_position 2020-05-04 14:39:35,265 - RECV: current_position= X214.17 Y184.00 Z3.18 : <<< Probe::probe_down_to_z 2020-05-04 14:39:35,265 - RECV: 1st Probe Z:3.18 2020-05-04 14:39:35,265 - RECV: >>> do_blocking_move_to X214.17 Y184.00 Z8.18 2020-05-04 14:39:35,275 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:35,809 - RECV: current_position= X214.17 Y184.00 Z8.18 : >>> Probe::probe_down_to_z 2020-05-04 14:39:35,809 - RECV: >>> do_blocking_move_to X214.17 Y184.00 Z1.05 2020-05-04 14:39:35,819 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:36,058 - SENT: M105 2020-05-04 14:39:36,171 - RECV: echo:busy: processing 2020-05-04 14:39:36,549 - RECV: current_position= X214.17 Y184.00 Z3.19 : sync_plan_position 2020-05-04 14:39:36,609 - RECV: current_position= X214.17 Y184.00 Z3.19 : <<< Probe::probe_down_to_z 2020-05-04 14:39:36,609 - RECV: 2nd Probe Z:3.19 Discrepancy:-0.01 2020-05-04 14:39:36,615 - RECV: current_position= X214.17 Y184.00 Z3.19 : <<< run_z_probe 2020-05-04 14:39:36,615 - RECV: >>> do_blocking_move_to X214.17 Y184.00 Z7.19 2020-05-04 14:39:36,625 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:36,971 - RECV: <<< Probe::probe_at_point 2020-05-04 14:39:36,977 - RECV: >>> Probe::probe_at_point(199.33, 151.00, raise, 0, probe_relative) 2020-05-04 14:39:36,977 - RECV: current_position= X214.17 Y184.00 Z7.19 : 2020-05-04 14:39:36,987 - RECV: >>> do_blocking_move_to X171.33 Y184.00 Z7.19 2020-05-04 14:39:36,987 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:37,562 - RECV: current_position= X171.33 Y184.00 Z7.19 : Probe::set_deployed 2020-05-04 14:39:37,588 - RECV: deploy: 1 2020-05-04 14:39:37,598 - RECV: current_position= X171.33 Y184.00 Z7.19 : >>> Probe::run_z_probe 2020-05-04 14:39:37,598 - RECV: current_position= X171.33 Y184.00 Z7.19 : >>> Probe::probe_down_to_z 2020-05-04 14:39:37,609 - RECV: >>> do_blocking_move_to X171.33 Y184.00 Z1.05 2020-05-04 14:39:37,609 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:37,897 - RECV: current_position= X171.33 Y184.00 Z3.09 : sync_plan_position 2020-05-04 14:39:37,897 - RECV: current_position= X171.33 Y184.00 Z3.09 : <<< Probe::probe_down_to_z 2020-05-04 14:39:37,907 - RECV: 1st Probe Z:3.09 2020-05-04 14:39:37,913 - RECV: >>> do_blocking_move_to X171.33 Y184.00 Z8.09 2020-05-04 14:39:37,913 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:38,171 - RECV: echo:busy: processing 2020-05-04 14:39:38,448 - RECV: current_position= X171.33 Y184.00 Z8.09 : >>> Probe::probe_down_to_z 2020-05-04 14:39:38,448 - RECV: >>> do_blocking_move_to X171.33 Y184.00 Z1.05 2020-05-04 14:39:38,459 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:39,105 - RECV: current_position= X171.33 Y184.00 Z3.09 : sync_plan_position 2020-05-04 14:39:39,115 - RECV: current_position= X171.33 Y184.00 Z3.09 : <<< Probe::probe_down_to_z 2020-05-04 14:39:39,115 - RECV: 2nd Probe Z:3.09 Discrepancy:0.00 2020-05-04 14:39:39,125 - RECV: current_position= X171.33 Y184.00 Z3.09 : <<< run_z_probe 2020-05-04 14:39:39,125 - RECV: >>> do_blocking_move_to X171.33 Y184.00 Z7.09 2020-05-04 14:39:39,125 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:39,607 - RECV: <<< Probe::probe_at_point 2020-05-04 14:39:39,617 - RECV: >>> Probe::probe_at_point(156.50, 151.00, raise, 0, probe_relative) 2020-05-04 14:39:39,617 - RECV: current_position= X171.33 Y184.00 Z7.09 : 2020-05-04 14:39:39,627 - RECV: >>> do_blocking_move_to X128.50 Y184.00 Z7.09 2020-05-04 14:39:39,627 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:40,108 - RECV: current_position= X128.50 Y184.00 Z7.09 : Probe::set_deployed 2020-05-04 14:39:40,108 - RECV: deploy: 1 2020-05-04 14:39:40,118 - RECV: current_position= X128.50 Y184.00 Z7.09 : >>> Probe::run_z_probe 2020-05-04 14:39:40,118 - RECV: current_position= X128.50 Y184.00 Z7.09 : >>> Probe::probe_down_to_z 2020-05-04 14:39:40,128 - RECV: >>> do_blocking_move_to X128.50 Y184.00 Z1.05 2020-05-04 14:39:40,138 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:40,164 - RECV: echo:busy: processing 2020-05-04 14:39:40,530 - RECV: current_position= X128.50 Y184.00 Z3.05 : sync_plan_position 2020-05-04 14:39:40,543 - RECV: current_position= X128.50 Y184.00 Z3.05 : <<< Probe::probe_down_to_z 2020-05-04 14:39:40,546 - RECV: 1st Probe Z:3.05 2020-05-04 14:39:40,546 - RECV: >>> do_blocking_move_to X128.50 Y184.00 Z8.05 2020-05-04 14:39:40,555 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:41,088 - RECV: current_position= X128.50 Y184.00 Z8.05 : >>> Probe::probe_down_to_z 2020-05-04 14:39:41,089 - RECV: >>> do_blocking_move_to X128.50 Y184.00 Z1.05 2020-05-04 14:39:41,089 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:41,742 - RECV: current_position= X128.50 Y184.00 Z3.05 : sync_plan_position 2020-05-04 14:39:41,755 - RECV: current_position= X128.50 Y184.00 Z3.05 : <<< Probe::probe_down_to_z 2020-05-04 14:39:41,757 - RECV: 2nd Probe Z:3.05 Discrepancy:-0.00 2020-05-04 14:39:41,757 - RECV: current_position= X128.50 Y184.00 Z3.05 : <<< run_z_probe 2020-05-04 14:39:41,767 - RECV: >>> do_blocking_move_to X128.50 Y184.00 Z7.05 2020-05-04 14:39:41,767 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:42,171 - RECV: echo:busy: processing 2020-05-04 14:39:42,278 - RECV: <<< Probe::probe_at_point 2020-05-04 14:39:42,398 - RECV: >>> Probe::probe_at_point(113.67, 151.00, raise, 0, probe_relative) 2020-05-04 14:39:42,431 - RECV: current_position= X128.50 Y184.00 Z7.05 : 2020-05-04 14:39:42,456 - RECV: >>> do_blocking_move_to X85.67 Y184.00 Z7.05 2020-05-04 14:39:42,457 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:42,812 - RECV: current_position= X85.67 Y184.00 Z7.05 : Probe::set_deployed 2020-05-04 14:39:42,836 - RECV: deploy: 1 2020-05-04 14:39:42,926 - RECV: current_position= X85.67 Y184.00 Z7.05 : >>> Probe::run_z_probe 2020-05-04 14:39:42,957 - RECV: current_position= X85.67 Y184.00 Z7.05 : >>> Probe::probe_down_to_z 2020-05-04 14:39:42,976 - RECV: >>> do_blocking_move_to X85.67 Y184.00 Z1.05 2020-05-04 14:39:42,990 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:43,163 - RECV: current_position= X85.67 Y184.00 Z3.05 : sync_plan_position 2020-05-04 14:39:43,173 - RECV: current_position= X85.67 Y184.00 Z3.05 : <<< Probe::probe_down_to_z 2020-05-04 14:39:43,173 - RECV: 1st Probe Z:3.05 2020-05-04 14:39:43,173 - RECV: >>> do_blocking_move_to X85.67 Y184.00 Z8.05 2020-05-04 14:39:43,183 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:43,720 - RECV: current_position= X85.67 Y184.00 Z8.05 : >>> Probe::probe_down_to_z 2020-05-04 14:39:43,723 - RECV: >>> do_blocking_move_to X85.67 Y184.00 Z1.05 2020-05-04 14:39:43,723 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:44,167 - RECV: echo:busy: processing 2020-05-04 14:39:44,369 - RECV: current_position= X85.67 Y184.00 Z3.05 : sync_plan_position 2020-05-04 14:39:44,380 - RECV: current_position= X85.67 Y184.00 Z3.05 : <<< Probe::probe_down_to_z 2020-05-04 14:39:44,390 - RECV: 2nd Probe Z:3.05 Discrepancy:-0.01 2020-05-04 14:39:44,394 - RECV: current_position= X85.67 Y184.00 Z3.05 : <<< run_z_probe 2020-05-04 14:39:44,394 - RECV: >>> do_blocking_move_to X85.67 Y184.00 Z7.05 2020-05-04 14:39:44,404 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:44,878 - RECV: <<< Probe::probe_at_point 2020-05-04 14:39:44,878 - RECV: >>> Probe::probe_at_point(70.83, 151.00, raise, 0, probe_relative) 2020-05-04 14:39:44,891 - RECV: current_position= X85.67 Y184.00 Z7.05 : 2020-05-04 14:39:44,894 - RECV: >>> do_blocking_move_to X42.83 Y184.00 Z7.05 2020-05-04 14:39:44,894 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:45,381 - RECV: current_position= X42.83 Y184.00 Z7.05 : Probe::set_deployed 2020-05-04 14:39:45,384 - RECV: deploy: 1 2020-05-04 14:39:45,388 - RECV: current_position= X42.83 Y184.00 Z7.05 : >>> Probe::run_z_probe 2020-05-04 14:39:45,388 - RECV: current_position= X42.83 Y184.00 Z7.05 : >>> Probe::probe_down_to_z 2020-05-04 14:39:45,398 - RECV: >>> do_blocking_move_to X42.83 Y184.00 Z1.05 2020-05-04 14:39:45,398 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:45,799 - RECV: current_position= X42.83 Y184.00 Z2.98 : sync_plan_position 2020-05-04 14:39:45,809 - RECV: current_position= X42.83 Y184.00 Z2.98 : <<< Probe::probe_down_to_z 2020-05-04 14:39:45,809 - RECV: 1st Probe Z:2.98 2020-05-04 14:39:45,809 - RECV: >>> do_blocking_move_to X42.83 Y184.00 Z7.98 2020-05-04 14:39:45,823 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:46,171 - RECV: echo:busy: processing 2020-05-04 14:39:46,349 - RECV: current_position= X42.83 Y184.00 Z7.98 : >>> Probe::probe_down_to_z 2020-05-04 14:39:46,359 - RECV: >>> do_blocking_move_to X42.83 Y184.00 Z1.05 2020-05-04 14:39:46,359 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:47,006 - RECV: current_position= X42.83 Y184.00 Z2.98 : sync_plan_position 2020-05-04 14:39:47,016 - RECV: current_position= X42.83 Y184.00 Z2.98 : <<< Probe::probe_down_to_z 2020-05-04 14:39:47,016 - RECV: 2nd Probe Z:2.98 Discrepancy:-0.00 2020-05-04 14:39:47,026 - RECV: current_position= X42.83 Y184.00 Z2.98 : <<< run_z_probe 2020-05-04 14:39:47,039 - RECV: >>> do_blocking_move_to X42.83 Y184.00 Z6.98 2020-05-04 14:39:47,040 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:47,509 - RECV: <<< Probe::probe_at_point 2020-05-04 14:39:47,520 - RECV: >>> Probe::probe_at_point(28.00, 151.00, raise, 0, probe_relative) 2020-05-04 14:39:47,520 - RECV: current_position= X42.83 Y184.00 Z6.98 : 2020-05-04 14:39:47,530 - RECV: >>> do_blocking_move_to X0.00 Y184.00 Z6.98 2020-05-04 14:39:47,535 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:48,017 - RECV: current_position= X0.00 Y184.00 Z6.98 : Probe::set_deployed 2020-05-04 14:39:48,017 - RECV: deploy: 1 2020-05-04 14:39:48,017 - RECV: current_position= X0.00 Y184.00 Z6.98 : >>> Probe::run_z_probe 2020-05-04 14:39:48,028 - RECV: current_position= X0.00 Y184.00 Z6.98 : >>> Probe::probe_down_to_z 2020-05-04 14:39:48,038 - RECV: >>> do_blocking_move_to X0.00 Y184.00 Z1.05 2020-05-04 14:39:48,038 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:48,163 - RECV: echo:busy: processing 2020-05-04 14:39:48,529 - RECV: current_position= X0.00 Y184.00 Z3.02 : sync_plan_position 2020-05-04 14:39:48,609 - RECV: current_position= X0.00 Y184.00 Z3.02 : <<< Probe::probe_down_to_z 2020-05-04 14:39:48,624 - RECV: 1st Probe Z:3.02 2020-05-04 14:39:48,640 - RECV: >>> do_blocking_move_to X0.00 Y184.00 Z8.02 2020-05-04 14:39:48,654 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:48,986 - RECV: current_position= X0.00 Y184.00 Z8.02 : >>> Probe::probe_down_to_z 2020-05-04 14:39:48,989 - RECV: >>> do_blocking_move_to X0.00 Y184.00 Z1.05 2020-05-04 14:39:48,989 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:49,640 - RECV: current_position= X0.00 Y184.00 Z3.02 : sync_plan_position 2020-05-04 14:39:49,650 - RECV: current_position= X0.00 Y184.00 Z3.02 : <<< Probe::probe_down_to_z 2020-05-04 14:39:49,654 - RECV: 2nd Probe Z:3.02 Discrepancy:0.00 2020-05-04 14:39:49,657 - RECV: current_position= X0.00 Y184.00 Z3.02 : <<< run_z_probe 2020-05-04 14:39:49,657 - RECV: >>> do_blocking_move_to X0.00 Y184.00 Z7.02 2020-05-04 14:39:49,667 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:50,140 - RECV: <<< Probe::probe_at_point 2020-05-04 14:39:50,154 - RECV: >>> Probe::probe_at_point(28.00, 193.00, raise, 0, probe_relative) 2020-05-04 14:39:50,154 - RECV: current_position= X0.00 Y184.00 Z7.02 : 2020-05-04 14:39:50,158 - RECV: >>> do_blocking_move_to X0.00 Y226.00 Z7.02 2020-05-04 14:39:50,158 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:50,170 - RECV: echo:busy: processing 2020-05-04 14:39:50,641 - RECV: current_position= X0.00 Y226.00 Z7.02 : Probe::set_deployed 2020-05-04 14:39:50,641 - RECV: deploy: 1 2020-05-04 14:39:50,651 - RECV: current_position= X0.00 Y226.00 Z7.02 : >>> Probe::run_z_probe 2020-05-04 14:39:50,657 - RECV: current_position= X0.00 Y226.00 Z7.02 : >>> Probe::probe_down_to_z 2020-05-04 14:39:50,661 - RECV: >>> do_blocking_move_to X0.00 Y226.00 Z1.05 2020-05-04 14:39:50,661 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:51,059 - RECV: current_position= X0.00 Y226.00 Z3.06 : sync_plan_position 2020-05-04 14:39:51,062 - RECV: current_position= X0.00 Y226.00 Z3.06 : <<< Probe::probe_down_to_z 2020-05-04 14:39:51,062 - RECV: 1st Probe Z:3.06 2020-05-04 14:39:51,062 - RECV: >>> do_blocking_move_to X0.00 Y226.00 Z8.06 2020-05-04 14:39:51,072 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:51,533 - SENT: M105 2020-05-04 14:39:51,608 - RECV: current_position= X0.00 Y226.00 Z8.06 : >>> Probe::probe_down_to_z 2020-05-04 14:39:51,608 - RECV: >>> do_blocking_move_to X0.00 Y226.00 Z1.05 2020-05-04 14:39:51,608 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:52,171 - RECV: echo:busy: processing 2020-05-04 14:39:52,262 - RECV: current_position= X0.00 Y226.00 Z3.06 : sync_plan_position 2020-05-04 14:39:52,272 - RECV: current_position= X0.00 Y226.00 Z3.06 : <<< Probe::probe_down_to_z 2020-05-04 14:39:52,272 - RECV: 2nd Probe Z:3.06 Discrepancy:0.00 2020-05-04 14:39:52,288 - RECV: current_position= X0.00 Y226.00 Z3.06 : <<< run_z_probe 2020-05-04 14:39:52,292 - RECV: >>> do_blocking_move_to X0.00 Y226.00 Z7.06 2020-05-04 14:39:52,292 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:52,765 - RECV: <<< Probe::probe_at_point 2020-05-04 14:39:52,775 - RECV: >>> Probe::probe_at_point(70.83, 193.00, raise, 0, probe_relative) 2020-05-04 14:39:52,775 - RECV: current_position= X0.00 Y226.00 Z7.06 : 2020-05-04 14:39:52,786 - RECV: >>> do_blocking_move_to X42.83 Y226.00 Z7.06 2020-05-04 14:39:52,789 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:53,263 - RECV: current_position= X42.83 Y226.00 Z7.06 : Probe::set_deployed 2020-05-04 14:39:53,273 - RECV: deploy: 1 2020-05-04 14:39:53,273 - RECV: current_position= X42.83 Y226.00 Z7.06 : >>> Probe::run_z_probe 2020-05-04 14:39:53,286 - RECV: current_position= X42.83 Y226.00 Z7.06 : >>> Probe::probe_down_to_z 2020-05-04 14:39:53,289 - RECV: >>> do_blocking_move_to X42.83 Y226.00 Z1.05 2020-05-04 14:39:53,289 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:53,693 - RECV: current_position= X42.83 Y226.00 Z3.00 : sync_plan_position 2020-05-04 14:39:53,693 - RECV: current_position= X42.83 Y226.00 Z3.00 : <<< Probe::probe_down_to_z 2020-05-04 14:39:53,693 - RECV: 1st Probe Z:3.00 2020-05-04 14:39:53,703 - RECV: >>> do_blocking_move_to X42.83 Y226.00 Z8.00 2020-05-04 14:39:53,703 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:54,170 - RECV: echo:busy: processing 2020-05-04 14:39:54,243 - RECV: current_position= X42.83 Y226.00 Z8.00 : >>> Probe::probe_down_to_z 2020-05-04 14:39:54,249 - RECV: >>> do_blocking_move_to X42.83 Y226.00 Z1.05 2020-05-04 14:39:54,249 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:54,898 - RECV: current_position= X42.83 Y226.00 Z3.00 : sync_plan_position 2020-05-04 14:39:54,907 - RECV: current_position= X42.83 Y226.00 Z3.00 : <<< Probe::probe_down_to_z 2020-05-04 14:39:54,907 - RECV: 2nd Probe Z:3.00 Discrepancy:-0.00 2020-05-04 14:39:54,920 - RECV: current_position= X42.83 Y226.00 Z3.00 : <<< run_z_probe 2020-05-04 14:39:54,921 - RECV: >>> do_blocking_move_to X42.83 Y226.00 Z7.01 2020-05-04 14:39:54,927 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:55,404 - RECV: <<< Probe::probe_at_point 2020-05-04 14:39:55,404 - RECV: >>> Probe::probe_at_point(113.67, 193.00, raise, 0, probe_relative) 2020-05-04 14:39:55,417 - RECV: current_position= X42.83 Y226.00 Z7.01 : 2020-05-04 14:39:55,420 - RECV: >>> do_blocking_move_to X85.67 Y226.00 Z7.01 2020-05-04 14:39:55,420 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:55,904 - RECV: current_position= X85.67 Y226.00 Z7.01 : Probe::set_deployed 2020-05-04 14:39:55,904 - RECV: deploy: 1 2020-05-04 14:39:55,917 - RECV: current_position= X85.67 Y226.00 Z7.01 : >>> Probe::run_z_probe 2020-05-04 14:39:55,920 - RECV: current_position= X85.67 Y226.00 Z7.01 : >>> Probe::probe_down_to_z 2020-05-04 14:39:55,930 - RECV: >>> do_blocking_move_to X85.67 Y226.00 Z1.05 2020-05-04 14:39:55,930 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:56,168 - RECV: echo:busy: processing 2020-05-04 14:39:56,318 - RECV: current_position= X85.67 Y226.00 Z3.07 : sync_plan_position 2020-05-04 14:39:56,328 - RECV: current_position= X85.67 Y226.00 Z3.07 : <<< Probe::probe_down_to_z 2020-05-04 14:39:56,328 - RECV: 1st Probe Z:3.07 2020-05-04 14:39:56,328 - RECV: >>> do_blocking_move_to X85.67 Y226.00 Z8.07 2020-05-04 14:39:56,338 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:56,872 - RECV: current_position= X85.67 Y226.00 Z8.07 : >>> Probe::probe_down_to_z 2020-05-04 14:39:56,872 - RECV: >>> do_blocking_move_to X85.67 Y226.00 Z1.05 2020-05-04 14:39:56,872 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:57,526 - RECV: current_position= X85.67 Y226.00 Z3.06 : sync_plan_position 2020-05-04 14:39:57,536 - RECV: current_position= X85.67 Y226.00 Z3.06 : <<< Probe::probe_down_to_z 2020-05-04 14:39:57,536 - RECV: 2nd Probe Z:3.06 Discrepancy:0.01 2020-05-04 14:39:57,546 - RECV: current_position= X85.67 Y226.00 Z3.06 : <<< run_z_probe 2020-05-04 14:39:57,552 - RECV: >>> do_blocking_move_to X85.67 Y226.00 Z7.06 2020-05-04 14:39:57,552 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:58,032 - RECV: <<< Probe::probe_at_point 2020-05-04 14:39:58,032 - RECV: >>> Probe::probe_at_point(156.50, 193.00, raise, 0, probe_relative) 2020-05-04 14:39:58,045 - RECV: current_position= X85.67 Y226.00 Z7.06 : 2020-05-04 14:39:58,048 - RECV: >>> do_blocking_move_to X128.50 Y226.00 Z7.06 2020-05-04 14:39:58,048 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:58,168 - RECV: echo:busy: processing 2020-05-04 14:39:58,535 - RECV: current_position= X128.50 Y226.00 Z7.06 : Probe::set_deployed 2020-05-04 14:39:58,535 - RECV: deploy: 1 2020-05-04 14:39:58,545 - RECV: current_position= X128.50 Y226.00 Z7.06 : >>> Probe::run_z_probe 2020-05-04 14:39:58,549 - RECV: current_position= X128.50 Y226.00 Z7.06 : >>> Probe::probe_down_to_z 2020-05-04 14:39:58,549 - RECV: >>> do_blocking_move_to X128.50 Y226.00 Z1.05 2020-05-04 14:39:58,559 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:58,950 - RECV: current_position= X128.50 Y226.00 Z3.06 : sync_plan_position 2020-05-04 14:39:58,960 - RECV: current_position= X128.50 Y226.00 Z3.06 : <<< Probe::probe_down_to_z 2020-05-04 14:39:58,960 - RECV: 1st Probe Z:3.06 2020-05-04 14:39:58,960 - RECV: >>> do_blocking_move_to X128.50 Y226.00 Z8.06 2020-05-04 14:39:58,970 - RECV: <<< do_blocking_move_to 2020-05-04 14:39:59,503 - RECV: current_position= X128.50 Y226.00 Z8.06 : >>> Probe::probe_down_to_z 2020-05-04 14:39:59,503 - RECV: >>> do_blocking_move_to X128.50 Y226.00 Z1.05 2020-05-04 14:39:59,513 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:00,157 - RECV: current_position= X128.50 Y226.00 Z3.06 : sync_plan_position 2020-05-04 14:40:00,167 - RECV: current_position= X128.50 Y226.00 Z3.06 : <<< Probe::probe_down_to_z 2020-05-04 14:40:00,177 - RECV: 2nd Probe Z:3.06 Discrepancy:-0.00 2020-05-04 14:40:00,177 - RECV: current_position= X128.50 Y226.00 Z3.06 : <<< run_z_probe 2020-05-04 14:40:00,187 - RECV: >>> do_blocking_move_to X128.50 Y226.00 Z7.06 2020-05-04 14:40:00,187 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:00,187 - RECV: echo:busy: processing 2020-05-04 14:40:00,667 - RECV: <<< Probe::probe_at_point 2020-05-04 14:40:00,671 - RECV: >>> Probe::probe_at_point(199.33, 193.00, raise, 0, probe_relative) 2020-05-04 14:40:00,671 - RECV: current_position= X128.50 Y226.00 Z7.06 : 2020-05-04 14:40:00,681 - RECV: >>> do_blocking_move_to X171.33 Y226.00 Z7.06 2020-05-04 14:40:00,681 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:01,170 - RECV: current_position= X171.33 Y226.00 Z7.06 : Probe::set_deployed 2020-05-04 14:40:01,170 - RECV: deploy: 1 2020-05-04 14:40:01,173 - RECV: current_position= X171.33 Y226.00 Z7.06 : >>> Probe::run_z_probe 2020-05-04 14:40:01,183 - RECV: current_position= X171.33 Y226.00 Z7.06 : >>> Probe::probe_down_to_z 2020-05-04 14:40:01,183 - RECV: >>> do_blocking_move_to X171.33 Y226.00 Z1.05 2020-05-04 14:40:01,183 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:01,644 - RECV: current_position= X171.33 Y226.00 Z3.08 : sync_plan_position 2020-05-04 14:40:01,733 - RECV: current_position= X171.33 Y226.00 Z3.08 : <<< Probe::probe_down_to_z 2020-05-04 14:40:01,753 - RECV: 1st Probe Z:3.08 2020-05-04 14:40:01,763 - RECV: >>> do_blocking_move_to X171.33 Y226.00 Z8.08 2020-05-04 14:40:01,765 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:02,135 - RECV: current_position= X171.33 Y226.00 Z8.08 : >>> Probe::probe_down_to_z 2020-05-04 14:40:02,145 - RECV: >>> do_blocking_move_to X171.33 Y226.00 Z1.05 2020-05-04 14:40:02,145 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:02,174 - RECV: echo:busy: processing 2020-05-04 14:40:02,799 - RECV: current_position= X171.33 Y226.00 Z3.09 : sync_plan_position 2020-05-04 14:40:02,802 - RECV: current_position= X171.33 Y226.00 Z3.09 : <<< Probe::probe_down_to_z 2020-05-04 14:40:02,802 - RECV: 2nd Probe Z:3.09 Discrepancy:-0.00 2020-05-04 14:40:02,812 - RECV: current_position= X171.33 Y226.00 Z3.09 : <<< run_z_probe 2020-05-04 14:40:02,812 - RECV: >>> do_blocking_move_to X171.33 Y226.00 Z7.09 2020-05-04 14:40:02,812 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:03,296 - RECV: <<< Probe::probe_at_point 2020-05-04 14:40:03,305 - RECV: >>> Probe::probe_at_point(242.17, 193.00, raise, 0, probe_relative) 2020-05-04 14:40:03,305 - RECV: current_position= X171.33 Y226.00 Z7.09 : 2020-05-04 14:40:03,315 - RECV: >>> do_blocking_move_to X214.17 Y226.00 Z7.09 2020-05-04 14:40:03,321 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:03,799 - RECV: current_position= X214.17 Y226.00 Z7.09 : Probe::set_deployed 2020-05-04 14:40:03,799 - RECV: deploy: 1 2020-05-04 14:40:03,815 - RECV: current_position= X214.17 Y226.00 Z7.09 : >>> Probe::run_z_probe 2020-05-04 14:40:03,818 - RECV: current_position= X214.17 Y226.00 Z7.09 : >>> Probe::probe_down_to_z 2020-05-04 14:40:03,818 - RECV: >>> do_blocking_move_to X214.17 Y226.00 Z1.05 2020-05-04 14:40:03,828 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:04,176 - RECV: echo:busy: processing 2020-05-04 14:40:04,216 - RECV: current_position= X214.17 Y226.00 Z3.18 : sync_plan_position 2020-05-04 14:40:04,220 - RECV: current_position= X214.17 Y226.00 Z3.18 : <<< Probe::probe_down_to_z 2020-05-04 14:40:04,220 - RECV: 1st Probe Z:3.18 2020-05-04 14:40:04,220 - RECV: >>> do_blocking_move_to X214.17 Y226.00 Z8.18 2020-05-04 14:40:04,230 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:04,767 - RECV: current_position= X214.17 Y226.00 Z8.18 : >>> Probe::probe_down_to_z 2020-05-04 14:40:04,767 - RECV: >>> do_blocking_move_to X214.17 Y226.00 Z1.05 2020-05-04 14:40:04,767 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:05,421 - RECV: current_position= X214.17 Y226.00 Z3.19 : sync_plan_position 2020-05-04 14:40:05,431 - RECV: current_position= X214.17 Y226.00 Z3.19 : <<< Probe::probe_down_to_z 2020-05-04 14:40:05,431 - RECV: 2nd Probe Z:3.19 Discrepancy:-0.01 2020-05-04 14:40:05,441 - RECV: current_position= X214.17 Y226.00 Z3.19 : <<< run_z_probe 2020-05-04 14:40:05,441 - RECV: >>> do_blocking_move_to X214.17 Y226.00 Z7.19 2020-05-04 14:40:05,441 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:05,923 - RECV: <<< Probe::probe_at_point 2020-05-04 14:40:05,933 - RECV: >>> Probe::probe_at_point(285.00, 193.00, raise, 0, probe_relative) 2020-05-04 14:40:05,933 - RECV: current_position= X214.17 Y226.00 Z7.19 : 2020-05-04 14:40:05,947 - RECV: >>> do_blocking_move_to X257.00 Y226.00 Z7.19 2020-05-04 14:40:05,947 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:06,177 - RECV: echo:busy: processing 2020-05-04 14:40:06,427 - RECV: current_position= X257.00 Y226.00 Z7.19 : Probe::set_deployed 2020-05-04 14:40:06,427 - RECV: deploy: 1 2020-05-04 14:40:06,437 - RECV: current_position= X257.00 Y226.00 Z7.19 : >>> Probe::run_z_probe 2020-05-04 14:40:06,437 - RECV: current_position= X257.00 Y226.00 Z7.19 : >>> Probe::probe_down_to_z 2020-05-04 14:40:06,450 - RECV: >>> do_blocking_move_to X257.00 Y226.00 Z1.05 2020-05-04 14:40:06,450 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:06,851 - RECV: current_position= X257.00 Y226.00 Z3.15 : sync_plan_position 2020-05-04 14:40:06,861 - RECV: current_position= X257.00 Y226.00 Z3.15 : <<< Probe::probe_down_to_z 2020-05-04 14:40:06,861 - RECV: 1st Probe Z:3.15 2020-05-04 14:40:06,861 - RECV: >>> do_blocking_move_to X257.00 Y226.00 Z8.15 2020-05-04 14:40:06,871 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:06,931 - SENT: M105 2020-05-04 14:40:07,395 - RECV: current_position= X257.00 Y226.00 Z8.15 : >>> Probe::probe_down_to_z 2020-05-04 14:40:07,408 - RECV: >>> do_blocking_move_to X257.00 Y226.00 Z1.05 2020-05-04 14:40:07,411 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:08,059 - RECV: current_position= X257.00 Y226.00 Z3.16 : sync_plan_position 2020-05-04 14:40:08,059 - RECV: current_position= X257.00 Y226.00 Z3.16 : <<< Probe::probe_down_to_z 2020-05-04 14:40:08,069 - RECV: 2nd Probe Z:3.16 Discrepancy:-0.01 2020-05-04 14:40:08,079 - RECV: current_position= X257.00 Y226.00 Z3.16 : <<< run_z_probe 2020-05-04 14:40:08,085 - RECV: >>> do_blocking_move_to X257.00 Y226.00 Z7.16 2020-05-04 14:40:08,085 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:08,181 - RECV: echo:busy: processing 2020-05-04 14:40:08,561 - RECV: <<< Probe::probe_at_point 2020-05-04 14:40:08,569 - RECV: >>> Probe::probe_at_point(285.00, 235.00, raise, 0, probe_relative) 2020-05-04 14:40:08,579 - RECV: current_position= X257.00 Y226.00 Z7.16 : 2020-05-04 14:40:08,585 - RECV: >>> do_blocking_move_to X257.00 Y268.00 Z7.16 2020-05-04 14:40:08,589 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:09,056 - RECV: current_position= X257.00 Y268.00 Z7.16 : Probe::set_deployed 2020-05-04 14:40:09,056 - RECV: deploy: 1 2020-05-04 14:40:09,066 - RECV: current_position= X257.00 Y268.00 Z7.16 : >>> Probe::run_z_probe 2020-05-04 14:40:09,078 - RECV: current_position= X257.00 Y268.00 Z7.16 : >>> Probe::probe_down_to_z 2020-05-04 14:40:09,084 - RECV: >>> do_blocking_move_to X257.00 Y268.00 Z1.05 2020-05-04 14:40:09,088 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:09,483 - RECV: current_position= X257.00 Y268.00 Z3.11 : sync_plan_position 2020-05-04 14:40:09,492 - RECV: current_position= X257.00 Y268.00 Z3.11 : <<< Probe::probe_down_to_z 2020-05-04 14:40:09,494 - RECV: 1st Probe Z:3.11 2020-05-04 14:40:09,503 - RECV: >>> do_blocking_move_to X257.00 Y268.00 Z8.11 2020-05-04 14:40:09,509 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:10,035 - RECV: current_position= X257.00 Y268.00 Z8.11 : >>> Probe::probe_down_to_z 2020-05-04 14:40:10,042 - RECV: >>> do_blocking_move_to X257.00 Y268.00 Z1.05 2020-05-04 14:40:10,046 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:10,167 - RECV: echo:busy: processing 2020-05-04 14:40:10,691 - RECV: current_position= X257.00 Y268.00 Z3.11 : sync_plan_position 2020-05-04 14:40:10,694 - RECV: current_position= X257.00 Y268.00 Z3.11 : <<< Probe::probe_down_to_z 2020-05-04 14:40:10,697 - RECV: 2nd Probe Z:3.11 Discrepancy:-0.00 2020-05-04 14:40:10,700 - RECV: current_position= X257.00 Y268.00 Z3.11 : <<< run_z_probe 2020-05-04 14:40:10,704 - RECV: >>> do_blocking_move_to X257.00 Y268.00 Z7.11 2020-05-04 14:40:10,707 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:11,197 - RECV: <<< Probe::probe_at_point 2020-05-04 14:40:11,209 - RECV: >>> Probe::probe_at_point(242.17, 235.00, raise, 0, probe_relative) 2020-05-04 14:40:11,214 - RECV: current_position= X257.00 Y268.00 Z7.11 : 2020-05-04 14:40:11,221 - RECV: >>> do_blocking_move_to X214.17 Y268.00 Z7.11 2020-05-04 14:40:11,229 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:11,697 - RECV: current_position= X214.17 Y268.00 Z7.11 : Probe::set_deployed 2020-05-04 14:40:11,698 - RECV: deploy: 1 2020-05-04 14:40:11,710 - RECV: current_position= X214.17 Y268.00 Z7.11 : >>> Probe::run_z_probe 2020-05-04 14:40:11,721 - RECV: current_position= X214.17 Y268.00 Z7.11 : >>> Probe::probe_down_to_z 2020-05-04 14:40:11,727 - RECV: >>> do_blocking_move_to X214.17 Y268.00 Z1.05 2020-05-04 14:40:11,732 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:12,115 - RECV: current_position= X214.17 Y268.00 Z3.16 : sync_plan_position 2020-05-04 14:40:12,127 - RECV: current_position= X214.17 Y268.00 Z3.16 : <<< Probe::probe_down_to_z 2020-05-04 14:40:12,130 - RECV: 1st Probe Z:3.16 2020-05-04 14:40:12,131 - RECV: >>> do_blocking_move_to X214.17 Y268.00 Z8.15 2020-05-04 14:40:12,144 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:12,176 - RECV: echo:busy: processing 2020-05-04 14:40:12,667 - RECV: current_position= X214.17 Y268.00 Z8.15 : >>> Probe::probe_down_to_z 2020-05-04 14:40:12,674 - RECV: >>> do_blocking_move_to X214.17 Y268.00 Z1.05 2020-05-04 14:40:12,678 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:13,321 - RECV: current_position= X214.17 Y268.00 Z3.16 : sync_plan_position 2020-05-04 14:40:13,321 - RECV: current_position= X214.17 Y268.00 Z3.16 : <<< Probe::probe_down_to_z 2020-05-04 14:40:13,321 - RECV: 2nd Probe Z:3.16 Discrepancy:0.00 2020-05-04 14:40:13,331 - RECV: current_position= X214.17 Y268.00 Z3.16 : <<< run_z_probe 2020-05-04 14:40:13,331 - RECV: >>> do_blocking_move_to X214.17 Y268.00 Z7.15 2020-05-04 14:40:13,331 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:13,828 - RECV: <<< Probe::probe_at_point 2020-05-04 14:40:13,835 - RECV: >>> Probe::probe_at_point(199.33, 235.00, raise, 0, probe_relative) 2020-05-04 14:40:13,842 - RECV: current_position= X214.17 Y268.00 Z7.15 : 2020-05-04 14:40:13,848 - RECV: >>> do_blocking_move_to X171.33 Y268.00 Z7.15 2020-05-04 14:40:13,849 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:14,171 - RECV: echo:busy: processing 2020-05-04 14:40:14,328 - RECV: current_position= X171.33 Y268.00 Z7.15 : Probe::set_deployed 2020-05-04 14:40:14,331 - RECV: deploy: 1 2020-05-04 14:40:14,339 - RECV: current_position= X171.33 Y268.00 Z7.15 : >>> Probe::run_z_probe 2020-05-04 14:40:14,345 - RECV: current_position= X171.33 Y268.00 Z7.15 : >>> Probe::probe_down_to_z 2020-05-04 14:40:14,354 - RECV: >>> do_blocking_move_to X171.33 Y268.00 Z1.05 2020-05-04 14:40:14,358 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:14,753 - RECV: current_position= X171.33 Y268.00 Z3.08 : sync_plan_position 2020-05-04 14:40:14,762 - RECV: current_position= X171.33 Y268.00 Z3.08 : <<< Probe::probe_down_to_z 2020-05-04 14:40:14,766 - RECV: 1st Probe Z:3.08 2020-05-04 14:40:14,775 - RECV: >>> do_blocking_move_to X171.33 Y268.00 Z8.08 2020-05-04 14:40:14,779 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:15,305 - RECV: current_position= X171.33 Y268.00 Z8.08 : >>> Probe::probe_down_to_z 2020-05-04 14:40:15,309 - RECV: >>> do_blocking_move_to X171.33 Y268.00 Z1.05 2020-05-04 14:40:15,312 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:15,961 - RECV: current_position= X171.33 Y268.00 Z3.08 : sync_plan_position 2020-05-04 14:40:15,970 - RECV: current_position= X171.33 Y268.00 Z3.08 : <<< Probe::probe_down_to_z 2020-05-04 14:40:15,973 - RECV: 2nd Probe Z:3.08 Discrepancy:0.00 2020-05-04 14:40:15,983 - RECV: current_position= X171.33 Y268.00 Z3.08 : <<< run_z_probe 2020-05-04 14:40:15,990 - RECV: >>> do_blocking_move_to X171.33 Y268.00 Z7.07 2020-05-04 14:40:15,993 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:16,176 - RECV: echo:busy: processing 2020-05-04 14:40:16,463 - RECV: <<< Probe::probe_at_point 2020-05-04 14:40:16,467 - RECV: >>> Probe::probe_at_point(156.50, 235.00, raise, 0, probe_relative) 2020-05-04 14:40:16,471 - RECV: current_position= X171.33 Y268.00 Z7.07 : 2020-05-04 14:40:16,476 - RECV: >>> do_blocking_move_to X128.50 Y268.00 Z7.07 2020-05-04 14:40:16,476 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:16,963 - RECV: current_position= X128.50 Y268.00 Z7.07 : Probe::set_deployed 2020-05-04 14:40:16,964 - RECV: deploy: 1 2020-05-04 14:40:16,969 - RECV: current_position= X128.50 Y268.00 Z7.07 : >>> Probe::run_z_probe 2020-05-04 14:40:16,971 - RECV: current_position= X128.50 Y268.00 Z7.07 : >>> Probe::probe_down_to_z 2020-05-04 14:40:16,976 - RECV: >>> do_blocking_move_to X128.50 Y268.00 Z1.05 2020-05-04 14:40:16,976 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:17,390 - RECV: current_position= X128.50 Y268.00 Z3.06 : sync_plan_position 2020-05-04 14:40:17,400 - RECV: current_position= X128.50 Y268.00 Z3.06 : <<< Probe::probe_down_to_z 2020-05-04 14:40:17,404 - RECV: 1st Probe Z:3.06 2020-05-04 14:40:17,410 - RECV: >>> do_blocking_move_to X128.50 Y268.00 Z8.06 2020-05-04 14:40:17,413 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:17,944 - RECV: current_position= X128.50 Y268.00 Z8.06 : >>> Probe::probe_down_to_z 2020-05-04 14:40:17,950 - RECV: >>> do_blocking_move_to X128.50 Y268.00 Z1.05 2020-05-04 14:40:17,954 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:18,167 - RECV: echo:busy: processing 2020-05-04 14:40:18,605 - RECV: current_position= X128.50 Y268.00 Z3.06 : sync_plan_position 2020-05-04 14:40:18,709 - RECV: current_position= X128.50 Y268.00 Z3.06 : <<< Probe::probe_down_to_z 2020-05-04 14:40:18,765 - RECV: 2nd Probe Z:3.06 Discrepancy:-0.00 2020-05-04 14:40:18,828 - RECV: current_position= X128.50 Y268.00 Z3.06 : <<< run_z_probe 2020-05-04 14:40:18,835 - RECV: >>> do_blocking_move_to X128.50 Y268.00 Z7.06 2020-05-04 14:40:18,839 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:19,099 - RECV: <<< Probe::probe_at_point 2020-05-04 14:40:19,105 - RECV: >>> Probe::probe_at_point(113.67, 235.00, raise, 0, probe_relative) 2020-05-04 14:40:19,109 - RECV: current_position= X128.50 Y268.00 Z7.06 : 2020-05-04 14:40:19,115 - RECV: >>> do_blocking_move_to X85.67 Y268.00 Z7.06 2020-05-04 14:40:19,118 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:19,653 - RECV: current_position= X85.67 Y268.00 Z7.06 : Probe::set_deployed 2020-05-04 14:40:19,660 - RECV: deploy: 1 2020-05-04 14:40:19,697 - RECV: current_position= X85.67 Y268.00 Z7.06 : >>> Probe::run_z_probe 2020-05-04 14:40:19,739 - RECV: current_position= X85.67 Y268.00 Z7.06 : >>> Probe::probe_down_to_z 2020-05-04 14:40:19,753 - RECV: >>> do_blocking_move_to X85.67 Y268.00 Z1.05 2020-05-04 14:40:19,753 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:20,015 - RECV: current_position= X85.67 Y268.00 Z3.09 : sync_plan_position 2020-05-04 14:40:20,019 - RECV: current_position= X85.67 Y268.00 Z3.09 : <<< Probe::probe_down_to_z 2020-05-04 14:40:20,019 - RECV: 1st Probe Z:3.09 2020-05-04 14:40:20,022 - RECV: >>> do_blocking_move_to X85.67 Y268.00 Z8.09 2020-05-04 14:40:20,023 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:20,174 - RECV: echo:busy: processing 2020-05-04 14:40:20,572 - RECV: current_position= X85.67 Y268.00 Z8.09 : >>> Probe::probe_down_to_z 2020-05-04 14:40:20,575 - RECV: >>> do_blocking_move_to X85.67 Y268.00 Z1.05 2020-05-04 14:40:20,578 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:21,227 - RECV: current_position= X85.67 Y268.00 Z3.10 : sync_plan_position 2020-05-04 14:40:21,234 - RECV: current_position= X85.67 Y268.00 Z3.10 : <<< Probe::probe_down_to_z 2020-05-04 14:40:21,239 - RECV: 2nd Probe Z:3.10 Discrepancy:-0.00 2020-05-04 14:40:21,243 - RECV: current_position= X85.67 Y268.00 Z3.10 : <<< run_z_probe 2020-05-04 14:40:21,255 - RECV: >>> do_blocking_move_to X85.67 Y268.00 Z7.10 2020-05-04 14:40:21,257 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:21,723 - RECV: <<< Probe::probe_at_point 2020-05-04 14:40:21,733 - RECV: >>> Probe::probe_at_point(70.83, 235.00, raise, 0, probe_relative) 2020-05-04 14:40:21,733 - RECV: current_position= X85.67 Y268.00 Z7.10 : 2020-05-04 14:40:21,743 - RECV: >>> do_blocking_move_to X42.83 Y268.00 Z7.10 2020-05-04 14:40:21,743 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:22,079 - SENT: M105 2020-05-04 14:40:22,176 - RECV: echo:busy: processing 2020-05-04 14:40:22,234 - RECV: current_position= X42.83 Y268.00 Z7.10 : Probe::set_deployed 2020-05-04 14:40:22,239 - RECV: deploy: 1 2020-05-04 14:40:22,246 - RECV: current_position= X42.83 Y268.00 Z7.10 : >>> Probe::run_z_probe 2020-05-04 14:40:22,259 - RECV: current_position= X42.83 Y268.00 Z7.10 : >>> Probe::probe_down_to_z 2020-05-04 14:40:22,266 - RECV: >>> do_blocking_move_to X42.83 Y268.00 Z1.05 2020-05-04 14:40:22,270 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:22,645 - RECV: current_position= X42.83 Y268.00 Z3.04 : sync_plan_position 2020-05-04 14:40:22,657 - RECV: current_position= X42.83 Y268.00 Z3.04 : <<< Probe::probe_down_to_z 2020-05-04 14:40:22,661 - RECV: 1st Probe Z:3.04 2020-05-04 14:40:22,661 - RECV: >>> do_blocking_move_to X42.83 Y268.00 Z8.05 2020-05-04 14:40:22,661 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:23,203 - RECV: current_position= X42.83 Y268.00 Z8.05 : >>> Probe::probe_down_to_z 2020-05-04 14:40:23,206 - RECV: >>> do_blocking_move_to X42.83 Y268.00 Z1.05 2020-05-04 14:40:23,207 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:23,859 - RECV: current_position= X42.83 Y268.00 Z3.05 : sync_plan_position 2020-05-04 14:40:23,872 - RECV: current_position= X42.83 Y268.00 Z3.05 : <<< Probe::probe_down_to_z 2020-05-04 14:40:23,875 - RECV: 2nd Probe Z:3.05 Discrepancy:-0.01 2020-05-04 14:40:23,875 - RECV: current_position= X42.83 Y268.00 Z3.05 : <<< run_z_probe 2020-05-04 14:40:23,885 - RECV: >>> do_blocking_move_to X42.83 Y268.00 Z7.05 2020-05-04 14:40:23,885 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:24,174 - RECV: echo:busy: processing 2020-05-04 14:40:24,358 - RECV: <<< Probe::probe_at_point 2020-05-04 14:40:24,371 - RECV: >>> Probe::probe_at_point(28.00, 235.00, raise, 0, probe_relative) 2020-05-04 14:40:24,375 - RECV: current_position= X42.83 Y268.00 Z7.05 : 2020-05-04 14:40:24,375 - RECV: >>> do_blocking_move_to X0.00 Y268.00 Z7.05 2020-05-04 14:40:24,384 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:24,864 - RECV: current_position= X0.00 Y268.00 Z7.05 : Probe::set_deployed 2020-05-04 14:40:24,864 - RECV: deploy: 1 2020-05-04 14:40:24,878 - RECV: current_position= X0.00 Y268.00 Z7.05 : >>> Probe::run_z_probe 2020-05-04 14:40:24,878 - RECV: current_position= X0.00 Y268.00 Z7.05 : >>> Probe::probe_down_to_z 2020-05-04 14:40:24,888 - RECV: >>> do_blocking_move_to X0.00 Y268.00 Z1.05 2020-05-04 14:40:24,888 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:25,282 - RECV: current_position= X0.00 Y268.00 Z3.10 : sync_plan_position 2020-05-04 14:40:25,282 - RECV: current_position= X0.00 Y268.00 Z3.10 : <<< Probe::probe_down_to_z 2020-05-04 14:40:25,292 - RECV: 1st Probe Z:3.10 2020-05-04 14:40:25,292 - RECV: >>> do_blocking_move_to X0.00 Y268.00 Z8.10 2020-05-04 14:40:25,292 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:25,828 - RECV: current_position= X0.00 Y268.00 Z8.10 : >>> Probe::probe_down_to_z 2020-05-04 14:40:25,838 - RECV: >>> do_blocking_move_to X0.00 Y268.00 Z1.05 2020-05-04 14:40:25,842 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:26,170 - RECV: echo:busy: processing 2020-05-04 14:40:26,493 - RECV: current_position= X0.00 Y268.00 Z3.10 : sync_plan_position 2020-05-04 14:40:26,502 - RECV: current_position= X0.00 Y268.00 Z3.10 : <<< Probe::probe_down_to_z 2020-05-04 14:40:26,505 - RECV: 2nd Probe Z:3.10 Discrepancy:0.00 2020-05-04 14:40:26,509 - RECV: current_position= X0.00 Y268.00 Z3.10 : <<< run_z_probe 2020-05-04 14:40:26,513 - RECV: >>> do_blocking_move_to X0.00 Y268.00 Z7.10 2020-05-04 14:40:26,513 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:26,989 - RECV: <<< Probe::probe_at_point 2020-05-04 14:40:27,003 - RECV: >>> Probe::probe_at_point(28.00, 277.00, raise, 0, probe_relative) 2020-05-04 14:40:27,009 - RECV: current_position= X0.00 Y268.00 Z7.10 : 2020-05-04 14:40:27,016 - RECV: >>> do_blocking_move_to X0.00 Y310.00 Z7.10 2020-05-04 14:40:27,019 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:27,483 - RECV: current_position= X0.00 Y310.00 Z7.10 : Probe::set_deployed 2020-05-04 14:40:27,493 - RECV: deploy: 1 2020-05-04 14:40:27,493 - RECV: current_position= X0.00 Y310.00 Z7.10 : >>> Probe::run_z_probe 2020-05-04 14:40:27,507 - RECV: current_position= X0.00 Y310.00 Z7.10 : >>> Probe::probe_down_to_z 2020-05-04 14:40:27,507 - RECV: >>> do_blocking_move_to X0.00 Y310.00 Z1.05 2020-05-04 14:40:27,507 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:27,901 - RECV: current_position= X0.00 Y310.00 Z3.12 : sync_plan_position 2020-05-04 14:40:27,911 - RECV: current_position= X0.00 Y310.00 Z3.12 : <<< Probe::probe_down_to_z 2020-05-04 14:40:27,911 - RECV: 1st Probe Z:3.12 2020-05-04 14:40:27,921 - RECV: >>> do_blocking_move_to X0.00 Y310.00 Z8.12 2020-05-04 14:40:27,921 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:28,171 - RECV: echo:busy: processing 2020-05-04 14:40:28,453 - RECV: current_position= X0.00 Y310.00 Z8.12 : >>> Probe::probe_down_to_z 2020-05-04 14:40:28,463 - RECV: >>> do_blocking_move_to X0.00 Y310.00 Z1.05 2020-05-04 14:40:28,463 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:29,115 - RECV: current_position= X0.00 Y310.00 Z3.12 : sync_plan_position 2020-05-04 14:40:29,118 - RECV: current_position= X0.00 Y310.00 Z3.12 : <<< Probe::probe_down_to_z 2020-05-04 14:40:29,121 - RECV: 2nd Probe Z:3.12 Discrepancy:0.00 2020-05-04 14:40:29,125 - RECV: current_position= X0.00 Y310.00 Z3.12 : <<< run_z_probe 2020-05-04 14:40:29,130 - RECV: >>> do_blocking_move_to X0.00 Y310.00 Z7.12 2020-05-04 14:40:29,131 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:29,654 - RECV: <<< Probe::probe_at_point 2020-05-04 14:40:29,750 - RECV: >>> Probe::probe_at_point(70.83, 277.00, raise, 0, probe_relative) 2020-05-04 14:40:29,788 - RECV: current_position= X0.00 Y310.00 Z7.12 : 2020-05-04 14:40:29,790 - RECV: >>> do_blocking_move_to X42.83 Y310.00 Z7.12 2020-05-04 14:40:29,792 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:30,118 - RECV: current_position= X42.83 Y310.00 Z7.12 : Probe::set_deployed 2020-05-04 14:40:30,118 - RECV: deploy: 1 2020-05-04 14:40:30,128 - RECV: current_position= X42.83 Y310.00 Z7.12 : >>> Probe::run_z_probe 2020-05-04 14:40:30,138 - RECV: current_position= X42.83 Y310.00 Z7.12 : >>> Probe::probe_down_to_z 2020-05-04 14:40:30,144 - RECV: >>> do_blocking_move_to X42.83 Y310.00 Z1.05 2020-05-04 14:40:30,144 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:30,174 - RECV: echo:busy: processing 2020-05-04 14:40:30,536 - RECV: current_position= X42.83 Y310.00 Z3.06 : sync_plan_position 2020-05-04 14:40:30,546 - RECV: current_position= X42.83 Y310.00 Z3.06 : <<< Probe::probe_down_to_z 2020-05-04 14:40:30,546 - RECV: 1st Probe Z:3.06 2020-05-04 14:40:30,546 - RECV: >>> do_blocking_move_to X42.83 Y310.00 Z8.06 2020-05-04 14:40:30,556 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:31,088 - RECV: current_position= X42.83 Y310.00 Z8.06 : >>> Probe::probe_down_to_z 2020-05-04 14:40:31,098 - RECV: >>> do_blocking_move_to X42.83 Y310.00 Z1.05 2020-05-04 14:40:31,098 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:31,749 - RECV: current_position= X42.83 Y310.00 Z3.05 : sync_plan_position 2020-05-04 14:40:31,759 - RECV: current_position= X42.83 Y310.00 Z3.05 : <<< Probe::probe_down_to_z 2020-05-04 14:40:31,759 - RECV: 2nd Probe Z:3.05 Discrepancy:0.00 2020-05-04 14:40:31,775 - RECV: current_position= X42.83 Y310.00 Z3.05 : <<< run_z_probe 2020-05-04 14:40:31,775 - RECV: >>> do_blocking_move_to X42.83 Y310.00 Z7.05 2020-05-04 14:40:31,775 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:32,171 - RECV: echo:busy: processing 2020-05-04 14:40:32,253 - RECV: <<< Probe::probe_at_point 2020-05-04 14:40:32,253 - RECV: >>> Probe::probe_at_point(113.67, 277.00, raise, 0, probe_relative) 2020-05-04 14:40:32,267 - RECV: current_position= X42.83 Y310.00 Z7.05 : 2020-05-04 14:40:32,269 - RECV: >>> do_blocking_move_to X85.67 Y310.00 Z7.05 2020-05-04 14:40:32,269 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:32,762 - RECV: current_position= X85.67 Y310.00 Z7.05 : Probe::set_deployed 2020-05-04 14:40:32,766 - RECV: deploy: 1 2020-05-04 14:40:32,776 - RECV: current_position= X85.67 Y310.00 Z7.05 : >>> Probe::run_z_probe 2020-05-04 14:40:32,782 - RECV: current_position= X85.67 Y310.00 Z7.05 : >>> Probe::probe_down_to_z 2020-05-04 14:40:32,789 - RECV: >>> do_blocking_move_to X85.67 Y310.00 Z1.05 2020-05-04 14:40:32,792 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:33,168 - RECV: current_position= X85.67 Y310.00 Z3.10 : sync_plan_position 2020-05-04 14:40:33,178 - RECV: current_position= X85.67 Y310.00 Z3.10 : <<< Probe::probe_down_to_z 2020-05-04 14:40:33,178 - RECV: 1st Probe Z:3.10 2020-05-04 14:40:33,178 - RECV: >>> do_blocking_move_to X85.67 Y310.00 Z8.10 2020-05-04 14:40:33,188 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:33,730 - RECV: current_position= X85.67 Y310.00 Z8.10 : >>> Probe::probe_down_to_z 2020-05-04 14:40:33,736 - RECV: >>> do_blocking_move_to X85.67 Y310.00 Z1.05 2020-05-04 14:40:33,740 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:34,174 - RECV: echo:busy: processing 2020-05-04 14:40:34,375 - RECV: current_position= X85.67 Y310.00 Z3.10 : sync_plan_position 2020-05-04 14:40:34,398 - RECV: current_position= X85.67 Y310.00 Z3.10 : <<< Probe::probe_down_to_z 2020-05-04 14:40:34,401 - RECV: 2nd Probe Z:3.10 Discrepancy:0.00 2020-05-04 14:40:34,411 - RECV: current_position= X85.67 Y310.00 Z3.10 : <<< run_z_probe 2020-05-04 14:40:34,411 - RECV: >>> do_blocking_move_to X85.67 Y310.00 Z7.10 2020-05-04 14:40:34,421 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:34,887 - RECV: <<< Probe::probe_at_point 2020-05-04 14:40:34,903 - RECV: >>> Probe::probe_at_point(156.50, 277.00, raise, 0, probe_relative) 2020-05-04 14:40:34,913 - RECV: current_position= X85.67 Y310.00 Z7.10 : 2020-05-04 14:40:34,913 - RECV: >>> do_blocking_move_to X128.50 Y310.00 Z7.10 2020-05-04 14:40:34,923 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:35,388 - RECV: current_position= X128.50 Y310.00 Z7.10 : Probe::set_deployed 2020-05-04 14:40:35,388 - RECV: deploy: 1 2020-05-04 14:40:35,388 - RECV: current_position= X128.50 Y310.00 Z7.10 : >>> Probe::run_z_probe 2020-05-04 14:40:35,404 - RECV: current_position= X128.50 Y310.00 Z7.10 : >>> Probe::probe_down_to_z 2020-05-04 14:40:35,414 - RECV: >>> do_blocking_move_to X128.50 Y310.00 Z1.05 2020-05-04 14:40:35,420 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:35,802 - RECV: current_position= X128.50 Y310.00 Z3.07 : sync_plan_position 2020-05-04 14:40:35,812 - RECV: current_position= X128.50 Y310.00 Z3.07 : <<< Probe::probe_down_to_z 2020-05-04 14:40:35,812 - RECV: 1st Probe Z:3.07 2020-05-04 14:40:35,822 - RECV: >>> do_blocking_move_to X128.50 Y310.00 Z8.07 2020-05-04 14:40:35,822 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:36,174 - RECV: echo:busy: processing 2020-05-04 14:40:36,351 - RECV: current_position= X128.50 Y310.00 Z8.07 : >>> Probe::probe_down_to_z 2020-05-04 14:40:36,361 - RECV: >>> do_blocking_move_to X128.50 Y310.00 Z1.05 2020-05-04 14:40:36,361 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:37,009 - RECV: current_position= X128.50 Y310.00 Z3.07 : sync_plan_position 2020-05-04 14:40:37,019 - RECV: current_position= X128.50 Y310.00 Z3.07 : <<< Probe::probe_down_to_z 2020-05-04 14:40:37,019 - RECV: 2nd Probe Z:3.07 Discrepancy:0.00 2020-05-04 14:40:37,019 - RECV: current_position= X128.50 Y310.00 Z3.07 : <<< run_z_probe 2020-05-04 14:40:37,019 - RECV: >>> do_blocking_move_to X128.50 Y310.00 Z7.07 2020-05-04 14:40:37,029 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:37,453 - SENT: M105 2020-05-04 14:40:37,520 - RECV: <<< Probe::probe_at_point 2020-05-04 14:40:37,520 - RECV: >>> Probe::probe_at_point(199.33, 277.00, raise, 0, probe_relative) 2020-05-04 14:40:37,536 - RECV: current_position= X128.50 Y310.00 Z7.07 : 2020-05-04 14:40:37,536 - RECV: >>> do_blocking_move_to X171.33 Y310.00 Z7.07 2020-05-04 14:40:37,546 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:38,019 - RECV: current_position= X171.33 Y310.00 Z7.07 : Probe::set_deployed 2020-05-04 14:40:38,019 - RECV: deploy: 1 2020-05-04 14:40:38,029 - RECV: current_position= X171.33 Y310.00 Z7.07 : >>> Probe::run_z_probe 2020-05-04 14:40:38,029 - RECV: current_position= X171.33 Y310.00 Z7.07 : >>> Probe::probe_down_to_z 2020-05-04 14:40:38,039 - RECV: >>> do_blocking_move_to X171.33 Y310.00 Z1.05 2020-05-04 14:40:38,039 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:38,174 - RECV: echo:busy: processing 2020-05-04 14:40:38,441 - RECV: current_position= X171.33 Y310.00 Z3.08 : sync_plan_position 2020-05-04 14:40:38,448 - RECV: current_position= X171.33 Y310.00 Z3.08 : <<< Probe::probe_down_to_z 2020-05-04 14:40:38,451 - RECV: 1st Probe Z:3.08 2020-05-04 14:40:38,457 - RECV: >>> do_blocking_move_to X171.33 Y310.00 Z8.08 2020-05-04 14:40:38,463 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:38,994 - RECV: current_position= X171.33 Y310.00 Z8.08 : >>> Probe::probe_down_to_z 2020-05-04 14:40:38,994 - RECV: >>> do_blocking_move_to X171.33 Y310.00 Z1.05 2020-05-04 14:40:38,994 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:39,651 - RECV: current_position= X171.33 Y310.00 Z3.09 : sync_plan_position 2020-05-04 14:40:39,658 - RECV: current_position= X171.33 Y310.00 Z3.09 : <<< Probe::probe_down_to_z 2020-05-04 14:40:39,658 - RECV: 2nd Probe Z:3.09 Discrepancy:-0.01 2020-05-04 14:40:39,658 - RECV: current_position= X171.33 Y310.00 Z3.09 : <<< run_z_probe 2020-05-04 14:40:39,668 - RECV: >>> do_blocking_move_to X171.33 Y310.00 Z7.09 2020-05-04 14:40:39,668 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:40,154 - RECV: <<< Probe::probe_at_point 2020-05-04 14:40:40,160 - RECV: >>> Probe::probe_at_point(242.17, 277.00, raise, 0, probe_relative) 2020-05-04 14:40:40,160 - RECV: current_position= X171.33 Y310.00 Z7.09 : 2020-05-04 14:40:40,160 - RECV: >>> do_blocking_move_to X214.17 Y310.00 Z7.09 2020-05-04 14:40:40,170 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:40,170 - RECV: echo:busy: processing 2020-05-04 14:40:40,648 - RECV: current_position= X214.17 Y310.00 Z7.09 : Probe::set_deployed 2020-05-04 14:40:40,657 - RECV: deploy: 1 2020-05-04 14:40:40,657 - RECV: current_position= X214.17 Y310.00 Z7.09 : >>> Probe::run_z_probe 2020-05-04 14:40:40,667 - RECV: current_position= X214.17 Y310.00 Z7.09 : >>> Probe::probe_down_to_z 2020-05-04 14:40:40,677 - RECV: >>> do_blocking_move_to X214.17 Y310.00 Z1.05 2020-05-04 14:40:40,680 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:41,072 - RECV: current_position= X214.17 Y310.00 Z3.14 : sync_plan_position 2020-05-04 14:40:41,082 - RECV: current_position= X214.17 Y310.00 Z3.14 : <<< Probe::probe_down_to_z 2020-05-04 14:40:41,084 - RECV: 1st Probe Z:3.14 2020-05-04 14:40:41,088 - RECV: >>> do_blocking_move_to X214.17 Y310.00 Z8.14 2020-05-04 14:40:41,094 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:41,726 - RECV: current_position= X214.17 Y310.00 Z8.14 : >>> Probe::probe_down_to_z 2020-05-04 14:40:41,801 - RECV: >>> do_blocking_move_to X214.17 Y310.00 Z1.05 2020-05-04 14:40:41,841 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:42,171 - RECV: echo:busy: processing 2020-05-04 14:40:42,282 - RECV: current_position= X214.17 Y310.00 Z3.14 : sync_plan_position 2020-05-04 14:40:42,290 - RECV: current_position= X214.17 Y310.00 Z3.14 : <<< Probe::probe_down_to_z 2020-05-04 14:40:42,295 - RECV: 2nd Probe Z:3.14 Discrepancy:0.00 2020-05-04 14:40:42,302 - RECV: current_position= X214.17 Y310.00 Z3.14 : <<< run_z_probe 2020-05-04 14:40:42,306 - RECV: >>> do_blocking_move_to X214.17 Y310.00 Z7.14 2020-05-04 14:40:42,308 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:42,780 - RECV: <<< Probe::probe_at_point 2020-05-04 14:40:42,790 - RECV: >>> Probe::probe_at_point(285.00, 277.00, raise, 0, probe_relative) 2020-05-04 14:40:42,796 - RECV: current_position= X214.17 Y310.00 Z7.14 : 2020-05-04 14:40:42,796 - RECV: >>> do_blocking_move_to X257.00 Y310.00 Z7.14 2020-05-04 14:40:42,805 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:43,289 - RECV: current_position= X257.00 Y310.00 Z7.14 : Probe::set_deployed 2020-05-04 14:40:43,290 - RECV: deploy: 1 2020-05-04 14:40:43,298 - RECV: current_position= X257.00 Y310.00 Z7.14 : >>> Probe::run_z_probe 2020-05-04 14:40:43,303 - RECV: current_position= X257.00 Y310.00 Z7.14 : >>> Probe::probe_down_to_z 2020-05-04 14:40:43,308 - RECV: >>> do_blocking_move_to X257.00 Y310.00 Z1.05 2020-05-04 14:40:43,308 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:43,700 - RECV: current_position= X257.00 Y310.00 Z3.10 : sync_plan_position 2020-05-04 14:40:43,710 - RECV: current_position= X257.00 Y310.00 Z3.10 : <<< Probe::probe_down_to_z 2020-05-04 14:40:43,710 - RECV: 1st Probe Z:3.10 2020-05-04 14:40:43,720 - RECV: >>> do_blocking_move_to X257.00 Y310.00 Z8.10 2020-05-04 14:40:43,720 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:44,173 - RECV: echo:busy: processing 2020-05-04 14:40:44,265 - RECV: current_position= X257.00 Y310.00 Z8.10 : >>> Probe::probe_down_to_z 2020-05-04 14:40:44,270 - RECV: >>> do_blocking_move_to X257.00 Y310.00 Z1.05 2020-05-04 14:40:44,275 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:44,911 - RECV: current_position= X257.00 Y310.00 Z3.11 : sync_plan_position 2020-05-04 14:40:44,920 - RECV: current_position= X257.00 Y310.00 Z3.11 : <<< Probe::probe_down_to_z 2020-05-04 14:40:44,930 - RECV: 2nd Probe Z:3.11 Discrepancy:-0.00 2020-05-04 14:40:44,936 - RECV: current_position= X257.00 Y310.00 Z3.11 : <<< run_z_probe 2020-05-04 14:40:44,936 - RECV: >>> do_blocking_move_to X257.00 Y310.00 Z7.11 2020-05-04 14:40:44,946 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:45,427 - RECV: <<< Probe::probe_at_point 2020-05-04 14:40:45,434 - RECV: current_position= X257.00 Y310.00 Z7.11 : Probe::set_deployed 2020-05-04 14:40:45,434 - RECV: deploy: 0 2020-05-04 14:40:45,437 - RECV: Probe::move_z(5.00) 2020-05-04 14:40:45,447 - RECV: >>> do_blocking_move_to X257.00 Y310.00 Z8.05 2020-05-04 14:40:45,450 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:45,714 - RECV: BLTouch STOW requested 2020-05-04 14:40:45,717 - RECV: BLTouch Command :90 2020-05-04 14:40:46,509 - RECV: bltouch.stow_proc() end 2020-05-04 14:40:46,519 - RECV: >>> do_blocking_move_to X257.00 Y310.00 Z8.05 2020-05-04 14:40:46,519 - RECV: <<< do_blocking_move_to 2020-05-04 14:40:46,535 - RECV: current_position= X257.00 Y310.00 Z8.05 : > probing complete 2020-05-04 14:40:46,535 - RECV: Bilinear Leveling Grid: 2020-05-04 14:40:46,535 - RECV: 0 1 2 3 4 5 6 2020-05-04 14:40:46,545 - RECV: 0 -0.057 -0.128 -0.053 -0.046 -0.010 +0.106 +0.081 2020-05-04 14:40:46,555 - RECV: 1 -0.062 -0.118 -0.050 -0.048 -0.009 +0.105 +0.078 2020-05-04 14:40:46,555 - RECV: 2 -0.031 -0.093 -0.014 -0.018 +0.021 +0.126 +0.091 2020-05-04 14:40:46,571 - RECV: 3 -0.027 -0.067 +0.001 +0.003 +0.035 +0.137 +0.122 2020-05-04 14:40:46,571 - RECV: 4 +0.013 -0.046 +0.018 +0.012 +0.036 +0.136 +0.106 2020-05-04 14:40:46,581 - RECV: 5 +0.050 -0.002 +0.044 +0.014 +0.026 +0.105 +0.059 2020-05-04 14:40:46,581 - RECV: 6 +0.069 +0.005 +0.050 +0.021 +0.035 +0.093 +0.056 2020-05-04 14:40:46,594 - RECV: G29 uncorrected Z:8.05 2020-05-04 14:40:46,595 - RECV: corrected Z:7.97 2020-05-04 14:40:46,595 - RECV: current_position= X257.00 Y310.00 Z7.97 : sync_plan_position 2020-05-04 14:40:46,595 - RECV: >>> do_blocking_move_to X257.00 Y310.00 Z15.00 2020-05-04 14:40:46,605 - RECV: <<< do_blocking_move_to ```
thierryzoller commented 4 years ago
Log Output ``` 2020-05-04 14:52:23,920 - RECV: echo:M420 V 2020-05-04 14:52:23,920 - RECV: Bilinear Leveling Grid: 2020-05-04 14:52:23,934 - RECV: 0 1 2 3 4 5 6 2020-05-04 14:52:23,934 - RECV: 0 -0.066 -0.126 -0.048 -0.045 -0.008 +0.108 +0.073 2020-05-04 14:52:23,944 - RECV: 1 -0.045 -0.116 -0.035 -0.039 -0.001 +0.113 +0.082 2020-05-04 14:52:23,944 - RECV: 2 -0.024 -0.097 -0.017 -0.018 +0.029 +0.122 +0.090 2020-05-04 14:52:23,954 - RECV: 3 -0.030 -0.075 +0.001 +0.003 +0.043 +0.138 +0.126 2020-05-04 14:52:23,954 - RECV: 4 +0.011 -0.048 +0.024 +0.013 +0.038 +0.137 +0.106 2020-05-04 14:52:23,967 - RECV: 5 +0.057 -0.003 +0.046 +0.022 +0.027 +0.107 +0.060 2020-05-04 14:52:23,970 - RECV: 6 +0.069 -0.005 +0.046 +0.022 +0.024 +0.086 +0.042 2020-05-04 14:52:23,970 - RECV: echo:Bed Leveling OFF 2020-05-04 14:52:23,980 - RECV: echo:Fade Height OFF 2020-05-04 14:52:23,980 - RECV: ok 2020-05-04 14:52:24,051 - RECV: echo:M105 2020-05-04 14:52:24,063 - RECV: ok T:20.86 /0.00 B:20.62 /0.00 @:0 B@:0 2020-05-04 14:52:27,052 - RECV: echo:M105 2020-05-04 14:52:27,052 - RECV: ok T:20.70 /0.00 B:20.62 /0.00 @:0 B@:0 2020-05-04 14:52:30,052 - RECV: echo:M105 2020-05-04 14:52:30,055 - RECV: ok T:20.86 /0.00 B:20.74 /0.00 @:0 B@:0 2020-05-04 14:52:31,592 - SENT: M500 2020-05-04 14:52:31,592 - RECV: echo:M500 2020-05-04 14:52:31,628 - RECV: echo:Settings Stored (826 bytes; crc 22621) 2020-05-04 14:52:31,628 - RECV: ok 2020-05-04 14:52:33,066 - RECV: echo:M105 2020-05-04 14:52:33,086 - RECV: ok T:20.78 /0.00 B:20.66 /0.00 @:0 B@:0 2020-05-04 14:52:34,532 - SENT: M501 2020-05-04 14:52:34,536 - RECV: echo:M501 2020-05-04 14:52:34,561 - RECV: echo:V78 stored settings retrieved (826 bytes; crc 22621) 2020-05-04 14:52:34,565 - RECV: Axis 88 home_offset = 0.00 position_shift = 0.00 2020-05-04 14:52:34,565 - RECV: Axis 88 min:0.00 max:310.00 2020-05-04 14:52:34,565 - RECV: Axis 89 home_offset = 0.00 position_shift = 0.00 2020-05-04 14:52:34,575 - RECV: Axis 89 min:0.00 max:310.00 2020-05-04 14:52:34,575 - RECV: Axis 90 home_offset = 0.00 position_shift = 0.00 2020-05-04 14:52:34,585 - RECV: Axis 90 min:0.00 max:380.00 2020-05-04 14:52:34,585 - RECV: echo: G21 ; Units in mm (mm) 2020-05-04 14:52:34,595 - RECV: echo:; Filament settings: Disabled 2020-05-04 14:52:34,599 - RECV: echo: M200 D1.75 2020-05-04 14:52:34,601 - RECV: echo: M200 D0 2020-05-04 14:52:34,601 - RECV: echo:; Steps per unit: 2020-05-04 14:52:34,601 - RECV: echo: M92 X80.00 Y80.00 Z400.00 E444.00 2020-05-04 14:52:34,611 - RECV: echo:; Maximum feedrates (units/s): 2020-05-04 14:52:34,611 - RECV: echo: M203 X300.00 Y300.00 Z50.00 E40.00 2020-05-04 14:52:34,621 - RECV: echo:; Maximum Acceleration (units/s2): 2020-05-04 14:52:34,621 - RECV: echo: M201 X2000.00 Y2000.00 Z100.00 E5000.00 2020-05-04 14:52:34,621 - RECV: echo:; Acceleration (units/s2): P R T 2020-05-04 14:52:34,634 - RECV: echo: M204 P800.00 R10000.00 T2000.00 2020-05-04 14:52:34,635 - RECV: echo:; Advanced: B S T J 2020-05-04 14:52:34,641 - RECV: echo: M205 B20000.00 S0.00 T0.00 J0.01 2020-05-04 14:52:34,641 - RECV: echo:; Home offset: 2020-05-04 14:52:34,641 - RECV: echo: M206 X0.00 Y0.00 Z0.00 2020-05-04 14:52:34,641 - RECV: echo:; Auto Bed Leveling: 2020-05-04 14:52:34,641 - RECV: echo: M420 S0 Z0.00 2020-05-04 14:52:34,641 - RECV: echo: G29 W I0 J0 Z-0.06650 2020-05-04 14:52:34,641 - RECV: echo: G29 W I1 J0 Z-0.12650 2020-05-04 14:52:34,651 - RECV: echo: G29 W I2 J0 Z-0.04850 2020-05-04 14:52:34,651 - RECV: echo: G29 W I3 J0 Z-0.04500 2020-05-04 14:52:34,651 - RECV: echo: G29 W I4 J0 Z-0.00800 2020-05-04 14:52:34,651 - RECV: echo: G29 W I5 J0 Z0.10800 2020-05-04 14:52:34,651 - RECV: echo: G29 W I6 J0 Z0.07300 2020-05-04 14:52:34,651 - RECV: echo: G29 W I0 J1 Z-0.04500 2020-05-04 14:52:34,661 - RECV: echo: G29 W I1 J1 Z-0.11650 2020-05-04 14:52:34,663 - RECV: echo: G29 W I2 J1 Z-0.03500 2020-05-04 14:52:34,663 - RECV: echo: G29 W I3 J1 Z-0.03950 2020-05-04 14:52:34,664 - RECV: echo: G29 W I4 J1 Z-0.00100 2020-05-04 14:52:34,664 - RECV: echo: G29 W I5 J1 Z0.11250 2020-05-04 14:52:34,664 - RECV: echo: G29 W I6 J1 Z0.08200 2020-05-04 14:52:34,664 - RECV: echo: G29 W I0 J2 Z-0.02400 2020-05-04 14:52:34,664 - RECV: echo: G29 W I1 J2 Z-0.09750 2020-05-04 14:52:34,664 - RECV: echo: G29 W I2 J2 Z-0.01700 2020-05-04 14:52:34,676 - RECV: echo: G29 W I3 J2 Z-0.01850 2020-05-04 14:52:34,676 - RECV: echo: G29 W I4 J2 Z0.02900 2020-05-04 14:52:34,676 - RECV: echo: G29 W I5 J2 Z0.12200 2020-05-04 14:52:34,676 - RECV: echo: G29 W I6 J2 Z0.08950 2020-05-04 14:52:34,676 - RECV: echo: G29 W I0 J3 Z-0.03050 2020-05-04 14:52:34,686 - RECV: echo: G29 W I1 J3 Z-0.07500 2020-05-04 14:52:34,686 - RECV: echo: G29 W I2 J3 Z0.00100 2020-05-04 14:52:34,686 - RECV: echo: G29 W I3 J3 Z0.00300 2020-05-04 14:52:34,686 - RECV: echo: G29 W I4 J3 Z0.04300 2020-05-04 14:52:34,686 - RECV: echo: G29 W I5 J3 Z0.13750 2020-05-04 14:52:34,686 - RECV: echo: G29 W I6 J3 Z0.12550 2020-05-04 14:52:34,696 - RECV: echo: G29 W I0 J4 Z0.01050 2020-05-04 14:52:34,696 - RECV: echo: G29 W I1 J4 Z-0.04800 2020-05-04 14:52:34,698 - RECV: echo: G29 W I2 J4 Z0.02400 2020-05-04 14:52:34,698 - RECV: echo: G29 W I3 J4 Z0.01250 2020-05-04 14:52:34,698 - RECV: echo: G29 W I4 J4 Z0.03750 2020-05-04 14:52:34,698 - RECV: echo: G29 W I5 J4 Z0.13650 2020-05-04 14:52:34,698 - RECV: echo: G29 W I6 J4 Z0.10550 2020-05-04 14:52:34,698 - RECV: echo: G29 W I0 J5 Z0.05650 2020-05-04 14:52:34,698 - RECV: echo: G29 W I1 J5 Z-0.00300 2020-05-04 14:52:34,709 - RECV: echo: G29 W I2 J5 Z0.04600 2020-05-04 14:52:34,709 - RECV: echo: G29 W I3 J5 Z0.02150 2020-05-04 14:52:34,709 - RECV: echo: G29 W I4 J5 Z0.02700 2020-05-04 14:52:34,709 - RECV: echo: G29 W I5 J5 Z0.10700 2020-05-04 14:52:34,709 - RECV: echo: G29 W I6 J5 Z0.06000 2020-05-04 14:52:34,709 - RECV: echo: G29 W I0 J6 Z0.06850 2020-05-04 14:52:34,719 - RECV: echo: G29 W I1 J6 Z-0.00500 2020-05-04 14:52:34,719 - RECV: echo: G29 W I2 J6 Z0.04550 2020-05-04 14:52:34,719 - RECV: echo: G29 W I3 J6 Z0.02150 2020-05-04 14:52:34,719 - RECV: echo: G29 W I4 J6 Z0.02350 2020-05-04 14:52:34,719 - RECV: echo: G29 W I5 J6 Z0.08600 2020-05-04 14:52:34,719 - RECV: echo: G29 W I6 J6 Z0.04200 2020-05-04 14:52:34,719 - RECV: echo:; PID settings: 2020-05-04 14:52:34,730 - RECV: echo: M301 P12.80 I0.91 D45.09 2020-05-04 14:52:34,733 - RECV: echo: M304 P33.00 I48.00 D29.00 2020-05-04 14:52:34,733 - RECV: echo:; Z-Probe Offset (mm): 2020-05-04 14:52:34,733 - RECV: echo: M851 X28.00 Y-33.00 Z-3.05 2020-05-04 14:52:34,733 - RECV: echo:; Linear Advance: 2020-05-04 14:52:34,733 - RECV: echo: M900 K0.18 ```
thierryzoller commented 4 years ago

Issued a G29Q

2020-05-04 14:54:27,382 - SENT: G29 Q 2020-05-04 14:54:27,385 - RECV: echo:G29 Q 2020-05-04 14:54:27,388 - RECV: current_position= X257.00 Y310.00 Z15.07 : >>> G29 2020-05-04 14:54:27,388 - RECV: Machine Type: Cartesian 2020-05-04 14:54:27,398 - RECV: Probe: BLTOUCH 2020-05-04 14:54:27,398 - RECV: Probe Offset X28.00 Y-33.00 Z-3.05 (Right-Front & Below Nozzle) 2020-05-04 14:54:27,408 - RECV: Auto Bed Leveling: BILINEAR (disabled)

thierryzoller commented 4 years ago

Issued an M420 S1

2020-05-04 14:56:20,423 - RECV: echo:M420 S1 2020-05-04 14:56:20,433 - RECV: current_position= X257.00 Y310.00 Z15.07 : Leveling OFF 2020-05-04 14:56:20,443 - RECV: current_position= X257.00 Y310.00 Z15.00 : ...Now ON 2020-05-04 14:56:20,447 - RECV: current_position= X257.00 Y310.00 Z15.00 : sync_plan_position 2020-05-04 14:56:20,447 - RECV: echo:Bed Leveling ON 2020-05-04 14:56:20,447 - RECV: echo:Fade Height OFF 2020-05-04 14:56:20,457 - RECV: X:257.00 Y:310.00 Z:15.00 E:0.00 Count X:20560 Y:24800 Z:6028

thierryzoller commented 4 years ago

Issued an G26 R999

Videos here :

Picture here: scratching_dj

(Those are scratches, not filament)

thierryzoller commented 4 years ago

I dont think that is the way it is supposed to work. The only way I suceed in printing is leveling the bed manually

thierryzoller commented 4 years ago

Let me know what you need from me please.

thierryzoller commented 4 years ago

I turned off the Printer after the last post 2 days ago and haven't touched it since. Today I power it up, connect to it via Pronterface and the Z-Offset now shows

M851 X28.00 Y-33.00 Z-2.35

As you can see in the logs above it was previously during the tests:

M851 X28.00 Y-33.00 Z-3.05

I have not changed printed or done anything to the printer. Is there some sort of Savestate error and the wrong values are being used?

thierryzoller commented 4 years ago

Here is the full log from todays startup :

Log Output ``` Marlin bugfix-2.0.x echo: Last Updated: 2020-05-03 | Author: (ZOLLER, BLTouch) echo:Compiled: May 3 2020 echo: Free Memory: 4735 PlannerBufferBytes: 1312 echo:V78 stored settings retrieved (826 bytes; crc 19789) Printer is now online. >>> m503 SENDING:M503 echo: G21 ; Units in mm (mm) echo:; Filament settings: Disabled echo: M200 D1.75 echo: M200 D0 echo:; Steps per unit: echo: M92 X80.00 Y80.00 Z400.00 E444.00 echo:; Maximum feedrates (units/s): echo: M203 X300.00 Y300.00 Z50.00 E40.00 echo:; Maximum Acceleration (units/s2): echo: M201 X2000.00 Y2000.00 Z100.00 E5000.00 echo:; Acceleration (units/s2): P R T echo: M204 P800.00 R10000.00 T2000.00 echo:; Advanced: B S T J echo: M205 B20000.00 S0.00 T0.00 J0.01 echo:; Home offset: echo: M206 X0.00 Y0.00 Z0.00 echo:; Auto Bed Leveling: echo: M420 S0 Z0.00 echo: G29 W I0 J0 Z-0.06650 echo: G29 W I1 J0 Z-0.12650 echo: G29 W I2 J0 Z-0.04850 echo: G29 W I3 J0 Z-0.04500 echo: G29 W I4 J0 Z-0.00800 echo: G29 W I5 J0 Z0.10800 echo: G29 W I6 J0 Z0.07300 echo: G29 W I0 J1 Z-0.04500 echo: G29 W I1 J1 Z-0.11650 echo: G29 W I2 J1 Z-0.03500 echo: G29 W I3 J1 Z-0.03950 echo: G29 W I4 J1 Z-0.00100 echo: G29 W I5 J1 Z0.11250 echo: G29 W I6 J1 Z0.08200 echo: G29 W I0 J2 Z-0.02400 echo: G29 W I1 J2 Z-0.09750 echo: G29 W I2 J2 Z-0.01700 echo: G29 W I3 J2 Z-0.01850 echo: G29 W I4 J2 Z0.02900 echo: G29 W I5 J2 Z0.12200 echo: G29 W I6 J2 Z0.08950 echo: G29 W I0 J3 Z-0.03050 echo: G29 W I1 J3 Z-0.07500 echo: G29 W I2 J3 Z0.00100 echo: G29 W I3 J3 Z0.00300 echo: G29 W I4 J3 Z0.04300 echo: G29 W I5 J3 Z0.13750 echo: G29 W I6 J3 Z0.12550 echo: G29 W I0 J4 Z0.01050 echo: G29 W I1 J4 Z-0.04800 echo: G29 W I2 J4 Z0.02400 echo: G29 W I3 J4 Z0.01250 echo: G29 W I4 J4 Z0.03750 echo: G29 W I5 J4 Z0.13650 echo: G29 W I6 J4 Z0.10550 echo: G29 W I0 J5 Z0.05650 echo: G29 W I1 J5 Z-0.00300 echo: G29 W I2 J5 Z0.04600 echo: G29 W I3 J5 Z0.02150 echo: G29 W I4 J5 Z0.02700 echo: G29 W I5 J5 Z0.10700 echo: G29 W I6 J5 Z0.06000 echo: G29 W I0 J6 Z0.06850 echo: G29 W I1 J6 Z-0.00500 echo: G29 W I2 J6 Z0.04550 echo: G29 W I3 J6 Z0.02150 echo: G29 W I4 J6 Z0.02350 echo: G29 W I5 J6 Z0.08600 echo: G29 W I6 J6 Z0.04200 echo:; PID settings: echo: M301 P12.80 I0.91 D45.09 echo: M304 P33.00 I48.00 D29.00 echo:; Z-Probe Offset (mm): echo: M851 X28.00 Y-33.00 Z-2.35 echo:; Linear Advance: echo: M900 K0.18 Probe Offset X28.00 Y-33.00 Z-2.35 ```
thierryzoller commented 4 years ago

Gents I went through all that hassle just to get to the bottom of this, would apprecivate someone chiming in :) @thinkyhead

encodedLife commented 4 years ago

Hey, i also have the Bltouch 3.1 (on Skr 1.3) i use the following settings:

define Z_MIN_PROBE_ENDSTOP_INVERTING true define Z_PROBE_LOW_POINT -10 <- this should be higher then the Z-Probe offset

also level the corners br

Edit: i know -10 for Z_PROBE_LOW_POINT is a little bit to much but i don´t even know why this setting is there

thierryzoller commented 4 years ago

Thanks polato but we had ton of reports that Marlin is not compensating correctly since the latest releases. This post is an attempt to help properly debug this. For instance I am not goin to set "Inverting True" when this is not required for my setup. Leveling the corners is not the issue.

ziporah commented 4 years ago

I experienced issues as wel, for the sake of trying, I inverted my axis and set X to max end-stop instead of min-end stop, altered all other required settings to make X work correctly and re-ran the probe. My conclusion here is that the probing sequence is exactly the same, while it should be reverted. it starts at X 220-probing distance, Y0-probing distance, while it should start at X0-probing distance, Y0-probing distance. This seems to verify the issues I'm seeing, the leveling matrix doesn't take the inversion settings into account and seems to map the wrong matrix on the bed. I will try printing again with this settings and update here. Not sure I might have to do the same for my Y axis, I'm still trying to tracking this...

encodedLife commented 4 years ago

Hey, i also have the Bltouch 3.1 (on Skr 1.3) i use the following settings:

define Z_MIN_PROBE_ENDSTOP_INVERTING true define Z_PROBE_LOW_POINT -10 <- this should be higher then the Z-Probe offset

also level the corners br

Edit: i know -10 for Z_PROBE_LOW_POINT is a little bit to much but i don´t even know why this setting is there

well, I forgot to say that I also changed my homing. Before my homing point where on rear right now I put the end stops to front left and also changed these settings. And now it´s working better but not as it should be.

@thierryzoller could you try following: Calibrate the Z-Offset with a sheet of paper and save the value. Make bed leveling with: G29 Turn of Bed leveling: M420 S0 Go to the first leveling Point: G42 I0 J0 Print the Bed Leveling Mesh Values: M420 V Then go to zero with the z axis: G1 Z0 Turn Bed leveling on: M420 S1

the current Z-position on the Display should change to the (0,0) value of the printed Mesh values. If you use the following command G1 Z0, the same space should be available as for the paper calibration. When I perform these steps, the distance between the nozzle and the bed is more or less than the point at which I performed the paper calibration.

ziporah commented 4 years ago

I followed your procedure exactly, the values shown are inverted. I went to G42 I2 J2, my grid value is +0.43 there. Then go to G1 Z0 with bed leveling disabled. enable leveling. The display shows - 0.43 and go to G1 Z0, the bed moves up 0.43 instead of going down.

encodedLife commented 4 years ago

I followed your procedure exactly, the values shown are inverted. I went to G42 I2 J2, my grid value is +0.43 there. Then go to G1 Z0 with bed leveling disabled. enable leveling. The display shows - 0.43 and go to G1 Z0, the bed moves up 0.43 instead of going down.

ok i think there is the bug.

EDIT: to get a better understanding about the bug someone with another Probe or another Probe system should try the same steps. Then we can determine if this bug is only on BLTouch 3.1 or in the FW.

I´m sorry I don´t have so much time, to investigate in this problem. I would recommend using this bug finding strategy, i you want.

ziporah commented 4 years ago

I have a simple bl touch. I only defined this in the config: ‘’’

define BLTOUCH

‘’’

thierryzoller commented 4 years ago

Upload you config please

thierryzoller commented 4 years ago

@polato94 : There is no need to as it worked beforehand on previous builds, rather than staying theoretical one should take a look at the code and determine where the error happens. Signed/unsigned ? For that I have to leave it to someone else. The bug was demonstrated and reproduced. I am unaware what part of the code is responsible for this operations - and would expect a Dev to step in.

You said: to get a better understanding about the bug someone with another Probe or another Probe system should try the same steps. Then we can determine if this bug is only on BLTouch 3.1 or in the FW.

thierryzoller commented 4 years ago

Should be somewhere around here : https://github.com/MarlinFirmware/Marlin/blob/2.0.x/Marlin/src/module/probe.cpp https://github.com/MarlinFirmware/Marlin/blob/2.0.x/Marlin/src/module/probe.h

marcjwebb commented 4 years ago

hya all, hope everyone here is safe and well. wondered if this was fixed in the latest bugfix on the firmware page? i am too getting this issue. ( ender 3 pro, bltouch v3.1, marlin 2.0.5.3 )

thinkyhead commented 4 years ago

Still tracking down the cause. If someone knows a particular version of Marlin where it's still okay, that would be useful data. I'll be able to get into troubleshooting this issue in about 12 hours….

thinkyhead commented 4 years ago

I went to G42 I2 J2, my grid value is +0.43 there.

Then go to G1 Z0 with bed leveling disabled. Enable leveling. The display shows -0.43. Go to G1 Z0, the bed moves up 0.43 instead of going down.

If the Z position was 0 before leveling was disabled, then the display should should indeed show -0.43. That accords with my description above. And, at the very least, moving to Z0 is supposed to move the nozzle farther away from the bed. So there is definitely something amiss!

That could be a case where the planner wasn't sync'ed with the updated Z position after it was changed by the set_bed_leveling_enabled function… or as alluded to, the soft endstops could be getting in the way.

You can check whether the planner and the logical position are properly synchronized by turning on M114_DETAIL and then sending M114 D at the point just after you disable leveling, but before you (don't) do the move to Z0. That will probably reveal that the planner and the logical position are out of phase. If only it could tell us where and how…

It would be worth doing some experiments to see if changing the values of the Z min soft endstop has any effect on leveling behavior. I bet there's something there. See if doing M211 S0 has any effect on the way this bug manifests, or if turning off soft endstops altogether makes some difference.

If handling has been changed recently around set_bed_leveling_enabled or around the way soft endstops get applied or reckoned — perhaps in relation to the MIN_POS/MAX_POS settings— in recent months, these would be good things to check…

I will look into this more in about 10-12 hours, after the whole sleep thing.

ziporah commented 4 years ago

Upload you config please This is my current configuration

this is my configuration test with Linear, which appears to be totally off, reverting back to bilinear (only change in following file) Configuration_adv.txt Configuration.txt

ziporah commented 4 years ago

I reconfigured my X axis to default behaviour, uploaded clean firmware, reset to default settings, ran G28, followed by G29 here's the output:

Log Output ``` echo:Index: 628 Size: 692 echo:Hardcoded Default Settings Loaded echo:SD card ok Bilinear Leveling Grid: 0 1 2 3 4 0 +0.843 +0.985 +0.160 +0.646 +1.167 1 +0.674 +0.645 +1.152 +1.095 +1.210 2 +0.334 +0.479 +0.880 +0.996 +1.076 3 +0.581 +0.032 +0.751 +0.955 +1.199 4 +0.491 +0.103 -0.358 -0.238 +0.372 >>> M114 D SENDING:M114 D X:108.00 Y:120.00 Z:9.66 E:0.00 Count X:10680 Y:11752 Z:4129 >>> M420 S0 SENDING:M420 S0 echo:Bed Leveling OFF echo:Fade Height OFF >>> G42 I2 J2 SENDING:G42 I2 J2 >>> M114 D SENDING:M114 D X:110.00 Y:93.50 Z:10.40 E:0.00 Count X:10878 Y:9156 Z:4129 >>> M114_DETAIL SENDING:M114_DETAIL X:110.00 Y:93.50 Z:10.40 E:0.00 Count X:10878 Y:9156 Z:4129 >>> G1 Z0 SENDING:G1 Z0 >>> M114_DETAIL SENDING:M114_DETAIL X:110.00 Y:93.50 Z:0.00 E:0.00 Count X:10878 Y:9156 Z:0 >>> M420 S1 SENDING:M420 S1 echo:Bed Leveling ON echo:Fade Height OFF >>> M114_DETAIL SENDING:M114_DETAIL X:110.00 Y:93.50 Z:-0.88 E:0.00 Count X:10878 Y:9156 Z:0 >>> G1 Z0 SENDING:G1 Z0 ```

at Z:4129 => the Z axis was still in the position after homing and bed leveling then issued the first G1 Z0 display showed -0.88 befor the final G1 Z0 and Z went up on G1 Z0 If you need some more debugging info, let me know, I'll try to collect asap. Should I try the 0.2.0-bugfix branch ? => re-programmed with M114_DETAIL enabled, running the procedure again, will post when finished

thierryzoller commented 4 years ago

the current Z-position on the Display should change to the (0,0) value

My display doesn't show Z, what M503 value should I watch?

ziporah commented 4 years ago

M114 D shows the current value

thierryzoller commented 4 years ago

@polato94 : This is bug-fix2.0 build from an hour ago - I did what you said step by step. After the 420 S1 there was 0 movement of the Z axis and M114 D shows

> X:28.00 Y:25.00 Z:0.19 E:0.00 Count X:2240 Y:2000 **Z:0**

I should have been -0.190 as far as I can tell :

> Bilinear Leveling Grid:
      0      1      2      3      4      5      6
 0 -0.190 -0.139 -0.150 -0.128 +0.006 +0.047 +0.127
 1 -0.165 -0.116 -0.115 -0.114 +0.012 +0.066 +0.135
 2 -0.104 -0.054 -0.065 -0.058 +0.064 +0.095 +0.155
 3 -0.036 +0.003 -0.006 -0.011 +0.092 +0.107 +0.174
 4 +0.055 +0.090 +0.059 +0.039 +0.121 +0.148 +0.188
 5 +0.187 +0.199 +0.148 +0.106 +0.169 +0.142 +0.189
 6 +0.242 +0.254 +0.198 +0.158 +0.233 +0.206 +0.243

### Step by Step:

> G28 : 
> X:127.00 Y:188.00 Z:14.97 E:0.00 Count X:10160 Y:15040 Z:6000
> G29 : 
> X:257.00 Y:310.00 Z:15.00 E:0.00 Count X:20560 Y:24800 **Z:6092** <**--- Why 92?**
> G42 I0 J0
> G29Q gives me ABL Adjustment Z-0.183
>m420 v also gives me z-0.183
> M420 S0
> X:257.00 Y:310.00 Z:15.23 E:0.00 Count X:20560 Y:24800 Z:6092
>g1 z0
> m420 s1
> X:28.00 Y:25.00 Z:0.18 E:0.00 Count X:2240 Y:2000 Z:0

The nozzle scratches the Bed at this point @polato94

ziporah commented 4 years ago

This is still 0.2.x firmware, this time with M114_DETAIL compiled in Clean again, homing G28, bed level G29 Z position after homing on display: 9.55 Z position after disabling bed leveling : 10 Z position after G42 I2 J2 , G1 Z0 : 0 Re-enable leveling : -0.442 Z position after G1 Z0 : 0 => axis went up detailed info in this gist: https://gist.github.com/ziporah/f82595526618b0a5deaf7a4ba887897e

let's wait for @thinkyhead to chime in his ideas.

thierryzoller commented 4 years ago

Here is the Debug Log:

Log Output ``` > 2020-05-10 20:08:17,457 - SENT: M420 S0 > 2020-05-10 20:08:17,457 - RECV: echo:M420 S0 > 2020-05-10 20:08:17,457 - RECV: current_position= X257.00 Y310.00 Z15.00 : Leveling ON > 2020-05-10 20:08:17,457 - RECV: current_position= X257.00 Y310.00 Z15.22 : ...Now OFF > 2020-05-10 20:08:17,471 - RECV: current_position= X257.00 Y310.00 Z15.22 : sync_plan_position > 2020-05-10 20:08:17,471 - RECV: echo:Bed Leveling OFF > 2020-05-10 20:08:17,471 - RECV: echo:Fade Height OFF > 2020-05-10 20:08:17,471 - RECV: ok > 2020-05-10 20:08:34,783 - SENT: G42 I0 J0 > 2020-05-10 20:08:34,783 - RECV: echo:G42 I0 J0 > 2020-05-10 20:08:34,783 - RECV: ok > 2020-05-10 20:08:55,030 - SENT: M420 V > 2020-05-10 20:08:55,030 - RECV: echo:M420 V > 2020-05-10 20:08:55,030 - RECV: Bilinear Leveling Grid: > 2020-05-10 20:08:55,046 - RECV: 0 1 2 3 4 5 6 > 2020-05-10 20:08:55,046 - RECV: 0 -0.191 -0.146 -0.147 -0.134 -0.000 +0.046 +0.125 > 2020-05-10 20:08:55,046 - RECV: 1 -0.178 -0.113 -0.119 -0.115 +0.008 +0.066 +0.134 > 2020-05-10 20:08:55,046 - RECV: 2 -0.108 -0.051 -0.062 -0.058 +0.061 +0.096 +0.159 > 2020-05-10 20:08:55,061 - RECV: 3 -0.043 +0.011 -0.003 -0.010 +0.093 +0.111 +0.177 > 2020-05-10 20:08:55,061 - RECV: 4 +0.044 +0.096 +0.060 +0.036 +0.120 +0.142 +0.189 > 2020-05-10 20:08:55,061 - RECV: 5 +0.183 +0.203 +0.146 +0.111 +0.171 +0.148 +0.190 > 2020-05-10 20:08:55,076 - RECV: 6 +0.240 +0.254 +0.194 +0.154 +0.228 +0.204 +0.248 > 2020-05-10 20:08:55,076 - RECV: echo:Bed Leveling OFF > 2020-05-10 20:08:55,076 - RECV: echo:Fade Height OFF > 2020-05-10 20:08:58,802 - SENT: G1 Z0 > 2020-05-10 20:08:58,802 - RECV: echo:G1 Z0 > 2020-05-10 20:08:58,802 - RECV: ok > 2020-05-10 20:09:03,749 - SENT: M420 S1 > 2020-05-10 20:09:03,749 - RECV: echo:M420 S1 > 2020-05-10 20:09:03,749 - RECV: current_position= X28.00 Y25.00 Z0.00 : Leveling OFF > 2020-05-10 20:09:03,749 - RECV: current_position= X28.00 Y25.00 Z0.19 : ...Now ON > 2020-05-10 20:09:03,763 - RECV: current_position= X28.00 Y25.00 Z0.19 : sync_plan_position > 2020-05-10 20:09:03,763 - RECV: echo:Bed Leveling ON > 2020-05-10 20:09:03,763 - RECV: echo:Fade Height OFF > 2020-05-10 20:09:03,763 - RECV: X:28.00 Y:25.00 Z:0.19 E:0.00 Count X:2240 Y:2000 Z:0 > 2020-05-10 20:09:03,763 - RECV: ok > 2020-05-10 20:09:04,345 - RECV: echo:M105 > 2020-05-10 20:09:04,361 - RECV: ok T:23.09 /0.00 B:23.01 /0.00 @:0 B@:0 > 2020-05-10 20:09:07,355 - RECV: echo:M105 > 2020-05-10 20:09:07,355 - RECV: ok T:23.16 /0.00 B:23.09 /0.00 @:0 B@:0 > 2020-05-10 20:09:08,984 - SENT: M114 D > 2020-05-10 20:09:08,984 - RECV: echo:M114 D > 2020-05-10 20:09:08,984 - RECV: X:28.00 Y:25.00 Z:0.19 E:0.00 Count X:2240 Y:2000 Z:0 > 2020-05-10 20:09:09,000 - RECV: Logical: X:28.000 Y:25.000 Z:0.191 > 2020-05-10 20:09:09,000 - RECV: Raw: X:28.000 Y:25.000 Z:0.191 > 2020-05-10 20:09:09,000 - RECV: Leveled: X:28.000 Y:25.000 Z:0.000 > 2020-05-10 20:09:09,000 - RECV: UnLevel: X:28.000 Y:25.000 Z:0.191 > 2020-05-10 20:09:09,016 - RECV: Stepper: X:2240 Y:2000 Z:0 E:0 > 2020-05-10 20:09:09,016 - RECV: FromStp: X:28.000 Y:25.000 Z:0.000 E:0.000 > 2020-05-10 20:09:09,016 - RECV: Diff: X:0.000 Y:0.000 Z:0.000 E:0.000 ```
thierryzoller commented 4 years ago

I can also notice no compensation when doing G1 travel moves. Not sure that is supposed to be compensated.

thierryzoller commented 4 years ago

In an attempt to find a build that works I flashed 2.0.5 - One observation, I turned ABL off, the Z motor slightly adjusted midst printing move (althought it is on the very same layer). I turned ABL on, same thing. Why would the zmotor ever so slighly spin when executing a printing move in the middle of a layer?

hitbyatruck commented 4 years ago

Hello, everyone. This bug has been driving me nuts as well. It's been over a week of trying to figure out the problem and I still can't figure out why the ABL is not compensating for the mesh while printing. As anyone been able to figure out what may be causing this bug? After several tries with different firmware versions, nothing seems to make sense for why this keeps happening, when several people don't have the same problem. I'm with an Ender 3 with a SKR mini E3 V1.2 and a BLtouch V2.1. Let me know if there's any other information that may be prove usefull on solving this problem and I'll try to debug it along with you guys, if you don't mind.

HooverC91 commented 4 years ago

Following and willing to provide input. I have a Prusa Bear with both a PINDA and a Genuine BLTouch 3.1 and noticed the BLTouch has far worse results than the PINDA (as if its compensating some but not enough). I tested this by greatly skewing the bed and printing first layer tests. The only difference is the mounting location- PINDA (23, 5, 0.68) vs BLTouch (-24.3, -34.1, 2.13)

hitbyatruck commented 4 years ago

As of now, the current bugfix 2.0.x seems to be working out ok... so far, at least.

thinkyhead commented 4 years ago

Good to hear that the current bugfix ABL is behaving. ABL has been pretty solid on our test machines, but I still hear about some anomalies related to …maybe… soft endstops. We're not entirely sure. But, between prints there seems to be an accumulating error in Z. Other than that, the compensation does follow the bed contours when it's supposed to.

For troubleshooting leveling and getting a deeper look at what might be going on, the DEBUG_LEVELING_FEATURE adds a lot of extra logging that appears with M111 S32. But for checking whether the leveling at a particular spot on the bed is correct, the combination of that with M114_DETAIL allows you to:

thierryzoller commented 4 years ago

Sorry to rain on the parade @hitbyatruck - latest bugfix0.20 (today) didn't fix anything and introduced Y stutter (other issue). Hence why keep this issue is open, still waiting on way to help solving it. Also changed softstop to -10, didn't change a thing.

My video shows it crashes the bed, provided full logs. Was waiting on what to do next. What should I do next?

thinkyhead commented 4 years ago

Thanks for all the data. At this point you will have to wait for someone with troubleshooting and coding ability to install the latest Marlin on a test machine, investigate the issue, narrow down the cause, and hopefully resolve the issue and submit a patch for testing.

GhostlyCrowd commented 4 years ago

Still tracking down the cause. If someone knows a particular version of Marlin where it's still okay, that would be useful data. I'll be able to get into troubleshooting this issue in about 12 hours….

If it helps every person with ABL issues who has rolled back to 2.0.3 is 100% happy that i have personally rolled back. Many of them are too busy printing to move forward again to test, I have one friend who is willing to test as soon as this last batch of PPE is done. Also UBL does no suffer from this issue, but as stated above it appears to be a mesh inversion or non-iversion, related to no respecting the inversion or lack of in the axis in the firmware.

thinkyhead commented 4 years ago

it appears to be a mesh inversion or non-iversion

We'll see. I have closely examined the log output from @thierryzoller and @ziporah related to how turning leveling on and off affects the current Z position and the underlying stepper count. Everything there looks appropriate.

A very simple controlled test that anyone can try is to make a fake mesh that is all zeros to start with, and then just change the center point value. Do small and large moves around the center to see how the nozzle behaves. Of course, keep the nozzle above the bed so that you don't damage any components.

Start out with the Z Fade turned off so that you get full Z adjustment at any height. Later, experiment with how changing Z fade affects movement. We've tried to make changing the Z fade during segmented movement a safe thing to do. However, it's not necessarily recommended, so during testing only change Z fade in-between moves.

By using very controlled numbers and a very controlled set of moves, along with detailed logging using G29 Q and M114 D (as needed) it should be obvious when Z is moving too much or too little or going in the wrong direction.

The thing to do then is to make some short, fake print job that doesn't heat up or extrude, but just turns on leveling, moves XY around, then raises Z and moves XY some more, and does this for about a centimeter in height. The G-code could contain your usual slicer start/end G-code, along with "M114 D" commands to examine any "interesting" codes that your slicer inserts.

At the end of the fake print job, try to run the fake print job again, and look closely to see if Z is getting thrown off, and by how much. Check to see if the M114 D report shows a discrepancy at the same time.

It would be worth trying G-code that contains G28 and M420 S1 at the top. And then to try again without the G28 that re-homes XYZ. Does the G28 fix the XYZ position?

Take careful note of whether your first G28 was done with a cold bed, and your second G28 was done on a heated bed. The bed can expand by a large amount, and the contours of the mesh will vary depending on how hot the bed is. For this reason, always heat your bed before you do G28 with a probe or measure your bed with G29.

Generally, should you do G28 and/or G29 between prints?

To get a sense of how much the bed may be expanding, Marlin contains useful new feature called PROBE_TEMP_COMPENSATION. It requires the probe to have a temp sensor, but you can set TEMP_SENSOR_PROBE equal to 998 and it will just use the bed temperature. You can then use the G76 command to measure the deflection of your bed at a range of temperatures, and this will also pick up some of the error that the bed temperature might be introducing to your probe.

thinkyhead commented 4 years ago

2.0.3

I will closely compare 2.0.3 to the code that followed. It sounds like even 2.0.4 exhibits some anomalies.

ziporah commented 4 years ago

I just tried compiling 2.0.3 and ran a test print on it, I'm not really convinced the leveling is working as expected. I reset my settings, G28, G29, Z offset measurement on probe point I2 J2, but it slams the head in the glass plate when I reload settings and restart with the measured offset. I lowered the offset from -3.50 to -3.20 and then I can start printing, but it shouldn't be off anyway. There must be something amiss by disabling the soft endstops with M211 S0. Second observation is that the leveling on the back of the plane still seems to be wrong. it still pushes the head to deep in the bed, while at front it is slightly to high. The print sticks to the bed, but I don't believe this is optimal and leveling is still not correct here. The print covers the inner 3x3 matrix, it's not a full bed coverage test

>>> M420 V
SENDING:M420 V
Bilinear Leveling Grid:
      0      1      2      3      4
 0 +0.203 +0.064 -0.025 +0.229 -0.193
 1 -0.628 -0.116 -0.270 +0.195 -0.389
 2 -0.760 -0.368 -0.017 -0.015 -0.154
 3 -1.172 -0.442 -0.079 +0.150 -0.246
 4 -0.963 -0.974 -0.375 +0.246 -0.106
echo:Bed Leveling ON
...
M503
echo:  M851 X2.00 Y-63.00 Z-3.20
GhostlyCrowd commented 4 years ago

I just tried compiling 2.0.3 and ran a test print on it, I'm not really convinced the leveling is working as expected. …

@ziporah

Is your bed really this un level (below) or is this part of the ABL error you are seeing? If its really this unlevel you should try to manually address that at least get the corners with in reason of each other for ABL to work, it compensates for bed level issues but it's not a miracle worker, you will still have issues on a very unlevel bed even with ABL so if your bed is indeed as below, wildly unlevel this may be part of the problem.

image

ziporah commented 4 years ago

I'm totally baffled what's wrong with the machine/firmware. I've leveled the bed manually several times, and I did manage to print without the ABL, before I added the BL Touch. I added it in order to get better prints, but even after running G29 several times in a row, it is showing different meshes on each iteration. Yes, the bed is heated at 60 degrees. I've already run M48 to validate the BL touch and it shows a correction of 0.026 consistent over several runs. In total madness I disassembled the bed, removed the Y axis, cleaned everything, measured all again to be parallel and sliding smooth, so I can't find nothing wrong there. I would at least expect the mesh that's measured to be the same on each run, within the tolerance of the BL touch, but even that's a dream ...

thierryzoller commented 4 years ago

@GhostlyCrowd : From left bottom to left top there is around 1mm of difference, the graph is grossly misrepresenting. ABL should easily cover 1mm from a 300mm distance. Mine is a bit more level, but still doesn't work. Not the problem.

thierryzoller commented 4 years ago

I do not have the tolerance issue that you are describing, as can be seen in the logs I posted above. So we can exclude that as the issue.

GhostlyCrowd commented 4 years ago

This is an example i just pulled from a friend on 2.0.3, 2.0.3 was the latest build where he didnt have abl issues and the bltouch failing to deploy and driving the tool head into his bed.

He is using more mesh points and extrapolating beyond the grid. Try a few more mesh points and extrapolation and see if it at leats improves your symptoms on 2.0.3

image

thierryzoller commented 4 years ago

BLTouch failed to deploy only in case I had a wiring issue (lose connection) - there is an issue documenting this on here.

thierryzoller commented 4 years ago

Understand that we should be looking everywhere, but as the person that has opened this issue, can we stay within that frame for a second? I have no deviation of BLTouch measures, it deploys correctly and coherently. What I am seeing is :