2007-11-23 11:40:28.685 TV: Attempting to change from None to WatchingPreRecorded
2007-11-23 11:40:28.685 RingBuf(/content/Video/Temporary/swear_jar_300k.wmv): OpenFile(/content/Video/Temporary/swear_jar_300k.wmv, 12)
2007-11-23 11:40:28.685 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:40:28.714 AFD: Stream #0, has id 0x1 codec id WMAV2, type Audio, bitrate 32048 at 0x0xacfc310
2007-11-23 11:40:28.714 AFD: Looking for decoder for WMAV2
2007-11-23 11:40:28.715 AFD: Opened codec 0xacfb0c0, id(WMAV2) type(Audio)
2007-11-23 11:40:28.716 AFD: Stream #1, has id 0x31 codec id WMV3, type Video, bitrate 274432 at 0x0xacf9e50
2007-11-23 11:40:28.718 VDP: Accepting: cmp(> 0 0) dec(ffmpeg) rend(xv-blit) osd(softblend) osdfade(enabled) deint(linearblend,linearblend) filt()
2007-11-23 11:40:28.718 VDP: LoadBestPreferences(2048x2048, 0)
2007-11-23 11:40:28.718 VDP: LoadBestPreferences(2048x2048, 60)
2007-11-23 11:40:28.718 VDP: LoadBestPreferences(400x300, 60)
2007-11-23 11:40:28.718 AFD: InitVideoCodec() 0xacf9780 id(WMV3) type (Video).
2007-11-23 11:40:28.718 detectInterlace(Detect Scan, Interlaced Scan, 29.97, 304) ->Interlaced Scan
2007-11-23 11:40:28.718 AFD: Using ffmpeg for video decoding
2007-11-23 11:40:28.718 AFD: Looking for decoder for WMV3
2007-11-23 11:40:28.718 AFD: Opened codec 0xacf9780, id(WMV3) type(Video)
2007-11-23 11:40:28.777 RingBuf(/content/Video/Temporary/swear_jar_300k.wmv): CalcReadAheadThresh(181879728 KB)
			 -> threshhold(64 KB) min read(0 KB) blk size(32 KB)
