Problem with fresh Openhab 2.5 / Zigbee / Bitronvideo Ember Dongle / Device Pairing

Ok, I’ve bought some of the Muller lights so I’ll have a look at them once they arrive.

1 Like

I upgraded my Ubuntu 19.10 VM to OpenHab 2.5.1. Here is a log the following actions:

  • Reset tint color+white light bulb (00158D0001FDF3BD).
  • Start OpenHab 2.5.1 service.
  • Add BV dongle as a thing.
  • Start ZigBee discovery.
  • Switch on tint color+white light bulb (00158D0001FDF3BD). The bulb starts in pairing mode.
  • The bulb appears in the inbox.
  • Add bulb as a thing.
  • Wait a little until the thing status turns to ONLINE.
  • At this point, the bulb itself still doesn’t signal successful pairing. It stays in a dimmed mode like it is waiting for something.
  • I try to modify the lamp colors via the control panel in Paper UI. The values change in Paper UI, but the lamp does not respond.

openhab_2.5.1.log (422.6 KB)

I hope this new log is of any help. Thank you.

Yesterday I updated openhab to version 2.5.1 stable.
Since the update my aqara sensors are not working any longer, but other zigbee devices are working fine.
I haven’t tried to re-discover the devices yet.
Please can somebody give some advice how to solve the problem.

Openhab is running on PI4 with Openhabian image.
CC2531 Dongle is used.

The log level is not set to debug yet, but I can see the following entries in the log file:

2020-01-14 21:35:03.373 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - 00158D0004116DF3: Starting ZigBee device discovery
2020-01-14 21:35:03.384 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - 00158D000388E493: Starting ZigBee device discovery
2020-01-14 21:35:03.402 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - 00158D00041105F6: Starting ZigBee device discovery
2020-01-14 21:35:03.407 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - 00158D000342BF4D: Starting ZigBee device discovery
…
2020-01-14 21:35:14.574 [WARN ] [ding.zigbee.handler.ZigBeeSerialPort] - Processing DATA_AVAILABLE event: Serial buffer overrun
2020-01-14 21:35:14.575 [WARN ] [ding.zigbee.handler.ZigBeeSerialPort] - Processing DATA_AVAILABLE event: Serial buffer overrun
2020-01-14 21:35:14.575 [WARN ] [ding.zigbee.handler.ZigBeeSerialPort] - Processing DATA_AVAILABLE event: Serial buffer overrun
…
2020-01-14 21:36:36.783 [ERROR] [converter.ZigBeeConverterSwitchLevel] - 00158D000388E493: Error opening device level controls
2020-01-14 21:36:36.785 [INFO ] [ng.zigbee.handler.ZigBeeThingHandler] - 00158D000388E493: Channel zigbee:device:stick1:00158d000388e493:00158D000388E493_1_dimmer failed to initialise device
2020-01-14 21:36:42.812 [ERROR] [converter.ZigBeeConverterSwitchLevel] - 00158D000342BF4D: Error opening device level controls
2020-01-14 21:36:42.814 [INFO ] [ng.zigbee.handler.ZigBeeThingHandler] - 00158D000342BF4D: Channel zigbee:device:stick1:00158d000342bf4d:00158D000342BF4D_1_dimmer failed to initialise device
2020-01-14 21:36:52.901 [ERROR] [531.network.packet.ZToolPacketStream] - Packet parsing failed due to exception.
com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolParseException: Packet checksum failed
at com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolPacketStream.parsePacket(ZToolPacketStream.java:141) [bundleFile:?]
at com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolPacketParser.run(ZToolPacketParser.java:107) [bundleFile:?]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_222]
2020-01-14 21:36:52.910 [ERROR] [531.network.packet.ZToolPacketStream] - Packet parsing failed due to exception.
com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolParseException: Packet checksum failed
at com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolPacketStream.parsePacket(ZToolPacketStream.java:141) [bundleFile:?]
at com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolPacketParser.run(ZToolPacketParser.java:107) [bundleFile:?]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_222]
2020-01-14 21:36:52.917 [ERROR] [531.network.packet.ZToolPacketStream] - Packet parsing failed due to exception.
com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolParseException: Packet checksum failed
at com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolPacketStream.parsePacket(ZToolPacketStream.java:141) [bundleFile:?]
at com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolPacketParser.run(ZToolPacketParser.java:107) [bundleFile:?]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_222]
…
2020-01-14 21:37:19.745 [WARN ] [ding.zigbee.handler.ZigBeeSerialPort] - Processing DATA_AVAILABLE event: Serial buffer overrun
2020-01-14 21:37:19.748 [WARN ] [ding.zigbee.handler.ZigBeeSerialPort] - Processing DATA_AVAILABLE event: Serial buffer overrun
2020-01-14 21:37:19.750 [WARN ] [ding.zigbee.handler.ZigBeeSerialPort] - Processing DATA_AVAILABLE event: Serial buffer overrun
2020-01-14 21:37:26.186 [ERROR] [531.network.packet.ZToolPacketStream] - Packet parsing failed due to exception.
com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolParseException: Packet checksum failed
at com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolPacketStream.parsePacket(ZToolPacketStream.java:141) [bundleFile:?]
at com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolPacketParser.run(ZToolPacketParser.java:107) [bundleFile:?]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_222]

