Author Topic: Light Switch - not switching OFF by event  (Read 4995 times)

gurari

  • NewMember
  • *
  • Posts: 48
  • Country: bg
Light Switch - not switching OFF by event
« on: July 22, 2015, 01:04:58 AM »
Hi all!
I was playing for a while with the Pi Gateway. It is just brilliant peace work and I want to congratulate you Felix for creating such a environment and sharing it with us!

I have one switch mote which I want to make to turn ON the lights at some hours and turn them OFF at another hours. So I saw there are events for doing this. I've attached one for the ON and for the OFF, also I've changed the hrs for the events in the metrics.js . All good so far. in the data stream I see that there are events and the time until they will execute. When the time for switch ON comes and if the light is OFF it switches ON - cool! The magic works! But when the time to switch OFF comes the event is just rescheduled for 24hrs and nothing happens. I've tried putting only OFF event but still same situation. Looks like the conditions for the state of the button are not correctly checked because when I tried to put 4 event (ON - OFF - ON - OFF) on every ON event I receive -
Code: [Select]
NODEACTION: {"nodeId":28,"action":"BTN1:1"}
**** ADDING SCHEDULED EVENT - nodeId:28 event:switchMoteON_PM2 to run in ~24.00h rs
>: ACK:OK
even the button state is ON

So what I'm not doing right?

These are commands for ON and OFF (just changed hours from Felix example)
Code: [Select]
  switchMoteON_PM2 : { label:'SwitchMote ON at 9:00:02PM!', icon:'clock', descr:'Turn this switch ON at 9:00:02PM every day', nextSchedule:function(node) { return exports.timeoutOffset(7,51,32); /*run at 9:00:02PM*/ }, scheduledExecute:function(node) { if (node.metrics['B1'] && node.metrics['B1'].value == 'OFF') { sendMessageToNode({nodeId:node._id, action:'BTN1:1'}); }; } },
  switchMoteOFF_AM2 : { label:'SwitchMote OFF at 6:30:02AM!', icon:'clock', descr:'Turn this switch OFF at 6:30:02AM every day', nextSchedule:function(node) { return exports.timeoutOffset(7,54,2); /*run at 6:30:2AM */ }, scheduledExecute:function(node) { if (node.metrics['B1'] && node.metrics['B1'].value == 'ON') { sendMessageToNode({nodeId:node._id, action:'BTN1:0'}); }; } },

Felix

  • Administrator
  • Hero Member
  • *****
  • Posts: 6866
  • Country: us
    • LowPowerLab
Re: Light Switch - not switching OFF by event
« Reply #1 on: July 22, 2015, 07:59:33 AM »
Thanks for the feedback :)
I will need to say right away that I just made some updates to both the gateway code (& image) and also the switchmote code (this one some time ago).
If you don't have the latest code please get that first. I would flush the gateway nodes database since I overwrote the events.
Those 9:00:02 (2 seconds diff) were put in place some time ago when I saw there were some hits and misses with a lot of lights switching on/off at the same time so I tries to divide the group. I think the real issue in such cases (if it still happens) lies in the SwitchMote sketch which responds to a request first with an ACK then with a separate packet to report the status. I tried to improve that and also I made some changes to the gateway, now settings are kept in a separate file and other small things that should address this problem you're reporting. Please report back how it works.

gurari

  • NewMember
  • *
  • Posts: 48
  • Country: bg
Re: Light Switch - not switching OFF by event
« Reply #2 on: July 23, 2015, 12:33:45 AM »
Hello Felix,
There was a overload or so on your server so I can answer just now. Yesterday I downloaded your new files for the gateway. I've also installed console-stamp. All started working. Checked which version of the SwitchMote I am using - SwitchMote.ino which was update 2 months ago. Also all the libraries used by this sketch are the last version.
In the metrics.js I've changed only the time for the events to see if the things will work for me. Then started gateway.js, deleted all the nodes present there, after they were active again I put the ON and OFF events for the SwitchMote. When the time for the ON event came the light associated with this button was ON, but after that when the time for OFF command came... the same situation, only this row

Code: [Select]
[07-22-15_23:04:00.017] [LOG] **** ADDING SCHEDULED EVENT - nodeId:28 event:switchMoteOFF_PM to run in ~24.00hrs

without a row for action how it was for the ON event

Code: [Select]
[07-22-15_23:02:00.012] [LOG] NODEACTION: {"nodeId":28,"action":"BTN1:1"}

The same was if interchange the ON and OFF times. If the OFF is first then the ON is only "adding scheduled event" without "node action". Then I made another test. If I add one by one events all was working. First I added the ON event and when the time came the light was on, after that I added the OFF event and when the time came the light was OFF.
So now I'm not touching anything and waiting to see what will happen tonight ;)
« Last Edit: July 23, 2015, 12:35:27 AM by gurari »

Felix

  • Administrator
  • Hero Member
  • *****
  • Posts: 6866
  • Country: us
    • LowPowerLab
Re: Light Switch - not switching OFF by event
« Reply #3 on: July 23, 2015, 08:19:45 AM »
My lights seem to work fine with both events enabled at any time. You should not have to enable them in a certain order or anything like that.
I would really want to find the issue if there is one with the gateway code.
Your console output should be in the nohup file in the same directory, it keeps growing as output gets dumped there over time but it lets you see what happened and also you can flush it if you want to regain of the space used.

gurari

  • NewMember
  • *
  • Posts: 48
  • Country: bg
Re: Light Switch - not switching OFF by event
« Reply #4 on: July 23, 2015, 09:10:09 AM »
Tonight we will see what will happen with the events. Looking the code I also think that there should be no difference how the events will be activated. I don't know what is the reason first time the nodeaction to be send and after that only to reschedule the event without sending data... hope to find the solution because it is very strange...

Felix

  • Administrator
  • Hero Member
  • *****
  • Posts: 6866
  • Country: us
    • LowPowerLab
Re: Light Switch - not switching OFF by event
« Reply #5 on: July 23, 2015, 09:38:51 AM »
When you activate an event it will ONLY set it to "1" in the node event collection. So if you look in the gateway.db you should see something like this:


{"_id":xxxx,"updated":1437614100098,"rssi":61,"metrics":{"B1":{"label":"B1","value":"ON","updated":1437614100098,"pin":"1","graph":"1"}},"type":"SwitchMote","label":"My SwitchMote","events":{"switchMoteON_PM":1,"switchMoteOFF_AM":1},"descr":"This is my switchmote"}

Internally to the gateway.js script, there is a collection of events scheduled with javascript timers. When you enable/disable events that collection and the timers are kept in synch (or should be) with the new status and the DB statuses.

gurari

  • NewMember
  • *
  • Posts: 48
  • Country: bg
Re: Light Switch - not switching OFF by event
« Reply #6 on: July 24, 2015, 12:58:18 AM »
Good morning ;)
Some results for me. Yesterday I was at a birthday party so I came back at home late and wasn't able to see with my eyes how the system is working but the log is showing some good results

Code: [Select]
[07-23-15_23:02:00.013] [LOG] NODEACTION: {"nodeId":28,"action":"BTN1:1"}
[07-23-15_23:02:00.021] [LOG] **** ADDING SCHEDULED EVENT - nodeId:28 event:switchMoteON_PM to run in ~24.00hrs
[07-23-15_23:02:00.038] [LOG] >: ACK:OK
[07-23-15_23:02:48.124] [LOG] >: [25] H:53.50 F:23.30   [RSSI:-88]
[07-23-15_23:02:48.157] [LOG]    [25] DB-Updates:1
[07-23-15_23:03:00.009] [LOG] NODEACTION: {"nodeId":28,"action":"BTN1:0"}
[07-23-15_23:03:00.015] [LOG] **** ADDING SCHEDULED EVENT - nodeId:28 event:switchMoteOFF_AM to run in ~24.00hrs
[07-23-15_23:03:00.034] [LOG] >: ACK:OK
[07-23-15_23:03:01.053] [LOG] >: [28] BTN1:0   [RSSI:-56][ACK-sent]

Looks like all is working like it should and I'm very happy!
Still I can't understand what is the issue whit this events because I made another test. I've copied this ON/OFF events and added them for this very same switch mote

Code: [Select]
  switchMoteON_PM1 : { label:'SwitchMote ON at 91PM!', icon:'clock', descr:'Turn this switch ON at 91PM sharp every day', nextSchedule:function(node) { return exports.timeoutOffset(07,24); /*run at 9:15PM*/ }, scheduledExecute:function(node) { if (node.metrics['B1'] && node.metrics['B1'].value == 'OFF') { sendMessageToNode({nodeId:node._id, action:'BTN1:1'}); }; } },
  switchMoteOFF_AM2 : { label:'SwitchMote OFF at 61:30AM!', icon:'clock', descr:'Turn this switch OFF at 61:30AM every day', nextSchedule:function(node) { return exports.timeoutOffset(07,27); /*run at 6:00AM */ }, scheduledExecute:function(node) { if (node.metrics['B1'] && node.metrics['B1'].value == 'ON') { sendMessageToNode({nodeId:node._id, action:'BTN1:0'}); }; } },

and here are the results

Code: [Select]
[07-24-15_07:22:48.794] [LOG] NEW CONNECTION FROM 127.0.0.1:32972
[07-24-15_07:23:01.307] [LOG] **** ADDING SCHEDULED EVENT - nodeId:28 event:switchMoteON_PM1 to run in ~0.02hrs
[07-24-15_07:23:08.254] [LOG] **** ADDING SCHEDULED EVENT - nodeId:28 event:switchMoteOFF_AM2 to run in ~0.06hrs
[07-24-15_07:23:46.068] [LOG] >: [25] H:72.80 F:23.40   [RSSI:-91]
[07-24-15_07:23:46.098] [LOG]    [25] DB-Updates:1
[07-24-15_07:24:00.013] [LOG] NODEACTION: {"nodeId":28,"action":"BTN1:1"}
[07-24-15_07:24:00.018] [LOG] **** ADDING SCHEDULED EVENT - nodeId:28 event:switchMoteON_PM1 to run in ~24.00hrs
[07-24-15_07:24:00.038] [LOG] >: ACK:OK
[07-24-15_07:24:01.058] [LOG] >: [28] BTN1:1   [RSSI:-59][ACK-sent]
[07-24-15_07:24:01.089] [LOG]    [28] DB-Updates:1
[07-24-15_07:26:16.203] [LOG] >: [25] H:72.20 F:23.90   [RSSI:-91]
[07-24-15_07:26:16.235] [LOG]    [25] DB-Updates:1
[07-24-15_07:27:00.017] [LOG] **** ADDING SCHEDULED EVENT - nodeId:28 event:switchMoteOFF_AM2 to run in ~24.00hrs
[07-24-15_07:27:16.248] [LOG] >: [25] H:71.60 F:24.00   [RSSI:-91]
[07-24-15_07:27:16.280] [LOG]    [25] DB-Updates:1

again the light didn't go OFF  :o

Then when I added the events one by one - first the ON and after that the OFF - all worked again

Code: [Select]
[07-24-15_07:39:15.322] [LOG] **** ADDING SCHEDULED EVENT - nodeId:28 event:switchMoteON_PM1 to run in ~00.01hrs
[07-24-15_07:39:17.289] [LOG] >: [25] H:67.00 F:24.60   [RSSI:-93]
[07-24-15_07:39:17.389] [LOG]    [25] DB-Updates:1
[07-24-15_07:39:47.317] [LOG] >: [25] H:67.10 F:24.60   [RSSI:-84]
[07-24-15_07:39:47.363] [LOG]    [25] DB-Updates:1
[07-24-15_07:40:00.014] [LOG] NODEACTION: {"nodeId":28,"action":"BTN1:1"}
[07-24-15_07:40:00.019] [LOG] **** ADDING SCHEDULED EVENT - nodeId:28 event:switchMoteON_PM1 to run in ~24.00hrs
[07-24-15_07:40:00.039] [LOG] >: ACK:OK
[07-24-15_07:40:01.059] [LOG] >: [28] BTN1:1   [RSSI:-61][ACK-sent]
[07-24-15_07:40:01.090] [LOG]    [28] DB-Updates:1
[07-24-15_07:40:17.888] [LOG] **** ADDING SCHEDULED EVENT - nodeId:28 event:switchMoteOFF_AM2 to run in ~00.05hrs
[07-24-15_07:42:48.242] [LOG] >: [25] H:67.40 F:24.40   [RSSI:-90]
[07-24-15_07:42:48.274] [LOG]    [25] DB-Updates:1
[07-24-15_07:43:00.007] [LOG] NODEACTION: {"nodeId":28,"action":"BTN1:0"}
[07-24-15_07:43:00.014] [LOG] **** ADDING SCHEDULED EVENT - nodeId:28 event:switchMoteOFF_AM2 to run in ~24.00hrs
[07-24-15_07:43:00.033] [LOG] >: ACK:OK
[07-24-15_07:43:01.052] [LOG] >: [28] BTN1:0   [RSSI:-61][ACK-sent]

