nächster Timer wird falsch erkannt

Dr. Seltsam · 14. Juni 2006

ich habe die Tagesschau für tägliche Aufnahme programmiert (MDMDFSS). Zusätzlich ist ein Timer für jeden Samstag vormittag aktiv (c´t-Magazin).

Sporadisch habe ich nun das Problem, das der Rechner zur Tagesschau nicht aufwacht. Zum Beispiel heute

Also schaue ich mir das Log von gestern Abend an, als der Rechner runtergefahren wurde (und kurz davor)

Jun 13 22:43:41 linvdr user.info vdr: [2974] cleaning up schedules data
Jun 13 22:43:47 linvdr user.info vdr: [2974] timer 2 (1 2000-2018 VPS 'Tagesschau') set to event Die 13.06.2006 20:00-20:15 (VPS: 13.06 20:00) 'Tagesschau'

Jun 13 22:57:56 linvdr user.debug vdr: [2974] next timer event at Sat Jun 17 12:25:00 2006
Jun 13 22:57:56 linvdr user.info vdr: [2974] confirm: Taste drücken, um Ausschalten abzubrechen
Jun 13 22:57:56 linvdr user.info vdr: [2974] warning: Taste drücken, um Ausschalten abzubrechen
Jun 13 23:00:01 linvdr cron.notice crond[3019]: USER root pid 3049 cmd convert.pl -q -s
Jun 13 23:02:57 linvdr user.info vdr: [2974] confirmed
Jun 13 23:02:57 linvdr user.info vdr: [2974] executing '/usr/bin/poweroff.pl 1150539900 307323 25 "c't magazin" 0'

Wieso setzt vdr am 13.6. abends um 22:43 den nächsten Ausführungstermin für die tägliche Tagesschau auf den gleichen Tag (also quasi für einen in der Vergangenheit liegenden Zeitpunkt) ????

Klar, dass dann das poweroff-script als nächsten Timer das c´t-Magazin für nächsten Samstag einträgt. Die Tagesschau kommt danach ja erst in 364 Tagen ....

Wenn ich den Timer aufrufe, steht die Tagesschau immer noch auf täglich. Meistens wird sie ja auch aufgenommen ....

Ich versteh´s nicht! vdr-Version ist 1.4.0-3

Dr. Seltsam · 14. Juni 2006

ich hab eine Idee:

Wenn ich mich genau entsinne, ist das Problem erst aufgetreten, seitdem ich für den Tagesschau-Timer VPS aktiviert habe.

Ich vermute mal, vdr will sicherheitshalber auch trotz abgelaufener Uhrzeit noch auf die Sendung warten, falls diese verspätet kommt.
Für das poweroff-script ist das natürlich fatal: Da müsste man die poweroff.pl wohl so modifizieren, dass in der Vergangenheit liegende Zeiten bei VPS-Timern nicht in /proc/acpi/alarm geschrieben werden

woprr · 14. Juni 2006

so ist es. seither benutz ich vps nich mehr.

kls · 15. Juni 2006

Zitat

Originally posted by Dr. Seltsam
ich habe die Tagesschau für tägliche Aufnahme programmiert (MDMDFSS). Zusätzlich ist ein Timer für jeden Samstag vormittag aktiv (c´t-Magazin).

Sporadisch habe ich nun das Problem, das der Rechner zur Tagesschau nicht aufwacht. Zum Beispiel heute

Also schaue ich mir das Log von gestern Abend an, als der Rechner runtergefahren wurde (und kurz davor)

Jun 13 22:43:41 linvdr user.info vdr: [2974] cleaning up schedules data
Jun 13 22:43:47 linvdr user.info vdr: [2974] timer 2 (1 2000-2018 VPS 'Tagesschau') set to event Die 13.06.2006 20:00-20:15 (VPS: 13.06 20:00) 'Tagesschau'

Alles anzeigen

Interessant wäre das Log vom Start des VDR bis zu diesem Zeitpunkt. Schau mal, ob während dieser Zeit eine Zeile wie

switching device X to channel 1

vorkommt, oder ob du manuell auf den ARD-Transponder geschaltet hast. Falls nämlich seit dem Start von VDR niemals dieser Transponder eingestellt war, dann kann er anscheinend auf dem ersten Event "hängenbleiben", auch wenn dieser schon lang vorbei ist.

Kann es sein, daß du nur _eine_ DVB-Karte hast? Dann könnte ich mir nämlich erklären, wie das passieren konnte. Ansonsten würde VDR eine freie DVB-Karte benutzen, um ab und zu auf den jeweiligen Transponder eines VPS-Timers zu schalten, damit er eventuelle Änderungen mitbekommt.

Ich werde es auf jeden Fall mal so ändern, daß auch auf einem Sytem mit nur einer DVB-Karte nach dem Start auf jeden Fall alle Transponder mit VPS-Timern einmal angewählt werden, um die Events aktuell zu haben.

Klaus

Dr. Seltsam · 15. Juni 2006

Zitat

Original von kls
Interessant wäre das Log vom Start des VDR bis zu diesem Zeitpunkt. Schau mal, ob während dieser Zeit eine Zeile wie

switching device X to channel 1

vorkommt, oder ob du manuell auf den ARD-Transponder geschaltet hast. Falls nämlich seit dem Start von VDR niemals dieser Transponder eingestellt war, dann kann er anscheinend auf dem ersten Event "hängenbleiben", auch wenn dieser schon lang vorbei ist.

