device status and program problems

[EricK]

ISY firmware 4.2.10 with a year old PLM, V9B.  Last night a door was open and I did not receive a notification at 930 that it was,  Hidden door sensor, linked to a KPL in the bedroom.

If
        (
             From    10:45:07PM
             To       6:30:00AM (next day)
          Or Time is  9:45:00PM
        )
    And Status  'Basement / Basement Devices / Exercise Room - Door Sensor' is On
 
Then
        Send Notification to 'Eric text' content 'Exercise Room Door is Open'
 
Else
   - No Actions - (To add one, press 'Action')
 
 

 The kpl was lit, which is how I knew the door was open.  A program that is supposed to adjust the lights going up the steps at 9pm did not run

If
        From     9:00:03PM
        To      12:05:00AM (next day)
 
Then
        Set Scene 'Hall and Foyer / Hallway Stairs 50%' On
 
Else
   - No Actions - (To add one, press 'Action')
 
 

and then a program to adjust the lights down further just after midnight did not run either.  A program to turn off my KPL back light did run

If
        Time is 11:00:03PM
 
Then
        Set 'Master Bedroom / Master Bedroom Devices / Master His KPL - A lights' On  7 / Off 0 (Backlight Level)
 
Else
   - No Actions - (To add one, press 'Action')
 
 

I just received a notification at 310AM that my water valve was closed.  ELK WSV controlled by an io linc. I have two notifications that should be sent.  The first is if the relay status is closed, that program did not trigger.  The second program, my confirmation program, sends notification if the io sensor is on, that program did trigger.  I checked the valved and it was still open.  The ISY showed the sensor was on, so I queried the device and the status of the sensor changed to off.

I disabled the 

[EricK]

Sorry, posted by accident and cannot edit.

I disabled the water valve program but do not understand what is happening.  The io linc sensor was not on, so why did the ISY show that it was.  Could it be a communication problem after the 3AM query.  That would not explain the programs based upon time not running.  Is my PLM going bad.  Just now while logged into the ISY the log in screen popped up like it was logging me out then back it.  It is not set up for access from outside by network and I am not using the default password.  

I have to work late tonight so I may not be able to trouble shoot until tomorrow, but any help would be appreciated.  Not feeling well right now so was up any way.

Eric

[LeeG]

Is the Trigger Reverse option set for the I/O Linc?   If so the Sensor state will change with 3AM Query because Trigger Reverse does not reverse the Query result.

[oberkc]

What makes you think the 9pm program did not run? Is it disabled? If you check program status after 9 and before midnight, does it show TRUE?

 

What evidence is there that the 11pm program did not run? Are you basing this upon the fact that the backlight levels remain unchanged?

[Xathros]

Are all of the failures with notifications?  If so, this could be an issue with notifications not sending rather than programs not running.  Check your error log around the times these notifications were to be sent for any errors.

 

-Xathros

Edited December 1, 2014 by Xathros

[EricK]

The 11pm program did run, the backlight did adjust.

The 9pm program did not show a last run time when I checked it at around 1030pm and the lights did not adjust. It did not show true. Once I manually selected run then for it the program did run.

The same for the mn program did not show true. By checking I mean looking in the admin console at the program details.

The only thing new in the house was a surge suppressor I plugged in for a small christmas tree with leds. Still would not explain why some programs did not appear to run or why the isy thought the io linc sensor was on. Strange things.

Edited December 1, 2014 by EricK

[Xathros]

Hi EricK-

 

Can you describe the conditions on the programs that didn't run?  Are they in folders with conditions and if so, what are the conditions on the folder(s).  I have never seen the ISY miss running a time based program unless there was a power loss or another unmet condition in the program or enclosing folder.

 

-Xathros

[oberkc]

The 11pm program did run, the backlight did adjust.

The 9pm program did not show a last run time when I checked it at around 1030pm and the lights did not adjust. It did not show true. Once I manually selected run then for it the program did run.

