[vlc-devel] why can't vlc read my webcam?

Wed Feb 24 04:18:22 CET 2010

I am using vlc 1.0.5.

The log of messages with verbosity on 2 is attatched.

if the system is like 100% idle, why is direct show having such a
problem buffering?

Maybe the camera is slow, but I would think a 100% idle box would be
able to get a few frames a second..

----------------------------------

I'm using it via libvlc, and giving it a vmem surface ..
--vmem-width=60 --vmem-height=62... a small surface.

In the thread that creates the vlc instance, the lock routine grabs a
free image from a queue, and allocates one if none free.
When unlock is called, (15ms later), the frame is put in a queue, and
the display update thread is woken, and returns.

then 150ms+(idle) the Lock routine is called, the thread that does the
update is 1.5ms to run in a seperate thread.

At some point, I get a Lock, and when Unlock is called (using 18ms to
fill the vmem surface), Lock is immediately recalled.

then I get an erratic call of Lock from 20ms to 120ms, 60ms, 180...
then a quick 0ms call

the VLC outputs...

[028ff374] main input error: ES_OUT_SET_(GROUP_)PCR  is called too
late, increasing pts_delay to 200 ms
[028ff374] main input error: ES_OUT_RESET_PCR called
[05845bac] rawvideo decoder warning: invalid frame size (128 < 3840000)
[05845bac] main decoder debug: End of video preroll
[05845bac] main decoder debug: Received first picture
       6310581574341 4.568|E30000002B0~vlc_interface.c(286):LOCK.

--

[028ff374] main input debug: Buffering 0%
       6310735631403 82.878|E30000002B0~vlc_interface.c(286):LOCK.

--

[028ff374] main input debug: Buffering 56%
[028ff374] main input debug: Buffering -53%
       6310889009643 82.428|E30000002B0~vlc_interface.c(286):LOCK.
[028ff374] main input debug: Stream buffering done (224 ms in 213 ms)
[028ff374] main input debug: Decoder buffering done in 1 ms
       6311042200769 82.376|E30000002B0~vlc_interface.c(286):LOCK.

-------

[028ff374] main input error: ES_OUT_SET_(GROUP_)PCR  is called too
late, increasing pts_delay to 239 ms
[028ff374] main input error: ES_OUT_RESET_PCR called
[05845bac] rawvideo decoder warning: invalid frame size (128 < 3840000)
[05845bac] main decoder debug: End of video preroll
[05845bac] main decoder debug: Received first picture
       6311222767739 18.051|E30000002B0~vlc_interface.c(504):unlock

----------

My lock and unlock routines themsleves take very little time, the only
variables in that thread are what VLC does between the lock and unlock
(fills an output buffer 15-18ms) and the time it takes to ask for
another lock (180+ms - maybe 200ms from buffering minus the 15-18 ms
it was used)

I recently updated my code to not use GetTickCount() and use
timeGetTime() instead.  It, unfortuatnly is 50% the speed and
10,000,000 calls of GetTickCount is 47ms and timeGetTime is 94ms.

maybe your timers are suffering from the +/- 16ms timer of windows?

