Timer too close only when print is finished

[iLikeMilk3064]

Basic Information:

Printer Model: Voron 0 / TinyM Mod
MCU / Printerboard: Btt Octopus Pro V1.1 H723
Host / SBC
klippy.log

klippy.zip (1.0 MB)

Hello everyone!

After updating my printer to klipper version v0.13.0-229 the printer stops at the end with the “Timer too close error”

During the print, there are no problems, no matter, how long the print takes. Before updating klipper to version v0.13.0-229, everything worked fine with no error. I have already updated everthing and replaced the SD-Card.

Please help me figure out what´s wrong, where else to look?

[EddyMI3D]

On every sliced file?

[iLikeMilk3064]

Yes, I tried at least 5 files

[EddyMI3D]

The usual issues are listed here: Timer too close

BTW: HOLD_CURRENT with the steppers is not recommended.

[nefelim4ag]

Hmmm, something strange, it always dies on the:
queue_digital_out oid=22 clock=445285424 on_ticks=0

Sent 99 5504.017080 5504.017080 13: seq: 1c, queue_digital_out oid=22 clock=1014871658 on_ticks=0
Dumping receive queue 100 messages
...
Receive: 99 5504.017496 5504.017080 12: seq: 1d, shutdown clock=1040419231 static_string_id=Timer too close
...
Sent 99 9953.251806 9953.251806 13: seq: 18, queue_digital_out oid=22 clock=445285424 on_ticks=0
Dumping receive queue 100 messages
Receive: 96 9953.159649 9952.943025 15: seq: 18, analog_in_state oid=18 next_clock=563659008 value=29975
Receive: 97 9953.169607 9952.943025 15: seq: 18, analog_in_state oid=19 next_clock=568859008 value=30702
Receive: 98 9953.229677 9952.943025 15: seq: 18, analog_in_state oid=25 next_clock=600059008 value=27446
Receive: 99 9953.252281 9953.251806 12: seq: 19, shutdown clock=459527199 static_string_id=Timer too close

(I suspect it is a fan, because there is not a lot of such cmds in the queue, and the last one is: queue_digital_out oid=22 clock=1039342246 on_ticks=1)

Something from this:

[gcode_macro _END_PRINT]
gcode = 
	G91
	G1 Z10
	G1 E-5 F3000
	
	G90
	G1 X0 Y0 F5000
	
	M84
	M106 S0
	M104 S0
	M140 S0
	SET_FAN_SPEED FAN=exhaust_fan SPEED=0.0
	
	_SET_FLAP_ENABLED ENABLED=0

Does that.

Probably it is one of the fans.

This sounds quite strange.

If you can reproduce this reliably (I suspect you don’t have to really print something, just dummy print and then end macro).
You can try to perform the: Klipper Versioning, Downgrading, and Bisecting

To find where it has been broken.

It is possible that recent refactoring introduced a bug with Pin PWM scheduling.

Thanks.

[iLikeMilk3064]

Thank you, it is an issue with the _END_PRINT macro, which calls the _SET_FLAP_ENABLED ENABLED=0 macro.

I changed it to:

[gcode_macro _END_PRINT]
gcode:
  G91
  G1 Z10
  G1 E-5 F3000

  G90 ;Absolute pos
  G1 X0 Y0 F5000 ;Wipe out

  M84 ;Disable Motors
  M106 S0 ;Turn fan off
  SET_FAN_SPEED FAN=exhaust_fan SPEED=0.0
  
  M104 S0 ;Turn off hotend
  M140 S0 ;Turn off bed

Not sure why the error occurred after the update.

[koconnor]

This issue looks like a regression introduced in the recent flush rework ( Simplify host motion flushing by KevinOConnor · Pull Request #7001 · Klipper3d/klipper · GitHub ).

The oid=22 is the manual_stepper enable pin. The issue appears to be that explicit MANUAL_STEPPER STEPPER=flap_stepper ENABLE=x commands no longer work properly. The code was expecting that all steps are generated after each command and thus all stepper enable/disable commands will be synchronous with previous motion commands. Now that the steps are lazily generated, the “just in time” stepper enable check (via flush callbacks) can be run out of order with the explicit enable/disable commands. Thus we get into a situation where a subsequent motor disable can be sent out of order with respect to a prior motor enable, which causes the micro-controller to correctly report an error.

The underlying problem looks to be similar to the problem raised in Fix flushing bug in manual_stepper by KevinOConnor · Pull Request #7019 · Klipper3d/klipper · GitHub .

I’ll need to think about how to best fix this.

-Kevin

[koconnor]

Hopefully this will be fixed with Unify and improve explicit stepper enable handling by KevinOConnor · Pull Request #7029 · Klipper3d/klipper · GitHub .

-Kevin