Live TV crash for unknown reason (ringbuffer concerned)

[trankkilou@…]

While wathing live tv, the frontend crash for unknown reason. It occurs each time average 6 sec after an hour or half an hour. No problem with disk space or permissions right.

It display at screen "unknown error while displaying video". Make back and tv again works but it's very annoying. I have install lastest version from ATrpms with yum.

[root@jujubox ~]# mythbackend --version Library API version: 0.20.20060828-3 Source code version: Unknown Options compiled in:

linux release using_xvmcw using_lmsensors using_v4l using_oss using_alsa using_arts using_jack using_ivtv using_firewire using_dbox2 using_hdhr using_ip_rec using_freebox using_live using_lirc using_joystick_menu using_dvb using_x11 using_xv using_xrandr using_xvmc using_xvmc_vld using_frontend using_backend

ok now here the log of the backend: 2006-10-31 15:59:59.952 NVP: progressive frame seen after 6 interlaced frames 2006-10-31 16:00:00.030 Disabled deinterlacing 2006-10-31 16:00:00.109 NVP: interlaced frame seen after 4 progressive frames 2006-10-31 16:00:00.412 NVP: progressive frame seen after 7 interlaced frames 2006-10-31 16:00:00.472 Disabled deinterlacing 2006-10-31 16:00:00.752 NVP: interlaced frame seen after 9 progressive frames 2006-10-31 16:00:00.896 LiveTVChain(live-jujubox-2006-10-31T15:36:56): ReloadAll?(): Added new recording 2006-10-31 16:00:00.896 Resyncing position map. posmapStarted = 0 livetv(1) watchingRec(0) 2006-10-31 16:00:00.992 Position map filled from DB to: 33843 2006-10-31 16:00:00.992 SyncPositionMap? watchingrecording, from DB: 1466 entries 2006-10-31 16:00:00.992 SyncPositionMap? watchingrecording no entries from encoder, try DB 2006-10-31 16:00:00.999 Position map filled from DB to: 33843 2006-10-31 16:00:00.999 SyncPositionMap? watchingrecording total: 1466 entries 2006-10-31 16:00:01.079 LiveTVChain(live-jujubox-2006-10-31T15:36:56): SwitchTo?(1) 2006-10-31 16:00:01.080 LiveTVChain(live-jujubox-2006-10-31T15:36:56): Entry@1: '1506_20061031160000' 2006-10-31 16:00:01.080 NVP: IsReallyNearEnd?() br(1899KB) fps(25) sz(0KB) vfl(8) frh(0) ne:1 2006-10-31 16:00:01.080 SwitchToProgram?(void) 2006-10-31 16:00:01.088 RingBuf?(/buffre/1506_20061031153658.mpg): OpenFile?(myth://192.168.1.20:6543/1506_20061031160000.mpg, 10) 2006-10-31 16:00:01.349 NVP: prebuffering pause 2006-10-31 16:00:01.349 NVP: Waiting for prebuffer.. 0 AAAAAAAAAAuAALAAAAAAAAAAAAAAAAA 2006-10-31 16:00:01.512 NVP: Waiting for prebuffer.. 1 AAAAAAAAAAuAALAAAAAAAAAAAAAAAAA 2006-10-31 16:00:01.675 NVP: Waiting for prebuffer.. 2 AAAAAAAAAAuAALAAAAAAAAAAAAAAAAA 2006-10-31 16:00:01.840 NVP: Waiting for prebuffer.. 3 AAAAAAAAAAuAALAAAAAAAAAAAAAAAAA 2006-10-31 16:00:02.003 NVP: Waiting for prebuffer.. 4 AAAAAAAAAAuAALAAAAAAAAAAAAAAAAA 2006-10-31 16:00:02.168 NVP: Waiting for prebuffer.. 5 AAAAAAAAAAuAALAAAAAAAAAAAAAAAAA 2006-10-31 16:00:02.332 NVP: Waiting for prebuffer.. 6 AAAAAAAAAAuAALAAAAAAAAAAAAAAAAA 2006-10-31 16:00:02.480 LiveTVChain(live-jujubox-2006-10-31T15:36:56): ReloadAll?(): Added new recording 2006-10-31 16:00:02.496 NVP: Waiting for prebuffer.. 7 AAAAAAAAAAuAALAAAAAAAAAAAAAAAAA 2006-10-31 16:00:02.659 NVP: Waiting for prebuffer.. 8 AAAAAAAAAAuAALAAAAAAAAAAAAAAAAA 2006-10-31 16:00:02.823 NVP: Waiting for prebuffer.. 9 AAAAAAAAAAuAALAAAAAAAAAAAAAAAAA 2006-10-31 16:00:02.987 NVP: Prebuffer wait timed out 10 times. 2006-10-31 16:00:02.988 NVP: Waiting for prebuffer.. 0 AAAAAAAAAAuAALAAAAAAAAAAAAAAAAA 2006-10-31 16:00:03.151 NVP: Waiting for prebuffer.. 1 AAAAAAAAAAuAALAAAAAAAAAAAAAAAAA 2006-10-31 16:00:03.315 NVP: Waiting for prebuffer.. 2 AAAAAAAAAAuAALAAAAAAAAAAAAAAAAA 2006-10-31 16:00:03.479 NVP: Waiting for prebuffer.. 3 AAAAAAAAAAuAALAAAAAAAAAAAAAAAAA 2006-10-31 16:00:03.648 NVP: Waiting for prebuffer.. 4 AAAAAAAAAAuAALAAAAAAAAAAAAAAAAA 2006-10-31 16:00:03.815 NVP: Waiting for prebuffer.. 5 AAAAAAAAAAuAALAAAAAAAAAAAAAAAAA 2006-10-31 16:00:03.983 NVP: Waiting for prebuffer.. 6 AAAAAAAAAAuAALAAAAAAAAAAAAAAAAA 2006-10-31 16:00:04.151 NVP: Waiting for prebuffer.. 7 AAAAAAAAAAuAALAAAAAAAAAAAAAAAAA 2006-10-31 16:00:04.319 NVP: Waiting for prebuffer.. 8 AAAAAAAAAAuAALAAAAAAAAAAAAAAAAA 2006-10-31 16:00:04.487 NVP: Waiting for prebuffer.. 9 AAAAAAAAAAuAALAAAAAAAAAAAAAAAAA 2006-10-31 16:00:04.655 NVP: Prebuffer wait timed out 10 times. 2006-10-31 16:00:04.656 NVP: Waiting for prebuffer.. 0 ... 2006-10-31 16:00:06.331 NVP: Prebuffer wait timed out 10 times. 2006-10-31 16:00:06.331 NVP: Waiting for prebuffer.. 0 AAAAAAAAAAuAALAAAAAAAAAAAAAAAAA 2006-10-31 16:00:06.499 NVP: Waiting for prebuffer.. 1 AAAAAAAAAAuAALAAAAAAAAAAAAAAAAA 2006-10-31 16:00:06.591 RingBuf?(/buffre/1506_20061031160000.mpg): Invalid file (fd -1) when opening '/buffre/1506_20061031160000.mpg'. 2006-10-31 16:00:06.592 RingBuf?(/buffre/1506_20061031160000.mpg): CalcReadAheadThresh?(4000 KB)

-> threshhold(146 KB) min read(32 KB) blk size(64 KB)

2006-10-31 16:00:06.592 NVP, Error: SwitchToProgram?'s OpenFile? failed. 2006-10-31 16:00:06.592 NVP, Error: Unknown error, exiting decoder 2006-10-31 16:00:06.592 NVP: Exited decoder loop. 2006-10-31 16:00:06.592 TV: Attempting to change from WatchingLiveTV to None 2006-10-31 16:00:06.609 TV: StopStuff?() -- begin 2006-10-31 16:00:06.609 TV: StopStuff?(): stopping ring buffer[s] 2006-10-31 16:00:06.609 TV: StopStuff?(): stopping player[s] (1/2) 2006-10-31 16:00:06.609 TV: StopStuff?(): stopping recorder[s] 2006-10-31 16:00:06.675 VideoOutputXv?: dtor 2006-10-31 16:00:06.676 VideoOutputXv?: DiscardFrames?(1) 2006-10-31 16:00:06.676 VideoBuffers::DiscardFrames?(1): AAAAAAAAAAuAALAAAAAAAAAAAAAAAAA 2006-10-31 16:00:06.676 VideoBuffers::DiscardFrames?(): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done() 2006-10-31 16:00:06.676 VideoBuffers::DiscardFrames?(1): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done 2006-10-31 16:00:06.676 VideoOutputXv?: DiscardFrames?() 3: AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done() 2006-10-31 16:00:06.676 VideoOutputXv?: DiscardFrames?(1) 2006-10-31 16:00:06.676 VideoBuffers::DiscardFrames?(1): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA 2006-10-31 16:00:06.676 VideoBuffers::DiscardFrames?(): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done() 2006-10-31 16:00:06.676 VideoBuffers::DiscardFrames?(1): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done 2006-10-31 16:00:06.676 VideoOutputXv?: DiscardFrames?() 3: AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done() 2006-10-31 16:00:06.677 VideoOutputXv?: Closing XVideo port 274 2006-10-31 16:00:07.065 TV: StopStuff?(): stopping player[s] (2/2)

Now the log of the frontend 2006-10-31 15:59:59.548 DVBRec(0): 12 PID filters open. 2006-10-31 16:00:00.476 Writing PAT & PMT @530249676 + 883600 2006-10-31 16:00:00.716 TVRec(1): SwitchLiveTVRingBuffer(discont 0, set_rec 1) 2006-10-31 16:00:00.720 TVRec(1): GetProgramRingBufferForLiveTV() 2006-10-31 16:00:00.773 TVRec(1): StartedRecording?(0x2aaab4000cb0) fn(/buffre/1506_2006103116000 0.mpg) 2006-10-31 16:00:00.781 MythSocket?(887d00:-1): writeStringList: Error, called with unconnected s ocket. 2006-10-31 16:00:00.850 TVRec(1): FinishedRecording?(Unknown) in recgroup: LiveTV 2006-10-31 16:00:00.868 Chain: Updated endtime for '1506_20061031153658' to 20061031160000 2006-10-31 16:00:00.879 MythSocket?(887d00:-1): writeStringList: Error, called with unconnected s ocket. 2006-10-31 16:00:00.881 Finished recording Unknown: channel 1506 2006-10-31 16:00:00.888 Preview: 'myth://192.168.1.20:6543/1506_20061031153658.mpg' is not local ,

replacing with '/buffre/1506_20061031153658.mpg', which is local.

2006-10-31 16:00:00.895 Chain: Appended@2 '1506_20061031160000' 2006-10-31 16:00:00.981 MythSocket?(887d00:-1): writeStringList: Error, called with unconnected s ocket. 2006-10-31 16:00:00.981 DTVRec(1): SetNextRecord?(0x2aaab4000cb0, 0x2aaab402bc50) 2006-10-31 16:00:01.082 MythSocket?(887d00:-1): writeStringList: Error, called with unconnected s ocket. 2006-10-31 16:00:01.389 MythSocket?(887d00:-1): writeStringList: Error, called with unconnected s ocket. 2006-10-31 16:00:01.388 TVRec(1): SetFlags?(RingBufferReady?,) -> FrontendReady?,RunMainLoop?,Cancel NextRecording?,AskAllowRecording?,RecorderRunning?,RingBufferReady?, 2006-10-31 16:00:01.392 TVRec(1): !has_rec(1) !rec_soon(1) curRec(0x8e2e80) starttm(2006-10-31T1 5:36:58) 2006-10-31 16:00:01.392 TVRec(1): Enabling Full LiveTV UI. 2006-10-31 16:00:01.393 MythSocket?(887d00:-1): writeStringList: Error, called with unconnected s ocket. 2006-10-31 16:00:01.456 Writing PAT & PMT @530612704 + 777568 2006-10-31 16:00:01.640 DVBRec(0): 12 PID filters open. 0: start_time: 964.285 duration: 124.373 1: start_time: 964.238 duration: 124.364 2: start_time: 964.238 duration: 124.420 stream: start_time: 10713.753 duration: 1382.450 bitrate=3069 kb/s 2006-10-31 16:00:01.836 AFD: Opened codec 0x982e50, id(MPEG2VIDEO) type(Video) 2006-10-31 16:00:01.855 AFD: Opened codec 0x983490, id(MP3) type(Audio) 2006-10-31 16:00:01.856 AFD: Opened codec 0x99f270, id(DVB_SUBTITLE) type(Subtitle) [mpeg2video @ 0x3335edb050]ac-tex damaged at 2 24 [mpeg2video @ 0x3335edb050]mb incr damaged [mpeg2video @ 0x3335edb050]ac-tex damaged at 17 26 [mpeg2video @ 0x3335edb050]invalid cbp at 33 27 [mpeg2video @ 0x3335edb050]slice mismatch [mpeg2video @ 0x3335edb050]ac-tex damaged at 0 29 [mpeg2video @ 0x3335edb050]invalid cbp at 1 30 [mpeg2video @ 0x3335edb050]slice mismatch [mpeg2video @ 0x3335edb050]mb incr damaged [mpeg2video @ 0x3335edb050]invalid cbp at 30 33 [mpeg2video @ 0x3335edb050]ac-tex damaged at 0 34 [mpeg2video @ 0x3335edb050]ac-tex damaged at 0 35 2006-10-31 16:00:02.297 DTVRec(1): ResetForNewFile?(void) 2006-10-31 16:00:02.395 TVRec(1): SwitchLiveTVRingBuffer(discont 0, set_rec 1) 2006-10-31 16:00:02.423 RecBase?(0): SetRingBuffer?(0x2aaab402bc50) '/buffre/1506_20061031160000.m pg' 2006-10-31 16:00:02.431 TVRec(1): GetProgramRingBufferForLiveTV() 2006-10-31 16:00:02.432 TVRec(1): RingBufferChanged?() 2006-10-31 16:00:02.444 TVRec(1): StartedRecording?(0x2aaab4014200) fn(/buffre/1506_2006103116000 2.mpg) 2006-10-31 16:00:02.454 MythSocket?(887d00:-1): writeStringList: Error, called with unconnected s ocket. 2006-10-31 16:00:02.454 TVRec(1): FinishedRecording?(Unknown) in recgroup: LiveTV 2006-10-31 16:00:02.460 Chain: Updated endtime for '1506_20061031160000' to 20061031160002 2006-10-31 16:00:02.464 MythSocket?(887d00:-1): writeStringList: Error, called with unconnected s ocket. 2006-10-31 16:00:02.466 Finished recording Unknown: channel 1506 2006-10-31 16:00:02.472 Preview: 'myth://192.168.1.20:6543/1506_20061031160000.mpg' is not local ,

replacing with '/buffre/1506_20061031160000.mpg', which is local.

2006-10-31 16:00:02.475 Chain: Appended@3 '1506_20061031160002' 2006-10-31 16:00:02.476 MythSocket?(887d00:-1): writeStringList: Error, called with unconnected s ocket. 2006-10-31 16:00:02.476 DTVRec(1): SetNextRecord?(0x2aaab4014200, 0x2aaab42522c0) 2006-10-31 16:00:02.489 TVRec(1): SetFlags?(RingBufferReady?,) -> FrontendReady?,RunMainLoop?,Cancel NextRecording?,AskAllowRecording?,RecorderRunning?,RingBufferReady?, 2006-10-31 16:00:02.489 TVRec(1): !has_rec(1) !rec_soon(1) curRec(0x8e2e80) starttm(2006-10-31T1 5:36:58) 2006-10-31 16:00:02.496 TVRec(1): Enabling Full LiveTV UI. 2006-10-31 16:00:02.498 MythSocket?(887d00:-1): writeStringList: Error, called with unconnected s ocket. 2006-10-31 16:00:02.499 TVRec(1): FinishedRecording?(Unknown) in recgroup: LiveTV 2006-10-31 16:00:02.505 Chain: Updated endtime for '1506_20061031153658' to 20061031160002 2006-10-31 16:00:02.507 Finished recording Unknown: channel 1506 2006-10-31 16:00:02.507 MythSocket?(887d00:-1): writeStringList: Error, called with unconnected s ocket. 2006-10-31 16:00:02.477 Preview Error: Previewer file '/buffre/1506_20061031160000.mpg' is not v alid. 2006-10-31 16:00:03.069 DTVRec(1): ResetForNewFile?(void) 2006-10-31 16:00:03.073 RecBase?(0): SetRingBuffer?(0x2aaab42522c0) '/buffre/1506_20061031160002.m pg' 2006-10-31 16:00:03.074 TVRec(1): RingBufferChanged?() 2006-10-31 16:00:03.076 TVRec(1): FinishedRecording?(Unknown) in recgroup: LiveTV 2006-10-31 16:00:03.077 Chain: Updated endtime for '1506_20061031160000' to 20061031160003 2006-10-31 16:00:03.080 MythSocket?(887d00:-1): writeStringList: Error, called with unconnected s ocket. 2006-10-31 16:00:03.082 Finished recording Unknown: channel 1506 2006-10-31 16:00:03.715 Writing PAT & PMT @24628 + 1378416 2006-10-31 16:00:04.195 DVBRec(0): 12 PID filters open. 2006-10-31 16:00:04.771 Writing PAT & PMT @390664 + 141376 2006-10-31 16:00:05.611 Writing PAT & PMT @754820 + 141376 2006-10-31 16:00:06.620 StopLiveTV(void) curRec: 0x9832f0 pseudoRec: 0 2006-10-31 16:00:06.634 TVRec(1): Changing from WatchingLiveTV to None 2006-10-31 16:00:06.640 TVRec(1): ClearFlags?(FrontendReady?,CancelNextRecording?,) -> RunMainLoop?, AskAllowRecording?,RecorderRunning?,RingBufferReady?, 2006-10-31 16:00:06.640 TVRec(1): SetFlags?(AskAllowRecording?,) -> RunMainLoop?,AskAllowRecording?, RecorderRunning?,RingBufferReady?, 2006-10-31 16:00:06.641 TVRec(1): Request: Program(no) channel() input() flags(KillRec?,KillRingB uffer,) 2006-10-31 16:00:06.667 Writing PAT & PMT @1111644 + 812912 2006-10-31 16:00:06.671 MythSocket?(887d00:-1): writeStringList: Error, called with unconnected s ocket. 2006-10-31 16:00:06.680 DVBRec(0): Close() fd(15) -- begin 2006-10-31 16:00:06.947 DVBRec(0): Close() fd(-1) -- end 2006-10-31 16:00:07.019 TVRec(1): ClearFlags?(RecorderRunning?,) -> RunMainLoop?,AskAllowRecording?, RingBufferReady?, 2006-10-31 16:00:07.025 DVBRec(0): SetOutputPAT(NULL) 2006-10-31 16:00:07.025 DVBRec(0): SetOutputPMT(NULL) 2006-10-31 16:00:07.027 TVRec(1): FinishedRecording?(Unknown) in recgroup: LiveTV 2006-10-31 16:00:07.028 Chain: Updated endtime for '1506_20061031160002' to 20061031160007 2006-10-31 16:00:07.032 MythSocket?(887d00:-1): writeStringList: Error, called with unconnected s ocket. 2006-10-31 16:00:07.033 Finished recording Unknown: channel 1506 2006-10-31 16:00:07.049 TVRec(1): ClearFlags?(RecorderRunning?,) -> RunMainLoop?,AskAllowRecording?, RingBufferReady?, 2006-10-31 16:00:07.049 MythSocket?(887d00:-1): writeStringList: Error, called with unconnected s ocket. 2006-10-31 16:00:07.050 TVRec(1): Tearing down RingBuffer? 2006-10-31 16:00:07.064 TVRec(1): ClearFlags?(PENDINGACTIONS,) -> RunMainLoop?,AskAllowRecording?,R ingBufferReady

I hope it could help

[anonymous]

I thought I would add that I have also experienced this issue (many times), it seems to me to coincide with watching LiveTV when crossing from one TV program to another on the same channel. I have not attached my mythbackend log as it is effectively the same error, i.e. a file cannot be opened and returns -1, but on the file system, when I look after the error occurs in the front end, the file does exist (although it is 0 bytes in size).

I am using the latest rpm's from atrpms.net which have the accompanying changelog entry: "Sun Nov 5 11:00:00 2006 Axel Thimm - 0.20-144 - Update to latest svn fixes (11683)."

I also know that I have seen this behaviour in previous atrpms versions, although I cannot confirm for how long the bug has been present.

I am running the frontend and backend on the same hardware - AMD 3400+, Dvico Fusion HDTV Dual (mercurial version of v4l drivers).

I'll keep an eye on this ticket, if anyone would like further information or some gdb-based debugging, please let me know.

[danielk]

We need a backtrace, the TicketHowTo has a link to the relevant portion of the MythTV documentation. Please use MythTV from SVN head for the backtrace.

[trankkilou@…]

Ok I have a correct programm guide now and it still crash but less often. I ever happen between programm so it's not very annoying but if this bug could be resolve...