----------------
-------------- next part --------------
main debug: Buffering 56%
main debug: Stream buffering done (223 ms in 213 ms)
main debug: Decoder buffering done in 1 ms
main warning: PTS is out of range (-10000), dropping buffer
main warning: PTS is out of range (-33219), dropping buffer
main warning: output date isn't PTS date, requesting resampling (41561)
main warning: buffer is 67089 late, triggering upsampling
main debug: no usable vout present, spawning one
main debug: looking for text renderer module: 2 candidates
main debug: thread (fontlist builder) created at priority 0 (../../.././modules/misc/freetype.c:480)
freetype debug: using fontsize: 2
main debug: using text renderer module "freetype"
main debug: thread started
main debug: TIMER module_need() : 6.000 ms - Total 6.000 ms / 1 intvls (Avg 6.000 ms)
freetype debug: Building font database...
main debug: looking for video filter2 module: 20 candidates
freetype debug: Finished building font database.
freetype debug: Took 0 microseconds
main debug: thread ended
swscale debug: 32x32 chroma: YUVA -> 16x16 chroma: YUVA with scaling using Bicubic (good quality)
main debug: using video filter2 module "swscale"
main debug: TIMER module_need() : 4.000 ms - Total 4.000 ms / 1 intvls (Avg 4.000 ms)
main debug: looking for video filter2 module: 20 candidates
yuvp debug: YUVP to YUVA converter
main debug: using video filter2 module "yuvp"
main debug: TIMER module_need() : 66.000 ms - Total 66.000 ms / 1 intvls (Avg 66.000 ms)
main debug: window size: 1600x1200
main debug: looking for video output module: 7 candidates
direct3d debug: creating Vout EventThread
main debug: thread (Vout Events Thread) created at priority 0 (../../../.././modules/video_output/msw/direct3d.c:218)
main debug: thread started
direct3d debug: DirectXCreateWindow
main debug: looking for hwnd module: 3 candidates
qt4 debug: requesting video...
qt4 debug: Video was requested -1, -1
qt4 debug: Video is resizing to: 1600 1200
qt4 debug: Updating the geometry
main debug: using hwnd module "qt4"
main debug: TIMER module_need() : 17.000 ms - Total 17.000 ms / 1 intvls (Avg 17.000 ms)
direct3d debug: created video sub-window
direct3d debug: Vout EventThread running
direct3d debug: disabling screen saver
main debug: using video output module "direct3d"
main debug: TIMER module_need() : 36.000 ms - Total 36.000 ms / 1 intvls (Avg 36.000 ms)
main debug: Deinterlacing available
direct3d debug: Direct3D device adapter successfully initialized
direct3d debug: selected surface pixel format is YUY2
direct3d debug: 1 Direct3D pictures created successfully
direct3d debug: Direct3D scene created successfully
main debug: got 1 direct buffer(s)
main debug: pic render sz 1600x1200, of (0,0), vsz 1600x1200, 4cc YUY2, ar 4:3, sar 1:1, msk r0x0 g0x0 b0x0
main debug: pic in sz 1600x1200, of (0,0), vsz 1600x1200, 4cc YUY2, ar 4:3, sar 1:1, msk r0x0 g0x0 b0x0
main debug: pic out sz 1600x1200, of (0,0), vsz 1600x1200, 4cc YUY2, ar 4:3, sar 1:1, msk r0x0 g0x0 b0x0
main debug: direct render, mapping render pictures 0-14 to system pictures 1-15
main debug: End of video preroll
qt4 debug: Qt: Entering Fullscreen
freetype debug: using fontsize: 75
main debug: looking for video blending module: 1 candidate
blend debug: chroma: YUVA -> YUY2
main debug: using video blending module "blend"
main debug: TIMER module_need() : 0.000 ms - Total 0.000 ms / 1 intvls (Avg 0.000 ms)
main warning: timing screwed, stopping resampling
main warning: buffer is 105983 late, triggering upsampling
main warning: resampling stopped after 3265000 usec (drift: -47497)
main warning: buffer is 44522 late, triggering upsampling
main error: ES_OUT_SET_(GROUP_)PCR  is called too late, increasing pts_delay to 200 ms
main error: ES_OUT_RESET_PCR called
rawvideo warning: invalid frame size (128 < 3840000)
main debug: End of video preroll
main debug: Received first picture
main debug: Buffering 0%
main debug: End of audio preroll
main debug: Buffering 55%
main debug: Buffering -52%
main debug: Stream buffering done (223 ms in 213 ms)
main debug: Decoder buffering done in 1 ms
main warning: PTS is out of range (-10000), dropping buffer
main warning: output PTS is out of range (9000), clearing out
main warning: PTS is out of range (-33219), dropping buffer
main error: ES_OUT_SET_(GROUP_)PCR  is called too late, increasing pts_delay to 238 ms
main error: ES_OUT_RESET_PCR called
rawvideo warning: invalid frame size (128 < 3840000)
main debug: End of video preroll
main debug: Received first picture
main debug: Buffering 0%
main debug: End of audio preroll
main debug: Buffering -87%
main debug: Buffering 46%
main debug: Buffering 89%
main debug: Buffering -17%
main debug: Stream buffering done (325 ms in 325 ms)
main debug: Decoder buffering done in 0 ms
main warning: PTS is out of range (-10000), dropping buffer
main warning: output PTS is out of range (141561), clearing out
main warning: PTS is out of range (-33219), dropping buffer
main warning: buffer is 95917 late, triggering upsampling
main error: ES_OUT_SET_(GROUP_)PCR  is called too late, increasing pts_delay to 346 ms
main error: ES_OUT_RESET_PCR called
rawvideo warning: invalid frame size (128 < 3840000)
main debug: End of video preroll
main debug: Received first picture
main debug: Buffering 0%
main debug: End of audio preroll
main debug: Buffering 29%
main debug: Buffering -74%
main debug: Buffering 61%
main debug: Buffering 93%
main debug: Buffering -26%
main debug: Stream buffering done (427 ms in 437 ms)
main debug: Decoder buffering done in 0 ms
main warning: PTS is out of range (-10000), dropping buffer
main warning: output PTS is out of range (143561), clearing out
main warning: PTS is out of range (-33219), dropping buffer
main warning: buffer is 95957 late, triggering upsampling
main error: ES_OUT_SET_(GROUP_)PCR  is called too late, increasing pts_delay to 448 ms
main error: ES_OUT_RESET_PCR called
rawvideo warning: invalid frame size (128 < 3840000)
main debug: End of video preroll
main debug: Received first picture
main debug: Buffering 0%
main debug: End of audio preroll
main debug: Buffering -90%
main debug: Buffering 24%
main debug: Buffering 47%
main debug: Buffering -53%
main debug: Buffering 72%
main debug: Buffering 97%
main debug: Buffering -16%
main debug: Stream buffering done (539 ms in 539 ms)
main debug: Decoder buffering done in 0 ms
main warning: PTS is out of range (-10000), dropping buffer
main warning: output PTS is out of range (105561), clearing out
main warning: PTS is out of range (-33219), dropping buffer
main warning: buffer is 105973 late, triggering upsampling
main error: ES_OUT_SET_(GROUP_)PCR  is called too late, increasing pts_delay to 572 ms
main error: ES_OUT_RESET_PCR called
rawvideo warning: invalid frame size (128 < 3840000)
main debug: End of video preroll
main debug: Received first picture
main debug: Buffering 0%
main debug: End of audio preroll
main debug: Buffering 19%
main debug: Buffering -87%
main debug: Buffering 37%
main debug: Buffering 56%
main debug: Buffering -58%
main debug: Buffering 76%
main debug: Buffering -29%
main debug: Buffering 94%
main debug: Stream buffering done (650 ms in 650 ms)
main debug: Decoder buffering done in 0 ms
main warning: PTS is out of range (-10000), dropping buffer
main warning: output PTS is out of range (117561), clearing out
main warning: PTS is out of range (-32219), dropping buffer
main error: ES_OUT_SET_(GROUP_)PCR  is called too late, increasing pts_delay to 705 ms
main error: ES_OUT_RESET_PCR called
rawvideo warning: invalid frame size (128 < 3840000)
main warning: received buffer in the future
main debug: End of video preroll
main debug: Received first picture
main debug: Buffering 0%
main debug: End of audio preroll
main debug: Buffering 14%
main debug: Buffering -99%
main debug: Buffering 30%
main debug: Buffering 46%
main debug: Buffering -75%
main debug: Buffering 61%
main debug: Buffering -52%
main debug: Buffering 76%
main debug: Buffering 92%
main debug: Buffering -28%
main debug: Stream buffering done (762 ms in 761 ms)
main debug: Decoder buffering done in 1 ms
main warning: PTS is out of range (-10000), dropping buffer
main warning: output PTS is out of range (694561), clearing out
main warning: PTS is out of range (-33219), dropping buffer
main warning: buffer is 63164 late, triggering upsampling
main error: ES_OUT_SET_(GROUP_)PCR  is called too late, increasing pts_delay to 956 ms
main error: ES_OUT_RESET_PCR called
rawvideo warning: invalid frame size (128 < 3840000)
main warning: received buffer in the future
main warning: received buffer in the future
main warning: received buffer in the future
main warning: received buffer in the future
main warning: received buffer in the future
main debug: End of video preroll
main debug: Received first picture
main debug: Buffering 0%
main debug: End of audio preroll
main debug: Buffering 11%
main debug: Buffering -88%
main debug: Buffering 23%
main debug: Buffering 33%
main debug: Buffering -70%
main debug: Buffering 45%
main debug: Buffering 57%
main debug: Buffering -53%
main debug: Buffering 67%
main debug: Buffering 79%
main debug: Buffering -35%
main debug: Buffering 91%
main debug: Buffering -18%
main debug: Stream buffering done (985 ms in 976 ms)
main debug: Decoder buffering done in 0 ms
main warning: PTS is out of range (-10000), dropping buffer
main warning: late picture skipped (666336 > -2054)
main warning: output PTS is out of range (442561), clearing out
main warning: late picture skipped (332993 > -2054)
main warning: PTS is out of range (-33219), dropping buffer
main warning: late picture skipped (499665 > -2054)
main warning: late picture skipped (166321 > -2054)
main warning: late picture skipped (833008 > -2054)
main error: ES_OUT_SET_(GROUP_)PCR  is called too late, increasing pts_delay to 1147 ms
main error: ES_OUT_RESET_PCR called
rawvideo warning: invalid frame size (128 < 3840000)
main warning: received buffer in the future
main debug: End of video preroll
main debug: Received first picture
main debug: Buffering 0%
main debug: End of audio preroll
main debug: Buffering 9%
main debug: Buffering -90%
main debug: Buffering 18%
main debug: Buffering 28%
main debug: Buffering -76%
main debug: Buffering 38%
main debug: Buffering 47%
main debug: Buffering -61%
main debug: Buffering 56%
main debug: Buffering 66%
main debug: Buffering -47%
main debug: Buffering 76%
main debug: Buffering -32%
main debug: Buffering 84%
main debug: Buffering 94%
main debug: Buffering -18%
main debug: Stream buffering done (1198 ms in 1198 ms)
main debug: Decoder buffering done in 0 ms
main warning: PTS is out of range (-10000), dropping buffer
main warning: late picture skipped (866307 > -2002)
main warning: output PTS is out of range (715561), clearing out
main warning: late picture skipped (699635 > -2002)
main warning: PTS is out of range (-33219), dropping buffer
main warning: late picture skipped (1032978 > -2002)
main warning: late picture skipped (532963 > -2002)
main warning: late picture skipped (366292 > -2002)
main warning: late picture skipped (202620 > -2001)
main warning: buffer is 66895 late, triggering upsampling
main error: ES_OUT_SET_(GROUP_)PCR  is called too late, increasing pts_delay to 1388 ms
main error: ES_OUT_RESET_PCR called
rawvideo warning: invalid frame size (128 < 3840000)
main warning: received buffer in the future
main debug: End of video preroll
main debug: Received first picture
main debug: Buffering 0%
main debug: End of audio preroll
main debug: Buffering 7%
main debug: Buffering -92%
main debug: Buffering 16%
main debug: Buffering 23%
main debug: Buffering -80%
main debug: Buffering 31%
main debug: Buffering 39%
main debug: Buffering -68%
main debug: Buffering 47%
main debug: Buffering -56%
main debug: Buffering 54%
main debug: Buffering 62%
main debug: Buffering -44%
main debug: Buffering 70%
main debug: Buffering 78%
main debug: Buffering -32%
main debug: Buffering 86%
main debug: Buffering 94%
main debug: Buffering -20%
main debug: Stream buffering done (1422 ms in 1412 ms)
main debug: Decoder buffering done in 0 ms
main warning: PTS is out of range (-10000), dropping buffer
main warning: output PTS is out of range (919561), clearing out
main warning: PTS is out of range (-33219), dropping buffer
main warning: late picture skipped (778262 > -2000)
main warning: late picture skipped (611591 > -2000)
main warning: late picture skipped (1278277 > -2000)
main warning: late picture skipped (1111605 > -2000)
main warning: late picture skipped (944934 > -2000)
main warning: late picture skipped (448919 > -2250)
main warning: late picture skipped (284247 > -2250)
main error: ES_OUT_SET_(GROUP_)PCR  is called too late, increasing pts_delay to 1655 ms
main error: ES_OUT_RESET_PCR called
rawvideo warning: invalid frame size (128 < 3840000)
main warning: received buffer in the future
main warning: received buffer in the future
main warning: received buffer in the future
main warning: received buffer in the future
main debug: End of video preroll
main debug: Received first picture
main debug: Buffering 0%
main debug: End of audio preroll
main debug: Buffering 6%
main debug: Buffering -96%
main debug: Buffering 12%
main debug: Buffering -85%
main debug: Buffering 19%
main debug: Buffering 26%
main debug: Buffering -75%
main debug: Buffering 33%
main debug: Buffering 39%
main debug: Buffering -65%
main debug: Buffering 46%
main debug: Buffering 52%
main debug: Buffering -55%
main debug: Buffering 58%
main debug: Buffering 65%
main debug: Buffering -45%
main debug: Buffering 72%
main debug: Buffering 79%
main debug: Buffering -35%
main debug: Buffering 85%
main debug: Buffering -25%
main debug: Buffering 92%
main debug: Buffering 98%
main debug: Buffering -15%
main debug: Stream buffering done (1737 ms in 1736 ms)
main debug: Decoder buffering done in 0 ms
main warning: PTS is out of range (-10000), dropping buffer
main warning: output PTS is out of range (1303561), clearing out
main warning: late picture skipped (1246561 > -2282)
main warning: PTS is out of range (-32219), dropping buffer
main warning: late picture skipped (1079889 > -2282)
main warning: late picture skipped (913218 > -2282)
main warning: late picture skipped (1579904 > -2282)
main warning: late picture skipped (1413233 > -2282)
main warning: late picture skipped (749546 > -2282)
main warning: late picture skipped (584875 > -2211)
main warning: late picture skipped (421203 > -2211)
main warning: late picture skipped (256531 > -2211)
main warning: buffer is 86969 late, triggering upsampling
main error: ES_OUT_SET_(GROUP_)PCR  is called too late, increasing pts_delay to 1986 ms
main error: ES_OUT_RESET_PCR called
rawvideo warning: invalid frame size (128 < 3840000)
main warning: received buffer in the future
main warning: received buffer in the future
main warning: received buffer in the future
main warning: received buffer in the future
main debug: End of video preroll
main debug: Received first picture
main debug: Buffering 0%
main debug: End of audio preroll
main debug: Buffering 5%
main debug: Buffering -94%
main debug: Buffering 10%
main debug: Buffering 16%
main debug: Buffering -86%
main debug: Buffering 21%
main debug: Buffering 27%
main debug: Buffering -78%
main debug: Buffering 32%
main debug: Buffering -69%
main debug: Buffering 38%
main debug: Buffering 43%
main debug: Buffering -61%
main debug: Buffering 49%
main debug: Buffering 54%
main debug: Buffering -52%
main debug: Buffering 60%
main debug: Buffering 65%
main debug: Buffering -44%
main debug: Buffering 71%
main debug: Buffering 76%
main debug: Buffering -36%
main debug: Buffering 82%
main debug: Buffering 87%
main debug: Buffering -27%
main debug: Buffering 93%
main debug: Buffering 98%
main debug: Buffering -19%
main debug: Stream buffering done (2062 ms in 2063 ms)
main debug: Decoder buffering done in 0 ms
main warning: PTS is out of range (-10000), dropping buffer
main warning: late picture skipped (1207502 > -2105)
main warning: output PTS is out of range (1529561), clearing out
main warning: late picture skipped (1874188 > -2105)
main warning: PTS is out of range (-33219), dropping buffer
main warning: late picture skipped (1707517 > -2105)
main warning: late picture skipped (1540845 > -2105)
main warning: late picture skipped (1374173 > -2105)
main warning: late picture skipped (1043830 > -2328)
main warning: late picture skipped (879159 > -2328)
main warning: late picture skipped (715487 > -2328)
main warning: late picture skipped (558815 > -2496)
main warning: late picture skipped (394144 > -2496)
main warning: output date isn't PTS date, requesting resampling (41812)
main warning: buffer is 48210 late, triggering upsampling
main error: ES_OUT_SET_(GROUP_)PCR  is called too late, increasing pts_delay to 2321 ms
main error: ES_OUT_RESET_PCR called
rawvideo warning: invalid frame size (128 < 3840000)
main warning: late picture skipped (5137643999 > -2372)
main warning: received buffer in the future
main warning: late picture skipped (5137643999 > -2372)
main warning: late picture skipped (5137643999 > -2372)
main debug: End of video preroll
main debug: Received first picture
main debug: Buffering 0%
main debug: End of audio preroll
main debug: Buffering 4%
main debug: Buffering -102%
main debug: Buffering 9%
main debug: Buffering 14%
main debug: Buffering -95%
main debug: Buffering 18%
main debug: Buffering -87%
main debug: Buffering 23%
main debug: Buffering 28%
main debug: Buffering -80%
main debug: Buffering 32%
main debug: Buffering 37%
main debug: Buffering -73%
main debug: Buffering 42%
main debug: Buffering 47%
main debug: Buffering -66%
main debug: Buffering 51%
main debug: Buffering 56%
main debug: Buffering -59%
main debug: Buffering 61%
main debug: Buffering 65%
main debug: Buffering -52%
main debug: Buffering 70%
main debug: Buffering -44%
main debug: Buffering 75%
main debug: Buffering 80%
main debug: Buffering -37%
main debug: Buffering 84%
main debug: Buffering 89%
main debug: Buffering -30%
main debug: Buffering 94%
main debug: Buffering 98%
main debug: Buffering -23%
main debug: Stream buffering done (2397 ms in 2398 ms)
main debug: Decoder buffering done in 0 ms
main warning: late picture skipped (2031443 > -2118)
main warning: PTS is out of range (-10000), dropping buffer
main warning: late picture skipped (1864771 > -2118)
main warning: output PTS is out of range (2510749), clearing out
main warning: late picture skipped (1698099 > -2118)
main warning: PTS is out of range (-33219), dropping buffer
main warning: late picture skipped (2364786 > -2118)
main warning: late picture skipped (2198114 > -2118)
main warning: late picture skipped (1533428 > -2118)
main warning: late picture skipped (1369756 > -2338)
main warning: late picture skipped (1205085 > -2338)
main warning: late picture skipped (1040413 > -2338)
main warning: late picture skipped (888741 > -2753)
main warning: late picture skipped (724070 > -2753)
main warning: late picture skipped (559398 > -2753)
main warning: buffer is 82583 late, triggering upsampling
main error: ES_OUT_SET_(GROUP_)PCR  is called too late, increasing pts_delay to 2896 ms
main error: ES_OUT_RESET_PCR called
rawvideo warning: invalid frame size (128 < 3840000)
main warning: received buffer in the future
main warning: received buffer in the future
main debug: End of video preroll
main debug: Received first picture
main debug: Buffering 0%
main debug: End of audio preroll
main debug: Buffering 3%
main debug: Buffering -97%
main debug: Buffering 7%
main debug: Buffering 11%
main debug: Buffering -91%
main debug: Buffering 14%
main debug: Buffering -86%
main debug: Buffering 18%
main debug: Buffering 22%
main debug: Buffering -80%
main debug: Buffering 26%
main debug: Buffering 29%
main debug: Buffering -74%
main debug: Buffering 33%
main debug: Buffering 37%
main debug: Buffering -68%
main debug: Buffering 41%
main debug: Buffering 44%
main debug: Buffering -63%
main debug: Buffering 48%
main debug: Buffering 52%
main debug: Buffering -57%
main debug: Buffering 56%
main debug: Buffering -51%
main debug: Buffering 59%
main debug: Buffering 63%
main debug: Buffering -45%
main debug: Buffering 67%
main debug: Buffering 71%
main debug: Buffering -40%
main debug: Buffering 75%
main debug: Buffering 78%
main debug: Buffering -34%
main debug: Buffering 82%
main debug: Buffering 86%
main debug: Buffering -28%
main debug: Buffering 90%
main debug: Buffering 93%
main debug: Buffering -22%
main debug: Buffering 97%
main debug: Buffering -17%
main debug: Stream buffering done (2936 ms in 2946 ms)
main debug: Decoder buffering done in 0 ms
main warning: PTS is out of range (-10000), dropping buffer
main warning: output PTS is out of range (2452561), clearing out
main warning: PTS is out of range (-33219), dropping buffer
main warning: late picture skipped (2484712 > -2043)
main warning: late picture skipped (2318040 > -2043)
main warning: late picture skipped (2151369 > -2043)
main warning: late picture skipped (2818055 > -2043)
main warning: late picture skipped (2651383 > -2043)
main warning: late picture skipped (1987697 > -2282)
main warning: late picture skipped (1823025 > -2282)
main warning: late picture skipped (1658354 > -2282)
main warning: late picture skipped (1497682 > -2711)
main warning: late picture skipped (1333011 > -2711)
main warning: late picture skipped (1168339 > -2711)
main warning: late picture skipped (1014667 > -4283)
main warning: late picture skipped (849996 > -4283)
main warning: late picture skipped (684324 > -4283)
main warning: late picture skipped (530653 > -5462)
main warning: buffer is 65000 late, triggering upsampling
main error: ES_OUT_SET_(GROUP_)PCR  is called too late, increasing pts_delay to 3439 ms
main error: ES_OUT_RESET_PCR called
rawvideo warning: invalid frame size (128 < 3840000)
main warning: received buffer in the future
main debug: End of video preroll
main debug: Received first picture
main debug: Buffering 0%
main debug: End of audio preroll
main debug: Buffering 3%
main debug: Buffering -96%
main debug: Buffering 6%
main debug: Buffering 9%
main debug: Buffering -91%
main debug: Buffering 12%
main debug: Buffering 15%
main debug: Buffering -86%
main debug: Buffering 19%
main debug: Buffering 22%
main debug: Buffering -81%
main debug: Buffering 25%
main debug: Buffering 28%
main debug: Buffering -76%
main debug: Buffering 31%
main debug: Buffering -72%
main debug: Buffering 34%
main debug: Buffering 38%
main debug: Buffering -67%
main debug: Buffering 41%
main debug: Buffering 44%
main debug: Buffering -62%
main debug: Buffering 47%
main debug: Buffering 50%
main debug: Buffering -57%
main debug: Buffering 53%
main debug: Buffering 57%
main debug: Buffering -52%
main debug: Buffering 60%
main debug: Buffering 63%
main debug: Buffering -47%
main debug: Buffering 66%
main debug: Buffering -42%
main debug: Buffering 69%
main debug: Buffering 72%
main debug: Buffering -38%
main debug: Buffering 75%
main debug: Buffering 79%
main debug: Buffering -33%
main debug: Buffering 82%
main debug: Buffering 85%
main debug: Buffering -28%
main debug: Buffering 88%
main debug: Buffering 91%
main debug: Buffering -23%
main debug: Buffering 95%
main debug: Buffering 98%
main debug: Buffering -18%
main debug: Stream buffering done (3485 ms in 3485 ms)
main debug: Decoder buffering done in 0 ms
main warning: PTS is out of range (-10000), dropping buffer
main warning: late picture skipped (2633623 > -2160)
main warning: output PTS is out of range (2991561), clearing out
main warning: late picture skipped (3300309 > -2160)
main warning: PTS is out of range (-33219), dropping buffer
main warning: late picture skipped (3133638 > -2160)
main warning: late picture skipped (2966966 > -2160)
main warning: late picture skipped (2800295 > -2160)
main warning: late picture skipped (2468951 > -2160)
main warning: late picture skipped (2305280 > -2370)
main warning: late picture skipped (2140608 > -2370)
main warning: late picture skipped (1975937 > -2370)
main warning: late picture skipped (1831265 > -3027)
main warning: late picture skipped (1665593 > -3027)
main warning: late picture skipped (1500922 > -3027)
main warning: late picture skipped (1347250 > -3270)
main warning: late picture skipped (1181579 > -3270)
main warning: late picture skipped (1016907 > -3270)
main warning: late picture skipped (864235 > -4702)
main warning: late picture skipped (698564 > -4702)
main error: ES_OUT_SET_(GROUP_)PCR  is called too late, increasing pts_delay to 4003 ms
main error: ES_OUT_RESET_PCR called
rawvideo warning: invalid frame size (128 < 3840000)
main warning: late picture skipped (5147452999 > -4026)
main warning: late picture skipped (5147452999 > -4026)
main warning: received buffer in the future
main debug: End of video preroll
main debug: Received first picture
main debug: Buffering 0%
main debug: End of audio preroll
main debug: Buffering 2%
main debug: Buffering -100%
main debug: Buffering 5%
main debug: Buffering 8%
main debug: Buffering -96%
main debug: Buffering 10%
main debug: Buffering 13%
main debug: Buffering -91%
main debug: Buffering 16%
main debug: Buffering 19%
main debug: Buffering -87%
main debug: Buffering 21%
main debug: Buffering -83%
main debug: Buffering 24%
main debug: Buffering 27%
main debug: Buffering -79%
main debug: Buffering 29%
main debug: Buffering 32%
main debug: Buffering -75%
main debug: Buffering 35%
main debug: Buffering 38%
main debug: Buffering -71%
main debug: Buffering 40%
main debug: Buffering 43%
main debug: Buffering -66%
main debug: Buffering 46%
main debug: Buffering 48%
main debug: Buffering -62%
main debug: Buffering 51%
main debug: Buffering -58%
main debug: Buffering 54%
main debug: Buffering 57%
main debug: Buffering -54%
main debug: Buffering 59%
main debug: Buffering 62%
main debug: Buffering -50%
main debug: Buffering 65%
main debug: Buffering 68%
main debug: Buffering -46%
main debug: Buffering 70%
main debug: Buffering 73%
main debug: Buffering -41%
main debug: Buffering 76%
main debug: Buffering 78%
main debug: Buffering -37%
main debug: Buffering 81%
main debug: Buffering -33%
main debug: Buffering 84%
main debug: Buffering 87%
main debug: Buffering -29%
main debug: Buffering 89%
main debug: Buffering 92%
main debug: Buffering -25%
main debug: Buffering 95%
main debug: Buffering 97%
main debug: Buffering -21%
main debug: Stream buffering done (4023 ms in 4033 ms)
main debug: Decoder buffering done in 0 ms
main warning: PTS is out of range (-10000), dropping buffer
main warning: output PTS is out of range (3965561), clearing out
main warning: late picture skipped (4000877 > -2140)
main warning: PTS is out of range (-33219), dropping buffer
main warning: late picture skipped (3834206 > -2140)
main warning: late picture skipped (3667534 > -2140)
main warning: late picture skipped (3500863 > -2140)
main warning: late picture skipped (3334191 > -2140)
main warning: late picture skipped (3170519 > -2105)
main warning: late picture skipped (3005848 > -2105)
main warning: late picture skipped (2843176 > -2328)
main warning: late picture skipped (2678505 > -2328)
main warning: late picture skipped (2514833 > -2328)
main warning: late picture skipped (2359161 > -2246)
main warning: late picture skipped (2195490 > -2246)
main warning: late picture skipped (2030818 > -2246)
main warning: late picture skipped (1875147 > -2184)
main warning: late picture skipped (1710475 > -2184)
main warning: late picture skipped (1545803 > -2184)
main warning: late picture skipped (1392132 > -2388)
main warning: late picture skipped (1226460 > -2388)
main warning: late picture skipped (1061789 > -2388)
main warning: late picture skipped (908117 > -2541)
main error: ES_OUT_SET_(GROUP_)PCR  is called too late, increasing pts_delay to 4814 ms
main error: ES_OUT_RESET_PCR called
rawvideo warning: invalid frame size (128 < 3840000)
main warning: received buffer in the future
main warning: received buffer in the future
main warning: received buffer in the future
main warning: received buffer in the future
main warning: received buffer in the future
main debug: End of video preroll
main debug: Received first picture
main debug: Buffering 0%
main debug: End of audio preroll
main debug: Buffering 2%
main debug: Buffering -98%
main debug: Buffering 4%
main debug: Buffering -95%
main debug: Buffering 6%
main debug: Buffering 8%
main debug: Buffering -91%
main debug: Buffering 11%
main debug: Buffering 13%
main debug: Buffering -88%
main debug: Buffering 15%
main debug: Buffering 17%
main debug: Buffering -84%
main debug: Buffering 20%
main debug: Buffering 22%
main debug: Buffering -81%
main debug: Buffering 24%
main debug: Buffering 27%
main debug: Buffering -78%
main debug: Buffering 29%
main debug: Buffering -74%
main debug: Buffering 31%
main debug: Buffering 33%
main debug: Buffering -71%
main debug: Buffering 36%
main debug: Buffering 38%
main debug: Buffering -67%
main debug: Buffering 40%
main debug: Buffering 42%
main debug: Buffering -64%
main debug: Buffering 45%
main debug: Buffering 47%
main debug: Buffering -60%
main debug: Buffering 49%
main debug: Buffering 51%
main debug: Buffering -57%
main debug: Buffering 54%
main debug: Buffering 56%
main debug: Buffering -53%
main debug: Buffering 58%
main debug: Buffering -50%
main debug: Buffering 60%
main debug: Buffering 63%
main debug: Buffering -46%
main debug: Buffering 65%
main debug: Buffering 67%
main debug: Buffering -43%
main debug: Buffering 70%
main debug: Buffering 72%
main debug: Buffering -39%
main debug: Buffering 74%
main debug: Buffering 76%
main debug: Buffering -36%
main debug: Buffering 79%
main debug: Buffering 81%
main debug: Buffering -33%
main debug: Buffering 83%
main debug: Buffering -29%
main debug: Buffering 85%
main debug: Buffering 87%
main debug: Buffering -26%
main debug: Buffering 90%
main debug: Buffering 92%
main debug: Buffering -22%
main debug: Buffering 94%
main debug: Buffering 97%
main debug: Buffering -19%
main debug: Buffering 99%
main debug: Stream buffering done (4897 ms in 4896 ms)
main debug: Decoder buffering done in 0 ms
main warning: PTS is out of range (-10000), dropping buffer
main warning: output PTS is out of range (4452561), clearing out
main warning: late picture skipped (4080087 > -2000)
main warning: PTS is out of range (-33219), dropping buffer
main warning: late picture skipped (4746774 > -2000)
main warning: late picture skipped (4580102 > -2000)
main warning: late picture skipped (4413431 > -2000)
main warning: late picture skipped (4246759 > -2000)
main warning: late picture skipped (3917416 > -2250)
main warning: late picture skipped (3752744 > -2250)
main warning: late picture skipped (3594073 > -2437)
main warning: late picture skipped (3429401 > -2437)
main warning: late picture skipped (3264729 > -2437)
main warning: late picture skipped (3111058 > -2577)
main error: ES_OUT_SET_(GROUP_)PCR  is called too late, increasing pts_delay to 5612 ms
main error: ES_OUT_RESET_PCR called
main warning: can't get output picture
rawvideo warning: invalid frame size (128 < 3840000)
main warning: late picture skipped (5157278999 > -2577)
main warning: received buffer in the future
main warning: late picture skipped (5157278999 > -2577)
main warning: received buffer in the future
main warning: late picture skipped (5157278999 > -2577)
main warning: received buffer in the future
main warning: late picture skipped (5157278999 > -2577)
main warning: received buffer in the future
main warning: late picture skipped (5157278999 > -2577)
main warning: received buffer in the future
main warning: late picture skipped (5157278999 > -2577)
main warning: late picture skipped (5157278999 > -2577)
main warning: late picture skipped (5157278999 > -2577)
main warning: late picture skipped (5157278999 > -2577)
main warning: late picture skipped (5157278999 > -2577)
main warning: late picture skipped (5157278999 > -2577)
main warning: late picture skipped (5157278999 > -2577)
main warning: late picture skipped (5157278999 > -2577)
main warning: late picture skipped (5157278999 > -2577)
main debug: End of video preroll
main debug: Received first picture
main debug: Buffering 0%
main debug: End of audio preroll
main debug: Buffering 1%
main debug: Buffering -100%
main debug: Buffering 3%
main debug: Buffering 5%
main debug: Buffering -97%
main debug: Buffering 7%
main debug: Buffering 9%
main debug: Buffering -94%
main debug: Buffering 11%
main debug: Buffering 48%
main debug: Buffering -61%
main debug: Buffering 50%
main debug: Buffering 52%
main debug: Buffering -58%
main debug: Buffering 54%
main debug: Buffering 56%
main debug: Buffering -55%
main debug: Buffering 58%
main debug: Buffering -52%
main debug: Buffering 60%
main debug: Buffering 62%
main debug: Buffering -49%
main debug: Buffering 64%
main debug: Buffering 65%
main debug: Buffering -46%
main debug: Buffering 67%
main debug: Buffering 69%
main debug: Buffering -44%
main debug: Buffering 71%
main debug: Buffering 73%
main debug: Buffering -41%
main debug: Buffering 75%
main debug: Buffering 77%
main debug: Buffering -38%
main debug: Buffering 79%
main debug: Buffering -35%
main debug: Buffering 81%
main debug: Buffering 83%
main debug: Buffering -32%
main debug: Buffering 85%
main debug: Buffering 87%
main debug: Buffering -29%
main debug: Buffering 89%
main debug: Buffering 91%
main debug: Buffering -26%
main debug: Buffering 93%
main debug: Buffering 95%
main debug: Buffering -23%
main debug: Buffering 96%
main debug: Buffering 98%
main debug: Buffering -20%
main debug: Stream buffering done (5658 ms in 5659 ms)
main debug: Decoder buffering done in 0 ms
main warning: PTS is out of range (-10000), dropping buffer
main warning: late picture skipped (4960283 > -2036)
main warning: output PTS is out of range (5812561), clearing out
main warning: late picture skipped (5626969 > -2036)
main warning: PTS is out of range (-33219), dropping buffer
main warning: late picture skipped (5460297 > -2036)
main warning: late picture skipped (5293626 > -2036)
main warning: late picture skipped (5126954 > -2036)
main warning: late picture skipped (4796611 > -2277)
main warning: late picture skipped (4632939 > -2277)
main warning: late picture skipped (4468268 > -2277)
main warning: late picture skipped (4304596 > -2207)
main warning: late picture skipped (4139925 > -2207)
main warning: late picture skipped (3987253 > -2405)
main warning: late picture skipped (3823581 > -2405)
main warning: late picture skipped (3658910 > -2405)
main warning: late picture skipped (3503238 > -2553)
main warning: late picture skipped (3338567 > -2553)
main warning: late picture skipped (3172895 > -2553)
main warning: late picture skipped (3019223 > -2664)
main warning: late picture skipped (2853552 > -2664)
main warning: late picture skipped (2688880 > -2664)
main warning: late picture skipped (2536209 > -2748)
main warning: late picture skipped (2370537 > -2748)
main warning: late picture skipped (2205865 > -2748)
main warning: late picture skipped (2052194 > -2811)
main warning: late picture skipped (1887522 > -2811)
main warning: late picture skipped (1721851 > -2811)
main warning: late picture skipped (1569179 > -2858)
main warning: late picture skipped (1403507 > -2858)
main warning: late picture skipped (1293837 > -2858)
main error: ES_OUT_SET_(GROUP_)PCR  is called too late, increasing pts_delay to 6711 ms
main error: ES_OUT_RESET_PCR called
rawvideo warning: invalid frame size (128 < 3840000)
main warning: received buffer in the future
main warning: received buffer in the future
main debug: End of video preroll
main debug: Received first picture
main debug: Buffering 0%
main debug: End of audio preroll
main debug: Buffering -99%
main debug: Buffering 1%
main debug: Buffering 3%
main debug: Buffering -97%
main debug: Buffering 4%
main debug: Buffering 6%
main debug: Buffering -94%
main debug: Buffering 8%
main debug: Buffering 9%
main debug: Buffering -92%
main debug: Buffering 11%
main debug: Buffering 12%
main debug: Buffering -89%
main debug: Buffering 14%
main debug: Buffering 16%
main debug: Buffering -87%
main debug: Buffering 17%
main debug: Buffering -84%
main debug: Buffering 19%
main debug: Buffering 21%
main debug: Buffering -82%
main debug: Buffering 22%
main debug: Buffering 24%
main debug: Buffering -79%
main debug: Buffering 25%
main debug: Buffering 27%
main debug: Buffering -77%
main debug: Buffering 29%
main debug: Buffering 30%
main debug: Buffering -74%
main debug: Buffering 32%
main debug: Buffering 34%
main debug: Buffering -72%
main debug: Buffering 35%
main debug: Buffering -69%
main debug: Buffering 37%
main debug: Buffering 38%
main debug: Buffering -67%
main debug: Buffering 40%
main debug: Buffering 42%
main debug: Buffering -64%
main debug: Buffering 43%
main debug: Buffering 45%
main debug: Buffering -62%
main debug: Buffering 46%
main debug: Buffering 48%
main debug: Buffering -59%
main debug: Buffering 50%
main debug: Buffering 51%
main debug: Buffering -57%
main debug: Buffering 53%
main debug: Buffering -54%
main debug: Buffering 55%
main debug: Buffering 56%
main debug: Buffering -52%
main debug: Buffering 58%
main debug: Buffering 59%
main debug: Buffering -49%
main debug: Buffering 61%
main debug: Buffering 63%
main debug: Buffering -47%
main debug: Buffering 64%
main debug: Buffering 66%
main debug: Buffering -44%
main debug: Buffering 68%
main debug: Buffering 69%
main debug: Buffering -42%
main debug: Buffering 71%
main debug: Buffering 72%
main debug: Buffering -39%
main debug: Buffering 74%
main debug: Buffering -37%
main debug: Buffering 76%
main debug: Buffering 77%
main debug: Buffering -35%
main debug: Buffering 79%
main debug: Buffering 80%
main debug: Buffering -32%
main debug: Buffering 82%
main debug: Buffering 84%
main debug: Buffering -30%
main debug: Buffering 85%
main debug: Buffering 87%
main debug: Buffering -27%
main debug: Buffering 89%
main debug: Buffering 90%
main debug: Buffering -25%
main debug: Buffering 92%
main debug: Buffering -22%
main debug: Buffering 93%
main debug: Buffering 95%
main debug: Buffering -20%
main debug: Buffering 97%
main debug: Buffering 98%
main debug: Buffering -17%
main debug: Stream buffering done (6747 ms in 6757 ms)
main debug: Decoder buffering done in 0 ms
main warning: PTS is out of range (-10000), dropping buffer
main warning: late picture skipped (6674493 > -2000)
main warning: output PTS is out of range (6363561), clearing out
main warning: late picture skipped (6507821 > -2000)
main warning: PTS is out of range (-33219), dropping buffer
main warning: late picture skipped (6341149 > -2000)
main warning: late picture skipped (6174478 > -2000)
main warning: late picture skipped (6007806 > -2000)
main warning: late picture skipped (5844135 > -2250)
main warning: late picture skipped (5679463 > -2250)
main warning: late picture skipped (5513791 > -2250)
main warning: late picture skipped (5362120 > -2187)
main warning: late picture skipped (5197448 > -2187)
main warning: late picture skipped (5031777 > -2187)
main warning: late picture skipped (4878105 > -2390)
main warning: late picture skipped (4713433 > -2390)
main warning: late picture skipped (4547762 > -2390)
main warning: late picture skipped (4395090 > -2542)
main warning: late picture skipped (4230419 > -2542)
main warning: late picture skipped (4064747 > -2542)
main warning: late picture skipped (3912075 > -2656)
main warning: late picture skipped (3746404 > -2656)
main warning: late picture skipped (3581732 > -2656)
main warning: late picture skipped (3428061 > -2742)
main warning: late picture skipped (3263389 > -2742)
main warning: late picture skipped (3097717 > -2742)
main warning: late picture skipped (2945046 > -3056)
main warning: late picture skipped (2836538 > -3056)
main warning: late picture skipped (2670867 > -3056)
main warning: buffer is 61380 late, triggering upsampling
main warning: late picture skipped (2518195 > -3292)
main warning: late picture skipped (2352523 > -3292)
main warning: late picture skipped (2187852 > -3292)
main warning: late picture skipped (2034180 > -3219)
main warning: late picture skipped (1869509 > -3219)
main warning: late picture skipped (1703837 > -3219)
main error: ES_OUT_SET_(GROUP_)PCR  is called too late, increasing pts_delay to 7895 ms
main error: ES_OUT_RESET_PCR called
main warning: late picture skipped (1551165 > -3414)
rawvideo warning: invalid frame size (128 < 3840000)
main warning: received buffer in the future
main warning: received buffer in the future
main debug: End of video preroll
main debug: Received first picture
main debug: Buffering 0%
main debug: End of audio preroll
main debug: Buffering 1%
main debug: Buffering -98%
main debug: Buffering 2%
main debug: Buffering 4%
main debug: Buffering -96%
main debug: Buffering 5%
main debug: Buffering -94%
main debug: Buffering 6%
main debug: Buffering 8%
main debug: Buffering -92%
main debug: Buffering 9%
main debug: Buffering 11%
main debug: Buffering -90%
main debug: Buffering 12%
main debug: Buffering 13%
main debug: Buffering -88%
main debug: Buffering 15%
main debug: Buffering 16%
main debug: Buffering -86%
main debug: Buffering 18%
main debug: Buffering 19%
main debug: Buffering -84%
main debug: Buffering 20%
main debug: Buffering 22%
main debug: Buffering -82%
main debug: Buffering 23%
main debug: Buffering -79%
main debug: Buffering 24%
main debug: Buffering 26%
main debug: Buffering -77%
main debug: Buffering 27%
main debug: Buffering 28%
main debug: Buffering -75%
main debug: Buffering 30%
main debug: Buffering 31%
main debug: Buffering -73%
main debug: Buffering 33%
main debug: Buffering 34%
main debug: Buffering -71%
main debug: Buffering 35%
main debug: Buffering 37%
main debug: Buffering -69%
main debug: Buffering 38%
main debug: Buffering -67%
main debug: Buffering 40%
main debug: Buffering 41%
main debug: Buffering -65%
main debug: control type=1
main debug: thread (es out timeshift) created at priority 1 (../.././src/input/es_out_timeshift.c:743)
main debug: thread started
main debug: Buffering 42%
main debug: Buffering 44%
main debug: Buffering -63%
main debug: Buffering 45%
main debug: Buffering 46%
main debug: Buffering -60%
main debug: Buffering 48%
main debug: Buffering 49%
main debug: Buffering -58%
main debug: Buffering 51%
main debug: Buffering 52%
main debug: Buffering -56%
main debug: Buffering 53%
main debug: Buffering -54%
main debug: Buffering 55%
main debug: Buffering 56%
main debug: Buffering -52%
main debug: Buffering 57%
main debug: Buffering 59%
main debug: Buffering -50%
main debug: Buffering 60%
main debug: Buffering 62%
main debug: Buffering -48%
main debug: Buffering 63%
main debug: Buffering 64%
main debug: Buffering -46%
main debug: Buffering 66%
main debug: Buffering 67%
main debug: Buffering -44%
main debug: Buffering 68%
main debug: Buffering -41%
main debug: Buffering 70%
main debug: Buffering 71%
main debug: Buffering -39%
main debug: Buffering 73%
main debug: Buffering 74%
main debug: Buffering -37%
main debug: Buffering 75%
main debug: Buffering 77%
main debug: Buffering -35%
main debug: Buffering 78%
main debug: Buffering 80%
main debug: Buffering -33%
main debug: Buffering 81%
main debug: Buffering 82%
main debug: Buffering -31%
main debug: Buffering 84%
main debug: Buffering 85%
main debug: Buffering -29%
main debug: Buffering 86%
main debug: Buffering -27%
main debug: Buffering 88%
main debug: Buffering 89%
main debug: Buffering -25%
main debug: Buffering 90%
main debug: Buffering 92%
main debug: Buffering -22%
main debug: Buffering 93%
main debug: Buffering 95%
main debug: Buffering -20%
main debug: Buffering 96%
main debug: Buffering 97%
main debug: Buffering -18%
main debug: Buffering 99%
main debug: Stream buffering done (7944 ms in 7944 ms)
main debug: Decoder buffering done in 0 ms