stutter on large circles

[sniperlucian]

I am printing a lamp starting 7cm at bottom up to 10 cm diameter at top and 10 cm high, 1mm thick = 2 perimeters. At the last cm, with the biggest diameters, klippy starts to stutter, accelerating and stopping at each segment, also extruder is accelerating and deaccelerating. This leaves unfortunately an uneven surface.

Could it be that the segments are to large to be recognized by lookahead?

Slic3r Prusa Edition 1.4.0.1

klippy_circle_stutter.log

[mamoit]

how many vertices does a horizontal section of the object have? I have had that behavior when the amount of gcodes sent to the mcu are too large. If you have for eg a cylinder with 1k vertices and each perimeter is very short, then the number of G1/G0s sent per second (read edge of the layer) will be in such amounts that the communication layer won't be able to handle it. Try lowering the resolution of your object slightly, or maybe increase the communication baudrate (this may lead to communication failure though).

[jakep82]

Using virtual SD will fix this problem. If the file is fed directly to Klipper it can process the g-code significantly faster. Octoprint can't read and send the g-code fast enough to keep up with circles that have hundreds or thousands of very short line segments.

[mamoit]

@jakep82 That's an awesome tip! Will try to do a stress test tomorrow.

[jakep82]

I first discovered this problem and the solution on Redeem which is the firmware for Replicape. I've done my own stress testing, and it makes a huge difference on some prints. I've actually switched to a Pi Zero W just because this feature works so well that I no longer need the power of a Pi 3.

[mamoit]

Impressive!

[mamoit]

So... 5mm radius "circle" with n points in the circumference, and a feedrate of 60mm/s. Hardware is a raspberry pi 3b, running octoprint.

VSD -> virtual sd card Octo -> using octoprint

| N points | ~ lines/second | VSD     | Octo     |
|----------|----------------|---------|----------|
| 4        | 3              | OK      | OK       |
| 8        | 6              | OK      | OK       |
| 16       | 12             | OK      | OK       |
| 32       | 24             | OK      | OK       |
| 64       | 49             | OK      | OK       |
| 128      | 98             | OK      | OK       |
| 256      | 195            | OK      | Breaks   |
| 512      | 391            | Stutter | Unusable |

[sniperlucian]

How did you generate the g-code for this test?

[mamoit]

My own little script: https://gist.github.com/mamoit/a51d513ec2d13f78ea0db2df3ab7771a

[KevinOConnor]

My own little script:

Interesting. If you gather the log from the test, you can check what klipper reported its load as. The graphstats.py script can plot the mcu and host buffer load (see https://github.com/KevinOConnor/klipper/blob/master/docs/Debugging.md#generating-load-graphs ). The print_stall value in the log is also interesting - it reports the number of times the host software felt it needed to delay the print to get more moves queued.

In general, the Klipper results look okay to me - 512 segments per 5mm circle is a bit excessive (a line segment every 60 microns), so I'm not sure it's worth optimizing for this case. One could use a more powerful host cpu if it was really important.

-Kevin

[mamoit]

So... I re-ran it, twice from octoprint, and twice from the virtual_sdcard. here are my results:

Octoprint

Virtual SD Card

You can clearly see the 8 different runs, being that the last ones choke. Every board will eventually stop handling the gcode throughput. Currently the bottleneck seems to be on the octoprint side of thing. There are issues with octoprint comunicating with Marlin too, but those are mostly related to the ping pong protocol and the need for an OK on every command sent over the wire. With the soon to be implemented G2 of Slic3r, the amount of short moves to be streamed will reduce dramatically for most prints.

For me this is a non-issue until further notice :smile: Just a fun stress test

[KevinOConnor]

Odd that you're seeing a stutter on the virtual sd run - the load graph doesn't show a problem. Feel free to attach the log from a run with a stutter on virtual sd.

Every board will eventually stop handling the gcode throughput.

Indeed.

-Kevin

[mamoit]

I will do an even worse stress test tomorrow ;)

[sniperlucian]

tried you stress test and didnt had any trouble, except going with higher vertics.

9:00 - 9:05 5mm. via Repetier Host 9:05-9:20 100m diameter. via Repetier Host 9:25 - 9:40 50mm diameter and Vertics: 1024, 2048, 4096, 8192, 16384 Repetier Host 9:40 - 50mm and Vertics: 1024, 2048 with virtual SDCARD

Even though here is no host buffer filling up, here is still massive stutter even with virtual SDCARD.

Here are short stall and I dont understand where the bottle neck is. Is it the max. speed of the serial wire? Maybe an upgrade to STM32 and CDC solves this issue?

Just reading the logfiles stalled_bytes goes up to > 1000 bytes ...

[mamoit]

@sniperlucian what is your host hardware? My results where from a raspberry pi 3b (plus I think...)

[mamoit]

This is the graph of the original log you posted (the interesting part of it). I don't really know what to make of it to be honest, other that you suddenly started to send a lot more data towards the end (~6:30) and had a couple of huge spikes on the host buffer usage.

[KevinOConnor]