Without a debug log it’s not really possible to say what’s happening - I can say that the binding hasn’t found some information it needs so we get the “failed opening device control” error, and there is a packet checksum failure which probably indicates an error in the reception of a frame on the serial port.

I can’t really comment much more than this.

I would recommend you to open a separate thread, as this topic is about different hardware and a different problem.

Based on advice I’ve created a separate thread.

Yesterday, I did another attempt with openhabian 1.4 / Openhab 2.5.1.

It wasn’t a 100% fresh install as I started with fresh 2.5 M2 to include two spirit zigbee thermostats and then upgraded to 2.5.1. Though zigbee was the only binding installed, this ended up with new errors (“Error reading from serial port”, “Adding local node to network: NWK unknown”) after upgrading from fresh 2.5 M2 to 2.5.1.

Finally I decided to give up on this issue, at least for the next months until things are stabilized. I already spent too many hours on this :smiley:

I installed 2.5 M2 again - and as expected, everything just works.

Hello Martin,
just for my curiosity: Did you delete the userdata/cache and userdata/tmp folder after the upgrade to 2.5.1? I had strange issue with knx reconnects/OutOfMemory errors and the “serial connection errors”. After doing a openHAB shutdown, deleting userdata/cache and userdata/tmp and restart of openHAB, my system is now running for two days with 2.5.1 and a Telegesis dongle without an issue. (Currently I’m happy. :slight_smile: )

Thank you for asking. Yes, I used the built-in function “sudo openhab-cli clean-chache”, but this didn’t help.

I’ve checked out the ZBT-ExtendedColor and ZBT-ColorTemperature bulbs and they both seem to work fine.

I started with zigbee in OH 2.5 with the HUSBZB-1 stick. Have not been able tot get the smart things sensor to pair correctly. Can get a bulb to pair correctly. Here is my log from when the paring ran.

2020-01-15 06:11:34.718 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 286D9700010C5DFC: Discovery: Starting discovery for existing device

2020-01-15 06:11:34.740 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - B0CE1814035644AF: Discovery: Starting discovery for existing device

2020-01-15 06:11:34.740 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - Starting ZigBee scan for zigbee:coordinator_ember:93b31b85

2020-01-15 06:11:34.750 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - 286D9700010C5DFC: Starting ZigBee device discovery

2020-01-15 06:11:34.751 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 286D9700010C5DFC: Creating ZigBee device zigbee:device with bridge zigbee:coordinator_ember:93b31b85

2020-01-15 06:11:34.751 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - B0CE1814035644AF: Starting ZigBee device discovery

2020-01-15 06:11:34.752 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - B0CE1814035644AF: Creating ZigBee device zigbee:device with bridge zigbee:coordinator_ember:93b31b85

2020-01-15 06:11:34.754 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - B0CE1814035644AF: ZigBee node property discovery start

==> /var/log/openhab2/events.log <==

2020-01-15 06:11:34.755 [home.event.InboxAddedEvent] - Discovery Result with UID 'zigbee:device:93b31b85:286d9700010c5dfc' has been added.

==> /var/log/openhab2/openhab.log <==

2020-01-15 06:11:34.756 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zigbee:device:93b31b85:286d9700010c5dfc' to inbox.

2020-01-15 06:11:34.757 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 286D9700010C5DFC: ZigBee node property discovery start

2020-01-15 06:11:34.757 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - B0CE1814035644AF: ZigBee node property discovery using basic cluster on endpoint 406F/1

2020-01-15 06:11:34.760 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 286D9700010C5DFC: ZigBee node property discovery using basic cluster on endpoint 928D/1

