Troubleshooting and Logs

[ghost]

I've installed shairport-sync on a Rasberry Pi 3 running Rasbian 9. I believe I have it installed correctly on the pi, but I don't see it as an airport option on my 2 ios devices running 11.4.1.

I've worked through the installation instructions a few times and tried installing it from the repositories. But no luck.

Are there program logs I can review to troubleshoot this?

Thanks!

[mikebrady]

Thanks for the post. Yep, there are logs. First though, it should be worth getting the version string for Shairport Sync:

$ shairport-sync -V

Note that it's an uppercase "V". It should respond with something like:

3.2.1-OpenSSL-Avahi-ALSA-soxr-metadata-sysconfdir:/etc

Perhaps you could post that result here.

On Raspbian 9, more familiarly Raspbian Stretch, you can see the status of a service, e.g:

$ sudo systemctl status shairport-sync

If it's running normally, you'll get something like this, which BTW indicates that it's just been restarted:

● shairport-sync.service - Shairport Sync - AirPlay Audio Receiver
   Loaded: loaded (/lib/systemd/system/shairport-sync.service; enabled; vendor preset: enabled)
   Active: active (running) since Mon 2018-08-06 07:00:40 IST; 36s ago
 Main PID: 25271 (shairport-sync)
   CGroup: /system.slice/shairport-sync.service
           └─25271 /usr/local/bin/shairport-sync

If the service failed, you might get something like this, which has happened because another instance of shairport-sync was already running:

● shairport-sync.service - Shairport Sync - AirPlay Audio Receiver
   Loaded: loaded (/lib/systemd/system/shairport-sync.service; enabled; vendor preset: enabled)
   Active: failed (Result: exit-code) since Mon 2018-08-06 06:57:45 IST; 10s ago
  Process: 25189 ExecStart=/usr/local/bin/shairport-sync (code=exited, status=1/FAILURE)
 Main PID: 25189 (code=exited, status=1/FAILURE)

Aug 06 06:57:45 raspberrypi systemd[1]: Started Shairport Sync - AirPlay Audio Receiver.
Aug 06 06:57:45 raspberrypi shairport-sync[25189]: fatal error: Could not establish a service on port 5000 -- program terminating. Is another instance of Shairport Sync running on this device?
Aug 06 06:57:45 raspberrypi systemd[1]: shairport-sync.service: Main process exited, code=exited, status=1/FAILURE
Aug 06 06:57:45 raspberrypi systemd[1]: shairport-sync.service: Unit entered failed state.
Aug 06 06:57:45 raspberrypi systemd[1]: shairport-sync.service: Failed with result 'exit-code'.

To get more detail, you can set the verbosity of the log entries it generates by editing the configuration file, typically at: /etc/shairport-sync.conf. Look for the log_verbosity entry, change it to 1 or 2 (make sure to uncomment the line!) and restart shairport-sync. Then look in the log with, e.g:

$ sudo journalctl -n100

to look at the last 100 lines of the log. With a log verbosity of 1, you might get something like this:

Aug 06 07:13:14 raspberrypi shairport-sync[25339]: alsa output device name is "hw:0".
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: Lowest dB value is a mute
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: Hardware mixer has dB volume from -102.380000 to 4.000000.
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: Version: "3.2.1-OpenSSL-Avahi-ALSA-soxr-metadata-sysconfdir:/etc"
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: statistics_requester status is 0.
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: daemon status is 0.
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: deamon pid file path is "/var/run/shairport-sync/shairport-sync.pid".
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: rtsp listening port is 5000.
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: udp base port is 6001.
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: udp port range is 100.
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: player name is "Raspberrypi".
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: backend is "(null)".
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: on-start action is "(null)".
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: on-stop action is "(null)".
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: wait-cmd status is 0.
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: on-start returns output is 0.
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: mdns backend "(null)".
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: stuffing option is "1" (0-basic, 1-soxr).
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: resync time is 0.050000 seconds.
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: allow a session to be interrupted: 1.
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: busy timeout time is 120.
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: drift tolerance is 0.010000 seconds.
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: password is "(null)".
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: ignore_volume_control is 0.
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: volume_max_db is not set
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: playback_mode is 0 (0-stereo, 1-mono, 1-reverse_stereo, 2-both_left, 3-both_right).
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: disable_synchronization is 0.
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: use_mmap_if_available is 1.
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: output_rate is 44100.
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: output_format is 3 (0-unknown, 1-S8, 2-U8, 3-S16, 4-S24, 5-S24_3LE, 6-S24_3BE, 7-S32).
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: audio backend desired buffer length is 0.150000 seconds.
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: audio backend latency offset is 0.000000 seconds.
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: audio backend silence lead-in time is -1.000000 seconds. A value -1.0 means use the default.
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: volume range in dB (zero means use the range specified by the mixer): 60.
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: zeroconf regtype is "_raop._tcp".
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: decoders_supported field is 1.
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: use_apple_decoder is 0.
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: alsa_use_hardware_mute is 0.
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: no special mdns service interface was requested.
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: configuration file name "/etc/shairport-sync.conf" resolves to "/etc/shairport-sync.conf".
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: metadata enabled is 1.
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: metadata pipename is "/tmp/shairport-sync-metadata".
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: metadata socket address is "(null)" port 0.
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: metadata socket packet size is "500".
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: get-coverart is 1.
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: loudness is 0.
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: loudness reference level is -20.000000
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: disable resend requests is off.
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: diagnostic_drop_packet_fraction is 0.000000. A value of 0.0 means no packets will be dropped deliberately.
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: Setting loudness threshhold to -20.000000.
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: deactivating loudness filter
Aug 06 07:13:15 raspberrypi shairport-sync[25339]: avahi: service 'AF31192A3A11@Raspberrypi' successfully added.

