pssc / ha-addon-squeezelite

Squeezelite Player Addon for Home Assistant, for use with a Logitech Media Server
GNU General Public License v3.0
7 stars 0 forks source link

Helicopter noise instead of music #1

Open Vinndimon opened 2 years ago

Vinndimon commented 2 years ago

Sometimes, randomly, Squeezelite loses the ability to play music. Instead of music it plays some strange "helicopter" noise. The decoder skips frames according to the log:

[23:46:54.206332] stream_init:454 init stream
[23:46:54.208194] output_init_alsa:933 init output
[23:46:54.208255] output_init_alsa:973 requested alsa_buffer: 40 alsa_period: 4 format: any mmap: 1
[23:46:54.220820] output_init_common:432 supported rates: 384000 352800 192000 176400 96000 88200 48000 44100 32000 24000 22500 16000 12000 11025 8000 
[23:46:54.220987] output_init_alsa:997 unable to lock memory: Cannot allocate memory
[23:46:54.221143] output_init_alsa:1005 glibc detected using mallopt
[23:46:54.223658] decode_init:153 init decode
[23:46:54.223658] output_thread:682 open output device: default
[23:46:54.223779] register_dsd:908 using dsd to decode dsf,dff
[23:46:54.223818] alsa_open:351 opening device at: 44100
[23:46:54.225942] alsa_open:422 opened device default using format: S32_LE sample rate: 44100 mmap: 0
[23:46:54.226012] alsa_open:513 buffer: 40 period: 4 -> buffer size: 1764 period size: 441
[23:46:55.017393] load_faad:633 loaded libfaad.so.2
[23:46:55.017445] register_faad:663 using faad to decode aac
[23:46:55.025044] load_vorbis:356 loaded libvorbisfile.so.3
[23:46:55.025097] register_vorbis:385 using vorbis to decode ogg
[23:46:55.025147] load_flac:304 loaded libFLAC.so.8
[23:46:55.025153] register_flac:332 using flac to decode ogf,flc
[23:46:55.025159] register_pcm:483 using pcm to decode aif,pcm
[23:46:55.032636] load_mad:394 loaded libmad.so.0
[23:46:55.032684] register_mad:423 using mad to decode mp3
[23:46:55.032856] discover_server:795 sending discovery
[23:46:55.064290] discover_server:806 got response from: 192.168.50.63:3483
[23:46:55.064403] slimproto:898 connecting to 192.168.50.63:3483
[23:46:55.065673] slimproto:937 connected
[23:46:55.065722] sendHELO:148 mac: d0:c8:d9:c4:1b:64
[23:46:55.065733] sendHELO:150 cap: Model=squeezelite,AccuratePlayPoints=1,HasDigitalOut=1,HasPolarityInversion=1,Balance=1,Firmware=v1.9.9-1386,ModelName=SqueezeLite-HA-Addon,MaxSampleRate=384000,dsf,dff,aac,ogg,ogf,flc,aif,pcm,mp3

[23:49:23.447770] decode_flush:236 decode flush
[23:49:23.447820] output_flush:445 flush output buffer
[23:49:26.567683] codec_open:264 codec open: 'm'
[23:49:26.567819] connect_socket:164 connecting to 192.168.50.63:9000
[23:49:26.570450] stream_sock:600 header: GET /stream.mp3?player=d0:c8:d9:c4:1b:64 HTTP/1.0

[23:49:26.640158] stream_thread:331 headers: len: 491
HTTP/1.1 200 OK
Server: Logitech Media Server (8.2.0 - 1627922070)
Connection: close
Content-Type: audio/mpeg
Set-Cookie: Squeezebox-albumView=; path=/
Set-Cookie: Squeezebox-expandPlayerControl=true; path=/
Set-Cookie: Squeezebox-expanded-MY_MUSIC=0; path=/
Set-Cookie: Squeezebox-expanded-FAVORITES=0; path=/
Set-Cookie: Squeezebox-expanded-PLUGINS=0; path=/
Set-Cookie: Squeezebox-expanded-PLUGIN_MY_APPS_MODULE_NAME=0; path=/
Set-Cookie: Squeezebox-expanded-RADIO=0; path=/

