Smarthome: Warnings when updating an item file with tags

[kaikreuzer]

When my item file is reloaded, I see a warning for each item that has tags in my log:

12:34:37.967 [WARN ] [mmon.registry.AbstractManagedProvider] - Could not update element with key _tags:GF_Toilet in ManagedMetadataProviderImpl, because it does not exists.
12:34:37.971 [INFO ] [smarthome.event.ItemUpdatedEvent     ] - Item 'GF_Toilet' has been updated.
12:34:37.974 [WARN ] [mmon.registry.AbstractManagedProvider] - Could not update element with key _tags:GF_Corridor in ManagedMetadataProviderImpl, because it does not exists.
12:34:37.978 [INFO ] [smarthome.event.ItemUpdatedEvent     ] - Item 'GF_Corridor' has been updated.
12:34:37.982 [WARN ] [mmon.registry.AbstractManagedProvider] - Could not update element with key _tags:FF_Bath in ManagedMetadataProviderImpl, because it does not exists.
12:34:37.985 [INFO ] [smarthome.event.ItemUpdatedEvent     ] - Item 'FF_Bath' has been updated.
12:34:37.989 [WARN ] [mmon.registry.AbstractManagedProvider] - Could not update element with key _tags:FF_Office in ManagedMetadataProviderImpl, because it does not exists.
12:34:37.991 [INFO ] [smarthome.event.ItemUpdatedEvent     ] - Item 'FF_Office' has been updated.
12:34:37.995 [WARN ] [mmon.registry.AbstractManagedProvider] - Could not update element with key _tags:FF_Child in ManagedMetadataProviderImpl, because it does not exists.
12:34:37.998 [INFO ] [smarthome.event.ItemUpdatedEvent     ] - Item 'FF_Child' has been updated.
12:34:38.001 [WARN ] [mmon.registry.AbstractManagedProvider] - Could not update element with key _tags:FF_Bed in ManagedMetadataProviderImpl, because it does not exists.
12:34:38.005 [INFO ] [smarthome.event.ItemUpdatedEvent     ] - Item 'FF_Bed' has been updated.
12:34:38.008 [WARN ] [mmon.registry.AbstractManagedProvider] - Could not update element with key _tags:FF_Corridor in ManagedMetadataProviderImpl, because it does not exists.
12:34:38.012 [INFO ] [smarthome.event.ItemUpdatedEvent     ] - Item 'FF_Corridor' has been updated.

Items are these:

Group GF_Toilet     "Toilet"        <bath>      (gGF) ["location:wc"]
Group GF_Corridor   "Corridor"      <corridor>  (gGF) ["location:korridor"]
Group FF_Bath       "Bathroom"      <bath>      (gFF) ["location:bad"]
Group FF_Office     "Office"        <office>    (gFF) ["location:büro"]
Group FF_Child      "Child's Room"  <boy_1>      (gFF) ["location:kinderzimmer"]
Group FF_Bed        "Bedroom"       <bedroom>   (gFF) ["location:schlafzimmer"]
Group FF_Corridor   "Corridor"      <corridor>  (gFF) ["location:korridor"]

Observed on openHAB 2.3 release build.

[kaikreuzer]

@sjka Any idea? I keep seeing this and it is a bit annoying to have those in the log file...

[DomQuixote]

Same problem for me.

[DomQuixote]

And we are not the only ones... https://community.openhab.org/t/help-with-a-few-item-warnings-oh-2-3/45832/6.

[sjsf]

Having had a close look into this, I can confirm that the warning - as annoying as it is - was completely harmless. A fix is on the way, of course.

[roswennen]

@sjka Are you absolutely sure it's harmless I see the people having issues with the imperihome binding when they see these warnings and for me Homekit binding issues started when these warnings started happening.

[htreu]

We had an attempt to transparently handle tags on items as metadata with #5431. This was however rolled back with #5873 on July 11th.
I consider the problems described here and in other referenced issues as resolved.

