Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Thing File based configuration not loaded correctly after changing #4201

Closed
miloit opened this issue Apr 28, 2024 · 33 comments · Fixed by #4219
Closed

Thing File based configuration not loaded correctly after changing #4201

miloit opened this issue Apr 28, 2024 · 33 comments · Fixed by #4219
Labels
bug An unexpected problem or unintended behavior of the Core

Comments

@miloit
Copy link

miloit commented Apr 28, 2024

Hello,

I changed the thing file

from

Thing shelly:shellyplus1pm:441793cea354 "Plus1PM_Bett_links" @ "Bedroom" [deviceIp="ip", password="password"]
Thing shelly:shellyplus1pm:d4d4da7cbde0 "Plus1PM_Bett_rechts" @ "Bedroom" [deviceIp="ip", password="password"]

to

Thing shelly:shellyplus1pm:441793cea354 "Plus1PM_Bett_linksd" @ "Bedroom" [deviceIp="ip", password="password"]
Thing shelly:shellyplus1pm:d4d4da7cbde0 "Plus1PM_Bett_rechtsd" @ "Bedroom" [deviceIp="ip", password="password"]

this is the log

2024-04-10 13:53:54.527 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'shelly.things'
2024-04-10 13:53:54.549 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'shelly:shellyplus1pm:441793cea354' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Unerwarteter Fehler - WebSocket connection closed abnormal
2024-04-10 13:53:54.556 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'shelly:shellyplus1pm:d4d4da7cbde0' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Unerwarteter Fehler - WebSocket connection closed abnormal
2024-04-10 13:53:56.549 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'shelly:shellyplus1pm:441793cea354' changed from ONLINE to UNKNOWN (CONFIGURATION_PENDING): Initialisierung oder Gerät im Schlafmodus.
2024-04-10 13:53:56.556 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'shelly:shellyplus1pm:d4d4da7cbde0' changed from ONLINE to UNKNOWN (CONFIGURATION_PENDING): Initialisierung oder Gerät im Schlafmodus.
2024-04-10 13:53:56.772 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'shelly:shellyplus1pm:441793cea354' changed from UNKNOWN (CONFIGURATION_PENDING): Initialisierung oder Gerät im Schlafmodus. to ONLINE
2024-04-10 13:53:56.882 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'shelly:shellyplus1pm:d4d4da7cbde0' changed from UNKNOWN (CONFIGURATION_PENDING): Initialisierung oder Gerät im Schlafmodus. to ONLINE

than change it back to

Thing shelly:shellyplus1pm:441793cea354 "Plus1PM_Bett_links" @ "Bedroom" [deviceIp="ip", password="password"]
Thing shelly:shellyplus1pm:d4d4da7cbde0 "Plus1PM_Bett_rechts" @ "Bedroom" [deviceIp="ip", password="password"]

seeing this in the log

2024-04-10 13:54:47.340 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'shelly.things'

but this in the ui

No update was loaded

@miloit miloit added the bug An unexpected problem or unintended behavior of the Core label Apr 28, 2024
@lolodomo
Copy link
Contributor

As I understand, you only change the thing label.
Can you please tell us if this is something that does not work only for Shelly things or for any thing ?

And what is your running OH version ?

@miloit
Copy link
Author

miloit commented Apr 29, 2024

@lolodomo yes, for any binding/thing you do ..it doesn't matter if you only change the label or the settings of the thing....so just a change...also item files I see this behavior....

I recognized this behavior in OH4.2M2

OH4.2M2 on latest openhabian release

@lolodomo
Copy link
Contributor

lolodomo commented May 1, 2024

I am able to reproduce. We can change several times the thing label and it is properly updated. The problem is only when you try to restore the initial value. This change is apparently ignored even if the logs show that the file is reloaded.

@lolodomo
Copy link
Contributor

lolodomo commented May 1, 2024

@jimtng ! do you think your PR #4076 could also fix this issue ? If not, with your knowledge of how the loading of things is working, do you understand the current issue ?