2020-01-15 06:11:34.809 [DEBUG] [converter.ZigBeeConverterSwitchLevel] - B0CE1814035644AF: ZigBee attribute reports ZclAttribute [cluster=Level Control, id=0, name=Current Level, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=254, lastReportTime=Tue Jan 14 06:11:34 CST 2020, implemented=true]

2020-01-15 06:11:34.912 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - B0CE1814035644AF: Date code failed

2020-01-15 06:11:34.913 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - B0CE1814035644AF: ZigBee node property discovery using OTA cluster on endpoint 406F/1

2020-01-15 06:11:34.913 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - B0CE1814035644AF: ZigBee node property discovery complete: {zigbee_logicaltype=END_DEVICE, zigbee_powerlevel=FULL, zigbee_manufacturercode=0x1160, modelId=E11-G13, zigbee_networkaddress=16495, zigbee_powersource=MAINS, zigbee_stkversion=0, zigbee_zclversion=1, vendor=sengled, zigbee_powermode=RECEIVER_ON_IDLE, zigbee_powersources=[MAINS], hardwareVersion=1, firmwareVersion=0x00000009, zigbee_applicationVersion=1}

2020-01-15 06:11:34.914 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - B0CE1814035644AF: Update ZigBee device zigbee:device with bridge zigbee:coordinator_ember:93b31b85, label 'sengled E11-G13'

2020-01-15 06:11:35.226 [DEBUG] [ding.zigbee.internal.ZigBeeDataStore] - B0CE1814035644AF: ZigBee saving network state complete.

2020-01-15 06:11:51.552 [DEBUG] [converter.ZigBeeConverterSwitchLevel] - B0CE1814035644AF: ZigBee attribute reports ZclAttribute [cluster=Level Control, id=0, name=Current Level, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=254, lastReportTime=Tue Jan 14 06:11:51 CST 2020, implemented=true]

2020-01-15 06:11:58.762 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 286D9700010C5DFC: Manufacturer request failed

2020-01-15 06:12:10.763 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 286D9700010C5DFC: Model request failed

2020-01-15 06:12:22.765 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 286D9700010C5DFC: Hardware version failed

2020-01-15 06:12:34.767 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 286D9700010C5DFC: Application version failed

2020-01-15 06:12:46.768 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 286D9700010C5DFC: Stack version failed

2020-01-15 06:12:58.769 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 286D9700010C5DFC: ZCL version failed

2020-01-15 06:13:10.771 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 286D9700010C5DFC: Date code failed

2020-01-15 06:13:10.772 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 286D9700010C5DFC: ZigBee node property discovery using OTA cluster on endpoint 928D/1

2020-01-15 06:13:22.773 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 286D9700010C5DFC: Could not get OTA firmware version from device

2020-01-15 06:13:22.774 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 286D9700010C5DFC: ZigBee node property discovery complete: {zigbee_logicaltype=END_DEVICE, zigbee_powerlevel=FULL, zigbee_manufacturercode=0x1241, zigbee_networkaddress=37517, zigbee_powermode=RECEIVER_ON_IDLE, zigbee_powersources=[MAINS], zigbee_powersource=MAINS}

2020-01-15 06:13:23.035 [DEBUG] [ding.zigbee.internal.ZigBeeDataStore] - 286D9700010C5DFC: ZigBee saving network state complete.

This is possibly due to the device sleeping.

I am rather confident that this whole issue is related to the system OpenHab is running on. What system are you using for testing? If Linux: which distribution (version), kernel (version) and hardware are you using?

I am running into that issue on fresh installs of OpenHabian 1.5 on RPi 3B and 0w and Ubuntu 19.10 x86_64 VM. I would need to check kernel versions, though (maybe not relevant, but who knows).

Anything I can do in the mean time?

Really? Why is that do you think? Personally, I think that’s really unlikely.

I use a Mac for testing but this should make no difference at all. We have just certified (ie ZigBee alliance certification) a system running on a Pi type computer - all with the same Ember chipset (well, different chipset, but the same firmware and driver etc).

This device is also used by Qivicon - I forget if I mentioned, but I wrote this for them, and they are using this regularly with the HB2 hardware which again is similar to a Pi.

OpenHAB is pretty much hardware agnostic so I’m really surprised that you think this is caused by the host - in my experience, that’s pretty unlikely.

Kept opening and closing the contact sensor until it gave it a name in discovery.
Added it as a thing and now it has the error “OFFLINE - HANDLER_INITIALIZING_ERROR”

