[mythtv-users] HDPVR unable to record after upgrading to r20007 - in trunk

Wed Feb 18 02:05:17 UTC 2009

Ok, so I rebuilt under r2009 with the fixed patch and had no luck.  Turning
on verbose logging for record gave me the following output:

2009-02-17 20:40:28.598 mythbackend version: trunk [20009M] www.mythtv.org
2009-02-17 20:40:28.601 Using runtime prefix = /usr
2009-02-17 20:40:28.602 Empty LocalHostName.
2009-02-17 20:40:28.603 Using localhost value of MythTV
2009-02-17 20:40:28.607 mythbackend version: trunk [20009M] www.mythtv.org
2009-02-17 20:40:28.613 Using runtime prefix = /usr
2009-02-17 20:40:28.614 Empty LocalHostName.
2009-02-17 20:40:28.615 Using localhost value of MythTV
2009-02-17 20:40:28.618 New DB connection, total: 1
2009-02-17 20:40:28.627 Connected to database 'mythconverg' at host:
localhost
2009-02-17 20:40:28.629 New DB connection, total: 1
2009-02-17 20:40:28.631 Closing DB connection named 'DBManager0'
2009-02-17 20:40:28.638 Connected to database 'mythconverg' at host:
localhost
2009-02-17 20:40:28.642 Connected to database 'mythconverg' at host:
localhost
2009-02-17 20:40:28.647 Current Schema Version: 1228
2009-02-17 20:40:28.648 Closing DB connection named 'DBManager0'
2009-02-17 20:40:28.651 New DB connection, total: 2
2009-02-17 20:40:28.657 Connected to database 'mythconverg' at host:
localhost
2009-02-17 20:40:28.672 Current Schema Version: 1228
2009-02-17 20:40:28.657 Connected to database 'mythconverg' at host:
localhost
2009-02-17 20:40:28.675 New DB connection, total: 2
2009-02-17 20:40:28.690 Connected to database 'mythconverg' at host:
localhost
2009-02-17 20:40:28.692 Preview Error: Previewer file
'/media/DVR/recordings/2024_20090217194000.mpg' is not valid.
2009-02-17 20:40:28.706 Preview Error: Run() file not local:
'/media/DVR/recordings/2024_20090217194000.mpg'
2009-02-17 20:40:28.707 Preview Error: Previewer file
'/media/DVR/recordings/2024_20090217183800.mpg' is not valid.
2009-02-17 20:40:28.718 Preview Error: Preview process not ok.
            fileinfo(/media/DVR/recordings/2024_20090217194000.mpg.png)
exists: 0 readable: 0 size: 0
2009-02-17 20:40:28.719 Preview Error: Run() file not local:
'/media/DVR/recordings/2024_20090217183800.mpg'
2009-02-17 20:40:28.747 Preview Error: Preview process not ok.
            fileinfo(/media/DVR/recordings/2024_20090217183800.mpg.png)
