Odd G4 Behaviour from Macro called from SD File
-
@NineMile That is a pretty complex test setup you have there I doubt if anyone will be able to reproduce it. I think you will need to try and simplify things if we are to get to the root cause of the problems. I'm struggling to imagine how adding m400 to the script would cause it to hang as well. It would be good to have simple test cases we can use to try and reproduce those problems.
-
@gloomyandy said in Odd G4 Behaviour from Macro called from SD File:
@NineMile That is a pretty complex test setup you have there I doubt if anyone will be able to reproduce it. I think you will need to try and simplify things if we are to get to the root cause of the problems. I'm struggling to imagine how adding m400 to the script would cause it to hang as well. It would be good to have simple test cases we can use to try and reproduce those problems.
I'll see if I can simplify the setup to reproduce the issue easier. Will reply once I have a simpler repro.
On the
M400
front, I think the behaviour withM598
is the same and I grabbed the output ofM122
while the job was stuck processing.HTTP
doingM25
was because I clicked the pause button in DWC to try and cancel the job.Movement locks held by File, null HTTP is doing "M25" in state(s) 0 File is doing "M598" in state(s) 0 0, running macro USB is ready with "M122" in state(s) 0 Aux is idle in state(s) 0 Trigger is idle in state(s) 0 Queue is doing "M400" in state(s) 0 0, running macro LCD is idle in state(s) 0 Daemon is doing "G4 P{global.mosDAEUR}" in state(s) 0 0, running macro Autopause is idle in state(s) 0 File2 is idle in state(s) 0, sync state 1 Queue2 is idle in state(s) 0 Q0 segments left 0, axes/extruders owned 0x0000003 Queue 0 has 'M3.9 P0 S24000' for move 43 Queue 0 has 'M3.9 P0 S12000' for move 45 Queue 0 has 'M3.9 P0 S24000' for move 47 Queue 0 has 'M3.9 P0 S12000' for move 49 Queue 0 has 'M3.9 P0 S24000' for move 51 Queue 0 has 'M3.9 P0 S12000' for move 53 Queue 0 has 'M3.9 P0 S24000' for move 55 Queue 0 has 'M3.9 P0 S12000' for move 57 Queue 0 has 'M3.9 P0 S24000' for move 59 Q1 segments left 0, axes/extruders owned 0x0000000 Code queue 1 is empty
Which looks to me like it has queued
M3.9
commands to be interspersed with the move queue, but theM3.9
macro is waiting for the queued moves to finish - and they can't finish because they're waiting for the queue to empty. -
@gloomyandy I've tried to simplify this as much as possible (using
M3.8
so is not touching the complexM3.9
command from above)M3.8.g
:if { !inputs[state.thisInput].active } M99 var dwellTime = 10 M3 P0 S{param.S} echo { "[L=" ^ line ^ " T=" ^ state.time ^ "] Waiting " ^ var.dwellTime ^ " seconds for spindle to change speed - #" ^ param.I } G4 S{var.dwellTime} echo { "[L=" ^ line ^ " T=" ^ state.time ^ "] Finished waiting for spindle to change speed - #" ^ param.I }
test.gcode
:(Home) G28 (Movement Configuration) G90 G21 (Park ppindle) G0 Z0 (Move to center of table) G0 X150 Y150 (Start spindle) echo {"[L=" ^ line ^ " T=" ^ state.time ^ "] Running M3.8 #1" } M3.8 S24000 I1 echo {"[L=" ^ line ^ " T=" ^ state.time ^ "] M3.8 Complete #1" } (Do some moves) G0 X100 Y100 G0 X0 Y200 G0 X200 Y0 G0 X100 Y100 G0 X40 Y80 (Change spindle speed) echo {"[L=" ^ line ^ " T=" ^ state.time ^ "] Running M3.8 #2" } M3.8 S12000 I2 echo {"[L=" ^ line ^ " T=" ^ state.time ^ "] M3.8 Complete #2" } (Do some more moves) G0 X50 Y100 G0 X0 Y200 G0 X200 Y0 G0 X100 Y100 G0 X80 Y40 G0 X150 Y150 (Stop spindle) echo {"[L=" ^ line ^ " T=" ^ state.time ^ "] Running M3.8 #3" } M3.8 S0 I3 echo {"[L=" ^ line ^ " T=" ^ state.time ^ "] M3.8 Complete #3" } G0 X0 Y0 echo { "[L=" ^ line ^ " T=" ^ state.time ^ "] File complete" }
When running the
test.gcode
file, I would (naively I guess) expect there to be a 10 second pause after the machine moves to the centre of the table, and then another 10 second pause after 5 moves. I'd then expect the final 10 second wait to stop the spindle and then a move toX150 Y150
.What actually happens is
M3.8
is triggered as soon as the machine starts moving from the home location toX150 Y150
, and then the machine continues moving from the centre point straight away, logging that it is waiting but actually proceeding with the moves. It then runs the nextM3.8
command and completes that command before theG4
from the previous call toM3.8
has finished.After that point I'm not entirely sure what happens, but there is a 17 second delay after the
File Complete
message before the job actually completes, which makes me think there are multipleG4
s in the queue still being processed sequentially.Full log of the file running in the screenshot below:
I haven't managed to get any particularly useful info from interspersing
M122
into the print (I'm not even sure how to do this properly given that they're queued differently, aside fromFile
processing the movement commands (and theM3.8
macro) and theG4
commands ending up inQueue
:Movement locks held by null, null HTTP is idle in state(s) 0 File is doing "G0 X40 Y80" in state(s) 0 USB is ready with "M122" in state(s) 0 Aux is idle in state(s) 0 Trigger is idle in state(s) 0 Queue is doing "G4 S{var.dwellTime}" in state(s) 0 0, running macro LCD is idle in state(s) 0 Daemon is doing "G4 P{global.mosDAEUR}" in state(s) 0 0, running macro Autopause is idle in state(s) 0 File2 is idle in state(s) 0, sync state 2 Queue2 is idle in state(s) 0 Q0 segments left 1, axes/extruders owned 0x0000007 Code queue 0 is empty Q1 segments left 0, axes/extruders owned 0x0000000 Code queue 1 is empty
-
@NineMile What happens without the M3 commands in your files? I have no way of running those commands, so really need an example without them.
-
@gloomyandy Just to be clear I mean the actual M3 spindle control commands not the M3.8 ones.
-
@gloomyandy said in Odd G4 Behaviour from Macro called from SD File:
@gloomyandy Just to be clear I mean the actual M3 spindle control commands not the M3.8 ones.
With the
M3 P0 S{param.S}
line removed I see the following, and no pause in movement after 5 moves - so it looks like the behaviour is the same even without theM3
. -
@NineMile If you substitute M98 calls to your M3.8 macro does the test do what you expect? I've just tried that on my test system and it seems to work as you might expect it to work. So I basically replaced
M3.8 S24000 I1
with
M98 p"M3.8.g" S24000 I1
and made similar changes to other parts of the test (noting the change to the parameters).So this is the test file I have been using (I had to make some changes because I can't run in CNC mode):
;(Home) ;G28 ;(Movement Configuration) G90 G21 ;(Park ppindle) G0 Z10 ;(Move to center of table) G0 X150 Y150 ;(Start spindle) echo {"[L=" ^ line ^ " T=" ^ state.time ^ "] Running M3.8 #1" } ;M3.8 S24000 I1 M98 p"M3.8.g" S24000 I1 echo {"[L=" ^ line ^ " T=" ^ state.time ^ "] M3.8 Complete #1" } ;(Do some moves) G0 X100 Y100 G0 X0 Y200 G0 X200 Y0 G0 X100 Y100 G0 X40 Y80 ;(Change spindle speed) echo {"[L=" ^ line ^ " T=" ^ state.time ^ "] Running M3.8 #2" } ;M3.8 S12000 I2 M98 p"M3.8.g" S12000 I2 echo {"[L=" ^ line ^ " T=" ^ state.time ^ "] M3.8 Complete #2" } ;(Do some more moves) G0 X50 Y100 G0 X0 Y200 G0 X200 Y0 G0 X100 Y100 G0 X80 Y40 G0 X150 Y150 ;(Stop spindle) echo {"[L=" ^ line ^ " T=" ^ state.time ^ "] Running M3.8 #3" } ;M3.8 S0 I3 M98 p"M3.8.g" S0 I3 echo {"[L=" ^ line ^ " T=" ^ state.time ^ "] M3.8 Complete #3" } G0 X0 Y0 echo { "[L=" ^ line ^ " T=" ^ state.time ^ "] File complete" }
Without the above change, I think I'm basically seeing what you are seeing with the dwell commands not running until the end of the file (at least that is what it looks like, it is a little confusing).
-
@gloomyandy said in Odd G4 Behaviour from Macro called from SD File:
@NineMile If you substitute M98 calls to your M3.8 macro does the test do what you expect? I've just tried that on my test system and it seems to work as you might expect it to work. So I basically replaced
M3.8 S24000 I1
with
M98 p"M3.8.g" S24000 I1
and made similar changes to other parts of the test (noting the change to the parameters).So this is the test file I have been using (I had to make some changes because I can't run in CNC mode):
;(Home) ;G28 ;(Movement Configuration) G90 G21 ;(Park ppindle) G0 Z10 ;(Move to center of table) G0 X150 Y150 ;(Start spindle) echo {"[L=" ^ line ^ " T=" ^ state.time ^ "] Running M3.8 #1" } ;M3.8 S24000 I1 M98 p"M3.8.g" S24000 I1 echo {"[L=" ^ line ^ " T=" ^ state.time ^ "] M3.8 Complete #1" } ;(Do some moves) G0 X100 Y100 G0 X0 Y200 G0 X200 Y0 G0 X100 Y100 G0 X40 Y80 ;(Change spindle speed) echo {"[L=" ^ line ^ " T=" ^ state.time ^ "] Running M3.8 #2" } ;M3.8 S12000 I2 M98 p"M3.8.g" S12000 I2 echo {"[L=" ^ line ^ " T=" ^ state.time ^ "] M3.8 Complete #2" } ;(Do some more moves) G0 X50 Y100 G0 X0 Y200 G0 X200 Y0 G0 X100 Y100 G0 X80 Y40 G0 X150 Y150 ;(Stop spindle) echo {"[L=" ^ line ^ " T=" ^ state.time ^ "] Running M3.8 #3" } ;M3.8 S0 I3 M98 p"M3.8.g" S0 I3 echo {"[L=" ^ line ^ " T=" ^ state.time ^ "] M3.8 Complete #3" } G0 X0 Y0 echo { "[L=" ^ line ^ " T=" ^ state.time ^ "] File complete" }
Without the above change, I think I'm basically seeing what you are seeing with the dwell commands not running until the end of the file (at least that is what it looks like, it is a little confusing).
Yep using
M98 P"M3.8.g"...
works as I would expect - so there's a difference in the wayM98
runs macros vs how macros are run when they're called directly by their M-Code?What's the chances that these can be made to work in the same manner?
I tried using an intermediate macro (So the gcode runs
M3.7
andM3.7
runsM98 P"M3.8.g" ...
but that exhibited the previous ("broken") behaviour. -
-
-
-
@NineMile said in Odd G4 Behaviour from Macro called from SD File:
Notes: RRF 3.5.0-rc3 stm32, not the version that fixes the multiple movement systems issues but I have code at the top of all of my macros to stop them executing in the secondary movement system.
If this issue occurs only when the macro is called from a job file then please try a more recent firmware build.
-
@dc42 I've tried the same code with yesterday's build and it did the same thing for me.See this post for details: https://forum.duet3d.com/post/336370
-
@dc42 Just to clear with the build as of 27th Mar, the version of the file using M3.8 directly does not seem to delay when you might expect it to. The version using M98 to run the same macro file does delay as expected.
I've just tried the same test files on a Duet3 running 3.5.0-rc.3+8 and see the same "odd" behaviour with the macro being "called" as a substitute for a gcode then the dwell does not happen when expected (they seem to happen at the end of the print), but with the same macro call using M98 then the dwell happens as expected.
These are the test files I used on the duet3, first the file I print (from my "jobs" directory):
G92 X0 Y0 M564 H0 ;(Home) ;G28 ;(Movement Configuration) G90 G21 ;(Park ppindle) ;(Move to center of table) G0 X150 ;(Start spindle) echo {"[L=" ^ line ^ " T=" ^ state.time ^ "] Running M3.8 #1" } M3.8 S24000 I1 ;M98 p"M3.8.g" S24000 I1 echo {"[L=" ^ line ^ " T=" ^ state.time ^ "] M3.8 Complete #1" } ;(Do some moves) G0 X100 G0 X0 G0 X200 G0 X100 G0 X40 ;(Change spindle speed) echo {"[L=" ^ line ^ " T=" ^ state.time ^ "] Running M3.8 #2" } M3.8 S12000 I2 ;M98 p"M3.8.g" S12000 I2 echo {"[L=" ^ line ^ " T=" ^ state.time ^ "] M3.8 Complete #2" } ;(Do some more moves) G0 X50 G0 X0 G0 X200 G0 X100 G0 X80 G0 X150 ;(Stop spindle) echo {"[L=" ^ line ^ " T=" ^ state.time ^ "] Running M3.8 #3" } M3.8 S0 I3 ;M98 p"M3.8.g" S0 I3 echo {"[L=" ^ line ^ " T=" ^ state.time ^ "] M3.8 Complete #3" } G0 X0 echo { "[L=" ^ line ^ " T=" ^ state.time ^ "] File complete" }
Then the M3.8 macro (that goes in system):
;if { !inputs[state.thisInput].active } ; M99 var dwellTime = 10 echo { "[L=" ^ line ^ " T=" ^ state.time ^ "] Waiting " ^ var.dwellTime ^ " seconds for spindle to change speed - #" ^ param.I } G4 S{var.dwellTime} echo { "[L=" ^ line ^ " T=" ^ state.time ^ "] Finished waiting for spindle to change speed - #" ^ param.I }
Note my Duet3 is a bench test system that only has a single stepper motor attached (as X) and has no homing switches hence the changes to allow the print file to run. I don't think any of these changes make any difference to the problem described here.