Clock sync and unrealistic extruder temps after restart

Developers
1

I have been Mildly Annoyed, and decided to do something about it.

I have been having the same issue as some other folks, but I can’t post more than 2 links here, so you’ll have to check out the original issue at Clock sync and unrealistic extruder temps after restart · Issue #6619 · Klipper3d/klipper · GitHub

In short, when using a SB2209 CAN bus toolhead board, when restarting Klipper with RESTART, the extruder temperature is reported as a very large number, either negative or positive, before returning to normal over the next ~10 seconds. This doesn’t happen all the time; it’s pretty random.

Here is the cause as well as I can understand it:

  1. The toolhead keeps sending thermocouple_result commands, because it wasn’t restarted.
  2. When a thermocouple_result command is sent before clock sync finishes, SecondarySync’s clock_adj still has 1 for the mcu frequency, which results in spi_temperature.py’s _handle_temperature_response getting an undivided value from its call to clock_to_print_time().
  3. If the temperature reading has changed on the first thermocouple_result command after clock sync has finished, temperature_callback in heaters.py will multiply the difference in temperature by the difference between the undivided value and the new correct value, resulting in a very large “smoothed” temperature, either negative or positive depending on the direction of the temperature change.

On my machine, I implemented the following fix:

In _handle_spi_response in spi_temperature.py:

        last_read_time  = self.mcu.clock_to_print_time(last_read_clock)
+        if last_read_time == last_read_clock:
+            logging.warning("Ignoring untrustworthy clock sync")
+            return
        self._callback(last_read_time, temp)

I’m not sure if this is the appropriate fix, as this is the first time I’ve touched the Klipper codebase, but I rather doubt it. It feels like something more fundamental should change, like maybe clock_to_print_time should throw an error if the clock isn’t synced.

1 Like
2

Would you be able to provide a Klipper log from the event? Make sure you’re running pristine Klipper code, issue a RESTART, issue an M112 after the event, and then post the full Klipper log file here. Contact - Klipper documentation

With a log from the event I’m sure we can track down the problem and update the mainline code with a fix. I didn’t fully understand the sequence of events you described above.

Thanks,
-Kevin

3

I PR’d my dumb change to Danger Klipper, and Lasse gave me some pointers for improving it.

If you also want those changes, you can cherry pick them or I can make you a PR if you like.

4

I wonder if this would also fix the temperature on startup issue for MAX31865 temp sensor chips. Occasionally this chip, used on the flysht can toolhead board will read an absurdly large value on start. There was some speculation that the max chip takes a period of time to wakeup and during that initial period there is a temperature reporting issue. Maybe the max chip pins are not configured properly high/low.