Countdown timer plugin (UI5)

Good point. I’ll try to work on it when time permits - over the weekend.
Thanks
MJ

Ok, here’s the first report on my trial & error: Seems @RTS is on the right track to the root of the problem.
After 24 hours of not having triggered the motion sensor and therefore not reset the countdown timer I do not have any repeat messages at all. This looks good. I get a countdown message in the log every 10 seconds (as designed since I changed the tick in the lua script as per @Brientim’s post below).

On to more testing … or rather verifying …

MJ

[quote=“emtschei, post:95, topic:170481”]On the same note as my previous post here I noticed increasing log entries from the countdown timer plugin over the time it runs.

06      09/19/13 18:55:02.133   Device_Variable::m_szValue_set device: 33 service: urn:futzle-com:serviceId:CountdownTimer1 variable                         : Remaining was: 78827 now: 78827 #hooks: 0 upnp: 0 v:0xcc66f8/NONE duplicate:1 <0x2d289680>
06      09/19/13 18:55:03.101   Device_Variable::m_szValue_set device: 33 service: urn:futzle-com:serviceId:CountdownTimer1 variable                         : Remaining was: 78827 now: 78826 #hooks: 0 upnp: 0 v:0xcc66f8/NONE duplicate:0 <0x2d289680>
06      09/19/13 18:55:03.102   Device_Variable::m_szValue_set device: 33 service: urn:futzle-com:serviceId:CountdownTimer1 variable                         : Remaining was: 78826 now: 78826 #hooks: 0 upnp: 0 v:0xcc66f8/NONE duplicate:1 <0x2d289680>
06      09/19/13 18:55:03.102   Device_Variable::m_szValue_set device: 33 service: urn:futzle-com:serviceId:CountdownTimer1 variable                         : Remaining was: 78826 now: 78826 #hooks: 0 upnp: 0 v:0xcc66f8/NONE duplicate:1 <0x2d289680>
06      09/19/13 18:55:03.103   Device_Variable::m_szValue_set device: 33 service: urn:futzle-com:serviceId:CountdownTimer1 variable                         : Remaining was: 78826 now: 78826 #hooks: 0 upnp: 0 v:0xcc66f8/NONE duplicate:1 <0x2d289680>
06      09/19/13 18:55:03.104   Device_Variable::m_szValue_set device: 33 service: urn:futzle-com:serviceId:CountdownTimer1 variable                         : Remaining was: 78826 now: 78826 #hooks: 0 upnp: 0 v:0xcc66f8/NONE duplicate:1 <0x2d289680>
06      09/19/13 18:55:03.105   Device_Variable::m_szValue_set device: 33 service: urn:futzle-com:serviceId:CountdownTimer1 variable                         : Remaining was: 78826 now: 78826 #hooks: 0 upnp: 0 v:0xcc66f8/NONE duplicate:1 <0x2d289680>
06      09/19/13 18:55:03.106   Device_Variable::m_szValue_set device: 33 service: urn:futzle-com:serviceId:CountdownTimer1 variable                         : Remaining was: 78826 now: 78826 #hooks: 0 upnp: 0 v:0xcc66f8/NONE duplicate:1 <0x2d289680>
06      09/19/13 18:55:03.106   Device_Variable::m_szValue_set device: 33 service: urn:futzle-com:serviceId:CountdownTimer1 variable                         : Remaining was: 78826 now: 78826 #hooks: 0 upnp: 0 v:0xcc66f8/NONE duplicate:1 <0x2d289680>
06      09/19/13 18:55:03.107   Device_Variable::m_szValue_set device: 33 service: urn:futzle-com:serviceId:CountdownTimer1 variable                         : Remaining was: 78826 now: 78826 #hooks: 0 upnp: 0 v:0xcc66f8/NONE duplicate:1 <0x2d289680>
06      09/19/13 18:55:03.108   Device_Variable::m_szValue_set device: 33 service: urn:futzle-com:serviceId:CountdownTimer1 variable                         : Remaining was: 78826 now: 78826 #hooks: 0 upnp: 0 v:0xcc66f8/NONE duplicate:1 <0x2d289680>
06      09/19/13 18:55:03.109   Device_Variable::m_szValue_set device: 33 service: urn:futzle-com:serviceId:CountdownTimer1 variable                         : Remaining was: 78826 now: 78826 #hooks: 0 upnp: 0 v:0xcc66f8/NONE duplicate:1 <0x2d289680>
06      09/19/13 18:55:03.109   Device_Variable::m_szValue_set device: 33 service: urn:futzle-com:serviceId:CountdownTimer1 variable                         : Remaining was: 78826 now: 78826 #hooks: 0 upnp: 0 v:0xcc66f8/NONE duplicate:1 <0x2d289680>
06      09/19/13 18:55:03.121   Device_Variable::m_szValue_set device: 33 service: urn:futzle-com:serviceId:CountdownTimer1 variable                         : Remaining was: 78826 now: 78826 #hooks: 0 upnp: 0 v:0xcc66f8/NONE duplicate:1 <0x2d289680>
06      09/19/13 18:55:03.121   Device_Variable::m_szValue_set device: 33 service: urn:futzle-com:serviceId:CountdownTimer1 variable                         : Remaining was: 78826 now: 78826 #hooks: 0 upnp: 0 v:0xcc66f8/NONE duplicate:1 <0x2d289680>
06      09/19/13 18:55:03.122   Device_Variable::m_szValue_set device: 33 service: urn:futzle-com:serviceId:CountdownTimer1 variable                         : Remaining was: 78826 now: 78826 #hooks: 0 upnp: 0 v:0xcc66f8/NONE duplicate:1 <0x2d289680>
06      09/19/13 18:55:03.123   Device_Variable::m_szValue_set device: 33 service: urn:futzle-com:serviceId:CountdownTimer1 variable                         : Remaining was: 78826 now: 78826 #hooks: 0 upnp: 0 v:0xcc66f8/NONE duplicate:1 <0x2d289680>
06      09/19/13 18:55:03.124   Device_Variable::m_szValue_set device: 33 service: urn:futzle-com:serviceId:CountdownTimer1 variable                         : Remaining was: 78826 now: 78826 #hooks: 0 upnp: 0 v:0xcc66f8/NONE duplicate:1 <0x2d289680>
06      09/19/13 18:55:03.124   Device_Variable::m_szValue_set device: 33 service: urn:futzle-com:serviceId:CountdownTimer1 variable                         : Remaining was: 78826 now: 78826 #hooks: 0 upnp: 0 v:0xcc66f8/NONE duplicate:1 <0x2d289680>
06      09/19/13 18:55:03.125   Device_Variable::m_szValue_set device: 33 service: urn:futzle-com:serviceId:CountdownTimer1 variable                         : Remaining was: 78826 now: 78826 #hooks: 0 upnp: 0 v:0xcc66f8/NONE duplicate:1 <0x2d289680>
06      09/19/13 18:55:03.126   Device_Variable::m_szValue_set device: 33 service: urn:futzle-com:serviceId:CountdownTimer1 variable                         : Remaining was: 78826 now: 78826 #hooks: 0 upnp: 0 v:0xcc66f8/NONE duplicate:1 <0x2d289680>
06      09/19/13 18:55:03.127   Device_Variable::m_szValue_set device: 33 service: urn:futzle-com:serviceId:CountdownTimer1 variable                         : Remaining was: 78826 now: 78826 #hooks: 0 upnp: 0 v:0xcc66f8/NONE duplicate:1 <0x2d289680>
06      09/19/13 18:55:03.127   Device_Variable::m_szValue_set device: 33 service: urn:futzle-com:serviceId:CountdownTimer1 variable                         : Remaining was: 78826 now: 78826 #hooks: 0 upnp: 0 v:0xcc66f8/NONE duplicate:1 <0x2d289680>
06      09/19/13 18:55:03.128   Device_Variable::m_szValue_set device: 33 service: urn:futzle-com:serviceId:CountdownTimer1 variable                         : Remaining was: 78826 now: 78826 #hooks: 0 upnp: 0 v:0xcc66f8/NONE duplicate:1 <0x2d289680>
06      09/19/13 18:55:03.129   Device_Variable::m_szValue_set device: 33 service: urn:futzle-com:serviceId:CountdownTimer1 variable                         : Remaining was: 78826 now: 78826 #hooks: 0 upnp: 0 v:0xcc66f8/NONE duplicate:1 <0x2d289680>
06      09/19/13 18:55:03.134   Device_Variable::m_szValue_set device: 33 service: urn:futzle-com:serviceId:CountdownTimer1 variable                         : Remaining was: 78826 now: 78826 #hooks: 0 upnp: 0 v:0xcc66f8/NONE duplicate:1 <0x2d289680>
06      09/19/13 18:55:03.135   Device_Variable::m_szValue_set device: 33 service: urn:futzle-com:serviceId:CountdownTimer1 variable                         : Remaining was: 78826 now: 78826 #hooks: 0 upnp: 0 v:0xcc66f8/NONE duplicate:1 <0x2d289680>
06      09/19/13 18:55:04.101   Device_Variable::m_szValue_set device: 33 service: urn:futzle-com:serviceId:CountdownTimer1 variable                         : Remaining was: 78826 now: 78825 #hooks: 0 upnp: 0 v:0xcc66f8/NONE duplicate:0 <0x2d289680>
06      09/19/13 18:55:04.102   Device_Variable::m_szValue_set device: 33 service: urn:futzle-com:serviceId:CountdownTimer1 variable                         : Remaining was: 78825 now: 78825 #hooks: 0 upnp: 0 v:0xcc66f8/NONE duplicate:1 <0x2d289680>

