tool change macro issue

jag

I am running RRF 3.0 on a Duet 2 Wifi.
My setup has 2 extruders with a RC servo to lift the one that is not in use.
Everything was working fine until yesterday. I was making a number of changes to the config file, nothing drastic. I think I just changed some of the settings for the extruder cooling fan.
Now, when I attempt to change tools, the M280 commands in the tpre0 and tpre1 get stuck in the queue and nothing runs after that.
The commands in the tpre macros are just:
M280 P0 S110
and
M280 P1 S58

I'm not sure what the extra code showing up in the queue is.
If I run the M280 commands directly, I don't have any problem. The servo moves as commanded.
Today I updated to the 3.0 release version. There was no change.
Does anyone have any idea what is going on?

1/14/2020, 10:58:06 AM	M122
=== Diagnostics ===
RepRapFirmware for Duet 2 WiFi/Ethernet version 3.0 running on Duet Ethernet 1.02 or later
Board ID: 08DGM-9T6BU-FG3S0-7JTDD-3S06T-1B4ZF
Used output buffers: 3 of 24 (15 max)
=== RTOS ===
Static ram: 30516
Dynamic ram: 91916 of which 0 recycled
Exception stack ram used: 472
Never used ram: 8168
Tasks: NETWORK(ready,640) HEAT(blocked,1232) MAIN(running,3676) IDLE(ready,156)
Owned mutexes:
=== Platform ===
Last reset 00:01:51 ago, cause: software
Last software reset at 2020-01-14 10:56, reason: User, spinning module GCodes, available RAM 8168 bytes (slot 0)
Software reset code 0x0003 HFSR 0x00000000 CFSR 0x00000000 ICSR 0x0441f000 BFAR 0xe000ed38 SP 0xffffffff Task 0x4e49414d
Error status: 0
Free file entries: 10
SD card 0 detected, interface speed: 20.0MBytes/sec
SD card longest block write time: 7.0ms, max retries 0
MCU temperature: min 26.0, current 26.4, max 26.6
Supply voltage: min 24.1, current 24.2, max 24.2, under voltage events: 0, over voltage events: 0, power good: yes
Driver 0: standstill, SG min/max not available
Driver 1: standstill, SG min/max not available
Driver 2: standstill, SG min/max not available
Driver 3: standstill, SG min/max not available
Driver 4: standstill, SG min/max not available
Date/time: 2020-01-14 10:58:04
Cache data hit count 189777812
Slowest loop: 9.97ms; fastest: 0.10ms
I2C nak errors 0, send timeouts 0, receive timeouts 0, finishTimeouts 0, resets 0
=== Move ===
Hiccups: 0(0), FreeDm: 169, MinFreeDm: 169, MaxWait: 0ms
Bed compensation in use: none, comp offset 0.000
=== MainDDARing ===
Scheduled moves: 7, completed moves: 4, StepErrors: 0, LaErrors: 0, Underruns: 0, 0
=== AuxDDARing ===
Scheduled moves: 0, completed moves: 0, StepErrors: 0, LaErrors: 0, Underruns: 0, 0
=== Heat ===
Bed heaters = 0 -1 -1 -1, chamberHeaters = -1 -1 -1 -1
Heater 1 is on, I-accum = 0.0
=== GCodes ===
Segments left: 1
Stack records: 2 allocated, 0 in use
Movement lock held by null
http is idle in state(s) 0
telnet is idle in state(s) 0
file is idle in state(s) 0
serial is idle in state(s) 0
aux is idle in state(s) 0
daemon is idle in state(s) 0
queue is idle in state(s) 0
autopause is idle in state(s) 0
Code queue is not empty:
Queued 'M280 P0 S58 I1ter5" S58 I1�yς��u�ԍ3h6T��<'7��am�5��K>��Z�{' for move 7
Queued 'M280 P0 S110eater5" S110 I1ruderrX�C%'���' for move 7
2 of 16 codes have been queued.
=== Network ===
Slowest loop: 48.59ms; fastest: 0.05ms
Responder states: HTTP(0) HTTP(0) HTTP(0) HTTP(0) FTP(0) Telnet(0)
HTTP sessions: 2 of 8
Interface state 5, link 100Mbps full duplex

Danal

This is a real long shot... I have seen a few oddities in R3 with toolchange macros solved by putting an M400 at the beginning of all the macros.

Again, not a good fit for your exact symptom, but it is very quick to try.

jag

@Danal Thanks for the suggestion.
For a minute, I thought it had fixed it. I turned the machine on this morning, added an M400 to the beginning of the two macros (tpre0 and tpre1) and it was working like a charm.
Then I made some modifications to them (I made them call another macro that does the actual servo moves) but I left the M400 in (and added it to the other macros as well).
It worked for a while, until a reboot and now it's all broken again.
I changed it back to just the M400 and M280 P0 S110 and it still doesn't work.
From looking at the queue in the M122 output, it looks like it is continuing to read past the EOF of the macro.
There is some garbage in the queue that appears to be code from previous revisions of the macro.
So, I tried putting an M99 at the end of the macro figuring that would make it exit even if it is ignoring the EOF.
That unfortunately didn't fix it. The queue is still showing some gibberish after the gcode:
Queued 'M280 P0 S58�D�M�>(��F��a��hgM6"��V�(�D'r�?�G�n$��~UT' for move 7

I can't figure out why it was working for a little while and now it isn't.

dc42

Please check that the problem still occurs in 3.01beta1. Then post your config.g file and tool change files.

jag

@dc42 It does still occur with 3.01b1.
Here are my config files and my tpre files.
Let me know if I am missing something obvious.
Thanks!

config.g
tpre0.g
tpre1.g

Danal

I realize this appears to be a flaw with the end of the tpre... nonetheless, may we see your tpost and tfree as well?

And, even longer shot... M400 at beginning and end of each.

Danal

Oh, and HUGELY long shot. Format a different SD and copy everything over.

jag

Tfree for both tools is empty (just comments at the top):

; tfree1.g
; called when tool 1 is freed
;
; generated by RepRapFirmware Configuration Tool v2 on Thu Jan 10 2019 13:50:44 GMT-0500 (EST)

There is no tpost for either tool.
I had been thinking of the SD card route. I just got a new SD card and tried it (I backed the old one up with tar and unpacked it onto the new card).
Same deal.

I just deleted the tfree files so that there are only tpre macros. Same behavior.
I added M400 to the end of both the macros (after the M99 so it should theoretically be skipped anyway). No change.
I added it before the M99, still the same.

Interestingly, the selected tool does change in the web UI. If I attempt to move the machine (G0 Z100 for example), the machine does not move but the web UI location does change.

jag

I seem to have found a workaround. I'm not sure if it will continue to work.
I changed the macro to have a relative move before and after the M280 servo command. Suddenly it started working.
So, now my code is:

M400
G91
G0 Z5 F4000
M280 P0 S110
G0 Z-5
M400
M99

jag

Nevermind. I made another change to the config.g (reduced the extruder cooling fan speed to make it quieter) and now it isn't working again.
Strange...

jag

And interestingly, the symptoms in the output from M122 are different:
Now it gets stuck with:
=== GCodes ===
Segments left: 1
Movement lock held by http
http is doing "M280 P0 S110" in state(s) 0 11, running macro

1/16/2020, 12:46:14 PM	m122
=== Diagnostics ===
RepRapFirmware for Duet 2 WiFi/Ethernet version 3.01-beta1 running on Duet Ethernet 1.02 or later
Board ID: 08DGM-9T6BU-FG3S0-7JTDD-3S06T-1B4ZF
Used output buffers: 3 of 24 (11 max)
=== RTOS ===
Static ram: 27984
Dynamic ram: 92600 of which 0 recycled
Exception stack ram used: 480
Never used ram: 10008
Tasks: NETWORK(ready,644) HEAT(blocked,1240) MAIN(running,1844) IDLE(ready,76)
Owned mutexes:
=== Platform ===
Last reset 00:00:53 ago, cause: software
Last software reset at 2020-01-16 12:45, reason: User, spinning module GCodes, available RAM 10008 bytes (slot 2)
Software reset code 0x0003 HFSR 0x00000000 CFSR 0x00000000 ICSR 0x0041f000 BFAR 0xe000ed38 SP 0xffffffff Task 0x4e49414d
Error status: 0
Free file entries: 9
SD card 0 detected, interface speed: 20.0MBytes/sec
SD card longest block write time: 0.0ms, max retries 0
MCU temperature: min 23.4, current 23.6, max 24.2
Supply voltage: min 24.1, current 24.2, max 24.3, under voltage events: 0, over voltage events: 0, power good: yes
Driver 0: standstill, SG min/max not available
Driver 1: standstill, SG min/max not available
Driver 2: standstill, SG min/max 221/370
Driver 3: standstill, SG min/max not available
Driver 4: standstill, SG min/max not available
Date/time: 2020-01-16 12:46:10
Cache data hit count 91184188
Slowest loop: 2.36ms; fastest: 0.09ms
I2C nak errors 0, send timeouts 0, receive timeouts 0, finishTimeouts 0, resets 0
=== Move ===
Hiccups: 0(0), FreeDm: 169, MinFreeDm: 166, MaxWait: 36518ms
Bed compensation in use: none, comp offset 0.000
=== MainDDARing ===
Scheduled moves: 7, completed moves: 4, StepErrors: 0, LaErrors: 0, Underruns: 0, 0
=== AuxDDARing ===
Scheduled moves: 0, completed moves: 0, StepErrors: 0, LaErrors: 0, Underruns: 0, 0
=== Heat ===
Bed heaters = 0 -1 -1 -1, chamberHeaters = -1 -1 -1 -1
=== GCodes ===
Segments left: 1
Movement lock held by http
http is doing "M280 P0 S110" in state(s) 0 11, running macro
telnet is idle in state(s) 0
file is idle in state(s) 0
serial is idle in state(s) 0
aux is idle in state(s) 0
daemon is idle in state(s) 0
queue is idle in state(s) 0
autopause is idle in state(s) 0
Code queue is empty.
=== Network ===
Slowest loop: 8.20ms; fastest: 0.02ms
Responder states: HTTP(0) HTTP(0) HTTP(0) HTTP(0) FTP(0) Telnet(0)
HTTP sessions: 1 of 8
Interface state 5, link 100Mbps full duplex

jag

It is currently working again. I'm not sure what happened. I thought the problem might have been that my homeall.g called my homez.g with an M98 with no quotes around the filename. I modified my homeall to not call the homez (and a few other tweaks) and everything suddenly started working. But, when I put the bad M98 back in (with no quotes, just to see if it would fail), I couldn't reproduce the problem.