Incorrect Final Z Position After Homing with Probe

[MSzturc]

Description

When homing the Z-axis using a probe, the final Z position is incorrect. This issue occurs because the starting position for the second homing is calculated based on the retract position. As a result, the retract distance is applied twice, but only reverted once.

Root Cause

The issue lies in the calculation of the starting position for the second homing attempt, where the retract distance is incorrectly handled. This results in an additional retract operation that is not compensated for, leading to an incorrect Z position.

Example Log

Below is a log demonstrating the issue:

    Starting home_rails operation with 
        forcepos: [None, None, 254.4, None] 
    and movepos: [None, None, 1.2, None]
    
    Homing axes determined: [2]
    Toolhead position set to startpos: [96.0, 106.0, 254.4, 0.0]
    
    Endstops initialized: [(<extras.BDsensor.BDsensorEndstopWrapper object at 0x7f8fb03e50>, 'z')]
    
    Homing info retrieved: 
    homing_info(
    speed=15.0, 
    position_endstop=1.2, 
    retract_speed=5.0, 
    retract_dist=3.0, 
    positive_dir=False, 
    second_homing_speed=8.0, 
    use_sensorless_homing=False, 
    min_home_dist=3.0)
    
    Endstop states reset. Starting first homing move.
    BDsensorVer:V1.2 ,switch_mode=0,collision_homing=1,collision_cal=1
    
    Retract distance required: 3.0
    Needs rehome: False
    
    Retracting to position: [96.0, 106.0, 4.2, 0.0]
    
    Performing dwell after retraction.
    
    Second homing attempt starting from position: [96.0, 106.0, 7.2, 0.0]
    
    Performing final retraction.
    Retracting to position: [96.0, 106.0, 4.2, 0.0]

Analysis

• The position_endstop is 1.2
• The retract distance 3
• At first home the z position is correct: 4.2
• At second home the z position is incorrect: 7.2
• After homing the final position is 4.2 for z which should be 1.2

Additional Notes

This issue causes a significant offset in Z homing, which can lead to incorrect bed leveling and printing failures. Resolving this bug is crucial for accurate Z-axis calibration.

[Zeanon]

I know bd-sensor doesn't specify to set the homing retract dist to 0 to disable a second homing move, but all other Eddy current sensors I know of do that.
Could you try without a second homing move and report your results?
I am not totally sure whether it's a kalico or bd sensor issue
Also have you tried it with normal Klipper to make sure it only occurs with kalico?

[MSzturc]

Disabling the second homing step works as a workaround. also the BDSensor is compatible with the standard Klipper master since Klipper resets the position between runs.

While the second homing step isn’t strictly necessary, it does provide a valuable benefit. Unlike switch-based probes, eddy current probes enable high-speed Z-axis homing. For instance, I home the Z-axis at 150mm/s, which offers enough margin to avoid crashes but sacrifices some accuracy (the BD sensor has an accuracy of ±0.3mm at this speed). To address this, I perform a second homing step at 8mm/s for the final 2mm, ensuring greater precision.

[Zeanon]

I totally get why you want the second homing
I just wanted to know if disabling fixes the issue to narrow down where to look in the code

[Zeanon]