[23:49:26.686368] mad_decode:247 setting track_start
[23:49:26.686416] _checkfade:294 fade mode: 2 duration: 0 track-start
[23:49:26.686424] _checkfade:304 fade IN: 0 frames
[23:49:26.866154] _output_frames:153 track start sample rate: 44100 replay_gain: 0
[23:49:26.876382] _output_frames:181 fade start reached
[23:49:26.876432] _output_frames:214 fade complete
[23:49:28.767843] _output_frames:73 skip 26945 of 26945 frames
[23:49:30.776225] _output_frames:73 skip 79468 of 79468 frames
[23:49:33.011716] _output_frames:73 skip 94241 of 94241 frames
[23:49:35.029718] _output_frames:73 skip 76513 of 76513 frames
[23:49:37.050504] _output_frames:73 skip 88641 of 88641 frames
[23:49:39.071898] _output_frames:73 skip 72015 of 72015 frames
[23:49:41.072472] _output_frames:73 skip 80570 of 80570 frames
[23:49:43.052227] _output_frames:73 skip 79027 of 79027 frames

The only thing that fixes it is complete reboot of the device. Restarting the service does not help.

pssc commented 2 years ago

Hi can you provide more information on your setup , Hardware, and are you using pulseaduio or direct Audio HW Access?

Dididam commented 2 years ago

I have the same behaviour. Hass.io on raspberry pi 3. Tried with hifiberry and usb soundcard. How do I find out which audio is used? Here’s the log from the system audio log D: [alsa-sink-HiFiBerry DAC+ HiFi pcm512x-hifi-0] source.c: Processing rewind... D: [alsa-sink-HiFiBerry DAC+ HiFi pcm512x-hifi-0] sink.c: alsa_output.platform-soc_sound.stereo-fallback: Found underrun 896 bytes ago (2664 bytes ahead in playback buffer) D: [alsa-sink-HiFiBerry DAC+ HiFi pcm512x-hifi-0] sink.c: alsa_output.platform-soc_sound.stereo-fallback: Found underrun 896 bytes ago (2600 bytes ahead in playback buffer) D: [alsa-sink-HiFiBerry DAC+ HiFi pcm512x-hifi-0] protocol-native.c: Requesting rewind due to end of underrun. D: [alsa-sink-HiFiBerry DAC+ HiFi pcm512x-hifi-0] alsa-sink.c: Requested to rewind 896 bytes. D: [alsa-sink-HiFiBerry DAC+ HiFi pcm512x-hifi-0] alsa-sink.c: Limited to 896 bytes. D: [alsa-sink-HiFiBerry DAC+ HiFi pcm512x-hifi-0] alsa-sink.c: before: 224 D: [alsa-sink-HiFiBerry DAC+ HiFi pcm512x-hifi-0] alsa-sink.c: after: 224 D: [alsa-sink-HiFiBerry DAC+ HiFi pcm512x-hifi-0] alsa-sink.c: Rewound 896 bytes. D: [alsa-sink-HiFiBerry DAC+ HiFi pcm512x-hifi-0] sink.c: Processing rewind... D: [alsa-sink-HiFiBerry DAC+ HiFi pcm512x-hifi-0] sink-input.c: Have to rewind 896 bytes on render memblockq. D: [alsa-sink-HiFiBerry DAC+ HiFi pcm512x-hifi-0] source.c: Processing rewind... D: [alsa-sink-HiFiBerry DAC+ HiFi pcm512x-hifi-0] alsa-sink.c: Wakeup from ALSA! D: [alsa-sink-HiFiBerry DAC+ HiFi pcm512x-hifi-0] alsa-sink.c: Wakeup from ALSA! D: [alsa-sink-HiFiBerry DAC+ HiFi pcm512x-hifi-0] alsa-sink.c: Wakeup from ALSA!

pssc commented 2 years ago

@Dididam you can check in the addon log at boot what audio device its opening it also lists what is available, probably the default, in which case this is straining through pulseaudio as well, this may be to much for a Pi3 and the usb is just a bit flaky under load .

