Update of dynamic state options in UIs is broken

[lolodomo]

@cweitkamp : we have a major issue. The update of state options in UIs is now broken in snapshot 2431.
This is certainly a consequence of PR #1505

Note that the new event is working well, I was able to catch it in the remote openHAB binding.

The problem is that after you update your state options provider for a channel, this update is ignored in UIs (Main UI and Basic UI). And this is not a cache problem of course.

Could it be because the webui is not yet in phase with the core changes ?

[cweitkamp]

update of state options in UIs is now broken

What does that mean exactly? How can I reproduce this? Can you elaborate a little bit?

[lolodomo]

Just run the current code or the snapshot 2431.
I played with an updated binding (Sonos in my current case (with the 2 new references).
It looks like the first initialization of the list of options is done.
But then when it should update, you still see the old list o options in UI.
But the new code is run and the new event is produced.

For an untouched binding (I checked the home connect binding), it even looks like the state options are not set at all.

I would like to be sure that it is not due to outdated UIs not in phase with the new core code before investigating/debugging in Eclipse.

[lolodomo]

In Eclipse, I see resolution with core.thing.3.1.0.202106211206 and ui.basic.3.1.0.202106201606.
UI bundles are from yesterday beofre the core changes.
I hope it explains the issue.

[lolodomo]

Same in build 2431:

                           _   _     _     ____
   ___   ___   ___   ___  | | | |   / \   | __ )
  / _ \ / _ \ / _ \ / _ \ | |_| |  / _ \  |  _ \
 | (_) | (_) |  __/| | | ||  _  | / ___ \ | |_) )
  \___/|  __/ \___/|_| |_||_| |_|/_/   \_\|____/
       |_|       3.1.0-SNAPSHOT - Build #2431

Use '<tab>' for a list of available commands
and '[cmd] --help' for help on a specific command.
To exit, use '<ctrl-d>' or 'logout'.

openhab> bundle:list -s | grep basic
267 x Active x  80 x 3.1.0.202106201606    x org.openhab.ui.basic
openhab> bundle:list -s | grep thing
207 x Active x  80 x 3.1.0.202106211236    x org.openhab.core.model.thing
208 x Active x  80 x 3.1.0.202106211239    x org.openhab.core.model.thing.ide
209 x Active x  80 x 3.1.0.202106211240    x org.openhab.core.model.thing.runtime
213 x Active x  80 x 3.1.0.202106211218    x org.openhab.core.thing
214 x Active x  75 x 3.1.0.202106211225    x org.openhab.core.thing.xml

I hope we just need to rebuild all the UIs.

[kaikreuzer]

I have started a new build of the UI against the latest core: https://ci.openhab.org/job/openHAB-WebUI/360/
It shouldn't take long, let's hope it helps!

[lolodomo]

Thank you, I just noticed the rebuild in progress.
I will try with the next snapshot tomorrow morning.

[lolodomo]

Unfortunately, the issue is still there in snapshot 2433 :(

Could you check and confirm @cweitkamp ?

I could restore an older snapshot from few days to be sure what broke the feature.

[lolodomo]

I have now restored the snapshot 2415 and the problem is still there !
So the problem is older than I imagined and not related to the yesterday changes.
That would be cool if someone could confirm the problem. I hope I am not creazy.
I imagine the problem is in the core ui bundle.

[lolodomo]

I have one strange feeling: just by reading the code, it looks like itemdtomapper is setting item command description with state options when no command options are available.
As command description has then priority over state description when building the page in BasicUI, it could explain why the next updated state options are ignored (and why the initial setting is working).
To be confirmed after debugging.

We must not store command description when there is none. We must not create one from the state description.

Here is the suspected line:

openhab-core/bundles/org.openhab.core.io.rest.core/src/main/java/org/openhab/core/io/rest/core/item/EnrichedItemDTOMapper.java

Line 101 in 79edf2b

item.getCommandDescription(locale));

[cweitkamp]

After introduction of the CommandDescription we tried to prefer them for building UI based controls. If no CommandDescription is available it will be built each time during runtime from the StateOptions. AFAIR there is no place where they are stored.

