pMiniBuffer->full() && (abs(pMiniBuffer->mean()) > 5) / Problem with pulseaudio --player pulse #957

dflvunoooooo · 2021-12-15T10:25:13Z

dflvunoooooo
Dec 15, 2021

Describe the bug
I get the two errors outputBufferDacTime and pShortBuffer messages, when playing music on my desktop. And every time the letter appears the playback stutters a bit.

Steps to Reproduce

Start Snapclient via: snapclient --user brian --player pulse --host X.X.X.X --hostID my-desktop-name

Environment details

OS: Arch Linux
Snapcast version 0.25.0
Installed from a arch linux package

Attach logfile if applicable
Generate logs with snapclient --logfilter debug or snapserver --logging.filter debug if possible and paste them in the following codeblock

2021-12-15 11-19-28.806 [Info] (Stream) outputBufferDacTime > bufferMs: 139976062853 > 1000
2021-12-15 11-19-36.032 [Info] (Stream) pShortBuffer->full() && (abs(shortMedian_) > 5): -6397
2021-12-15 11-19-38.208 [Info] (Stream) pShortBuffer->full() && (abs(shortMedian_) > 5): 6524
2021-12-15 11-19-41.045 [Info] (Stream) pShortBuffer->full() && (abs(shortMedian_) > 5): -13404
2021-12-15 11-19-44.031 [Info] (Stream) pShortBuffer->full() && (abs(shortMedian_) > 5): 7081

dflvunoooooo · 2021-12-15T10:28:28Z

dflvunoooooo
Dec 15, 2021
Author

The bug #920 was closed and I can not reopen it.

I tried the suggested solution. The -sampleformat 48000:16:2 gives the error:

2021-12-15 11-25-04.951 [Fatal] (Snapclient) Exception: sampleformat channels must be * (= same as the source)
2021-12-15 11-25-04.951 [Notice] (Snapclient) Snapclient terminated.

And the alsa backend would be very unpleasant, because then it does not show up in kmix.

0 replies

badaix · 2021-12-15T10:52:33Z

badaix
Dec 15, 2021
Maintainer

You could try the suggestion from the error message: --sampleformat 48000:16:*

0 replies

dflvunoooooo · 2021-12-15T11:01:50Z

dflvunoooooo
Dec 15, 2021
Author

Ah! I did totally misunderstand that error message, thanks! With your suggestion it is working, even with the --player pulse option!

0 replies

dflvunoooooo · 2021-12-16T10:47:23Z

dflvunoooooo
Dec 16, 2021
Author

I am sad to say it did only work temporarily. When I start snapclient with --player pulse I get again the same error:

2021-12-16 11-41-00.035 [Info] (Stream) pShortBuffer->full() && (abs(shortMedian_) > 5): -5620
2021-12-16 11-41-04.024 [Info] (Stream) pShortBuffer->full() && (abs(shortMedian_) > 5): 10504
2021-12-16 11-41-06.797 [Info] (Stream) pShortBuffer->full() && (abs(shortMedian_) > 5): -7345
2021-12-16 11-41-08.972 [Info] (Stream) pShortBuffer->full() && (abs(shortMedian_) > 5): 5326
2021-12-16 11-41-12.044 [Info] (Stream) pShortBuffer->full() && (abs(shortMedian_) > 5): 7460
2021-12-16 11-41-14.220 [Info] (Stream) pShortBuffer->full() && (abs(shortMedian_) > 5): -5962
2021-12-16 11-41-16.395 [Info] (Stream) pShortBuffer->full() && (abs(shortMedian_) > 5): 8504

But if I start snapclient with the --player alsa option, everything is working. Can I do something about that? I would prefer to use pulse, as mentioned.

0 replies

badaix · 2021-12-16T11:33:33Z

badaix
Dec 16, 2021
Maintainer

No idea. Also you should provide debug logs:

Attach logfile if applicable
Generate logs with snapclient --logfilter debug or snapserver --logging.filter debug if possible and paste them in the following codeblock

0 replies

dflvunoooooo · 2021-12-16T12:04:39Z

dflvunoooooo
Dec 16, 2021
Author

Ah yes, the debug output. Here it is:

