search

badaix / snapcast

Synchronous multiroom audio player
GNU General Public License v3.0
6.21k stars 456 forks source link

[Windows] ~3 second stutters every ~30 seconds (Not enough frames) #1153

Closed rwjack closed 10 months ago

rwjack commented 1 year ago

Describe the bug Title is self explanatory, attached the logs. This doesn't happen on any other of my Linux based devices, only on the Windows desktop. I first noticed the issue using Snap.Net, and thought it was specific to it, but upon running snapclient from a terminal, the same issue occurs. Exact stutter is at log line: 2023-08-27 15-32-13.818 [Info] ( <- Ctrl+F this value )

I have tried changing the default format, but it did not resolve the issue. image

Note that when using exclusive WASAPI mode, the stutters do not occur, although this is not a proper solution since I have no other audio from my desktop in that case.

As it seems this was the case during my testing about a month ago, but today I can't even get the exclusive mode working. image

Steps to Reproduce Download snapcast, run with commands in log.

Environment details

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

C:\Users\[REDACTED]\Downloads\snapcast_win64>snapclient.exe --host [REDACTED] --hostID [REDACTED]--logfilter debug
2023-08-27 15-31-35.901 [Debug] (Snapclient) Trying to get PCM device for player: wasapi, parameter: , card: default
2023-08-27 15-31-35.907 [Info] (Snapclient) Version 0.27.0, revision 54a3d862
2023-08-27 15-31-35.908 [Info] (Connection) Resolving host IP for: [REDACTED]
2023-08-27 15-31-35.908 [Info] (Connection) Connecting
2023-08-27 15-31-35.922 [Notice] (Connection) Connected to [REDACTED]
2023-08-27 15-31-35.924 [Info] (Connection) My MAC: "[REDACTED]", socket: 396
2023-08-27 15-31-35.925 [Debug] (Connection) outstanding async_write
2023-08-27 15-31-35.926 [Info] (Controller) ServerSettings - buffer: 1000, latency: 0, volume: 63, muted: 0
2023-08-27 15-31-35.926 [Info] (Controller) Codec: flac, sampleformat: 44100:16:2
2023-08-27 15-31-35.927 [Info] (Player) Player name: wasapi, device: default, description: Speakers (High Definition Audio Device), idx: 0, sharing mode: shared, parameters: <none>
2023-08-27 15-31-35.927 [Info] (Player) Mixer mode: software, parameters: <none>
2023-08-27 15-31-35.928 [Info] (Player) Sampleformat: 44100:16:2, stream: 44100:16:2
2023-08-27 15-31-35.928 [Debug] (Player) setVolume exp with base 10: 0.63 => 0.362866
2023-08-27 15-31-35.930 [Info] (WASAPI) Device accepts format: 192000:32:2
2023-08-27 15-31-35.939 [Info] (WASAPI) Initializing WASAPI in shared mode
2023-08-27 15-31-35.958 [Debug] (WASAPI) New session state = active
2023-08-27 15-31-36.668 [Info] (Controller) diff to server [ms]: -1.69314e+12
2023-08-27 15-31-36.878 [Debug] (Stream) Silent frames: 233, frames: 441, age: -5.297
2023-08-27 15-31-36.888 [Debug] (Stats) Chunk: 0        0       0       0       1       33      0
2023-08-27 15-31-37.008 [Debug] (Stats) Chunk: 0        0       0       0       13      33      0
2023-08-27 15-31-38.008 [Debug] (Stats) Chunk: 0        0       0       0       113     33      0
2023-08-27 15-31-39.008 [Debug] (Stats) Chunk: 0        0       0       0       213     33      0
2023-08-27 15-31-40.008 [Debug] (Stats) Chunk: 0        0       0       0       313     33      0
2023-08-27 15-31-41.008 [Debug] (Stats) Chunk: 0        0       0       0       413     33      0
2023-08-27 15-31-42.008 [Debug] (Stats) Chunk: 0        0       0       0       500     33      0
2023-08-27 15-31-43.008 [Debug] (Stats) Chunk: 0        0       0       0       500     33      0
2023-08-27 15-31-44.008 [Debug] (Stats) Chunk: 0        0       0       0       500     33      0
2023-08-27 15-31-45.008 [Debug] (Stats) Chunk: 0        0       0       0       500     33      0
2023-08-27 15-31-46.008 [Debug] (Stats) Chunk: 0        0       0       0       500     33      0
2023-08-27 15-31-47.008 [Debug] (Stats) Chunk: 0        0       0       0       500     33      0
2023-08-27 15-31-48.008 [Debug] (Stats) Chunk: 0        0       0       0       500     33      0
2023-08-27 15-31-49.008 [Debug] (Stats) Chunk: 0        0       0       0       500     33      0
2023-08-27 15-31-50.008 [Debug] (Stats) Chunk: 0        0       0       0       500     33      0
2023-08-27 15-31-51.008 [Debug] (Stats) Chunk: 0        0       0       0       500     33      0
2023-08-27 15-31-52.008 [Debug] (Stats) Chunk: 0        0       0       0       500     33      0
2023-08-27 15-31-53.008 [Debug] (Stats) Chunk: 0        0       0       0       500     33      0
2023-08-27 15-31-54.008 [Debug] (Stats) Chunk: 0        0       0       0       500     33      0
2023-08-27 15-31-55.008 [Debug] (Stats) Chunk: 0        0       0       0       500     33      0
2023-08-27 15-31-56.008 [Debug] (Stats) Chunk: 0        0       0       0       500     33      0
2023-08-27 15-31-57.008 [Debug] (Stats) Chunk: 0        0       0       0       500     33      0
2023-08-27 15-31-58.008 [Debug] (Stats) Chunk: 0        0       0       0       500     33      0
2023-08-27 15-31-59.008 [Debug] (Stats) Chunk: 0        0       0       0       500     33      0
2023-08-27 15-32-00.008 [Debug] (Stats) Chunk: 0        0       0       0       500     33      0
2023-08-27 15-32-01.007 [Debug] (Stats) Chunk: 0        0       0       0       500     33      0
2023-08-27 15-32-02.008 [Debug] (Stats) Chunk: 0        0       0       0       500     33      0
2023-08-27 15-32-03.008 [Debug] (Stats) Chunk: 0        0       0       0       500     33      0
2023-08-27 15-32-04.008 [Debug] (Stats) Chunk: 0        0       0       0       500     33      0
2023-08-27 15-32-05.008 [Debug] (Stats) Chunk: 0        0       0       0       500     33      0
2023-08-27 15-32-06.008 [Debug] (Stats) Chunk: 0        0       0       0       500     33      0
2023-08-27 15-32-07.008 [Debug] (Stats) Chunk: 0        0       0       0       500     33      0
2023-08-27 15-32-08.008 [Debug] (Stats) Chunk: 0        0       0       0       500     33      0
2023-08-27 15-32-09.008 [Debug] (Stats) Chunk: 0        0       0       0       500     33      0
2023-08-27 15-32-10.008 [Debug] (Stats) Chunk: 0        0       0       0       500     33      0
2023-08-27 15-32-11.007 [Debug] (Stats) Chunk: 0        0       0       0       500     33      0
2023-08-27 15-32-12.008 [Debug] (Stats) Chunk: 0        0       0       0       500     33      0
2023-08-27 15-32-13.008 [Debug] (Stats) Chunk: 0        0       0       0       500     33      0
2023-08-27 15-32-13.818 [Info] (Stream) Exception: Not enough frames available, requested frames: 441, available: 107
2023-08-27 15-32-13.819 [Info] (WASAPI) Failed to get chunk
2023-08-27 15-32-13.820 [Debug] (WASAPI) New session state = inactive
2023-08-27 15-32-13.931 [Info] (WASAPI) Waiting for chunk
2023-08-27 15-32-14.039 [Info] (WASAPI) Waiting for chunk
2023-08-27 15-32-14.148 [Info] (WASAPI) Waiting for chunk
2023-08-27 15-32-14.258 [Info] (WASAPI) Waiting for chunk
2023-08-27 15-32-14.367 [Info] (WASAPI) Waiting for chunk
2023-08-27 15-32-14.476 [Info] (WASAPI) Waiting for chunk
2023-08-27 15-32-14.585 [Info] (WASAPI) Waiting for chunk
2023-08-27 15-32-14.694 [Info] (WASAPI) Waiting for chunk
2023-08-27 15-32-14.803 [Info] (WASAPI) Waiting for chunk
2023-08-27 15-32-14.913 [Info] (WASAPI) Waiting for chunk
2023-08-27 15-32-14.975 [Debug] (Connection) Disconnecting
2023-08-27 15-32-14.976 [Debug] (Connection) Disconnected
2023-08-27 15-32-15.023 [Info] (WASAPI) Waiting for chunk
2023-08-27 15-32-15.025 [Debug] (WASAPI) New session state = active
2023-08-27 15-32-15.026 [Debug] (Connection) Disconnecting
2023-08-27 15-32-15.026 [Debug] (Connection) Not connected
2023-08-27 15-32-16.026 [Info] (Connection) Resolving host IP for: [REDACTED]
2023-08-27 15-32-16.027 [Info] (Connection) Connecting
2023-08-27 15-32-16.028 [Notice] (Connection) Connected to [REDACTED]
2023-08-27 15-32-16.029 [Info] (Connection) My MAC: "[REDACTED]", socket: 580
2023-08-27 15-32-16.029 [Debug] (Connection) outstanding async_write
2023-08-27 15-32-16.030 [Info] (Controller) ServerSettings - buffer: 1000, latency: 0, volume: 63, muted: 0
2023-08-27 15-32-16.030 [Info] (Controller) Codec: flac, sampleformat: 44100:16:2
2023-08-27 15-32-16.031 [Info] (Player) Player name: wasapi, device: default, description: Speakers (High Definition Audio Device), idx: 0, sharing mode: shared, parameters: <none>
2023-08-27 15-32-16.031 [Info] (Player) Mixer mode: software, parameters: <none>
2023-08-27 15-32-16.032 [Info] (Player) Sampleformat: 44100:16:2, stream: 44100:16:2
2023-08-27 15-32-16.032 [Debug] (Player) setVolume exp with base 10: 0.63 => 0.362866
2023-08-27 15-32-16.034 [Info] (WASAPI) Device accepts format: 192000:32:2
2023-08-27 15-32-16.037 [Info] (WASAPI) Initializing WASAPI in shared mode
2023-08-27 15-32-16.783 [Info] (Controller) diff to server [ms]: -1.69314e+12
2023-08-27 15-32-16.974 [Debug] (Stream) Silent frames: 312, frames: 441, age: -7.095
2023-08-27 15-32-16.984 [Debug] (Stats) Chunk: 0        0       0       0       1       33      0
2023-08-27 15-32-17.003 [Debug] (Stats) Chunk: 0        0       0       0       3       33      0
2023-08-27 15-32-18.004 [Debug] (Stats) Chunk: 0        0       0       0       103     33      0
2023-08-27 15-32-19.004 [Debug] (Stats) Chunk: 0        0       0       0       203     33      0
2023-08-27 15-32-20.004 [Debug] (Stats) Chunk: 0        0       0       0       303     33      0
2023-08-27 15-32-21.003 [Debug] (Stats) Chunk: 0        0       0       0       403     33      0
2023-08-27 15-32-22.004 [Debug] (Stats) Chunk: 0        0       0       0       500     33      0
rwjack commented 10 months ago

https://github.com/stijnvdb88/Snap.Net/issues/49