Symptom - No audio - Githubissues

moodeaudio commented 7 years ago

Hi Mike,

Received this debug log from a user that is experiencing no audio with his particular USB audio device. Wondering if you could have a look at the log.

-Tim

Symptom: No audio Device: FOSTEX HP-A8

pi@moode:~ $ /usr/local/bin/shairport-sync -vvv -a "Moode Airplay" -S soxr -w -B /var/www/command/spspre.sh -E /var/www/command/spspost.sh -- -d hw:1
Looking for the configuration file "/usr/local/etc/shairport-sync.conf".
Looking for configuration file at full path "/usr/local/etc/shairport-sync.conf"
Value read for output rate is 44100.
Output device name is "hw:1".
The processor is running little-endian.
Version: "3.0.2-OpenSSL-Avahi-ALSA-stdout-soxr-metadata-sysconfdir:/usr/local/etc"
statistics_requester status is 0.
daemon status is 0.
rtsp listening port is 5000.
udp base port is 6001.
udp port range is 100.
Shairport Sync player name is "Moode Airplay".
Audio Output name is "(null)".
on-start action is "/var/www/command/spspre.sh".
on-stop action is "/var/www/command/spspost.sh".
wait-cmd status is 1.
mdns backend "(null)".
userSuppliedLatency is 0.
AirPlayLatency is -1.
iTunesLatency is -1.
forkedDaapdLatency is -1.
stuffing option is "1" (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.150000 seconds.
audio backend latency offset is 0.000000 seconds.
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.
no special mdns service interface was requested.
configuration file name "/usr/local/etc/shairport-sync.conf" resolves to "/usr/local/etc/shairport-sync.conf".
metdata enabled is 0.
metadata pipename is "(null)".
metadata socket address is "(null)" port 0.
metadata socket packet size is "500".
get-coverart is 0.
Successful Startup
avahi: avahi_register.
avahi: register_service.
avahi: service '4EA8E21A3B78@Moode Airplay' group is not yet commited.
avahi: request to add "_raop._tcp" service without metadata
avahi: service '4EA8E21A3B78@Moode Airplay' group is registering.
avahi: service '4EA8E21A3B78@Moode Airplay' successfully added.
New RTSP connection from [fe80::1461:2775:cfa5:3c56]:59070 to self at [fe80::d4da:c089:bc3:f3a]:5000.
New RTSP connection from 192.168.10.3:59071 to self at 192.168.10.5:5000.
    CSeq: 0.
    DACP-ID: 84291406A44CF224.
    Active-Remote: 497723504.
    User-Agent: AirPlay/320.20.
RTSP Packet received of type "OPTIONS":
  Type: "CSeq", content: "0"
  Type: "DACP-ID", content: "84291406A44CF224"
  Type: "Active-Remote", content: "497723504"
  Type: "User-Agent", content: "AirPlay/320.20"
RTSP Response:
  Type: "CSeq", content: "0"
  Type: "Server", content: "AirTunes/105.1"
  Type: "Public", content: "ANNOUNCE, SETUP, RECORD, PAUSE, FLUSH, TEARDOWN, OPTIONS, GET_PARAMETER, SET_PARAMETER"
RTSP connection closed.
Closing down RTSP conversation thread...
RTSP conversation thread terminated.
    CSeq: 1.
    DACP-ID: 84291406A44CF224.
    Active-Remote: 497723504.
    User-Agent: AirPlay/320.20.
RTSP Packet received of type "OPTIONS":
  Type: "CSeq", content: "1"
  Type: "DACP-ID", content: "84291406A44CF224"
  Type: "Active-Remote", content: "497723504"
  Type: "User-Agent", content: "AirPlay/320.20"
RTSP Response:
  Type: "CSeq", content: "1"
  Type: "Server", content: "AirTunes/105.1"
  Type: "Public", content: "ANNOUNCE, SETUP, RECORD, PAUSE, FLUSH, TEARDOWN, OPTIONS, GET_PARAMETER, SET_PARAMETER"
    Apple-Challenge: eRq5MEIgfPBiCzoU26N8qg==.
    CSeq: 2.
    DACP-ID: 84291406A44CF224.
    Active-Remote: 497723504.
    User-Agent: AirPlay/320.20.
RTSP Packet received of type "OPTIONS":
  Type: "Apple-Challenge", content: "eRq5MEIgfPBiCzoU26N8qg=="
  Type: "CSeq", content: "2"
  Type: "DACP-ID", content: "84291406A44CF224"
  Type: "Active-Remote", content: "497723504"
  Type: "User-Agent", content: "AirPlay/320.20"
RTSP Response:
  Type: "Apple-Response", content: "L9gzU8b0ghuX6ItSgcnwqW0rXZXPxm2+5mnlkL632EOfaF6Er/u/zK1R3ohS0yx3Uaz7REJ43aj5j2TCIlb815IwEK8jU4eKAp5IcpjbKF7krm9vIh6HgLiwbKIKDa5ES8bLJx0fw7hZw1X1V41304j37a2AmGrnIunPpysUdrgH/+vOIiC1Skt+yK1EmH2S9oS2F+6VbeW0ymm1Rk36yhLb6PX7PDS8nI+Qqmbn4PhTXc/Q5LnKjDaZnsdZ0ycDNEYzHj+qnCC2EucQe/494LOC+RRgIwS0U/1zdqSklnwf9SeqgVix/XU32rmRrLthzndzw2/Akf8DUVye3dD0eA"
  Type: "CSeq", content: "2"
  Type: "Server", content: "AirTunes/105.1"
  Type: "Public", content: "ANNOUNCE, SETUP, RECORD, PAUSE, FLUSH, TEARDOWN, OPTIONS, GET_PARAMETER, SET_PARAMETER"
    Content-Length: 677.
    Content-Type: application/sdp.
    CSeq: 3.
    DACP-ID: 84291406A44CF224.
    Active-Remote: 497723504.
    User-Agent: AirPlay/320.20.
RTSP Packet received of type "ANNOUNCE":
  Type: "Content-Length", content: "677"
  Type: "Content-Type", content: "application/sdp"
  Type: "CSeq", content: "3"
  Type: "DACP-ID", content: "84291406A44CF224"
  Type: "Active-Remote", content: "497723504"
  Type: "User-Agent", content: "AirPlay/320.20"
Play connection from user agent "AirPlay/320.20".
RTSP Response:
  Type: "CSeq", content: "3"
  Type: "Server", content: "AirTunes/105.1"
    Transport: RTP/AVP/UDP;unicast;mode=record;timing_port=54939;control_port=59861.
    CSeq: 4.
    DACP-ID: 84291406A44CF224.
    Active-Remote: 497723504.
    User-Agent: AirPlay/320.20.
RTSP Packet received of type "SETUP":
  Type: "Transport", content: "RTP/AVP/UDP;unicast;mode=record;timing_port=54939;control_port=59861"
  Type: "CSeq", content: "4"
  Type: "DACP-ID", content: "84291406A44CF224"
  Type: "Active-Remote", content: "497723504"
  Type: "User-Agent", content: "AirPlay/320.20"
Active-Remote string seen: "497723504".
DACP-ID string seen: "84291406A44CF224".
User-Agent is AirPlay; selecting the AirPlay latency of -1 frames.
rtp_setup: cport=59861 tport=54939.
Set up play connection from fe80::1461:2775:cfa5:3c56 to self at fe80::d4da:c089:bc3:f3a.
listening for audio, control and timing on ports 6001, 6002, 6003.
Output sample ratio is 1.
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=6002;timing_port=6003;server_port=6001"
  Type: "Session", content: "1"
Output frame bytes is 4.
Audio receiver -- Server RTP thread starting.
Control receiver -- Server RTP thread starting.
Timing receiver -- Server RTP thread starting.
Timing sender thread starting.
Output bit depth is 16.
    CSeq: 5.
    DACP-ID: 84291406A44CF224.
    Active-Remote: 497723504.
    User-Agent: AirPlay/320.20.
RTSP Packet received of type "RECORD":
  Type: "CSeq", content: "5"
  Type: "DACP-ID", content: "84291406A44CF224"
  Type: "Active-Remote", content: "497723504"
  Type: "User-Agent", content: "AirPlay/320.20"
RTSP Response:
  Type: "CSeq", content: "5"
  Type: "Server", content: "AirTunes/105.1"
  Type: "Audio-Latency", content: "11025"
    Content-Length: 18.
    Content-Type: text/parameters.
    CSeq: 6.
    DACP-ID: 84291406A44CF224.
    Active-Remote: 497723504.
    User-Agent: AirPlay/320.20.
RTSP Packet received of type "SET_PARAMETER":
  Type: "Content-Length", content: "18"
  Type: "Content-Type", content: "text/parameters"
  Type: "CSeq", content: "6"
  Type: "DACP-ID", content: "84291406A44CF224"
  Type: "Active-Remote", content: "497723504"
  Type: "User-Agent", content: "AirPlay/320.20"
volume: 0.000000

RTSP Response:
  Type: "CSeq", content: "6"
  Type: "Server", content: "AirTunes/105.1"
    RTP-Info: seq=28377;rtptime=2242940215.
    CSeq: 7.
    DACP-ID: 84291406A44CF224.
    Active-Remote: 497723504.
    User-Agent: AirPlay/320.20.
RTSP Packet received of type "FLUSH":
  Type: "RTP-Info", content: "seq=28377;rtptime=2242940215"
  Type: "CSeq", content: "7"
  Type: "DACP-ID", content: "84291406A44CF224"
  Type: "Active-Remote", content: "497723504"
  Type: "User-Agent", content: "AirPlay/320.20"
Flush requested up to 2242940215. It seems as if 0 is special.
RTSP Response:
  Type: "CSeq", content: "7"
  Type: "Server", content: "AirTunes/105.1"
    RTP-Info: seq=28377;rtptime=2242943118.
    CSeq: 8.
    DACP-ID: 84291406A44CF224.
    Active-Remote: 497723504.
    User-Agent: AirPlay/320.20.
RTSP Packet received of type "FLUSH":
  Type: "RTP-Info", content: "seq=28377;rtptime=2242943118"
  Type: "CSeq", content: "8"
  Type: "DACP-ID", content: "84291406A44CF224"
  Type: "Active-Remote", content: "497723504"
  Type: "User-Agent", content: "AirPlay/320.20"
Flush requested up to 2242943118. It seems as if 0 is special.
RTSP Response:
  Type: "CSeq", content: "8"
  Type: "Server", content: "AirTunes/105.1"
syncing to seqno 28377.
Hammerton Decoder used on encrypted audio.
Output sample ratio is 1
Output written using MMAP
audio_alsa: Sample format 2 not available for device "hw:1": Invalid argument
avahi: avahi_unregister.
Request to shut down all rtsp conversation threads
asking playing threads to stop
RTSP shutdown requested.
Closing down RTSP conversation thread...
one thread joined...
New RTSP connection from [fe80::1461:2775:cfa5:3c56]:59124 to self at [fe80::d4da:c089:bc3:f3a]:5000.
RTSP connection closed.
Closing down RTSP conversation thread...
RTSP conversation thread terminated.

mikebrady commented 7 years ago

Hi Tim. It looks like the device can't do 16-bit, so your user should select 32 bit in the configuration file. In the alsa stanza:

output_format = "S32";

The user should ensure s/he uncomments the line as well.

There's a reporting bug in 3.0.2 which correctly reports that the sample format isn't available, but it gives the wrong format number in the report. It's fixed in the development branch. Anyhow, that just causes confusion – it doesn't affect the operation.

moodeaudio commented 7 years ago

Hi Mike, user tried 32-bit but same result "no sound". Another symptom he reports is that his Fostex DAC does not show incoming sample rate change to 44.1k on its LCD if for example he was previously playing a 96K file.

I'll close issue and investigate further with user.

mikebrady / shairport-sync

Symptom - No audio #518