Long delay in reading variables

[GregKing]

I am trying to integrate motion sensors on my Ocelot/Secu16 setup into HS. To provide hysteresis on the toggling on/off of the sensor, I have code in the Ocelot set a variable on a sensor trigger and leave it set for 1 minute. This is the mechanism I am using to tell HS to turn on a light (actually a UPB link).

There is an extremely long delay in HS detecting the variable, on the order of 6-10 seconds (it varies). I have the polling set to 2 secs, so I could understand something on the order of 2-3 secs, but this is much longer.

gk

[zimmer62]

I'm using the ADIO Ocelet plugin and I also notice this delay most of the time. I wish it was a direct notification instead of polling. I'm not sure if anyone can elaborate why it's slow or how to make it faster.

[GregKing]

Yeah, I tried the ADIOcelot, but couldn't remember if it was slow. I had to change back to the HS one since I couldn't get the ADIOcelot one to work with variables the way I wanted to and the HS one did.

It's just slow with the vars though. If I used the input change, then it would trigger quickly. Apparently this is sent whenever there is a change. I haven't looked at the details of the Ocelot protocol.

gk

[stevene]

Why not use the actual input points for the motion sensors in HS ?

I have 5 modules on my ocelot with 20+ motion sensors and they respond instantly with HS.

That said I beleive the problem is in the ocelot itself, when inputs are changing the ocelot is sending those changes through the serial port, delaying the polling. ( this is just an observation after having the ocelot for 5+ years with motion sensors ).

StevenE

[zimmer62]

I'm not sure why I'm using the variable instead of input itself. I'll have to rethink what I was doing for now. I have the ocelot control my doorbell, and there is a program on the ocelot to set a variable, and control how long the ding and the dong are on the bell.

[GregKing]

Because I want the motion to trigger setting a light on for a fixed duration by executing a UPB link. If I use the input point, then the light flashes for the simple duration of the triggering time.

Yes, I could probably create some script logic in HS to perform this way, but it was a matter of 3-4 lines of code in the Ocelot. I set a timer if it's not running whenever motion is detected and when the timer expires, I clear the variable. This provides the hysteresis I wanted.

I hadn't thought about that the toggling may cause the Ocelot to delay it's variable output. I just assumed HS was polling this info and it was being sent in a reasonable time.

Maybe I'll create a timed action in the Ocelot to change a variable and see how soon HS sees that. Of course that is what happens after the one minute timeout, so I guess I could look into that.

gk

[stevene]

Because I want the motion to trigger setting a light on for a fixed duration by executing a UPB link. If I use the input point, then the light flashes for the simple duration of the triggering time.

gk

I could understand, I too myself would like to be able to limit the inputs to HS, I mean with so many motion sensors the serial communication from the ocelot is a lot. And HS has to weed through each one, luckily it does not seem to impact HS much.

StevenE

[GregKing]

Log info

Okay, I did some investigation of the log files and here is what I have found. There's an error msg generated stating: "Warning, Ocelot returned wrong buffer for variable request buffer, ignoring data".

It looks like the Ocelot plugin got data it wasn't expecting.

The log shows it cycling between Waiting for IO and Waiting for Vars correctly, up to the point at which an IO point changes. At this point, the plugin seems to get out of synch and spits the bit. This causes the delay, because it has to wait for subsequent polling intervals before it can read the vars.

As you can see here, it detects the first change to an IO point at 08:53:36 and subsequently logs an error.

