3.8.0 installation failing on Ubuntu

[gene96817]

I am finally trying to install 3.8.0. I am getting this failure.

root@studio1:/lib/systemd/system# service jamulus-headless status
● jamulus-headless.service - Jamulus headless server
Loaded: loaded (/lib/systemd/system/jamulus-headless.service; enabled; vendor preset: enabled)
Active: activating (auto-restart) (Result: exit-code) since Sun 2021-08-08 21:49:54 HST; 21s ago
Process: 6787 ExecStart=/bin/sh -c exec /usr/bin/jamulus-headless -s -n -e choral.jamulus.io:22724 -F -P --serverbindip 72.253.194.252 -m /etc/jamulus/jamulus_welcome -o HI-Studio1;Honolulu-Hawaii;225 (code=exited, status=1/FAILURE)
Main PID: 6787 (code=exited, status=1/FAILURE)

My command line looks like this:

ExecStart=/bin/sh -c 'exec /usr/bin/jamulus-headless -s -n -e choral.jamulus.io:22724 -F -P --serverbindip 72.253.194.252 -m /etc/jamulus/jamulus_welcome -o HI-Studio1;Honolulu-Hawaii;225'

I think I followed all the command options according to the table.

[rdica]

Run journalctl -u jamulus-headless and show us error messages please.

[gene96817]

Thank you for your reply. I found two errors: my external IP had changed and the argument for -o needed quotes.
With a system restart, my errors look like:

● jamulus-headless.service - Jamulus-Server
Loaded: loaded (/etc/systemd/system/jamulus-headless.service; enabled; vendor preset: enabled)
Active: activating (auto-restart) (Result: exit-code) since Tue 2021-08-10 11:49:05 HST; 14s ago
Process: 4173 ExecStart=/bin/sh -c /usr/bin/jamulus-headless -e choral.jamulus.io:22724 -F -o "HI-Studio1;Honolulu;225" -s -T -u 80 -w /etc/jamulus/jamulus_welcome -n --serverpublicip 72.234.252.109 -p 22124 (code=exited, status=1/FAILURE)
Main PID: 4173 (code=exited, status=1/FAILURE)
~
and:

Aug 10 11:52:06 studio1.eyc-labs.com systemd[1]: Started Jamulus-Server.
Aug 10 11:52:06 studio1.eyc-labs.com jamulus[4266]: - directory server: choral.jamulus.io:22724
Aug 10 11:52:06 studio1.eyc-labs.com jamulus[4266]: - using 64 samples frame size mode
Aug 10 11:52:06 studio1.eyc-labs.com jamulus[4266]: - server info: HI-Studio1;Honolulu;225
Aug 10 11:52:06 studio1.eyc-labs.com jamulus[4266]: - server mode chosen
Aug 10 11:52:06 studio1.eyc-labs.com jamulus[4266]: - using multithreading
Aug 10 11:52:06 studio1.eyc-labs.com jamulus[4266]: - maximum number of channels: 80
Aug 10 11:52:06 studio1.eyc-labs.com jamulus[4266]: - welcome message: /etc/jamulus/jamulus_welcome
Aug 10 11:52:06 studio1.eyc-labs.com jamulus[4266]: - no GUI mode chosen
Aug 10 11:52:06 studio1.eyc-labs.com jamulus[4266]: - server public IP: 72.234.252.109
Aug 10 11:52:06 studio1.eyc-labs.com jamulus[4266]: - selected port number: 22124
Aug 10 11:52:07 studio1.eyc-labs.com jamulus[4266]: Jamulus: Network Error: Cannot bind the socket (maybe the software is already running).
Aug 10 11:52:07 studio1.eyc-labs.com systemd[1]: jamulus-headless.service: Main process exited, code=exited, status=1/FAILURE
Aug 10 11:52:07 studio1.eyc-labs.com systemd[1]: jamulus-headless.service: Failed with result 'exit-code'.

[4]+ Stopped journalctl -u jamulus-headless --since "15 minutes ago"

How do I fix the network error?

Thanks

[gene96817]

It looks like I had two jamulus instances running. One was "jamulus" and the other "jamulus-headless".
How to I stop "jamulus" from starting up? I manually stopped "jamulus" and manually restarted "jamulus-headless". Now my jouirnal entries look like:

Aug 10 12:09:36 studio1.eyc-labs.com systemd[1]: Stopped Jamulus-Server.
Aug 10 12:09:36 studio1.eyc-labs.com systemd[1]: Started Jamulus-Server.
Aug 10 12:09:36 studio1.eyc-labs.com jamulus[5032]: - directory server: choral.jamulus.io:22724
Aug 10 12:09:36 studio1.eyc-labs.com jamulus[5032]: - using 64 samples frame size mode
Aug 10 12:09:36 studio1.eyc-labs.com jamulus[5032]: - server info: HI-Studio1;Honolulu;225
Aug 10 12:09:36 studio1.eyc-labs.com jamulus[5032]: - server mode chosen
Aug 10 12:09:36 studio1.eyc-labs.com jamulus[5032]: - using multithreading
Aug 10 12:09:36 studio1.eyc-labs.com jamulus[5032]: - maximum number of channels: 80
Aug 10 12:09:36 studio1.eyc-labs.com jamulus[5032]: - welcome message: /etc/jamulus/jamulus_welcome
Aug 10 12:09:36 studio1.eyc-labs.com jamulus[5032]: - no GUI mode chosen
Aug 10 12:09:36 studio1.eyc-labs.com jamulus[5032]: - server public IP: 72.234.252.109
Aug 10 12:09:36 studio1.eyc-labs.com jamulus[5032]: - selected port number: 22124
Aug 10 12:09:36 studio1.eyc-labs.com jamulus[5032]: Using "72.234.252.109" as external IP.
Aug 10 12:09:36 studio1.eyc-labs.com jamulus[5032]: Recording state not initialised
Aug 10 12:09:36 studio1.eyc-labs.com jamulus[5032]: multithreading enabled, setting thread count to 16
Aug 10 12:09:36 studio1.eyc-labs.com jamulus[5032]: *** Jamulus, Version 3.8.0
Aug 10 12:09:36 studio1.eyc-labs.com jamulus[5032]: *** Internet Jam Session Software
Aug 10 12:09:36 studio1.eyc-labs.com jamulus[5032]: *** Released under the GNU General Public License (GPL)
Aug 10 12:09:36 studio1.eyc-labs.com jamulus[5032]: Server Registration Status update: Registration requested
Aug 10 12:09:36 studio1.eyc-labs.com jamulus[5032]: Server Registration Status update: Registered
Aug 10 12:10:31 studio1.eyc-labs.com jamulus[5032]: 2021-08-10 12:10:31, 75.25.129.187, connected (1)
Aug 10 12:10:54 studio1.eyc-labs.com jamulus[5032]: 2021-08-10 12:10:54,, server idling -------------------------------------

[11]+ Stopped journalctl -u jamulus-headless --since "15 minutes ago"

[rdica]

systemctl status jamulus will show you status of a service called jamulus if the service exists. You'll want to disable the service by running systemctl disable jamulus in that case.
Sorry I missed the quoting of serverinfo.

[gene96817]