so I'm totally confused  ??? and have no idea what is happening. I'll leave all like it is and will see tonight and tomorrow morning what will happen

gurari

  • NewMember
  • *
  • Posts: 48
  • Country: bg
Re: Light Switch - not switching OFF by event
« Reply #7 on: July 25, 2015, 01:43:50 AM »
The last loop of events was total failure. All the OFF events didn't switch off the lamp.

nohup.out:
Code: [Select]
[07-24-15_23:02:00.018] [LOG] NODEACTION: {"nodeId":28,"action":"BTN1:1"}
[07-24-15_23:02:00.024] [LOG] **** ADDING SCHEDULED EVENT - nodeId:28 event:switchMoteON_PM to run in ~24.00hrs
[07-24-15_23:02:00.043] [LOG] >: ACK:OK
[07-24-15_23:02:01.063] [LOG] >: [28] BTN1:1   [RSSI:-60][ACK-sent]
[07-24-15_23:02:01.094] [LOG]    [28] DB-Updates:1
[07-24-15_23:02:28.099] [LOG] >: [25] H:52.50 F:24.20   [RSSI:-84]
[07-24-15_23:02:28.127] [LOG]    [25] DB-Updates:1
[07-24-15_23:02:58.134] [LOG] >: [25] H:52.40 F:24.20   [RSSI:-85]
[07-24-15_23:02:58.170] [LOG]    [25] DB-Updates:1
[07-24-15_23:03:00.009] [LOG] **** ADDING SCHEDULED EVENT - nodeId:28 event:switchMoteOFF_AM to run in ~24.00hrs
........
[07-25-15_07:40:00.011] [LOG] NODEACTION: {"nodeId":28,"action":"BTN1:1"}
[07-25-15_07:40:00.017] [LOG] **** ADDING SCHEDULED EVENT - nodeId:28 event:switchMoteON_PM1 to run in ~24.00hrs
[07-25-15_07:40:00.036] [LOG] >: ACK:OK
[07-25-15_07:40:01.055] [LOG] >: [28] BTN1:1   [RSSI:-59][ACK-sent]
[07-25-15_07:40:01.086] [LOG]    [28] DB-Updates:1
[07-25-15_07:40:26.088] [LOG] >: [25] H:57.40 F:25.50   [RSSI:-82]
[07-25-15_07:40:26.119] [LOG]    [25] DB-Updates:1
[07-25-15_07:40:56.124] [LOG] >: [25] H:57.50 F:25.50   [RSSI:-82]
[07-25-15_07:40:56.150] [LOG]    [25] DB-Updates:1
[07-25-15_07:41:26.160] [LOG] >: [25] H:57.30 F:25.60   [RSSI:-82]
[07-25-15_07:41:26.191] [LOG]    [25] DB-Updates:1
[07-25-15_07:41:56.195] [LOG] >: [25] H:57.20 F:25.70   [RSSI:-82]
[07-25-15_07:41:56.225] [LOG]    [25] DB-Updates:1
[07-25-15_07:42:56.241] [LOG] >: [25] H:57.30 F:25.70   [RSSI:-82]
[07-25-15_07:42:56.271] [LOG]    [25] DB-Updates:1
[07-25-15_07:43:00.007] [LOG] **** ADDING SCHEDULED EVENT - nodeId:28 event:switchMoteOFF_AM2 to run in ~24.00hrs

gateway.db
Code: [Select]
{"_id":28,"updated":1437799201060,"type":"SwitchMote","label":"lights","rssi":59,"metrics":{"B1":{"label":"B1","value":"ON","updated":1437799201060,"pin":"1","graph":"1"}},"events":{"switchMoteOFF_AM":1,"switchMoteON_PM":1,"switchMoteON_PM1":1,"switchMoteOFF_AM2":1}}

This was the only line I found about node 28 in the gateway.db
« Last Edit: July 25, 2015, 01:51:39 AM by gurari »

