Skip to content
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

Helicopter noise instead of music #1

Open
Vinndimon opened this issue Sep 29, 2021 · 32 comments
Open

Helicopter noise instead of music #1

Vinndimon opened this issue Sep 29, 2021 · 32 comments
Assignees
Labels
bug Something isn't working question Further information is requested

Comments

@Vinndimon
Copy link

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 pssc self-assigned this Oct 18, 2021
@pssc pssc added the question Further information is requested label Oct 18, 2021
@pssc
Copy link
Owner

pssc commented Oct 18, 2021

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

@Dididam
Copy link

Dididam commented Oct 21, 2021

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
Copy link
Owner

pssc commented Oct 21, 2021

@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...

@pssc pssc added the bug Something isn't working label Oct 21, 2021
@Dididam
Copy link

Dididam commented Oct 22, 2021

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
Copy link
Owner

pssc commented Oct 24, 2021

@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
Copy link

ghost commented Oct 25, 2021

@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_hifiberry_dacplus - 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_init_common:401 unable to open output device: hw:CARD=sndrpihifiberry
[14:21:21] INFO: Starting the Squeezelite options processing...

@pssc
Copy link
Owner

pssc commented Oct 25, 2021

@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
Copy link
Owner

pssc commented Oct 25, 2021

@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
Copy link
Owner

pssc commented Oct 25, 2021

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

@Dididam
Copy link

Dididam commented Oct 25, 2021

@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
Copy link
Owner

pssc commented Oct 27, 2021

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
Copy link
Author

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
Copy link
Owner

pssc commented Oct 29, 2021

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

@Vinndimon
Copy link
Author

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

@pssc
Copy link
Owner

pssc commented Oct 30, 2021 via email

@Vinndimon
Copy link
Author

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

@pssc
Copy link
Owner

pssc commented Oct 31, 2021

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

@pssc
Copy link
Owner

pssc commented Nov 2, 2021

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

@pssc
Copy link
Owner

pssc commented Nov 3, 2021

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

@Vinndimon
Copy link
Author

@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
Copy link
Author

@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
Copy link

Dididam commented Nov 3, 2021

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
Copy link
Owner

pssc commented Nov 3, 2021

@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
Copy link
Owner

pssc commented Nov 4, 2021

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
Copy link

Dididam commented Nov 4, 2021

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

@pssc
Copy link
Owner

pssc commented Nov 10, 2021

@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
Copy link
Author

Vinndimon commented Nov 11, 2021

@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
Copy link
Author

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

@xxxserxxx
Copy link

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
Copy link
Owner

pssc commented Feb 12, 2023

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

@xxxserxxx
Copy link

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
Copy link

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

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working question Further information is requested
Projects
None yet
Development

No branches or pull requests

5 participants