Random erratic extruder movements at the beginning of the print

Basic Information:

Printer Model: Sapphire Plus (modified)
MCU / Printerboard: MKS Eagle (STM32F407VGT6) via UART3
klippy.log
klippy.log (1.7 MB)

“Timer too close” error happens randomly at the begining of the print. When print started following happes:

Printer homes X and Y with endstops
Printer goes to the center of the bed and homes Z with BLTouch
Printer levels dual-Z bed with Z_TILT_ADJUST
Printer probes mesh with BED_MESH_CALIBRATE
Printer moves to Z0 and starts printing skirt
While printing first 200-300mm of skirt extruder motor makes fast noisy erratic movements and produces huge overextrusion.
Then printer halts with “timer too close”

If I immediately do Firmware Restart and start printing same file again it prints correctly. Error always happens at the start of the print during skirt printing. If print started without this error it always completes succesfuly, error never occurs in the middle of the printing.

Klipper is running on RaspberryPi 4, which is dedicated for this printer only, no other services are running on it, not overheating or undervoltage warning displayed. I tried switching TMC2209 to 1/16 instead 1/256, tried disconnecting USB-Webcam, but it didn’t help. htop does not show any CPU overload when error occurs.

Here is the same issue on Github, which was closed with proposition to create topic here.

1 Like

Hello @PKav !

You may have a look here:

Hello!

I checked everything there. It’s definitely not a hardware issue, because this error occurs only when print starts, never in the middle of the print. And these erratic extruder motor movements before print stops seems to be software issue too.

[stepper_x]
...
microsteps = 256
...

Edit: The above Github issue is unrelated

I already tried 1/16 microstepping and nothing changed. Same error, same weird extruder behavior.

It happens only at the begining of the print while printing skirt at 40 mm/s. It never happens later, even when printer does G0 at 180 mm/s

According to the performance chart in fluidd, MCU load never exceeds 15% even during fast movements.

I’m not sure what is causing this but you seem to exceed your MCU bandwidth by a significant factor. For some details on such graphs see Advanced Trouble-Shooting / Graphing Klipper

According to this graph UART between MCU and Host is used up by 1000%, but how is it possible? It’s not USB, it’s UART at default 250000 baudrate? How can it go above 100%?

And how can I do further diagnostics? Should I dump all data between MCU and Host?

To quote from the link posted above:

Bandwidth denotes the saturation of the communication line between Host and MCU. Scaling is based on a 250000 baud serial line. This means 100% here, when using a much faster USB connection, is not necessarily an indication for problems

(why the hell do we put down such information if nobody even cares to read it, when pointing to it)

With a factor of 10, we could slowly come into the region of a problem (at least this is the first time I see such high values).

Well, check it systematically.

  • Does it occur on every gcode file?
  • Do you use insanely high resolution files?
  • Weird slicer settings?

I guess, this is valid for USB, because USB-emulated COM-ports do not have baudrate. But I’m using UART and default baudrate. Three 150mm long wires: RX, TX and GND. So it shouldn’t go above 100%.

Yes, it can occur on any G-Code file, but not every time. It can happen on the second print after Klipper start, or it can print 5 times in a row without errors. It happens during first extrusion movements, when skirt is printed, but if I restart Klipper and print same file again no errors occur and print finishes successfully. So it doesn’t seem to be G-Code specific.

No, it can occur even on calibration cube.

I tried SuperSlicer and Cura. Error sometimes occurs on both, always during the first extrusion movements.

If you use a direct serial connection and not USB then the value is definitively an issue.
The graph is scaled 250 kbits/s and USB could go much faster but direct serial not.

Apart from this, I have no further idea, except the general comment that a microstepping of 256 is an overkill without any added value (on the contrary, can lead to unwanted effects due to high data rates to the stepper drivers).

I increaced baudrate to 1000000, but issue happened again.

Then I tried lowering microstepping rate to 4 for extruder motor. Issue happened again, but no error occurred, printer just keeps overextruding and weirdly moving extruder producing high noise.

So it seems like “timer too close” error is just a consequence. Klipper comands extruder to move wieredly, it overloads UART and error occurs.

I’ll try to collect longer log with erratic extruder movements and post here.

Please do not play with such. The defaults of Klipper work on thousands of installations and this will potentially only introduce further issues.

Hello again.

Here’s my new log with normal microstepping. Now error occured after about one minute of printing. Extruder did noisy erratic movements and produced overextrusion during corners. Straight lines seem to be OK. I guess, it might be somehow related to Pressure Advance handling. As usual, after Klipper and Firmware restart it printed same G-Code flawlessly.
Klippy_4.log (6.4 MB)

reduce your velocity

Velocity? My printer is limited to 180 mm/s and this occurs while printing skirt at 40 mm/s. It does not seem to be velocity related.

Hmm, this is a bit strange:

  • Your error message is Rescheduled timer in the past

  • This is caused by your extruder stepper (look at the i= value and see above link):

  • Neither your PA value nor the stepper settings would indicate this, so I’m not sure what is happening

  • Try deleting

    instantaneous_corner_velocity = 1
    max_extrude_only_distance = 1400
    max_extrude_only_velocity = 75
    max_extrude_only_accel = 10000
    max_extrude_cross_section = 99999
    
  • Set pressure_advance_smooth_time = 0.01 to 0.04

Yes, but I guess it’s just a conseqence of very high speed erratic extruder movements. If I set extruder microstepping to 256 it occurs during 5 seconds after print start, but if I set it to 4 it prints for much longer.

I’ll try your settings and post my results. I’ll also try to film those movements, maybe it will help

Hello again.

Issue still persists even with new settings. I added “max_extrude_cross_section = 99999” back, because otherwise I get following error:

// Move exceeds maximum extrusion (9.173mm^2 vs 0.640mm^2)
// See the 'max_extrude_cross_section' config option for details
23:23:45 
!! Move exceeds maximum extrusion (9.173mm^2 vs 0.640mm^2)

I managed to film it. Sorry for messy wiring, this printer is not finished yet, will wire everything after fixing this issue. WARNING: Loud extruder motor sound!

YouTube video

klippy (2).log (730.9 KB)

Changing a setting in an attempt to simply ignore an error is never a good idea. The error is telling you there is a problem with your gcode. It could be one of several problems such as the nozzle diameter or filament diameter configured in your slicer, or it could be a mismatch between absolute and relative extrusion mode. You need to look into what is wrong and change the max_extrude_cross_section back to a sane value.

This is not GCode issue. If I restart Klipper and print same file again it prints flawlessly.