[clempat]

Hey thanks for the fix. I have a small question. I got those warning but in my case it was not so harmless. I realised that any change in the item file (where the warning occurs) will put the states of the items to NULL until the next update.

Will it be fixed with this ?

[kaikreuzer]

@clempat Please provide the exact version you are using and a current log file. The entries mentioned in that issue should not at all appear anymore in a recent snapshot.

[roswennen]

@kaikreuzer

I also still have these errors, see below.

I'm on the openhab/openhab:2.3.0-amd64-debian docker version, which I think is the latest docker version.

These errors are far from innocent indeed. I have the homekit binding installed and the errors occur for all Homekit linked items. They cause the Homekit appearance of these items to break, all the items disappear in Homekit. And the errors are followed by a bunch of Homekit errors see below as well.

The only way to make the Homekit items appear again is by completely stopping and starting the container. The items re-appear but have lost all their room info in Homekit, so need to reallocate >50 items every time I touch the items file.

I can also confirm that the error makes the state change to NULL as @clempat was saying.

Hope this helps and hope this causes this issue to be re-opened.

==> /logs/openhab.log <==

2018-09-02 07:06:44.982 [WARN ] [mon.registry.AbstractManagedProvider] - Could not update element with key _tags:NB_S1_O7_lichtgarage in ManagedMetadataProviderImpl, because it does not exists.

2018-09-02 07:06:44.997 [WARN ] [mon.registry.AbstractManagedProvider] - Could not update element with key _tags:NB_S1_O8_lichttraphal in ManagedMetadataProviderImpl, because it does not exists.

2018-09-02 07:06:45.027 [WARN ] [mon.registry.AbstractManagedProvider] - Could not update element with key _tags:NB_S1_O11_lichteetplaats in ManagedMetadataProviderImpl, because it does not exists.

2018-09-02 07:06:45.050 [WARN ] [mon.registry.AbstractManagedProvider] - Could not update element with key _tags:NB_S1_O12_kastkinesis in ManagedMetadataProviderImpl, because it does not exists.

2018-09-02 07:06:45.073 [WARN ] [mon.registry.AbstractManagedProvider] - Could not update element with key _tags:NB_S2_O1_lichtnisbed in ManagedMetadataProviderImpl, because it does not exists.

2018-09-02 07:06:45.095 [WARN ] [mon.registry.AbstractManagedProvider] - Could not update element with key _tags:NB_S2_O2_lichtsterrenhemel in ManagedMetadataProviderImpl, because it does not exists.

2018-09-02 07:06:45.115 [WARN ] [mon.registry.AbstractManagedProvider] - Could not update element with key _tags:NB_S2_O3_lichtterras in ManagedMetadataProviderImpl, because it does not exists.

==> /logs/openhab.log <==

