Last night I had a few recording failures between 9 and 11 PM. Several shows were being recorded ..<div><br></div><div>30 Rock, 9:00 - 9:30 (no recording at all)</div><div>The Finder, 9:00 - 10:00 (only first 30 minutes recorded)</div>
<div>The Firm, 10:00 - 11:00 (only about a minute and half recorded)</div><div><br></div><div>Also recording was Rachel Maddow on the HD-PVR from 9:00 to 10:00, which recorded without incident.</div><div><br></div><div>Despite the recordings being cut short the log reports the recordings finishing at the scheduled times. I only see one recorder failed message in the log, and that's when 30 Rock was scheduled to finish, which is also around the same time The Finder cuts out.</div>
<div><br></div><div>Here is my backend log for the time in question ...</div><div><br></div><div><div>2012-01-26 20:59:51.750 TVRec(1): Changing from None to RecordingOnly</div><div>2012-01-26 20:59:51.751 TVRec(1): HW Tuner: 1->1</div>
<div>2012-01-26 20:59:51.764 AutoExpire: CalcParams(): Max required Free Space: 4.0 GB w/freq: 14 min</div><div>2012-01-26 20:59:51.811 Started recording: "30 Rock": channel 4081 on cardid 1, sourceid 4</div><div>
2012-01-26 20:59:51.812 scheduler: Started recording: "30 Rock": channel 4081 on cardid 1, sourceid 4</div><div>2012-01-26 20:59:52.030 TVRec(2): Changing from None to RecordingOnly</div><div>2012-01-26 20:59:52.060 TVRec(2): HW Tuner: 2->2</div>
<div>2012-01-26 20:59:52.121 AutoExpire: CalcParams(): Max required Free Space: 4.0 GB w/freq: 7 min</div><div>2012-01-26 20:59:52.140 Started recording: "The Finder":"A Cinderella Story": channel 4171 on cardid 2, sourceid 4</div>
<div>2012-01-26 20:59:52.193 scheduler: Started recording: "The Finder":"A Cinderella Story": channel 4171 on cardid 2, sourceid 4</div><div>2012-01-26 20:59:52.319 TVRec(7): Changing from None to RecordingOnly</div>
<div>2012-01-26 20:59:52.370 TVRec(7): HW Tuner: 7->7</div><div>2012-01-26 20:59:52.480 AutoExpire: CalcParams(): Max required Free Space: 4.0 GB w/freq: 4 min</div><div>2012-01-26 20:59:52.519 Started recording: "The Rachel Maddow Show": channel 1376 on cardid 7, sourceid 1</div>
<div>2012-01-26 20:59:52.521 scheduler: Started recording: "The Rachel Maddow Show": channel 1376 on cardid 7, sourceid 1</div><div>2012-01-26 20:59:52.931 Updating status for "The Finder":"A Cinderella Story" on cardid 2 (Tuning => Recording)</div>
<div>2012-01-26 20:59:52.988 TVRec(2): rec->GetPathname(): '/mnt/be2hd1/4171_20120126210000.mpg'</div><div>2012-01-26 20:59:55.690 ProgramInfo(1376_20120126210000.mpg), Error: GetPlaybackURL: '1376_20120126210000.mpg' should be local, but it can not be found.</div>
<div>2012-01-26 20:59:55.731 ProgramInfo(4081_20120126210000.mpg), Error: GetPlaybackURL: '4081_20120126210000.mpg' should be local, but it can not be found.</div><div>2012-01-26 20:59:58.812 ProgramInfo(4081_20120126210000.mpg), Error: GetPlaybackURL: '4081_20120126210000.mpg' should be local, but it can not be found.</div>
<div>2012-01-26 21:00:00.099 Updating status for "The Rachel Maddow Show" on cardid 7 (Tuning => Recording)</div><div>2012-01-26 21:00:00.177 TVRec(7): rec->GetPathname(): '/mnt/be2hd2/1376_20120126210000.mpg'</div>
<div>2012-01-26 21:00:02.277 MainServer::ANN Playback</div><div>2012-01-26 21:00:02.278 adding: frontend1 as a client (events: 0)</div><div>2012-01-26 21:00:02.279 MainServer::HandleAnnounce FileTransfer</div><div>2012-01-26 21:00:02.279 adding: frontend1 as a remote file transfer</div>
<div>2012-01-26 21:00:03.761 MainServer::ANN Monitor</div><div>2012-01-26 21:00:03.761 adding: livingroom as a client (events: 0)</div><div>2012-01-26 21:00:03.763 MainServer::ANN Monitor</div><div>2012-01-26 21:00:03.763 adding: livingroom as a client (events: 1)</div>
<div>2012-01-26 21:00:14.451 ProgramInfo(4081_20120126210000.mpg), Error: GetPlaybackURL: '4081_20120126210000.mpg' should be local, but it can not be found.</div><div>2012-01-26 21:00:58.106 ProgramInfo(4081_20120126210000.mpg), Error: GetPlaybackURL: '4081_20120126210000.mpg' should be local, but it can not be found.</div>
<div>2012-01-26 21:01:03.256 ProgramInfo(4081_20120126210000.mpg), Error: GetPlaybackURL: '4081_20120126210000.mpg' should be local, but it can not be found.</div><div>2012-01-26 21:01:06.950 MainServer::ANN Playback</div>
<div>2012-01-26 21:01:06.950 adding: frontend1 as a client (events: 0)</div><div>2012-01-26 21:01:06.951 MainServer::HandleAnnounce FileTransfer</div><div>2012-01-26 21:01:06.952 adding: frontend1 as a remote file transfer</div>
<div>2012-01-26 21:05:23.275 MainServer::ANN Monitor</div><div>2012-01-26 21:05:23.349 adding: livingroom as a client (events: 0)</div><div>2012-01-26 21:05:23.351 MainServer::ANN Monitor</div><div>2012-01-26 21:05:23.430 adding: livingroom as a client (events: 1)</div>
<div>2012-01-26 21:09:41.801 MainServer::ANN Playback</div><div>2012-01-26 21:09:41.802 adding: frontend1 as a client (events: 0)</div><div>2012-01-26 21:09:41.803 MainServer::HandleAnnounce FileTransfer</div><div>2012-01-26 21:09:41.803 adding: frontend1 as a remote file transfer</div>
<div>2012-01-26 21:09:44.155 MainServer::ANN Monitor</div><div>2012-01-26 21:09:44.219 adding: livingroom as a client (events: 0)</div><div>2012-01-26 21:09:44.220 MainServer::ANN Monitor</div><div>2012-01-26 21:09:44.220 adding: livingroom as a client (events: 1)</div>
<div>2012-01-26 21:11:29.939 MainServer::ANN Monitor</div><div>2012-01-26 21:11:29.949 adding: livingroom as a client (events: 0)</div><div>2012-01-26 21:11:29.950 MainServer::ANN Monitor</div><div>2012-01-26 21:11:29.950 adding: livingroom as a client (events: 1)</div>
<div>2012-01-26 21:11:30.729 ProgramInfo(4081_20120126210000.mpg), Error: GetPlaybackURL: '4081_20120126210000.mpg' should be local, but it can not be found.</div><div>Error in my_thread_global_end(): 1 threads didn't exit</div>
<div>2012-01-26 21:11:58.354 MainServer::ANN Playback</div><div>2012-01-26 21:11:58.354 adding: frontend1 as a client (events: 0)</div><div>2012-01-26 21:11:58.355 MainServer::HandleAnnounce FileTransfer</div><div>2012-01-26 21:11:58.355 adding: frontend1 as a remote file transfer</div>
<div>2012-01-26 21:12:06.172 AutoExpire: CalcParams(): Max required Free Space: 4.0 GB w/freq: 4 min</div><div>2012-01-26 21:16:06.753 AutoExpire: CalcParams(): Max required Free Space: 4.0 GB w/freq: 4 min</div><div>2012-01-26 21:20:07.313 AutoExpire: CalcParams(): Max required Free Space: 4.0 GB w/freq: 4 min</div>
<div>2012-01-26 21:24:07.855 AutoExpire: CalcParams(): Max required Free Space: 4.0 GB w/freq: 4 min</div><div>2012-01-26 21:28:08.414 AutoExpire: CalcParams(): Max required Free Space: 4.0 GB w/freq: 4 min</div><div>2012-01-26 21:28:33.772 UPnpMedia: BuildMediaMap VIDEO scan starting in :/mnt/be1hd1/videos/:</div>
<div>2012-01-26 21:28:33.772 UPnpMedia: BuildMediaMap Done. Found 0 objects</div><div>2012-01-26 21:32:00.008 TVRec(1): Changing from RecordingOnly to None</div><div>2012-01-26 21:32:00.046 Updating status for "30 Rock" on cardid 1 (Tuning => Recorder Failed)</div>
<div>2012-01-26 21:32:00.047 Reschedule requested for id 0.</div><div>2012-01-26 21:32:01.667 Preview Error: Encountered problems running '/usr/bin/mythpreviewgen --size 0x0 --chanid 4081 --starttime 20120126210000 > /dev/null'</div>
<div>2012-01-26 21:32:11.816 AutoExpire: CalcParams(): Max required Free Space: 4.0 GB w/freq: 7 min</div><div>2012-01-26 21:32:14.155 Scheduled 1827 items in 14.1 = 0.00 match + 14.05 place</div><div>2012-01-26 21:32:14.157 scheduler: Scheduled items: Scheduled 1827 items in 14.1 = 0.00 match + 14.05 place</div>
<div>2012-01-26 21:39:12.568 AutoExpire: CalcParams(): Max required Free Space: 4.0 GB w/freq: 7 min</div><div>2012-01-26 21:46:13.093 AutoExpire: CalcParams(): Max required Free Space: 4.0 GB w/freq: 7 min</div><div>2012-01-26 21:53:13.617 AutoExpire: CalcParams(): Max required Free Space: 4.0 GB w/freq: 7 min</div>
<div>2012-01-26 21:57:37.057 ProgramInfo(4081_20120126210000.mpg), Error: GetPlaybackURL: '4081_20120126210000.mpg' should be local, but it can not be found.</div><div>2012-01-26 21:57:46.109 ProgramInfo(4081_20120126210000.mpg), Error: GetPlaybackURL: '4081_20120126210000.mpg' should be local, but it can not be found.</div>
<div>2012-01-26 21:57:54.040 Reschedule requested for id 0.</div><div>2012-01-26 21:58:02.802 Scheduled 1827 items in 8.7 = 0.02 match + 8.70 place</div><div>2012-01-26 21:58:02.804 scheduler: Scheduled items: Scheduled 1827 items in 8.7 = 0.02 match + 8.70 place</div>
<div>2012-01-26 21:58:35.774 UPnpMedia: BuildMediaMap VIDEO scan starting in :/mnt/be1hd1/videos/:</div><div>2012-01-26 21:58:35.774 UPnpMedia: BuildMediaMap Done. Found 0 objects</div><div>2012-01-26 21:58:50.822 Reschedule requested for id 0.</div>
<div>2012-01-26 21:58:57.343 Scheduled 1827 items in 6.5 = 0.00 match + 6.46 place</div><div>2012-01-26 21:58:57.345 scheduler: Scheduled items: Scheduled 1827 items in 6.5 = 0.00 match + 6.46 place</div><div>2012-01-26 21:59:19.772 TVRec(3): ASK_RECORDING 3 29 0 0</div>
<div>2012-01-26 21:59:20.206 TVRec(1): ASK_RECORDING 1 29 0 0</div><div>2012-01-26 21:59:20.244 TVRec(4): ASK_RECORDING 4 29 0 0</div><div>2012-01-26 21:59:51.507 TVRec(1): Changing from None to RecordingOnly</div><div>2012-01-26 21:59:51.520 TVRec(1): HW Tuner: 1->1</div>
<div>2012-01-26 21:59:51.540 AutoExpire: CalcParams(): Max required Free Space: 4.0 GB w/freq: 4 min</div><div>2012-01-26 21:59:51.541 Started recording: "The Firm":"Chapter Five": channel 4081 on cardid 1, sourceid 4</div>
<div>2012-01-26 21:59:51.543 scheduler: Started recording: "The Firm":"Chapter Five": channel 4081 on cardid 1, sourceid 4</div><div>2012-01-26 21:59:52.486 Updating status for "The Firm":"Chapter Five" on cardid 1 (Tuning => Recording)</div>
<div>2012-01-26 21:59:52.543 TVRec(1): rec->GetPathname(): '/mnt/be1hd1/4081_20120126220000.mpg'</div><div>2012-01-26 22:00:14.142 AutoExpire: CalcParams(): Max required Free Space: 4.0 GB w/freq: 4 min</div><div>
2012-01-26 22:02:00.749 TVRec(7): Changing from RecordingOnly to None</div><div>2012-01-26 22:02:00.750 Updating status for "The Rachel Maddow Show" on cardid 7 (Recording => Recorded)</div><div>2012-01-26 22:02:00.751 Finished recording The Rachel Maddow Show: channel 1376</div>
<div>2012-01-26 22:02:00.753 scheduler: Finished recording: The Rachel Maddow Show: channel 1376</div><div>2012-01-26 22:02:00.810 Reschedule requested for id 0.</div><div>2012-01-26 22:02:00.999 TVRec(2): Changing from RecordingOnly to None</div>
<div>2012-01-26 22:02:01.000 Updating status for "The Finder":"A Cinderella Story" on cardid 2 (Recording => Recorded)</div><div>2012-01-26 22:02:01.001 Finished recording The Finder "A Cinderella Story": channel 4171</div>
<div>2012-01-26 22:02:01.062 scheduler: Finished recording: The Finder "A Cinderella Story": channel 4171</div><div>2012-01-26 22:02:01.104 Finished recording The Finder "A Cinderella Story": channel 4171</div>
<div>2012-01-26 22:02:03.785 Finished recording The Rachel Maddow Show: channel 1376</div><div>2012-01-26 22:02:03.792 scheduler: Last message repeated 1 times: Finished recording: The Finder "A Cinderella Story": channel 4171</div>
<div>2012-01-26 22:02:03.794 scheduler: Finished recording: The Rachel Maddow Show: channel 1376</div><div>2012-01-26 22:02:05.633 MainServer, Error: PREVIEW_SUCCESS but no receivers.</div><div>2012-01-26 22:02:05.636 MainServer::ANN Monitor</div>
<div>2012-01-26 22:02:05.636 adding: livingroom as a client (events: 0)</div><div>2012-01-26 22:02:05.637 MainServer::ANN Monitor</div><div>2012-01-26 22:02:05.638 adding: livingroom as a client (events: 1)</div><div>2012-01-26 22:02:13.452 Reschedule interrupted, will retry</div>
<div>2012-01-26 22:02:13.452 Reschedule requested for id 0.</div><div>2012-01-26 22:02:13.452 Reschedule requested for id 0.</div><div>2012-01-26 22:02:25.798 Scheduled 1817 items in 12.3 = 0.00 match + 12.30 place</div><div>
2012-01-26 22:02:25.800 scheduler: Scheduled items: Scheduled 1817 items in 12.3 = 0.00 match + 12.30 place</div><div>2012-01-26 22:04:14.694 AutoExpire: CalcParams(): Max required Free Space: 4.0 GB w/freq: 14 min</div><div>
2012-01-26 22:18:15.200 AutoExpire: CalcParams(): Max required Free Space: 4.0 GB w/freq: 14 min</div><div>2012-01-26 22:28:39.776 UPnpMedia: BuildMediaMap VIDEO scan starting in :/mnt/be1hd1/videos/:</div><div>2012-01-26 22:28:39.776 UPnpMedia: BuildMediaMap Done. Found 0 objects</div>
<div>2012-01-26 22:32:15.706 AutoExpire: CalcParams(): Max required Free Space: 4.0 GB w/freq: 14 min</div><div>2012-01-26 22:46:16.213 AutoExpire: CalcParams(): Max required Free Space: 4.0 GB w/freq: 14 min</div><div>2012-01-26 22:58:41.778 UPnpMedia: BuildMediaMap VIDEO scan starting in :/mnt/be1hd1/videos/:</div>
<div>2012-01-26 22:58:41.778 UPnpMedia: BuildMediaMap Done. Found 0 objects</div><div>2012-01-26 22:58:50.478 Reschedule requested for id 0.</div><div>2012-01-26 22:59:03.623 Scheduled 1816 items in 13.1 = 0.00 match + 13.10 place</div>
<div>2012-01-26 22:59:03.625 scheduler: Scheduled items: Scheduled 1816 items in 13.1 = 0.00 match + 13.10 place</div><div>2012-01-26 22:59:20.012 TVRec(7): ASK_RECORDING 7 29 0 0</div><div>2012-01-26 22:59:51.970 TVRec(7): Changing from None to RecordingOnly</div>
<div>2012-01-26 22:59:51.972 TVRec(7): HW Tuner: 7->7</div><div>2012-01-26 22:59:52.142 AutoExpire: CalcParams(): Max required Free Space: 4.0 GB w/freq: 7 min</div><div>2012-01-26 22:59:52.151 Started recording: "The Daily Show With Jon Stewart":"Tilda Swinton": channel 1248 on cardid 7, sourceid 1</div>
<div>2012-01-26 22:59:52.153 scheduler: Started recording: "The Daily Show With Jon Stewart":"Tilda Swinton": channel 1248 on cardid 7, sourceid 1</div><div>2012-01-26 23:00:01.679 Updating status for "The Daily Show With Jon Stewart":"Tilda Swinton" on cardid 7 (Tuning => Recording)</div>
<div>2012-01-26 23:00:01.744 TVRec(7): rec->GetPathname(): '/mnt/be1hd1/1248_20120126230000.mpg'</div><div>2012-01-26 23:00:16.731 AutoExpire: CalcParams(): Max required Free Space: 4.0 GB w/freq: 7 min</div><div>
2012-01-26 23:02:00.082 TVRec(1): Changing from RecordingOnly to None</div><div>2012-01-26 23:02:00.083 Updating status for "The Firm":"Chapter Five" on cardid 1 (Recording => Recorded)</div><div>2012-01-26 23:02:00.084 Finished recording The Firm "Chapter Five": channel 4081</div>
<div>2012-01-26 23:02:00.085 Reschedule requested for id 0.</div><div>2012-01-26 23:02:00.086 scheduler: Finished recording: The Firm "Chapter Five": channel 4081</div><div>2012-01-26 23:02:00.192 Finished recording The Firm "Chapter Five": channel 4081</div>
<div>2012-01-26 23:02:00.324 MainServer::ANN Monitor</div><div>2012-01-26 23:02:00.324 adding: livingroom as a client (events: 0)</div><div>2012-01-26 23:02:00.325 MainServer::ANN Monitor</div><div>2012-01-26 23:02:00.325 adding: livingroom as a client (events: 1)</div>
<div>2012-01-26 23:02:12.440 Scheduled 1806 items in 12.3 = 0.00 match + 12.31 place</div><div>2012-01-26 23:02:12.442 scheduler: Last message repeated 1 times: Finished recording: The Firm "Chapter Five": channel 4081</div>
<div>2012-01-26 23:02:12.445 scheduler: Scheduled items: Scheduled 1806 items in 12.3 = 0.00 match + 12.31 place</div></div><div><br></div><div><br></div><div>Any ideas as to what might have happened?</div>