3.5.0rc1: Input shaping causes layer shifts!?

adrian

@gloomyandy
gcode:
https://fastupload.io/K2qmozelOP3eK4A/file

NeoDue

@dc42 thanks! I have rewritten the file to save its data in a file:

; Parameters to control motion to sense endstops. Copy these from the homing files.
var xHomingSpeed = 500
var yHomingSpeed = 320
; uncomment and set current if stall homing is used
;var xHomingCurrentPercent = 25
;var yHomingCurrentPercent = 25


T0 ; activate correct Tool - the one on the X axis

G91                      ; relative positioning
G1 Z5 F360               ; get some distance between nozzle and bed / part
G90                      ; absolute positioning

; Go to bed centre
G1 X{(move.axes[0].max + move.axes[0].min)/2} Y{(move.axes[1].max + move.axes[1].min)/2} F3000

; Reduce currents in case we are using stall homing - uncomment if stall homing is used
; M913 X{var.xHomingCurrentPercent} Y{var.yHomingCurrentPercent}

M400

; Check Y axis
if sensors.endstops[1].highEnd
  G1 H4 Y{move.axes[1].max+20} F{var.yHomingSpeed}
  echo >>"axisshiftcheck_results.txt" "Y homing error was "^{move.axes[1].machinePosition - move.axes[1].max}^""
  echo "Y homing error was", move.axes[1].machinePosition - move.axes[1].max
  G1 Y{move.axes[1].max-20}
else
  G1 H4 Y{move.axes[1].min-20} F{var.yHomingSpeed}
  echo >>"axisshiftcheck_results.txt" "Y homing error was "^{move.axes[1].machinePosition - move.axes[1].min}^""
  echo "Y homing error was", move.axes[1].machinePosition - move.axes[1].min
  G1 Y{move.axes[1].min+20}

; Check X axis
if sensors.endstops[0].highEnd
  G1 H4 X{move.axes[0].max+20} F{var.xHomingSpeed}
  echo >>"axisshiftcheck_results.txt" "X homing error was "^{move.axes[0].machinePosition - move.axes[0].max}^""
  echo "X homing error was", move.axes[0].machinePosition - move.axes[0].max
  G1 X{move.axes[0].max-20}
else
  G1 H4 X{move.axes[0].min-20} F{var.xHomingSpeed}
  echo >>"axisshiftcheck_results.txt" "X homing error was "^{move.axes[0].machinePosition - move.axes[0].min}^""
  echo "X homing error was", move.axes[0].machinePosition - move.axes[0].min
  G1 X{move.axes[0].min+20}

; Restore motor current
M400
M913 X100 Y100
M400

G91                      ; relative positioning
G1 Z-5 F360              ; move bed back to where it was
G90                      ; absolute positioning

... and have added an M98 command into the appropriate places of the print file. I will let that run tonight.

NeoDue

@dc42 1st attempt:

Y homing error was 0.000
X homing error was 0.012
Y homing error was -0.012
X homing error was -0.012

Those offsets are within the tolerance of the endstops...

I will repeat the test once or twice tomorrow, but it seems it is indeed caused by the filament.

Edit: the printer had likely IS disabled in this test, please ignore it.

NeoDue

@dc42 test prints will follow tomorrow. I finished two test runs this evening - only to find out I accidentially verified that there is no issue when IS is disabled...

dc42

@NeoDue said in 3.5.0rc1: Input shaping causes layer shifts!?:

Edit: In case it matters: the "test-blob" I found occurs on layer 2, 4 and 6 in the middle of the last line of the solid infill of my test part. Prusaslicer decided in its wisdom to split this line into two long pieces which are connected by two very short ones. This is the gcode that causes the blob:

; (tool position before this snippet begins: X-7.877 Y28.826)
G1 X-7.823 Y28.723 E.00266
G1 X-7.815 Y-7.037 E.75823
G1 X-7.867 Y-7.142 E.00277
G1 X-7.919 Y-7.246 E.00303
G1 X-7.922 Y-42.252 E.91196

Thanks, that's useful information. I will investigate what is happening there.

NeoDue

@dc42 Okay, here is the full set of tests, three with IS off and three with IS on - it is nothing extruder related after all

test 1 (IS most likely off)
Y homing error was 0.000
X homing error was 0.012
Y homing error was -0.012
X homing error was -0.012

test 2 (IS off)
Y homing error was 0.000
X homing error was 0.012
Y homing error was -0.012
X homing error was -0.012

test 3 (IS off)
Y homing error was -0.012
X homing error was 0.000
Y homing error was -0.012
X homing error was 0.000