2018-09-02 07:07:15.128 [ERROR] [lfe.hap.impl.connections.HttpSession] - Could not handle request
java.lang.NullPointerException: null
at java.util.Collections$UnmodifiableMap.(Collections.java:1446) [?:?]
at java.util.Collections.unmodifiableMap(Collections.java:1433) [?:?]
at com.beowulfe.hap.impl.HomekitRegistry.getCharacteristics(HomekitRegistry.java:75) [221:org.openhab.io.homekit:2.3.0]
at com.beowulfe.hap.impl.json.CharacteristicsController.get(CharacteristicsController.java:52) [221:org.openhab.io.homekit:2.3.0]
at com.beowulfe.hap.impl.connections.HttpSession.handleAuthenticatedRequest(HttpSession.java:87) [221:org.openhab.io.homekit:2.3.0]
at com.beowulfe.hap.impl.connections.ConnectionImpl.doHandleRequest(ConnectionImpl.java:51) [221:org.openhab.io.homekit:2.3.0]
at com.beowulfe.hap.impl.connections.ConnectionImpl.handleRequest(ConnectionImpl.java:46) [221:org.openhab.io.homekit:2.3.0]
at com.beowulfe.hap.impl.http.impl.AccessoryHandler.channelRead0(AccessoryHandler.java:47) [221:org.openhab.io.homekit:2.3.0]
at com.beowulfe.hap.impl.http.impl.AccessoryHandler.channelRead0(AccessoryHandler.java:15) [221:org.openhab.io.homekit:2.3.0]
at io.netty.channel.SimpleChannelInboundHandler.channelRead(SimpleChannelInboundHandler.java:105) [221:org.openhab.io.homekit:2.3.0]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:308) [221:org.openhab.io.homekit:2.3.0]
at io.netty.channel.AbstractChannelHandlerContext.access$600(AbstractChannelHandlerContext.java:32) [221:org.openhab.io.homekit:2.3.0]
at io.netty.channel.AbstractChannelHandlerContext$7.run(AbstractChannelHandlerContext.java:299) [221:org.openhab.io.homekit:2.3.0]
at io.netty.util.concurrent.DefaultEventExecutor.run(DefaultEventExecutor.java:36) [221:org.openhab.io.homekit:2.3.0]
at io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:112) [221:org.openhab.io.homekit:2.3.0]
at io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:137) [221:org.openhab.io.homekit:2.3.0]
at java.lang.Thread.run(Thread.java:748) [?:?]

2018-09-02 07:07:16.929 [ERROR] [kit.internal.HomekitAccessoryUpdater] - Received duplicate subscription on humidity_sensor2

2018-09-02 07:07:16.930 [ERROR] [kit.internal.HomekitAccessoryUpdater] - Received duplicate subscription on humidity_sensor2

2018-09-02 07:07:16.940 [ERROR] [kit.internal.HomekitAccessoryUpdater] - Received duplicate subscription on TempBuitenCurrent

2018-09-02 07:07:16.941 [ERROR] [kit.internal.HomekitAccessoryUpdater] - Received duplicate subscription on TempBuitenCurrent

2018-09-02 07:07:16.966 [ERROR] [kit.internal.HomekitAccessoryUpdater] - Received duplicate subscription on TV_Slaapkamer

2018-09-02 07:07:16.967 [ERROR] [kit.internal.HomekitAccessoryUpdater] - Received duplicate subscription on TV_Slaapkamer

Items are defined like this in the items file
Switch NB_S1_O1_lichtWC "WC" (gLichtBeneden) [ "Lighting" , "LichtBeneden" ] { nikobus="09B9:1" }
Switch NB_S1_O2_lichtbadkamer "Badkamer" (gLichtBeneden) [ "Lighting" , "LichtBeneden" ] { nikobus="09B9:2" }
Switch NB_S1_O3_lichtkeuken "Keuken" (gLichtBeneden) [ "Lighting" , "LichtBeneden" ] { nikobus="09B9:3" }
S

[kaikreuzer]

Hope this helps and hope this causes this issue to be re-opened.

You are saying you have this on openHAB 2.3, but you will have to confirm that it is still the same on a recent 2.4 snapshot, which I doubt. So there's no reason to re-open this issue as it is already fixed.

Additionally, your log shows an exception in the homekit add-on (or rather its internal library) - so it is not clear how this bug might affect the behavior here.

[edizius]

I am also using OpenHab v 2.3.0 (openhabian), and also still get These warnings followed by NULL state and the problem that alexa can Not find the switches which have hue emulation tags

[5iver]

I am also using OpenHab v 2.3.0 (openhabian), and also still get These warnings

You will need to wait for the next stable release of OH, or upgrade to a snapshot build or milestone release.

[edizius]

Is it fixed with the actual nightly release of OH? Is there a release date for the next stable release?

[5iver]

Is it fixed with the actual nightly release of OH?

Yes, the fix has been in the nightly OH snapshot builds since June. It is also in the testing Milestone releases. I believe there is a goal to have annual stable releases, but there is not a published stable release date.