2021-12-16 13-02-42.178 [Debug] (Snapclient) Trying to get PCM device for player: pulse, parameter: , card: default
2021-12-16 13-02-42.190 [Info] (Snapclient) Version 0.25.0
2021-12-16 13-02-42.190 [Info] (Connection) Resolving host IP for: X.X.X.X
2021-12-16 13-02-42.190 [Info] (Connection) Connecting
2021-12-16 13-02-42.193 [Notice] (Connection) Connected to 192.168.0.13
2021-12-16 13-02-42.193 [Info] (Connection) My MAC: "X:X:X:X:X:X", socket: 8
2021-12-16 13-02-42.208 [Debug] (Connection) outstanding async_write
2021-12-16 13-02-42.212 [Info] (Controller) ServerSettings - buffer: 1000, latency: 0, volume: 100, muted: 0
metadata:{"STREAM":"Librespot"}
2021-12-16 13-02-42.212 [Info] (Controller) Codec: flac, sampleformat: 44100:16:2
2021-12-16 13-02-42.212 [Info] (Resampler) Resampling from 44100:16:2 to 48000:16:2
2021-12-16 13-02-42.212 [Info] (Player) Player name: pulse, device: default, description: Let PulseAudio server choose the device, idx: 42, sharing mode: unspecified, parameters: <none>
2021-12-16 13-02-42.212 [Info] (Player) Mixer mode: software, parameters: <none>
2021-12-16 13-02-42.212 [Info] (Player) Sampleformat: 48000:16:0, stream: 48000:16:2
2021-12-16 13-02-42.212 [Info] (PulsePlayer) Setting property "application.icon_name" to "snapcast"
2021-12-16 13-02-42.212 [Info] (PulsePlayer) Setting property "media.role" to "music"
2021-12-16 13-02-42.212 [Info] (PulsePlayer) Using buffer_time: 100 ms, server: default
2021-12-16 13-02-42.212 [Debug] (PulsePlayer) State changed 2: authorizing
2021-12-16 13-02-42.218 [Debug] (PulsePlayer) State changed 3: setting name
2021-12-16 13-02-42.222 [Debug] (PulsePlayer) State changed 4: ready
2021-12-16 13-02-42.223 [Debug] (Player) setVolume exp with base 10: 1 => 1
2021-12-16 13-02-42.228 [Info] (Stream) outputBufferDacTime > bufferMs: 140079215079 > 1000
2021-12-16 13-02-42.228 [Debug] (Stream) Failed to get chunk, returning silence
2021-12-16 13-02-42.248 [Info] (Stream) No chunks available
2021-12-16 13-02-42.258 [Debug] (Resampler) Resample buffer completely filled, adding space for 5ms; new buffer size: 4800 bytes
2021-12-16 13-02-42.278 [Debug] (Resampler) Resample buffer completely filled, adding space for 5ms; new buffer size: 5760 bytes
2021-12-16 13-02-42.339 [Debug] (Resampler) Resample buffer completely filled, adding space for 5ms; new buffer size: 6720 bytes
2021-12-16 13-02-42.369 [Info] (Controller) diff to server [ms]: 6.80145e+08
2021-12-16 13-02-42.420 [Debug] (Resampler) Resample buffer completely filled, adding space for 5ms; new buffer size: 7680 bytes
2021-12-16 13-02-43.100 [Debug] (Stream) Silent frames: 479, frames: 1024, age: -9.982
2021-12-16 13-02-43.121 [Debug] (Stats) Chunk: 2        2       2       2       1       92      0
2021-12-16 13-02-44.017 [Debug] (Stats) Chunk: -8       7       6       6       43      93      0
2021-12-16 13-02-45.019 [Debug] (Stats) Chunk: 0        0       -1      -1      90      94      0
2021-12-16 13-02-46.022 [Debug] (Stats) Chunk: -49      -56     -22     -11     137     89      1
2021-12-16 13-02-47.024 [Debug] (Stats) Chunk: -197     -135    -49     -24     184     73      32
2021-12-16 13-02-48.006 [Debug] (Stats) Chunk: -229     -236    -173    -39     230     69      24
2021-12-16 13-02-48.027 [Info] (Stream) pShortBuffer->full() && (abs(shortMedian_) > 5): -17392
2021-12-16 13-02-48.070 [Debug] (Stream) Silent frames: 56, frames: 1024, age: -1.18
2021-12-16 13-02-49.009 [Debug] (Stats) Chunk: 37       41      37      37      44      74      0
2021-12-16 13-02-50.011 [Debug] (Stats) Chunk: 107      79      37      37      91      81      0
2021-12-16 13-02-51.014 [Debug] (Stats) Chunk: 130      123     101     44      138     84      -19
2021-12-16 13-02-51.035 [Info] (Stream) pShortBuffer->full() && (abs(shortMedian_) > 5): 10196
2021-12-16 13-02-51.056 [Debug] (Stream) age > 0: 13ms, dropping old chunks
2021-12-16 13-02-51.056 [Debug] (Stream) age: -2, requested chunk_duration: 21, duration: 37
2021-12-16 13-02-51.056 [Debug] (Stream) Silent frames: 97, frames: 1024, age: -2.035
2021-12-16 13-02-52.016 [Debug] (Stats) Chunk: 84       80      62      62      45      93      -1
2021-12-16 13-02-53.019 [Debug] (Stats) Resample idone: 1152/1152, odone: 892/1920, delay: 808.218
2021-12-16 13-02-53.019 [Debug] (Stats) Chunk: -37      10      66      66      92      81      0
2021-12-16 13-02-53.211 [Info] (Stream) pShortBuffer->full() && (abs(shortMedian_) > 5): 6629
2021-12-16 13-02-53.232 [Debug] (Stream) Silent frames: 311, frames: 1024, age: -6.497
2021-12-16 13-02-54.021 [Debug] (Stats) Chunk: 15       7       4       4       37      79      0
2021-12-16 13-02-55.024 [Debug] (Stats) Chunk: 54       53      22      22      84      83      0
2021-12-16 13-02-56.005 [Debug] (Stats) Chunk: 104      87      53      50      130     89      -14
2021-12-16 13-02-56.027 [Info] (Stream) pShortBuffer->full() && (abs(shortMedian_) > 5): 5392
2021-12-16 13-02-56.048 [Debug] (Stream) age > 0: 10ms, dropping old chunks
2021-12-16 13-02-56.048 [Debug] (Stream) age: -25, requested chunk_duration: 21, duration: 18
2021-12-16 13-02-56.048 [Debug] (Stream) Silent frames: 1024, frames: 1024, age: -25.828
2021-12-16 13-02-56.069 [Debug] (Stream) Silent frames: 211, frames: 1024, age: -4.411
2021-12-16 13-02-57.008 [Debug] (Stats) Chunk: -6       9       9       9       44      89      -1
2021-12-16 13-02-58.010 [Debug] (Stats) Chunk: -153     -150    -13     -13     91      74      0
2021-12-16 13-02-59.013 [Debug] (Stats) Chunk: -83      -108    -129    -96     138     81      19
2021-12-16 13-02-59.034 [Info] (Stream) pShortBuffer->full() && (abs(shortMedian_) > 5): -12959
2021-12-16 13-02-59.056 [Debug] (Stream) Silent frames: 376, frames: 1024, age: -7.844
2021-12-16 13-03-00.015 [Debug] (Stats) Chunk: 23       15      14      14      45      84      0
2021-12-16 13-03-01.018 [Debug] (Stats) Chunk: 81       81      26      26      92      90      0
2021-12-16 13-03-02.021 [Debug] (Stats) Chunk: -48      0       63      35      139     77      -15
2021-12-16 13-03-02.042 [Info] (Stream) pShortBuffer->full() && (abs(shortMedian_) > 5): 6376

