Choppy AC3 audio with Bluetooth and MMDevice
When playing files with AC3 audio there are periodically these small pauses, in the logs this is visible with "main warning: playback too late (61933): up-sampling".
Works find in 2.2.8, problem is audible in vlc-3.0.0-20171228-0501-rc5-win64-debug.7z (from nightly builds).
This log was with Broadway-5.1-48khz-448kbit.ac3:
main debug: processing request item: Broadway-5.1-48khz-448kbit.ac3, node: Playlist, skip: 0
main debug: rebuilding array of current - root Playlist
main debug: rebuild done - 1 items, index 0
main debug: starting playback of new item
main debug: resyncing on Broadway-5.1-48khz-448kbit.ac3
main debug: Broadway-5.1-48khz-448kbit.ac3 is at 0
main debug: creating new input thread
main debug: Creating an input for 'Broadway-5.1-48khz-448kbit.ac3'
main debug: requesting art for new input thread
main debug: using timeshift granularity of 50 MiB
main debug: using timeshift path: C:\Users\Hannes\AppData\Local\Temp
main debug: `file:///C:/Users/Hannes/Downloads/Broadway-5.1-48khz-448kbit.ac3' gives access `file' demux `any' path `/C:/Users/Hannes/Downloads/Broadway-5.1-48khz-448kbit.ac3'
main debug: creating demux: access='file' demux='any' location='/C:/Users/Hannes/Downloads/Broadway-5.1-48khz-448kbit.ac3' file='C:\Users\Hannes\Downloads\Broadway-5.1-48khz-448kbit.ac3'
main debug: looking for access_demux module matching "file": 15 candidates
main debug: no access_demux modules matched
main debug: creating access: file:///C:/Users/Hannes/Downloads/Broadway-5.1-48khz-448kbit.ac3
main debug: (path: C:\Users\Hannes\Downloads\Broadway-5.1-48khz-448kbit.ac3)
main debug: looking for access module matching "file": 25 candidates
main debug: using access module "filesystem"
main debug: looking for stream_filter module matching "prefetch,cache_read": 24 candidates
cache_read debug: Using stream method for AStream*
cache_read debug: starting pre-buffering
cache_read debug: received first data after 0 ms
cache_read debug: pre-buffering done 1024 bytes in 0s - 1000000 KiB/s
main debug: using stream_filter module "cache_read"
main debug: looking for stream_filter module matching "any": 24 candidates
main debug: looking for meta fetcher module matching "any": 1 candidates
lua debug: Trying Lua scripts in C:\Users\Hannes\AppData\Roaming\vlc\lua\meta\fetcher
lua debug: Trying Lua scripts in C:\Users\Hannes\AppData\Roaming\vlc\lua\playlist
lua debug: Trying Lua scripts in C:\Program Files\VideoLAN\VLC-debug\lua\meta\fetcher
lua debug: Trying Lua scripts in C:\Program Files\VideoLAN\VLC-debug\lua\playlist
main debug: no meta fetcher modules matched
main debug: looking for art finder module matching "any": 2 candidates
lua debug: Trying Lua playlist script C:\Program Files\VideoLAN\VLC-debug\lua\playlist\anevia_streams.luac
lua debug: Trying Lua playlist script C:\Program Files\VideoLAN\VLC-debug\lua\playlist\anevia_xml.luac
lua debug: Trying Lua scripts in C:\Users\Hannes\AppData\Roaming\vlc\lua\meta\art
lua debug: Trying Lua scripts in C:\Program Files\VideoLAN\VLC-debug\lua\meta\art
lua debug: Trying Lua playlist script C:\Program Files\VideoLAN\VLC-debug\lua\meta\art\00_musicbrainz.luac
lua debug: Trying Lua playlist script C:\Program Files\VideoLAN\VLC-debug\lua\playlist\appletrailers.luac
lua debug: skipping script (unmatched scope) C:\Program Files\VideoLAN\VLC-debug\lua\meta\art\00_musicbrainz.luac
lua debug: Trying Lua playlist script C:\Program Files\VideoLAN\VLC-debug\lua\meta\art\01_googleimage.luac
lua debug: Trying Lua playlist script C:\Program Files\VideoLAN\VLC-debug\lua\playlist\bbc_co_uk.luac
lua debug: skipping script (unmatched scope) C:\Program Files\VideoLAN\VLC-debug\lua\meta\art\01_googleimage.luac
lua debug: Trying Lua playlist script C:\Program Files\VideoLAN\VLC-debug\lua\meta\art\02_frenchtv.luac
lua debug: Trying Lua playlist script C:\Program Files\VideoLAN\VLC-debug\lua\playlist\cue.luac
lua debug: skipping script (unmatched scope) C:\Program Files\VideoLAN\VLC-debug\lua\meta\art\02_frenchtv.luac
lua debug: Trying Lua playlist script C:\Program Files\VideoLAN\VLC-debug\lua\meta\art\03_lastfm.luac
lua debug: skipping script (unmatched scope) C:\Program Files\VideoLAN\VLC-debug\lua\meta\art\03_lastfm.luac
main debug: no art finder modules matched
lua debug: Trying Lua playlist script C:\Program Files\VideoLAN\VLC-debug\lua\playlist\dailymotion.luac
lua debug: Trying Lua playlist script C:\Program Files\VideoLAN\VLC-debug\lua\playlist\jamendo.luac
lua debug: Trying Lua playlist script C:\Program Files\VideoLAN\VLC-debug\lua\playlist\koreus.luac
lua debug: Trying Lua playlist script C:\Program Files\VideoLAN\VLC-debug\lua\playlist\liveleak.luac
lua debug: Trying Lua playlist script C:\Program Files\VideoLAN\VLC-debug\lua\playlist\newgrounds.luac
lua debug: Trying Lua playlist script C:\Program Files\VideoLAN\VLC-debug\lua\playlist\rockbox_fm_presets.luac
lua debug: Trying Lua playlist script C:\Program Files\VideoLAN\VLC-debug\lua\playlist\soundcloud.luac
lua debug: Trying Lua playlist script C:\Program Files\VideoLAN\VLC-debug\lua\playlist\twitch.luac
lua debug: Trying Lua playlist script C:\Program Files\VideoLAN\VLC-debug\lua\playlist\vimeo.luac
lua debug: Trying Lua playlist script C:\Program Files\VideoLAN\VLC-debug\lua\playlist\vocaroo.luac
lua debug: Trying Lua playlist script C:\Program Files\VideoLAN\VLC-debug\lua\playlist\youtube.luac
main debug: no stream_filter modules matched
main debug: looking for stream_directory module matching "any": 1 candidates
main debug: no stream_directory modules matched
main debug: attachment of directory-extractor failed for file:///C:/Users/Hannes/Downloads/Broadway-5.1-48khz-448kbit.ac3
main debug: looking for stream_filter module matching "record": 24 candidates
main debug: using stream_filter module "record"
main debug: creating demux: access='file' demux='any' location='/C:/Users/Hannes/Downloads/Broadway-5.1-48khz-448kbit.ac3' file='C:\Users\Hannes\Downloads\Broadway-5.1-48khz-448kbit.ac3'
main debug: looking for demux module matching "any": 55 candidates
es debug: detected format a52
main debug: looking for packetizer module matching "any": 24 candidates
main debug: using packetizer module "a52"
es debug: did not sync on first block
a52 debug: A/52 channels:6 samplerate:48000 bitrate:448000
main debug: selecting program id=0
main debug: using demux module "es"
main debug: looking for a subtitle file in C:\Users\Hannes\Downloads\
main debug: looking for audio decoder module matching "any": 23 candidates
main debug: reusing audio output
main debug: looking for aout stream module matching "any": 2 candidates
wasapi error: cannot negotiate audio format (error 0x88890008): digital pass-through not supported
qt debug: IM: Setting an input
main debug: no aout stream modules matched
main error: module not functional
main debug: keeping audio output
main error: failed to create audio output
avcodec debug: using ffmpeg Lavc58.6.103
avcodec debug: CPU flags: 0x000fd3db
avcodec debug: codec (ac3) started
main debug: using audio decoder module "avcodec"
main debug: looking for meta reader module matching "any": 2 candidates
lua debug: Trying Lua scripts in C:\Users\Hannes\AppData\Roaming\vlc\lua\meta\reader
lua debug: Trying Lua scripts in C:\Program Files\VideoLAN\VLC-debug\lua\meta\reader
lua debug: Trying Lua playlist script C:\Program Files\VideoLAN\VLC-debug\lua\meta\reader\filename.luac
main debug: no meta reader modules matched
main debug: `file:///C:/Users/Hannes/Downloads/Broadway-5.1-48khz-448kbit.ac3' successfully opened
main debug: Buffering 0%
main debug: Buffering 10%
main debug: Buffering 21%
main debug: reusing audio output
main debug: Buffering 32%
main debug: looking for aout stream module matching "any": 2 candidates
main debug: Buffering 42%
main debug: Buffering 53%
main debug: Buffering 64%
main debug: Buffering 74%
main debug: Buffering 85%
main debug: Buffering 96%
main debug: Stream buffering done (320 ms in 1 ms)
wasapi debug: modified format
wasapi debug: buffer size : 88200 frames
wasapi debug: maximum latency: 11610000 ns
wasapi debug: default period : 10000000 ns
wasapi debug: minimum period : 3000000 ns
main debug: using aout stream module "wasapi"
main debug: output 'f32l' 44100 Hz Stereo frame=1 samples/8 bytes
main debug: looking for audio volume module matching "any": 2 candidates
main debug: using audio volume module "float_mixer"
main debug: input 'f32l' 48000 Hz 3F2M/LFE frame=1 samples/24 bytes
main debug: looking for audio filter module matching "scaletempo": 16 candidates
scaletempo debug: format: 48000 rate, 6 nch, 4 bps, fl32
scaletempo debug: params: 30 stride, 0.200 overlap, 14 search
scaletempo debug: 1.000 scale, 1440.000 stride_in, 1440 stride_out, 1152 standing, 288 overlap, 672 search, 2400 queue, fl32 mode
main debug: using audio filter module "scaletempo"
main debug: conversion: 'f32l'->'f32l' 48000 Hz->48000 Hz 3F2M/LFE->3F2M/LFE
main debug: conversion pipeline complete
main debug: looking for audio filter module matching "binauralizer": 16 candidates
spatialaudio debug: Using the HRTF file: C:\Program Files\VideoLAN\VLC-debug\hrtfs\dodeca_and_7channel_3DSL_HRTF.sofa
main debug: using audio filter module "spatialaudio"
main debug: conversion: 'f32l'->'f32l' 48000 Hz->48000 Hz 3F2M/LFE->3F2M/LFE
main debug: conversion pipeline complete
main debug: conversion: 'f32l'->'f32l' 44100 Hz->44100 Hz Stereo->Stereo
main debug: conversion pipeline complete
main debug: looking for audio resampler module matching "any": 3 candidates
main debug: using audio resampler module "samplerate"
main debug: Decoder wait done in 12 ms
main debug: inserting 396 zeroes
mmdevice debug: state changed: 1
main warning: playback too late (70233): up-sampling
main warning: timing screwed (drift: 143622 us): stopping resampling
main warning: playback too late (145497): up-sampling
main warning: playback way too late (183722): flushing buffers
wasapi debug: reset
mmdevice debug: state changed: 0
main debug: inserting 18917 zeroes
mmdevice debug: state changed: 1
main warning: playback too late (61933): up-sampling
main warning: timing screwed (drift: 123986 us): stopping resampling
main warning: playback too late (125337): up-sampling
main warning: playback way too late (180005): flushing buffers
wasapi debug: reset
mmdevice debug: state changed: 0
main debug: inserting 18960 zeroes
mmdevice debug: state changed: 1
main warning: playback too late (60797): up-sampling
main warning: timing screwed (drift: 123345 us): stopping resampling
main warning: playback too late (126460): up-sampling
main warning: playback way too late (183094): flushing buffers
wasapi debug: reset
main debug: inserting 18915 zeroes
mmdevice debug: state changed: 0
mmdevice debug: state changed: 1
main warning: playback too late (60946): up-sampling
main warning: timing screwed (drift: 122114 us): stopping resampling
main warning: playback too late (124624): up-sampling
main warning: playback way too late (180690): flushing buffers
wasapi debug: reset
mmdevice debug: state changed: 0
main debug: inserting 18311 zeroes
mmdevice debug: state changed: 1
main warning: playback too late (61851): up-sampling
main warning: timing screwed (drift: 126902 us): stopping resampling
main warning: playback too late (128435): up-sampling
main warning: playback way too late (183216): flushing buffers
wasapi debug: reset
mmdevice debug: state changed: 0
main debug: inserting 18913 zeroes
mmdevice debug: state changed: 1
main warning: playback too late (63902): up-sampling
main warning: timing screwed (drift: 131307 us): stopping resampling
main warning: playback too late (132976): up-sampling
main warning: playback way too late (182767): flushing buffers
wasapi debug: reset
mmdevice debug: state changed: 0
main debug: inserting 18911 zeroes
mmdevice debug: state changed: 1
main warning: playback too late (60391): up-sampling
main warning: timing screwed (drift: 121829 us): stopping resampling
main warning: playback too late (124659): up-sampling
main warning: playback way too late (180095): flushing buffers
wasapi debug: reset
mmdevice debug: state changed: 0
main debug: inserting 18910 zeroes
mmdevice debug: state changed: 1
main warning: playback too late (62706): up-sampling
main warning: timing screwed (drift: 127316 us): stopping resampling
main warning: playback too late (130250): up-sampling
main warning: playback way too late (181119): flushing buffers
Edited by Jean-Baptiste Kempf