In this example there were 26 entries for one second. I have seen over 30 entries though and it looks like the longer the Lua engine is running the more entries per second are written.
After a reload of the Lua engine everything is back to normal - but only for a while. My LuaUPnP logs get currently switched every 10 minutes. I had an unexpected system reboot this afternoon which I might attribute to the masses of log entries (no hard proof though), maybe some memory leaks or overflow …

I am curious if others that run lengthy timers experience similar problems.

Btw. I’m running a Vera3 with the latest Fw 1.5.622.[/quote]

This looks very similar to the problem I have described in another thread. There, it’s the smart virtual thermostat that “clutters” the log with thousands of lines, and makes the log grow to megabyte size within minutes.
[url=http://forum.micasaverde.com/index.php/topic,16750.0.html]http://forum.micasaverde.com/index.php/topic,16750.0.html[/url]

I haven’t yet been able to tell when it happens, but it can be OK for log periods (hours) and then the problem will reappear.
I also have countdown timers in my system. Perhaps this is a more general problem, not particular to one plugin?

[quote=“emtschei, post:102, topic:170481”]Ok, here’s the first report on my trial & error: Seems @RTS is on the right track to the root of the problem.
After 24 hours of not having triggered the motion sensor and therefore not reset the countdown timer I do not have any repeat messages at all. This looks good. I get a countdown message in the log every 10 seconds (as designed since I changed the tick in the lua script as per @Brientim’s post below).

On to more testing … or rather verifying …

MJ[/quote]

I created a new instance of the Countdown timer plugin and also reverted the changed Lua code to issue a log line for every second (as per original plugin).
The new device is not referenced in any scene or trigger. Start/Restart/Cancel were done manually using the device buttons.

Here’s what I found:
@RTS was right. I restarted the timer at various intervals and with each restart an additional log entry per tick was produced. Please see attachment.
After cancelling the timer the output got quiet, as expected.
A new start of the timer using either Start or Restart (after it got cancelled) reverted the log output to one entry per tick.
This behavior can be reproduced.
I also verified this phenomenon with a much smaller timer value of only 10 seconds. Same result.

As @AndersH pointed out below, he noticed a similar behavior. Maybe it has to do with the Countdown timer plugin - but maybe not.

I’d appreciate if the more knowledgeable members here could bring in their theories and maybe @futzle as the creator of the plugin has any insights.

Thank you
MJ

I’ve been watching this discussion with interest, but didn’t really have enough to go on till now.

emtschei, I think you nailed it: “Restart” is the culprit. I’m astonished that multiple luup.call_timer() doesn’t crash LuaUPnP. But I think I found the part in my logic where I fail to check that the delay has already been scheduled, and schedule another one anyway.

Try the attached replacement for L_CountdownTimer1.lua. Does it resolve the multiple entries?

I'm astonished that multiple luup.call_timer() doesn't crash LuaUPnP

I was worried about this at one time as well … but now I depend on it for PLEG.
I have lots of scheduled timers running in parallel with different times.

Thank you, @futzle. You’re my man … well, my woman.
I am happy I could provide some input to put you on the right track. And I’m glad you found the bug. Much appreciated.
So far this looks good in the logs. See attachment.

Now, if we just could have the logging interval (tick) as a setting in the device control tab (device independent) that would be splendid ;).

