Bug? Missing next timer event
Commit Message
Udo Richter wrote:
> I just noticed a serious issue with a missed timer event. After a daily
> timer, VDR did an automatic shutdown, but not for the next day to record
> the same timer again, but for the next following timer event!
Ok, I was able to verify and debug this a bit. Using the attached patch,
I was able to provoke and monitor this.
The attached patch adds debug code to GetNextActiveTimer, checking
whether Matches() does anything, and whether StopTime() is in the past.
This log shows a daily timer running out:
> Aug 3 01:33:28 vdr: timer 14 (1 0124-0135 'Das Erste') modified (active)
> Aug 3 01:33:30 vdr: timer 14 (1 0124-0135 'Das Erste') start
> Aug 3 01:33:39 vdr: Power button pressed
> Aug 3 01:33:39 vdr: confirm: Aufnahme läuft - trotzdem ausschalten?
> Aug 3 01:33:39 vdr: warning: Aufnahme läuft - trotzdem ausschalten?
> Aug 3 01:33:50 vdr: not confirmed
> Aug 3 01:35:00 vdr: timer 14 (1 0124-0135 'Das Erste') stop
> Aug 3 01:35:01 vdr: Start/Stop Timer error: Start changed from Thu Aug 3 01:24:00 2006 to Fri Aug 4 01:24:00 2006, stop from Thu Aug 3 01:35:00 2006 to Fri Aug 4 01:35:00 2006
> Aug 3 01:35:01 vdr: next timer event at Fri Aug 4 01:24:00 2006
> Aug 3 01:35:01 vdr: confirm: Taste drücken, um Ausschalten abzubrechen
> Aug 3 01:35:01 vdr: warning: Taste drücken, um Ausschalten abzubrechen
> Aug 3 01:35:07 vdr: confirmed
'The Start/Stop Timer error' shows that GetNextActiveTimer would have
seen the finished Aug 3 timer, not the next Aug 4 timer. The timing for
shutdown is actually that short, and the 'next timer' is not updated,
even if the shutdown is 5 minutes later.
However, observe that the check is done at 01:35:01. If VDR is a little
bit faster, the check could be at 01:35:00, and the call to Matches()
would not switch to the Aug 4 timer either.
The other debug message should show this, but I could not trigger this.
Maybe on a faster machine it would do.
I suggest two changes to VDR:
- As the patch does, add a Matches() call to GetNextActiveTimer
- In Matches(), change this:
@@ -351,7 +351,7 @@
if (DayMatches(t0)) {
time_t a = SetTime(t0, begin);
time_t b = a + length;
- if ((!day || a >= day) && t <= b) {
+ if ((!day || a >= day) && t < b) {
startTime = a;
stopTime = b;
break;
This way the daily timer already jumps to next day at t=StopTime, not at
t=StopTime+1. This matches the following line:
return startTime <= t + Margin && t < stopTime; // must stop
*before* stopTime to allow adjacent timers
Both changes should fix this issue imho, but its safer to have both.
By the way, in the above situation, VDR did shut down 7 seconds after
the timer ended, because UserShutdown was still true. Normally VDR would
have waited 5 minutes. But thats another issue.
Cheers,
Udo
@@ -647,6 +647,23 @@
{
cTimer *t0 = NULL;
for (cTimer *ti = First(); ti; ti = Next(ti)) {
+ time_t stop=ti->StopTime();
+ time_t start=ti->StartTime();
+ ti->Matches();
+ if (stop!=ti->StopTime() || start!=ti->StartTime()) {
+ esyslog("Start/Stop Timer error: Start changed from %s to %s, stop from %s to %s",
+ *TimeToString(start),*TimeToString(ti->StartTime()),
+ *TimeToString(stop),*TimeToString(ti->StopTime()));
+ printf("Start/Stop Timer error: Start changed from %s to %s, stop from %s to %s\n",
+ *TimeToString(start),*TimeToString(ti->StartTime()),
+ *TimeToString(stop),*TimeToString(ti->StopTime()));
+ }
+ if (ti->StopTime() <= time(NULL)) {
+ esyslog("Start/Stop Timer error: Outdated timer from %s to %s",
+ *TimeToString(start),*TimeToString(stop));
+ printf("Start/Stop Timer error: Outdated timer from %s to %s\n",
+ *TimeToString(start),*TimeToString(stop));
+ }
if ((ti->HasFlags(tfActive)) && (!t0 || ti->StopTime() > time(NULL) && ti->Compare(*t0) < 0))
t0 = ti;
}