Changes to filtering criteria for add-ons aren't effective until later

[Nadahar]

If you change filtering criteria for add-ons (show incompatible, unpublished etc.), the changes aren't reflected until after the 7.5 minute cache in the REST API expires since #4107.

Expected Behavior

Changes to settings should be effective immediately

Current Behavior

It takes a long time until the settings change is effective, and there's no way for the user to know this or know how long to wait. In effect, the settings seem not to work.

Possible Solution

• Revert the add-on part of #4107 and find other ways to mitigate the original problem (presumably a lot of requests for the same information.
• Make the "expiry logic" much smarter than it is.

Steps to Reproduce (for Bugs)

1. Change one of the settings that affect add-on filtering, for example "Settings -> Add-ons -> Include potentially incompatible add-ons".
2. Browse the add-on store and observe that the setting change doesn't apply.

[florian-h05]

You can listen to config changes for the add-on settings (you need the config PID, but this can found in the URL when opening the add-on settings) similarly to https://github.com/openhab/openhab-core/pull/3838/files. Basically you only need to implement org.osgi.service.cm.ConfigurationListener and properly filter.

[Nadahar]

You can listen to config changes for the add-on settings (you need the config PID, but this can found in the URL when opening the add-on settings) similarly to https://github.com/openhab/openhab-core/pull/3838/files. Basically you only need to implement org.osgi.service.cm.ConfigurationListener and properly filter.

I tried to find a way to do that, but didn't succeed. It seems like the approach in https://github.com/openhab/openhab-core/pull/3838 is cleaner/easier, but it's still somewhat problematic. First of all, the settings for marketplace behavior is spread over 3 different config PIDs (add-ons, community marketplace and json marketplace). Second, it "overrides" the cache behavior that is already built in to the add-on handling.

I'm wondering how anybody publishing an add-on on the marketplace should be able to get through several levels of caching and actually manage to refresh to check the changes he/she has made. It's not always easy to get it right, so I'd expect that there potentially be several steps of "modify -> check" until the add-on behaves as planned. That will take a very long time, and be very frustrating if you have to wait up to 22.5 minutes for things to refresh, and it will make no sense to whoever is doing it why it doesn't update. Is there a way to make MainUI "bypass" this cache on demand, by sending a modified request - so that it would be possible to make some functionality in the UI with "refresh now" or similar? It still wouldn't affect the core-provided 15 minutes cache though, unless there's a way to signal this to the REST API.

[Nadahar]

I've been trying to figure out a way to handle this correctly, and it seems very complicated to me. I'm starting to think that the easiest solution is to just revert #4107. Can I ask what #4107 was supposed to do? Was it to reduce the data transmitted, or to ease the load on OH? Was this problematic as it was? Or was this to allow MainUI to be "more sloppy" with the requests?

I've been reading HTTP spec info to try to figure out how this is supposed to work, and as I understand it, Last-Modified isn't suitable for this use at all. First of all, it isn't suitable for resources that can change multiple times within the same second, since the resolution is one second. Second, it's not supposed to be used as a "cache control" with a timeout like here, it's supposed to be used to reflect when the resource was actually last modified. Also, you can't "share" a "last modified" value between different resources, like what is done here (the same value is used for add-ons and add-on services). To actually figure out when something has changed is complicated, as change happens on several levels.

I tried looking into using EntityTag instead, like a kind of "revision number" that changes whenever the underlying resource is changed. It doesn't have the problem with "changed within the same second" that Last-Modified has. But still, this is complicated to do. My idea was to let each AddonService increase a counter each time their list of Addons changed. AddonResource could then sum these "revisions" for the services in question for a given request, plus add a separate "configuration changed" counter that AddonResource would have to keep track of, to come up with a EntityTag that would actually reflect if something has changed.

But, this is quite a lot of work to implement in all the different AddonServices, and even if done, there are still a couple of problems:

• Addon.setInstalled() can be called, which directly set's the add-ons' "installed state". To address this, a "changelistener" would have to be implemented so that an add-on could alert it's AddonService(s) when it has been mutated (although I don't think this is the intended design, the reality is that some add-ons are sometimes provided by more than one AddonService). This would introduce some handling, potential concurrency issues etc.
• The biggest problem is that the way these classes are designed, querying them is what actually triggers a check for changes. So, changes wouldn't be detected by the AddonService if the EntityTag was a match, since it would never result in a call to a method that ends up calling refreshSource(). To overcome that, you'd have to make some other mechanism for actually detecting changes. File watching could be used to trigger updates for file based add-ons, but there's nothing that could trigger an update of e.g. remote add-ons, so it would have to run on a timer. I'm pretty sure that the result of doing this would result in many more "refreshes" (and thus system load) than just letting this be refreshed when actually needed (like the design is today).

This actually also made me realize why another bug I've experienced happens: The current Last-Modified "logic" is only applied when you request multiple add-ons or add-on services. If you request a single add-on, the request always goes through to the underlying source. This leads to the bizarre situation that when you look at a specific add-on in MainUI, the information is updated, but when you go back to the "overview", the information is still outdated - even if you refresh the page.

All in all, I think making this work correctly requires a lot of changes and redesign to how these classes interact, and it seems to me like it's most likely not worth it, any solution I can think of will have downsides that can easily be worse than the "cost" of frequently enumerating the add-ons.

[florian-h05]

I'm starting to think that the easiest solution is to just revert https://github.com/openhab/openhab-core/pull/4107.

No.

Can I ask what https://github.com/openhab/openhab-core/pull/4107 was supposed to do?

Browsing the add-on store was previously painfully slow, everything when switching a tab the add-ons were reloaded due to the way the tabbed pages are handled by Framework7. Reloading them was very slow, I don’t know why exactly. Changing this behaviour of Framework7 would mean we would need to add client-side „caching“, that would probably be problematic as well as the client would know way less about changes to add-ons compared to the server.

I’d rather propose to add a force refresh to Main UI … or add a new AddonUpdatedEvent so signal changes to add-ons (only relevant for marketplace and community).

[Nadahar]

Browsing the add-on store was previously painfully slow, everything when switching a tab the add-ons were reloaded due to the way the tabbed pages are handled by Framework7. Reloading them was very slow, I don’t know why exactly.

I think I'll have to disable this locally and see if I can "recreate the problem". As far as I can tell, most of this info is already cached in the AddonServices, and I sort of doubt that generating the response is that slow. Which opens the possibility that what's causing the slowness is the transfer and processing (in MainUI) of the data itself. If that is the case, I think we can solve it in a way that doesn't cause any of the current problems:

By implementing hashCode on Addons (and any other object that "need caching"), Java does most of the work for us. Collections generate their hashCodes by combining the hashCodes of all the elements, which means that if any of the elements' hashCode change or the elements themselves change, the hashCode of the collection will change. If we implement hashCode for the elements (e.g. Addon) so that every field is taken into account, it all becomes an easy way to check for "identical result" using EntityTag. So, we could let core do the usual "work" on each request, and then reply with 304 if the hashCodes match (which is handled for us if we simply make an EntityTag from the hashCode).

This would mean that the time before the response is ready would increase, but once the response is ready, it will only actually be sent if the response is different. If the problem is the transfer/processing of the response in MainUI, it should be sufficient. But, since we don't know if that's the case, it must be tested, which is why I have to make sure I can replicate the problem first.

There is a chance of hashCode collisions, that is that two different results can generate the same hashCode, but chances are slim, and I don't think that will happen much in reality. We should probably make the EntityTag "weak" to indicate to the browser that it's not guaranteed to be unique. LastModified is always considered "weak", so it seems like the browsers mostly "trust it"/use it regardless.

[Nadahar]

I've now modified my local installation so that lastModifiedIsValid() always returns false - effectively disabling this caching, and bumped the logging to ERROR to easily see the requests, plus appending path- and query parameters to the logging message. Unfortunately, headers aren't readily available, I didn't investigate how to log them. But, except for the two requests to /services, it doesn't seem like there are any redundant requests.

This is the result of one single refresh of the browser while browsing the add-on store:

14:10:47.538 [ERROR] [t.core.internal.addons.AddonResource] - Received HTTP GET request at 'addons/services' {} {}
14:10:47.831 [ERROR] [t.core.internal.addons.AddonResource] - Received HTTP GET request at 'addons/services' {} {}
14:10:47.913 [ERROR] [t.core.internal.addons.AddonResource] - Received HTTP GET request at 'addons' {} {serviceId=[jar]}
14:10:47.913 [ERROR] [t.core.internal.addons.AddonResource] - Received HTTP GET request at 'addons' {} {serviceId=[eclipse]}
14:10:47.913 [ERROR] [t.core.internal.addons.AddonResource] - Received HTTP GET request at 'addons' {} {serviceId=[marketplace]}
14:10:47.913 [ERROR] [t.core.internal.addons.AddonResource] - Received HTTP GET request at 'addons' {} {serviceId=[json]}

Also, browsing the add-ons in MainUI is fast, switching to a different tab and back results in no new request and is fast. The only time I see any "slowness" is when the "remote cache" is expired, so that the remote add-ons are fetched from the forum. But, that only happens every 15 minutes, and it takes the time it takes - nothing much can be done about that for now. My plan for versioned add-ons include an external caching of the forum though, to reduce the load on the forum from all the OH installations querying this information, so if that becomes reality, the request might be considerable quicker.

But, since I can't replicate the "slowness", I can't verify if my suggested "solution" (using hashCodes) will be a remedy. Any further hints about how to experience the problem? I have "show incompatible" and "show unpublished" enabeld, and I also have a JSON marketplace defined, so I should already see the maximum number of add-ons. Can it be that this has only been a problem with very resource-starved OH installations, and that it is in fact the processing in core that takes the time?

[Nadahar]

Since I can't reproduce any slowness with "lastModified" disabled, I decided to check out latest main instead of my working code, in case I had changed something that made it faster. But, I get the same results with the latest main:

20:19:25.993 [ERROR] [t.core.internal.addons.AddonResource] - Received HTTP GET request at 'addons/services' {} {}
20:19:26.029 [ERROR] [t.core.internal.addons.AddonResource] - Replied to HTTP GET request 'addons/services' {} {}
20:19:26.061 [ERROR] [t.core.internal.addons.AddonResource] - Received HTTP GET request at 'addons' {} {serviceId=[jar]}
20:19:26.062 [ERROR] [t.core.internal.addons.AddonResource] - Replied to HTTP GET request 'addons' {} {serviceId=[jar]}
20:19:26.069 [ERROR] [t.core.internal.addons.AddonResource] - Received HTTP GET request at 'addons' {} {serviceId=[eclipse]}
20:19:26.077 [ERROR] [t.core.internal.addons.AddonResource] - Received HTTP GET request at 'addons' {} {serviceId=[json]}
20:19:26.079 [ERROR] [t.core.internal.addons.AddonResource] - Replied to HTTP GET request 'addons' {} {serviceId=[eclipse]}
20:19:26.083 [ERROR] [t.core.internal.addons.AddonResource] - Received HTTP GET request at 'addons' {} {serviceId=[marketplace]}
20:19:26.142 [ERROR] [t.core.internal.addons.AddonResource] - Replied to HTTP GET request 'addons' {} {serviceId=[json]}
20:19:26.389 [ERROR] [t.core.internal.addons.AddonResource] - Replied to HTTP GET request 'addons' {} {serviceId=[marketplace]}

I've now added logging for when the reply is sent as well. As you can see, the times are relatively reasonable. The "jar" service responds almost immediately, the "eclipse" service (which isn't relevant in normal installations) within 10 ms, the "json" service took 65 ms and the community marketplace took 306 ms.

Here is another refresh:

20:27:01.584 [ERROR] [t.core.internal.addons.AddonResource] - Received HTTP GET request at 'addons/services' {} {}
20:27:01.586 [ERROR] [t.core.internal.addons.AddonResource] - Replied to HTTP GET request 'addons/services' {} {}
20:27:01.833 [ERROR] [t.core.internal.addons.AddonResource] - Received HTTP GET request at 'addons/services' {} {}
20:27:01.834 [ERROR] [t.core.internal.addons.AddonResource] - Replied to HTTP GET request 'addons/services' {} {}
20:27:01.889 [ERROR] [t.core.internal.addons.AddonResource] - Received HTTP GET request at 'addons' {} {serviceId=[jar]}
20:27:01.889 [ERROR] [t.core.internal.addons.AddonResource] - Replied to HTTP GET request 'addons' {} {serviceId=[jar]}
20:27:01.891 [ERROR] [t.core.internal.addons.AddonResource] - Received HTTP GET request at 'addons' {} {serviceId=[marketplace]}
20:27:01.891 [ERROR] [t.core.internal.addons.AddonResource] - Received HTTP GET request at 'addons' {} {serviceId=[eclipse]}
20:27:01.891 [ERROR] [t.core.internal.addons.AddonResource] - Received HTTP GET request at 'addons' {} {serviceId=[json]}
20:27:01.894 [ERROR] [t.core.internal.addons.AddonResource] - Replied to HTTP GET request 'addons' {} {serviceId=[eclipse]}
20:27:01.922 [ERROR] [t.core.internal.addons.AddonResource] - Replied to HTTP GET request 'addons' {} {serviceId=[json]}
20:27:02.055 [ERROR] [t.core.internal.addons.AddonResource] - Replied to HTTP GET request 'addons' {} {serviceId=[marketplace]}

Again, the times are quite reasonable, and the UI doesn't feel slow. Also, regardless of how much I "browse around" in the "Add-on Store", the requests aren't repeated, not when I change "category" and not if I switch to another tab and back. The only way I can seem to be able to make MainUI resend the requests is by refreshing the page in the browser, or if I navigate to e.g. "Settings" and then back to "Add-on Store".

So, I'm wondering if something else is going on here. Has something, seemingly unrelated, been changed that affects this since this was made, or am I testing it "wrong"?

[Nadahar]

To be thorough, I reverted 7f47d825a0864002e6b0d491d17554176996e5de locally (including the stuff that isn't directly related to add-ons) and added the same logging:

22:28:30.688 [ERROR] [t.core.internal.addons.AddonResource] - Received HTTP GET request at 'addons/services' {} {}
22:28:30.689 [ERROR] [t.core.internal.addons.AddonResource] - Replied to HTTP GET request 'addons/services' {} {}
22:28:30.737 [ERROR] [t.core.internal.addons.AddonResource] - Received HTTP GET request at 'addons' {} {serviceId=[jar]}
22:28:30.737 [ERROR] [t.core.internal.addons.AddonResource] - Received HTTP GET request at 'addons' {} {serviceId=[eclipse]}
22:28:30.738 [ERROR] [t.core.internal.addons.AddonResource] - Replied to HTTP GET request 'addons' {} {serviceId=[jar]}
22:28:30.740 [ERROR] [t.core.internal.addons.AddonResource] - Received HTTP GET request at 'addons' {} {serviceId=[marketplace]}
22:28:30.740 [ERROR] [t.core.internal.addons.AddonResource] - Replied to HTTP GET request 'addons' {} {serviceId=[eclipse]}
22:28:30.744 [ERROR] [t.core.internal.addons.AddonResource] - Received HTTP GET request at 'addons' {} {serviceId=[json]}
22:28:30.756 [ERROR] [t.core.internal.addons.AddonResource] - Replied to HTTP GET request 'addons' {} {serviceId=[json]}
22:28:30.822 [ERROR] [t.core.internal.addons.AddonResource] - Replied to HTTP GET request 'addons' {} {serviceId=[marketplace]}

When the remote add-on cache must be refreshed, there is a delay of 700-1000 ms as the forum is queried and the data is processed. The next 15 minutes, the request takes somewhere between 80 and 300 ms to process. This is slow, and I believe that the "refresh code" is inefficient and can be made much quicker, but these 80-300 ms isn't enough to make the "Add-on Store" slow to use, especially since the calls are only made when the page is refreshed or when you enter it from a different part of the UI. Selecting different categories or browsing within the "Add-on Store" doesn't involve waiting for this, as these requests aren't sent while you do that.

[openhab-bot]

This issue has been mentioned on openHAB Community. There might be relevant details there:

https://community.openhab.org/t/openhab-5-0-milestone-discussion/162686/321

[florian-h05]

So I have just come back to this, and it seems our add-on store redesign (https://www.openhab.org/blog/2024-07-07-openhab-4-2-release.html#add-on-store-redesign) that was done after caching changed the loading behaviour. IIRC I added caching because every category change caused the store to (re)load the add-ons, making it slow. But the new add-on store doesn't do this, so let's remove the faulty caching: #4925