This is the log when I added it as a thing.

2020-01-15 20:34:54.131 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 286D9700010C5DFC: Initializing ZigBee thing handler zigbee:device:93b31b85:286d9700010c5dfc

==> /var/log/openhab2/events.log <==

2020-01-15 20:34:54.132 [hingStatusInfoChangedEvent] - 'zigbee:device:93b31b85:286d9700010c5dfc' changed from INITIALIZING to UNKNOWN

==> /var/log/openhab2/openhab.log <==

2020-01-15 20:34:54.133 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 286D9700010C5DFC: Coordinator status changed to ONLINE.

2020-01-15 20:34:54.134 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 286D9700010C5DFC: Coordinator is ONLINE. Starting device initialisation.

2020-01-15 20:34:54.147 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 286D9700010C5DFC: Start initialising ZigBee Thing handler

2020-01-15 20:34:54.149 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 286D9700010C5DFC: ZigBee node property discovery start

2020-01-15 20:34:54.150 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 286D9700010C5DFC: ZigBee node property discovery using basic cluster on endpoint 3F13/1

==> /var/log/openhab2/events.log <==

2020-01-15 20:34:54.173 [nt.FirmwareStatusInfoEvent] - Firmware status of thing zigbee:device:93b31b85:286d9700010c5dfc changed to UNKNOWN.

==> /var/log/openhab2/openhab.log <==

2020-01-15 20:34:54.190 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 286D9700010C5DFC: Node updated - ZigBeeNode [state=ONLINE, IEEE=286D9700010C5DFC, NWK=3F13, Type=END_DEVICE, endpoints=[1]]

2020-01-15 20:34:54.199 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - 286D9700010C5DFC: Starting ZigBee device discovery

2020-01-15 20:34:54.200 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 286D9700010C5DFC: Creating ZigBee device zigbee:device with bridge zigbee:coordinator_ember:93b31b85

2020-01-15 20:34:54.202 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 286D9700010C5DFC: ZigBee node property discovery start

2020-01-15 20:34:54.202 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 286D9700010C5DFC: ZigBee node property discovery using basic cluster on endpoint 3F13/1

2020-01-15 20:34:54.409 [DEBUG] [converter.ZigBeeConverterSwitchLevel] - B0CE1814035644AF: ZigBee attribute reports ZclAttribute [cluster=On/Off, id=0, name=On Off, dataType=BOOLEAN, lastValue=false, lastReportTime=Wed Jan 15 20:34:54 CST 2020, implemented=false]

2020-01-15 20:34:54.413 [DEBUG] [converter.ZigBeeBaseChannelConverter] - B0CE1814035644AF: Channel zigbee:device:93b31b85:b0ce1814035644af:B0CE1814035644AF_1_dimmer updated to OFF

2020-01-15 20:34:54.413 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - B0CE1814035644AF: Updating ZigBee channel state zigbee:device:93b31b85:b0ce1814035644af:B0CE1814035644AF_1_dimmer to OFF

2020-01-15 20:34:54.413 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - Reset timeout for handler with thingUID=zigbee:device:93b31b85:b0ce1814035644af

2020-01-15 20:34:54.413 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - Canceling timeout task for thingUID=zigbee:device:93b31b85:b0ce1814035644af

2020-01-15 20:34:54.414 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - Scheduling timeout task for thingUID=zigbee:device:93b31b85:b0ce1814035644af in 150 seconds

2020-01-15 20:34:54.466 [DEBUG] [ding.zigbee.internal.ZigBeeDataStore] - 286D9700010C5DFC: ZigBee saving network state complete.

2020-01-15 20:34:56.305 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 286D9700010C5DFC: Stack version failed

2020-01-15 20:34:56.578 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 286D9700010C5DFC: Stack version failed

2020-01-15 20:34:56.855 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 286D9700010C5DFC: Date code failed

2020-01-15 20:34:56.857 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 286D9700010C5DFC: ZigBee node property discovery using OTA cluster on endpoint 3F13/1

2020-01-15 20:34:56.857 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 286D9700010C5DFC: ZigBee node property discovery complete: {zigbee_logicaltype=END_DEVICE, zigbee_powerlevel=FULL, zigbee_manufacturercode=0x1241, modelId=multi, zigbee_networkaddress=16147, zigbee_powersource=MAINS, zigbee_zclversion=2, vendor=Samjin, zigbee_powermode=RECEIVER_ON_IDLE, zigbee_powersources=[MAINS], hardwareVersion=0, firmwareVersion=0xFFFFFFFF, zigbee_applicationVersion=17}