exists: 0 readable: 0 size: 0
2009-02-17 20:40:29.107 MainServer::ANN Monitor
2009-02-17 20:40:29.113 adding: mythtv as a client (events: 0)
2009-02-17 20:40:32.996 MainServer::ANN Monitor
2009-02-17 20:40:32.998 adding: mythtv as a client (events: 0)
2009-02-17 20:40:33.692 MainServer::ANN Monitor
2009-02-17 20:40:33.693 adding: mythtv as a client (events: 0)
2009-02-17 20:40:33.724 MainServer::ANN Monitor
2009-02-17 20:40:33.732 adding: mythtv as a client (events: 0)
2009-02-17 20:40:38.618 MainServer::ANN Monitor
2009-02-17 20:40:38.621 adding: mythtv as a client (events: 0)
2009-02-17 20:40:39.323 MainServer::ANN Monitor
2009-02-17 20:40:39.324 adding: mythtv as a client (events: 0)
2009-02-17 20:40:39.353 MainServer::ANN Monitor
2009-02-17 20:40:39.355 adding: mythtv as a client (events: 0)
2009-02-17 20:40:40.759 Reschedule requested for id 0.
2009-02-17 20:40:41.357 Scheduled 176 items in 0.6 = 0.01 match + 0.57 place
2009-02-17 20:40:42.309 MainServer::ANN Monitor
2009-02-17 20:40:42.312 adding: mythtv as a client (events: 0)
2009-02-17 20:40:42.489 MainServer::ANN Monitor
2009-02-17 20:40:42.490 adding: mythtv as a client (events: 0)
2009-02-17 20:40:43.707 MainServer::ANN Monitor
2009-02-17 20:40:43.709 adding: mythtv as a client (events: 0)
2009-02-17 20:40:46.379 Reschedule requested for id 0.
2009-02-17 20:40:46.985 Scheduled 176 items in 0.6 = 0.01 match + 0.58 place
2009-02-17 20:40:56.538 MainServer::ANN Monitor
2009-02-17 20:40:56.541 adding: mythtv as a client (events: 0)
2009-02-17 20:40:57.239 MainServer::ANN Monitor
2009-02-17 20:40:57.241 adding: mythtv as a client (events: 0)
2009-02-17 20:40:57.242 Reschedule requested for id 393.
2009-02-17 20:40:57.490 MainServer::ANN Monitor
2009-02-17 20:40:57.494 adding: mythtv as a client (events: 0)
2009-02-17 20:40:57.842 Scheduled 176 items in 0.6 = 0.01 match + 0.58 place
2009-02-17 20:41:08.707 Reschedule requested for id 394.
2009-02-17 20:41:09.307 Scheduled 177 items in 0.6 = 0.05 match + 0.54 place
2009-02-17 20:41:09.311 TVRec(3): RecordPending on inputid 1
2009-02-17 20:41:09.313 TVRec(3): StartRecording(ESPNEWS)
2009-02-17 20:41:09.314 TVRec(3): ASK_RECORDING 3 0 0 0
2009-02-17 20:41:09.378 TVRec(3): StartedRecording(0x1c3ae40)
fn(/media/DVR/recordings/2072_20090217204100.mpg)
2009-02-17 20:41:09.386 TVRec(3): ClearFlags(CancelNextRecording,) ->
RunMainLoop,
2009-02-17 20:41:09.386 TVRec(3): Changing from None to RecordingOnly
2009-02-17 20:41:09.391 TVRec(3):
ClearFlags(FrontendReady,CancelNextRecording,) -> RunMainLoop,
2009-02-17 20:41:09.392 TVRec(3): Request: Program(yes) channel() input()
flags(Recording,)
2009-02-17 20:41:09.395 TVRec(3): HW Tuner: 3->3
2009-02-17 20:41:09.396 TVRec(3): ClearFlags(PENDINGACTIONS,) ->
RunMainLoop,
2009-02-17 20:41:09.397 TVRec(3): No recorder yet, calling TuningFrequency
2009-02-17 20:41:10.478 ret_pid(0) child(12017) status(0x0)
2009-02-17 20:41:11.479 ret_pid(0) child(12017) status(0x0)
2009-02-17 20:41:11.754 ret_pid(12017) child(12017) status(0x0)
2009-02-17 20:41:11.754 External Tuning program exited with no error
2009-02-17 20:41:11.835 TVRec(3): ClearFlags(NeedToStartRecorder,) ->
RunMainLoop,
2009-02-17 20:41:11.836 TVRec(3): SetFlags(NeedToStartRecorder,) ->
RunMainLoop,NeedToStartRecorder,
2009-02-17 20:41:11.836 TVRec(3): Starting Recorder
2009-02-17 20:41:11.873 Using profile 'Default' to record
2009-02-17 20:41:11.881 RecBase(3:/dev/video0): SetRingBuffer(0x1a9c400)
'/media/DVR/recordings/2072_20090217204100.mpg'
2009-02-17 20:41:11.882 RecBase(3:/dev/video0): SetRecording(0x1c3ae40)
title(ESPNEWS)
2009-02-17 20:41:11.969 MPEGRec(/dev/video0): usingv4l2(1) has_v4l2_vbi(0)
has_buggy_vbi(1)
2009-02-17 20:41:11.980 AutoExpire: CalcParams(): Max required Free Space:
6.0 GB w/freq: 15 min
2009-02-17 20:41:11.985 Started recording: ESPNEWS: channel 2072 on cardid
3, sourceid 2
2009-02-17 20:41:12.065 DevRdB(/dev/video0): buffer size 9400 KB
2009-02-17 20:41:12.089 MPEGRec(/dev/video0): DRB ready
2009-02-17 20:41:12.090 MPEGRec(/dev/video0): SetStreamData(0x1b9f8b0) --
begin
2009-02-17 20:41:12.091 MPEGRec(/dev/video0): SetStreamData(0x1b9f8b0) --
end 1
2009-02-17 20:41:12.096 MPEGRec(/dev/video0): HandleSingleProgramPAT(NULL)
2009-02-17 20:41:12.108 MPEGRec(/dev/video0): Initial startup of recorder
2009-02-17 20:41:12.109 MPEGRec(/dev/video0): Checking Resolution
2009-02-17 20:41:12.111 TVRec(3): SetFlags(RecorderRunning,RingBufferReady,)
-> RunMainLoop,NeedToStartRecorder,RecorderRunning,RingBufferReady,
2009-02-17 20:41:12.116 TVRec(3): ClearFlags(NeedToStartRecorder,) ->
RunMainLoop,RecorderRunning,RingBufferReady,
2009-02-17 20:41:17.483 MPEGRec(/dev/video0): Got Resolution 1280x720
2009-02-17 20:41:17.488 MPEGRec(/dev/video0): StartEncoding
2009-02-17 20:41:17.489 MPEGRec(/dev/video0): Encoding started
2009-02-17 20:41:17.743 DevRdB(/dev/video0) Error: Poll timeout (1)
2009-02-17 20:41:18.259 DevRdB(/dev/video0) Error: Poll timeout (3)
2009-02-17 20:41:18.771 DevRdB(/dev/video0) Error: Poll timeout (5)
2009-02-17 20:41:19.287 DevRdB(/dev/video0) Error: Poll timeout (7)
2009-02-17 20:41:19.795 DevRdB(/dev/video0) Error: Poll timeout (9)
2009-02-17 20:41:20.051 DevRdB(/dev/video0) Error: Poll giving up
2009-02-17 20:41:20.052 DevRdB(/dev/video0): fill_ringbuffer: error state
2009-02-17 20:41:20.055 MPEGRec(/dev/video0) Error: Device error detected
2009-02-17 20:41:20.060 MPEGRec(/dev/video0): RestartEncoding
2009-02-17 20:41:20.061 DevRdB(/dev/video0): Stop(): Not running.
2009-02-17 20:41:20.062 MPEGRec(/dev/video0): StopEncoding
2009-02-17 20:41:21.475 MPEGRec(/dev/video0): Encoding stopped
2009-02-17 20:41:21.476 MPEGRec(/dev/video0): Checking Resolution
2009-02-17 20:41:27.091 MPEGRec(/dev/video0): Got Resolution 1280x720
2009-02-17 20:41:27.093 MPEGRec(/dev/video0): StartEncoding
2009-02-17 20:41:27.093 MPEGRec(/dev/video0): Encoding started
2009-02-17 20:41:27.347 DevRdB(/dev/video0) Error: Poll timeout (1)
2009-02-17 20:41:27.863 DevRdB(/dev/video0) Error: Poll timeout (3)
2009-02-17 20:41:28.375 DevRdB(/dev/video0) Error: Poll timeout (5)
2009-02-17 20:41:28.887 DevRdB(/dev/video0) Error: Poll timeout (7)
2009-02-17 20:41:29.399 DevRdB(/dev/video0) Error: Poll timeout (9)
2009-02-17 20:41:29.655 DevRdB(/dev/video0) Error: Poll giving up
2009-02-17 20:41:29.656 DevRdB(/dev/video0): fill_ringbuffer: error state
2009-02-17 20:41:29.659 MPEGRec(/dev/video0) Error: Device error detected
2009-02-17 20:41:29.664 MPEGRec(/dev/video0): RestartEncoding
2009-02-17 20:41:29.665 DevRdB(/dev/video0): Stop(): Not running.
2009-02-17 20:41:29.672 MPEGRec(/dev/video0): StopEncoding
2009-02-17 20:41:31.091 MPEGRec(/dev/video0): Encoding stopped

