[mythtv-users] Dual HDPVR woes

[Andrew Theurer]

I guess add me to the list of people having hdpvr problems.  I scanned
the archives for related problems, but I am not quite sure this is the
same:

I have 2 hdpvr devices attached to 2 directTV STBs via component and
analog stereo.  They had been working more or less OK for several
months.  At one point I had to add a cron job to power them off/on
every night, as once in a while they would simply lock up.  Recently
I've had problems that occur almost every day, usually within 10-20
minutes of a recording.  It seems to happen when both are in use, but
not am not 100% sure.  When this happens, I get syslog errors like:

Mar 21 20:00:03 media kernel: [436876.767788] hdpvr 3-3:1.0: config
call request for value 0x1500 returned 1
Mar 21 20:00:03 media kernel: [436876.771797] hdpvr 3-3:1.0: config
call request for value 0x1700 returned 1
Mar 21 20:00:04 media kernel: [436878.687708] hdpvr 2-3:1.0: config
call request for value 0x1500 returned 1
Mar 21 20:00:04 media kernel: [436878.691703] hdpvr 2-3:1.0: config
call request for value 0x1700 returned 1
Mar 21 20:00:12 media kernel: [436886.241792] hdpvr 3-3:1.0: config
call request for value 0x2900 returned 1
Mar 21 20:00:12 media kernel: [436886.248787] hdpvr 3-3:1.0: config
call request for value 0x2a00 returned 1
Mar 21 20:00:12 media kernel: [436886.255753] hdpvr 3-3:1.0: config
call request for value 0x2c00 returned 1
Mar 21 20:00:12 media kernel: [436886.262784] hdpvr 3-3:1.0: config
call request for value 0x2b00 returned 1
Mar 21 20:00:12 media kernel: [436886.668048] hdpvr 3-3:1.0: config
call request for value 0x700 returned 1
Mar 21 20:00:12 media kernel: [436886.712752] hdpvr 3-3:1.0: config
call request for value 0x800 returned 1
Mar 21 20:00:12 media kernel: [436886.712800] hdpvr 3-3:1.0: transmit
worker exited
Mar 21 20:00:13 media kernel: [436887.142831] hdpvr 2-3:1.0: config
call request for value 0x2900 returned 1
Mar 21 20:00:13 media kernel: [436887.149828] hdpvr 2-3:1.0: config
call request for value 0x2a00 returned 1
Mar 21 20:00:13 media kernel: [436887.156863] hdpvr 2-3:1.0: config
call request for value 0x2c00 returned 1
Mar 21 20:00:13 media kernel: [436887.163813] hdpvr 2-3:1.0: config
call request for value 0x2b00 returned 1
Mar 21 20:00:15 media kernel: [436889.359041] hdpvr 3-3:1.0: config
call request for value 0x2900 returned 1
Mar 21 20:00:15 media kernel: [436889.365899] hdpvr 3-3:1.0: config
call request for value 0x2a00 returned 1
Mar 21 20:00:15 media kernel: [436889.371890] hdpvr 3-3:1.0: config
call request for value 0x2c00 returned 1
Mar 21 20:00:15 media kernel: [436889.377891] hdpvr 3-3:1.0: config
call request for value 0x2b00 returned 1
Mar 21 20:00:16 media kernel: [436890.032900] hdpvr 3-3:1.0: config
call request for value 0x700 returned 1
Mar 21 20:00:17 media kernel: [436890.994450] hdpvr 2-3:1.0: config
call request for value 0x700 returned 1
Mar 21 20:00:17 media kernel: [436891.032096] hdpvr 2-3:1.0: config
call request for value 0x800 returned 1
Mar 21 20:00:17 media kernel: [436891.032142] hdpvr 2-3:1.0: transmit
worker exited
Mar 21 20:00:20 media kernel: [436893.788477] hdpvr 2-3:1.0: config
call request for value 0x2900 returned 1
Mar 21 20:00:20 media kernel: [436893.794468] hdpvr 2-3:1.0: config
call request for value 0x2a00 returned 1
Mar 21 20:00:20 media kernel: [436893.800513] hdpvr 2-3:1.0: config
call request for value 0x2c00 returned 1
Mar 21 20:00:20 media kernel: [436893.806460] hdpvr 2-3:1.0: config
call request for value 0x2b00 returned 1
Mar 21 20:00:20 media kernel: [436893.811465] hdpvr 2-3:1.0: config
call request for value 0x1200 returned 1
Mar 21 20:00:20 media kernel: [436894.368605] hdpvr 2-3:1.0: config
call request for value 0x700 returned 1
Mar 21 20:05:02 media CRON[23649]: (root) CMD (command -v debian-sa1 >
/dev/null && debian-sa1 1 1)
Mar 21 20:09:01 media CRON[23654]: (root) CMD (  [ -x
/usr/lib/php5/maxlifetime ] && [ -d /var/lib/php5 ] && find
/var/lib/php5/ -depth -mindepth 1 -maxdepth 1 -type f -cmin
+$(/usr/lib/php5/maxlifetime) -delete)
Mar 21 20:10:01 media CRON[23663]: (root) CMD ([ -x
/etc/init.d/mythtv-status ] && /etc/init.d/mythtv-status reload >
/dev/null)
Mar 21 20:15:02 media CRON[23671]: (root) CMD (command -v debian-sa1 >
/dev/null && debian-sa1 1 1)
Mar 21 20:17:01 media CRON[23679]: (root) CMD (   cd / && run-parts
--report /etc/cron.hourly)
Mar 21 20:18:33 media kernel: [437987.329236] hdpvr 2-3:1.0: config
call request for value 0x800 returned 1
Mar 21 20:18:33 media kernel: [437987.329281] hdpvr 2-3:1.0: transmit
worker exited
Mar 21 20:18:34 media kernel: [437987.791364] hdpvr 2-3:1.0: config
call request for value 0x700 returned 1
Mar 21 20:18:34 media kernel: [437987.999212] hdpvr 3-3:1.0: config
call request for value 0x800 returned 1
Mar 21 20:18:34 media kernel: [437987.999259] hdpvr 3-3:1.0: transmit
worker exited
Mar 21 20:18:34 media kernel: [437988.513583] hdpvr 3-3:1.0: config
call request for value 0x700 returned 1
Mar 21 20:18:38 media kernel: [437991.937235] hdpvr 2-3:1.0: config
call request for value 0x800 returned 1
Mar 21 20:18:38 media kernel: [437991.937274] hdpvr 2-3:1.0: transmit
worker exited
Mar 21 20:18:38 media kernel: [437992.360123] hdpvr 2-3:1.0: no video
signal at input 0
Mar 21 20:18:38 media kernel: [437992.400958] hdpvr 3-3:1.0: config
call request for value 0x800 returned 1
Mar 21 20:18:38 media kernel: [437992.401004] hdpvr 3-3:1.0: transmit
worker exited
Mar 21 20:18:39 media kernel: [437992.830078] hdpvr 3-3:1.0: no video
signal at input 0

