resume redundant extrusion

bugpwr

@Phaedrux I will make a video later as this huge printer is now printing, but let me try to describe the steps clearer:

start print
pause in the middle of the print. wait until paused. 10mm retract occurs as it should. print is now paused.
resume the print. unretract (extrude) of 10mm happens accordung to resume.g. This has no effect because it was retracted before.
printer now extrudes another 5 to 15 mm for no reason, very quickly, much quicker than the F rate specification of the respective command in resume.g
printing resumes with an ugly blob. this happens almost every single resume.

droftarts

@bugpwr Original thread is here: https://reprap.org/forum/read.php?416,832302

Please post your config.g, and the gcode (or a test gcode) that exhibits the problem. Are you pausing in the middle of a long move? Are you using absolute extrusion? Do you have segmentation enabled?

Please could you also test with RRF 3.6.0-beta.2, as this issue may already have been fixed. https://github.com/Duet3D/RepRapFirmware/releases/tag/3.6.0-beta.2

Ian

bugpwr

@droftarts hi, sorry it took so long and many thanks for help.

First, answering your questions:

same with beta2
no, the pause is not in the middle of a particularly long move. My feeling is that this happens at every pause.
I could not find any segmentation settings in OrcaSlicer (which I am using)
from what i see in gcode, the slicer is using relative extrusion
attaching the gcode of a cube 20x20x20 with 2 walls and some simple infil, that is used in the video
youtube link at youtu be: c0CzmD-DGdg?si=Dh9AtsguJKMDB1lt to see the phenomenon in action. an overextrusion is clearly heard at 00:26

Here goes config.g:

===================================================
; General preferences
G90                                            ; send absolute coordinates...
M83                                            ; ...but relative extruder moves
M550 P"M1 Magrethea"   

; Emergency stop at E6 - to be replaced with power cut
M950 J6 C"duex.e6stop"
M581 P6 T0 S1 R0

; Network
M552 S1                                        ; connect wifi to internally stored ssid
M586 P0 S1                                     ; enable HTTP
M586 P1 S1                                     ;  FTP

; Drives
M569 P0 S1                                     ; X ; physical drive 0 goes forwards
M569 P1 S1                                     ; C
M569 P2 S1                                     ; this is the dual channel connected to right Z motors
M569 P3 S1                                     
M569 P4 S0                                     ; E
M569 P5 S0                                     ; 
M569 P6 S0                                     ; 
M569 P7 S0                                     ; right Y
M569 P8 S1                                     ; left Y
M584 X0 Y7:8 Z2:5:6 E4 C1 P3                              ; set drive mapping; P4=visible axes. right Z motors are on the dual channel driver. 5 is back left, 6 front left
M350 X16 Y16:16 Z16:16:16 E16 C16 I1                        ; configure microstepping with interpolation
M92 X80.00 Y100:100 Z1600:1600:1600 E783 C80	; these are the correct theoretical model. measured with orca calibration 
M566 X300 Y300:300 Z10:10:10 E320.00 ;120.00          ; set maximum instantaneous speed changes (mm/min)
M203 X10000.00 Y10000:10000 Z600:600:600 E1200.00         ; set maximum speeds (mm/min)
M201 X6000.00 Y4000:4000 Z100:100:100 E450.00             ; set accelerations (mm/s^2)  
M906 X1200 Y900:900 Z1800:900:900 E900 C80 I15              ; set motor currents (mA) and motor idle factor in %. My extruder is rated for 1A
M84 S30                                        ; Set idle timeout

; Axis Limits
M208 X0 Y0 Z0 S1                                        ; set axis minima
M208 X652 Y430 Z690 S0                                  ; set axis maxima. z could be 701. X has about 1mm spare, to enlarge, relocate X probe. 

; Endstops
M574 X2 S1 P"!xstop"	; x stop, sorry for using NO stop. better to reconfigure as NC
M574 Y2 S1 P"ystop+e1stop" ; configured as NC, which is a good thing to do

; Filament sensors
;M591 D0 P3 C"e0_stop" S1  ; drive 0, magnetic filament monitor, plug, enable 
M591 D0 P1 C"!^e0stop" S1	 ; microswitch sensor drive 0, active low, pin, enable

; Z-Probe
;M307 H3 A-1 C-1 D-1        ; H7 means E6 (Duex /Expansion). Disable heater so this pin can be used; probably not needed coz it says heater not found
; "You can no longer disable a heater using M307 A-1 C-1 D-1. To use the pin for something else, don't create a heater on that pin."
M950 S0 C"duex.pwm5"                         ; create servo pin 0 for BLTouch
M558 P9 C"^zprobe.i^H^H^H^Hn" H5 F120 T6000            ; set Z probe type to bltouch and the dive height + speeds
G31 P20 X-31 Y1 Z1.12                        ; set Z probe trigger value, offset and trigger height; lower Z means print higher. NOZZLE: 0.5 HF
M375 ; load height map

; Heaters
M308 S0 P"bedtemp" Y"thermistor" T100000 B3950 ; configure sensor 0 as thermistor on pin bedtemp. Tnnn (for thermistor sensors) Thermistor resistance at 25C, Steinhart-Hart thermistor model B coefficient
M950 H0 C"!exp.heater4" T0 ; Q0
M140 H0                                        ; map heated bed to heater 0
M143 H0 S120                                    ; set temperature limit for heater 0 

