Ticket #7713: playback-issue.txt

File playback-issue.txt, 26.5 KB (added by Bánó Gábor <banogabor@…>, 16 years ago)

Strange playback issue in mythfrontend. Watch the fps!

Line 
12009-12-06 20:03:51.717 mythfrontend version: trunk [22859M] www.mythtv.org
22009-12-06 20:03:51.718 Using runtime prefix = /usr/local
32009-12-06 20:03:51.718 Using configuration directory = /home/gabesz/.mythtv
42009-12-06 20:03:52.497 Empty LocalHostName.
52009-12-06 20:03:52.497 Using localhost value of gabesz-linux
62009-12-06 20:03:52.498 Testing network connectivity to '192.168.1.1'
72009-12-06 20:03:52.509 New DB connection, total: 1
82009-12-06 20:03:52.515 Connected to database 'mythconverg' at host: 192.168.1.1
92009-12-06 20:03:52.516 Closing DB connection named 'DBManager0'
102009-12-06 20:03:52.528 ScreenSaverX11Private: Gnome screen saver support enabled
112009-12-06 20:03:52.530 DPMS is disabled.
122009-12-06 20:03:52.531 Primary screen: 0.
132009-12-06 20:03:52.533 Connected to database 'mythconverg' at host: 192.168.1.1
142009-12-06 20:03:52.535 Running in a window
152009-12-06 20:03:52.536 Using screen 0, 1920x1030 at 0,25
162009-12-06 20:03:52.565 MythUI Image Cache size set to 20971520 bytes
172009-12-06 20:03:52.593 AudioPulseUtil: Suspend Success
182009-12-06 20:03:52.593 user: 1000 effective user: 1000 before privileged thread
192009-12-06 20:03:52.594 user: 1000 effective user: 1000 run_priv_thread
202009-12-06 20:03:52.594 user: 1000 effective user: 1000 after privileged thread
212009-12-06 20:03:52.594 Enabled verbose msgs: important general playback
222009-12-06 20:03:52.612 Primary screen: 0.
232009-12-06 20:03:52.613 Running in a window
242009-12-06 20:03:52.613 Using screen 0, 1920x1030 at 0,25
252009-12-06 20:03:52.614 Using theme base resolution of 1280x720
262009-12-06 20:03:52.638 LIRC, Error: Failed to connect to Unix socket '/dev/lircd'
27 eno: Nincs ilyen fájl vagy könyvtár (2)
282009-12-06 20:03:52.772 Using the OpenGL painter
292009-12-06 20:03:52.910 Loaded base theme from /usr/local/share/mythtv/themes/Mythbuntu/base.xml
302009-12-06 20:03:52.938 Loaded base theme from /usr/local/share/mythtv/themes/default-wide/base.xml
312009-12-06 20:03:52.970 Loaded base theme from /usr/local/share/mythtv/themes/default/base.xml
322009-12-06 20:03:52.970 Unable to load window 'backgroundwindow' from base
332009-12-06 20:03:53.005 Current MythTV Schema Version (DBSchemaVer): 1246
342009-12-06 20:03:53.317 Desktop video mode: 1920x1080 60.0024 Hz
352009-12-06 20:03:53.355 max_width: 1920 max_height: 1080
362009-12-06 20:03:53.697 Registering Internal as a media playback plugin.
372009-12-06 20:03:53.703 Plugin mytharchive (0.22.20091022-1) binary version does not match libraries (0.23.20091116-1)
382009-12-06 20:03:53.703 Test Popup Version Failed
392009-12-06 20:03:53.703 Unable to initialize plugin 'mytharchive'.
402009-12-06 20:03:53.704 Plugin mythbrowser (0.22.20091022-1) binary version does not match libraries (0.23.20091116-1)
412009-12-06 20:03:53.704 Unable to initialize plugin 'mythbrowser'.
422009-12-06 20:03:53.711 Plugin mythflix (0.22.20091022-1) binary version does not match libraries (0.23.20091116-1)
432009-12-06 20:03:53.711 Unable to initialize plugin 'mythflix'.
442009-12-06 20:03:53.713 Plugin mythgallery (0.22.20091022-1) binary version does not match libraries (0.23.20091116-1)
452009-12-06 20:03:53.713 Unable to initialize plugin 'mythgallery'.
462009-12-06 20:03:53.716 Plugin mythgame (0.22.20091022-1) binary version does not match libraries (0.23.20091116-1)
472009-12-06 20:03:53.716 libmythgame.so/main.o: binary version mismatch
482009-12-06 20:03:53.716 Unable to initialize plugin 'mythgame'.
492009-12-06 20:03:53.718 Plugin mythmovies (0.22.20091022-1) binary version does not match libraries (0.23.20091116-1)
502009-12-06 20:03:53.718 libmythmovies.so/main.o: binary version mismatch
512009-12-06 20:03:53.718 Unable to initialize plugin 'mythmovies'.
522009-12-06 20:03:53.720 Plugin mythnews (0.22.20091022-1) binary version does not match libraries (0.23.20091116-1)
532009-12-06 20:03:53.720 Unable to initialize plugin 'mythnews'.
542009-12-06 20:03:53.733 Current MythVideo Schema Version (mythvideo.DBSchemaVer): 1029
552009-12-06 20:03:53.817 MMUnix::AddDevice() Error: failed to stat /dev/bdi,
56 eno: Nincs ilyen fájl vagy könyvtár (2)
572009-12-06 20:03:53.820 MMUnix::AddDevice() Error: failed to stat /dev/power,
58 eno: Nincs ilyen fájl vagy könyvtár (2)
592009-12-06 20:03:53.827 MMUnix::AddDevice() Error: failed to stat /dev/trace,
60 eno: Nincs ilyen fájl vagy könyvtár (2)
612009-12-06 20:03:53.840 MMUnix::AddDevice() Error: failed to stat /dev/bdi,
62 eno: Nincs ilyen fájl vagy könyvtár (2)
632009-12-06 20:03:53.843 MMUnix::AddDevice() Error: failed to stat /dev/power,
64 eno: Nincs ilyen fájl vagy könyvtár (2)
652009-12-06 20:03:53.854 MMUnix::AddDevice() Error: failed to stat /dev/trace,
66 eno: Nincs ilyen fájl vagy könyvtár (2)
672009-12-06 20:03:53.864 Plugin mythweather (0.22.20091022-1) binary version does not match libraries (0.23.20091116-1)
682009-12-06 20:03:53.864 Unable to initialize plugin 'mythweather'.
692009-12-06 20:03:53.869 Loading window theme from /usr/local/share/mythtv/themes/Mythbuntu/menu-ui.xml
702009-12-06 20:03:53.906 Loading menu theme from /usr/local/share/mythtv/themes/classic//mainmenu.xml
712009-12-06 20:03:53.927 Found mainmenu.xml for theme 'Mythbuntu'
722009-12-06 20:03:54.087 Using NV NPOT texture extension
732009-12-06 20:03:54.136 MythContext: Connecting to backend server: 192.168.1.1:6543 (try 1 of 1)
742009-12-06 20:03:54.138 Using protocol version 50
752009-12-06 20:04:05.474 Loading menu theme from /usr/local/share/mythtv/themes/classic//tvmenu.xml
762009-12-06 20:04:06.856 New DB connection, total: 2
772009-12-06 20:04:06.857 Connected to database 'mythconverg' at host: 192.168.1.1
782009-12-06 20:04:06.861 Loading window theme from /usr/local/share/mythtv/themes/Mythbuntu/recordings-ui.xml
792009-12-06 20:04:09.833 TV: StartTV() -- begin
802009-12-06 20:04:09.833 TV: ctor
812009-12-06 20:04:09.938 TV: DrawUnusedRects() -- begin
822009-12-06 20:04:09.938 TV: DrawUnusedRects() -- end
832009-12-06 20:04:09.939 TV: tv->Playback() -- begin
842009-12-06 20:04:09.962 TV: tv->Playback() -- end
852009-12-06 20:04:09.962 TV: StartTV -- process events begin
862009-12-06 20:04:09.974 TV: HandleStateChange(0) -- begin
872009-12-06 20:04:09.975 TV: Attempting to change from None to Watching WatchingPreRecorded
882009-12-06 20:04:09.976 RingBuf(myth://192.168.1.1:6543/3203_20091202212000.mpg): OpenFile(myth://192.168.1.1:6543/3203_20091202212000.mpg, 12)
892009-12-06 20:04:10.095 RingBuf(myth://192.168.1.1:6543/3203_20091202212000.mpg): CalcReadAheadThresh(0 KB)
90 -> threshhold(64 KB) min read(0 KB) blk size(32 KB)
912009-12-06 20:04:10.145 TV: StartPlayer(0, Watching WatchingPreRecorded, main) -- begin
922009-12-06 20:04:10.248 [h264 @ 0x7f9a198e69e0]mmco: unref short failure
932009-12-06 20:04:10.745 AFD: Stream #0, has id 0x7ef codec id H264, type Video, bitrate 0 at 0x7f9a027f83a0
942009-12-06 20:04:10.750 VDP: Accepting: cmp() dec(vdpau) cpus(2) rend(vdpau) osd(vdpau) osdfade(enabled) deint(none,none) filt()
952009-12-06 20:04:10.750 VDP: LoadBestPreferences(2048x2048, 0)
962009-12-06 20:04:10.750 VDP: LoadBestPreferences(2048x2048, 60)
972009-12-06 20:04:10.750 VDP: LoadBestPreferences(720x576, 60)
982009-12-06 20:04:10.753 VDP: Accepting: cmp() dec(vdpau) cpus(2) rend(vdpau) osd(vdpau) osdfade(enabled) deint(none,none) filt()
992009-12-06 20:04:10.753 VDP: LoadBestPreferences(2048x2048, 0)
1002009-12-06 20:04:10.753 VDP: LoadBestPreferences(2048x2048, 60)
1012009-12-06 20:04:10.753 VDP: LoadBestPreferences(720x576, 60)
1022009-12-06 20:04:10.753 Using 1 CPUs for decoding
1032009-12-06 20:04:10.753 AFD: InitVideoCodec() 0x7f9a01e0ea50 id(H264) type (Video).
1042009-12-06 20:04:10.753 detectInterlace(Detect Scan, Interlaced Scan, 25, 576) ->Interlaced Scan
1052009-12-06 20:04:10.753 AFD: Using vdpau for video decoding
1062009-12-06 20:04:10.753 AFD: Looking for decoder for H264
1072009-12-06 20:04:10.754 AFD: Opened codec 0x7f9a01e0ea50, id(H264) type(Video)
1082009-12-06 20:04:10.754 AFD: Stream #1, has id 0x7f0 codec id AAC/LATM, type Audio, bitrate 0 at 0x7f9a01e0eff0
1092009-12-06 20:04:10.754 AFD: codec AAC/LATM has 2 channels
1102009-12-06 20:04:10.754 AFD: Looking for decoder for AAC/LATM
1112009-12-06 20:04:10.754 AFD: Opened codec 0x7f9a027fc840, id(AAC/LATM) type(Audio)
1122009-12-06 20:04:10.754 AFD: Stream #2, has id 0x7f1 codec id DVB_VBI, type Data, bitrate 0 at 0x7f9a01e0f3b0
1132009-12-06 20:04:10.754 AFD: data codec (Data)
1142009-12-06 20:04:10.754 AFD: Stream #3, has id 0x7f2 codec id DVB_VBI, type Data, bitrate 0 at 0x7f9a027fd250
1152009-12-06 20:04:10.754 AFD: data codec (Data)
1162009-12-06 20:04:10.754 RingBuf(myth://192.168.1.1:6543/3203_20091202212000.mpg): CalcReadAheadThresh(0 KB)
117 -> threshhold(64 KB) min read(0 KB) blk size(32 KB)
1182009-12-06 20:04:10.926 Opening audio device 'default'. ch 2(2) sr 48000 (reenc 0)
1192009-12-06 20:04:10.926 Opening ALSA audio device 'default'.
1202009-12-06 20:04:11.026 AudioOutput Warning: Mixer attach error -2: Nincs ilyen fájl vagy könyvtár
121 Check Mixer Name in Setup: '/dev/mixer'
1222009-12-06 20:04:11.043 Dec: Trying to select track (w/lang)
1232009-12-06 20:04:11.043 Dec: Selecting first track
1242009-12-06 20:04:11.043 Dec: Selected track #1 in the Unknown language(0)
1252009-12-06 20:04:11.043 Dec: Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
1262009-12-06 20:04:11.165 Position map filled from DB to: 112302
1272009-12-06 20:04:11.166 Dec: SyncPositionMap prerecorded, from DB: 4945 entries
1282009-12-06 20:04:11.166 Dec: SyncPositionMap, new totframes: 112302, new length: 4492, posMap size: 4945
1292009-12-06 20:04:11.166 AFD: Position map found
1302009-12-06 20:04:11.167 AFD: Successfully opened decoder for file: "myth://192.168.1.1:6543/3203_20091202212000.mpg". novideo(0)
1312009-12-06 20:04:11.186 VideoOutput: Allowed renderers: vdpau
1322009-12-06 20:04:11.187 VideoOutput: Allowed renderers (filt: vdpau): vdpau
1332009-12-06 20:04:11.190 VDP: Accepting: cmp() dec(vdpau) cpus(2) rend(vdpau) osd(vdpau) osdfade(enabled) deint(none,none) filt()
1342009-12-06 20:04:11.190 VDP: LoadBestPreferences(2048x2048, 0)
1352009-12-06 20:04:11.190 VDP: LoadBestPreferences(2048x2048, 60)
1362009-12-06 20:04:11.190 VDP: LoadBestPreferences(720x576, 60)
1372009-12-06 20:04:11.190 VideoOutput: Preferred renderer: vdpau
1382009-12-06 20:04:11.190 VideoOutput: Trying video renderer: 'vdpau'
1392009-12-06 20:04:11.214 VDP: Accepting: cmp() dec(vdpau) cpus(2) rend(vdpau) osd(vdpau) osdfade(enabled) deint(none,none) filt()
1402009-12-06 20:04:11.214 VDP: LoadBestPreferences(2048x2048, 0)
1412009-12-06 20:04:11.215 VDP: LoadBestPreferences(2048x2048, 60)
1422009-12-06 20:04:11.225 VideoOutWindow::SetPIPState. pip_state: 0]
1432009-12-06 20:04:11.225 Snapping width to avoid scaling: width: 720, left: 0
1442009-12-06 20:04:11.225 Display Rect left: 0, top: 5, width: 720, height: 469, aspect: 1.33333
1452009-12-06 20:04:11.225 Video Rect left: 0, top: 0, width: 720, height: 576, aspect: 1.36364
1462009-12-06 20:04:11.225 VDP: LoadBestPreferences(720x576, 60)
1472009-12-06 20:04:11.225 Snapping width to avoid scaling: width: 720, left: 0
1482009-12-06 20:04:11.225 Display Rect left: 0, top: 5, width: 720, height: 469, aspect: 1.33333
1492009-12-06 20:04:11.225 Video Rect left: 0, top: 0, width: 720, height: 576, aspect: 1.36364
1502009-12-06 20:04:11.225 VDP: SetVideoRenderer(vdpau)
1512009-12-06 20:04:11.226 VDP: SetVideoRender(vdpau) == GetVideoRenderer()
1522009-12-06 20:04:11.226 VidOutVDPAU: VDPAU Colorkey: 0x20202 (depth 24)
1532009-12-06 20:04:11.228 VideoOutput: Pixel dimensions: Screen 1920x1080, window 720x480
1542009-12-06 20:04:11.228 VideoOutput: Actual display dimensions: 513x292 mm Aspect: 1.75685
1552009-12-06 20:04:11.228 VideoOutput: Estimated window dimensions: 192x129 mm Aspect: 1.48837
1562009-12-06 20:04:11.516 VDPAU: Version 0
1572009-12-06 20:04:11.516 VDPAU: Information NVIDIA VDPAU Driver Shared Library 190.42 Tue Oct 20 21:20:26 PDT 2009
1582009-12-06 20:04:11.569 Display Rect left: 30, top: 0, width: 660, height: 480, aspect: 1.48837
1592009-12-06 20:04:11.569 Video Rect left: 0, top: 0, width: 720, height: 576, aspect: 1.36364
1602009-12-06 20:04:11.569 VidOutVDPAU: Created VDPAU context (GPU decode)
1612009-12-06 20:04:11.576 VDPAU: Created OSD (720x480)
1622009-12-06 20:04:11.581 Over/underscan. V: 0, H: 0
1632009-12-06 20:04:11.581 Display Rect left: 30, top: 0, width: 660, height: 480, aspect: 1.48837
1642009-12-06 20:04:11.581 Video Rect left: 0, top: 0, width: 720, height: 576, aspect: 1.36364
1652009-12-06 20:04:11.581 VDP: LoadBestPreferences(720x576, 25)
1662009-12-06 20:04:11.581 NVP(0): Forcing decode extra audio option on (Video method requires it).
1672009-12-06 20:04:11.583 NVP(0): LoadFilters(''..) -> 0x0
1682009-12-06 20:04:11.585 OSD Theme Dimensions W: 1280 H: 720
1692009-12-06 20:04:11.779 NVP(0): ClearAfterSeek(1)
1702009-12-06 20:04:11.779 VidOutVDPAU: ClearAfterSeek()
1712009-12-06 20:04:11.779 VidOutVDPAU: DiscardFrames(0)
1722009-12-06 20:04:11.779 playCtx: StartDecoderThread(): took 593 ms to start player.
1732009-12-06 20:04:11.779 VideoBuffers::DiscardFrames(0): AAAAAAAAAAAAAAAAA
1742009-12-06 20:04:11.779 VideoBuffers::DiscardFrames(0): AAAAAAAAAAAAAAAAA -- done
1752009-12-06 20:04:11.779 VidOutVDPAU: DiscardFrames() 3: AAAAAAAAAAAAAAAAA -- done()
1762009-12-06 20:04:11.779 TV: StartPlayer(0, Watching WatchingPreRecorded, main) -- end ok
1772009-12-06 20:04:11.780 TV: Changing from None to Watching WatchingPreRecorded
1782009-12-06 20:04:11.780 New DB connection, total: 3
1792009-12-06 20:04:11.782 Connected to database 'mythconverg' at host: 192.168.1.1
1802009-12-06 20:04:11.784 Realtime priority would require SUID as root.
1812009-12-06 20:04:11.785 VDP: GetFilteredDeint() : vdpau -> 'none'
1822009-12-06 20:04:11.787 DRMVideoSync: Could not open device /dev/dri/card0, Nincs ilyen fájl vagy könyvtár
1832009-12-06 20:04:11.788 OpenGLVideoSync()
1842009-12-06 20:04:11.791 [h264_vdpau @ 0x7f9a198e69e0]mmco: unref short failure
1852009-12-06 20:04:11.825 TV: HandleStateChange(0) -- end
1862009-12-06 20:04:11.825 VDPAU: Created VDPAU decoder (4 ref frames)
1872009-12-06 20:04:11.826 Detect Letterbox: The source is not a supported frame format (was 11)
1882009-12-06 20:04:11.829 Forcing GLX version to 1.2 (orig 1.4)
1892009-12-06 20:04:11.830 GLCtx: Created OpenGL window.
1902009-12-06 20:04:11.830 GLCtx: Created GLX context.
1912009-12-06 20:04:11.830 GLCtx: GLX Version: 1.2
1922009-12-06 20:04:11.831 GLCtx: Direct rendering: Yes
1932009-12-06 20:04:11.846 ScreenSaverX11Private: ResetTimer -- begin
1942009-12-06 20:04:11.846 ScreenSaverX11Private: StopTimer
1952009-12-06 20:04:11.858 ScreenSaverX11Private: StartTimer
1962009-12-06 20:04:11.858 ScreenSaverX11Private: ResetTimer -- end
1972009-12-06 20:04:11.860 [h264_vdpau @ 0x7f9a198e69e0]mmco: unref short failure
1982009-12-06 20:04:11.876 GLCtx: OpenGL vendor : NVIDIA Corporation
1992009-12-06 20:04:11.876 GLCtx: OpenGL renderer: GeForce 8200/PCI/SSE2
2002009-12-06 20:04:11.876 GLCtx: OpenGL version : 3.2.0 NVIDIA 190.42
2012009-12-06 20:04:11.876 GLCtx: Max texture size: 8192 x 8192
2022009-12-06 20:04:11.876 GLCtx: Max texture units: 4
2032009-12-06 20:04:11.898 Using video as timebase
2042009-12-06 20:04:11.898 Video timing method: SGI OpenGL
2052009-12-06 20:04:11.898 Refresh rate: 16666, frame interval: 40000
2062009-12-06 20:04:11.942 AO: dropping back audio_buffer_unused
2072009-12-06 20:04:11.965 NVP(0): Video is 3.89843 frames behind audio (too slow), dropping frame to catch up.
2082009-12-06 20:04:11.965 NVP(0): Video is 4.88005 frames behind audio (too slow), dropping frame to catch up.
2092009-12-06 20:04:11.965 NVP(0): Video is 5.36627 frames behind audio (too slow), dropping frame to catch up.
2102009-12-06 20:04:11.965 NVP(0): Video is 5.48095 frames behind audio (too slow), dropping frame to catch up.
2112009-12-06 20:04:11.966 NVP(0): Video is 5.31695 frames behind audio (too slow), dropping frame to catch up.
2122009-12-06 20:04:11.966 NVP(0): Video is 4.9502 frames behind audio (too slow), dropping frame to catch up.
2132009-12-06 20:04:11.966 NVP(0): Video is 4.42515 frames behind audio (too slow), dropping frame to catch up.
2142009-12-06 20:04:11.966 NVP(0): Video is 3.78135 frames behind audio (too slow), dropping frame to catch up.
2152009-12-06 20:04:11.984 AO: dropping back audio_buffer_unused
2162009-12-06 20:04:12.040 AO: dropping back audio_buffer_unused
2172009-12-06 20:04:12.097 AO: dropping back audio_buffer_unused
2182009-12-06 20:04:12.127 AO: dropping back audio_buffer_unused
2192009-12-06 20:04:12.158 AO: dropping back audio_buffer_unused
2202009-12-06 20:04:12.189 AO: dropping back audio_buffer_unused
2212009-12-06 20:04:12.220 AO: dropping back audio_buffer_unused
2222009-12-06 20:04:12.225 AO: dropping back audio_buffer_unused
2232009-12-06 20:04:12.256 AO: dropping back audio_buffer_unused
2242009-12-06 20:04:12.286 AO: dropping back audio_buffer_unused
2252009-12-06 20:04:12.316 VDPAU: Using 4 output surfaces (max 4)
2262009-12-06 20:04:12.317 AO: dropping back audio_buffer_unused
2272009-12-06 20:04:12.348 AO: dropping back audio_buffer_unused
2282009-12-06 20:04:12.379 AO: dropping back audio_buffer_unused
229'video_output' mean = '40321,69', std. dev. = '18781,16', fps = '24,80'
230'video_output' mean = '43164,07', std. dev. = '13838,58', fps = '23,17'
231'video_output' mean = '44164,37', std. dev. = '14657,71', fps = '22,64'
2322009-12-06 20:04:28.847 NVP(0): 400 interlaced frames seen.
233'video_output' mean = '43164,43', std. dev. = '13428,63', fps = '23,17'
2342009-12-06 20:04:31.032 TV: DrawUnusedRects() -- begin
2352009-12-06 20:04:31.032 TV: DrawUnusedRects() -- end
236'video_output' mean = '44330,92', std. dev. = '15092,74', fps = '22,56'
2372009-12-06 20:04:35.274 TV: DoNVPSeek() -- begin
2382009-12-06 20:04:35.274 TV: DoNVPSeek() -- ff
2392009-12-06 20:04:35.274 TV: DoNVPSeek() -- end
2402009-12-06 20:04:35.274 UpdateOSDSeekMessage(Skip Ahead, 2)
2412009-12-06 20:04:35.337 VidOutVDPAU: UpdatePauseFrame() LUUAuUAUUuULUUuUU
2422009-12-06 20:04:35.340 AFD: DoFastForward(1291 (555), do discard frames)
2432009-12-06 20:04:35.340 Dec: DoFastForward(1291 (555), do discard frames)
2442009-12-06 20:04:35.340 Dec: FindPosition(1291, search not adjusted) -->
245 [57:1283(12775164),58:1315(13132552)]
2462009-12-06 20:04:35.341 AFD: SeekReset(1283, 8, do flush, do discard)
2472009-12-06 20:04:35.341 AFD: SeekReset() flushing
2482009-12-06 20:04:35.341 VidOutVDPAU: DiscardFrames(1)
2492009-12-06 20:04:35.341 VideoBuffers::DiscardFrames(1): AUUAUUAUUUUAUUUUU
2502009-12-06 20:04:35.341 VideoBuffers::DiscardFrames(): AAAAAAAAAAAAAAAAA -- done()
2512009-12-06 20:04:35.341 VideoBuffers::DiscardFrames(1): AAAAAAAAAAAAAAAAA -- done
2522009-12-06 20:04:35.342 VidOutVDPAU: DiscardFrames() 3: AAAAAAAAAAAAAAAAA -- done()
2532009-12-06 20:04:35.357 [h264_vdpau @ 0x7f9a198e69e0]number of reference frames exceeds max (probably corrupt input), discarding one
2542009-12-06 20:04:35.357 [h264_vdpau @ 0x7f9a198e69e0]number of reference frames exceeds max (probably corrupt input), discarding one
2552009-12-06 20:04:35.357 [h264_vdpau @ 0x7f9a198e69e0]number of reference frames exceeds max (probably corrupt input), discarding one
2562009-12-06 20:04:35.357 [h264_vdpau @ 0x7f9a198e69e0]number of reference frames exceeds max (probably corrupt input), discarding one
2572009-12-06 20:04:35.357 [h264_vdpau @ 0x7f9a198e69e0]mmco: unref short failure
2582009-12-06 20:04:35.400 [h264_vdpau @ 0x7f9a198e69e0]mmco: unref short failure
2592009-12-06 20:04:35.405 NVP(0): ClearAfterSeek(0)
2602009-12-06 20:04:35.414 NVP(0): Waiting for prebuffer.. 0 ALAALAAaaAAAAAAaA
2612009-12-06 20:04:35.647 NVP(0): Video is 3.54485 frames ahead of audio,
262 doubling video frame interval to slow down.
2632009-12-06 20:04:35.697 NVP(0): Video is 3.90862 frames ahead of audio,
264 doubling video frame interval to slow down.
2652009-12-06 20:04:35.797 NVP(0): Video is 4.3752 frames ahead of audio,
266 doubling video frame interval to slow down.
2672009-12-06 20:04:35.847 NVP(0): Video is 4.35015 frames ahead of audio,
268 doubling video frame interval to slow down.
2692009-12-06 20:04:35.897 NVP(0): Video is 4.2751 frames ahead of audio,
270 doubling video frame interval to slow down.
2712009-12-06 20:04:35.964 NVP(0): Video is 4.15632 frames ahead of audio,
272 doubling video frame interval to slow down.
2732009-12-06 20:04:36.014 NVP(0): Video is 3.86722 frames ahead of audio,
274 doubling video frame interval to slow down.
2752009-12-06 20:04:36.081 NVP(0): Video is 3.59415 frames ahead of audio,
276 doubling video frame interval to slow down.
2772009-12-06 20:04:36.131 NVP(0): Video is 3.22685 frames ahead of audio,
278 doubling video frame interval to slow down.
2792009-12-06 20:04:36.214 NVP(0): Video is 3.13888 frames ahead of audio,
280 doubling video frame interval to slow down.
281'video_output' mean = '46331,75', std. dev. = '22082,59', fps = '21,58'
2822009-12-06 20:04:38.831 TV: DoNVPSeek() -- begin
2832009-12-06 20:04:38.831 TV: DoNVPSeek() -- ff
2842009-12-06 20:04:38.831 TV: DoNVPSeek() -- end
2852009-12-06 20:04:38.831 UpdateOSDSeekMessage(Skip Ahead, 2)
2862009-12-06 20:04:38.920 VidOutVDPAU: UpdatePauseFrame() UAULUUUuAUUUUUUuL
2872009-12-06 20:04:38.922 AFD: DoFastForward(2117 (1381), do discard frames)
2882009-12-06 20:04:38.922 Dec: DoFastForward(2117 (1381), do discard frames)
2892009-12-06 20:04:38.922 Dec: FindPosition(2117, search not adjusted) -->
290 [94:2097(20929476),95:2121(21170116)]
2912009-12-06 20:04:38.924 AFD: SeekReset(2097, 20, do flush, do discard)
2922009-12-06 20:04:38.924 AFD: SeekReset() flushing
2932009-12-06 20:04:38.924 VidOutVDPAU: DiscardFrames(1)
2942009-12-06 20:04:38.924 VideoBuffers::DiscardFrames(1): UAUAUUUUAUUUUUUUA
2952009-12-06 20:04:38.924 VideoBuffers::DiscardFrames(): AAAAAAAAAAAAAAAAA -- done()
2962009-12-06 20:04:38.924 VideoBuffers::DiscardFrames(1): AAAAAAAAAAAAAAAAA -- done
2972009-12-06 20:04:38.924 VidOutVDPAU: DiscardFrames() 3: AAAAAAAAAAAAAAAAA -- done()
2982009-12-06 20:04:38.943 [h264_vdpau @ 0x7f9a198e69e0]number of reference frames exceeds max (probably corrupt input), discarding one
2992009-12-06 20:04:38.943 [h264_vdpau @ 0x7f9a198e69e0]number of reference frames exceeds max (probably corrupt input), discarding one
3002009-12-06 20:04:38.944 [h264_vdpau @ 0x7f9a198e69e0]number of reference frames exceeds max (probably corrupt input), discarding one
3012009-12-06 20:04:38.944 [h264_vdpau @ 0x7f9a198e69e0]number of reference frames exceeds max (probably corrupt input), discarding one
3022009-12-06 20:04:38.944 [h264_vdpau @ 0x7f9a198e69e0]mmco: unref short failure
3032009-12-06 20:04:38.975 [h264_vdpau @ 0x7f9a198e69e0]mmco: unref short failure
3042009-12-06 20:04:39.050 NVP(0): ClearAfterSeek(0)
3052009-12-06 20:04:39.064 NVP(0): Waiting for prebuffer.. 0 ALAAAAaAAAAAALAAA
3062009-12-06 20:04:42.589 TV: DoNVPSeek() -- begin
3072009-12-06 20:04:42.589 TV: DoNVPSeek() -- ff
3082009-12-06 20:04:42.589 TV: DoNVPSeek() -- end
3092009-12-06 20:04:42.589 UpdateOSDSeekMessage(Skip Ahead, 2)
3102009-12-06 20:04:42.654 VidOutVDPAU: UpdatePauseFrame() ULUuUUuAUULUUuUAU
3112009-12-06 20:04:42.655 AFD: DoFastForward(2947 (2211), do discard frames)
3122009-12-06 20:04:42.655 Dec: DoFastForward(2947 (2211), do discard frames)
3132009-12-06 20:04:42.655 Dec: FindPosition(2947, search not adjusted) -->
314 [130:2935(29198656),131:2952(29376316)]
3152009-12-06 20:04:42.657 AFD: SeekReset(2935, 12, do flush, do discard)
3162009-12-06 20:04:42.657 AFD: SeekReset() flushing
3172009-12-06 20:04:42.657 VidOutVDPAU: DiscardFrames(1)
3182009-12-06 20:04:42.657 VideoBuffers::DiscardFrames(1): UAUUUUUAUUAUUUUAU
3192009-12-06 20:04:42.657 VideoBuffers::DiscardFrames(): AAAAAAAAAAAAAAAAA -- done()
3202009-12-06 20:04:42.657 VideoBuffers::DiscardFrames(1): AAAAAAAAAAAAAAAAA -- done
3212009-12-06 20:04:42.657 VidOutVDPAU: DiscardFrames() 3: AAAAAAAAAAAAAAAAA -- done()
3222009-12-06 20:04:42.780 NVP(0): ClearAfterSeek(0)
3232009-12-06 20:04:42.797 NVP(0): Waiting for prebuffer.. 0 LAAaAAALAALAAAAAA
324'video_output' mean = '47665,06', std. dev. = '31708,27', fps = '20,98'
3252009-12-06 20:04:46.663 NVP(0): 800 interlaced frames seen.
326'video_output' mean = '39829,32', std. dev. = '8523,31', fps = '25,11'
327'video_output' mean = '39997,81', std. dev. = '8217,26', fps = '25,00'
328'video_output' mean = '39998,26', std. dev. = '8217,94', fps = '25,00'
329'video_output' mean = '39997,46', std. dev. = '8218,18', fps = '25,00'
3302009-12-06 20:05:01.872 ScreenSaverX11Private: Calling gnome-screensaver-command --poke
3312009-12-06 20:05:02.663 NVP(0): 1200 interlaced frames seen.
332'video_output' mean = '39997,76', std. dev. = '8210,21', fps = '25,00'
333'video_output' mean = '39998,00', std. dev. = '8264,64', fps = '25,00'
334'video_output' mean = '39997,43', std. dev. = '8311,34', fps = '25,00'
335'video_output' mean = '39998,02', std. dev. = '8209,00', fps = '25,00'
3362009-12-06 20:05:18.662 NVP(0): 1600 interlaced frames seen.
337'video_output' mean = '39997,83', std. dev. = '8208,00', fps = '25,00'
338'video_output' mean = '39998,32', std. dev. = '8199,97', fps = '25,00'
339'video_output' mean = '39997,61', std. dev. = '8127,62', fps = '25,00'
340'video_output' mean = '39997,59', std. dev. = '8088,51', fps = '25,00'
3412009-12-06 20:05:34.662 NVP(0): 2000 interlaced frames seen.
342'video_output' mean = '39997,86', std. dev. = '8202,05', fps = '25,00'
343'video_output' mean = '39830,94', std. dev. = '8165,32', fps = '25,11'
3442009-12-06 20:05:41.119 TV: DrawUnusedRects() -- begin
3452009-12-06 20:05:41.119 TV: DrawUnusedRects() -- end
3462009-12-06 20:05:42.588 TV: SetActive(0,w/o OSD) 0 -> 0 -- begin
3472009-12-06 20:05:42.588 TV: SetActive(0,w/o OSD) 0 -> 0 -- end
3482009-12-06 20:05:42.628 TV: HandleStateChange(0) -- begin
3492009-12-06 20:05:42.628 TV: Attempting to change from Watching WatchingPreRecorded to None
3502009-12-06 20:05:42.628 TV: StopStuff() for player ctx 0 -- begin
3512009-12-06 20:05:42.628 TV: SetActive(0,w/o OSD) 0 -> 0 -- begin
3522009-12-06 20:05:42.628 TV: SetActive(0,w/o OSD) 0 -> 0 -- end
3532009-12-06 20:05:42.628 TV: StopStuff(): stopping ring buffer
3542009-12-06 20:05:42.633 NVP(0): Exited decoder loop.
3552009-12-06 20:05:42.651 TV: StopStuff(): stopping player
3562009-12-06 20:05:42.651 TV: StopStuff() -- end
3572009-12-06 20:05:42.652 TV: Changing from Watching WatchingPreRecorded to None
3582009-12-06 20:05:42.652 TV: HandleStateChange(0) -- end
3592009-12-06 20:05:42.652 TV: StartTV -- process events end
3602009-12-06 20:05:42.652 TV: StartTV -- process events 2 begin
3612009-12-06 20:05:42.652 ScreenSaverX11Private: StopTimer
3622009-12-06 20:05:42.652 TV: StartTV -- process events 2 end
3632009-12-06 20:05:42.655 TV::~TV() -- begin
3642009-12-06 20:05:42.662 ~OpenGLVideoSync() -- closing opengl vsync
3652009-12-06 20:05:42.662 GLCtx: Deleting OpenGL Resources
3662009-12-06 20:05:42.663 GLCtx: Unmapping gl window
3672009-12-06 20:05:42.663 GLCtx: Destroying gl window
3682009-12-06 20:05:42.663 GLCtx: Destroying glx context
3692009-12-06 20:05:42.682 GLCtx: Closing display
3702009-12-06 20:05:42.682 VidOutVDPAU: DiscardFrames(1)
3712009-12-06 20:05:42.682 VideoBuffers::DiscardFrames(1): UUAuULuUUUUuALULU
3722009-12-06 20:05:42.682 VideoBuffers::DiscardFrames(): AAAAAAAAAAAAAAAAA -- done()
3732009-12-06 20:05:42.682 VideoBuffers::DiscardFrames(1): AAAAAAAAAAAAAAAAA -- done
3742009-12-06 20:05:42.683 VidOutVDPAU: DiscardFrames() 3: AAAAAAAAAAAAAAAAA -- done()
3752009-12-06 20:05:42.707 TV::~TV() -- lock
3762009-12-06 20:05:42.907 TV::~TV() -- end
3772009-12-06 20:05:42.907 TV: StartTV -- end
3782009-12-06 20:05:45.898 AudioPulseUtil: Resume Success
3792009-12-06 20:05:45.898 Deleting UPnP client...