No audio pa backend

[haydnjonesdesign]

Hi there.

Firstly, thanks for what I'm sure is great software and contribution to the open source world. I've had a look through the issues open and closed to assist in getting a result and failed to find anything helpful. I'm not sure if this is a bug but thought it helpful if there is a reference if someone else has this issue.

Probem

No audio is heard when connected to shairport-sync.

Steps to reproduce

Clone compile and install shairport-sync via github readme.md Run shairport-sync

shairport-sync -vv

Summary

Shairport-sync appears in list of speakers in Spotify and iTunes. Can connect to speaker with no issue. Verbose logging confirms connection. Can play song, again verbose logging shows that the song is received however no sound is heard. Can hear system sounds and audio played through other applications so can confirm there is no issue with the audio card or speaker connection.

Shairport-sync appears in PulseAudio's manager and the volume can be configured so it's definately registering with PA.

Running shairport-sync and PA as 'user' and not 'system' or 'root'.

There is a line in the verbose logging that could reveal the issue

sync error in milliseconds, net correction in ppm, corrections in ppm, total packets, missing packets, late packets, too late packets, resend requests, min DAC queue size, min buffer occupancy, max buffer occupancy

but this covers so many aspects I'm not sure that its not just a generic info message.

System Details

PRETTY_NAME="Debian GNU/Linux 10 (buster)"
NAME="Debian GNU/Linux"
VERSION_ID="10"
VERSION="10 (buster)"
VERSION_CODENAME=buster
ID=debian

PA Details

Server String: /run/user/1001/pulse/native
Library Protocol Version: 32
Server Protocol Version: 32
Is Local: yes
Client Index: 11
Tile Size: 65472
User Name: Nimbus
Host Name: Box
Server Name: pulseaudio
Server Version: 12.2
Default Sample Specification: s16le 2ch 44100Hz
Default Channel Map: front-left,front-right
Default Sink: alsa_output.pci-0000_00_1b.0.analog-stereo
Default Source: alsa_input.pci-0000_00_1b.0.analog-stereo
Cookie: 53d1:026e

Shairport-sync log

shairport-sync -vv
Looking for configuration file at full path "/etc/shairport-sync.conf"
The processor is running little-endian.
Version: "3.2.2-OpenSSL-Avahi-ALSA-pa-dummy-stdout-pipe-soxr-convolution-metadata-sysconfdir:/etc"
statistics_requester status is 1.
daemon status is 0.
daemon pid file path is "/run/shairport-sync/shairport-sync.pid".
rtsp listening port is 5000.
udp base port is 6001.
udp port range is 100.
player name is "Box".
backend is "pa".
on-start action is "(null)".
on-stop action is "(null)".
wait-cmd status is 0.
on-start returns output is 0.
mdns backend "avahi".
userSuppliedLatency is 0.
stuffing option is "0" (0-basic, 1-soxr).
resync time is 0.050000 seconds.
allow a session to be interrupted: 0.
busy timeout time is 120.
drift tolerance is 0.001995 seconds.
password is "(null)".
ignore_volume_control is 0.
volume_max_db is not set
playback_mode is 0 (0-stereo, 1-mono, 1-reverse_stereo, 2-both_left, 3-both_right).
disable_synchronization is 0.
use_mmap_if_available is 1.
output_rate is 44100.
output_format is 3 (0-unknown, 1-S8, 2-U8, 3-S16, 4-S24, 5-S24_3LE, 6-S24_3BE, 7-S32).
audio backend desired buffer length is 0.350000 seconds.
audio backend latency offset is 0.000000 seconds.
audio backend silence lead-in time is -1.000000 seconds. A value -1.0 means use the default.
volume range in dB (zero means use the range specified by the mixer): 0.
zeroconf regtype is "_raop._tcp".
decoders_supported field is 1.
use_apple_decoder is 0.
alsa_use_hardware_mute is 0.
no special mdns service interface was requested.
configuration file name "/etc/shairport-sync.conf" resolves to "/etc/shairport-sync.conf".
metadata enabled is 0.
metadata pipename is "(null)".
metadata socket address is "(null)" port 0.
metadata socket packet size is "500".
get-coverart is 0.
convolution is 0.
convolution IR file is "(null)"
convolution max length 8192
convolution gain is 0.000000
loudness is 0.
loudness reference level is -20.000000
disable resend requests is off.
diagnostic_drop_packet_fraction is 0.000000. A value of 0.0 means no packets will be dropped deliberately.
avahi: service '3B8DF6E6A611@Box' group is not yet committed.
avahi: request to add "_raop._tcp" service without metadata
avahi: service '3B8DF6E6A611@Box' group is registering.
avahi: service '3B8DF6E6A611@Box' successfully added.
New RTSP connection from 192.168.0.111:59421 to self at 192.168.0.102:5000 on conversation thread 1.
New RTSP connection from [fe80::4bb:fd4d:a858:4862]:59420 to self at [fe80::223:24ff:fe66:4689]:5000 on conversation thread 2.
Connection 1: RTSP thread terminated.
RTSP thread 2 received an RTSP Packet of type "ANNOUNCE":
  Type: "Content-Length", content: "674"
  Type: "Content-Type", content: "application/sdp"
  Type: "CSeq", content: "3"
  Type: "DACP-ID", content: "7FD8534A0324E2C0"
  Type: "Active-Remote", content: "904729186"
  Type: "User-Agent", content: "AirPlay/425.1"
Connection 2: ANNOUNCE
Play connection from user agent "AirPlay/425.1" on RTSP conversation thread 2.
AirPlay version 425 detected.
RTSP thread 2: RTSP Response:
  Type: "CSeq", content: "3"
  Type: "Server", content: "AirTunes/105.1"
RTSP thread 2 received an RTSP Packet of type "SETUP":
  Type: "Transport", content: "RTP/AVP/UDP;unicast;mode=record;timing_port=51305;control_port=62524"
  Type: "CSeq", content: "4"
  Type: "DACP-ID", content: "7FD8534A0324E2C0"
  Type: "Active-Remote", content: "904729186"
  Type: "User-Agent", content: "AirPlay/425.1"
Connection 2: SETUP -- Active-Remote string seen: "904729186".
Connection 2: SETUP -- DACP-ID string seen: "7FD8534A0324E2C0".
Connection 2: SETUP -- Connection from fe80::4bb:fd4d:a858:4862 to self at fe80::223:24ff:fe66:4689.
RTSP thread 2: RTSP Response:
  Type: "CSeq", content: "4"
  Type: "Server", content: "AirTunes/105.1"
  Type: "Transport", content: "RTP/AVP/UDP;unicast;interleaved=0-1;mode=record;control_port=6001;timing_port=6002;server_port=6003"
  Type: "Session", content: "1"
RTSP thread 2 received an RTSP Packet of type "RECORD":
  Type: "CSeq", content: "5"
  Type: "DACP-ID", content: "7FD8534A0324E2C0"
  Type: "Active-Remote", content: "904729186"
  Type: "User-Agent", content: "AirPlay/425.1"
Connection 2: RECORD
pbeg
RTSP thread 2: RTSP Response:
  Type: "CSeq", content: "5"
  Type: "Server", content: "AirTunes/105.1"
  Type: "Audio-Latency", content: "11025"
