Maestro crash

On the Titanium, RISC OS 5.29 (16 Feb 2021), Maestro 2.15 (10-Feb-21) crashes on attempting to play anything, eventually totally stiffing the machine. (It is all just fine on RPCEmu.)

20 Feb 16:58:55 000 80000002: Error from Filer: Internal error: abort on data transfer at &204B6B70
20 Feb 16:59:24 000 FDFDFDFD: Error from (unknown): !!!!NULL.POINTER.DEREFERENCE!!!!
20 Feb 16:59:39 000 00000185: Error from Filer: Not a heap block

And there is pain.

Time: Sat Feb 20 17:07:34 2021
Location: Offset 00003600 in module WindowManager
Current Wimp task: Maestro
Last app to start: BASIC -quit "ADFS::Titan4.$.Work.Proj.Maestro.!Maestro.!RunImage" ADFS::Titan4.$.Work.Proj.Maestro.Maestro.BachFXVI

R0  = 0000000f R1  = 0000000f R2  = fc13ef48 R3  = 00000000
R4  = 0000000b R5  = 00000001 R6  = fc13ef48 R7  = 00000000
R8  = 20455819 R9  = 00000000 R10 = 20455818 R11 = 00000001
R12 = 20073374 R13 = fa207f58 R14 = fc13f7d8 R15 = fc12b7d4
DFAR = 0000000f  Mode SVC32  Flags nzCv if   PSR = 20000013