@mamoit - I ran your test case locally. I tracked down the problem with the higher vertex count - it's actually a problem with the test case. At higher vertexes, the limited precision of the XY coordinates in the gcode file is leading to non-ideal angles between vertices. Change the assorted {x:.4} output to {x:.12} in the script and the problem goes away for me. That said, I've no doubt you could increase the vertex count to the point where it will break klipper.

@sniperlucian - not sure what the original problem you are seeing is from. The original log showed two print stalls early in the print, but otherwise seems fine. (Note - stalled_bytes is totally unrelated and it does not indicate a problem - the information you are looking for is in print_stall.) You might want to upload a video of the stalls you are seeing - the problem may be due to commands in the gcode that are resulting in klipper changing speeds.

-Kevin

[mamoit]

:man_facepalming: for the .4... Just going to remove it. Is there a limit to the number of decimal places?

[mamoit]

Ok, way better, this time around, started printing from the virtual_sdcard from 32 vertex, and it handled up to 2048 vertex. At 4096 klippy died. Ran this test twice, it happened around the same spot.

Hardware: MKS 1.4 (arduino mega 2560) baudrate 250k

Log: klippy.log

Plot

This is way more performance than what I ever thought I could get from a printer. Marlin slows down waaaay earlier.

[KevinOConnor]

At 4096 klippy died.

Yeah - I ran into that as well. I uploaded a fix last night (commit 82738955).

That said, it'll still error if you increase the vertices further. (If the host cpu load becomes ridiculously high, then the heuristics in the host software to detect that load may not get enough cpu time itself.)

-Kevin

[mamoit]

Just pulled it and tried it. Now it is stuttering at 1024?!? Keeps hanging more and more frequently until 8112, when it starts spamming:

MCU 'mcu' shutdown: No next step
This is generally indicative of an intermittent
communication failure between micro-controller and host.
Once the underlying issue is corrected, use the
"FIRMWARE_RESTART" command to reset the firmware, reload the
config, and restart the host software.
Printer is shutdown

Another run's log (started stalling at 1k): klippy.log

[sniperlucian]

@mamoit I having ubuntu on a quad Xenon as host. repetierhost consumes 10%, even in VirtualSDCard mode. Klippy max. < 7%.

@KevinOConnor I would expect a nice circular movement with constant speed. What I have are very strong randomly speed variations. From very low variation till very strong, like very short zigzag infall lines. I will try to upload a video later.

I plotted the layer and the segments and here are actually some spikes. But not as high as I would expect the variations in speed I can see during printing. Look-ahead should smooth that out anyway ?!!?

I have activated pressure advance - might be an interaction?

(The very big spikes are the shift between the perimeter)

[mamoit]

@sniperlucian That hardware is quite a beast for the task :laughing: comparing it with an Rpi is not even worth it. Have you ran the latest version of my code? I had an approximation mistake that was detected by @KevinOConnor.

[KevinOConnor]

I would expect a nice circular movement with constant speed. What I have are very strong randomly speed variations. From very low variation till very strong, like very short zigzag infall lines. I will try to upload a video later.

Can you upload the gcode file? I fear the slicer may have emitted a zigzag movement for the top layer. That is, you may not be getting a smooth circular movement because the printer may not have been commanded to move in a smooth circle. If you bring up that layer in the "layer view" or in a gcode viewer, does it show circular movements? Another thing to look for is changes in the extrusion flow rate. Retractions in the middle of the layer could also be an issue.

The pressure advance setting does not impact the move planning, so should have no impact here.

-Kevin

[sniperlucian]

I thought that first too - but the top layer actually doesn't have those spices. The plots are from layer -5.

lamp.txt

[KevinOConnor]

Unfortunately, the slicer did a poor job producing g-code for this object. At the lower levels there are lines like the following:

G1 X178.543 Y69.903 E224.5867
G1 X179.241 Y70.566 E224.6283

which are XY moves of almost exactly 0.96mm and E moves of 0.0416mm. Later in the file, though, there are moves like:

G1 X204.04 Y51.282 E12766.53
G1 X204.872 Y52.283 E12766.59
G1 X205.677 Y53.305 E12766.64

here, the E precision is truncated and it results in consistent XY moves of 1.301mm but dramatically different extrusion amounts (it changes from .05mm to .06mm on each segment).

As a result, Klipper does not (and should not) perform look-ahead between these moves. Because each move is different it results in lots of speed ups and slow downs which is altering the finish quality.

Not sure why the slicer is doing the above. -Kevin

[sniperlucian]

Do you mind if I post your findings in sli3er prusa forum?

[supermerill]

7 digits of precision in base 10. mantisse of a float : 23+1 bits. 2^24 = 16 777 216. So it's because the slicer use float and not double. or maybe a precision problem when writing it up...

It's created with slic3rPE? I can't replicate the issue, it works fine with me. (G1 X119.994 Y111.658 E11028.78524)

[sniperlucian]

good catch.

Slic3r Prusa supports relative E distances. This would decouple resolution from absolute position.

Does klippy support relative E ?

[oderwat]

I use Cura in relative Extrusion mode with Klipper. So it does support this. But I like more how S3D handles extrusion, which basically uses absolute extrusion but resets it at loops.

[KevinOConnor]

Yes, you can report it upstream. Yes, Klipper supports relative E distances.

-Kevin