The same for the mn program did not show true. By checking I mean looking in the admin console at the program details.

The only thing new in the house was a surge suppressor I plugged in for a small christmas tree with leds. Still would not explain why some programs did not appear to run or why the isy thought the io linc sensor was on. Strange things.

Sorry. I misunderstood. The only thing I see that runs "just after midnight" is 7n your second program, and it does nothing that I can see. What program do you expect torun after midnight that "adjusts the lights down further"?

[EricK]

Xathros,the conditions on the programs that did not run were times. The programs are not in folders with conditions. There was no power loss. The last run box was empty. In my 9pm to mn program the little program icon did not have the green stripe during the run time.

Oberkc, sorry I did not post the other program. It is something like this

If time is 1206am

Then set scene hallway stairs 30% on.

The lights go from 90% to 50%, then to 30%. I realize the to time in my second program does nothing but help me organize and remember.

My landscape and moon light timer programs did trigger by time

[Xathros]

EricK-

 

Anything notable in either the Log or Error Log around the affected times?

 

-Xathros

[EricK]

I did not check the error log but dumped the log. It was 4am and in word pad so I'll have to dig thru it.

I also do not know why the isy showed the io linc sensor was on when it was not.

Thanks for helping guys.

[Xathros]

I did not check the error log but dumped the log. It was 4am and in word pad so I'll have to dig thru it.

I also do not know why the isy showed the io linc sensor was on when it was not.

Thanks for helping guys.

Always happy to help.

 

Re: The IOLinc sensor, if you know when it should have turned OFF, check your log for that off message.  It's possible that it got missed leaving the ISY thinking the sensor was on.  Try running a few tests with the event viewer running at level 3, query the IOLinc and see what the event viewer shows for Max/Remaining hops.  This should give an indication of comm quality between the PLM and the IOLinc.

 

-Xathros

[EricK]

Xathros,

The sensor was not on. It only turns on when the water valve closes. The green sensor light on the io linc was not on. A kpl button controlled by the sensor was not on. We'll see what time I can get home tonight to look at things and try what you suggested. I'll unplug the new power strip. I wish I had some screen shots with the programs not running when they should have been. Evidence.

Eric

[Xathros]

EricK-

 

My suggestion was that the ISY did not hear the message last time the sensor turned off, not that the sensor was actually on.  All of the evidence you have provided so far indicates that the sensor was off but the ISY believed it was still on.  This makes me think there may be some comm issues between the IOLinc and the PLM location.  The sensor must have sent the off message as the KPL button status was correctly updated.

 

Does the new power strip share a circuit with either the PLM or IOLinc?  If so, then this could very well be the issue and could likely be resolved by adding a filterlinc or relocating that strip to another circuit if possible.

 

It may be worth running the event viewer test a few times both with and without that strip plugged in to see if there is a noticeable change in comm quality with.without the strip.

 

-Xathros

[EricK]

Xathros,

I promise that sensor was not on recently. If the sensor turns on it should mean that my water valve is closed.

The power strip is on a separate circuit from the plm and io Linc. Really a bad week for me to have to trouble shoot. Hopefully everything will go back to working smoothly.

[Xathros]

I feel your pain.  Things never seem to fail at convenient times here either.

 

Another remote possibility is a phantom on message received by the PLM similar to the dreaded ALL ON or random scene On events that some have seen.  While unlikely, this could explain the unexpected sensor On state reflected by your ISY.  Following that train of thought, maybe you could post your PLM's hardware (Sticker) and firmware (from the ISY) versions for comparison with other known problematic PLM versions.

 

It seems to me that the more RF insteon traffic in any one install, the greater the chance for corrupted insteon messages to mess things up.  This is just gut feeling but I suspect it is shared by others here.

 