fc12b78c : ebfffd91 : BL      &FC12ADD8
fc12b790 : e8bd0003 : LDMIA   R13!,{R0,R1}
fc12b794 : e79b1001 : LDR     R1,[R11,R1]
fc12b798 : e3710001 : CMN     R1,#1
fc12b79c : 1afffff6 : BNE     &FC12B77C
fc12b7a0 : ebfffe46 : BL      &FC12B0C0
fc12b7a4 : e8bd8c03 : LDMIA   R13!,{R0,R1,R10,R11,PC}
fc12b7a8 : e52de004 : STR     R14,[R13,#-4]!
fc12b7ac : e4d0e001 : LDRB    R14,[R0],#1
fc12b7b0 : e4c1e001 : STRB    R14,[R1],#1
fc12b7b4 : e35e0020 : CMP     R14,#&20           ; =" "
fc12b7b8 : 2afffffb : BCS     &FC12B7AC
fc12b7bc : e2411001 : SUB     R1,R1,#1
fc12b7c0 : e49df004 : LDR     PC,[R13],#4
fc12b7c4 : e52de004 : STR     R14,[R13,#-4]!
fc12b7c8 : e1a01000 : MOV     R1,R0
fc12b7cc * e4d1e001 * LDRB    R14,[R1],#1
fc12b7d0 : e35e0020 : CMP     R14,#&20           ; =" "
fc12b7d4 : 2afffffc : BCS     &FC12B7CC
fc12b7d8 : e0411000 : SUB     R1,R1,R0
fc12b7dc : e49df004 : LDR     PC,[R13],#4
fc12b7e0 : e92d5000 : STMDB   R13!,{R12,R14}
fc12b7e4 : e59cc000 : LDR     R12,[R12,#0]
fc12b7e8 : e58c01dc : STR     R0,[R12,#476]
fc12b7ec : e3a00001 : MOV     R0,#1
fc12b7f0 : e58c01d8 : STR     R0,[R12,#472]
fc12b7f4 : e58c01f0 : STR     R0,[R12,#496]
fc12b7f8 : e3a00019 : MOV     R0,#&19            ; =25
fc12b7fc : eb002e1c : BL      &FC137074
fc12b800 : 73a00000 : MOVVC   R0,#0
fc12b804 : 7b001ab3 : BLVC    &FC1322D8
fc12b808 : 7b005b34 : BLVC    &FC1424E0

R15 = fc12b7d4 = WindowManager +3608 = count0 +10
R14_svc = fc13f7d8 = WindowManager +1760c = starterrorbox +1c
          Function call to fc12b7c4 = WindowManager +35f8 = count0 +0

SVC stack:
fa207f58 : fc13f7d8 : - R14: fc13f7d8 (ASM call to fc12b7c4)
         :          : | fc13f7d8 = WindowManager +1760c
         :          : | = starterrorbox +1c
         :          : | fc12b7c4 = WindowManager +35f8
         :          : | = count0 +0
fa207f5c : fc13f344 : - R14: fc13f344 (ASM call to fc13f7bc)
         :          : | fc13f344 = WindowManager +17178
         :          : | = useerrorwindow +50
         :          : | fc13f7bc = WindowManager +175f0
         :          : | = starterrorbox +0

Thanks David – I’ll look into that.

I don’t suppose you know if the previous version played OK? And does the crash happen when you try to play just a minimal file (a handful of notes on the score) or relatively complex scores, like the ones in Documents?

I found Maestro 2.01 and that crashes on the Titanium. The crash also occurs on the Titanium with OS5.24. An easy way to stiff the Titanium is to load one of the music files then Quit Maestro. I don’t have a short file at the moment, job for tomorrow.

Oddly there is no such crash on the RPi400. I’m not sure what to make of that.

The crash does occur on an unbooted Titanium so it is not something on the machine messing it up.

Odd!!!

Hmm – that does sound odd. I can’t reproduce the crash on RPCEmu (as you noted), but I’ll be able to try it out on a Pi in a day or two to see if that’s producing any pain/crashes when playing. I don’t have access to a Titanium, unfortunately.

2.01 is more or less the version that’s been around for years, and doesn’t have any of my recent edits to the typesetting, etc. If that’s crashing on the Titanium too (in the same way), then either Maestro has a very longstanding bug or there’s possibly something in the Titanium’s sound system that’s tripping it up.

I don’t suppose you know if the previous version played OK?

I have tried Maestro 2.14, from git, and that crashes.

And does the crash happen when you try to play just a minimal file (a handful of notes on the score)

A short file of eight notes is OK.

Maestro has never done any bounds checking when writing data to memory, and will happily write beyond its Wimpslot if the file is big enough (the latest merge request addresses this). But I’d be surprised if any of the bundled tunes are big enough to provoke that error, and it’s not immediately clear to me why it would only crop up on the Titanium. You could try bumping up the Wimpslot by a large amount, and see if this makes any difference.

I have tried Maestro 2.14, from git, and that crashes.

Just so I’m clear: both old (2.01) and new versions of Maestro work fine on both RPCEmu and the Pi, and both old and new versions crash on the Titanium in the same way (ie, loading a file then quitting, or loading a file and trying to play it)?

You could try bumping up the Wimpslot by a large amount, and see if this makes any difference.

That doesn’t help.

Just so I’m clear: both old (2.01) and new versions of Maestro work fine on both RPCEmu and the Pi,

2.01, 2.14 and 2.15 are all good on the RPi400, only 2.15 has been tried on RPCEmu.

I have tried a build from the MemoryChanges branch and that crashes on the Titanium.

it’s not immediately clear to me why it would only crop up on the Titanium

Indeed! What would be useful is a test from another Titanium, just in case there is something wrong with mine.

I’ll keep digging!

@David Pitt, I get the same results on my Titanium running 529 (11th,16th Feb 2021) plus the latest HD4 (21st Feb 2021).

Interestingly if I only have Maestro running then I can play tunes. Apache, HandlMes1b and one or two more. I ran the entire tune and after returning the start block to the beginning closed the Window and started afresh with a new tune.Should the position block automatically return when the tune finishes?

However if I try to run any other app whilst a tune is running we are back to a frozen machine.

Clicking on a Maestro tune without Maestro on the Icon bar gives a fresh error box viz
‘Not in a REPEAT loop’ (internal error 6315)

Thanks Ron. Very strange. It sounds like Maestro is trampling over something it shouldn’t be, but why it appears to only do this on a Titanium is a mystery. From these reports, it seems that loading files is a possible source of the instability – opening an empty document and editing it (and playing?) doesn’t cause a crash. Is that right?

From these reports, it seems that loading files is a possible source of the instability – opening an empty document and editing it (and playing?) doesn’t cause a crash. Is that right?

Yes. The loaded file needs to be ‘big enough’, a small file of 123B works. All the examples are ‘big enough’. The crash can occur on loading a file, on quitting or shortly after quitting on some other desktop action. It is very unmissable on the Titanium.

Thanks. I assume there’s no change depending on whether a file is double-clicked to load Maestro, or double-clicked with Maestro already loaded, or dragged to the Maestro icon? I’ll take a look at all the file loading code, and see if something’s amiss.

I assume there’s no change depending on whether a file is double-clicked to load Maestro, or double-clicked with Maestro already loaded, or dragged to the Maestro icon?

That is so, it does not matter how the file is started.

I have had a further try on a Raspberry Pi, a RPi1 this time, and there is no sign of any trouble.

I also get a similar crashes when using Maestro v2.05 on my Titanium. Something is indeed getting overwritten … but it is proving a pain to try and debug, especially as results do not seem totally consistent. I will report if/when I find something!

Reporter shows two errors.

10:51:17.81 WimpSlot -min 256k -max 720k
10:51:17.81 Run <Maestro$Dir>.!RunImage ADFS::Titan4.$.Work.Proj.Maestro.Maestro.Gigue
10:51:17.81 @RunType_FFB ADFS::Titan4.$.Work.Proj.Maestro.!Maestro.!RunImage ADFS::Titan4.$.Work.Proj.Maestro.Maestro.Gigue
10:51:17.81 Basic -quit "ADFS::Titan4.$.Work.Proj.Maestro.!Maestro.!RunImage" ADFS::Titan4.$.Work.Proj.Maestro.Maestro.Gigue
10:51:17.81 ** Error **
  Error  : &000001E6
  Message: SWI name not known
10:51:17.82 Exec
heapsize%=12288
10:51:17.83 Set Maestro$Running Yes
10:51:17.83 FX 229,0
10:51:17.83 FX 229,1
10:51:23.98 UnSet Maestro$Running
10:51:23.98 ** BASICError ** ERR=15 Subscript out of range ERL=4342
10:51:23.98 Exec
10:51:43.21 ** WimpError ** from Filer
  Error  : &00000185
  Message: Not a heap block
10:51:43.21 Exec

SWI name not known occurs as Maestro starts.

Subscript out of range ERL=4342 occurs as Maestro quits.

Line 4342 is PROCheap_freeblock(Heap%,NoteBlock%(c%)). Further probing with Reporter shows c% to be 8, but the DIM is only 7.

Both of these are also seen on the RPi400, where there is no crash.

Not a heap block is collateral damage, or the Filer getting trampled.

Looks like you’re using the latest version in Git. That subscript out of range is a typo – thanks (c% should be i%) – but it’s only in the MemoryChanges branch, so it wouldn’t explain crashes in older versions. I’m guessing the SWI name not known is Maestro testing for MIDI in PROCEnumerateSWIs

Reverting to a vanilla Maestro 2.15 Reporter now shows an Invalid Error Block Address on the Titanium but not on the Rasperry Pi.

11:42:36.64 Basic -quit "ADFS::Titan4.$.Work.Proj.Maestro.!Maestro.!RunImage" ADFS::Titan4.$.Work.Proj.Maestro.Maestro.Gigue
11:42:36.65 ** Error **
  Error  : &000001E6
  Message: SWI name not known
11:42:36.65 Exec
11:42:36.66 Set Maestro$Running Yes
11:42:36.66 FX 229,0
11:42:36.66 FX 229,1
Invalid Error Block address: &0000000B
11:42:36.68 Exec
11:42:36.69 ** Error **
  Error  : &80000002
  Message: Internal error: abort on data transfer at &FC13F7F0
11:42:36.69 ** WimpError ** from Filer
  Error  : &80000002
  Message: Internal error: abort on data transfer at &FC13F7F0
11:42:36.69 Exec
11:42:36 ZeroPain: 34 new log file entries

Reporter 2.72 (15 Aug 2020)     Listed 38 lines

Thanks David. That’s very useful.

If I deliberately put a syntax error into the procedure in question (PROCload_music), then I get the same irrecoverable crash on RPCEmu that you’re reporting on the Titanium. So the local error-handler in that procedure appears to be broken. I’ll look into that first. And then there’s the question of what’s causing the error in the first place, which I hope will be easier to diagnose once the handler isn’t lethal.

@ David, Martin & Chris,
Last night, after managing to play six Maestro tunes without problems, I decided to run some other apps whilst a Maestro tune was playing*. To my surprise there were no crashes that is until the tune playing finished and I, after closing the Maestro window and attempting to start a new tune ended up with a grey screen and the dreaded ‘Not a heap block’ message.

*Starting with a blank desktop is my usual test for new software.

Debugging this has been a challenge, but I now have a theory, even if it seems far-fetched!

I suspect that in sone circumstances SYS "Sound_AttachVoice" can overwrite part of the RMA Heap… but maybe only on the Titanium. If this is the root cause, then it could explain the variety of symptoms, depending on what is overwritten and what notices first.

I have a little test program as follows:

REM > Test
ON ERROR PROCerror:END
*ReportClear
*Report \G Test started
v%=2
FOR chan% = 0 TO 7
  *Report chan% v%
  *ReportHeap
  SYS "Sound_AttachVoice",chan%+1,v%
  *ReportHeap
NEXT
*Report \G Test completed ok
END
:
DEF PROCerror
  ON ERROR OFF
  *ReportError T
  *Report \V Test failed - if HEAP error a reboot recommended!
ENDPROC 

It works ok on my RPi, but fails on my Titanium.
*ReportHeap raises an error if the heap is found to be invalid, in this case Heap Error: Bad Alloc Length, because it has been overwritten with &7442EF20

Can anyone else (carefully) try this at home, and see if the results are the same?

The SWI Sound_AttachVoice is as used in PROClInstruments in Maestro.

I have a little test program as follows:

Can confirm that all works as expected on RPCEmu – no heap errors and test completes OK.

I have a little test program

Can anyone else (carefully) try this at home

This test stiffs the Titanium in much the same way as Maestro.

Reporter 2.72 (15 Aug 2020)     List              Mon 22nd Feb 2021  16:58

16:57:45.96 ** Clear **
Test started
chan%=0 v%=2
Heap RMA=&20000000 Max=256M Size=5412K Free=68K Largest=23484 Used=5343K (1861) Freed=68K (120) Unused=16
Heap RMA=&20000000 Max=256M Size=5412K Free=67K Largest=22620 Used=5344K (1862) Freed=67K (120) Unused=16
chan%=1 v%=2
Heap RMA=&20000000 Max=256M Size=5412K Free=67K Largest=22620 Used=5344K (1862) Freed=67K (120) Unused=16
Heap RMA=&20000000 Max=256M Size=5412K Free=66K Largest=21756 Used=5345K (1863) Freed=66K (120) Unused=16
chan%=2 v%=2・
Heap RMA=&20000000 Max=256M Size=5412K Free=66K Largest=21756 Used=5345K (1863) Freed=66K (120) Unused=16
Heap RMA=&20000000 Max=256M Size=5412K Free=65K Largest=20892 Used=5346K (1864) Freed=65K (120) Unused=16
chan%=3 v%=2
Heap RMA=&20000000 Max=256M Size=5412K Free=65K Largest=20892 Used=5346K (1864) Freed=65K (120) Unused=16
Heap RMA=&20000000 Max=256M Size=5412K Free=64K Largest=20028 Used=5347K (1865) Freed=64K (120) Unused=16
chan%=4 v%=2
Heap RMA=&20000000 Max=256M Size=5412K Free=64K Largest=20028 Used=5347K (1865) Freed=64K (120) Unused=16
Heap RMA=&20000000 Max=256M Size=5412K Free=65488 Largest=19164 Used=5348K (1866) Freed=65472 (120) Unused=16
chan%=5 v%=2
Heap RMA=&20000000 Max=256M Size=5412K Free=65488 Largest=19164 Used=5348K (1866) Freed=65472 (120) Unused=16
Heap RMA=&20000000 Max=256M Size=5412K Free=64624 Largest=18300 Used=5348K (1867) Freed=64608 (120) Unused=16
chan%=6 v%=2
Heap RMA=&20000000 Max=256M Size=5412K Free=64624 Largest=18300 Used=5348K (1867) Freed=64608 (120) Unused=16
Heap RMA=&20000000 Max=256M Size=5412K Free=63760 Largest=17436 Used=5349K (1868) Freed=63744 (120) Unused=16
chan%=7 v%=2
Heap RMA=&20000000 Max=256M Size=5412K Free=63760 Largest=17436 Used=5349K (1868) Freed=63744 (120) Unused=16
Heap RMA=&20000000 Max=256M Size=5412K
202E6234 541,717,428 Alloc
Heap Error: Bad Alloc Length
202E6130 |10 F2 34 E7・04 E0 9D E4¦12 F0 21 E3・0F 00 99 E8 : .Ú4Á.‡ù‰.!„..ôË : +0
202E6140 |94 03 03 E0・0C 80 4A E0¦98 03 03 E0・02 00 3B E3 : î..‡.ÄJ‡ò..‡..;„ : +16
202E6150 |A3 30 A0 01・04 00 5B E3¦23 31 A0 01・A3 31 A0 C1 : £0†...[„#1†.£1†¡ : +32
202E6160 |23 39 A0 E1・80 80 8F E2¦28 80 88 E2・07 81 98 E7 : #9†·ÄÄè‚(Äà‚.ÅòÁ : +48
202E6170 |3C 60 88 E2・09 7D 88 E2¦18 60 89 E5・1C 70 89 E5 : <`à‚.}à‚.`âÂ.pâ : +64
202E6180 |00 00 53 E3・0C 30 98 05¦10 40 98 05・14 50 98 05 : ..S„.0ò..@ò..Pò. : +80
202E6190 |04 00 00 0A・03 3A A0 E1¦23 3A A0 E1・A4 50 A0 E1 : .....:†·#:†·§P†· : +96
202E61A0 |FF 54 85 E3・FF 58 85 E3¦00 00 50 E3・08 20 98 05 : .TÖ„.XÖ„..P„. ò. : +112
202E61B0 |07 00 00 0A・7F 00 00 E2¦00 04 80 E1・FF 0E C0 E3 : .......‚..Ä·..¿„ : +128
202E61C0 |10 00 80 E2・60 06 A0 E1¦10 00 A0 E1・01 04 50 E2 : ..Ä‚`.†·..†·..P‚ : +144
202E61D0 |A0 20 A0 E1・00 00 51 E3¦04 10 98 05・05 00 00 0A : † †·..Q„..ò..... : +160
202E61E0 |01 18 A0 E1・21 18 A0 E1¦04 00 98 E5・FF 00 C0 E3 : ..†·!.†·..òÂ..¿„ : +176
202E61F0 |FF 0C C0 E3・00 10 81 E1¦08 90 A0 E1・4C 86 1F E5 : ..¿„..Å·.ꆷLÜ. : +192
202E6200 |00 80 98 E5・FE 01 89 E9¦E7 FE FF EA・00 00 00 00 : .ÄòÂ..âÈÁ..Í.... : +208
202E6210 |00 00 00 00・54 0B 4A 20¦F4 07 4A 20・94 04 4A 20 : ....T.J Ù.J î.J  : +224
202E6220 |34 01 4A 20・D4 FD 49 20¦74 FA 49 20・14 F7 49 20 : 4.J ‘˝I t˙I .˜I  : +240
Error Block
202E6230 |B4 F3 49 20・53 74 72 69¦6E 67 4C 69・62 2D 53 6F : ¥ÛI StringLib-So : +0
202E6240 |66 74 00 00・00 00 00 00¦00 00 00 00・00 00 00 00 : ft.............. : +16
202E6250 |20 00 00 00・53 74 72 69¦6E 67 4C 69・62 2D 50 6C :  ...StringLib-Pl : +32
202E6260 |75 63 6B 00・00 00 00 00¦00 00 00 00・00 00 00 00 : uck............. : +48
202E6270 |20 00 00 00・53 74 72 69¦6E 67 4C 69・62 2D 53 74 :  ...StringLib-St : +64
202E6280 |65 65 6C 00・00 00 00 00¦00 00 00 00・00 00 00 00 : eel............. : +80
202E6290 |20 00 00 00・53 74 72 69¦6E 67 4C 69・62 2D 48 61 :  ...StringLib-Ha : +96
202E62A0 |72 64 00 00・00 00 00 00¦00 00 00 00・00 00 00 00 : rd.............. : +112
202E62B0 |80 09 00 00・0C 00 00 EA¦0F 00 00 EA・12 00 00 EA : Ä......Í...Í...Í : +128
202E62C0 |15 00 00 EA・77 00 00 EA¦83 00 00 EA・00 80 BD E8 : ...Íw..ÍÉ..Í.ÄΩË : +144
202E62D0 |28 00 00 00・40 03 00 00¦06 00 00 00・50 65 72 63 : (...@.......Perc : +160
202E62E0 |75 73 73 69・6F 6E 2D 53¦6F 66 74 00・01 0B 8F E2 : ussion-Soft...è‚ : +176
202E62F0 |C2 0F 80 E2・04 00 2D E5¦E3 00 00 EA・01 0B 8F E2 : ¬.Ä‚..-„..Í..è‚ : +192
202E6300 |BE 0F 80 E2・04 00 2D E5¦F5 01 00 EA・01 0B 8F E2 : æ.Ä‚..-Âı..Í..è‚ : +208
202E6310 |BA 0F 80 E2・04 00 2D E5¦7C 00 00 EA・01 0B 8F E2 : ∫.Ä‚..-Â|..Í..è‚ : +224
202E6320 |B6 0F 80 E2・04 00 2D E5¦FA 00 00 EA・0D 00 00 EA : ∂.Ä‚..-Â˙..Í...Í : +240
Heap Error: Bad Alloc Length
16:57:45.96 ** Error **
  Error  : &00821215
  Message: Heap Error: Bad Alloc Length
16:57:45.96 Exec
** Error ** ERR=&821215 Heap Error: Bad Alloc Length ERL=10
Test failed - if HEAP error a reboot recommended!
16:57:45.96 Exec
16:57:48.98 ** Save  ** ReportList01
16:57:48.99 ** WimpError ** from Filer
  Error  : &00000185
  Message: Not a heap block
16:57:48.99 Exec

Reporter 2.72 (15 Aug 2020)     Listed 74 lines

@ Martin,

Again same results as David, Titanium well and truly killed.

I suspect that in sone circumstances SYS “Sound_AttachVoice” can overwrite part of the RMA Heap… but maybe only on the Titanium

So I went and did the obvious then, REM’d out all the SYS "Sound_AttachVoice calls. The music file played in the sense of scrolling through in the window but not in the sense of actually playing any notes. The really good bit is that Maestro did not destroy the Titanium on quitting.

Thanks Chris, David & Ron. That seems to confirm I am not going totally mad.

The next challenge in this game seems to be AttachVoice…

The Reporter log from Martin’s test shows that only the last channel, 8, that triggers the error. (Channels are 1 to 8 in the PRM.)

A simpler version of the test is :-

REM > Test
REM channel 8 only
ON ERROR PROCerror:END
*ReportClear
*Report \G Test started
*ReportHeap
*channelvoice 8 2
*ReportHeap
*Report \G Test completed ok
END
:
DEF PROCerror
ON ERROR OFF
*ReportError T
*Report \V Test failed - if HEAP error a reboot recommended!
ENDPROC