@jimtng
Copy link
Contributor

jimtng commented May 1, 2024

I haven't tested this scenario specifically. Without tracing it at runtime, I "suspect" this is what's happening:

  • Version 1 was loaded
  • .things file changed, Version 2 loaded, but due to the leak, Version 1 is still retained in memory, and Version 2 added to the thingsMap. This issue/leak is fixed in Fix change detection for textual things #4076.
  • .things changed back to Version 1, but because it wasn't cleared off thingsMap in the previous change, a match is found, and therefore the file isn't reloaded.

#4076 should fix this issue

@lolodomo
Copy link
Contributor

lolodomo commented May 1, 2024

Ok, I will test again once #4076 is merged.

@miloit
Copy link
Author

miloit commented May 2, 2024

#4076 is merged

@jimtng
Copy link
Contributor

jimtng commented May 2, 2024

Yes it's merged, but it hasn't yet made it into the latest snapshot. Hopefully within the next 12 hours!

@lolodomo
Copy link
Contributor

lolodomo commented May 3, 2024

Tested with snapshot 4064 including #4076. The problem is now different, it is now possible to restore the initial value. But now the very first change after startup is "ignored". The next ones are OK.
@jimtng : any idea ?

@lolodomo
Copy link
Contributor

lolodomo commented May 3, 2024

Is it possible to update the issue title to precise that it concerns Thing files ?

@miloit miloit changed the title Filebased configuration not loaded correctly Thing File based configuration not loaded correctly after changing May 4, 2024
@miloit
Copy link
Author

miloit commented May 4, 2024

@lolodomo better title now?

@jimtng
Copy link
Contributor

jimtng commented May 4, 2024

Tested with snapshot 4064 including #4076. The problem is now different, it is now possible to restore the initial value. But now the very first change after startup is "ignored". The next ones are OK.

I can't seem to reproduce this issue. Can you tell me the steps to reproduce it?

Here's what I did:

  • Create a test.things file:
Thing astro:sun:home "test1" [ geolocation="52.5200066,13.4049540,100", interval=60 ]
Thing astro:moon:home "test1" [ geolocation="52.5200066,13.4049540", interval=60 ]
  • Stop openhab
  • Start openhab
  • Run a script to show the label of the astro:sun:home - it logged it as "test1"
  • Modified the test.things file and changed the label to "test2"
  • Rerun the script to show the label, it now logged as "test2" so it appears that it did get updated.

@lolodomo
Copy link
Contributor

lolodomo commented May 4, 2024

My scenario was:

  1. Having a file astro.things file in conf/things containing
Thing astro:sun:local "Astro" @ "Extérieur" [ geolocation="xxxx" ]
  1. Start OH
  2. Edit the file by changing the thing label and save & quit the file => I see the log about file loading but when I refresh the page in Main UI showing the list of things, the label is unchanged. Confirmed by running the console command "things list | grep astro".
  3. Edit the file by changing the thing label and save & quit the file => I see the log about file loading and now when I refresh the page in Main UI showing the list of things, the label is correct. Confirmed by running the console command "things list | grep astro".

Tested on RPI. The file is on the SD card (so not a network share) and edited using vi.

@jimtng
Copy link
Contributor

jimtng commented May 4, 2024

My scenario was:

  1. Having a file astro.things file in conf/things containing
Thing astro:sun:local "Astro" @ "Extérieur" [ geolocation="xxxx" ]
  1. Start OH
  2. Edit the file by changing the thing label and save & quit the file => I see the log about file loading but when I refresh the page in Main UI showing the list of things, the label is unchanged. Confirmed by running the console command "things list | grep astro".
  3. Edit the file by changing the thing label and save & quit the file => I see the log about file loading and now when I refresh the page in Main UI showing the list of things, the label is correct. Confirmed by running the console command "things list | grep astro".

I'm still not able to reproduce the problem.

I tried your things file verbatim (including geolocation="xxxx"). As a result I got

