[Problem]: playback goes silent when switching songs in web browser

[dasl-]

What happened?

I'm using a macbook SPS client, connecting to the SPS server via the system sound settings. I'm playing music from spotify in Chrome web browser

Client info:

• macOS Monterey 12.5.1 (21G83), M1
• Chrome Version 110.0.5481.100 (Official Build) (arm64)

When a song finishes playing on spotify and the next song begins to play, the audio output goes silent at the start of the next song. To speed up the testing feedback loop, you can start playing a song on spotify, and immediately seek to within ~5 seconds from the end of the song. After ~5 seconds has elapsed and the next song starts to play, you will only hear silence. The song "progress bar" still moves forward as if the song is playing, but no sound is heard. When this problem occurs, the only way I have found to make the audio return to normal is to disconnect the client from SPS and reconnect.

I experience the same problem (audio suddenly goes silent) when doing the following tasks:

1. Playing a song in spotify via chrome web browser and hitting the "Next" button - the audio goes silent when the next song begins
2. When playing spotify via firefox (version 110.0 (64-bit)) all of the same things that cause the audio to go silent in chrome also cause the same problem in firefox. Additionally, seeking the audio to a new position also triggers the silent audio. This is interesting because I cannot trigger the same problem solely by seeking the audio to a new position in chrome. In chrome, a new song must start for this issue to occur.

Notably, I am unable to trigger this problem whatsoever when playing spotify in the safari web browser (Version 15.6.1 (17613.3.9.1.16)).

I am quite certain that I did not used to have this problem. This suggests something recently changed in either SPS, macOS, firefox / chrome, or spotify. Let me know if you'd like me to try git bisect or similar to see if an older version of SPS did not have this problem. Or if I can perform any more testing that would be useful.

I doubt the problem is with spotify though, because I experience similar problems when playing audio from https://bandcamp.com/ and youtube via web browser, although I have not tested the scenarios quite as extensively as I have with using spotify in the web browser.

I have not noticed any similar problems when using SPS with an iOS client.

This bug report has some similarities with #1626

Logs

In the session which these logs describe, I started playing "Stayin Alive" by "Bee Gees" (observe these strings in the log file) in spotify via chrome web browser. I then seeked to ~5 seconds from the end of the track. When the next song, which was "Dancing Queen" by "ABBA" started, the audio went silent.

https://gist.github.com/dasl-/9559fbff3096b9decf81856890ddcd88

Relevant log output

See above

Configuration Information.

[piwall10] ~ % shairport-sync --displayConfig
         0.000880056 "shairport.c:1467" default metadata_pipename is "/tmp/shairport-sync-metadata".
         0.000165963 "shairport.c:2109" >> Display Config Start.
         0.010618000 "shairport.c:2109"
         0.000107315 "shairport.c:2109" From "uname -a":
         0.000044240 "shairport.c:2109"  Linux piwall10 5.10.103-v7l+ #1529 SMP Tue Mar 8 12:24:00 GMT 2022 armv7l GNU/Linux
         0.014255741 "shairport.c:2109"
         0.000348482 "shairport.c:2109" From /etc/os-release:
         0.000200981 "shairport.c:2109"  Raspbian GNU/Linux 10 (buster)
         0.012669296 "shairport.c:2109"
         0.000310871 "shairport.c:2109" From /sys/firmware/devicetree/base/model:
         0.000195055 "shairport.c:2109"  Raspberry Pi 4 Model B Rev 1.2
         0.000240223 "shairport.c:2109"
         0.000203388 "shairport.c:2109" Shairport Sync Version String:
         0.000211797 "shairport.c:2109"  4.1-rc0-273-gf164f19a-AirPlay2-OpenSSL-Avahi-ALSA-soxr-metadata-dbus-sysconfdir:/etc
         0.000192629 "shairport.c:2109"
         0.000154797 "shairport.c:2109" Command Line:
         0.000151703 "shairport.c:2109"  shairport-sync --displayConfig
         0.000250945 "shairport.c:2109"
         0.000154611 "shairport.c:2109" Configuration File:
         0.000151370 "shairport.c:2109"  /etc/shairport-sync.conf
         0.000157148 "shairport.c:2109"
         0.000361056 "shairport.c:2109" Configuration File Settings:
         0.000167222 "shairport.c:2109"  general :
         0.000151760 "shairport.c:2109"  {
         0.000150703 "shairport.c:2109"    volume_range_db = 40;
         0.000154519 "shairport.c:2109"    volume_max_db = 0.0;
         0.000152907 "shairport.c:2109"    name = "piwall";
         0.000151667 "shairport.c:2109"  };
         0.000181704 "shairport.c:2109"  alsa :
         0.000190722 "shairport.c:2109"  {
         0.000184444 "shairport.c:2109"    output_device = "hw:Headphones";
         0.000185519 "shairport.c:2109"    mixer_control_name = "Headphone";
         0.000217926 "shairport.c:2109"    disable_standby_mode = "always";
         0.000197722 "shairport.c:2109"  };
         0.000186611 "shairport.c:2109"  diagnostics :
         0.000154889 "shairport.c:2109"  {
         0.000150592 "shairport.c:2109"    log_verbosity = 2;
         0.000151630 "shairport.c:2109"    statistics = "yes";
         0.000152056 "shairport.c:2109"  };
         0.000159944 "shairport.c:2109"
         0.000154296 "shairport.c:2109" >> Display Config End.
         0.000161945 "shairport.c:2111" >> Goodbye!
         0.000215648 "shairport.c:1585" exit function called...
         0.000191037 "shairport.c:1603" Stopping D-Bus service
         0.000207741 "dbus-service.c:1211" stopping dbus service
         0.000203537 "shairport.c:1605" Stopping D-Bus service done
         0.000155796 "shairport.c:1621" Stopping DACP Monitor
         0.000150945 "shairport.c:1623" Stopping DACP Monitor Done
         0.000152574 "shairport.c:1627" Stopping metadata hub
         0.000150759 "shairport.c:1629" Stopping metadata done
         0.000151537 "shairport.c:1633" Stopping metadata
         0.000187074 "shairport.c:1635" Stopping metadata done
         0.000184833 "shairport.c:1637" Stopping the activity monitor.
         0.000155945 "shairport.c:1639" Stopping the activity monitor done.
         0.000176148 "shairport.c:1721" normal exit

How did you install Shairport Sync?

Built from source

Check previous issues

• Confirm

[dasl-]

Update: I've done some experimenting with old versions to see when the problem started occurring:

1. Using SPS 17c3979 and nqptp mikebrady/nqptp@5672c33 (main head) works. I cannot reproduce the bug.
2. Using SPS 6eb70ee and nqptp mikebrady/nqptp@5762735 (development head) is bad - I can reproduce the bug.

[mikebrady]

Many thanks for the report and the troubleshooting. Let me check it out.

[mikebrady]

Hi there. I could reproduce this and I think it's fixed on the latest push to the development branch. As ever, (a) thanks! and (b) if you got a chance to check it out and report back, it would be appreciated.

[dasl-]

It works! Thank you too, as usual 😎