Hallo Klaus,
hier ein ausführlicheres Log:

Code

Jun 13 21:43:46 linvdr user.info vdr: [2974] switching to channel 1
Jun 13 21:43:46 linvdr user.debug vdr: [2974] creating directory /vtx/C-1-1101-28106
Jun 13 21:43:46 linvdr user.debug vdr: [3003] receiver on device 1 thread started (pid=3003, tid=3003)
Jun 13 21:43:46 linvdr user.debug vdr: [3004] TS buffer on device 1 thread started (pid=3004, tid=3004)
Jun 13 21:43:46 linvdr user.debug vdr: [2974] setting watchdog timer to 900 seconds
Jun 13 21:43:46 linvdr user.info vdr: [2974] timer 2 (1 2000-2018 VPS 'Tagesschau') set to event Mit 14.06.2006 20:00-20:15 (VPS: 14.06 20:00) 'Tagesschau'
Jun 13 21:43:46 linvdr user.info vdr: [2974] timer 3 (25 1225-1315 'c't magazin') set to event Sam 17.06.2006 12:30-13:00 (VPS: 17.06 12:30) 'c't magazin'
Jun 13 21:43:47 linvdr user.info vdr: [2991] channel 1 (Das Erste) event Die 13.06.2006 20:15-21:00 (VPS: 13.06 20:15) 'FIFA WM 2006 live' status 4
Jun 13 21:43:48 linvdr user.info vdr: [2991] channel 25 (hr-fernsehen) event Die 13.06.2006 20:15-21:45 (VPS: 13.06 20:15) 'Tatort' status 4
Jun 13 21:43:48 linvdr user.info vdr: [2974] connect from 127.0.0.1, port 3819 - accepted
Jun 13 21:43:51 linvdr user.debug vdr: [2974] max. latency time 3 seconds
Jun 13 21:43:52 linvdr user.info vdr: [2974] closing SVDRP connection
Jun 13 21:43:52 linvdr user.debug vdr: [2974] assuming manual start of VDR
Jun 13 21:43:56 linvdr user.info vdr: [2974] timer 2 (1 2000-2018 VPS 'Tagesschau') set to event Die 13.06.2006 20:00-20:15 (VPS: 13.06 20:00) 'Tagesschau'
Jun 13 21:44:03 linvdr cron.notice crond[3019]: crond 2.3.2 dillon, started, log level 8 
Jun 13 21:44:58 linvdr user.info vdr: [2991] channel 25 (hr-fernsehen) event Die 13.06.2006 20:15-21:45 (VPS: 13.06 20:15) 'Tatort' status 1
Jun 13 21:44:59 linvdr user.info vdr: [2991] channel 25 (hr-fernsehen) event Die 13.06.2006 21:45-22:15 (VPS: 13.06 21:45) 'hessenjournal' status 2
Jun 13 21:45:01 linvdr cron.notice crond[3019]: USER root pid 3020 cmd convert.pl -q -s 
Jun 13 21:45:25 linvdr user.info vdr: [2998] channel 5 (SAT.1) event Die 13.06.2006 20:15-22:15 'Antonia - Zwischen Liebe und Macht, Teil 3' status 4
Jun 13 21:45:25 linvdr user.info vdr: [2998] channel 6 (ProSieben) event Die 13.06.2006 21:13-22:08 'Emergency Room - Die Notaufnahme' status 4
Jun 13 21:45:49 linvdr user.info vdr: [2991] channel 25 (hr-fernsehen) event Die 13.06.2006 21:45-22:15 (VPS: 13.06 21:45) 'hessenjournal' status 4
Jun 13 21:49:11 linvdr user.info vdr: [2974] replay /video0/4400_-_Die_Rückkehrer/2006-06-13.03.36.50.99.rec
Jun 13 21:49:11 linvdr user.debug vdr: [2974] playing '/video0/4400_-_Die_Rückkehrer/2006-06-13.03.36.50.99.rec/001.vdr'
Jun 13 21:49:11 linvdr user.info vdr: [2974] loading /video0/4400_-_Die_Rückkehrer/2006-06-13.03.36.50.99.rec//marks.vdr
Jun 13 21:49:12 linvdr user.debug vdr: [3004] TS buffer on device 1 thread ended (pid=3004, tid=3004)
Jun 13 21:49:12 linvdr user.debug vdr: [3003] buffer stats: 3948 (0%) used
Jun 13 21:49:12 linvdr user.debug vdr: [3003] receiver on device 1 thread ended (pid=3003, tid=3003)
Jun 13 21:49:12 linvdr user.debug vdr: [3021] dvbplayer thread started (pid=3021, tid=3021)
Jun 13 21:49:12 linvdr user.info vdr: [3021] resuming replay at index 10344 (0:06:53.20)
Jun 13 21:49:12 linvdr user.debug vdr: [3022] non blocking file reader thread started (pid=3022, tid=3022)
Jun 13 21:49:12 linvdr user.debug vdr: [3021] SetBrokenLink: no GOP header found in video packet
Jun 13 21:49:12 linvdr user.debug vdr: [3021] setting audio track to 33 (0)
Jun 13 21:49:16 linvdr user.debug vdr: [2974] creating directory /video0/%4400_-_Die_Rückkehrer/2006-06-13.03.36.50.99.rec
Jun 13 21:49:16 linvdr user.info vdr: [2974] loading /video0/4400_-_Die_Rückkehrer/2006-06-13.03.36.50.99.rec//marks.vdr
Jun 13 21:49:16 linvdr user.debug vdr: [2974] playing '/video0/4400_-_Die_Rückkehrer/2006-06-13.03.36.50.99.rec/001.vdr'
Jun 13 21:49:16 linvdr user.debug vdr: [2974] recording to '/video0/%4400_-_Die_Rückkehrer/2006-06-13.03.36.50.99.rec/001.vdr'
Jun 13 21:49:16 linvdr user.info vdr: [2974] info: Schnitt gestartet
Jun 13 21:49:16 linvdr user.debug vdr: [3023] video cutting thread started (pid=3023, tid=3023)
Jun 13 21:49:21 linvdr user.debug vdr: [3022] non blocking file reader thread ended (pid=3022, tid=3022)
Jun 13 21:49:21 linvdr user.debug vdr: [3021] dvbplayer thread ended (pid=3021, tid=3021)
Jun 13 21:49:21 linvdr user.info vdr: [2974] switching to channel 1
Jun 13 21:49:21 linvdr user.debug vdr: [2974] buffer stats: 0 (0%) used
Jun 13 21:49:22 linvdr user.debug vdr: [3025] receiver on device 1 thread started (pid=3025, tid=3025)
Jun 13 21:49:22 linvdr user.debug vdr: [3026] TS buffer on device 1 thread started (pid=3026, tid=3026)
Jun 13 21:49:26 linvdr user.info vdr: [2991] channel 1 (Das Erste) event Die 13.06.2006 21:00-23:30 (VPS: 13.06 20:15) 'FIFA WM 2006 live' status 4
Jun 13 21:49:27 linvdr user.info vdr: [2974] timer 2 (1 2000-2018 VPS 'Tagesschau') set to event Mit 14.06.2006 20:00-20:15 (VPS: 14.06 20:00) 'Tagesschau'
Jun 13 21:49:46 linvdr user.info vdr: [2974] replay /video0/Tagesschau/_/2006-06-13.20.00.50.99.rec
Jun 13 21:49:46 linvdr user.debug vdr: [2974] playing '/video0/Tagesschau/_/2006-06-13.20.00.50.99.rec/001.vdr'
Jun 13 21:49:46 linvdr user.debug vdr: [3026] TS buffer on device 1 thread ended (pid=3026, tid=3026)
Jun 13 21:49:46 linvdr user.debug vdr: [3025] buffer stats: 3948 (0%) used
Jun 13 21:49:46 linvdr user.debug vdr: [3025] receiver on device 1 thread ended (pid=3025, tid=3025)
Jun 13 21:49:46 linvdr user.debug vdr: [3027] dvbplayer thread started (pid=3027, tid=3027)
Jun 13 21:49:46 linvdr user.debug vdr: [3028] non blocking file reader thread started (pid=3028, tid=3028)
Jun 13 21:49:46 linvdr user.debug vdr: [3027] setting audio track to 33 (0)
Jun 13 21:50:01 linvdr cron.notice crond[3019]: USER root pid 3029 cmd convert.pl -q -s 
Jun 13 21:52:09 linvdr user.debug vdr: [2974] buffer stats: 0 (0%) used
Jun 13 21:52:10 linvdr user.debug vdr: [3031] receiver on device 1 thread started (pid=3031, tid=3031)
Jun 13 21:52:10 linvdr user.debug vdr: [3032] TS buffer on device 1 thread started (pid=3032, tid=3032)
Jun 13 21:52:16 linvdr user.debug vdr: [3023] video cutting thread ended (pid=3023, tid=3023)
Jun 13 21:52:17 linvdr user.info vdr: [2974] info: Schnitt beendet
Jun 13 21:55:01 linvdr cron.notice crond[3019]: USER root pid 3033 cmd convert.pl -q -s 
Jun 13 22:00:01 linvdr cron.notice crond[3019]: USER root pid 3034 cmd convert.pl -q -s 
Jun 13 22:03:27 linvdr syslog.info -- MARK --
Jun 13 22:05:01 linvdr cron.notice crond[3019]: USER root pid 3035 cmd convert.pl -q -s 
Jun 13 22:05:11 linvdr user.debug vdr: [3028] non blocking file reader thread ended (pid=3028, tid=3028)
Jun 13 22:05:11 linvdr user.debug vdr: [3027] dvbplayer thread ended (pid=3027, tid=3027)
Jun 13 22:05:12 linvdr user.info vdr: [2974] switching to channel 1
Jun 13 22:05:12 linvdr user.debug vdr: [3032] TS buffer on device 1 thread ended (pid=3032, tid=3032)
Jun 13 22:05:12 linvdr user.debug vdr: [3031] buffer stats: 4324 (0%) used
Jun 13 22:05:12 linvdr user.debug vdr: [3031] receiver on device 1 thread ended (pid=3031, tid=3031)
Jun 13 22:05:12 linvdr user.debug vdr: [2974] buffer stats: 0 (0%) used
Jun 13 22:05:12 linvdr user.debug vdr: [3037] receiver on device 1 thread started (pid=3037, tid=3037)
Jun 13 22:05:12 linvdr user.debug vdr: [3038] TS buffer on device 1 thread started (pid=3038, tid=3038)
Jun 13 22:06:35 linvdr user.info vdr: [2974] cleaning up id3 cache
Jun 13 22:09:41 linvdr user.info vdr: [2998] channel 6 (ProSieben) event Die 13.06.2006 22:08-23:05 'The L Word - Wenn Frauen Frauen lieben' status 4
Jun 13 22:10:01 linvdr cron.notice crond[3019]: USER root pid 3039 cmd convert.pl -q -s 
Jun 13 22:15:01 linvdr cron.notice crond[3019]: USER root pid 3040 cmd convert.pl -q -s 
Jun 13 22:16:05 linvdr user.info vdr: [2998] channel 5 (SAT.1) event Die 13.06.2006 22:15-23:15 'Navy CIS' status 4
Jun 13 22:16:07 linvdr user.info vdr: [2991] channel 25 (hr-fernsehen) event Die 13.06.2006 21:45-22:15 (VPS: 13.06 21:45) 'hessenjournal' status 1
Jun 13 22:16:08 linvdr user.info vdr: [2991] channel 25 (hr-fernsehen) event Die 13.06.2006 22:15-22:45 (VPS: 13.06 22:15) 'Hauptsache Kultur' status 2
Jun 13 22:16:57 linvdr user.info vdr: [2991] channel 25 (hr-fernsehen) event Die 13.06.2006 22:15-22:45 (VPS: 13.06 22:15) 'Hauptsache Kultur' status 4
Jun 13 22:20:01 linvdr cron.notice crond[3019]: USER root pid 3041 cmd convert.pl -q -s 
Jun 13 22:23:27 linvdr syslog.info -- MARK --
Jun 13 22:25:01 linvdr cron.notice crond[3019]: USER root pid 3042 cmd convert.pl -q -s 
Jun 13 22:30:01 linvdr cron.notice crond[3019]: USER root pid 3043 cmd convert.pl -q -s 
Jun 13 22:35:01 linvdr cron.notice crond[3019]: USER root pid 3044 cmd convert.pl -q -s 
Jun 13 22:40:01 linvdr cron.notice crond[3019]: USER root pid 3045 cmd convert.pl -q -s 
Jun 13 22:43:27 linvdr syslog.info -- MARK --
Jun 13 22:43:41 linvdr user.info vdr: [2974] cleaning up schedules data
Jun 13 22:43:47 linvdr user.info vdr: [2974] timer 2 (1 2000-2018 VPS 'Tagesschau') set to event Die 13.06.2006 20:00-20:15 (VPS: 13.06 20:00) 'Tagesschau'
Jun 13 22:43:53 linvdr user.info vdr: [2974] connect from 127.0.0.1, port 1932 - accepted
Jun 13 22:43:57 linvdr user.info vdr: [2974] closing SVDRP connection
Jun 13 22:45:01 linvdr cron.notice crond[3019]: USER root pid 3046 cmd convert.pl -q -s 
Jun 13 22:46:24 linvdr user.info vdr: [2991] channel 25 (hr-fernsehen) event Die 13.06.2006 22:15-22:45 (VPS: 13.06 22:15) 'Hauptsache Kultur' status 1
Jun 13 22:46:24 linvdr user.info vdr: [2995] channel 25 (hr-fernsehen) event Die 13.06.2006 22:45-23:15 (VPS: 13.06 22:45) 'c't magazin' status 2
Jun 13 22:47:04 linvdr user.info vdr: [2991] channel 25 (hr-fernsehen) event Die 13.06.2006 22:45-23:15 (VPS: 13.06 22:45) 'c't magazin' status 4
Jun 13 22:50:01 linvdr cron.notice crond[3019]: USER root pid 3047 cmd convert.pl -q -s 
Jun 13 22:55:01 linvdr cron.notice crond[3019]: USER root pid 3048 cmd convert.pl -q -s 
Jun 13 22:57:56 linvdr user.debug vdr: [2974] next timer event at Sat Jun 17 12:25:00 2006
Jun 13 22:57:56 linvdr user.info vdr: [2974] confirm: Taste drücken, um Ausschalten abzubrechen
Jun 13 22:57:56 linvdr user.info vdr: [2974] warning: Taste drücken, um Ausschalten abzubrechen
Jun 13 23:00:01 linvdr cron.notice crond[3019]: USER root pid 3049 cmd convert.pl -q -s 
Jun 13 23:02:57 linvdr user.info vdr: [2974] confirmed
Jun 13 23:02:57 linvdr user.info vdr: [2974] executing '/usr/bin/poweroff.pl 1150539900 307323 25 "c't magazin" 0'
Jun 13 23:03:00 linvdr daemon.info init: ^MStarting pid 3056, console /dev/console: '/etc/init.d/rcShutdown'
Jun 13 23:03:00 linvdr user.debug vdr: [2974] max. latency time 305 seconds
Jun 13 23:03:03 linvdr user.info vdr: [2974] caught signal 15
Jun 13 23:03:03 linvdr user.info vdr: [2974] stopping plugin: tvonscreen
Jun 13 23:03:03 linvdr user.info vdr: [2974] stopping plugin: mplayer
Jun 13 23:03:03 linvdr user.info vdr: [2974] stopping plugin: mp3
Jun 13 23:03:03 linvdr user.info vdr: [2974] stopping plugin: femon
Jun 13 23:03:03 linvdr user.info vdr: [2974] stopping plugin: epgsearch
Jun 13 23:03:03 linvdr user.info vdr: [2974] stopping plugin: osdteletext
Jun 13 23:03:03 linvdr user.info vdr: [2974] stopping plugin: pvrinput
Jun 13 23:03:06 linvdr user.err vdr: [2974] ERROR: KBD remote control thread 3001 won't end (waited 3 seconds) - canceling it...
Jun 13 23:03:06 linvdr user.info vdr: [2974] saved setup to /etc/vdr/setup.conf
Jun 13 23:03:06 linvdr user.debug vdr: [2990] tuner on device 1 thread ended (pid=2990, tid=2990)
Jun 13 23:03:06 linvdr user.debug vdr: [3037] receiver on device 1 thread ended (pid=3037, tid=3037)
Jun 13 23:03:06 linvdr user.debug vdr: [2991] section handler thread ended (pid=2991, tid=2991)
Jun 13 23:03:06 linvdr user.debug vdr: [2994] tuner on device 2 thread ended (pid=2994, tid=2994)
Jun 13 23:03:06 linvdr user.debug vdr: [2995] section handler thread ended (pid=2995, tid=2995)
Jun 13 23:03:06 linvdr user.debug vdr: [2997] tuner on device 3 thread ended (pid=2997, tid=2997)
Jun 13 23:03:06 linvdr user.debug vdr: [2998] section handler thread ended (pid=2998, tid=2998)
Jun 13 23:03:06 linvdr user.info vdr: [2974] deleting plugin: tvonscreen
Jun 13 23:03:06 linvdr user.info vdr: [2974] deleting plugin: mplayer
Jun 13 23:03:06 linvdr user.info vdr: [2974] deleting plugin: mp3
Jun 13 23:03:06 linvdr user.info vdr: [2974] deleting plugin: femon
Jun 13 23:03:06 linvdr user.info vdr: [2974] deleting plugin: epgsearch
Jun 13 23:03:06 linvdr user.info vdr: [2974] deleting plugin: osdteletext
Jun 13 23:03:06 linvdr user.debug vdr: [2974] buffer stats: 0 (0%) used
Jun 13 23:03:06 linvdr user.info vdr: [2974] deleting plugin: pvrinput
Jun 13 23:03:06 linvdr user.debug vdr: [2974] =====================
Jun 13 23:03:06 linvdr user.debug vdr: [2974] EPG bugfix statistics
Jun 13 23:03:06 linvdr user.debug vdr: [2974] =====================
Jun 13 23:03:06 linvdr user.debug vdr: [2974] IF SOMEBODY WHO IS IN CHARGE OF THE EPG DATA FOR ONE OF THE LISTED
Jun 13 23:03:06 linvdr user.debug vdr: [2974] CHANNELS READS THIS: PLEASE TAKE A LOOK AT THE FUNCTION cEvent::FixEpgBugs()
Jun 13 23:03:06 linvdr user.debug vdr: [2974] IN VDR/epg.c TO LEARN WHAT'S WRONG WITH YOUR DATA, AND FIX IT!
Jun 13 23:03:06 linvdr user.debug vdr: [2974] =====================
Jun 13 23:03:06 linvdr user.debug vdr: [2974] Fix^IHits^IChannels
Jun 13 23:03:06 linvdr user.debug vdr: [2974] 2^I114^IZDFinfokanal
Jun 13 23:03:06 linvdr user.debug vdr: [2974] 3^I1795^IKiKa, ProSieben, SAT.1, N24, KABEL1, erotik first 23-5:30
Jun 13 23:03:06 linvdr user.debug vdr: [2974] 4^I12^IZDF, Info/3sat, EinsExtra, 3sat, EinsExtra
Jun 13 23:03:06 linvdr user.debug vdr: [2974] 6^I68^IBayerisches FS, SÜDWEST Ferns. BW, BR-alpha, rbb Berlin, rbb Brandenburg, SÜDWEST Ferns. RP, ...
Jun 13 23:03:06 linvdr user.debug vdr: [2974] 7^I2607^IBayerisches FS, SÜDWEST Ferns. BW, BR-alpha, Phoenix, Das Erste, hr-fernsehen, ...
Jun 13 23:03:06 linvdr user.debug vdr: [2974] 9^I120^ITERRA NOVA
Jun 13 23:03:06 linvdr user.debug vdr: [2974] 11^I120^ITERRA NOVA
Jun 13 23:03:06 linvdr user.debug vdr: [2974] =====================
Jun 13 23:03:06 linvdr user.debug vdr: [2974] max. latency time 305 seconds
Jun 13 23:03:06 linvdr user.info vdr: [2974] exiting
Jun 13 23:03:08 linvdr user.info kernel: ACPI: PCI interrupt for device 0000:01:01.0 disabled
Jun 13 23:03:08 linvdr user.info kernel: b2c2-flexcop: B2C2 FlexcopII/II(b)/III digital TV receiver chip unloaded successfully
Jun 13 23:03:09 linvdr user.warn kernel: saa7146: unregister extension 'budget_av'.
Jun 13 23:03:09 linvdr user.warn kernel: saa7146: unregister extension 'budget dvb'.
Jun 13 23:03:10 linvdr user.warn kernel: saa7146: unregister extension 'budget_ci dvb'.
Jun 13 23:03:10 linvdr user.info kernel: ACPI: PCI interrupt for device 0000:01:03.0 disabled
Jun 13 23:03:10 linvdr user.warn kernel: saa7146: unregister extension 'dvb'.
Jun 13 23:03:11 linvdr user.info kernel: ACPI: PCI inter

Alles anzeigen

um 21:43:46 sieht es richtig aus. 10sec später wird es fehlerhaft geändert.
um 21:49:27 (nach einem Wechsel auf Das Erste) wirds wieder richtig gesetzt. Um 22:43:47 wieder falsch. Und das ist dann der letzte Stand, der zum fehlerhaften Eintrag im Poweroff-script führt.

Zitat

Kann es sein, daß du nur _eine_ DVB-Karte hast? Dann könnte ich mir nämlich erklären, wie das passieren konnte. Ansonsten würde VDR eine freie DVB-Karte benutzen, um ab und zu auf den jeweiligen Transponder eines VPS-Timers zu schalten, damit er eventuelle Änderungen mitbekommt.

nee, eine 2. DVB-C-Karte ist jetzt neuerdings drin

kls · 16. Juni 2006

Zitat

Originally posted by Dr. Seltsam
...
um 21:43:46 sieht es richtig aus. 10sec später wird es fehlerhaft geändert.
um 21:49:27 (nach einem Wechsel auf Das Erste) wirds wieder richtig gesetzt. Um 22:43:47 wieder falsch. Und das ist dann der letzte Stand, der zum fehlerhaften Eintrag im Poweroff-script führt.

Das mehrmalige Hin und Her ist allerdings sehr merkwürdig. Momentan kann ich mir das nicht erklären.

Hast du irgend etwas am laufen, das die EPG-Daten vielleicht verändert?

Tritt das bei dir regelmäßig auf? Wenn ja, dann bau doch mal in cTimer::SetEventFromSchedule() einige Debug-Ausgaben ein, um zu sehen, wie er zur jeweiligen Entscheidung kommt.

Klaus

Dr. Seltsam · 16. Juni 2006

Zitat

Original von kls
Hast du irgend etwas am laufen, das die EPG-Daten vielleicht verändert?

nicht das ich wüsste. was könnte das z.B. sein?

Zitat

Tritt das bei dir regelmäßig auf? Wenn ja, dann bau doch mal in cTimer::SetEventFromSchedule() einige Debug-Ausgaben ein, um zu sehen, wie er zur jeweiligen Entscheidung kommt.

mache ich gerne, aber da brauche ich Hilfe ....

kls · 17. Juni 2006

Zitat

Originally posted by Dr. Seltsam

nicht das ich wüsste. was könnte das z.B. sein?

Das könnte irgend ein Patch, Plugin oder externes Tool sein, das die EPG-Daten verändert. Am besten, du testest es mal mit "plain vanilla" VDR, falls das möglich ist.

Zitat

mache ich gerne, aber da brauche ich Hilfe ....

Fangen wir mal hiermit an:

Diff

--- timers.c    2006/05/25 14:36:37     1.61
+++ timers.c    2006/06/17 11:30:50
@@ -494,6 +494,14 @@
                   }
                }
            }
