Marlin: ABL compensation not working - BLTOUCH 3.1

[thierryzoller]

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

• Fresh bugfix2.0 build
• Configuration attached
• Issued the command M111 S247 to enable maximum logging.
• BLTouch V.3.1 PWM Documentation : https://5020dafe-17d8-4c4c-bf3b-914a8fdd5140.filesusr.com/ugd/f5a1c8_d40d077cf5c24918bd25b6524f649f11.pdf

Configuration.txt
Configuration_adv.txt

[thierryzoller]

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]

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]

• Issued a M420 V
• Issued a M500
• Issued a M501

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<print_accel> R<retract_accel> T<travel_accel>
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<min_segment_time_us> S<min_feedrate> T<min_travel_feedrate> J<junc_dev>
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]

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]

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]

Issued an G26 R999

• Scratches the bed immediately
• Verification
  >> m420 s1
  SENDING:M420 S1
  echo:Bed Leveling ON
  echo:Fade Height OFF

Videos here :

• https://youtu.be/-RpWCo1oagw
• https://youtu.be/sYaAf5wG_LQ

Picture here:

(Those are scratches, not filament)

[thierryzoller]

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]

Let me know what you need from me please.

[thierryzoller]

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]

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<print_accel> R<retract_accel> T<travel_accel>
echo:  M204 P800.00 R10000.00 T2000.00
echo:; Advanced: B<min_segment_time_us> S<min_feedrate> T<min_travel_feedrate> J<junc_dev>
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]

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

[encodedLife]

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]

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]

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]

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]

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]

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]

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

define BLTOUCH

‘’’

[thierryzoller]

Upload you config please

[thierryzoller]

@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]

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]

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]

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]

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

• In this position the bed is 0.43mm higher, so the bed and nozzle end up 0.43mm closer at this position when leveling is disabled. The correct behavior at this point should be:
  
  
  
  • Leveling ON to OFF: Z=0 becomes Z=+0.43 (and shouldn't be constrained by soft endstops, etc.)
  
  
  • Leveling OFF to ON: Z=0 becomes Z=-0.43 (and shouldn't be constrained by soft endstops, etc.)
  
  

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]

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]

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]

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]

M114 D shows the current value

[thierryzoller]

@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]

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]

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]

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

[thierryzoller]

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]

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]

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]

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

[thinkyhead]

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:

• use G29 Q to get a report of bed leveling compensation at the current point, and also
• use M114 D to get deeper details about the steppers and leveling calculations.

[thierryzoller]

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]

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]

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]

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?

• If homing with a probe, G28 is good between prints to account for expansion.
• If homing Z to max and/or with an endstop, another G28 is not strictly needed.
• Another G29 between prints can't hurt, since heat warp isn't entirely predictable.

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]

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]

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]

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.

[ziporah]

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]

@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]

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]

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

[thierryzoller]

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

[thierryzoller]

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 :

• Z movements on 2.0.5 builds although ABL is disabled ??
• Not seeing compensation on newest builds

[ziporah]

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

The BLTouch always deployed here as well. I do see Z movement on the newest builds, but by the looks of it, it's rather an inversed compensation.

[thierryzoller]

I'd like to use "DEBUG_LEVELING_FEATURE" and "M111 S32" but I won't understand what I am seeing.

[thestephenmarshall]

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.

Same here. Just ran 2.0.3 and leveling is not working as expected here either even after restart on first print. ¯_(ツ)_/¯

Interesting observation here: before going dual Z (TMC2208), I was running parallel on Z and was able to get perfect ABL in 2.0.4.4 only after restart on first print. After dual Z, the ABL ghost is back to haunt me regardless of restart or being the first print. It is almost as though the ABL is overcompensating.

Guess I'll run all the bugfix branch latest and attach my log out as well...

[Mils24]

Hi all, I am following this thread closely as I also have issues where my bilinear mesh is not being applied to my prints.

Mesh is being measured ok and showing on EEPROM but is not active during printing. (M420 S1 is in my start script after my G28)

I hope the smarter guys than me on here are working to find a solution. Any update on current progress would be greatly appreciated?

I am also willing to help in any way I can. I can offer data and configs if you need extra material to help find the source of the problem.

Printer: Homemade delta
Motherboard: MKS SBASE 1.3
Firmware: Marlin Bugfix 2.0.x (currently) also tried Marlin 2.0.5 before moving to Bugfix as I had read somewhere that Bugfix worked with ABL.
Sensor: Triangle Labs 3DTouch (BL Touch clone)
ABL type: Bilinear ABL

Really hope we can find a solution soon as about 1/3 of my bed is currently unusable.

Thanks.

[Mils24]

Please see my debug file below as per @thinkyhead instructions for commenting on this issue.

Debug.txt

[thinkyhead]

With DEBUG_LEVELING_FEATURE enabled, you gain another ability with ABL (Bilinear, Linear, 3-point):

• During a print, send G29 Q to get the current leveling information. This command will cause Marlin to report the amount of leveling that is being applied at the current position.
• And, with M114_DETAIL the M114 D command during a print will convey similar information.

