MODEP crashes when using Sooper Looper and/or MIDI

I’ve been getting quite a bit of crashes lately and because of your thread I think it is related to Sooper Looper as it is the only thing that has changed in my setup recently as I have been learning how to loop lately. I am using the recommend settings for the pisound sound card, 48000khz, 128bit, 2 cycles/periods.

My loops are getting longer and they seem to be crashing more frequently.

I am using the most recent Patchbox OS + Modep now as I thought updating might solve the crashes.

Here is the last bit in my /var/log/messages just before crash, and nothing of note that I can tell:

May 8 09:31:11 patchbox kernel: [ 9.677493] snd-rpi-pisound soc:sound: snd-soc-dummy-dai ↔ 3f203000.i2s mapping ok
May 8 09:31:11 patchbox kernel: [ 9.930306] cfg80211: Loading compiled-in X.509 certificates for regulatory database
May 8 09:31:11 patchbox kernel: [ 10.058519] cfg80211: Loaded X.509 cert ‘sforshee: 00b28ddf47aef9cea7’
May 8 09:31:11 patchbox kernel: [ 10.253317] usbcore: registered new interface driver brcmfmac
May 8 09:31:11 patchbox kernel: [ 11.363305] usbcore: registered new interface driver snd-usb-audio
May 8 09:31:11 patchbox kernel: [ 14.174528] uart-pl011 3f201000.serial: no DMA platform data
May 8 09:31:11 patchbox kernel: [ 14.245779] 8021q: 802.1Q VLAN Support v1.8
May 8 09:31:11 patchbox kernel: [ 14.528921] Adding 102396k swap on /var/swap. Priority:-2 extents:1 across:102396k SSFS
May 8 09:31:11 patchbox kernel: [ 14.571418] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
May 8 09:31:11 patchbox kernel: [ 14.571433] brcmfmac: power management disabled
May 8 09:31:12 patchbox kernel: [ 15.166160] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
May 8 09:31:12 patchbox kernel: [ 15.166272] 8021q: adding VLAN 0 to HW filter on device eth0
May 8 09:31:12 patchbox kernel: [ 15.177153] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
May 8 09:31:18 patchbox kernel: [ 20.867354] Bluetooth: Core ver 2.22
May 8 09:31:18 patchbox kernel: [ 20.867500] NET: Registered protocol family 31
May 8 09:31:18 patchbox kernel: [ 20.867507] Bluetooth: HCI device and connection manager initialized
May 8 09:31:18 patchbox kernel: [ 20.867573] Bluetooth: HCI socket layer initialized
May 8 09:31:18 patchbox kernel: [ 20.867593] Bluetooth: L2CAP socket layer initialized
May 8 09:31:18 patchbox kernel: [ 20.867735] Bluetooth: SCO socket layer initialized
May 8 09:31:18 patchbox kernel: [ 20.890706] Bluetooth: HCI UART driver ver 2.3
May 8 09:31:18 patchbox kernel: [ 20.890721] Bluetooth: HCI UART protocol H4 registered
May 8 09:31:18 patchbox kernel: [ 20.890839] Bluetooth: HCI UART protocol Three-wire (H5) registered
May 8 09:31:18 patchbox kernel: [ 20.891220] Bluetooth: HCI UART protocol Broadcom registered
May 8 09:31:18 patchbox kernel: [ 21.352607] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
May 8 09:31:18 patchbox kernel: [ 21.352618] Bluetooth: BNEP filters: protocol multicast
May 8 09:31:18 patchbox kernel: [ 21.355945] Bluetooth: BNEP socket layer initialized
May 8 09:31:18 patchbox kernel: [ 21.571792] Bluetooth: RFCOMM TTY layer initialized
May 8 09:31:18 patchbox kernel: [ 21.571826] Bluetooth: RFCOMM socket layer initialized
May 8 09:31:18 patchbox kernel: [ 21.572003] Bluetooth: RFCOMM ver 1.11
May 8 09:31:19 patchbox vncserver-x11[597,root]: ServerManager: Server started
May 8 09:31:19 patchbox rfkill: unblock set for type wifi
May 8 09:31:19 patchbox vncserver-x11[597,root]: ConsoleDisplay: Cannot find a running X server on vt1
May 8 09:31:21 patchbox kernel: [ 24.213358] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
May 8 09:31:21 patchbox kernel: [ 24.213405] brcmfmac: power management disabled
May 8 09:31:27 patchbox kernel: [ 30.383503] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
May 8 09:31:56 patchbox vncserver-x11[597,root]: ConsoleDisplay: Found running X server (pid=983, binary=/usr/lib/xorg/Xorg)
May 8 09:31:59 patchbox kernel: [ 51.658110] fuse init (API version 7.27)
May 8 09:32:01 patchbox udisksd[1132]: udisks daemon version 2.8.1 starting
May 8 09:32:01 patchbox udisksd[1132]: failed to load module crypto: libbd_crypto.so.2: cannot open shared object file: No such file or directory
May 8 09:32:01 patchbox udisksd[1132]: failed to load module mdraid: libbd_mdraid.so.2: cannot open shared object file: No such file or directory
May 8 09:32:02 patchbox udisksd[1132]: Failed to load the ‘mdraid’ libblockdev plugin
May 8 09:32:02 patchbox udisksd[1132]: Failed to load the ‘crypto’ libblockdev plugin
May 8 09:32:02 patchbox udisksd[1132]: Acquired the name org.freedesktop.UDisks2 on the system message bus
May 8 09:32:03 patchbox vncserver-x11[597,root]: ConsoleDisplay: Cannot find a running X server on vt1
May 8 09:48:25 patchbox kernel: [ 0.000000] Booting Linux on physical CPU 0x0