Are you aarch64 or armv7?

Is this just happening randomly? what else is the Pi doing?

Also you could try killing and restarting the HA PA container and then addon to see if this fixes it,

Also setting the cards up for direct access via squeezelite is probably worthwhile,

I have a Pi3B+ and a usb sound card I will see if I can replicate under the same arch...

Dididam commented 2 years ago

It’s aarch64 OS 6.5 The audio output list: Null Jack Pulse Default - default Alsa output ( home assistant pulseaudio sound server) Yesterday I noticed that one radio stream is working the other is producing jitter. But I don’t know how to find which stream tune in is using. Local mp3 is also producing jitter.

Is there a guide howto set up direct access?

pssc commented 2 years ago

@Dididam ok not seeing the sound card in that output is it running in Protection mode disabled.?

I don't have a guide yet so lets start here ;-)

This may well cause issues with inbuilt HA Audio system.

Run in Protection mode disabled. Run and look in the logs of the addon-on at the audio output list. note the name of the output you want to use on the config tab "Select Show unused optional configuration options" for output insert the name there.

ghost commented 2 years ago

@pssc What is full permission mode? Is equal to disabling the protection mode? Then I get the output for the following sound devices:

_Output devices: null - Discard all samples (playback) or generate zero samples (capture) jack - JACK Audio Connection Kit pulse - PulseAudio Sound Server default - Default ALSA Output (Home Assistant PulseAudio Sound Server) sysdefault:CARD=sndrpihifiberry - snd_rpi_hifiberry_dacplus, HiFiBerry DAC+ HiFi pcm512x-hifi-0 - Default Audio Device dmix:CARD=sndrpihifiberry,DEV=0 - snd_rpi_hifiberry_dacplus, HiFiBerry DAC+ HiFi pcm512x-hifi-0 - Direct sample mixing device dsnoop:CARD=sndrpihifiberry,DEV=0 - snd_rpi_hifiberry_dacplus, HiFiBerry DAC+ HiFi pcm512x-hifi-0 - Direct sample snooping device hw:CARD=sndrpihifiberry,DEV=0 - snd_rpi_hifiberry_dacplus, HiFiBerry DAC+ HiFi pcm512x-hifi-0 - Direct hardware device without any conversions plughw:CARD=sndrpihifiberry,DEV=0 - snd_rpi_hifiberry_dacplus, HiFiBerry DAC+ HiFi pcm512x-hifi-0 - Hardware device with all software conversions usbstream:CARD=sndrpihifiberry - snd_rpi_hifiberrydacplus - USB Stream Output

But what is the part of the sound device name I place as output in the config? I didn't manage to get it to open the output device:

_[14:21:21] INFO: squeezelite -M SqueezeLite-HA-Addon -N /data/name -o hw:CARD=sndrpihifiberry -m 2d:35:1b:6e:7b:5c -d all=debug [14:21:21.117660] stream_init:454 init stream [14:21:21.118231] stream_init:455 streambuf size: 2097152 [14:21:21.126978] output_init_alsa:933 init output [14:21:21.127105] output_init_alsa:973 requested alsa_buffer: 40 alsa_period: 4 format: any mmap: 1 [14:21:21.127166] output_init_common:360 outputbuf size: 3528000 [14:21:21.127404] output_init_common:384 idle timeout: 0 [14:21:21.133988] ALSA snd_pcm_hw_open:1711 open '/dev/snd/pcmC0D0p' failed (-16) [14:21:21.134152] test_open:281 playback open error: Device or resource busy [14:21:21.134193] output_initcommon:401 unable to open output device: hw:CARD=sndrpihifiberry [14:21:21] INFO: Starting the Squeezelite options processing...

pssc commented 2 years ago

@fovk500 yes thats right well at a guess HA audio may have the device open, try sysdefault:CARD=sndrpihifiberry what Pi are you using?

pssc commented 2 years ago

@fovk500 @Dididam anything in dmesg logs? this is all classic Pi I can't keep up behaviour

