Sirmeili

I just wanted to give an update. This was fixed by updating to a newer version at the request of Michael from UD. I have been up for the past week and a half without issues.

Yeah, I'm still waiting on a first contact from my ticket (holiday weekend so I understand). What are you doing at the moment to keep everything running? This is killing my WAF. Are you waiting for it to fail or are you doing some kind of automated reboot?

Well, not great news. I woke up and while HA can control the ISY, the polisy is slow to react I get duplicate commands (like it thinks that the ISY didn't respond and HA tried again, or that was all on the ISY side) Trying to log into the pg3x web interface just constantly kicks me back out to the login screen after logging in, but before doing so, it says there is no ISY detected. I have no idea where to see how HA might be overloading the ISY. I've kept the Event Viewer on and I don't see a bunch of excessive commands or anything being sent to it. I've also tried rebooting from the ISY admin interface and the phone since this started happening, but all I get is any ISY with no lights on it. I have to power cycle it manually to get it to work. Looking at the HA logs, I noticed that I was getting heartbeat messages on Saturday from the ISY, but they stopped shortly after my last restart (within an hour or 2) and after that I would get these 2023-11-25 15:40:15.170 WARNING (MainThread) [pyisyox.events.websocket] Websocket disconnected unexpectedly with code: 0 I've also seen this here and there: 2023-11-26 04:13:31.099 ERROR (MainThread) [pyisyox.events.websocket] Error during receive Received frame with non-zero reserved bits After about 24 hours I start to see this: 2023-11-26 13:54:06.099 WARNING (MainThread) [pyisyox] Timeout while trying to connect to the ISY. That goes on untl this morning when it was not as responsive. Note that until this morning, HA didn't see to have many issues talking to the ISY, but obviously in the background it did. I still don't know if this is on the ISY or the HA side, but I can tell you that the code on the HA side for this integration seems to not have changed since earlier this year. it's using websockets so not sure if something changed in the base HA code, but the integration hasn't changed. At this time, I'm not 100% sure the "beta" is the way to go. If anyone can tell me where I can see the logs that points to HA hammering the ISY, I would love to look at them so I can go back to HA and see if it can ber fixed over there. Otherwise, their logs don't show a bunch of communication back to the ISY until the ISY starts to timeout.

So, just a quick update. As of this morning the Polisy is acting fine (both PG3x and the ISY). I'm not seeing any of the java.net.sockettimeoutexceptions in the polisy logs. Still not going to say it's 100% working, I'll continue to monitor, but things are looking up. Some notes if you are using Home Assistant and want to install the beta version of the "Universal Devices ISY/IoX" integration from HACs. t is a replacement/overwrite. That is to say you only have to install it from HACs and nothing else. It will put itself in the custom_components directory and upon restart HA will us that version instead of the included one (so easy install/backout) If you are using any Events in HA for ISY devices, the event data has changed and broken a lot of my automations. It adds the address into the event data. It's a pretty easy fix, but something to be aware of. As far as I can tell, except #2, everything else from a device/entity perspective is the same and all my dashboards and automations (except the issue in #2 for triggers) are working as expected. I'll reprort back tomorrow if it's still working or sooner if I notice it breaks again.

Will. do. So far so good and I don't see the above errors in the HA logs, but then again, don't know if they occurred because the polisy freaked out. I should know in the nest 24 hours and I'll report back.

I looked at the HA logs and I did see lots of these, so it could be that it is on the HA side, but not sure as I never looked before. 2023-11-25 11:57:12.651 DEBUG (MainThread) [pyisy.events.websocket] Starting websocket connection. 2023-11-25 11:57:12.654 ERROR (MainThread) [pyisy.events.websocket] Unexpected websocket error Session is closed Traceback (most recent call last): File "/usr/local/lib/python3.11/site-packages/pyisy/events/websocket.py", line 218, in websocket async with self.req_session.ws_connect( File "/usr/local/lib/python3.11/site-packages/aiohttp/client.py", line 1141, in __aenter__ self._resp = await self._coro ^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/aiohttp/client.py", line 779, in _ws_connect resp = await self.request( ^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/aiohttp/client.py", line 400, in _request raise RuntimeError("Session is closed") RuntimeError: Session is closed I did install the HACs UD ISY/IOX plugin (which is just a newer version of hte one in HA that uses a beta version of pyisy). I'll see if that is any better.

Ok, so it's HA doing it to the polisy? Anyway I can validate this is the same issue in my logs that you know of?

This just started happening, but my polisy is going non-responsive once a day. It's quite frustrating. One thing I've noticed when I do get to the logs is that it says there are errors with "java.net.Sockettimeoutexception" over and over. I can still SSH into the device, but nothing seems to be overwhelming the system. I also can't access the ISY Admin either. I have zero nodes installed and basically just use this as an ISY for my HomeAssistant install. It has been working for months without an issue until recently. Any ideas? I will also open a ticket, but thought the forums might offer faster responses on the holiday weekend.

I changed from calling a light directly to calling a scene and here are the logs. I really REALLY wish they had MS in the times Looks like the first one was maybe 1s? but the second one it's hard to tell. It didn't seem that much faster, but it's hard to compare from hours ago when I tested the other way.

So this is back to happening. ISY says the KPL is in the correct state, but the KPL remains in the wrong state. I have another thread going about another issue, but it was stated that Insteon waits for states. My guess is that button states aren't "verified" because they are set by scenes? Which makes me wonder if the KPL is reporting the scene has been executed and it's just not executing it. I'm thinking of a factory reset and then just having the ISY rewrite the links.

Yeah, sorry, it's confusing and perhaps I tried to give too many details too quickly (I tend to do that). I originally thought it was the REST API causing the delay, but now I think it's the ISY itself (for whatever reason, good or bad). So, I will say that there is a definite delay of 1.5s for the light to turn on. I have been able to reproduce with a program. When Door X Opens, turn on Light Y I recreated the scenario back in the ISY. without having MS it's hard to actually tell how fast the ISY is actually doing anything. I can tell you the light takes about 1-1.5s to turn on. Even making that .5s would be a huge improvement. in the logs I have 50.DB.65 is the light 47.FA.62 is the door switch. (I can recreate the scene issue if need be as well, but this is just easier to set up while I'm working). Attached are the logs. Where can I submit a support request? ISY-Events-Log.v5.6.3__Tue 2023.08.01 09.47.29 AM.txt

I find it odd that there has been a lot of talk about isy making sure that a device responds first. I have another post from last week where it seemed that the air gapping of the KPL fixed it, but the problem came back today. I send a scene to adjust the KPL buttons state and in the ISY they say they are correct, but the KPL itself never reports the same state. I would expect from what I'm hearing here that the ISY would wait for confirmation that the KPL made it's change before updating itself. So maybe my network is hosed. Not sure. This was all just working under HS and now under the ISY it's not. And i'm not trying to say HS is better, I don't feel it is. I didn't factory reset any devices, but I did tell the ISY to wipe any existing links when adding these devices.

Actually I have a scene setup in the ISY that only has responders to turn them off (so they all turn off at once). From HA I trigger the scene Off via the ISY when I get a fast off for a specific KPL. I have a feeling that based on my testing with the door sensor, it would be the same if I had a program in the ISY do it. In both systems I was using Option 2, but the problem is that the scene command is not sent out, much like the individual command, until about 1.5s after the initial "trigger" when using the ISY (whether it be the door sensor status or the fast off command from the KPL). In HS this was faster, perhaps for the reasons you mentioned. Seems to just be a limitation of the technology. The reason I noticed it with the door sensor was that in my utility room I used to have a z-wave switch, but the door sensor was a hidden insteon door sensor. Opening the door, even though it had to go through HS was near instant*. When I went to both insteon devices (door and switch), even though yes, I still had the isy control the devices instead of a scene, it was a lot slower. I understand the potential explanations why that may be given the nature if Insteon. *I know this is not the same situation as this thread discusses. I'm just saying how I had it set up before for that door. For my main use case of using fast off from a KPL to execute an insteon scene from HS, it is still significantly faster than it is in the ISY/HA

I did not move all my devices back over, no. I tested with the 3 devices I'm moving around for this test. That said, HS still has about 10 other devices on it and the ISY has a lot more. But when using the ISY event viewer, I can tell you that I don't have a lot of other traffic when I'm running my tests. I did the same test with all 3 devices in all 3 systems and had the same results in the ISY and HA, but not HS.

A final thought, and I don't really think this would have any effect. HS is currently running on a machine with an i7-6700k while the Polisy and HA/Hub are on much lower power machines. I woudln't think that this type of processing would be that greatly effected by this (that processor is overkill for this and that server is/was used for other things like PLex), but throwing it out there.

So, QQ that I don't think I saw an answer to. What are the ""Previous Message Ignored"" logs? Why is it getting messages and ignoring them? Is the sensor sending out multiple updates and that is clogging up the network?

So my biggest use case for this scenario is turning off a "room". I use Fast off on the main light to trigger a scene with no controllers to turn off all the insteon devices. The problem with a 1.5s delay is that there is no instant feedback, so when this happens you always stop..wait for the scene then move on. With the near instant reaction in HS, I didn't have this "second guessing" if a room was going to turn off (i find that Fast off is a bit fiddly from time to time). Because of this adjusting scenes in a program doesn't help ,but I can see how it could help with potentially turning a light on/off based on the time of day. I don't mean to sound ungrateful or anything. I think just my expectations were set by another implementation that as @bpwwer said could have been optimized for performance over reliability.

I did your test of a program and saw the delay. I even posted the logs and showed how there were multiple "Previous message ignored" I moved a few devices to HA using the built in integration (not the isy one) and I get the same issue. I guess this might explain why Insteon is dying a slow death. I never had this problem in HS and I really don't want to go back there just to get Insteon to be performant. Perhaps Mark over there wrote it to be more performant and less reliable, but it was always 100% reliable for me. Waiting 1.5s for a "command" to go out after a signal has already been received should not be acceptable in home automation these days. I'm not ruling out it's my environment, I just find it odd since I never saw this in HS.

I've been talking with @shbatm on the PyISY github as well. I don't think it will be much help here. It seems to be a limitation of the ISY. I'm looking at using the Insteon HUB directly with HA to see if I have that same delay. I liked the ISY for specific things, but I can't live with that 1-1.5s delay between a sensor/device sending an update and it allowing a command to another device (again, I didn't have this limitation when using HomeSeer's direct insteon control)

I should be more clear. Anytime the ISy gets an update from a device controlled outside the isy, I get this. I.e. if I use "Fast off" on a switch/dimmer, I get the same delay on any subsequent actions.

I will try that out. My only thing is when I had this same setup in homeseer with it controlling the insteon devices directly, I didn't have any such delay. Again, the delay I'm seeing is after a sensor is updated, the subsequent command is delayed. My tests tried be catching requests out and that actually seemed to work ok. I don't get why the sensor coming in is slowing the next response. I also don't get all the "previous message ignored" logs which seems to fill the 1.5s gap.

Ok. I guess I will backtrack on this somewhat. If calling from the ISY (I put a simple html page on the isy with JS to call the same device in rapid succession) it does seem to operate fast (most the time). I do get an occassional 2 second delay on one of the requests. This is if I call the 4 requests in async (though they do still execute in order). In this example you can see the 4th request still took some time but the first 3 completed in under 50ms. 2023-07-30T20:18:32.500Z Recived: 2023-07-30T20:18:30.641Z Recived: 2023-07-30T20:18:30.640Z Recived: 2023-07-30T20:18:30.640Z Recived: 2023-07-30T20:18:30.597Z Sent: 2023-07-30T20:18:30.597Z Sent: 2023-07-30T20:18:30.596Z Sent: 2023-07-30T20:18:30.596Z Sent: Even if I do it serially, they appear to execute quite well to a point. The third and forth are delayed by almost 1.5s and 1s respectively. 2023-07-30T20:26:17.993Z Recived: 2023-07-30T20:26:16.983Z Sent: 2023-07-30T20:26:16.982Z Recived: 2023-07-30T20:26:15.566Z Sent: 2023-07-30T20:26:15.566Z Recived: 2023-07-30T20:26:15.559Z Sent: 2023-07-30T20:26:15.559Z Recived: 2023-07-30T20:26:15.552Z Sent: Which I guess is to be somewhat expected. I'm still confused that in the scenario of a sensor has gone off, notified HA, and HA turned around and called back the ISY, why it is taking 1.5 seconds (consistantly). Here are some tests where I manually triggered a door sensor and ran my script immediately after. The first request after doing so is delayed, again by about 1.5s.: 2023-07-30T20:36:49.935Z Recived 2023-07-30T20:36:49.929Z Sent 2023-07-30T20:36:49.929Z Recived 2023-07-30T20:36:49.057Z Sent 2023-07-30T20:36:49.057Z Recived 2023-07-30T20:36:48.174Z Sent 2023-07-30T20:36:48.174Z Recived 2023-07-30T20:36:46.664Z Sent Could the ISY really be tied up that much after a sensor has been tripped? I tried the same scenario with an ISY program. Door triggers program, program turns on light. Same issue. there is a good 1.5s delay, which makes little sense to me. I've attached the log from the ISY for just this test in case anyone can see what is going on. I don't know why there are a lot of "Previous Message Ignored" like things are being sent multiple times. To be clear here, I'm not trying to hammer the ISY with requests. My simple use case is a sensor is tripped, sent to HA, HA sends a request back, as explained above, this even happens with a program on the ISY. My ultimate use case is to have this automation only run under certain scenarios, which I can't really do with an Insteon Scene (I.e., only turn on the light if the door opens and X is true). *note my tests above are now only limted to the ISY showing that at times, it is in fact taking 1 to 1.5s to process a rest request). ISY-Events-Log.v5.6.3__Sun 2023.07.30 04.50.20 PM.txt

Ok so I might be wrong here. I opened up the event viewer, opened a tab pointing to a rest endpoint (http://10.0.0.172:8080/rest/nodes/50%20D0%20C4%201/cmd/DOF) and just hammered the refresh. I can see all the rest calls come in in quick succession. I don't have a quick way to test if they are in fact sending commands to the device (since it's the same value). I'll have to see if there is a way for me to call the rest API with subsequent calls with alternating values.

Just a quick note that it appears even from the admin screen you are limited to about 1 command a second. I created a program which turns a light on/off 2 times and it doesn't seem to have such a limitation, so the limitation definitely is not from the ISY to the PLM, it's just in it's incoming/outgoing messaging (don't know if the Admin uses the same REST interface or what) to UIs/Integrations that seem to have a limitation.

So I was able to reproduce it manually. I do think now it's something on the ISY, but this is just sort of unacceptable. it should be able to handle more than requests at a time like that. I would assume it is multi threaded, but perhaps not. it tried calling the ISY rest end points directly and yup, even subsequent calls of the exact same are immediate for the first call and then about a 1.5 second delay for one immediately after. My guess is that the ISY is somehow throttling outgoing/incoming requests. This is bad because 1.5s may not seem like a lot, but when you open a door it can feel like forever when waiting for a light to turn on. I didn't have this issue when I had insteon directly set up in HomeSeer, and I honestly don't recall this an issue when I was using the ISY plugin for Homeseer a few years ago, but I was on an ISY 994 back then, not a polisy. My last test was just turning on 2 light and then turning them off (4 actions) and yup, the first one was fast, but the next 3 commands all took 1 second each. Which again, doesn't seem like that much, but in the world of networking and ms fast transactions, 1000ms is a long time. I will have to see if I can find another option because these delays are not acceptable unless someone can tell me how to speed them up?