What exactly happens when it crashes? Is it only the audio software that crashes, or the whole system?

It is the whole system, all of the sudden all the output turns into a sine wave of sorts, a constant hz and then I go to reload the pedal dashboard and it never reloads, and the wifi hotspot drops as well as my open ssh connection.

So, I can hear it instantly, just switches to noise instantly.

I think this issue is worthy of its own topic.

Could you share the output of the commands listed here: https://blokas.io/modep/docs/Troubleshooting/, the ‘status’ and journalctl ones. The start and stop commands restart the MODEP services as well as Jack, they should help you recover the system from the bad state.

1 Like

Thanks for splitting this out. I’m gearing up for a family camping trip into the mountains for the weekend and will hit this when I get back on Tuesday (or after) as it is frequently reproducible now.

So, I hooked the PiSound up to Ethernet and disabled the wifi hotspot and was able to stay connected during the the last crash just now. Worth noting that what triggered it almost instantly was using an Akai MPK Mini midi through to a Tetra Synth. Sooper Looper was in Playback mode while doing this, not record mode.

Here are some logs:

sudo journalctl --unit modep-mod-ui

May 14 23:56:30 patchbox authbind[501]: DEBUG:root:[host] received ← ‘data_finish’
May 14 23:56:30 patchbox authbind[501]: DEBUG:root:[host] idle? → 1
May 14 23:56:30 patchbox authbind[501]: DEBUG:root:[host] popped from queue: output_data_ready
May 14 23:56:30 patchbox authbind[501]: DEBUG:root:[host] sending → output_data_ready
May 14 23:56:30 patchbox authbind[501]: DEBUG:root:[host] received ← ‘resp 0\x00’
May 14 23:56:30 patchbox authbind[501]: DEBUG:root:[host] received ← ‘output_set 1 level 0.001587’
May 14 23:56:30 patchbox authbind[501]: DEBUG:root:[host] received ← ‘data_finish’
May 14 23:56:30 patchbox authbind[501]: Cannot read socket fd = 12 err = Success
May 14 23:56:30 patchbox authbind[501]: CheckRes error
May 14 23:56:30 patchbox authbind[501]: JackSocketClientChannel read fail
May 14 23:56:30 patchbox systemd[1]: Stopping MOD-UI…
May 14 23:56:30 patchbox systemd[1]: modep-mod-ui.service: Main process exited, code=killed, status=15/TERM
May 14 23:56:30 patchbox systemd[1]: modep-mod-ui.service: Succeeded.
May 14 23:56:30 patchbox systemd[1]: Stopped MOD-UI.

