Homegear events missing in OpenHAB

Hi,

we’re using the Homematic binding with homegear. We’ve noticed that sometimes events generated by Homematic components are received by homegear, but ignored by OpenHAB 2.

A PRESS_LONG event is linked to a switch named “tor_ta_freigabe”.

In this example the PRESS_LONG event at 20:54:00 has not been processed by OpenHAB, but the event at 20:55:32 has been processed. It’s not reproducible; most of the time it works, but sometime it doesn’t.

Please have a look at the following logs:

  • Homegear:

06/19/17 20:54:00.353 Module HomeMatic BidCoS: Info: PRESS_LONG on channel 1 of HomeMatic BidCoS peer 3 with serial number OEQ0176016 was set to 0x13.
06/19/17 20:54:00.625 Module HomeMatic BidCoS: Info: Ignoring PRESS_LONG.
06/19/17 20:54:00.898 Module HomeMatic BidCoS: Info: Ignoring PRESS_LONG.
06/19/17 20:54:01.171 Module HomeMatic BidCoS: Info: Ignoring PRESS_LONG.
06/19/17 20:54:01.444 Module HomeMatic BidCoS: Info: Ignoring PRESS_LONG.
06/19/17 20:54:01.716 Module HomeMatic BidCoS: Info: Ignoring PRESS_LONG.
06/19/17 20:54:01.989 Module HomeMatic BidCoS: Info: Ignoring PRESS_LONG.
06/19/17 20:54:02.262 Module HomeMatic BidCoS: Info: Ignoring PRESS_LONG.
06/19/17 20:54:02.535 Module HomeMatic BidCoS: Info: Ignoring PRESS_LONG.
06/19/17 20:54:02.535 Module HomeMatic BidCoS: Info: PRESS_LONG_RELEASE on channel 1 of HomeMatic BidCoS peer 3 with serial number OEQ0176016 was set to 0x13.
06/19/17 20:55:32.829 Module HomeMatic BidCoS: Info: PRESS_LONG on channel 1 of HomeMatic BidCoS peer 3 with serial number OEQ0176016 was set to 0x14.
06/19/17 20:55:33.101 Module HomeMatic BidCoS: Info: Ignoring PRESS_LONG.
06/19/17 20:55:33.374 Module HomeMatic BidCoS: Info: Ignoring PRESS_LONG.
06/19/17 20:55:33.647 Module HomeMatic BidCoS: Info: Ignoring PRESS_LONG.
06/19/17 20:55:33.920 Module HomeMatic BidCoS: Info: Ignoring PRESS_LONG.
06/19/17 20:55:34.193 Module HomeMatic BidCoS: Info: Ignoring PRESS_LONG.
06/19/17 20:55:34.466 Module HomeMatic BidCoS: Info: Ignoring PRESS_LONG.
06/19/17 20:55:34.739 Module HomeMatic BidCoS: Info: Ignoring PRESS_LONG.
06/19/17 20:55:35.012 Module HomeMatic BidCoS: Info: Ignoring PRESS_LONG.
06/19/17 20:55:35.012 Module HomeMatic BidCoS: Info: PRESS_LONG_RELEASE on channel 1 of HomeMatic BidCoS peer 3 with serial number OEQ0176016 was set to 0x14.

  • OpenHAB:

2017-06-19 20:54:56.228 [ThingUpdatedEvent ] - Thing ‘homematic:GATEWAY-EXTRAS-11ADD6BF:11add6bf:GWE00000000’ has been updated.
2017-06-19 20:54:56.363 [ThingUpdatedEvent ] - Thing ‘homematic:HG-HM-MOD-EM-8:11add6bf:OEQ0176016’ has been updated.
2017-06-19 20:54:56.450 [ThingUpdatedEvent ] - Thing ‘homematic:HG-HM-Sec-Key-S:11add6bf:NEQ0682619’ has been updated.
2017-06-19 20:54:56.605 [ThingUpdatedEvent ] - Thing ‘homematic:HG-HM-RC-Key4-2:11add6bf:NEQ0683927’ has been updated.
2017-06-19 20:55:32.850 [ItemStateChangedEvent ] - tor_ta_freigabe changed from OFF to ON
2017-06-19 20:55:32.877 [ItemCommandEvent ] - Item ‘gl_vsw_freigabe_steuerung’ received command ON
2017-06-19 20:55:32.884 [ItemStateChangedEvent ] - gl_vsw_freigabe_steuerung changed from OFF to ON
2017-06-19 20:55:34.847 [ItemStateChangedEvent ] - tor_ta_freigabe changed from ON to OFF
2017-06-19 20:57:33.215 [ItemCommandEvent ] - Item ‘gl_vsw_freigabe_steuerung’ received command OFF
2017-06-19 20:57:33.227 [ItemStateChangedEvent ] - gl_vsw_freigabe_steuerung changed from ON to OFF
2017-06-19 21:00:56.634 [ThingUpdatedEvent ] - Thing ‘homematic:GATEWAY-EXTRAS-11ADD6BF:11add6bf:GWE00000000’ has been updated.
2017-06-19 21:00:56.840 [ThingUpdatedEvent ] - Thing ‘homematic:HG-HM-MOD-EM-8:11add6bf:OEQ0176016’ has been updated.
2017-06-19 21:00:56.936 [ThingUpdatedEvent ] - Thing ‘homematic:HG-HM-Sec-Key-S:11add6bf:NEQ0682619’ has been updated.
2017-06-19 21:00:57.089 [ThingUpdatedEvent ] - Thing ‘homematic:HG-HM-RC-Key4-2:11add6bf:NEQ0683927’ has been updated.