2020-01-15 20:34:56.858 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 286D9700010C5DFC: Checking endpoint 1 channels

2020-01-15 20:34:57.131 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 286D9700010C5DFC: Date code failed

2020-01-15 20:34:57.132 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 286D9700010C5DFC: ZigBee node property discovery using OTA cluster on endpoint 3F13/1

2020-01-15 20:34:57.133 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 286D9700010C5DFC: ZigBee node property discovery complete: {zigbee_logicaltype=END_DEVICE, zigbee_powerlevel=FULL, zigbee_manufacturercode=0x1241, modelId=multi, zigbee_networkaddress=16147, zigbee_powersource=MAINS, zigbee_zclversion=2, vendor=Samjin, zigbee_powermode=RECEIVER_ON_IDLE, zigbee_powersources=[MAINS], hardwareVersion=0, firmwareVersion=0xFFFFFFFF, zigbee_applicationVersion=17}

2020-01-15 20:34:57.134 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 286D9700010C5DFC: Update ZigBee device zigbee:device with bridge zigbee:coordinator_ember:93b31b85, label 'Samjin multi'

2020-01-15 20:34:57.404 [DEBUG] [ding.zigbee.internal.ZigBeeDataStore] - 286D9700010C5DFC: ZigBee saving network state complete.

2020-01-15 20:34:57.925 [DEBUG] [nternal.converter.ZigBeeConverterIas] - 286D9700010C5DFC: IAS zone type CONTACT_SWITCH

2020-01-15 20:34:57.929 [DEBUG] [nternal.converter.ZigBeeConverterIas] - 286D9700010C5DFC: IAS zone type CONTACT_SWITCH

2020-01-15 20:34:57.929 [DEBUG] [nternal.converter.ZigBeeConverterIas] - 286D9700010C5DFC: IAS zone type CONTACT_SWITCH

2020-01-15 20:34:57.930 [DEBUG] [nternal.converter.ZigBeeConverterIas] - 286D9700010C5DFC: IAS zone type CONTACT_SWITCH

2020-01-15 20:34:58.193 [DEBUG] [nternal.converter.ZigBeeConverterIas] - 286D9700010C5DFC: IAS zone type CONTACT_SWITCH

2020-01-15 20:34:58.196 [DEBUG] [nternal.converter.ZigBeeConverterIas] - 286D9700010C5DFC: IAS zone type CONTACT_SWITCH

2020-01-15 20:34:58.197 [DEBUG] [nternal.converter.ZigBeeConverterIas] - 286D9700010C5DFC: IAS zone type CONTACT_SWITCH

2020-01-15 20:34:58.198 [DEBUG] [nternal.converter.ZigBeeConverterIas] - 286D9700010C5DFC: IAS zone type CONTACT_SWITCH

2020-01-15 20:34:58.199 [DEBUG] [nternal.converter.ZigBeeConverterIas] - 286D9700010C5DFC: IAS zone type CONTACT_SWITCH

2020-01-15 20:34:58.200 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 286D9700010C5DFC: Dynamically created 7 channels

2020-01-15 20:34:58.202 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 286D9700010C5DFC: Updating thing definition as channels have changed from [] to [zigbee:device:93b31b85:286d9700010c5dfc:286D9700010C5DFC_1_batterylevel, zigbee:device:93b31b85:286d9700010c5dfc:286D9700010C5DFC_1_temperature, zigbee:device:93b31b85:286d9700010c5dfc:286D9700010C5DFC_1_tamper, zigbee:device:93b31b85:286d9700010c5dfc:286D9700010C5DFC_1_batteryalarm, zigbee:device:93b31b85:286d9700010c5dfc:286D9700010C5DFC_1_contact1, zigbee:device:93b31b85:286d9700010c5dfc:286D9700010C5DFC_1_iaslowbattery, zigbee:device:93b31b85:286d9700010c5dfc:286D9700010C5DFC_1_batteryvoltage]

==> /var/log/openhab2/events.log <==

2020-01-15 20:34:58.204 [me.event.ThingUpdatedEvent] - Thing 'zigbee:device:93b31b85:286d9700010c5dfc' has been updated.

==> /var/log/openhab2/openhab.log <==

2020-01-15 20:34:58.205 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 286D9700010C5DFC: Initializing device

