2008-03-16 18:26:22.866 user: 1001 effective user: 1001 before privileged thread
2008-03-16 18:26:22.866 user: 1001 effective user: 1001 after privileged thread
2008-03-16 18:26:22.866 user: 1001 effective user: 1001 run_priv_thread
2008-03-16 18:26:22.868 New DB connection, total: 2
2008-03-16 18:26:22.869 Connected to database 'mythconverg' at host: 192.168.1.200
2008-03-16 18:26:22.872 mythfrontend version: 0.22.20080313-2 www.mythtv.org
2008-03-16 18:26:22.872 Enabled verbose msgs:  important general playback audio
2008-03-16 18:26:23.381 Connecting to lcd server: localhost:6545 (try 1 of 10)
2008-03-16 18:26:23.628 max_width: 1280 max_height: 720
2008-03-16 18:26:23.749 Total desktop dim: 1280x720, with 1 screen[s].
2008-03-16 18:26:23.750 Using screen 0, 1280x720 at 0,0
2008-03-16 18:26:23.751 Switching to wide mode (ProjectGrayhem-wide)
2008-03-16 18:26:23.764 Using the OpenGL painter
2008-03-16 18:26:23.766 JoystickMenuClient Error: Joystick disabled - Failed to read /home/mythtv/.mythtv/joystickmenurc
2008-03-16 18:26:23.766 lirc init success using configuration file: /home/mythtv/.mythtv/lircrc
2008-03-16 18:26:23.915 Specified base font 'medium' does not exist for font clock
2008-03-16 18:26:23.915 Specified base font 'medium' does not exist for font small
2008-03-16 18:26:23.915 Specified base font 'medium' does not exist for font medium
2008-03-16 18:26:23.916 Specified base font 'medium' does not exist for font large
2008-03-16 18:26:23.917 Loading from: /usr/local/share/mythtv/themes/ProjectGrayhem-wide/base.xml
2008-03-16 18:26:23.937 Loading from: /usr/local/share/mythtv/themes/default/base.xml
2008-03-16 18:26:24.006 Key F2 is bound to multiple actions in context TV Playback.
2008-03-16 18:26:24.006 Key F3 is bound to multiple actions in context TV Playback.
2008-03-16 18:26:24.020 Registering Internal as a media playback plugin.
2008-03-16 18:26:24.080 MonitorRegisterExtensions(0x100, gif,jpg,png)
2008-03-16 18:26:24.125 Using NV NPOT texture extension
2008-03-16 18:26:24.172 MythMusic adding CD-Writer: 0,0,0 -- DVDRW SHW-160P6S
2008-03-16 18:26:24.172 MythMusic adding CD-Writer: 2,0,0 -- FUJITSU MHV2080B
2008-03-16 18:26:24.225 MonitorRegisterExtensions(0x40, ogg,mp3,aac,flac)
2008-03-16 18:26:29.930 XMLParse::LoadTheme using /usr/local/share/mythtv/themes/ProjectGrayhem-wide/ui.xml
2008-03-16 18:26:30.196 Connecting to backend server: 192.168.1.200:6543 (try 1 of 5)
2008-03-16 18:26:30.197 Using protocol version 40
2008-03-16 18:26:31.367 RingBuf(/mythtv/recordings/area2/4401_20080316133000.mpg): OpenFile(/mythtv/recordings/area2/4401_20080316133000.mpg, 1)
2008-03-16 18:26:31.411 RingBuf(/mythtv/recordings/area2/4401_20080316133000.mpg): CalcReadAheadThresh(3075348032 KB)
			 -> threshhold(64 KB) min read(0 KB) blk size(32 KB)
