Don't use incomplete clock sync for SPI temperature; always warn

[chuckwagoncomputing]

The problem is outlined in Klipper3d/klipper#6619

In this PR, I have done two things:

• Add a simple check to avoid reporting the wrong temperature
• Add some warnings for when an uncompleted clock sync is used in clock_to_print_time() and print_time_to_clock()

There may be a better solution to this; I'm not sure. I headed down the path of making clock_to_print_time() and print_time_to_clock() raise an exception, but there's just too much stuff that happily accepts the wrong value for my little non-python-fluent brain to handle it all.

[bwnance]

looks great! Thanks :)

[chuckwagoncomputing]

In case someone is interested in improving this, there is one other thing that regularly tries to call estimated_print_time() (which calls clock_to_print_time()) before clock sync is completed.
Call stack:

File "/home/biqu/klipper/klippy/reactor.py", line 386, in _dispatch_loop
    timeout = self._check_timers(eventtime, busy)
File "/home/biqu/klipper/klippy/reactor.py", line 181, in _check_timers
    t.waketime = waketime = t.callback(eventtime)
File "/home/biqu/klipper/klippy/webhooks.py", line 551, in _do_query
    res = query[obj_name] = po.get_status(eventtime)
File "/home/biqu/klipper/klippy/toolhead.py", line 692, in get_status
    estimated_print_time = self.mcu.estimated_print_time(eventtime)
File "/home/biqu/klipper/klippy/mcu.py", line 1225, in estimated_print_time
    return self._clocksync.estimated_print_time(eventtime)
File "/home/biqu/klipper/klippy/clocksync.py", line 173, in estimated_print_time
    for line in traceback.format_stack():

I'm not sure what the source is of this; seems to be webhook related. I did have mainsail open in my browser.

[dalegaard]

In case someone is interested in improving this, there is one other thing that regularly tries to call estimated_print_time() (which calls clock_to_print_time()) before clock sync is completed. Call stack:

File "/home/biqu/klipper/klippy/toolhead.py", line 692, in get_status
    estimated_print_time = self.mcu.estimated_print_time(eventtime)

I'm not sure what the source is of this; seems to be webhook related. I did have mainsail open in my browser.

This is called when the API is requesting status to show in the frontend, in this case it's the print time returned for the toolhead object.

Best regards,
Lasse

[dalegaard]

As regards to the issue, can you try moving this line in spi_temperature to a connect handler?

        mcu.register_response(
            self._handle_spi_response, "thermocouple_result", oid
        )

An alternative could be to add a is_connected or similar variable, and set that in a connect handler, then check it within _handle_spi_response (this method avoids the "unhandled message" log messages).

ClockSync gets initialized during the klippy:mcu_identify event. klippy:connect is run after, so when that happens we know ClockSync is initialized.

I actually think the two warnings you put in ClockSync should be extended to dump the callstack because anything calling them before the connect event has passed should be considered a bug. Thoughts @rogerlz ? Maybe we could add a is_synced function to the ClockSync system so callers can check before introducing a bug.

Best regards,
Lasse

[chuckwagoncomputing]

Thank you for your input! This is the kind of architectural knowledge I was missing. I'll make some changes some time in the next few days.

[chuckwagoncomputing]

I changed the check to checking the frequency value in clock_adj because the clock calibration calls these functions after setting the frequency value, but before setting last_sync_time.

[chuckwagoncomputing]

@bwnance Are you waiting for something from me, or are you just busy? I think it's ready for review.
I'm not in any hurry - there's no reason I need it merged, I just want to help out. Neither do I want this to just sit here because I haven't understood what's wanted of me, which is why I ask.

[dalegaard]

Hi,

Did the connected handler fix stop the issue as intended? If so, I think this is good to merge.

Best regards,
Lasse

[chuckwagoncomputing]

Yes, as far as I can tell, it's working perfectly.

[rogerlz]

Thank you!