+        //XXX
+        if (Index() == 1) {// timer 2
+           if (Event && event && Event != event) {
+              dsyslog("event = %d %s", event->RunningStatus(), *event->ToDescr());
+              dsyslog("Event = %d %s", Event->RunningStatus(), *Event->ToDescr());
+              }
+           }
+        //XXX
         SetEvent(Event);
         }
      }

Alles anzeigen

Dabei wird davon ausgegangen, daß dein Tagesschau-Timer die Nummer 2 hat. Falls sich das inzwischen geändert haben sollte, müsstest du den Code anpassen.

Klaus

Dr. Seltsam · 22. Juni 2006

Hallo Klaus,

den Patch habe ich inzwischen drin.
Blöde Frage: wie erkenne ich die Nr. des Timers? nach der Reihenfolge in der Anzeige scheint es nicht zu gehen, denn dort ist die Tagesschau an erster Stelle. In /etc/vdr/timers.conf steht sie an 4. Stelle

Tja, jetzt habe ich wieder so einen Fall, aber VPS war beim Timer deaktiviert!

Code

Jun 21 19:53:02 linvdr user.info vdr: [2973] timer 2 (25 1225-1315 'c't magazin') set to event Sam 24.06.2006 12:30-13:00 (VPS: 24.06 12:30) 'c't magazin'
Jun 21 19:53:02 linvdr user.info vdr: [2973] timer 4 (1 1957-2020 'Tagesschau') set to event Mit 21.06.2006 20:00-20:15 (VPS: 21.06 20:00) 'Tagesschau'
Jun 21 19:53:02 linvdr user.info vdr: [2991] channel 1 (Das Erste) event Mit 21.06.2006 19:55-20:00 (VPS: 21.06 19:55) 'Börse im Ersten' status 2
Jun 21 19:53:03 linvdr user.info vdr: [2991] channel 25 (hr-fernsehen) event Mit 21.06.2006 19:30-19:58 (VPS: 21.06 19:30) 'Hessenschau' status 4
Jun 21 19:53:04 linvdr user.info vdr: [2973] connect from 127.0.0.1, port 2476 - accepted
Jun 21 19:53:06 linvdr user.debug vdr: [2973] max. latency time 2 seconds
Jun 21 19:53:07 linvdr user.info vdr: [2973] closing SVDRP connection
Jun 21 19:53:18 linvdr cron.notice crond[3020]: crond 2.3.2 dillon, started, log level 8
Jun 21 19:53:21 linvdr user.info vdr: [3000] EPGSearch: timer conflict check started
Jun 21 19:53:21 linvdr user.info vdr: [3000] EPGSearch: timer conflict check finished
Jun 21 19:54:40 linvdr user.info vdr: [2998] channel 5 (SAT.1) event Mit 21.06.2006 19:45-20:15 'K 11 - Kommissare im Einsatz' status 4
Jun 21 19:54:41 linvdr user.info vdr: [2998] channel 6 (ProSieben) event Mit 21.06.2006 18:58-19:59 'Galileo' status 4
Jun 21 19:55:01 linvdr cron.notice crond[3020]: USER root pid 3021 cmd convert.pl -q -s
Jun 21 19:55:09 linvdr user.info vdr: [2991] channel 1 (Das Erste) event Mit 21.06.2006 19:55-20:00 (VPS: 21.06 19:55) 'Börse im Ersten' status 4
Jun 21 19:57:00 linvdr user.debug vdr: [2973] switching device 2 to channel 1
Jun 21 19:57:00 linvdr user.info vdr: [2973] timer 4 (1 1957-2020 'Tagesschau') start
Jun 21 19:57:00 linvdr user.debug vdr: [2973] Title: 'Tagesschau' Subtitle: ''
Jun 21 19:57:00 linvdr user.info vdr: [2973] record /video0/Tagesschau/_/2006-06-21.19.57.50.99.rec
Jun 21 19:57:00 linvdr user.debug vdr: [2973] creating directory /video0/Tagesschau/_/2006-06-21.19.57.50.99.rec
Jun 21 19:57:00 linvdr user.debug vdr: [2973] recording to '/video0/Tagesschau/_/2006-06-21.19.57.50.99.rec/001.vdr'
Jun 21 19:57:00 linvdr user.debug vdr: [3022] file writer thread started (pid=3022, tid=3022)
Jun 21 19:57:00 linvdr user.debug vdr: [3023] recording thread started (pid=3023, tid=3023)
Jun 21 19:57:00 linvdr user.debug vdr: [3024] receiver on device 2 thread started (pid=3024, tid=3024)
Jun 21 19:57:00 linvdr user.debug vdr: [3025] TS buffer on device 2 thread started (pid=3025, tid=3025)
Jun 21 19:58:33 linvdr user.info vdr: [2995] channel 1 (Das Erste) event Mit 21.06.2006 19:55-20:00 (VPS: 21.06 19:55) 'Börse im Ersten' status 1
Jun 21 19:58:33 linvdr user.info vdr: [2991] channel 1 (Das Erste) event Mit 21.06.2006 20:00-20:15 (VPS: 21.06 20:00) 'Tagesschau' status 2
Jun 21 19:59:45 linvdr user.info vdr: [2991] channel 25 (hr-fernsehen) event Mit 21.06.2006 19:30-19:58 (VPS: 21.06 19:30) 'Hessenschau' status 1
Jun 21 19:59:46 linvdr user.info vdr: [2991] channel 25 (hr-fernsehen) event Mit 21.06.2006 19:58-20:00 (VPS: 21.06 19:30) 'hessenschau wetter' status 2
Jun 21 20:00:02 linvdr cron.notice crond[3020]: USER root pid 3026 cmd convert.pl -q -s
Jun 21 20:00:06 linvdr user.info vdr: [2991] channel 1 (Das Erste) event Mit 21.06.2006 20:00-20:15 (VPS: 21.06 20:00) 'Tagesschau' status 4
Jun 21 20:00:10 linvdr user.info vdr: [2991] channel 25 (hr-fernsehen) event Mit 21.06.2006 20:00-20:15 (VPS: 21.06 20:00) 'Tagesschau' status 4
Jun 21 20:05:01 linvdr cron.notice crond[3020]: USER root pid 3027 cmd convert.pl -q -s
Jun 21 20:08:42 linvdr user.info vdr: [2998] channel 6 (ProSieben) event Mit 21.06.2006 19:59-20:15 'NEWSTIME' status 4
Jun 21 20:10:01 linvdr cron.notice crond[3020]: USER root pid 3028 cmd convert.pl -q -s
Jun 21 20:12:43 linvdr syslog.info -- MARK --
Jun 21 20:15:01 linvdr cron.notice crond[3020]: USER root pid 3029 cmd convert.pl -q -s
Jun 21 20:16:21 linvdr user.info vdr: [2991] channel 25 (hr-fernsehen) event Mit 21.06.2006 20:00-20:15 (VPS: 21.06 20:00) 'Tagesschau' status 1
Jun 21 20:16:22 linvdr user.info vdr: [2995] channel 25 (hr-fernsehen) event Mit 21.06.2006 20:15-20:45 (VPS: 21.06 20:15) 'Hessen-Reporter' status 2
Jun 21 20:16:26 linvdr user.info vdr: [2991] channel 25 (hr-fernsehen) event Mit 21.06.2006 20:15-20:45 (VPS: 21.06 20:15) 'Hessen-Reporter' status 4
Jun 21 20:16:38 linvdr user.info vdr: [2991] channel 1 (Das Erste) event Mit 21.06.2006 20:15-21:45 (VPS: 21.06 20:15) 'Die Schönste aus Bitterfeld' status 4
Jun 21 20:17:05 linvdr user.info vdr: [2998] channel 6 (ProSieben) event Mit 21.06.2006 20:15-21:57 'Stürmische Liebe - Swept Away' status 4
Jun 21 20:17:05 linvdr user.info vdr: [2998] channel 5 (SAT.1) event Mit 21.06.2006 20:15-22:15 'Sind denn alle netten Männer schwul' status 4
Jun 21 20:20:00 linvdr user.debug vdr: [3023] recording thread ended (pid=3023, tid=3023)
Jun 21 20:20:00 linvdr user.debug vdr: [3025] TS buffer on device 2 thread ended (pid=3025, tid=3025)
Jun 21 20:20:00 linvdr user.debug vdr: [3024] buffer stats: 155852 (7%) used
Jun 21 20:20:00 linvdr user.debug vdr: [3024] receiver on device 2 thread ended (pid=3024, tid=3024)
Jun 21 20:20:00 linvdr user.debug vdr: [3022] file writer thread ended (pid=3022, tid=3022)
Jun 21 20:20:01 linvdr user.debug vdr: [2973] buffer stats: 266772 (5%) used
Jun 21 20:20:01 linvdr user.info vdr: [2973] timer 4 (1 1957-2020 'Tagesschau') stop
Jun 21 20:20:01 linvdr cron.notice crond[3020]: USER root pid 3030 cmd convert.pl -q -s
Jun 21 20:20:02 linvdr user.debug vdr: [2973] next timer event at Sat Jun 24 12:25:00 2006
Jun 21 20:20:02 linvdr user.info vdr: [2973] confirm: Taste drücken, um Ausschalten abzubrechen
Jun 21 20:20:02 linvdr user.info vdr: [2973] warning: Taste drücken, um Ausschalten abzubrechen
Jun 21 20:23:00 linvdr user.info vdr: [3000] EPGSearch: timer conflict check started
Jun 21 20:23:00 linvdr user.info vdr: [3000] EPGSearch: timer conflict check finished
Jun 21 20:25:01 linvdr cron.notice crond[3020]: USER root pid 3031 cmd convert.pl -q -s
Jun 21 20:25:03 linvdr user.info vdr: [2973] confirmed
Jun 21 20:25:03 linvdr user.info vdr: [2973] executing '/usr/bin/poweroff.pl 1151144700 230397 25 "c't magazin" 0'

Alles anzeigen

das macht mich stutzig:
Jun 21 20:20:02 linvdr user.debug vdr: [297 21 20:20:02 linvdr user.debug vdr: [2973] next timer event at Sat Jun 24 12:25:00 2006

Wieso erkennt vdr nicht, dass bei einem täglichen Timer die nächste Tagesschau am 22.06 das nächste timer event ist ?? Stattdessen wird Timer #2 , der erst am 24.06. kommt, gesetzt. bei diesem Timer ist die Darstellung im OSD un in timers.conf übrigens identisch -beides in der zweiten Zeile.

kls · 22. Juni 2006

Zitat

Originally posted by Dr. Seltsam
Hallo Klaus,

den Patch habe ich inzwischen drin.
Blöde Frage: wie erkenne ich die Nr. des Timers? nach der Reihenfolge in der Anzeige scheint es nicht zu gehen, denn dort ist die Tagesschau an erster Stelle. In /etc/vdr/timers.conf steht sie an 4. Stelle

Die Nummern der Timer entsprechen ihrer Position In der timers.conf. Im Timers-Menü sind sie immer nach der Startzeit sortiert.

Zitat

das macht mich stutzig:
Jun 21 20:20:02 linvdr user.debug vdr: [297 21 20:20:02 linvdr user.debug vdr: [2973] next timer event at Sat Jun 24 12:25:00 2006

Wieso erkennt vdr nicht, dass bei einem täglichen Timer die nächste Tagesschau am 22.06 das nächste timer event ist ?? Stattdessen wird Timer #2 , der erst am 24.06. kommt, gesetzt. bei diesem Timer ist die Darstellung im OSD un in timers.conf übrigens identisch -beides in der zweiten Zeile.

Ich glaube ich sehe jetzt, woran das liegt. VDR wird unmittelbar nach der Aufnahme heruntergefahren. Bis dahin vergehen zwar noch 5 Minuten im "Press any key to cancel shutdown" Prompt, aber während dieser Zeit hat er keine Gelegenheit mehr, die Funktion Timers.SetEvents() aufzurufen. Das wäre aber nötig, um den gerade abgelaufenen Timer auf den nächsten Event zu setzen.

Da muß ich mir wohl cTimer::SetEventFromSchedule() nochmal genauer anschauen um herauszufunden, ab wann man davon ausgehen kann, daß ein gerade abgelaufener Timer sicher auf dem nächsten Event (oder keinem mehr) steht.

Das löst aber immer noch nicht das Rätsel, warum dein Tagesschau-Timer manchmal innerhalb weniger Sekunden zwischen zwei Events hin- und hergeschaltet wird...

Klaus

Dr. Seltsam · 22. Juni 2006

Hallo Klaus,
prima, das kannst Du bestimmt fixen

Zitat

Original von kls
Das löst aber immer noch nicht das Rätsel, warum dein Tagesschau-Timer manchmal innerhalb weniger Sekunden zwischen zwei Events hin- und hergeschaltet wird...

da werde ich dann nochmal einen VPS-Timer mit der zum Patch passenden Timer-Nr. anlegen, damit wir das nächstes mal genauer sehen.

nächster Timer wird falsch erkannt

Jetzt mitmachen!

Teilen

Benutzer online in diesem Thema