RTSP thread 2 received an RTSP Packet of type "SET_PARAMETER":
  Type: "Content-Length", content: "18"
  Type: "Content-Type", content: "text/parameters"
  Type: "CSeq", content: "6"
  Type: "DACP-ID", content: "7FD8534A0324E2C0"
  Type: "Active-Remote", content: "904729186"
  Type: "User-Agent", content: "AirPlay/425.1"
RTSP thread 2: RTSP Response:
  Type: "CSeq", content: "6"
  Type: "Server", content: "AirTunes/105.1"
RTSP thread 2 received an RTSP Packet of type "SET_PARAMETER":
  Type: "Content-Length", content: "18"
  Type: "Content-Type", content: "text/parameters"
  Type: "CSeq", content: "7"
  Type: "DACP-ID", content: "7FD8534A0324E2C0"
  Type: "Active-Remote", content: "904729186"
  Type: "User-Agent", content: "AirPlay/425.1"
RTSP thread 2: RTSP Response:
  Type: "CSeq", content: "7"
  Type: "Server", content: "AirTunes/105.1"
RTSP thread 2 received an RTSP Packet of type "FLUSH":
  Type: "RTP-Info", content: "seq=14629;rtptime=3643152220"
  Type: "CSeq", content: "8"
  Type: "DACP-ID", content: "7FD8534A0324E2C0"
  Type: "Active-Remote", content: "904729186"
  Type: "User-Agent", content: "AirPlay/425.1"
RTSP thread 2: RTSP Response:
  Type: "CSeq", content: "8"
  Type: "Server", content: "AirTunes/105.1"
sync error in milliseconds, net correction in ppm, corrections in ppm, total packets, missing packets, late packets, too late packets, resend requests, min DAC queue size, min buffer occupancy, max buffer occupancy
RTSP thread 2 received an RTSP Packet of type "FLUSH":
  Type: "RTP-Info", content: "seq=17744;rtptime=3644250311"
  Type: "CSeq", content: "21"
  Type: "DACP-ID", content: "7FD8534A0324E2C0"
  Type: "Active-Remote", content: "904729186"
  Type: "User-Agent", content: "AirPlay/425.1"
RTSP thread 2: RTSP Response:
  Type: "CSeq", content: "21"
  Type: "Server", content: "AirTunes/105.1"
RTSP thread 2 received an RTSP Packet of type "FLUSH":
  Type: "RTP-Info", content: "seq=17744;rtptime=3644251634"
  Type: "CSeq", content: "22"
  Type: "DACP-ID", content: "7FD8534A0324E2C0"
  Type: "Active-Remote", content: "904729186"
  Type: "User-Agent", content: "AirPlay/425.1"
RTSP thread 2: RTSP Response:
  Type: "CSeq", content: "22"
  Type: "Server", content: "AirTunes/105.1"
RTSP thread 2 received an RTSP Packet of type "TEARDOWN":
  Type: "CSeq", content: "26"
  Type: "DACP-ID", content: "7FD8534A0324E2C0"
  Type: "Active-Remote", content: "904729186"
  Type: "User-Agent", content: "AirPlay/425.1"
Connection 2: TEARDOWN
Playback Stopped. Total playing time 00:00:31.
Cancelling timing, control and audio threads...
Cancel timing thread.
Join timing thread.
shutdown timing socket.
close timing socket.
Timing thread terminated.
Cancel control thread.
Join control thread.
shutdown control socket.
close control socket.
Control thread terminated.
Cancel audio thread.
Join audio thread.
shutdown audio socket.
close audio socket.
Audio thread terminated.
Freeing audio buffers and decoders.
Connection 2: player thread terminated.
pend
RTSP thread 2: RTSP Response:
  Type: "CSeq", content: "26"
  Type: "Server", content: "AirTunes/105.1"
  Type: "Connection", content: "close"
Connection 2: RTSP thread terminated

Shairport-sync conf

// Sample Configuration File for Shairport Sync
// Commented out settings are generally the defaults, except where noted.

// General Settings
general =
{
//  name = "%H"; // This means "Hostname" -- see below. This is the name the service will advertise to iTunes.
//      The default is "Hostname" -- i.e. the machine's hostname with the first letter capitalised (ASCII only.)
//      You can use the following substitutions:
//              %h for the hostname,
//              %H for the Hostname (i.e. with first letter capitalised (ASCII only)),
//              %v for the version number, e.g. 3.0 and
//              %V for the full version string, e.g. 3.0-OpenSSL-Avahi-ALSA-soxr-metadata-sysconfdir:/etc
//      Overall length can not exceed 50 characters. Example: "Shairport Sync %v on %H".
//  password = "secret"; // leave this commented out if you don't want to require a password
//  interpolation = "basic"; // aka "stuffing". Default is "basic", alternative is "soxr". Use "soxr" only if you have a reasonably fast processor.
    output_backend = "pa"; // Run "shairport-sync -h" to get a list of all output_backends, e.g. "alsa", "pipe", "stdout". The default is the first one.
    mdns_backend = "avahi"; // Run "shairport-sync -h" to get a list of all mdns_backends. The default is the first one.
//  port = 5000; // Listen for service requests on this port
//  udp_port_base = 6001; // start allocating UDP ports from this port number when needed
//  udp_port_range = 100; // look for free ports in this number of places, starting at the UDP port base. Allow at least 10, though only three are needed in a steady state.
//  drift_tolerance_in_seconds = 0.002; // allow a timing error of this number of seconds of drift away from exact synchronisation before attempting to correct it
//  resync_threshold_in_seconds = 0.050; // a synchronisation error greater than this number of seconds will cause resynchronisation; 0 disables it
//  ignore_volume_control = "no"; // set this to "yes" if you want the volume to be at 100% no matter what the source's volume control is set to.
//  volume_range_db = 60 ; // use this advanced setting to set the range, in dB, you want between the maximum volume and the minimum volume. Range is 30 to 150 dB. Leave it commented out to use mixer's native range.
//  volume_max_db = 0.0 ; // use this advanced setting, which must have a decimal point in it, to set the maximum volume, in dB, you wish to use.
//      The setting is for the hardware mixer, if chosen, or the software mixer otherwise. The value must be in the mixer's range (0.0 to -96.2 for the software mixer).
//      Leave it commented out to use mixer's maximum volume.
//  volume_control_profile = "standard" ; // use this advanced setting to specify how the airplay volume is transferred to the mixer volume.
//      "standard" makes the volume change more quickly at lower volumes and slower at higher volumes.
//      "flat" makes the volume change at the same rate at all volumes.
//  run_this_when_volume_is_set = "/full/path/to/application/and/args"; //  Run the specified application whenever the volume control is set or changed.
//      The desired AirPlay volume is appended to the end of the command line – leave a space if you want it treated as an extra argument.
//      AirPlay volume goes from 0 to -30 and -144 means "mute".

//  regtype = "_raop._tcp"; // Use this advanced setting to set the service type and transport to be advertised by Zeroconf/Bonjour. Default is "_raop._tcp".
//  playback_mode = "stereo"; // This can be "stereo", "mono", "reverse stereo", "both left" or "both right". Default is "stereo".
//  alac_decoder = "hammerton"; // This can be "hammerton" or "apple". This advanced setting allows you to choose
//      the original Shairport decoder by David Hammerton or the Apple Lossless Audio Codec (ALAC) decoder written by Apple.
//  interface = "name"; // Use this advanced setting to specify the interface on which Shairport Sync should provide its service. Leave it commented out to get the default, which is to select the interface(s) automatically.

//  audio_backend_latency_offset_in_seconds = 0.0; // Set this offset to compensate for a fixed delay in the audio back end. E.g. if the output device delays by 100 ms, set this to -0.1.
//  audio_backend_buffer_desired_length_in_seconds = 0.15; // If set too small, buffer underflow occurs on low-powered machines. Too long and the response time to volume changes becomes annoying. Default is 0.15 seconds in the alsa backend, 0.35 seconds in the pa backend and 1.0 seconds otherwise.
//  audio_backend_silent_lead_in_time = 2.0; // This optional advanced setting, from 0.0 and 4.0 seconds, sets the length of the period of silence that precedes the start of the audio. The default is the latency, usually 2.0 seconds. Values greater than the latency are ignored. Values that are too low will affect initial synchronisation.
//  dbus_service_bus = "system"; // The Shairport Sync dbus interface, if selected at compilation, will appear
//      as "org.gnome.ShairportSync" on the whichever bus you specify here: "system" (default) or "session".
//  mpris_service_bus = "system"; // The Shairport Sync mpris interface, if selected at compilation, will appear
//      as "org.gnome.ShairportSync" on the whichever bus you specify here: "system" (default) or "session".
};