Anyway, no rush.  Whenever you are ready to troubleshoot this, I and others here and at UDI stand ready to help.  Do what you can in the interim to document the issues and save logs and error logs that reflect the problems as they may prove quite valuable in determining the root cause when we do get to work on this.

 

-Xathros

[EricK]

Got home and everything seems to be working fine.  Here are some interrogations and info:

PLM is V1.B per the sticker, V9B from the ISY.

Error logs look ok I think.  The false io linc sensor on notification was just after 3AM on 12/1.

Sun 2014/11/30 10:43:48 PM	System	-5006	uuid:44	
Mon 2014/12/01 02:34:37 AM	System	-100	[DHCP] state=RENEW	
Mon 2014/12/01 03:10:21 AM	System	-5012	46	
Mon 2014/12/01 02:34:57 PM	System	-100	[DHCP] state=RENEW

Event level 3 query for the io linc sensor, which again never turned on.  The ISY thought it was on right after the 3AM system query. 

Mon 12/01/2014 09:12:36 PM : [All         ] Writing 0 bytes to devices

Mon 12/01/2014 09:15:01 PM : [  27 A1 8B 4]      DON   4

Mon 12/01/2014 09:15:29 PM : [INST-TX-I1  ] 02 62 28 C2 87 0F 19 01

Mon 12/01/2014 09:15:29 PM : [INST-ACK    ] 02 62 28.C2.87 0F 19 01 06          LTSREQ (01)

Mon 12/01/2014 09:15:29 PM : [INST-SRX    ] 02 50 28.C2.87 28.CC.86 27 00 00           (00)

Mon 12/01/2014 09:15:29 PM : [Std-Direct Ack] 28.C2.87-->ISY/PLM Group=0, Max Hops=3, Hops Left=1

Mon 12/01/2014 09:15:29 PM : [D2D EVENT   ] Event [28 C2 87 1] [ST] [0] uom=0 prec=-1

Mon 12/01/2014 09:15:29 PM : [  28 C2 87 1]       ST   0

Mon 12/01/2014 09:15:29 PM : [D2D-CMP 009B] STS [28 C2 87 1] ST op=1 Event(val=0 uom=0 prec=-1) is Condition(val=255 uom=0 prec=-1) --> false

Mon 12/01/2014 09:15:29 PM : [INST-TX-I1  ] 02 62 28 C2 87 0F 19 00

Mon 12/01/2014 09:15:29 PM : [INST-ACK    ] 02 62 28.C2.87 0F 19 00 06          LTSREQ (LIGHT)

Mon 12/01/2014 09:15:29 PM : [INST-SRX    ] 02 50 28.C2.87 28.CC.86 27 00 00           (00)

Mon 12/01/2014 09:15:29 PM : [Std-Direct Ack] 28.C2.87-->ISY/PLM Group=0, Max Hops=3, Hops Left=1

Here is the event viewer for the hallway stairs 9pm program that did not run yesterday.  When I opened the event viewer window, not sure why I got the first two lines before running the program.

Mon 12/01/2014 09:18:17 PM : [FileOpen    ] Open failed for [/CONF/IR.CFG] (r)

Mon 12/01/2014 09:18:20 PM : [FileOpen    ] Open failed for [/CONF/NET/WOL.CFG] (r)

Mon 12/01/2014 09:19:31 PM : [        Time] 21:19:31 1(0)

Mon 12/01/2014 09:19:31 PM : [INST-TX-I1  ] 02 62 00 00 25 CF 11 00

Mon 12/01/2014 09:19:31 PM : [INST-ACK    ] 02 62 00.00.25 CF 11 00 06          LTONRR (00)

Event Level 3 for query of the hallway stair load controlling switch:

Mon 12/01/2014 09:24:07 PM : [INST-TX-I1  ] 02 62 17 1E EC 0F 19 00

Mon 12/01/2014 09:24:07 PM : [INST-ACK    ] 02 62 17.1E.EC 0F 19 00 06          LTSREQ (LIGHT)