Oh, and credit goes to @RTS. He suggested to check on correlation between timer resets and log entries. Thank you too, Richard.

MJ

I will submit the fixed version up to apps.mios.com real soon. I’m still thinking of the best way to code granularity into the delay so that it Just Works. I think I will adopt the suggestion floated here to delay either n % or m seconds, whichever is less.

I did the % in PLTS … it has the bad side effect of strange countdown values being displayed … need something like we used to do in the days of figuring nice label values for graphs … need nice interval values for display.

[quote=“futzle, post:3, topic:170481”]In this example, imagine that you have a light that you want to turn off five minutes after it is turned on. If the light is turned off manually before 5 minutes, do nothing.

  1. Create a Countdown Timer. Rename it Five minute timer. Go to the configuration tab and change the Duration to 300 seconds.
  2. Create a scene. Rename it Light goes on. Edit the scene, setting a trigger for the light device: A device is turned on or off > Device is turned on. Make the scene activate the Start button on the Five Minute Timer.
  3. Create a second scene. Rename it Light goes off. Edit the scene, setting a trigger for the light device: A device is turned on or off > Device is turned off. Make the scene activate the Cancel button on the Five Minute Timer.
  4. Create a third scene. Rename it Turn light off. Edit the scene, setting a trigger for the Five Minute Timer: Timer completes while not muted. Make the scene activate the Off button on the light device.