3/11/2008 8:53:25 PM Comm byte count:  0
3/11/2008 8:53:26 PM Comm byte count:  0
3/11/2008 8:53:27 PM Waiting for IO info from Ocelot
3/11/2008 8:53:28 PM 2A 0 0 8D B5 0 F0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 
3/11/2008 8:53:28 PM Waiting for var info from Ocelot
3/11/2008 8:53:28 PM 2A 0 0 91 AA 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 FF FF 0 0 0 0 FF 0 
3/11/2008 8:53:28 PM Comm byte count:  0
3/11/2008 8:53:30 PM Waiting for IO info from Ocelot
3/11/2008 8:53:30 PM 2A 0 0 8D B5 0 F0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 
3/11/2008 8:53:30 PM Waiting for var info from Ocelot
3/11/2008 8:53:31 PM 2A 0 0 91 AA 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 FF FF 0 0 0 0 FF 0 
3/11/2008 8:53:31 PM Comm byte count:  0
3/11/2008 8:53:32 PM Comm byte count:  0
3/11/2008 8:53:33 PM Waiting for IO info from Ocelot
3/11/2008 8:53:33 PM 2A 0 0 8D B5 0 F0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 
3/11/2008 8:53:33 PM Waiting for var info from Ocelot
3/11/2008 8:53:34 PM 2A 0 0 91 AA 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 FF FF 0 0 0 0 FF 0 
3/11/2008 8:53:34 PM Comm byte count:  0
3/11/2008 8:53:35 PM Comm byte count:  0
3/11/2008 8:53:36 PM Waiting for IO info from Ocelot
3/11/2008 8:53:36 PM 2A 0 0 8D B5 0 F0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 
3/11/2008 8:53:36 PM Waiting for var info from Ocelot
3/11/2008 8:53:36 PM IO point change mod=  1 point=  0 newval=  1
3/11/2008 8:53:36 PM Setting HS device: [1 to OFF
3/11/2008 8:53:36 PM 2A 0 0 8D B5 0 F0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 
3/11/2008 8:53:36 PM Warning, Ocelot returned wrong buffer for variable buffer request, ignoring data
3/11/2008 8:53:36 PM Comm byte count:  264
3/11/2008 8:53:36 PM Rcv data: b0= 42 b1= 0 b2= 0
3/11/2008 8:53:36 PM Comm byte count:  261
3/11/2008 8:53:36 PM Rcv data: b0= 145 b1= 170 b2= 0
3/11/2008 8:53:36 PM Comm byte count:  258
3/11/2008 8:53:36 PM Rcv data: b0= 0 b1= 0 b2= 0
3/11/2008 8:53:36 PM Comm byte count:  255
3/11/2008 8:53:36 PM Rcv data: b0= 0 b1= 0 b2= 0
3/11/2008 8:53:37 PM Comm byte count:  252
3/11/2008 8:53:37 PM Rcv data: b0= 0 b1= 0 b2= 0
3/11/2008 8:53:37 PM Comm byte count:  249
3/11/2008 8:53:37 PM Rcv data: b0= 0 b1= 0 b2= 0
3/11/2008 8:53:37 PM Comm byte count:  246
3/11/2008 8:53:37 PM Rcv data: b0= 0 b1= 0 b2= 0
3/11/2008 8:53:37 PM Comm byte count:  243

It then walks through the data in increments of 3 bytes until it gets to the end and then it reports the IO change again. Note that it appears to be cycling here as the motion detector is triggering which is correct.

Finally, at 08:53:59, it reads the vars correctly.

I think in this case, I would have gotten my var notification within about 3-4 secs of the motion trigger. However, I suspect in other times, it may have several of these errors, causing the delay to increase to additional multiples of the 2 second polling value, i.e. 7-10 seconds, which is what I am seeing with varying delays.

3/11/2008 8:53:37 PM Comm byte count:  13
3/11/2008 8:53:37 PM Rcv data: b0= 0 b1= 0 b2= 0
3/11/2008 8:53:37 PM Comm byte count:  10
3/11/2008 8:53:37 PM Rcv data: b0= 0 b1= 0 b2= 0
3/11/2008 8:53:37 PM Comm byte count:  7
3/11/2008 8:53:37 PM Rcv data: b0= 0 b1= 235 b2= 33
3/11/2008 8:53:37 PM Comm byte count:  4
3/11/2008 8:53:37 PM Rcv data: b0= 240 b1= 1 b2= 0
3/11/2008 8:53:37 PM IO point change mod=  1 point=  0 newval=  0
3/11/2008 8:53:37 PM Setting HS device: [1 to ON
3/11/2008 8:53:37 PM Comm byte count:  4
3/11/2008 8:53:37 PM Rcv data: b0= 240 b1= 1 b2= 0
3/11/2008 8:53:37 PM IO point change mod=  1 point=  0 newval=  1
3/11/2008 8:53:37 PM Setting HS device: [1 to OFF
3/11/2008 8:53:37 PM Comm byte count:  0
3/11/2008 8:53:37 PM Comm byte count:  0
3/11/2008 8:53:37 PM Comm byte count:  4
3/11/2008 8:53:37 PM Rcv data: b0= 240 b1= 1 b2= 0
3/11/2008 8:53:37 PM IO point change mod=  1 point=  0 newval=  0
3/11/2008 8:53:37 PM Setting HS device: [1 to ON
3/11/2008 8:53:37 PM Comm byte count:  0
3/11/2008 8:53:37 PM Comm byte count:  4
3/11/2008 8:53:37 PM Rcv data: b0= 240 b1= 1 b2= 0
3/11/2008 8:53:37 PM IO point change mod=  1 point=  0 newval=  1
3/11/2008 8:53:37 PM Setting HS device: [1 to OFF
3/11/2008 8:53:37 PM Comm byte count:  0
3/11/2008 8:53:38 PM Comm byte count:  4
3/11/2008 8:53:38 PM Rcv data: b0= 240 b1= 1 b2= 0
3/11/2008 8:53:38 PM IO point change mod=  1 point=  0 newval=  0
3/11/2008 8:53:38 PM Setting HS device: [1 to ON
3/11/2008 8:53:38 PM Comm byte count:  0
3/11/2008 8:53:38 PM Comm byte count:  0
3/11/2008 8:53:38 PM Waiting for IO info from Ocelot
3/11/2008 8:53:39 PM 2A 0 0 8D B5 0 F0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 
3/11/2008 8:53:39 PM Waiting for var info from Ocelot
3/11/2008 8:53:39 PM 2A 0 0 91 AA 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 FF FF 0 0 4 0 FF 0 
3/11/2008 8:53:39 PM Setting Var: #21 to  1
3/11/2008 8:53:39 PM Setting Var: #63 to  4
3/11/2008 8:53:39 PM Comm byte count:  0
3/11/2008 8:53:41 PM Waiting for IO info from Ocelot
3/11/2008 8:53:42 PM 2A 0 0 8D B5 0 F0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 
3/11/2008 8:53:42 PM Waiting for var info from Ocelot

[GregKing]

Bump...

[rjh]

Using variables will be slow, you need to use the digital inputs as those send a message immediately.

[GregKing]

What kind of answer is that?

You're basically saying that reading variables from the Ocelot doesn't work, so don't plan on using this functionality.

My analysis shows that there appears to be a bug in your processing (or a bug in the Ocelot) and yet you seem to disregard this. If you are saying the bug is in the Ocelot, then I guess I need to post the error on the Appdig board.

As I stated in an earlier thread, I can't use the input triggers. If I tie the input directly to the action (UPB link) then the lights flash on and off with each pulse. I have logic within the ocelot to communicate to HS using the variables based on various status info within the ocelot.

gk


gk

Using variables will be slow, you need to use the digital inputs as those send a message immediately.

[rjh]

We have not touched this plugin in over 2 years so I don't understand why there is an issue all of a sudden. Variables are retrieved during the polling interval. Maybe there is a COM port issue? If you run the CMAX software and monitor the variables do you see them change quicker? I don't know how often the CMAX software is polling however.

[GregKing]

Good suggestion. I'll try to test using CMAX to see if it has the same buffer problem. I didn't see any error log setting in CMAX, so not sure how to capture detailed data flow.

gk