This is the [slightly edited] log of a normal startup of a service called Raspberry using soxr interpolation. You could also use:

$ sudo systemctl status shairport-sync

to give you the status and the last few [slightly edited] lines of the log:

● shairport-sync.service - Shairport Sync - AirPlay Audio Receiver
   Loaded: loaded (/lib/systemd/system/shairport-sync.service; enabled; vendor preset: enabled)
   Active: active (running) since Mon 2018-08-06 07:13:14 IST; 3min 46s ago
 Main PID: 25339 (shairport-sync)
   CGroup: /system.slice/shairport-sync.service
           └─25339 /usr/local/bin/shairport-sync

Aug 06 07:13:14 raspberrypi shairport-sync[25339]: Setting loudness threshhold to -20.000000.
Aug 06 07:13:14 raspberrypi shairport-sync[25339]: deactivating loudness filter
Aug 06 07:13:15 raspberrypi shairport-sync[25339]: avahi: service 'AF31192A3A11@Raspberrypi' successfully added.

Please let us know how you're doing.

[ghost]

Thanks for your fast reply, Mike.

Here's the output:

Version: 3.2.1-OpenSSL-Avahi-ALSA-sysconfdir:/etc

Status:

● shairport-sync.service - Shairport Sync - AirPlay Audio Receiver
   Loaded: loaded (/lib/systemd/system/shairport-sync.service; enabled; vendor preset: enabled)
   Active: active (running) since Mon 2018-08-06 08:02:38 PDT; 4min 10s ago
 Main PID: 529 (shairport-sync)
   CGroup: /system.slice/shairport-sync.service
           └─529 /usr/local/bin/shairport-sync

Aug 06 08:02:38 raspberrypi systemd[1]: Started Shairport Sync - AirPlay Audio Receiver.

Journal:

...
Aug 06 08:02:38 raspberrypi systemd[1]: Starting LSB: powerful, efficient, and scalable Mail Transport Agent...
Aug 06 08:02:38 raspberrypi systemd[1]: Starting Samba NMB Daemon...
Aug 06 08:02:38 raspberrypi systemd[1]: Started Shairport Sync - AirPlay Audio Receiver.
Aug 06 08:02:38 raspberrypi systemd[1]: Starting OpenBSD Secure Shell server...
Aug 06 08:02:38 raspberrypi systemd[1]: Starting /etc/rc.local Compatibility...
Aug 06 08:02:38 raspberrypi systemd[1]: Starting Permit User Sessions...
Aug 06 08:02:38 raspberrypi systemd[1]: Started /etc/rc.local Compatibility.
Aug 06 08:02:38 raspberrypi systemd[1]: Started Permit User Sessions.
Aug 06 08:02:38 raspberrypi systemd[1]: Starting Hold until boot process finishes up...
...

Needless to say, still no joy.

[mikebrady]

Okay, so it looks like Shairport Sync is actually running.

A couple of questions:

• Are you running a firewall somewhere?
• Do you have two active network ports on your Pi?

There is an iOS app called "Discovery" from TildeSoft (they also do "Bonjour Browser" for a Mac) and avahi-browse in the avahiutils package to allow you to see what is being advertised at the Shairport Sync end and what is being seen as the iOS device end.

If something isn't getting through, the usual culprit is a firewall somewhere or a bad-quality router.

Alternatively it might also be that Shairport Sync is advertising its services on another [i.e. the wrong] network port.

There's a bit more detail on the TROUBLESHOOTING.md page.

[ghost]

Thanks for the tip about the iOS discovery app. With the app, I can see the airplay stream coming off of my Apple TV, but can't find anything coming out of the pi.

I'm running a very good Netgear R7000 router. Just to be sure, I moved the pi into the same room, a few feet from the router. No go.

I'm not currently running a firewall on the PI and have disabled ufw.

I am running the stock shairport-sync config file.

I have turned off power saving/low power modes.

Only one network connection wlan0 and I turned off eth0.

[mikebrady]

Thanks for the update. In the configuration file, at /etc/shairport-sync.conf, there is a setting in the general section called interface. If you uncomment this and give it the name of the interface you want to advertise on (e.g. wlan0) and reboot, then you should be safe using both network ports.

Using avahi-browse on the Pi, you should be able to see that it’s advertising the Shairport Sync AirPlay service, and indeed you should be able to see the AppleTV service as well. If not, then something — maybe some setting — is up with your network. Bonjour relies on multicast — is it possible that the Netgear router is suppressing multicast or something like that?

[Update] Having a quick look on the internet reveals that there seem to be issues with multicast on the Netgear R7000. Not sure of their significance, TBH, but probably worth following up.

[ghost]

I reimaged the pi and got it working.

Thanks for your time and help with this--not to mention the great software.

[mikebrady]

I’m glad it worked out for you.