// Advanced parameters for controlling how Shairport Sync runs a play session
sessioncontrol =
{
//  run_this_before_play_begins = "/full/path/to/application and args"; // make sure the application has executable permission. If it's a script, include the shebang (#!/bin/...) on the first line
//  run_this_after_play_ends = "/full/path/to/application and args"; // make sure the application has executable permission. If it's a script, include the shebang (#!/bin/...) on the first line
//  wait_for_completion = "no"; // set to "yes" to get Shairport Sync to wait until the "run_this..." applications have terminated before continuing
//  allow_session_interruption = "no"; // set to "yes" to allow another device to interrupt Shairport Sync while it's playing from an existing audio source
//  session_timeout = 120; // wait for this number of seconds after a source disappears before terminating the session and becoming available again.
};

// Back End Settings

// These are parameters for the "alsa" audio back end.
alsa =
{
//  output_device = "default"; // the name of the alsa output device. Use "alsamixer" or "aplay" to find out the names of devices, mixers, etc.
//  mixer_control_name = "PCM"; // the name of the mixer to use to adjust output volume. If not specified, volume in adjusted in software.
//  mixer_device = "default"; // the mixer_device default is whatever the output_device is. Normally you wouldn't have to use this.
//  output_rate = 44100; // can be 44100, 88200, 176400 or 352800, but the device must have the capability.
//  output_format = "S16"; // can be "U8", "S8", "S16", "S24", "S24_3LE", "S24_3BE" or "S32", but the device must have the capability. Except where stated using (*LE or *BE), endianness matches that of the processor.
//  disable_synchronization = "no"; // Set to "yes" to disable synchronization. Default is "no".
//  period_size = <number>; // Use this optional advanced setting to set the alsa period size near to this value
//  buffer_size = <number>; // Use this optional advanced setting to set the alsa buffer size near to this value
//  use_mmap_if_available = "yes"; // Use this optional advanced setting to control whether MMAP-based output is used to communicate  with the DAC. Default is "yes"
//  use_hardware_mute_if_available = "no"; // Use this optional advanced setting to control whether the hardware in the DAC is used for muting. Default is "no", for compatibility with other audio players.
};

// Parameters for the "sndio" audio back end. All are optional.
sndio =
{
//  device = "snd/0"; // optional setting to set the name of the output device. Default is the sndio system default.
//  rate = 44100; // optional setting  which can be 44100, 88200, 176400 or 352800, but the device must have the capability. Default is 44100.
//  format = "S16"; // optional setting  which can be "U8", "S8", "S16", "S24", "S24_3LE", "S24_3BE" or "S32", but the device must have the capability. Except where stated using (*LE or *BE), endianness matches that of the processor.
//  round = <number>; // advanced optional setting to set the period size near to this value
//  bufsz = <number>; // advanced optional setting to set the buffer size near to this value
};

// Parameters for the "pa" PulseAudio  backend.
pa =
{
//  application_name = "Shairport Sync"; //Set this to the name that should appear in the Sounds "Applications" tab when Shairport Sync is active.
};

// Parameters for the "pipe" audio back end, a back end that directs raw CD-style audio output to a pipe. No interpolation is done.
pipe =
{
//  name = "/path/to/pipe"; // there is no default pipe name for the output
};

// These are no configuration file parameters for the "stdout" audio back end. No interpolation is done.

// These are no configuration file  parameters for the "ao" audio back end. No interpolation is done.

// Static latency settings are deprecated and the settings have been removed.

dsp =
{

//////////////////////////////////////////
// This convolution filter can be used to apply almost any correction to the audio signal, like frequency and phase correction.
// For example you could measure (with a good microphone and a sweep-sine) the frequency response of your speakers + room,
// and apply a correction to get a flat response curve.
//////////////////////////////////////////
//
//  convolution = "yes";                  // Activate the convolution filter.
//  convolution_ir_file = "impulse.wav";  // Impulse Response file to be convolved to the audio stream
//  convolution_gain = -4.0;              // Static gain applied to prevent clipping during the convolution process
//  convolution_max_length = 44100;       // Truncate the input file to this length in order to save CPU.

//////////////////////////////////////////
// This loudness filter is used to compensate for human ear non linearity.
// When the volume decreases, our ears loose more sentisitivity in the low range frequencies than in the mid range ones.
// This filter aims at compensating for this loss, applying a variable gain to low frequencies depending on the volume.
// More info can be found here: https://en.wikipedia.org/wiki/Equal-loudness_contour
// For this filter to work properly, you should disable (or set to a fix value) all other volume control and only let shairport-sync control your volume.
// The setting "loudness_reference_volume_db" should be set at the volume reported by shairport-sync when listening to music at a normal listening volume.
//////////////////////////////////////////
//
//  loudness = "yes";                     // Activate the filter
//  loudness_reference_volume_db = -20.0; // Above this level the filter will have no effect anymore. Below this level it will gradually boost the low frequencies.

};

// How to deal with metadata, including artwork
metadata =
{
//  enabled = "no"; // set this to yes to get Shairport Sync to solicit metadata from the source and to pass it on via a pipe
//  include_cover_art = "no"; // set to "yes" to get Shairport Sync to solicit cover art from the source and pass it via the pipe. You must also set "enabled" to "yes".
//  pipe_name = "/tmp/shairport-sync-metadata";
//  pipe_timeout = 5000; // wait for this number of milliseconds for a blocked pipe to unblock before giving up
//  socket_address = "226.0.0.1"; // if set to a host name or IP address, UDP packets containing metadata will be sent to this address. May be a multicast address. "socket-port" must be non-zero and "enabled" must be set to yes"
//  socket_port = 5555; // if socket_address is set, the port to send UDP packets to
//  socket_msglength = 65000; // the maximum packet size for any UDP metadata. This will be clipped to be between 500 or 65000. The default is 500.
};