0 replies

dflvunoooooo · 2021-12-20T12:06:16Z

dflvunoooooo
Dec 20, 2021
Author

If I set the buffersize with --player pulse:buffer_time=900 ot anything between 100 and 900, things do not change. But with buffersize 1000 there is more noticeable stuttering than with default 100, but with buffersize 10 the stuttering almost disappears and the pMiniBuffer->full() && (abs(pMiniBuffer->mean()) > 5) error does not occur anymore. Now I get an pBuffer->full() && (abs(median_) > 2): error.

2021-12-20 12-59-38.888 [Debug] (Snapclient) Trying to get PCM device for player: pulse, parameter: , card: default
2021-12-20 12-59-38.900 [Info] (Snapclient) Version 0.25.0
2021-12-20 12-59-38.900 [Info] (Connection) Resolving host IP for: 192.168.0.13
2021-12-20 12-59-38.900 [Info] (Connection) Connecting
2021-12-20 12-59-38.903 [Notice] (Connection) Connected to 192.168.0.13
2021-12-20 12-59-38.903 [Info] (Connection) My MAC: "90:78:41:38:8e:02", socket: 8
2021-12-20 12-59-38.923 [Debug] (Connection) outstanding async_write
2021-12-20 12-59-38.927 [Info] (Controller) ServerSettings - buffer: 1000, latency: 0, volume: 100, muted: 0
metadata:{"STREAM":"Librespot"}
2021-12-20 12-59-38.928 [Info] (Controller) Codec: flac, sampleformat: 44100:16:2
2021-12-20 12-59-38.928 [Info] (Player) Player name: pulse, device: default, description: Let PulseAudio server choose the device, idx: 42, sharing mode: unspecified, parameters: buffer_time=10
2021-12-20 12-59-38.928 [Info] (Player) Mixer mode: software, parameters: <none>
2021-12-20 12-59-38.928 [Info] (Player) Sampleformat: 44100:16:2, stream: 44100:16:2
2021-12-20 12-59-38.928 [Info] (PulsePlayer) Setting property "application.icon_name" to "snapcast"
2021-12-20 12-59-38.928 [Info] (PulsePlayer) Setting property "media.role" to "music"
2021-12-20 12-59-38.928 [Info] (PulsePlayer) Using buffer_time: 10 ms, server: default
2021-12-20 12-59-38.928 [Debug] (PulsePlayer) State changed 2: authorizing
2021-12-20 12-59-38.934 [Debug] (PulsePlayer) State changed 3: setting name
2021-12-20 12-59-38.939 [Debug] (PulsePlayer) State changed 4: ready
2021-12-20 12-59-38.940 [Debug] (Player) setVolume exp with base 10: 1 => 1
2021-12-20 12-59-38.950 [Info] (Stream) outputBufferDacTime > bufferMs: 140475056050 > 1000
2021-12-20 12-59-38.950 [Debug] (Stream) Failed to get chunk, returning silence
2021-12-20 12-59-39.088 [Info] (Controller) diff to server [ms]: -4.28864e+07
2021-12-20 12-59-39.893 [Debug] (Stream) Silent frames: 198, frames: 235, age: -4.512
2021-12-20 12-59-39.898 [Debug] (Stats) Chunk: 0        0       0       0       1       7       0
2021-12-20 12-59-40.005 [Debug] (Stats) Chunk: 0        0       0       0       21      7       0
2021-12-20 12-59-41.002 [Debug] (Stats) Chunk: 28       27      21      12      208     10      0
2021-12-20 12-59-42.005 [Debug] (Stats) Chunk: 25       24      22      21      396     10      -21
2021-12-20 12-59-42.564 [Info] (Stream) pBuffer->full() && (abs(median_) > 2): 2193
2021-12-20 12-59-42.570 [Debug] (Stream) age > 0: 3ms, dropping old chunks
2021-12-20 12-59-42.570 [Debug] (Stream) age: -13, requested chunk_duration: 5, duration: 26
2021-12-20 12-59-42.570 [Debug] (Stream) Silent frames: 235, frames: 235, age: -13.934
2021-12-20 12-59-42.580 [Debug] (Stream) Silent frames: 146, frames: 235, age: -3.317
2021-12-20 12-59-43.002 [Debug] (Stats) Chunk: -2       -1      -1      -1      79      11      -13
2021-12-20 12-59-44.004 [Debug] (Stats) Chunk: 19       19      15      0       267     13      0
2021-12-20 12-59-45.002 [Debug] (Stats) Chunk: 23       22      17      16      454     14      -24
2021-12-20 12-59-46.004 [Debug] (Stats) Chunk: 33       32      32      18      500     16      -23
2021-12-20 12-59-47.001 [Debug] (Stats) Chunk: -17      -16     -7      22      500     11      -13
2021-12-20 12-59-47.007 [Info] (Stream) pBuffer->full() && (abs(median_) > 2): 2273
2021-12-20 12-59-47.012 [Debug] (Stream) Silent frames: 77, frames: 235, age: -1.752
2021-12-20 12-59-48.004 [Debug] (Stats) Chunk: 6        5       1       0       186     12      0
2021-12-20 12-59-49.001 [Debug] (Stats) Chunk: 12       12      12      6       373     12      -2
2021-12-20 12-59-50.004 [Debug] (Stats) Chunk: 22       22      20      12      500     14      -24
2021-12-20 12-59-51.006 [Debug] (Stats) Chunk: -2       0       13      14      500     12      -21

