Interesting I have been running the Ecobee suite since I have had my Hubitats.
Just checked another client sites and the percentage used by Ecobee usage is about the same:
Yeah I keep getting a severe load message in my hubitat messages. And removing this has stopped it. I removed ecobee suite over a week ago and have not had that message once since.
At this point we have a few examples of what the runtime stats should look like. Can you replicate the issue and then post the runtime stats so we can see what your hub is doing. Without more details there is no way to know what is actually happening. Allot of folks run this app without issue.
it may also help to go into the app details. Click on the gear next to the app in the apps page and then list show a screen shot of what is at the bottom
I have posted stuff in this thread and I had a case open with hubitat directly.
I have seen your reports of concerns about Ecobee Suite (scattered over 3 or 4 different threads, making it difficult to track the context, BTW). From what you've shown me, the CPU and Memory overhead of Ecobee Suite is infinitesimal, even while it may be the busiest application. In fact, MANY ES users run with higher load than you are seeing, and they haven't reported similar issues.
BTW: Shooting the biggest thing you see may have made the problem temporarily go away, but you haven't necessarily found the culprit. Hopefully Hubitat support can help you track down why you are seeing things get clogged up...
If you'd like some of my help regarding what you are seeing, please post the following here in this Ecobee Suite thread, and I'll see what I can do:
- Versions of Ecobee Suite Manager, Thermostat and Sensors
- The number of Ecobee thermostats and sensors you are using
- Your current polling frequency (set in ES Manager)
- The list of ES Helper applications you are running
- The screen shots showing the run times for both ES Manager (application) and ES Thermostat/Sensors (devices)
- The type of Hubitat hub you are running these all on (C4, C5, C7, ...)
- A Snapshot of your Live Logging for ES Manager and your ES Thermostat(s)
FWIW, you don't have to use my Ecobee Suite if you don't like it. You can choose to use the native Hubitat support, or you can pay to use the other user-contributed Ecobee Device setup. I don't make money on Ecobee Suite (it's a hobby), but it meets the needs of quite a lot of people.
And complaining in multiple, unconnected threads makes it extremely difficult for anyone to follow and/or help you.
Good Luck!!!!
2 Likes
Do you happen to have any Helper Apps that are trigged by other automation?
I'm having a similar issue and think I finally have made some headway. I removed ESM and the issue went away. I readded ESM, added my two thermostats back, and ran that for a few days without issue.
I previously had a helper that changes the thermostat program to 'Home' whenever a virtual switch is turned on. I have an automation rule under Simple Automation Rules to turn that switch on at 7:45 am. I re-enabled it yesterday and manually turned the switch on with no issues. When it triggered this morning off the rule, everything worked fine, with no log errors, but the CPU utilization jumped to over 50%.
[app:101](http://10.21.84.16/logs#pastapp101)2021-06-04 08:32:32.661 am [trace](http://10.21.84.16/installedapp/configure/101)Updates sent (824 / 3369ms)
[app:101](http://10.21.84.16/logs#pastapp101)2021-06-04 08:32:31.825 am [info](http://10.21.84.16/installedapp/configure/101)Polling 411921644635,411907883212 completed
[app:101](http://10.21.84.16/logs#pastapp101)2021-06-04 08:32:31.719 am [info](http://10.21.84.16/installedapp/configure/101)24 updates for 2 thermostats (Downstairs, Upstairs)
[app:101](http://10.21.84.16/logs#pastapp101)2021-06-04 08:32:29.460 am [info](http://10.21.84.16/installedapp/configure/101)Polling: Auth_token refreshed
[app:101](http://10.21.84.16/logs#pastapp101)2021-06-04 08:32:29.430 am [info](http://10.21.84.16/installedapp/configure/101)Requesting ( equipmentStatus settings program events audio location alerts runtime extendedRuntime weather ) for thermostats Downstairs, Upstairs (411921644635,411907883212) - [true]
[app:101](http://10.21.84.16/logs#pastapp101)2021-06-04 08:32:29.406 am [info](http://10.21.84.16/installedapp/configure/101)Polling 411921644635,411907883212 (forced)
[app:101](http://10.21.84.16/logs#pastapp101)2021-06-04 08:32:29.329 am [trace](http://10.21.84.16/installedapp/configure/101)Checking for updates...
[app:101](http://10.21.84.16/logs#pastapp101)2021-06-04 08:32:27.351 am [info](http://10.21.84.16/installedapp/configure/101)Requesting ( equipmentStatus settings program events audio location alerts runtime extendedRuntime weather ) for thermostats Downstairs, Upstairs (411921644635,411907883212) - [true]
[app:101](http://10.21.84.16/logs#pastapp101)2021-06-04 08:32:27.324 am [info](http://10.21.84.16/installedapp/configure/101)Polling 411921644635,411907883212 (forced)
[app:101](http://10.21.84.16/logs#pastapp101)2021-06-04 08:32:27.245 am [trace](http://10.21.84.16/installedapp/configure/101)Checking for updates...
[app:101](http://10.21.84.16/logs#pastapp101)2021-06-04 08:02:31.916 am [trace](http://10.21.84.16/installedapp/configure/101)Updates sent (1317 / 4685ms)
[app:101](http://10.21.84.16/logs#pastapp101)2021-06-04 08:02:30.586 am [info](http://10.21.84.16/installedapp/configure/101)Polling 411921644635,411907883212 completed
[app:101](http://10.21.84.16/logs#pastapp101)2021-06-04 08:02:30.477 am [info](http://10.21.84.16/installedapp/configure/101)38 updates for 2 thermostats (Downstairs, Upstairs)
[app:101](http://10.21.84.16/logs#pastapp101)2021-06-04 08:02:28.213 am [info](http://10.21.84.16/installedapp/configure/101)Requesting ( equipmentStatus settings program events audio runtime extendedRuntime weather ) for thermostats Downstairs, Upstairs (411921644635,411907883212) - [false]
[app:101](http://10.21.84.16/logs#pastapp101)2021-06-04 08:02:28.186 am [info](http://10.21.84.16/installedapp/configure/101)Polling 411921644635,411907883212
[app:101](http://10.21.84.16/logs#pastapp101)2021-06-04 08:02:27.266 am [trace](http://10.21.84.16/installedapp/configure/101)Checking for updates...
[app:101](http://10.21.84.16/logs#pastapp101)2021-06-04 07:45:12.645 am [trace](http://10.21.84.16/installedapp/configure/101)prior poll not finished, skipping...
[app:101](http://10.21.84.16/logs#pastapp101)2021-06-04 07:45:12.554 am [trace](http://10.21.84.16/installedapp/configure/101)prior poll not finished, skipping...
[app:101](http://10.21.84.16/logs#pastapp101)2021-06-04 07:45:09.279 am [trace](http://10.21.84.16/installedapp/configure/101)prior poll not finished, skipping...
[app:101](http://10.21.84.16/logs#pastapp101)2021-06-04 07:45:07.313 am [info](http://10.21.84.16/installedapp/configure/101)setProgram(home) for EcobeeTherm: Upstairs (411907883212) returned true
[app:101](http://10.21.84.16/logs#pastapp101)2021-06-04 07:45:06.473 am [info](http://10.21.84.16/installedapp/configure/101)setProgram(Home) for EcobeeTherm: Upstairs (411907883212) - holdType: indefinite
[app:101](http://10.21.84.16/logs#pastapp101)2021-06-04 07:45:06.345 am [trace](http://10.21.84.16/installedapp/configure/101)prior poll not finished, skipping...
[app:101](http://10.21.84.16/logs#pastapp101)2021-06-04 07:45:05.714 am [info](http://10.21.84.16/installedapp/configure/101)resumeProgram(Upstairs, true) for EcobeeTherm: Upstairs (411907883212) returned true
[app:101](http://10.21.84.16/logs#pastapp101)2021-06-04 07:45:03.936 am [info](http://10.21.84.16/installedapp/configure/101)setProgram(home) for EcobeeTherm: Downstairs (411921644635) returned true
[app:101](http://10.21.84.16/logs#pastapp101)2021-06-04 07:45:02.976 am [info](http://10.21.84.16/installedapp/configure/101)setProgram(Home) for EcobeeTherm: Downstairs (411921644635) - holdType: indefinite
[app:101](http://10.21.84.16/logs#pastapp101)2021-06-04 07:45:02.860 am [info](http://10.21.84.16/installedapp/configure/101)Requesting ( equipmentStatus settings program events audio runtime extendedRuntime weather ) for thermostats Downstairs, Upstairs (411921644635,411907883212) - [true]
[app:101](http://10.21.84.16/logs#pastapp101)2021-06-04 07:45:02.835 am [info](http://10.21.84.16/installedapp/configure/101)Polling 411921644635,411907883212
[app:101](http://10.21.84.16/logs#pastapp101)2021-06-04 07:45:01.896 am [trace](http://10.21.84.16/installedapp/configure/101)Checking for updates...
[app:101](http://10.21.84.16/logs#pastapp101)2021-06-04 07:45:01.281 am [info](http://10.21.84.16/installedapp/configure/101)resumeProgram(Downstairs, true) for EcobeeTherm: Downstairs (411921644635) returned trueDo you have anything turn the switch off after it was turned on? I use a similar concept. I have a few switches that turn the house into a mode(sleeping) and another that takes it out(I am up). These switches turn themselves off after 5 seconds. But many things trigger from them. By chance do you have something else possibly flipping the virtual switch off. Did you have the helper app set to turn it off?
This drastic increase in cpu seems like a flashing red light for a race condition somewhere.
Did you happen to catch the runtime usage logs at the time of the spike?
Also, please try running with a cycle time of 1 minutes - at longer cycles, there can be a TON of changes that have to be parsed and updated, likely causing the spike. With shorter cycles, less data has to be collected and analyzed each time.
That said, with the longer cycles (and backed up by the logs) the continued high CPU utilization is likely due to something other than ES Manager, because it SLEEPS between polling cycles. As the log shows, lots of activity around the setProgram(“home”) request (expected, because set points and program names change), but then ES Manager does nothing until the next cycle.
Can you please post a screen shot of the settings for the Simple Automation you are using to change the program?
Thanks!
Here's the simple automation rule. It's normally set to 7:45 am. I changed it this morning to see if I could reproduce the spike, to no avail. I'm not sure what you mean by the "cycle" setting. You mean the polling interval? I did not catch the app stats this go round, but I've checked them during the elevated CPU usage before and nothing stood out. I'm with you on the problem not inherently being ESM. I'd wager it's something else that's getting triggered by the way people use ESM.
@mavrrick58 here's the helper app which is set to turn off the switch after 5 seconds. The switch is not used for anything besides changing the thermostat program.
I was able to reproduce it. What I didn't do this morning before testing the helper was set the thermostat program to Sleep (which is what it would normally be in when the automations fire).
ESM Logs
app:1012021-06-04 01:07:56.221 pm traceUpdates sent (1114 / 4644ms)
app:1012021-06-04 01:07:55.094 pm infoPolling 411921644635,411907883212 completed
app:1012021-06-04 01:07:54.986 pm info35 updates for 2 thermostats (Downstairs, Upstairs)
app:1012021-06-04 01:07:52.726 pm traceNo updates
app:1012021-06-04 01:07:52.671 pm infoChecking: Auth_token refreshed
app:1012021-06-04 01:07:52.602 pm infoRequesting ( equipmentStatus settings program events audio runtime extendedRuntime weather ) for thermostats Downstairs, Upstairs (411921644635,411907883212) - [true]
app:1012021-06-04 01:07:52.571 pm infoPolling 411921644635,411907883212
app:1012021-06-04 01:07:51.610 pm traceChecking for updates...
app:1012021-06-04 01:07:49.399 pm traceChecking for updates...
app:1012021-06-04 12:55:12.775 pm traceprior poll not finished, skipping...
app:1012021-06-04 12:55:12.714 pm traceprior poll not finished, skipping...
app:1012021-06-04 12:55:09.397 pm traceprior poll not finished, skipping...
app:1012021-06-04 12:55:07.382 pm infosetProgram(home) for EcobeeTherm: Upstairs (411907883212) returned true
app:1012021-06-04 12:55:06.560 pm infosetProgram(Home) for EcobeeTherm: Upstairs (411907883212) - holdType: indefinite
app:1012021-06-04 12:55:06.357 pm traceprior poll not finished, skipping...
app:1012021-06-04 12:55:05.619 pm inforesumeProgram(Upstairs, true) for EcobeeTherm: Upstairs (411907883212) returned true
app:1012021-06-04 12:55:04.046 pm infosetProgram(home) for EcobeeTherm: Downstairs (411921644635) returned true
app:1012021-06-04 12:55:03.095 pm infosetProgram(Home) for EcobeeTherm: Downstairs (411921644635) - holdType: indefinite
app:1012021-06-04 12:55:02.964 pm infoRequesting ( equipmentStatus settings program events audio runtime extendedRuntime weather ) for thermostats Downstairs, Upstairs (411921644635,411907883212) - [false]
app:1012021-06-04 12:55:02.940 pm infoPolling 411921644635,411907883212
app:1012021-06-04 12:55:02.002 pm traceChecking for updates...
app:1012021-06-04 12:55:01.206 pm inforesumeProgram(Downstairs, true) for EcobeeTherm: Downstairs (411921644635) returned true
app:1012021-06-04 12:49:02.987 pm traceUpdates sent (59 / 2511ms)
app:1012021-06-04 12:49:02.914 pm infoPolling 411907883212 completed
app:1012021-06-04 12:49:02.804 pm info7 updates for 1 thermostat (Upstairs)
app:1012021-06-04 12:49:01.774 pm traceprior poll not finished, skipping...
app:1012021-06-04 12:49:01.317 pm infoRequesting ( equipmentStatus settings program events audio ) for thermostat Upstairs (411907883212) - [false]
app:1012021-06-04 12:49:01.301 pm infoPolling 411907883212
app:1012021-06-04 12:49:00.509 pm traceChecking for updates...
app:1012021-06-04 12:48:56.389 pm infosetProgram(sleep) for EcobeeTherm: Upstairs (411907883212) returned true
app:1012021-06-04 12:48:56.348 pm traceUpdates sent (370 / 3273ms)
app:1012021-06-04 12:48:55.967 pm infoPolling 411921644635 completed
app:1012021-06-04 12:48:55.865 pm info8 updates for 1 thermostat (Downstairs)
app:1012021-06-04 12:48:55.371 pm infosetProgram(Sleep) for EcobeeTherm: Upstairs (411907883212) - holdType: indefinite
app:1012021-06-04 12:48:54.918 pm inforesumeProgram(Upstairs, true) for EcobeeTherm: Upstairs (411907883212) returned true
app:1012021-06-04 12:48:53.984 pm infoRequesting ( equipmentStatus settings program events audio runtime extendedRuntime ) for thermostat Downstairs (411921644635) - [false]
app:1012021-06-04 12:48:53.967 pm infoPolling 411921644635
app:1012021-06-04 12:48:53.111 pm traceChecking for updates...
app:1012021-06-04 12:48:33.432 pm traceUpdates sent (670 / 4857ms)
app:1012021-06-04 12:48:32.749 pm infoPolling 411921644635,411907883212 completed
app:1012021-06-04 12:48:32.647 pm info25 updates for 2 thermostats (Downstairs, Upstairs)
app:1012021-06-04 12:48:30.106 pm traceprior poll not finished, skipping...
app:1012021-06-04 12:48:30.092 pm infoRequesting ( equipmentStatus settings program events audio runtime extendedRuntime ) for thermostats Downstairs, Upstairs (411921644635,411907883212) - [false]
app:1012021-06-04 12:48:30.060 pm infoPolling 411921644635,411907883212
app:1012021-06-04 12:48:28.621 pm traceChecking for updates...
app:1012021-06-04 12:48:27.911 pm traceUpdates sent (2594 / 6844ms)
app:1012021-06-04 12:48:25.298 pm infoPolling 411921644635,411907883212 completed
app:1012021-06-04 12:48:25.116 pm info174 updates for 2 thermostats (Downstairs, Upstairs)
app:1012021-06-04 12:48:24.610 pm infosetProgram(sleep) for EcobeeTherm: Downstairs (411921644635) returned true
app:1012021-06-04 12:48:23.496 pm infosetProgram(Sleep) for EcobeeTherm: Downstairs (411921644635) - holdType: indefinite
app:1012021-06-04 12:48:22.985 pm inforesumeProgram(Downstairs, true) for EcobeeTherm: Downstairs (411921644635) returned true
app:1012021-06-04 12:48:21.913 pm infoRequesting ( equipmentStatus settings program events audio location alerts runtime extendedRuntime weather ) for thermostats Downstairs, Upstairs (411921644635,411907883212) - [false]
app:1012021-06-04 12:48:21.881 pm infoPolling 411921644635 (forced)
app:1012021-06-04 12:48:21.160 pm infoClearing change logs for thermostat 411921644635
app:1012021-06-04 12:48:21.106 pm traceChecking for updates...
Downstairs Thermostat
dev:1292021-06-04 01:07:56.199 pm infoUpdated 24 objects (493ms)
dev:1292021-06-04 12:55:09.351 pm inforefresh() - calling pollChildren , deviceId = 411921644635
dev:1292021-06-04 12:55:04.554 pm infoUpdated 2 objects (92ms)
dev:1292021-06-04 12:55:04.459 pm infoUpdated 5 objects (96ms)
dev:1292021-06-04 12:55:04.359 pm infoThermostat Program is Hold: Home
dev:1292021-06-04 12:55:04.270 pm infoUpdated 6 objects (133ms)
dev:1292021-06-04 12:55:04.132 pm infoUpdated 1 object (83ms)
dev:1292021-06-04 12:55:04.129 pm infosetProgram(home) for EcobeeTherm: Downstairs (411921644635) returned true
dev:1292021-06-04 12:55:03.105 pm infoUpdated 1 object (7ms)
dev:1292021-06-04 12:55:03.100 pm infosetProgram(Home) for EcobeeTherm: Downstairs (411921644635) - holdType: indefinite
dev:1292021-06-04 12:55:03.061 pm infoThermostat Program is Home (resumed)
dev:1292021-06-04 12:55:03.059 pm inforesumeProgram() - No current hold
dev:1292021-06-04 12:55:01.804 pm inforefresh() - calling pollChildren , deviceId = 411921644635
dev:1292021-06-04 12:55:01.746 pm inforesumeProgram(true) - succeeded
dev:1292021-06-04 12:55:01.743 pm infoUpdated 7 objects (105ms)
dev:1292021-06-04 12:55:01.445 pm infoUpdated 9 objects (127ms)
dev:1292021-06-04 12:55:01.300 pm infoUpdated 1 object (91ms)
dev:1292021-06-04 12:55:01.295 pm inforesumeProgram(Downstairs, true) for EcobeeTherm: Downstairs (411921644635) returned true
dev:1292021-06-04 12:48:56.333 pm infoUpdated 9 objects (331ms)
dev:1292021-06-04 12:48:33.412 pm infoUpdated 25 objects (459ms)
dev:1292021-06-04 12:48:28.455 pm inforefresh() - calling pollChildren , deviceId = 411921644635
dev:1292021-06-04 12:48:27.893 pm infoUpdated 199 objects (2309ms)
dev:1292021-06-04 12:48:25.201 pm infoUpdated 2 objects (10ms)
dev:1292021-06-04 12:48:25.189 pm infoUpdated 5 objects (128ms)
dev:1292021-06-04 12:48:25.057 pm infoThermostat Program is Hold: Sleep
dev:1292021-06-04 12:48:24.985 pm infoUpdated 10 objects (274ms)
dev:1292021-06-04 12:48:24.704 pm infoUpdated 1 object (92ms)
dev:1292021-06-04 12:48:24.701 pm infosetProgram(sleep) for EcobeeTherm: Downstairs (411921644635) returned true
dev:1292021-06-04 12:48:23.593 pm infoUpdated 1 object (94ms)
dev:1292021-06-04 12:48:23.588 pm infosetProgram(Sleep) for EcobeeTherm: Downstairs (411921644635) - holdType: indefinite
dev:1292021-06-04 12:48:23.411 pm inforesumeProgram(true) - succeeded
dev:1292021-06-04 12:48:23.408 pm infoUpdated 7 objects (21ms)
dev:1292021-06-04 12:48:23.276 pm infoUpdated 5 objects (151ms)
dev:1292021-06-04 12:48:23.104 pm infoUpdated 1 object (104ms)
dev:1292021-06-04 12:48:23.098 pm inforesumeProgram(Downstairs, true) for EcobeeTherm: Downstairs (411921644635) returned true
dev:1292021-06-04 12:48:21.937 pm infoUsing holdType indefinite
dev:1292021-06-04 12:48:20.897 pm inforefresh() - calling pollChildren , deviceId = 411921644635
Upstairs
dev:1302021-06-04 01:07:55.673 pm infoUpdated 20 objects (492ms)
dev:1302021-06-04 12:55:12.720 pm inforefresh() - calling pollChildren , deviceId = 411907883212
dev:1302021-06-04 12:55:07.904 pm infoUpdated 2 objects (85ms)
dev:1302021-06-04 12:55:07.817 pm infoUpdated 5 objects (86ms)
dev:1302021-06-04 12:55:07.728 pm infoThermostat Program is Hold: Home
dev:1302021-06-04 12:55:07.657 pm infoUpdated 6 objects (189ms)
dev:1302021-06-04 12:55:07.463 pm infoUpdated 1 object (79ms)
dev:1302021-06-04 12:55:07.460 pm infosetProgram(home) for EcobeeTherm: Upstairs (411907883212) returned true
dev:1302021-06-04 12:55:06.569 pm infoUpdated 1 object (7ms)
dev:1302021-06-04 12:55:06.565 pm infosetProgram(Home) for EcobeeTherm: Upstairs (411907883212) - holdType: indefinite
dev:1302021-06-04 12:55:06.528 pm infoThermostat Program is Home (resumed)
dev:1302021-06-04 12:55:06.527 pm inforesumeProgram() - No current hold
dev:1302021-06-04 12:55:06.271 pm inforefresh() - calling pollChildren , deviceId = 411907883212
dev:1302021-06-04 12:55:06.174 pm inforesumeProgram(true) - succeeded
dev:1302021-06-04 12:55:06.171 pm infoUpdated 7 objects (16ms)
dev:1302021-06-04 12:55:05.956 pm infoUpdated 9 objects (128ms)
dev:1302021-06-04 12:55:05.813 pm infoUpdated 1 object (192ms)
dev:1302021-06-04 12:55:05.809 pm inforesumeProgram(Upstairs, true) for EcobeeTherm: Upstairs (411907883212) returned true
dev:1302021-06-04 12:49:02.965 pm infoUpdated 8 objects (20ms)
dev:1302021-06-04 12:49:00.375 pm inforefresh() - calling pollChildren , deviceId = 411907883212
dev:1302021-06-04 12:48:56.830 pm infoUpdated 2 objects (9ms)
dev:1302021-06-04 12:48:56.819 pm infoUpdated 5 objects (88ms)
dev:1302021-06-04 12:48:56.728 pm infoThermostat Program is Hold: Sleep
dev:1302021-06-04 12:48:56.614 pm infoUpdated 10 objects (134ms)
dev:1302021-06-04 12:48:56.474 pm infoUpdated 1 object (82ms)
dev:1302021-06-04 12:48:56.470 pm infosetProgram(sleep) for EcobeeTherm: Upstairs (411907883212) returned true
dev:1302021-06-04 12:48:55.555 pm infoUpdated 1 object (181ms)
dev:1302021-06-04 12:48:55.454 pm infosetProgram(Sleep) for EcobeeTherm: Upstairs (411907883212) - holdType: indefinite
dev:1302021-06-04 12:48:55.298 pm inforesumeProgram(true) - succeeded
dev:1302021-06-04 12:48:55.295 pm infoUpdated 7 objects (19ms)
dev:1302021-06-04 12:48:55.156 pm infoUpdated 5 objects (137ms)
dev:1302021-06-04 12:48:55.004 pm infoUpdated 1 object (83ms)
dev:1302021-06-04 12:48:54.999 pm inforesumeProgram(Upstairs, true) for EcobeeTherm: Upstairs (411907883212) returned true
dev:1302021-06-04 12:48:53.997 pm infoUsing holdType indefinite
dev:1302021-06-04 12:48:52.936 pm inforefresh() - calling pollChildren , deviceId = 411907883212
dev:1302021-06-04 12:48:32.929 pm infoUpdated 5 objects (143ms)
dev:1302021-06-04 12:48:25.540 pm infoUpdated 13 objects (184ms)
Handler
app:1042021-06-04 12:55:12.958 pm infoAnd I turned off Ugh
app:1042021-06-04 12:55:07.911 pm traceNotification Message (notify=false): I set EcobeeTherm: Upstairs to Hold: Home
app:1042021-06-04 12:55:06.255 pm debugsendHoldType: indefinite, sendHoldHours: null
app:1042021-06-04 12:55:06.254 pm infoUsing holdType indefinite
app:1042021-06-04 12:55:06.225 pm infoUsing holdType indefinite
app:1042021-06-04 12:55:04.574 pm traceSetting Thermostat Program to programParam: Home and holdType: Ecobee Manager Setting
app:1042021-06-04 12:55:04.571 pm debugthermostatHold: hold
app:1042021-06-04 12:55:04.569 pm traceIn each loop: Working on stat: EcobeeTherm: Upstairs
app:1042021-06-04 12:55:04.565 pm traceNotification Message (notify=false): I set EcobeeTherm: Downstairs to Hold: Home
app:1042021-06-04 12:55:01.785 pm debugsendHoldType: indefinite, sendHoldHours: null
app:1042021-06-04 12:55:01.783 pm infoUsing holdType indefinite
app:1042021-06-04 12:55:01.780 pm infoUsing holdType indefinite
app:1042021-06-04 12:55:00.166 pm traceSetting Thermostat Program to programParam: Home and holdType: Ecobee Manager Setting
app:1042021-06-04 12:55:00.162 pm debugthermostatHold: hold
app:1042021-06-04 12:55:00.159 pm traceIn each loop: Working on stat: EcobeeTherm: Downstairs
app:1042021-06-04 12:55:00.156 pm tracechangeProgramHandler() entered with evt: switch: on
app:1042021-06-04 12:55:00.147 pm tracechangeSwitchHandler() entered with evt: Ugh switch turned on
app:1042021-06-04 12:53:26.617 pm debug...initialization complete
app:1042021-06-04 12:53:26.611 pm debugatomicState.expectedEvent set to null
app:1042021-06-04 12:53:26.561 pm infoEcobee Suite Mode/Switches/Program Helper, version 1.8.23 on Hubitat - Initializing...
app:1042021-06-04 12:53:26.543 pm traceUpdated with settings [minimize:false, modeOrRoutine:Switch(es), startOn:on, tempDisable:false, notify:false, cancelVacation:false, startOff:true, myThermostats:[EcobeeTherm: Downstairs, EcobeeTherm: Upstairs], whichProgram:Home, infoOff:false, debugOff:false, startSwitches:[Ugh], holdType:Ecobee Manager Setting, startOffDelay:5]
app:1042021-06-04 12:53:22.332 pm debugFound the following programs: [Away, Home, Sleep, Resume Program]
app:1042021-06-04 12:53:22.331 pm infogetThermostatPrograms: returning [Away, Home, Sleep]
app:1042021-06-04 12:49:16.627 pm debugFound the following programs: [Away, Home, Sleep, Resume Program]
app:1042021-06-04 12:49:16.625 pm infogetThermostatPrograms: returning [Away, Home, Sleep]
Switch
dev:1012021-06-04 12:55:12.952 pm infoUgh was turned off
dev:1012021-06-04 12:55:00.095 pm infoUgh was turned onSo go into the virtual switch device and adjust it's setting for "Enable Auto off" to 5 seconds. Save that settings and then go into the helper app and turn off the switch to turn off the switch after actions.
Try that and see if that helps you. That is at least how mine works and doesn't seem to suffer the same issue.
There are a few things that appear not quite right above.
Your setting for the Switch says 5 seconds and it 12 seconds to turn it off. is one thing that stands out to me.
@storageanarchy will have to confirm, but I think the Helper App will wait for confirmation of the program change before starting the timer.
I'm recreating the Simple Automation rule in RM. Simple Automation, as I just found out, doesn't have an "off after XX time" option if you turn the switch on at a specific time.
OH! One of those, I read what you wrote but processed it completely wrong. I didn't even realize the devices themselves have an auto off config. I'll try that after testing having RM turn it off.
If you don't have any luck with having the virtual switch turn itself off (in the virtual switch device itself), and you revert to having the Helper turn it off after everything is done, then first set the loglevel to 4 (but not 5). We might get some helpful hints from the added logging.
TYVM for taking the time to test out the various theories!
Yes, I meant polling interval. Please try it set to 1 minute (it looks like you are set for 10 or 15 minutes?
Definitely not a problem on the testing. Based on the shear amount of code in this app and drivers, it's obvious you've put a lot of time and effort into this. The least I can do is help with isolating this CPU issue folks are having. I really appreciate both you and @mavrrick58 trying to help me out.
Back to the testing. I don't believe the "off" side of things is the issue. I removed it altogether and still have the CPU spike. For clarity, and a log of sorts, I'm going to recap.
I have two Ecobee3 thermostats with remote sensors. The ESM app version is: String getVersionNum() { return "1.8.53" }. I installed ESM using Package Manager. Global polling is set to 30 minutes. Only the thermostats were added to Hubitat. I have one Helper App configured that is watching a virtual switch called "Ugh" and changes the comfort mode to "Home" on both thermostats when the switch turns on.
The reproduction scenario:
- Place the thermostats into comfort mode "Sleep" (for testing, I'm doing this via the devices in HE).
- Trigger automation to turn on the "Ugh" switch.
- CPU spike occurs.
Testing (reboot after each attempt):
- The original automation was set using Simple Automation to turn the switch on. The Helper App was set to turn the switch off. (CPU spike ~25%)
- Moved the automation to Rule Machine and added an action to wait 2 seconds then turn the switch back off. Removed the "off" cycle from the Helper App. (CPU spike ~25%)
- Removed the 'wait' and 'off' actions from RM. Set the "Ugh" switch to auto-off after 2 seconds via the device preferences. (CPU spike ~25%)
- Removed turning the switch off altogether. Only left the rule to turn on the switch. (CPU spike ~25%).
5. Changed polling interval to 1 minute. (CPU went to 9% and dropped back down to 6.5%)
So, it would appear the polling interval might have been the problem. I'm going to re-enable the auto-off in the device properties and keep and eye on it. If I see anything come back up. I'll post back. If I don't see any issues after a few days, I will also post back.
3 Likes
Sad panda. On top of this, I now can't get any log data to load from before 7 a.m. this morning. I did notice the CPU spikes when I woke up and ran through the logs. The only events happening at the time were ESM polling, but nothing that would indicate an issue.
I’m not sure I understand what you are charting here. Is this the percent of total wall-clock time, or the percentage of total execution time?
The green line should be CPU utilization at the point the dashboard update was captured (5 minute update intervals). The blue line is CPU load. Anything over a 2 for load triggers the system alert and is about when I start noticing automation impacts.
Interesting.
Could you perhaps try opening ESM and the clicking Done next time you see the sustained spike? I’m wondering if this resets the load back to more reasonable levels.