Mythbackend log:

2012-03-21 20:18:33.475 DevRdB(/dev/v4l/video1) Error: Poll giving up
2012-03-21 20:18:33.519 MPEGRec(/dev/v4l/video1) Error: Device error detected
2012-03-21 20:18:34.114 DevRdB(/dev/v4l/video0) Error: Poll giving up
2012-03-21 20:18:34.208 MPEGRec(/dev/v4l/video0) Error: Device error detected
2012-03-21 20:18:38.069 DevRdB(/dev/v4l/video1) Error: Poll giving up
2012-03-21 20:18:38.147 MPEGRec(/dev/v4l/video1) Error: Device error detected
2012-03-21 20:18:38.536 DevRdB(/dev/v4l/video0) Error: Poll giving up
2012-03-21 20:18:38.610 MPEGRec(/dev/v4l/video0) Error: Device error detected
2012-03-21 20:18:38.616 MPEGRec(/dev/v4l/video1) Error: StartEncoding failed
                        eno: Resource temporarily unavailable (11)
2012-03-21 20:18:39.086 MPEGRec(/dev/v4l/video0) Error: StartEncoding failed
                        eno: Resource temporarily unavailable (11)


At 20:00 is when the recordings started, and it seemed to work until
20:18, when both failed at about the same time.  I see the "no video
signal at input X".  Does that mean this is strictly a problem with
the source (the DirecTV STB) or could there be a problem in the
driver?  Are there any concerns about the various "config call request
for value Z returned 1" listed above?

BTW, A couple months ago DirecTV decided to start having their STBs
kill the video if there was not a IR input signal within so long (but
for some reason they decided to not consider http requests when doing
this).  I disabled that back then which fixed that problem of "no
video signal".

FWIW, in an attempt to make this more reliable, I also added 2 new USB
PCI cards, each one dedicated to a hdpvr, which did not help:

# lsusb -t
/:  Bus 08.Port 1: Dev 1, Class=root_hub, Driver=ohci_hcd/1p, 12M
/:  Bus 07.Port 1: Dev 1, Class=root_hub, Driver=ohci_hcd/2p, 12M
/:  Bus 06.Port 1: Dev 1, Class=root_hub, Driver=ohci_hcd/1p, 12M
/:  Bus 05.Port 1: Dev 1, Class=root_hub, Driver=ohci_hcd/2p, 12M
/:  Bus 04.Port 1: Dev 1, Class=root_hub, Driver=ohci_hcd/10p, 12M
/:  Bus 03.Port 1: Dev 1, Class=root_hub, Driver=ehci_hcd/3p, 480M
    |__ Port 3: Dev 14, If 0, Class=vend., Driver=hdpvr, 480M
/:  Bus 02.Port 1: Dev 1, Class=root_hub, Driver=ehci_hcd/3p, 480M
    |__ Port 3: Dev 14, If 0, Class=vend., Driver=hdpvr, 480M
/:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=ehci_hcd/10p, 480M


Any suggestions?

-Andrew