Is your Item read-only? This imo is the only situation where the above logic does not make sense.

[lolodomo]

No my item is not read-only.
"stored" was not the appropriate word, I meant provided to the REST API.
I will have to validate my analysis ... which is unfortunately right I believe. This will fully explain why the first time it is OK and not the next time.

[lolodomo]

If I use the API explorer and requests the data for my item, I can see a stateDescription AND a commandDescription. Both have the same list of options and not the expected list. I am not sure if it is normal to have a commandDescription, is it ?
By the way, my options are not updatred while the dynamic state provider is triggered.

[cweitkamp]

I tried to reproduce your issue with latest code via Eclipse and Kodi binding which uses both (a BaseDynamicCommandDescriptionProvider and a BaseDynamicStateDescriptionProvider). Everything is working for me. The new events are sent correctly and either StateOption as well as CommandOption are changing in Main UI. The response of REST API changes respectively.

I am not sure how I can help you. Can you provide code? An example configuration? Screenshots?

[lolodomo]

That is creazy !

With snapshot 2433, after the startup, the state options of my Sonos item listing my favorite radio stations is correctly set:

• OK in MainUI => 13 options
• OK in BasicUI => 13 options
• OK when I request my item using API explorer => 13 options

Then I remove one of my favorite radio using the Sonos app.

I see the expected new event logged:
It proves that the binding used the options provider to update the list of state options.

18:49:52.696 [INFO ] [.event.ChannelDescriptionChangedEvent] - Description for field 'STATE_OPTIONS' of channel 'sonos:xxx:salon:radio' changed from '{"options":[{"value":"xxx","label":"xxx"},...]}' to '{"options":[{"value":"xxx","label":"xxx"},]}' for linked items: [SonosSalonPlayRadio]

The event shows that the number of options goes from 13 to 12, as expected.

But then:

• not OK in MainUI => still 13 options rather than 12
• not OK in BasicUI => still 13 options rather than 12
• not OK when I request my item using API explorer => still 13 options rather than 12

I used "Ctrl+F5" in Firefox but unchanged.

[lolodomo]

If I open UI using Edge, I still see 13 options. So this is not due to the browser.

For me, it is clear, the item state description was not updated.

The first setting is always OK but then the next updates are not impacting the item data (while the produced .ChannelDescriptionChangedEvent event is correct).

[lolodomo]

I am not sure how I can help you. Can you provide code? An example configuration? Screenshots?

In my last test, I simply use the 2433 distirbution with absolutely no code modification.
My test were done with the Sonos binding which provides a channel for the favorite radio stations that is built dynamically.

[lolodomo]

I extended my Sonos dynamic state options provider to see when it is called.
When I display the item in MainUI, in BasicUI or when I request it with API explorer, I can see that getStateDescription from my Sonos provider is called and returned the correct number of options but this is apparently not what is finally used.
I still predict that a list of outdated options is rather used.

[lolodomo]

I am sure there is BIG bug, certainly subtile. Unfortunately, I am not clear how to debug that. This is of course somewhere in the core framework but all this is very complex (service, fragment, provider, registry, ...). I am a little lost.

@cweitkamp : did you try to trigger several updates of your options ?

[lolodomo]

I also added logs in the BasicUI backend, that is in the render of my selection widget called when I open the page containing my item.

At init, I first see:

23:52:24.509 [INFO ] [.SonosStateDescriptionOptionProvider] - SONOS setStateOptions channel sonos:CONNECT:salon:radio options 12
23:52:24.511 [INFO ] [.SonosStateDescriptionOptionProvider] - SONOS setStateOptions channel sonos:CONNECT:salon:radio => opts 12

My state options are correctly loaded by the Sonos binding.

Then I open BasicUI:

3:53:20.008 [INFO ] [ic.internal.render.SelectionRenderer] - Calling item.getCommandDescription() for SonosSalonPlayRadio2
23:53:20.009 [INFO ] [.SonosStateDescriptionOptionProvider] - SONOS localizedStateOptions channel sonos:CONNECT:salon:radio options 12 locale null returned 12 options
23:53:20.009 [INFO ] [.SonosStateDescriptionOptionProvider] - SONOS getStateDescription channel sonos:CONNECT:salon:radio locale null returned 12 options
23:53:20.009 [INFO ] [ic.internal.render.SelectionRenderer] - item.getCommandDescription() returned 12 options

