[mythtv-users] (only some) failed recordings on my HVR-950Q

Brian J. Murrell brian at interlinx.bc.ca
Mon Sep 27 11:36:18 UTC 2010


So, I thought my HVR-950Q was performing wonderfully in my backend
(r26407 on 0.23.1-fixes at the time) recording up to 3 programs in
parallel with multirec but in reviewing my recordings I am finding that
there are times when the backend says it's recording a program but
nothing is actually written to disk.  The first (of two) occurrences I
have on hand are:

2  1h recordings at 21:00
1 30m recording at 21:31
2  1h recordings at 22:00

So starting with 2 recordings, going to 3 at 21;31 followed by 2
recordings (all resulted in no recording file on disk).

The second occurrence was the next day:

1 30m recording at 21:30
1  1h recording at 22:00
1  1h recording at 22:01

Again, all 3 resulted in no recording file on disk.

All programs before or after it recorded fine on the same tuner so it
seems this issue is very hit-or-miss.

In these cases the scheduler is not simply forgetting to record (as per
my other message) but in this case it's actually going through the
motions of recording, just not actually writing anything to disk (from
the first occurrence):

2010-09-20 20:59:00.448 Reschedule requested for id 0.
2010-09-20 20:59:15.688 Scheduled 914 items in 15.2 = 0.00 match + 15.16 place
2010-09-20 20:59:15.956 scheduler: Scheduled items: Scheduled 914 items in 15.2 = 0.00 match + 15.16 place
2010-09-20 20:59:29.375 TVRec(1): ASK_RECORDING 1 29 0 0
2010-09-20 20:59:29.376 TVRec(1): ASK_RECORDING 1 29 0 0
2010-09-20 20:59:29.422 TVRec(2): ASK_RECORDING 2 29 0 0
2010-09-20 20:59:29.423 TVRec(2): ASK_RECORDING 2 29 0 0
2010-09-20 20:59:29.870 TVRec(3): ASK_RECORDING 3 29 0 0
2010-09-20 20:59:29.871 TVRec(3): ASK_RECORDING 3 29 0 0
2010-09-20 21:00:00.419 TVRec(1): Changing from RecordingOnly to None
2010-09-20 21:00:00.553 ProgramInfo(): Updated pathname '':'' -> '2003_20100920200000.mpg'
2010-09-20 21:00:00.614 Finished recording House "Now What": channel 2003
2010-09-20 21:00:01.099 scheduler: Finished recording: House "Now What": channel 2003
2010-09-20 21:00:01.153 ProgramInfo(): Updated pathname '':'' -> '2003_20100920200000.mpg'
2010-09-20 21:00:01.259 MainServer::ANN Monitor
2010-09-20 21:00:01.320 adding: pvrfe as a client (events: 0)
2010-09-20 21:00:01.317 ProgramInfo(2003_20100920200000.mpg), Error: Unknown type, recording width was 720
2010-09-20 21:00:01.695 ProgramInfo(): Updated pathname '':'' -> '2003_20100920200000.mpg'
2010-09-20 21:00:01.836 Finished recording House "Now What": channel 2003
2010-09-20 21:00:01.912 ProgramInfo(): Updated pathname '':'' -> '2003_20100920200000.mpg'
2010-09-20 21:00:02.014 MainServer::ANN Monitor
2010-09-20 21:00:02.145 adding: pvrfe as a client (events: 0)
2010-09-20 21:00:02.046 ProgramInfo(): Updated pathname '':'' -> '2003_20100920200000.mpg'
2010-09-20 21:00:02.812 ProgramInfo(): Updated pathname '':'' -> '2011_20100920210000.mpg'
2010-09-20 21:00:03.590 TVRec(1): Changing from None to RecordingOnly
2010-09-20 21:00:03.655 RingBuf(/storage1/2003_20100920200000.mpg): Waited 2.0 seconds for data to become available...
2010-09-20 21:00:03.656 TVRec(1): HW Tuner: 1->1
2010-09-20 21:00:06.773 mythbackend version: branches/release-0-23-fixes [26407] www.mythtv.org
2010-09-20 21:00:06.776 mythbackend version: branches/release-0-23-fixes [26407] www.mythtv.org
2010-09-20 21:00:06.778 mythbackend version: branches/release-0-23-fixes [26407] www.mythtv.org
2010-09-20 21:00:06.907 Using runtime prefix = /usr
2010-09-20 21:00:06.908 Using runtime prefix = /usr
2010-09-20 21:00:06.910 Using configuration directory = /home/mythtv/.mythtv
2010-09-20 21:00:06.985 Using configuration directory = /home/mythtv/.mythtv
2010-09-20 21:00:06.988 Using runtime prefix = /usr
2010-09-20 21:00:07.008 Using localhost value of pvr
2010-09-20 21:00:07.009 Using localhost value of pvr
2010-09-20 21:00:07.015 Using configuration directory = /home/mythtv/.mythtv
2010-09-20 21:00:07.110 Using localhost value of pvr
2010-09-20 21:00:07.324 New DB connection, total: 1
2010-09-20 21:00:07.324 New DB connection, total: 1
2010-09-20 21:00:07.325 New DB connection, total: 1
2010-09-20 21:00:07.550 Connected to database 'mythconverg' at host: localhost
2010-09-20 21:00:07.551 Connected to database 'mythconverg' at host: localhost
2010-09-20 21:00:07.555 Closing DB connection named 'DBManager0'
2010-09-20 21:00:07.556 Closing DB connection named 'DBManager0'
2010-09-20 21:00:07.559 Connected to database 'mythconverg' at host: localhost
2010-09-20 21:00:07.560 Connected to database 'mythconverg' at host: localhost
2010-09-20 21:00:07.571 Current MythTV Schema Version (DBSchemaVer): 1254
2010-09-20 21:00:07.572 Current MythTV Schema Version (DBSchemaVer): 1254
2010-09-20 21:00:07.575 Connected to database 'mythconverg' at host: localhost
2010-09-20 21:00:07.621 Closing DB connection named 'DBManager0'
2010-09-20 21:00:07.624 ProgramInfo(): Updated pathname '':'' -> '2003_20100920200000.mpg'
2010-09-20 21:00:07.627 Connected to database 'mythconverg' at host: localhost
2010-09-20 21:00:07.628 ProgramInfo(): Updated pathname '':'' -> '2003_20100920200000.mpg'
2010-09-20 21:00:07.683 Current MythTV Schema Version (DBSchemaVer): 1254
2010-09-20 21:00:07.693 ProgramInfo(): Updated pathname '':'' -> '2003_20100920200000.mpg'
2010-09-20 21:00:08.105 ~MythContext waiting for threads to exit.
2010-09-20 21:00:08.493 mythbackend version: branches/release-0-23-fixes [26407] www.mythtv.org
2010-09-20 21:00:08.496 Using runtime prefix = /usr
2010-09-20 21:00:08.496 Using configuration directory = /home/mythtv/.mythtv
2010-09-20 21:00:08.498 Using localhost value of pvr
2010-09-20 21:00:08.514 New DB connection, total: 1
2010-09-20 21:00:08.519 Connected to database 'mythconverg' at host: localhost
2010-09-20 21:00:08.521 Closing DB connection named 'DBManager0'
2010-09-20 21:00:08.523 Connected to database 'mythconverg' at host: localhost
2010-09-20 21:00:08.532 Current MythTV Schema Version (DBSchemaVer): 1254
2010-09-20 21:00:08.541 ProgramInfo(): Updated pathname '':'' -> '2003_20100920200000.mpg'
2010-09-20 21:00:10.590 AFD: Opened codec 0x93677d0, id(MPEG2VIDEO) type(Video)
2010-09-20 21:00:10.595 AFD: Opened codec 0x91153c0, id(MPEG2VIDEO) type(Video)
2010-09-20 21:00:10.594 AFD: Opened codec 0x841b6b0, id(MPEG2VIDEO) type(Video)
2010-09-20 21:00:10.600 AFD: codec AC3 has 2 channels
2010-09-20 21:00:10.601 AFD: Opened codec 0x936be80, id(AC3) type(Audio)
2010-09-20 21:00:10.602 AFD: codec AC3 has 2 channels
2010-09-20 21:00:10.602 AFD: codec AC3 has 2 channels
2010-09-20 21:00:10.604 AFD: Opened codec 0x841ae20, id(AC3) type(Audio)
2010-09-20 21:00:10.605 AFD: Opened codec 0x9116b40, id(AC3) type(Audio)
2010-09-20 21:00:10.606 AFD: codec AC3 has 2 channels
2010-09-20 21:00:10.608 AFD: codec AC3 has 2 channels
2010-09-20 21:00:10.608 AFD: codec AC3 has 2 channels
2010-09-20 21:00:10.608 AFD: Opened codec 0x936c400, id(AC3) type(Audio)
2010-09-20 21:00:10.610 AFD: Opened codec 0x9117290, id(AC3) type(Audio)
2010-09-20 21:00:10.611 AFD: Opened codec 0x8420dd0, id(AC3) type(Audio)
2010-09-20 21:00:11.081 AFD: Opened codec 0x8f34120, id(MPEG2VIDEO) type(Video)
2010-09-20 21:00:11.244 AFD: codec AC3 has 2 channels
2010-09-20 21:00:11.345 AFD: Opened codec 0x8f346e0, id(AC3) type(Audio)
2010-09-20 21:00:11.373 AFD: codec AC3 has 2 channels
2010-09-20 21:00:11.433 AFD: Opened codec 0x8f36050, id(AC3) type(Audio)
2010-09-20 21:00:12.802 Preview: Grabbed preview '/storage1/2003_20100920200000.mpg' 720x480 at 64s
2010-09-20 21:00:12.799 Preview: Grabbed preview '/storage1/2003_20100920200000.mpg' 720x480 at 64s
2010-09-20 21:00:12.808 Preview: Grabbed preview '/storage1/2003_20100920200000.mpg' 720x480 at 64s
2010-09-20 21:00:12.809 Preview: Grabbed preview '/storage1/2003_20100920200000.mpg' 720x480 at 64s
2010-09-20 21:00:13.240 ~MythContext waiting for threads to exit.
2010-09-20 21:00:13.241 ~MythContext waiting for threads to exit.
2010-09-20 21:00:13.242 ~MythContext waiting for threads to exit.
2010-09-20 21:00:13.243 ~MythContext waiting for threads to exit.
2010-09-20 21:00:13.363 commflag: Commercial Flagging Finished: House "Now What" recorded from channel 2003 at Mon Sep 20 20:00:00 2010 (0 commercial break(s))
2010-09-20 21:00:25.604 AutoExpire: CalcParams(): Max required Free Space: 3.0 GB w/freq: 14 min
2010-09-20 21:00:25.606 Started recording: The Event "Pilot": channel 2011 on cardid 1, sourceid 2
2010-09-20 21:00:25.610 scheduler: Last message repeated 1 times: Finished recording: House "Now What": channel 2003
2010-09-20 21:00:25.614 scheduler: Started recording: The Event "Pilot": channel 2011 on cardid 1, sourceid 2
2010-09-20 21:00:25.689 ProgramInfo(): Updated pathname '':'' -> '2003_20100920200000.mpg'
2010-09-20 21:00:25.692 ProgramInfo(): Updated pathname '':'' -> '2003_20100920200000.mpg'
2010-09-20 21:00:25.695 ProgramInfo(): Updated pathname '':'' -> '2003_20100920200000.mpg'
2010-09-20 21:00:25.698 ProgramInfo(): Updated pathname '':'' -> '2003_20100920200000.mpg'
2010-09-20 21:00:25.704 MainServer, Warning: Unknown socket closing MythSocket(0x98e89f8)
2010-09-20 21:00:25.704 MainServer, Warning: Unknown socket closing MythSocket(0x98e89f8)
2010-09-20 21:00:25.705 MainServer::ANN Playback
2010-09-20 21:00:25.706 adding: pvrfe as a client (events: 0)
2010-09-20 21:00:25.707 MainServer, Warning: Unknown socket closing MythSocket(0x99a46c8)
2010-09-20 21:00:25.707 MythSocket(98e89f8:-1): writeStringList: Error, socket went unconnected.
			We wrote 0 of 24 bytes with 1 errors
