Duet3D Logo Duet3D
    • Tags
    • Documentation
    • Order
    • Register
    • Login

    Odd G4 Behaviour from Macro called from SD File

    Scheduled Pinned Locked Moved Unsolved
    Gcode meta commands
    3
    13
    318
    Loading More Posts
    • Oldest to Newest
    • Newest to Oldest
    • Most Votes
    Reply
    • Reply as topic
    Log in to reply
    This topic has been deleted. Only users with topic management privileges can see it.
    • NineMileundefined
      NineMile
      last edited by NineMile

      As part of the safety system for a machine, I've written M3.9 and M5.9 macros which take the place of the M3 and M5 spindle commands - the idea is that a post-processor can call M3.9 instead of the usual M3 command and this will add an operator confirmation via an M291 call if the spindle is currently off, as well as waiting a period of time for the spindle to accelerate before proceeding on to cutting.

      This delay time is machine and spindle specific which means it should be handled within the macro system I'm writing, because there are situations where the machine itself needs to stop and start the spindle outside of the control of the post-processor (e.g. parking and stopping the spindle during a tool change or during pause and resume).

      I'm seeing some odd behaviour when my M3.9 macro is called from a print file, in that it looks like the G4 dwell commands are not queued after the M3 to change the spindle speed, but end up being run after all queued movements have completed (which appears to include queued movements that sequentially would execute after the G4).

      The Command Queueing section of the docs is a bit unclear to me on this front - it seems like movement commands after the call to my macro are being queued before the G4 command at the end of the macro.

      This is backed up by the echo running just before the G4 showing in the console when I would expect the G4 to execute.

      My understanding is that G4 or M400 should wait for all queued moves to complete before executing, but it looks like this is happening out-of-order - as in, the movement commands after the macro call are queued while the macro is running, meaning that the G4 at the end of the macro only gets to run at the end of the file.

      The docs do say that a command is NOT queued if the call contains an OM expression (mine do, obviously) but what does 'not queued' mean in this instance? It doesn't appear to be 'run instantly' and it also doesn't seem to be 'not run at all', it's looking like the G4 is queued but as part of a separate queue which is not executed sequentially with the movement commands and takes lower priority.

      Any ideas here, or ways I can mitigate this behaviour? I've tried an M400 at the top of the M3.9.g file but this seems to cause RRF to get stuck "processing" the job and the only solution is to reboot the mainboard. Same with an M598.

      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.

      My M3.9 looks like this:

      ; M3.9.g: SPINDLE ON, CLOCKWISE - WAIT FOR SPINDLE TO ACCELERATE
;
; It takes a bit of time to spin up the spindle. How long this
; requires depends on the VFD setup and the spindle power. The spindle
; needs to be controlled by both the firmware (for pause / resume
; amongst other things) and the post-processor, so we need an m-code
; that can be used by both and that means our wait-for-spindle dwell
; time only needs to exist in one place.
; USAGE: M3.9 [S<rpm>] [P<spindle-id>] [D<override-dwell-seconds>]

; Make sure this file is not executed by the secondary motion system
if { !inputs[state.thisInput].active }
    M99

var sID = { (exists(param.P) ? param.P : global.mosSID) }

var sStop = { spindles[var.sID].state == "stopped" }
var sNC   = { exists(param.S) && spindles[var.sID].current == param.S }

var dwellTime = 0

; D parameter always overrides the wait time
if { exists(param.D) }
    set var.dwellTime = { param.D }
else
    ; Dwell time defaults to the previously timed spindle acceleration time.
    ; This assumes the spindle is accelerating from a stop.
    set var.dwellTime = { global.mosSAS }

    ; If we're changing spindle speed
    if { exists(param.S) }
        ; If this is a deceleration, adjust dwellTime
        if { spindles[var.sID].current > param.S }
            set var.dwellTime = { global.mosSDS }

        ; Now calculate the change in velocity as a percentage
        ; of the maximum spindle speed, and multiply the dwell time
        ; by that percentage with 5% extra leeway.
        set var.dwellTime = { ceil(var.dwellTime * (abs(spindles[var.sID].current - param.S) / spindles[var.sID].max) * 1.05 * 10)/10 }

var warnMsg = {"<b>CAUTION</b>: Spindle " ^ var.sID ^ " will now start. Check that workpiece and tool are secure, and all safety precautions have been taken before pressing <b>Continue</b>."}

; If the spindle is stopped
if { var.sStop }
    ; If we're running a job, and we're not paused, pausing or resuming
    ; then warn the user and allow them to pause or abort the job.
    if { job.file.fileName != null && var.sStop && !global.mosEM && state.status != "resuming" && state.status != "pausing" && state.status != "paused" }
        M291 P{var.warnMsg} R"MillenniumOS: Warning" S4 K{"Continue", "Pause", "Cancel"} F0
        if { input == 1 }
            M291 P{ "<b>CAUTION</b>: The job has been paused. Clicking <b>""Resume Job""</b> will start the spindle <b>INSTANTLY</b>, with no confirmation.<br/><b>BE CAREFUL!</b>" } R"MillenniumOS: Warning" S2 T0
            M25
        elif { input == 2 }
            abort { "Operator paused spindle startup!" }

    ; Otherwise just warn the user and allow them to abort.
    else
        M291 P{var.warnMsg} R"MillenniumOS: Warning" S4 K{"Continue", "Cancel"} F0
        if { input == 1 }
            abort { "Operator aborted spindle startup!" }