That is OK, the call to item.getCommandDescription() is requesting my Sonos dynamic option provider and finally returns the correct number of options (12).

Then in the Sonos app, I removed a favorite station. I see the update of state options by the Sonos dynamic option provider:

23:54:05.302 [INFO ] [.SonosStateDescriptionOptionProvider] - SONOS setStateOptions channel sonos:CONNECT:salon:radio options 11
23:54:05.304 [INFO ] [.SonosStateDescriptionOptionProvider] - SONOS setStateOptions channel sonos:CONNECT:salon:radio => opts 11

And now I reopen BasicUI:

23:54:23.320 [INFO ] [ic.internal.render.SelectionRenderer] - Calling item.getCommandDescription() for SonosSalonPlayRadio2
23:54:23.321 [INFO ] [.SonosStateDescriptionOptionProvider] - SONOS localizedStateOptions channel sonos:CONNECT:salon:radio options 11 locale null returned 11 options
23:54:23.321 [INFO ] [.SonosStateDescriptionOptionProvider] - SONOS getStateDescription channel sonos:CONNECT:salon:radio locale null returned 11 options
23:54:23.321 [INFO ] [ic.internal.render.SelectionRenderer] - item.getCommandDescription() returned 12 options

Here is the problem. You can see that my Sonos dynamic option provider is requested and provided 11 options but finally the returned command description contains 12 options and UI page is built with that.

By curiosity, I also called item.getStateDescription() in the selection renderer but the result is the same:

23:54:23.321 [INFO ] [ic.internal.render.SelectionRenderer] - Calling item.getStateDescription() for SonosSalonPlayRadio2
23:54:23.321 [INFO ] [.SonosStateDescriptionOptionProvider] - SONOS localizedStateOptions channel sonos:CONNECT:salon:radio options 11 locale null returned 11 options
23:54:23.322 [INFO ] [.SonosStateDescriptionOptionProvider] - SONOS getStateDescription channel sonos:CONNECT:salon:radio locale null returned 11 options
23:54:23.322 [INFO ] [ic.internal.render.SelectionRenderer] - item.getStateDescription() returned 12 options

So item.getCommandDescription() and item.getStateDescription() run by the BasicUI widget renderer are returning a bad list of options.

[lolodomo]

@cweitkamp : ok, I am making progress. I have now added logs in CommandDescriptionServiceImpl and StateDescriptionServiceImpl.

This is a use case when I added a favorite radio station.

In fact, I discovered that there are two state description fragments returned for my item.
The first returned 11 options and the second 12 options. The merge of both resulted in 11 options.

00:54:36.880 [INFO ] [ic.internal.render.SelectionRenderer] - Calling item.getCommandDescription() for SonosSalonPlayRadio2
00:54:36.880 [INFO ] [ervice.CommandDescriptionServiceImpl] - CommandDescriptionServiceImpl getCommandDescription 2 providers
00:54:36.881 [INFO ] [.service.StateDescriptionServiceImpl] - StateDescriptionServiceImpl getMergedStateDescriptionFragments 3 providers
00:54:36.881 [INFO ] [.service.StateDescriptionServiceImpl] - StateDescriptionServiceImpl first found fragment with 11 options
00:54:36.881 [INFO ] [.SonosStateDescriptionOptionProvider] - SONOS localizedStateOptions channel sonos:CONNECT:salon:radio options 12 locale null returned 12 options
00:54:36.881 [INFO ] [.SonosStateDescriptionOptionProvider] - SONOS getStateDescription channel sonos:CONNECT:salon:radio locale null returned 12 options
00:54:36.881 [INFO ] [.service.StateDescriptionServiceImpl] - StateDescriptionServiceImpl Merging with other found fragment with 12 options
00:54:36.881 [INFO ] [ic.internal.render.SelectionRenderer] - item.getCommandDescription() returned 11 options

