Bug in 1.1.9 : Slowdown on small segments (SD or USB)

[houseofbugs]

I have the latest (as of 8:15PM CST 7/30/18) 1.1.x bugfix running on a few machines. Both have bilinear leveling enabled. Some machines are running the 1284p chip and others are running the 2560.

I am going to run a test and disable the new junction deviation feature and see if the issue persists but it is doing random pauses over SD and USB printing. Here is a snippet of the terminal output when it happens:

Send: N3543 G1 X96.976 Y110.644 F7200*74
Recv: ok
Send: N3544 G1 E3.0000 F3000*3
Recv: ok
Send: N3545 G1 X97.067 Y110.734 E0.0086 F720*7
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: ok
Send: N3546 M105*19
Recv: ok T:215.05 /215.00 B:50.43 /50.00 @:44 B@:0
Send: N3547 G1 X96.976 Y110.644 E-3.0000 F128*37
Recv: ok
Send: N3548 G1 X105.980 Y114.556 F7200*119
Recv: ok

It shows busy: processing when this happens but the print continues after a few seconds. I am running a modified version of the bugfix (my Unified branch) but it did it as well on my Tornado with the regular bugfix branch as well.

I am going to be digging into this more over the next few days and was wondering if anyone else is seeing the same issue with the latest bugfix version.

This Gcode does it at the front of the benchy right before it does the infill: https://content.timothyhoogland.com/files/ShareXUpload/3DBenchy.gcode

I will be disabling the new junction deviation and testing with that disabled and the new SCurve Acceleration enabled and disabled but my Ender2 with the 1284P is doing it with the SCurve disabled.

Also going to see if it does it with Cura as I am only using S3D at the moment.

[houseofbugs]

Digging into it more I noticed that the "pausing" is that the E is retracting VERY slowly despite the slicer setting set high. I am still toggling on and off other settings. Will post more details in the next few days as I test more.

[houseofbugs]

Update. Disabling/Enabling any combination of the S Curve and Junction has no effect. Trying different GCode settings in S3D to see if that has any influence.

[houseofbugs]

Slicer settings have no effect. It seems to do it on very SMALL segments. The extruder motor is moving VERY slowly when this happens.

There are small parts on the 1st layer where it fills in a tiny spot and that is where it has issues. Larger moves are not a problem.

Gcode used: https://content.timothyhoogland.com/files/ShareXUpload/NEW%20SETTINGS%202x%20piBase_fixed.gcode

[houseofbugs]

Video of the issue: https://www.youtube.com/watch?v=exf9ktlKgxA

[houseofbugs]

I've been digging and it doesn't do it on Cura because its not making these tiny extrusions. I'm tuning my S3D settings to see if this has any effect. But its pausing on these very tiny extrusions.

[houseofbugs]

Changing from 3 to 2 shells fixes it with S3D but there is still an issue with the motion code.

Any ideas? Stepper pulse settings are what I am going to start changing next. Using A4988 settings ATM.

[thinkyhead]

Now that 1.1.9 is released, we might see more cases where the motion code gets confused, caused by factors we didn't catch in our testing so far. I hope we can find the cause and it's nothing too complicated! Any ideas @ejtagle ?

[ejtagle]

@houseofbugs : Disable Linear advance (recompile without LA) and recheck. I do suspect LA to be the problem here...

[AnHardt]

Could you please repost your log from the first message without the checksums or properly quoted as code?

Send: N3545 G1 X97.067 Y110.734 E0.0086 F7207

is locking 10 times too slow. (Assuming the last 7 to be the checksum)

[houseofbugs]

@AnHardt I'll have to re-run the print and log. I don't have the logs at the moment.

@ejtagle This was with LA disabled. It doesn't matter if it's on or off.

[AnHardt]

No. You are the one having access to the source of your first message - who can edit it. The '*' in the log are translated to formating instructions. Either remove the stars end everything up to the lines end, or set the whole block in ``` log ```

See https://guides.github.com/features/mastering-markdown/

[thinkyhead]

Edited OP log for prettiness…

[houseofbugs]

Still trying to figure out what's going on with this issue. Is anyone else looking into it?

[houseofbugs]

https://pastebin.com/Vm9TM1dU

Heres a print log from the pause. I am chaning up different settings to do with the buffers and the segments. Haven't found anything that fixes it yet. I am going to review the planner code and compare to the 1.1.8 base to see if I can isolate the change(s) that are causing this bug.

I flashed all 15 machines here that all have varying hardware but 2560 and 1284p boards both exhibit this issue. So not hardware specific.

