AKAPADIA

@Michel Kohanim, I think I have the cause of this one figured out - though I cannot explain why it happens. I had a program that would refresh ELK zone voltages every 3 minutes (attached). It made 3 sequential network calls. Since the old ISY is no longer at that IP address (I'm now running on Polisy), these calls should timeout. They have an explicit timeout of 1 second. So I see no obvious reason for causing the program execution delay. However, I have proved that disabling this program (which is fine because I no longer need it; the ELK Node server keeps voltages up to date by itself) eliminates all the delays. Reenabling the program with no other changes reintroduces the delays, so I know this is the root cause. Two attachments: the errant program and the network resource definitions.

Thanks @Geddy. Step 1 checks out. Everything was the same. Added parameter in Step 2, but I have not been able to repro the issue even before I made this change. I didn't ever have this issue with the IsY; just noticed it in early days with Polisy. Will keep an eye open. Thank you for the suggestion.

@Michel Kohanim, yes, it's a KPL button. Of course, since I posted, it hasn't happened ... I use this feature once a day.

I have the following program that checks the status of a keypadlinc button, and if the status is On, waits 1.5 hours and then sets the switch to Off. My assumption is that the event would fire when the button is turned On and the program would run, and as long as the button is untouched, the event wouldn't fire retrigger and 1.5 hours later, the button would reset to Off. On my old Isy this worked as per my above assumptions. On the Polisy, I find that the button never resets well beyond the 1.5 hour mark and in the UI the program shows that it's running. I can only imagine that the status must be getting reevaluated repeatedly, thus resetting the clock - or else there is some other issue. At any rate, this seems like a behavior change at the least when compared with the old Isy? Wondering whether my assumption is incorrect OR there is some other potential issue afoot here?

Tonight I added a new ZWave outlet to replace a failing Insteon outlet. This works fine but when I tried to make changes to the programs that referenced the old outlet, I began getting weird program save errors. I rebooted the ISY admin UI and tried again. This time I could save a few programs but they were taking much longer to save and then I got the same errors (screen shot attached). Beginning to wonder if I have hardware issues with my Polisy? (After a couple of admin UI restarts, and attempting to save only 1 program at a time, I was able to save)

Reporting on event log level 3 with the same repro scenario: - operate Blind (this is button 5 on keypad with address 2B.A8.02 at the start of the log. It shows up at time 2:33.30 in the level 3 log but at time 2:33.57 in the Excel based log) - immediate walk to Powder Bath and trigger light few seconds later (this is shows up at time 2:34.02 in the level 3 log, but at time 2:34.09 in the Excel log. The interesting thing here is that it takes me only a few seconds to walk over to the bathroom but the event log shows a much larger time difference) - wait ~40 seconds - observe both blind go down and light come on in powder bath, virtually immediately after each other (the powder bath light switch address is 2B.69.8D and can be seen being activated in the level 3 log 2:34.03, and the program to lower the blind sets a variable on response to the key pad press, which can be seen at 2:34:03 (variable # 50 set to 255)) Level3log.txt

I have the event log open and capturing traffic at level 3 and I am trying to reproduce the problem. I was merely providing you with extra information to help narrow the problem down faster, I certainly do not claim to know best :-). Thank you for your help and input.

Thanks @MrBill. This only started happening after my change to Polisy. Also, in the previous post dated 4/13, 11:19, note that the program didn't show as running in the Isy admin UI until 10s of seconds after the motion sensor triggered. This seems to have nothing to do with Insteon and rules it out from my perspective, unless I am missing something. If the program had shown itself in the 'running' state on trigger, and remained running for 20+ seconds, and then the light came on, then you might conceivably say Insteon communication is the cause.

Hi @Michel Kohanim, The event viewer does not explicitly show DON; it just says the light went to 100%. I think that corresponds to DON, though. I don't think this is related to the PLM at all, because I have yet another very interesting observation to report: In short: - I went to my family room and pressed keypad button F to operate a blind. Nothing happened - I walked to my powder bath and the motion sensor there triggered, but the bath light did not come on - I started counting the seconds in my head and, after ~30-40 seconds, both the blind went up and powder light came on virtually simultaneously. I am betting if I had been watching the Isy UI, both programs had not run until this point - inspite of the trigger conditions being received successfully. It's like Isy had suspended execution of all programs for some reason. - The log files show exactly this result. Highlighted in yellow, you see the effect of the blind activation thru keypad F (and the eventual blind execution thru the toggle of keypad E from on->off). Highlighted in green, you see the effect of the powder motion sensor triggering and then the eventual powder light coming on at the same time the blind program triggered.

@Michel Kohanim, Family Flood is an Insteon 8 button keypad's 'main' button (top left). I have another interesting observation to share from yesterday. I looked at the ISY UI while I got my wife to trigger the sensor in a repro of the issue. The ISY UI did not show the program as triggering for a full 20+ seconds after the sensor showed that it had been triggered (the ELK node output zone swung to "On"). Once the program triggered (icon turned green), the light came on instantly. Also noticing this problem is more widespread and affects other programs as well. Appears random. Note: I am using a wired PLM 2413U (brand new)

Text of program to turn on light attached!

More info: Other programs triggered by the same keypad also exhibit delays. However, this is intermittent. Sometimes it works fine. And sometimes there are delays. It almost seems like there is a warm up where if I trigger this device 'cold' there is a delay, but subsequent interactions allow the program to run quickly. Very puzzling. This cannot be Insteon related because it works fine with the old Isy - the problem shows just in the Polisy setup.

I recently moved to Polisy from ISY. I am running IoP 5.4.3. Things are mostly working correctly, except occasionally I have large (40+ second) lags between the trigger of a program and the eventual observed effect of its execution. For instance, in my family room I have an occupancy sensor and a motion sensor tied to my Elk system which I use to trigger lights on using an Isy program. What used to take ~2 seconds to trigger on the Isy just took 40+ seconds on IoP. When I look at the debug logs, I do see the same 40 second delay (see screen shot of log file) - between the time the IsY saw the occupancy sensor trigger and by the time the light came on: When I look at the error logs in between those two events, I don't see anything amiss. How would I debug this further? Tue 2022/04/12 07:48:06 PM 0 -170001 <s:Envelope><s:Body><u:Unsubscribe xmlns:u="urn:udi-com:service:X_Polisy_Service:1"><SID>uuid:27</SID></u:Unsubscribe></s:Body></s:Envelope> Tue 2022/04/12 07:49:09 PM 0 -170001 <s:Envelope><s:Body><u:Subscribe xmlns:u="urn:udi-com:service:X_Insteon_Lighting_Service:1"><reportURL>REUSE_SOCKET</reportURL><duration>infinite</duration></u:Subscribe></s:Body></s:Envelope> Tue 2022/04/12 07:49:18 PM 0 -170001 [TCP-Conn] -1/-140002, Net Module Rule: 17 Tue 2022/04/12 07:49:18 PM 0 -170001 [TCP-Conn] -2/-140002, Net Module Rule: 16 Tue 2022/04/12 07:49:18 PM 0 -170001 [TCP-Conn] -2/-140002, Net Module Rule: 15 Tue 2022/04/12 07:50:42 PM 0 -170001 <s:Envelope><s:Body><u:Unsubscribe xmlns:u="urn:udicom:service:X_Insteon_Lighting_Service:1"><SID>uuid:28</SID></u:Unsubscribe></s:Body></s:Envelope> I wondered if the IsY was too busy - because there is pretty heavy logging - lots of things happening with the Elk Node server. I wondered if it was related to that Insteon device, but when I use my UD Mobile app to remotely operate the light, it's instantaneous.