Idle_timeout not triggered when using delayed_gcode

General Discussion
1

Basic Information:

Printer Model: LDO Voron 2.4 RevD
MCU / Printerboard: Leviathan
Host / SBC: Raspberry Pi 4
klippy.log

klippy.zip (3.1 MB)

Fill out above information and in all cases attach your klippy.log file (use zip to compress it, if too big). Pasting your printer.cfg is not needed
Be sure to check our “Knowledge Base” Category first. Most relevant items, e.g. error messages, are covered there

Describe your issue:

I have been at this for days and cannot get to the bottom of the issue.

I have idle timeout configured:

idle_timeout

gcode:

IDLE_TIMEOUT

timeout: 1800

but it never fires, manually running my macros work as expected, so I read the docs and using the API explored states.

When my print completes the state transitions is correct as standby or idle

GET ``http://voron24.local/printer/objects/query?print_stats

{
"result": {
"eventtime": 147363.244125516,
"status": {
"print_stats": {
"filename": "",
"total_duration": 0.0,
"print_duration": 0.0,
"filament_used": 0.0,
"state": "standby",
"message": "",
"info": {
"total_layer": null,
"current_layer": null
}
}
}
}
}

When I query idle_timout however it always remains ‘printing’

GET ``http://voron24.local/printer/objects/query?idle_timeout

{
"result": {
"eventtime": 147508.385373504,
"status": {
"idle_timeout": {
"state": "Printing",
"printing_time": 4582.452879657998,
"idle_timeout": 1800.0
}
}
}
}

This is true regardless of what I do, even after a complete restart or power cycle, the state is always printing.

I cannot find any hints in the documentation of what I can possible have misconfigured and I also don’t see anything useful in the logs that hinting at possible errors in my setup.

Any pointers will be much appreciated.

…

2

I found the root cause, by inspecting the idle_timout python code the blinking LED’s I implemented kept the toolhead PCB busy and reported printing due to the delayed gcode implementation of switching hardware.

Digging deeper it transpires that ANY delayed_gcode calls causes this behaviour, so all delayed gcode should be turned off post print to trigger idle_timeout.

[IdleTimeout] get_status called: state=Ready, printing_time=0.0, idle_timeout=1800.0
[IdleTimeout] get_status called: state=Ready, printing_time=0.0, idle_timeout=1800.0
[IdleTimeout] get_status called: state=Ready, printing_time=0.0, idle_timeout=1800.0
[IdleTimeout] get_status called: state=Ready, printing_time=0.0, idle_timeout=1800.0
[IdleTimeout] get_status called: state=Ready, printing_time=0.0, idle_timeout=1800.0
[IdleTimeout] handle_sync_print_time called: curtime=1744.818620885, print_time=1754.2186728525, est_print_time=1754.4686728525, state=Ready
[IdleTimeout][STACK] File “/home/jattie/klipper/klippy/reactor.py”, line 387, in _dispatch_loop
[IdleTimeout][STACK] File “/home/jattie/klipper/klippy/reactor.py”, line 184, in _check_timers
[IdleTimeout][STACK] File “/home/jattie/klipper/klippy/extras/delayed_gcode.py”, line 34, in _gcode_timer_event
[IdleTimeout][STACK] File “/home/jattie/klipper/klippy/gcode.py”, line 241, in run_script
[IdleTimeout][STACK] File “/home/jattie/klipper/klippy/gcode.py”, line 223, in _process_commands
[IdleTimeout][STACK] File “/home/jattie/klipper/klippy/gcode.py”, line 151, in
[IdleTimeout][STACK] File “/home/jattie/klipper/klippy/gcode.py”, line 161, in
[IdleTimeout][STACK] File “/home/jattie/klipper/klippy/gcode.py”, line 336, in _cmd_mux
[IdleTimeout][STACK] File “/home/jattie/klipper/klippy/extras/fan_generic.py”, line 43, in cmd_SET_FAN_SPEED
[IdleTimeout][STACK] File “/home/jattie/klipper/klippy/extras/fan.py”, line 72, in set_speed_from_command
[IdleTimeout][STACK] File “/home/jattie/klipper/klippy/extras/output_pin.py”, line 66, in queue_gcode_request
[IdleTimeout][STACK] File “/home/jattie/klipper/klippy/toolhead.py”, line 529, in register_lookahead_callback
[IdleTimeout][STACK] File “/home/jattie/klipper/klippy/toolhead.py”, line 323, in get_last_move_time
[IdleTimeout][STACK] File “/home/jattie/klipper/klippy/toolhead.py”, line 267, in _calc_print_time
[IdleTimeout][STACK] File “/home/jattie/klipper/klippy/klippy.py”, line 227, in send_event
[IdleTimeout][STACK] File “/home/jattie/klipper/klippy/klippy.py”, line 227, in
[IdleTimeout][STACK] File “/home/jattie/klipper/klippy/extras/idle_timeout.py”, line 106, in handle_sync_print_time
[IdleTimeout] State transitioned to Printing, updating timer, check_time=0.25
[IdleTimeout] get_status called: state=Printing, printing_time=0.03806874099996094, idle_timeout=1800.0
[IdleTimeout] timeout_handler called: eventtime=1745.069032811, state=Printing
[IdleTimeout] timeout_handler: print_time=1754.4686728525, est_print_time=1754.4690821225, lookahead_empty=True, buffer_time=-0.00040926999986368173
[IdleTimeout] Buffer time > -READY_TIMEOUT, waiting
[IdleTimeout] get_status called: state=Printing, printing_time=0.28829585199991925, idle_timeout=1800.0

3

You can implement blinking LED:s via the template system. This way you can create blinking effects without delayed macros.

You first need to create a template with built in blinking animation. We are using the printer.toolhead.estimated_print_time to get a timestamp that’s used for the blinking.

[display_template my_blinking_led]
param_red: 0
param_green: 0
param_blue: 0
param_white: 0
text:
  {% set frame = (printer.toolhead.estimated_print_time|int % 2) %}
  {frame|float*param_red}, {frame|float*param_green}, {frame|float*param_blue}, {frame|float*param_white}

Then you can set/activate the template to a led via the SET_LED_TEMPLATE command and it will blink all by itself without delayed macros or help. You can send the colors as parameters for the template.

# Set red color blink
SET_LED_TEMPLATE LED=rgb_light INDEX=1 TEMPLATE=my_blinking_led param_red=1

# Set green color blink
SET_LED_TEMPLATE LED=rgb_light INDEX=1 TEMPLATE=my_blinking_led param_green=1

If you want to turn of the led or change to a solid color you can’t use the SET_LED command directly because the template will override the led next update cycle. You first need to disable the template:

# Set blank template to disable template
SET_LED_TEMPLATE LED=rgb_light INDEX=1 TEMPLATE=
# Set solid blue color
SET_LED LED=rgb_light RED=0 GREEN=0 BLUE=1 WHITE=0
4

Thanks for the information, I will try out templates.

I have implemented some python code changes to idle_timeout.py that facilitates the behaviour around the delayed_gcode macros and still transition the states correctly by applying optionally switching the mode of behaviour using a new key in the printer config.

[idle_timeout]
gcode: 
    IDLE_TIMEOUT
timeout: 120
verbose_debug: True
robust_delayed_gcode: True

Is this a useful and desired expansion to add to idle_timeout behaviour?

I have cleaned the code and submitted a pull request.