// Diagnostic settings. These are for diagnostic and debugging only. Normally you sould leave them commented out
diagnostics =
{
//  disable_resend_requests = "no"; // set this to yes to stop Shairport Sync from requesting the retransmission of missing packets. Default is "no".
    statistics = "yes"; // set to "yes" to print statistics in the log
    log_verbosity = 2; // "0" means no debug verbosity, "3" is most verbose.
//  log_show_time_since_startup = "no"; // set this to yes if you want the time since startup in the debug message -- seconds down to nanoseconds
//  log_show_time_since_last_message = "no"; // set this to yes if you want the time since the last debug message in the debug message -- seconds down to nanoseconds
//  drop_this_fraction_of_audio_packets = 0.0; // use this to simulate a noisy network where this fraction of UDP packets are lost in transmission. E.g. a value of 0.001 would mean an average of 0.1% of packets are lost, which is actually quite a high figure.
};

[mikebrady]

Thanks for the post. The line:

sync error in milliseconds, net correction in ppm, corrections in ppm, total packets, missing packets, late packets, too late packets, resend requests, min DAC queue size, min buffer occupancy, max buffer occupancy

is meant to be the title row for rows of statistics that are generated approximately every eight seconds while audio is playing (you have enabled the output of statistics in the diagnostics section of the configuration file). The fact that there are no such lines of statistics after about 30 seconds makes me think that somehow the audio wasn't being received. But that is a very tentative guess!

I suggest that:

1. You update the the latest version of Shairport Sync, which is 3.3.7rc3. This has many improvements and bug fixes.
2. If it was possible, could you try running Shairport Sync with an identical configuration, but outputting to the ALSA backend rarther than the PA back end. In that way, you could establish if the problem is with transmission and reception or whether it might be a problem with the PulseAudio back end.

[haydnjonesdesign]

Thanks for the reply Mike.

I've updated to the latest version as suggest and tested ALSA as the backend. No luck. I had two options for output_devices listed as options via the -h flag. I checked these in alsamixer. The first option hw:HDMI and or hw:0 resulted in

0.016320207 "audio_alsa.c:437" *warning: the alsa output_device "hw:0" can not be found.

The second option hw:1 or hw:PCH reported no errors but still no audio.

From your response this sounds like an issue with the transmission/reception. Could it be related to Avahi?

Version

3.3.7rc3-OpenSSL-Avahi-ALSA-pa-soxr-metadata-sysconfdir:/etc

Log

/usr/local/bin/shairport-sync -vu
         0.000458330 "shairport.c:1729" Started!
         0.000050065 "shairport.c:1756" software version: "3.3.7rc3-OpenSSL-Avahi-ALSA-pa-soxr-metadata-sysconfdir:/etc"
         0.000007690 "shairport.c:1762" log verbosity is 1.
         0.000012627 "audio_alsa.c:1015" alsa: alsa_maximum_stall_time of 0.200000 sec.
         0.000025209 "audio_alsa.c:1302" alsa: disable_standby_mode is "never".
         0.000009436 "audio_alsa.c:1304" alsa: disable_standby_mode_silence_threshold is 0.040000 seconds.
         0.000009698 "audio_alsa.c:1306" alsa: disable_standby_mode_silence_scan_interval is 0.004000 seconds.
         0.000013975 "audio_alsa.c:1345" alsa: output device name is "hw:PCH".
         0.000124305 "shairport.c:1810" disable resend requests is off.
         0.000013138 "shairport.c:1814" diagnostic_drop_packet_fraction is 0.000000. A value of 0.0 means no packets will be dropped deliberately.
         0.000005854 "shairport.c:1815" statistics_requester status is 1.
         0.000004142 "shairport.c:1820" rtsp listening port is 5000.
         0.000003736 "shairport.c:1821" udp base port is 6001.
         0.000004263 "shairport.c:1822" udp port range is 10.
         0.000004003 "shairport.c:1823" player name is "Box".
         0.000003938 "shairport.c:1824" backend is "alsa".
         0.000003811 "shairport.c:1825" run_this_before_play_begins action is "(null)".
         0.000004184 "shairport.c:1826" run_this_after_play_ends action is "(null)".
         0.000003979 "shairport.c:1827" wait-cmd status is 0.
         0.000009665 "shairport.c:1828" run_this_before_play_begins may return output is 0.
         0.000009352 "shairport.c:1829" run_this_if_an_unfixable_error_is_detected action is "(null)".
         0.000006357 "shairport.c:1830" run_this_before_entering_active_state action is  "(null)".
         0.000006212 "shairport.c:1831" run_this_after_exiting_active_state action is  "(null)".
         0.000007115 "shairport.c:1832" active_state_timeout is  10.000000 seconds.
         0.000010648 "shairport.c:1833" mdns backend "avahi".
         0.000008418 "shairport.c:1837" interpolation setting is "auto".
         0.000007830 "shairport.c:1838" interpolation soxr_delay_threshold is 30.
         0.000008292 "shairport.c:1839" resync time is 0.050000 seconds.
         0.000009219 "shairport.c:1840" allow a session to be interrupted: 0.
         0.000007903 "shairport.c:1841" busy timeout time is 120.
         0.000008377 "shairport.c:1842" drift tolerance is 0.001995 seconds.
         0.000009827 "shairport.c:1843" password is "(null)".
         0.000009516 "shairport.c:1844" ignore_volume_control is 0.
         0.000005835 "shairport.c:1848" volume_max_db is not set
         0.000005849 "shairport.c:1850" volume range in dB (zero means use the range specified by the mixer): 0.
         0.000009006 "shairport.c:1854" volume_range_combined_hardware_priority (1 means hardware mixer attenuation is used first) is 0.
         0.000009181 "shairport.c:1856" playback_mode is 0 (0-stereo, 1-mono, 1-reverse_stereo, 2-both_left, 3-both_right).
         0.000008705 "shairport.c:1857" disable_synchronization is 0.
         0.000008302 "shairport.c:1858" use_mmap_if_available is 1.
         0.000008460 "shairport.c:1860" output_format automatic selection is enabled.
         0.000006334 "shairport.c:1864" output_rate automatic selection is enabled.
         0.000008352 "shairport.c:1868" audio backend desired buffer length is 0.200000 seconds.
         0.000009176 "shairport.c:1870" audio_backend_buffer_interpolation_threshold_in_seconds is 0.120000 seconds.
         0.000009120 "shairport.c:1871" audio backend latency offset is 0.000000 seconds.
         0.000009122 "shairport.c:1873" audio backend silence lead-in time is "auto".
         0.000008387 "shairport.c:1877" zeroconf regtype is "_raop._tcp".
         0.000006549 "shairport.c:1878" decoders_supported field is 1.
         0.000008233 "shairport.c:1879" use_apple_decoder is 0.
         0.000008151 "shairport.c:1880" alsa_use_hardware_mute is 0.
         0.000007879 "shairport.c:1884" no special mdns service interface was requested.
         0.000018922 "shairport.c:1888" configuration file name "/etc/shairport-sync.conf" resolves to "/etc/shairport-sync.conf".
         0.000011150 "shairport.c:1894" metadata enabled is 1.
         0.000006635 "shairport.c:1895" metadata pipename is "/tmp/shairport-sync-metadata".
         0.000007919 "shairport.c:1897" metadata socket address is "(null)" port 0.
         0.000008547 "shairport.c:1898" metadata socket packet size is "500".
         0.000008073 "shairport.c:1899" get-coverart is 1.
         0.000008112 "shairport.c:1917" loudness is 0.
         0.000008340 "shairport.c:1918" loudness reference level is -20.000000
         0.000099687 "rtsp.c:1665" metadata pipe name is "/tmp/shairport-sync-metadata".
         0.003931747 "mdns_avahi.c:375" avahi_dacp_monitor_start Avahi DACP monitor successfully started
         1.496353413 "shairport.c:201" "soxr" interpolation has been chosen.
       327.474271766 "rtsp.c:1062" Connection 1: SETUP DACP-ID "1C9B63E78F38BC51" from fe80::4bb:fd4d:a858:4862 to fe80::223:24ff:fe66:4689 with UDP ports Control: 6001, Timing: 6002 and Audio: 6003.
         0.246366806 "audio_alsa.c:529" alsa: output format chosen is "S32".
         0.000047903 "audio_alsa.c:569" alsa: output speed chosen is 44100.
         0.025085473 "player.c:1953" sync error in milliseconds, net correction in ppm, corrections in ppm, total packets, missing packets, late packets, too late packets, resend requests, min DAC queue size, min buffer occupancy, max buffer occupancy, source nominal frames per second, source actual frames per second, output frames per second, source clock drift in ppm, source clock drift sample count, rough calculated correction in ppm
       117.359508446 "rtsp.c:338" Connection 1: As Yeats almost said, "Too long a silence / can make a stone of the heart".
         0.000195054 "player.c:1648" Playback Stopped. Total playing time 00:01:57. Input: 0.00 frames per second.

