I think whats going on here is:
I’m parsing a packet beginning with 0x51, which from my hub, says it contains my groups. I’d imagine this number varies from hub to hub.
Give me a few minutes... I’ll update the logic and we can test that hypothesis 
1 Like
Updated logic is in there and worked on my hub. Import the app again from GitHub and see if it’s pulling groups for you.
Not sure it's related, but I updated the app and my hub stopped responding. Attempting a graceful shutdown now.
1 Like
The only code modified was adding the for loop, a debug line, and changing the logic on that case to be containsKey.
I can make this logic faster, I see, but I’m it sure why it would cause slowdown or a lockup
Hmm... my gateway isn’t parsing anything, now... I’m investigating.
I rebooted my hub and the slow behavior persisted. Then after what felt like an hour of watching load screens I was able to disable the App with the disable App check box and do an 8081-Hub-Reboot. Now that my Hub has restarted with the app disabled all is working. I'll keep it that way until you give me the all-clear. I did have a log screen open during that time and nothing untoward appeared, so no help there.
1 Like
I think there is an issue with parse ... not sure what it is. It will cause the driver to keep opening connections, and those can stack up over time if they can't close fast enough.
1 Like
Yes but more like a rest of world driver, it's only seems to be in America that get the pre staging capability. I have seen posts from loads of people all over other than USA that have this issue I get. It's what is needed when the lamps are connected directly or though a Hue bridge. Unfortunately we seem to have been put on the back burner for it.
There is work around's by using rules in stead of HE apps or along side, but it's makes things complex when not done in the driver. It's Pro the last reason I hold off advising HE to Jo blogs, unless I'm managing it.
But basically all HEs apps are setup to send colour then ON rather than ON delay then colour. Its not the "best" look when they transition as they are turning on but I don't mind it, at least they work (this is when you have a working driver).
So, even with color prestaging off, a color or ct command doesn't turn the light on until after the color is sent because the color command sends an on afterwards, and you need the on sent first. Is that what you're saying?
1 Like
I never updated seeing that I don't really need groups so why update when it works right ?
My HE seems very slow now too with the 0.22 update. I'll keep watching the thread for any indication that this is solved.
correct
Removed 0.21 and added new copies of v0.22 parent/all child drivers. So far other than the gateway none of my devices have been found (~30 minutes).
Anything I should try?
Summary
dev:8332020-02-16 05:38:45.125 pm debugLightify (192.168.100.135): Transmitting: 0B000013000000000100000000
dev:8332020-02-16 05:38:45.121 pm debugLightify (192.168.100.135): Number of failed responses: 1
dev:8332020-02-16 05:38:00.427 pm debugLightify (192.168.100.135): Transmitting: 0B000013000000000100000000
dev:8332020-02-16 05:38:00.420 pm debugLightify (192.168.100.135): Number of failed responses: 0
dev:8332020-02-16 05:37:47.995 pm debug40350 >= 22500. First run: false
dev:8332020-02-16 05:37:47.991 pm debugProper time has passed, or it is the device's first run.
dev:8332020-02-16 05:37:47.890 pm debugLightify (192.168.100.135): Stopping connectDevice loop. Starting refresh loop
dev:8332020-02-16 05:37:47.815 pm infoLightify (192.168.100.135): Connection successfully established
dev:8332020-02-16 05:37:47.803 pm debugLightify (192.168.100.135): Transmitting: 0B000013000000000100000000
dev:8332020-02-16 05:37:47.800 pm debug2585 >= 22500. First run: true
dev:8332020-02-16 05:37:47.797 pm debugProper time has passed, or it is the device's first run.
dev:8332020-02-16 05:37:47.723 pm debugLightify (192.168.100.135): Stopping connectDevice loop. Starting refresh loop
dev:8332020-02-16 05:37:47.621 pm infoLightify (192.168.100.135): Connection successfully established
dev:8332020-02-16 05:37:46.591 pm debugLightify (192.168.100.135): Opening Socket Connection.
dev:8332020-02-16 05:37:46.397 pm debugLightify (192.168.100.135): Opening Socket Connection.
dev:8332020-02-16 05:37:45.591 pm debugLightify (192.168.100.135): socketStatus: receive error: Stream closed.
dev:8332020-02-16 05:37:45.588 pm infoLightify (192.168.100.135): A connection issue occurred.
dev:8332020-02-16 05:37:45.216 pm debugLightify (192.168.100.135): Stopping refresh loop. Starting connectDevice loop
dev:8332020-02-16 05:37:45.213 pm debugLightify (192.168.100.135): Initializing device.
dev:8332020-02-16 05:37:45.191 pm debugLightify (192.168.100.135): Number of failed responses: 2
dev:8332020-02-16 05:37:14.353 pm debugLightify (192.168.100.135): Transmitting: 0B000013000000000100000000
dev:8332020-02-16 05:37:14.349 pm debugLightify (192.168.100.135): Number of failed responses: 1
dev:8332020-02-16 05:37:08.455 pm debugLightify (192.168.100.135): Transmitting: 0B000013000000000100000000
dev:8332020-02-16 05:37:08.443 pm debugLightify (192.168.100.135): Number of failed responses: 0
dev:8332020-02-16 05:37:07.645 pm debugLightify (192.168.100.135): Transmitting: 0B000013000000000100000000
dev:8332020-02-16 05:37:07.642 pm debug2822 >= 22500. First run: true
dev:8332020-02-16 05:37:07.639 pm debugProper time has passed, or it is the device's first run.
dev:8332020-02-16 05:37:07.501 pm debugLightify (192.168.100.135): Stopping connectDevice loop. Starting refresh loop
dev:8332020-02-16 05:37:07.451 pm infoLightify (192.168.100.135): Connection successfully established
dev:8332020-02-16 05:37:05.949 pm debugLightify (192.168.100.135): Opening Socket Connection.
dev:8332020-02-16 05:37:05.014 pm debugLightify (192.168.100.135): socketStatus: receive error: Stream closed.
dev:8332020-02-16 05:37:05.011 pm infoLightify (192.168.100.135): A connection issue occurred.
dev:8332020-02-16 05:37:04.820 pm debugLightify (192.168.100.135): Stopping refresh loop. Starting connectDevice loop
dev:8332020-02-16 05:37:04.817 pm debugLightify (192.168.100.135): Initializing device.
dev:8332020-02-16 05:37:04.815 pm debugLightify (192.168.100.135): Number of failed responses: 2
dev:8332020-02-16 05:37:00.173 pm debugLightify (192.168.100.135): Transmitting: 0B000013000000000100000000
dev:8332020-02-16 05:37:00.120 pm debugLightify (192.168.100.135): Number of failed responses: 1
dev:8332020-02-16 05:36:45.107 pm debugLightify (192.168.100.135): Transmitting: 0B000013000000000100000000
dev:8332020-02-16 05:36:45.104 pm debugLightify (192.168.100.135): Number of failed responses: 0
dev:8332020-02-16 05:36:02.614 pm debug75198 >= 22500. First run: false
dev:8332020-02-16 05:36:02.611 pm debugProper time has passed, or it is the device's first run.
dev:8332020-02-16 05:36:02.515 pm debugLightify (192.168.100.135): Stopping connectDevice loop. Starting refresh loop
dev:8332020-02-16 05:36:02.465 pm infoLightify (192.168.100.135): Connection successfully established
dev:8332020-02-16 05:36:02.409 pm debugLightify (192.168.100.135): Transmitting: 0B000013000000000100000000
dev:8332020-02-16 05:36:02.407 pm debug2288 >= 22500. First run: true
dev:8332020-02-16 05:36:02.405 pm debugProper time has passed, or it is the device's first run.
dev:8332020-02-16 05:36:02.359 pm debugLightify (192.168.100.135): Stopping connectDevice loop. Starting refresh loop
dev:8332020-02-16 05:36:02.289 pm infoLightify (192.168.100.135): Connection successfully established
dev:8332020-02-16 05:36:01.491 pm debugLightify (192.168.100.135): socketStatus: receive error: Stream closed.
dev:8332020-02-16 05:36:01.488 pm infoLightify (192.168.100.135): A connection issue occurred.
dev:8332020-02-16 05:36:01.429 pm debugLightify (192.168.100.135): Opening Socket Connection.
dev:8332020-02-16 05:36:01.277 pm debugLightify (192.168.100.135): Opening Socket Connection.
dev:8332020-02-16 05:36:00.392 pm debugLightify (192.168.100.135): socketStatus: receive error: Stream closed.
dev:8332020-02-16 05:36:00.389 pm infoLightify (192.168.100.135): A connection issue occurred.
dev:8332020-02-16 05:36:00.120 pm debugLightify (192.168.100.135): Stopping refresh loop. Starting connectDevice loop
dev:8332020-02-16 05:36:00.117 pm debugLightify (192.168.100.135): Initializing device.
dev:8332020-02-16 05:36:00.115 pm debugLightify (192.168.100.135): Number of failed responses: 2
dev:8332020-02-16 05:35:45.122 pm debugLightify (192.168.100.135): Transmitting: 0B000013000000000100000000
dev:8332020-02-16 05:35:45.119 pm debugLightify (192.168.100.135): Number of failed responses: 1
dev:8332020-02-16 05:35:00.108 pm debugLightify (192.168.100.135): Transmitting: 0B000013000000000100000000
dev:8332020-02-16 05:35:00.105 pm debugLightify (192.168.100.135): Number of failed responses: 0
dev:8332020-02-16 05:34:47.413 pm debug60070 >= 22500. First run: false
dev:8332020-02-16 05:34:47.411 pm debugProper time has passed, or it is the device's first run.
dev:8332020-02-16 05:34:47.352 pm debugLightify (192.168.100.135): Stopping connectDevice loop. Starting refresh loop
dev:8332020-02-16 05:34:47.272 pm debugLightify (192.168.100.135): Transmitting: 0B000013000000000100000000
dev:8332020-02-16 05:34:47.271 pm infoLightify (192.168.100.135): Connection successfully established
dev:8332020-02-16 05:34:47.269 pm debug2193 >= 22500. First run: true
dev:8332020-02-16 05:34:47.265 pm debugProper time has passed, or it is the device's first run.
dev:8332020-02-16 05:34:47.222 pm debugLightify (192.168.100.135): Stopping connectDevice loop. Starting refresh loop
dev:8332020-02-16 05:34:47.191 pm infoLightify (192.168.100.135): Connection successfully established
dev:8332020-02-16 05:34:46.361 pm debugLightify (192.168.100.135): socketStatus: receive error: Stream closed.
dev:8332020-02-16 05:34:46.359 pm infoLightify (192.168.100.135): A connection issue occurred.
dev:8332020-02-16 05:34:46.256 pm debugLightify (192.168.100.135): Opening Socket Connection.
dev:8332020-02-16 05:34:46.171 pm debugLightify (192.168.100.135): Opening Socket Connection.
dev:8332020-02-16 05:34:45.219 pm debugLightify (192.168.100.135): socketStatus: receive error: Stream closed.
dev:8332020-02-16 05:34:45.217 pm infoLightify (192.168.100.135): A connection issue occurred.
dev:8332020-02-16 05:34:45.077 pm debugLightify (192.168.100.135): Stopping refresh loop. Starting connectDevice loop
dev:8332020-02-16 05:34:45.074 pm debugLightify (192.168.100.135): Initializing device.
dev:8332020-02-16 05:34:45.072 pm debugLightify (192.168.100.135): Number of failed responses: 2
dev:8332020-02-16 05:34:20.948 pm debugLightify (192.168.100.135): Transmitting: 0F00001E01000000FFFFFFFFFFFFFFFF00
dev:8332020-02-16 05:34:08.995 pm debugLightify (192.168.100.135): Transmitting: 0B000013000000000100000000
dev:8332020-02-16 05:34:08.992 pm debugLightify (192.168.100.135): Number of failed responses: 1
dev:8332020-02-16 05:34:00.095 pm debugLightify (192.168.100.135): Transmitting: 0B000013000000000100000000
dev:8332020-02-16 05:34:00.092 pm debugLightify (192.168.100.135): Number of failed responses: 0
dev:8332020-02-16 05:33:47.341 pm debug73250 >= 22500. First run: false
dev:8332020-02-16 05:33:47.338 pm debugProper time has passed, or it is the device's first run.
dev:8332020-02-16 05:33:47.290 pm debugLightify (192.168.100.135): Stopping connectDevice loop. Starting refresh loop
dev:8332020-02-16 05:33:47.263 pm infoLightify (192.168.100.135): Connection successfully established
dev:8332020-02-16 05:33:47.247 pm debugLightify (192.168.100.135): Transmitting: 0B000013000000000100000000
dev:8332020-02-16 05:33:47.245 pm debug2170 >= 22500. First run: true
dev:8332020-02-16 05:33:47.242 pm debugProper time has passed, or it is the device's first run.
dev:8332020-02-16 05:33:47.197 pm debugLightify (192.168.100.135): Stopping connectDevice loop. Starting refresh loop
dev:8332020-02-16 05:33:47.164 pm infoLightify (192.168.100.135): Connection successfully established
dev:8332020-02-16 05:33:46.333 pm debugLightify (192.168.100.135): socketStatus: receive error: Stream closed.
dev:8332020-02-16 05:33:46.331 pm infoLightify (192.168.100.135): A connection issue occurred.
dev:8332020-02-16 05:33:46.248 pm debugLightify (192.168.100.135): Opening Socket Connection.
dev:8332020-02-16 05:33:46.154 pm debugLightify (192.168.100.135): Opening Socket Connection.
dev:8332020-02-16 05:33:45.343 pm debugLightify (192.168.100.135): socketStatus: receive error: Stream closed.
dev:8332020-02-16 05:33:45.340 pm infoLightify (192.168.100.135): A connection issue occurred.
dev:8332020-02-16 05:33:45.075 pm debugLightify (192.168.100.135): Stopping refresh loop. Starting connectDevice loop
dev:8332020-02-16 05:33:45.072 pm debugLightify (192.168.100.135): Initializing device.
dev:8332020-02-16 05:33:45.060 pm debugLightify (192.168.100.135): Number of failed responses: 2
dev:8332020-02-16 05:33:00.060 pm debugLightify (192.168.100.135): Transmitting: 0B000013000000000100000000
dev:8332020-02-16 05:33:00.057 pm debugLightify (192.168.100.135): Number of failed responses: 1
dev:8332020-02-16 05:32:45.208 pm debugLightify (192.168.100.135): Transmitting: 0B000013000000000100000000
dev:8332020-02-16 05:32:45.161 pm debugLightify (192.168.100.135): Number of failed responses: 0
dev:8332020-02-16 05:32:34.089 pm debug3540 >= 22500. First run: true
dev:8332020-02-16 05:32:34.059 pm debugProper time has passed, or it is the device's first run.
dev:8332020-02-16 05:32:33.936 pm debugLightify (192.168.100.135): Stopping connectDevice loop. Starting refresh loop
dev:8332020-02-16 05:32:33.818 pm infoLightify (192.168.100.135): Connection successfully established
dev:8332020-02-16 05:32:32.320 pm debugLightify (192.168.100.135): Opening Socket Connection.
dev:8332020-02-16 05:32:30.563 pm debugLightify (192.168.100.135): Stopping refresh loop. Starting connectDevice loop
dev:8332020-02-16 05:32:30.504 pm debugLightify (192.168.100.135): Initializing device.
dev:8332020-02-16 05:30:28.429 pm debugLightify (192.168.100.135): socketStatus: receive error: Stream closed.
dev:8332020-02-16 05:30:28.426 pm infoLightify (192.168.100.135): A connection issue occurred.
dev:8332020-02-16 05:29:36.124 pm errororg.quartz.JobPersistenceException: Couldn't obtain job names: The database has been closed [90098-197] on line 220 (updated)
dev:8332020-02-16 05:29:33.245 pm infoLightify (192.168.100.135): Connection successfully established
dev:8332020-02-16 05:29:32.191 pm debugLightify (192.168.100.135): Opening Socket Connection.
dev:8332020-02-16 05:29:31.826 pm errororg.h2.jdbc.JdbcSQLException: IO Exception: "nio:/data/hub/hubitatdb.mv.db"; SQL statement: UPDATE DEVICE D SET D.STATE = ? WHERE D.ID = ? [90028-197] (socketStatus)
dev:8332020-02-16 05:29:31.277 pm debugLightify (192.168.100.135): socketStatus: receive error: Stream closed.
dev:8332020-02-16 05:29:31.247 pm infoLightify (192.168.100.135): A connection issue occurred.
dev:8332020-02-16 05:29:30.873 pm debugLightify (192.168.100.135): Stopping refresh loop. Starting connectDevice loop
dev:8332020-02-16 05:29:30.836 pm debugLightify (192.168.100.135): Initializing device.
dev:8332020-02-16 05:29:03.022 pm debug75175 >= 22500. First run: false
dev:8332020-02-16 05:29:03.020 pm debugProper time has passed, or it is the device's first run.
dev:8332020-02-16 05:29:02.770 pm infoLightify (192.168.100.135): Connection successfully established
dev:8332020-02-16 05:29:02.638 pm debug2556 >= 22500. First run: true
dev:8332020-02-16 05:29:02.595 pm debugProper time has passed, or it is the device's first run.
dev:8332020-02-16 05:29:02.405 pm infoLightify (192.168.100.135): Connection successfully established
dev:8332020-02-16 05:29:01.726 pm infoLightify (192.168.100.135): A connection issue occurred.
dev:8332020-02-16 05:29:00.434 pm infoLightify (192.168.100.135): A connection issue occurred.
dev:8332020-02-16 05:27:47.844 pm debug103667 >= 22500. First run: false
dev:8332020-02-16 05:27:47.818 pm debugProper time has passed, or it is the device's first run.
dev:8332020-02-16 05:27:47.634 pm infoLightify (192.168.100.135): Connection successfully established
dev:8332020-02-16 05:27:47.539 pm debug2366 >= 22500. First run: true
dev:8332020-02-16 05:27:47.537 pm debugProper time has passed, or it is the device's first run.
dev:8332020-02-16 05:27:47.381 pm infoLightify (192.168.100.135): Connection successfully established
dev:8332020-02-16 05:27:46.654 pm infoLightify (192.168.100.135): A connection issue occurred.
dev:8332020-02-16 05:27:45.452 pm infoLightify (192.168.100.135): A connection issue occurred.
dev:8332020-02-16 05:26:04.152 pm debug76038 >= 22500. First run: false
dev:8332020-02-16 05:26:04.150 pm debugProper time has passed, or it is the device's first run.
dev:8332020-02-16 05:26:03.843 pm infoLightify (192.168.100.135): Connection successfully established
dev:8332020-02-16 05:26:02.927 pm debug2796 >= 22500. First run: true
dev:8332020-02-16 05:26:02.925 pm debugProper time has passed, or it is the device's first run.
dev:8332020-02-16 05:26:02.703 pm infoLightify (192.168.100.135): Connection successfully established
dev:8332020-02-16 05:26:01.916 pm infoLightify (192.168.100.135): A connection issue occurred.
dev:8332020-02-16 05:26:00.739 pm infoLightify (192.168.100.135): A connection issue occurred.
dev:8332020-02-16 05:24:48.113 pm debug3012 >= 22500. First run: true
dev:8332020-02-16 05:24:48.091 pm debugProper time has passed, or it is the device's first run.
dev:8332020-02-16 05:24:47.951 pm debug82465 >= 22500. First run: false
dev:8332020-02-16 05:24:47.949 pm debugProper time has passed, or it is the device's first run.
dev:8332020-02-16 05:24:47.762 pm infoLightify (192.168.100.135): Connection successfully established
dev:8332020-02-16 05:24:47.745 pm infoLightify (192.168.100.135): Connection successfully established
dev:8332020-02-16 05:24:45.431 pm infoLightify (192.168.100.135): A connection issue occurred.
dev:8332020-02-16 05:23:25.466 pm debug2409 >= 22500. First run: true
dev:8332020-02-16 05:23:25.463 pm debugProper time has passed, or it is the device's first run.
dev:8332020-02-16 05:23:25.298 pm infoLightify (192.168.100.135): Connection successfully established
dev:8332020-02-16 05:23:20.604 pm debug1162 >= 30000. First run: true
dev:8332020-02-16 05:23:20.601 pm debugProper time has passed, or it is the device's first run.
My hub started acting up (500 errors, no lutron commands from Alexa going through so I am doing a restore to my last good config)
I'm working on a solution for all of the above.
I currently have it implemented as [Color] > [On]. Is the standard practice the other way? My thought was that not showing the transition was the idea behind that. I'll be re-working color pre-staging, anyways, so I can easily change it.
1 Like
I think what's happening is this:
When the app initially installs, it checks if a child device is created. If one isn't, it creates one and runs initialize. It appears to call this two times, of which the gateway driver should bounce the second request. There was a bug where the driver wouldn't bounce the second request, and it would open two connections simultaneously, without closing the second connection after initialization.
After the gateway refreshed, it would then refresh twice, and not parse—I'm still trying to find the parse bug. When there's nothing to parse, the device reads a failed packet response, and will kill a connection after three of these are read (the default number of failed pings in the settings).
In addition, the JVM can take quite a while to kill these connections. It's a lot better in 2.1.9, but it still can compound in a poorly written driver—like you've seen here.
I've fixed the duplicate initialization check. I am still figuring out what I did to break transmissions last night between my final tests and publishing.
Thanks for your patience. If anyone needs 0.21, shoot me a message.
1 Like
Here is 0.21 in an archive, for those in need. I'm making progress on a fix, but still need some time
2 Likes
Hahaha ugh. where are my proofreaders at? 
You write a million for loops in your life, and sometimes you just don't check if they're even in the correct order...
3 Likes
Alright ... it's all working again. I haven't tested this exact as far as longevity goes, but my hub ran fine with it all day yesterday, and all last night (and a few days prior) until I messed up writing a for loop this morning. I think it's safe.
You can download 0.22 from my GIT repo (new logic for group detection is tested and working, too )
2 Likes
It found my devices/group, I am excited to test tomorrow (1 year old is in the room with the 'test' lights or I'd be playing with it right now).
1 Like
