[mythtv] Recording/scheduling thread dying?

[Karsten Kretschmer]

Dave Just wrote:
> Has anyone else noticed their backend stopping recording scheduled 
> programs after running for a while?

I have noticed what I think is the same problem. I have a setup with
svn revision 9716 from trunk on a machine with two DVB-S cards both
receiving Astra 19.2 east. Last night I had two shows scheduled: the
first 22:20-00:50, the second 00:20-02:05. The first one was recorded
fine, but the second one and another one this morning was not. I
noticed missed recordings previously in the last few weeks, but now i
have kept the logs to try to find the problem.

I noticed that up to the scheduled beginning of the second of the two
overlapping shows, the backend log (record,channel,file,schedule,jobqueue)
shows a rescheduling about every five minutes, but then no further
rescheduling happens. The last rescheduling log is:

| 2006-05-01 00:19:09.398 Reschedule requested for id -1.
| Query 0: /record.search = :NRST AND (record.recordid = :NRRECORDID OR :NRRECORDID = -1) AND program.manualid = 0 AND program.title = record.title 
| 2006-05-01 00:19:09.628  |-- Start DB Query 0...
| 2006-05-01 00:19:09.633  |-- -1 results in 0.004372 sec.
| 2006-05-01 00:19:09.633  +-- Done.
| 2006-05-01 00:19:09.633 PruneOldRecords...
| 2006-05-01 00:19:09.634 Card 2 is recording "Copykill"
| 2006-05-01 00:19:09.634 AddNewRecords...
| 2006-05-01 00:19:09.637  |-- Start DB Query...
| 2006-05-01 00:19:09.661  |-- 18 results in 0.02386 sec. Processing...
| 2006-05-01 00:19:09.668  +-- Cleanup...
| 2006-05-01 00:19:09.668 AddNotListed...
| 2006-05-01 00:19:09.668  |-- Start DB Query...
| 2006-05-01 00:19:09.672  |-- 0 results in 0.002992 sec. Processing...
| 2006-05-01 00:19:09.672 Sort by time...
| 2006-05-01 00:19:09.672 PruneOverlaps...
| 2006-05-01 00:19:09.672 Sort by priority...
| 2006-05-01 00:19:09.672 BuildListMaps...
| 2006-05-01 00:19:09.672 SchedNewRecords...
| 2006-05-01 00:19:09.672 Scheduling:
|   #Django - "Spielfilm Italien / Spani   21 29109  01 00:20-02:05  2 2  F -  -1/1
|      !Copykill - "Copykill"                  9 1899  30 22:20-00:50  2 2  F 2  -1/1
|   +Toto: Live in Amsterdam                6 29007  01 07:55-09:05  2 2  F 2  -1/1
|   +The Eagles: Farewell 1 Tour Concert    6 29007  01 15:10-16:20  2 2  F 2  -1/1
|   +Eiskalte Engel - "Eiskalte Engel"      8 1898  02 02:45-04:35  2 2  F 2  -1/1
|   +Django - "Spielfilm Italien / Spani   21 29109  01 00:20-02:05  1 1  F 1  -1/0
| 2006-05-01 00:19:09.673 ClearListMaps...
| 2006-05-01 00:19:09.673 Sort by time...
| 2006-05-01 00:19:09.673 PruneRedundants...
| 2006-05-01 00:19:09.673 Sort by time...
| --- print list start ---
| Title - Subtitle                    Chan ChID Day Start  End   C I  T N   Pri
| Copykill - "Copykill"                  9 1899  30 22:20-00:50  2 2  F 2  -1/1
| Django - "Spielfilm Italien / Spani   21 29109  01 00:20-02:05  1 1  F 1  -1/0
| Toto: Live in Amsterdam                6 29007  01 07:55-09:05  2 2  F 2  -1/1
| The Eagles: Farewell 1 Tour Concert    6 29007  01 15:10-16:20  2 2  F 2  -1/1
| Eiskalte Engel - "Eiskalte Engel"      8 1898  02 02:45-04:35  2 2  F 2  -1/1
| ---  print list end  ---
| 2006-05-01 00:19:09.674 Scheduled 5 items in 0.3 = 0.24 match + 0.04 place

As far as I remember (unfortunately I didn't keep the old logs) in the
previous cases this problem occured also at the second of two
overlapping recordings, i.e. the first one was recorded, the second
one and all following ones were not. The missed recordings do not show
up in the "Previously Recorded" list, but are visible in mythweb's
schedules listing. mythbackend --resched is unsuccessful.

Maybe this helps a little bit. I have more log output, but I don't
know what, if any, would be useful for debugging. I didn't find any
clue there.

Karsten