Mute the timer to temporarily override the automatic turning off of the light.[/quote]

works fine-lights turn on/off with the peset timer. i tried to set it up for my garage door but encountered some problems creating the 3rd scene. after the countdown, garage door does not close. i have a garage door plugin installed, ZFM-80 and SM103 sensor. any help will be appreciated.

So what does happen? At what point does reality diverge from your expectations? Have you double-checked the scene that is triggered by the completion of the timer? Have you made sure the timer is not muted?

If I am to help you debug this I’ll need a great deal more information.

So what does happen? At what point does reality diverge from your expectations? Have you double-checked the scene that is triggered by the completion of the timer? Have you made sure the timer is not muted?

If I am to help you debug this I’ll need a great deal more information.[/quote]
created a countdown timer and named it 11-minute garage door timer (660 seconds duration), and created the following scenes:
(1) scene name garage door is open. trigger door is locked or unlocked > device is opened. in the advanced tab, i made the scene activate the start button in the 11 minute timer
(2) scene name garage door is closed. created a trigger a door is locked or unlocked > device is closed. in the advanced tab, i made the scene activate the cancel button in the 11 minute timer
that’s it - i am not sure how to create the 3rd scene just like the turn off light and timer completes while not muted thanks for your prompt response and i hope you can provide me with some guidance.

So I’m assuming that in this Garage Door plugin there is a button on the dashboard that closes the door. I will call this button “Close”.

Create a scene. Edit its triggers. Add a trigger for the 11-minute timer: “timer completes while not muted”. Give this trigger an arbitrary name.

Continue editing the scene. Go to the Devices tab and find the Garage Door device. Click on its “Close” button. It will light up.

Finish editing the scene. SAVE.

