mikebrady / shairport-sync

AirPlay and AirPlay 2 audio player
Other
7.3k stars 574 forks source link

No audio on RPi 4 #1312

Closed outsharded closed 3 years ago

outsharded commented 3 years ago

I have been using Shairport on RPi for some time but since the Raspberry Pi OS Update it has shown on phone that audio is playing, but can hear nothing out of speakers. Don't know whether the AV Jack is issue but the speakers, cable and setup are working fine. Is there a way to fix this

P.S. Simple as possible please - I don't know that much

bloomkd46 commented 3 years ago

I am have had the same problem ever since I updated my iPhone to the most recent beta

Logs:

Loaded: loaded (/lib/systemd/system/shairport-sync.service; enabled; vendor preset: enabled)
   Active: active (running) since Sun 2021-10-03 07:43:20 PDT; 6 days ago
 Main PID: 1546 (shairport-sync)
    Tasks: 15 (limit: 3720)
   CGroup: /system.slice/shairport-sync.service
           └─1546 /usr/local/bin/shairport-sync

Oct 09 16:10:35 RPI4 shairport-sync[1546]:          0.042971334 "rtsp.c:1012" Remote Control Stream stream (second) message
Oct 09 16:10:35 RPI4 shairport-sync[1546]:          0.000103184 "rtsp.c:1017"   Content Plist (as XML):
                                                   --
                                                   <?xml version="1.0" encoding="UTF-8"?>
                                                   <!DOCTYPE plist PUBLIC "-//Apple//DTD PLIST 1.0//EN" "http://www.apple.com/DTDs/PropertyList-1.0.dtd">
                                                   <plist version="1.0">
                                                   <dict>
                                                           <key>streams</key>
                                                           <array>
                                                                   <dict>
                                                                           <key>clientUUID</key>
                                                                           <string>30CCAF11-BBA9-4D60-B368-A060C045D0C6</string>
                                                                           <key>clientTypeUUID</key>
                                                                           <string>1910A70F-DBC0-4242-AF95-115DB30604E1</string>
                                                                           <key>channelID</key>
                                                                           <string>1E7E7DB7-E879-43F0-8E17-029F12464EC4</string>
                                                                           <key>controlType</key>
                                                                           <integer>1</integer>
                                                                           <key>type</key>
                                                                           <integer>130</integer>
                                                                   </dict>
                                                           </array>
                                                   </dict>
                                                   </plist>
                                                   --
Oct 09 16:10:36 Koltons-RPI4 shairport-sync[1546]:          1.370234116 "rtsp.c:5005" Connection 75: new connection from fdf0:2c1e:5f2:1:1489:3369:e1cd:e656:55712 to self at fdf0:2c1e:5f2:1:e6d1:64d0:538e:e5df:7000.
Oct 09 16:10:36 RPI4 shairport-sync[1546]:          0.313261816 "rtsp.c:662" Connection 32: cancelled.
Oct 09 16:10:36 RPI4 shairport-sync[1546]:          0.001645787 "rtsp.c:670" Connection 32: joined.
Oct 09 16:10:38 RPI4 shairport-sync[1546]:          1.701417838 "rtsp.c:2866" SETUP on Connection 75. Buffered Audio Stream Detected.
Oct 09 16:10:38 RPI4 shairport-sync[1546]:          0.058149297 "audio_alsa.c:529" alsa: output format chosen is "S16".
Oct 09 16:10:38 RPI4 shairport-sync[1546]:          0.000691496 "audio_alsa.c:569" alsa: output speed chosen is 44100.
Oct 09 16:10:38 RPI4 shairport-sync[1546]:          0.300620188 "rtsp.c:4665" Connection 75: Unrecognised and unhandled rtsp request "SETRATE".
Oct 09 16:10:38 RPI4 shairport-sync[1546]:          0.000112018 "rtsp.c:4681" Content: "62706C6973743030D2010203045772747054696D65547261746512BC68F89C1001080D151A1F0000000000000101000000000000000500000000000000000000000000000021".