Astro parameters geolocation could not be split into latitude and longitude, disabling thing 'astro:sun:local'

But upon changing the label, it did get updated on the Main UI (I had to refresh the browser).

I then tried entering an actual coordinate in the .things file:

Thing astro:sun:local "Astro" @ "Extérieur" [ geolocation="52.5200066,13.4049540,100" ]

Stopped openhab
Started it, confirming the label in Main UI
Then this time using vim to edit the file locally (not over samba), then saved the changes with :wq
the new label showed up on main ui.

@lolodomo
Copy link
Contributor

lolodomo commented May 4, 2024

Of course, I do not use "xxxx" as geolocation, it was just to not provide a real position.

If you are sure it works, I will try again.

@lolodomo
Copy link
Contributor

lolodomo commented May 5, 2024

My server was restarted yesterday. This morning, I tried again and I reproduced the problem. The first change of thing label is not applied even if the change of file is detected. Next changes are fine, even returning to the original thing label.

@miloit : can you confirm my experience with #4076 merged ?

@miloit
Copy link
Author

miloit commented May 5, 2024

@lolodomo can confirm same behaviour as before

I am on openHAB 4.2.0 (Build #4065)

I changed the file shelly.things from
Thing shelly:shellyplus1pm:441793cea354 "Plus1PM_Bett_links" @ "Bedroom" [deviceIp="ip", password="password"] Thing shelly:shellyplus1pm:d4d4da7cbde0 "Plus1PM_Bett_rechts" @ "Bedroom" [deviceIp="ip", password="password"]

to

Thing shelly:shellyplus1pm:441793cea354 "Plus1PM_Bett_linkse" @ "Bedroom" [deviceIp="ip", password="password"] Thing shelly:shellyplus1pm:d4d4da7cbde0 "Plus1PM_Bett_rechtse" @ "Bedroom" [deviceIp="ip", password="password"]

in the log I see
2024-05-05 10:57:28.575 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'shelly.things'

But still the old description in the UI

I stopped openhab started new now it was changed....tried it 2 times the same scenario....means only new loaded with a restart

@lolodomo
Copy link
Contributor

lolodomo commented May 5, 2024

Is it only at the first change or at any next change ?
For me, it works well except the first change.

Please note that the list of things in Main UI is not automatically updated, you have to refresh it.

@miloit
Copy link
Author

miloit commented May 5, 2024

Only first change

@lolodomo
Copy link
Contributor

lolodomo commented May 5, 2024

Only first change

Well, we have the same result.

@jimtng : that is strange that you can't reproduce it.

@miloit
Copy link
Author

miloit commented May 5, 2024

Can I log it somehow more?

@jimtng
Copy link
Contributor

jimtng commented May 5, 2024

I was testing it on snapshot build 4064 and couldn't replicate the problem.
I then tried installing build 4065 but encountered a problem when installing the astro binding, maybe because the addon build wasn't done yet (I don't quite understand how the packaging system works). So I tried build 4064 again and still cannot reproduce the problem.

  • I stopped openhab
  • Then started it again
  • Loaded the Main UI page to see the thing label as set in the file
  • Then edited the .things file to change the label (add / remove a letter or so)
  • Then refreshed the Main UI page, the change of label I made is reflected on the Things page

@jimtng
Copy link
Contributor

jimtng commented May 5, 2024

I think there's still a bug. I'm now able to reproduce this under a different set of conditions. Looking into it more!

@jimtng
Copy link
Contributor

jimtng commented May 5, 2024

The Bug I found was this:

However, I still haven't been able to reproduce the problem when the .things file only contain things from the same binding.

In any case, could you please test this jar file? You will need to clear openhab cache and tmp dirs. Note I had to add a fake .zip extension. This is not a zip file. Just rename and remove the .zip extension and do not unzip it.

org.openhab.core.model.thing-4.2.0-SNAPSHOT.jar.zip

This file needs to be placed inside ./runtime/system/org/openhab/core/bundles/org.openhab.core.model.thing/4.2.0-SNAPSHOT/ - please back up your original org.openhab.core.model.thing-4.2.0-SNAPSHOT.jar file first!