Mon 12/01/2014 09:24:07 PM : [INST-SRX    ] 02 50 17.1E.EC 28.CC.86 2B 00 7F           (7F)

Mon 12/01/2014 09:24:07 PM : [Std-Direct Ack] 17.1E.EC-->ISY/PLM Group=0, Max Hops=3, Hops Left=2

Mon 12/01/2014 09:24:07 PM : [D2D EVENT   ] Event [17 1E EC 1] [ST] [127] uom=0 prec=-1

Mon 12/01/2014 09:24:07 PM : [  17 1E EC 1]       ST 127

Mon 12/01/2014 09:24:07 PM : [D2D-CMP 0064] STS [17 1E EC 1] ST op=6 Event(val=127 uom=0 prec=-1) != Condition(val=0 uom=0 prec=-1) --> true

Mon 12/01/2014 09:24:07 PM : [D2D EVENT   ] Event [17 1E EC 1] [OL] [229] uom=0 prec=-1

Mon 12/01/2014 09:24:07 PM : [  17 1E EC 1]       OL 229

Mon 12/01/2014 09:24:07 PM : [D2D EVENT   ] Event [17 1E EC 1] [RR] [26] uom=0 prec=-1

Mon 12/01/2014 09:24:07 PM : [  17 1E EC 1]       RR  26

Thanks,

Eric

[Xathros]

The proximity of the sensor ON to the 3AM query makes me wonder about the IOLinc trigger reverse option.  If Trigger reverse is enabled, this would explain the behavior.  As LeeG reported above, Trigger reverse reverses the sensor commands when the sensor state changes but does not reverse the sensor when queried.  This has the effect of changing the sensor state in the ISY when the 3Am query runs.

 

Can you verify that Trigger Reverse is not checked in the IOLinc options?

 

-Xathros

[EricK]

Trigger reverse is not checked.  I have had an io linc go bad before, but this one seems to be working.  Stusviews has coined the term "gremlincs" which may be my problem.

[johnnyt]

Did you press the query button? I've had IOLincs change mysteriously several times, in my case from latching to momentary and it didn't show up until I queried it. To this day no one has offered an explanation for it nor can I predict when it will happen. I like the term gremlincs. It hasn't happen that often relatively speaking (I was using 11 IOLincs at one point), it did affect more than 1 IOLinc, and the problem was intermittent, suggesting to me it wasn't failing hw. I long ago reduced my use of IOLincs for this and other reasons.

 

 

Sent from my iPad using Tapatalk

[Xathros]

Another thought and maybe @LeeG can chime in on this, some multi-node devices when queried report the status for the multiple nodes and a duplicate message from one node can be mistaken as status for a a defferent node by the ISY.  If your IOLinc relay was on when it was queried, it may be possible that the ISY mistook a duplicate on status message from the relay as the sensor status.  I have heard of this happening with the EZIO devices and I vaguely remember a thread where this happened with an IOLinc in a garage door application.

 

Do you know what the relay status should have been with the false sensor On occurred?

 

-Xathros

[LeeG]

I have seen event traces where a duplicate Query response with a low Hops Left value comes back late, falling into the next Query command sequence.  It gave the appearance of a node state that was not true.  I looked for this case yesterday in my collection of trace files but could not find an old trace with this circumstance.  The trace was posted by the user but did not find it in the forum either.  It is rare and requires an event trace of the actual situation to confirm.  This is very rare so it may not have anything to do with this thread.

[EricK]

The relay was definitely off.  If the relay turns on the water valve closes which trigger a variety of notifications and a terrible WAF.

[Xathros]

In this case, the one sample trace shows good comms between the IOLinc and PLM though that one brief trace is not really enough to says all is good there without question.  If the relay was off then and given Lee's response above, I find a false status message to be unlikely. Not sure where else to go with this now.  Keep an eye on it and lets see if there is any pattern to the problem if it happens again.

 

-Xathros