Error: meta command: Too many indices

Phaedrux

@DonStauffer said in Error: meta command: Too many indices:

This ran successfully with no error 6 times, then the 7th time the Duet 2 WiFi rebooted

Is that repeatable?

DonStauffer

@Phaedrux Repeatable in the sense that if you run it over and over, the reboot will happen, and so far it has always been less than 10 runs. But not always 7. I just made it fail in 2 runs.

DonStauffer

@Phaedrux This macro was a stress test, of course. I don't need an array 12 levels deep. I was going for 6 so I can combine some of my global data to make the global namespace less cluttered. But I decided if the strategy failed, more dimensions would make it fail sooner.

DonStauffer

@Phaedrux This one I just ran 50 times in a row with a 1 second delay, correct results, no error and no reboot:

var Inner = vector(2, vector(2, vector(2, vector(2, 0))))
var Outer = vector(2, vector(2, var.Inner))

var Inner1 = var.Outer[0][0]

set var.Inner1[0][0][0][0] = 1
set var.Outer[0][0] = var.Inner1

var Inner2 = var.Outer[0][0]
echo var.Inner2[0][0][0][0]

dc42

@DonStauffer see https://github.com/Duet3D/RepRapFirmware/issues/1008 for a known bug when using the 'set' command with multiple array indices. We are currently testing a fox in preparation for release 3.5.2.

dc42 created this issue in Duet3D/RepRapFirmware

closed Bug: setting elements of nested arrays sometimes goes wrong #1008

DonStauffer

@dc42 Oh, the same as the other one I ran into? I can usually eventually find a way around it. Maybe this test case will help. I was able to write two macros, one of which reliably works, the other reliably doesn't.

I'm wondering, though: At least with explicit subscripts, going over 4 seems to always fail. Is that expected, or part of the bug? Is there a designed limit to the number of subscripts, apart from this issue? I looked and none is documented.

dc42

@DonStauffer I can provide you with an internal build to try when we have tested the fix some more.

DonStauffer

@dc42 If I can be useful, I'm happy to help any way I can.

dc42

@DonStauffer currently up to 5 array indices should be supported.

dc42

@DonStauffer I just noticed that in some places 5 are allowed, in other places 4. I'll make it consistent.

dc42

@DonStauffer I've put an internal build for Duet 2 at https://www.dropbox.com/scl/fo/xoi07h62s8y73fumtdnfm/AGJ2rkQE833Umf_-9YXbitU?rlkey=7ymwbzg9vc8go203g1ind34er&dl=0. It should allow 5 array indices everywhere and fix the issue with assigning array elements when multiple indices are used.

DonStauffer

@dc42 With this 3.5.1+3 update I haven't seen array corruption at all. I am having spontaneous reboots whose precise location in code seems variable. Diagnostics show an out of memory condition which I didn't see before: About how much memory do I start out with for global variables?
M122
=== Diagnostics ===
RepRapFirmware for Duet 2 WiFi/Ethernet version 3.5.1+3 (2024-05-21 20:58:33) running on Duet WiFi 1.02 or later + DueX5
Board ID: 08DGM-9T6BU-FG3SN-6JKD0-3S06Q-9AY7D
Used output buffers: 3 of 26 (26 max)
=== RTOS ===
Static ram: 23304
Dynamic ram: 75856 of which 0 recycled
Never used RAM 11128, free system stack 184 words
Tasks: NETWORK(2,nWait 6,11.9%,220) HEAT(3,nWait 5,0.1%,328) Move(4,nWait 5,0.0%,345) DUEX(5,nWait 5,0.0%,20) MAIN(1,running,87.5%,678) IDLE(0,ready,0.5%,29), total 100.0%
Owned mutexes:
=== Platform ===
Last reset 00:04:18 ago, cause: software
Last software reset at 2024-05-23 16:44, reason: OutOfMemory, Gcodes spinning, available RAM 8, slot 2
Software reset code 0x41c3 HFSR 0x00000000 CFSR 0x00000000 ICSR 0x0041f000 BFAR 0xe000ed38 SP 0x20002590 Task MAIN Freestk 1156 ok
Stack: 20019850 004106fb 00000000 00400247 00000000 00000000 00000020 00400299 00000018 20019638 20002614 00000000 2000260c 004601c1 00000000 00412bed 20019638 20002614 2000b854 00000000 20019638 20002614 2000b7f0 00439e09 0000000c 00000000 00000000
Error status: 0x04
Aux0 errors 0,0,0
MCU temperature: min 42.9, current 43.3, max 44.5
Supply voltage: min 24.0, current 24.0, max 24.4, under voltage events: 0, over voltage events: 0, power good: yes
Heap OK, handles allocated/used 99/35, heap memory allocated/used/recyclable 2048/1144/0, gc cycles 113
Events: 0 queued, 0 completed
Driver 0: standstill, SG min n/a
Driver 1: standstill, SG min n/a
Driver 2: standstill, SG min n/a
Driver 3: standstill, SG min n/a
Driver 4: standstill, SG min n/a
Driver 5: standstill, SG min n/a
Driver 6: standstill, SG min n/a
Driver 7: standstill, SG min n/a
Driver 8: standstill, SG min n/a
Driver 9: standstill, SG min n/a
Driver 10:
Driver 11:
Date/time: 2024-05-23 16:48:18
Cache data hit count 4294967295
Slowest loop: 15.09ms; fastest: 0.19ms
I2C nak errors 0, send timeouts 0, receive timeouts 0, finishTimeouts 0, resets 0
=== Storage ===
Free file entries: 9
SD card 0 detected, interface speed: 20.0MBytes/sec
SD card longest read time 8.5ms, write time 0.0ms, max retries 0
=== Move ===
DMs created 83, segments created 0, maxWait 0ms, bed compensation in use: none, height map offset 0.000, max steps late 0, min interval 0, bad calcs 0, ebfmin 0.00, ebfmax 0.00
no step interrupt scheduled
Moves shaped first try 0, on retry 0, too short 0, wrong shape 0, maybepossible 0
=== DDARing 0 ===
Scheduled moves 0, completed 0, hiccups 0, stepErrors 0, LaErrors 0, Underruns [0, 0, 0], CDDA state -1
=== Heat ===
Bed heaters 0 -1 -1 -1, chamber heaters -1 -1 -1 -1, ordering errs 0
Heater 1 is on, I-accum = 0.0
=== GCodes ===
Movement locks held by null
HTTP is idle 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
Daemon is doing "G4 P{var.DaemonPeriod}" in state(s) 0 0, running macro
Autopause is idle in state(s) 0
Q0 segments left 0
Code queue 0 is empty
=== Filament sensors ===
check 0 clear 1452769
Extruder 0 sensor: no data received
Extruder 1 sensor: no data received
=== DueX ===
Read count 1, 0.23 reads/min
=== Network ===
Slowest loop: 8.49ms; fastest: 0.00ms
Responder states: HTTP(0) HTTP(0) HTTP(0) FTP(0) Telnet(0)
HTTP sessions: 2 of 8
=== WiFi ===
Interface state: active
Module is connected to access point
Failed messages: pending 0, notrdy 0, noresp 0
Firmware version 2.1.0
MAC address 84:f3:eb:83:47:be
Module reset reason: Power up, Vcc 3.36, flash size 4194304, free heap 42968
WiFi IP address 192.168.1.130
Signal strength -51dBm, channel 11, mode 802.11n, reconnections 0
Clock register 00002002
Socket states: 0 0 0 0 0 0 0 0

