Audio stutter (playback to late, timing screwed)

[beatles]

Hi all,

I never had big problems with the VLC player but at the moment I can't use it anymore.
Without changing any settings I have stutter issues when I am playing an mp3 file. The same issue while I am watching a movie (but also here only the audio is the problem).
All my files are on my local HD so there can't be a network problem.

I already tried to increase my cache levels etc. but nothing helped so far. I removed the newest version and installed 2.1.5 but as well here, no difference.
In my log file you find

"playback too late", "timing screwed" etc.

I am running the newest OS X: OS X El Capitan 10.11.2

Log file (newest version 2.2.1)

-- logger module started --
core debug: VLC media player - 2.2.1 Terry Pratchett (Weatherwax)
core debug: Copyright © 1996-2015 the VideoLAN team
core debug: revision 2.2.1-0-ga425c42
core debug: configured with ../extras/package/macosx/../../../configure '--prefix=/Users/fpk/Desktop/vlc-2.2/secondrelease/vlc_install_dir' '--enable-macosx' '--enable-merge-ffmpeg' '--enable-growl' '--enable-faad' '--enable-flac' '--enable-theora' '--enable-shout' '--enable-ncurses' '--enable-twolame' '--enable-realrtsp' '--enable-libass' '--enable-macosx-eyetv' '--enable-macosx-qtkit' '--enable-macosx-avfoundation' '--disable-skins2' '--disable-xcb' '--disable-caca' '--disable-sdl' '--disable-samplerate' '--disable-macosx-dialog-provider' '--with-macosx-version-min=10.6' '--build=x86_64-apple-darwin10' 'build_alias=x86_64-apple-darwin10' 'CC=xcrun clang' 'CFLAGS=' 'LDFLAGS=' 'CXX=xcrun clang++' 'OBJC=xcrun clang'
core debug: using interface module "logger"
core debug: looking for interface module matching "hotkeys,none": 15 candidates
core debug: using interface module "hotkeys"
core: Running vlc with the default interface. Use 'cvlc' to use vlc without interface.
core debug: looking for interface module matching "any": 15 candidates
macosx debug: Starting macosx interface
core debug: looking for services probe module matching "any": 5 candidates
core debug: no services probe modules matched
core debug: looking for extension module matching "any": 1 candidates
lua debug: Opening Lua Extension module
lua debug: Trying Lua scripts in /Users/petermeier 1/Library/Application Support/org.videolan.vlc/lua/extensions
lua debug: Trying Lua scripts in /Applications/VLC.app/Contents/MacOS/share/lua/extensions
lua debug: Trying Lua playlist script /Applications/VLC.app/Contents/MacOS/share/lua/extensions/VLSub.luac
lua debug: Scanning Lua script /Applications/VLC.app/Contents/MacOS/share/lua/extensions/VLSub.luac
lua debug: Script /Applications/VLC.app/Contents/MacOS/share/lua/extensions/VLSub.luac has the following capability flags: 0x5
lua debug: Trying Lua scripts in /Applications/VLC.app/Contents/MacOS/share/share/lua/extensions
core debug: using extension module "lua"
macosx debug: Found 1 video capture devices
macosx debug: Found 2 audio capture devices
macosx debug: no optical media found
core debug: adding item `06 HVOB - Dogs.mp3' ( file:///Users/petermeier%201/Downloads/Hvob%20-%20HVOB/06%20HVOB%20-%20Dogs.mp3 )
core debug: processing request item: 06 HVOB - Dogs.mp3, node: Playlist, skip: 0
core debug: rebuilding array of current - root Playlist
core debug: rebuild done - 1 items, index 0
core debug: starting playback of the new playlist item
core debug: resyncing on 06 HVOB - Dogs.mp3
core debug: 06 HVOB - Dogs.mp3 is at 0
core debug: creating new input thread
core debug: Creating an input for '06 HVOB - Dogs.mp3'
core debug: requesting art for 06 HVOB - Dogs.mp3
core debug: Creating an input for '06 HVOB - Dogs.mp3'
core debug: using timeshift granularity of 50 MiB, in path '/tmp'
core debug: `file:///Users/petermeier%201/Downloads/Hvob%20-%20HVOB/06%20HVOB%20-%20Dogs.mp3' gives access `file' demux `' path `/Users/petermeier%201/Downloads/Hvob%20-%20HVOB/06%20HVOB%20-%20Dogs.mp3'
core debug: specified demux `any'
core debug: creating demux: access='file' demux='any' location='/Users/petermeier%201/Downloads/Hvob%20-%20HVOB/06%20HVOB%20-%20Dogs.mp3' file='/Users/petermeier 1/Downloads/Hvob - HVOB/06 HVOB - Dogs.mp3'
core debug: looking for access_demux module matching "file": 14 candidates
core debug: looking for meta fetcher module matching "any": 1 candidates
lua debug: Trying Lua scripts in /Users/petermeier 1/Library/Application Support/org.videolan.vlc/lua/meta/fetcher
lua debug: Trying Lua scripts in /Applications/VLC.app/Contents/MacOS/share/lua/meta/fetcher
lua debug: Trying Lua playlist script /Applications/VLC.app/Contents/MacOS/share/lua/meta/fetcher/tvrage.luac
core debug: no access_demux modules matched
core debug: creating access 'file' location='/Users/petermeier%201/Downloads/Hvob%20-%20HVOB/06%20HVOB%20-%20Dogs.mp3', path='/Users/petermeier 1/Downloads/Hvob - HVOB/06 HVOB - Dogs.mp3'
core debug: looking for access module matching "file": 19 candidates
filesystem debug: opening file `/Users/petermeier 1/Downloads/Hvob - HVOB/06 HVOB - Dogs.mp3'
lua debug: skipping script (unmatched scope) /Applications/VLC.app/Contents/MacOS/share/lua/meta/fetcher/tvrage.luac
core debug: using access module "filesystem"
lua debug: Trying Lua scripts in /Applications/VLC.app/Contents/MacOS/share/share/lua/meta/fetcher
core debug: Using stream method for AStream*
core debug: no meta fetcher modules matched
core debug: starting pre-buffering
core debug: searching art for 06 HVOB - Dogs.mp3
core debug: received first data after 0 ms
core debug: pre-buffering done 1024 bytes in 0s - 5780 KiB/s
core debug: looking for stream_filter module matching "any": 9 candidates
core debug: no stream_filter modules matched
core debug: looking for stream_filter module matching "record": 9 candidates
core debug: looking for art finder module matching "any": 2 candidates
core debug: using stream_filter module "record"
core debug: creating demux: access='file' demux='any' location='/Users/petermeier%201/Downloads/Hvob%20-%20HVOB/06%20HVOB%20-%20Dogs.mp3' file='/Users/petermeier 1/Downloads/Hvob - HVOB/06 HVOB - Dogs.mp3'
core debug: ID3v2.3 revision 0 tag found, skipping 411086 bytes
core debug: looking for demux module matching "any": 66 candidates
lua debug: Trying Lua scripts in /Users/petermeier 1/Library/Application Support/org.videolan.vlc/lua/meta/art
lua debug: Trying Lua scripts in /Applications/VLC.app/Contents/MacOS/share/lua/meta/art
lua debug: Trying Lua playlist script /Applications/VLC.app/Contents/MacOS/share/lua/meta/art/00_musicbrainz.luac
lua debug: skipping script (unmatched scope) /Applications/VLC.app/Contents/MacOS/share/lua/meta/art/00_musicbrainz.luac
lua debug: Trying Lua playlist script /Applications/VLC.app/Contents/MacOS/share/lua/meta/art/01_googleimage.luac
lua debug: skipping script (unmatched scope) /Applications/VLC.app/Contents/MacOS/share/lua/meta/art/01_googleimage.luac
lua debug: Trying Lua playlist script /Applications/VLC.app/Contents/MacOS/share/lua/meta/art/02_frenchtv.luac
lua debug: skipping script (unmatched scope) /Applications/VLC.app/Contents/MacOS/share/lua/meta/art/02_frenchtv.luac
lua debug: Trying Lua playlist script /Applications/VLC.app/Contents/MacOS/share/lua/meta/art/03_lastfm.luac
lua debug: skipping script (unmatched scope) /Applications/VLC.app/Contents/MacOS/share/lua/meta/art/03_lastfm.luac
lua debug: Trying Lua scripts in /Applications/VLC.app/Contents/MacOS/share/share/lua/meta/art
core debug: no art finder modules matched
core debug: art not found for 06 HVOB - Dogs.mp3
core debug: Creating an input for '06 HVOB - Dogs.mp3'
es debug: detected format mpga
core debug: looking for packetizer module matching "any": 23 candidates
core debug: using packetizer module "mpeg_audio"
es debug: did not sync on first block
mpeg_audio debug: MPGA channels:2 samplerate:44100 bitrate:320
core debug: selecting program id=0
core debug: using demux module "es"
core debug: looking for a subtitle file in /Users/petermeier 1/Downloads/Hvob - HVOB/
core debug: looking for decoder module matching "any": 40 candidates
core debug: no fetch required for Dogs (art currently file:///Users/petermeier%201/Library/Caches/org.videolan.vlc/art/artistalbum/HVOB/HVOB/art.jpg)
core debug: no fetch required for Dogs (art currently file:///Users/petermeier%201/Library/Caches/org.videolan.vlc/art/artistalbum/HVOB/HVOB/art.jpg)
core debug: no fetch required for Dogs (art currently file:///Users/petermeier%201/Library/Caches/org.videolan.vlc/art/artistalbum/HVOB/HVOB/art.jpg)
core debug: using decoder module "mpeg_audio"
core debug: looking for meta reader module matching "any": 2 candidates
taglib debug: Found embedded art: 3 (image/jpeg) is 408854 bytes
core debug: using meta reader module "taglib"
core debug: removing module "taglib"
core debug: `file:///Users/petermeier%201/Downloads/Hvob%20-%20HVOB/06%20HVOB%20-%20Dogs.mp3' successfully opened
core debug: Buffering 0%
core debug: Buffering 2%
mpeg_audio debug: MPGA channels:2 samplerate:44100 bitrate:320
core debug: Buffering 5%
core debug: reusing audio output
core debug: Buffering 7%
core debug: VLC is looking for: 'mpga' 44100 Hz Stereo frame=1152 samples/1053 bytes
core debug: Buffering 10%
auhal debug: attempting to use device 0
core debug: Buffering 13%
core debug: Buffering 15%
core debug: Buffering 18%
auhal debug: using default audio device 55
core debug: Buffering 20%
auhal debug: found 9 stream formats for stream id 56
core debug: Buffering 23%
core debug: Buffering 26%
auhal debug: Audio device supports PCM mode only
core debug: Buffering 28%
core debug: Buffering 31%
core debug: Buffering 33%
core debug: Buffering 36%
auhal debug: Current device has a latency of 16 frames
core debug: Buffering 39%
core debug: Buffering 41%
core debug: Buffering 44%
core debug: Buffering 47%
core debug: Buffering 49%
core debug: Buffering 52%
core debug: Buffering 54%
core debug: Buffering 57%
core debug: Buffering 60%
core debug: Buffering 62%
core debug: Buffering 65%
core debug: Buffering 67%
core debug: Buffering 70%
core debug: Buffering 73%
core debug: Buffering 75%
core debug: Buffering 78%
core debug: Buffering 80%
core debug: Buffering 83%
core debug: Buffering 86%
core debug: Buffering 88%
core debug: Buffering 91%
core debug: Buffering 94%
core debug: Buffering 96%
core debug: Buffering 99%
core debug: Stream buffering done (1018 ms in 2 ms)
auhal debug: current format is: [44100.000000][mcpl][9][8][1][8][2][32]
auhal debug: layout of AUHAL has 2 channels
auhal debug: selected 2 physical channels for device output
auhal debug: VLC will output: Stereo
auhal debug: we set the AU format: [44100.000000][mcpl][9][8][1][8][2][32]
auhal debug: the actual set AU format is [44100.000000][mcpl][9][8][1][8][2][32]
auhal debug: analog output successfully opened
core debug: output 'f32l' 44100 Hz Stereo frame=1 samples/8 bytes
core debug: looking for audio volume module matching "any": 2 candidates
core debug: using audio volume module "float_mixer"
core debug: input 'mpga' 44100 Hz Stereo frame=1152 samples/1053 bytes
core debug: looking for audio filter module matching "scaletempo": 14 candidates
scaletempo debug: format: 44100 rate, 2 nch, 4 bps, fl32
scaletempo debug: params: 30 stride, 0.200 overlap, 14 search
scaletempo debug: 1.000 scale, 1323.000 stride_in, 1323 stride_out, 1059 standing, 264 overlap, 617 search, 2204 queue, fl32 mode
core debug: using audio filter module "scaletempo"
core debug: conversion: 'mpga'->'f32l' 44100 Hz->44100 Hz Stereo->Stereo
core debug: looking for audio converter module matching "any": 11 candidates
core debug: no audio converter modules matched
core debug: looking for audio converter module matching "any": 11 candidates
mpgatofixed32 debug: mpga->f32l, bits per sample: 32
core debug: using audio converter module "mpgatofixed32"
core debug: conversion pipeline complete
core debug: conversion: 'f32l'->'f32l' 44100 Hz->44100 Hz Stereo->Stereo
core debug: conversion pipeline complete
core debug: looking for audio resampler module matching "any": 2 candidates
core debug: using audio resampler module "ugly_resampler"
core debug: End of audio preroll
core debug: Decoder wait done in 34 ms
macosx debug: Enable media key support
core warning: playback too late (83507): up-sampling
macosx debug: prevented sleep through IOKit (6638)
core warning: playback way too late (185114): flushing buffers
core debug: inserting 48124 zeroes
core warning: playback too late (75522): up-sampling
core warning: timing screwed (drift: 156192 us): stopping resampling
core warning: playback too late (156506): up-sampling
core warning: playback way too late (204553): flushing buffers
core debug: inserting 46600 zeroes
core warning: playback too late (88209): up-sampling
core warning: playback way too late (204367): flushing buffers
core debug: inserting 46540 zeroes
core warning: playback too late (76750): up-sampling
core warning: timing screwed (drift: 155274 us): stopping resampling
core warning: playback too late (148106): up-sampling
core warning: playback way too late (197817): flushing buffers
core debug: inserting 47157 zeroes
core warning: playback too late (64963): up-sampling
core debug: incoming request - stopping current input
core debug: control: stopping input
core debug: incoming request - stopping current input
core debug: finished input
core debug: removing module "mpeg_audio"
core debug: killing decoder fourcc `mpga', 0 PES in FIFO
core debug: removing module "ugly_resampler"
core debug: removing module "mpgatofixed32"
core debug: removing module "scaletempo"
auhal debug: Stopping the auhal module
core debug: removing module "float_mixer"
core debug: keeping audio output
core debug: removing module "es"
core debug: removing module "mpeg_audio"
core debug: removing module "record"
core debug: removing module "filesystem"
core debug: Program doesn't contain anymore ES
core debug: incoming request - stopping current input
core debug: dead input
macosx debug: releasing sleep blocker (6638)

Thank you for any suggestions...

[homemacine]

Hi,

I have the same problem here. Listening music with Quicktime or iTunes... no problem, but with VLC my songs stop for 1 second randomly and continue again playing until stop again. I never had problems with VLC before.

I'm on iMac 27" i7 quad core 32Gb RAM mid 2011 and OS X El Capitan updated up today with VLC Version 2.2.1 Terry Pratchett (Weatherwax) (Intel 64bit)


Sorry for my bad english.


Thanx in advance... Best regards.

[dfuhrmann]

Whats you audio output device?

[homemacine]

I'm using the standard integrated audio output on iMac... I don't have any additional audio device. By the way... I've found this repeated error on log messages when playing a song.

Code: Select all

macosx debug: releasing old sleep blocker (2264) macosx debug: prevented sleep through IOKit (2265) core debug: Buffering 62% core debug: Buffering 73% core debug: Buffering 83% core debug: Buffering 94% core debug: Stream buffering done (1044 ms in 631 ms) core debug: Decoder wait done in 0 ms core warning: playback too late (165210): up-sampling core error: ES_OUT_SET_(GROUP_)PCR is called too late (pts_delay increased to 1000 ms) core error: ES_OUT_RESET_PCR called core debug: End of audio preroll core debug: Buffering 0% core debug: Buffering 10% core debug: Buffering 20% core debug: Buffering 31% core debug: Buffering 41% core debug: Buffering 52% core debug: Buffering 62% core debug: Buffering 73% core debug: Buffering 83% core debug: Buffering 94% core debug: Stream buffering done (1044 ms in 1456 ms) core debug: Decoder wait done in 0 ms core warning: buffer too late (-94503 us): dropped core debug: playback too late (165258): flushing buffers core warning: playback too late (165274): up-sampling core error: ES_OUT_SET_(GROUP_)PCR is called too late (pts_delay increased to 1008 ms) core error: ES_OUT_RESET_PCR called core debug: End of audio preroll core debug: Buffering 0% core debug: Buffering 10% core debug: Buffering 20% core debug: Buffering 31% core debug: Buffering 41% core debug: Buffering 51% core debug: Buffering 62% core debug: Buffering 72% core debug: Buffering 82% core debug: Buffering 93% core debug: Stream buffering done (1044 ms in 1498 ms) core debug: Decoder wait done in 0 ms core warning: buffer too late (-94502 us): dropped core debug: playback too late (165255): flushing buffers core warning: playback too late (165272): up-sampling core error: ES_OUT_SET_(GROUP_)PCR is called too late (pts_delay increased to 1008 ms) core error: ES_OUT_RESET_PCR called core debug: End of audio preroll core debug: Buffering 0% core debug: Buffering 10%

[dreadLocks]

Any solution to this, i have the same problem.

https://forum.videolan.org/viewtopic.ph ... ng#p443625