Skip to content

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
To upload designs, you'll need to enable LFS and have an admin enable hashed storage. More information