Marcello T

Forum Replies Created

Viewing 5 posts - 1 through 5 (of 5 total)
  • Back to forum
    Posted in: Allo USB Bundle
  • Marcello T premium
    6. Juli 2021 at 11:35 #51414

    Hi Mario,

    it would be possible that I’ve stabilized the multiroom architecture – more than 24 hours without interruptions or audio stops and all the players are perfectly in sync.

    After some researches (like https://www.alsa-project.org/wiki/FramesPeriods) and following you suggestions, I understood that the problem was on ALSA buffer that got empty since it was not filled at proper speed.
    I modified the Squeezelite startup params, in particular the „ALSA Parameters“ changing the output buffer with „-a 180:4::“ – increasing the buffer size to 180ms keeping the period count at 4 seems that solved my problems – in the debug info this config is confirmed (1000ms/180ms=5,55 -> 44100 Hz/5,5 = 7936 bytes of buffer size and the period size is 1/4th = 1984 bytes as in the debug log):

    #### SQUEEZELITE VERSION ####
    Squeezelite Max2Play v1.0.3 based on v1.8.7-999, Copyright 2012-2015 Adrian Smith, 2015-2017 Ralph Irving.

    #### SQUEEZELITE BUILDOPTIONS ####
    Build options: LINUX ALSA EVENTFD RESAMPLE FFMPEG VISEXPORT IR GPIO DSD CONTROLSBS ALSASYNC BLUETOOTHSYNC

    #### AUDIOPLAYER CONFIG ####
    ### Configuration of Audioplayers
    SQUEEZELITE_PARAMETER=-o plughw:CARD=Headphones,DEV=0 -a 180:4:: -v
    SQUEEZESLAVE_PARAMETER=-n plugequal
    SHAIRPORT_PARAMETER=-d pulse
    USE_USB_DAC=0
    USE_EQUALIZER=0
    SYSTEM_USER=pi
    GMEDIARENDERER_ALSA_DEVICE=hw:CARD=Headphones,DEV=0
    BLUEALSA_PLAY_AUDIOCARD=hw:0,0

    #### SQUEEZELITE -l ####
    Output devices:
    null – Discard all samples (playback) or generate zero samples (capture)
    jack – JACK Audio Connection Kit
    pulse – PulseAudio Sound Server
    equal
    plugequal – Equalizer for plughw:0,0
    bluetooth – Your Bluetooth device 40:EF:4C:FF:03:22
    default:CARD=b1 – bcm2835 HDMI 1, bcm2835 HDMI 1 – Default Audio Device
    sysdefault:CARD=b1 – bcm2835 HDMI 1, bcm2835 HDMI 1 – Default Audio Device
    dmix:CARD=b1,DEV=0 – bcm2835 HDMI 1, bcm2835 HDMI 1 – Direct sample mixing device
    dsnoop:CARD=b1,DEV=0 – bcm2835 HDMI 1, bcm2835 HDMI 1 – Direct sample snooping device
    hw:CARD=b1,DEV=0 – bcm2835 HDMI 1, bcm2835 HDMI 1 – Direct hardware device without any conversions
    plughw:CARD=b1,DEV=0 – bcm2835 HDMI 1, bcm2835 HDMI 1 – Hardware device with all software conversions
    usbstream:CARD=b1 – bcm2835 HDMI 1 – USB Stream Output
    default:CARD=Headphones – bcm2835 Headphones, bcm2835 Headphones – Default Audio Device
    sysdefault:CARD=Headphones – bcm2835 Headphones, bcm2835 Headphones – Default Audio Device
    dmix:CARD=Headphones,DEV=0 – bcm2835 Headphones, bcm2835 Headphones – Direct sample mixing device
    dsnoop:CARD=Headphones,DEV=0 – bcm2835 Headphones, bcm2835 Headphones – Direct sample snooping device
    hw:CARD=Headphones,DEV=0 – bcm2835 Headphones, bcm2835 Headphones – Direct hardware device without any conversions
    plughw:CARD=Headphones,DEV=0 – bcm2835 Headphones, bcm2835 Headphones – Hardware device with all software conversions
    usbstream:CARD=Headphones – bcm2835 Headphones – USB Stream Output

    #### SHAIRPORT (SYNC) VERSION ####
    3.3.1-OpenSSL-Avahi-ALSA-soxr-sysconfdir:/usr/local/etc

    #### OUTPUT SOUND DETAILS CARD 0 ####
    closed

    #### OUTPUT SOUND DETAILS CARD 1 ####
    access: MMAP_INTERLEAVED
    format: S16_LE
    subformat: STD
    channels: 2
    rate: 44100 (44100/1)
    period_size: 1984
    buffer_size: 7936

    #### SOUNDDEVICES IN USE ####
    USER PID ACCESS COMMAND
    /dev/snd/controlC0: root 342 f…. alsactl
    pi 3140 F…. pulseaudio
    /dev/snd/controlC1: root 342 f…. alsactl
    /dev/snd/pcmC1D0p: pi 2997 F…m squeezelite

    Thanks for the support
    Regards

    Marcello T premium
    5. Juli 2021 at 11:54 #51410

    Hi Mario,

    I need some help to understand how the buffers works.
    If I change these parameters in some combinations, Squeezelite does not start – a combination that works is 180:4:: but increasing too much cause players to not play at all. For instance 160:8:: does not works.

    From the help is not clear how to distinguish between ms or bytes and how buffers are used to setup properly the params (with 80:4:: does it means the buffer is 80×4? 80 is ms or bytes? what happens if using more buffers? better to increase buffers or size, how to choose?)
    I think that there should be some standard configs (or max supported) for the standard pi hardware, and I have not to guess.

    Anyway to understand more about my problem I moved the Server from the Controller (RPi3+ in living room, closest to the main router) to the ClientOne on the 2nd floor (second Rpi3+), the farest client – the player on the controller is working as usual while the other two players continue to hang, even that one hosting the server (!) and killing pulseaudio service unlock the audio.
    Everything is working on cable LAN, not WiFi.

    So:
    – even with the server on the same client with standard audio (headphone) the player hangs – need to kill pulseaudio to restart
    – with crontab killing pulseaudio the audio is working but is out of sync
    – tryed to disable pulseaudio service (systemctl –user stop pulseaudio.socket pulseaudio.service) but the audio still hangs and in this case I have nothing to kill… so the problem could be on ALSA layer since is the basic hardware control software
    – killing pulseaudio should have some other effects to unlock the audio sync, but I’m pretty confident that is not pulseaudio the problem

    – the only combination that is not experiencing problems is the streaming to bluetooth speaker – I see that in this case the player uses bluealsa, but apart this I do not know if bluealsa bypass the standard pulseaudio->alsa combination
    – as a confirmation, if I disable all the player or exclude them from the synch group except the player streaming on bluetooth speaker with the server on any of the Rpi3+ (i miss only a test on Rpi2) everything works perfectly

    – Changing params on Server side does not make any positive effects:
    – increased the players latency
    – increased the radio timeouts
    – Used even the „local caching“ option, that in theory should write locally a buffer before streaming

    It should be unlikely I’m the only one experiencing problems with standard hardware… is there any specific set of configs to adopt?
    The last test I’m going to do is to use a bluetooth speaker with the plugin on the players that continue to hang.

    If I’ll get a continuos playing it will be a final confirmation that the problem is the standard audio.

    Many thanks
    Regards
    Marcello

    Marcello T premium
    28. Juni 2021 at 19:57 #51369

    Hi Mario,

    up to now I made a progress using crontab to kill pulseaudio every 20 mins. At least the players are working.
    Of course is a workaround but I’m not able to understand (yet) if the problem is pulse audio or what.

    I’m going crazy trying to understand why the reason is pulseaudio, since I told to squeezelite to use the direct HW. The expectation would be that squeezelite would use the ALSA driver skipping pulseaudio.
    So I’m wondering if the cause could be an interference with pulseaudio that hangs because found ALSA occupied by squeezelite and locks the audio in such a way. Infact killing periodically pulseaudio avoid the issue or makes the music playing again on the hanged player.
    Worst thing is that if pulseaudio keeps hanged for a while, the LMS remove the player from the group for timeout and I need to reboot it.

    I’m not using any special audio and I’m not sure if continuing with max2Play and hifi cards to expand the system.
    Not clear if the problem it’s me or the product 🙂

    Now I’m playing with server logs… there are 84 components that can be logged under „server settings->Advanced->Logging (or recording)“ – mostly on „error“ level by def, so they do not log except in case of errors.
    I changed to „debug“ level the network.protocol.slimproto and starting logging informations on a sort of keep alive of the players and other info.

    I got some elements, that I’ve not correlated to pulseaudio yet since I miss other logs for the time being, that makes me thinking to a sort of „buffer underrun“ problem – just speculating since without a guide to the parameter is quite complicated to guess the meaning of the logs, but the parameter „output_fulness“ dropped down suddenly in the same moment of audio stop, reported -1 for a while and then rising again after 32/33 secs (b8:27:eb:bf:93:3d is the MAC addr of Rpi2 player) :

    [21-06-28 15:36:22.3549] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=507280, elapsed=7349.181
    [21-06-28 15:36:23.3576] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=147416, elapsed=7350.183
    [21-06-28 15:36:23.8701] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMo: fullness=1379, output_fullness=-1, elapsed=7350.642
    [21-06-28 15:36:23.8774] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMp: fullness=1379, output_fullness=-1, elapsed=7350.642
    [21-06-28 15:36:23.9772] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.661
    [21-06-28 15:36:24.0619] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.707
    [21-06-28 15:36:24.2768] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.641
    [21-06-28 15:36:24.5852] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.649
    [21-06-28 15:36:24.8853] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.665
    [21-06-28 15:36:25.1823] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.657
    [21-06-28 15:36:25.4845] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.658
    [21-06-28 15:36:25.7886] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.643
    [21-06-28 15:36:26.0889] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.643
    [21-06-28 15:36:26.3952] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.665
    [21-06-28 15:36:26.6963] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.667
    [21-06-28 15:36:26.9929] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.645
    [21-06-28 15:36:27.2946] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.628
    [21-06-28 15:36:27.6031] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.631
    [21-06-28 15:36:27.9088] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.621
    [21-06-28 15:36:28.2010] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.633
    [21-06-28 15:36:28.5495] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.663
    [21-06-28 15:36:28.8539] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.660
    [21-06-28 15:36:29.0307] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.637
    [21-06-28 15:36:29.1477] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.642
    [21-06-28 15:36:29.4534] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.622
    [21-06-28 15:36:29.7579] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.621
    [21-06-28 15:36:30.0589] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.660
    [21-06-28 15:36:30.3576] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.660
    [21-06-28 15:36:30.6594] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.640
    [21-06-28 15:36:30.9630] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.643
    [21-06-28 15:36:31.2713] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.632
    [21-06-28 15:36:31.5900] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.623
    [21-06-28 15:36:31.8637] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.667
    [21-06-28 15:36:32.1775] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.655
    [21-06-28 15:36:32.4738] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.657
    [21-06-28 15:36:32.7749] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.638
    [21-06-28 15:36:33.0784] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.642
    [21-06-28 15:36:33.3771] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.660
    [21-06-28 15:36:33.6812] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.642
    [21-06-28 15:36:33.9759] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.629
    [21-06-28 15:36:34.0390] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.675
    [21-06-28 15:36:34.2796] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.632
    [21-06-28 15:36:34.5913] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.641
    [21-06-28 15:36:34.8827] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.652
    [21-06-28 15:36:35.1804] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.634
    [21-06-28 15:36:35.4845] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.638
    [21-06-28 15:36:35.7883] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.618
    [21-06-28 15:36:36.0863] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.637
    [21-06-28 15:36:36.3882] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.661
    [21-06-28 15:36:36.6881] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.640
    [21-06-28 15:36:36.9859] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.640
    [21-06-28 15:36:37.2911] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.661
    [21-06-28 15:36:37.5905] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.662
    [21-06-28 15:36:37.8963] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.649
    [21-06-28 15:36:38.1997] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.634
    [21-06-28 15:36:38.4974] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.651
    [21-06-28 15:36:38.8219] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.637
    [21-06-28 15:36:39.0357] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.666
    [21-06-28 15:36:39.1271] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.755
    [21-06-28 15:36:39.4190] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.660
    [21-06-28 15:36:39.7187] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.642
    [21-06-28 15:36:40.0214] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.643
    [21-06-28 15:36:40.3217] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.622
    [21-06-28 15:36:40.6232] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.644
    [21-06-28 15:36:40.9219] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.666
    [21-06-28 15:36:41.2339] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.638
    [21-06-28 15:36:41.5285] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.651
    [21-06-28 15:36:41.8436] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.624
    [21-06-28 15:36:42.1412] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.639
    [21-06-28 15:36:42.4409] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.661
    [21-06-28 15:36:42.7461] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.645
    [21-06-28 15:36:43.0437] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.645
    [21-06-28 15:36:43.3509] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.622
    [21-06-28 15:36:43.6507] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.641
    [21-06-28 15:36:43.9564] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.663
    [21-06-28 15:36:44.0331] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.729
    [21-06-28 15:36:44.2758] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.668
    [21-06-28 15:36:44.5680] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.641
    [21-06-28 15:36:44.8677] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.641
    [21-06-28 15:36:45.1667] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.660
    [21-06-28 15:36:45.4673] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.659
    [21-06-28 15:36:45.7688] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.639
    [21-06-28 15:36:46.0718] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.626
    [21-06-28 15:36:46.3790] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.633
    [21-06-28 15:36:46.6752] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.648
    [21-06-28 15:36:46.9803] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.634
    [21-06-28 15:36:47.2824] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.654
    [21-06-28 15:36:47.5840] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.643
    [21-06-28 15:36:47.8852] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.625
    [21-06-28 15:36:48.1869] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.651
    [21-06-28 15:36:48.4923] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.636
    [21-06-28 15:36:48.7868] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.651
    [21-06-28 15:36:49.0430] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.628
    [21-06-28 15:36:49.1055] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.699
    [21-06-28 15:36:49.4078] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.636
    [21-06-28 15:36:49.7102] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.640
    [21-06-28 15:36:50.0188] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.640
    [21-06-28 15:36:50.3228] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.661
    [21-06-28 15:36:50.6223] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.642
    [21-06-28 15:36:50.9216] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.646
    [21-06-28 15:36:51.2313] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.635
    [21-06-28 15:36:51.5289] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.651
    [21-06-28 15:36:51.8258] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.640
    [21-06-28 15:36:52.1336] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.646
    [21-06-28 15:36:52.4309] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.644
    [21-06-28 15:36:52.7337] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.626
    [21-06-28 15:36:53.0382] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.653
    [21-06-28 15:36:53.3387] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.654
    [21-06-28 15:36:53.6410] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.634
    [21-06-28 15:36:53.9380] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.633
    [21-06-28 15:36:54.0377] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=1379, output_fullness=-1, elapsed=7350.711
    [21-06-28 15:36:55.1625] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMf: fullness=1379, output_fullness=-1, elapsed=0.000
    [21-06-28 15:36:55.1708] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMf: fullness=0, output_fullness=-1, elapsed=0.000
    [21-06-28 15:36:55.1797] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMc: fullness=0, output_fullness=-1, elapsed=0.000
    [21-06-28 15:36:55.2942] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=0, output_fullness=-1, elapsed=0.000
    [21-06-28 15:36:55.5908] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=10240, output_fullness=-1, elapsed=0.000
    [21-06-28 15:36:55.8986] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=46080, output_fullness=-1, elapsed=0.000
    [21-06-28 15:36:55.9188] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMl: fullness=50176, output_fullness=-1, elapsed=0.000
    [21-06-28 15:36:56.0656] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMr: fullness=65683, output_fullness=548728, elapsed=0.000
    [21-06-28 15:36:57.0551] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMs: fullness=19453, output_fullness=3308336, elapsed=0.780
    [21-06-28 15:36:57.0740] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=19453, output_fullness=3308336, elapsed=0.781
    [21-06-28 15:36:58.0508] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=23195, output_fullness=3324384, elapsed=1.782
    [21-06-28 15:36:59.0231] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=20424, output_fullness=3324368, elapsed=2.753
    [21-06-28 15:37:00.0220] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=24166, output_fullness=3333320, elapsed=3.755
    [21-06-28 15:37:01.0258] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=21396, output_fullness=3308768, elapsed=4.756
    [21-06-28 15:37:02.0263] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=21045, output_fullness=3324608, elapsed=5.757
    [21-06-28 15:37:03.0277] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=16603, output_fullness=3340448, elapsed=6.758
    [21-06-28 15:37:04.0226] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=22016, output_fullness=3326480, elapsed=7.750
    [21-06-28 15:37:05.0863] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=17574, output_fullness=3338784, elapsed=8.751
    [21-06-28 15:37:06.0240] Slim::Networking::Slimproto::_stat_handler (784) b8:27:eb:bf:93:3d: STAT-STMt: fullness=21316, output_fullness=3354384,

    Any ideas or suggestions on which component to log?
    I’ll continue with experiments.

    Regards
    Marcello

    Marcello T premium
    23. Juni 2021 at 15:50 #51356

    Hi Mario,

    I’ve already tested a couple of choices –
    – sysadefault -> same behaviours
    – pulseaudio -> audio is very bad on RPi3+, not working at all on a RPi2

    Anyway made a step ahead in the analysis following some of your suggestions.
    I’m pretty sure that I have a synchronization problem:

    1. Stopped the Squeeze-X player – left 3 players in the group, all on RPis -> no changes, same issue
    2. Stopped the 2 RPi2 with headphone output -> left 2 players in the group, Main RPi with server and Squeeze-X software -> continuous audio, no interruptions, no rebuffering
    3. Added to the players group one player – I used the Rpi3+ to be sure to avoid any perf issue -> again rebuffering problems, audio stops and client player with pulseaudio hanged – shutted down the player and fallen back to the step 2, no issues

    I’ll make a test with the PRPi2, but I’ve few doubts that i will get different behaviuor of the step 3.

    Could I check anything specific? log, config files, or other?
    Is it possibile to tune any parameter for the players synch? the only param I found is under the server config -> player/<player name>/synch/network latency – I raised up to 15ms (was 2ms by default) but with no effects.

    Many thanks
    Regards
    Marcello

    Marcello T premium
    22. Juni 2021 at 15:09 #51351

    Thanks for the quick answer.

    Going thru the questions:

    1. The Rpis are connected via wireline – no benefits from switching from wireless to cable connection
    2. The LMS server is running on an Rpi3+, the other two clients (those with audio on headphones) are an Rpi2 and a Rpi3+
    3. Audio output is based on „hw – bcm2385 headphone…direct hardware…DEV=0) on client Rpis
    4. all software is based on latest image of Max2Play (version Beta-210428, upgraded from the package 2.53 hoping in a solution):

    in the following Debug info from section Settings/reboot and Audio:

    Controller and Server – Rpi3+ (audio on bluethooth speaker – direct streaming in audio selection)

    #### FILESYSTEM ####
    Filesystem 1K-blocks Used Available Use% Mounted on
    /dev/root 30202200 3619688 25325024 13% /
    devtmpfs 413524 0 413524 0% /dev
    tmpfs 446804 36 446768 1% /dev/shm
    tmpfs 446804 12756 434048 3% /run
    tmpfs 5120 4 5116 1% /run/lock
    tmpfs 446804 0 446804 0% /sys/fs/cgroup
    /dev/mmcblk0p1 258096 48791 209305 19% /boot
    tmpfs 89360 8 89352 1% /run/user/1000

    #### LOAD AVERAGE ####
    0.57 0.67 0.66 1/250 14132

    #### KERNEL ####
    Linux Max2Play-Controller 5.10.17-v7+ #1421 SMP Thu May 27 13:59:01 BST 2021 armv7l GNU/Linux

    #### LINUX-VERSION ####
    Distributor ID: Raspbian
    Description: Raspbian GNU/Linux 10 (buster)
    Release: 10
    Codename: buster

    #### SQUEEZELITE VERSION ####
    Squeezelite Max2Play v1.0.3 based on v1.8.7-999, Copyright 2012-2015 Adrian Smith, 2015-2017 Ralph Irving.

    #### SQUEEZELITE BUILDOPTIONS ####
    Build options: LINUX ALSA EVENTFD RESAMPLE FFMPEG VISEXPORT IR GPIO DSD CONTROLSBS ALSASYNC BLUETOOTHSYNC

    #### AUDIOPLAYER CONFIG ####
    ### Configuration of Audioplayers
    SQUEEZELITE_PARAMETER=-o plug:bluetooth -a 80:4:: -B -v
    SQUEEZESLAVE_PARAMETER=-n plugequal
    SHAIRPORT_PARAMETER=-d hw:CARD=Headphones,DEV=0
    USE_USB_DAC=0
    USE_EQUALIZER=0
    SYSTEM_USER=pi
    BLUEALSA_PLAY_AUDIOCARD=hw:0,0
    BLUEALSA_PLAY_MIXER=PCM
    GMEDIARENDERER_ALSA_DEVICE=hw:CARD=Headphones,DEV=0

    –First Client (RPi3+) — audio on „headphone jack“

    #### FILESYSTEM ####
    Filesystem 1K-blocks Used Available Use% Mounted on
    /dev/root 30295896 3016520 26018140 11% /
    devtmpfs 413524 0 413524 0% /dev
    tmpfs 446804 36 446768 1% /dev/shm
    tmpfs 446804 23852 422952 6% /run
    tmpfs 5120 4 5116 1% /run/lock
    tmpfs 446804 0 446804 0% /sys/fs/cgroup
    /dev/mmcblk0p1 258096 48791 209305 19% /boot
    tmpfs 89360 8 89352 1% /run/user/1000

    #### LOAD AVERAGE ####
    0.21 0.15 0.10 1/224 24221

    #### KERNEL ####
    Linux Max2Play-ClientOne 5.10.17-v7+ #1421 SMP Thu May 27 13:59:01 BST 2021 armv7l GNU/Linux

    #### LINUX-VERSION ####
    Distributor ID: Raspbian
    Description: Raspbian GNU/Linux 10 (buster)
    Release: 10
    Codename: buster

    #### SQUEEZELITE VERSION ####
    Squeezelite Max2Play v1.0.3 based on v1.8.7-999, Copyright 2012-2015 Adrian Smith, 2015-2017 Ralph Irving.

    #### SQUEEZELITE BUILDOPTIONS ####
    Build options: LINUX ALSA EVENTFD RESAMPLE FFMPEG VISEXPORT IR GPIO DSD CONTROLSBS ALSASYNC BLUETOOTHSYNC

    #### AUDIOPLAYER CONFIG ####
    ### Configuration of Audioplayers
    SQUEEZELITE_PARAMETER=-o hw:CARD=Headphones,DEV=0 -a 80:4:: -v
    SQUEEZESLAVE_PARAMETER=-n plugequal
    SHAIRPORT_PARAMETER=-d pulse
    USE_USB_DAC=0
    USE_EQUALIZER=0
    SYSTEM_USER=pi
    GMEDIARENDERER_ALSA_DEVICE=hw:CARD=Headphones,DEV=0

    –Second Client (RPi2) — audio on „headphone jack“

    #### FILESYSTEM ####
    Filesystem 1K-blocks Used Available Use% Mounted on
    /dev/root 30202200 3010836 25933876 11% /
    devtmpfs 413528 0 413528 0% /dev
    tmpfs 446808 4 446804 1% /dev/shm
    tmpfs 446808 34924 411884 8% /run
    tmpfs 5120 4 5116 1% /run/lock
    tmpfs 446808 0 446808 0% /sys/fs/cgroup
    /dev/mmcblk0p1 258096 48791 209305 19% /boot
    tmpfs 89360 8 89352 1% /run/user/1000

    #### LOAD AVERAGE ####
    0.04 0.05 0.01 1/207 28400

    #### KERNEL ####
    Linux Max2Play-ClientTwo 5.10.17-v7+ #1421 SMP Thu May 27 13:59:01 BST 2021 armv7l GNU/Linux

    #### LINUX-VERSION ####
    Distributor ID: Raspbian
    Description: Raspbian GNU/Linux 10 (buster)
    Release: 10
    Codename: buster

    #### SQUEEZELITE VERSION ####
    Squeezelite Max2Play v1.0.3 based on v1.8.7-999, Copyright 2012-2015 Adrian Smith, 2015-2017 Ralph Irving.

    #### SQUEEZELITE BUILDOPTIONS ####
    Build options: LINUX ALSA EVENTFD RESAMPLE FFMPEG VISEXPORT IR GPIO DSD CONTROLSBS ALSASYNC BLUETOOTHSYNC

    #### AUDIOPLAYER CONFIG ####
    ### Configuration of Audioplayers
    SQUEEZELITE_PARAMETER=-o hw:CARD=Headphones,DEV=0 -a 80:4:: -v
    SQUEEZESLAVE_PARAMETER=-n plugequal
    SHAIRPORT_PARAMETER=-d hw:CARD=Headphones,DEV=0
    USE_USB_DAC=0
    USE_EQUALIZER=0
    SYSTEM_USER=pi
    GMEDIARENDERER_ALSA_DEVICE=hw:CARD=Headphones,DEV=0

    Thanks
    BR
    Marcello

Viewing 5 posts - 1 through 5 (of 5 total)