Conf

// Sample Configuration File for Shairport Sync
// Commented out settings are generally the defaults, except where noted.

// General Settings
general =
{
//  name = "%H"; // This means "Hostname" -- see below. This is the name the service will advertise to iTunes.
//      The default is "Hostname" -- i.e. the machine's hostname with the first letter capitalised (ASCII only.)
//      You can use the following substitutions:
//              %h for the hostname,
//              %H for the Hostname (i.e. with first letter capitalised (ASCII only)),
//              %v for the version number, e.g. 3.0 and
//              %V for the full version string, e.g. 3.0-OpenSSL-Avahi-ALSA-soxr-metadata-sysconfdir:/etc
//      Overall length can not exceed 50 characters. Example: "Shairport Sync %v on %H".
//  password = "secret"; // leave this commented out if you don't want to require a password
//  interpolation = "basic"; // aka "stuffing". Default is "basic", alternative is "soxr". Use "soxr" only if you have a reasonably fast processor.
    output_backend = "alsa"; // Run "shairport-sync -h" to get a list of all output_backends, e.g. "alsa", "pipe", "stdout". The default is the first one.
    mdns_backend = "avahi"; // Run "shairport-sync -h" to get a list of all mdns_backends. The default is the first one.
//  port = 5000; // Listen for service requests on this port
//  udp_port_base = 6001; // start allocating UDP ports from this port number when needed
//  udp_port_range = 100; // look for free ports in this number of places, starting at the UDP port base. Allow at least 10, though only three are needed in a steady state.
//  drift_tolerance_in_seconds = 0.002; // allow a timing error of this number of seconds of drift away from exact synchronisation before attempting to correct it
//  resync_threshold_in_seconds = 0.050; // a synchronisation error greater than this number of seconds will cause resynchronisation; 0 disables it
//  ignore_volume_control = "no"; // set this to "yes" if you want the volume to be at 100% no matter what the source's volume control is set to.
//  volume_range_db = 60 ; // use this advanced setting to set the range, in dB, you want between the maximum volume and the minimum volume. Range is 30 to 150 dB. Leave it commented out to use mixer's native range.
//  volume_max_db = 0.0 ; // use this advanced setting, which must have a decimal point in it, to set the maximum volume, in dB, you wish to use.
//      The setting is for the hardware mixer, if chosen, or the software mixer otherwise. The value must be in the mixer's range (0.0 to -96.2 for the software mixer).
//      Leave it commented out to use mixer's maximum volume.
//  volume_control_profile = "standard" ; // use this advanced setting to specify how the airplay volume is transferred to the mixer volume.
//      "standard" makes the volume change more quickly at lower volumes and slower at higher volumes.
//      "flat" makes the volume change at the same rate at all volumes.
//  run_this_when_volume_is_set = "/full/path/to/application/and/args"; //  Run the specified application whenever the volume control is set or changed.
//      The desired AirPlay volume is appended to the end of the command line – leave a space if you want it treated as an extra argument.
//      AirPlay volume goes from 0 to -30 and -144 means "mute".

//  regtype = "_raop._tcp"; // Use this advanced setting to set the service type and transport to be advertised by Zeroconf/Bonjour. Default is "_raop._tcp".
//  playback_mode = "stereo"; // This can be "stereo", "mono", "reverse stereo", "both left" or "both right". Default is "stereo".
//  alac_decoder = "hammerton"; // This can be "hammerton" or "apple". This advanced setting allows you to choose
//      the original Shairport decoder by David Hammerton or the Apple Lossless Audio Codec (ALAC) decoder written by Apple.
//  interface = "name"; // Use this advanced setting to specify the interface on which Shairport Sync should provide its service. Leave it commented out to get the default, which is to select the interface(s) automatically.

//  audio_backend_latency_offset_in_seconds = 0.0; // Set this offset to compensate for a fixed delay in the audio back end. E.g. if the output device delays by 100 ms, set this to -0.1.
//  audio_backend_buffer_desired_length_in_seconds = 0.15; // If set too small, buffer underflow occurs on low-powered machines. Too long and the response time to volume changes becomes annoying. Default is 0.15 seconds in the alsa backend, 0.35 seconds in the pa backend and 1.0 seconds otherwise.
//  audio_backend_silent_lead_in_time = 2.0; // This optional advanced setting, from 0.0 and 4.0 seconds, sets the length of the period of silence that precedes the start of the audio. The default is the latency, usually 2.0 seconds. Values greater than the latency are ignored. Values that are too low will affect initial synchronisation.
//  dbus_service_bus = "system"; // The Shairport Sync dbus interface, if selected at compilation, will appear
//      as "org.gnome.ShairportSync" on the whichever bus you specify here: "system" (default) or "session".
//  mpris_service_bus = "system"; // The Shairport Sync mpris interface, if selected at compilation, will appear
//      as "org.gnome.ShairportSync" on the whichever bus you specify here: "system" (default) or "session".
};

// Advanced parameters for controlling how Shairport Sync runs a play session
sessioncontrol =
{
//  run_this_before_play_begins = "/full/path/to/application and args"; // make sure the application has executable permission. If it's a script, include the shebang (#!/bin/...) on the first line
//  run_this_after_play_ends = "/full/path/to/application and args"; // make sure the application has executable permission. If it's a script, include the shebang (#!/bin/...) on the first line
//  wait_for_completion = "no"; // set to "yes" to get Shairport Sync to wait until the "run_this..." applications have terminated before continuing
//  allow_session_interruption = "no"; // set to "yes" to allow another device to interrupt Shairport Sync while it's playing from an existing audio source
//  session_timeout = 120; // wait for this number of seconds after a source disappears before terminating the session and becoming available again.
};

// Back End Settings

