Mycroft on Raspberry Pi OS only works in debug mode

mike99mac · January 23, 2021, 8:07pm

Baconator, thanks for the reply, but as I mentioned I’m running Raspberry Pi OS, not Pycroft.

Why would I get a “Connection failure: Connection refused” in normal mode, but not in debug mode. Anybody know?

Thanks.

-Mike Mac

baconator · January 23, 2021, 8:32pm

Yes, I accounted for that.

What’s “normal” mode for you? What’s debug? What’s actually running when you start either of those modes? What’s in the logs (voice, messagebus, etc)?

mike99mac · January 23, 2021, 8:55pm

Hey Baconator, wow, thanks for the quick reply!

I created the file /etc/systemd/system/mycroft.service as is described in the docs.
I issued the command ‘systemctl enable mycroft’ so that mycroft is started at boot time.
I reboot and issue the command ‘service mycroft status’, and the reply is that it is running.
I speak ‘Hey Mycroft’ and … nothing.
I then stop the service with ‘service mycroft stop’.
I start mycroft interactively with ‘mycroft-start debug’.
I speak ‘Hey Mycroft’ and hear a bleep.
I speak ‘What’s the weather?’ and get a nice answer.

So, starting mycroft at boot time as a service does not appear to be working, but starting it interactively in debug mode does.

Any help will be appreciated.

-Mike M

baconator · January 23, 2021, 8:59pm

What’s actually running when you start with the systemd start up? What’s in the logs (voice, messagebus, etc) for that?

How do both of those compare to when you run it in debug?

mike99mac · January 23, 2021, 9:11pm

Thanks again B.

I Ctrl-C out of the debug mode and start mycroft with ‘service mycroft start’. I wait a minute and speak ‘Hey Mycroft’. I look at /var/log/mycroft/voice.log and I see:

Connection failure: Connection refused
pa_context_connect() failed: Connection refused
2021-01-23 16:08:07.901 | INFO     |  4696 | __main__:handle_record_begin:37 | Begin Recording...
2021-01-23 16:08:14.178 | INFO     |  4696 | __main__:handle_record_end:45 | End Recording...
2021-01-23 16:08:15.598 | ERROR    |  4696 | mycroft.client.speech.listener:transcribe:239 | list index out of range
2021-01-23 16:08:15.601 | ERROR    |  4696 | mycroft.client.speech.listener:transcribe:240 | Speech Recognition could not understand audio

So why the ‘Connection refused’? Hmm, maybe it’s running as root and not as pi?

-Mike M

mike99mac · January 23, 2021, 9:26pm

Following up on my own reply. No, both in interactive mode and ‘systemctl mode’, all processes are running as pi.

Another thought - might the registration code not be getting sent in systemctl mode? So the mycroft.ai server is not recognizing my device as being being registered?

I searched the web and saw a similar issue by ‘marko’ in 2019.

Thanks.

-Mike

baconator · January 24, 2021, 2:31am

I hate to sound like a broken record, but, what’s actually running when you start with the systemd start up vs debug? What all is in the logs of note from the systemd start up? What’s different for those on the debug startup?

mike99mac · January 24, 2021, 12:37pm

When started with ‘mycroft-start debug’ I see these mycroft processes:

pi@raspberrypi:~$ ps -ef | grep mycroft | grep -v grep
pi        8498  4742  0 06:54 pts/1    00:00:00 bash /home/pi/mycroft-core/bin/mycroft-start debug
pi        8522  8498 12 06:54 pts/1    00:00:19 python3 -m mycroft.messagebus.service
pi        8525  8498 28 06:54 pts/1    00:00:43 python3 -m mycroft.skills
pi        8528  8498  7 06:54 pts/1    00:00:12 python3 -m mycroft.audio
pi        8531  8498 15 06:54 pts/1    00:00:23 python3 -m mycroft.client.speech
pi        8534  8498  9 06:54 pts/1    00:00:13 python3 -m mycroft.client.enclosure
pi        8536  8498 39 06:54 pts/1    00:01:00 python3 -m mycroft.client.text
pi        8747  8531  0 06:55 pts/1    00:00:00 /home/pi/.mycroft/precise/precise-engine/precise-engine /home/pi/.mycroft/precise/hey-mycroft.pb 2048
pi        8749  8747 54 06:55 pts/1    00:01:17 /home/pi/.mycroft/precise/precise-engine/precise-engine /home/pi/.mycroft/precise/hey-mycroft.pb 2048

