Hi *,
my family and me greatly enjoy vdr since years, but I finally got around to update the system to a current state (on top of openSUSE 10.2) lately. The system is running dedicated for vdr (1.4.5) purposes, using two hauppauge ff 2.1 cards.
Yesterday we decided to watch the new Dittsche programme from Monday night, but had to notice, that the recording stopped prematurely:
Mar 6 00:39:46 ziggy vdr: [3975] channel 1 (Das Erste) event Die 06.03.2007 00:35-01:05 (VPS: 06.03 00:35) 'Dittsche' status 2 Mar 6 00:39:46 ziggy vdr: [3838] switching device 2 to channel 1 Mar 6 00:39:46 ziggy vdr: [3838] timer 3 (1 0035-0105 VPS 'Dittsche~Dittsche~Das wirklich wahre Leben') start Mar 6 00:39:46 ziggy vdr: [3838] Title: 'Dittsche' Subtitle: 'Das wirklich wahre Leben' Mar 6 00:39:46 ziggy vdr: [3838] record /video0/Dittsche/Dittsche/Das_wirklich_wahre_Leben/2007-03-06.00.35.50.99.rec Mar 6 00:39:46 ziggy vdr: [3838] creating directory /video0/Dittsche/Dittsche/Das_wirklich_wahre_Leben/2007-03-06.00.35.50.99.rec Mar 6 00:39:46 ziggy vdr: [3838] recording to '/video0/Dittsche/Dittsche/Das_wirklich_wahre_Leben/2007-03-06.00.35.50.99.rec/001.vdr' Mar 6 00:39:46 ziggy vdr: [11192] file writer thread started (pid=3838, tid=11192) Mar 6 00:39:46 ziggy vdr: [11193] recording thread started (pid=3838, tid=11193) Mar 6 00:39:46 ziggy vdr: [11194] receiver on device 2 thread started (pid=3838, tid=11194) Mar 6 00:39:46 ziggy vdr: [11195] TS buffer on device 2 thread started (pid=3838, tid=11195) Mar 6 00:40:33 ziggy vdr: [3975] channel 1 (Das Erste) event Die 06.03.2007 00:35-01:05 (VPS: 06.03 00:35) 'Dittsche' status 4
Mar 6 00:44:00 ziggy vdr: [3991] EPGSearch: search timer update started Mar 6 00:44:00 ziggy vdr: [3991] EPGSearch: search timer update finished Mar 6 00:46:39 ziggy vdr: [3838] switching to channel 1 Mar 6 00:46:45 ziggy vdr: [3838] switching to channel 2 Mar 6 00:46:48 ziggy vdr: [3838] switching to channel 3 Mar 6 00:46:50 ziggy vdr: [3838] switching to channel 4 Mar 6 00:46:56 ziggy vdr: [3838] switching to channel 5 Mar 6 00:47:00 ziggy vdr: [3838] switching to channel 6 Mar 6 00:47:01 ziggy vdr: [3838] switching to channel 7 Mar 6 00:47:03 ziggy vdr: [3838] switching to channel 8 Mar 6 00:47:05 ziggy vdr: [3838] switching to channel 9 Mar 6 00:47:08 ziggy vdr: [3838] switching to channel 10 Mar 6 00:47:14 ziggy vdr: [3838] switching to channel 11 Mar 6 00:47:18 ziggy vdr: [3838] switching to channel 12 Mar 6 00:47:19 ziggy vdr: [3838] switching to channel 13 Mar 6 00:47:22 ziggy vdr: [3838] switching to channel 14 Mar 6 00:47:33 ziggy vdr: [3838] switching to channel 15 Mar 6 00:47:36 ziggy vdr: [3838] switching to channel 16 Mar 6 00:47:39 ziggy vdr: [3838] switching to channel 17 Mar 6 00:48:00 ziggy vdr: [3838] switching to channel 18 Mar 6 00:48:03 ziggy vdr: [3838] switching to channel 19 Mar 6 00:52:55 ziggy vdr: [3975] changing pids of channel 1101 from 201+201:202:204 to 901+901:902:204 Mar 6 00:53:55 ziggy vdr: [3975] changing pids of channel 1101 from 901+901:902:204 to 701+701:702:204 Mar 6 00:54:54 ziggy vdr: [3975] changing pids of channel 1101 from 701+701:702:204 to 901+901:902:204 Mar 6 00:55:55 ziggy vdr: [3975] changing pids of channel 1101 from 901+901:902:204 to 701+701:702:204 Mar 6 00:56:55 ziggy vdr: [3975] changing pids of channel 1101 from 701+701:702:204 to 901+901:902:204 Mar 6 00:57:54 ziggy vdr: [3975] changing pids of channel 1101 from 901+901:902:204 to 701+701:702:204 Mar 6 00:58:54 ziggy vdr: [3975] changing pids of channel 1101 from 701+701:702:204 to 901+901:902:204 Mar 6 00:59:55 ziggy vdr: [3975] changing pids of channel 1101 from 901+901:902:204 to 701+701:702:204
Mar 6 01:00:43 ziggy vdr: [3975] channel 1 (Das Erste) event Die 06.03.2007 00:35-01:05 (VPS: 06.03 00:35) 'Dittsche' status 1 Mar 6 01:00:43 ziggy vdr: [11193] recording thread ended (pid=3838, tid=11193) Mar 6 01:00:43 ziggy vdr: [11195] TS buffer on device 2 thread ended (pid=3838, tid=11195) Mar 6 01:00:43 ziggy vdr: [11194] buffer stats: 118440 (5%) used Mar 6 01:00:43 ziggy vdr: [11194] receiver on device 2 thread ended (pid=3838, tid=11194) Mar 6 01:00:43 ziggy vdr: [11192] file writer thread ended (pid=3838, tid=11192) Mar 6 01:00:43 ziggy vdr: [3838] buffer stats: 118816 (2%) used Mar 6 01:00:43 ziggy vdr: [3838] timer 3 (1 0035-0105 VPS 'Dittsche~Dittsche~Das wirklich wahre Leben') stop
Mar 6 01:00:54 ziggy vdr: [3975] changing pids of channel 1101 from 701+701:702:204 to 901+901:902:204 Mar 6 01:01:56 ziggy vdr: [3975] changing pids of channel 1101 from 901+901:902:204 to 701+701:702:204 Mar 6 01:02:55 ziggy vdr: [3975] changing pids of channel 1101 from 701+701:702:204 to 901+901:902:204 Mar 6 01:03:43 ziggy vdr: [3838] switching to channel 1 Mar 6 01:03:46 ziggy vdr: [3838] switching to channel 2 Mar 6 01:03:49 ziggy vdr: [3838] switching to channel 3 Mar 6 01:03:54 ziggy vdr: [3838] switching to channel 4 Mar 6 01:03:55 ziggy vdr: [3975] changing pids of channel 1101 from 901+901:902:204 to 701+701:702:204 Mar 6 01:03:57 ziggy vdr: [3838] switching to channel 5 Mar 6 01:03:59 ziggy vdr: [3838] switching to channel 6 Mar 6 01:04:00 ziggy vdr: [3928] channel 5 (RTL Television) event Die 06.03.2007 01:00-01:05 'Teleshoppingsendung' status 4 Mar 6 01:04:00 ziggy vdr: [3838] switching to channel 7 Mar 6 01:04:02 ziggy vdr: [3838] switching to channel 8 Mar 6 01:04:04 ziggy vdr: [3838] switching to channel 9 Mar 6 01:04:07 ziggy vdr: [3838] switching to channel 8 Mar 6 01:04:54 ziggy vdr: [3928] changing pids of channel 1101 from 701+701:702:204 to 901+901:902:204 Mar 6 01:05:53 ziggy vdr: [3928] changing pids of channel 1101 from 901+901:902:204 to 701+701:702:204 Mar 6 01:06:55 ziggy vdr: [3928] changing pids of channel 1101 from 701+701:702:204 to 901+901:902:204 Mar 6 01:07:07 ziggy vdr: [3975] changing ca descriptors of channel 1132 Mar 6 01:07:48 ziggy vdr: [3975] changing name of channel 52 from 'Golf,;' to 'Basketball BBL,;' Mar 6 01:07:55 ziggy vdr: [3928] changing pids of channel 1101 from 901+901:902:204 to 701+701:702:204 Mar 6 01:08:30 ziggy vdr: [3975] changing pids of channel 45 from 511+511:512=deu,513=deu;515=deu:32 to 511+511:512=deu;515=deu:32 Mar 6 01:08:54 ziggy vdr: [3928] changing pids of channel 1101 from 701+701:702:204 to 901+901:902:204 Mar 6 01:09:42 ziggy vdr: [3974] frontend 1 timed out while tuning to channel 0, tp 111914 Mar 6 01:09:56 ziggy vdr: [3928] changing pids of channel 1101 from 901+901:902:204 to 701+701:702:204 Mar 6 01:10:04 ziggy vdr: [3928] channel 1 (Das Erste) event Die 06.03.2007 01:05-02:45 (VPS: 06.03 01:05) 'Das letzte Kommando' status 4
Mar 6 01:10:08 ziggy vdr: [3838] timer 3 (1 0035-0105 VPS 'Dittsche~Dittsche~Das wirklich wahre Leben') set to no event Mar 6 01:10:26 ziggy vdr: [3838] deleting timer 3 (1 0035-0105 VPS 'Dittsche~Dittsche~Das wirklich wahre Leben')
The clock is reliable (adjusted via NTP), thus vdr happened to start the recording at 00:39:46, about 48 sec before the broadcast started, very nice so far. But what happened at 01:00:43? vdr just decided to stop the recording, even a few minutes _before_ the original VPS time frame, vastly prematurely.
For the sake of completeness, I included all messages in between, while I don't understand some of them. Yes, I zapped through the channels two times, but what happened at 01:04:00 and 01:10:04? Both times it shows status 4, which means "event running", if I read the source correctly: 0=undefined, 1=not running, 2=starts in a few seconds, 3=pausing, 4=running waht does event mean here, but most most important question is: What happened, that stopped the timer prematurely, and how can I prevent this from happening the next time.
Anyway thanks for your patience and this great project.
Kind regards, Pete
Hans-Peter Jansen wrote:
[...]
vdr: [3975] channel 1 (Das Erste) event Die 06.03.2007 00:35-01:05 (VPS: 06.03 00:35) 'Dittsche' status 4
[...]
Mar 6 01:00:43 ziggy vdr: [3975] channel 1 (Das Erste) event Die 06.03.2007 00:35-01:05 (VPS: 06.03 00:35) 'Dittsche' status 1
[...]
This is a problem I also have. The fault is in the broadcaster's system. I've wrote a number of emails to the support of the ARD, but they seem to ignore the problem and claim that everything is OK on their side. Instead, they suspected a problem with my setup, or that the problem is caused somewhere between the playout center (which is in Potsdam) and the actual transmitters, or that this problem is only related to the reception technique used (I use DVB-T, but I've already seen this on DVB-S and thus it should be the same with DVB-C). They've also suggested to not use VPS because of this.
For each email I wrote they needed at least two weeks to answer. I gave up on this (for now) because I have better things to do instead of writing long mails to tv stations.
It seems to affect at least all stations which belong to the ARD, every night on 0000 UTC (so 0100 MET for now, in the summer you will notice it happens on 0200 UTC)
Regards, Andreas
[Resend, since it didn't made it to the list..]
Dear Andreas,
Am Mittwoch, 7. März 2007 17:33 schrieb Andreas Mueller:
I can imagine that this is a quichotesque undertaking..
Hmm, to clarify: the reliability of VPS is impaired starting from 00:00 CET up to which time? Which times are impared, start and/or end time?
Maybe Klaus could syslog some more detailed infos regarding the deviation, and possibly check the values semantically, e.g. in this case, vdr could have checked the original duration, compared with the broadcasted one, and better had used the longer one.. Could that be a useful strategy? Does anybody see downsides?
Maybe time to get my feet wet with vdr hacking (but my c++ brain is quite rusty..)
Thanks for your helpful answer, Andreas.
Kind regards, Pete
Hans-Peter Jansen wrote:
All events are stopped (status 1) on 0100 CET/0200 CEST. So if you have an event that runs from 0030 CET to 0130 CET, it will stop (status 1) on 0100 CET. For the next event, in this case starting at 0130, everything will be okay, so status 4 will be transmitted at the correct time.
So for every programme which will end (or might end in the case of a delay) after 0100 CET/0200 CEST, you'll have to take into account that the VPS timer will stop at 0100/0200.
No, I don't think this is the right way. This is really something the broadcaster has to fix.
Regards, Andreas.