// These are parameters for the "alsa" audio back end.
alsa =
{
    output_device = "hw:PCH"; // the name of the alsa output device. Use "alsamixer" or "aplay" to find out the names of devices, mixers, etc.
//  mixer_control_name = "PCM"; // the name of the mixer to use to adjust output volume. If not specified, volume in adjusted in software.
//  mixer_device = "default"; // the mixer_device default is whatever the output_device is. Normally you wouldn't have to use this.
//  output_rate = 44100; // can be 44100, 88200, 176400 or 352800, but the device must have the capability.
//  output_format = "S16"; // can be "U8", "S8", "S16", "S24", "S24_3LE", "S24_3BE" or "S32", but the device must have the capability. Except where stated using (*LE or *BE), endianness matches that of the processor.
//  disable_synchronization = "no"; // Set to "yes" to disable synchronization. Default is "no".
//  period_size = <number>; // Use this optional advanced setting to set the alsa period size near to this value
//  buffer_size = <number>; // Use this optional advanced setting to set the alsa buffer size near to this value
//  use_mmap_if_available = "yes"; // Use this optional advanced setting to control whether MMAP-based output is used to communicate  with the DAC. Default is "yes"
//  use_hardware_mute_if_available = "no"; // Use this optional advanced setting to control whether the hardware in the DAC is used for muting. Default is "no", for compatibility with other audio players.
};

// Parameters for the "sndio" audio back end. All are optional.
sndio =
{
//  device = "snd/0"; // optional setting to set the name of the output device. Default is the sndio system default.
//  rate = 44100; // optional setting  which can be 44100, 88200, 176400 or 352800, but the device must have the capability. Default is 44100.
//  format = "S16"; // optional setting  which can be "U8", "S8", "S16", "S24", "S24_3LE", "S24_3BE" or "S32", but the device must have the capability. Except where stated using (*LE or *BE), endianness matches that of the processor.
//  round = <number>; // advanced optional setting to set the period size near to this value
//  bufsz = <number>; // advanced optional setting to set the buffer size near to this value
};

// Parameters for the "pa" PulseAudio  backend.
pa =
{
//  application_name = "Shairport Sync"; //Set this to the name that should appear in the Sounds "Applications" tab when Shairport Sync is active.
};

// Parameters for the "pipe" audio back end, a back end that directs raw CD-style audio output to a pipe. No interpolation is done.
pipe =
{
//  name = "/path/to/pipe"; // there is no default pipe name for the output
};

// These are no configuration file parameters for the "stdout" audio back end. No interpolation is done.

// These are no configuration file  parameters for the "ao" audio back end. No interpolation is done.

// Static latency settings are deprecated and the settings have been removed.

dsp =
{

//////////////////////////////////////////
// This convolution filter can be used to apply almost any correction to the audio signal, like frequency and phase correction.
// For example you could measure (with a good microphone and a sweep-sine) the frequency response of your speakers + room,
// and apply a correction to get a flat response curve.
//////////////////////////////////////////
//
//  convolution = "yes";                  // Activate the convolution filter.
//  convolution_ir_file = "impulse.wav";  // Impulse Response file to be convolved to the audio stream
//  convolution_gain = -4.0;              // Static gain applied to prevent clipping during the convolution process
//  convolution_max_length = 44100;       // Truncate the input file to this length in order to save CPU.

//////////////////////////////////////////
// This loudness filter is used to compensate for human ear non linearity.
// When the volume decreases, our ears loose more sentisitivity in the low range frequencies than in the mid range ones.
// This filter aims at compensating for this loss, applying a variable gain to low frequencies depending on the volume.
// More info can be found here: https://en.wikipedia.org/wiki/Equal-loudness_contour
// For this filter to work properly, you should disable (or set to a fix value) all other volume control and only let shairport-sync control your volume.
// The setting "loudness_reference_volume_db" should be set at the volume reported by shairport-sync when listening to music at a normal listening volume.
//////////////////////////////////////////
//
//  loudness = "yes";                     // Activate the filter
//  loudness_reference_volume_db = -20.0; // Above this level the filter will have no effect anymore. Below this level it will gradually boost the low frequencies.

};

// How to deal with metadata, including artwork
metadata =
{
//  enabled = "no"; // set this to yes to get Shairport Sync to solicit metadata from the source and to pass it on via a pipe
//  include_cover_art = "no"; // set to "yes" to get Shairport Sync to solicit cover art from the source and pass it via the pipe. You must also set "enabled" to "yes".
//  pipe_name = "/tmp/shairport-sync-metadata";
//  pipe_timeout = 5000; // wait for this number of milliseconds for a blocked pipe to unblock before giving up
//  socket_address = "226.0.0.1"; // if set to a host name or IP address, UDP packets containing metadata will be sent to this address. May be a multicast address. "socket-port" must be non-zero and "enabled" must be set to yes"
//  socket_port = 5555; // if socket_address is set, the port to send UDP packets to
//  socket_msglength = 65000; // the maximum packet size for any UDP metadata. This will be clipped to be between 500 or 65000. The default is 500.
};

// Diagnostic settings. These are for diagnostic and debugging only. Normally you sould leave them commented out
diagnostics =
{
//  disable_resend_requests = "no"; // set this to yes to stop Shairport Sync from requesting the retransmission of missing packets. Default is "no".
    statistics = "yes"; // set to "yes" to print statistics in the log
    log_verbosity = 2; // "0" means no debug verbosity, "3" is most verbose.
//  log_show_time_since_startup = "no"; // set this to yes if you want the time since startup in the debug message -- seconds down to nanoseconds
//  log_show_time_since_last_message = "no"; // set this to yes if you want the time since the last debug message in the debug message -- seconds down to nanoseconds
//  drop_this_fraction_of_audio_packets = 0.0; // use this to simulate a noisy network where this fraction of UDP packets are lost in transmission. E.g. a value of 0.001 would mean an average of 0.1% of packets are lost, which is actually quite a high figure.
};

Options

    avahi

Available audio backends:
    alsa (default)
    pa

Settings and options for the audio backend "alsa":
    -d output-device    set the output device, default is "default".
    -c mixer-control    set the mixer control name, default is to use no mixer.
    -m mixer-device     set the mixer device, default is the output device.
    -i mixer-index      set the mixer index, default is 0.
    hardware output devices:
      "hw:HDMI"
      "hw:PCH"

[mikebrady]

Thanks for the update. It looks increasingly as if the audio isn't getting from the source player (e.g. iTunes/iOS) across the network and into Shairport Sync. Looking at the log, the Shairport Sync service can be seen by the player, it seems, and a play session is started. However it looks as if no audio arrived and Shairport Sync gave up ("117.359508446 "rtsp.c:338" Connection 1: As Yeats almost said...").

So, do you have firewalls in your system somewhere that might be blocking UDP? They could be on the player, the receiver, the router... (Just check some of the ideas in TROUBLESHOOTING.md.)

[RUGMJ]

A suggestion I would give is to make sure your volume is turned up on the source device as shairport sync lowers it dramatically when you connect

[brunophilipe]

I'm having the exact same issue for a few weeks now. I have tested that the speakers work by running speaker-test -c2 -twav -l7. I have also tested connecting from many different devices (two Macs, one iPhone, one iPad) and they all say it's connected but no audio comes out. For the life of me I can't find the log file that shairport-sync is using (on raspbian), but the last few lines printed when I run systemctl status shairport-sync.service are these:

Nov 03 00:47:50 ankaa shairport-sync[387]:          0.000197448|Scan Result: 200, Bad Scan Count: 0, Idle Scan Count: 0.
Nov 03 00:47:50 ankaa shairport-sync[387]:          0.004409072|dacp_send_command: "playstatusupdate?revision-number=11".
Nov 03 00:47:50 ankaa shairport-sync[387]:          0.003535007|dacp_send_command: 0.007803 seconds, response code 403, command "playstatusupdate?revision-number=11".
Nov 03 00:47:51 ankaa shairport-sync[387]:          1.003500692|dacp_send_command: "getproperty?properties=dmcp.volume".
Nov 03 00:47:51 ankaa shairport-sync[387]:          0.005227875|dacp_send_command: 0.008364 seconds, response code 200, command "getproperty?properties=dmcp.volume".
Nov 03 00:47:51 ankaa shairport-sync[387]:          0.004320269|dacp_send_command: "getspeakers".
Nov 03 00:47:51 ankaa shairport-sync[387]:          0.005244126|dacp_send_command: 0.009311 seconds, response code 200, command "getspeakers".
Nov 03 00:47:51 ankaa shairport-sync[387]:          0.000201562|Scan Result: 200, Bad Scan Count: 0, Idle Scan Count: 0.
Nov 03 00:47:51 ankaa shairport-sync[387]:          0.004365166|dacp_send_command: "playstatusupdate?revision-number=11".
Nov 03 00:47:51 ankaa shairport-sync[387]:          0.005055010|dacp_send_command: 0.009270 seconds, response code 403, command "playstatusupdate?revision-number=11".

Edit: I have built from source to enable media logging, but have never ended up using it. I will try re-building without and report back.

[haydnjonesdesign]

Thanks @mikebrady and @RUGMJ7443. I went through the troubleshooting documentation yesterday and found the issue. Athough it the device isn't a RPI, UFW was blocking connections. When installing I had noted that shairport-sync used port 5000 and had opened it but didn't notice to open any others. Perhaps in the troubleshooting document re-title to "UFW Blocking Ports (commonly includes RPI) or something to that matter and in the read me add the ports listed in the troubleshooting as a requirement to be open.

@brunophilipe Try disabliing UFW if you have it

sudo ufw disable

Then connect and test. If it works then follow the guide in Troubleshooting to open required ports.

Thanks again for your assistance and efforts in producing this app.

[brunophilipe]

@haydnjonesdesign Thank you for your help!

I don't have UFW installed. Also, this is an old installation that I have been using for over a year, and it "simply" stopped working some day in the past weeks. After rebuilding from source for version 3.3rc7, I get this printed to the systemctl log while playing:

Nov 03 00:57:56 ankaa shairport-sync[5355]:          0.000390418|input frame rate out of bounds at 44213.17 fps.
Nov 03 00:57:56 ankaa shairport-sync[5355]:          0.005787673|input frame rate out of bounds at 44213.17 fps.
Nov 03 00:57:56 ankaa shairport-sync[5355]:          0.000405886|input frame rate out of bounds at 44213.17 fps.
Nov 03 00:57:56 ankaa shairport-sync[5355]:          0.000853700|input frame rate out of bounds at 44213.17 fps.
Nov 03 00:57:56 ankaa shairport-sync[5355]:          0.000776096|input frame rate out of bounds at 44213.17 fps.
Nov 03 00:57:56 ankaa shairport-sync[5355]:          0.005489287|input frame rate out of bounds at 44213.17 fps.
Nov 03 00:57:56 ankaa shairport-sync[5355]:          0.000357084|input frame rate out of bounds at 44213.17 fps.
Nov 03 00:57:56 ankaa shairport-sync[5355]:          0.000371459|input frame rate out of bounds at 44213.17 fps.
Nov 03 00:57:56 ankaa shairport-sync[5355]:          0.001730943|input frame rate out of bounds at 44213.17 fps.
Nov 03 00:57:56 ankaa shairport-sync[5355]:          0.006327309|input frame rate out of bounds at 44213.17 fps.
Nov 03 00:57:56 ankaa shairport-sync[5355]:          0.000329012|input frame rate out of bounds at 44213.17 fps.
Nov 03 00:57:56 ankaa shairport-sync[5355]:          0.001238701|input frame rate out of bounds at 44213.17 fps.

Edit: My dumb guess is that Apple changed something about the protocol. I guess that would explain why it stopped working out of nowhere?

[mikebrady]

Perhaps in the troubleshooting document re-title to "UFW Blocking Ports (commonly includes RPI) or something to that matter and in the read me add the ports listed in the troubleshooting as a requirement to be open.

Done. Thanks for the suggestion, @haydnjonesdesign.

[mikebrady]

@brunophilipe, the log can be seen using the standard journalctl command. To follow log entries as they are made, I use

$sudo journalctl -f

I suggest you set the log verbosity to 2 and enable statistics, and see what turns up in the log.

Apple doesn't seem to have changed anything related to protocols recently. What else has changed in the environment?

Also, please take a look at the TROUBLESHOOTING.md page -- there might be something in there.

[brunophilipe]

So I've finally had some time to continue troubleshooting this and no luck. One important update, I failed to understand that the "pa backend" on the title of this issue referred to PulseAudio, my Pi uses alsa.

However, as a last resort troubleshooting I installed shairplay from apt-get, and it plays audio just fine. Not sure what I can do at this point to troubleshoot this any further. I have completely cleaned and rebuilt shairport-sync, and even installed the version from apt-get, and none of them work anymore.

As far as logging goes, everything seems to be in order, no issues are logged. This is a sample from my log with verbosity set to 2 while playing audio:

Nov 16 20:41:15 ankaa shairport-sync[7673]:        274.877181225 "rtsp.c:2972" Connection 2: new connection from 192.168.0.93:55562 to self at 192.168.0.144:5000.
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.001118390 "rtsp.c:2653" Connection 2: Received an RTSP Packet of type "ANNOUNCE":
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000167657 "rtsp.c:507"   Type: "CSeq", content: "1"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000089219 "rtsp.c:507"   Type: "Content-Type", content: "application/sdp"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000079220 "rtsp.c:507"   Type: "Content-Length", content: "571"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000069271 "rtsp.c:507"   Type: "User-Agent", content: "Music/1.0.6 (Macintosh; OS X 10.15.7) AppleWebKit/609.4.1"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000076302 "rtsp.c:507"   Type: "Client-Instance", content: "85FD764FB3EA9B6D"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000065729 "rtsp.c:507"   Type: "DACP-ID", content: "85FD764FB3EA9B6D"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000074792 "rtsp.c:507"   Type: "Active-Remote", content: "1379453244"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.051486198 "rtsp.c:2215" Play connection from user agent "Music/1.0.6 (Macintosh; OS X 10.15.7) AppleWebKit/609.4.1" on RTSP conversation thread 2.
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000218647 "rtsp.c:2696" Connection 2: RTSP Response:
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000091042 "rtsp.c:507"   Type: "CSeq", content: "1"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000079219 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.004310434 "rtsp.c:2653" Connection 2: Received an RTSP Packet of type "SETUP":
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000186251 "rtsp.c:507"   Type: "CSeq", content: "2"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000205626 "rtsp.c:507"   Type: "Transport", content: "RTP/AVP/UDP;unicast;interleaved=0-1;mode=record;control_port=6001;timing_port=6002"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000088177 "rtsp.c:507"   Type: "User-Agent", content: "Music/1.0.6 (Macintosh; OS X 10.15.7) AppleWebKit/609.4.1"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000080313 "rtsp.c:507"   Type: "Client-Instance", content: "85FD764FB3EA9B6D"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000073907 "rtsp.c:507"   Type: "DACP-ID", content: "85FD764FB3EA9B6D"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000070937 "rtsp.c:507"   Type: "Active-Remote", content: "1379453244"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000090886 "rtsp.c:976" Connection 2: SETUP -- Active-Remote string seen: "1379453244".
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000088126 "rtsp.c:995" Connection 2: SETUP -- DACP-ID string seen: "85FD764FB3EA9B6D".
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000116302 "rtp.c:968" Connection 2: SETUP -- Connection from 192.168.0.93 to self at 192.168.0.144.
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000331720 "rtsp.c:1062" Connection 2: SETUP DACP-ID "85FD764FB3EA9B6D" from 192.168.0.93 to 192.168.0.144 with UDP ports Control: 6001, Timing: 6002 and Audio: 6003.
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000118021 "rtsp.c:2696" Connection 2: RTSP Response:
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000075574 "rtsp.c:507"   Type: "CSeq", content: "2"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000073333 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000071303 "rtsp.c:507"   Type: "Transport", content: "RTP/AVP/UDP;unicast;interleaved=0-1;mode=record;control_port=6001;timing_port=6002;server_port=6003"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000069740 "rtsp.c:507"   Type: "Session", content: "1"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.001528808 "rtsp.c:2653" Connection 2: Received an RTSP Packet of type "RECORD":
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000166198 "rtsp.c:507"   Type: "CSeq", content: "3"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000091824 "rtsp.c:507"   Type: "Session", content: "1"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000075625 "rtsp.c:507"   Type: "Range", content: "npt=0-"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000071302 "rtsp.c:507"   Type: "RTP-Info", content: "seq=39654;rtptime=2859881488"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000070261 "rtsp.c:507"   Type: "User-Agent", content: "Music/1.0.6 (Macintosh; OS X 10.15.7) AppleWebKit/609.4.1"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000067761 "rtsp.c:507"   Type: "Client-Instance", content: "85FD764FB3EA9B6D"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000070990 "rtsp.c:507"   Type: "DACP-ID", content: "85FD764FB3EA9B6D"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000067812 "rtsp.c:507"   Type: "Active-Remote", content: "1379453244"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000091876 "rtsp.c:855" Connection 2: RECORD
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.005559033 "audio_alsa.c:529" alsa: output format chosen is "S32".
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.001000837 "audio_alsa.c:569" alsa: output speed chosen is 44100.
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.002536365 "audio_alsa.c:1816" alsa: prepare() -- opened output device
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000296303 "audio_alsa.c:1965" alsa: alsa_buffer_monitor_thread_code() -- closing the output device
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000208907 "player.c:3078" do_flush: flush to 2859881488.
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000150105 "rtsp.c:2696" Connection 2: RTSP Response:
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000090573 "rtsp.c:507"   Type: "CSeq", content: "3"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000095521 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000076563 "rtsp.c:507"   Type: "Audio-Latency", content: "11025"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.001439902 "rtsp.c:2653" Connection 2: Received an RTSP Packet of type "SET_PARAMETER":
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000257136 "rtsp.c:507"   Type: "CSeq", content: "4"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000113751 "rtsp.c:507"   Type: "Session", content: "1"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000091250 "rtsp.c:507"   Type: "Content-Type", content: "text/parameters"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000086459 "rtsp.c:507"   Type: "Content-Length", content: "18"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000081198 "rtsp.c:507"   Type: "User-Agent", content: "Music/1.0.6 (Macintosh; OS X 10.15.7) AppleWebKit/609.4.1"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000088073 "rtsp.c:507"   Type: "Client-Instance", content: "85FD764FB3EA9B6D"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000098021 "rtsp.c:507"   Type: "DACP-ID", content: "85FD764FB3EA9B6D"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000088594 "rtsp.c:507"   Type: "Active-Remote", content: "1379453244"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000143178 "rtsp.c:2696" Connection 2: RTSP Response:
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000100001 "rtsp.c:507"   Type: "CSeq", content: "4"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000076823 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.002224071 "audio_alsa.c:1754" alsa: do_close() -- closing alsa handle
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000899431 "audio_alsa.c:1968" alsa: alsa_buffer_monitor_thread_code() -- alsa_backend_state => abm_disconnected
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000539638 "rtsp.c:2653" Connection 2: Received an RTSP Packet of type "SET_PARAMETER":
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000205730 "rtsp.c:507"   Type: "CSeq", content: "5"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000120677 "rtsp.c:507"   Type: "Session", content: "1"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000100105 "rtsp.c:507"   Type: "Content-Type", content: "text/parameters"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000085521 "rtsp.c:507"   Type: "Content-Length", content: "18"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000095209 "rtsp.c:507"   Type: "User-Agent", content: "Music/1.0.6 (Macintosh; OS X 10.15.7) AppleWebKit/609.4.1"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000080833 "rtsp.c:507"   Type: "Client-Instance", content: "85FD764FB3EA9B6D"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000081563 "rtsp.c:507"   Type: "DACP-ID", content: "85FD764FB3EA9B6D"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000074063 "rtsp.c:507"   Type: "Active-Remote", content: "1379453244"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000124636 "rtsp.c:2696" Connection 2: RTSP Response:
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000086354 "rtsp.c:507"   Type: "CSeq", content: "5"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000082917 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.004908041 "player.c:2004" Set initial volume to 0.000000.
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000218074 "player.c:2007" Play begin
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000111771 "player.c:945" flush request: flush output device.
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.003623348 "player.c:247" Hammerton Decoder used on encrypted audio.
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.001224536 "player.c:1005" flush request: flush frame 2859881488 expired -- buffer contains 704 frames, from 2859881488 to 2859882191
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000181928 "player.c:1029" flush request: request dropped.
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000092084 "player.c:1110" first_packet_time set for frame 2859881488.
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.009286392 "audio_alsa.c:1780" alsa: play() -- opened output device
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.000163594 "audio_alsa.c:1785" alsa: play() -- alsa_backend_state => abm_playing
Nov 16 20:41:15 ankaa shairport-sync[7673]:          0.279649412 "player.c:1175" Change in estimated first_packet_time:  -0.6365 milliseconds.
Nov 16 20:41:16 ankaa shairport-sync[7673]:          0.712733092 "player.c:1175" Change in estimated first_packet_time:   0.1022 milliseconds.
Nov 16 20:41:17 ankaa shairport-sync[7673]:          0.787371310 "player.c:1175" Change in estimated first_packet_time:   0.0498 milliseconds.
Nov 16 20:41:17 ankaa shairport-sync[7673]:          0.219062605 "player.c:1175" Change in estimated first_packet_time:   0.0984 milliseconds.
Nov 16 20:41:17 ankaa shairport-sync[7673]:          0.108474189 "player.c:2288" first frame sync error (positive --> late): 1 frames, 0.023 mS at 44100 frames per second output.
Nov 16 20:41:17 ankaa shairport-sync[7673]:          0.000235990 "player.c:2305" final sync adjustment: 7 silent frames added with a bias of 8 frames.
Nov 16 20:41:35 ankaa shairport-sync[7673]:         17.827220502 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     7978.3,      536.1,    10112.3.
Nov 16 20:41:55 ankaa shairport-sync[7673]:         19.964655814 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     7982.5,      615.1,    15385.6.

Please let me know if there's anything else I can try, or any esoteric settings I can set on my config file that might make it print out something interesting.

[github-actions[bot]]

This issue has been inactive for 60 days so will be closed 7 days from now. To prevent this, please remove the "stale" label or post a comment.