I have 3 fragment providers. Don't know if this is normal.
2 of them are returning a fragment for my item. Why ?
One of them of course is expected and requests my Sonos binding dynamic options provider.

These 2 fragment providers returning a different number of options is clearly the cause of my problem.

Or if the both fragments is something normal, maybe the problem is their merge ?

[cweitkamp]

Can you identify which provider are running in your system? Call from Karaf console:

bundle:services | grep DynamicStateDescriptionProvider

[lolodomo]

My detailed tests were run inside Eclipse and I can't run such command.
But as the behaviour is the same in my production server, here is the result:

bundle:services | grep DynamicStateDescriptionProvider
[org.openhab.core.thing.type.DynamicStateDescriptionProvider, org.openhab.binding.homeconnect.internal.type.HomeConnectDynamicStateDescriptionProvider]
[org.openhab.core.thing.type.DynamicStateDescriptionProvider, org.openhab.binding.hue.internal.handler.HueStateDescriptionOptionProvider]
[org.openhab.core.thing.type.DynamicStateDescriptionProvider, org.openhab.binding.lgwebos.internal.LGWebOSStateDescriptionOptionProvider]
[org.openhab.core.thing.type.DynamicStateDescriptionProvider, org.openhab.binding.netatmo.internal.NATherm1StateDescriptionProvider]
[org.openhab.core.thing.type.DynamicStateDescriptionProvider, org.openhab.binding.remoteopenhab.internal.RemoteopenhabStateDescriptionOptionProvider]
[org.openhab.core.thing.type.DynamicStateDescriptionProvider, org.openhab.binding.rotel.internal.RotelStateDescriptionOptionProvider]
[org.openhab.core.thing.type.DynamicStateDescriptionProvider, org.openhab.binding.sonos.internal.SonosStateDescriptionOptionProvider]
[org.openhab.core.thing.type.DynamicStateDescriptionProvider, org.openhab.binding.sonyprojector.internal.SonyProjectorStateDescriptionOptionProvider]

[lolodomo]

In my Eclipse setup, I should in theory have 2, one for sonos and one for remoteopenhab.

And one provider attached to the CommandDescriptionServiceImpl is certainly coming from remoteopenhab binding; don't know for the second.

[lolodomo]

I will check this evening the type of each of my StateDescriptionFragmentProvider..
Looking at the code, I can imagine the 3 are:
ChannelStateDescriptionProvider
MetadataStateDescriptionProvider
GenericItemProvider

Will see which one delivers the wrong information.

[lolodomo]

Here is with enhanced logs (scenario when I removed a favorite stations, going from 12 to 11 stations):

19:14:36.232 [INFO ] [ic.internal.render.SelectionRenderer] - Calling item.getCommandDescription() for SonosSalonPlayRadio2
19:14:36.233 [INFO ] [ervice.CommandDescriptionServiceImpl] - CommandDescriptionServiceImpl getCommandDescription 2 providers
19:14:36.233 [INFO ] [.service.StateDescriptionServiceImpl] - StateDescriptionServiceImpl with 3 fragment providers
19:14:36.233 [INFO ] [.service.StateDescriptionServiceImpl] - StateDescriptionServiceImpl fragment provider MetadataStateDescriptionFragmentProvider
19:14:36.233 [INFO ] [.service.StateDescriptionServiceImpl] - No fragment returned by fragment provider MetadataStateDescriptionFragmentProvider
19:14:36.233 [INFO ] [.service.StateDescriptionServiceImpl] - StateDescriptionServiceImpl fragment provider GenericItemProvider
19:14:36.233 [INFO ] [.service.StateDescriptionServiceImpl] - Fragment provider GenericItemProvider returned a state description with 12 options
19:14:36.233 [INFO ] [.service.StateDescriptionServiceImpl] - StateDescriptionServiceImpl fragment provider ChannelStateDescriptionProvider
19:14:36.233 [INFO ] [.SonosStateDescriptionOptionProvider] - SONOS localizedStateOptions channel sonos:CONNECT:salon:radio options 11 locale null returned 11 options
19:14:36.233 [INFO ] [.SonosStateDescriptionOptionProvider] - SONOS getStateDescription channel sonos:CONNECT:salon:radio locale null returned 11 options
19:14:36.233 [INFO ] [.service.StateDescriptionServiceImpl] - Fragment provider ChannelStateDescriptionProvider returned a state description with 11 options
19:14:36.234 [INFO ] [ic.internal.render.SelectionRenderer] - item.getCommandDescription() returned 12 options