DonStauffer

@dc42 OK, I'm sure I know what's going on now.

Your array subscript fix worked.

The remaining problem where my machine would reboot spontaneously with M122 showing an "OutOfMemory" reason was actually some leftover debugging code which I didn't realize was causing a macro call nesting depth of 8. I knew the maximum depth is 7. Rather than getting a message about the depth, the innermost call worked sometimes and not others, and the reboot happened during the nested call sometimes and outside of it other times.

So, I broke the macro call nesting depth limit but the RRF response could be called "ill-behaved."

EDIT: I believe the array subscript issue is solved, and I haven't seen array corruption since, after extensive testing. The OutOfMemory reboot problem tricked me. It's still there, but it just didn't show itself as frequently, and even less predictably than with nesting > 7. This one is frustrating. I have no reason to believe it has anything to do with the array corruption issue. But the reboots are so unpredictable it's hard to find the cause.

dc42

@DonStauffer thanks. From your M122 report I can see that the Out Of Memory error was caused not by excessive expression nesting but when trying to create a new variable. Unfortunately there is very little free RAM on Duet 2 in some configurations, so it's not possible to create a lot of variables, especially ones that occupy a lot of space i.e. arrays and strings.

DonStauffer

@dc42 It seems like the problem was initializing an array element to null, then later assigning an array value to it. There was no error message, but when I changed that the spontaneous reboots stopped.

My global arrays contain just under 400 integers. My estimate is total global data is around 1.5kb assuming 4-byte integers.

Right now everything appears to be running correctly. If I had any concern, it's just that debugging random reboots is a challenge that takes time. Error messages are usually easier. I'm happy with how things are working right now.

dc42

@DonStauffer thanks for the update. My guess is that when the reboot happened, your array assignment was causing a new heap block to be allocated because there was insufficient space in the existing one(s) to accommodate the array. Running M122 just before the failing array assignment would likely confirm this. I'll add a Github issue to see if we can check for sufficient free memory before we try to allocate a new heap block. https://github.com/Duet3D/RepRapFirmware/issues/1013

PS - the maximum depth to which macros may be nested is 10, Each additional nesting requires some memory to be allocated.

dc42 created this issue in Duet3D/RepRapFirmware

open Check for sufficient free memory before allocating a new heap block #1013

DonStauffer

@dc42 I got rid of about half my array elements by restructuring it, and for the first time, 100% of the reboots stopped. So fundamentally, it seems like I have between 1kB and 1.5kB of global space to play with total, or else I start getting a mess. In other words, I was running out of memory, but instead of sending a message, it slammed into a brick wall. So all the other stuff was probably just rearranging where and when the memory ran out.