Mod Duo X stuck on restore/update mode

Dietr1ch · October 30, 2019, 7:55am

I can ssh into the machine/box, but the screen gets stuck at the “Mod Duo | X” screen
Currently the jack and mod-host services are not even loaded (no such file or dir), and
mod-ui is inactive, but it likely depends on the other 2.

I tried reinstalling following the troubleshooting page on the wiki, but unplugging
and powering on my Duo X with the 1st button pressed doesn’t seem to get me into recovery
mode, I still get an ethernet adapter instead of a mass storage device through USB.

Can I just dump the tar image into some directory and expect it to be picked up at boot time
for reinstalling?
Am I just entering restore/update mode incorrectly?

Jan · October 30, 2019, 10:27am

Hi @Dietr1ch,

The recovery mode is entered by holding down both the left encoder and left-most bottom button, did you try that, or did you only hold down the 1st button?

Hmm, I do agree that the wording of it in the wiki is a bit unclear, I will change that!

MikeFlynnBass · October 30, 2019, 10:39am

I’ll try that on my DUO - I was pressing just the left knob not the button at the same time - that might sort my frozen box out

Dietr1ch · November 3, 2019, 8:25pm

Thanks for updating the wiki

I was able to reinstall, but that didn’t fixed the issue even doing so 3 times in a row
(the wiki references an issue that might require reinstalling twice).

I’m still able to ssh into the box and noticed that my public key was still sitting there,
so the reinstall didn’t touched all the configuration, which is likely why my mod duo
isn’t working.

