[3.2-beta-3.2] Strange pauses during print

Phaedrux

Did you see the test procedure in my last post for inducing hiccups?

BoA

@Phaedrux OK, so with 256 microstepping, 3200steps/mm I reached 65mm/s with 0 hiccups. Which is 208k steps/s

With 66.6mm/s I had 2 hiccups (at over 210k steps/s).

Far higher than required during printing.

Phaedrux

With a single axis active anyway. Will be interesting to see what @DC42 thinks.

BoA

@Phaedrux Same results with XY active - moving head diagonally 0,0 to 200,200 and back to 0,0

at 4000mm/min 0 hiccups

And for completness: gcode file I am printing: gravitrax_dual_0.2mm_PETG_MK3S_52m.gcode

BoA

There is something in this gcode that makes rrf3 struggle to process. I am printing similar hexagonal elements filling the whole bed at ~100mm/s, 300mm/s idle moves and... 0 pauses, 0 hiccups counted. Same slicer, same slicer settings.

Phaedrux

@BoA said in [3.2-beta-3.2] Strange pauses during print:

M566 X1200.00 Y1200.00 Z12.00

Can you try increasing your Z jerk to 60 and reprinting the gcode that was pausing before?

There is an interaction between mesh compensation and low z jerk that can cause pauses in XY movement to allow the slower z axis time to adjust since it's part of the coordinated move. this can be exacerbated by high print speeds.

https://duet3d.dozuki.com/Wiki/Using_mesh_bed_compensation#Section_Troubleshooting

BoA

@Phaedrux Just started. But... I do not think this is it. Bed compensation works on all prints same way, as it compensates for the same bed. Also I just printed a square element 140x140mm at 180mm/s + 300mm/s idle without any issues.

Neverthless I just changes Z jerk to 60 and started print that causes pauses... Will let You know in an hour

BoA

@Phaedrux As expected, that did not help. A executed M122 during print, and just after the single pause hiccups counter went from 0 to over 16000.

https://drive.google.com/file/d/19Zhcq5f3gCc43F2qHmSnbkO4UZDmZIAL/view?usp=sharing

Pause at 0:52

And more pauses following, but not recorded.
Before this pause, 0 hiccups:

=== Platform ===
Last reset 03:09:09 ago, cause: software
Last software reset at 2020-11-18 17:42, reason: User, GCodes spinning, available RAM 99700, slot 0
Software reset code 0x0003 HFSR 0x00000000 CFSR 0x00000000 ICSR 0x0044a000 BFAR 0x00000000 SP 0xffffffff Task MAIN
Error status: 0x04
MCU temperature: min 38.2, current 38.3, max 38.5
Supply voltage: min 24.6, current 24.7, max 24.9, under voltage events: 0, over voltage events: 0, power good: yes
12V rail voltage: min 12.1, current 12.2, max 12.3, under voltage events: 0
Driver 0: position 16847, ok, reads 21772, writes 0 timeouts 0, SG min/max 0/1023
Driver 1: position 17242, ok, reads 21771, writes 0 timeouts 0, SG min/max 0/423
Driver 2: position 2596, ok, reads 21771, writes 0 timeouts 0, SG min/max 0/225
Driver 3: position 0, ok, reads 21771, writes 0 timeouts 0, SG min/max 0/386
Driver 4: position 0, ok, reads 21772, writes 0 timeouts 0, SG min/max 0/320
Driver 5: position 0, standstill, reads 21772, writes 0 timeouts 0, SG min/max not available
Date/time: 2020-11-18 20:51:44
Slowest loop: 8.57ms; fastest: 0.14ms

After over 16000 hiccups counted and:

=== Platform ===
Last reset 00:28:52 ago, cause: software
Last software reset at 2020-11-17 17:49, reason: User, GCodes spinning, available RAM 99492, slot 0
Software reset code 0x0003 HFSR 0x00000000 CFSR 0x00000000 ICSR 0x0044a000 BFAR 0x00000000 SP 0xffffffff Task MAIN
Error status: 0x00
MCU temperature: min 38.8, current 39.0, max 39.3
Supply voltage: min 24.6, current 24.8, max 24.9, under voltage events: 0, over voltage events: 0, power good: yes
12V rail voltage: min 12.1, current 12.2, max 12.3, under voltage events: 0
Driver 0: position 27870, standstill, reads 21523, writes 0 timeouts 0, SG min/max 0/1023
Driver 1: position 19411, ok, reads 21523, writes 0 timeouts 0, SG min/max 0/951
Driver 2: position 2030, ok, reads 21523, writes 0 timeouts 0, SG min/max 0/1023
Driver 3: position 0, standstill, reads 21523, writes 0 timeouts 0, SG min/max 0/125
Driver 4: position 0, standstill, reads 21523, writes 0 timeouts 0, SG min/max 0/119
Driver 5: position 0, standstill, reads 21524, writes 0 timeouts 0, SG min/max not available
Date/time: 2020-11-17 18:17:57
Slowest loop: 329.89ms; fastest: 0.15ms

Take a look on Slowest loop time. Seems to be much higher after this strange pause.

Phaedrux

Thanks for testing. Definitely an exaggerated pause there.

Phaedrux

Each time you run M122 it clears the hiccup counter.

BoA

@Phaedrux I am aware of that. Just in the middle of print, each m122 reported 0 hiccups, and just after pause over 16000, after another pause (longer one) almost 50000. And other thing is this platform slowest loop significantly higher than normally.

BoA

This post is deleted!

BoA

@Phaedrux I just tested this particular print with 3.2beta4, and there ar even more pauses and for longer time, than with 3.2beta3.2

After each pause I gou a hiccups counter from 0 to around 30000. Between pauses hiccups counter is 0 all the time.

As I can not see anything from @dc42 I am guessing he just missed that.

dc42

@BoA, please post the file you are printing and your config.g file.

This may be related to https://forum.duet3d.com/post/195269.

BoA

@dc42 I posted before, but:
config.g
gravitrax_dual_support_0.2mm_PETG_52m.gcode

dc42

Thanks. I confirmed and fixed this issue. I have put new RRF 3.2beta4+3 binaries at https://www.dropbox.com/sh/tehhdvunh0pgr7q/AADgJ4Qj7W18MYaRRNNDdhpwa?dl=0.

BoA

@dc42 Confirmed: No more pauses during print. Zero hiccups, and some 3 underruns?

=== MainDDARing ===
hiccups 0, stepErrors 0, LaErrors 0, Underruns [0, 0, 3]

Anyway - prints with no issues now.

dc42

Thanks for confirming. I will mark this as solved.