It looks like I am getting all sorts of Poll timeout errors.  I do have the
latest "DeviceReadBuffer-polltimeout.2.patch<http://svn.mythtv.org/trac/attachment/ticket/5604/DeviceReadBuffer-polltimeout.2.patch>"
applied and have verified it took by parsing the code manually.  I've also
tried another power-cycle of the HD-PVR with no success.  Any other
suggestions?

Thanks again for the help!
John

On Mon, Feb 16, 2009 at 9:13 PM, John Hoyt <john.hoyt at gmail.com> wrote:

> Thanks!
>
> As or the suggestion, I already tried power-cycling the HDPVR, and believe
> it to be a mythtvbackend problem as I can record video by running "cat
> /dev/video0 < test.ts" but can not record it from mythtv.  Also after a
> mythbackend crash, I can get the HDPVR to record (again using cat) by
> unloading and reloading the module without a power cycle.
>
> John
>
> On Mon, Feb 16, 2009 at 9:03 PM, john <jppoet at gmail.com> wrote:
>
>>
>> On Feb 16, 2009, at 6:51 PM, john wrote:
>>
>>
>> On Feb 16, 2009, at 6:16 PM, John Hoyt wrote:
>>
>>
>>
>> I uploaded a fixed version of that patch to the ticket.  However, reading
>> your log entries, I don't think that is your problem.  Have you tried
>> power-cycling your HD-PVR?
>>
>> John
>>
>>
>>
>> _______________________________________________
>> mythtv-users mailing list
>> mythtv-users at mythtv.org
>> http://mythtv.org/cgi-bin/mailman/listinfo/mythtv-users
>>
>>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mythtv.org/pipermail/mythtv-users/attachments/20090217/678c69c4/attachment.htm>