When started with systemctl:

# ps -ef | grep mycroft | grep -v grep
pi        9412     1 23 06:58 ?        00:00:14 python3 -m mycroft.messagebus.service
pi        9415     1 39 06:58 ?        00:00:23 python3 -m mycroft.skills
pi        9418     1 17 06:58 ?        00:00:10 python3 -m mycroft.audio
pi        9421     1 14 06:58 ?        00:00:08 python3 -m mycroft.client.speech
pi        9424     1 15 06:58 ?        00:00:09 python3 -m mycroft.client.enclosure
pi        9463  9421  0 06:58 ?        00:00:00 /home/pi/.mycroft/precise/precise-engine/precise-engine /home/pi/.mycroft/precise/hey-mycroft.pb 2048
pi        9465  9463 71 06:58 ?        00:00:36 /home/pi/.mycroft/precise/precise-engine/precise-engine /home/pi/.mycroft/precise/hey-mycroft.pb 2048

So the mycroft.client.text process is missing when started with systemctl. Odd.

What might cause that?

-Mike M

j1nx · January 24, 2021, 4:24pm

That is actually the mycroft-cli-client and should be missing.

Can you post the content of your systemd file?

mike99mac · January 25, 2021, 1:29am

Sure, here it is - copied from the documentation:

pi@raspberrypi:/etc/systemd/system$ cat mycroft.service
[Unit]
Description=Mycroft AI
After=pulseaudio.service

[Service]
User=pi
WorkingDirectory=/home/pi/
ExecStart=/home/pi/mycroft-core/bin/mycroft-start all
ExecStop=/home/pi/mycroft-core/bin/mycroft-stop
Type=forking
Restart=no

[Install]
WantedBy=multi-user.target

-Mike M

j1nx · January 25, 2021, 3:42pm

Could you give it a go with;

“Type=simple”

instead of Forking

Don’t forget to; sudo systemctl daemon-reload.

Secondly; can you post the content of your pulseaudio.service file?

Thirdly; if the pulseaudio service is not running as the pi user, but a dedicated user instead. Did you add the pi user to the pulse and pulse-acces group?

mike99mac · January 26, 2021, 12:26pm

Yes, I will try it later today - thanks for the suggestion.

-Mike M

mike99mac · January 26, 2021, 10:55pm

j1nx,

