Hi,
a recording last night failed and I ask, if someone can explain the reason.
The timer was for german channel ZDF with VPS info, but apparently a running state was not broadcasted. The timer started on scheduled time, but stopped after 4 seconds. It seems VDR detected that no running state is availabe, but stopped the recording immediately.
I know that VPS is not reliable, but when VDR can start the timer on right time without running state it should be able to stop it after scheduled time.
Is it a problem in VDR or did I miss something? I'm using VDR 1.3.41 from c't distribution. The log entries during recording time, there was no user interaction:
Feb 26 22:26:17 vdr vdr: [4646] timer 4 (5 2230-0005 'Hautnah - Die Methode Hill') set to event Son 26.02.2006 22:30-00:05 (VPS: 26.02 22:30) 'Hautnah - Die Methode Hill' Feb 26 22:26:29 vdr vdr: [4646] max. latency time 12 seconds Feb 26 22:28:00 vdr vdr: [4646] timer 4 (5 2230-0005 'Hautnah - Die Methode Hill') entered VPS margin Feb 26 22:28:00 vdr vdr: [4646] switching device 1 to channel 5 Feb 26 22:28:00 vdr vdr: [4840] channel 7 (ZDFdokukanal) event 21:45 'Radfahrer - Von Pedalrittern und Bikern' status 4 Feb 26 22:28:00 vdr vdr: [4840] channel 9 (3sat) event 21:15 'Hoffnung - ein deutscher Winterstern' status 4 Feb 26 22:28:01 vdr vdr: [4840] channel 6 (ZDFinfokanal) event 22:15 'Herr der Regeln' status 4 Feb 26 22:28:01 vdr vdr: [4646] switching to channel 1 Feb 26 22:30:00 vdr vdr: [4646] switching device 1 to channel 5 Feb 26 22:30:00 vdr vdr: [4646] timer 4 (5 2230-0005 'Hautnah - Die Methode Hill') start Feb 26 22:30:00 vdr vdr: [4646] Title: 'Hautnah - Die Methode Hill' Subtitle: 'Schlussblende' Feb 26 22:30:00 vdr vdr: [4646] executing '/usr/lib/vdr/vdr-recordingaction before "/video/vdr/Hautnah_-_Die_Methode_Hill/2006-02-26.22.30.50.14.rec"' Feb 26 22:30:00 vdr vdr: [4646] record /video/vdr/Hautnah_-_Die_Methode_Hill/2006-02-26.22.30.50.14.rec Feb 26 22:30:00 vdr vdr: [4646] creating directory /video/vdr/Hautnah_-_Die_Methode_Hill Feb 26 22:30:00 vdr vdr: [4646] creating directory /video/vdr/Hautnah_-_Die_Methode_Hill/2006-02-26.22.30.50.14.rec Feb 26 22:30:00 vdr vdr: [4646] recording to '/video/vdr/Hautnah_-_Die_Methode_Hill/2006-02-26.22.30.50.14.rec/001.vdr' Feb 26 22:30:00 vdr vdr: [4852] file writer thread started (pid=4646, tid=4852) Feb 26 22:30:00 vdr vdr: [4853] recording thread started (pid=4646, tid=4853) Feb 26 22:30:00 vdr vdr: [4854] receiver on device 1 thread started (pid=4646, tid=4854) Feb 26 22:30:00 vdr vdr: [4855] TS buffer on device 1 thread started (pid=4646, tid=4855) Feb 26 22:30:01 vdr vdr: [4840] channel 6 (ZDFinfokanal) event 22:30 'Hilfe, mein Kind will nicht essen!' status 4 Feb 26 22:30:01 vdr vdr: [4646] switching to channel 1 Feb 26 22:30:01 vdr vdr: [4646] info: Kanal nicht verfügbar! Feb 26 22:30:01 vdr vdr: [4840] changing pids of channel 69 from 310+310:320=deu:330 to 310+310:320:0 Feb 26 22:30:02 vdr vdr: [4840] channel 7 (ZDFdokukanal) event 22:30 'Rahmen, Ritzel und rasierte Beine' status 4 Feb 26 22:30:03 vdr vdr: [4646] switching to channel 5 Feb 26 22:30:03 vdr vdr: [4857] transfer thread started (pid=4646, tid=4857) Feb 26 22:30:04 vdr vdr: [4853] recording thread ended (pid=4646, tid=4853) Feb 26 22:30:04 vdr vdr: [4852] file writer thread ended (pid=4646, tid=4852) Feb 26 22:30:04 vdr vdr: [4646] buffer stats: 60724 (1%) used Feb 26 22:30:04 vdr vdr: [4646] timer 4 (5 2230-0005 'Hautnah - Die Methode Hill') stop Feb 26 22:30:04 vdr vdr: [4646] executing '/usr/lib/vdr/vdr-recordingaction after "/video/vdr/Hautnah_-_Die_Methode_Hill/2006-02-26.22.30.50.14.rec"'
Gruß, Frank
Frank Behrens wrote:
VDR started recording at 22:30, which was the timer's start time. Then after it had switched to channel 5, the actual running status of the event was probably set to "not running", so VDR stopped recording.
It would be interesting to see the log entries before and after these, to be able to tell whether there was any running status change on channel 5 at all.
Klaus
Klaus, thanks for your response.
Klaus Schmidinger vdr@linuxtv.org wrote on 28 Feb 2006 22:49:
IMHO it was not _set_ to "not running", it was still in this initial state.
No, there was no status change for channel 5 in syslog between Feb 26 22:26:11 vdr vdr: [4646] VDR version 1.3.41 started and Feb 27 00:10:07 vdr vdr: [4646] exiting The VDR switched on automatically some seconds before.
Before that channel switch we could not get any status event, because we were on a different transponder.
As a summary all status changes between vdr start and stop:
Feb 26 22:26:30 vdr vdr: [4840] channel 10 (arte) event 21:40 'Rios Rebellen' status 4 Feb 26 22:26:30 vdr vdr: [4840] channel 8 (Phoenix) event 22:15 'Fall Deutschland' status 4 Feb 26 22:28:00 vdr vdr: [4840] channel 7 (ZDFdokukanal) event 21:45 'Radfahrer - Von Pedalrittern und Bikern' status 4 Feb 26 22:28:00 vdr vdr: [4840] channel 9 (3sat) event 21:15 'Hoffnung - ein deutscher Winterstern' status 4 Feb 26 22:28:01 vdr vdr: [4840] channel 6 (ZDFinfokanal) event 22:15 'Herr der Regeln' status 4 Feb 26 22:30:01 vdr vdr: [4840] channel 6 (ZDFinfokanal) event 22:30 'Hilfe, mein Kind will nicht essen!' status 4 Feb 26 22:30:02 vdr vdr: [4840] channel 7 (ZDFdokukanal) event 22:30 'Rahmen, Ritzel und rasierte Beine' status 4 Feb 26 22:41:36 vdr vdr: [4840] channel 9 (3sat) event 21:15 'Hoffnung - ein deutscher Winterstern' status 1 Feb 26 22:42:41 vdr vdr: [4840] channel 9 (3sat) event 22:40 'Der Alte' status 4 Feb 26 22:44:24 vdr vdr: [4840] channel 6 (ZDFinfokanal) event 22:45 'kind & kegel' status 4 Feb 26 22:59:30 vdr vdr: [4840] channel 6 (ZDFinfokanal) event 23:00 'AKTUELL - thema der woche' status 4 Feb 26 23:00:01 vdr vdr: [4840] channel 7 (ZDFdokukanal) event 23:00 'Im Angesicht des Todes' status 4 Feb 26 23:14:18 vdr vdr: [4840] channel 6 (ZDFinfokanal) event 23:15 'Abenteuer Labor' status 4 Feb 26 23:29:21 vdr vdr: [4840] channel 6 (ZDFinfokanal) event 23:30 'Naturkatastrophen' status 4 Feb 26 23:40:18 vdr vdr: [4840] channel 9 (3sat) event 22:40 'Der Alte' status 1 Feb 26 23:40:50 vdr vdr: [4840] channel 9 (3sat) event 23:40 'Kommissar Beck - Die neuen Fälle: Todesengel' status 4 Feb 26 23:44:17 vdr vdr: [4840] channel 6 (ZDFinfokanal) event 23:45 'Total normal' status 4 Feb 26 23:59:29 vdr vdr: [4840] channel 6 (ZDFinfokanal) event 00:00 'AKTUELL - welt' status 4 Feb 27 00:00:02 vdr vdr: [4840] channel 7 (ZDFdokukanal) event 00:00 'Fisch & Chips' status 4
It seems ZDF (channel 5) did not send any running status information.
Gruß, Frank
Frank Behrens wrote:
Well, apparently they did send EPG events, because if they hadn't, then VDR would have recorded as if no VPS flag had been set.
After the recording had started, the event for the current programme must have been refreshed, so that VDR took it into account again (it only "trusts" events for VPS recordings if the "present/following" EIT table has been "seen" within the past 30 seconds). If that event then had the running status set to SI::RunningStatusNotRunning VDR would not log a status change, and just stop recording, waiting until the running status changes to "running" - which apparently never happened.
Klaus
-
Frank Behrens -
Klaus Schmidinger