M308 S1 P"e1temp" Y"thermistor" T100000 B3950  ; configure sensor 1 as thermistor on pin e1temp
M950 H1 C"e1heat" T1                           ; create nozzle heater output on e1heat and map it to sensor 1
M307 H1 R3.004 K0.380:0.000 D11.29 E1.35 S1.00 B0 V23.9
M570 H1 P20 T20			; temperature excursion 20, time 20s - abit too long but the PID is annoying
M143 H1 S270                                   ; set temperature limit for heater 1 to 270C

; Fans
M950 F1 C"duex.fan4" Q10                           ; create fan 1 on pin fan1 and set its frequency
M106 P1 S1 H1 T45                                 ; set fan 1 value. Thermostatic control is turned on
M950 F2 C"duex.fan3" Q10                           
M106 P2 S0 L250 X255 B0.1 H-1                            ; set fan 0 value. Thermostatic control is turned off


; Tools
M563 P1 D0 H1 F2 S"Right"                            ; define tool 1, extruder 0, heater 1, fan 2
G10 P1 X0 Y0 Z0                                ; set tool 1 axis offsets
G10 P1 R0 S0                                   ; set initial tool 1 active and standby temperatures to 0C

M309 P1 S0.03 ; this is flow/heater power compensation 


; Custom settings are not defined

; Miscellaneous
M575 P1 S1 B115200                                       ; enable support for PanelDue, UART at 115200 baud
M564 H0	; H1 = forbid movement of axes that have not been homed, H0 = allow movement of axes that have not been homed
M302 P1	; allow cold extrusion 

G92 C0 ; nevermind this axis for now

T1 ; default tool is 1
======================================================

end of config.g

Cube_PLA_6m41s.gcode

Phaedrux

Were you able to capture photo/video of what you're seeing?

bugpwr

@Phaedrux yes, I posted the garbled video link above - "youtube link at youtu be: c0CzmD-DGdg?si=Dh9AtsguJKMDB1lt to see the phenomenon in action. an overextrusion is clearly heard at 00:26
"

droftarts

@Phaedrux, @bugpwr said in resume redundant extrusion:

youtube link at youtu be: c0CzmD-DGdg?si=Dh9AtsguJKMDB1lt to see the phenomenon in action. an overextrusion is clearly heard at 00:26

Link to video is https://youtu.be/c0CzmD-DGdg. In case you can't post links, I've upvoted your post, so you should have enough reputation now.

Yes, it certainly looks like it's over extruding. I can't see anything obviously amiss; gcode is using relative extruder moves, and there's not extra extrusion moves in resume.g. Any time you pause a print from SD card, the state of the print is saved to a special file on the SD card, sys/resurrect.g. Can you pause the print, copy that file and post it? Also, does the same thing happen if you pause and resume from DWC rather than Paneldue? What firmware version is the PanelDue running (check the 'Setup' screen)?

Ian

bugpwr

hi,
yes - same behavior with DWC and PanelDue. This has been around for a while. Also, if I may share my gut feeling of being around Duet systems - I believe this is very common. Not sure what's different (perhaps it's related to the fact I have a 2.85 system?). It may be that some people don't notice this because this "redundant" extrusion happens very fast - and often the extruder is upable to push the filament through, missing steps.

PanelDue v3.5.5-v3-7.0

Ressurect follows:

; Resume printing file "0:/gcodes/1734786214211-cube_pla_6m41s.gcode" after print paused at 2025-01-19 08:36
M140 P0 S60.0
G29 S1
M568 P1 A2 S200 R200
M486 S0 A"Cube id:1190329520128 copy 0"
G21
M98 P"resurrect-prologue.g" X335.750 Y205.250 Z6.900
M290 R0 X0.000 Y0.000 Z0.000
; Workplace coordinates
G10 L2 P1 X0.00 Y0.00 Z0.00
G10 L2 P2 X0.00 Y0.00 Z0.00
G10 L2 P3 X0.00 Y0.00 Z0.00
G10 L2 P4 X0.00 Y0.00 Z0.00
G10 L2 P5 X0.00 Y0.00 Z0.00
G10 L2 P6 X0.00 Y0.00 Z0.00
G10 L2 P7 X0.00 Y0.00 Z0.00
G10 L2 P8 X0.00 Y0.00 Z0.00
G10 L2 P9 X0.00 Y0.00 Z0.00
M486 S0
T1
G54
M106 S1.00
M116
G92 E0.00000
M83
G94
G17
M23 "0:/gcodes/1734786214211-cube_pla_6m41s.gcode"
M26 S19185
G0 F6000 Z8.900
G0 F6000 X335.750 Y205.250
G0 F6000 Z6.900
G1 F1200.0 P0
M204 P450.0 T3000.0
G21
M106 P2 S1.00
M302 P1
M24

droftarts

@bugpwr said in resume redundant extrusion:

This has been around for a while. Also, if I may share my gut feeling of being around Duet systems - I believe this is very common. Not sure what's different (perhaps it's related to the fact I have a 2.85 system?). It may be that some people don't notice this because this "redundant" extrusion happens very fast - and often the extruder is upable to push the filament through, missing steps.

I don't think it's common, or the forum would be awash with people reporting it. Not to do with a 2.85mm filament either; I run a tool with 2.85mm filament, and haven't experienced this.

I can't see anything in the resurrect.g file that would be causing the double extrusion. Can you add a line to your "resume.g" to see if it's running twice? eg

; resume.g
G1 R1 X0 Y0 F6000 ; move XY first to saved pos
G1 R1 X0 Y0 Z5 F6000 ; go to 5mm above position of the last print move

G1 R1 X0 Y0 Z0 F6000 ; go back to the last print move
M400 ; wait for moves to complete
M83 ; relative extruder moves
G1 E10 F300
echo "If you see this twice, resume.g is running twice!"