systemctl still shows that some critical things are not starting :(,

systemctl status jack mod-noise-removal mod-peakmeter mod-self-test mod-ui mod-host

● jack.service
Loaded: not-found (Reason: No such file or directory)
Active: inactive (dead)

● mod-noise-removal.service - MOD Noise Removal
Loaded: loaded (/etc/systemd/system/mod-noise-removal.service; enabled; vendor preset: enabled)
Active: active (running) since Thu 1970-01-01 00:00:01 UTC; 16min ago
Main PID: 1691 (mod-noise-remov)
CGroup: /system.slice/mod-noise-removal.service
└─1691 /usr/bin/mod-noise-removal

● mod-peakmeter.service - MOD Peakmeter
Loaded: loaded (/etc/systemd/system/mod-peakmeter.service; enabled; vendor preset: enabled)
Active: inactive (dead)

● mod-self-test.service - MOD Self Test
Loaded: loaded (/etc/systemd/system/mod-self-test.service; enabled; vendor preset: enabled)
Active: inactive (dead)
Condition: start condition failed at Thu 1970-01-01 00:00:01 UTC; 16min ago
ConditionPathExists=/root/need-self-test was not met

● mod-ui.service - MOD Web Server
Loaded: loaded (/etc/systemd/system/mod-ui.service; enabled; vendor preset: enabled)
Active: inactive (dead)

● mod-host.service
Loaded: not-found (Reason: No such file or directory)
Active: inactive (dead)

top says that mod-noise-removal is using ~200% cpu, I’m not sure if it’s stuck or that’s just an
artifact of using a rt kernel.

I’m not sure how to debug this as I’m not familiar with the system.
Where should I look for useful logs? Is there documentation on the things that should be running, their relationship and how start up?

Dietr1ch · November 4, 2019, 8:08am

I ran the self test, passed the screen, knobs and button tests, but got 9 failing tests

mod-self-test

…
TEXT: Press right-most button
TEXT: Press right-most button
TEXT: Please wait…
TEXT: Please wait…
jackdmp 1.9.12
Copyright 2001-2005 Paul Davis and others.
Copyright 2004-2016 Grame.
Copyright 2016-2017 Filipe Coelho.
jackdmp comes with ABSOLUTELY NO WARRANTY
This is free software, and you are welcome to redistribute it
under certain conditions; see the file COPYING for details
CPU DMA Latency optimization enabled
`default’ server already active
Failed to open server
Exception ignored in: <bound method AutoTerminatingProcess.del of <test_audio.AutoTerminatingProcess object at 0xffff7b742ba8>>
Traceback (most recent call last):
File “/usr/share/mod/self-test/test_audio.py”, line 30, in del
self.proc.terminate()
File “/usr/lib/python3.4/subprocess.py”, line 1686, in terminate
File “/usr/lib/python3.4/subprocess.py”, line 1681, in send_signal
ProcessLookupError: [Errno 3] No such process

Since it looked like a python crash I inspected the test a bit and found the logs,

ERROR: test_export (test_gpio.TestGPIOs)

OSError: [Errno 16] Device or resource busy

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
File “/usr/share/mod/self-test/test_gpio.py”, line 30, in test_export
fh.write(“87\n”)
OSError: [Errno 16] Device or resource busy

FAIL: test_usage (test_audio.TestJackdServerUsage)

Traceback (most recent call last):
File “/usr/share/mod/self-test/test_audio.py”, line 142, in test_usage
self.assertIsNone(proc.poll())
AssertionError: 255 is not None

FAIL: test_1_loopback (test_audio.TestAudioFlow)

Traceback (most recent call last):
File “/usr/share/mod/self-test/test_audio.py”, line 231, in setUp
self.assertIsNone(self.proc.poll())
AssertionError: 255 is not None

FAIL: test_2_headphones (test_audio.TestAudioFlow)

Traceback (most recent call last):
File “/usr/share/mod/self-test/test_audio.py”, line 231, in setUp
self.assertIsNone(self.proc.poll())
AssertionError: 255 is not None

FAIL: test_3_nothing (test_audio.TestAudioFlow)

Traceback (most recent call last):
File “/usr/share/mod/self-test/test_audio.py”, line 231, in setUp
self.assertIsNone(self.proc.poll())
AssertionError: 255 is not None

FAIL: test_1_loopback_on (test_midi.TestMidiLoopback)

Traceback (most recent call last):
File “/usr/share/mod/self-test/test_midi.py”, line 50, in test_1_loopback_on
self.assertEqual(self.serial.readall(), self.kTestDataBuf)
AssertionError: b’’ != b’\x90dd\x80d\x00’

FAIL: test_1_loopback_on (test_controlchain.TestControlChainLoopback)

Traceback (most recent call last):
File “/usr/share/mod/self-test/test_controlchain.py”, line 57, in test_1_loopback_on
self.assertEqual(self.serial.readall(), self.kTestDataBuf)
AssertionError: b’’ != b’\x90dd\x80d\x00’

FAIL: test_register (test_network.TestNetworkRegisterHost)

Traceback (most recent call last):
File “/usr/share/mod/self-test/test_network.py”, line 27, in test_register
self.assertCommand(“ifconfig usb1 %s” % MOD_HOST_IP)
File “/usr/share/mod/self-test/test_abstract.py”, line 87, in assertCommand
self.assertEqual(os.system(cmd+" &>/dev/null"), 0)
AssertionError: 256 != 0

FAIL: test_mod_host_ip (test_network.TestNetworkPing)

Traceback (most recent call last):
File “/usr/share/mod/self-test/test_network.py”, line 43, in test_mod_host_ip
self.assertCommand(“ping -c 1 %s” % MOD_HOST_IP)
File “/usr/share/mod/self-test/test_abstract.py”, line 87, in assertCommand
self.assertEqual(os.system(cmd+" &>/dev/null"), 0)
AssertionError: 256 != 0

Ran 27 tests in 85.128s

FAILED (failures=8, errors=1)

Dietr1ch · November 4, 2019, 8:23am

Jack seemed to have issues starting.
I killed the existing instance (I’m not sure why there was one since I thought that systemd was handling it and it was saying it was dead), ran it manually (mod-jackd) and then killed it, and then ran the self test again, this time I got a little bit further and got to hear something on my headphones (some increasingly loud ~sine waves), but still 7 tests failed after I was asked to unplug the audio cables.

I think that shutting down jackd ended up cleaning up some of its state.

These are the changes,

These tests now passed,

test_1_loopback (test_audio.TestAudioFlow)
test_3_nothing (test_audio.TestAudioFlow)

And these tests failed differently,

test_1_loopback (test_audio.TestAudioFlow)
test_3_nothing (test_audio.TestAudioFlow)

FAIL: test_1_loopback (test_audio.TestAudioFlow)

Traceback (most recent call last):
File “/usr/share/mod/self-test/test_audio.py”, line 268, in test_1_loopback
self.assertCommand(self_test_helper + " copy-check 1 0.0 0.4")
AssertionError: 51456 != 0

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
File “/usr/share/mod/self-test/test_audio.py”, line 273, in test_1_loopback
raise AssertionError(e)
AssertionError: 51456 != 0

FAIL: test_2_headphones (test_audio.TestAudioFlow)

Traceback (most recent call last):
File “/usr/share/mod/self-test/test_audio.py”, line 383, in test_2_headphones
self.assertCommand(self_test_helper + " copy-check 1 0.3 1.001")
AssertionError: 25856 != 0

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
File “/usr/share/mod/self-test/test_audio.py”, line 388, in test_2_headphones
raise AssertionError(e)
AssertionError: 25856 != 0

Dietr1ch · November 4, 2019, 8:42am

I enabled volatile logging for systemd,

mount / -o remount,rw
cat /etc/systemd/journald.conf

[Journal]
Storage=volatile
SystemMaxUse=20M

I restarted the box and see some logs, but it’s getting too late to keep debugging.

falkTX · November 4, 2019, 9:30am

ok a few things…

even if you try to run the self-test, likely it will fail as you need very specific cables.
midi and audio cables are fine, for loopback mode, but you will also need a network loopback cable, in a setup like so:

regarding the services, you should look for “jack2”, not “jack”.
and mod-host service does not exist.

to really get to the bottom of this, the best is to stop running services and running them manually.
for jack:

systemctl stop jack2
mod-jackd

(while that is running, you can do this one:

systemctl stop mod-ui
hmi-reset
mod-ui.run

the self-test is not intended for end users to run, it is only available in the system for convenience for us, otherwise we would take it out.

Dietr1ch · November 6, 2019, 7:45am

Ok, mod-jackd runs properly, but its systemd unit (jack2) hangs when starting up.
It seems that it’s hanging on some unmet dependencies.

systemctl list-jobs

JOB UNIT TYPE STATE
74 mixserver.service start waiting
63 enable-usb-gadget.service start running
71 cpu-freq-manager.service start running
82 post-boot-actions.service start waiting
153 jack-netmanager.service start waiting
65 jack-usb-gadget.service start waiting
66 jack2.service start waiting
75 mod-ui.service start waiting
64 mod-peakmeter.service start waiting

At the end of the script that enable-usb-gadget runs this is ran,

/usr/bin/systemctl start jack-netmanager

I lucked out a bit and I recalled that command being around when I ran ps aux | grep "jack" to look for jackd.

To my surprise, jack-netmanager depends on jack2,

jack2.service
└─enable-usb-gadget.service (ExecStart=/usr/sbin/enable-usb-gadget.sh)
  └─(Runs /usr/bin/systemctl start jack-netmanager)
     └─jack-netmanager.service
       └─jack2.service

Seems like a deadlock to me

Since enable-usb-gadget.sh conditionally runs systemctl start I commented that line out.
After a reboot systemd got to run the jackd and the mod-ui, so now I can just unplug/plug
the box and get a working pedal without ssh-ing into it.

However, systemd-analyze still complains that the boot has not finished.

systemctl list-jobs

JOB UNIT TYPE STATE
56 cpu-freq-manager.service start running
1 multi-user.target start waiting

Looking at /usr/sbin/cpu-freq-manager it seems that the oneshot unit won’t ever finish, so startup won’t finish. Maybe it should be set up as a daemon instead of a oneshot.

I tried out using Type=simple and got systemd’s startup fixed,

systemd-analyze critical-chain

multi-user.target @2.034s
  └─mod-ui.service @2.034s
      └─controlchaind.service @1.848s +182ms
        └─basic.target @465ms
          └─sockets.target @465ms
            └─controlchaind.socket @465ms
              └─sysinit.target @464ms
                └─systemd-tmpfiles-setup.service @242ms +222ms
                  └─systemd-journal-flush.service @220ms +16ms
                    └─var.mount @201ms +5ms
                      └─local-fs-pre.target @200ms
                        └─systemd-tmpfiles-setup-dev.service @188ms +10ms
                          └─kmod-static-nodes.service @113ms +20ms
                            └─system.slice @97ms
                              └─-.slice @95ms

Also, I guess that setting Restart=always shouldn’t hurt.

Dietr1ch · November 6, 2019, 8:03am

BTW, I still have no clue on how I really got to that broken state, and if my
configuration differs in other ways to the one on the release.
I guess I’ll pretend that things are fine as long as I can keep playing guitar, and that maybe
the configs will be restored on the next upgrade, but it would be nice to have a way to diff
my config against the intended image from the release. Is there a way to do so?

falkTX · November 6, 2019, 10:27am

Very detailed analysis, thank you!
jack-net-manager is something left on the side now that usb-gadget works on the Duo X (though in a limited way, as audio outputs do not work).

I do not know how to get such diff, but seems very likely it got to this state by enabling jack net-manager service together with the usb-gadget mode.
Will be fixed in v1.8.1, coming very soon.

EDIT: the net-manager start inside the enable-usb-gadget script was already removed in the future v1.9 release, I see now I did not backport the fix. and btw, we got that script working for Windows too! No audio though, but MIDI and ethernet at the same time works

pqs · November 6, 2019, 5:32pm

excellent use case… bookmarking!