0 replies

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

pMiniBuffer->full() && (abs(pMiniBuffer->mean()) > 5) / Problem with pulseaudio --player pulse #957

{{title}}

Replies: 7 comments

{{title}}

{{title}}

{{title}}

{{editor}}'s edit

{{editor}}'s edit

{{title}}

{{title}}

{{title}}

{{title}}

Select a reply

pMiniBuffer->full() && (abs(pMiniBuffer->mean()) > 5) / Problem with pulseaudio --player pulse #957

dflvunoooooo Dec 15, 2021

Replies: 7 comments

dflvunoooooo Dec 15, 2021 Author

badaix Dec 15, 2021 Maintainer

dflvunoooooo Dec 15, 2021 Author

dflvunoooooo Dec 16, 2021 Author

badaix Dec 16, 2021 Maintainer

dflvunoooooo Dec 16, 2021 Author

dflvunoooooo Dec 20, 2021 Author

dflvunoooooo
Dec 15, 2021

dflvunoooooo
Dec 15, 2021
Author

badaix
Dec 15, 2021
Maintainer

dflvunoooooo
Dec 15, 2021
Author

dflvunoooooo
Dec 16, 2021
Author

badaix
Dec 16, 2021
Maintainer

dflvunoooooo
Dec 16, 2021
Author

dflvunoooooo
Dec 20, 2021
Author