mikebrady / shairport-sync

AirPlay and AirPlay 2 audio player
Other
7.2k stars 571 forks source link

[Problem]: No sound when changing song in macOS Music app #1626

Closed eos1d3 closed 1 year ago

eos1d3 commented 1 year ago

What happened?

Start Music App and keep changing songs one by one to play with 1-5 seconds. After some songs are played successfully, suddenly a new song has no sound at all. But Music app shows it is playing normally. To fix this issue, just select some songs to play and usually it will resume normal.

macOS: 12.6.3

PS: I do not see this problem before I upgraded to 12.6.3. But I am not sure if it is macOS conflict. i

Relevant log output

When the problem occurs, I see no log is created. But every time I start in verbose mode, I always see this at the beginning.

ALSA lib conf.c:5084:(parse_args) Unknown parameter 1
ALSA lib conf.c:5217:(snd_config_expand) Parse arguments error: No such file or directory
ALSA lib control.c:1471:(snd_ctl_open_noupdate) Invalid CTL hw:1,1

Configuration Information.

Display Config Start.

From "uname -a": Linux pi3 5.15.76-v7+ #1597 SMP Fri Nov 4 12:13:17 GMT 2022 armv7l GNU/Linux

From /etc/os-release: Raspbian GNU/Linux 11 (bullseye)

From /sys/firmware/devicetree/base/model: Raspberry Pi 3 Model B Rev 1.2

Shairport Sync Version String: 4.1.1-AirPlay2-OpenSSL-Avahi-ALSA-soxr-sysconfdir:/etc

Command Line: shairport-sync --displayConfig

Configuration File: /etc/shairport-sync.conf

Configuration File Settings: general : { name = "Pi3 Airplay 2"; }; alsa : { output_device = "hw:1,1"; mixer_control_name = "PCM"; };

Display Config End. Goodbye!

How did you install Shairport Sync?

Built from source

Check previous issues

eos1d3 commented 1 year ago

PS: Forgot to mention, please select the airplay device in Music App. Do not use system sound to select.

Screen Shot 2023-02-04 at 2 55 35 PM
mikebrady commented 1 year ago

Thanks for the report. I have not seen this problem, so will investigate.

Was there some particular reason for choosing hw:1,1? Could you say what kind of device is it, please?

You can turn on Shairport Sync logs by setting the log_verbosity to 1 in the configuration file and restarting. It's not a good idea to set it to 2 or 3 at this stage...

eos1d3 commented 1 year ago

hw:1,1 is my USB Creative Sound device. I have been using this configuration with orignal shairport-sync for 2 years without any issue.

I have been using Airplay 2 version since it was released. And just find this issue today. I have verified this issue with another Mac (12.6.3), and get the same issue.

I stopped the service and and running in verbose mode (with -v param). When the problem occurs, I see no special message is shown.

mikebrady commented 1 year ago

Thanks for the information!

eos1d3 commented 1 year ago

I am going to do a test and send you a full log. But what is the path of the log file?

mikebrady commented 1 year ago

Thanks. By default the log goes to the system log, hence you can see it using ‘journalctl’.

eos1d3 commented 1 year ago

After reboot of my PI3, I started Music App and played random songs. Each song was played for 1-3 seconds only.

When I started playing the first song, I saw ALSA lib error. But the song was played normally.

Then I repeatedly changed around 10 songs. At 23:36:xx, no sound occurred once. And at 23:37:00, no sound again on another song. No message was shown for these two errors.

And another finding is when no sound occurs, the temporary fix is to play ANOTHER song. Keep pressing Pause and Play on the same song won't help.

Hope this help!

-- Journal begins at Thu 2022-09-22 08:23:40 HKT. --
Feb 04 23:33:44 pi3 systemd[640]: Listening on GnuPG cryptographic agent and passphrase cache (restricted).
Feb 04 23:33:44 pi3 systemd[640]: Listening on GnuPG cryptographic agent (ssh-agent emulation).
Feb 04 23:33:44 pi3 systemd[640]: Listening on GnuPG cryptographic agent and passphrase cache.
Feb 04 23:33:44 pi3 systemd[640]: Reached target Sockets.
Feb 04 23:33:44 pi3 systemd[640]: Reached target Basic System.
Feb 04 23:33:44 pi3 systemd[640]: Reached target Main User Target.
Feb 04 23:33:44 pi3 systemd[640]: Startup finished in 564ms.
Feb 04 23:33:44 pi3 systemd[1]: Started User Manager for UID 1000.
Feb 04 23:33:44 pi3 systemd[1]: Started Session 1 of user pi.
Feb 04 23:33:48 pi3 systemd[1]: systemd-hostnamed.service: Succeeded.
Feb 04 23:34:56 pi3 shairport-sync[611]: ALSA lib conf.c:5084:(parse_args) Unknown parameter 1
Feb 04 23:34:56 pi3 shairport-sync[611]: ALSA lib conf.c:5217:(snd_config_expand) Parse arguments error: No such file or directory
Feb 04 23:34:56 pi3 shairport-sync[611]: ALSA lib control.c:1471:(snd_ctl_open_noupdate) Invalid CTL hw:1,1
eos1d3 commented 1 year ago

I just reinstalled shairport-sync and the problem is still the same.

And I also found that not all albums will cause this issue. Some are found from XLD created Apple Lossless File. But I never have this issue with original shairport-sync with this format. And AirPlay 2 version did not have this issue after using it for months.

You can try this album which I have the most problem.

https://drive.google.com/drive/folders/1OIS6X5IMZilYDohkDQ2o0BQXmGJ5yU_5?usp=sharing

Thanks!

mikebrady commented 1 year ago

Thanks. Let me suggest an experiment: set the alsa disable_standby_mode to "auto" or "always". (Remember to uncomment the line as well! And you'll need to restart Shairport Sync.) See if the problem persists.

eos1d3 commented 1 year ago

Hi,

Tried with the two options and the problem is still there. The line is uncommented.

And another finding: if song has no sound and just let it play to the end. Music app will then play the next song automatically and the problem is gone for the next one.. It seems to be a starting problem.

mikebrady commented 1 year ago

Thanks again. I’ll need to dig in to this issue to try to work out what’s happening.

eos1d3 commented 1 year ago

Hi, today I let Music app play the problematic album. And let it loops the whole album repeatedly. I find that the problem never occurs. So this problem will occur only when a song is playing and is interrupted by switching to another song.

mikebrady commented 1 year ago

Can I just check the outcome of the “experiment”, please?

Thanks. Let me suggest an experiment: set the alsa disable_standby_mode to "auto" or "always". (Remember to uncomment the line as well! And you'll need to restart Shairport Sync.) See if the problem persists.

When you tried it, did you get any of those alsa lib errors occurring, or did they disappear?

eos1d3 commented 1 year ago

I also suspect the same thing but have not tested it yet. I did find another warning saying sound device not found at the beginning of a test before. But it worked later after that message.

I will test again later today.

eos1d3 commented 1 year ago

Set disable_standby_mode to auto, and rebooted my PI3.

Start Music app, the messages appeared immediately:

Feb 06 20:53:02 pi3 shairport-sync[617]: ALSA lib conf.c:5084:(parse_args) Unknown parameter 1
Feb 06 20:53:02 pi3 shairport-sync[617]: ALSA lib conf.c:5217:(snd_config_expand) Parse arguments error: No such file or directory
Feb 06 20:53:02 pi3 shairport-sync[617]: ALSA lib control.c:1471:(snd_ctl_open_noupdate) Invalid CTL hw:1,1
Feb 06 20:53:02 pi3 shairport-sync[617]: ALSA lib conf.c:5084:(parse_args) Unknown parameter 1
Feb 06 20:53:02 pi3 shairport-sync[617]: ALSA lib conf.c:5217:(snd_config_expand) Parse arguments error: No such file or directory
Feb 06 20:53:02 pi3 shairport-sync[617]: ALSA lib control.c:1471:(snd_ctl_open_noupdate) Invalid CTL hw:1,1
Feb 06 20:53:02 pi3 shairport-sync[617]: fatal error: the alsa output_device "hw:1,1" can not be found.

The sound output lasted 1-2 seconds and no sound after that. Switched to another song then it worked again.

Set disable_standby_mode set to always, no alsa lib errors. Then rebooted and tested. No such errors. Third reboot, No such errors.

It is safe to say disable_standby_mode has to be always.

mikebrady commented 1 year ago

Thanks for the update. From all the information I think there are two separate things:

  1. Normally, when you switch to a new track, Shairport Sync ("SPS") will close the DAC driver and reopen it very quickly afterwards. My guess is that the driver needs a little time to recover after being closed before it can make the device available again at "hw:1,1" so you get these odd error messages from the alsa library saying it can't find it. When you set "disable_standby" to "always", the DAC driver is opened only once -- when SPS starts up -- and is never reopened afterwards. When no audio is available to play, it plays silence. The purpose of this it to keep the driver open and stop the faint clicking you sometimes get when a driver closes or when the hardware goes into standby mode. But in this case it is also stops this reopening error by stopping reopening completely.

  2. I downloaded the sample album (nice!) and played it exhaustively on an intel 27" iMac running macOS Ventura 13.2 (22D49) and the Music app 1.3.3.2. I couldn't get it to misbehave, but I'll keep trying. There are lots of reports of problems with the Music app and AirPlay 2 (not SPS) that seem similar, so who knows if it's an Apple bug or an SPS bug!

eos1d3 commented 1 year ago

I have to clarify two things:

  1. alsa lib messages appeared mostly once at the very beginning (or a long time after I do not use it), not at the next track.
  2. Playing next track are mostly OK. Only ~20% chance may have no sound.
  3. Some albums (also .m4a files) do not have this issue.

I have used Airplay 2 since it was released and did not have any issue. I did suspect it is Monterey 12.6.3 or Music app 1.2.5.7. I will use Ventura to test again and inform you later.

Thanks a lot for help!

eos1d3 commented 1 year ago

Just upgraded to Ventura and Music app is also 1.3.3.2. The no sound issue is still there. But it is a lot less. Before it is around 20% of chance will get no sound, now it is around 5%.

So the only different from your is the sound device. Mine is Sound Blaster USB device. When I use Big Sur and old shairport-sync, I never found this issue.

I can try PI4 or without using USB device. May try these when I am free.

Anyway, thanks a lot for help!

mikebrady commented 1 year ago

Thanks for the updates. I guess it would be worth trying with the Pi's built-in DAC outputting to the audio jack. The audio quality will be poor and there will be a noisy start-up click, but it would help to (hopefully) eliminate the output device as a cause of the problem...

eos1d3 commented 1 year ago

Hi, I have a quick test with internal DAC (output to headphone). No sound problem is still there.

mikebrady commented 1 year ago

Super. That suggests that those alsa lib messages have nothing to do with the missing audio.

eos1d3 commented 1 year ago

Right. When I set disable_standby_mode to always, I never see error any more.

The problem occurs only when a song is playing and is interrupted by next song. If I let Music app play one by one, the problem never occurs.

You may check if there is improvement for this condition.

eos1d3 commented 1 year ago

I turn on both local speaker and airplay at the same time. If no sound occurs, local speaker does not have sound too. It seems Music app is problematic.

Screenshot 2023-02-09 at 11 55 02 PM
mikebrady commented 1 year ago

Thanks, yeah -- it's very frustrating, trying to debug this kind of problem 😕.

mikebrady commented 1 year ago

Okay, a race condition has been found. It was found on a slow CPU, but it just might be relevant to your problem -- certainly it's worth checking.

If you got a chance to pull the latest from the development branch and try it out, it would be appreciated. No rush, but your feedback would be useful. Please note that if you are moving to the development branch of Shairport Sync from the master branch, it's important to pull the latest NQPTP, switch to its development branch and build and install it -- the development version of Shairport Sync is not compatible with the main branch of NQPTP!

eos1d3 commented 1 year ago

Hi, I have just tested the development branch, update both NQPTP and shairport-sync with:

git clone https://github.com/mikebrady/shairport-sync.git
$ cd shairport-sync
$ git checkout development
$ autoreconf -fi
$ ./configure --sysconfdir=/etc --with-alsa \
    --with-soxr --with-avahi --with-ssl=openssl --with-systemd --with-airplay-2
$ make
# make install
git clone https://github.com/mikebrady/nqptp.git
$ cd nqptp
$ git checkout development
$ autoreconf -fi
$ ./configure --with-systemd-startup
$ make
# make install

The instructions for NQPTP says it is git checkout danger, but it danger does not exists. So I use git checkout development

The result shows no improvement at all. The no sound problem still exists. I have restarted PI3 two times before tests.

mikebrady commented 1 year ago

Thank you very much for trying it out -- the search must go on! The bug made itself known on a (very) slow CPU, so it was a long shot that it might be evident on a Pi 3. The references to the (obsolete) danger branch have been fixed, thanks.

eos1d3 commented 1 year ago

No problem for me. I can help with PI3. But I will try PI4 to confirm the issue.

mikebrady commented 1 year ago

Only if it’s convenient, thanks. My guess is it’ll be the same as the Pi 3.

eos1d3 commented 1 year ago

You are right! Just tested on PI4, the problem is exactly the same.

tazounet commented 1 year ago

Hello, I have the same issue with macOS 12.6.x and Music App (Airplay selected in Music App, not in System Preferences). HW is a PI4 with a HifiBerry DAC+. The issue is only with the Airplay 2 mode (I tried to switch back to AP1 and no issue).

ekozan commented 1 year ago

same probleme here on PI3on dev branch / Mac OS 12.0.1 (21A559)

Feb 17 20:05:03 airplay-salon shairport-sync:          0.000242000 "rtsp.c:2451"   No Content Plist. Content length: 0.
Feb 17 20:05:05 airplay-salon shairport-sync:          1.873261000 "rtp.c:1275" set_ptp_anchor_info: clock: 38f9d381d00d0008, rtptime: 3822174885, networktime: 3e0c187522f21, frame adjustment:  -0.495.
Feb 17 20:05:05 airplay-salon shairport-sync:          0.149237000 "rtsp.c:2449" Connection 1: POST /feedback Content-Length 0
Feb 17 20:05:05 airplay-salon shairport-sync:          0.007301000 "rtsp.c:2451"   Type: "CSeq", content: "56"
Feb 17 20:05:05 airplay-salon shairport-sync:          0.000568000 "rtsp.c:2451"   Type: "DACP-ID", content: "1C2ADD1FD8E503EF"
Feb 17 20:05:05 airplay-salon shairport-sync:          0.000211000 "rtsp.c:2451"   Type: "Active-Remote", content: "833488163"
Feb 17 20:05:05 airplay-salon shairport-sync:          0.000168000 "rtsp.c:2451"   Type: "User-Agent", content: "AirPlay/595.13.1"
Feb 17 20:05:05 airplay-salon shairport-sync:          0.000166000 "rtsp.c:2451"   No Content Plist. Content length: 0.

on normal branch I remember solve this problem by removing ipv6 but we cannot on dev because of binding bug on nqptp who complain about it :D

on phone :

Feb 17 20:24:05 airplay-salon shairport-sync:          1.003155000 "rtp.c:1275" set_ptp_anchor_info: clock: f4afe77d8ed60008, rtptime: 3753991904, networktime: 4e4de39f031e, frame adjustment:   0.213.
Feb 17 20:24:06 airplay-salon shairport-sync:          0.785141000 "rtsp.c:2449" Connection 7: POST /feedback Content-Length 0
Feb 17 20:24:06 airplay-salon shairport-sync:          0.008586000 "rtsp.c:2451"   Type: "CSeq", content: "263"
Feb 17 20:24:06 airplay-salon shairport-sync:          0.000428000 "rtsp.c:2451"   Type: "DACP-ID", content: "7DBC86796429F59F"
Feb 17 20:24:06 airplay-salon shairport-sync:          0.000338000 "rtsp.c:2451"   Type: "Active-Remote", content: "1459944182"
Feb 17 20:24:06 airplay-salon shairport-sync:          0.000176000 "rtsp.c:2451"   Type: "User-Agent", content: "AirPlay/665.13.1"
Feb 17 20:24:06 airplay-salon shairport-sync:          0.000401000 "rtsp.c:2451"   No Content Plist. Content length: 0.
Feb 17 20:24:07 airplay-salon shairport-sync:          1.173451000 "rtp.c:1275" set_ptp_anchor_info: clock: f4afe77d8ed60008, rtptime: 3754078696, networktime: 4e4e58ed4a18, frame adjustment:   0.367.
Feb 17 20:24:08 airplay-salon shairport-sync:          0.895382000 "rtsp.c:2449" Connection 7: POST /feedback Content-Length 0
Feb 17 20:24:08 airplay-salon shairport-sync:          0.012806000 "rtsp.c:2451"   Type: "CSeq", content: "264"
Feb 17 20:24:08 airplay-salon shairport-sync:          0.000567000 "rtsp.c:2451"   Type: "DACP-ID", content: "7DBC86796429F59F"
Feb 17 20:24:08 airplay-salon shairport-sync:          0.000201000 "rtsp.c:2451"   Type: "Active-Remote", content: "1459944182"
Feb 17 20:24:08 airplay-salon shairport-sync:          0.000169000 "rtsp.c:2451"   Type: "User-Agent", content: "AirPlay/665.13.1"
Feb 17 20:24:08 airplay-salon shairport-sync:          0.000467000 "rtsp.c:2451"   No Content Plist. Content length: 0.
mikebrady commented 1 year ago

Thanks for these updates!

mikebrady commented 1 year ago

Just FYI, Issue #1633 has been resolved -- a bug was identified and fixed. Again, it's not exactly the same as the issues you report here, but probably worth a try, at your leisure.

eos1d3 commented 1 year ago

Just reinstalled using development branch. This issue is still there. 😅

mikebrady commented 1 year ago

Just reinstalled using development branch. This issue is still there. 😅

Thanks!

mikebrady commented 1 year ago

I have a 12.6.3 installation now, but for the life of me, I can't get it to misbehave. Is there anything special about your networks, firewalls, anything like that?

eos1d3 commented 1 year ago

Hi, not all songs will create this issue. Please use the songs from my Google drive link. These songs are easy to produce this issue. Some other my music are hard to find it.

I use Ethernet without using WiFi, I do not think network has issue.

I do not turn on OS level firewall.

BTW, I have Synology nas. Its audio player run on browser and has interface to play my music collection. And I use it to play those problematic songs one by one for a few seconds, it never has issue like Music app.

@ekozan @tazounet Hi, what is your Mac? Intel Mac or M1/M2 Mac? Mine is Intel Mac and having the issue.

tazounet commented 1 year ago

Intel Mac and both the Mac & RPI4 are connected using Ethernet

mikebrady commented 1 year ago

Yeah, I’ve been using an Intel Mac, but it’s on Wi-Fi.

ekozan commented 1 year ago

Intel mac on my side

github-actions[bot] commented 1 year ago

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

eos1d3 commented 11 months ago

Hi, just updated to shairport-sync 4.3.2, with Music app 1.2.5.7, Monetary 12.7 (21G816). This issue seems gone. I keep playing the same album many many times and do not have any issue now.

tazounet commented 9 months ago

Hello, I confirm the issue seems fixed by shairport-sync 4.3.2 :) Thanks