P.S.

it still works when airplaying from HomePod

EDIT:

I have this problem on both my raspberry pi 3b and 4

mikebrady commented 3 years ago

Thanks for the posts.

@bloomkd46 your issue seems (1) to be related to the beta of iOS, and (2) you are using the developer version of Shairport Sync -- see a similar report at #1308. @tecdude has mentioned neither of these things, so I'd say your issue and @tecdude's are different.

@tecdude, it's hard to be definitive about the fault caused by updating the Raspberry Pi OS, so if it were possible, the easiest thing would be to start over with a fresh installation of Raspberry Pi OS Lite on a new SD card. If that is inconvenient, then I'd suggest doing a full reinstall of Shairport Sync as described in the INSTALL.md page, taking care to follow every step exactly, especially the steps necessary to remove the existing installation of Shairport Sync. With a little experience of the Linux command line, it's really straightforward.

outsharded commented 3 years ago

Reinstalled and still not working. I tested and the Jack is working, so it must be a Shairpoint Sync error.

mikebrady commented 3 years ago

Thanks for the update. It's unlikely to be Shairport Sync -- it runs fine on the Raspberry Pi 4. Maybe there might be something in TROUBLESHOOTING or REPORTING ISSUES that might help?

bloomkd46 commented 3 years ago

@tecdude could you please try to play music on the rpi then run sudo systemctl status shairport-sync on your rpi and post the results

outsharded commented 3 years ago

@bloomkd46

● shairport-sync.service - Shairport Sync - AirPlay Audio Receiver
   Loaded: loaded (/lib/systemd/system/shairport-sync.service; enabled; vendor preset: enabled)
   Active: active (running) since Sun 2021-10-10 16:17:00 BST; 8min ago
 Main PID: 2741 (shairport-sync)
    Tasks: 4 (limit: 1438)
   CGroup: /system.slice/shairport-sync.service
           └─2741 /usr/local/bin/shairport-sync

Oct 10 16:17:00 FrontRoom systemd[1]: Started Shairport Sync - AirPlay Audio Receiver.
Oct 10 16:24:26 FrontRoom shairport-sync[2741]: Failed to create secure directory (/home/shairport-sync/.config/pulse): No such file or directory
Oct 10 16:24:26 FrontRoom shairport-sync[2741]: warning: failed to find mixer control "PCM".
~
~
~
~
~
~
~
~
~
~
~
mikebrady commented 3 years ago

@tecdude, one of the changes in Raspberry Pi OS has been to change the name of the mixer, i.e. the hardware volume control in the DAC that drives the output jack. It used to be "PCM", but now it's either "Headphone" or "Headphones" -- you can check which it is with alsamixer. So, that's the first thing to fix, and it is case-sensitive. Then let's see how things are. Thanks to @bloomkd46!

outsharded commented 3 years ago

What does this mean? I then changed the sound card in alsamixer to Headphone. How do I modify the settings to use this?

Screenshot 2021-10-11 at 15 58 16

mikebrady commented 3 years ago

Thanks for the screenshot. There are some directions in the README. (That link is to development branch BUILDFORAP1 guide, which is more up to date.)

outsharded commented 3 years ago

Thank you! It's now working.

mikebrady commented 3 years ago

Good stuff!

jkpe commented 3 years ago

Hi @mikebrady!

I am running iOS 15.1 Release Candidate (19B74) and am seeing the same behaviour as above. No audio when playing music from my phone but if I select the HomePod first followed by Shairport music is played.

You mentioned in #1308 that iOS asking for SETRATE could be a bug in the beta, although I appreciate the release candidate is technically a beta.

The first example is me playing from my phone where I get no audio and the second example is HomePod first and then Shairport where I get audio.

Thanks!

root@piairplay:~# shairport-sync -vu --statistics
         0.001102443 "shairport.c:1805" Features: 0x1c340405fca00.
         0.000435467 "shairport.c:1834" Started in Airplay 2 mode on device "xx"!
         0.000075469 "shairport.c:1876" software version: "4.1-dev-8-gd25a20aa-AirPlay2-OpenSSL-Avahi-ALSA-soxr-metadata-dbus-sysconfdir:/etc"
         0.000127916 "shairport.c:1882" log verbosity is 1.
         0.000326873 "audio_alsa.c:1015" alsa: alsa_maximum_stall_time of 0.200000 sec.
         0.000156614 "audio_alsa.c:1302" alsa: disable_standby_mode is "never".
         0.000111198 "audio_alsa.c:1304" alsa: disable_standby_mode_silence_threshold is 0.040000 seconds.
         0.000024010 "audio_alsa.c:1306" alsa: disable_standby_mode_silence_scan_interval is 0.004000 seconds.
         0.000207551 "audio_alsa.c:1345" alsa: output device name is "hw:Headphones".
         0.000354269 "shairport.c:1911" libsodium initialised.
         0.000028281 "shairport.c:1938" disable resend requests is off.
         0.000130833 "shairport.c:1942" diagnostic_drop_packet_fraction is 0.000000. A value of 0.0 means no packets will be dropped deliberately.
         0.000092291 "shairport.c:1943" statistics_requester status is 1.
         0.000087969 "shairport.c:1948" rtsp listening port is 7000.
         0.000084583 "shairport.c:1949" udp base port is 6001.
         0.000084270 "shairport.c:1950" udp port range is 10.
         0.000083906 "shairport.c:1951" player name is "Piairplay".
         0.000083594 "shairport.c:1952" backend is "alsa".
         0.000083176 "shairport.c:1953" run_this_before_play_begins action is "(null)".
         0.000083229 "shairport.c:1954" run_this_after_play_ends action is "(null)".
         0.000085781 "shairport.c:1955" wait-cmd status is 0.
         0.000085573 "shairport.c:1956" run_this_before_play_begins may return output is 0.
         0.000084426 "shairport.c:1957" run_this_if_an_unfixable_error_is_detected action is "(null)".
         0.000084583 "shairport.c:1958" run_this_before_entering_active_state action is  "(null)".
         0.000085937 "shairport.c:1959" run_this_after_exiting_active_state action is  "(null)".
         0.000085104 "shairport.c:1960" active_state_timeout is  10.000000 seconds.
         0.000090989 "shairport.c:1961" mdns backend "(null)".
         0.000084427 "shairport.c:1965" interpolation setting is "auto".
         0.000083958 "shairport.c:1966" interpolation soxr_delay_threshold is 30.
         0.000083958 "shairport.c:1967" resync time is 0.050000 seconds.
         0.000086302 "shairport.c:1968" allow a session to be interrupted: 0.
         0.000083593 "shairport.c:1969" busy timeout time is 0.
         0.000084531 "shairport.c:1970" drift tolerance is 0.001995 seconds.
         0.000087395 "shairport.c:1971" password is "(null)".
         0.000083542 "shairport.c:1972" ignore_volume_control is 0.
         0.000083437 "shairport.c:1976" volume_max_db is not set
         0.000083124 "shairport.c:1978" volume range in dB (zero means use the range specified by the mixer): 60.
         0.000085000 "shairport.c:1982" volume_range_combined_hardware_priority (1 means hardware mixer attenuation is used first) is 0.
         0.000086718 "shairport.c:1984" playback_mode is 0 (0-stereo, 1-mono, 1-reverse_stereo, 2-both_left, 3-both_right).
         0.000087865 "shairport.c:1985" disable_synchronization is 0.
         0.000085520 "shairport.c:1986" use_mmap_if_available is 1.
         0.000083698 "shairport.c:1988" output_format automatic selection is enabled.
         0.000084166 "shairport.c:1992" output_rate automatic selection is enabled.
         0.000084948 "shairport.c:1996" audio backend desired buffer length is 0.200000 seconds.
         0.000086510 "shairport.c:1998" audio_backend_buffer_interpolation_threshold_in_seconds is 0.120000 seconds.
         0.000088958 "shairport.c:1999" audio backend latency offset is 0.000000 seconds.
         0.000086978 "shairport.c:2001" audio backend silence lead-in time is "auto".
         0.000083385 "shairport.c:2005" zeroconf regtype is "_raop._tcp".
         0.000084479 "shairport.c:2006" decoders_supported field is 1.
         0.000083906 "shairport.c:2007" use_apple_decoder is 0.
         0.000083541 "shairport.c:2008" alsa_use_hardware_mute is 0.
         0.000083542 "shairport.c:2012" no special mdns service interface was requested.
         0.000181770 "shairport.c:2016" configuration file name "/etc/shairport-sync.conf" resolves to "/etc/shairport-sync.conf".
         0.000024895 "shairport.c:2022" metadata enabled is 1.
         0.000087240 "shairport.c:2023" metadata pipename is "/tmp/shairport-sync-metadata".
         0.000084374 "shairport.c:2025" metadata socket address is "(null)" port 0.
         0.000084896 "shairport.c:2026" metadata socket packet size is "500".
         0.000086145 "shairport.c:2027" get-coverart is 1.
         0.000084427 "shairport.c:2045" loudness is 0.
         0.000082916 "shairport.c:2046" loudness reference level is -20.000000
         0.000308801 "rtsp.c:3645" metadata pipe name is "/tmp/shairport-sync-metadata".
         0.014118637 "dbus-service.c:548" >> setting loudness threshold to -20.000000.
         0.000131509 "dbus-service.c:561" >> setting drift tolerance to 0.001995 seconds
         0.000068906 "dbus-service.c:909" >> ALACDecoder set to "hammerton"
         0.000051458 "dbus-service.c:914" >> Active set to "false"
         0.000039167 "dbus-service.c:919" >> disable standby mode set to "off"
         0.000039896 "dbus-service.c:940" >> interpolation set to "auto" (soxr support built in)
         0.000047395 "dbus-service.c:456" >> deactivating disable standby
         0.000032760 "dbus-service.c:538" >> deactivating loudness
         0.000128750 "dbus-service.c:441" >> log verbosity set to 1.
         0.000070729 "dbus-service.c:425" >> start logging statistics
         0.000065208 "dbus-service.c:390" >> stop including elapsed time in logs
         0.000066875 "dbus-service.c:400" >> start including delta time in logs
         0.000066562 "dbus-service.c:413" >> start including file and line in logs
         0.000114739 "dbus-service.c:1046" Shairport Sync native D-Bus service started at "org.gnome.ShairportSync" on the system bus.
         1.491529087 "shairport.c:212" "soxr" interpolation has been chosen.
       281.866610563 "rtsp.c:5005" Connection 1: new connection from fd4d:7f74:5023:6:c43:8ecf:5ffa:b282:51461 to self at fd4d:7f74:5023:6:5da0:9697:e71b:8ec7:7000.
         3.349118249 "rtsp.c:2866" SETUP on Connection 1. Buffered Audio Stream Detected.
         0.007481992 "audio_alsa.c:900" Lowest dB value is a mute
         0.001202182 "audio_alsa.c:529" alsa: output format chosen is "S16".
         0.000147499 "audio_alsa.c:569" alsa: output speed chosen is 44100.
         0.231569058 "rtsp.c:4665" Connection 1: Unrecognised and unhandled rtsp request "SETRATE".
         0.000278592 "rtsp.c:4681" Content: "62706C6973743030D2010203045772747054696D65547261746512D2EA6F221001080D151A1F0000000000000101000000000000000500000000000000000000000000000021".
