Pausing during a macro and resuming, same macro is run again?
-
I have had some issues when pausing a printing file that was performing a macro at the time of pause. The macro finishes as usual and then the job is paused. Then when resuming, that same macro is run AGAIN before continuing on to the rest of the file. I understand that for files consisting of mostly G0/G1 commands, this re-running of the last command would be no issue, but for long macros and macros which physically toggle something (in my case pick up an attachment on the toolhead) it can be catastrophic if the macro is run again.
I've had this issue since I got into using the duet3 on rrf3.1.0.Here is a test case:
File in gcodes directory: "pause_macro_issue.nc"
Contents:M98 P"0:/macros/pretendMacro1.g" G4 S0.5 M98 P"0:/macros/pretendMacro2.g" G4 S0.5 M98 P"0:/macros/pretendMacro3.g" G4 S0.5
pretendMacro1.g:
G4 S0.5 M118 P0 S"Part 1 of pretendMacro1" L1 G4 S0.5 M118 P0 S"Part 2 of pretendMacro1" L1 G4 S0.5 M118 P0 S"Part 3 of pretendMacro1" L1 G4 S0.5 M118 P0 S"Part 4 of pretendMacro1" L1
pretendMacro2.g:
G4 S0.5 M118 P0 S"Part 1 of pretendMacro2" L1 G4 S0.5 M118 P0 S"Part 2 of pretendMacro2" L1 G4 S0.5 M118 P0 S"Part 3 of pretendMacro2" L1 G4 S0.5 M118 P0 S"Part 4 of pretendMacro2" L1
pretendMaco3.g:
G4 S0.5 M118 P0 S"Part 1 of pretendMacro3" L1 G4 S0.5 M118 P0 S"Part 2 of pretendMacro3" L1 G4 S0.5 M118 P0 S"Part 3 of pretendMacro3" L1 G4 S0.5 M118 P0 S"Part 4 of pretendMacro3" L1
Logfile output:
2021-04-25 08:00:46 File 0:/gcodes/pause_macro_issue.nc selected for printing 2021-04-25 08:00:46 Part 1 of pretendMacro1 2021-04-25 08:00:47 Part 2 of pretendMacro1 2021-04-25 08:00:47 Part 3 of pretendMacro1 2021-04-25 08:00:48 Part 4 of pretendMacro1 2021-04-25 08:00:49 Part 1 of pretendMacro2 2021-04-25 08:00:50 Part 2 of pretendMacro2 2021-04-25 08:00:50 Part 3 of pretendMacro2 2021-04-25 08:00:51 Part 4 of pretendMacro2 2021-04-25 08:00:51 Printing paused at X1040.5 Y-1284.0 Z0.0 A90.0 B0.0 2021-04-25 08:01:01 Printing resumed 2021-04-25 08:01:01 Printing resumed 2021-04-25 08:01:02 Part 1 of pretendMacro2 2021-04-25 08:01:02 Part 2 of pretendMacro2 2021-04-25 08:01:03 Part 3 of pretendMacro2 2021-04-25 08:01:03 Part 4 of pretendMacro2 2021-04-25 08:01:04 Part 1 of pretendMacro3 2021-04-25 08:01:05 Part 2 of pretendMacro3 2021-04-25 08:01:05 Part 3 of pretendMacro3 2021-04-25 08:01:06 Part 4 of pretendMacro3 2021-04-25 08:01:07 Done printing file 2021-04-25 08:01:07 Done printing file 2021-04-25 08:01:07 Finished printing file 0:/gcodes/pause_macro_issue.nc, print time was 0h 0m
It can be seen from the printout that pretendMacro2.g is run twice.
For now I'm trying to think of a conditional solution in my macros to just ignore the second run... But I feel as if this shouldn't be happening.
If this isn't a bug, is there a way to avoid this issue?
Cheers,
TM112:
m122 === Diagnostics === RepRapFirmware for Duet 3 MB6HC version 3.3beta3.1 (2021-04-26 11:17:17) running on Duet 3 MB6HC v1.01 or later (SBC mode) Board ID: 08DJM-956L2-G43S8-6J9D6-3S46R-KU2AD Used output buffers: 5 of 40 (20 max) === RTOS === Static ram: 150600 Dynamic ram: 61752 of which 0 recycled Never used RAM 92984, free system stack 200 words Tasks: SBC(ready,7.7%,310) HEAT(delaying,0.0%,365) Move(notifyWait,0.0%,300) CanReceiv(notifyWait,0.0%,907) CanSender(notifyWait,0.0%,373) CanClock(delaying,0.0%,353) TMC(notifyWait,7.7%,93) MAIN(running,84.2%,1264) IDLE(ready,0.3%,29), total 100.0% Owned mutexes: HTTP(MAIN) === Platform === Last reset 00:00:31 ago, cause: software Last software reset at 2021-04-25 08:15, reason: User, GCodes spinning, available RAM 92768, slot 0 Software reset code 0x0003 HFSR 0x00000000 CFSR 0x00000000 ICSR 0x0044a000 BFAR 0x00000000 SP 0x00000000 Task SBC Freestk 0 n/a Error status: 0x00 Aux0 errors 0,0,0 Aux1 errors 0,0,0 Step timer max interval 185 MCU temperature: min 58.1, current 58.3, max 58.4 Supply voltage: min 24.1, current 24.1, max 24.1, under voltage events: 0, over voltage events: 0, power good: yes 12V rail voltage: min 12.1, current 12.1, max 12.1, under voltage events: 0 Heap OK, handles allocated/used 99/1, heap memory allocated/used/recyclable 2048/10/0, gc cycles 0 Driver 0: position 0, standstill, reads 44901, writes 19 timeouts 0, SG min/max 0/0 Driver 1: position 0, standstill, reads 44904, writes 16 timeouts 0, SG min/max 0/0 Driver 2: position 0, standstill, reads 44907, writes 14 timeouts 0, SG min/max 0/0 Driver 3: position 0, standstill, reads 44907, writes 14 timeouts 0, SG min/max 0/0 Driver 4: position 0, standstill, reads 44907, writes 14 timeouts 0, SG min/max 0/0 Driver 5: position 0, standstill, reads 44910, writes 11 timeouts 0, SG min/max 0/0 Date/time: 2021-04-25 08:15:55 Slowest loop: 74.73ms; fastest: 0.03ms === Storage === Free file entries: 10 SD card 0 not detected, interface speed: 37.5MBytes/sec SD card longest read time 0.0ms, write time 0.0ms, max retries 0 === Move === DMs created 125, maxWait 0ms, bed compensation in use: none, comp offset 0.000 === MainDDARing === Scheduled moves 0, completed moves 0, hiccups 0, stepErrors 0, LaErrors 0, Underruns [0, 0, 0], CDDA state -1 === AuxDDARing === Scheduled moves 0, completed moves 0, hiccups 0, stepErrors 0, LaErrors 0, Underruns [0, 0, 0], CDDA state -1 === Heat === Bed heaters = -1 -1 -1 -1 -1 -1 -1 -1 -1 -1 -1 -1, chamberHeaters = -1 -1 -1 -1 === GCodes === Segments left: 0 Movement lock held by null HTTP* is doing "M122" 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 Code queue is empty. === CAN === Messages queued 172, send timeouts 0, received 13, lost 0, longest wait 1ms for reply type 6043, peak Tx sync delay 14789, free buffers 49 (min 48) === SBC interface === State: 4, failed transfers: 0 Last transfer: 3ms ago RX/TX seq numbers: 1056/1056 SPI underruns 0, overruns 0 Number of disconnects: 0, IAP RAM available 0x2c8fc Buffer RX/TX: 0/0-0 === Duet Control Server === Duet Control Server v3.3-b3 Code buffer space: 4096 Configured SPI speed: 8000000 Hz Full transfers per second: 34.81 Codes per second: 3.39 Maximum length of RX/TX data transfers: 4912/448
-
what is in your pause.g and resume.g?
How are you pausing? button or gcode? -
@owend pause.g and resume.g just have comments in them. Pausing via button on status page.
-
@tristanryerparke said in Pausing during a macro and resuming, same macro is run again?:
I have had some issues when pausing a printing file that was performing a macro at the time of pause. The macro finishes as usual and then the job is paused. Then when resuming, that same macro is run AGAIN before continuing on to the rest of the file.
When RRF is running in standalone mode, pausing is not possible during execution of a macro, so a pause command will be delayed until the macro has finished. I guess that Duet Control Server doesn't replicate this behaviour. I'll ask @chrishamm to take a look.
-
@tristanryerparke Thanks for reporting this. I can confirm this is a problem in DSF which will be fixed in the upcoming v3.3-RC1.