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