Over the past few weeks I’ve been tracing down issues with habpanel taking forever to load and I noticed that under the development console of FireFox that the bottleneck seems to be that /rest/items takes 6000+ ms to load and I’m not sure why. I’m running my OpenHab 2.3 in a Ubuntu 18.04 LTS server HyperV (2016) VM that is configured with 3GB of RAM and 2 CPUs, CPU load in top hovers around 10% with occasional spikes to 50% but never much more than that and RAM usage is right around 32% as well. The VM itself is running on SSD with a disk response time of 1ms, and there’s no paging or anything going on. The physical server seems to be running ok, none of the other VMs are exhibiting issues and rules fire timely as they should.
If I go to /rest/items manually I can confirm that it does take multiple seconds to load and comes back with 423 items, which seems like a lot so maybe that’s the issue? I don’t recall having any issues running the same config on 2.2 though but my memory may be faulty there.
Is this normal or how do I troubleshoot from here? The rest interface doesn’t appear to generate any kind of log that I can find
I do not think this is normal. It should not take that long to return.
Do you see similar delays with BasicUI or ClassicUI? Do you see similar delays if you poll that REST call directly (you can make the call from the REST Docs, installable from the Misc tab in PaperUI). This is to narrow down the problem between HABPanel and the server side.
I have not tried classic UI or basic UI, but I have had issues with habmin and paper UI, and testing through the REST Docs directly is slow as well. I tested both from my workstation and from the windows hyper-v host and both show “items?recursive=false” at approx. 6600ms in the network tab for developer tools in FireFox.
Strangely, after playing with the type filter in the REST Docs it seems the true bottleneck is with my String items somehow, even though those are about 100 of 423. All other types (switch, dimmer, group, number) all come back super fast. I’m going to try and go through process of elimination and see if I can figure out which one(s) are the problem
After doing some elimination, I’ve narrowed it down to the following items linked to my Alexa control binding for my four echos so I’m going to raise the question in that thread to see if we can figure out what’s going on
AmazonPlayListId (adds about 300ms each)
PlayAlarmSound (adds about 400ms each)
PlayMusicProvider (adds about 800ms each)
Not much data at all. AmazonPlaylistId and PlayAlarmSound are both empty (PlayAlarmSound also returns 15 options but none with long values or labels) and PlayMusicProvider only has a short string (“TUNEIN” for my test echo) with 5 options but again none with values or labels that are very long (the longest is “I_HEART_RADIO” for example)
None have a tag (if you mean [“tag”] in their definitions)
Here are the actual item definitions for reference, the item definitions for the other three echos are identical and all have the same delays when called individually
String Echo_Kitchen_AmazonMusicPlayListId "Echo Kitchen Amazon Music Playlist Id (Write Only)" (Alexa_Kitchen) {channel="amazonechocontrol:echo:echoAP:SerialNumber:amazonMusicPlayListId"}
String Echo_Kitchen_PlayAlarmSound "Echo Kitchen Play Alarm Sound" (Alexa_Kitchen) {channel="amazonechocontrol:echo:echoAP:SerialNumber:playAlarmSound"}
String Echo_Kitchen_PlayMusicProvider "Echo Kitchen Play Music Provider" (Alexa_Kitchen) {channel="amazonechocontrol:echo:echoAP:SerialNumber:musicProviderId"}
OK, I’m out of ideas. I’ve no idea why these Items would be any different from any others unless somehow they need to ask the binding for the value first. But I’m all but certain that isn’t how it works. It should just grab the current state of the Item as it exists in the Item registry at that time.
I think that’s exactly what it is. I turned on debug logging for that binding and every time I made a REST call to one of those three items three log entries for calls to amazon.com popped into the log. Thankfully I wasn’t using those channels yet so for the time being i’ll leave them commented out.
Thanks for this, after some debugging of my slow REST interface, this turned out to be the cause here as well. Running on 2.3.0 release, 6-700 items. ~100 msec for rest/items over HTTP, but when all alexa items activated I got 2-6 seconds, measured using 'time curl '.
Just as you, not all items in my alexa.items were problematic, so I have been able to keep those I use (mainly TTS).
Did you post something in another thread more specific to the alexa binding on this issue?
I posted about it a few times actually in the main thread for the Alexa control plugin but my posts kept getting buried in other conversations going on in that thread. Eventually michi responded that he’s not aware of any solution to the problem unfortunately, in this comment
@Kai, can the DynamicStateProvider be the reason for the slowdown of the REST Interface? Is there somerhing what I can fix in the binding? Maybe a cache?
So is this specifically about the EchoControl binding? I.e. if it is started, the REST API is slow and when the bundle is stopped, it is fast?
If so, yes: The DynamicStateProvider could be the culprit, if it does expensive operations. Any improvement of its implementation (such as doing caching) should make it faster.
Well, external HTTP requests are the worst thing you can do in a synchronous call - that definitely needs to be cached! Maybethis is helpful for such purposes.
Yeah, still having that problem and now running release 2.4 with the official 2.4 binding. I’ve just accepted that it won’t work and took those items out altogether at this point, unfortunately.