If I have answered a question different to the one you think you’ve asked, please advise me where I’ve gone off the rails. You haven’t actually said yet what you want to happen so I am making educated guesses.

[quote=“futzle, post:113, topic:170481”]So I’m assuming that in this Garage Door plugin there is a button on the dashboard that closes the door. I will call this button “Close”.

Create a scene. Edit its triggers. Add a trigger for the 11-minute timer: “timer completes while not muted”. Give this trigger an arbitrary name.

Continue editing the scene. Go to the Devices tab and find the Garage Door device. Click on its “Close” button. It will light up.

Finish editing the scene. SAVE.

If I have answered a question different to the one you think you’ve asked, please advise me where I’ve gone off the rails. You haven’t actually said yet what you want to happen so I am making educated guesses.[/quote]
that’s it, you did it. my garage door now auto closes after 11 minutes. my mistake was i kept going to the “advanced” tab instead of what you said “devices”. thank you very much for your help. great app!!

[quote=“futzle, post:113, topic:170481”]So I’m assuming that in this Garage Door plugin there is a button on the dashboard that closes the door. I will call this button “Close”.

Create a scene. Edit its triggers. Add a trigger for the 11-minute timer: “timer completes while not muted”. Give this trigger an arbitrary name.

Continue editing the scene. Go to the Devices tab and find the Garage Door device. Click on its “Close” button. It will light up.

Finish editing the scene. SAVE.

If I have answered a question different to the one you think you’ve asked, please advise me where I’ve gone off the rails. You haven’t actually said yet what you want to happen so I am making educated guesses.[/quote]
hi, any idea why the 11-minute timer keeps closing and opening the garage door about 2 to 3 times?

How long does it take your garage door to open/close?

With the garage door plugin, if the door is open, when you click “close” it will immediately switch to closed, even while the door is still traveling. After some amount of time (maybe 10 or 20 seconds?), if the door isn’t closed yet, that status will revert to open again.

That might be starting a new timer, that isn’t being canceled properly when the door closes?

For this reason, I don’t base my garage door timers on the lock device, but instead I base them directly on the sensor device (in my case, an alarm system sensor exposed in Vera).

[quote=“PurdueGuy, post:116, topic:170481”]How long does it take your garage door to open/close?

With the garage door plugin, if the door is open, when you click “close” it will immediately switch to closed, even while the door is still traveling. After some amount of time (maybe 10 or 20 seconds?), if the door isn’t closed yet, that status will revert to open again.

That might be starting a new timer, that isn’t being canceled properly when the door closes?

For this reason, I don’t base my garage door timers on the lock device, but instead I base them directly on the sensor device (in my case, an alarm system sensor exposed in Vera).[/quote]

very good point and your analysis makes a very good sense. i would say my sears craftsman garage opener travels about 10 - 15 seconds. the reason why i enable my 11 miniute timer all day (regardless of day or night) is because there were instances that we left during the day and the wife gets paranoid if we closed the garage door or not and she will call the neighbor for her peace of mind. i arm my SM103 garage sensor at 8pm. i will modify the scene and tie the countdown timer to the SM103; this means t hat i have to arm it (the sensor) all day. i wonder if arming the sensor all day and night affects battery life.

Arming the sensor won’t affect battery life at all.

However, why do you have to arm it? You can use the “sensor is tripped” trigger for normal operation.
That would allow you to use separate triggers when you want to do something special (such as arming when on vacation and getting notices).

Arming the sensor won’t affect battery life at all.

However, why do you have to arm it? You can use the “sensor is tripped” trigger for normal operation.
That would allow you to use separate triggers when you want to do something special (such as arming when on vacation and getting notices).[/quote]

i just learned something new from you. stupid me - i armed all my window/door sensors at night and bypass in the morning. ok i will modify all these scenes. thanks a lot.

Wouldn’t it be nice to be able to pause the Countdown Timer? With a “pause” and a “resume” button/function I would be able to use it to control a device by usage time. I would be able to allow the usage of an appliance for a certain amount of time daily.