sudo journalctl --unit modep-mod-host

May 14 17:46:14 patchbox mod-host[497]: mod-host ready!
May 14 23:56:30 patchbox mod-host[497]: Cannot read socket fd = 35 err = Success
May 14 23:56:30 patchbox mod-host[497]: CheckRes error
May 14 23:56:30 patchbox mod-host[497]: JackSocketClientChannel read fail
May 14 23:56:30 patchbox mod-host[497]: Cannot read socket fd = 29 err = Success
May 14 23:56:30 patchbox mod-host[497]: CheckRes error
May 14 23:56:30 patchbox mod-host[497]: JackSocketClientChannel read fail
May 14 23:56:30 patchbox mod-host[497]: Cannot read socket fd = 23 err = Success
May 14 23:56:30 patchbox mod-host[497]: CheckRes error
May 14 23:56:30 patchbox mod-host[497]: JackSocketClientChannel read fail
May 14 23:56:30 patchbox mod-host[497]: Cannot read socket fd = 17 err = Success
May 14 23:56:30 patchbox mod-host[497]: CheckRes error
May 14 23:56:30 patchbox mod-host[497]: JackSocketClientChannel read fail
May 14 23:56:30 patchbox mod-host[497]: Cannot read socket fd = 5 err = Success
May 14 23:56:30 patchbox mod-host[497]: CheckRes error
May 14 23:56:30 patchbox mod-host[497]: JackSocketClientChannel read fail
May 14 23:56:30 patchbox mod-host[497]: Cannot read socket fd = 26 err = Success
May 14 23:56:30 patchbox mod-host[497]: CheckRes error
May 14 23:56:30 patchbox mod-host[497]: JackSocketClientChannel read fail
May 14 23:56:30 patchbox mod-host[497]: Cannot read socket fd = 20 err = Success
May 14 23:56:30 patchbox mod-host[497]: CheckRes error
May 14 23:56:30 patchbox mod-host[497]: JackSocketClientChannel read fail
May 14 23:56:30 patchbox mod-host[497]: Cannot read socket fd = 32 err = Success
May 14 23:56:30 patchbox mod-host[497]: CheckRes error
May 14 23:56:30 patchbox mod-host[497]: JackSocketClientChannel read fail
May 14 23:56:30 patchbox mod-host[497]: Server is not running
May 14 23:56:30 patchbox mod-host[497]: Server is not running
May 14 23:56:30 patchbox systemd[1]: Stopping MOD-host…
May 14 23:56:30 patchbox mod-host[497]: Starting!!
May 14 23:56:30 patchbox mod-host[497]: stopping record
May 14 23:56:30 patchbox mod-host[497]: Starting!!
May 14 23:56:30 patchbox mod-host[497]: stopping record
May 14 23:56:31 patchbox systemd[1]: modep-mod-host.service: Succeeded.
May 14 23:56:31 patchbox systemd[1]: Stopped MOD-host.

sudo journalctl --unit jack