2007-11-23 11:40:28.779 Opening OSS audio device '/dev/dsp'.
2007-11-23 11:40:28.782 Dec: Trying to select track (w/lang)
2007-11-23 11:40:28.782 Dec: Selecting first track
2007-11-23 11:40:28.782 Dec: Selected track #1 in the Unknown language(0)
2007-11-23 11:40:28.782 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:28.785 SyncPositionMap prerecorded, from DB: 0 entries
2007-11-23 11:40:28.785 DPMS Deactivated 
2007-11-23 11:40:28.785 AFD: Recording has no position -- using libavformat seeking.
2007-11-23 11:40:28.785 AFD: Successfully opened decoder for file: "/content/Video/Temporary/swear_jar_300k.wmv". novideo(0)
2007-11-23 11:40:28.787 VideoOutput: Allowed renderers: ivtv,xv-blit,xshm,xlib
2007-11-23 11:40:28.787 VideoOutput: Allowed renderers (filt: ffmpeg): xlib,xshm,xv-blit
2007-11-23 11:40:28.788 VDP: Accepting: cmp(> 0 0) dec(ffmpeg) rend(xv-blit) osd(softblend) osdfade(enabled) deint(linearblend,linearblend) filt()
2007-11-23 11:40:28.788 VDP: LoadBestPreferences(2048x2048, 0)
2007-11-23 11:40:28.788 VDP: LoadBestPreferences(2048x2048, 60)
2007-11-23 11:40:28.788 VDP: LoadBestPreferences(400x304, 60)
2007-11-23 11:40:28.788 VideoOutput: Preferred renderer: xv-blit
2007-11-23 11:40:28.788 VideoOutput: Trying video renderer: xv-blit
2007-11-23 11:40:28.790 VDP: Accepting: cmp(> 0 0) dec(ffmpeg) rend(xv-blit) osd(softblend) osdfade(enabled) deint(linearblend,linearblend) filt()
2007-11-23 11:40:28.790 VDP: LoadBestPreferences(2048x2048, 0)
2007-11-23 11:40:28.790 VDP: LoadBestPreferences(2048x2048, 60)
2007-11-23 11:40:28.798 VideoOutputXv: ctor
2007-11-23 11:40:28.798 XOff: 0, YOff: 0
2007-11-23 11:40:28.798 VDP: LoadBestPreferences(400x304, 60)
2007-11-23 11:40:28.798 Display Rect  left: 0, top: 0, width: 800, height: 600, aspect: 1.33333
2007-11-23 11:40:28.798 Video Rect    left: 0, top: 0, width: 400, height: 304, aspect: 1.33333
2007-11-23 11:40:28.799 VideoOutputXv: Pixel dimensions: Screen 800x600, window 800x600
2007-11-23 11:40:28.799 VideoOutputXv: Estimated display dimensions: 271x203 mm  Aspect: 1.33498
2007-11-23 11:40:28.799 VideoOutputXv: Estimated window dimensions: 271x203 mm  Aspect: 1.33498
2007-11-23 11:40:28.799 VideoOutputXv: InitSetupBuffers() render: xv-blit, allowed: xv-blit,xshm,xlib
2007-11-23 11:40:28.801 VDP: Accepting: cmp(> 0 0) dec(ffmpeg) rend(xv-blit) osd(softblend) osdfade(enabled) deint(linearblend,linearblend) filt()
2007-11-23 11:40:28.801 VDP: LoadBestPreferences(2048x2048, 0)
2007-11-23 11:40:28.801 VDP: LoadBestPreferences(2048x2048, 60)
2007-11-23 11:40:28.801 VDP: LoadBestPreferences(400x304, 60)
2007-11-23 11:40:28.801 VideoOutputXv: @ j=0 Looking for flag[s]: XvInputMask XvImageMask  10
2007-11-23 11:40:28.801 VideoOutputXv: Adaptor#0: Intel(R) Textured Video has flag[s]: XvInputMask XvImageMask 
2007-11-23 11:40:28.801 VideoOutputXv: Has XVideo flags...
2007-11-23 11:40:28.801 VideoOutputXv: Has XV_BRIGHTNESS...
2007-11-23 11:40:28.801 VideoOutputXv: Here...
2007-11-23 11:40:28.802 VideoOutputXv: Grabbed xv port 73
2007-11-23 11:40:28.802 VideoOutputXv: XVideo surface found on port 73
2007-11-23 11:40:28.802 VideoOutputXv: XVideo Adaptor Name: 'Intel(R) Textured Video'
2007-11-23 11:40:28.802 VideoOutputXv: XVideo Format #0 is 'YUY2'
2007-11-23 11:40:28.802 VideoOutputXv: XVideo Format #1 is 'YV12'
2007-11-23 11:40:28.802 VideoOutputXv: XVideo Format #2 is 'I420'
2007-11-23 11:40:28.802 VideoOutputXv: XVideo Format #3 is 'UYVY'
2007-11-23 11:40:28.802 VideoOutputXv: XVideo Using ids: GUID_YV12_PLANAR
2007-11-23 11:40:28.802 VideoOutputXv: Using XVideo Format 'YV12'
2007-11-23 11:40:28.802 VideoOutputXv: CreateShmImages(32): video_dim: 400x304
2007-11-23 11:40:28.811 VDP: SetVideoRenderer(xv-blit)
2007-11-23 11:40:28.811 VDP: SetVideoRender(xv-blit) == GetVideoRenderer()
2007-11-23 11:40:28.812 VideoOutputXv: Chromakeying not possible with this XVideo port.
2007-11-23 11:40:28.812 Display Rect  left: 0, top: 0, width: 800, height: 600, aspect: 1.33333
2007-11-23 11:40:28.812 Video Rect    left: 0, top: 0, width: 400, height: 304, aspect: 1.33333
2007-11-23 11:40:28.813 Over/underscan. V: 0, H: 0
2007-11-23 11:40:28.813 Display Rect  left: 0, top: 0, width: 800, height: 600, aspect: 1.33333
2007-11-23 11:40:28.813 Video Rect    left: 0, top: 0, width: 400, height: 304, aspect: 1.33333
2007-11-23 11:40:28.813 VDP: LoadBestPreferences(400x304, 29.97)
2007-11-23 11:40:28.814 NVP: LoadFilters(''..) -> 0
2007-11-23 11:40:29.574 NVP: ClearAfterSeek(1)
2007-11-23 11:40:29.574 VideoOutputXv: ClearAfterSeek()
2007-11-23 11:40:29.574 VideoOutputXv: DiscardFrames(0)
2007-11-23 11:40:29.574 VideoBuffers::DiscardFrames(0): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
2007-11-23 11:40:29.574 VideoBuffers::DiscardFrames(0): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done
2007-11-23 11:40:29.574 VideoOutputXv: DiscardFrames() 3: AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done()
2007-11-23 11:40:29.575 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.575 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.575 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.575 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.575 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.575 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.575 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.575 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.575 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.575 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.575 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.575 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.575 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.575 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.575 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.575 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.575 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.576 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.576 Using realtime priority.
2007-11-23 11:40:29.576 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.575 TV: StartPlayer(): took 880 ms to start player.
2007-11-23 11:40:29.576 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.576 VDP: GetFilteredDeint() : xv-blit -> 'linearblend'
2007-11-23 11:40:29.576 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.576 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.576 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.576 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.576 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.576 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.576 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.576 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.576 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.576 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.576 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.576 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.576 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.576 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.576 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.576 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.576 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.576 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.577 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.577 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.577 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.577 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.577 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.577 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.577 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.577 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.577 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.577 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.577 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.577 Using deinterlace method linearblend
2007-11-23 11:40:29.577 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.577 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.577 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.577 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.577 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.576 TV: Changing from None to WatchingPreRecorded
2007-11-23 11:40:29.577 nVidiaVideoSync: Could not open device /dev/nvidia0, No such file or directory
2007-11-23 11:40:29.577 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.578 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.578 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.578 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.578 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.578 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.578 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.578 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.578 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.578 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.578 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.578 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.578 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.578 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.578 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.578 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.578 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.578 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.578 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.578 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.578 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.578 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.578 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.578 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.578 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.579 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.579 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.579 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.579 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.579 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.579 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.579 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.579 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.579 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.579 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.579 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.579 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.579 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.579 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.579 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.579 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.579 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.579 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.579 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.579 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.579 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.579 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.579 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.579 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.579 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.579 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.579 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.580 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.580 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.580 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.580 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.583 AFD: DoFastForward(119 (1), do discard frames)
2007-11-23 11:40:29.595 Using audio as timebase
2007-11-23 11:40:29.595 Video timing method: DRM
2007-11-23 11:40:29.595 Refresh rate: 16579, frame interval: 33366
2007-11-23 11:40:29.612 NVP: Waiting for prebuffer.. 0 uAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
2007-11-23 11:40:29.740 AFD: SeekReset(128720178, 0, do flush, do discard)
2007-11-23 11:40:29.740 AFD: SeekReset() flushing
2007-11-23 11:40:29.740 VideoOutputXv: DiscardFrames(1)
2007-11-23 11:40:29.740 VideoBuffers::DiscardFrames(1): uAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
2007-11-23 11:40:29.740 VideoBuffers::DiscardFrames(): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done()
2007-11-23 11:40:29.740 VideoBuffers::DiscardFrames(1): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done
2007-11-23 11:40:29.740 VideoOutputXv: DiscardFrames() 3: AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done()
2007-11-23 11:40:29.741 NVP: ClearAfterSeek(0)
2007-11-23 11:40:29.761 NVP: Waiting for prebuffer.. 1 AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
2007-11-23 11:40:29.795 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-11-23 11:40:29.795 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2007-11-23 11:40:29.795 AFD: HandleGopStart: Initial key frame distance: 15.
2007-11-23 11:40:29.827 NVP: progressive frame seen after 2 interlaced  frames
2007-11-23 11:40:29.879 Disabled deinterlacing
'video_output' mean = '33980.53', std. dev. = '3632.36', fps = '29.43'
'video_output' mean = '33323.31', std. dev. = '1657.40', fps = '30.01'