2020-01-15 20:34:58.206 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 286D9700010C5DFC: Initializing channel zigbee:device:93b31b85:286d9700010c5dfc:286D9700010C5DFC_1_batterylevel with org.openhab.binding.zigbee.internal.converter.ZigBeeConverterBatteryPercent@6628e230

2020-01-15 20:34:58.207 [DEBUG] [verter.ZigBeeConverterBatteryPercent] - 286D9700010C5DFC: Initialising device battery percent converter

2020-01-15 20:34:58.738 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 286D9700010C5DFC: Initializing channel zigbee:device:93b31b85:286d9700010c5dfc:286D9700010C5DFC_1_temperature with org.openhab.binding.zigbee.internal.converter.ZigBeeConverterTemperature@3b9ef5df

2020-01-15 20:34:59.062 [ERROR] [ng.zigbee.handler.ZigBeeThingHandler] - 286D9700010C5DFC: Exception creating channels 

java.lang.NullPointerException: null

	at org.openhab.binding.zigbee.internal.converter.ZigBeeConverterTemperature.initializeDevice(ZigBeeConverterTemperature.java:79) ~[bundleFile:?]

	at org.openhab.binding.zigbee.handler.ZigBeeThingHandler.initializeDevice(ZigBeeThingHandler.java:492) ~[bundleFile:?]

	at org.openhab.binding.zigbee.handler.ZigBeeThingHandler.doNodeInitialisation(ZigBeeThingHandler.java:381) [bundleFile:?]

	at org.openhab.binding.zigbee.handler.ZigBeeThingHandler.access$0(ZigBeeThingHandler.java:238) [bundleFile:?]

	at org.openhab.binding.zigbee.handler.ZigBeeThingHandler$1.call(ZigBeeThingHandler.java:232) [bundleFile:?]

	at org.openhab.binding.zigbee.handler.ZigBeeThingHandler$1.call(ZigBeeThingHandler.java:1) [bundleFile:?]

	at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_232]

	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_232]

	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:1.8.0_232]

	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_232]

	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_232]

	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_232]

==> /var/log/openhab2/events.log <==

2020-01-15 20:34:59.078 [hingStatusInfoChangedEvent] - 'zigbee:device:93b31b85:286d9700010c5dfc' changed from UNKNOWN to OFFLINE (HANDLER_INITIALIZING_ERROR)

2020-01-15 20:34:59.085 [me.event.ThingUpdatedEvent] - Thing 'zigbee:device:93b31b85:286d9700010c5dfc' has been updated.

==> /var/log/openhab2/openhab.log <==

2020-01-15 20:34:59.090 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 286D9700010C5DFC: Start initialising ZigBee Thing handler

2020-01-15 20:34:59.090 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 286D9700010C5DFC: ZigBee node property discovery start

2020-01-15 20:34:59.091 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 286D9700010C5DFC: ZigBee node property discovery using basic cluster on endpoint 3F13/1

2020-01-15 20:34:59.525 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 286D9700010C5DFC: Stack version failed

2020-01-15 20:34:59.773 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 286D9700010C5DFC: Date code failed

2020-01-15 20:34:59.774 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 286D9700010C5DFC: ZigBee node property discovery using OTA cluster on endpoint 3F13/1

2020-01-15 20:34:59.775 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 286D9700010C5DFC: ZigBee node property discovery complete: {zigbee_logicaltype=END_DEVICE, zigbee_powerlevel=FULL, zigbee_manufacturercode=0x1241, modelId=multi, zigbee_networkaddress=16147, zigbee_powersource=MAINS, zigbee_zclversion=2, zigbee_routes=[], zigbee_lastupdate=, zigbee_stkcompliance=22, vendor=Samjin, zigbee_powermode=RECEIVER_ON_IDLE, zigbee_powersources=[MAINS], hardwareVersion=0, firmwareVersion=0xFFFFFFFF, zigbee_neighbors=[], zigbee_applicationVersion=17, zigbee_device_initialised=false, zigbee_devices=[]}

2020-01-15 20:34:59.776 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 286D9700010C5DFC: Checking endpoint 1 channels

2020-01-15 20:34:59.780 [DEBUG] [nternal.converter.ZigBeeConverterIas] - 286D9700010C5DFC: IAS zone type CONTACT_SWITCH

2020-01-15 20:34:59.785 [DEBUG] [nternal.converter.ZigBeeConverterIas] - 286D9700010C5DFC: IAS zone type CONTACT_SWITCH

