AVM DECT 200 Wallplugs not working in OH4.0.0 M3

helmar74 · June 28, 2023, 2:45pm

Hi ,
I upgraded my Testsystem from OH 3.4.4 to 4.0.0M3.
Now some of my Fritz!DECT 200 Wall Plugs are in state UNKNOWN, some are Online and are working.
Here’s the logoutput during startup:

2023-06-28 16:12:06.355 [WARN ] [core.thing.internal.ThingManagerImpl] - Channel types or config descriptions for thing 'avmfritz:FRITZ_DECT_200:192_168_1_1:1XXXXXXXXXXX' are missing in the respective registry for more than 120s. In case it does not happen immediately after an upgrade, it should be fixed in the binding.
2023-06-28 16:12:06.368 [ERROR] [.update.UpdateChannelInstructionImpl] - Failed to create channel 'avmfritz:FRITZ_DECT_200:192_168_1_1:1XXXXXXXXXXX:power' because channel type 'system:electrical-power' could not be found.
2023-06-28 16:12:06.369 [ERROR] [.update.UpdateChannelInstructionImpl] - Failed to create channel 'avmfritz:FRITZ_DECT_200:192_168_1_1:1XXXXXXXXXXX:voltage' because channel type 'system:electrical-voltage' could not be found.
2023-06-28 16:12:06.370 [INFO ] [core.thing.internal.ThingManagerImpl] - Updating 'avmfritz:FRITZ_DECT_200:192_168_1_1:1XXXXXXXXXXX' from version 0 to 1
2023-06-28 16:12:06.410 [WARN ] [core.thing.internal.ThingManagerImpl] - Channel types or config descriptions for thing 'kodi:kodi:9849245e' are missing in the respective registry for more than 120s. In case it does not happen immediately after an upgrade, it should be fixed in the binding.
2023-06-28 16:12:06.414 [WARN ] [core.thing.internal.ThingManagerImpl] - Failed to normalize configuration for thing 'kodi:kodi:9849245e': {thing/channel=Type description kodi:volume for kodi:kodi:9849245e:volume not found, although we checked the presence before.}
2023-06-28 16:12:06.466 [WARN ] [core.thing.internal.ThingManagerImpl] - Channel types or config descriptions for thing 'avmfritz:FRITZ_DECT_210:192_168_1_1:1XXXXXXXXXXX' are missing in the respective registry for more than 120s. In case it does not happen immediately after an upgrade, it should be fixed in the binding.
2023-06-28 16:12:06.469 [WARN ] [core.thing.internal.ThingManagerImpl] - Channel types or config descriptions for thing 'avmfritz:FRITZ_DECT_200:192_168_1_1:1XXXXXXXXXXX' are missing in the respective registry for more than 120s. In case it does not happen immediately after an upgrade, it should be fixed in the binding.
2023-06-28 16:12:06.476 [WARN ] [core.thing.internal.ThingManagerImpl] - Channel types or config descriptions for thing 'avmfritz:FRITZ_DECT_200:192_168_1_1:1XXXXXXXXXXX' are missing in the respective registry for more than 120s. In case it does not happen immediately after an upgrade, it should be fixed in the binding.
2023-06-28 16:12:06.483 [WARN ] [core.thing.internal.ThingManagerImpl] - Channel types or config descriptions for thing 'avmfritz:FRITZ_DECT_200:192_168_1_1:1XXXXXXXXXXX' are missing in the respective registry for more than 120s. In case it does not happen immediately after an upgrade, it should be fixed in the binding.
2023-06-28 16:12:06.488 [WARN ] [core.thing.internal.ThingManagerImpl] - Channel types or config descriptions for thing 'avmfritz:FRITZ_DECT_200:192_168_1_1:1XXXXXXXXXXX' are missing in the respective registry for more than 120s. In case it does not happen immediately after an upgrade, it should be fixed in the binding.
2023-06-28 16:12:08.493 [WARN ] [core.thing.internal.ThingManagerImpl] - Channel types or config descriptions for thing 'amazonechocontrol:echo:1XXXXXXX:GXXXXXXXXXXXXXXX' are missing in the respective registry for more than 120s. In case it does not happen immediately after an upgrade, it should be fixed in the binding.
2023-06-28 16:12:08.495 [WARN ] [core.thing.internal.ThingManagerImpl] - Channel types or config descriptions for thing 'amazonechocontrol:echo:1XXXXXXX:GXXXXXXXXXXXXXXX' are missing in the respective registry for more than 120s. In case it does not happen immediately after an upgrade, it should be fixed in the binding.
2023-06-28 16:12:08.499 [WARN ] [core.thing.internal.ThingManagerImpl] - Channel types or config descriptions for thing 'amazonechocontrol:echo:1XXXXXXX:GXXXXXXXXXXXXXXX' are missing in the respective registry for more than 120s. In case it does not happen immediately after an upgrade, it should be fixed in the binding.