I've had a good look through your config.g, and there are a few things worth changing, though I don't think they'll impact this issue:

Motor settings

M350 X16 Y16:16 Z16:16:16 E16 C16 I1                        ; configure microstepping with interpolation
M92 X80.00 Y100:100 Z1600:1600:1600 E783 C80	; these are the correct theoretical model. measured with orca calibration 
M566 X300 Y300:300 Z10:10:10 E320.00 ;120.00          ; set maximum instantaneous speed changes (mm/min)
M203 X10000.00 Y10000:10000 Z600:600:600 E1200.00         ; set maximum speeds (mm/min)
M201 X6000.00 Y4000:4000 Z100:100:100 E450.00             ; set accelerations (mm/s^2)  
M906 X1200 Y900:900 Z1800:900:900 E900 C80 I15              ; set motor currents (mA) and motor idle factor in %. My extruder is rated for 1A

All of the above Gcodes should only have one parameter for the Y and Z axes. While the extra ones are usually ignored, it has caused issues in the past. eg see the notes for M350 https://docs.duet3d.com/en/User_manual/Reference/Gcodes#m350-set-microstepping-mode

RepRapFirmware does not support individual motor settings where an axis has multiple motors connected to different stepper drivers. The first parameter specified will be used for all motors on the axis. You should use identical motors on any axis that has more than one motor to avoid unexpected behaviour.

Also, you have different values for the motor current for the three Z motors in M906.

Z probe

M558 P9 C"^zprobe.i^H^H^H^Hn" H5 F120 T6000            ; set Z probe type to bltouch and the dive height + speeds
G31 P20 X-31 Y1 Z1.12                        ; set Z probe trigger value, offset and trigger height; lower Z means print higher. NOZZLE: 0.5 HF
M375 ; load height map

Probably just a typo, but there's some stray characters in the M558 line ^H^H^H