2020-01-15 20:34:59.786 [DEBUG] [nternal.converter.ZigBeeConverterIas] - 286D9700010C5DFC: IAS zone type CONTACT_SWITCH

2020-01-15 20:34:59.786 [DEBUG] [nternal.converter.ZigBeeConverterIas] - 286D9700010C5DFC: IAS zone type CONTACT_SWITCH

2020-01-15 20:34:59.788 [DEBUG] [nternal.converter.ZigBeeConverterIas] - 286D9700010C5DFC: IAS zone type CONTACT_SWITCH

2020-01-15 20:34:59.789 [DEBUG] [nternal.converter.ZigBeeConverterIas] - 286D9700010C5DFC: IAS zone type CONTACT_SWITCH

2020-01-15 20:34:59.793 [DEBUG] [nternal.converter.ZigBeeConverterIas] - 286D9700010C5DFC: IAS zone type CONTACT_SWITCH

2020-01-15 20:34:59.794 [DEBUG] [nternal.converter.ZigBeeConverterIas] - 286D9700010C5DFC: IAS zone type CONTACT_SWITCH

2020-01-15 20:34:59.794 [DEBUG] [nternal.converter.ZigBeeConverterIas] - 286D9700010C5DFC: IAS zone type CONTACT_SWITCH

2020-01-15 20:34:59.795 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 286D9700010C5DFC: Dynamically created 7 channels

2020-01-15 20:34:59.796 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 286D9700010C5DFC: Initializing device

2020-01-15 20:34:59.797 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 286D9700010C5DFC: Initializing channel zigbee:device:93b31b85:286d9700010c5dfc:286D9700010C5DFC_1_batterylevel with org.openhab.binding.zigbee.internal.converter.ZigBeeConverterBatteryPercent@11cbaacc

2020-01-15 20:34:59.797 [DEBUG] [verter.ZigBeeConverterBatteryPercent] - 286D9700010C5DFC: Initialising device battery percent converter

2020-01-15 20:35:00.280 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 286D9700010C5DFC: Initializing channel zigbee:device:93b31b85:286d9700010c5dfc:286D9700010C5DFC_1_temperature with org.openhab.binding.zigbee.internal.converter.ZigBeeConverterTemperature@713f3717

2020-01-15 20:35:00.561 [ERROR] [ng.zigbee.handler.ZigBeeThingHandler] - 286D9700010C5DFC: Exception creating channels 

java.lang.NullPointerException: null

	at org.openhab.binding.zigbee.internal.converter.ZigBeeConverterTemperature.initializeDevice(ZigBeeConverterTemperature.java:79) ~[bundleFile:?]

	at org.openhab.binding.zigbee.handler.ZigBeeThingHandler.initializeDevice(ZigBeeThingHandler.java:492) ~[bundleFile:?]

	at org.openhab.binding.zigbee.handler.ZigBeeThingHandler.doNodeInitialisation(ZigBeeThingHandler.java:381) [bundleFile:?]

	at org.openhab.binding.zigbee.handler.ZigBeeThingHandler.access$0(ZigBeeThingHandler.java:238) [bundleFile:?]

	at org.openhab.binding.zigbee.handler.ZigBeeThingHandler$1.call(ZigBeeThingHandler.java:232) [bundleFile:?]

	at org.openhab.binding.zigbee.handler.ZigBeeThingHandler$1.call(ZigBeeThingHandler.java:1) [bundleFile:?]

	at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_232]

	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_232]

	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:1.8.0_232]

	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_232]

	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_232]

	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_232]

2020-01-15 20:35:25.486 [WARN ] [nternal.profiles.SystemOffsetProfile] - Received a QuantityType state '18 °C' with unit, but the offset is defined as a plain number without unit (2), please consider adding a unit to the profile offset.

==> /var/log/openhab2/events.log <==

2020-01-15 20:35:25.489 [vent.ItemStateChangedEvent] - ThermostatCurrentTempUp changed from 66.4 to 18

==> /var/log/openhab2/openhab.log <==

2020-01-15 20:35:28.455 [DEBUG] [converter.ZigBeeConverterSwitchLevel] - B0CE1814035644AF: ZigBee attribute reports ZclAttribute [cluster=Level Control, id=0, name=Current Level, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=254, lastReportTime=Wed Jan 15 20:35:28 CST 2020, implemented=true]

2020-01-15 20:35:49.022 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - B0CE1814035644AF: Polling...

