VLC 2.1.2 sporadic 1-2 sec audio drop out

[le_sacre]

Since updating to 2.1.2, every 30 minutes or so of playback, audio drops out for about 1-2 seconds. Sync is still fine. Many different file formats affected. OS X 10.6.8, MBP 6,2.

[trialanderror]

Sounds the similar to mine. See my post yesterday titled "Version 2.1.2 with OSX10.9 Crash whilst playing from NAS"
I've downgraded to 2.0.9 and all problem stops.

[le_sacre]

Seems quite different actually (from what's described at https://forum.videolan.org/viewtopic.php?f=12&t=115932). I have no crash, and no pause or other problem in the video. Just the audio cuts out briefly, as described.

[dfuhrmann]

Please upload a VLC log.

[le_sacre]

Sorry for this long reply; couldn't find an upload function in the application or on this forum interface.

I assume the problem might be near the end, where it says "main warning: playback way too early (-161260): playing silence"?


main debug: starting playback of the new playlist item
main debug: resyncing on S03E01.mp4
main debug: S03E01.mp4 is at 0
main debug: creating new input thread
main debug: Creating an input for 'S03E01.mp4'
main debug: using timeshift granularity of 50 MiB, in path '/tmp'
main debug: `file:///Volumes/Dmitry/-video/project.runway/S03E01.mp4' gives access `file' demux `' path `/Volumes/Dmitry/-video/project.runway/S03E01.mp4'
macosx debug: releasing sleep blocker (300)
main debug: creating demux: access='file' demux='' location='/Volumes/Dmitry/-video/project.runway/S03E01.mp4' file='/Volumes/Dmitry/-video/project.runway/S03E01.mp4'
main debug: looking for access_demux module matching "file": 13 candidates
macosx debug: releasing sleep blocker (300)
macosx debug: toggle playlist from state: removed splitview 0, minimized view 0. Sender is 0x0, unhide video view 1
macosx debug: toggle playlist to state: removed splitview 0, minimized view 0
main debug: no access_demux modules matched
main debug: creating access 'file' location='/Volumes/Dmitry/-video/project.runway/S03E01.mp4', path='/Volumes/Dmitry/-video/project.runway/S03E01.mp4'
main debug: looking for access module matching "file": 18 candidates
filesystem debug: opening file `/Volumes/Dmitry/-video/project.runway/S03E01.mp4'
main debug: using access module "filesystem"
main debug: Using stream method for AStream*
main debug: starting pre-buffering
main debug: received first data after 0 ms
main debug: pre-buffering done 1024 bytes in 0s - 3401 KiB/s
main debug: looking for stream_filter module matching "any": 9 candidates
main debug: no stream_filter modules matched
main debug: looking for stream_filter module matching "record": 9 candidates
main debug: using stream_filter module "record"
main debug: creating demux: access='file' demux='' location='/Volumes/Dmitry/-video/project.runway/S03E01.mp4' file='/Volumes/Dmitry/-video/project.runway/S03E01.mp4'
main debug: looking for demux module matching "mp4": 63 candidates
mp4 warning: unknown box type colr (incompletely loaded)
mp4 warning: cannot read one box
mp4 debug: dumping root Box "root"
mp4 debug: | + ftyp size 28
mp4 debug: | + moov size 1559444
mp4 debug: | | + mvhd size 108
mp4 debug: | | + iods size 24
mp4 debug: | | + trak size 1021864
mp4 debug: | | | + tkhd size 92
mp4 debug: | | | + mdia size 1021728
mp4 debug: | | | | + mdhd size 32
mp4 debug: | | | | + hdlr size 33
mp4 debug: | | | | + minf size 1021655
mp4 debug: | | | | | + vmhd size 20
mp4 debug: | | | | | + dinf size 36
mp4 debug: | | | | | | + dref size 28
mp4 debug: | | | | | | | + url size 12
mp4 debug: | | | | | + stbl size 1021591
mp4 debug: | | | | | | + stsd size 194
mp4 debug: | | | | | | | + avc1 size 178
mp4 debug: | | | | | | | | + avcC size 58
mp4 debug: | | | | | | | | + colr size 18
mp4 debug: | | | | | | | | + pasp size 16
mp4 debug: | | | | | | + stts size 24
mp4 debug: | | | | | | + stsz size 300392
mp4 debug: | | | | | | + stsc size 40
mp4 debug: | | | | | | + stco size 75112
mp4 debug: | | | | | | + ctts size 565976
mp4 debug: | | | | | | + stss size 4740
mp4 debug: | | | | | | + sdtp size 75105
mp4 debug: | | | + edts size 36
mp4 debug: | | | | + elst size 28
mp4 debug: | | + trak size 537329
mp4 debug: | | | + tkhd size 92
mp4 debug: | | | + mdia size 537207
mp4 debug: | | | | + mdhd size 32
mp4 debug: | | | | + hdlr size 33
mp4 debug: | | | | + minf size 537134
mp4 debug: | | | | | + smhd size 16
mp4 debug: | | | | | + dinf size 36
mp4 debug: | | | | | | + dref size 28
mp4 debug: | | | | | | | + url size 12
mp4 debug: | | | | | + stbl size 537074
mp4 debug: | | | | | | + stsd size 106
mp4 debug: | | | | | | | + mp4a size 90
mp4 debug: | | | | | | | | + esds size 54
mp4 debug: | | | | | | + stts size 24
mp4 debug: | | | | | | + stsz size 469772
mp4 debug: | | | | | | + stsc size 40
mp4 debug: | | | | | | + stco size 67124
mp4 debug: | | | + udta size 22
mp4 debug: | | | | + name size 14
mp4 debug: | | + udta size 111
mp4 debug: | | | + meta size 103
mp4 debug: | | | | + hdlr size 33
mp4 debug: | | | | + ilst size 58
mp4 debug: | | | | | + ctoo size 50
mp4 debug: | + mdat size 372516300
mp4 debug: unrecognized major file specification (mp42).
mp4 debug: found 2 tracks
mp4 warning: elst box found
mp4 debug: - [0] duration=2505603ms media time=66ms) rate=1.0
mp4 debug: track[Id 0x1] read 18774 chunk
mp4 warning: CTTS table
mp4 debug: track[Id 0x1] read 75093 samples length:2505s
main debug: selecting program id=0
mp4 debug: adding track[Id 0x1] video (enable) language undef
mp4 debug: track[Id 0x2] read 16777 chunk
mp4 debug: track[Id 0x2] read 117438 samples length:2505s
mp4 debug: adding track[Id 0x2] audio (enable) language undef
main debug: using demux module "mp4"
main debug: looking for a subtitle file in /Volumes/Dmitry/-video/project.runway/
main debug: looking for decoder module matching "any": 38 candidates
avcodec debug: trying to use direct rendering
avcodec debug: allowing 4 thread(s) for decoding
avcodec debug: avcodec codec (H264 - MPEG-4 AVC (part 10)) started
avcodec debug: using frame thread mode with 4 threads
main debug: using decoder module "avcodec"
main debug: looking for decoder module matching "any": 38 candidates
main debug: using decoder module "faad"
main debug: looking for meta reader module matching "any": 2 candidates
lua debug: Trying Lua scripts in /Users/tj/Library/Application Support/org.videolan.vlc/lua/meta/reader
lua debug: Trying Lua scripts in /Applications/VLC.app/Contents/MacOS/share/lua/meta/reader
lua debug: Trying Lua playlist script /Applications/VLC.app/Contents/MacOS/share/lua/meta/reader/filename.luac
lua debug: Trying Lua scripts in /Applications/VLC.app/Contents/MacOS/share/share/lua/meta/reader
main debug: no meta reader modules matched
main debug: `file:///Volumes/Dmitry/-video/project.runway/S03E01.mp4' successfully opened
mp4 debug: elst (0) gives 0ms (movie)-> 66ms (track)
mp4 debug: track[Id 0x1] using Sync Sample Box (stss)
mp4 debug: stts gives 2 --> 0 (sample number)
mp4 debug: track[Id 0x2] does not provide Sync Sample Box (stss)
main debug: Buffering 0%
main debug: Buffering 0%
main debug: Buffering 10%
main debug: Buffering 20%
main debug: Buffering 30%
faad warning: decoded zero sample
main debug: Buffering 40%
main debug: Buffering 50%
main debug: Buffering 60%
main debug: trying to reuse free vout
main debug: Buffering 70%
main debug: removing module "freetype"
main debug: Buffering 80%
main debug: Buffering 90%
main debug: Buffering 100%
main debug: Stream buffering done (1100 ms in 1 ms)
main debug: looking for text renderer module matching "any": 3 candidates
freetype debug: looking for Arial Unicode MS
freetype debug: found /Library/Fonts/Arial Unicode.ttf
freetype debug: Using Arial Unicode MS as font from file /Library/Fonts/Arial Unicode.ttf
freetype debug: using fontsize: 2
main debug: using text renderer module "freetype"
main debug: removing module "vout_macosx"
main debug: Opening vout display wrapper
main debug: looking for vout display module matching "any": 5 candidates
vout_macosx debug: Quartz Extreme acceleration is active
main debug: Reusing previous vout window
macosx debug: releasing old sleep blocker (300)
macosx debug: prevented sleep through IOKit (300)
main debug: VoutDisplayEvent 'resize' 686x344 window
main debug: using vout display module "vout_macosx"
main debug: original format sz 686x344, of (0,0), vsz 686x344, 4cc I420, sar 3884:4369, msk r0x0 g0x0 b0x0
main debug: reusing provided vout
main debug: reusing audio output
avcodec debug: using direct rendering
main debug: VLC is looking for: 'f32l' 48000 Hz Stereo frame=1 samples/8 bytes
auhal debug: attempting to use device 268
auhal debug: found 16 stream formats for stream id 269
auhal debug: Audio device supports PCM mode only
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: [48000.000000][mcpl][9][8][1][8][2][32]
auhal debug: the actual set AU format is [48000.000000][mcpl][9][8][1][8][2][32]
auhal debug: analog output successfully opened
main debug: output 'f32l' 48000 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 Stereo frame=1 samples/8 bytes
main debug: looking for audio filter module matching "scaletempo": 14 candidates
scaletempo debug: format: 48000 rate, 2 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 Stereo->Stereo
main debug: conversion pipeline complete
main debug: conversion: 'f32l'->'f32l' 48000 Hz->48000 Hz Stereo->Stereo
main debug: conversion pipeline complete
main debug: looking for audio resampler module matching "any": 2 candidates
main debug: using audio resampler module "ugly_resampler"
main debug: End of audio preroll
main debug: End of video preroll
main debug: Received first picture
freetype debug: looking for Arial Unicode MS
freetype debug: found /Library/Fonts/Arial Unicode.ttf
main debug: Decoder buffering done in 125 ms
main warning: playback way too early (-161260): playing silence
main debug: inserting 7740 zeroes
main debug: VoutDisplayEvent 'resize' 1920x1080 fullscreen
main warning: picture is too late to be displayed (missing 91 ms)
main warning: picture is too late to be displayed (missing 58 ms)
main warning: picture is too late to be displayed (missing 25 ms)
main debug: picture might be displayed late (missing 17 ms)
main debug: picture might be displayed late (missing 18 ms)
main debug: picture might be displayed late (missing 5 ms)
main warning: picture is too late to be displayed (missing 263 ms)
main warning: picture is too late to be displayed (missing 230 ms)
main warning: picture is too late to be displayed (missing 197 ms)
main warning: picture is too late to be displayed (missing 163 ms)
main warning: picture is too late to be displayed (missing 130 ms)
main warning: picture is too late to be displayed (missing 97 ms)
main warning: picture is too late to be displayed (missing 63 ms)
main warning: picture is too late to be displayed (missing 30 ms)
main warning: playback way too late (277589): flushing buffers
main debug: inserting 54633 zeroes
main debug: picture might be displayed late (missing 15 ms)
main debug: picture might be displayed late (missing 0 ms)

[dfuhrmann]

It looks like this is only the log for the start of file. Interesting would be the parts where it actually drops audio. "playback way too early" might happen on the start of file, but if you see this or something similar in the middle of the playback, this might be the issue.

[keKs]

Code: Select all

auhal debug: default device changed to 47 core debug: restart requested (2) auhal debug: using default audio device 47 auhal debug: default device changed to 47 auhal debug: found 23 stream formats for stream id 48 auhal debug: Using audio device for digital output auhal debug: original stream format: [44100.000000][mcpl][4][8][1][8][2][24] auhal debug: setting stream format: [48000.000000][3cac][76][6144][1536][0][2][16] auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: actual format in use: [48000.000000][3cac][76][6144][1536][0][2][16] auhal debug: digital output successfully opened core debug: output 'spdi' 48000 Hz 3F2R/LFE frame=1536 samples/6144 bytes core debug: looking for audio volume module matching "any": 2 candidates core debug: no audio volume modules matched core debug: restarting filters... core debug: input 'a52 ' 48000 Hz 3F2R/LFE frame=1536 samples/1536 bytes core debug: pass-through: 'a52 '->'spdi' 48000 Hz->48000 Hz 3F2R/LFE->3F2R/LFE core debug: looking for audio converter module matching "any": 11 candidates core debug: using audio converter module "a52tospdif" core warning: buffer too late (-8259235 us): dropped core debug: removing module "a52tospdif" core debug: restarting output... auhal debug: setting stream format: [44100.000000][mcpl][4][8][1][8][2][24] auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: actual format in use: [44100.000000][mcpl][4][8][1][8][2][24] core debug: VLC is looking for: 'a52 ' 48000 Hz 3F2R/LFE frame=1536 samples/1536 bytes auhal debug: attempting to use device 0 auhal debug: default device changed to 47 auhal debug: default device actually changed, resetting aout core debug: restart requested (2) auhal debug: using default audio device 47 auhal debug: default device changed to 47 auhal debug: found 23 stream formats for stream id 48 auhal debug: Using audio device for digital output auhal debug: original stream format: [44100.000000][mcpl][4][8][1][8][2][24] auhal debug: setting stream format: [48000.000000][3cac][76][6144][1536][0][2][16] auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: actual format in use: [48000.000000][3cac][76][6144][1536][0][2][16] auhal debug: digital output successfully opened core debug: output 'spdi' 48000 Hz 3F2R/LFE frame=1536 samples/6144 bytes core debug: looking for audio volume module matching "any": 2 candidates core debug: no audio volume modules matched core debug: restarting filters... core debug: input 'a52 ' 48000 Hz 3F2R/LFE frame=1536 samples/1536 bytes core debug: pass-through: 'a52 '->'spdi' 48000 Hz->48000 Hz 3F2R/LFE->3F2R/LFE core debug: looking for audio converter module matching "any": 11 candidates core debug: using audio converter module "a52tospdif" core warning: buffer too late (-8884434 us): dropped core debug: removing module "a52tospdif" core debug: restarting output... core error: ES_OUT_SET_(GROUP_)PCR is called too late (jitter of 8956 ms ignored) core warning: early picture skipped auhal debug: setting stream format: [44100.000000][mcpl][4][8][1][8][2][24] core warning: early picture skipped core warning: early picture skipped core warning: early picture skipped core warning: early picture skipped auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active core warning: early picture skipped core warning: early picture skipped core warning: picture is too late to be displayed (missing 4480 ms) auhal debug: actual format in use: [44100.000000][mcpl][4][8][1][8][2][24] core debug: VLC is looking for: 'a52 ' 48000 Hz 3F2R/LFE frame=1536 samples/1536 bytes auhal debug: attempting to use device 0 auhal debug: default device changed to 47 auhal debug: using default audio device 47 auhal debug: default device actually changed, resetting aout auhal debug: default device changed to 47 core debug: restart requested (2) auhal debug: found 23 stream formats for stream id 48 auhal debug: Using audio device for digital output auhal debug: original stream format: [44100.000000][mcpl][4][8][1][8][2][24] auhal debug: setting stream format: [48000.000000][3cac][76][6144][1536][0][2][16] auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: actual format in use: [48000.000000][3cac][76][6144][1536][0][2][16] auhal debug: digital output successfully opened core debug: output 'spdi' 48000 Hz 3F2R/LFE frame=1536 samples/6144 bytes core debug: looking for audio volume module matching "any": 2 candidates core debug: no audio volume modules matched core debug: restarting filters... core debug: input 'a52 ' 48000 Hz 3F2R/LFE frame=1536 samples/1536 bytes core debug: pass-through: 'a52 '->'spdi' 48000 Hz->48000 Hz 3F2R/LFE->3F2R/LFE core debug: looking for audio converter module matching "any": 11 candidates core debug: using audio converter module "a52tospdif" core warning: buffer too late (-9511528 us): dropped core debug: discarded audio buffer core debug: discarded audio buffer core debug: discarded audio buffer core debug: discarded audio buffer core debug: discarded audio buffer core debug: discarded audio buffer core debug: discarded audio buffer core debug: discarded audio buffer core debug: discarded audio buffer core debug: discarded audio buffer core debug: discarded audio buffer core debug: discarded audio buffer core warning: early picture skipped core debug: discarded audio buffer core debug: discarded audio buffer core warning: early picture skipped core debug: discarded audio buffer core debug: discarded audio buffer core debug: discarded audio buffer core warning: early picture skipped core debug: discarded audio buffer core debug: removing module "a52tospdif" core debug: restarting output... auhal debug: setting stream format: [44100.000000][mcpl][4][8][1][8][2][24] auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: actual format in use: [44100.000000][mcpl][4][8][1][8][2][24] core debug: VLC is looking for: 'a52 ' 48000 Hz 3F2R/LFE frame=1536 samples/1536 bytes auhal debug: attempting to use device 0 auhal debug: default device changed to 47 auhal debug: default device actually changed, resetting aout core debug: restart requested (2) auhal debug: using default audio device 47 auhal debug: found 23 stream formats for stream id 48 auhal debug: Using audio device for digital output auhal debug: default device changed to 47 auhal debug: ignore, as digital mode is active auhal debug: original stream format: [44100.000000][mcpl][4][8][1][8][2][24] auhal debug: setting stream format: [48000.000000][3cac][76][6144][1536][0][2][16] auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: actual format in use: [48000.000000][3cac][76][6144][1536][0][2][16] auhal debug: digital output successfully opened core debug: output 'spdi' 48000 Hz 3F2R/LFE frame=1536 samples/6144 bytes core debug: looking for audio volume module matching "any": 2 candidates core debug: no audio volume modules matched core debug: restarting filters... core debug: input 'a52 ' 48000 Hz 3F2R/LFE frame=1536 samples/1536 bytes core debug: pass-through: 'a52 '->'spdi' 48000 Hz->48000 Hz 3F2R/LFE->3F2R/LFE core debug: looking for audio converter module matching "any": 11 candidates core debug: using audio converter module "a52tospdif" core warning: buffer too late (-122245 us): dropped core debug: removing module "a52tospdif" core debug: restarting output... auhal debug: setting stream format: [44100.000000][mcpl][4][8][1][8][2][24] auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: actual format in use: [44100.000000][mcpl][4][8][1][8][2][24] core debug: VLC is looking for: 'a52 ' 48000 Hz 3F2R/LFE frame=1536 samples/1536 bytes auhal debug: attempting to use device 0 auhal debug: default device changed to 47 auhal debug: using default audio device 47 auhal debug: default device actually changed, resetting aout auhal debug: default device changed to 47 core debug: restart requested (2) auhal debug: found 23 stream formats for stream id 48 auhal debug: Using audio device for digital output auhal debug: original stream format: [44100.000000][mcpl][4][8][1][8][2][24] auhal debug: setting stream format: [48000.000000][3cac][76][6144][1536][0][2][16] auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: actual format in use: [48000.000000][3cac][76][6144][1536][0][2][16] auhal debug: digital output successfully opened core debug: output 'spdi' 48000 Hz 3F2R/LFE frame=1536 samples/6144 bytes core debug: looking for audio volume module matching "any": 2 candidates core debug: no audio volume modules matched core debug: restarting filters... core debug: input 'a52 ' 48000 Hz 3F2R/LFE frame=1536 samples/1536 bytes core debug: pass-through: 'a52 '->'spdi' 48000 Hz->48000 Hz 3F2R/LFE->3F2R/LFE core debug: looking for audio converter module matching "any": 11 candidates core debug: using audio converter module "a52tospdif" core warning: buffer too late (-749922 us): dropped core debug: removing module "a52tospdif" core debug: restarting output... auhal debug: setting stream format: [44100.000000][mcpl][4][8][1][8][2][24] auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: actual format in use: [44100.000000][mcpl][4][8][1][8][2][24] core debug: VLC is looking for: 'a52 ' 48000 Hz 3F2R/LFE frame=1536 samples/1536 bytes auhal debug: attempting to use device 0 auhal debug: default device changed to 47 auhal debug: using default audio device 47 auhal debug: default device actually changed, resetting aout core debug: restart requested (2) auhal debug: default device changed to 47 auhal debug: found 23 stream formats for stream id 48 auhal debug: Using audio device for digital output auhal debug: original stream format: [44100.000000][mcpl][4][8][1][8][2][24] auhal debug: setting stream format: [48000.000000][3cac][76][6144][1536][0][2][16] auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: actual format in use: [48000.000000][3cac][76][6144][1536][0][2][16] auhal debug: digital output successfully opened core debug: output 'spdi' 48000 Hz 3F2R/LFE frame=1536 samples/6144 bytes core debug: looking for audio volume module matching "any": 2 candidates core debug: no audio volume modules matched core debug: restarting filters... core debug: input 'a52 ' 48000 Hz 3F2R/LFE frame=1536 samples/1536 bytes core debug: pass-through: 'a52 '->'spdi' 48000 Hz->48000 Hz 3F2R/LFE->3F2R/LFE core debug: looking for audio converter module matching "any": 11 candidates core debug: using audio converter module "a52tospdif" core warning: buffer too late (-1377853 us): dropped core debug: removing module "a52tospdif" core debug: restarting output... auhal debug: setting stream format: [44100.000000][mcpl][4][8][1][8][2][24] auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: actual format in use: [44100.000000][mcpl][4][8][1][8][2][24] core debug: VLC is looking for: 'a52 ' 48000 Hz 3F2R/LFE frame=1536 samples/1536 bytes auhal debug: attempting to use device 0 auhal debug: default device changed to 47 auhal debug: default device actually changed, resetting aout core debug: restart requested (2) auhal debug: using default audio device 47 auhal debug: default device changed to 47 auhal debug: found 23 stream formats for stream id 48 auhal debug: Using audio device for digital output auhal debug: original stream format: [44100.000000][mcpl][4][8][1][8][2][24] auhal debug: setting stream format: [48000.000000][3cac][76][6144][1536][0][2][16] auhal debug: default device changed to 47 auhal debug: ignore, as digital mode is active auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: actual format in use: [48000.000000][3cac][76][6144][1536][0][2][16] auhal debug: digital output successfully opened core debug: output 'spdi' 48000 Hz 3F2R/LFE frame=1536 samples/6144 bytes core debug: looking for audio volume module matching "any": 2 candidates core debug: no audio volume modules matched core debug: restarting filters... core debug: input 'a52 ' 48000 Hz 3F2R/LFE frame=1536 samples/1536 bytes core debug: pass-through: 'a52 '->'spdi' 48000 Hz->48000 Hz 3F2R/LFE->3F2R/LFE core debug: looking for audio converter module matching "any": 11 candidates core debug: using audio converter module "a52tospdif" core warning: buffer too late (-2001536 us): dropped core debug: removing module "a52tospdif" core debug: restarting output... auhal debug: setting stream format: [44100.000000][mcpl][4][8][1][8][2][24] auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: actual format in use: [44100.000000][mcpl][4][8][1][8][2][24] core debug: VLC is looking for: 'a52 ' 48000 Hz 3F2R/LFE frame=1536 samples/1536 bytes auhal debug: attempting to use device 0 auhal debug: default device changed to 47 auhal debug: default device actually changed, resetting aout core debug: restart requested (2) auhal debug: using default audio device 47 auhal debug: default device changed to 47 auhal debug: found 23 stream formats for stream id 48 auhal debug: Using audio device for digital output auhal debug: original stream format: [44100.000000][mcpl][4][8][1][8][2][24] auhal debug: setting stream format: [48000.000000][3cac][76][6144][1536][0][2][16] auhal debug: default device changed to 47 auhal debug: ignore, as digital mode is active auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: actual format in use: [48000.000000][3cac][76][6144][1536][0][2][16] auhal debug: digital output successfully opened core debug: output 'spdi' 48000 Hz 3F2R/LFE frame=1536 samples/6144 bytes core debug: looking for audio volume module matching "any": 2 candidates core debug: no audio volume modules matched core debug: restarting filters... core debug: input 'a52 ' 48000 Hz 3F2R/LFE frame=1536 samples/1536 bytes core debug: pass-through: 'a52 '->'spdi' 48000 Hz->48000 Hz 3F2R/LFE->3F2R/LFE core debug: looking for audio converter module matching "any": 11 candidates core debug: using audio converter module "a52tospdif" core warning: buffer too late (-2627722 us): dropped core debug: removing module "a52tospdif" core debug: restarting output... auhal debug: setting stream format: [44100.000000][mcpl][4][8][1][8][2][24] auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: actual format in use: [44100.000000][mcpl][4][8][1][8][2][24] core debug: VLC is looking for: 'a52 ' 48000 Hz 3F2R/LFE frame=1536 samples/1536 bytes auhal debug: attempting to use device 0 auhal debug: default device changed to 47 auhal debug: default device actually changed, resetting aout core debug: restart requested (2) auhal debug: using default audio device 47 auhal debug: default device changed to 47 auhal debug: found 23 stream formats for stream id 48 auhal debug: Using audio device for digital output auhal debug: original stream format: [44100.000000][mcpl][4][8][1][8][2][24] auhal debug: setting stream format: [48000.000000][3cac][76][6144][1536][0][2][16] auhal debug: default device changed to 47 auhal debug: ignore, as digital mode is active auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: actual format in use: [48000.000000][3cac][76][6144][1536][0][2][16] auhal debug: digital output successfully opened core debug: output 'spdi' 48000 Hz 3F2R/LFE frame=1536 samples/6144 bytes core debug: looking for audio volume module matching "any": 2 candidates core debug: no audio volume modules matched core debug: restarting filters... core debug: input 'a52 ' 48000 Hz 3F2R/LFE frame=1536 samples/1536 bytes core debug: pass-through: 'a52 '->'spdi' 48000 Hz->48000 Hz 3F2R/LFE->3F2R/LFE core debug: looking for audio converter module matching "any": 11 candidates core debug: using audio converter module "a52tospdif" core warning: buffer too late (-3250501 us): dropped core debug: removing module "a52tospdif" core debug: restarting output... auhal debug: setting stream format: [44100.000000][mcpl][4][8][1][8][2][24] auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: actual format in use: [44100.000000][mcpl][4][8][1][8][2][24] core debug: VLC is looking for: 'a52 ' 48000 Hz 3F2R/LFE frame=1536 samples/1536 bytes auhal debug: attempting to use device 0 auhal debug: default device changed to 47 auhal debug: using default audio device 47 auhal debug: default device actually changed, resetting aout core debug: restart requested (2) auhal debug: found 23 stream formats for stream id 48 auhal debug: Using audio device for digital output auhal debug: default device changed to 47 auhal debug: ignore, as digital mode is active auhal debug: original stream format: [44100.000000][mcpl][4][8][1][8][2][24] auhal debug: setting stream format: [48000.000000][3cac][76][6144][1536][0][2][16] auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: actual format in use: [48000.000000][3cac][76][6144][1536][0][2][16] auhal debug: digital output successfully opened core debug: output 'spdi' 48000 Hz 3F2R/LFE frame=1536 samples/6144 bytes core debug: looking for audio volume module matching "any": 2 candidates core debug: no audio volume modules matched core debug: restarting filters... core debug: input 'a52 ' 48000 Hz 3F2R/LFE frame=1536 samples/1536 bytes core debug: pass-through: 'a52 '->'spdi' 48000 Hz->48000 Hz 3F2R/LFE->3F2R/LFE core debug: looking for audio converter module matching "any": 11 candidates core debug: using audio converter module "a52tospdif" core warning: buffer too late (-3876454 us): dropped core debug: removing module "a52tospdif" core debug: restarting output... auhal debug: setting stream format: [44100.000000][mcpl][4][8][1][8][2][24] auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: actual format in use: [44100.000000][mcpl][4][8][1][8][2][24] core debug: VLC is looking for: 'a52 ' 48000 Hz 3F2R/LFE frame=1536 samples/1536 bytes auhal debug: attempting to use device 0 auhal debug: default device changed to 47 auhal debug: default device actually changed, resetting aout core debug: restart requested (2) auhal debug: using default audio device 47 auhal debug: default device changed to 47 auhal debug: found 23 stream formats for stream id 48 auhal debug: Using audio device for digital output auhal debug: original stream format: [44100.000000][mcpl][4][8][1][8][2][24] auhal debug: setting stream format: [48000.000000][3cac][76][6144][1536][0][2][16] auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: actual format in use: [48000.000000][3cac][76][6144][1536][0][2][16] auhal debug: digital output successfully opened core debug: output 'spdi' 48000 Hz 3F2R/LFE frame=1536 samples/6144 bytes core debug: looking for audio volume module matching "any": 2 candidates core debug: no audio volume modules matched core debug: restarting filters... core debug: input 'a52 ' 48000 Hz 3F2R/LFE frame=1536 samples/1536 bytes core debug: pass-through: 'a52 '->'spdi' 48000 Hz->48000 Hz 3F2R/LFE->3F2R/LFE core debug: looking for audio converter module matching "any": 11 candidates core debug: using audio converter module "a52tospdif" core warning: buffer too late (-4503813 us): dropped core debug: removing module "a52tospdif" core debug: restarting output... auhal debug: setting stream format: [44100.000000][mcpl][4][8][1][8][2][24] auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active core warning: picture is too late to be displayed (missing 111 ms) core warning: picture is too late to be displayed (missing 70 ms) core warning: picture is too late to be displayed (missing 28 ms) auhal debug: actual format in use: [44100.000000][mcpl][4][8][1][8][2][24] core debug: VLC is looking for: 'a52 ' 48000 Hz 3F2R/LFE frame=1536 samples/1536 bytes auhal debug: attempting to use device 0 auhal debug: default device changed to 47 auhal debug: default device actually changed, resetting aout core debug: restart requested (2) auhal debug: using default audio device 47 auhal debug: found 23 stream formats for stream id 48 auhal debug: Using audio device for digital output auhal debug: default device changed to 47 auhal debug: ignore, as digital mode is active auhal debug: original stream format: [44100.000000][mcpl][4][8][1][8][2][24] auhal debug: setting stream format: [48000.000000][3cac][76][6144][1536][0][2][16] auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: actual format in use: [48000.000000][3cac][76][6144][1536][0][2][16] auhal debug: digital output successfully opened core debug: output 'spdi' 48000 Hz 3F2R/LFE frame=1536 samples/6144 bytes core debug: looking for audio volume module matching "any": 2 candidates core debug: no audio volume modules matched core debug: restarting filters... core debug: input 'a52 ' 48000 Hz 3F2R/LFE frame=1536 samples/1536 bytes core debug: pass-through: 'a52 '->'spdi' 48000 Hz->48000 Hz 3F2R/LFE->3F2R/LFE core debug: looking for audio converter module matching "any": 11 candidates core debug: using audio converter module "a52tospdif" core warning: buffer too late (-5126871 us): dropped core debug: removing module "a52tospdif" core debug: restarting output... auhal debug: setting stream format: [44100.000000][mcpl][4][8][1][8][2][24] auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: actual format in use: [44100.000000][mcpl][4][8][1][8][2][24] core debug: VLC is looking for: 'a52 ' 48000 Hz 3F2R/LFE frame=1536 samples/1536 bytes auhal debug: attempting to use device 0 auhal debug: default device changed to 47 auhal debug: default device actually changed, resetting aout core debug: restart requested (2) auhal debug: using default audio device 47 auhal debug: default device changed to 47 auhal debug: found 23 stream formats for stream id 48 auhal debug: Using audio device for digital output auhal debug: original stream format: [44100.000000][mcpl][4][8][1][8][2][24] auhal debug: setting stream format: [48000.000000][3cac][76][6144][1536][0][2][16] auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: actual format in use: [48000.000000][3cac][76][6144][1536][0][2][16] auhal debug: digital output successfully opened core debug: output 'spdi' 48000 Hz 3F2R/LFE frame=1536 samples/6144 bytes core debug: looking for audio volume module matching "any": 2 candidates core debug: no audio volume modules matched core debug: restarting filters... core debug: input 'a52 ' 48000 Hz 3F2R/LFE frame=1536 samples/1536 bytes core debug: pass-through: 'a52 '->'spdi' 48000 Hz->48000 Hz 3F2R/LFE->3F2R/LFE core debug: looking for audio converter module matching "any": 11 candidates core debug: using audio converter module "a52tospdif" core warning: buffer too late (-5756176 us): dropped core debug: removing module "a52tospdif" core debug: restarting output... auhal debug: setting stream format: [44100.000000][mcpl][4][8][1][8][2][24] auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: actual format in use: [44100.000000][mcpl][4][8][1][8][2][24] core debug: VLC is looking for: 'a52 ' 48000 Hz 3F2R/LFE frame=1536 samples/1536 bytes auhal debug: attempting to use device 0 auhal debug: default device changed to 47 auhal debug: default device actually changed, resetting aout core debug: restart requested (2) auhal debug: using default audio device 47 auhal debug: found 23 stream formats for stream id 48 auhal debug: Using audio device for digital output auhal debug: default device changed to 47 auhal debug: ignore, as digital mode is active auhal debug: original stream format: [44100.000000][mcpl][4][8][1][8][2][24] auhal debug: setting stream format: [48000.000000][3cac][76][6144][1536][0][2][16] auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: actual format in use: [48000.000000][3cac][76][6144][1536][0][2][16] auhal debug: digital output successfully opened core debug: output 'spdi' 48000 Hz 3F2R/LFE frame=1536 samples/6144 bytes core debug: looking for audio volume module matching "any": 2 candidates core debug: no audio volume modules matched core debug: restarting filters... core debug: input 'a52 ' 48000 Hz 3F2R/LFE frame=1536 samples/1536 bytes core debug: pass-through: 'a52 '->'spdi' 48000 Hz->48000 Hz 3F2R/LFE->3F2R/LFE core debug: looking for audio converter module matching "any": 11 candidates core debug: using audio converter module "a52tospdif" core warning: buffer too late (-6381743 us): dropped core debug: removing module "a52tospdif" core debug: restarting output... auhal debug: setting stream format: [44100.000000][mcpl][4][8][1][8][2][24] auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: actual format in use: [44100.000000][mcpl][4][8][1][8][2][24] core debug: VLC is looking for: 'a52 ' 48000 Hz 3F2R/LFE frame=1536 samples/1536 bytes auhal debug: attempting to use device 0 auhal debug: default device changed to 47 auhal debug: default device actually changed, resetting aout auhal debug: using default audio device 47 core debug: restart requested (2) auhal debug: default device changed to 47 auhal debug: found 23 stream formats for stream id 48 auhal debug: Using audio device for digital output auhal debug: original stream format: [44100.000000][mcpl][4][8][1][8][2][24] auhal debug: setting stream format: [48000.000000][3cac][76][6144][1536][0][2][16] auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: actual format in use: [48000.000000][3cac][76][6144][1536][0][2][16] auhal debug: digital output successfully opened core debug: output 'spdi' 48000 Hz 3F2R/LFE frame=1536 samples/6144 bytes core debug: looking for audio volume module matching "any": 2 candidates core debug: no audio volume modules matched core debug: restarting filters... core debug: input 'a52 ' 48000 Hz 3F2R/LFE frame=1536 samples/1536 bytes core debug: pass-through: 'a52 '->'spdi' 48000 Hz->48000 Hz 3F2R/LFE->3F2R/LFE core debug: looking for audio converter module matching "any": 11 candidates core debug: using audio converter module "a52tospdif" core warning: buffer too late (-7003844 us): dropped core debug: removing module "a52tospdif" core debug: restarting output... auhal debug: setting stream format: [44100.000000][mcpl][4][8][1][8][2][24] auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: actual format in use: [44100.000000][mcpl][4][8][1][8][2][24] core debug: VLC is looking for: 'a52 ' 48000 Hz 3F2R/LFE frame=1536 samples/1536 bytes auhal debug: attempting to use device 0 auhal debug: using default audio device 47 auhal debug: default device changed to 47 auhal debug: default device changed to 47 auhal debug: found 23 stream formats for stream id 48 auhal debug: Using audio device for digital output auhal debug: original stream format: [44100.000000][mcpl][4][8][1][8][2][24] auhal debug: setting stream format: [48000.000000][3cac][76][6144][1536][0][2][16] auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active auhal debug: actual format in use: [48000.000000][3cac][76][6144][1536][0][2][16] auhal debug: digital output successfully opened core debug: output 'spdi' 48000 Hz 3F2R/LFE frame=1536 samples/6144 bytes core debug: looking for audio volume module matching "any": 2 candidates core debug: no audio volume modules matched core debug: restarting filters... core debug: input 'a52 ' 48000 Hz 3F2R/LFE frame=1536 samples/1536 bytes core debug: pass-through: 'a52 '->'spdi' 48000 Hz->48000 Hz 3F2R/LFE->3F2R/LFE core debug: looking for audio converter module matching "any": 11 candidates core debug: using audio converter module "a52tospdif" core warning: buffer too late (-7630087 us): dropped core warning: buffer too late (-7598156 us): dropped core warning: buffer too late (-7566221 us): dropped core warning: buffer too late (-7534277 us): dropped core warning: buffer too late (-7502324 us): dropped core warning: buffer too late (-7470353 us): dropped core warning: buffer too late (-7438370 us): dropped core warning: buffer too late (-7406392 us): dropped core error: ES_OUT_SET_(GROUP_)PCR is called too late (jitter of 8198 ms ignored) core warning: buffer too late (-7374420 us): dropped core debug: discarded audio buffer core warning: early picture skipped core debug: discarded audio buffer core debug: discarded audio buffer core debug: discarded audio buffer core warning: early picture skipped core debug: discarded audio buffer core debug: discarded audio buffer core debug: discarded audio buffer core warning: early picture skipped core debug: discarded audio buffer core debug: discarded audio buffer core debug: discarded audio buffer core debug: discarded audio buffer core debug: discarded audio buffer core debug: discarded audio buffer core debug: discarded audio buffer core warning: playback way too early (-905477): playing silence core debug: inserting 43462 zeroes auhal debug: default device changed to 39 auhal debug: ignore, as digital mode is active

there you go. i am using the nighty build 2.2.0. it was happening with 2.1.2 also but maybe its the video file. i dont know.

[dfuhrmann]

Looks like you are using digital surround output. And this actually works (aka: you hear normal output, and audio just drops out 1 or 2 seconds from time to time)? Over which time period was this log recorded, approximately?

[dhg]

I'm facing the same problem with versions 2.1.2, 2.2.0 (nightly build) - using digital surround output through hdmi and optical external output from mac book to av-receiver. Problem occurs with different video files on dolby d and dts.

On version 2.0.9 i have no problems.

Any news regarding this issue ?

[Baron015]

I have the same issue with intermittent audio dropouts on DD5.1 over HDMI with the same 'way too early, playing silence' log messages. OSX 10.9 VLC 2.1.3. Any news of fix or workaround ?

[Baron015]

OK just downloaded VLC 2.1.4 and issue still present. Audio drop outs of less than one second, approx every 5 minutes. Tried several H.264 mkv files, all exhibit the issue. Both DD and DTS surround sound tried, audio device = HDMI (encoded signal). Other than this problem, video and audio is excellent in every way.

Section from log here:

main debug: resampling stopped (drift: -115743 us)
main warning: playback too early (-115652): down-sampling
main debug: resampling stopped (drift: -115652 us)
main warning: playback too early (-115257): down-sampling
main debug: resampling stopped (drift: -115257 us)
main warning: playback too early (-115204): down-sampling
main debug: resampling stopped (drift: -115204 us)
main warning: playback too early (-115082): down-sampling
main debug: resampling stopped (drift: -115082 us)
main warning: playback too early (-115596): down-sampling
main debug: resampling stopped (drift: -115596 us)
main warning: playback too early (-115513): down-sampling
main debug: resampling stopped (drift: -115513 us)
main warning: playback too early (-102515): down-sampling
main debug: resampling stopped (drift: -102515 us)
main warning: playback too early (-101671): down-sampling
main debug: resampling stopped (drift: -101671 us)
main warning: playback too early (-101476): down-sampling
main debug: resampling stopped (drift: -101476 us)
main warning: playback too early (-101275): down-sampling
main debug: resampling stopped (drift: -101275 us)
main warning: playback too early (-101791): down-sampling
main debug: resampling stopped (drift: -101791 us)
main warning: playback too early (-101699): down-sampling
main debug: resampling stopped (drift: -101699 us)
main warning: playback too early (-101333): down-sampling
main debug: resampling stopped (drift: -101333 us)
main warning: playback too early (-100902): down-sampling
main debug: resampling stopped (drift: -100902 us)
main warning: playback too early (-89017): down-sampling
main debug: resampling stopped (drift: -89017 us)
main warning: playback way too early (-120271): playing silence
main debug: inserting 5773 zeroes

[Baron015]

OK I tried the nightly build vlc-2.2.0-x86_64-20140219-0113.zip 2014-02-19 01:15 VLC media player - 2.2.0-git Weatherwax

This seems to have cured the problem entirely ! Very happy.

Rgds
TB.

[xYankee]

I've been having this issue for a while, including with the latest/final 2.1.4 build.

I'm running 10.9.2 on a 2011 Mac mini connected to a Logitech Z-5500 via optical. It only happens with video clips that have encoded audio (DTS or DD 5.1).

Anyone have any advice?

[detlef]

I guess, this was never solved - still the same problem in Version 2.2.4 Weatherwax (Intel 64bit)