Also, you're probably getting a message at start up about 'a significant Z offset`, because you're loading a height map when Z isn't homed. Comment out the M375, and load the heightmap after Z home.

Once you've changed the above, send M98 P"config.g" and check if it reports any errors.

If the issue persists, you may need to set up logging so we can catch what Gcodes are actually being sent.

Ian

bugpwr

hi,

First, thank you very much for the review of my gcode. I have removed the extra ":" entries except in case of motor currents, where different Z currents are on purpose: there are 4 motors connected to 3 controllers, I did not have a spare (also, I don't see a similar note on M906, though I guess I have been excessively optimistic). These changes had no effect on the situation unfortunately.

I have performed the "echo" experiment, no double execution of resume.g.
By the way, it would not have caused this result - because the speed of this "extra" extrusion is very different from F300 - it is really really fast.

I have noticed a somewhat strange result of M114, not sure if related:
X:335.750 Y:194.700 Z:44.300 E:0.000 E0:76.4 Count 26860 19470 70578 Machine 335.750 194.700 44.300 Bed comp -0.188

will go on with the logging and report.

bugpwr

not sure what I am doing wrong, but M929 S3 P"/sys/log.txt" did not produce any file.

bugpwr

Sorry my bad, here's the log that should include a couple of the pause eventslog.txt

droftarts

@bugpwr said in resume redundant extrusion:

I don't see a similar note on M906,

It's the last note in the M906 notes.

I think we need the debug output of the Gcode module, rather than the system log (I don't think this will show much, and is rather impenetrable), which is summoned by M111 https://docs.duet3d.com/en/User_manual/Reference/Gcodes#m111-set-debug-level
Send M111 to see what is enabled currently (nothing), and enable the Gcode module. eg

M111
Debugging on for modules:
Debugging off for modules: Platform(0) Network(1) Webserver(2) Gcodes(3) Move(4) Heat(5) Kinematics(6) InputShaping(7) Debug(8) PrintMonitor(9) Storage(10) PortControl(11) DuetExpansion(12) FilamentSensors(13) WiFi(14) Display(15) SbcInterface(16) CAN(17) Expansion(18)

M111 P3 S1
Debugging on for modules: Gcodes(3 - 0xff)
Debugging off for modules: Platform(0) Network(1) Webserver(2) Move(4) Heat(5) Kinematics(6) InputShaping(7) Debug(8) PrintMonitor(9) Storage(10) PortControl(11) DuetExpansion(12) FilamentSensors(13) WiFi(14) Display(15) SbcInterface(16) CAN(17) Expansion(18)

Debug output is normally sent to the USB port, so connect a PC with a serial terminal to the Duet, and hopefully you can capture if an errant Gcode is being sent on resume. Possibly turn on the 'Move(4)' module too. Hopefully this will give us a clue what is going on.

Ian

bugpwr

@droftarts for now - this is debug(3) output. Personally, I don't see anything criminal here:

Aux: M409 F"d99f"
Aux: M409 F"d99f"
Aux: M409 F"d99f"
Aux: M409 F"d99f"
Aux: M409 F"d99f"
Aux: M409 F"d99f"
HTTP: M24
HTTP: G1 R1 X0 Y0 F6000
HTTP: G1 R1 X0 Y0 Z5 F6000
HTTP: G1 R1 X0 Y0 Z0 F6000
HTTP: M400
Aux: M409 F"d99f"
Aux: M409 K"volumes" F"v"
Aux: M409 F"d99f"
Aux: M409 F"d99f"
Aux: M409 F"d99f"
HTTP: M83
HTTP: G1 E10 F300
Aux: M409 F"d99f"
Aux: M409 K"volumes" F"v"
Aux: M409 F"d99f"
Aux: M409 F"d99f"
Aux: M409 F"d99f"
File: G1 X316.25 Y205.25 E.39947
File: M73 P21 R5
File: G1 X335.75 Y205.25 E.39947
File: M73 P21 R5
File: G1 X335.75 Y224.7 E.39845
File: G1 E-.5 F2700
Aux: M409 F"d99f"
Aux: M409 F"d99f"
File: G1 Z5.2 F30000
Aux: M409 F"d99f"
File: G1 X335.75 Y224.75 Z5.2
File: G1 Z4.8
File: G1 E.5 F2100
File: G1 F1200
File: G1 X316.25 Y224.75 E.39947
File: G1 X316.25 Y205.25 E.39947

bugpwr

and this is the capture with move(4)

Aux: M409 F"d99f"
Aux: M409 F"d99f"
Aux: M409 F"d99f"
Aux: M409 F"d99f"
Aux: M409 F"d99f"
Aux: M409 F"d99f"
Aux: M409 F"d99f"
Aux: M409 F"d99f"
Aux: M409 F"d99f"
Aux: M409 F"d99f"
Aux: M409 F"d99f"
Aux: M409 F"d99f"
Aux: M409 F"d99f"
Aux: M409 F"d99f"
Aux: M409 F"d99f"
Aux: M409 F"d99f"
HTTP: M24
HTTP: G1 R1 X0 Y0 F6000
Transformed 316.25 224.75 25.20 to 25300 22475 40318 0
HTTP: G1 R1 X0 Y0 Z5 F6000
Transformed 316.25 224.75 10.20 to 25300 22475 16318 0
HTTP: G1 R1 X0 Y0 Z0 F6000
Transformed 316.25 224.75 5.20 to 25300 22475 8318 0
HTTP: M400
AddLin: st=3217650990 steps=3000.0
addlin 1 ts=3217650990 DDA: start=[316.250000 194.750000 25.238518 0.000000] end=[316.250000 224.750000 25.198977 0.000000] s=3.0000e+1 vec=[0.000000 0.999999 -0.001318 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000]
a=2.2756e-9 d=2.2756e-9 reqv=1.0667e-4 startv=0.0000e+0 topv=1.0667e-4 endv=0.0000e+0 cks=328125 fp=4294967295 fl=0aa3
pp: td=3.000e+1 ad=2.500e+0 dsd=2.750e+1 a=2.276e-9 d=2.276e-9 ac=46875 sc=234375 dc=46875
Add seg: st=3217650990 t=46875 dist=250.00 u=-9.145e-9 a=2.276e-7 f=01
Add seg: st=3217697865 t=234375 dist=2500.00 u=1.067e-2 a=0.000e+0 f=01
Add seg: st=3217932240 t=46875 dist=250.00 u=1.067e-2 a=-2.276e-7 f=01
AddLin: st=3217650990 steps=-64.0
addlin 1 ts=3217650990 DDA: start=[316.250000 194.750000 25.238518 0.000000] end=[316.250000 224.750000 25.198977 0.000000] s=3.0000e+1 vec=[0.000000 0.999999 -0.001318 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000]
a=2.2756e-9 d=2.2756e-9 reqv=1.0667e-4 startv=0.0000e+0 topv=1.0667e-4 endv=0.0000e+0 cks=328125 fp=4294967295 fl=0aa3
pp: td=3.000e+1 ad=2.500e+0 dsd=2.750e+1 a=2.276e-9 d=2.276e-9 ac=46875 sc=234375 dc=46875
Add seg: st=3217650990 t=46875 dist=-5.33 u=1.881e-10 a=-4.855e-9 f=01
Add seg: st=3217697865 t=234375 dist=-53.33 u=-2.276e-4 a=0.000e+0 f=01
Add seg: st=3217932240 t=46875 dist=-5.33 u=-2.276e-4 a=4.855e-9 f=01
pr 2 ts=3217650990 DDA: start=[316.250000 194.750000 25.238518 0.000000] end=[316.250000 224.750000 25.198977 0.000000] s=3.0000e+1 vec=[0.000000 0.999999 -0.001318 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000]
a=2.2756e-9 d=2.2756e-9 reqv=1.0667e-4 startv=0.0000e+0 topv=1.0667e-4 endv=0.0000e+0 cks=328125 fp=4294967295 fl=0aa3
Aux: M409 F"d99f"
Forward transformed 25301 21857 40332 to 316.26 218.57 25.21
AddLin: st=3217979115 steps=-24000.0
addlin 1 ts=3217979115 DDA: start=[316.250000 224.750000 25.198977 -0.000000] end=[316.250000 224.750000 10.198977 -0.000000] s=1.5000e+1 vec=[0.000000 0.000000 -1.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000]
a=1.1378e-10 d=1.1378e-10 reqv=1.0667e-5 startv=0.0000e+0 topv=1.0667e-5 endv=1.0667e-5 cks=1453125 fp=4294967295 fl=0a81
pp: td=1.500e+1 ad=5.000e-1 dsd=1.500e+1 a=1.138e-10 d=1.138e-10 ac=93750 sc=1359375 dc=0
Add seg: st=3217979115 t=93750 dist=-800.00 u=-5.495e-11 a=-1.820e-7 f=05
Add seg: st=3218072865 t=1359375 dist=-23200.00 u=-1.707e-2 a=0.000e+0 f=05
pr 2 ts=3217979115 DDA: start=[316.250000 224.750000 25.198977 -0.000000] end=[316.250000 224.750000 10.198977 -0.000000] s=1.5000e+1 vec=[0.000000 0.000000 -1.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000]
a=1.1378e-10 d=1.1378e-10 reqv=1.0667e-5 startv=0.0000e+0 topv=1.0667e-5 endv=1.0667e-5 cks=1453125 fp=4294967295 fl=0a81
Forward transformed 25301 22475 35920 to 316.26 224.75 22.45
Aux: M409 K"volumes" F"v"
Forward transformed 25301 22475 31482 to 316.26 224.75 19.68
Aux: M409 F"d99f"
Forward transformed 25301 22475 26396 to 316.26 224.75 16.50
Forward transformed 25301 22475 20158 to 316.26 224.75 12.60
Aux: M409 F"d99f"
AddLin: st=3219432240 steps=-8000.0
addlin 1 ts=3219432240 DDA: start=[316.250000 224.750000 10.198977 -0.000000] end=[316.250000 224.750000 5.198977 -0.000000] s=5.0000e+0 vec=[0.000000 0.000000 -1.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000]
a=1.1378e-10 d=1.1378e-10 reqv=1.0667e-5 startv=1.0667e-5 topv=1.0667e-5 endv=0.0000e+0 cks=515625 fp=4294967295 fl=0a83
pp: td=5.000e+0 ad=0.000e+0 dsd=4.500e+0 a=1.138e-10 d=1.138e-10 ac=0 sc=421875 dc=93750
Add seg: st=3219432240 t=421875 dist=-7200.00 u=-1.707e-2 a=0.000e+0 f=05
Add seg: st=3219854115 t=93750 dist=-800.00 u=-1.707e-2 a=1.820e-7 f=05
pr 2 ts=3219432240 DDA: start=[316.250000 224.750000 10.198977 -0.000000] end=[316.250000 224.750000 5.198977 -0.000000] s=5.0000e+0 vec=[0.000000 0.000000 -1.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000]
a=1.1378e-10 d=1.1378e-10 reqv=1.0667e-5 startv=1.0667e-5 topv=1.0667e-5 endv=0.0000e+0 cks=515625 fp=4294967295 fl=0a83
Forward transformed 25301 22475 15679 to 316.26 224.75 9.80
Forward transformed 25301 22475 12358 to 316.26 224.75 7.72
Aux: M409 F"d99f"
HTTP: M83
HTTP: G1 E10 F300
Transformed 316.25 224.75 5.20 to 25300 22475 8318 0
AddLin: st=3220006007 steps=7830.0
addlin 1 ts=3220006007 DDA: start=[316.250000 224.750000 5.198977 -0.000000] end=[316.250000 224.750000 5.198977 -0.000000] s=1.0000e+1 vec=[0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 1.000000]
a=5.1200e-10 d=5.1200e-10 reqv=5.3333e-6 startv=0.0000e+0 topv=5.3333e-6 endv=0.0000e+0 cks=1885417 fp=4294967295 fl=0b83
pp: td=1.000e+1 ad=2.778e-2 dsd=9.972e+0 a=5.120e-10 d=5.120e-10 ac=10417 sc=1864583 dc=10417
Add seg: st=3220006007 t=10417 dist=21.75 u=-1.336e-7 a=4.009e-7 f=05
Add seg: st=3220016424 t=1864583 dist=7786.50 u=4.176e-3 a=0.000e+0 f=05
Add seg: st=3221881007 t=10417 dist=21.75 u=4.176e-3 a=-4.009e-7 f=05
pr 2 ts=3220006007 DDA: start=[316.250000 224.750000 5.198977 -0.000000] end=[316.250000 224.750000 5.198977 -0.000000] s=1.0000e+1 vec=[0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 1.000000]
a=5.1200e-10 d=5.1200e-10 reqv=5.3333e-6 startv=0.0000e+0 topv=5.3333e-6 endv=0.0000e+0 cks=1885417 fp=4294967295 fl=0b83
Forward transformed 25301 22475 8319 to 316.26 224.75 5.20
Aux: M409 F"d99f"
Forward transformed 25301 22475 8319 to 316.26 224.75 5.20
Forward transformed 25301 22475 8319 to 316.26 224.75 5.20
Aux: M409 K"volumes" F"v"
Forward transformed 25301 22475 8319 to 316.26 224.75 5.20
Forward transformed 25301 22475 8319 to 316.26 224.75 5.20
Aux: M409 F"d99f"
Forward transformed 25301 22475 8319 to 316.26 224.75 5.20
Aux: M409 F"d99f"
Forward transformed 25301 22475 8319 to 316.26 224.75 5.20
Transformed 316.25 224.75 5.20 to 25300 22475 8318 0
AddLin: st=3221948491 steps=7830.0
addlin 1 ts=3221948491 DDA: start=[316.250000 224.750000 5.198977 0.000000] end=[316.250000 224.750000 5.198977 0.000000] s=1.0000e+1 vec=[0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 1.000000]
a=5.1200e-10 d=5.1200e-10 reqv=2.1333e-5 startv=0.0000e+0 topv=2.1333e-5 endv=0.0000e+0 cks=510417 fp=4294967295 fl=0b83
pp: td=1.000e+1 ad=4.444e-1 dsd=9.556e+0 a=5.120e-10 d=5.120e-10 ac=41667 sc=427083 dc=41667
Add seg: st=3221948491 t=41667 dist=348.00 u=-1.336e-7 a=4.009e-7 f=05
Add seg: st=3221990158 t=427083 dist=7134.00 u=1.670e-2 a=0.000e+0 f=05
Add seg: st=3222417241 t=41667 dist=348.00 u=1.670e-2 a=-4.009e-7 f=05
pr 2 ts=3221948491 DDA: start=[316.250000 224.750000 5.198977 0.000000] end=[316.250000 224.750000 5.198977 0.000000] s=1.0000e+1 vec=[0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 1.000000]
a=5.1200e-10 d=5.1200e-10 reqv=2.1333e-5 startv=0.0000e+0 topv=2.1333e-5 endv=0.0000e+0 cks=510417 fp=4294967295 fl=0b83
Forward transformed 25301 22475 8319 to 316.26 224.75 5.20
Aux: M409 F"d99f"
Forward transformed 25301 22475 8319 to 316.26 224.75 5.20
File: G1 X316.25 Y205.25 E.39947
Transformed 316.25 205.25 5.22 to 25300 20525 8359 0
File: M73 P24 R5
File: G1 X335.75 Y205.25 E.39947
Transformed 335.75 205.25 5.21 to 26860 20525 8330 0
File: G1 X335.75 Y224.7 E.39845
File: G1 E-.5 F2700
AddLin: st=3222522240 steps=-1950.0
addlin 1 ts=3222522240 DDA: start=[316.250000 224.750000 5.198977 -0.000000] end=[316.250000 205.250000 5.224679 -0.000000] s=1.9500e+1 vec=[0.000000 -0.999999 0.001318 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.020486]
a=5.1200e-10 d=5.1200e-10 reqv=2.1333e-5 startv=0.0000e+0 topv=2.1333e-5 endv=3.5200e-6 cks=949423 fp=17103 fl=0aaf
pp: td=1.950e+1 ad=4.444e-1 dsd=1.907e+1 a=5.120e-10 d=5.120e-10 ac=41667 sc=872964 dc=34792
Add seg: st=3222522240 t=41667 dist=-44.44 u=1.712e-8 a=-5.120e-8 f=00
Add seg: st=3222563907 t=872964 dist=-1862.32 u=-2.133e-3 a=0.000e+0 f=00
Add seg: st=3223436871 t=34792 dist=-43.23 u=-2.133e-3 a=5.120e-8 f=00
AddLin: st=3222522240 steps=41.0
addlin 1 ts=3222522240 DDA: start=[316.250000 224.750000 5.198977 -0.000000] end=[316.250000 205.250000 5.224679 -0.000000] s=1.9500e+1 vec=[0.000000 -0.999999 0.001318 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.020486]
a=5.1200e-10 d=5.1200e-10 reqv=2.1333e-5 startv=0.0000e+0 topv=2.1333e-5 endv=3.5200e-6 cks=949423 fp=17103 fl=0aaf
pp: td=1.950e+1 ad=4.444e-1 dsd=1.907e+1 a=5.120e-10 d=5.120e-10 ac=41667 sc=872964 dc=34792
Add seg: st=3222522240 t=41667 dist=0.93 u=-3.604e-10 a=1.077e-9 f=00
Add seg: st=3222563907 t=872964 dist=39.16 u=4.485e-5 a=0.000e+0 f=00
Add seg: st=3223436871 t=34792 dist=0.91 u=4.485e-5 a=-1.077e-9 f=00
AddLin: st=3222522240 steps=312.8
addlin 1 ts=3222522240 DDA: start=[316.250000 224.750000 5.198977 -0.000000] end=[316.250000 205.250000 5.224679 -0.000000] s=1.9500e+1 vec=[0.000000 -0.999999 0.001318 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.020486]
a=5.1200e-10 d=5.1200e-10 reqv=2.1333e-5 startv=0.0000e+0 topv=2.1333e-5 endv=3.5200e-6 cks=949423 fp=17103 fl=0aaf
pp: td=1.950e+1 ad=4.444e-1 dsd=1.907e+1 a=5.120e-10 d=5.120e-10 ac=41667 sc=872964 dc=34792
Add seg: st=3222522240 t=41667 dist=7.13 u=-2.752e-9 a=8.213e-9 f=00
Add seg: st=3222563907 t=872964 dist=298.72 u=3.422e-4 a=0.000e+0 f=00
Add seg: st=3223436871 t=34792 dist=6.93 u=3.422e-4 a=-8.213e-9 f=00
pr 2 ts=3222522240 DDA: start=[316.250000 224.750000 5.198977 -0.000000] end=[316.250000 205.250000 5.224679 -0.000000] s=1.9500e+1 vec=[0.000000 -0.999999 0.001318 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.020486]
a=5.1200e-10 d=5.1200e-10 reqv=2.1333e-5 startv=0.0000e+0 topv=2.1333e-5 endv=3.5200e-6 cks=949423 fp=17103 fl=0aaf
Forward transformed 25301 22475 8319 to 316.26 224.75 5.20
Aux: M409 F"d99f"
Forward transformed 25301 22081 8326 to 316.26 220.81 5.20
Forward transformed 25301 21442 8339 to 316.26 214.42 5.21
Aux: M409 F"d99f"
Transformed 335.75 224.70 5.18 to 26860 22470 8293 0
Forward transformed 25301 20644 8356 to 316.26 206.44 5.22
File: G1 Z6.1 F30000
AddLin: st=3223471663 steps=1560.0
addlin 1 ts=3223471663 DDA: start=[316.250000 205.250000 5.224679 -0.000000] end=[335.750000 205.250000 5.206129 -0.000000] s=1.9500e+1 vec=[1.000000 0.000000 -0.000951 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.020486]
a=5.1200e-10 d=5.1200e-10 reqv=2.1333e-5 startv=3.5200e-6 topv=2.1333e-5 endv=3.5200e-6 cks=943115 fp=17141 fl=0aaf
pp: td=1.950e+1 ad=4.323e-1 dsd=1.907e+1 a=5.120e-10 d=5.120e-10 ac=34792 sc=873531 dc=34792
Add seg: st=3223471663 t=34792 dist=34.59 u=2.816e-4 a=4.096e-8 f=00
Add seg: st=3223506455 t=873531 dist=1490.82 u=1.707e-3 a=0.000e+0 f=00
Add seg: st=3224379986 t=34792 dist=34.59 u=1.707e-3 a=-4.096e-8 f=00
AddLin: st=3223471663 steps=-29.0
addlin 1 ts=3223471663 DDA: start=[316.250000 205.250000 5.224679 -0.000000] end=[335.750000 205.250000 5.206129 -0.000000] s=1.9500e+1 vec=[1.000000 0.000000 -0.000951 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.020486]
a=5.1200e-10 d=5.1200e-10 reqv=2.1333e-5 startv=3.5200e-6 topv=2.1333e-5 endv=3.5200e-6 cks=943115 fp=17141 fl=0aaf
pp: td=1.950e+1 ad=4.323e-1 dsd=1.907e+1 a=5.120e-10 d=5.120e-10 ac=34792 sc=873531 dc=34792
Add seg: st=3223471663 t=34792 dist=-0.64 u=-5.235e-6 a=-7.614e-10 f=00
Add seg: st=3223506455 t=873531 dist=-27.71 u=-3.173e-5 a=0.000e+0 f=00
Add seg: st=3224379986 t=34792 dist=-0.64 u=-3.173e-5 a=7.614e-10 f=00
AddLin: st=3223471663 steps=312.8
addlin 1 ts=3223471663 DDA: start=[316.250000 205.250000 5.224679 -0.000000] end=[335.750000 205.250000 5.206129 -0.000000] s=1.9500e+1 vec=[1.000000 0.000000 -0.000951 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.020486]
a=5.1200e-10 d=5.1200e-10 reqv=2.1333e-5 startv=3.5200e-6 topv=2.1333e-5 endv=3.5200e-6 cks=943115 fp=17141 fl=0aaf
pp: td=1.950e+1 ad=4.323e-1 dsd=1.907e+1 a=5.120e-10 d=5.120e-10 ac=34792 sc=873531 dc=34792
Add seg: st=3223471663 t=34792 dist=6.93 u=5.646e-5 a=8.213e-9 f=00
Add seg: st=3223506455 t=873531 dist=298.92 u=3.422e-4 a=0.000e+0 f=00
Add seg: st=3224379986 t=34792 dist=6.93 u=3.422e-4 a=-8.213e-9 f=00
pr 2 ts=3223471663 DDA: start=[316.250000 205.250000 5.224679 -0.000000] end=[335.750000 205.250000 5.206129 -0.000000] s=1.9500e+1 vec=[1.000000 0.000000 -0.000951 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.020486]
a=5.1200e-10 d=5.1200e-10 reqv=2.1333e-5 startv=3.5200e-6 topv=2.1333e-5 endv=3.5200e-6 cks=943115 fp=17141 fl=0aaf
Transformed 335.75 224.70 5.18 to 26860 22470 8293 0
Transformed 335.75 224.70 5.88 to 26860 22470 9413 0
File: G1 X335.75 Y224.75 Z6.1
Transformed 335.75 224.75 5.88 to 26860 22475 9413 0
File: G1 Z5.7
Transformed 335.75 224.75 5.48 to 26860 22475 8773 0
File: G1 E.5 F2100
Transformed 335.75 224.75 5.48 to 26860 22475 8773 0
File: G1 F1200
Transformed 335.75 224.75 5.48 to 26860 22475 8773 0
File: G1 X316.25 Y224.75 E.39947
Transformed 316.25 224.75 5.50 to 25300 22475 8798 0
File: M73 P25 R5
File: G1 X316.25 Y205.25 E.39947
File: M73 P25 R5
File: M73 P25 R4
File: G1 X335.75 Y205.25 E.39947
Aux: M409 F"d99f"
Forward transformed 25658 20526 8353 to 320.73 205.26 5.22
Forward transformed 26093 20526 8345 to 326.16 205.26 5.22
Aux: M409 F"d99f"
Forward transformed 26551 20526 8336 to 331.89 205.26 5.21
AddLin: st=3224414778 steps=1945.0
addlin 1 ts=3224414778 DDA: start=[335.750000 205.250000 5.206129 -0.000000] end=[335.750000 224.699997 5.183259 -0.000000] s=1.9450e+1 vec=[0.000000 0.999999 -0.001176 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.020486]
a=5.1200e-10 d=5.1200e-10 reqv=2.1333e-5 startv=3.5200e-6 topv=2.1333e-5 endv=0.0000e+0 cks=947079 fp=17168 fl=0aaf
pp: td=1.945e+1 ad=4.323e-1 dsd=1.901e+1 a=5.120e-10 d=5.120e-10 ac=34792 sc=870620 dc=41667
Add seg: st=3224414778 t=34792 dist=43.23 u=3.520e-4 a=5.120e-8 f=00
Add seg: st=3224449570 t=870620 dist=1857.32 u=2.133e-3 a=0.000e+0 f=00
Add seg: st=3225320190 t=41667 dist=44.44 u=2.133e-3 a=-5.120e-8 f=00
AddLin: st=3224414778 steps=-37.0
addlin 1 ts=3224414778 DDA: start=[335.750000 205.250000 5.206129 -0.000000] end=[335.750000 224.699997 5.183259 -0.000000] s=1.9450e+1 vec=[0.000000 0.999999 -0.001176 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.020486]
a=5.1200e-10 d=5.1200e-10 reqv=2.1333e-5 startv=3.5200e-6 topv=2.1333e-5 endv=0.0000e+0 cks=947079 fp=17168 fl=0aaf
pp: td=1.945e+1 ad=4.323e-1 dsd=1.901e+1 a=5.120e-10 d=5.120e-10 ac=34792 sc=870620 dc=41667
Add seg: st=3224414778 t=34792 dist=-0.82 u=-6.696e-6 a=-9.740e-10 f=00
Add seg: st=3224449570 t=870620 dist=-35.33 u=-4.058e-5 a=0.000e+0 f=00
Add seg: st=3225320190 t=41667 dist=-0.85 u=-4.058e-5 a=9.740e-10 f=00
AddLin: st=3224414778 steps=312.0
addlin 1 ts=3224414778 DDA: start=[335.750000 205.250000 5.206129 -0.000000] end=[335.750000 224.699997 5.183259 -0.000000] s=1.9450e+1 vec=[0.000000 0.999999 -0.001176 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.020486]
a=5.1200e-10 d=5.1200e-10 reqv=2.1333e-5 startv=3.5200e-6 topv=2.1333e-5 endv=0.0000e+0 cks=947079 fp=17168 fl=0aaf
pp: td=1.945e+1 ad=4.323e-1 dsd=1.901e+1 a=5.120e-10 d=5.120e-10 ac=34792 sc=870620 dc=41667
Add seg: st=3224414778 t=34792 dist=6.93 u=5.646e-5 a=8.213e-9 f=00
Add seg: st=3224449570 t=870620 dist=297.92 u=3.422e-4 a=0.000e+0 f=00
Add seg: st=3225320190 t=41667 dist=7.13 u=3.422e-4 a=-8.213e-9 f=00
pr 2 ts=3224414778 DDA: start=[335.750000 205.250000 5.206129 -0.000000] end=[335.750000 224.699997 5.183259 -0.000000] s=1.9450e+1 vec=[0.000000 0.999999 -0.001176 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.020486]
a=5.1200e-10 d=5.1200e-10 reqv=2.1333e-5 startv=3.5200e-6 topv=2.1333e-5 endv=0.0000e+0 cks=947079 fp=17168 fl=0aaf
Transformed 316.25 205.25 5.52 to 25300 20525 8839 0
File: M73 P25 R4
File: G1 X335.75 Y224.7 E.39845
Aux: M409 F"d99f"
Forward transformed 26860 20674 8328 to 335.75 206.74 5.20
Forward transformed 26860 21407 8314 to 335.75 214.07 5.20
Aux: M409 F"d99f"
Forward transformed 26860 21968 8303 to 335.75 219.68 5.19[Warning: 7644 received bytes dropped.]

droftarts

@bugpwr Thanks, I've asked @dc42 to have a look, see if he can see what's going on, as I'm not sure how to read the 'move' output.

Ian

dc42

@bugpwr I've taken a look at your debug output and I don't see anything abnormal in it. I can see the 10mm reprime move being generated correctly. After that I see some small extruder movements in combination with XYZ movements as commanded by the file.

Are you certain that the 10mm retract operation is being performed correctly? It might be helpful to try the pause/resume with the nozzle removed so that you can see whether the correct amount of filament is being retracted. If the retraction is not being fully performed, that would account for the reprime move ending up with the extruder skipping that we can hear. Perhaps you should try reducing the speed of that retraction in pause.g.

If that doesn't resolve it, please can you try putting a G1 G4 S2 command at the end of resume.g to add a 2 second delay. Then see whether the uncommanded extrusion follows on immediately from the 10mm reprime move (before the delay), or after the delay.

jay_s_uk

@bugpwr dc42 means G4 S2 and not G1 S2

bugpwr

@dc42 hi dc42, first - thanks for stepping in, this is much appreciated.
I have performed the experiments. Starting from the end - after adding the G4 delay, it's seen clearly that this extra E move happens after the whole file. (should I try adding M400 before the wait?)
The "redundant extrusion" happens very fast, unaffected by the F parameter in "G1 E10 F300" from resume.g, while the priming move is indeed affected by the F setting (with F300 for example, it is fairly slow and completed just fine, but then comes that extra move which is ultra fast and causes extruder skips). By the way, the F300 speed would not cause the skips, it would just extrude the filament. I tried making this even slower and I see the change in the normal priming move.

So, the source of the move is elsewhere (my honest guess would be that it has something to do with the "confinement" of relative move coordinates between the macro and the job file and switching between the two, but I have no evidence). Also, judging by the speed of this, it does not seem to come from any "actual" gcode in any of the files.

Here's another strange observation that is probably unrelated but may provide some useful evidence: the print head does not decend to the model before the G4 wait I have inserted; instead, it remains 5mm above the model, then the wait, then the failed extrusion, and then the print proceeds with print head descending to the last move. Thanks again, P

Notepad

It might be just coincidence, but I remember having a similar issues all the way back in 3.5.0 and never found a fix for it
https://forum.duet3d.com/topic/35544/resume-g-activating-twice-with-fw3-5

droftarts

@Notepad Thanks, I knew there was another report of something similar, couldn't find it! Do you still have this problem?

Ian