I tried changing to “Type=simple”, and … same results :((

This is not that big of a deal because I can start it manually. Still it would be nice to resolve.

A question is: Are others getting mycroft to start using systemd with the config file from the documentation?

Thanks.

-Mike M

j1nx · January 27, 2021, 10:22am

It sounds to me, you do not start pulseaudio as system wide deamon utilizing pulseaudio.service.

If you start mycroft manually by CLI, it starts a session of pulseaudio for that program.
If you start mycroft via systemd, you state that it should start only after the pulseaudio service, but of course you need to make sure you also enable it at boot and that the pulseaudio service indeed is started and running for mycroft to connect to.

So what is the content of your pulseaudio.service file?
What does “sudo systemctl status pulseaudio” say?

mike99mac · January 28, 2021, 1:02am

j1nx,

I added an /etc/systemd/system/pulseaudio script, and that shows it is running after a reboot.

But mycroft still fails

After digging some, I see this:

journalctl -xe | grep mycroft
...
raspberrypi mycroft-start[785]: fatal: unable to access 'https://github.com/MycroftAI/mycroft-core.git/': Could not resolve host: github.com
...

So is mycroft trying to start too early and can’t get out to the internet?

I tried adding various 'after=network’s , all to no avail.

I also tried an old-fashioned /etc/init.d/mycroft script. This also failed where I see:

Jan 27 19:56:23 raspberrypi polkitd(authority=local)[485]: Operator of unix-process:1389:31208 successfully authenticated as unix-user:pi to gain ONE-SHOT authorization for action org.freedesktop.systemd1.manage-units for system-bus-name::1.48 [/bin/systemctl --no-pager start mycroft.service] (owned by unix-user:pi)

Is it trying to run as root and not pi?

sigh …

Thanks for your help.

-Mike M

j1nx · January 28, 2021, 3:58pm

Can you post the content of your;

pulseaudio.service
/etc/pulse/system.pa
/etc/pulse/daemon.conf

There are so many bits and pieces that need to be aligned properly that it is just a lot easier for me if you just post your files instead of snippets. I still believe your issues lies in mycroft not being allowed to talk properly with pulse audio.

mike99mac · January 28, 2021, 7:29pm

j1nx,

Thanks for sticking with this one. Here’s the info:

# cat /etc/systemd/system/pulseaudio.service
[Unit]
Description=PulseAudio system server

[Service]
ExecStart=/usr/bin/pulseaudio --daemonize=no --system --realtime --log-target=journal
ExecStop=/usr/bin/pulseaudio --kill
Type=notify

[Install]
WantedBy=multi-user.target

# egrep -v '^#|^$' /etc/pulse/system.pa
load-module module-device-restore
load-module module-stream-restore
load-module module-card-restore
.ifexists module-udev-detect.so
load-module module-udev-detect
.else
load-module module-detect
.endif
.ifexists module-esound-protocol-unix.so
load-module module-esound-protocol-unix
.endif
load-module module-native-protocol-unix
load-module module-default-device-restore
load-module module-rescue-streams
load-module module-always-sink
load-module module-suspend-on-idle
load-module module-position-event-sounds

# egrep -v '^;|^$|^#' /etc/pulse/daemon.conf
default-fragment-size-msec = 15

# cat /etc/systemd/system/mycroft.service
[Unit]
Description=Mycroft AI
After=pulseaudio.service network-online.target
Wants=network-online.target

[Service]
User=pi
WorkingDirectory=/home/pi/
ExecStart=/home/pi/mycroft-core/bin/mycroft-start all
ExecStop=/home/pi/mycroft-core/bin/mycroft-stop
Type=simple
Restart=no

[Install]
WantedBy=multi-user.target

I moved the SYSV script out of /etc/init.d and went back to systemd. I rebooted and pulseaudio was running but mycroft was not. To debug I did this:

# journalctl | grep mycroft
Jan 28 14:02:21 raspberrypi mycroft-start[784]: fatal: unable to access 'https://github.com/MycroftAI/mycroft-core.git/': Could not resolve host: github.com
...

“Could not resolve host” sure looks like a smoking gun. I could not even do an nslookup. I searched the web and installed dnsutils:

# nslookup github.com
-bash: nslookup: command not found
# apt-get install dnsutils
...
# reboot

I could now nslookup github. I rebooted many times trying different requriments in the mycroft systemd config file.

Still no joy :((

-Mike M

baconator · January 29, 2021, 5:01am

The start up scripts check for updates. Removing that and manually updating might be worthwhile.

mike99mac · January 29, 2021, 11:36am

I tried ‘sudo apt update’ and ‘sudo apt upgrade’, then a reboot - same symptoms.

-Mike M

mike99mac · January 30, 2021, 12:07pm

Hi,

I added a line for mycroft to wait 30 seconds to the systemd file:

ExecStartPre=/bin/sleep 30

Then I rebooted and got an SSH session while mycroft was sleeping:

$ service mycroft status
● mycroft.service - Mycroft AI
   Loaded: loaded (/etc/systemd/system/mycroft.service; enabled; vendor preset: enabled)
   Active: activating (start-pre) since Sat 2021-01-30 06:50:34 EST; 16s ago
Cntrl PID: 788 (sleep)
    Tasks: 1 (limit: 2063)
   CGroup: /system.slice/mycroft.service
           └─788 /bin/sleep 30

The service failed again, but differently:

$ journalctl -xe | grep mycroft
-- Subject: A start job for unit mycroft.service has begun execution
-- A start job for unit mycroft.service has begun execution.
-- Subject: A start job for unit mycroft.service has finished successfully
-- A start job for unit mycroft.service has finished successfully.
Jan 30 06:51:17 raspberrypi mycroft-start[1192]: error: insufficient permission for adding an object to repository database .git/objects
...

What would cause this error message?

I can still start mycroft interactively with either ‘all’ or ‘debug’.

Thanks.

-Mike M