Ticket #5754: strictly_notes.txt

File strictly_notes.txt, 6.5 KB (added by simonwalls@…, 3 years ago)

Notes on a recording seeming to be stopped by Active EIT scan (modified) closing the channel

Line 
1
2Strictly Come Dancing (Sat 6th Dec) was programmed to record.
3
4Only a 1.5 minute file was recorded, at 65Mb size.
5
6mythbackend.log:
7
82008-12-06 18:03:03.230 Started recording: Strictly Come Dancing: channel 1001 on cardid 1, sourceid 1
92008-12-06 18:03:03.236 Scheduler: Update next_record for 291
102008-12-06 18:03:03.776 EITScanner (1): Started passive scan.
112008-12-06 18:03:18.252 EITHelper: Added 2 events
122008-12-06 18:03:18.709 EITHelper: Added 1 events
132008-12-06 18:03:19.161 EITHelper: Added 2 events
142008-12-06 18:03:19.606 EITHelper: Added 1 events
152008-12-06 18:03:22.048 EITHelper: Added 1 events
162008-12-06 18:03:35.720 EITHelper: Added 1 events
172008-12-06 18:04:30.648 UPnpMedia: BuildMediaMap VIDEO scan starting in :/mnt/video:
182008-12-06 18:04:30.962 UPnpMedia: BuildMediaMap Done. Found 186 objects
192008-12-06 18:04:35.753 EITScanner (1): Added 20 EIT Events
202008-12-06 18:04:35.787 EITScanner: Rate limiting reschedules..
212008-12-06 18:04:37.690 TVRec(1): Reached Active Scan Duration, ceasing active scan until next cycle. Flushing cache...
222008-12-06 18:04:37.787 EITCache: Wrote 1 modified entries of 336 for channel 1019 to database.
232008-12-06 18:03:03.236 Scheduler: Update next_record for 291
242008-12-06 18:03:03.776 EITScanner (1): Started passive scan.
252008-12-06 18:03:18.252 EITHelper: Added 2 events
262008-12-06 18:03:18.709 EITHelper: Added 1 events
272008-12-06 18:03:19.161 EITHelper: Added 2 events
282008-12-06 18:03:19.606 EITHelper: Added 1 events
292008-12-06 18:03:22.048 EITHelper: Added 1 events
302008-12-06 18:03:35.720 EITHelper: Added 1 events
312008-12-06 18:04:30.648 UPnpMedia: BuildMediaMap VIDEO scan starting in :/mnt/video:
322008-12-06 18:04:30.962 UPnpMedia: BuildMediaMap Done. Found 186 objects
332008-12-06 18:04:35.753 EITScanner (1): Added 20 EIT Events
342008-12-06 18:04:35.787 EITScanner: Rate limiting reschedules..
352008-12-06 18:04:37.690 TVRec(1): Reached Active Scan Duration, ceasing active scan until next cycle. Flushing cache...
362008-12-06 18:04:37.787 EITCache: Wrote 1 modified entries of 336 for channel 1019 to database.
372008-12-06 18:04:37.795 EITCache: Wrote 1 modified entries of 151 for channel 1020 to database.
382008-12-06 18:04:37.853 EITCache: Wrote 2 modified entries of 395 for channel 1070 to database.
392008-12-06 18:04:37.869 EITCache: Wrote 1 modified entries of 462 for channel 1071 to database.
402008-12-06 18:04:37.913 EITCache: Wrote 2 modified entries of 16 for channel 1105 to database.
412008-12-06 18:04:37.973 EITCache: Wrote 1 modified entries of 77 for channel 1718 to database.
422008-12-06 18:04:38.022 TVRec(1): For Reference - Signal Monitor not running.
432008-12-06 18:04:38.068 TVRec(1): Calculated Active Scan wait time of 48 minutes. Active Scan will resume then.
442008-12-06 18:12:42.981 AutoExpire: CalcParams(): Max required Free Space: 3.0 GB w/freq: 15 min
452008-12-06 18:27:43.099 AutoExpire: CalcParams(): Max required Free Space: 3.0 GB w/freq: 15 min
462008-12-06 18:34:31.065 UPnpMedia: BuildMediaMap VIDEO scan starting in :/mnt/video:
472008-12-06 18:34:31.328 UPnpMedia: BuildMediaMap Done. Found 186 objects
482008-12-06 18:42:43.181 AutoExpire: CalcParams(): Max required Free Space: 3.0 GB w/freq: 15 min
492008-12-06 18:52:38.721 TVRec(1): Improved Active Scan cycle time 60 minutes
502008-12-06 18:52:38.756 TVRec(1): Improved Active Scan Duration   12 minutes
512008-12-06 18:52:38.757 TVRec(1): EIT Active Scan being (re)started.
522008-12-06 18:52:38.759 EITScanner (1): StartActiveScan called with 6 multiplexes
532008-12-06 18:52:46.634 Finished recording Strictly Come Dancing: channel 1001
542008-12-06 18:52:46.744 Reschedule requested for id 0.
552008-12-06 18:52:46.848 BuildWorkList...
562008-12-06 18:52:46.921 AddNewRecords...
572008-12-06 18:52:46.967  |-- Start DB Query...
582008-12-06 18:52:47.114  |-- 354 results in 0.117853 sec. Processing...
592008-12-06 18:52:47.787 Using runtime prefix = /usr
602008-12-06 18:52:47.879 Empty LocalHostName.
612008-12-06 18:52:47.881 Using localhost value of mythserver
622008-12-06 18:52:47.951 New DB connection, total: 1
632008-12-06 18:52:48.005 Connected to database 'mythconverg' at host: localhost
642008-12-06 18:52:48.012 Closing DB connection named 'DBManager0'
652008-12-06 18:52:48.015 Connected to database 'mythconverg' at host: localhost
662008-12-06 18:52:48.018 New DB connection, total: 2
672008-12-06 18:52:48.021 Connected to database 'mythconverg' at host: localhost
682008-12-06 18:52:48.025 Current Schema Version: 1214
692008-12-06 18:52:50.946 AFD: Opened codec 0x98750c0, id(MPEG2VIDEO) type(Video)
702008-12-06 18:52:50.976 AFD: codec MP3 has 2 channels
712008-12-06 18:52:50.978 AFD: Opened codec 0x98756b0, id(MP3) type(Audio)
722008-12-06 18:52:50.979 AFD: codec MP3 has 0 channels
732008-12-06 18:52:50.981 AFD: Opened codec 0x9875ca0, id(MP3) type(Audio)
742008-12-06 18:52:50.982 AFD: Opened codec 0x9876290, id(DVB_SUBTITLE) type(Subtitle)
752008-12-06 18:52:51.260 Preview: Grabbed preview '/storage/recordings/1001_20081206180300.mpg' 720x576@124s
762008-12-06 18:55:01.786 mythmon: mythbackend not running!
772008-12-06 18:55:03.839 Using runtime prefix = /usr
782008-12-06 18:55:03.887 Empty LocalHostName.
792008-12-06 18:55:03.888 Using localhost value of mythserver
802008-12-06 18:55:03.907 New DB connection, total: 1
812008-12-06 18:55:03.918 Connected to database 'mythconverg' at host: localhost
82
83
84So mythbackend stopped running sometime after the Grab Preview at 18:52:51. However the mpeg file is only about 90s long, and only contains pre-programme broadcase content. The desired recorded programme is not there.
85
86Getting info on the recorded file duration using ProjectX:
87++> Mpg Video: PID 0x0258 / PesID 0xE0 / SubID 0x00 :
88-> Video: fr-ct-1p-cg-og-dg -> 2158-1-0-180-0-0
89-> Video length: 2158 frames @ 00:01:26.320
90-> GOP summary: min. 20, max. 24 fields; contains interlaced frames
91-> avg. nom. bitrate 4496183bps (min/max: 4000000/5117200)
92-> set first sequenceheader bitrate to 5117200bps
93---> new File: /storage/recordings/1001_20081206180300.m2v
94
95
96Note length = 1 min 26 secs.  Recording started at 18:03:03 plus 1m26 = 18:04:29. This agrees with the recording not containing any of the desired program, which began at 18:05:00 approx.
97The 'crash' was noticed at 18:55:01 (so not directly related to the recording stopping), but at 18:04:37 the EIT Active Scan (modified by my patch) went into Wait mode. At 18:04:38 the EIT scanner remarked that the Signal Monitor was not running.
98
99Looks like the EIT scan modification can stop the channel when a recording is in progress!
100