2010-09-20 21:00:25.707 MainServer::HandleAnnounce FileTransfer
2010-09-20 21:00:25.710 adding: pvrfe as a remote file transfer
2010-09-20 21:00:25.708 Waiting for a process request thread.. 
2010-09-20 21:00:25.709 MythSocket(99a46c8:-1): writeStringList: Error, socket went unconnected.
			We wrote 0 of 10 bytes with 1 errors
2010-09-20 21:00:25.706 MainServer::ANN Playback
2010-09-20 21:00:25.716 adding: pvrfe as a client (events: 0)
2010-09-20 21:00:25.717 MainServer, Warning: Unknown socket closing MythSocket(0x99a1928)
2010-09-20 21:00:25.717 ProgramInfo(): Updated pathname '':'' -> '2003_20100920200000.mpg'
2010-09-20 21:00:25.715 MainServer::HandleAnnounce FileTransfer
2010-09-20 21:00:25.765 adding: pvrfe as a remote file transfer
2010-09-20 21:00:25.719 MythSocket(99a1928:-1): writeStringList: Error, socket went unconnected.
			We wrote 0 of 10 bytes with 1 errors
2010-09-20 21:00:25.769 ProgramInfo(): Updated pathname '':'' -> '2003_20100920200000.mpg'
2010-09-20 21:00:25.873 ProgramInfo(): Updated pathname '':'' -> '2024_20100920210000.mpg'
2010-09-20 21:00:26.014 TVRec(2): Changing from None to RecordingOnly
2010-09-20 21:00:26.020 TVRec(2): HW Tuner: 2->2
2010-09-20 21:00:26.072 ProgramInfo(2011_20100920210000.mpg), Error: GetPlaybackURL: '2011_20100920210000.mpg' should be local, but it can not be found.
2010-09-20 21:00:26.126 AutoExpire: CalcParams(): Max required Free Space: 3.0 GB w/freq: 7 min
2010-09-20 21:00:26.127 Started recording: Lone Star "Pilot": channel 2024 on cardid 2, sourceid 2
2010-09-20 21:00:26.131 scheduler: Started recording: Lone Star "Pilot": channel 2024 on cardid 2, sourceid 2
2010-09-20 21:00:27.092 MythSocket(9b02d38:8): writeStringList: Error, No data written on writeBlock (880 errors)
2010-09-20 21:00:27.212 Reschedule requested for id 0.
2010-09-20 21:00:37.359 Scheduled 911 items in 10.1 = 0.00 match + 10.06 place
2010-09-20 21:00:37.364 scheduler: Scheduled items: Scheduled 911 items in 10.1 = 0.00 match + 10.06 place
2010-09-20 21:02:32.978 AutoExpire: CalcParams(): Max required Free Space: 3.0 GB w/freq: 7 min
2010-09-20 21:03:02.924 MainServer::ANN Playback
2010-09-20 21:03:02.924 adding: pvrfe as a client (events: 0)
2010-09-20 21:03:02.926 MainServer::ANN Monitor
2010-09-20 21:03:02.926 adding: pvrfe as a client (events: 1)
2010-09-20 21:03:05.291 ProgramInfo(2011_20100920210000.mpg), Error: GetPlaybackURL: '2011_20100920210000.mpg' should be local, but it can not be found.
2010-09-20 21:03:05.297 ProgramInfo(2024_20100920210000.mpg), Error: GetPlaybackURL: '2024_20100920210000.mpg' should be local, but it can not be found.
2010-09-20 21:03:05.623 ProgramInfo(2024_20100920210000.mpg), Error: GetPlaybackURL: '2024_20100920210000.mpg' should be local, but it can not be found.
2010-09-20 21:03:06.217 ProgramInfo(2024_20100920210000.mpg), Error: GetPlaybackURL: '2024_20100920210000.mpg' should be local, but it can not be found.
2010-09-20 21:03:06.223 ProgramInfo(2011_20100920210000.mpg), Error: GetPlaybackURL: '2011_20100920210000.mpg' should be local, but it can not be found.
2010-09-20 21:03:06.571 ProgramInfo(2024_20100920210000.mpg), Error: GetPlaybackURL: '2024_20100920210000.mpg' should be local, but it can not be found.
2010-09-20 21:03:07.064 ProgramInfo(2024_20100920210000.mpg), Error: GetPlaybackURL: '2024_20100920210000.mpg' should be local, but it can not be found.
2010-09-20 21:03:07.069 ProgramInfo(2011_20100920210000.mpg), Error: GetPlaybackURL: '2011_20100920210000.mpg' should be local, but it can not be found.
2010-09-20 21:03:07.327 ProgramInfo(2024_20100920210000.mpg), Error: GetPlaybackURL: '2024_20100920210000.mpg' should be local, but it can not be found.
2010-09-20 21:03:08.311 ProgramInfo(2011_20100920210000.mpg), Error: GetPlaybackURL: '2011_20100920210000.mpg' should be local, but it can not be found.
2010-09-20 21:07:54.412 ProgramInfo(2024_20100920210000.mpg), Error: GetPlaybackURL: '2024_20100920210000.mpg' should be local, but it can not be found.
2010-09-20 21:08:02.749 ProgramInfo(): Updated pathname '':'' -> '1042_20100919220000.mpg'
2010-09-20 21:08:02.836 MainServer::ANN Playback
2010-09-20 21:08:02.837 adding: pvrfe as a client (events: 0)
2010-09-20 21:08:02.839 MainServer::HandleAnnounce FileTransfer
2010-09-20 21:08:02.839 adding: pvrfe as a remote file transfer
2010-09-20 21:08:02.844 ProgramInfo(): Updated pathname '':'' -> '1042_20100919220000.mpg'
2010-09-20 21:08:02.869 ProgramInfo(): Updated pathname '':'' -> '1042_20100919220000.mpg'
2010-09-20 21:08:02.924 ProgramInfo(): Updated pathname '':'' -> '1042_20100919220000.mpg'
2010-09-20 21:08:15.697 ProgramInfo(): Updated pathname '':'' -> '1042_20100919220000.mpg'
2010-09-20 21:08:15.700 ProgramInfo(): Updated pathname '':'' -> '1042_20100919220000.mpg'
2010-09-20 21:09:33.230 AutoExpire: CalcParams(): Max required Free Space: 3.0 GB w/freq: 7 min
2010-09-20 21:16:33.473 AutoExpire: CalcParams(): Max required Free Space: 3.0 GB w/freq: 7 min
2010-09-20 21:17:04.621 MainServer::ANN Monitor
2010-09-20 21:17:04.624 adding: pvr as a client (events: 0)
2010-09-20 21:17:07.022 ProgramInfo(2011_20100920210000.mpg), Error: GetPlaybackURL: '2011_20100920210000.mpg' should be local, but it can not be found.
2010-09-20 21:17:07.025 ProgramInfo(2024_20100920210000.mpg), Error: GetPlaybackURL: '2024_20100920210000.mpg' should be local, but it can not be found.
2010-09-20 21:20:09.272 MainServer::ANN Playback
2010-09-20 21:20:09.273 adding: jenny as a client (events: 0)
2010-09-20 21:20:09.559 ProgramInfo(2011_20100920210000.mpg), Error: GetPlaybackURL: '2011_20100920210000.mpg' should be local, but it can not be found.
2010-09-20 21:20:09.561 ProgramInfo(2024_20100920210000.mpg), Error: GetPlaybackURL: '2024_20100920210000.mpg' should be local, but it can not be found.
2010-09-20 21:20:09.708 ProgramInfo(2024_20100920210000.mpg), Error: GetPlaybackURL: '2024_20100920210000.mpg' should be local, but it can not be found.
2010-09-20 21:20:09.895 ProgramInfo(2024_20100920210000.mpg), Error: GetPlaybackURL: '2024_20100920210000.mpg' should be local, but it can not be found.
2010-09-20 21:20:09.900 ProgramInfo(2011_20100920210000.mpg), Error: GetPlaybackURL: '2011_20100920210000.mpg' should be local, but it can not be found.
2010-09-20 21:20:10.129 ProgramInfo(2024_20100920210000.mpg), Error: GetPlaybackURL: '2024_20100920210000.mpg' should be local, but it can not be found.
2010-09-20 21:20:10.276 ProgramInfo(2024_20100920210000.mpg), Error: GetPlaybackURL: '2024_20100920210000.mpg' should be local, but it can not be found.
2010-09-20 21:20:10.281 ProgramInfo(2011_20100920210000.mpg), Error: GetPlaybackURL: '2011_20100920210000.mpg' should be local, but it can not be found.
2010-09-20 21:20:20.886 ProgramInfo(2024_20100920210000.mpg), Error: GetPlaybackURL: '2024_20100920210000.mpg' should be local, but it can not be found.
2010-09-20 21:20:22.351 ProgramInfo(2011_20100920210000.mpg), Error: GetPlaybackURL: '2011_20100920210000.mpg' should be local, but it can not be found.

You can see by all of the "should be local, but it can not be found."
that nothing was being written when Myth thought there should be.

FWIW, the "2003_20100920200000.mpg" immediately prior (the tail end of
which can be seen in the log snipped above) recorded just fine from the
same tuner.

Any ideas?

b.

-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 198 bytes
Desc: This is a digitally signed message part
URL: <http://mythtv.org/pipermail/mythtv-users/attachments/20100927/c3326250/attachment.pgp>


More information about the mythtv-users mailing list