2007-11-23 11:32:42.774 TV: Attempting to change from None to WatchingPreRecorded
2007-11-23 11:32:42.774 RingBuf(/content/Video/Temporary/swear_jar_300k.wmv): OpenFile(/content/Video/Temporary/swear_jar_300k.wmv, 12)
2007-11-23 11:32:42.774 RingBuf(/content/Video/Temporary/swear_jar_300k.wmv): CalcReadAheadThresh(9420020 KB)
			 -> threshhold(64 KB) min read(0 KB) blk size(32 KB)
2007-11-23 11:32:42.804 AFD: Stream #0, has id 0x1 codec id WMAV2, type Audio, bitrate 32048 at 0x0xaa740b0
2007-11-23 11:32:42.804 AFD: Looking for decoder for WMAV2
2007-11-23 11:32:42.805 AFD: Opened codec 0xaa743a0, id(WMAV2) type(Audio)
2007-11-23 11:32:42.805 AFD: Stream #1, has id 0x31 codec id WMV3, type Video, bitrate 274432 at 0x0xaa741b0
2007-11-23 11:32:42.807 VDP: Accepting: cmp(> 0 0) dec(ffmpeg) rend(xv-blit) osd(softblend) osdfade(enabled) deint(linearblend,linearblend) filt()
2007-11-23 11:32:42.807 VDP: LoadBestPreferences(2048x2048, 0)
2007-11-23 11:32:42.808 VDP: LoadBestPreferences(2048x2048, 60)
2007-11-23 11:32:42.808 VDP: LoadBestPreferences(400x300, 60)
2007-11-23 11:32:42.808 AFD: InitVideoCodec() 0xaa739e0 id(WMV3) type (Video).
2007-11-23 11:32:42.808 detectInterlace(Detect Scan, Interlaced Scan, 29.97, 304) ->Interlaced Scan
2007-11-23 11:32:42.808 AFD: Using ffmpeg for video decoding
2007-11-23 11:32:42.808 AFD: Looking for decoder for WMV3
2007-11-23 11:32:42.808 AFD: Opened codec 0xaa739e0, id(WMV3) type(Video)
2007-11-23 11:32:42.867 RingBuf(/content/Video/Temporary/swear_jar_300k.wmv): CalcReadAheadThresh(179225280 KB)
			 -> threshhold(64 KB) min read(0 KB) blk size(32 KB)
2007-11-23 11:32:42.868 Opening OSS audio device '/dev/dsp'.
2007-11-23 11:32:42.872 Dec: Trying to select track (w/lang)
2007-11-23 11:32:42.872 Dec: Selecting first track
2007-11-23 11:32:42.872 Dec: Selected track #1 in the Unknown language(0)
2007-11-23 11:32:42.872 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:42.874 DPMS Deactivated 
2007-11-23 11:32:42.875 SyncPositionMap prerecorded, from DB: 0 entries
2007-11-23 11:32:42.875 AFD: Recording has no position -- using libavformat seeking.
2007-11-23 11:32:42.875 AFD: Successfully opened decoder for file: "/content/Video/Temporary/swear_jar_300k.wmv". novideo(0)
2007-11-23 11:32:42.876 VideoOutput: Allowed renderers: ivtv,xv-blit,xshm,xlib
2007-11-23 11:32:42.877 VideoOutput: Allowed renderers (filt: ffmpeg): xlib,xshm,xv-blit
2007-11-23 11:32:42.878 VDP: Accepting: cmp(> 0 0) dec(ffmpeg) rend(xv-blit) osd(softblend) osdfade(enabled) deint(linearblend,linearblend) filt()
2007-11-23 11:32:42.878 VDP: LoadBestPreferences(2048x2048, 0)
2007-11-23 11:32:42.878 VDP: LoadBestPreferences(2048x2048, 60)
2007-11-23 11:32:42.878 VDP: LoadBestPreferences(400x304, 60)
2007-11-23 11:32:42.878 VideoOutput: Preferred renderer: xv-blit
2007-11-23 11:32:42.878 VideoOutput: Trying video renderer: xv-blit
2007-11-23 11:32:42.879 VDP: Accepting: cmp(> 0 0) dec(ffmpeg) rend(xv-blit) osd(softblend) osdfade(enabled) deint(linearblend,linearblend) filt()
2007-11-23 11:32:42.879 VDP: LoadBestPreferences(2048x2048, 0)
2007-11-23 11:32:42.880 VDP: LoadBestPreferences(2048x2048, 60)
2007-11-23 11:32:42.888 VideoOutputXv: ctor
2007-11-23 11:32:42.888 XOff: 0, YOff: 0
2007-11-23 11:32:42.888 VDP: LoadBestPreferences(400x304, 60)
2007-11-23 11:32:42.888 Display Rect  left: 0, top: 0, width: 800, height: 600, aspect: 1.33333
2007-11-23 11:32:42.888 Video Rect    left: 0, top: 0, width: 400, height: 304, aspect: 1.33333
2007-11-23 11:32:42.889 VideoOutputXv: Pixel dimensions: Screen 800x600, window 800x600
2007-11-23 11:32:42.889 VideoOutputXv: Estimated display dimensions: 271x203 mm  Aspect: 1.33498
2007-11-23 11:32:42.889 VideoOutputXv: Estimated window dimensions: 271x203 mm  Aspect: 1.33498
2007-11-23 11:32:42.889 VideoOutputXv: InitSetupBuffers() render: xv-blit, allowed: xv-blit,xshm,xlib
2007-11-23 11:32:42.891 VDP: Accepting: cmp(> 0 0) dec(ffmpeg) rend(xv-blit) osd(softblend) osdfade(enabled) deint(linearblend,linearblend) filt()
2007-11-23 11:32:42.891 VDP: LoadBestPreferences(2048x2048, 0)
2007-11-23 11:32:42.891 VDP: LoadBestPreferences(2048x2048, 60)
2007-11-23 11:32:42.891 VDP: LoadBestPreferences(400x304, 60)
2007-11-23 11:32:42.891 VideoOutputXv: @ j=0 Looking for flag[s]: XvInputMask XvImageMask  10
2007-11-23 11:32:42.891 VideoOutputXv: Adaptor#0: Intel(R) Textured Video has flag[s]: XvInputMask XvImageMask 
2007-11-23 11:32:42.891 VideoOutputXv: Has XVideo flags...
2007-11-23 11:32:42.891 VideoOutputXv: Has XV_BRIGHTNESS...
2007-11-23 11:32:42.891 VideoOutputXv: Here...
2007-11-23 11:32:42.892 VideoOutputXv: Grabbed xv port 73
2007-11-23 11:32:42.892 VideoOutputXv: XVideo surface found on port 73
2007-11-23 11:32:42.892 VideoOutputXv: XVideo Adaptor Name: 'Intel(R) Textured Video'
2007-11-23 11:32:42.892 VideoOutputXv: XVideo Format #0 is 'YUY2'
2007-11-23 11:32:42.892 VideoOutputXv: XVideo Format #1 is 'YV12'
2007-11-23 11:32:42.892 VideoOutputXv: XVideo Format #2 is 'I420'
2007-11-23 11:32:42.892 VideoOutputXv: XVideo Format #3 is 'UYVY'
2007-11-23 11:32:42.892 VideoOutputXv: XVideo Using ids: GUID_I420_PLANAR
2007-11-23 11:32:42.892 VideoOutputXv: Using XVideo Format 'I420'
2007-11-23 11:32:42.892 VideoOutputXv: CreateShmImages(32): video_dim: 400x304
2007-11-23 11:32:42.902 VDP: SetVideoRenderer(xv-blit)
2007-11-23 11:32:42.902 VDP: SetVideoRender(xv-blit) == GetVideoRenderer()
2007-11-23 11:32:42.902 VideoOutputXv: Chromakeying not possible with this XVideo port.
2007-11-23 11:32:42.902 Display Rect  left: 0, top: 0, width: 800, height: 600, aspect: 1.33333
2007-11-23 11:32:42.902 Video Rect    left: 0, top: 0, width: 400, height: 304, aspect: 1.33333
2007-11-23 11:32:42.903 Over/underscan. V: 0, H: 0
2007-11-23 11:32:42.903 Display Rect  left: 0, top: 0, width: 800, height: 600, aspect: 1.33333
2007-11-23 11:32:42.903 Video Rect    left: 0, top: 0, width: 400, height: 304, aspect: 1.33333
2007-11-23 11:32:42.903 VDP: LoadBestPreferences(400x304, 29.97)
2007-11-23 11:32:42.904 NVP: LoadFilters(''..) -> 0
2007-11-23 11:32:43.669 NVP: ClearAfterSeek(1)
2007-11-23 11:32:43.669 VideoOutputXv: ClearAfterSeek()
2007-11-23 11:32:43.669 VideoOutputXv: DiscardFrames(0)
2007-11-23 11:32:43.669 TV: StartPlayer(): took 884 ms to start player.
2007-11-23 11:32:43.669 VideoBuffers::DiscardFrames(0): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
2007-11-23 11:32:43.670 TV: Changing from None to WatchingPreRecorded
2007-11-23 11:32:43.670 VideoBuffers::DiscardFrames(0): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done
2007-11-23 11:32:43.670 VideoOutputXv: DiscardFrames() 3: AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done()
2007-11-23 11:32:43.671 VDP: GetFilteredDeint() : xv-blit -> 'linearblend'
2007-11-23 11:32:43.671 Using realtime priority.
2007-11-23 11:32:43.670 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.671 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.671 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.671 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.671 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.671 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.671 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.671 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.671 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.671 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.671 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.671 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.671 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.671 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.672 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.672 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.672 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.672 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.672 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.672 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.672 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.672 Using deinterlace method linearblend
2007-11-23 11:32:43.672 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.672 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.672 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.672 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.672 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.672 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.672 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.672 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.672 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.672 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.672 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.672 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.672 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.672 nVidiaVideoSync: Could not open device /dev/nvidia0, No such file or directory
2007-11-23 11:32:43.672 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.672 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.672 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.673 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.673 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.673 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.673 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.673 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.673 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.673 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.673 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.673 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.673 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.673 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.673 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.673 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.673 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.673 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.673 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.673 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.673 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.673 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.673 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.673 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.673 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.673 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.673 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.673 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.673 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.673 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.674 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.674 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.674 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.674 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.674 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.674 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.674 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.674 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.674 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.674 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.674 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.674 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.674 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.674 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.674 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.674 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.674 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.674 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.674 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.674 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.674 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.674 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.674 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.674 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.674 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.674 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.674 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.675 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.675 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.675 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.675 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.675 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.675 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.675 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.675 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.675 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.675 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.675 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.675 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.675 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.675 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.675 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.675 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.675 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.675 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.675 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.678 AFD: DoFastForward(124 (1), do discard frames)
2007-11-23 11:32:43.689 Using audio as timebase
2007-11-23 11:32:43.689 Video timing method: DRM
2007-11-23 11:32:43.689 Refresh rate: 16579, frame interval: 33366
2007-11-23 11:32:43.706 NVP: Waiting for prebuffer.. 0 uAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
2007-11-23 11:32:43.830 AFD: SeekReset(128720178, 0, do flush, do discard)
2007-11-23 11:32:43.830 AFD: SeekReset() flushing
2007-11-23 11:32:43.830 VideoOutputXv: DiscardFrames(1)
2007-11-23 11:32:43.830 VideoBuffers::DiscardFrames(1): uAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
2007-11-23 11:32:43.830 VideoBuffers::DiscardFrames(): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done()
2007-11-23 11:32:43.830 VideoBuffers::DiscardFrames(1): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done
2007-11-23 11:32:43.830 VideoOutputXv: DiscardFrames() 3: AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done()
2007-11-23 11:32:43.830 NVP: ClearAfterSeek(0)
2007-11-23 11:32:43.855 NVP: Waiting for prebuffer.. 1 AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
2007-11-23 11:32:43.885 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:32:43.885 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:32:43.885 AFD: HandleGopStart: Initial key frame distance: 15.
2007-11-23 11:32:43.905 NVP: progressive frame seen after 2 interlaced  frames
2007-11-23 11:32:43.957 Disabled deinterlacing
'video_output' mean = '33814.66', std. dev. = '3268.12', fps = '29.57'