cat /proc/asound/**CARDNAME**/pcm0p/sub0/hw_params may be usefull

We can massage the alsa buffering behaviour with -a 16384:1024:: to adjust the buffer and period size.

pssc commented 2 years ago

looking upstream other than the report https://github.com/ralph-irving/squeezelite/issues/145 could be similar and this is also up streamed here at https://github.com/ralph-irving/squeezelite/issues/149 but the PA build had real issues during my testing. We are pinned at commit https://github.com/ralph-irving/squeezelite/commit/556de5689d27b4440adbfeb3c3012da02dbf438e atm, and due to HA needs we are pretty much tied to a self build

Dididam commented 2 years ago

@pssc this is getting far beyond my skills. I‘ll stick around and try again once there’s an update. Anyways appreciate your efforts.

pssc commented 2 years ago

New version out please report back @Dididam @Vinndimon @fovk500 this will use the PA build by default and swap to alsa if you specify and output device

Vinndimon commented 2 years ago

I am still having this problem with the new version. Both with OS protection on and off. My system is Intel NUC with Ubuntu 20.04 and HA Supervised. Here is the full log:

[s6-init] making user provided files available at /var/run/s6/etc...exited 0.
[s6-init] ensuring user provided files have correct perms...exited 0.
[fix-attrs.d] applying ownership & permissions fixes...
[fix-attrs.d] done.
[cont-init.d] executing container initialization scripts...
[cont-init.d] 00-banner.sh: executing... 

-----------------------------------------------------------
 Add-on: Squeezelite
 Squeezelite player for Logitech Media Server on home assistant
-----------------------------------------------------------
 Add-on version: 0.10
 You are running the latest version of this add-on.
 System: Ubuntu 20.04.3 LTS  (amd64 / generic-x86-64)
 Home Assistant Core: 2021.9.7
 Home Assistant Supervisor: 2021.10.6
-----------------------------------------------------------
 Please, share the above information when looking for help
 or support in, e.g., GitHub, forums or the Discord chat.
-----------------------------------------------------------
[cont-init.d] 00-banner.sh: exited 0.
[cont-init.d] 01-log-level.sh: executing... 
[cont-init.d] 01-log-level.sh: exited 0.
[cont-init.d] done.
[services.d] starting services
[services.d] done.
[14:35:55] INFO: Starting the Squeezelite options processing...
[14:35:55] INFO: Using Squeezelite alsa version
[14:35:56] INFO: Squeezelite possible outputs...
Output devices:
  null                           - Discard all samples (playback) or generate zero samples (capture)
  jack                           - JACK Audio Connection Kit
  pulse                          - PulseAudio Sound Server
  default                        - Default ALSA Output (Home Assistant PulseAudio Sound Server)

