[mythtv-users] failed recordings on HVR-1600: DevRdB(/dev/dvb/adapter1/frontend0): Poll giving up 2
Brian J. Murrell
brian at interlinx.bc.ca
Fri Dec 9 17:10:13 UTC 2011
The other night, my HVR-1600 was supposed to record two clearqam
programs on the same transport (is that the correct nomenclature for the
broadcast channel?) but seems to have failed. Recordings prior and
subsequent were successful.
The backend log reported during this failure:
2011-12-07 22:00:00.687331 I [1625/1949] TVRecEvent tv_rec.cpp:992
(HandleStateChange) - TVRec(1): Changing from None to RecordingOnly
2011-12-07 22:00:00.715160 I [1625/1949] TVRecEvent tv_rec.cpp:3434
(TuningCheckForHWChange) - TVRec(1): HW Tuner: 1->1
2011-12-07 22:00:00.891411 I [1625/2194] TVRecEvent tv_rec.cpp:992
(HandleStateChange) - TVRec(11): Changing from RecordingOnly to None
2011-12-07 22:00:01.103688 I [1625/2194] TVRecEvent
recordinginfo.cpp:1108 (FinishedRecording) - Finished recording Storage
Wars "Tanks for the Memories": channel 1019
2011-12-07 22:00:01.115712 E [1625/7589] RecThread mpegrecorder.cpp:1044
(run) - MPEGRec(/dev/video1): Device EOF detected
2011-12-07 22:00:01.990880 N [1625/2195] Scheduler autoexpire.cpp:264
(CalcParams) - AutoExpire: CalcParams(): Max required Free Space: 3.0 GB
w/freq: 4 min
2011-12-07 22:00:01.991166 I [1625/2195] Scheduler scheduler.cpp:2456
(HandleRecordingStatusChange) - Tuning recording: "CSI: Crime Scene
Investigation":Zippered: channel 2917 on cardid 1, sourceid 2
2011-12-07 22:00:02.390675 I [1625/7049] DVBRead
mpeg/mpegdescriptors.cpp:72 (ParseOnlyInclude) - Excluding Descriptor 83
2011-12-07 22:00:02.390718 I [1625/7049] DVBRead
mpeg/mpegdescriptors.cpp:72 (ParseOnlyInclude) - Excluding Descriptor a
2011-12-07 22:00:02.390759 I [1625/7049] DVBRead
mpeg/mpegdescriptors.cpp:72 (ParseOnlyInclude) - Excluding Descriptor 83
2011-12-07 22:00:02.390783 I [1625/7049] DVBRead
mpeg/mpegdescriptors.cpp:72 (ParseOnlyInclude) - Excluding Descriptor a
2011-12-07 22:00:02.535747 I [1625/1949] TVRecEvent tv_rec.cpp:3948
(TuningNewRecorder) - TVRec(1): rec->GetPathname():
'/video/mythtv/2917_20111207220000.mpg'
2011-12-07 22:00:02.965083 I [1625/7589] RecThread mythdbcon.cpp:479
(CloseDatabases) - Closing DB connection named 'DBManager81'
2011-12-07 22:00:04.238409 I [1625/2085] TVRecEvent tv_rec.cpp:992
(HandleStateChange) - TVRec(2): Changing from RecordingOnly to None
2011-12-07 22:00:04.296911 I [1625/2085] TVRecEvent
recordinginfo.cpp:1108 (FinishedRecording) - Finished recording Criminal
Minds "Self-Fulfilling Prophecy": channel 2917
2011-12-07 22:00:04.415071 I [1625/7074] RecThread mythdbcon.cpp:75
(MSqlDatabase) - Database connection created: DBManager100
2011-12-07 22:00:04.415170 I [1625/7074] RecThread mythdbcon.cpp:298
(popConnection) - New DB connection, total: 35
2011-12-07 22:00:04.416565 I [1625/7074] RecThread mythdbcon.cpp:179
(OpenDatabase) - Connected to database 'mythconverg' at host: localhost
2011-12-07 22:00:04.435417 I [1625/7074] RecThread mythdbcon.cpp:479
(CloseDatabases) - Closing DB connection named 'DBManager100'
2011-12-07 22:00:04.876862 I [1625/2085] TVRecEvent tv_rec.cpp:992
(HandleStateChange) - TVRec(2): Changing from None to RecordingOnly
2011-12-07 22:00:04.880716 I [1625/2085] TVRecEvent tv_rec.cpp:3434
(TuningCheckForHWChange) - TVRec(2): HW Tuner: 2->2
2011-12-07 22:00:07.303591 N [1625/2195] Scheduler autoexpire.cpp:264
(CalcParams) - AutoExpire: CalcParams(): Max required Free Space: 3.0 GB
w/freq: 4 min
2011-12-07 22:00:07.303697 I [1625/2195] Scheduler scheduler.cpp:2456
(HandleRecordingStatusChange) - Tuning recording: Revenge:Loyalty:
channel 3776 on cardid 2, sourceid 2
2011-12-07 22:00:08.767051 I [1625/2195] Scheduler scheduler.cpp:2456
(HandleRecordingStatusChange) - Started recording: "CSI: Crime Scene
Investigation":Zippered: channel 2917 on cardid 1, sourceid 2
2011-12-07 22:00:10.104434 I [1625/1625] CoreContext scheduler.cpp:603
(UpdateRecStatus) - Updating status for "Happy Endings":"Grinches Be
Crazy" on cardid 1 (Recording => Recorded)
2011-12-07 22:00:10.269066 I [1625/1625] CoreContext scheduler.cpp:603
(UpdateRecStatus) - Updating status for "Storage Wars":"Tanks for the
Memories" on cardid 11 (Recording => Recorded)
2011-12-07 22:00:10.370180 I [1625/1625] CoreContext scheduler.cpp:603
(UpdateRecStatus) - Updating status for "Criminal
Minds":"Self-Fulfilling Prophecy" on cardid 2 (Recording => Recorded)
2011-12-07 22:00:10.444919 E [1625/1625] CoreContext mainserver.cpp:868
(customEvent) - MainServer: PREVIEW_SUCCESS but no receivers.
2011-12-07 22:00:10.524969 I [1625] ProcessRequest mainserver.cpp:1356
(HandleAnnounce) - MainServer::ANN Playback
2011-12-07 22:00:10.525011 I [1625] ProcessRequest mainserver.cpp:1358
(HandleAnnounce) - adding: pvr as a client (events: 0)
2011-12-07 22:00:10.541908 I [1625] ProcessRequest mainserver.cpp:1356
(HandleAnnounce) - MainServer::ANN Playback
2011-12-07 22:00:10.541952 I [1625] ProcessRequest mainserver.cpp:1358
(HandleAnnounce) - adding: pvr as a client (events: 0)
2011-12-07 22:00:10.559459 I [1625] ProcessRequest mainserver.cpp:1356
(HandleAnnounce) - MainServer::ANN Monitor
2011-12-07 22:00:10.559499 I [1625] ProcessRequest mainserver.cpp:1358
(HandleAnnounce) - adding: pvr as a client (events: 1)
2011-12-07 22:00:10.571540 I [1625] ProcessRequest mainserver.cpp:1356
(HandleAnnounce) - MainServer::ANN Monitor
2011-12-07 22:00:10.571585 I [1625] ProcessRequest mainserver.cpp:1358
(HandleAnnounce) - adding: pvr as a client (events: 1)
2011-12-07 22:00:13.500322 E [1625/7861] ProcessRequest
programinfo.cpp:2166 (GetPlaybackURL) -
ProgramInfo(4097_20111201200000.mpg): GetPlaybackURL:
'4097_20111201200000.mpg' should be local, but it can not be found.
2011-12-07 22:00:13.642245 E [1625/7861] ProcessRequest
programinfo.cpp:2166 (GetPlaybackURL) -
ProgramInfo(1042_20111124110000.mpg): GetPlaybackURL:
'1042_20111124110000.mpg' should be local, but it can not be found.
2011-12-07 22:00:13.727291 E [1625/7861] ProcessRequest
programinfo.cpp:2166 (GetPlaybackURL) -
ProgramInfo(3776_20111207220000.mpg): GetPlaybackURL:
'3776_20111207220000.mpg' should be local, but it can not be found.
2011-12-07 22:00:14.048552 I [1625] ProcessRequest mythdbcon.cpp:75
(MSqlDatabase) - Database connection created: DBManager101
2011-12-07 22:00:14.048650 I [1625] ProcessRequest mythdbcon.cpp:298
(popConnection) - New DB connection, total: 35
2011-12-07 22:00:14.051697 I [1625] ProcessRequest mythdbcon.cpp:179
(OpenDatabase) - Connected to database 'mythconverg' at host: localhost
2011-12-07 22:00:16.137967 E [1625/8197] ProcessRequest
programinfo.cpp:2166 (GetPlaybackURL) -
ProgramInfo(4097_20111201200000.mpg): GetPlaybackURL:
'4097_20111201200000.mpg' should be local, but it can not be found.
2011-12-07 22:00:16.259022 E [1625/8197] ProcessRequest
programinfo.cpp:2166 (GetPlaybackURL) -
ProgramInfo(1042_20111124110000.mpg): GetPlaybackURL:
'1042_20111124110000.mpg' should be local, but it can not be found.
2011-12-07 22:00:16.336523 E [1625/8197] ProcessRequest
programinfo.cpp:2166 (GetPlaybackURL) -
ProgramInfo(3776_20111207220000.mpg): GetPlaybackURL:
'3776_20111207220000.mpg' should be local, but it can not be found.
2011-12-07 22:00:27.411592 E [1625/7050] DeviceReadBuffer
DeviceReadBuffer.cpp:509 (Poll) - DevRdB(/dev/dvb/adapter1/frontend0):
Poll giving up 2
2011-12-07 22:00:27.412040 E [1625/7049] DVBRead
dvbstreamhandler.cpp:209 (RunTS) - DVBSH(/dev/dvb/adapter1/frontend0):
Device error detected
2011-12-07 22:00:27.412083 E [1625/7049] DVBRead
dvbstreamhandler.cpp:215 (RunTS) - DVBSH(/dev/dvb/adapter1/frontend0):
Device EOF detected
2011-12-07 22:00:28.014487 I [1625/7049] DVBRead mythdbcon.cpp:479
(CloseDatabases) - Closing DB connection named 'DBManager58'
2011-12-07 22:00:28.060048 E [1625/7601] RecThread dvbrecorder.cpp:134
(run) - DVBRec(4:/dev/dvb/adapter1/frontend0): Stream handler died
unexpectedly.
2011-12-07 22:00:28.060501 E [1625/8226] RecThread dvbrecorder.cpp:134
(run) - DVBRec(1:/dev/dvb/adapter1/frontend0): Stream handler died
unexpectedly.
2011-12-07 22:00:28.064247 I [1625/8226] RecThread mythdbcon.cpp:75
(MSqlDatabase) - Database connection created: DBManager102
2011-12-07 22:00:28.064343 I [1625/8226] RecThread mythdbcon.cpp:298
(popConnection) - New DB connection, total: 35
2011-12-07 22:00:28.065836 I [1625/8226] RecThread mythdbcon.cpp:179
(OpenDatabase) - Connected to database 'mythconverg' at host: localhost
2011-12-07 22:00:28.067934 I [1625/2091] TVRecEvent tv_rec.cpp:992
(HandleStateChange) - TVRec(4): Changing from RecordingOnly to None
2011-12-07 22:00:28.078658 I [1625/8226] RecThread mythdbcon.cpp:479
(CloseDatabases) - Closing DB connection named 'DBManager102'
2011-12-07 22:00:28.092972 I [1625/1625] CoreContext scheduler.cpp:603
(UpdateRecStatus) - Updating status for "Harry's Law":"Purple Hearts" on
cardid 4 (Recording => Recorder Failed)
2011-12-07 22:00:28.130716 I [1625/7601] RecThread mythdbcon.cpp:75
(MSqlDatabase) - Database connection created: DBManager103
2011-12-07 22:00:28.130814 I [1625/7601] RecThread mythdbcon.cpp:298
(popConnection) - New DB connection, total: 35
2011-12-07 22:00:28.132021 I [1625/7601] RecThread mythdbcon.cpp:179
(OpenDatabase) - Connected to database 'mythconverg' at host: localhost
2011-12-07 22:00:28.137156 I [1625/7601] RecThread mythdbcon.cpp:479
(CloseDatabases) - Closing DB connection named 'DBManager103'
2011-12-07 22:00:28.180190 I [1625/1625] CoreContext scheduler.cpp:603
(UpdateRecStatus) - Updating status for Revenge:Loyalty on cardid 2
(Tuning => Recorder Failed)
2011-12-07 22:00:28.215489 I [1625/2195] Scheduler scheduler.cpp:2008
(HandleReschedule) - Reschedule requested for id 0.
2011-12-07 22:00:28.215529 I [1625/2195] Scheduler scheduler.cpp:2008
(HandleReschedule) - Reschedule requested for id 0.
2011-12-07 22:00:28.215554 I [1625/2195] Scheduler scheduler.cpp:2008
(HandleReschedule) - Reschedule requested for id 0.
2011-12-07 22:00:28.215579 I [1625/2195] Scheduler scheduler.cpp:2008
(HandleReschedule) - Reschedule requested for id 0.
2011-12-07 22:00:28.215600 I [1625/2195] Scheduler scheduler.cpp:2008
(HandleReschedule) - Reschedule requested for id 0.
2011-12-07 22:00:28.723666 I [1625/1949] TVRecEvent tv_rec.cpp:992
(HandleStateChange) - TVRec(1): Changing from RecordingOnly to None
2011-12-07 22:00:28.755838 I [1625/1625] CoreContext scheduler.cpp:603
(UpdateRecStatus) - Updating status for "CSI: Crime Scene
Investigation":Zippered on cardid 1 (Recording => Recorder Failed)
2011-12-07 22:01:33.342789 N [1625/2197] Expire autoexpire.cpp:264
(CalcParams) - AutoExpire: CalcParams(): Max required Free Space: 3.0 GB
w/freq: 14 min
2011-12-07 22:01:50.792157 I [1625/2195] Scheduler scheduler.cpp:2055
(HandleReschedule) - Reschedule interrupted, will retry
2011-12-07 22:01:50.805021 I [1625/2195] Scheduler scheduler.cpp:2008
(HandleReschedule) - Reschedule requested for id 0.
2011-12-07 22:01:50.805062 I [1625/2195] Scheduler scheduler.cpp:2008
(HandleReschedule) - Reschedule requested for id 0.
Worth noting that the CSI and Harry's law that are reporting as failed
were recorded in full.
The kernel log buffer reported at the same time frame:
Dec 7 22:00:01 pvr kernel: [34563.279588] cx18-0: Could not find buf 0
for stream encoder MPEG
Dec 7 22:00:01 pvr kernel: [34563.473447] cx18-0: Unable to find blank
work order form to schedule incoming mailbox command processing
Dec 7 22:00:01 pvr kernel: [34563.655761] cx18-0: ignoring gop_end: not
(yet?) supported by the firmware
Dec 7 22:00:02 pvr kernel: [34564.150773] cx18-0: Skipped encoder MPEG,
buffer 63, 29 times - it must have dropped out of rotation
Dec 7 22:00:02 pvr kernel: [34564.329266] cx18-0: Skipped TS, buffer
84, 16 times - it must have dropped out of rotation
Any ideas?
Cheers,
b.
More information about the mythtv-users
mailing list