5.1 48000hz flac audio stuttering, 2.1.4 AND 2.2.0 git

[plasmacutter]

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:

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

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..

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