[mythtv-users] Multirecord: failed rec. brings down ongoing rec.

warpme warpme at o2.pl
Mon Nov 29 13:37:07 UTC 2010


Hi *

I'm looking for advice with finding root cause for sometime failed multirecordings on DVB-S (so far occurs only on one given mplex). BE/FE are 0.24-fixes 27020.

Scenario (details - see log below):
-DVBrec 5 is recording
-DVBrec 6 at 12:30 is starting rec. on the same mplex but different program
-few sec latter DVBrec6 failed, but also DVBrec5 wend down :-(  

What I see:
At 12:30:31.947 I see issue (DevRdB(/dev/dvb/adapter3/frontend0) Error: Poll giving up) which brings DVBrec6 down.
But what is 12:30:29.461 "TVRec(5): Deleting stale pending recording 6 'Turbo Kamera 7'" ?
It refers to running recording on DVBrec5 but with name on prog from failed DVBrec6.

Why this ?

 
--------------
2010-11-28 12:30:06.298 TVRec(6): Got good signal
2010-11-28 12:30:06.399 TVRec(6): TeardownSignalMonitor() -- begin
2010-11-28 12:30:06.406 DVBSM(/dev/dvb/adapter3/frontend0): Stop() -- begin
2010-11-28 12:30:06.432 SM(/dev/dvb/adapter3/frontend0)::Stop: begin
2010-11-28 12:30:06.400 Updating status for "Turbo Kamera 7" on cardid 6 (Tuning => Recording)
2010-11-28 12:30:06.402 DVBRec(5:/dev/dvb/adapter3/frontend0): PID 0x81 discontinuity detected
2010-11-28 12:30:06.473 DVBRec(5:/dev/dvb/adapter3/frontend0): PID 0x81 discontinuity detected
2010-11-28 12:30:06.487 DVBRec(5:/dev/dvb/adapter3/frontend0): PID 0x81 discontinuity detected
2010-11-28 12:30:06.510 DVBRec(5:/dev/dvb/adapter3/frontend0): PID 0x81 discontinuity detected
2010-11-28 12:30:06.533 DTVSM(/dev/dvb/adapter3/frontend0)::SetNIT(): net_id = 318
2010-11-28 12:30:06.556 SM(/dev/dvb/adapter3/frontend0)::AddFlags: Seen(NIT,) Match() Wait()
2010-11-28 12:30:06.576 DVBRec(5:/dev/dvb/adapter3/frontend0): PID 0x81 discontinuity detected
2010-11-28 12:30:06.599 DVBRec(5:/dev/dvb/adapter3/frontend0): PID 0x81 discontinuity detected
2010-11-28 12:30:06.620 DVBRec(5:/dev/dvb/adapter3/frontend0): PID 0x81 discontinuity detected
2010-11-28 12:30:06.643 DVBRec(5:/dev/dvb/adapter3/frontend0): PID 0x81 discontinuity detected
2010-11-28 12:30:06.498 SM(/dev/dvb/adapter3/frontend0)::Stop: end
2010-11-28 12:30:06.676 DVBSH(/dev/dvb/adapter3/frontend0): RemoveListener(0x92bbb30) -- begin
2010-11-28 12:30:06.682 DVBSH(/dev/dvb/adapter3/frontend0): RemoveListener(0x92bbb30) -- locked
2010-11-28 12:30:06.689 DVBSH(/dev/dvb/adapter3/frontend0): RemoveListener(0x92bbb30) -- end
2010-11-28 12:30:06.709 DVBSM(/dev/dvb/adapter3/frontend0): Stop() -- end
2010-11-28 12:30:06.722 SM(/dev/dvb/adapter3/frontend0)::Stop: begin
2010-11-28 12:30:06.736 SM(/dev/dvb/adapter3/frontend0)::Stop: end
2010-11-28 12:30:06.749 TVRec(6): TeardownSignalMonitor() -- end
2010-11-28 12:30:06.766 TVRec(6): ClearFlags(SignalMonitorRunning,) -> RunMainLoop,WaitingForSignal,NeedToStartRecorder,
2010-11-28 12:30:06.779 TVRec(6): ClearFlags(WaitingForSignal,) -> RunMainLoop,NeedToStartRecorder,
2010-11-28 12:30:06.702 DVBRec(5:/dev/dvb/adapter3/frontend0): PID 0x81 discontinuity detected
2010-11-28 12:30:06.809 PIDInfo(/dev/dvb/adapter3/frontend0): Closing filter for pid 0x94
2010-11-28 12:30:06.794 TVRec(6): Starting Recorder
2010-11-28 12:30:06.823 PIDInfo(/dev/dvb/adapter3/frontend0): Closing filter for pid 0x208
2010-11-28 12:30:06.843 Using profile 'Default' to record
2010-11-28 12:30:06.866 TVRec(6): rec->GetPathname(): '/myth/tv/8009_20101128123000.mpg'
2010-11-28 12:30:06.849 PIDInfo(/dev/dvb/adapter3/frontend0): Closing filter for pid 0x247
2010-11-28 12:30:06.879 PIDInfo(/dev/dvb/adapter3/frontend0): Closing filter for pid 0x2da
2010-11-28 12:30:06.893 DVBRec(5:/dev/dvb/adapter3/frontend0): PID 0x81 discontinuity detected
2010-11-28 12:30:06.900 DVBRec(5:/dev/dvb/adapter3/frontend0): PID 0x81 discontinuity detected
2010-11-28 12:30:06.913 DVBRec(5:/dev/dvb/adapter3/frontend0): PID 0x81 discontinuity detected
2010-11-28 12:30:06.926 DVBRec(5:/dev/dvb/adapter3/frontend0): PID 0x81 discontinuity detected
2010-11-28 12:30:06.943 DVBRec(5:/dev/dvb/adapter3/frontend0): PID 0x81 discontinuity detected
2010-11-28 12:30:06.956 DVBRec(5:/dev/dvb/adapter3/frontend0): PID 0x81 discontinuity detected
2010-11-28 12:30:06.969 DVBRec(5:/dev/dvb/adapter3/frontend0): PID 0x81 discontinuity detected
2010-11-28 12:30:06.917 RecBase(6:/dev/dvb/adapter3/frontend0): SetRingBuffer(0x920add8) '/myth/tv/8009_20101128123000.mpg'
2010-11-28 12:30:06.989 DVBRec(6:/dev/dvb/adapter3/frontend0): SetPAT(4319 on 0x10c)
2010-11-28 12:30:06.999 CreatePATSingleProgram()
2010-11-28 12:30:07.012 PAT in input stream
2010-11-28 12:30:07.019 Program Association Table
 PSIP tableID(0x0) length(57) extension(0x3e8)
      version(2) current(1) section(0) last_section(0)
         tsid: 1000
 programCount: 12
  program number     0 has PID 0x  10   data  0x 0 0x 0 0xe0 0x10
  program number  4311 has PID 0x 104   data  0x10 0xd7 0xe1 0x 4
  program number  4312 has PID 0x 105   data  0x10 0xd8 0xe1 0x 5
  program number  4313 has PID 0x 106   data  0x10 0xd9 0xe1 0x 6
  program number  4316 has PID 0x 109   data  0x10 0xdc 0xe1 0x 9
  program number  4318 has PID 0x 10b   data  0x10 0xde 0xe1 0x b
  program number  4319 has PID 0x 10c   data  0x10 0xdf 0xe1 0x c
  program number  4320 has PID 0x 10d   data  0x10 0xe0 0xe1 0x d
  program number  4321 has PID 0x 10e   data  0x10 0xe1 0xe1 0x e
  program number  4322 has PID 0x 10f   data  0x10 0xe2 0xe1 0x f
  program number  4333 has PID 0x 118   data  0x10 0xed 0xe1 0x18
  program number 15050 has PID 0x 101   data  0x3a 0xca 0xe1 0x 1

2010-11-28 12:30:07.032 desired_program(4319) pid(0x10c)
2010-11-28 12:30:07.046 pmt_pid(0x10c)
2010-11-28 12:30:07.059 PAT for output stream
2010-11-28 12:30:07.072 Program Association Table
 PSIP tableID(0x0) length(13) extension(0x3e8)
      version(2) current(1) section(0) last_section(0)
         tsid: 1000
 programCount: 1
  program number     1 has PID 0x 10c   data  0x 0 0x 1 0xe1 0x c

2010-11-28 12:30:07.086 DVBRec(6:/dev/dvb/adapter3/frontend0): SetPMT(4319)
2010-11-28 12:30:07.109 CreatePMTSingleProgram()
2010-11-28 12:30:07.123 PMT in input stream
2010-11-28 12:30:07.136 Program Map Table ver(20) pid(0x10c) pnum(4319) len(194)
  Conditional Access: sid(0x100) pid(0x6b0) data_size(13)
  Conditional Access: sid(0x500) pid(0x650) data_size(11)
  Conditional Access: sid(0xb00) pid(0x504) data_size(0)
  Conditional Access: sid(0xb01) pid(0x599) data_size(0)
  Conditional Access: sid(0xb02) pid(0x58d) data_size(0)
  Conditional Access: sid(0x1803) pid(0x5a8) data_size(0)
  Conditional Access: sid(0x1813) pid(0x71b) data_size(0)
  Multiplex Buffer Utilization Descriptor (0xc) length(4)
  Smoothing Buffer Descriptor (0x10) length(6)

 Stream #0 pid(0x208) type(video-mpeg2  0x2)
  Video Descriptor (0x2) length(3)
  Stream Identifier Descriptor (0x52): ComponentTag=0x7
  Unknown(6) Descriptor (0x6) length(1)
 Stream #1 pid(0x2da) type(audio-mp2-layer[1,2,3]  0x4)
  Audio Descriptor (0x3) length(1)
  ISO-639 Language: code(pol) canonical(pol) eng(Polish)
  Stream Identifier Descriptor (0x52): ComponentTag=0xd0
 Stream #2 pid(0x247) type(private-data  0x6)
  Teletext Descriptor (0x56) length(5)
  Stream Identifier Descriptor (0x52): ComponentTag=0x47
 Stream #3 pid(0xd0) type(unknown  0xc0)
  Unknown(194) Descriptor (0xc2) length(24)
  Unknown(198) Descriptor (0xc6) length(5)
 Stream #4 pid(0xd5) type(unknown  0xc1)
  Unknown(194) Descriptor (0xc2) length(8)

2010-11-28 12:30:07.149 PMT for output stream
2010-11-28 12:30:07.163 Program Map Table ver(20) pid(0x10c) pnum(1) len(128)
  Multiplex Buffer Utilization Descriptor (0xc) length(4)
  Smoothing Buffer Descriptor (0x10) length(6)

 Stream #0 pid(0x208) type(video-mpeg2  0x2)
  Video Descriptor (0x2) length(3)
  Stream Identifier Descriptor (0x52): ComponentTag=0x7
  Unknown(6) Descriptor (0x6) length(1)
 Stream #1 pid(0x2da) type(audio-mp2-layer[1,2,3]  0x4)
  Audio Descriptor (0x3) length(1)
  ISO-639 Language: code(pol) canonical(pol) eng(Polish)
  Stream Identifier Descriptor (0x52): ComponentTag=0xd0
 Stream #2 pid(0x247) type(private-data  0x6)
  Teletext Descriptor (0x56) length(5)
  Stream Identifier Descriptor (0x52): ComponentTag=0x47
 Stream #3 pid(0xd0) type(unknown  0xc0)
  Unknown(194) Descriptor (0xc2) length(24)
  Unknown(198) Descriptor (0xc6) length(5)
 Stream #4 pid(0xd5) type(unknown  0xc1)
  Unknown(194) Descriptor (0xc2) length(8)

2010-11-28 12:30:07.176 RecBase(6:/dev/dvb/adapter3/frontend0): SetRecording(0x94690c0) title(Turbo Kamera 7)
2010-11-28 12:30:07.194 DVBRec(6:/dev/dvb/adapter3/frontend0): Card opened successfully fd(-1)
2010-11-28 12:30:07.202 DVBSH(/dev/dvb/adapter3/frontend0): AddListener(0x92bbb30) -- begin
2010-11-28 12:30:07.216 DVBSH(/dev/dvb/adapter3/frontend0): AddListener(0x92bbb30) -- locked
2010-11-28 12:30:07.229 DVBSH(/dev/dvb/adapter3/frontend0): AddListener(0x92bbb30) -- end
2010-11-28 12:30:07.205 TVRec(6): SetFlags(RecorderRunning,RingBufferReady,) -> RunMainLoop,NeedToStartRecorder,RecorderRunning,RingBufferReady,
2010-11-28 12:30:07.274 TVRec(6): ClearFlags(NeedToStartRecorder,) -> RunMainLoop,RecorderRunning,RingBufferReady,
2010-11-28 12:30:10.710 Reschedule interrupted, will retry
2010-11-28 12:30:10.717 Reschedule requested for id 0.
2010-11-28 12:30:16.789 Scheduled 566 items in 6.0 = 0.02 match + 5.94 place
2010-11-28 12:30:16.804 scheduler: Scheduled items: Scheduled 566 items in 6.0 = 0.02 match + 5.94 place
2010-11-28 12:30:29.461 TVRec(5): Deleting stale pending recording 6 'Turbo Kamera 7'
2010-11-28 12:30:31.947 DevRdB(/dev/dvb/adapter3/frontend0) Error: Poll giving up
2010-11-28 12:30:31.952 DevRdB(/dev/dvb/adapter3/frontend0): fill_ringbuffer: error state
2010-11-28 12:30:31.966 DVBSH(/dev/dvb/adapter3/frontend0) Error: Device error detected
2010-11-28 12:30:31.979 DVBSH(/dev/dvb/adapter3/frontend0): RunTS(): shutdown
2010-11-28 12:30:31.992 PIDInfo(/dev/dvb/adapter3/frontend0): Closing filter for pid 0x0
2010-11-28 12:30:32.009 PIDInfo(/dev/dvb/adapter3/frontend0): Closing filter for pid 0x10
2010-11-28 12:30:32.022 PIDInfo(/dev/dvb/adapter3/frontend0): Closing filter for pid 0x11
2010-11-28 12:30:32.036 PIDInfo(/dev/dvb/adapter3/frontend0): Closing filter for pid 0x14
2010-11-28 12:30:32.049 PIDInfo(/dev/dvb/adapter3/frontend0): Closing filter for pid 0x81
2010-11-28 12:30:32.062 PIDInfo(/dev/dvb/adapter3/frontend0): Closing filter for pid 0xd0
2010-11-28 12:30:32.076 PIDInfo(/dev/dvb/adapter3/frontend0): Closing filter for pid 0xd5
2010-11-28 12:30:32.099 PIDInfo(/dev/dvb/adapter3/frontend0): Closing filter for pid 0x101
2010-11-28 12:30:32.112 PIDInfo(/dev/dvb/adapter3/frontend0): Closing filter for pid 0x104
2010-11-28 12:30:32.126 PIDInfo(/dev/dvb/adapter3/frontend0): Closing filter for pid 0x105
2010-11-28 12:30:32.139 PIDInfo(/dev/dvb/adapter3/frontend0): Closing filter for pid 0x106
2010-11-28 12:30:32.166 PIDInfo(/dev/dvb/adapter3/frontend0): Closing filter for pid 0x109
2010-11-28 12:30:32.186 PIDInfo(/dev/dvb/adapter3/frontend0): Closing filter for pid 0x10b
2010-11-28 12:30:32.199 PIDInfo(/dev/dvb/adapter3/frontend0): Closing filter for pid 0x10c
2010-11-28 12:30:32.219 PIDInfo(/dev/dvb/adapter3/frontend0): Closing filter for pid 0x10d
2010-11-28 12:30:32.242 PIDInfo(/dev/dvb/adapter3/frontend0): Closing filter for pid 0x10e
2010-11-28 12:30:32.256 PIDInfo(/dev/dvb/adapter3/frontend0): Closing filter for pid 0x10f
2010-11-28 12:30:32.276 PIDInfo(/dev/dvb/adapter3/frontend0): Closing filter for pid 0x118
2010-11-28 12:30:32.299 PIDInfo(/dev/dvb/adapter3/frontend0): Closing filter for pid 0x201
2010-11-28 12:30:32.319 PIDInfo(/dev/dvb/adapter3/frontend0): Closing filter for pid 0x294
2010-11-28 12:30:32.345 DVBSH(/dev/dvb/adapter3/frontend0): RunTS(): end
2010-11-28 12:30:32.363 DVBRec(5:/dev/dvb/adapter3/frontend0) Error: Stream handler died unexpectedly.
2010-11-28 12:30:32.376 DVBSH(/dev/dvb/adapter3/frontend0): RemoveListener(0xa5513298) -- begin
2010-11-28 12:30:32.382 DVBSH(/dev/dvb/adapter3/frontend0): RemoveListener(0xa5513298) -- locked
2010-11-28 12:30:32.389 DVBSH(/dev/dvb/adapter3/frontend0): RemoveListener(0xa5513298) -- end
2010-11-28 12:30:32.396 DVBRec(5:/dev/dvb/adapter3/frontend0): Close() fd(-1) -- begin
2010-11-28 12:30:32.409 DVBRec(5:/dev/dvb/adapter3/frontend0): Close() fd(-1) -- end
2010-11-28 12:30:32.363 DVBRec(6:/dev/dvb/adapter3/frontend0) Error: Stream handler died unexpectedly.
2010-11-28 12:30:32.429 DVBSH(/dev/dvb/adapter3/frontend0): RemoveListener(0x92bbb30) -- begin
2010-11-28 12:30:32.442 DVBSH(/dev/dvb/adapter3/frontend0): RemoveListener(0x92bbb30) -- locked
2010-11-28 12:30:32.466 DVBSH(/dev/dvb/adapter3/frontend0): RemoveListener(0x92bbb30) -- end
2010-11-28 12:30:32.486 DVBRec(6:/dev/dvb/adapter3/frontend0): Close() fd(-1) -- begin
2010-11-28 12:30:32.499 DVBRec(6:/dev/dvb/adapter3/frontend0): Close() fd(-1) -- end
2010-11-28 12:30:32.477 TVRec(5): Changing from RecordingOnly to None
2010-11-28 12:30:32.526 TVRec(5): ClearFlags(FrontendReady,CancelNextRecording,) -> RunMainLoop,RecorderRunning,RingBufferReady,
2010-11-28 12:30:32.532 TVRec(5): HandleTuning Request: Program(no) channel() input() flags(CloseRec,KillRingBuffer,)
2010-11-28 12:30:32.553 TVRec(5): FinishedRecording(Dokument W Tvn 24) in recgroup: 3 - Wspolne
2010-11-28 12:30:32.559 Updating status for "Dokument W Tvn 24" on cardid 5 (Recording => Recorder Failed)
2010-11-28 12:30:32.578 Reschedule requested for id 0.
2010-11-28 12:30:32.563 TVRec(5): ClearFlags(RecorderRunning,) -> RunMainLoop,RingBufferReady,
2010-11-28 12:30:32.604 RecBase(5:/dev/dvb/adapter3/frontend0): SetRecording(0x0)
2010-11-28 12:30:32.622 TVRec(5): FinishedRecording(Dokument W Tvn 24) in recgroup: 3 - Wspolne
2010-11-28 12:30:32.659 TVRec(5): ClearFlags(RecorderRunning,) -> RunMainLoop,RingBufferReady,
2010-11-28 12:30:32.673 TVRec(5): Tearing down RingBuffer
2010-11-28 12:30:32.680 TVRec(5): ClearFlags(PENDINGACTIONS,) -> RunMainLoop,RingBufferReady,
2010-11-28 12:30:33.328 TVRec(6): Changing from RecordingOnly to None
2010-11-28 12:30:33.332 TVRec(6): ClearFlags(FrontendReady,CancelNextRecording,) -> RunMainLoop,RecorderRunning,RingBufferReady,
2010-11-28 12:30:33.346 TVRec(6): HandleTuning Request: Program(no) channel() input() flags(CloseRec,KillRingBuffer,)
2010-11-28 12:30:33.360 TVRec(6): FinishedRecording(Turbo Kamera 7) in recgroup: 2 - Piotr
2010-11-28 12:30:33.373 Updating status for "Turbo Kamera 7" on cardid 6 (Recording => Recorder Failed)
2010-11-28 12:30:33.376 TVRec(6): ClearFlags(RecorderRunning,) -> RunMainLoop,RingBufferReady,
2010-11-28 12:30:33.399 RecBase(6:/dev/dvb/adapter3/frontend0): SetRecording(0x0)
2010-11-28 12:30:33.414 TVRec(6): FinishedRecording(Turbo Kamera 7) in recgroup: 2 - Piotr
2010-11-28 12:30:33.431 TVRec(6): ClearFlags(RecorderRunning,) -> RunMainLoop,RingBufferReady,
2010-11-28 12:30:33.442 TVRec(6): Tearing down RingBuffer
2010-11-28 12:30:33.456 TVRec(6): ClearFlags(PENDINGACTIONS,) -> RunMainLoop,RingBufferReady,
2010-11-28 12:30:36.600 Reschedule interrupted, will retry
2010-11-28 12:30:36.612 Reschedule requested for id 0.
2010-11-28 12:30:36.619 Reschedule requested for id 0.
2010-11-28 12:30:40.609 Scheduled 566 items in 3.9 = 0.02 match + 3.92 place
2010-11-28 12:30:40.621 scheduler: Scheduled items: Scheduled 566 items in 3.9 = 0.02 match + 3.92 place
2010-11-28 12:34:00.674 Reschedule requested for id 0.
2010-11-28 12:34:04.677 Scheduled 566 items in 3.9 = 0.01 match + 3.94 place
2010-11-28 12:34:04.686 scheduler: Scheduled items: Scheduled 566 items in 3.9 = 0.01 match + 3.94 place
-------------


More information about the mythtv-users mailing list