I just did some quite extensive digging and I cant seem to be able to reproduce that issue at all.
the calculation for the start pos are the same in both kalico and klipper.
I also cant seem to find the code giving the logged information, could you provide that so I have a chance of finding the cause?
(I suppose you are running this for the bdsensor: https://github.com/markniu/Bed_Distance_sensor/blob/new/klipper/BDsensor.py#L1184)

[MSzturc]

Yeah I invested a lot time to debug that issue. The log file I provided is a run home_rails (homing.py) enhanced by proper logging code

[Zeanon]

Could you please provide that file, so I know when the logging exactly happens to better troubleshoot the code
Since I am not able to reproduce it, I can only guess rn

[MSzturc]

I no longer have it, as I reverted all changes after patching the issue on my fork. Normally, I’d create a PR, but since my fix is just a quick and dirty workaround, I can’t submit it here. The entire homing process in Klipper/Kalico feels overly complex, and I don’t have the resources to fully understand its behavior across all scenarios to create a proper fix.

As I understand it, the sensorless homing code for the X/Y axes conflicts with the Z-axis homing process.

[MSzturc]

I reconstructed the logging code with ChatGPT, hopefully this helps:

  def home_rails(self, rails, forcepos, movepos):
      # Notify of upcoming homing operation
      self.printer.send_event("homing:home_rails_begin", self, rails)
      logging.info("Starting home_rails operation with \n        forcepos: %s \n    and movepos: %s", forcepos, movepos)
      
      # Alter kinematics class to think printer is at forcepos
      homing_axes = [axis for axis in range(3) if forcepos[axis] is not None]
      logging.info("Homing axes determined: %s", homing_axes)
      
      startpos = self._fill_coord(forcepos)
      homepos = self._fill_coord(movepos)
      self.toolhead.set_position(startpos, homing_axes=homing_axes)
      logging.info("Toolhead position set to startpos: %s", startpos)
  
      # Perform first home
      endstops = [es for rail in rails for es in rail.get_endstops()]
      logging.info("Endstops initialized: %s", endstops)
      
      hi = rails[0].get_homing_info()
      logging.info("Homing info retrieved: \n%s", hi)
  
      hmove = HomingMove(self.printer, endstops)
  
      self._set_current_homing(homing_axes, pre_homing=True)
      self._reset_endstop_states(endstops)
      logging.info("Endstop states reset. Starting first homing move.")
      
      hmove.homing_move(homepos, hi.speed)
      
      # Check for rehome requirement
      needs_rehome = False
      retract_dist = hi.retract_dist
      if hmove.moved_less_than_dist(hi.min_home_dist, homing_axes):
          needs_rehome = True
          retract_dist = hi.min_home_dist
  
      logging.info("Retract distance required: %s", retract_dist)
      logging.info("Needs rehome: %s", needs_rehome)
  
      # Perform second home
      if retract_dist:
          # Retract
          startpos = self._fill_coord(forcepos)
          homepos = self._fill_coord(movepos)
          axes_d = [hp - sp for hp, sp in zip(homepos, startpos)]
          move_d = math.sqrt(sum([d * d for d in axes_d[:3]]))
          retract_r = min(1.0, retract_dist / move_d)
          retractpos = [
              hp - ad * retract_r for hp, ad in zip(homepos, axes_d)
          ]
          logging.info("Retracting to position: %s", retractpos)
          self.toolhead.move(retractpos, hi.retract_speed)
          
          logging.info("Performing dwell after retraction.")
          if not hi.use_sensorless_homing or needs_rehome:
              # Home again
              startpos = [
                  rp - ad * retract_r for rp, ad in zip(retractpos, axes_d)
              ]
              self.toolhead.set_position(startpos)
              logging.info("Second homing attempt starting from position: %s", startpos)
              
              self._reset_endstop_states(endstops)
              hmove = HomingMove(self.printer, endstops)
              hmove.homing_move(homepos, hi.second_homing_speed)
              try:
                  if hmove.check_no_movement() is not None:
                      raise self.printer.command_error(
                          "Endstop %s still triggered after retract"
                          % (hmove.check_no_movement(),)
                      )
                  if (
                      hi.use_sensorless_homing
                      and needs_rehome
                      and hmove.moved_less_than_dist(
                          hi.min_home_dist, homing_axes
                      )
                  ):
                      raise self.printer.command_error(
                          "Early homing trigger on second home!"
                      )
              finally:
                  self._set_current_homing(homing_axes, pre_homing=False)
              if hi.retract_dist:
                  # Retract (again)
                  startpos = self._fill_coord(forcepos)
                  homepos = self._fill_coord(movepos)
                  axes_d = [hp - sp for hp, sp in zip(homepos, startpos)]
                  move_d = math.sqrt(sum([d * d for d in axes_d[:3]]))
                  retract_r = min(1.0, hi.retract_dist / move_d)
                  retractpos = [
                      hp - ad * retract_r for hp, ad in zip(homepos, axes_d)
                  ]
                  logging.info("Performing final retraction.\nRetracting to position: %s", retractpos)
                  self.toolhead.move(retractpos, hi.retract_speed)
  
      self._set_current_homing(homing_axes, pre_homing=False)
      # Signal home operation complete
      self.toolhead.flush_step_generation()
      self.trigger_mcu_pos = {
          sp.stepper_name: sp.trig_pos for sp in hmove.stepper_positions
      }
      self.adjust_pos = {}
      self.printer.send_event("homing:home_rails_end", self, rails)
      if any(self.adjust_pos.values()):
          # Apply any homing offsets
          kin = self.toolhead.get_kinematics()
          homepos = self.toolhead.get_position()
          kin_spos = {
              s.get_name(): (
                  s.get_commanded_position()
                  + self.adjust_pos.get(s.get_name(), 0.0)
              )
              for s in kin.get_steppers()
          }
          newpos = kin.calc_position(kin_spos)
          for axis in homing_axes:
              homepos[axis] = newpos[axis]
          self.toolhead.set_position(homepos)