Hi,
I've noticed some shutdown problems with vdr-1.5.1 in my setup: when my vdr wakes up for a timed recording, it doesn't automatically shutdown itself anymore after the recording is done. The MinEventTimeout is set to 15 minutes and MinUserInactivity to 600 minutes, but in my case there hasn't been any user activity, so vdr should have shutdown in 15 minutes after the recording was stopped and the logs don't reveal anything unusual. Have I misunderstood something? Does this automatic shutdown feature still work in your setups?
BR, -- rofa
Rolf Ahrenberg wrote:
I've noticed some shutdown problems with vdr-1.5.1 in my setup: when my vdr wakes up for a timed recording, it doesn't automatically shutdown itself anymore after the recording is done. The MinEventTimeout is set to 15 minutes and MinUserInactivity to 600 minutes, but in my case there hasn't been any user activity, so vdr should have shutdown in 15 minutes after the recording was stopped and the logs don't reveal anything unusual. Have I misunderstood something? Does this automatic shutdown feature still work in your setups?
It should work, and it does for me.
Check your log for the "assuming manual start of VDR" line around VDR startup. This indicates that the wakeup was more than 10 minutes away from the time that VDR remembered on last shutdown.
Also check your setup.conf for the NextWakeupTime entry, thats where VDR remembers the planned wakeup time now. (This is a time_t, you can translate it with perl -e "print scalar localtime(1172945228)")
Finally, there should be an "next timer event at" or "next plugin wakeup at" in the logs around shutdown that also indicates the time VDR planned to wake up.
Cheers,
Udo
On Sat, 3 Mar 2007, Udo Richter wrote:
Check your log for the "assuming manual start of VDR" line around VDR startup. This indicates that the wakeup was more than 10 minutes away from the time that VDR remembered on last shutdown.
No "assuming manual start of VDR" entry found on my logs, so this really was on automatic wakeup for the timer.
Also check your setup.conf for the NextWakeupTime entry, thats where VDR remembers the planned wakeup time now. (This is a time_t, you can translate it with perl -e "print scalar localtime(1172945228)")
Finally, there should be an "next timer event at" or "next plugin wakeup at" in the logs around shutdown that also indicates the time VDR planned to wake up.
VDR # fgrep NextWakeupTime /etc/vdr/setup.conf NextWakeupTime = 1172998680
VDR # perl -e "print scalar localtime(1172998680)" Sun Mar 4 10:58:00 2007
VDR # fgrep "next timer" /var/log/vdr.log Mar 4 02:05:57 xxx vdr: [6748] next timer event at Sun Mar 4 10:58:00 2007
Mar 4 10:58:00 xxx vdr: [6688] timer 18 (5 1058-1130 'xxx') start Mar 4 11:30:00 xxx vdr: [6688] timer 18 (5 1058-1130 'xxx') stop Mar 4 11:30:09 xxx vdr: [6700] channel 4 (Nelonen) event Su 04.03.2007 11:30-12:30 'Alaston tiede' status 4 Mar 4 11:31:09 xxx vdr: [6688] deleting timer 18 (5 1058-1130 'xxx') ... and vdr just stays on ...
BR, -- rofa
Rolf Ahrenberg wrote:
No "assuming manual start of VDR" entry found on my logs, so this really was on automatic wakeup for the timer.
If VDR did detect it as manual start, then something else must have caused VDR to believe that there's an interactive user. Something triggers the activity, maybe a plugin?
Mar 4 02:05:57 xxx vdr: [6748] next timer event at Sun Mar 4 10:58:00 2007
Mar 4 10:58:00 xxx vdr: [6688] timer 18 (5 1058-1130 'xxx') start ... and vdr just stays on ...
... and I assume that VDR started not more than 10 minutes before, eg. after 10:48?
Please add the attached patch, it logs some more infos that might shed light on this.
This gives log lines like this:
Mar 4 12:11:18 xx vdr: [3788] Manual Start check: Delta = 240
- means on VDR startup, the expected vs. now time was 240 seconds, VDR started 4 minutes before planned.
The following log lines get dumped once a minute:
Mar 4 12:12:20 xx vdr: [3788] LastActivity: Never Mar 4 12:12:20 xx vdr: [3788] ActiveTimeout: 62 Mar 4 12:12:20 xx vdr: [3788] Retry: Never
- No keyboard activity ever, no interactive user, ready to shut down again since 62 seconds. Never tried to restart. Thats how it should look like.
Mar 4 12:14:20 xx vdr: [3788] LastActivity: 36 Mar 4 12:14:20 xx vdr: [3788] ActiveTimeout: -1164 Mar 4 12:14:20 xx vdr: [3788] Retry: Never
- This is after activity: Last key stroke 36 seconds ago, no automatic shutdown for next 1164 seconds.
Cheers,
Udo
Index: vdr.c =================================================================== --- vdr.c (Revision 874) +++ vdr.c (Arbeitskopie) @@ -1193,6 +1193,37 @@
// Main thread hooks of plugins: PluginManager.MainThreadHook(); + + +#define DebugTimeouts +#ifdef DebugTimeouts + + static time_t DebugTime = time(NULL); + time_t Now = time(NULL); + if (Now - DebugTime >= 60) { + time_t LastActivity = cRemote::LastActivity(); + if (!LastActivity) + dsyslog("LastActivity: Never "); + else + dsyslog("LastActivity: %5i ",(int)(Now - LastActivity)); + + time_t ActiveTimeout = ShutdownHandler.GetUserInactiveTime(); + if (!ActiveTimeout) + dsyslog("ActiveTimeout: Never "); + else + dsyslog("ActiveTimeout: %6i ",(int)(Now - ActiveTimeout)); + + time_t Retry = ShutdownHandler.GetRetry(); + if (!Retry) + dsyslog("Retry: Never "); + else + dsyslog("Retry: %6i ",(int)(Now - Retry)); + + DebugTime = Now; + } + +#endif + }
if (ShutdownHandler.EmergencyExitRequested()) Index: shutdown.c =================================================================== --- shutdown.c (Revision 874) +++ shutdown.c (Arbeitskopie) @@ -103,6 +103,8 @@ void cShutdownHandler::CheckManualStart(int ManualStart) { time_t Delta = Setup.NextWakeupTime ? Setup.NextWakeupTime - time(NULL) : 0; + + dsyslog("Manual Start check: Delta = %i", (int)Delta);
if (!Setup.NextWakeupTime || abs(Delta) > ManualStart) { // Apparently the user started VDR manually
On Sun, 4 Mar 2007, Udo Richter wrote:
Please add the attached patch, it logs some more infos that might shed light on this.
Ok. Here's my log debug entries:
Mar 4 17:56:06 xxx vdr: [6740] VDR version 1.5.1 started Mar 4 17:56:10 xxx vdr: [6740] Manual Start check: Delta = 230
Mar 4 17:57:14 xxx vdr: [6740] LastActivity: Never Mar 4 17:57:14 xxx vdr: [6740] ActiveTimeout: 64 Mar 4 17:57:14 xxx vdr: [6740] Retry: Never
...
Mar 4 17:59:14 xxx vdr: [6740] LastActivity: Never Mar 4 17:59:14 xxx vdr: [6740] ActiveTimeout: 184 Mar 4 17:59:14 xxx vdr: [6740] Retry: Never
Mar 4 18:00:00 xxx vdr: [6740] timer 14 (3 1800-1805 'zzz') start
Mar 4 18:00:14 xxx vdr: [6740] LastActivity: Never Mar 4 18:00:14 xxx vdr: [6740] ActiveTimeout: 244 Mar 4 18:00:14 xxx vdr: [6740] Retry: Never
...
Mar 4 18:04:14 xxx vdr: [6740] LastActivity: Never Mar 4 18:04:14 xxx vdr: [6740] ActiveTimeout: 484 Mar 4 18:04:14 xxx vdr: [6740] Retry: Never
Mar 4 18:05:01 xxx vdr: [6740] timer 14 (3 1800-1805 'zzz') stop
Mar 4 18:05:14 xxx vdr: [6740] LastActivity: Never Mar 4 18:05:14 xxx vdr: [6740] ActiveTimeout: 544 Mar 4 18:05:14 xxx vdr: [6740] Retry: Never
Mar 4 18:06:13 xxx vdr: [6740] deleting timer 14 (3 1800-1805 'zzz')
Mar 4 18:06:14 xxx vdr: [6740] LastActivity: Never Mar 4 18:06:14 xxx vdr: [6740] ActiveTimeout: 604 Mar 4 18:06:14 xxx vdr: [6740] Retry: Never
...
Mar 4 18:31:14 xxx vdr: [6740] LastActivity: Never Mar 4 18:31:14 xxx vdr: [6740] ActiveTimeout: 2104 Mar 4 18:31:14 xxx vdr: [6740] Retry: Never
... goes on and on and no shutdown attempts...
My current activity/timeout settings are: MinUserInactivity = 600 MinEventTimeout = 10
BR, -- rofa
Rolf Ahrenberg wrote:
On Sun, 4 Mar 2007, Udo Richter wrote: Mar 4 18:31:14 xxx vdr: [6740] LastActivity: Never Mar 4 18:31:14 xxx vdr: [6740] ActiveTimeout: 2104 Mar 4 18:31:14 xxx vdr: [6740] Retry: Never
... goes on and on and no shutdown attempts...
Found it! And, more important: Blame Klaus! :)
Klaus changed the meaning of cRemote::LastActivity() before integrating it, and missed to adapt one call to it, the cRemote::LastActivity() > ACTIVITYTIMEOUT check before doing housekeeping. And after startup, cRemote::LastActivity() will return 0, blocking all housekeeping. Correct is (time(NULL) - cRemote::LastActivity()) > ACTIVITYTIMEOUT, as in the attached patch.
Cheers,
Udo
Index: vdr.c =================================================================== --- vdr.c (Revision 874) +++ vdr.c (Arbeitskopie) @@ -1162,7 +1162,7 @@ ShutdownHandler.countdown.Cancel(); }
- if (!Interact && !cRecordControls::Active() && !cCutter::Active() && !Interface->HasSVDRPConnection() && cRemote::LastActivity() > ACTIVITYTIMEOUT) { + if (!Interact && !cRecordControls::Active() && !cCutter::Active() && !Interface->HasSVDRPConnection() && (time(NULL) - cRemote::LastActivity()) > ACTIVITYTIMEOUT) { // Handle housekeeping tasks
// Shutdown:
On Sun, Mar 04, 2007 at 08:31:16PM +0100, Udo Richter wrote:
Rolf Ahrenberg wrote:
On Sun, 4 Mar 2007, Udo Richter wrote: Mar 4 18:31:14 xxx vdr: [6740] LastActivity: Never Mar 4 18:31:14 xxx vdr: [6740] ActiveTimeout: 2104 Mar 4 18:31:14 xxx vdr: [6740] Retry: Never
... goes on and on and no shutdown attempts...
Found it! And, more important: Blame Klaus! :)
Klaus changed the meaning of cRemote::LastActivity() before integrating it, and missed to adapt one call to it, the cRemote::LastActivity() > ACTIVITYTIMEOUT check before doing housekeeping. And after startup, cRemote::LastActivity() will return 0, blocking all housekeeping. Correct is (time(NULL) - cRemote::LastActivity()) > ACTIVITYTIMEOUT, as in the attached patch.
That explains why I haven't had any problems with this, with any version of your shutdown rewrite patch for vdr 1.4. It's good to use the stable version. :-)
Marko
Udo Richter wrote:
Rolf Ahrenberg wrote:
On Sun, 4 Mar 2007, Udo Richter wrote: Mar 4 18:31:14 xxx vdr: [6740] LastActivity: Never Mar 4 18:31:14 xxx vdr: [6740] ActiveTimeout: 2104 Mar 4 18:31:14 xxx vdr: [6740] Retry: Never
... goes on and on and no shutdown attempts...
Found it! And, more important: Blame Klaus! :)
It's always good to have somebody to blame ;-) Especially with such an important feature...
Klaus
Hi Rolf,
I've the same problem with VDR 1.5.1... The VDR does not shutdown after a recording. I didn't find any entry in the logfile that the VDR will initiate a shutdown. With VDR 1.4.5 everything is working well and I use the same config files with VDR 1.5.1 and VDR 1.4.5. Even also the runvdr is identical. I use NVRAM-wakeup to wakeup the VDR. It works well if I do a manual shutdown on VDR 1.5.1, but not with the automatic shutdown...
Regards, Juergen
Rolf schrieb am Samstag, 3. März 2007 um 18:03:
Hi,
I've noticed some shutdown problems with vdr-1.5.1 in my setup: when my vdr wakes up for a timed recording, it doesn't automatically shutdown itself anymore after the recording is done. The MinEventTimeout is set to 15 minutes and MinUserInactivity to 600 minutes, but in my case there hasn't been any user activity, so vdr should have shutdown in 15 minutes after the recording was stopped and the logs don't reveal anything unusual. Have I misunderstood something? Does this automatic shutdown feature still work in your setups?
BR,
rofa
vdr mailing list vdr@linuxtv.org http://www.linuxtv.org/cgi-bin/mailman/listinfo/vdr
Jürgen Schilling wrote:
I've the same problem with VDR 1.5.1... The VDR does not shutdown after a recording.
It looks like VDR assumed the start to be manually, not automatically.
Same for you: Check the logs for "assuming manual start of VDR", "next timer event at" and "next plugin wakeup at" messages, and check setup.conf for the NextWakeupTime line. These infos should explain what went wrong.
Cheers,
Udo
Hi Udo,
I've applied your patch to vdr.c and it seems that it's working now.
Cheers, Juergen
Udo schrieb am Sonntag, 4. März 2007 um 11:06:
Jürgen Schilling wrote:
I've the same problem with VDR 1.5.1... The VDR does not shutdown after a recording.
It looks like VDR assumed the start to be manually, not automatically.
Same for you: Check the logs for "assuming manual start of VDR", "next timer event at" and "next plugin wakeup at" messages, and check setup.conf for the NextWakeupTime line. These infos should explain what went wrong.
Cheers,
Udo
vdr mailing list vdr@linuxtv.org http://www.linuxtv.org/cgi-bin/mailman/listinfo/vdr