As you can see, the two fragment providers are GenericItemProvider and ChannelStateDescriptionProvider.
GenericItemProvider is providing the outdated information, that is the 12 options.
ChannelStateDescriptionProvider is providing the correct information that is the 11 options.

Any idea why GenericItemProvider delivers wrong information ? It delivers the dynamic options but the old ones.

Looking at the code of the merge of fragments, the list of options of second fragment are just ignored if the first fragment has already options. It clearly explains why the final state description contains 12 options.

So the result depends on the order of fragment providers. Maybe, the order is the reverse sometimes and it would explain why it works for some users.

PS: I have now only the Sonos binding setup in Eclipse.

[lolodomo]

I also checked the rank of each fragment provider:

• MetadataStateDescriptionFragmentProvider has rank 1
• GenericItemProvider has rank 0
• ChannelStateDescriptionProvider has rank -1

Is it expected that GenericItemProvider returns dynamic state options ? Not the most uptodate ?

If it is, maybe we should consider the rank when going through the fragment providers ? And dgive priority to ChannelStateDescriptionProvider ?
Currently the code in StateDescriptionServiceImpl is just doing a for on stateDescriptionFragmentProviders which is of type Set<StateDescriptionFragmentProvider>.

openhab-core/bundles/org.openhab.core/src/main/java/org/openhab/core/internal/service/StateDescriptionServiceImpl.java

Line 70 in 79edf2b

for (StateDescriptionFragmentProvider provider : stateDescriptionFragmentProviders) {

@cweitkamp @kaikreuzer : I think the analysis is now relatively clear. WDYT ?

[lolodomo]

Can I have please attention, it looks like a major bug and I would recommend to fix it before releasing 3.1.
It is relatively complex and I am not sure where is the problem, even if it seems that the problem is GenericItemProvider providing outdated state description with options.

[lolodomo]

As a workaround, we can update the code to be sure that GenericItemProvider will be handled after ChannelStateDescriptionProvider by StateDescriptionServiceImpl. At least, this will fix the display of options in Basic UI.
I should check if it also fix the display of options in Main UI (meaning in case the cause is the same).
I am not sure we can use the rank in this case.

[lolodomo]

In fact the fragment providers are already sorted in the reverse order of their rank:

openhab-core/bundles/org.openhab.core/src/main/java/org/openhab/core/internal/service/StateDescriptionServiceImpl.java

Line 43 in 79edf2b

private final Set<StateDescriptionFragmentProvider> stateDescriptionFragmentProviders = Collections.synchronizedSet(

So the order is the same for everybody. GenericItemProvider is handled before ChannelStateDescriptionProvider .

[cweitkamp]

@lolodomo First of all I'd like to point out that you got my attention from the first time you opened this issue. Second I'd like to thank you for your deep analysis.

The GenericItemProvider should not return StateOptions in the fragments. Only patters. The problem is in the following lines of code:

openhab-core/bundles/org.openhab.core/src/main/java/org/openhab/core/internal/service/StateDescriptionServiceImpl.java

Lines 77 to 81 in 8e3f87a

	if (result == null) {
	result = (StateDescriptionFragmentImpl) fragment;
	} else {
	result.merge(fragment);
	}

When result == null we assign the found fragment. Later we merge more fragments found into it. The fragment object itself is still the original reference thus we are merging into object hold in the GenericItemProvider In other words the problem is that when we change any of the original fragments' properties, this will also affect the original object.

Solution is to create a deep copy of the first found fragment before merging other fragments into it.

[lolodomo]

The GenericItemProvider should not return StateOptions in the fragments. Only patters.

That was my feeling too.
Thank you for finding the root cause and the solution.
I am hurry to test that.
Unfortunately it generates delay to other PRs I intend to work on this week.