Add these to your g-code to get reports at certain points.

[Mils24]

Thanks @thinkyhead I will add some of these in and see what it returns on the first layer during some test prints and report back.

[thinkyhead]

The data collection is appreciated. I have not been able to reproduce the issue.

Can I also assume that no one is using BABYSTEPPING at the start of their print? Because with the babystep-probe-offset option, of course this will change your probe offset and result in your nozzle height changing on the next G28.

[Mils24]

Im not sure what you mean by "...of course this will change your probe offset and result in your nozzle height changing on the next G28."

I am fine tuning my nozzle distance with baby stepping each time a print starts.

Up until recently when I used babystepping to change my z offset it saved to my EEPROM for the next print however over the last few days I have noticed that it now stays fixed and every print I have to baby step it to suit. (my z offset in my firmware is 0 and only in my EEPROM)

Does baby stepping the z_offset cancel the ABL mesh?

Every time I change something in my firmware from reading on here, my testing procedure is as follows:

• G28
• G33
• M500
• G29 (m500 is in my G29 end code so I don't save)
• Print a single layer test print (I don't baby step the test)

Every time to date the ABL has not worked but the full bed mesh is visible within the EEPROM.

Should I upload my config.h and adv_config.h?

[thinkyhead]

Does baby stepping the z_offset cancel the ABL mesh?

No. But it stores the new offset in SRAM and propagates it to the next G28.

If your probe offset is very precise, this might not be what you really want to do. Conceptually, it is tempting to think that applying babystepping to the probe offset for the next G28 is a good thing since it means your next print will be better. But, since you're adjusting for the material, the layer height of the print, the amount of "squish," the amount of thermal expansion in the bed, and so on, and these can all depend on flow, bed surface, and other factors… Well, first layer squish is not the best proxy for "probe offset needs adjustment." This is especially true if the babystepping adjustment is done (only) during the initial priming near the edge of the bed, since the edge height is usually an outlier.

[thinkyhead]

Every time to date the ABL has not worked but the full bed mesh is visible within the EEPROM.

When the print is misbehaving, also send an M420 V to check that the mesh is still the same, and has not been "stepped on" by a buffer overflow, or anything like that.

[Mils24]

So I have done a bit of testing tonight again as per your instruction @thinkyhead.

Please see the attached .txt files.

File 1 shows my mesh data after a G29. It also shows some G29 Q points whilst printing the skirt around my level test print. These G29 Q requests were typed around the 'bad area' of the bed however they didn't show up straight away in my terminal. (Im using Octoprint terminal)

Mesh data and test.txt

File 2 shows some more points on my test print and you can clearly see the differentiation on the layer height. Please see reference points of .txt file with regards the photo below.

Test Print 2.txt

From my limited knowledge of interpreting these output files it looks like its saying that the levelling is active and working, however as seen in the image it is definitely not.

[thinkyhead]

Thanks @Mils24 —

Thanks for the extra data. The mesh data looks a little bit bowl-shaped, which indicates possibly our G33 calibration isn't working as well as it could.

I am concerned there might be some issue with the probe being offset from the nozzle, mostly as it would affect G33. My only Delta has a probe offset of { 0, 0, 0.1 } so I can't validate that mechanically. For this machine the G33 works reasonably well.

To confirm that your G33 calibration is good, set the nozzle very close to the bed and do motions in the XY plane with leveling turned off. Make sure that the nozzle stays the same distance from the bed at all points.

As a confirmation step to see whether the probe could be misbehaving in the G29 procedure, please try G29 again but this time use AUTO_BED_LEVELING_BILINEAR plus PROBE_MANUALLY.

We can then compare the manual mesh to the probe mesh. If there is a significant difference, especially in certain areas, that might tell us something important.

[Mils24]

Hello @thinkyhead thanks for this. I will get on it asap and revert back.

Interesting you mentioned the the G33 may not be working correctly.

Tonight in my hunt for a solution I came across another online Delta Calibration calculator.I inputted my values and followed the steps and it seemed to make a big improvement which leads me to believe that the Marlin bug fix 2.0.x build G33 isn't working correctly.

However I will test as per above instructions and post results. I haven't done a PROBE_MANUALLY before. Is this just a series of G30 X(co-ordinate) Y(co-ordinate) or is there a better script?

[boelle]

@thierryzoller still an issue?

[thierryzoller]

@thierryzoller still an issue?

Unless I say otherwise yes.

[thinkyhead]

It would be good to get this sorted, or at least confirm what the true behaviors are. Please revisit https://github.com/MarlinFirmware/Marlin/issues/17872#issuecomment-627027841 and follow it very closely.

[thierryzoller]

I explained that I have an hardware issue on that particular machine and that I have been waiting on replacement parts ever since. I will try to replicate once I am able to do so,I was discouraged when my issue_s_ kept getting closed admidst that simple explanation.

[github-actions[bot]]

This issue is stale because it has been open 30 days with no activity. Remove stale label / comment or this will be closed in 5 days.

[github-actions[bot]]

This issue has been automatically locked since there has not been any recent activity after it was closed. Please open a new issue for related bugs.