[houseofbugs]

Things tested and didn't have any effects:

• ADAPTIVE_STEP_SMOOTHING enabled
• DEFAULT_MINSEGMENTTIME changes 20000, 25000, 50000
• TX_BUFFER_SIZE 4 from 0

Still digging. Going to start messing with the stepper driver values next.

[houseofbugs]

Stepper delays and other stepper related settings had no effect on this.

[houseofbugs]

@ejtagle LA on or off it does the pausing. Already ruled that out.

Also disabled ABL on there and still pauses. Running out of ideas here.

[celogeek]

The issue is also present on bugfixes-2.x

[thinkyhead]

I'll dive into this tonight and see if I can figure out what's going on. The updated planner / stepper code is pretty new and quite complex. We're not surprised that it still has some rough edges.

[houseofbugs]

This is the only issue that I've seen so far. The new motion is pretty great outside of this odd bug. The prints on the machine with the new jerk and accel handling with LA 1.5 are night and day between 1.1.8. Let me know if there are other things I can test for.

I think I've hit my knowledge limit but then again I was working at 4AM trying to analyze the code to see if there was something that stood out to me as a possible cause.

@thinkyhead if I need to make a coffee fund donation let me know. :P

[Eganwp]

Can someone test toggling “gap fill” and “thin wall extrusion” in the drop down in the advanced tab of S3D? My guess is this is why it’s happening and doesn’t happen in Cura. I’d test it but I’m at work.

[mitchdetailed]

Ill test it out when I get home tonight @eganwp , although someone will likely beat me to the test.

[mitchdetailed]

Update: Adjusted S3D settings in 'Advanced' 'Internal Thin Wall Behavior' to 'Allow gap fill'

Didn't have any pause or hesitation.

[Eganwp]

Awesome, I figured that might be where the bug is coming from! Thanks for testing it for me. I’m home from work now but in the middle of Marlin FW flashes.

Travis

On Aug 16, 2018, at 9:25 PM, mitchdetailed notifications@github.com wrote:

Update: Adjusted S3D settings in 'Advanced' 'Internal Thin Wall Behavior' to 'Allow gap fill'

Didn't have any pause or hesitation.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub, or mute the thread.

[houseofbugs]

@Eganwp any idea on where to look? I can start poking around in the code and testing possible fixes.

[thinkyhead]

@houseofbugs — Do any of the tips above help with the stuttering you saw? Another thing you might try —when you see this pausing— is to send M111 S8 to enable "Dry Run Mode." This will stop extrusion from happening, so of course you don't want to do this on an important print! But if turning off extrusion makes the weird pauses stop happening, that will confirm my suspicion that something about the E axis is throwing off the planner.

[Deneteus]

@houseofbugs What is your E-Jerk Setting set to on the printers that are experiencing this issue with 1.1.9? Is it set to 5? Can you set it to 25 and see if it still happens?

[celogeek]

In my case I have JUNCTION_DEVIATION activated

[dot-bob]

One thing to note both examples of your attached GCODE have issues. I see instances where your retraction is very very slow. Like 0.05 mm/s. So with a distance of -3mm it can take 60 seconds to complete the retraction. Do a search for single digit feed rates and you will see what I mean (i.e G1 X71.447 Y131.784 E-3.0000 F2)

[celogeek]

For sure this is not good. is they a way to limit too slow extrusion ? may be a feature ;)

[houseofbugs]

@Deneteus I'll play with the jerk. When we have junction deviation on is there a way to have the E only use the traditional jerk control or set a different one?

@dot-bob

I did see this one:

G92 E0 G1 X71.447 Y131.784 E-3.0000 F2

This is after it. I wonder why S3D is making that low feedrate.

Send: N3699 G1 X54.353 Y127.418 E-3.0000 F2767*22 Changing monitoring state from "Printing" to "Cancelling" Recv: echo:busy: processing Recv: echo:busy: processing Recv: echo:busy: processing Recv: echo:busy: processing

This is a slowdown. I cancelled the print. Feedrate is high there.

[houseofbugs]

Maybe this is an S3D issue? I'll start poking around. I ran G1 E-3.0000 F2 and it took about 12 seconds to complete. I didn't take into account the planner buffer when I was looking at the terminal. That would make sense because the line of code causing the issue is what it was actually processing at the moment.

[AnHardt]

Is looking like an error on both sides. S3D should not send stupid things like G1 E-3.0000 F2, meaning "Move the extruder backwards 3mm with a speed of 2mm/minute", what should last 90 seconds. And Marlin should not be ready with that after 12s but after 90.