2020-01-15 20:35:49.023 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - B0CE1814035644AF: Polling zigbee:device:93b31b85:b0ce1814035644af:B0CE1814035644AF_1_dimmer

2020-01-15 20:35:49.064 [DEBUG] [converter.ZigBeeConverterSwitchLevel] - B0CE1814035644AF: ZigBee attribute reports ZclAttribute [cluster=On/Off, id=0, name=On Off, dataType=BOOLEAN, lastValue=false, lastReportTime=Wed Jan 15 20:35:49 CST 2020, implemented=false]

2020-01-15 20:35:49.064 [DEBUG] [converter.ZigBeeBaseChannelConverter] - B0CE1814035644AF: Channel zigbee:device:93b31b85:b0ce1814035644af:B0CE1814035644AF_1_dimmer updated to OFF

2020-01-15 20:35:49.069 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - B0CE1814035644AF: Updating ZigBee channel state zigbee:device:93b31b85:b0ce1814035644af:B0CE1814035644AF_1_dimmer to OFF

2020-01-15 20:35:49.069 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - Reset timeout for handler with thingUID=zigbee:device:93b31b85:b0ce1814035644af

2020-01-15 20:35:49.070 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - Canceling timeout task for thingUID=zigbee:device:93b31b85:b0ce1814035644af

2020-01-15 20:35:49.070 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - Scheduling timeout task for thingUID=zigbee:device:93b31b85:b0ce1814035644af in 150 seconds

2020-01-15 20:35:49.114 [DEBUG] [converter.ZigBeeConverterSwitchLevel] - B0CE1814035644AF: ZigBee attribute reports ZclAttribute [cluster=Level Control, id=0, name=Current Level, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=254, lastReportTime=Wed Jan 15 20:35:49 CST 2020, implemented=true]

2020-01-15 20:35:54.201 [DEBUG] [converter.ZigBeeConverterSwitchLevel] - B0CE1814035644AF: ZigBee attribute reports ZclAttribute [cluster=On/Off, id=0, name=On Off, dataType=BOOLEAN, lastValue=false, lastReportTime=Wed Jan 15 20:35:54 CST 2020, implemented=false]

2020-01-15 20:35:54.201 [DEBUG] [converter.ZigBeeBaseChannelConverter] - B0CE1814035644AF: Channel zigbee:device:93b31b85:b0ce1814035644af:B0CE1814035644AF_1_dimmer updated to OFF

2020-01-15 20:35:54.202 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - B0CE1814035644AF: Updating ZigBee channel state zigbee:device:93b31b85:b0ce1814035644af:B0CE1814035644AF_1_dimmer to OFF

2020-01-15 20:35:54.203 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - Reset timeout for handler with thingUID=zigbee:device:93b31b85:b0ce1814035644af

2020-01-15 20:35:54.204 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - Canceling timeout task for thingUID=zigbee:device:93b31b85:b0ce1814035644af

2020-01-15 20:35:54.205 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - Scheduling timeout task for thingUID=zigbee:device:93b31b85:b0ce1814035644af in 150 seconds

I personally do not use Zigbee but perhaps the log viewer can help.

https://www.cd-jackson.com/index.php/openhab/zigbee-log-viewer

The log viewer won’t help since the log doesn’t contain the information the log viewer uses.

We know that the ZigBee dongles and devices are working and that OpenHab 2.5.1 (with 2.5.1 ZigBee binding) is generally able to make pairing work. So I am trying to narrow this down. We are having several Linux installations were this doesn’t work. Some on RPi, some on PC. We have at least a single Linux installation that seems to work (OpenSuse by @mrfrh). Your installation on macOS seems to work as well.

In an ideal world, the hardware and OS should not matter much to Java applications, but in my experience as a Java developer for several years, there are still more than enough platform specific details. They might seem minor, but they might make a major difference in practice.

I am trying to run OpenHab 2.5.1 on a MacBook Pro (macOS 10.14.6), but I am having trouble getting the BV 2010/10 to work. @chris Could you please point me to the driver download for this device? I could not find anything. Thank you very much.

My guess is that there is something misconfigured in the NCP - or - that there is even a bug in the NCP that shows up under some circumstances. I need to get the binding updated, but it’s problematic at the moment as I need to update the binding, then also update the distro - I’m trying to get this all centralised so it’s more under my control and I don’t need to wait weeks to get stuff merged.

I doubt though that this is a host issue.

There is no way to run the bitron dongle on a mac since they use non-standard USB IDs.