Freezing a few seconds after boot

[hizzlekizzle]

I'm using an RPi 3 (FAT32) with a USB MIDI controller, but it seems to freeze after about 5-10 seconds whether the controller is plugged in or not. It sounds great right up until then, though :)

Is there any way to do diagnostics/logging?

As an aside, I'm really happy to see someone working on this. I've been checking around for exactly this (headless dexed on RPi) every few months and was going to put in a feature request with dopefish to see if he would consider adding it to mt32-pi when i saw there was already a ticket for it. Then, I saw your comment about this project in the ticket comments! Exciting stuff.

[probonopd]

Thanks @hizzlekizzle. Just to be sure: You do get sound using a USB MIDI controller, but then after a few seconds you get no more sound? Which output are you using for sound, the headphone jack? If you attach the RPI to a HDMI display, you should see some debug output. Can you see something there?

[hizzlekizzle]

Yes, PWM/headphone jack and I do get sound until it freezes, at which point it just buzzes with whatever was the last sample (that is, it's not the full multi-wave tone, just a single wave).

Ah, I didn't think about HDMI output! Unfortunately, I don't see any obvious errors:

logger: Circle 44.3 started on Raspberry Pi 3 Model B
00:00:00.66 timer: SpeedFactor is 1.51
00:00:01.19 emmc: Found a valid version 3.0x SD card
00:00:02.07 usbdev0-1: Device ven424-9514, dev9-0-0 found
00:00:02.07 usbdev0-1: Interface int9-0-0 found
00:00:02.07 usbdev0-1: Using device/interface int9-0-0
00:00:02.82 usbdev0-1: Device ven424-ec00 found
00:00:02.82 usbdev0-1: Using device/interface ven424-ec00
00:00:03.01 usbdev0-1: Device ven763-115 found
00:00:03.03 usbdev0-1: Product: M-Audio USB 02        // This is my USB MIDI controller
00:00:03.03 usbdev0-1: Interface int1-1-0 found
00:00:03.03 usbdev0-1: Function is not supported
00:00:03.03 usbdev0-1: Interface int1-3-0 found
00:00:03.03 usbdev0-1: Using device/interface int1-3-0
00:00:03.09 smsc951x: MAC address is XX:XX:XX:XX:XX:XX
00:00:03.11 usbhub: Port 1: Device configured
00:00:03.16 usbhub: Port 3: Device configured
00:00:03.19 dwroot: Device configured
00:00:03.19 minidexed: Compile time: Mar  2 2022 9:07:13
00:00:03.19 kernel: PWM mode
00:00:03.20 syxfile: Directory /sysex/voice not found
00:00:03.20 minidexed: Serial MIDI interface enabled
Loading voice 1 "BRASS   1 "

To be clear, it doesn't print any new messages to the screen before/during the freeze.

I did see a pair of exception messages pop up once just as it froze, but it was only up for a few seconds before the screen blanked out to some diagonal lines. The diagonal line thing doesn't usually happen, though, so I think that was an unrelated fluke. It usually just stays on the frozen screen with the diagnostic messages forever.

Interestingly: if I hold one of the keys right at boot, it doesn't freeze immediately (I can hold it for >1 min with no freeze) but if I hit a few different keys, it freezes on the 4th or 5th tone/trigger. It'll also freeze after a few seconds with no keys pressed, or, if I hold one key to prevent freezing, it'll freeze after releasing/pressing the same key a few more times or if I press 4-5 other keys while holding the first. Odd stuff.

Let me know if you need to me to do/test anything else on my end. Otherwise, I'll just keep trying things as the project progresses.

[rsta2]

@hizzlekizzle Can you please replace the file kernel8.img on your SD card with the file extracted from the attached .zip file and run again. This should result in additional messages, which may help to solve the problem. If so, please post these messages.

kernel8.zip

[hizzlekizzle]

Oh thanks! Now we're getting somewhere :)

I get a bunch of:

00:00:05.XX dwhci: Transaction failed (status 0x202)

EDIT: ^^this is apparently printed when no keys are held.

followed by a few slight variations on:

MIDI 0: 90 32 00
GetChunk: Maximum duration was 100us (3%)

EDIT: ^^this is printed when keys are held.

followed by:

00:00:11.22 dwhcixferstagedata.cpp(224): stack[1] is 0xB47AC
00:00:11.22 dwhcixferstagedata.cpp(224): stack[11] is 0xB11C4
00:00:11.22 dwhcixferstagedata.cpp(224): stack[17] is 0xB1780
00:00:11.22 dwhcixferstagedata.cpp(224): stack[30] is 0xDC720
00:00:11.22 dwhcixferstagedata.cpp(224): stack[31] is 0xE08C8
00:00:11.22 dwhcixferstagedata.cpp(224): stack[59] is 0xDBE30

and then in red:

00:00:11.22 dwhcixferstagedata.cpp(224): assertion failed: nPacketsTransferred <= m_nPackets

EDIT: ^^and this is what happens when it actually freezes.

[rsta2]

Thanks for testing! Do you have the file cmdline.txt with the contents usbspeed=full on your SD card? If not, please create one. If so, please rename it to something else for another test. I will explain later, what happens here.

[hizzlekizzle]

Ok, I did have a cmdline.txt with usbspeed=full and renaming it got rid of the freezing! I was still getting a lot of crackling with the debug kernel but going back to the original kernel got rid of that, too, so I think I'm all set! Thanks for the assistance :)

Is there anything else you would like me to test while I'm here, or shall I close this one out?

[rsta2]

Great! Thanks for testing!

I think, this problem was device related. I don't know exactly, what happens, but I can only guess the your keyboard controller sends more data on an USB IN request, than the USB driver expected. This does normally not happen and triggers the failed assertion. I found some forum articles on the net, which state, that the M-Audio KeyRig 49 (which should have a similar firmware as yours) did not work even with Windows under some conditions. So this seems to be critical. Without the usbspeed=full setting, the USB works in a different mode, and luckily it seems to work there.

@probonopd I think we can learn two things from this:

1. The test kernel image was build without the REALTIME system option enabled in build.sh. This gives more info, when the system freezes with a failed assertion or an exception, caused by an unallowed memory access. Unfortunately it cannot be used for production, because the timing is worse without REALTIME, but for bug hunting it's an option.
2. The setting usbspeed=full should be optional. Perhaps we need to have a troubleshooting section, which explains it.

[probonopd]

@hizzlekizzle which model is your Product: M-Audio USB 02 MIDI controller? I am asking because for my M-AUDIO Keystation Mini 32 Mk3 I seem to need usbspeed=full. I am wondering whether the M-AUDIO stuff is so buggy or whether something else is going on.

@rsta2 would it be possible to have a fallback that would attach (for the lack of a better word) a USB device with usbspeed=full automatically in case attaching it without that option leads to an error?

[rsta2]

@probonopd The option usbspeed=full forces the whole USB bus to full speed (12 Mbps). The default on the RPi 1-3 and Zero is high speed (480 Mbps). What happens, when one USB device is already attached and works all-right with high speed and then a second device is attached, which needs full speed? It is not possible to bring down the whole USB thing then to enable it with full speed. No, this option can only be applied on user intervention, it's a workaround.

[rsta2]

@probonopd We could try one thing to solve this problem. Currently we use GetChunk(), which is called from an IRQ handler, to calculate and provide the audio samples. This has the effect, that other interrupts (for instance from the USB) cannot be handled, while the synth engine is running, which is relatively long.

There is an other method to do the audio processing outside from an IRQ handler on a secondary CPU core and providing the samples by calling CSoundBaseDevice::Write(). The audio IRQ handler is still there then, but does only have to copy the already calculated samples in a quick loop. The USB should be much more responsive with the normal high speed then.

Actually this is, what mt32-pi is doing and I did not found such USB MIDI issues it the Issues or Discussions there.

But a consequence would be, that the RPi 1 and Zero (W) cannot be supported then. My impression is, that most synth project, which are based on Circle, do not support the RPi 1 anyway.

[hizzlekizzle]

@probonopd it's this crummy little guy, the O2: https://www.soundonsound.com/reviews/m-audio-o2

[probonopd]

Let's both test mt32-pi and see whether it works properly with our USB controllers out of the box...

I tested the M-AUDIO Keystation Mini 32 Mk3 with mt32-pi on a Raspberry Pi 2 and it works properly.

@hizzlekizzle does your O2 do, too?

[hizzlekizzle]

I just tried mt32-pi with my O2 and it worked out of the box, yes.

[rsta2]

So after the successful tests of mt32-pi with your USB keyboard controllers I think we should try the CSoundBaseDevice::Write() method from a secondary CPU core with MiniDexed. Luckily changing MiniDexed for this was not a big deal. There is a patch attached with the needed updates for a test. Hopefully it should result in a smaller IRQ latency on CPU core 0 and in a better USB handling. It still works on the RPi 1 too, but the MIDI dump and profiling has to be disabled there, otherwise one will hear drops, when the screen scrolls.

multi-core.zip

[hizzlekizzle]

I just applied the patch and built for RPI3/32-bit and it seems to be running just fine without any freezing here.

[rsta2]

@hizzlekizzle Good to know. Thanks for testing!

[probonopd]

Ouch. Looks like the latest continuous build containing this patch does not work at all for me. I get USB "Function not supported" messages, the LCD does not show any messages. I get no MIDI or performance debug messages and no sound. Rebooting by pressing the rotary encoder knob still works, though.

Will revert it for now.

Keeping the build here:
https://github.com/probonopd/MiniDexed/releases/tag/multi-core

[rsta2]

Oops. On which RPi model have you tested this?

[probonopd]

RPi 2.

[rsta2]

OK, I will check this. I tested only on the RPi 4B with multi-core and on RPi 1 without. It was working there.

[rsta2]

I can reproduce the problem on the RPi 2B. I have to find the reason. Will take some time.

[probonopd]

Thanks for looking into it; no hurries! If I remember correctly, I had tested mt32-pi on the same Raspberry Pi 2.

[rsta2]

Thanks for info. How is looks like, this is a problem in the multi-core initialization with 32-bit only.

[rsta2]

I have found the problem. It's in the 32-bit multi-core initialization in Circle. The data cache has to be cleaned, before the secondary CPU cores can be started. Because of some bad luck this did not show up until now. I will prepare a hotfix for Circle.

[rsta2]

@probonopd The multi-core initialization problem is solved, but unfortunately there is another issue: The function opendir() hangs, when called on RPi 2B or 3B in 32-bit mode with ARM_ALLOW_MULTI_CORE enabled. This function is used in CSysExFileLoader::Load(). As far as I was able to track this down, this is caused by somebody overwriting the lock variable of a spin lock in the circle-newlib project. Still trying to find the reason for this problem, but before it has not been solved, it does not make sense to create a hotfix release. So it may take some time, until the multi-core MiniDexed really comes up.

[probonopd]

Looks like this project is stress-testing Circle? ;-) No hurry. Your help is tremendous!

[rsta2]

Thank you! :) Yes, but this is one reason, why I'm trying to help to improve MiniDexed. Because I learned, that you need the feedback from developing real applications, to be able to improve projects like circle-stdlib and circle. This helps a lot.

Both reported problems have been catched, and there is a new hotfix release 44.4.1 already, which solves the multi-core problem. I don't know, when @smuehlst has the time, to create a new release of circle-stdlib based of the fixes. He wanted to do this at this weekend, but now we had this delay from my side.

Then I will create a new PR with an improved multi-core support patch, so that you can test, if it solves the USB problems, which have been discovered with your USB keyboard controller.

[rsta2]

The announced multi-core patch with the fixes in available in PR #47.

[probonopd]

@hizzlekizzle does the latest build work for you? If yes, then I think we can close this issue. Thanks!

[hizzlekizzle]

I'm afraid it still crashes for me unless I remove the usbspeed=full :(

Perhaps there was something screwy with my self-compile that gave me a false-positive on the fix?

[rsta2]

@hizzlekizzle Yes, you have to remove the usbspeed=full in any way! There will be a fix in the next Circle release, so that it will not crash when this option is there. But it won't work with your USB keyboard controller with usbspeed=full. It seems to be a high-speed (only) device.

[hizzlekizzle]

Oh, gotcha. In that case, yes, it's working as expected!

Thanks for looking into this, guys :)

[apvanzanten]

Just for information if anybody is looking: I had this same issue with my Studiologic SL 73 Studio keyboard (removing the usbspeed=full from cmdline.txt fixes it).

[probonopd]

Thanks for letting us know @apvanzanten. Will add this to the documentation.