[houseofbugs]

So I re-sliced the same files. Profile same as previous code aside from support settings and temps. No super slow E movements....

https://content.timothyhoogland.com/files/ShareXUpload/Base_fixed.gcode

I have not updated my S3D installation. Same PC. Same profile aside from the support and temp changes. The same small segment is still there. What changed? I have no idea....headdesk

[thinkyhead]

And Marlin should not be ready with that after 12s but after 90.

I believe Marlin might have a limit not only on fastest speed, but also on slowest allowed speed. I'm not too surprised that it could be speeding up a tiny E move that was going to take 90s by 7-8 times.

[AnHardt]

We do have a limit to limit the time in between of two pulses. Else the timer register needs to have more bits. Or something like that.

[houseofbugs]

While you guys may have some ideas on handling Marlin changes to address this I found there is a S3D bug that is causing it.

Has the slow retract: https://content.timothyhoogland.com/files/ShareXUpload/3DBenchy.gcode Does NOT have the slow retract: https://content.timothyhoogland.com/files/ShareXUpload/3DBenchy2.gcode

Apparently if you have "Perform retraction during wipe movement" this causes the bug. I disabled it and the issue is not appearing.

S3D Issue: https://forum.simplify3d.com/viewtopic.php?t=8113

[Eganwp]

Good find Tim. I’ve been using single the single line thin wall fill instead of gap fill fix I found a couple weeks ago. Are you using linear advance & the new jerk & accel algorithms btw? I can’t get rid of bulging corners no matter what settings I use in 1.1.9 unless I don’t use the new jerk & accel features.

Sent from my iPhone 8

On Aug 30, 2018, at 6:20 PM, Timothy Hoogland notifications@github.com wrote:

While you guys may have some ideas on handling Marlin changes to address this I found there is a S3D bug that is causing it.

Has the slow retract: https://content.timothyhoogland.com/files/ShareXUpload/3DBenchy.gcode Does NOT have the slow retract: https://content.timothyhoogland.com/files/https://content.timothyhoogland.com/files/ShareXUpload/3DBenchy2.gcodeShareXUpload/3DBenchy2.gcode

Apparently if you have "Perform retraction during wipe movement" this causes the bug. I disabled it and the issue is not appearing.

S3D Issue: https://forum.simplify3d.com/viewtopic.php?t=8113

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub, or mute the thread.

[mitchdetailed]

Alrighty, simple rectification, but also still curious why it occurs with retraction while wiping enabled. Bravo Tim

On Thu, Aug 30, 2018, 7:20 PM Timothy Hoogland notifications@github.com wrote:

While you guys may have some ideas on handling Marlin changes to address this I found there is a S3D bug that is causing it.

Has the slow retract: https://content.timothyhoogland.com/files/ShareXUpload/3DBenchy.gcode Does NOT have the slow retract: https://content.timothyhoogland.com/files/ShareXUpload/3DBenchy2.gcode

Apparently if you have "Perform retraction during wipe movement" this causes the bug. I disabled it and the issue is not appearing.

[image: simplify3d_2018-08-30_19-16-32] https://user-images.githubusercontent.com/25088191/44886045-c1663c80-ac89-11e8-914d-e56b3c5199f4.png

S3D Issue: https://forum.simplify3d.com/viewtopic.php?t=8113

— You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub https://github.com/MarlinFirmware/Marlin/issues/11416#issuecomment-417509397, or mute the thread https://github.com/notifications/unsubscribe-auth/Aj2mrpyaFjLWcSM_5MkRheSk27hDCjoCks5uWIFhgaJpZM4VncXN .

[houseofbugs]

I just send S3D a bug report. Also made a post on the TH3D site here: https://www.th3dstudio.com/simplify3d-retraction-during-wipe-bug-causes-printer-slowdown/

Links back to this issue as well. Thank you everyone. Team effort! :D

[ejtagle]

@AnHardt : You are absolutely right. There is a limit on the minimum speed (perhaps, with the new stepper code, the limit could be lowered) but, it just does not make sense to print at such low speeds 👍

[Drammy]

So I guess the slow speed is the slicer trying to divide the retraction distance into the extrusion distance to ensure it 'wipes during retraction' ?

[celogeek]

Yes indeed. It retract during the moment. And it does it progressively.

[github-actions[bot]]

This issue has been automatically locked since there has not been any recent activity after it was closed. Please open a new issue for related bugs.