root@piairplay:~# shairport-sync -vu --statistics
         0.001096244 "shairport.c:1805" Features: 0x1c340405fca00.
         0.000192864 "shairport.c:1834" Started in Airplay 2 mode on device "xx"!
         0.000064635 "shairport.c:1876" software version: "4.1-dev-8-gd25a20aa-AirPlay2-OpenSSL-Avahi-ALSA-soxr-metadata-dbus-sysconfdir:/etc"
         0.000020573 "shairport.c:1882" log verbosity is 1.
         0.000040051 "audio_alsa.c:1015" alsa: alsa_maximum_stall_time of 0.200000 sec.
         0.000055469 "audio_alsa.c:1302" alsa: disable_standby_mode is "never".
         0.000019271 "audio_alsa.c:1304" alsa: disable_standby_mode_silence_threshold is 0.040000 seconds.
         0.000018281 "audio_alsa.c:1306" alsa: disable_standby_mode_silence_scan_interval is 0.004000 seconds.
         0.000071406 "audio_alsa.c:1345" alsa: output device name is "hw:Headphones".
         0.000505257 "shairport.c:1911" libsodium initialised.
         0.000066927 "shairport.c:1938" disable resend requests is off.
         0.000046562 "shairport.c:1942" diagnostic_drop_packet_fraction is 0.000000. A value of 0.0 means no packets will be dropped deliberately.
         0.000063854 "shairport.c:1943" statistics_requester status is 1.
         0.000054375 "shairport.c:1948" rtsp listening port is 7000.
         0.000045624 "shairport.c:1949" udp base port is 6001.
         0.000060365 "shairport.c:1950" udp port range is 10.
         0.000098957 "shairport.c:1951" player name is "Piairplay".
         0.000063594 "shairport.c:1952" backend is "alsa".
         0.000020052 "shairport.c:1953" run_this_before_play_begins action is "(null)".
         0.000099218 "shairport.c:1954" run_this_after_play_ends action is "(null)".
         0.000091145 "shairport.c:1955" wait-cmd status is 0.
         0.000057240 "shairport.c:1956" run_this_before_play_begins may return output is 0.
         0.000045468 "shairport.c:1957" run_this_if_an_unfixable_error_is_detected action is "(null)".
         0.000044583 "shairport.c:1958" run_this_before_entering_active_state action is  "(null)".
         0.000033490 "shairport.c:1959" run_this_after_exiting_active_state action is  "(null)".
         0.000019843 "shairport.c:1960" active_state_timeout is  10.000000 seconds.
         0.000021042 "shairport.c:1961" mdns backend "(null)".
         0.000016562 "shairport.c:1965" interpolation setting is "auto".
         0.000018177 "shairport.c:1966" interpolation soxr_delay_threshold is 30.
         0.000017083 "shairport.c:1967" resync time is 0.050000 seconds.
         0.000017552 "shairport.c:1968" allow a session to be interrupted: 0.
         0.000028646 "shairport.c:1969" busy timeout time is 0.
         0.000043489 "shairport.c:1970" drift tolerance is 0.001995 seconds.
         0.000044896 "shairport.c:1971" password is "(null)".
         0.000043229 "shairport.c:1972" ignore_volume_control is 0.
         0.000044114 "shairport.c:1976" volume_max_db is not set
         0.000043385 "shairport.c:1978" volume range in dB (zero means use the range specified by the mixer): 60.
         0.000045104 "shairport.c:1982" volume_range_combined_hardware_priority (1 means hardware mixer attenuation is used first) is 0.
         0.000045261 "shairport.c:1984" playback_mode is 0 (0-stereo, 1-mono, 1-reverse_stereo, 2-both_left, 3-both_right).
         0.000047239 "shairport.c:1985" disable_synchronization is 0.
         0.000043802 "shairport.c:1986" use_mmap_if_available is 1.
         0.000044010 "shairport.c:1988" output_format automatic selection is enabled.
         0.000044323 "shairport.c:1992" output_rate automatic selection is enabled.
         0.000043541 "shairport.c:1996" audio backend desired buffer length is 0.200000 seconds.
         0.000048541 "shairport.c:1998" audio_backend_buffer_interpolation_threshold_in_seconds is 0.120000 seconds.
         0.000049063 "shairport.c:1999" audio backend latency offset is 0.000000 seconds.
         0.000045260 "shairport.c:2001" audio backend silence lead-in time is "auto".
         0.000046510 "shairport.c:2005" zeroconf regtype is "_raop._tcp".
         0.000047135 "shairport.c:2006" decoders_supported field is 1.
         0.000044323 "shairport.c:2007" use_apple_decoder is 0.
         0.000043177 "shairport.c:2008" alsa_use_hardware_mute is 0.
         0.000047187 "shairport.c:2012" no special mdns service interface was requested.
         0.000081562 "shairport.c:2016" configuration file name "/etc/shairport-sync.conf" resolves to "/etc/shairport-sync.conf".
         0.000049687 "shairport.c:2022" metadata enabled is 1.
         0.000046666 "shairport.c:2023" metadata pipename is "/tmp/shairport-sync-metadata".
         0.000044844 "shairport.c:2025" metadata socket address is "(null)" port 0.
         0.000044166 "shairport.c:2026" metadata socket packet size is "500".
         0.000044479 "shairport.c:2027" get-coverart is 1.
         0.000046198 "shairport.c:2045" loudness is 0.
         0.000042969 "shairport.c:2046" loudness reference level is -20.000000
         0.000217811 "rtsp.c:3645" metadata pipe name is "/tmp/shairport-sync-metadata".
         0.025110329 "dbus-service.c:548" >> setting loudness threshold to -20.000000.
         0.000235415 "dbus-service.c:561" >> setting drift tolerance to 0.001995 seconds
         0.000140312 "dbus-service.c:909" >> ALACDecoder set to "hammerton"
         0.000106562 "dbus-service.c:914" >> Active set to "false"
         0.000090364 "dbus-service.c:919" >> disable standby mode set to "off"
         0.000087916 "dbus-service.c:940" >> interpolation set to "auto" (soxr support built in)
         0.000112604 "dbus-service.c:456" >> deactivating disable standby
         0.000071249 "dbus-service.c:538" >> deactivating loudness
         0.000182031 "dbus-service.c:441" >> log verbosity set to 1.
         0.000092499 "dbus-service.c:425" >> start logging statistics
         0.000072291 "dbus-service.c:390" >> stop including elapsed time in logs
         0.000076354 "dbus-service.c:400" >> start including delta time in logs
         0.000143176 "dbus-service.c:413" >> start including file and line in logs
         0.000174010 "dbus-service.c:1046" Shairport Sync native D-Bus service started at "org.gnome.ShairportSync" on the system bus.
         1.478203240 "shairport.c:212" "soxr" interpolation has been chosen.
        11.742837259 "rtsp.c:5005" Connection 1: new connection from 10.1.1.189:49188 to self at 10.1.1.192:7000.
         0.835255861 "rtsp.c:2866" SETUP on Connection 1. Buffered Audio Stream Detected.
         0.004088050 "audio_alsa.c:900" Lowest dB value is a mute
         0.000737548 "audio_alsa.c:529" alsa: output format chosen is "S16".
         0.000091770 "audio_alsa.c:569" alsa: output speed chosen is 44100.
         1.239717875 "rtp.c:1322" Connection 1: Clock 58d34946d6de0008 is now the new anchor clock and master clock. History: 1500.193922 milliseconds.
         0.000255259 "rtp.c:1404" Connection 1: NQPTP new master clock 58d34946d6de0008.
         0.022921278 "player.c:1060" Connection 1: Lead time for first frame 1224848064: 0.305705 seconds.
         8.104861336 "player.c:2848" sync error ms, net sync ppm, all sync ppm,     packets, min DAC queue, min buffers, max buffers,  output fps
         0.000123281 "player.c:2848"          0.12,          0.0,          0.0,        1003,          8558,          87,          88,    44100.32
         7.258955514 "player.c:1619" Connection 1: Playback Stopped. Total playing time 00:00:17. Input: 44108.93, output: 44100.32 frames per second.
mikebrady commented 3 years ago

Thanks @jkpe. This has nothing to do with the OP but, as you point out, is the same as #1308. Let’s hope it’s a bug, but if not, when the release finally comes out, we’ll see if we can get around it.