The working devices show the same configuration and firmware version as the unknown devices:

Anyone an idea, what’s going wrong here or what I can check and do to fix it?

helmar74 · June 28, 2023, 3:07pm

I tried re-adding the unknown things, this didn’t solve the problem.

hmerk · June 28, 2023, 8:50pm

You did not provide more information than in the milestone topic.
Please give us a bit more to work with. OS/Java version/how did you upgrade/did the upgrade script succeed without errors…

helmar74 · June 29, 2023, 4:05am

I installed Openhabian v 1.8 new and I restored a Openhab 3.4.4 Backup to this new testsystem.
The restore went well and afterwards OH 4.0.0M3 started

openhabian@oh40test:~ $ cat /etc/os-release
PRETTY_NAME="Raspbian GNU/Linux 11 (bullseye)"
NAME="Raspbian GNU/Linux"
VERSION_ID="11"
VERSION="11 (bullseye)"
VERSION_CODENAME=bullseye
ID=raspbian
ID_LIKE=debian
HOME_URL="http://www.raspbian.org/"
SUPPORT_URL="http://www.raspbian.org/RaspbianForums"
BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs"

Linux oh40test 6.1.21-v8+ #1642 SMP PREEMPT Mon Apr  3 17:24:16 BST 2023 aarch64 GNU/Linux

openjdk 17.0.6 2023-01-17
OpenJDK Runtime Environment (build 17.0.6+10-Raspbian-1deb11u1rpt1)
OpenJDK Client VM (build 17.0.6+10-Raspbian-1deb11u1rpt1, mixed mode, emulated-client)

Do you need further information?

hmerk · June 29, 2023, 6:23am

Thanks and yes, did the jsondb upgrade tool complete without errors ?
If not shure, you can run it manually

java -jar $OPENHAB_RUNTIME/bin/upgradetool.jar

helmar74 · June 29, 2023, 6:35am

Hi,

I tried to run it manually, but it failed

java -jar $OPENHAB_RUNTIME/bin/upgradetool.jar
[main] INFO org.openhab.core.tools.internal.Upgrader - Copying item unit from state description to metadata in database '/var/lib/openhab/jsondb/org.openhab.core.items.Item.json'
[main] ERROR org.openhab.core.tools.internal.Upgrader - Cannot access metadata database '/var/lib/openhab/jsondb/org.openhab.core.items.Metadata.json', check path and access rights.
[main] INFO org.openhab.core.tools.internal.Upgrader - Upgrading JS profile configuration in database '/var/lib/openhab/jsondb/org.openhab.core.thing.link.ItemChannelLink.json'
[main] ERROR org.openhab.core.tools.internal.Upgrader - Cannot access link database '/var/lib/openhab/jsondb/org.openhab.core.thing.link.ItemChannelLink.json', check path and access rights.

hmerk · June 29, 2023, 6:37am

Ok, one step further.
You have an issue with the permissions. Please run fix permissions from openHABian menu and rerun updater.
As you can see, upgrader did not succeed, which can lead to your errors…

helmar74 · June 29, 2023, 6:44am

done this:

Now it worked:

vironment variable ${OPENHAB_USERDATA} or provide a directory through the --dir option.
openhabian@oh40test:~ $ java -jar $OPENHAB_RUNTIME/bin/upgradetool.jar
[main] INFO org.openhab.core.tools.internal.Upgrader - Copying item unit from state description to metadata in database '/var/lib/openhab/jsondb/org.openhab.core.items.Item.json'
[main] INFO org.openhab.core.tools.internal.Upgrader - Upgrading JS profile configuration in database '/var/lib/openhab/jsondb/org.openhab.core.thing.link.ItemChannelLink.json'
[main] INFO org.openhab.core.tools.internal.Upgrader - i_ABFALL_ICAL_MORGEN -> http:url:t_ABFALL_ICAL:ABFALL_ICAL_MORGEN: rewrote JS profile link to new format
[main] INFO org.openhab.core.tools.internal.Upgrader - i_ABFALL_ICAL -> http:url:t_ABFALL_ICAL:ABFALL_ICAL_Heute: rewrote JS profile link to new format

After Restart i got the following errors, when starting karaff shell:

 $OPENHAB_RUNTIME/bin/client -p habopen
Logging in as openhab
Failed to load native library:jansi-2.4.0-500bd36a062e0a61-libjansi.so. osinfo: Linux/arm
java.lang.UnsatisfiedLinkError: /var/lib/openhab/tmp/jansi-2.4.0-500bd36a062e0a61-libjansi.so: /var/lib/openhab/tmp/jansi-2.4.0-500bd36a062e0a61-libjansi.so: cannot open shared object file: No such file or directory

In openhabl.log the error shows up when starting Fritzbox Bundle:

2023-06-29 08:42:32.191 [WARN ] [.thing.internal.CommunicationManager] - No ProfileFactory found which supports profile 'transform:PHONEBOOK' for link 'i_EingehenderCallName -> avmfritz:fritzbox:192_168_1_1:incoming_call'

And still some AVM DECT 200 Wallplugs are in state unknown, some are working:

hmerk · June 29, 2023, 6:51am

This can be ignored for now

You have an issue/error with an old transformation profile configured for the phonebook. As transformations and profiles have changed a bit, this needs to be reconfigured.