test 4 (IS on)
Y homing error was 0.000
X homing error was 0.012
Y homing error was -0.012
X homing error was -0.788

test 5 (IS on)
Y homing error was -0.012
X homing error was 0.000
Y homing error was -0.012
X homing error was -0.012

test 6 (IS on)
Y homing error was -0.012
X homing error was 0.000
Y homing error was -1.613
X homing error was -3.188

That means something still must be wrong with Input shaping... but what?

And one more thing puzzles me: the offsets measured here are quite a bit lower than the amount of layer shifts I get if I print the real part.
The only logical reason I can think of that might cause this would be that... something... related to Input Shaping causes a significant temporary loss of torque in the steppers which causes them to loose some steps in free air, but also causes them to be more vulnerable against the slightly larger blobs which then result in more lost steps? The EMF calculator says the stepper configuration is okay. I had doublechecked that when I saw increasing motor currents did tendencially rather in- than decrease the layer shift occurrances...

oliof

@NeoDue what IS algo are you using? I haven't tested thoroughly yet but I feel ZVDD may cause more issues than MZV.

NeoDue

@oliof I used EI2 for all recent test cases here - measuring with the input shaping plugin gave me the result that either ZVDDD or EI2 should be the best two options for my printer. Which one will be ultimately the best is something I need to find out when I can finally use it

oliof

@NeoDue I haven't tried EI2, but I have had much less issues with MZV than with ZVD. With my squirqle test, ZVD seems to be applied somewhat more irregularly than MZV; I would suspect that the variations in speed could affect extrusion as well which might contribute to the blobbing / extrusion irregularities.

NeoDue

@oliof at least according to my tests with the accelerometer MZV seemed quite a bit less effective, that was the reason why I had discarded that one. The options the Duet offers should work after all

But I will keep that in mind, thanks for the hint.

NeoDue

@dc42 one more test: I wanted to check if the TMC stepper maybe detects skipped steps while running the test and ran a M569.2 P0:0 and P0:3 R{0x73} (i.e. read the "LOST_STEPS" register) in regular intervals during the "print".

The register stayed at 0 all the time, while your macro yielded the following result:

test 7 (IS on)
Y homing error was -0.012
X homing error was 0.000
Y homing error was -0.692
X homing error was -5.600

dc42

@NeoDue thanks for running all those tests.

I am trying to find the cause of the blobs you reported when IS is enabled that you said you believed were caused by particular lines of code. So I've been running this print job with full debug output, using your machine configuration, with IS enabled and with IS not enabled:

; testing IS on short segments generated by PrusaSlicer

M83
M302 P1
M591 D0 S0
T0
G92 E0
G92 X-7.974 Y29.422 F3000			; set initial position

;WIDTH:0.398828
G1 F8190
G1 X-7.953 Y29.175 E.00567
;WIDTH:0.425466
G1 X-7.932 Y28.928 E.00608
G1 X-7.877 Y28.826 E.00284
;WIDTH:0.398828
G1 X-7.823 Y28.723 E.00266
;WIDTH:0.37219
G1 X-7.815 Y-7.037 E.75823
;WIDTH:0.411061
G1 X-7.867 Y-7.142 E.00277
;WIDTH:0.449932
G1 X-7.919 Y-7.246 E.00303
G1 X-7.922 Y-42.252 E.91196

The movement commands are taken from your print file. They include the lines you thought were where the blob occurs and a few preceding lines.

What I found is that IS isn't applied to any of those moves, mostly because they are too short (which is because you have segmentation enabled). The attempt to apply IS does change one of the moves very slightly but not in a way that significantly affects the step generation. So I haven't been able to find any cause of the blob you report.

Are you absolutely certain that these are the moves where the blob occurs when you run the print job with IS enabled?

I've put a new build of RRF for the 6HC at https://www.dropbox.com/scl/fo/p0136wx04h8xf6ejwdnn9/h?rlkey=efrfwyb6o5tqid11gustz3uvy&dl=0. I don't expect this to change the behaviour significantly, except that if you execute a G92 E command with a tool selected it now clears the fraction of an extruder step that is left over from the last move, for all extruders used by the current tool. I did this so that we can get consistent results regardless of the previous printing history.

NeoDue

@dc42 thanks for the investigation! However, with the new results from your measurement macro, I fear that the whole "blob" topic was the wrong way to go anyway...

Therefore please consider the following information to be purely optional:

I had taken two videos (they probably won't help you much, but here is a link to download them anyway..) of that part of the print, one with IS on and one with IS off, and I doublechecked with those. There are indeed two possibilities that might be the culprit: first, the one I had sent you:

starting from X-7.877 Y28.826, the print head first prints the thin long line to X-7.815 Y-7.037. Then it creates the two short lines and goes on to X-7.922 Y-42.252. At this position, the head retracts with a G10, lifts and moves back to X-7.919 Y-6.828, where it unretracts with G11 and creates a third long line to X-7.919 Y28.491.

And this third long line seems to be the second possibility where there is an issue - with IS on you hear a "crack" which, after listening to it with headphones several times, sounds more like noise from the extruder stepper to me.

During the test print, I only had managed to pause the printer after he made that third move, and I could see the larger blob where the two short segments are located. But one of the subsequent steps might be the culprit as well indeed.

dc42

@NeoDue the reason I wanted to investigate the blob was that it could have been caused by either incorrect extrusion or by incorrect axis movement, for example a short pause in axis movement; and incorrect axis movement is likely responsible for the layer shifts.

Investigating in depth the lines of GCode you provided has given me a better understand of what your print is doing. As a result I've identified another possible error in the code. Please can you try a print using the new files at https://www.dropbox.com/scl/fo/p0136wx04h8xf6ejwdnn9/h?rlkey=efrfwyb6o5tqid11gustz3uvy&dl=0. I'm interested both in whether there are any layer shifts, and in whether you still see the blobs that only occurred when you enable IS.

Thanks for your patience! You feedback has been invaluable to help me get this far.

NeoDue

@dc42 On the contrary - I have to thank you for taking the time to dive into this problem so deeply! This is what makes owning a Duet so different from the other printer controllers: the dedication of the team behind it.

I will do the test print for you as soon as I can, but unless I am very lucky, it might take until the weekend until I can deliver!

adrian

@dc42
I only had time to run my print again with your new firmware. Layer shifts even worse now.

My first run I forgot to enable IS and it ran fine. With IS on it layer shifted way more frequently than ever before.

m122
=== Diagnostics ===
RepRapFirmware for Duet 3 MB6HC version 3.5.0-rc.3+ (2024-02-19 14:31:56) running on Duet 3 MB6HC v1.02 or later (standalone mode)
Board ID: 08DJM-956BA-NA3TJ-6J1F8-3S06Q-1U86S
Used output buffers: 6 of 40 (40 max)
=== RTOS ===
Static ram: 155208
Dynamic ram: 124316 of which 592 recycled
Never used RAM 62228, free system stack 100 words
Tasks: NETWORK(1,ready,115.5%,162) ETHERNET(5,nWait 7,0.2%,117) ACCEL(6,nWait 6,0.0%,344) HEAT(3,nWait 6,0.2%,321) Move(4,nWait 6,7.8%,214) CanReceiv(6,nWait 1,0.0%,940) CanSender(5,nWait 7,0.0%,334) CanClock(7,delaying,0.1%,334) TMC(4,nWait 6,41.8%,54) MAIN(1,running,238.3%,103) IDLE(0,ready,0.3%,30), total 404.1%
Owned mutexes:
=== Platform ===
Last reset 02:06:49 ago, cause: software
Last software reset at 2024-02-19 20:45, reason: User, Gcodes spinning, available RAM 62324, slot 0
Software reset code 0x0003 HFSR 0x00000000 CFSR 0x00000000 ICSR 0x00400000 BFAR 0x00000000 SP 0x00000000 Task MAIN Freestk 0 n/a
Error status: 0x04
Aux0 errors 0,1,0
MCU temperature: min 33.8, current 34.3, max 35.3
Supply voltage: min 23.9, current 24.1, max 24.2, under voltage events: 0, over voltage events: 0, power good: yes
12V rail voltage: min 11.7, current 12.1, max 12.8, under voltage events: 0
Heap OK, handles allocated/used 99/0, heap memory allocated/used/recyclable 2048/56/56, gc cycles 0
Events: 0 queued, 0 completed
Driver 0: standstill, SG min 0, mspos 344, reads 49790, writes 21 timeouts 0
Driver 1: standstill, SG min 0, mspos 360, reads 49790, writes 21 timeouts 0
Driver 2: standstill, SG min 0, mspos 536, reads 49792, writes 21 timeouts 0
Driver 3: standstill, SG min 0, mspos 952, reads 49792, writes 21 timeouts 0
Driver 4: standstill, SG min 0, mspos 952, reads 49792, writes 21 timeouts 0
Driver 5: standstill, SG min 0, mspos 952, reads 49792, writes 21 timeouts 0
Date/time: 2024-02-19 22:51:54
Slowest loop: 236.02ms; fastest: 0.05ms
=== Storage ===
Free file entries: 20
SD card 0 detected, interface speed: 25.0MBytes/sec
SD card longest read time 19.3ms, write time 1.8ms, max retries 0
=== Move ===
DMs created 125, segments created 33, maxWait 313188ms, bed compensation in use: mesh, height map offset 0.000, max steps late 1, min interval -13129, bad calcs 1068, ebfmin 0.00, ebfmax 1.00
no step interrupt scheduled
Moves shaped first try 11555, on retry 6745, too short 23528, wrong shape 45799, maybepossible 2852
=== DDARing 0 ===
Scheduled moves 101503, completed 101503, hiccups 456, stepErrors 0, LaErrors 0, Underruns [0, 0, 0], CDDA state -1
=== DDARing 1 ===
Scheduled moves 0, completed 0, hiccups 0, stepErrors 0, LaErrors 0, Underruns [0, 0, 0], CDDA state -1
=== Heat ===
Bed heaters 0 -1 -1 -1 -1 -1 -1 -1 -1 -1 -1 -1, chamber heaters 2 -1 -1 -1, ordering errs 0
Heater 0 is on, I-accum = 0.3
Heater 1 is on, I-accum = 0.2
Heater 2 is on, I-accum = 0.0
=== GCodes ===
Movement locks held by null, null
HTTP is idle in state(s) 0
Telnet is idle in state(s) 0
File is idle in state(s) 0
USB is idle in state(s) 0
Aux is idle in state(s) 0
Trigger is idle in state(s) 0
Queue is idle in state(s) 0
LCD is idle in state(s) 0
SBC is idle in state(s) 0
Daemon is idle in state(s) 0
Aux2 is idle in state(s) 0
Autopause is idle in state(s) 0
File2 is idle in state(s) 0
Queue2 is idle in state(s) 0
Q0 segments left 0, axes/extruders owned 0x80000007
Code queue 0 is empty
Q1 segments left 0, axes/extruders owned 0x0000000
Code queue 1 is empty
=== CAN ===
Messages queued 68487, received 0, lost 0, errs 36169280, boc 0
Longest wait 0ms for reply type 0, peak Tx sync delay 0, free buffers 50 (min 50), ts 38049/0/0
Tx timeouts 0,0,38048,0,0,30437 last cancelled message type 4514 dest 127
=== Network ===
Slowest loop: 213.93ms; fastest: 0.03ms
Responder states: MQTT(0) HTTP(0) HTTP(2) HTTP(0) HTTP(0) HTTP(0) HTTP(0) FTP(0) Telnet(0) Telnet(0)
HTTP sessions: 2 of 8
= Ethernet =
Interface state: active
Error counts: 0 0 13 0 0 0
Socket states: 2 5 3 2 2 0 0 0
=== WiFi ===
Interface state: disabled
Module is disabled
Failed messages: pending 0, notrdy 0, noresp 0
Socket states: 0 0 0 0 0 0 0 0
=== Multicast handler ===
Responder is inactive, messages received 0, responses 0

dc42

@adrian thanks for testing that firmware.

Please can you try the firmware at https://www.dropbox.com/scl/fo/618dnwt7u1gxjs88hxvlg/h?rlkey=efh8iqql2nsbofa0n6k44zktc&dl=0. In this build I have disabled part of the input shaping so that I can determine which part the bug lies in.

dc42

@NeoDue @adrian I've found a likely cause of RRF trying to apply input shaping to moves when it was not possible, which is likely to lead to jerky motion. So please can you try the new firmware at https://www.dropbox.com/scl/fo/p0136wx04h8xf6ejwdnn9/h?rlkey=efrfwyb6o5tqid11gustz3uvy&dl=0.

PS - a check I added has just found an anomaly that I need to fix; so you may wish to wait for a new build from me tomorrow.

adrian

@dc42
I’ll try and test tomorrow with the upcoming version

dc42

@adrian @NeoDue and anyone else having layer shift issues in 3.5.0-rc3 when IS is enabled, please try the new main board binaries at https://www.dropbox.com/scl/fo/p0136wx04h8xf6ejwdnn9/h?rlkey=efrfwyb6o5tqid11gustz3uvy&dl=0.

This version fixes a probable cause of layer shifts in previous versions. It also produces debug output if it detects a malformed movement segment. To avoid having to connect a USB terminal to see any debug messages, you can use the new M111 B parameter. If you are running on any Duet 3 board then I suggest M111 B4096. If you are running on Duet 2 or Maestro then you won't have enough free RAM for that, but you can try M111 B256 and accept that the messages will be truncated.

Please report any debug messages you see here, as well as whether you get any later shifts (and a M122 report at the end of the print if you do).