5.1 48000hz flac audio stuttering, 2.1.4 AND 2.2.0 git
Posted: 30 Mar 2014 00:01
Hey, I have an H264 matroska with 5.1 48000hz flac that's stuttering pretty badly (2 seconds of video for 4 seconds of silence).
I've tried it with 2.1.4 and 2.2.0 git (latest build on the vlc nightlies page for x86_64).
behavior is the same with both. Local file on OS drive (I wanted to exclude any nas-based issues).
Truncated log output for the message which repeats as it stutters:
Other messages seen in other attempts at playback...
"timing screwed (drift 166880 us): stopping resampling"
"playback way too late( xxxx ): up sampling"
It seems to not know where to go...
Full log output below from beginning of playback to enough seconds in to manifest the behavior for a considerable amount of time..
I've tried it with 2.1.4 and 2.2.0 git (latest build on the vlc nightlies page for x86_64).
behavior is the same with both. Local file on OS drive (I wanted to exclude any nas-based issues).
Truncated log output for the message which repeats as it stutters:
Code: Select all
core warning: playback too late (169887): up-sampling
core warning: playback way too early (-174944): playing silence
core debug: inserting 8397 zeroes"timing screwed (drift 166880 us): stopping resampling"
"playback way too late( xxxx ): up sampling"
It seems to not know where to go...
Full log output below from beginning of playback to enough seconds in to manifest the behavior for a considerable amount of time..
Code: Select all
core debug: VLC media player - 2.2.0-git Weatherwax
core debug: Copyright © 1996-2014 the VideoLAN team
core debug: revision 2.1.0-git-2693-g5384c38
core debug: configured with ../extras/package/macosx/../../../configure '--prefix=/Users/buildbot/slave/vlc-bin-osx-x86_64/build/build/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' '--build=x86_64-apple-darwin10' '--with-macosx-version-min=10.6' '--with-macosx-sdk=/Applications/Xcode.app/Contents/Developer/Platforms/MacOSX.platform/Developer/SDKs/MacOSX10.8.sdk' 'build_alias=x86_64-apple-darwin10' 'CC=xcrun clang' 'CFLAGS=-g' 'LDFLAGS=' 'CXX=xcrun clang++' 'OBJC=xcrun clang'
core debug: adding item `[Coalgirls]_Kanon_ED_(1920x1080_Blu-Ray_FLAC)_[190239A6].mkv' ( file:///Users/plasmacutter/Movies/%5BCoalgirls%5D_Kanon_ED_%281920x1080_Blu-Ray_FLAC%29_%5B190239A6%5D.mkv )
core debug: Creating an input for '[Coalgirls]_Kanon_ED_(1920x1080_Blu-Ray_FLAC)_[190239A6].mkv'
core debug: processing request item: [Coalgirls]_Kanon_ED_(1920x1080_Blu-Ray_FLAC)_[190239A6].mkv, 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 [Coalgirls]_Kanon_ED_(1920x1080_Blu-Ray_FLAC)_[190239A6].mkv
core debug: [Coalgirls]_Kanon_ED_(1920x1080_Blu-Ray_FLAC)_[190239A6].mkv is at 0
core debug: creating new input thread
core debug: Creating an input for '[Coalgirls]_Kanon_ED_(1920x1080_Blu-Ray_FLAC)_[190239A6].mkv'
core debug: selected audio language[0] ja
core debug: selected audio language[1] ja
core debug: selected audio language[2] any
core debug: selected subtitle language[0] en
core debug: selected subtitle language[1] en
core debug: using timeshift granularity of 50 MiB, in path '/tmp'
core debug: `file:///Users/plasmacutter/Movies/%5BCoalgirls%5D_Kanon_ED_%281920x1080_Blu-Ray_FLAC%29_%5B190239A6%5D.mkv' gives access `file' demux `' path `/Users/plasmacutter/Movies/%5BCoalgirls%5D_Kanon_ED_%281920x1080_Blu-Ray_FLAC%29_%5B190239A6%5D.mkv'
core debug: enforced demux ` any'
core debug: creating demux: access='file' demux='any' location='/Users/plasmacutter/Movies/%5BCoalgirls%5D_Kanon_ED_%281920x1080_Blu-Ray_FLAC%29_%5B190239A6%5D.mkv' file='/Users/plasmacutter/Movies/[Coalgirls]_Kanon_ED_(1920x1080_Blu-Ray_FLAC)_[190239A6].mkv'
core debug: looking for access_demux module matching "file": 13 candidates
core debug: Creating an input for '[Coalgirls]_Kanon_ED_(1920x1080_Blu-Ray_FLAC)_[190239A6].mkv'
core debug: no access_demux modules matched
core debug: creating access 'file' location='/Users/plasmacutter/Movies/%5BCoalgirls%5D_Kanon_ED_%281920x1080_Blu-Ray_FLAC%29_%5B190239A6%5D.mkv', path='/Users/plasmacutter/Movies/[Coalgirls]_Kanon_ED_(1920x1080_Blu-Ray_FLAC)_[190239A6].mkv'
core debug: looking for access module matching "file": 18 candidates
filesystem debug: opening file `/Users/plasmacutter/Movies/[Coalgirls]_Kanon_ED_(1920x1080_Blu-Ray_FLAC)_[190239A6].mkv'
core debug: using access module "filesystem"
core debug: Using stream method for AStream*
core debug: starting pre-buffering
core debug: received first data after 0 ms
core debug: pre-buffering done 1024 bytes in 0s - 18867 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: using stream_filter module "record"
core debug: creating demux: access='file' demux='any' location='/Users/plasmacutter/Movies/%5BCoalgirls%5D_Kanon_ED_%281920x1080_Blu-Ray_FLAC%29_%5B190239A6%5D.mkv' file='/Users/plasmacutter/Movies/[Coalgirls]_Kanon_ED_(1920x1080_Blu-Ray_FLAC)_[190239A6].mkv'
core debug: looking for demux module matching "mkv": 65 candidates
mkv debug: | + Seek head
mkv debug: | | + Seek
mkv debug: | - tracks at 4299
mkv debug: | + Tracks
mkv debug: | | + Track Entry
mkv debug: | | | + Track Number=1
mkv debug: | | | + Track UID=1
mkv debug: | | | + Track Type=video
mkv debug: | | | + Track Enabled=1
mkv debug: | | | + Track Default=1
mkv debug: | | | + Track Forced=0
mkv debug: | | | + Track Lacing=0
mkv debug: | | | + Track MinCache=1
mkv debug: | | | + Track TimeCodeScale=1.000000
mkv debug: | | | + Track Max BlockAdditionID=0
mkv debug: | | | + Track CodecId=V_MPEG4/ISO/AVC
mkv debug: | | | + Track Codec Decode All=1
mkv debug: | | | + Track CodecPrivate size=36
mkv debug: | | | + Track Language=`und'
mkv debug: | | | + Track Name=Kanon ED
mkv debug: | | | + Track Video
mkv debug: | | | | + width=1920
mkv debug: | | | | + height=1080
mkv debug: | | | | + Track Video Interlaced=0
mkv debug: | | | | + display width=1920
mkv debug: | | | | + display height=1080
mkv debug: | | + Track Entry
mkv debug: | | | + Track Number=2
mkv debug: | | | + Track UID=2
mkv debug: | | | + Track Type=audio
mkv debug: | | | + Track Enabled=1
mkv debug: | | | + Track Default=1
mkv debug: | | | + Track Forced=0
mkv debug: | | | + Track Lacing=1
mkv debug: | | | + Track MinCache=0
mkv debug: | | | + Track TimeCodeScale=1.000000
mkv debug: | | | + Track Max BlockAdditionID=0
mkv debug: | | | + Track CodecId=A_FLAC
mkv debug: | | | + Track Codec Decode All=1
mkv debug: | | | + Track CodecPrivate size=113
mkv debug: | | | + Track Default Duration=85333333
mkv debug: | | | + Track Language=`jpn'
mkv debug: | | | + Track Name=5.1 FLAC
mkv debug: | | | + Track Audio
mkv debug: | | | | + afreq=48000
mkv debug: | | | | + achan=6
mkv debug: | | | | + abits=16
mkv debug: | | + Track Entry
mkv debug: | | | + Track Number=3
mkv debug: | | | + Track UID=3
mkv debug: | | | + Track Type=subtitle
mkv debug: | | | + Track Enabled=1
mkv debug: | | | + Track Default=1
mkv debug: | | | + Track Forced=0
mkv debug: | | | + Track Lacing=0
mkv debug: | | | + Track MinCache=0
mkv debug: | | | + Track TimeCodeScale=1.000000
mkv debug: | | | + Track Max BlockAdditionID=0
mkv debug: | | | + Track CodecId=S_TEXT/ASS
mkv debug: | | | + Track Codec Decode All=1
mkv debug: | | | + Track CodecPrivate size=878
mkv debug: | | | + Track Language=`und'
mkv debug: | | | + Track Name=English
mkv debug: | | + Seek
mkv debug: | - chained seekhead at 105165034
mkv debug: | + Seek head
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 88126
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 1591254
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 3100269
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 4611678
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 6127704
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 7732974
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 9276303
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 10788917
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 12451411
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 13968864
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 15494325
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 17024338
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 18540722
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 20074723
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 21577237
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 23095176
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 24610201
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 26114064
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 27664047
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 29175160
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 30727588
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 32250669
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 33790522
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 35305955
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 36808446
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 38323063
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 39827687
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 41331816
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 42841154
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 44347780
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 45852832
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 47354773
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 48925973
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 50431361
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 52028999
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 53549286
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 55058462
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 56568744
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 58070130
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 59575586
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 61097487
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 62609370
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 64128068
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 65639350
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 67299664
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 68801248
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 70317737
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 71854222
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 73376912
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 74895552
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 76397380
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 77926316
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 79580034
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 81107457
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 82650511
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 84171940
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 85729143
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 87238968
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 88891060
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 90414738
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 91922084
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 93428419
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 94997068
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 96520593
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 98043275
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 99545711
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 101063869
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 102574606
mkv debug: | | + Seek
mkv debug: | - unknown seekhead reference at 104089195
mkv debug: | | + Seek
mkv warning: MKV/Ebml Parser: m_el[mi_level] == NULL
mkv warning: MKV/Ebml Parser: Up cannot escape itself
mkv debug: | - unknown seekhead reference at 105128555
mkv debug: | | + Seek
mkv debug: | - cues at 105164859
mkv debug: | + Cues
mkv debug: | - loading cues done.
mkv debug: | | + Seek
mkv debug: | - attachments at 6640
mkv debug: | + Attachments
mkv debug: | | - Holla-Regular.ttf (application/x-truetype-font)
mkv debug: | | + Seek
mkv debug: | - info at 119
mkv debug: | + Information
mkv debug: | | + TimecodeScale=1000000
mkv debug: | | + Muxing Application=libebml v0.7.7 + libmatroska v0.8.1
mkv debug: | | + Writing Application=mkvmerge v2.9.8 ('C'est le bon') built on Aug 13 2009 12:49:06
mkv debug: | | + Duration=91091
mkv debug: | | + Date=Fri Jan 01 13:47:29 2010
mkv debug: | | + Title=Kanon ED
mkv debug: | | + UID=1824571052
mkv debug: | + Information
mkv debug: | + Void
mkv debug: | + Tracks
mkv debug: | + Void
mkv debug: | + Attachments
mkv debug: | + Cluster
core debug: no fetch required for Kanon ED (art currently (null))
mkv debug: found 3 es
core debug: selecting program id=0
core debug: Buffering 0%
mkv debug: Starting the UI Hook
core debug: using demux module "mkv"
core debug: no fetch required for Kanon ED (art currently (null))
core debug: looking for a subtitle file in /Users/plasmacutter/Movies/
core debug: looking for decoder module matching "any": 39 candidates
avcodec debug: CPU flags: 0x010053db
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
core debug: using decoder module "avcodec"
core debug: looking for decoder module matching "any": 39 candidates
core debug: using decoder module "flac"
core debug: looking for decoder module matching "any": 39 candidates
libass debug: adding embedded font Holla-Regular.ttf
core debug: using decoder module "libass"
core debug: looking for meta reader module matching "any": 2 candidates
lua debug: Trying Lua scripts in /Users/plasmacutter/Library/Application Support/org.videolan.vlc/lua/meta/reader
lua debug: Trying Lua scripts in /Applications/vlc-2.2.0-git/VLC.app/Contents/MacOS/share/lua/meta/reader
lua debug: Trying Lua playlist script /Applications/vlc-2.2.0-git/VLC.app/Contents/MacOS/share/lua/meta/reader/filename.luac
lua debug: Trying Lua scripts in /Applications/vlc-2.2.0-git/VLC.app/Contents/MacOS/share/share/lua/meta/reader
core debug: no meta reader modules matched
core debug: `file:///Users/plasmacutter/Movies/%5BCoalgirls%5D_Kanon_ED_%281920x1080_Blu-Ray_FLAC%29_%5B190239A6%5D.mkv' successfully opened
core debug: Buffering 0%
flac debug: decode STREAMINFO
flac debug: channels:6 samplerate:48000 bitspersamples:16
flac debug: STREAMINFO decoded
core debug: Buffering 0%
core debug: reusing audio output
core debug: VLC is looking for: 'f32l' 48000 Hz 3F2R/LFE frame=1 samples/24 bytes
auhal debug: attempting to use device 0
avcodec debug: available hardware decoder output format 81 (vda_vld)
avcodec debug: available software decoder output format 0 (yuv420p)
core debug: looking for hw decoder module matching "any": 1 candidates
core debug: no hw decoder modules matched
avcodec debug: available hardware decoder output format 81 (vda_vld)
avcodec debug: available software decoder output format 0 (yuv420p)
core debug: looking for hw decoder module matching "any": 1 candidates
core debug: no hw decoder modules matched
core debug: looking for text renderer module matching "any": 3 candidates
auhal debug: using default audio device 47
auhal debug: found 16 stream formats for stream id 48
auhal debug: Audio device supports PCM mode only
freetype debug: looking for Arial Unicode MS
core debug: Buffering 1%
freetype debug: found /Library/Fonts/Arial Unicode.ttf
freetype debug: looking for Monaco
core debug: Buffering 2%
freetype debug: found /System/Library/Fonts/Monaco.dfont
freetype debug: Using Arial Unicode MS as font from file /Library/Fonts/Arial Unicode.ttf
freetype debug: Using Monaco as mono-font from file /System/Library/Fonts/Monaco.dfont
freetype debug: using fontsize: 1
core debug: using text renderer module "freetype"
core debug: Buffering 2%
core debug: looking for video filter2 module matching "any": 57 candidates
swscale debug: 32x32 (32x32) chroma: YUVA -> 16x16 (16x16) chroma: RGBA with scaling using Bicubic (good quality)
core debug: using video filter2 module "swscale"
core debug: looking for video filter2 module matching "any": 57 candidates
core debug: Buffering 3%
core debug: Buffering 4%
core debug: Buffering 4%
core debug: Buffering 5%
core debug: Buffering 6%
core debug: Buffering 6%
core debug: Buffering 7%
yuvp debug: YUVP to YUVA converter
core debug: Buffering 7%
core debug: using video filter2 module "yuvp"
core debug: Deinterlacing available
core debug: Buffering 8%
core debug: deinterlace 0, mode blend, is_needed 0
core debug: Opening vout display wrapper
core debug: looking for vout display module matching "any": 6 candidates
core debug: Buffering 9%
core debug: Buffering 9%
core debug: looking for vout window nsobject module matching "any": 1 candidates
core debug: Buffering 10%
core debug: Buffering 10%
core debug: Buffering 11%
core debug: Buffering 12%
core debug: Buffering 12%
core debug: Buffering 13%
core debug: Buffering 14%
core debug: Buffering 14%
core debug: Buffering 15%
core debug: Buffering 15%
core debug: Buffering 16%
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]
core debug: Buffering 17%
core debug: Buffering 17%
auhal debug: analog output successfully opened
core debug: output 'f32l' 48000 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 's32l' 48000 Hz 3F2R/LFE frame=1 samples/24 bytes
core debug: looking for audio filter module matching "scaletempo": 14 candidates
scaletempo debug: format: 48000 rate, 6 nch, 4 bps, fl32
core debug: Buffering 18%
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
core debug: using audio filter module "scaletempo"
core debug: conversion: 's32l'->'f32l' 48000 Hz->48000 Hz 3F2R/LFE->3F2R/LFE
core debug: looking for audio converter module matching "any": 11 candidates
core debug: Buffering 19%
core debug: Buffering 19%
core debug: Buffering 20%
audio_format debug: s32l->f32l, bits per sample: 32->32
core debug: using audio converter module "audio_format"
core debug: conversion pipeline complete
core debug: conversion: 'f32l'->'f32l' 48000 Hz->48000 Hz 3F2R/LFE->Stereo
core debug: looking for audio converter module matching "any": 11 candidates
core debug: using audio converter module "simple_channel_mixer"
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: Buffering 21%
core debug: Buffering 21%
core debug: Buffering 22%
core debug: Buffering 23%
core debug: Buffering 23%
core debug: Buffering 24%
core debug: Buffering 25%
core debug: Buffering 25%
core debug: Buffering 26%
core debug: Buffering 27%
core debug: Buffering 27%
core debug: Buffering 28%
core debug: Buffering 29%
core debug: Buffering 29%
core debug: Buffering 30%
core debug: Buffering 31%
core debug: Buffering 31%
core debug: Buffering 32%
core debug: Buffering 33%
core debug: Buffering 33%
core debug: Buffering 34%
core debug: Buffering 34%
core debug: Buffering 35%
core debug: Buffering 36%
core debug: Buffering 36%
core debug: Buffering 37%
core debug: Buffering 37%
core debug: Buffering 38%
core debug: Buffering 39%
core debug: Buffering 39%
core debug: Buffering 40%
core debug: Buffering 41%
core debug: Buffering 41%
core debug: Buffering 42%
core debug: Buffering 42%
core debug: Buffering 43%
core debug: Buffering 44%
core debug: Buffering 44%
core debug: Buffering 45%
core debug: Buffering 45%
core debug: Buffering 46%
core debug: Buffering 47%
core debug: Buffering 47%
core debug: Buffering 48%
core debug: Buffering 49%
core debug: Buffering 49%
core debug: Buffering 50%
core debug: Buffering 51%
core debug: Buffering 52%
core debug: Buffering 52%
core debug: Buffering 53%
core debug: Buffering 53%
core debug: Buffering 54%
core debug: Buffering 54%
core debug: Buffering 55%
core debug: Buffering 56%
core debug: Buffering 57%
core debug: Buffering 57%
core debug: Buffering 58%
core debug: Buffering 58%
core debug: Buffering 59%
core debug: Buffering 60%
core debug: Buffering 60%
core debug: Buffering 61%
core debug: Buffering 61%
core debug: Buffering 62%
core debug: Buffering 62%
core debug: Buffering 63%
core debug: Buffering 64%
core debug: Buffering 64%
core debug: Buffering 65%
core debug: Buffering 66%
core debug: Buffering 66%
core debug: Buffering 67%
core debug: Buffering 68%
core debug: Buffering 68%
core debug: Buffering 69%
core debug: Buffering 69%
core debug: Buffering 70%
macosx debug: prevented sleep through IOKit (7598)
macosx debug: toggle playlist from state: removed splitview 0, minimized view 0. Event 3
core debug: Buffering 71%
macosx debug: toggle playlist to state: removed splitview 0, minimized view 0
core debug: Buffering 71%
core debug: Buffering 72%
core debug: Buffering 72%
core debug: Buffering 73%
core debug: Buffering 73%
core debug: Buffering 74%
core debug: Buffering 75%
core debug: Buffering 75%
core debug: Buffering 76%
core debug: Buffering 76%
core debug: Buffering 77%
core debug: Buffering 78%
core debug: Buffering 78%
core debug: Buffering 79%
core debug: Buffering 80%
core debug: Buffering 80%
core debug: Buffering 81%
core debug: Buffering 81%
core debug: Buffering 82%
core debug: Buffering 82%
core debug: Buffering 83%
core debug: Buffering 84%
core debug: Buffering 84%
core debug: Buffering 85%
core debug: Buffering 85%
core debug: Buffering 86%
core debug: Buffering 86%
core debug: Buffering 87%
core debug: Buffering 88%
core debug: Buffering 88%
core debug: Buffering 89%
core debug: Buffering 90%
core debug: Buffering 90%
core debug: Buffering 91%
core debug: Buffering 91%
core debug: Buffering 92%
core debug: Buffering 92%
core debug: Buffering 93%
core debug: Buffering 93%
core debug: Buffering 94%
core debug: Buffering 95%
core debug: Buffering 95%
core debug: Buffering 96%
core debug: Buffering 97%
core debug: Buffering 97%
core debug: Buffering 98%
core debug: Buffering 98%
core debug: Buffering 99%
core debug: Stream buffering done (60102 ms in 116 ms)
macosx debug: releasing old sleep blocker (7598)
macosx debug: prevented sleep through IOKit (7599)
macosx debug: toggle playlist from state: removed splitview 0, minimized view 0. Event 2
macosx debug: toggle playlist to state: removed splitview 0, minimized view 0
macosx debug: returning videoview with proposed position x=0, y=0, width=1920, height=1080
core debug: using vout window nsobject module "macosx"
core debug: VoutDisplayEvent 'resize' 1920x1080 window
core debug: using vout display module "macosx"
core debug: VoutDisplayEvent 'resize' 1867x1080 window
core debug: original format sz 1920x1090, of (0,0), vsz 1920x1080, 4cc I420, sar 1:1, msk r0x0 g0x0 b0x0
core debug: removing module "freetype"
core 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: looking for Monaco
freetype debug: found /System/Library/Fonts/Monaco.dfont
freetype debug: Using Arial Unicode MS as font from file /Library/Fonts/Arial Unicode.ttf
freetype debug: Using Monaco as mono-font from file /System/Library/Fonts/Monaco.dfont
freetype debug: using fontsize: 1
core debug: using text renderer module "freetype"
avcodec debug: enabling direct rendering
core debug: VoutDisplayEvent 'resize' 1867x1080 window
core debug: End of video preroll
core debug: Received first picture
freetype debug: looking for Arial Unicode MS
freetype debug: found /Library/Fonts/Arial Unicode.ttf
core debug: Decoder wait done in 216 ms
macosx warning: variable postprocess doesn't exist or isn't handled
core warning: playback too late (170895): up-sampling
core warning: playback way too late (181179): flushing buffers
core debug: inserting 48638 zeroes
core warning: playback too late (163219): up-sampling
core warning: playback way too early (-175487): playing silence
core debug: inserting 8423 zeroes
core warning: playback too late (174689): up-sampling
core warning: playback way too late (345425): flushing buffers
core debug: inserting 91775 zeroes
core warning: playback way too early (-344556): playing silence
core debug: inserting 16538 zeroes
core warning: playback too late (177214): up-sampling
core warning: playback way too late (260069): flushing buffers
core debug: inserting 95844 zeroes
core warning: playback too late (163922): up-sampling
core warning: playback way too early (-254883): playing silence
core debug: inserting 12234 zeroes
core warning: playback too late (166167): up-sampling
core warning: playback way too late (338095): flushing buffers
core debug: inserting 91742 zeroes
core warning: playback way too early (-346548): playing silence
core debug: inserting 16634 zeroes
core warning: playback too late (176667): up-sampling
core warning: playback way too late (180046): flushing buffers
core debug: inserting 95939 zeroes
core warning: playback too late (179747): up-sampling
core warning: playback way too late (181079): flushing buffers
core debug: inserting 95855 zeroes
core warning: playback way too early (-346118): playing silence
core debug: inserting 16613 zeroes
core warning: playback too late (165995): up-sampling
core debug: resampling stopped (drift: 2934 us)
core warning: playback too late (167814): up-sampling
core warning: playback way too late (339239): flushing buffers
core debug: inserting 91790 zeroes
core warning: playback way too early (-344988): playing silence
core debug: inserting 16559 zeroes
core warning: playback too late (179003): up-sampling
core warning: playback way too late (180304): flushing buffers
core debug: inserting 95818 zeroes
core warning: playback too late (169887): up-sampling
core warning: playback way too early (-174944): playing silence
core debug: inserting 8397 zeroes
core warning: playback too late (176232): up-sampling
core warning: playback way too late (252159): flushing buffers
core debug: inserting 91814 zeroes
core warning: playback too late (173673): up-sampling