[14:35:56] INFO: squeezelite -M SqueezeLite-HA-Addon -N /data/name -o pulse -m 6b:b6:96:31:7a:15 -d all=info
[14:35:56.030269] stream_init:454 init stream
[14:35:56.032339] output_init_alsa:936 init output
[14:35:56.032417] output_init_alsa:976 requested alsa_buffer: 40 alsa_period: 4 format: any mmap: 1
[14:35:56.046712] output_init_common:432 supported rates: 384000 352800 192000 176400 96000 88200 48000 44100 32000 24000 22500 16000 12000 11025 8000 
[14:35:56.046756] output_init_alsa:1000 unable to lock memory: Cannot allocate memory
[14:35:56.046767] output_init_alsa:1008 glibc detected using mallopt
[14:35:56.048962] decode_init:153 init decode
[14:35:56.049072] register_dsd:908 using dsd to decode dsf,dff
[14:35:56.049072] output_thread:685 open output device: pulse
[14:35:56.049144] alsa_open:354 opening device at: 44100
[14:35:56.049422] load_faad:633 loaded libfaad.so.2
[14:35:56.049456] register_faad:663 using faad to decode aac
[14:35:56.049682] load_vorbis:356 loaded libvorbisfile.so.3
[14:35:56.049703] register_vorbis:385 using vorbis to decode ogg
[14:35:56.049903] load_flac:308 loaded libFLAC.so.8
[14:35:56.049925] register_flac:336 using flac to decode ogf,flc
[14:35:56.049933] register_pcm:483 using pcm to decode aif,pcm
[14:35:56.050206] load_mad:394 loaded libmad.so.0
[14:35:56.050230] register_mad:423 using mad to decode mp3
[14:35:56.050376] discover_server:795 sending discovery
[14:35:56.051734] alsa_open:425 opened device pulse using format: S32_LE sample rate: 44100 mmap: 0
[14:35:56.051790] alsa_open:516 buffer: 40 period: 4 -> buffer size: 1764 period size: 441
[14:35:56.127337] discover_server:806 got response from: 192.168.50.63:3483
[14:35:56.127505] slimproto:869 retrieved name Гостиная from /data/name
[14:35:56.127548] slimproto:898 connecting to 192.168.50.63:3483
[14:35:56.128999] slimproto:937 connected
[14:35:56.129046] sendHELO:148 mac: 6b:b6:96:31:7a:15
[14:35:56.129062] sendHELO:150 cap: Model=squeezelite,AccuratePlayPoints=1,HasDigitalOut=1,HasPolarityInversion=1,Balance=1,Firmware=v1.9.9-1391,ModelName=SqueezeLite-HA-Addon,MaxSampleRate=384000,dsf,dff,aac,ogg,ogf,flc,aif,pcm,mp3
[14:35:56.137779] decode_flush:236 decode flush
[14:35:56.137848] output_flush:445 flush output buffer
[14:35:56.139246] decode_flush:236 decode flush
[14:35:56.139317] output_flush:445 flush output buffer
[14:36:11.190155] decode_flush:236 decode flush
[14:36:11.190200] output_flush:445 flush output buffer
[14:36:11.808635] codec_open:264 codec open: 'f'
[14:36:11.808900] connect_socket:164 connecting to 192.168.50.63:9000
[14:36:11.810653] stream_sock:600 header: GET /stream.mp3?player=6b:b6:96:31:7a:15 HTTP/1.0

[14:36:11.862631] stream_thread:331 headers: len: 493
HTTP/1.1 200 OK
Server: Logitech Media Server (8.2.0 - 1627922070)
Connection: close
Content-Type: audio/x-flac
Set-Cookie: Squeezebox-albumView=; path=/
Set-Cookie: Squeezebox-expandPlayerControl=true; path=/
Set-Cookie: Squeezebox-expanded-MY_MUSIC=0; path=/
Set-Cookie: Squeezebox-expanded-FAVORITES=0; path=/
Set-Cookie: Squeezebox-expanded-PLUGINS=0; path=/
Set-Cookie: Squeezebox-expanded-PLUGIN_MY_APPS_MODULE_NAME=0; path=/
Set-Cookie: Squeezebox-expanded-RADIO=0; path=/

[14:36:12.076204] write_cb:145 setting track_start
[14:36:12.157183] _output_frames:65 start buffer frames: 200704
[14:36:12.157298] _output_frames:153 track start sample rate: 44100 replay_gain: 0
[14:36:14.703254] decode_flush:236 decode flush
[14:36:14.703479] output_flush:445 flush output buffer
pssc commented 2 years ago

@Vinndimon remove your output device and it will switch to the pulse audio build

Vinndimon commented 2 years ago

@pssc how do I remove the output device? Do you mean removing the wire from the audio jack? I does not help.

pssc commented 2 years ago

In the config options

On Sat, 30 Oct 2021, 10:03 Vinndimon, @.***> wrote:

@pssc https://github.com/pssc how do I remove the output device? Do you mean removing the wire from the audio jack? I does not help.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/pssc/ha-addon-squeezelite/issues/1#issuecomment-955177094, or unsubscribe https://github.com/notifications/unsubscribe-auth/AANORYPX2GN6EYKP46E7HPLUJOYHHANCNFSM5FAQWYBA . Triage notifications on the go with GitHub Mobile for iOS https://apps.apple.com/app/apple-store/id1477376905?ct=notification-email&mt=8&pt=524675 or Android https://play.google.com/store/apps/details?id=com.github.android&referrer=utm_campaign%3Dnotification-email%26utm_medium%3Demail%26utm_source%3Dgithub.