2008-03-16 18:26:31.575 AFD: Stream #0, has id 0x2045 codec id MPEG2VIDEO, type Video, bitrate 80000000 at 0x0x82c84a0
2008-03-16 18:26:31.579 VDP: Accepting: cmp(>= 1920 1080) dec(ffmpeg) cpus(2) rend(xv-blit) osd(softblend) osdfade(enabled) deint(yadifdeint,linearblend) filt()
2008-03-16 18:26:31.579 VDP: Accepting: cmp(> 0 0) dec(ffmpeg) cpus(1) rend(xv-blit) osd(softblend) osdfade(enabled) deint(yadifdoubleprocessdeint,yadifdeint) filt()
2008-03-16 18:26:31.579 VDP: Accepting: cmp(>= 1920 1080) dec(ffmpeg) cpus(2) rend(quartz-blit) osd(softblend) osdfade(enabled) deint(linearblend,linearblend) filt()
2008-03-16 18:26:31.579 VDP: Accepting: cmp(> 0 0) dec(ffmpeg) cpus(1) rend(quartz-blit) osd(softblend) osdfade(enabled) deint(yadifdoubleprocessdeint,yadifdeint) filt()
2008-03-16 18:26:31.579 VDP: LoadBestPreferences(2048x2048, 0)
2008-03-16 18:26:31.580 VDP: LoadBestPreferences(2048x2048, 60)
2008-03-16 18:26:31.580 VDP: LoadBestPreferences(1280x720, 60)
2008-03-16 18:26:31.580 Using 1 CPUs for decoding
2008-03-16 18:26:31.580 AFD: InitVideoCodec() 0x82cb170 id(MPEG2VIDEO) type (Video).
2008-03-16 18:26:31.580 detectInterlace(Detect Scan, Interlaced Scan, 59.9401, 720) ->Progressive Scan
2008-03-16 18:26:31.580 AFD: Using ffmpeg for video decoding
2008-03-16 18:26:31.580 AFD: Looking for decoder for MPEG2VIDEO
2008-03-16 18:26:31.580 AFD: Opened codec 0x82cb170, id(MPEG2VIDEO) type(Video)
2008-03-16 18:26:31.580 AFD: Stream #1, has id 0x2044 codec id AC3, type Audio, bitrate 448000 at 0x0x82cd2b0
2008-03-16 18:26:31.580 AFD: codec AC3 has 6 channels
2008-03-16 18:26:31.580 AFD: Looking for decoder for AC3
2008-03-16 18:26:31.581 AFD: Opened codec 0x830cf90, id(AC3) type(Audio)
2008-03-16 18:26:31.581 AFD: Audio Track #1 is A/V stream #1 and has 6 channels in the English language(6647399).
2008-03-16 18:26:31.581 AFD: Stream #2, has id 0x2043 codec id AC3, type Audio, bitrate 192000 at 0x0x82d0200
2008-03-16 18:26:31.581 AFD: codec AC3 has 1 channels
2008-03-16 18:26:31.581 AFD: Looking for decoder for AC3
2008-03-16 18:26:31.582 AFD: Opened codec 0x82ca550, id(AC3) type(Audio)
2008-03-16 18:26:31.582 AFD: Audio Track #2 is A/V stream #2 and has 1 channels in the Spanish; Castilian language(7565409).
2008-03-16 18:26:31.582 AFD: Stream #3, has id 0x1638 codec id AC3, type Audio, bitrate 96000 at 0x0x82d1a90
2008-03-16 18:26:31.582 AFD: codec AC3 has 1 channels
2008-03-16 18:26:31.582 AFD: Looking for decoder for AC3
2008-03-16 18:26:31.583 AFD: Opened codec 0x830b160, id(AC3) type(Audio)
2008-03-16 18:26:31.583 AFD: Audio Track #3 is A/V stream #3 and has 1 channels in the French language(6713957).
2008-03-16 18:26:31.583 RingBuf(/mythtv/recordings/area2/4401_20080316133000.mpg): CalcReadAheadThresh(138465120 KB)
			 -> threshhold(64 KB) min read(0 KB) blk size(32 KB)
