[mythtv-users] Problem with record 'The Closer'

Greg greg12866 at nycap.rr.com
Tue Oct 19 14:04:37 UTC 2010


  On 10/19/2010 08:24 AM, Jim Morton wrote:
>  My system is having problems recording 'The Closer' on TBS. This has 
> happened several days in a row despite rebooting everything.
> The symptoms - the audio gets further out of sync as you watch the 
> show. At about 35-40 minutes in, it starts stuttering and echoing for 
> a couple minutes, getting progressively worse to the point that the 
> audio is not even understandable and then it just stops recording.
> It is being recorded from an HDPVR that is just 2 months old. (I did 
> hook it up to a windows box and updated the firmware when I got it.)
> Other recordings from the same tuner seem to be fine.
>
> I'm suspecting the HDPVR but would expect all recordings from it to be 
> bad. Can anyone point to any other possible culprit?
>
> Mythbuntu - mythbackend version: branches/release-0-23-fixes [s25362]
>
> Here are snippets of the backend log from the time of the recording 
> and dmesg output.
>
> 2010-10-18 13:59:51.749 TVRec(12): Changing from None to RecordingOnly
> 2010-10-18 13:59:51.766 TVRec(12): HW Tuner: 12->12
> 2010-10-18 13:59:52.859 ret_pid(0) child(15029) status(0x0)
> 2010-10-18 13:59:53.859 ret_pid(0) child(15029) status(0x0)
> 2010-10-18 13:59:54.860 ret_pid(0) child(15029) status(0x0)
> 2010-10-18 13:59:55.860 ret_pid(0) child(15029) status(0x0)
> 2010-10-18 13:59:56.820 ret_pid(15029) child(15029) status(0x0)
> 2010-10-18 13:59:56.821 External Tuning program exited with no error
> 2010-10-18 13:59:57.014 TVRec(12): rec->GetFileName(): 
> '/video/media/2138_20101018140000.mpg'
> 2010-10-18 13:59:57.211 AutoExpire: CalcParams(): Max required Free 
> Space: 22.0 GB w/freq: 7 min
> 2010-10-18 13:59:57.211 Started recording: The Closer "Mom Duty": 
> channel 2138 on cardid 12, sourceid 2
> 2010-10-18 14:00:18.718 AutoExpire: CalcParams(): Max required Free 
> Space: 22.0 GB w/freq: 7 min
> 2010-10-18 14:00:28.004 ProgramInfo(): Updated pathname '':'' -> 
> '2107_20101018140000.mpg'
> 2010-10-18 14:00:28.007 JobQueue: Commercial Flagging Starting for 
> Comedy Central Presents recorded from channel 2107 at Mon Oct 18 
> 14:00:00 2010
> 2010-10-18 14:00:28.057 ProgramInfo(): Updated pathname '':'' -> 
> '2107_20101018140000.mpg'
> 2010-10-18 14:00:28.130 Using runtime prefix = /usr
> 2010-10-18 14:00:28.130 Using configuration directory = 
> /home/mythtv/.mythtv
> 2010-10-18 14:00:28.131 Empty LocalHostName.
> 2010-10-18 14:00:28.131 Using localhost value of docbuntu
> 2010-10-18 14:00:28.136 New DB connection, total: 1
> 2010-10-18 14:00:28.139 Connected to database 'mythconverg' at host: 
> localhost
> 2010-10-18 14:00:28.139 Closing DB connection named 'DBManager0'
> 2010-10-18 14:00:28.139 Connected to database 'mythconverg' at host: 
> localhost
> 2010-10-18 14:00:28.142 ProgramInfo(): Updated pathname '':'' -> 
> '2107_20101018140000.mpg'
> 2010-10-18 14:00:28.176 MythContext: Connecting to backend server: 
> 192.168.1.8:6543 (try 1 of 1)
> 2010-10-18 14:00:28.177 Using protocol version 56
> 2010-10-18 14:00:28.178 MainServer::ANN Playback
> 2010-10-18 14:00:28.178 adding: docbuntu as a client (events: 0)
> 2010-10-18 14:00:28.178 MainServer::ANN Monitor
> 2010-10-18 14:00:28.179 adding: docbuntu as a client (events: 1)
> 2010-10-18 14:00:28.219 ProgramInfo(): Updated pathname '':'' -> 
> '2107_20101018140000.mpg'
> 2010-10-18 14:00:31.075 AFD: Opened codec 0x2317630, id(H264) type(Video)
> 2010-10-18 14:00:31.076 AFD: codec AAC has 2 channels
> 2010-10-18 14:00:31.076 AFD: Opened codec 0x2317e50, id(AAC) type(Audio)
> 2010-10-18 14:00:31.085 MythContext: Connecting to backend server: 
> 127.0.0.1:6543 (try 1 of 1)
> 2010-10-18 14:00:31.088 Using protocol version 56
> 2010-10-18 14:00:31.089 MainServer::ANN Playback
> 2010-10-18 14:00:31.090 adding: docbuntu as a client (events: 0)
> 2010-10-18 14:00:31.095 Should be local only query: GetKeyframePositions
> 2010-10-18 14:00:33.009 ProgramInfo(): Updated pathname '':'' -> 
> '2138_20101018140000.mpg'
> 2010-10-18 14:00:33.011 JobQueue: Commercial Flagging Starting for The 
> Closer "Mom Duty" recorded from channel 2138 at Mon Oct 18 14:00:00 2010
> 2010-10-18 14:00:33.063 ProgramInfo(): Updated pathname '':'' -> 
> '2138_20101018140000.mpg'
> 2010-10-18 14:00:33.097 Using runtime prefix = /usr
> 2010-10-18 14:00:33.097 Using configuration directory = 
> /home/mythtv/.mythtv
> 2010-10-18 14:00:33.098 Empty LocalHostName.
> 2010-10-18 14:00:33.098 Using localhost value of docbuntu
> 2010-10-18 14:00:33.103 New DB connection, total: 1
> 2010-10-18 14:00:33.106 Connected to database 'mythconverg' at host: 
> localhost
> 2010-10-18 14:00:33.106 Closing DB connection named 'DBManager0'
> 2010-10-18 14:00:33.106 Connected to database 'mythconverg' at host: 
> localhost
> 2010-10-18 14:00:33.108 ProgramInfo(): Updated pathname '':'' -> 
> '2138_20101018140000.mpg'
> 2010-10-18 14:00:33.133 MythContext: Connecting to backend server: 
> 192.168.1.8:6543 (try 1 of 1)
> 2010-10-18 14:00:33.134 Using protocol version 56
> 2010-10-18 14:00:33.135 MainServer::ANN Playback
> 2010-10-18 14:00:33.135 adding: docbuntu as a client (events: 0)
> 2010-10-18 14:00:33.135 MainServer::ANN Monitor
> 2010-10-18 14:00:33.136 adding: docbuntu as a client (events: 1)
> 2010-10-18 14:00:33.184 ProgramInfo(): Updated pathname '':'' -> 
> '2138_20101018140000.mpg'
> 2010-10-18 14:00:33.280 AFD: Opened codec 0x1e07210, id(H264) type(Video)
> 2010-10-18 14:00:33.280 AFD: codec AAC has 2 channels
> 2010-10-18 14:00:33.281 AFD: Opened codec 0x1e08d90, id(AAC) type(Audio)
> 2010-10-18 14:00:33.282 MythContext: Connecting to backend server: 
> 192.168.1.8:6543 (try 1 of 1)
> 2010-10-18 14:00:33.282 Using protocol version 56
> 2010-10-18 14:00:33.283 MainServer::ANN Playback
> 2010-10-18 14:00:33.283 adding: docbuntu as a client (events: 0)
> 2010-10-18 14:00:33.283 RecBase(12:/dev/video0): 
> GetKeyframePositions(766,9223372036854775807,#0) out of 7
> 2010-10-18 14:07:18.864 AutoExpire: CalcParams(): Max required Free 
> Space: 22.0 GB w/freq: 7 min
> 2010-10-18 14:08:31.646 [h264 @ 0x7f692511a380]B picture before any 
> references, skipping
> 2010-10-18 14:08:31.646 [h264 @ 0x7f692511a380]decode_slice_header error
> 2010-10-18 14:08:31.647 [h264 @ 0x7f692511a380]no frame!
> 2010-10-18 14:08:31.647 AFD Error: Unknown decoding error
> 2010-10-18 14:08:31.647 [h264 @ 0x7f692511a380]B picture before any 
> references, skipping
> 2010-10-18 14:08:31.648 [h264 @ 0x7f692511a380]decode_slice_header error
> 2010-10-18 14:08:31.648 [h264 @ 0x7f692511a380]no frame!
>
> <snip>
>
> 2010-10-18 14:30:07.682 ~MythContext waiting for threads to exit.
> 2010-10-18 14:30:08.887 mythbackend version: 
> branches/release-0-23-fixes [s25362] www.mythtv.org
>
> <snip>
>
> 2010-10-18 14:39:52.965 [h264 @ 0x7fd701601380]non-existing PPS 
> referenced
> 2010-10-18 14:39:52.983 Should be local only query: GetKeyframePositions
> 2010-10-18 14:39:52.983 Dec: DoFastForward(): desiredFrame(28559) > 
> last_frame(1277)
> 2010-10-18 14:39:52.983 Dec: DoFastForward(): Desired frame is way 
> past the end of the keyframe map!
>             Seeking to last keyframe instead.
> 2010-10-18 14:39:52.984 [h264 @ 0x7fd701601380]sps_id out of range
> 2010-10-18 14:39:52.984 [h264 @ 0x7fd701601380]non-existing SPS 31 
> referenced in buffering period
> 2010-10-18 14:39:52.984 [h264 @ 0x7fd701601380]non-existing PPS 
> referenced
> 2010-10-18 14:39:52.984 [h264 @ 0x7fd701601380]B picture before any 
> references, skipping
> 2010-10-18 14:39:52.985 [h264 @ 0x7fd701601380]decode_slice_header error
> 2010-10-18 14:39:52.985 [h264 @ 0x7fd701601380]no frame!
> 2010-10-18 14:39:52.985 AFD Error: Unknown decoding error
> 2010-10-18 14:39:52.985 [h264 @ 0x7fd701601380]sps_id out of range
> 2010-10-18 14:39:52.985 [h264 @ 0x7fd701601380]non-existing SPS 15 
> referenced in buffering period
> 2010-10-18 14:39:52.986 [h264 @ 0x7fd701601380]non-existing PPS 
> referenced
> 2010-10-18 14:39:52.986 [h264 @ 0x7fd701601380]number of reference 
> frames exceeds max (probably corrupt input), discarding one
> 2010-10-18 14:39:52.987 [h264 @ 0x7fd701601380]number of reference 
> frames exceeds max (probably corrupt input), discarding one
> 2010-10-18 14:39:52.987 [h264 @ 0x7fd701601380]number of reference 
> frames exceeds max (probably corrupt input), discarding one
> 2010-10-18 14:39:52.987 [h264 @ 0x7fd701601380]number of reference 
> frames exceeds max (probably corrupt input), discarding one
> 2010-10-18 14:39:52.987 [h264 @ 0x7fd701601380]number of reference 
> frames exceeds max (probably corrupt input), discarding one
>
> <snip>
>
> 2010-10-18 14:39:53.027 [h264 @ 0x7fd701601380]B picture before any 
> references, skipping
> 2010-10-18 14:39:53.027 [h264 @ 0x7fd701601380]decode_slice_header error
> 2010-10-18 14:39:53.027 [h264 @ 0x7fd701601380]no frame!
> 2010-10-18 14:39:53.027 AFD Error: Unknown decoding error
> 2010-10-18 14:39:53.028 [h264 @ 0x7fd701601380]B picture before any 
> references, skipping
> 2010-10-18 14:39:53.028 [h264 @ 0x7fd701601380]decode_slice_header error
> 2010-10-18 14:39:53.028 [h264 @ 0x7fd701601380]no frame!
> 2010-10-18 14:39:53.028 AFD Error: Unknown decoding error
> 2010-10-18 14:39:53.046 Should be local only query: GetKeyframePositions
> 2010-10-18 14:39:53.046 Dec: DoFastForward(): desiredFrame(28799) > 
> last_frame(1277)
> 2010-10-18 14:39:53.047 Dec: DoFastForward(): Desired frame is way 
> past the end of the keyframe map!
>             Seeking to last keyframe instead.
> 2010-10-18 14:39:53.047 [h264 @ 0x7fd701601380]sps_id out of range
> 2010-10-18 14:39:53.047 [h264 @ 0x7fd701601380]non-existing SPS 15 
> referenced in buffering period
> 2010-10-18 14:39:53.047 [h264 @ 0x7fd701601380]non-existing PPS 
> referenced
> 2010-10-18 14:39:53.053 [h264 @ 0x7fd701601380]sps_id out of range
> 2010-10-18 14:39:53.053 [h264 @ 0x7fd701601380]non-existing SPS 31 
> referenced in buffering period
> 2010-10-18 14:39:53.053 [h264 @ 0x7fd701601380]non-existing PPS 
> referenced
>
> <snip>
>
> 2010-10-18 14:49:56.815 DevRdB(/dev/video0) Error: Poll giving up
> 2010-10-18 14:49:56.817 MPEGRec(/dev/video0) Error: Device error detected
> 2010-10-18 14:49:56.817 DevRdB(/dev/video0): Stop(): Not running.
> 2010-10-18 14:50:18.278 DevRdB(/dev/video0) Error: Poll giving up
> 2010-10-18 14:50:18.283 MPEGRec(/dev/video0) Error: Device error detected
> 2010-10-18 14:50:18.283 DevRdB(/dev/video0): Stop(): Not running.
> 2010-10-18 14:51:00.680 MPEGRec(/dev/video0) Error: StartEncoding failed
>             eno: Resource temporarily unavailable (11)
> 2010-10-18 14:51:03.681 MPEGRec(/dev/video0) Warning: Unable to set 
> audio input.
>
>
> and from dmesg below you can see where I have toggled the power off 
> and on to get the HDPVR to begin recording again. It was not turned 
> off during the recording in question. Every now and then it stops 
> recording with a failed status and I have found that just turning off 
> and back on seems to fix it.
>
> root at docbuntu:/var/log/mythtv# dmesg | grep hdpvr
> [   15.597023] hdpvr 1-4:1.0: untested firmware version 0x15, the 
> driver might not work
> [   15.910861] hdpvr 1-4:1.0: device now attached to /dev/video0
> [   15.910880] usbcore: registered new interface driver hdpvr
> [58801.741294] hdpvr 1-4:1.0: device /dev/video0 disconnected
> [58810.718062] hdpvr 1-4:1.0: untested firmware version 0x15, the 
> driver might not work
> [58811.030881] hdpvr 1-4:1.0: device now attached to /dev/video0
> [255658.340037] hdpvr 1-4:1.0: device /dev/video0 disconnected
> [255665.098739] hdpvr 1-4:1.0: untested firmware version 0x15, the 
> driver mightnot work
> [255665.411734] hdpvr 1-4:1.0: device now attached to /dev/video0
> root at docbuntu:/var/log/mythtv#
>
Post your computer stats:

2010-10-18 14:00:28.007 JobQueue: Commercial Flagging Starting for 
Comedy Central Presents recorded from channel 2107 at Mon Oct 18 
14:00:00 2010
2010-10-18 13:59:57.211 Started recording: The Closer "Mom Duty": 
channel 2138 on cardid 12, sourceid 2
2010-10-18 14:00:33.009 ProgramInfo(): Updated pathname '':'' -> 
'2138_20101018140000.mpg'
2010-10-18 14:00:33.011 JobQueue: Commercial Flagging Starting for The 
Closer "Mom Duty" recorded from channel 2138 at Mon Oct 18 14:00:00 2010

I really  think you are overtaxing your computer..You are recording The 
Closer plus Commerical flagging 2 recordings...  I would turn off auto 
start commercial detection at the start of a recording and see if that 
doesn't help solve your problem...




More information about the mythtv-users mailing list