Vinndimon commented 2 years ago

@pssc i've tried different options. The one with the clean config too. With no dice.

pssc commented 2 years ago

@Vinndimon Try in the terminal & web addon speaker-test -t wav -c 2 and see what that sounds like

pssc commented 2 years ago

New version 0.11 with some fixes for the default pulse audio config.

pssc commented 2 years ago

I have been able to verify usb playback on adm64 and Pi3/Pi4 using PA.

Vinndimon commented 2 years ago

@pssc audio test runs normally. At least, after the reboot. I'll run a long-term test and come back if the addon breaks again.

Vinndimon commented 2 years ago

@pssc strangely, the new version works with sync very badly. It was able to sync with another player only after 10-20 seconds of playback. It was accompanied by stuttering. This problem becomes present each time I switch the track.

Dididam commented 2 years ago

Today I updated hassio and the add on. So far no helicopter. Regarding Syncing with another player I experience that after each track it takes some while until they are in sync again. It seems that the lms plugin starts later after track changes.

pssc commented 2 years ago

@Vinndimon, @Dididam this might be a feature of the direct Pulse Audio support, I will see if I can replicate. Are you using the Pulse Audio build(its in the logs) if so please try the alsa build (config option) and report back

pssc commented 2 years ago

So I was able to replicate using pulse audio and for me no issues occur with the alasa build via the default(pulse) target, so this is probably a bug in the pulse code in squeezelite, would like to here if people are still getting problems with the alsa build

Dididam commented 2 years ago

Setting the option to alsa build does the trick: synch between players is smooth and no helicopter.

pssc commented 2 years ago

@Vinndimon I have just pushed a version 0.12 with more tweaks for scheduling and memory locking in the alsa build would be interested if this one fixes your issues. (make sure you force alsa build).

Vinndimon commented 2 years ago

@pssc unfortunately, 0.12 (alsa) started with the helicopter noise right after the device reboot. However, the PA build works fine. At least for now. We'll see the final results in a day or so.

Vinndimon commented 2 years ago

UPD: the PA build has slight sync issues. Unfortunately.

xxxserxxx commented 1 year ago

Just to note: this is not an HA issue -- it's a pure squeezelite issue. I have squeezelite running on a small ARM computer who's only job is to be a receiver for LMS streaming music, and output it to an amp. There's no Home Assistant anywhere in this. I frequently get this (almost daily, when I first play music), and must restart squeezelite to restore it to proper functioning.

pssc commented 1 year ago

@xxxserxxx that is most useful, is that with alsa or pluse? is that a Pi or something else?

xxxserxxx commented 1 year ago

It's an odroid; I have two, connected to two different amps. They both have this problem. Both are (the now discontinued) ODROID U3 (Cortex-A9 Quad Core ARM, 2GB RAM), running the Ubuntu that came with them (which, with upgrades, is now bionic), and both are using ALSA.

The behavior is relatively new; I've posted more information in response to a related ticket on the squeezelite repo. It used to happen rarely, and with some recent update it's started happening almost daily. It seems to happen only when the system is inactive for several hours. I suspect it has something to do with something (ALSA, squeezelite, the device driver) going inactive and maybe getting swapped out of memory, or maybe the sound device being put to sleep by the OS; it never happens while music is more-or-less constantly playing, only after a period of inactivity. Or, maybe it has nothing to do with the audio device, and is a result of some loss of synchronization betwene the LMS server and the remote squeezelite -- again, due to no traffic over a longer period of time.

sanyadez commented 10 months ago

Maybe for someone will help my setup: Chuwi Larkbox X ( n100 version ) + Proxmox 8.0.4 as main OS + Home Assistant Operating System in the VM + sound card path through

Build: pulse Output: alsa_output.pci-0000_00_10.0.analog-stereo

It works. Any another setup gives the same helicopter noise