2008-03-16 18:26:31.583 AFD: Trying to select audio track (w/lang)
2008-03-16 18:26:31.583 AFD: Selected track 1: English AC3 5.1ch (A/V Stream #1)
2008-03-16 18:26:31.583 AFD: Initializing audio parms from audio track #1
2008-03-16 18:26:31.583 AFD: Audio format changed digital passthrough id( AC3) 48000Hz  2ch  16bps pt
			from id(NONE)    -1Hz -1ch   0bps    ; id(NONE)    -1Hz -1ch   0bps   
			to   id( AC3) 48000Hz  6ch  16bps pt ; id( AC3) 48000Hz  2ch  16bps pt
2008-03-16 18:26:31.583 Dec: Trying to select track (w/lang)
2008-03-16 18:26:31.584 Dec: Selecting first track
2008-03-16 18:26:31.584 Dec: Selected track #1 in the Unknown language(0)
2008-03-16 18:26:31.584 AFD: Recording has no position -- using libavformat seeking.
2008-03-16 18:26:31.584 AFD: Successfully opened decoder for file: "/mythtv/recordings/area2/4401_20080316133000.mpg". novideo(0)
2008-03-16 18:26:31.586 VDP: Accepting: cmp(>= 1920 1080) dec(ffmpeg) cpus(2) rend(xv-blit) osd(softblend) osdfade(enabled) deint(yadifdeint,linearblend) filt()
2008-03-16 18:26:31.586 VDP: Accepting: cmp(> 0 0) dec(ffmpeg) cpus(1) rend(xv-blit) osd(softblend) osdfade(enabled) deint(yadifdoubleprocessdeint,yadifdeint) filt()
2008-03-16 18:26:31.586 VDP: Accepting: cmp(>= 1920 1080) dec(ffmpeg) cpus(2) rend(quartz-blit) osd(softblend) osdfade(enabled) deint(linearblend,linearblend) filt()
2008-03-16 18:26:31.586 VDP: Accepting: cmp(> 0 0) dec(ffmpeg) cpus(1) rend(quartz-blit) osd(softblend) osdfade(enabled) deint(yadifdoubleprocessdeint,yadifdeint) filt()
2008-03-16 18:26:31.586 VDP: LoadBestPreferences(2048x2048, 0)
2008-03-16 18:26:31.587 VDP: LoadBestPreferences(2048x2048, 60)
2008-03-16 18:26:31.598 VideoOutputNull()
2008-03-16 18:26:31.598 VDP: LoadBestPreferences(1280x720, 60)
2008-03-16 18:26:31.599 Display Rect  left: 0, top: 0, width: 0, height: 0, aspect: 1.33333
2008-03-16 18:26:31.599 Video Rect    left: 0, top: 0, width: 1280, height: 720, aspect: 1.77778
2008-03-16 18:26:31.599 Created data @0xad8ab020->0xad9fc822
2008-03-16 18:26:31.599 Created data @0xad759020->0xad8aa822
2008-03-16 18:26:31.599 Created data @0xad607020->0xad758822
2008-03-16 18:26:31.599 Created data @0xad4b5020->0xad606822
2008-03-16 18:26:31.599 Created data @0xad363020->0xad4b4822
2008-03-16 18:26:31.599 Created data @0xad211020->0xad362822
2008-03-16 18:26:31.599 Created data @0xad0bf020->0xad210822
2008-03-16 18:26:31.599 Created data @0xacf6d020->0xad0be822
2008-03-16 18:26:31.599 Created data @0xace1b020->0xacf6c822
2008-03-16 18:26:31.599 Created data @0xaccc9020->0xace1a822
2008-03-16 18:26:31.599 Created data @0xacb77020->0xaccc8822
2008-03-16 18:26:31.599 Created data @0xaca25020->0xacb76822
2008-03-16 18:26:31.599 Created data @0xac8d3020->0xaca24822
2008-03-16 18:26:31.599 Created data @0xac781020->0xac8d2822
2008-03-16 18:26:31.600 Created data @0xac62f020->0xac780822
2008-03-16 18:26:31.600 Created data @0xac4dd020->0xac62e822
2008-03-16 18:26:31.600 Created data @0xac38b020->0xac4dc822
2008-03-16 18:26:31.600 Created data @0xac239020->0xac38a822
2008-03-16 18:26:31.600 Created data @0xac0e7020->0xac238822
2008-03-16 18:26:31.600 Created data @0xabf95020->0xac0e6822
2008-03-16 18:26:31.600 Created data @0xabe43020->0xabf94822
2008-03-16 18:26:31.600 Created data @0xabcf1020->0xabe42822
2008-03-16 18:26:31.600 Created data @0xabb9f020->0xabcf0822
2008-03-16 18:26:31.600 Created data @0xaba4d020->0xabb9e822
2008-03-16 18:26:31.600 Created data @0xab8fb020->0xaba4c822
2008-03-16 18:26:31.600 Created data @0xab7a9020->0xab8fa822
2008-03-16 18:26:31.600 Created data @0xab657020->0xab7a8822
2008-03-16 18:26:31.600 Created data @0xab505020->0xab656822
2008-03-16 18:26:31.600 Created data @0xab3b3020->0xab504822
2008-03-16 18:26:31.600 Created data @0xab261020->0xab3b2822
2008-03-16 18:26:31.600 Created data @0xab10f020->0xab260822
2008-03-16 18:26:31.600 Created data @0xaafbd020->0xab10e822
2008-03-16 18:26:31.646 VDP: SetVideoRenderer(null)
2008-03-16 18:26:31.646 VDP: Old preferences: rend(xv-blit) osd(softblend) deint(yadifdoubleprocessdeint,yadifdeint) filt()
2008-03-16 18:26:31.646 VDP: New preferences: rend(null) osd(softblend) deint(yadifdoubleprocessdeint,yadifdeint) filt()
2008-03-16 18:26:31.646 Display Rect  left: 0, top: 0, width: 0, height: 0, aspect: 1.33333
2008-03-16 18:26:31.646 Video Rect    left: 0, top: 0, width: 1280, height: 720, aspect: 1.77778
2008-03-16 18:26:31.647 NVP: LoadFilters(''..) -> 0
2008-03-16 18:26:31.648 NVP: ClearAfterSeek(1)
2008-03-16 18:26:31.649 NVP: Waiting for prebuffer.. 0 AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
2008-03-16 18:26:31.714 AFD: HandleGopStart: gopset not set, syncing positionMap
2008-03-16 18:26:31.714 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
2008-03-16 18:26:31.714 AFD: HandleGopStart: Initial key frame distance: 15.
2008-03-16 18:26:31.719 NVP: progressive frame seen after 2 interlaced  frames
2008-03-16 18:26:31.735 Disabled deinterlacing
2008-03-16 18:26:31.794 NVP: Exited decoder loop.
2008-03-16 18:26:31.794 TV: Attempting to change from None to WatchingRecording
2008-03-16 18:26:31.797 RingBuf(myth://192.168.1.200:6543/4401_20080316133000.mpg): OpenFile(myth://192.168.1.200:6543/4401_20080316133000.mpg, 12)
2008-03-16 18:26:31.800 ~VideoOutputNull()
2008-03-16 18:26:31.806 RingBuf(myth://192.168.1.200:6543/4401_20080316133000.mpg): CalcReadAheadThresh(3066837920 KB)
			 -> threshhold(64 KB) min read(0 KB) blk size(32 KB)
2008-03-16 18:26:31.807 Using protocol version 40
2008-03-16 18:26:31.859 AFD: Stream #0, has id 0x2045 codec id MPEG2VIDEO, type Video, bitrate 80000000 at 0x0x8599480
2008-03-16 18:26:31.861 VDP: Accepting: cmp(>= 1920 1080) dec(ffmpeg) cpus(2) rend(xv-blit) osd(softblend) osdfade(enabled) deint(yadifdeint,linearblend) filt()
2008-03-16 18:26:31.862 VDP: Accepting: cmp(> 0 0) dec(ffmpeg) cpus(1) rend(xv-blit) osd(softblend) osdfade(enabled) deint(yadifdoubleprocessdeint,yadifdeint) filt()
2008-03-16 18:26:31.862 VDP: Accepting: cmp(>= 1920 1080) dec(ffmpeg) cpus(2) rend(quartz-blit) osd(softblend) osdfade(enabled) deint(linearblend,linearblend) filt()
2008-03-16 18:26:31.862 VDP: Accepting: cmp(> 0 0) dec(ffmpeg) cpus(1) rend(quartz-blit) osd(softblend) osdfade(enabled) deint(yadifdoubleprocessdeint,yadifdeint) filt()
2008-03-16 18:26:31.862 VDP: LoadBestPreferences(2048x2048, 0)
2008-03-16 18:26:31.862 VDP: LoadBestPreferences(2048x2048, 60)
2008-03-16 18:26:31.862 VDP: LoadBestPreferences(1280x720, 60)
2008-03-16 18:26:31.862 Using 1 CPUs for decoding
2008-03-16 18:26:31.864 VDP: Accepting: cmp(>= 1920 1080) dec(ffmpeg) cpus(2) rend(xv-blit) osd(softblend) osdfade(enabled) deint(yadifdeint,linearblend) filt()
2008-03-16 18:26:31.865 VDP: Accepting: cmp(> 0 0) dec(ffmpeg) cpus(1) rend(xv-blit) osd(softblend) osdfade(enabled) deint(yadifdoubleprocessdeint,yadifdeint) filt()
2008-03-16 18:26:31.865 VDP: Accepting: cmp(>= 1920 1080) dec(ffmpeg) cpus(2) rend(quartz-blit) osd(softblend) osdfade(enabled) deint(linearblend,linearblend) filt()
2008-03-16 18:26:31.865 VDP: Accepting: cmp(> 0 0) dec(ffmpeg) cpus(1) rend(quartz-blit) osd(softblend) osdfade(enabled) deint(yadifdoubleprocessdeint,yadifdeint) filt()
2008-03-16 18:26:31.865 VDP: LoadBestPreferences(2048x2048, 0)
2008-03-16 18:26:31.865 VDP: LoadBestPreferences(2048x2048, 60)
2008-03-16 18:26:31.865 VDP: LoadBestPreferences(1280x720, 60)
2008-03-16 18:26:31.865 AFD: InitVideoCodec() 0x8599580 id(MPEG2VIDEO) type (Video).
2008-03-16 18:26:31.865 detectInterlace(Detect Scan, Interlaced Scan, 59.9401, 720) ->Progressive Scan
2008-03-16 18:26:31.865 AFD: Using ffmpeg for video decoding
2008-03-16 18:26:31.866 AFD: Looking for decoder for MPEG2VIDEO
2008-03-16 18:26:31.866 AFD: Opened codec 0x8599580, id(MPEG2VIDEO) type(Video)
2008-03-16 18:26:31.866 AFD: Stream #1, has id 0x2044 codec id AC3, type Audio, bitrate 448000 at 0x0x8599ac0
2008-03-16 18:26:31.866 AFD: codec AC3 has 6 channels
2008-03-16 18:26:31.866 AFD: Looking for decoder for AC3
2008-03-16 18:26:31.866 AFD: Opened codec 0x8599bc0, id(AC3) type(Audio)
2008-03-16 18:26:31.866 AFD: Audio Track #1 is A/V stream #1 and has 6 channels in the English language(6647399).
2008-03-16 18:26:31.867 AFD: Stream #2, has id 0x2043 codec id AC3, type Audio, bitrate 192000 at 0x0x859a100
2008-03-16 18:26:31.867 AFD: codec AC3 has 1 channels
2008-03-16 18:26:31.867 AFD: Looking for decoder for AC3
2008-03-16 18:26:31.867 AFD: Opened codec 0x859a200, id(AC3) type(Audio)
2008-03-16 18:26:31.868 AFD: Audio Track #2 is A/V stream #2 and has 1 channels in the Spanish; Castilian language(7565409).
2008-03-16 18:26:31.868 AFD: Stream #3, has id 0x1638 codec id AC3, type Audio, bitrate 96000 at 0x0x859a740
2008-03-16 18:26:31.868 AFD: codec AC3 has 1 channels
2008-03-16 18:26:31.868 AFD: Looking for decoder for AC3
2008-03-16 18:26:31.868 AFD: Opened codec 0x859a840, id(AC3) type(Audio)
2008-03-16 18:26:31.868 AFD: Audio Track #3 is A/V stream #3 and has 1 channels in the French language(6713957).
2008-03-16 18:26:31.869 RingBuf(myth://192.168.1.200:6543/4401_20080316133000.mpg): CalcReadAheadThresh(140251048 KB)
			 -> threshhold(64 KB) min read(0 KB) blk size(32 KB)
2008-03-16 18:26:31.869 AFD: Trying to select audio track (w/lang)
2008-03-16 18:26:31.869 AFD: Selected track 1: English AC3 5.1ch (A/V Stream #1)
2008-03-16 18:26:31.869 AFD: Initializing audio parms from audio track #1
2008-03-16 18:26:31.869 AFD: Audio format changed digital passthrough id( AC3) 48000Hz  2ch  16bps pt
			from id(NONE)    -1Hz -1ch   0bps    ; id(NONE)    -1Hz -1ch   0bps   
			to   id( AC3) 48000Hz  6ch  16bps pt ; id( AC3) 48000Hz  2ch  16bps pt
2008-03-16 18:26:31.873 AO: Killing AudioOutputDSP
2008-03-16 18:26:31.873 Opening audio device 'default'. ch 2(2) sr 48000
2008-03-16 18:26:31.873 Opening ALSA audio device 'default'.
2008-03-16 18:26:31.896 DPMS Deactivated 
2008-03-16 18:26:31.977 in SetParameters(format=2, channels=2, rate=48000, buffer_time=500000, period_time=125000)
2008-03-16 18:26:31.978 get_buffer_size returned 16384
2008-03-16 18:26:31.978 set_period_time_near returned 21333
2008-03-16 18:26:31.978 get_period_size returned 1024
2008-03-16 18:26:31.978 AO: Audio fragment size: 6144
2008-03-16 18:26:31.979 AO: Audio Stretch Factor: 1
2008-03-16 18:26:31.979 Audio Codec Used: not set
2008-03-16 18:26:31.980 AO: Ending reconfigure
2008-03-16 18:26:31.980 AO: Killing AudioOutputDSP
2008-03-16 18:26:31.980 AO: kickoffOutputAudioLoop: pid = 5386
2008-03-16 18:26:31.980 AO: OutputAudioLoop: Stop Event
2008-03-16 18:26:31.980 AO: kickoffOutputAudioLoop exiting
2008-03-16 18:26:32.057 Opening audio device 'default'. ch 2(2) sr 48000
2008-03-16 18:26:32.057 Opening ALSA audio device 'default'.
2008-03-16 18:26:32.157 in SetParameters(format=2, channels=2, rate=48000, buffer_time=500000, period_time=125000)
2008-03-16 18:26:32.158 get_buffer_size returned 16384
2008-03-16 18:26:32.158 set_period_time_near returned 21333
2008-03-16 18:26:32.158 get_period_size returned 1024
2008-03-16 18:26:32.158 AO: Audio fragment size: 6144
2008-03-16 18:26:32.158 AO: Audio Stretch Factor: 1
2008-03-16 18:26:32.158 Audio Codec Used: AC3
2008-03-16 18:26:32.159 AO: Ending reconfigure
2008-03-16 18:26:32.159 Dec: Trying to select track (w/lang)
2008-03-16 18:26:32.159 Dec: Selecting first track
2008-03-16 18:26:32.159 Dec: Selected track #1 in the Unknown language(0)
2008-03-16 18:26:32.159 Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(1)
2008-03-16 18:26:32.159 AO: kickoffOutputAudioLoop: pid = 5386
2008-03-16 18:26:32.159 AO: OutputAudioLoop: Play Event
2008-03-16 18:26:32.162 SyncPositionMap watchingrecording, from DB: 0 entries
2008-03-16 18:26:32.162 Filling position map from 0 to 1067907
2008-03-16 18:26:51.819 TV: StartPlayer(): took 20000 ms to start player.
2008-03-16 18:26:51.819 TV Error: StartPlayer(): NVP is not playing after 20000 msec
2008-03-16 18:26:51.819 TV: Changing from None to WatchingRecording
2008-03-16 18:26:51.823 TV Error: nvp->IsPlaying() timed out
2008-03-16 18:26:51.823 TV: Attempting to change from WatchingRecording to None
2008-03-16 18:26:51.823 TV: StopStuff() -- begin
2008-03-16 18:26:51.823 TV: StopStuff(): stopping ring buffer[s]
2008-03-16 18:26:51.843 TV: StopStuff(): stopping player[s] (1/2)
2008-03-16 18:26:51.843 TV: StopStuff(): stopping player[s] (2/2)