May 14 17:46:26 patchbox jackdrc[396]: port created: RtMidiOut-Client:midi/playback_1
May 14 23:56:30 patchbox jackdrc[396]: JackEngine::XRun: client mod-midi-broadcaster finished after current callback
May 14 23:56:30 patchbox jackdrc[396]: JackEngine::XRun: client mod-host finished after current callback
May 14 23:56:30 patchbox jackdrc[396]: JackEngine::XRun: client effect_0 finished after current callback
May 14 23:56:30 patchbox jackdrc[396]: JackEngine::XRun: client effect_1 finished after current callback
May 14 23:56:30 patchbox jackdrc[396]: JackEngine::XRun: client = effect_2 was not finished, state = Triggered
May 14 23:56:30 patchbox jackdrc[396]: JackEngine::XRun: client = effect_3 was not finished, state = Running
May 14 23:56:30 patchbox jackdrc[396]: JackEngine::XRun: client = effect_4 was not finished, state = Triggered
May 14 23:56:30 patchbox jackdrc[396]: JackEngine::XRun: client = effect_5 was not finished, state = Triggered
May 14 23:56:30 patchbox jackdrc[396]: JackEngine::XRun: client effect_6 finished after current callback
May 14 23:56:30 patchbox jackdrc[396]: JackAudioDriver::ProcessGraphAsyncMaster: Process error
May 14 23:56:30 patchbox jackdrc[396]: JackAudioDriver::ProcessGraphAsyncMaster: Process error
May 14 23:56:30 patchbox jackdrc[396]: jackd: …/common/JackMidiPort.cpp:133: void Jack::MidiBufferMixdown(void*, void**, int, jack_nframes_t): Assertion `next_event != 0’ failed.
May 14 23:56:30 patchbox jackdrc[396]: CheckSize error size = 32 Size() = 12
May 14 23:56:30 patchbox jackdrc[396]: CheckRead error
May 14 23:56:30 patchbox systemd[1]: jack.service: Main process exited, code=killed, status=6/ABRT
May 14 23:56:30 patchbox systemd[1]: jack.service: Failed with result ‘signal’.

Hrm, that all seemed to be something to do with aggregated midi mode, CPU spiked to 100% and crashed again and again, which I was able to recover from much faster by sudo shutdow --restart now instead of waiting 2-3 minutes to keep it unplugged and plug back in.

I changed to “separated mode” and it seems to not be crashing anymore with MIDI events. What seemed to be happening with the MIDI crash in Aggregate mode is that the MIDI was looping back in>out>in>out as I heard it on my internal Akai MPK speakers and also the Tetra was stuck looping too.

I am trying to reproduce now with Sooper Looper.

Welp go figure, been looping things for an hour now, and no crashes. The only thing I did significantly different that I can tell is disable the Hotspot and use ethernet to connect instead. I will try to re-enable the Hotspot and connect to it and see if that causes it.

K, so I reenabled hotspot and connected to it and it was fine until now. Then it crashed when I was doing a bunch of MIDI on my Akai MPK Mini to the Tetra. (no Sooper Looper activity, although the pedal was enabled but not in playback or record mode). And I just checked all three logs and all three only had information as recent as 4:17am BST (the crash was around 4:28am BST). And, interestingly there are now no logs before 4:17am BST either in the journalctl output. The logs at 4:17am all appear to be startup logs too, so maybe the system time was actually 4:17am BST then? This has me perplexed.

It appears that MIDI activity is definitely crashing things and not the Sooper Looper now. Which is really odd because I definitely know last week it was just crashing with Sooper Looper activity because I was solely trying to get my first loop down and was getting frustrated because just when I was getting the hang of it, it would crash and mess with the learning momentum. No MIDI involved then.

I’ll continue to test and look at more logs.

Update: I found that journalctl doesn’t persist logs by default and followed these instructions to persist them > http://ngelinux.com/why-journalctl-logs-disappear-after-reboot-and-how-to-make-it-permanent/, which is now working.

Allegedly they don’t persist because everything is actually stored in /var/log/messages, but that file is really noisy and hard to follow so I like this route better. We should probably include the above in the debugging wiki instructions.

K, so overnight the MODEP install crashed again but I couldn’t find logs. Then it was up again and I was tinkering on MIDI and it crashed. I finally got a log here after reboot (unplugging). Not sure if “May 15 20:00:00 patchbox jackdrc[431]: JackAudioDriver::ProcessGraphAsyncMaster: Process error” is useful but it is something!

patch@patchbox:~ $ sudo journalctl --unit jack
– Logs begin at Fri 2020-05-15 19:28:25 BST, end at Fri 2020-05-15 20:58:12 BST. –
May 15 20:00:00 patchbox jackdrc[431]: JackEngine::XRun: client = effect_0 was not finished, state = Triggered
May 15 20:00:00 patchbox jackdrc[431]: JackEngine::XRun: client = effect_1 was not finished, state = Running
May 15 20:00:00 patchbox jackdrc[431]: JackEngine::XRun: client = effect_2 was not finished, state = Triggered
May 15 20:00:00 patchbox jackdrc[431]: JackEngine::XRun: client = effect_3 was not finished, state = Triggered
May 15 20:00:00 patchbox jackdrc[431]: JackEngine::XRun: client = effect_4 was not finished, state = Triggered
May 15 20:00:00 patchbox jackdrc[431]: JackEngine::XRun: client = effect_5 was not finished, state = Triggered
May 15 20:00:00 patchbox jackdrc[431]: JackAudioDriver::ProcessGraphAsyncMaster: Process error
– Reboot –
May 15 20:27:11 patchbox systemd[1]: Started JACK Server.
May 15 20:27:11 patchbox jackdrc[418]: Failed to create secure directory (/home/jack/.config/pulse): No such file or directory

There wasn’t anything notable in mod-host or mod-ui Journal logs.

K, so I just noticed this at the top of my journalctl prints:

/var/log/journal/0371f17478ca4719867962bba6eb075b/user-1000@0005a5bc5e4406d0-e79b8e2dbb993d3e.journal~ corrupted

And that seems to be the reason there aren’t logs from before the crash, those files are binary. The only way to recover is to unplug the PiSound and then it doesn’t startup with flashing lights usually and I have to wait 2 minutes sometimes and then plug it in to get startup lights, and sometimes that doesn’t work and I have to wait another 2 minutes. Allegedly this is an FSCK type operation checking the filesystem.

At any rate, maybe I can actually get data from /var/log/messages still, and just grep/sed out all that mod-ui messages that are so noisy.

UPDATE: I don’t know what I was thinking /var/log/messages doesn’t have the noise that I thought I saw. I’ll have to figure out some other way to get logs. I think if I tail the logs to my SSH client computer (not the PiSound) that should do it and I can get the output just before crash!

UPDATE2: K, got all three tailing now with ssh patch@patch.local "sudo journalctl --unit modep-mod-ui|modep-mod-host|jack --follow" and the next crash should happen between now and 8 hours from now and it will be really easy to see now because the SSH connection will just terminate and there will be logs right there.

1 Like

It sounds like the software locks up when some MIDI loop happens, when endlessly the same events get forwarded in a circle. Do you have an idea how such circle could form in your setup? Maybe amidiauto or MOD’s new aggregate MIDI mode may have something to do with it.

There are two separate types of crashes that I can tell:

  1. Is the MIDI loop crash, which I can repeat in aggregate mode. I just have the MPK Mini and Tetra hooked up and somehow aggregate mode creates that loop. So that is crash type 1.
  2. Second crash type, is just time. If I have the PiSound on long enough with my no activity, it will crash in a matter of hours. I can never leave it on over night and have it work in the morning. And I can’t get logs saying what is happening. So I feel like some next steps are to enable a kernel crash logging. And also run some checks on the memory and also the SD card integrity. I think another test is to load a blank pedal board and probably what I will try first because it is easiest. I’ll also unplug all MIDI cables to rule that out. If it doesn’t crash over night with a blank board and no cables I’ll add back in things to see if I can trigger the crash again.

Here is a picture of the crash state it is usually in, with both LEDs lit up. Sometimes I think it isn’t both, but the last few have been like this.

K, I did this and it hasn’t crashed since. So now, I just added only the Sooper Looper pedal back in and will see if it crashes over night.

1 Like