@miloit
Copy link
Author

miloit commented May 5, 2024

@jimtng Which one do I need to replace?

1)./srv/openhab-sys/runtime/system/org/openhab/core/bundles/org.openhab.core.model.thing.runtime

2)./srv/openhab-sys/runtime/system/org/openhab/core/bundles/org.openhab.core.model.thing.runtime/4.2.0-SNAPSHOT/org.openhab.core.model.thing.runtime-4.2.0-SNAPSHOT.jar

3)./srv/openhab-sys/runtime/system/org/openhab/core/bundles/org.openhab.core.model.thing.ide

4)./srv/openhab-sys/runtime/system/org/openhab/core/bundles/org.openhab.core.model.thing.ide/4.2.0-SNAPSHOT/org.openhab.core.model.thing.ide-4.2.0-SNAPSHOT.jar

5)./srv/openhab-sys/runtime/system/org/openhab/core/bundles/org.openhab.core.model.thing

6)./srv/openhab-sys/runtime/system/org/openhab/core/bundles/org.openhab.core.model.thing/4.2.0-SNAPSHOT/org.openhab.core.model.thing-4.2.0-SNAPSHOT.jar

7)./usr/share/openhab/runtime/system/org/openhab/core/bundles/org.openhab.core.model.thing.runtime

8)./usr/share/openhab/runtime/system/org/openhab/core/bundles/org.openhab.core.model.thing.runtime/4.2.0-SNAPSHOT/org.openhab.core.model.thing.runtime-4.2.0-SNAPSHOT.jar

9)./usr/share/openhab/runtime/system/org/openhab/core/bundles/org.openhab.core.model.thing.ide

10)./usr/share/openhab/runtime/system/org/openhab/core/bundles/org.openhab.core.model.thing.ide/4.2.0-SNAPSHOT/org.openhab.core.model.thing.ide-4.2.0-SNAPSHOT.jar

11)./usr/share/openhab/runtime/system/org/openhab/core/bundles/org.openhab.core.model.thing

12)./usr/share/openhab/runtime/system/org/openhab/core/bundles/org.openhab.core.model.thing/4.2.0-SNAPSHOT/org.openhab.core.model.thing-4.2.0-SNAPSHOT.jar

@miloit
Copy link
Author

miloit commented May 5, 2024

In the meantime I tested also other thing files....the first time it's not changing but than it seems to be fine

@jimtng
Copy link
Contributor

jimtng commented May 5, 2024

@jimtng Which one do I need to replace?

The one with the exact same name.
I don't know why you have two.

@miloit
Copy link
Author

miloit commented May 5, 2024

the second one is just a link :) so I have only one.....I used find to find the location

@miloit
Copy link
Author

miloit commented May 5, 2024

@jimtng looks good for me.....now