Any idea what’s going wrong here?

Your log excerpt seems to start at 2017-06-19 20:54:56.228. The missing event might have been logged earlier?

You could enable the DEBUG (or even TRACE) log mode. Then we can see more details about the received messages.

No, unfortunately not:

2017-06-19 20:50:55.227 [ThingUpdatedEvent ] - Thing ‘homematic:GATEWAY-EXTRAS-11ADD6BF:11add6bf:GWE00000000’ has been updated.
2017-06-19 20:50:55.440 [ThingUpdatedEvent ] - Thing ‘homematic:HG-HM-MOD-EM-8:11add6bf:OEQ0176016’ has been updated.
2017-06-19 20:50:55.538 [ThingUpdatedEvent ] - Thing ‘homematic:HG-HM-Sec-Key-S:11add6bf:NEQ0682619’ has been updated.
2017-06-19 20:50:55.690 [ThingUpdatedEvent ] - Thing ‘homematic:HG-HM-RC-Key4-2:11add6bf:NEQ0683927’ has been updated.
2017-06-19 20:52:55.747 [ThingUpdatedEvent ] - Thing ‘homematic:GATEWAY-EXTRAS-11ADD6BF:11add6bf:GWE00000000’ has been updated.
2017-06-19 20:52:55.914 [ThingUpdatedEvent ] - Thing ‘homematic:HG-HM-MOD-EM-8:11add6bf:OEQ0176016’ has been updated.
2017-06-19 20:52:56.003 [ThingUpdatedEvent ] - Thing ‘homematic:HG-HM-Sec-Key-S:11add6bf:NEQ0682619’ has been updated.
2017-06-19 20:52:56.165 [ThingUpdatedEvent ] - Thing ‘homematic:HG-HM-RC-Key4-2:11add6bf:NEQ0683927’ has been updated.
2017-06-19 20:54:56.228 [ThingUpdatedEvent ] - Thing ‘homematic:GATEWAY-EXTRAS-11ADD6BF:11add6bf:GWE00000000’ has been updated.
2017-06-19 20:54:56.363 [ThingUpdatedEvent ] - Thing ‘homematic:HG-HM-MOD-EM-8:11add6bf:OEQ0176016’ has been updated.
2017-06-19 20:54:56.450 [ThingUpdatedEvent ] - Thing ‘homematic:HG-HM-Sec-Key-S:11add6bf:NEQ0682619’ has been updated.
2017-06-19 20:54:56.605 [ThingUpdatedEvent ] - Thing ‘homematic:HG-HM-RC-Key4-2:11add6bf:NEQ0683927’ has been updated.
2017-06-19 20:55:32.850 [ItemStateChangedEvent ] - tor_ta_freigabe changed from OFF to ON
2017-06-19 20:55:32.877 [ItemCommandEvent ] - Item ‘gl_vsw_freigabe_steuerung’ received command ON
2017-06-19 20:55:32.884 [ItemStateChangedEvent ] - gl_vsw_freigabe_steuerung changed from OFF to ON
2017-06-19 20:55:34.847 [ItemStateChangedEvent ] - tor_ta_freigabe changed from ON to OFF
2017-06-19 20:57:33.215 [ItemCommandEvent ] - Item ‘gl_vsw_freigabe_steuerung’ received command OFF
2017-06-19 20:57:33.227 [ItemStateChangedEvent ] - gl_vsw_freigabe_steuerung changed from ON to OFF

Thanks, I’ll try that and post a more complete log as soon as I’ve been able to reproduce this issue once more.