Please give us some more information, especially some log output would be helpful in order to se the error messages. Without knowing more about the device that causes the problem and the openHAB version you are using it won’t be easy to help you.
Hi Martin,
I have the latest stable 2.3 openhab with the homematic binding in 2.3
I don’t have any error message besides this (they occur every 2 minutes):
2018-10-14 00:57:48.241 [WARN ] [ematic.handler.HomematicThingHandler] - Channel not found for datapoint 'MEQ0792935:0#RSSI_DEVICE'
2018-10-14 00:57:48.246 [WARN ] [ematic.handler.HomematicThingHandler] - Channel not found for datapoint 'MEQ0792935:0#RSSI'
2018-10-14 00:57:48.250 [WARN ] [ematic.handler.HomematicThingHandler] - Channel not found for datapoint 'MEQ0792935:0#SIGNAL_STRENGTH'
2018-10-14 00:57:48.258 [WARN ] [ematic.handler.HomematicThingHandler] - Channel not found for datapoint 'MEQ0792935:0#LOWBAT'
2018-10-14 00:57:48.268 [WARN ] [ematic.handler.HomematicThingHandler] - Channel not found for datapoint 'MEQ0792935:4#ACTUAL_TEMPERATURE'
2018-10-14 00:57:48.273 [WARN ] [ematic.handler.HomematicThingHandler] - Channel not found for datapoint 'MEQ0792935:4#BATTERY_STATE'
2018-10-14 00:57:48.279 [WARN ] [ematic.handler.HomematicThingHandler] - Channel not found for datapoint 'MEQ0792935:4#BOOST_STATE'
2018-10-14 00:57:48.284 [WARN ] [ematic.handler.HomematicThingHandler] - Channel not found for datapoint 'MEQ0792935:4#CONTROL_MODE'
2018-10-14 00:57:48.290 [WARN ] [ematic.handler.HomematicThingHandler] - Channel not found for datapoint 'MEQ0792935:4#FAULT_REPORTING'
2018-10-14 00:57:48.296 [WARN ] [ematic.handler.HomematicThingHandler] - Channel not found for datapoint 'MEQ0792935:4#PARTY_START_TIME'
2018-10-14 00:57:48.302 [WARN ] [ematic.handler.HomematicThingHandler] - Channel not found for datapoint 'MEQ0792935:4#SET_TEMPERATURE'
2018-10-14 00:57:48.307 [WARN ] [ematic.handler.HomematicThingHandler] - Channel not found for datapoint 'MEQ0792935:4#VALVE_STATE'
After a restart it might work or any other of my homematic devices might have the same problem. If the problem occures I cannot receive any data from it or send commands to it.
Is there anything I can lookup to help you to find the error?
Looking at the datapoint names it seems that it is a thermostat device. What kind of Homematic device it is? A normal one or a Homematic IP device?
Where did you define the bridge and things? In Paper UI or in text format? There are some special requirements regarding Homegear.
It is defined in a things file as follows:
Thing HG-HM-CC-RT-DN MEQ0792934
I don’t use the Paper UI for this. It is a normal non IP device.
I have to the same device and it works without any problems. But I am using Raspberrymatic instead of Homegear.
Maybe @gerrieg has an idea.
It’s not the device not working, it’s just some devices are sometimes not correctly initialized.
I have 15 HM-CC-RT-DN Thermostats and 10 HM-TC-WM-W-EU Wall Thermostats. Almost every restart, up to three devices are not being initialized with the correct channels. Always different devices.
So, looking at the devices itself will not help, it is the initialization which is not working correctly all the time.
The problem occurs mostly with these thermostats, maybe because these have this massive amount of configuration parameters. But i have also seen this with HM-Sec-SCO door/window contacts. (Also not a single one.)
The single thing which helped a bit is delaying the rule engine on startup like i described there:
But the problem is still there, it is just no longer that visible as it used to be.
I know that this problem exists, but I have no solution.
The Homematic binding is special in that it loads all devices from the gateway and generates all openHab metadata at startup. This ensures that new devices are ready for use immediately without having to manually create hundreds of metadata entries for each device.
I think it’s a timing problem at startup, either in the binding or in the framework. I can’t reproduce it in the development environment. I’ve checked the code several times, the device is not initialized until all metadata has been added to openHab.
Without reproducibility in the development environment this will be hard to find.
@gerrieg, could you name some logger to put in trace mode to find more information about this problem?
I am unable to put the whole binding in trace, as soon as i do that, the pi slows down too much.
To narrow this down, please try this:
Set these loglevels in the karaf console
log:set DEBUG org.eclipse.smarthome.binding.homematic
log:set TRACE org.eclipse.smarthome.binding.homematic.internal.communicator.AbstractHomematicGateway
and then do a restart.
In the logfile, there is now a trace for each device that starts with ‘Generating ThingType for device …’ with all the channels and datapoints beeing loaded from the gateway and generated for openHab.
If you have a device with the ‘Channel not found …’ warning, check if the datapoint is in the logfile for that device.
- If not, the gateway does not send the datapoint metadata via api, but sends events.
- if yes, check what openHab knows about that device. Open this rest url and check the result if the datapoint is available for that device:
http://[OPENHAB_URL:OPENHAB_PORT]/rest/things/{thingUID}- if not, there is a problem generating the metadata
- if yes, there is another problem
1 Like
Thank you.
I set the log level and restarted.
So far it looks good (or bad, depending on view). No “Channel not found for datapoint”. I let it run for a few hours.
I’m seeing the same error for couple of my homematic sensors (connected to an up-to-date CCU2). One of them is a HM-Sec-SCo working smoothly at the CCU2 but resulting in “Channel not found for datapoint” when its state changes.
I changed the loggers according to @gerrieg last post.
“Generating ThingType for device …” only happens as follows:
(HM-Sec-SCo is not mentioned)
2018-10-24 12:07:53.185 [DEBUG] [rnal.type.HomematicTypeGeneratorImpl] - Generating ThingType for device 'HmIP-STH' with 1167 datapoints
2018-10-24 12:07:56.060 [DEBUG] [rnal.type.HomematicTypeGeneratorImpl] - Generating ThingType for device 'HmIP-WRC6' with 68 datapoints
2018-10-24 12:07:59.459 [DEBUG] [rnal.type.HomematicTypeGeneratorImpl] - Generating ThingType for device 'HMIP-PSM' with 442 datapoints
2018-10-24 12:08:07.016 [DEBUG] [rnal.type.HomematicTypeGeneratorImpl] - Generating ThingType for device 'HM-LC-Bl1-SM' with 389 datapoints
2018-10-24 12:08:07.188 [DEBUG] [rnal.type.HomematicTypeGeneratorImpl] - Generating ThingType for device 'GATEWAY-EXTRAS-CCU' with 10 datapoints
The log for the not working sensor during restart and after the first status change looks like this:
2018-10-24 12:08:07.465 [hingStatusInfoChangedEvent] - 'homematic:HM-Sec-SCo:ccu:MEQ0184635' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING
2018-10-24 12:08:07.621 [DEBUG] [ommunicator.AbstractHomematicGateway] - Received new (Integer) value '0' for 'MEQ0184635:0#RSSI_DEVICE' from gateway with id 'ccu'
2018-10-24 12:08:07.624 [DEBUG] [ommunicator.AbstractHomematicGateway] - Received new (Integer) value '-36' for 'MEQ0184635:0#RSSI_PEER' from gateway with id 'ccu'
2018-10-24 12:08:15.583 [DEBUG] [ommunicator.AbstractHomematicGateway] - Loading values for channel HmChannel[number=0,type=MAINTENANCE,initialized=false] of device 'MEQ0184635'
2018-10-24 12:08:15.748 [DEBUG] [ematic.handler.HomematicThingHandler] - Initializing thing 'homematic:HM-Sec-SCo:ccu:MEQ0184635' from gateway 'ccu'
2018-10-24 12:08:15.749 [DEBUG] [ommunicator.AbstractHomematicGateway] - Loading values for channel HmChannel[number=-1,type=HM-Sec-SCo,initialized=false] of device 'MEQ0184635'
2018-10-24 12:08:15.751 [hingStatusInfoChangedEvent] - 'homematic:HM-Sec-SCo:ccu:MEQ0184635' changed from INITIALIZING to ONLINE
2018-10-24 12:08:15.756 [DEBUG] [ommunicator.AbstractHomematicGateway] - Loading values for channel HmChannel[number=1,type=SHUTTER_CONTACT,initialized=false] of device 'MEQ0184635'
2018-10-24 12:08:16.484 [me.event.ThingUpdatedEvent] - Thing 'homematic:HM-Sec-SCo:ccu:MEQ0184635' has been updated.
2018-10-24 12:12:19.859 [DEBUG] [ommunicator.AbstractHomematicGateway] - Received new (Boolean) value 'true' for 'MEQ0184635:1#STATE' from gateway with id 'ccu'
2018-10-24 12:12:19.861 [WARN ] [ematic.handler.HomematicThingHandler] - Channel not found for datapoint 'MEQ0184635:1#STATE'
2018-10-24 12:12:19.864 [DEBUG] [ommunicator.AbstractHomematicGateway] - Received new (Boolean) value 'false' for 'MEQ0184635:1#LOWBAT' from gateway with id 'ccu'
2018-10-24 12:12:19.866 [WARN ] [ematic.handler.HomematicThingHandler] - Channel not found for datapoint 'MEQ0184635:1#LOWBAT'
2018-10-24 12:12:25.000 [DEBUG] [ommunicator.AbstractHomematicGateway] - Received new (Boolean) value 'false' for 'MEQ0184635:1#STATE' from gateway with id 'ccu'
2018-10-24 12:12:25.004 [WARN ] [ematic.handler.HomematicThingHandler] - Channel not found for datapoint 'MEQ0184635:1#STATE'
2018-10-24 12:12:25.008 [DEBUG] [ommunicator.AbstractHomematicGateway] - Received new (Boolean) value 'false' for 'MEQ0184635:1#LOWBAT' from gateway with id 'ccu'
2018-10-24 12:12:25.012 [WARN ] [ematic.handler.HomematicThingHandler] - Channel not found for datapoint 'MEQ0184635:1#LOWBAT'
And here’s what the rest-call returns:
{"status":"UNINITIALIZED","statusDetail":"BRIDGE_UNINITIALIZED"},"editable":true,"label":"EG_WOHNZIMMER_KONTAKT_TERRASSE","bridgeUID":"homematic:bridge:LEQ0395803","configuration":{"HMP_-1_CYCLIC_INFO_MSG":true,"HMP_1_EVENT_DELAYTIME":0.0,"HMP_-1_TRANSMIT_DEV_TRY_MAX":6,"HMP_1_TRANSMIT_TRY_MAX":6,"HMP_1_AES_ACTIVE":true,"HMP_-1_SABOTAGE_MSG":true,"HMP_-1_LOCAL_RESET_DISABLE":false,"HMP_1_MSG_FOR_POS_B":"OPEN","HMP_1_MSG_FOR_POS_A":"CLOSED"},"properties":{"serialNumber":"MEQ0184635","modelId":"HM-Sec-SCo","vendor":"eQ-3 AG","aesKey":"0","firmwareVersion":"1.0","batteryType":"1x AAA/Micro/LR03"},"UID":"homematic:HM-Sec-SCo:LEQ0395803:MEQ0184635","thingTypeUID":"homematic:HM-Sec-SCo","channels":[]}
Is there anything I can do?
Thanks
Mirko
@Mirko_Gerke
What i see is a wrong bridgeUID for this device: homematic:bridge:LEQ0395803. This should be homematic:bridge:ccu
Do you use things files or PaperUI?
After a week i did not find a single channel not found for datapoint warning in my logs.
The only change i did, was setting the log level as @gerrieg suggested. I am using things and items files. This is according to my opinion a clear indication that this is a timing problem and no general problem.
I will now set the binding back to warn level, but keep the abstract gateway at trace and restart.
I have the same issue every once in a while and am trying to debug as well.
If you @gerrieg have a few minutes to explain that’d be great.
I see that the issue is that getChannel returns null which is the case because my devices don’t have any channels at all (as also seen in the log examples above). So I’m trying to see where setChannels in ThingImpl is being set.
I assumed that the doInitializeInBackground method in HomematicThingHandler is responsible for that but I have not yet seen that in any stack trace at all.
Instead I see it being called from GenericThingProvider (lazyRetryRunnable) but I don’t know where that comes from.
Now to my question: I’d like to add some more debugging to the homematic binding and I was able to build the smarthome project using Maven. Unfortunately I have no idea at all how to now use my new snapshot build. Can anyone give me any hints on how to deploy which files in which way?
Copy the new jar to the addons folder. Then, in the Karaf console write
bundle:list | grep Homematic
You should see 2 Versions of the binding and one active. For the next commands, use the ID.
bundle:stop ID_OLD_VERSION
bundle:uninstall ID_OLD_VERSION
bundle:start ID_NEW_VERSION
Then restart openHab.
Hello Gerhard, I’m running OpenHab 2.2 with homematic binding to a RaspBerryMatic. Some days ago I updated my RaspBerryMatic from a quite old version to the latest version. Since that day I get a lot of error messages “Channel not found for datapoint …” in my openhab.log. How can I solve the problem? Is there a new or updated homematic binding available that I can install to eleminate these error messages? If yes, where can I get it from and how to perform the update process? Or is there another workaround that you can propose to me? Thank you very much in advance for your help.
Unfortunately since my upgrade to version 2.4 I experience this error very often. I have to restart OH multiple times to get my setup in a working state. Does it help to provide debug logs? I’m using a RPi3 and docker on Raspbian Stretch
I am encountering this issue quite frequently on my setup, and while I am sadly not available at this moment to help debug this further, I hope the following details may help someone to get a more stable repro (in my case, the issue manifests itself every 2-3 days).
I am running: OH 2.4.0(stable) + Homegear 0.7.34-2678 on an Odroid C1 with an almost-read-only setup (all the logging and most part of configuration redirected to ramfs). This means I use quite a few logrotate scripts (triggering on log size) which also do:
- reload Homegear service after its logs rotation,
/var/log/homegear/*.log /var/log/homegear/*.err { missingok rotate 1 compress delaycompress notifempty size 1M create 644 homegear homegear sharedscripts postrotate service homegear reload > /dev/null endscript } - restart Openhab after its logs rotation
/opt/openhab2/userdata/logs/*.log { missingok rotate 1 compress delaycompress notifempty size 1M create 640 openhab openhab sharedscripts postrotate service openhab2 restart > /dev/null endscript }
Quite frequently, I get either of the 2 error conditions:
- some Homematic things end up in
UNITIALIZED (BRIDGE_UNINTIALIZED)state, while others using the same bridge areONLINE(the bridge also is). - all the things seem to be
ONLINE, though no actual data is received, and the log is flooded byChannel not found for datapointerrors
Condition #2 is more nasty, as it is not detectible from the UI, and only visible in the logs (or when items start lingering in a stale state for a while).
This started happening to me after migration from OH 2.3, but I changed quite a lot of things in my setup, so multiple conditions may have caused it.
Workaround that brings my system back to life is touching the .things file (I even have a rule for it 
).
–
All in all, to a naked eye this appears to be a timing issue indeed. If getting a stable repro is of issue, I hope trying to loop-reload Homegear while OH is running may help trace it.
Will try to collect more useful info once I find some time for it.
1 Like
I’m seeing the exact same behavior as @mbronk. I can also confirm that touching my homematic.things file seems to help. Sometimes I need to do it twice.
One additional detail that might help in our investigation: For me this only happens for my HomeMatic IP devices. Regular devices seem never to be affected.