I am on openHAB 4.2.0 (Build #4065) with the jar file replaced as @jimtng wrote

I changed the file shelly.things from
Thing shelly:shellyplus1pm:441793cea354 "Plus1PM_Bett_links" @ "Bedroom" [deviceIp="ip", password="password"] Thing shelly:shellyplus1pm:d4d4da7cbde0 "Plus1PM_Bett_rechts" @ "Bedroom" [deviceIp="ip", password="password"]
to

Thing shelly:shellyplus1pm:441793cea354 "Plus1PM_Bett_linkse" @ "Bedroom" [deviceIp="ip", password="password"] Thing shelly:shellyplus1pm:d4d4da7cbde0 "Plus1PM_Bett_rechtse" @ "Bedroom" [deviceIp="ip", password="password"]
in the log I see

2024-05-05 22:30:40.510 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'shelly.things'
2024-05-05 22:30:40.630 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'shelly:shellyplus1pm:441793cea354' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Unerwarteter Fehler - WebSocket connection closed abnormal
2024-05-05 22:30:40.656 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'shelly:shellyplus1pm:d4d4da7cbde0' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Unerwarteter Fehler - WebSocket connection closed abnormal
2024-05-05 22:30:42.617 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'shelly:shellyplus1pm:441793cea354' changed from ONLINE to UNKNOWN (CONFIGURATION_PENDING): Initialisierung oder Gerät im Schlafmodus.
2024-05-05 22:30:42.654 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'shelly:shellyplus1pm:d4d4da7cbde0' changed from ONLINE to UNKNOWN (CONFIGURATION_PENDING): Initialisierung oder Gerät im Schlafmodus.
2024-05-05 22:30:43.046 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'shelly:shellyplus1pm:d4d4da7cbde0' changed from UNKNOWN (CONFIGURATION_PENDING): Initialisierung oder Gerät im Schlafmodus. to ONLINE
2024-05-05 22:30:43.081 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'shelly:shellyplus1pm:441793cea354' changed from UNKNOWN (CONFIGURATION_PENDING): Initialisierung oder Gerät im Schlafmodus. to ONLINE

already on the first attemp

changed back from

Thing shelly:shellyplus1pm:441793cea354 "Plus1PM_Bett_linkse" @ "Bedroom" [deviceIp="ip", password="password"] Thing shelly:shellyplus1pm:d4d4da7cbde0 "Plus1PM_Bett_rechtse" @ "Bedroom" [deviceIp="ip", password="password"]
to

Thing shelly:shellyplus1pm:441793cea354 "Plus1PM_Bett_links" @ "Bedroom" [deviceIp="ip", password="password"] Thing shelly:shellyplus1pm:d4d4da7cbde0 "Plus1PM_Bett_rechts" @ "Bedroom" [deviceIp="ip", password="password"]
in the log I see

2024-05-05 22:30:40.510 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'shelly.things' 2024-05-05 22:30:40.630 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'shelly:shellyplus1pm:441793cea354' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Unerwarteter Fehler - WebSocket connection closed abnormal 2024-05-05 22:30:40.656 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'shelly:shellyplus1pm:d4d4da7cbde0' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Unerwarteter Fehler - WebSocket connection closed abnormal 2024-05-05 22:30:42.617 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'shelly:shellyplus1pm:441793cea354' changed from ONLINE to UNKNOWN (CONFIGURATION_PENDING): Initialisierung oder Gerät im Schlafmodus. 2024-05-05 22:30:42.654 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'shelly:shellyplus1pm:d4d4da7cbde0' changed from ONLINE to UNKNOWN (CONFIGURATION_PENDING): Initialisierung oder Gerät im Schlafmodus. 2024-05-05 22:30:43.046 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'shelly:shellyplus1pm:d4d4da7cbde0' changed from UNKNOWN (CONFIGURATION_PENDING): Initialisierung oder Gerät im Schlafmodus. to ONLINE 2024-05-05 22:30:43.081 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'shelly:shellyplus1pm:441793cea354' changed from UNKNOWN (CONFIGURATION_PENDING): Initialisierung oder Gerät im Schlafmodus. to ONLINE

@jimtng
Copy link
Contributor

jimtng commented May 5, 2024

@lolodomo would you mind testing too please

@jimtng
Copy link
Contributor

jimtng commented May 6, 2024

@miloit thanks for testing. I take it that the jar I supplied did fix the problem?

Would you mind testing the following:

  1. only change the first thing then save the file and watch the log, and
  2. only change the second thing then save the file and watch the log

It should log that only the changed thing would go offline -> online and the unchanged thing should remain online.

@miloit
Copy link
Author

miloit commented May 6, 2024

@jimtng Yes the jar file fixed the problem

Also the second situation is running fine for me....

@openhab-bot
Copy link
Collaborator

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

https://community.openhab.org/t/since-4-2-0-snapshot-build-4065-and-later-unable-to-resolve-root-missing-requirement/155842/5

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug An unexpected problem or unintended behavior of the Core
Projects
None yet
Development

Successfully merging a pull request may close this issue.

4 participants