Suggestions for debugging a timing issue

[RadicalZephyr]

Hi all,

This is not a problem in master Klipper. As I've mentioned in an earlier issue I am working on adding support to the klippy/kinematics/extruder.py file for controlling my bespoke feed mechanism and I'm having trouble getting it to work.

In particular, I am getting a variety of timing issues when trying to control the outputs related to my feed mechanism. I am confident that it is my additions to Klipper that are causing these errors since I am able to dry print the same gcode file using the Klipper master branch just fine.

I am getting a "timer too close" error which I believe is caused by the code I have for turning off the pellet feed mechanism after all extruder moves have finished. This is using a reactor timer in the host software, and from the log file I can see that the timer is being called far more often than I want it to be. The code for this is here. Note, that the log file for this was obtained by simply removing the return None statement from the _setup_stop_timer function so that code does get executed. The pellet_control module is hooked into the extruder.py file at line 219.

The intention behind that code is that the _setup_stop_timer function is called once when the first extruder movement is scheduled, and the _update_turn_off_time function is called every time a new extruder move is scheduled. The purpose of the timer is to maintain a pending timer event for turning everything related to my pellet feed system off some period of time after the last extruder movement is scheduled.

I wanted to do this updating by looking at the scheduled time of the last step for each extruder move, but it doesn't look like this value is easily accessible from the python code since it is calculated in the C helper code. If you have a suggestion on what it would take to surface this value that would be much appreciated.

I'm also fairly convinced that my understanding of how to use the reactor and the timer handles it returns is fairly poor and I suspect I'm doing something fairly wrong but I'm unsure what it is. If you could take a look at it, or if you could point me to some documentation on the reactor being used (I haven't figured it out just yet by reading the code) that would also be very appreciated.

"timer too close" klippy.log

thanks for any suggestions or feedback on bad things my code might be doing!

[KevinOConnor]

The reactor takes a system time - which must not be mixed with "print times" nor "clocks". There's a little bit of info on this at: https://www.klipper3d.org/Code_Overview.html#time

I'm not sure how precise the pellet feeder signals need to be. If you need to toggle the gpio line faster than 100ms then be aware of #133.

-Kevin

[RadicalZephyr]

Ah that makes sense. Good to know about the timing, but that shouldn't be an issue, the cycling frequency is much slower than that (like one state change every several seconds at most).

I had seen the time section of the docs already, but I guess what I'm still unsure about is how to convert from a "print time" to a system time. Looking through the methods in clocksync.py I'm really not sure what the correct sequence of calls would be to transform the print_time that I get passed in update_next_movement_time into the correct system time to use as the waketime for my turn off callback.

I also realized that I'm using register_timer and probably should be using register_callback because I only want to get the callback once, and timer is probably a repeating callback. Is that accurate?

Thanks!

[KevinOConnor]

It's rare to go from a print_time to a systime, so there isn't a single method to do that. (It's also only possible to estimate the time, as the clocks could drift slightly.) It's possible to get at it from clocksync.estimate_clock_systime(clocksync.print_time_to_clock(print_time))

Yes - register_callback is a one shot callback, while register_timer has the mechanics to reschedule itself (if desired).

-Kevin

[RadicalZephyr]

Thanks, that ought to help a bit!

[RadicalZephyr]

Thanks, that did it!