Now I start to run out of clues. Could you please set the avm binding to TRACE logging (can be done through UI or console, restart openhab and post the avm binding related log entries.

helmar74 · June 29, 2023, 6:52am

Could you please tell me the command to enable TRACE logging?

hmerk · June 29, 2023, 6:55am

Sure, there are two ways now.

In Main UI → Settings ->Bindings select the avm binding and press the little gear button. you can change the log settings there, default should be INFO.
In openHAB console enter the following command

log:set TRACE org.openhab.binding.avm

helmar74 · June 29, 2023, 7:02am

Thank you

openhab> log:set TRACE org.openhab.binding.avm

Nothing more showed up in openhablog.og

2023-06-29 08:57:59.008 [WARN ] [.thing.internal.CommunicationManager] - No ProfileFactory found which supports profile 'transform:PHONEBOOK' for link 'i_EingehenderCallName -> avmfritz:fritzbox:192_168_1_1:incoming_call'

Tried a restart of Openhab, but this didn’t changed anything.

Also tried to set DEBUG LOGLEVEL, no further output in logfiles.

helmar74 · June 29, 2023, 7:06am

Do you have information, what has to be changed?

hmerk · June 29, 2023, 7:32am

TRACE is the highest log level, so this should give the most information.

hmerk · June 29, 2023, 7:34am

Not really, as I am not using transformations or profiles.
But a search here should give you some more insights.

hmerk · June 29, 2023, 7:38am

One more question, when you remove the unknown thing, does it reappear in the inbox after a while ?

helmar74 · June 29, 2023, 7:39am

Setting LOGLEVEL in console doesn’t worked. I set it in UI now the logs are comming, see attached file

openhablog.log (123.8 KB)

hmerk · June 29, 2023, 7:44am

sorry, command was wrong, needs to be

log:set TRACE org.openhab.binding.avmfritz

helmar74 · June 29, 2023, 7:50am

For me it looks like the things are newly created by the binding as the power channel is missing:

2023-06-29 09:39:25.664 [DEBUG] [nal.hardware.FritzAhaContentExchange] - GET response complete: <devicelist version="1" fwversion="7.56"><device identifier="08761 0004856" id="16" functionbitmask="33664" fwversion="04.25" manufacturer="AVM" productname="FRITZ!DECT 200"><present>1</present><txbusy>0</txbusy><name>Entfeuchter Keller</name><switch><state>0</state><mode>manuell</mode><lock>0</lock><devicelock>0</devicelock></switch><simpleonoff><state>0</state></simpleonoff><powermeter><voltage>228092</voltage><power>0</power><energy>286394</energy></powermeter><temperature><celsius>195</celsius><offset>0</offset></temperature></device><device identifier="08761 0296702" id="17" functionbitmask="35712" fwversion="04.25" manufacturer="AVM" productname="FRITZ!DECT 200"><present>1</present><txbusy>0</txbusy><name>Waschmaschine</name><switch><state>1</state><mode>manuell</mode><lock>0</lock><devicelock>0</devicelock></switch><simpleonoff><state>1</state></simpleonoff><powermeter><voltage>228013</voltage><power>0</power><energy>1649413</energy></powermeter><temperature><celsius>230</celsius><offset>0</offset></temperature></device><device identifier="08761 0296701" id="18" functionbitmask="35712" fwversion="04.25" manufacturer="AVM" productname="FRITZ!DECT 200"><present>1</present><txbusy>0</txbusy><name>Trockner</name><switch><state>1</state><mode>manuell</mode><lock>0</lock><devicelock>0</devicelock></switch><simpleonoff><state>1</state></simpleonoff><powermeter><voltage>230936</voltage><power>0</power><energy>1216393</energy></powermeter><temperature><celsius>230</celsius><offset>0</offset></temperature></device><device identifier="08761 0328309" id="19" functionbitmask="35712" fwversion="04.25" manufacturer="AVM" productname="FRITZ!DECT 200"><present>1</present><txbusy>0</txbusy><name>Heizlüfter Bad</name><switch><state>0</state><mode>manuell</mode><lock>0</lock><devicelock>0</devicelock></switch><simpleonoff><state>0</state></simpleonoff><powermeter><voltage>227882</voltage><power>0</power><energy>819533</energy></powermeter><temperature><celsius>240</celsius><offset>0</offset></temperature></device><device identifier="08761 0393046" id="20" functionbitmask="35712" fwversion="04.25" manufacturer="AVM" productname="FRITZ!DECT 200"><present>1</present><txbusy>0</txbusy><name>Hauswasserwerk</name><switch><state>1</state><mode>manuell</mode><lock>0</lock><devicelock>0</devicelock></switch><simpleonoff><state>1</state></simpleonoff><powermeter><voltage>230899</voltage><power>4220</power><energy>385624</energy></powermeter><temperature><celsius>200</celsius><offset>0</offset></temperature></device><device identifier="11657 0065738" id="21" functionbitmask="35712" fwversion="04.25" manufacturer="AVM" productname="FRITZ!DECT 210"><present>1</present><txbusy>0</txbusy><name>Balkon Süd</name><switch><state>0</state><mode>manuell</mode><lock>0</lock><devicelock>0</devicelock></switch><simpleonoff><state>0</state></simpleonoff><powermeter><voltage>220582</voltage><power>0</power><energy>38297</energy></powermeter><temperature><celsius>345</celsius><offset>0</offset></temperature></device></devicelist>

2023-06-29 09:39:25.665 [TRACE] [are.callbacks.FritzAhaUpdateCallback] - Received State response <devicelist version="1" fwversion="7.56"><device identifier="08761 0004856" id="16" functionbitmask="33664" fwversion="04.25" manufacturer="AVM" productname="FRITZ!DECT 200"><present>1</present><txbusy>0</txbusy><name>Entfeuchter Keller</name><switch><state>0</state><mode>manuell</mode><lock>0</lock><devicelock>0</devicelock></switch><simpleonoff><state>0</state></simpleonoff><powermeter><voltage>228092</voltage><power>0</power><energy>286394</energy></powermeter><temperature><celsius>195</celsius><offset>0</offset></temperature></device><device identifier="08761 0296702" id="17" functionbitmask="35712" fwversion="04.25" manufacturer="AVM" productname="FRITZ!DECT 200"><present>1</present><txbusy>0</txbusy><name>Waschmaschine</name><switch><state>1</state><mode>manuell</mode><lock>0</lock><devicelock>0</devicelock></switch><simpleonoff><state>1</state></simpleonoff><powermeter><voltage>228013</voltage><power>0</power><energy>1649413</energy></powermeter><temperature><celsius>230</celsius><offset>0</offset></temperature></device><device identifier="08761 0296701" id="18" functionbitmask="35712" fwversion="04.25" manufacturer="AVM" productname="FRITZ!DECT 200"><present>1</present><txbusy>0</txbusy><name>Trockner</name><switch><state>1</state><mode>manuell</mode><lock>0</lock><devicelock>0</devicelock></switch><simpleonoff><state>1</state></simpleonoff><powermeter><voltage>230936</voltage><power>0</power><energy>1216393</energy></powermeter><temperature><celsius>230</celsius><offset>0</offset></temperature></device><device identifier="08761 0328309" id="19" functionbitmask="35712" fwversion="04.25" manufacturer="AVM" productname="FRITZ!DECT 200"><present>1</present><txbusy>0</txbusy><name>Heizlüfter Bad</name><switch><state>0</state><mode>manuell</mode><lock>0</lock><devicelock>0</devicelock></switch><simpleonoff><state>0</state></simpleonoff><powermeter><voltage>227882</voltage><power>0</power><energy>819533</energy></powermeter><temperature><celsius>240</celsius><offset>0</offset></temperature></device><device identifier="08761 0393046" id="20" functionbitmask="35712" fwversion="04.25" manufacturer="AVM" productname="FRITZ!DECT 200"><present>1</present><txbusy>0</txbusy><name>Hauswasserwerk</name><switch><state>1</state><mode>manuell</mode><lock>0</lock><devicelock>0</devicelock></switch><simpleonoff><state>1</state></simpleonoff><powermeter><voltage>230899</voltage><power>4220</power><energy>385624</energy></powermeter><temperature><celsius>200</celsius><offset>0</offset></temperature></device><device identifier="11657 0065738" id="21" functionbitmask="35712" fwversion="04.25" manufacturer="AVM" productname="FRITZ!DECT 210"><present>1</present><txbusy>0</txbusy><name>Balkon Süd</name><switch><state>0</state><mode>manuell</mode><lock>0</lock><devicelock>0</devicelock></switch><simpleonoff><state>0</state></simpleonoff><powermeter><voltage>220582</voltage><power>0</power><energy>38297</energy></powermeter><temperature><celsius>345</celsius><offset>0</offset></temperature></device></devicelist>

2023-06-29 09:39:25.671 [DEBUG] [nal.handler.AVMFritzBaseThingHandler] - Update thing 'avmfritz:FRITZ_DECT_200:192_168_1_1:087610328309' with device model: [ain=08761 0328309,bitmask=35712,isHANFUNDevice=false,isHANFUNButton=false,isHANFUNAlarmSensor=false,isButton=false,isSwitchableOutlet=true,isTemperatureSensor=true,isHumiditySensor=false,isPowermeter=true,isDectRepeater=false,isHeatingThermostat=false,hasMicrophone=true,isHANFUNUnit=false,isHANFUNOnOff=true,isDimmableLight=false,isColorLight=false,isHANFUNBlind=false,id=19,manufacturer=AVM,productname=FRITZ!DECT 200,fwversion=04.25,present=1,name=Heizlüfter Bad,battery=null,batterylow=null,[state=0,mode=MANUAL,lock=0,devicelock=0],[state=false],[voltage=227.882,power=0.000,energy=819533],null,[celsius=24.0,offset=0.0],null,null,null,null,[],null]
2023-06-29 09:39:25.673 [DEBUG] [nal.handler.AVMFritzBaseThingHandler] - Channel 'power' in thing 'avmfritz:FRITZ_DECT_200:192_168_1_1:087610328309' does not exist, recreating thing.

But it looks like the recreation of the thing failed for the unknown devices (no power channel present):

I recreated one wall plug manually, the power channel is there, but thing state still unknown:

hmerk · June 29, 2023, 7:53am

That’s why I asked. Please do not recreate manually, wait until it reappears in inbox after deletion.