From patchwork Thu Aug 3 00:15:23 2006 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 8bit X-Patchwork-Submitter: Udo Richter X-Patchwork-Id: 12369 Received: from mail.gmx.net ([213.165.64.21]) by www.linuxtv.org with smtp (Exim 4.50) id 1G8Qw4-0001tD-Q2 for vdr@linuxtv.org; Thu, 03 Aug 2006 02:19:36 +0200 Received: (qmail invoked by alias); 03 Aug 2006 00:19:02 -0000 Received: from p548A452E.dip0.t-ipconnect.de (EHLO [192.168.73.1]) [84.138.69.46] by mail.gmx.net (mp037) with SMTP; 03 Aug 2006 02:19:02 +0200 X-Authenticated: #1417946 Message-ID: <44D1401B.8070401@gmx.de> Date: Thu, 03 Aug 2006 02:15:23 +0200 From: Udo Richter User-Agent: Thunderbird 2.0a1 (Windows/20060802) MIME-Version: 1.0 To: VDR Mailing List Subject: Re: [vdr] Bug? Missing next timer event References: <44D0C3C1.9030608@gmx.de> In-Reply-To: <44D0C3C1.9030608@gmx.de> X-Y-GMX-Trusted: 0 X-BeenThere: vdr@linuxtv.org X-Mailman-Version: 2.1.5 Precedence: list Reply-To: VDR Mailing List List-Id: VDR Mailing List List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Thu, 03 Aug 2006 00:19:36 -0000 Status: O X-Status: X-Keywords: X-UID: 10286 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 --- timers.c.bak 2006-08-03 01:01:35.191684432 +0200 +++ timers.c 2006-08-03 01:59:23.883790392 +0200 @@ -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; }