Thanks so much for your help. My blood pressure is returning to normal.
BUT... it is not yet running well :(
I have checked my local IP, my public IP, and my port mapping.
on a restart I get

● jamulus-headless.service - Jamulus-Server
Loaded: loaded (/etc/systemd/system/jamulus-headless.service; enabled; vendor preset: enabled)
Active: active (running) since Tue 2021-08-10 12:50:48 HST; 30s ago
Main PID: 966 (sh)
Tasks: 19 (limit: 65000)
Memory: 55.2M
CGroup: /system.slice/jamulus-headless.service
├─ 966 /bin/sh -c /usr/bin/jamulus-headless -e choral.jamulus.io:22724 -F -o "HI-Studio1;Honolulu;225" -s -T -u 80 -w /et>
└─1012 /usr/bin/jamulus-headless -e choral.jamulus.io:22724 -F -o HI-Studio1;Honolulu;225 -s -T -u 80 -w /etc/jamulus/jam>

Aug 10 12:50:48 studio1.eyc-labs.com jamulus[1012]: - no GUI mode chosen
Aug 10 12:50:48 studio1.eyc-labs.com jamulus[1012]: - server public IP: 72.234.252.109
Aug 10 12:50:48 studio1.eyc-labs.com jamulus[1012]: - selected port number: 22124
Aug 10 12:50:48 studio1.eyc-labs.com jamulus[1012]: Using "72.234.252.109" as external IP.
Aug 10 12:50:48 studio1.eyc-labs.com jamulus[1012]: Recording state not initialised
Aug 10 12:50:48 studio1.eyc-labs.com jamulus[1012]: multithreading enabled, setting thread count to 16
Aug 10 12:50:48 studio1.eyc-labs.com jamulus[1012]: *** Jamulus, Version 3.8.0
Aug 10 12:50:48 studio1.eyc-labs.com jamulus[1012]: *** Internet Jam Session Software
Aug 10 12:50:48 studio1.eyc-labs.com jamulus[1012]: *** Released under the GNU General Public License (GPL)
Aug 10 12:50:48 studio1.eyc-labs.com jamulus[1012]: Server Registration Status update: Bad address
~
~
~
[1]+ Stopped systemctl status jamulus-headless

and from the log

-- Reboot --
Aug 10 12:50:48 studio1.eyc-labs.com systemd[1]: Started Jamulus-Server.
Aug 10 12:50:48 studio1.eyc-labs.com jamulus[1012]: - directory server: choral.jamulus.io:22724
Aug 10 12:50:48 studio1.eyc-labs.com jamulus[1012]: - using 64 samples frame size mode
Aug 10 12:50:48 studio1.eyc-labs.com jamulus[1012]: - server info: HI-Studio1;Honolulu;225
Aug 10 12:50:48 studio1.eyc-labs.com jamulus[1012]: - server mode chosen
Aug 10 12:50:48 studio1.eyc-labs.com jamulus[1012]: - using multithreading
Aug 10 12:50:48 studio1.eyc-labs.com jamulus[1012]: - maximum number of channels: 80
Aug 10 12:50:48 studio1.eyc-labs.com jamulus[1012]: - welcome message: /etc/jamulus/jamulus_welcome
Aug 10 12:50:48 studio1.eyc-labs.com jamulus[1012]: - no GUI mode chosen
Aug 10 12:50:48 studio1.eyc-labs.com jamulus[1012]: - server public IP: 72.234.252.109
Aug 10 12:50:48 studio1.eyc-labs.com jamulus[1012]: - selected port number: 22124
Aug 10 12:50:48 studio1.eyc-labs.com jamulus[1012]: Using "72.234.252.109" as external IP.
Aug 10 12:50:48 studio1.eyc-labs.com jamulus[1012]: Recording state not initialised
Aug 10 12:50:48 studio1.eyc-labs.com jamulus[1012]: multithreading enabled, setting thread count to 16
Aug 10 12:50:48 studio1.eyc-labs.com jamulus[1012]: *** Jamulus, Version 3.8.0
Aug 10 12:50:48 studio1.eyc-labs.com jamulus[1012]: *** Internet Jam Session Software
Aug 10 12:50:48 studio1.eyc-labs.com jamulus[1012]: *** Released under the GNU General Public License (GPL)
Aug 10 12:50:48 studio1.eyc-labs.com jamulus[1012]: Server Registration Status update: Bad address
[2]+ Stopped journalctl -u jamulus-headless --since "15 minutes ago"

What else could be an address problem?

[gene96817]

One more clue.... on reboot, Jamulus shows the problem on previous message. With manual restart (I have repeated reboot+manual restart)... I get:

Aug 10 12:59:37 studio1.eyc-labs.com jamulus[999]: Server Registration Status update: Bad address
Aug 10 13:03:02 studio1.eyc-labs.com systemd[1]: Stopping Jamulus-Server...
Aug 10 13:03:02 studio1.eyc-labs.com jamulus[999]: OnHandledSignal: 15
Aug 10 13:03:02 studio1.eyc-labs.com jamulus[999]: Server Registration Status update: Unregistered
Aug 10 13:03:02 studio1.eyc-labs.com systemd[1]: jamulus-headless.service: Succeeded.
Aug 10 13:03:02 studio1.eyc-labs.com systemd[1]: Stopped Jamulus-Server.
Aug 10 13:03:02 studio1.eyc-labs.com systemd[1]: Started Jamulus-Server.
Aug 10 13:03:02 studio1.eyc-labs.com jamulus[3606]: - directory server: choral.jamulus.io:22724
Aug 10 13:03:02 studio1.eyc-labs.com jamulus[3606]: - using 64 samples frame size mode
Aug 10 13:03:02 studio1.eyc-labs.com jamulus[3606]: - server info: HI-Studio1;Honolulu;225
Aug 10 13:03:02 studio1.eyc-labs.com jamulus[3606]: - server mode chosen
Aug 10 13:03:02 studio1.eyc-labs.com jamulus[3606]: - using multithreading
Aug 10 13:03:02 studio1.eyc-labs.com jamulus[3606]: - maximum number of channels: 80
Aug 10 13:03:02 studio1.eyc-labs.com jamulus[3606]: - welcome message: /etc/jamulus/jamulus_welcome
Aug 10 13:03:02 studio1.eyc-labs.com jamulus[3606]: - no GUI mode chosen
Aug 10 13:03:02 studio1.eyc-labs.com jamulus[3606]: - server public IP: 72.234.252.109
Aug 10 13:03:02 studio1.eyc-labs.com jamulus[3606]: - selected port number: 22124
Aug 10 13:03:02 studio1.eyc-labs.com jamulus[3606]: Using "72.234.252.109" as external IP.
Aug 10 13:03:02 studio1.eyc-labs.com jamulus[3606]: Recording state not initialised
Aug 10 13:03:02 studio1.eyc-labs.com jamulus[3606]: multithreading enabled, setting thread count to 16
Aug 10 13:03:02 studio1.eyc-labs.com jamulus[3606]: *** Jamulus, Version 3.8.0
Aug 10 13:03:02 studio1.eyc-labs.com jamulus[3606]: *** Internet Jam Session Software
Aug 10 13:03:02 studio1.eyc-labs.com jamulus[3606]: *** Released under the GNU General Public License (GPL)
Aug 10 13:03:02 studio1.eyc-labs.com jamulus[3606]: Server Registration Status update: Registration requested
Aug 10 13:03:03 studio1.eyc-labs.com jamulus[3606]: Server Registration Status update: Registered

????? Is there a timing issue?
If the server registration fail, does Jamulus retry the regisration? What triggers the retry?

[rdica]

Can you paste the systemd unit file(s), you may have more than one (one for jamulus, one for headless).
Also, if there's more than one jamulus service, make sure one's disabled.
It's also possible the service is trying to start before the network interface is up, thats why I'm asking to see the unit file.

Here's my unit file:

[Unit]
Description=Jamulus-Server
After=network-online.target
StartLimitIntervalSec=0

[Service]
Type=simple
#Restart=always
Restart=on-failure
RestartSec=5
User=ardy
StandardOutput=journal
StandardError=inherit
SyslogIdentifier=jamulus
ExecStart=/usr/local/bin/jamulus --server --nogui --discononquit --welcomemessage /data/jamulus/html/jam.html --numchannels 10 --centralserver anygenre2.jamulus.io:22224 --serverinfo  "Rick's Open Jam;UTC-4 (3.8.0);225" -R /data/jamulus/recordings --norecord -l /data/jamulus/logs/jamulus-server.log -T -P

[Install]
WantedBy=multi-user.target

Note the After line in [Unit] section. Means the service won't be started until after network-online target is up.

I didn't have much success using the ExecStart=/bin/sh -c command method due to quoting issues I was just too lazy to troubleshoot, and use the above instead.

[gene96817]

The mystery deepens.
Below... the unit file.... the related log.... AND connecting to the server shows in the chat window "Server Terminated"
First the unit file:

[Unit]
Description=Jamulus-Server
After=network.target

[Service]
Type=simple
User=jamulus
Group=nogroup
NoNewPrivileges=true
ProtectSystem=true
ProtectHome=true
Nice=-20
IOSchedulingClass=realtime
IOSchedulingPriority=0

Change this to set genre, location and other parameters.

See Command-Line-Options

ExecStart=/bin/sh -c '/usr/bin/jamulus-headless -e choral.jamulus.io:22724 -F -o "HI-Studio1;Honolulu;225" -s -T -u 80 -w /etc/jamulus/jamulu>

Restart=on-failure
RestartSec=30
StandardOutput=journal
StandardError=inherit
SyslogIdentifier=jamulus

[Install]
WantedBy=multi-user.target

Where do I find documentation on all these options?
Then the log file looks like:

-- Logs begin at Tue 2021-06-15 20:27:00 HST, end at Wed 2021-08-11 18:52:54 HST. --
Aug 11 18:47:35 studio1.eyc-labs.com jamulus[27042]: Server Registration Status update: Registration requested
Aug 11 18:47:35 studio1.eyc-labs.com jamulus[27042]: Server Registration Status update: Registered
root@studio1:/etc/systemd/system# journalctl -u jamulus-headless --since "15 minutes ago"
-- Logs begin at Tue 2021-06-15 20:27:00 HST, end at Wed 2021-08-11 18:56:51 HST. --
Aug 11 18:47:35 studio1.eyc-labs.com jamulus[27042]: Server Registration Status update: Registration requested
Aug 11 18:47:35 studio1.eyc-labs.com jamulus[27042]: Server Registration Status update: Registered
Aug 11 18:56:31 studio1.eyc-labs.com jamulus[27042]: 2021-08-11 18:56:31, 72.234.252.109, connected (1)
root@studio1:/etc/systemd/system# journalctl -u jamulus-headless --since "1 hour ago"
-- Logs begin at Tue 2021-06-15 20:27:00 HST, end at Wed 2021-08-11 18:56:51 HST. --
Aug 11 18:02:01 studio1.eyc-labs.com jamulus[18731]: Server Registration Status update: Registration requested
Aug 11 18:02:01 studio1.eyc-labs.com jamulus[18731]: Server Registration Status update: Registered
Aug 11 18:17:01 studio1.eyc-labs.com jamulus[18731]: Server Registration Status update: Registration requested
Aug 11 18:17:01 studio1.eyc-labs.com jamulus[18731]: Server Registration Status update: Registered
Aug 11 18:28:03 studio1.eyc-labs.com jamulus[18731]: 2021-08-11 18:28:03, 72.234.252.109, connected (1)
Aug 11 18:32:01 studio1.eyc-labs.com jamulus[18731]: Server Registration Status update: Registration requested
Aug 11 18:32:01 studio1.eyc-labs.com jamulus[18731]: Server Registration Status update: Registered
Aug 11 18:32:34 studio1.eyc-labs.com jamulus[18731]: OnHandledSignal: 15
Aug 11 18:32:34 studio1.eyc-labs.com jamulus[18731]: 2021-08-11 18:32:34,, server idling -------------------------------------
Aug 11 18:32:34 studio1.eyc-labs.com systemd[1]: Stopping Jamulus-Server...
Aug 11 18:32:34 studio1.eyc-labs.com jamulus[18731]: Server Registration Status update: Unregistered
Aug 11 18:32:34 studio1.eyc-labs.com systemd[1]: jamulus-headless.service: Succeeded.
Aug 11 18:32:34 studio1.eyc-labs.com systemd[1]: Stopped Jamulus-Server.
Aug 11 18:32:34 studio1.eyc-labs.com systemd[1]: Started Jamulus-Server.
Aug 11 18:32:34 studio1.eyc-labs.com jamulus[27042]: - directory server: choral.jamulus.io:22724
Aug 11 18:32:34 studio1.eyc-labs.com jamulus[27042]: - using 64 samples frame size mode
Aug 11 18:32:34 studio1.eyc-labs.com jamulus[27042]: - server info: HI-Studio1;Honolulu;225
Aug 11 18:32:34 studio1.eyc-labs.com jamulus[27042]: - server mode chosen
Aug 11 18:32:34 studio1.eyc-labs.com jamulus[27042]: - using multithreading
Aug 11 18:32:34 studio1.eyc-labs.com jamulus[27042]: - maximum number of channels: 80
Aug 11 18:32:34 studio1.eyc-labs.com jamulus[27042]: - welcome message: /etc/jamulus/jamulus_welcome
Aug 11 18:32:34 studio1.eyc-labs.com jamulus[27042]: - no GUI mode chosen
Aug 11 18:32:34 studio1.eyc-labs.com jamulus[27042]: - server public IP: 72.234.252.109
Aug 11 18:32:34 studio1.eyc-labs.com jamulus[27042]: - selected port number: 22124
Aug 11 18:32:34 studio1.eyc-labs.com jamulus[27042]: Using "72.234.252.109" as external IP.
Aug 11 18:32:34 studio1.eyc-labs.com jamulus[27042]: Recording state not initialised
Aug 11 18:32:34 studio1.eyc-labs.com jamulus[27042]: multithreading enabled, setting thread count to 16
Aug 11 18:32:34 studio1.eyc-labs.com jamulus[27042]: *** Jamulus, Version 3.8.0
Aug 11 18:32:34 studio1.eyc-labs.com jamulus[27042]: *** Internet Jam Session Software
Aug 11 18:32:34 studio1.eyc-labs.com jamulus[27042]: *** Released under the GNU General Public License (GPL)
Aug 11 18:32:34 studio1.eyc-labs.com jamulus[27042]: Server Registration Status update: Registration requested
Aug 11 18:32:34 studio1.eyc-labs.com jamulus[27042]: 2021-08-11 18:32:34, 72.234.252.109, connected (1)
Aug 11 18:32:34 studio1.eyc-labs.com jamulus[27042]: Server Registration Status update: Registered
Aug 11 18:32:42 studio1.eyc-labs.com jamulus[27042]: 2021-08-11 18:32:42, 136.24.160.220, connected (2)
Aug 11 18:33:19 studio1.eyc-labs.com jamulus[27042]: 2021-08-11 18:33:19,, server idling -------------------------------------
Aug 11 18:33:25 studio1.eyc-labs.com jamulus[27042]: 2021-08-11 18:33:25, 72.234.252.109, connected (1)
Aug 11 18:33:38 studio1.eyc-labs.com jamulus[27042]: 2021-08-11 18:33:38,, server idling -------------------------------------
Aug 11 18:33:44 studio1.eyc-labs.com jamulus[27042]: 2021-08-11 18:33:44, 72.234.252.109, connected (1)
Aug 11 18:36:42 studio1.eyc-labs.com jamulus[27042]: 2021-08-11 18:36:42,, server idling -------------------------------------
Aug 11 18:47:35 studio1.eyc-labs.com jamulus[27042]: Server Registration Status update: Registration requested
Aug 11 18:47:35 studio1.eyc-labs.com jamulus[27042]: Server Registration Status update: Registered
Aug 11 18:56:31 studio1.eyc-labs.com jamulus[27042]: 2021-08-11 18:56:31, 72.234.252.109, connected (1)

I don't see anything that suggest a problem.
Jamulus Explorer shows my server registered.
Log shows my client connected.
Message says "Server terminated"
Luckly my bass singer just appeared on the serve. It sounds like the audio service is working.

Now what?

[dcorson-ticino-com]

I'm not the Linux expert who can decipher these files in all details, but my bet is that for some reason Jamulus is being started twice, once as jamullus-headless... and once as Jamulus-Server.

[gene96817]

What would be the distinction between "jamulus-headless" and "Jamulus-Server"?
I've already checked to make sure there is no "jamulus" running.
I'll check the process list tomorrow.

[rdica]

That last log bit doesn't show any indications of a problem.

What is the filename of the unit file, is it jamulus-headless.service?

In the log above, the reference to Jamulus-Server is taken from the Description field of the systemd unit file being processed.
If that unit file is jamulus-headless.service then they are the same service.

Try running find /etc/systemd /lib/systemd -type f -iname "*jamulus*", this will show you all jamulus unit files.
If you only have one unit file, you should be good to go.
If you're still seeing timing issues at boot with the service trying to start before network is up, try changing your After line in the unit file from network.target to network-online.target.

[gene96817]

@rdica Thank you for all your help. Turns out there were two services running. Cleaned up a corrupted jamulus_welcome file. Order has been restored. Linux intern, Gene