; Spindle can now be started

; Account for all permutations of M3 command
if { exists(param.S) }
    if { exists(param.P) }
        M3 S{param.S} P{param.P}
    else
        M3 S{param.S}
elif { exists(param.P) }
    M3 P{param.P}
else
    M3

if { result != 0 }
    abort { "Failed to control Spindle ID " ^ var.sID ^ "!" }

; Wait for the spindle to change speed
if { var.dwellTime > 0 }
    echo { "Waiting " ^ var.dwellTime ^ " seconds for spindle to change speed" }
    G4 S{var.dwellTime}

      using the following global variables:

      global mosEM = false
global mosSID = 0
global mosSAS = 10
global mosSDS = 10

      and my test gcode file is something like this:

      G28

G90

; Park spindle
G27

G0 X150 Y150

G91

; This call to M3.9 seems to run fine - the spindle is not turned on until clicking Continue in the prompt
; and movement does not commence for a period while the G4 runs
M3.9 S12000

while { iterations < 5 }
    G0 X-15
    G0 Y-15
    G0 X30
    G0 Y30

; This call to M3.9 does not prompt and changes the spindle speed (correct), but does not wait for the spindle
; to change speed (incorrect).
M3.9 S24000

; Neither of the M3.9 commands in here wait for the spindle to change speed either (incorrect)
while { iterations < 5 }
    M3.9 S8000
    G0 X-15
    G0 Y-15
    M3.9 S16000
    G0 X30
    G0 Y30

; End of File - all G4 commands that were executed at the bottom of `M3.9` now run sequentially, delaying the end of the job.
      gloomyandyundefined dc42undefined 2 Replies Last reply Reply Quote 0
      • gloomyandyundefined
        gloomyandy @NineMile
        last edited by

        @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.

        NineMileundefined 1 Reply Last reply Reply Quote 1
        • NineMileundefined
          NineMile @gloomyandy
          last edited by NineMile

          @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 with M598 is the same and I grabbed the output of M122 while the job was stuck processing. HTTP doing M25 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 the M3.9 macro is waiting for the queued moves to finish - and they can't finish because they're waiting for the queue to empty.

          NineMileundefined 1 Reply Last reply Reply Quote 0
          • NineMileundefined
            NineMile @NineMile
            last edited by NineMile

            @gloomyandy I've tried to simplify this as much as possible (using M3.8 so is not touching the complex M3.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 to X150 Y150.

            What actually happens is M3.8 is triggered as soon as the machine starts moving from the home location to X150 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 next M3.8 command and completes that command before the G4 from the previous call to M3.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 multiple G4s in the queue still being processed sequentially.

            Full log of the file running in the screenshot below:

            g4_behaviour.png

            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 from File processing the movement commands (and the M3.8 macro) and the G4 commands ending up in Queue:

            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
            gloomyandyundefined 1 Reply Last reply Reply Quote 0
            • gloomyandyundefined
              gloomyandy @NineMile
              last edited by

              @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.

              gloomyandyundefined 1 Reply Last reply Reply Quote 0
              • gloomyandyundefined
                gloomyandy @gloomyandy
                last edited by

                @gloomyandy Just to be clear I mean the actual M3 spindle control commands not the M3.8 ones.

                NineMileundefined 1 Reply Last reply Reply Quote 0
                • NineMileundefined
                  NineMile @gloomyandy
                  last edited by NineMile

                  @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 the M3.

                  g4_behaviour_no_m3.png

                  gloomyandyundefined 1 Reply Last reply Reply Quote 0
                  • gloomyandyundefined
                    gloomyandy @NineMile
                    last edited by

                    @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).

                    NineMileundefined 1 Reply Last reply Reply Quote 1
                    • NineMileundefined
                      NineMile @gloomyandy
                      last edited by

                      @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 way M98 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 and M3.7 runs M98 P"M3.8.g" ... but that exhibited the previous ("broken") behaviour.

                      gloomyandyundefined 1 Reply Last reply Reply Quote 0
                      • gloomyandyundefined
                        gloomyandy @NineMile
                        last edited by

                        @NineMile I think at this point we probably need to @dc42 to have a look at this issue. I'm not sure how using a macros to replace a gcode is supposed to work and if there are any limitations on what you can do in those macros.

                        1 Reply Last reply Reply Quote 0
                        • NineMileundefined NineMile referenced this topic
                        • Phaedruxundefined Phaedrux marked this topic as a question
                        • dc42undefined
                          dc42 administrators @NineMile
                          last edited by

                          @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.

                          Duet WiFi hardware designer and firmware engineer
                          Please do not ask me for Duet support via PM or email, use the forum
                          http://www.escher3d.com, https://miscsolutions.wordpress.com

                          gloomyandyundefined 2 Replies Last reply Reply Quote 0
                          • gloomyandyundefined
                            gloomyandy @dc42
                            last edited by gloomyandy

                            @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

                            1 Reply Last reply Reply Quote 0
                            • gloomyandyundefined
                              gloomyandy @dc42
                              last edited by

                              @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.

                              1 Reply Last reply Reply Quote 0
                              • First post
                                Last post
                              Unless otherwise noted, all forum content is licensed under CC-BY-SA