Felix

  • Administrator
  • Hero Member
  • *****
  • Posts: 6866
  • Country: us
    • LowPowerLab
Re: Light Switch - not switching OFF by event
« Reply #8 on: July 26, 2015, 10:20:37 AM »
I'll have to investigate some more.
Note the gateway.db recycles every 24hrs by default, so in general if you don't really use that switch it's very possible you might only see 1 entry.

gurari

  • NewMember
  • *
  • Posts: 48
  • Country: bg
Re: Light Switch - not switching OFF by event
« Reply #9 on: July 26, 2015, 04:46:34 PM »
If there is something I can do/test just tell me. Whole next week I'll be in Czech Republic drinking beer - sorry I wanted to say on training how to repair buses but if there is something that I can do it remotely I'll do it

Felix

  • Administrator
  • Hero Member
  • *****
  • Posts: 6866
  • Country: us
    • LowPowerLab
Re: Light Switch - not switching OFF by event
« Reply #10 on: July 31, 2015, 09:54:12 AM »
After several days of observation of my SwitchMote events I cannot find any fault and all of them turn ON and OFF as expected. I guess we can keep this thread open and see if any event/scheduling bugs can be identified.

gurari

  • NewMember
  • *
  • Posts: 48
  • Country: bg
Re: Light Switch - not switching OFF by event
« Reply #11 on: July 31, 2015, 03:38:40 PM »
Sure, as soon as get back home I'll reinstall all the pi gateway stuff and give it another try.I'll keep you informed. Cheers now from Budapest (beer)

TomWS

  • Hero Member
  • *****
  • Posts: 1930
Re: Light Switch - not switching OFF by event
« Reply #12 on: July 31, 2015, 03:45:55 PM »
 Egészségedre!

Tom

gurari

  • NewMember
  • *
  • Posts: 48
  • Country: bg
Re: Light Switch - not switching OFF by event
« Reply #13 on: August 03, 2015, 08:21:18 AM »
Наздраве! ;)
So finally I'm back and happily today the workshop is not full of vehicles and had time to reinstall the gateway.
I've put put a fresh copy of raspbian wheezy and done manual install of all other thing needed for gateway operation. But the situation is the same like before. I've done some test and I think that the problem is somewhere in the conditions that are checked when the scheduled time comes.

Code: [Select]
if (node.metrics['B1'] && node.metrics['B1'].value == 'OFF')

Unfortunately my JavaScripts skills are limited for the moment and the test that I've done are very simple. I changed the value of node.metrics['B1'].value ==  and then when the time comes only a reschedule of timer is done without action. So I have to figure out why these conditions aren't fulfilled every time when it seems the should be.

So I've just tested another thing. Removed the comparing part (to check if the value is On or OFF) from the events for the lights switch and all started working. So the problem is definitely in these conditions but I can't figure it out

switchMoteON_PM : { label:'SwitchMote ON at 9PM!', icon:'clock', descr:'Turn this switch ON at 9PM sharp every day', nextSchedule:function(node) { return exports.timeoutOffset(15,28); /*run at 9:15PM*/ }, scheduledExecute:function(node) { if (node.metrics['B1']) { sendMessageToNode({nodeId:node._id, action:'BTN1:1'}); }; } },
« Last Edit: August 03, 2015, 08:35:49 AM by gurari »

Felix

  • Administrator
  • Hero Member
  • *****
  • Posts: 6866
  • Country: us
    • LowPowerLab
Re: Light Switch - not switching OFF by event
« Reply #14 on: August 05, 2015, 08:48:06 AM »
Based on your observations I think I know what's going on.
When the OFF event is registered, it captures the context of the variables it encapsulates, but the code is executed/evaluated only when the event is fired, hours later.
If the switchmote status at that registration point in time is not satisfying the condition that is about to be evaluated when the event fires, the actual action is never triggered.
Under normal conditions that should not happen, but for some reason if the replies from the switchmote are delayed, and the event is fired sooner than the switchmote state changes from OFF to ON, then when the event fires it sees the OFF value from when it registered and ignores triggering the OFF action.

I know that's totally confusing. But basically I think just removing the condition and always doing the action will solve the problem in all cases as you already observed.
To fix this and keep the condition, the evaluation of the condition should not be encapsulated in the event call, but rather a function call that will evaluate the switchmote status in real time, when the event fires.