-
-
Notifications
You must be signed in to change notification settings - Fork 564
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
[Problem]: USB Audio: "player.c:2906" Large negative (i.e. early) sync error" #1845
Comments
Thanks for the post, and it was a very good idea to run It's a peculiar situation, to be sure. Those messages, like:
are coming from Shairport Sync trying to resynchronise, having calculated an error or more than ± 50 milliseconds. Let me suggest that you disable resynchronisation by setting |
Thank you for your response Mike. Setting shairport-sync -v
0.002191354 "shairport.c:2252" Startup in AirPlay 2 mode, with features 0x405c4a00,0x1c340 on device "b8:27:eb:b0:52:00".
0.000140469 "shairport.c:2291" Version String: "4.3.2-4-g45767ef9-AirPlay2-smi10-OpenSSL-Avahi-ALSA-soxr-sysconfdir:/etc"
0.000018646 "shairport.c:2310" Command Line: "shairport-sync -v".
0.000342812 "shairport.c:2346" Log Verbosity is 1.
0.000030886 "audio_alsa.c:1021" alsa: alsa_maximum_stall_time of 0.200000 sec.
0.000051458 "audio_alsa.c:1310" alsa: disable_standby_mode is "never".
0.000013490 "audio_alsa.c:1314" alsa: disable_standby_mode_silence_threshold is 0.040000 seconds.
0.000014322 "audio_alsa.c:1316" alsa: disable_standby_mode_silence_scan_interval is 0.004000 seconds.
0.000025730 "audio_alsa.c:1356" alsa: output device name is "hw:SoundLink".
0.000223073 "shairport.c:2394" disable_resend_requests is off.
0.000018802 "shairport.c:2395" diagnostic_drop_packet_fraction is 0.000000. A value of 0.0 means no packets will be dropped deliberately.
0.000017291 "shairport.c:2399" statistics_requester status is 0.
0.000013125 "shairport.c:2404" rtsp listening port is 7000.
0.000012136 "shairport.c:2405" udp base port is 6001.
0.000012291 "shairport.c:2406" udp port range is 10.
0.000012500 "shairport.c:2407" player name is "Living Room Bose".
0.000013177 "shairport.c:2408" backend is "alsa".
0.000012188 "shairport.c:2409" run_this_before_play_begins action is "(null)".
0.000020677 "shairport.c:2410" run_this_after_play_ends action is "(null)".
0.000056406 "shairport.c:2411" wait-cmd status is 0.
0.000040834 "shairport.c:2412" run_this_before_play_begins may return output is 0.
0.000039843 "shairport.c:2413" run_this_if_an_unfixable_error_is_detected action is "(null)".
0.000039584 "shairport.c:2415" run_this_before_entering_active_state action is "(null)".
0.000018698 "shairport.c:2417" run_this_after_exiting_active_state action is "(null)".
0.000014375 "shairport.c:2419" active_state_timeout is 10.000000 seconds.
0.000017291 "shairport.c:2420" mdns backend "(null)".
0.000012032 "shairport.c:2422" interpolation setting is "auto".
0.000012864 "shairport.c:2426" interpolation soxr_delay_threshold is 30000000.
0.000012969 "shairport.c:2427" resync time is 0.000000 seconds.
0.000013333 "shairport.c:2428" resync recovery time is 0.100000 seconds.
0.000013906 "shairport.c:2429" allow a session to be interrupted: 0.
0.000012292 "shairport.c:2430" busy timeout time is 0.
0.000012240 "shairport.c:2431" drift tolerance is 0.002000 seconds.
0.000014271 "shairport.c:2432" password is "(null)".
0.000011822 "shairport.c:2433" default airplay volume is: -24.000000.
0.000014688 "shairport.c:2434" high threshold airplay volume is: -16.000000.
0.000014531 "shairport.c:2436" check for higher-than-threshold volume for new play session is disabled.
0.000017604 "shairport.c:2442" ignore_volume_control is 0.
0.000013021 "shairport.c:2446" volume_max_db is not set
0.000012136 "shairport.c:2447" volume range in dB (zero means use the range specified by the mixer): 0.
0.000013333 "shairport.c:2449" volume_range_combined_hardware_priority (1 means hardware mixer attenuation is used first) is 0.
0.000013594 "shairport.c:2453" playback_mode is 0 (0-stereo, 1-mono, 1-reverse_stereo, 2-both_left, 3-both_right).
0.000013229 "shairport.c:2455" disable_synchronization is 0.
0.000012500 "shairport.c:2456" use_mmap_if_available is 1.
0.000011927 "shairport.c:2457" output_format automatic selection is enabled.
0.000012500 "shairport.c:2461" output_rate automatic selection is enabled.
0.000012500 "shairport.c:2465" audio backend desired buffer length is 0.200000 seconds.
0.000013750 "shairport.c:2467" audio_backend_buffer_interpolation_threshold_in_seconds is 0.120000 seconds.
0.000014792 "shairport.c:2469" audio backend latency offset is 0.000000 seconds.
0.000014010 "shairport.c:2471" audio backend silence lead-in time is "auto".
0.000012344 "shairport.c:2475" zeroconf regtype is "_raop._tcp".
0.000012396 "shairport.c:2476" decoders_supported field is 1.
0.000012031 "shairport.c:2477" use_apple_decoder is 0.
0.000011667 "shairport.c:2478" alsa_use_hardware_mute is 0.
0.000012291 "shairport.c:2482" no special mdns service interface was requested.
0.000042813 "shairport.c:2485" configuration file name "/etc/shairport-sync.conf" resolves to "/etc/shairport-sync.conf".
0.000015885 "shairport.c:2515" loudness is 0.
0.000012292 "shairport.c:2516" loudness reference level is -20.000000
0.000508125 "shairport.c:2643" NQPTP is online.
1.502434166 "shairport.c:255" "soxr" interpolation has been chosen.
// Airplay speaker is then selected on device
2.755037395 "rtsp.c:2902" Connection 1: AP2 PTP connection from xxxx::xxxx:xxxx:xxxx:xxxx:xxxxx ("iPhone") to self at xxxx::xxxx:xx:axxxx:xx:xxxx.
6.777910362 "rtsp.c:3258" Connection 1: SETUP AP2 no Active-Remote information the SETUP Record.
0.000118958 "rtsp.c:3277" Connection 1: SETUP AP2 doesn't include DACP-ID string information.
// Press play on device
2.479292759 "audio_alsa.c:1752" alsa: recovering from a previous underrun.
0.000299063 "audio_alsa.c:1752" alsa: recovering from a previous underrun.
0.008127292 "audio_alsa.c:1752" alsa: recovering from a previous underrun.
0.032327708 "audio_alsa.c:1752" alsa: recovering from a previous underrun.
0.000187135 "audio_alsa.c:1752" alsa: recovering from a previous underrun.
0.040256771 "audio_alsa.c:1752" alsa: recovering from a previous underrun.
0.000220209 "audio_alsa.c:1752" alsa: recovering from a previous underrun.
0.007962291 "audio_alsa.c:1752" alsa: recovering from a previous underrun.
0.032634479 "audio_alsa.c:1752" alsa: recovering from a previous underrun.
0.000194844 "audio_alsa.c:1752" alsa: recovering from a previous underrun.
0.040098333 "audio_alsa.c:1752" alsa: recovering from a previous underrun.
0.000569219 "audio_alsa.c:1752" alsa: recovering from a previous underrun.
0.007620677 "audio_alsa.c:1752" alsa: recovering from a previous underrun.
0.032633438 "audio_alsa.c:1752" alsa: recovering from a previous underrun.
0.000229479 "audio_alsa.c:1752" alsa: recovering from a previous underrun.
0.040174739 "audio_alsa.c:1752" alsa: recovering from a previous underrun.
0.000271459 "audio_alsa.c:1752" alsa: recovering from a previous underrun.
0.000164427 "audio_alsa.c:1752" alsa: recovering from a previous underrun. I also tried With this alsa error - would you have any other suggestions. I assume it is related to the alsa buffer size but not sure where to begin? If this is speaker specific I can revert to using the aux cable, however would happily keep troubleshooting if there is a way to make this work via USB audio. |
Thanks. This is a real puzzle, and it's good that you have the If you could do
It might show some anomaly... |
This returns the following info about the DAC: 0.000489531 "rtsp.c:3363" Connection 1: TCP Buffered Audio port opened: 39809.
0.000073021 "audio_alsa.c:900" alsa: hardware mixer prepare
0.000027657 "activity_monitor.c:167" am_state: am_active
0.003494427 "audio_alsa.c:923" Lowest dB value is a mute
0.000667812 "audio_alsa.c:548" alsa: output format chosen is "S16".
0.000098698 "audio_alsa.c:591" alsa: output speed chosen is 44100.
0.005742396 "audio_alsa.c:1528" alsa: update timestamps available
0.000073333 "audio_alsa.c:253" alsa: precision delay timing is available.
0.000016042 "audio_alsa.c:743" alsa: precision timing selected for "auto" mode
0.000014375 "audio_alsa.c:760" PCM handle name = 'hw:1'
0.000012552 "audio_alsa.c:774" alsa device parameters:
0.000018229 "audio_alsa.c:777" access type = MMAP_INTERLEAVED
0.000022344 "audio_alsa.c:780" format = 'S16_LE' (Signed 16 bit Little Endian)
0.000023177 "audio_alsa.c:784" subformat = 'STD' (Standard)
0.000017396 "audio_alsa.c:788" number of channels = 2
0.000015416 "audio_alsa.c:791" number of significant bits = 16
0.000016094 "audio_alsa.c:799" rate = 44100 frames per second (precisely).
0.000015938 "audio_alsa.c:808" precise (rational) rate = 44100.000 frames per second (i.e. 44100/1).
0.000023021 "audio_alsa.c:822" period_time = 5011 us (>).
0.000016197 "audio_alsa.c:832" period_size = 221 frames (precisely).
0.000020365 "audio_alsa.c:845" buffer_time = 2000000 us (precisely).
0.000014375 "audio_alsa.c:858" buffer_size = 88200 frames (precisely).
0.000016875 "audio_alsa.c:874" periods_per_buffer = 399 (>).
0.000017396 "audio_alsa.c:1792" do_open() set_mute_state
0.000014167 "audio_alsa.c:1909" alsa: prepare() -- opened output device
0.000379322 "player.c:3622" Connection 1: player_play.
0.000634636 "rtsp.c:3453" SETUP response
0.000120885 "rtsp.c:3453" Response Code: 200.
0.000021927 "rtsp.c:3453" Type: "CSeq", content: "13"
0.000013802 "rtsp.c:3453" Type: "Server", content: "AirTunes/366.0"
0.000013438 "rtsp.c:3453" Type: "Content-Type", content: "application/x-apple-binary-plist"
0.000084219 "rtsp.c:3453" Content Plist (as XML): Anything that stands out? This is also now showing that the underrun is is -1 frames: 0.000105364 "audio_alsa.c:1752" alsa: recovering from a previous underrun.
0.000292188 "audio_alsa.c:1752" alsa: recovering from a previous underrun.
0.040221562 "audio_alsa.c:1752" alsa: recovering from a previous underrun.
0.000432604 "player.c:2681" Underrun of -1 frames reported, but ignored.
0.000177813 "audio_alsa.c:1752" alsa: recovering from a previous underrun.
0.007601719 "audio_alsa.c:1752" alsa: recovering from a previous underrun.
0.033039635 "player.c:2681" Underrun of -1 frames reported, but ignored.
0.000153646 "audio_alsa.c:1752" alsa: recovering from a previous underrun.
0.000282291 "audio_alsa.c:1752" alsa: recovering from a previous underrun.
0.040152396 "audio_alsa.c:1752" alsa: recovering from a previous underrun. I tried with all of this with Raspberry Pi4 Model B and still get the same errors. |
Thanks. That all looks completely fine, unfortunately. I have occasionally heard of problems with the so-called precision timing, so it might be worth disabling it. To do that, set |
Tried the above and still nothing. I've just done some more testing and it has come to my attention that this is likely an issue with the DAC/Speak not actually able to play rates of 44100. Audio plays from the speaker via USB-Audio using the following command: $ aplay /usr/share/sounds/alsa/Front_Left.wav
Playing WAVE '/usr/share/sounds/alsa/Front_Left.wav' : Signed 16 bit Little Endian, Rate 48000 Hz, Mono I noted this was at a Rate of 48000 that shairport does not support. I then tested: speaker-test -r44100 --device=hw:1 -c2 Which provided no audio. However - speaker-test -r48000 --device=hw:1 -c2 Plays through the pink noise. I should have picked up on this earlier but although the speaker showed in sps-alsa-explore, it didn't necessarily mean that it could playback at a rate of 44100. I would assume this is now a speaker limitation (using USB Audio) and there is nothing further to troubleshoot? Thank you for your help with this Mike - I appreciate your time, and thank you for all your work on this player. |
Thanks for all your investigations. I think your conclusions are spot on. It does seems as if the SoundLink has a bug in it. Even though it can not play at 44,100 frames per second, when asked by Shairport Sync, the player advertises that it can do so. The lines following:
in the log listed above show the response from the DAC. As you've discovered, the device can only work at 48,000. Shairport Sync requires a playback rate of 44,100 or an integer multiple of it. Maybe this will help someone in the future. |
What happened?
I'm trying to output audio from a Raspberry Pi 3 Model B Rev 1.2 to a Bose SoundLink Revolve+ II Speaker via USB Input. I'm currently able to get shairport to work via Aux Input only. I'm hoping that I can connect these Bose speakers with a single cable for power and audio.
Also adding that I can get test audio to play to the speaker using the
speaker-test
command.This is the logs that I get:
Speaker shows up fine on my iPhone or Mac and connects, but as soon as I play audio the
"player.c:2906" Large negative (i.e. early) sync error of -2216 frames'
error begins appearing until I pause or exit shairport-sync.Using sps-alsa-explore command shows the following audio devices:
I've tried different variants of "output_device" / "mixer_control_name" / latency offsets / output rates and formats but always have the same sync error with ~-0.05 seconds.
Is there something I am missing? Everything else I have used with shairport-sync has worked perfectly and I am so thankful for this player!
Relevant log output
No response
System Information.
Raspberry Pi 3 Model B Rev 1.2
Bose SoundLink Revolve+ II Bluetooth Speaker
Configuration Information.
PulseAudio or PipeWire installed?
How did you install Shairport Sync?
Built from source
Check previous issues
The text was updated successfully, but these errors were encountered: