Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Exception creating channels #430

Closed
5iver opened this issue Apr 30, 2019 · 7 comments · Fixed by #433
Closed

Exception creating channels #430

5iver opened this issue Apr 30, 2019 · 7 comments · Fixed by #433

Comments

@5iver
Copy link

5iver commented Apr 30, 2019

Possibly caused by #427. This just started in OH S1579 and S1580. I've been using the 1.1.11 snapshot libraries for a while now, and update them frequently, but haven't seen any updates recently. My ZHA power outlet is fine, but my ZLL GE Link bulbs are all unresponsive. Here is a log from deleting one through Paper UI and rediscovering.

2019-04-30 00:33:40.611 [DEBUG] [org.openhab.binding.zigbee] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.core.ConfigDescriptionProvider}={service.id=1105, service.bundleid=305, service.scope=singleton} - org.openhab.binding.zigbee
2019-04-30 00:33:40.617 [DEBUG] [org.openhab.binding.zigbee] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.type.DynamicStateDescriptionProvider}={service.id=1106, service.bundleid=305, service.scope=singleton} - org.openhab.binding.zigbee
2019-04-30 00:33:40.618 [DEBUG] [org.openhab.binding.zigbee] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.firmware.FirmwareUpdateHandler}={service.id=1107, service.bundleid=305, service.scope=singleton} - org.openhab.binding.zigbee
2019-04-30 00:33:40.636 [DEBUG] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - 7C25240000163762: Initializing ZigBee thing handler zigbee:device:9b51c72d:7c25240000163762
2019-04-30 00:33:40.641 [DEBUG] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - 7C25240000163762: Coordinator status changed to ONLINE.
2019-04-30 00:33:40.641 [DEBUG] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - 7C25240000163762: Coordinator is ONLINE. Starting device initialisation.
2019-04-30 00:33:40.652 [DEBUG] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - 7C25240000163762: Start initialising ZigBee Thing handler
2019-04-30 00:33:40.654 [DEBUG] [org.openhab.binding.zigbee.discovery.ZigBeeNodePropertyDiscoverer] - 7C25240000163762: ZigBee node property discovery start
2019-04-30 00:33:40.655 [DEBUG] [org.openhab.binding.zigbee.discovery.ZigBeeNodePropertyDiscoverer] - 7C25240000163762: ZigBee node property discovery using 63400/1
2019-04-30 00:33:40.655 [DEBUG] [org.openhab.binding.zigbee.discovery.ZigBeeNodePropertyDiscoverer] - 7C25240000163762: ZigBee node property discovery complete: {zigbee_logicaltype=ROUTER, zigbee_powerlevel=FULL, modelId=ZLL Light, zigbee_networkaddress=63400, zigbee_powersource=MAINS, zigbee_stkversion=2, zigbee_datecode=20140812, zigbee_zclversion=1, vendor=GE_Appliances, zigbee_powermode=RECEIVER_ON_IDLE, zigbee_powersources=[MAINS], hardwareVersion=1, firmwareVersion=0x01030400, zigbee_applicationVersion=4}
2019-04-30 00:33:40.655 [DEBUG] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - 7C25240000163762: Checking endpoint 1 channels
2019-04-30 00:33:40.657 [DEBUG] [org.openhab.binding.zigbee.internal.converter.ZigBeeChannelConverterFactoryImpl] - 7C25240000163762: Removing channel zigbee:switch_onoff in favor of zigbee:switch_level
2019-04-30 00:33:40.657 [DEBUG] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - 7C25240000163762: Dynamically created 1 channels
2019-04-30 00:33:40.667 [DEBUG] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - 7C25240000163762: Updating thing definition as channels have changed from [] to [zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer]
2019-04-30 00:33:40.670 [DEBUG] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - 7C25240000163762: Initializing device
2019-04-30 00:33:40.670 [DEBUG] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - 7C25240000163762: Initializing channel zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer with org.openhab.binding.zigbee.internal.converter.ZigBeeConverterSwitchLevel@61ae3ad5
2019-04-30 00:33:40.718 [DEBUG] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - 7C25240000163762: Channel zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer linked - polling started.
2019-04-30 00:33:40.806 [DEBUG] [org.openhab.binding.zigbee.internal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state
2019-04-30 00:33:40.808 [DEBUG] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - 7C25240000163762: Node updated - ZigBeeNode [state=ONLINE, IEEE=7C25240000163762, NWK=F7A8, Type=ROUTER]
2019-04-30 00:33:40.810 [DEBUG] [org.openhab.binding.zigbee.internal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Start.
2019-04-30 00:33:40.831 [DEBUG] [org.openhab.binding.zigbee.internal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Done.
2019-04-30 00:33:41.482 [DEBUG] [org.openhab.binding.zigbee.internal.converter.ZigBeeConverterSwitchLevel] - 7C25240000163762: ZigBee attribute reports ZclAttribute [cluster=LEVEL_CONTROL, id=0, name=CurrentLevel, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=254, lastReportTime=Tue Apr 30 00:33:41 EDT 2019]
2019-04-30 00:33:41.483 [DEBUG] [org.openhab.binding.zigbee.internal.converter.ZigBeeConverterSwitchLevel] - 7C25240000163762: ZigBee attribute reports ZclAttribute [cluster=LEVEL_CONTROL, id=0, name=CurrentLevel, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=254, lastReportTime=Tue Apr 30 00:33:41 EDT 2019]
2019-04-30 00:33:41.483 [DEBUG] [org.openhab.binding.zigbee.internal.converter.ZigBeeConverterSwitchLevel] - 7C25240000163762: ZigBee attribute reports ZclAttribute [cluster=LEVEL_CONTROL, id=0, name=CurrentLevel, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=254, lastReportTime=Tue Apr 30 00:33:41 EDT 2019]
2019-04-30 00:33:41.484 [DEBUG] [org.openhab.binding.zigbee.converter.ZigBeeBaseChannelConverter] - 7C25240000163762: Channel zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer updated to 100
2019-04-30 00:33:41.484 [DEBUG] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - null: Updating ZigBee channel state zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer to 100
2019-04-30 00:33:41.483 [DEBUG] [org.openhab.binding.zigbee.internal.converter.ZigBeeConverterSwitchLevel] - 7C25240000163762: ZigBee attribute reports ZclAttribute [cluster=LEVEL_CONTROL, id=0, name=CurrentLevel, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=254, lastReportTime=Tue Apr 30 00:33:41 EDT 2019]
2019-04-30 00:33:41.485 [DEBUG] [org.openhab.binding.zigbee.converter.ZigBeeBaseChannelConverter] - 7C25240000163762: Channel zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer updated to 100
2019-04-30 00:33:41.485 [DEBUG] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - null: Updating ZigBee channel state zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer to 100
2019-04-30 00:33:41.483 [DEBUG] [org.openhab.binding.zigbee.internal.converter.ZigBeeConverterSwitchLevel] - 7C25240000163762: ZigBee attribute reports ZclAttribute [cluster=LEVEL_CONTROL, id=0, name=CurrentLevel, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=254, lastReportTime=Tue Apr 30 00:33:41 EDT 2019]
2019-04-30 00:33:41.483 [DEBUG] [org.openhab.binding.zigbee.internal.converter.ZigBeeConverterSwitchLevel] - 7C25240000163762: ZigBee attribute reports ZclAttribute [cluster=LEVEL_CONTROL, id=0, name=CurrentLevel, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=254, lastReportTime=Tue Apr 30 00:33:41 EDT 2019]
2019-04-30 00:33:41.486 [DEBUG] [org.openhab.binding.zigbee.converter.ZigBeeBaseChannelConverter] - 7C25240000163762: Channel zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer updated to 100
2019-04-30 00:33:41.487 [DEBUG] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - null: Updating ZigBee channel state zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer to 100
2019-04-30 00:33:41.483 [DEBUG] [org.openhab.binding.zigbee.internal.converter.ZigBeeConverterSwitchLevel] - 7C25240000163762: ZigBee attribute reports ZclAttribute [cluster=LEVEL_CONTROL, id=0, name=CurrentLevel, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=254, lastReportTime=Tue Apr 30 00:33:41 EDT 2019]
2019-04-30 00:33:41.487 [DEBUG] [org.openhab.binding.zigbee.converter.ZigBeeBaseChannelConverter] - 7C25240000163762: Channel zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer updated to 100
2019-04-30 00:33:41.488 [DEBUG] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - null: Updating ZigBee channel state zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer to 100
2019-04-30 00:33:41.490 [DEBUG] [org.openhab.binding.zigbee.handler.ZigbeeIsAliveTracker] - Reset timeout for handler with thingUID=zigbee:device:9b51c72d:7c25240000163762
2019-04-30 00:33:41.483 [DEBUG] [org.openhab.binding.zigbee.internal.converter.ZigBeeConverterSwitchLevel] - 7C25240000163762: ZigBee attribute reports ZclAttribute [cluster=LEVEL_CONTROL, id=0, name=CurrentLevel, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=254, lastReportTime=Tue Apr 30 00:33:41 EDT 2019]
2019-04-30 00:33:41.483 [DEBUG] [org.openhab.binding.zigbee.internal.converter.ZigBeeConverterSwitchLevel] - 7C25240000163762: ZigBee attribute reports ZclAttribute [cluster=LEVEL_CONTROL, id=0, name=CurrentLevel, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=254, lastReportTime=Tue Apr 30 00:33:41 EDT 2019]
2019-04-30 00:33:41.493 [DEBUG] [org.openhab.binding.zigbee.converter.ZigBeeBaseChannelConverter] - 7C25240000163762: Channel zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer updated to 100
2019-04-30 00:33:41.494 [DEBUG] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - null: Updating ZigBee channel state zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer to 100
2019-04-30 00:33:41.483 [DEBUG] [org.openhab.binding.zigbee.internal.converter.ZigBeeConverterSwitchLevel] - 7C25240000163762: ZigBee attribute reports ZclAttribute [cluster=LEVEL_CONTROL, id=0, name=CurrentLevel, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=254, lastReportTime=Tue Apr 30 00:33:41 EDT 2019]
2019-04-30 00:33:41.483 [DEBUG] [org.openhab.binding.zigbee.internal.converter.ZigBeeConverterSwitchLevel] - 7C25240000163762: ZigBee attribute reports ZclAttribute [cluster=LEVEL_CONTROL, id=0, name=CurrentLevel, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=254, lastReportTime=Tue Apr 30 00:33:41 EDT 2019]
2019-04-30 00:33:41.495 [DEBUG] [org.openhab.binding.zigbee.converter.ZigBeeBaseChannelConverter] - 7C25240000163762: Channel zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer updated to 100
2019-04-30 00:33:41.495 [DEBUG] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - null: Updating ZigBee channel state zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer to 100
2019-04-30 00:33:41.482 [DEBUG] [org.openhab.binding.zigbee.internal.converter.ZigBeeConverterSwitchLevel] - 7C25240000163762: ZigBee attribute reports ZclAttribute [cluster=LEVEL_CONTROL, id=0, name=CurrentLevel, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=254, lastReportTime=Tue Apr 30 00:33:41 EDT 2019]
2019-04-30 00:33:41.496 [DEBUG] [org.openhab.binding.zigbee.converter.ZigBeeBaseChannelConverter] - 7C25240000163762: Channel zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer updated to 100
2019-04-30 00:33:41.496 [DEBUG] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - null: Updating ZigBee channel state zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer to 100
2019-04-30 00:33:41.494 [DEBUG] [org.openhab.binding.zigbee.converter.ZigBeeBaseChannelConverter] - 7C25240000163762: Channel zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer updated to 100
2019-04-30 00:33:41.491 [DEBUG] [org.openhab.binding.zigbee.handler.ZigbeeIsAliveTracker] - Reset timeout for handler with thingUID=zigbee:device:9b51c72d:7c25240000163762
2019-04-30 00:33:41.497 [DEBUG] [org.openhab.binding.zigbee.handler.ZigbeeIsAliveTracker] - Reset timeout for handler with thingUID=zigbee:device:9b51c72d:7c25240000163762
2019-04-30 00:33:41.488 [DEBUG] [org.openhab.binding.zigbee.handler.ZigbeeIsAliveTracker] - Reset timeout for handler with thingUID=zigbee:device:9b51c72d:7c25240000163762
2019-04-30 00:33:41.487 [DEBUG] [org.openhab.binding.zigbee.converter.ZigBeeBaseChannelConverter] - 7C25240000163762: Channel zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer updated to 100
2019-04-30 00:33:41.499 [DEBUG] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - null: Updating ZigBee channel state zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer to 100
2019-04-30 00:33:41.483 [DEBUG] [org.openhab.binding.zigbee.internal.converter.ZigBeeConverterSwitchLevel] - 7C25240000163762: ZigBee attribute reports ZclAttribute [cluster=LEVEL_CONTROL, id=0, name=CurrentLevel, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=254, lastReportTime=Tue Apr 30 00:33:41 EDT 2019]
2019-04-30 00:33:41.499 [DEBUG] [org.openhab.binding.zigbee.handler.ZigbeeIsAliveTracker] - Reset timeout for handler with thingUID=zigbee:device:9b51c72d:7c25240000163762
2019-04-30 00:33:41.500 [DEBUG] [org.openhab.binding.zigbee.converter.ZigBeeBaseChannelConverter] - 7C25240000163762: Channel zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer updated to 100
2019-04-30 00:33:41.500 [DEBUG] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - null: Updating ZigBee channel state zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer to 100
2019-04-30 00:33:41.486 [DEBUG] [org.openhab.binding.zigbee.converter.ZigBeeBaseChannelConverter] - 7C25240000163762: Channel zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer updated to 100
2019-04-30 00:33:41.485 [DEBUG] [org.openhab.binding.zigbee.handler.ZigbeeIsAliveTracker] - Reset timeout for handler with thingUID=zigbee:device:9b51c72d:7c25240000163762
2019-04-30 00:33:41.501 [DEBUG] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - null: Updating ZigBee channel state zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer to 100
2019-04-30 00:33:41.483 [DEBUG] [org.openhab.binding.zigbee.internal.converter.ZigBeeConverterSwitchLevel] - 7C25240000163762: ZigBee attribute reports ZclAttribute [cluster=LEVEL_CONTROL, id=0, name=CurrentLevel, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=254, lastReportTime=Tue Apr 30 00:33:41 EDT 2019]
2019-04-30 00:33:41.484 [DEBUG] [org.openhab.binding.zigbee.converter.ZigBeeBaseChannelConverter] - 7C25240000163762: Channel zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer updated to 100
2019-04-30 00:33:41.502 [DEBUG] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - null: Updating ZigBee channel state zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer to 100
2019-04-30 00:33:41.502 [DEBUG] [org.openhab.binding.zigbee.handler.ZigbeeIsAliveTracker] - Reset timeout for handler with thingUID=zigbee:device:9b51c72d:7c25240000163762
2019-04-30 00:33:41.498 [DEBUG] [org.openhab.binding.zigbee.handler.ZigbeeIsAliveTracker] - Reset timeout for handler with thingUID=zigbee:device:9b51c72d:7c25240000163762
2019-04-30 00:33:41.497 [DEBUG] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - null: Updating ZigBee channel state zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer to 100
2019-04-30 00:33:41.496 [DEBUG] [org.openhab.binding.zigbee.converter.ZigBeeBaseChannelConverter] - 7C25240000163762: Channel zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer updated to 100
2019-04-30 00:33:41.503 [DEBUG] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - null: Updating ZigBee channel state zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer to 100
2019-04-30 00:33:41.502 [DEBUG] [org.openhab.binding.zigbee.converter.ZigBeeBaseChannelConverter] - 7C25240000163762: Channel zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer updated to 100
2019-04-30 00:33:41.503 [DEBUG] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - null: Updating ZigBee channel state zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer to 100
2019-04-30 00:33:41.504 [DEBUG] [org.openhab.binding.zigbee.handler.ZigbeeIsAliveTracker] - Reset timeout for handler with thingUID=zigbee:device:9b51c72d:7c25240000163762
2019-04-30 00:33:41.505 [DEBUG] [org.openhab.binding.zigbee.handler.ZigbeeIsAliveTracker] - Reset timeout for handler with thingUID=zigbee:device:9b51c72d:7c25240000163762
2019-04-30 00:33:41.506 [DEBUG] [org.openhab.binding.zigbee.handler.ZigbeeIsAliveTracker] - Reset timeout for handler with thingUID=zigbee:device:9b51c72d:7c25240000163762
2019-04-30 00:33:41.506 [DEBUG] [org.openhab.binding.zigbee.handler.ZigbeeIsAliveTracker] - Reset timeout for handler with thingUID=zigbee:device:9b51c72d:7c25240000163762
2019-04-30 00:33:41.508 [DEBUG] [org.openhab.binding.zigbee.handler.ZigbeeIsAliveTracker] - Reset timeout for handler with thingUID=zigbee:device:9b51c72d:7c25240000163762
2019-04-30 00:33:41.509 [DEBUG] [org.openhab.binding.zigbee.handler.ZigbeeIsAliveTracker] - Reset timeout for handler with thingUID=zigbee:device:9b51c72d:7c25240000163762
2019-04-30 00:33:42.204 [ERROR] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - 7C25240000163762: Exception creating channels 
java.lang.NullPointerException: null
        at org.openhab.binding.zigbee.internal.converter.ZigBeeConverterSwitchLevel.getPollingPeriod(ZigBeeConverterSwitchLevel.java:154) ~[305:org.openhab.binding.zigbee:2.5.0.201904290354]
        at org.openhab.binding.zigbee.handler.ZigBeeThingHandler.doNodeInitialisation(ZigBeeThingHandler.java:396) [305:org.openhab.binding.zigbee:2.5.0.201904290354]
        at org.openhab.binding.zigbee.handler.ZigBeeThingHandler.access$0(ZigBeeThingHandler.java:233) [305:org.openhab.binding.zigbee:2.5.0.201904290354]
        at org.openhab.binding.zigbee.handler.ZigBeeThingHandler$1.call(ZigBeeThingHandler.java:227) [305:org.openhab.binding.zigbee:2.5.0.201904290354]
        at org.openhab.binding.zigbee.handler.ZigBeeThingHandler$1.call(ZigBeeThingHandler.java:1) [305:org.openhab.binding.zigbee:2.5.0.201904290354]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
        at java.lang.Thread.run(Thread.java:748) [?:?]
2019-04-30 00:33:42.216 [DEBUG] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - 7C25240000163762: Start initialising ZigBee Thing handler
2019-04-30 00:33:42.217 [DEBUG] [org.openhab.binding.zigbee.discovery.ZigBeeNodePropertyDiscoverer] - 7C25240000163762: ZigBee node property discovery start
2019-04-30 00:33:42.219 [DEBUG] [org.openhab.binding.zigbee.discovery.ZigBeeNodePropertyDiscoverer] - 7C25240000163762: ZigBee node property discovery using 63400/1
2019-04-30 00:33:42.219 [DEBUG] [org.openhab.binding.zigbee.discovery.ZigBeeNodePropertyDiscoverer] - 7C25240000163762: ZigBee node property discovery complete: {zigbee_logicaltype=ROUTER, zigbee_powerlevel=FULL, modelId=ZLL Light, zigbee_networkaddress=63400, zigbee_powersource=MAINS, zigbee_stkversion=2, zigbee_datecode=20140812, zigbee_zclversion=1, zigbee_routes=[], zigbee_lastupdate=, zigbee_stkcompliance=0, vendor=GE_Appliances, zigbee_powermode=RECEIVER_ON_IDLE, zigbee_powersources=[MAINS], hardwareVersion=1, firmwareVersion=0x01030400, zigbee_neighbors=[], zigbee_applicationVersion=4, zigbee_device_initialised=true, zigbee_devices=[]}
2019-04-30 00:33:42.219 [DEBUG] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - 7C25240000163762: Checking endpoint 1 channels
2019-04-30 00:33:42.221 [DEBUG] [org.openhab.binding.zigbee.internal.converter.ZigBeeChannelConverterFactoryImpl] - 7C25240000163762: Removing channel zigbee:switch_onoff in favor of zigbee:switch_level
2019-04-30 00:33:42.221 [DEBUG] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - 7C25240000163762: Dynamically created 1 channels
2019-04-30 00:33:42.221 [DEBUG] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - 7C25240000163762: Device initialization will be skipped as the device is already initialized
2019-04-30 00:33:42.222 [ERROR] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - 7C25240000163762: Exception creating channels 
java.lang.NullPointerException: null
        at org.openhab.binding.zigbee.internal.converter.ZigBeeConverterSwitchLevel.getPollingPeriod(ZigBeeConverterSwitchLevel.java:154) ~[305:org.openhab.binding.zigbee:2.5.0.201904290354]
        at org.openhab.binding.zigbee.handler.ZigBeeThingHandler.doNodeInitialisation(ZigBeeThingHandler.java:396) [305:org.openhab.binding.zigbee:2.5.0.201904290354]
        at org.openhab.binding.zigbee.handler.ZigBeeThingHandler.access$0(ZigBeeThingHandler.java:233) [305:org.openhab.binding.zigbee:2.5.0.201904290354]
        at org.openhab.binding.zigbee.handler.ZigBeeThingHandler$1.call(ZigBeeThingHandler.java:227) [305:org.openhab.binding.zigbee:2.5.0.201904290354]
        at org.openhab.binding.zigbee.handler.ZigBeeThingHandler$1.call(ZigBeeThingHandler.java:1) [305:org.openhab.binding.zigbee:2.5.0.201904290354]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
        at java.lang.Thread.run(Thread.java:748) [?:?]
2019-04-30 00:33:42.458 [DEBUG] [org.openhab.binding.zigbee.internal.converter.ZigBeeConverterSwitchLevel] - 7C25240000163762: ZigBee attribute reports ZclAttribute [cluster=ON_OFF, id=0, name=OnOff, dataType=BOOLEAN, lastValue=true, lastReportTime=Tue Apr 30 00:33:42 EDT 2019]
2019-04-30 00:33:42.459 [DEBUG] [org.openhab.binding.zigbee.converter.ZigBeeBaseChannelConverter] - 7C25240000163762: Channel zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer updated to 100
2019-04-30 00:33:42.459 [DEBUG] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - null: Updating ZigBee channel state zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer to 100
2019-04-30 00:33:42.459 [DEBUG] [org.openhab.binding.zigbee.internal.converter.ZigBeeConverterSwitchLevel] - 7C25240000163762: ZigBee attribute reports ZclAttribute [cluster=ON_OFF, id=0, name=OnOff, dataType=BOOLEAN, lastValue=true, lastReportTime=Tue Apr 30 00:33:42 EDT 2019]
2019-04-30 00:33:42.466 [DEBUG] [org.openhab.binding.zigbee.internal.converter.ZigBeeConverterSwitchLevel] - 7C25240000163762: ZigBee attribute reports ZclAttribute [cluster=ON_OFF, id=0, name=OnOff, dataType=BOOLEAN, lastValue=true, lastReportTime=Tue Apr 30 00:33:42 EDT 2019]
2019-04-30 00:33:42.459 [DEBUG] [org.openhab.binding.zigbee.internal.converter.ZigBeeConverterSwitchLevel] - 7C25240000163762: ZigBee attribute reports ZclAttribute [cluster=ON_OFF, id=0, name=OnOff, dataType=BOOLEAN, lastValue=true, lastReportTime=Tue Apr 30 00:33:42 EDT 2019]
2019-04-30 00:33:42.467 [DEBUG] [org.openhab.binding.zigbee.converter.ZigBeeBaseChannelConverter] - 7C25240000163762: Channel zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer updated to 100
2019-04-30 00:33:42.467 [DEBUG] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - null: Updating ZigBee channel state zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer to 100
2019-04-30 00:33:42.467 [DEBUG] [org.openhab.binding.zigbee.converter.ZigBeeBaseChannelConverter] - 7C25240000163762: Channel zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer updated to 100
2019-04-30 00:33:42.463 [DEBUG] [org.openhab.binding.zigbee.internal.converter.ZigBeeConverterSwitchLevel] - 7C25240000163762: ZigBee attribute reports ZclAttribute [cluster=ON_OFF, id=0, name=OnOff, dataType=BOOLEAN, lastValue=true, lastReportTime=Tue Apr 30 00:33:42 EDT 2019]
2019-04-30 00:33:42.468 [DEBUG] [org.openhab.binding.zigbee.converter.ZigBeeBaseChannelConverter] - 7C25240000163762: Channel zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer updated to 100
2019-04-30 00:33:42.468 [DEBUG] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - null: Updating ZigBee channel state zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer to 100
2019-04-30 00:33:42.462 [DEBUG] [org.openhab.binding.zigbee.internal.converter.ZigBeeConverterSwitchLevel] - 7C25240000163762: ZigBee attribute reports ZclAttribute [cluster=ON_OFF, id=0, name=OnOff, dataType=BOOLEAN, lastValue=true, lastReportTime=Tue Apr 30 00:33:42 EDT 2019]
2019-04-30 00:33:42.462 [DEBUG] [org.openhab.binding.zigbee.internal.converter.ZigBeeConverterSwitchLevel] - 7C25240000163762: ZigBee attribute reports ZclAttribute [cluster=ON_OFF, id=0, name=OnOff, dataType=BOOLEAN, lastValue=true, lastReportTime=Tue Apr 30 00:33:42 EDT 2019]
2019-04-30 00:33:42.462 [DEBUG] [org.openhab.binding.zigbee.internal.converter.ZigBeeConverterSwitchLevel] - 7C25240000163762: ZigBee attribute reports ZclAttribute [cluster=ON_OFF, id=0, name=OnOff, dataType=BOOLEAN, lastValue=true, lastReportTime=Tue Apr 30 00:33:42 EDT 2019]
2019-04-30 00:33:42.462 [DEBUG] [org.openhab.binding.zigbee.internal.converter.ZigBeeConverterSwitchLevel] - 7C25240000163762: ZigBee attribute reports ZclAttribute [cluster=ON_OFF, id=0, name=OnOff, dataType=BOOLEAN, lastValue=true, lastReportTime=Tue Apr 30 00:33:42 EDT 2019]
2019-04-30 00:33:42.461 [DEBUG] [org.openhab.binding.zigbee.internal.converter.ZigBeeConverterSwitchLevel] - 7C25240000163762: ZigBee attribute reports ZclAttribute [cluster=ON_OFF, id=0, name=OnOff, dataType=BOOLEAN, lastValue=true, lastReportTime=Tue Apr 30 00:33:42 EDT 2019]
2019-04-30 00:33:42.461 [DEBUG] [org.openhab.binding.zigbee.internal.converter.ZigBeeConverterSwitchLevel] - 7C25240000163762: ZigBee attribute reports ZclAttribute [cluster=ON_OFF, id=0, name=OnOff, dataType=BOOLEAN, lastValue=true, lastReportTime=Tue Apr 30 00:33:42 EDT 2019]
2019-04-30 00:33:42.470 [DEBUG] [org.openhab.binding.zigbee.handler.ZigbeeIsAliveTracker] - Reset timeout for handler with thingUID=zigbee:device:9b51c72d:7c25240000163762
2019-04-30 00:33:42.473 [DEBUG] [org.openhab.binding.zigbee.internal.converter.ZigBeeConverterSwitchLevel] - 7C25240000163762: ZigBee attribute reports ZclAttribute [cluster=ON_OFF, id=0, name=OnOff, dataType=BOOLEAN, lastValue=true, lastReportTime=Tue Apr 30 00:33:42 EDT 2019]
2019-04-30 00:33:42.473 [DEBUG] [org.openhab.binding.zigbee.converter.ZigBeeBaseChannelConverter] - 7C25240000163762: Channel zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer updated to 100
2019-04-30 00:33:42.473 [DEBUG] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - 7C25240000163762: Updating ZigBee channel state zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer to 100
2019-04-30 00:33:42.473 [DEBUG] [org.openhab.binding.zigbee.handler.ZigbeeIsAliveTracker] - Reset timeout for handler with thingUID=zigbee:device:9b51c72d:7c25240000163762
2019-04-30 00:33:42.461 [DEBUG] [org.openhab.binding.zigbee.internal.converter.ZigBeeConverterSwitchLevel] - 7C25240000163762: ZigBee attribute reports ZclAttribute [cluster=ON_OFF, id=0, name=OnOff, dataType=BOOLEAN, lastValue=true, lastReportTime=Tue Apr 30 00:33:42 EDT 2019]
2019-04-30 00:33:42.461 [DEBUG] [org.openhab.binding.zigbee.internal.converter.ZigBeeConverterSwitchLevel] - 7C25240000163762: ZigBee attribute reports ZclAttribute [cluster=ON_OFF, id=0, name=OnOff, dataType=BOOLEAN, lastValue=true, lastReportTime=Tue Apr 30 00:33:42 EDT 2019]
2019-04-30 00:33:42.474 [DEBUG] [org.openhab.binding.zigbee.converter.ZigBeeBaseChannelConverter] - 7C25240000163762: Channel zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer updated to 100
2019-04-30 00:33:42.474 [DEBUG] [org.openhab.binding.zigbee.converter.ZigBeeBaseChannelConverter] - 7C25240000163762: Channel zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer updated to 100
2019-04-30 00:33:42.474 [DEBUG] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - null: Updating ZigBee channel state zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer to 100
2019-04-30 00:33:42.461 [DEBUG] [org.openhab.binding.zigbee.internal.converter.ZigBeeConverterSwitchLevel] - 7C25240000163762: ZigBee attribute reports ZclAttribute [cluster=ON_OFF, id=0, name=OnOff, dataType=BOOLEAN, lastValue=true, lastReportTime=Tue Apr 30 00:33:42 EDT 2019]
2019-04-30 00:33:42.475 [DEBUG] [org.openhab.binding.zigbee.converter.ZigBeeBaseChannelConverter] - 7C25240000163762: Channel zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer updated to 100
2019-04-30 00:33:42.476 [DEBUG] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - null: Updating ZigBee channel state zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer to 100
2019-04-30 00:33:42.472 [DEBUG] [org.openhab.binding.zigbee.handler.ZigbeeIsAliveTracker] - Reset timeout for handler with thingUID=zigbee:device:9b51c72d:7c25240000163762
2019-04-30 00:33:42.470 [DEBUG] [org.openhab.binding.zigbee.converter.ZigBeeBaseChannelConverter] - 7C25240000163762: Channel zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer updated to 100
2019-04-30 00:33:42.476 [DEBUG] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - null: Updating ZigBee channel state zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer to 100
2019-04-30 00:33:42.470 [DEBUG] [org.openhab.binding.zigbee.converter.ZigBeeBaseChannelConverter] - 7C25240000163762: Channel zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer updated to 100
2019-04-30 00:33:42.476 [DEBUG] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - null: Updating ZigBee channel state zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer to 100
2019-04-30 00:33:42.470 [DEBUG] [org.openhab.binding.zigbee.converter.ZigBeeBaseChannelConverter] - 7C25240000163762: Channel zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer updated to 100
2019-04-30 00:33:42.478 [DEBUG] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - null: Updating ZigBee channel state zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer to 100
2019-04-30 00:33:42.470 [DEBUG] [org.openhab.binding.zigbee.converter.ZigBeeBaseChannelConverter] - 7C25240000163762: Channel zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer updated to 100
2019-04-30 00:33:42.478 [DEBUG] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - null: Updating ZigBee channel state zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer to 100
2019-04-30 00:33:42.468 [DEBUG] [org.openhab.binding.zigbee.converter.ZigBeeBaseChannelConverter] - 7C25240000163762: Channel zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer updated to 100
2019-04-30 00:33:42.479 [DEBUG] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - null: Updating ZigBee channel state zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer to 100
2019-04-30 00:33:42.479 [DEBUG] [org.openhab.binding.zigbee.handler.ZigbeeIsAliveTracker] - Reset timeout for handler with thingUID=zigbee:device:9b51c72d:7c25240000163762
2019-04-30 00:33:42.468 [DEBUG] [org.openhab.binding.zigbee.converter.ZigBeeBaseChannelConverter] - 7C25240000163762: Channel zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer updated to 100
2019-04-30 00:33:42.479 [DEBUG] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - null: Updating ZigBee channel state zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer to 100
2019-04-30 00:33:42.468 [DEBUG] [org.openhab.binding.zigbee.converter.ZigBeeBaseChannelConverter] - 7C25240000163762: Channel zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer updated to 100
2019-04-30 00:33:42.468 [DEBUG] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - 7C25240000163762: Updating ZigBee channel state zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer to 100
2019-04-30 00:33:42.463 [DEBUG] [org.openhab.binding.zigbee.internal.converter.ZigBeeConverterSwitchLevel] - 7C25240000163762: ZigBee attribute reports ZclAttribute [cluster=ON_OFF, id=0, name=OnOff, dataType=BOOLEAN, lastValue=true, lastReportTime=Tue Apr 30 00:33:42 EDT 2019]
2019-04-30 00:33:42.480 [DEBUG] [org.openhab.binding.zigbee.converter.ZigBeeBaseChannelConverter] - 7C25240000163762: Channel zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer updated to 100
2019-04-30 00:33:42.480 [DEBUG] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - null: Updating ZigBee channel state zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer to 100
2019-04-30 00:33:42.480 [DEBUG] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - null: Updating ZigBee channel state zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer to 100
2019-04-30 00:33:42.481 [DEBUG] [org.openhab.binding.zigbee.handler.ZigbeeIsAliveTracker] - Reset timeout for handler with thingUID=zigbee:device:9b51c72d:7c25240000163762
2019-04-30 00:33:42.481 [DEBUG] [org.openhab.binding.zigbee.handler.ZigbeeIsAliveTracker] - Reset timeout for handler with thingUID=zigbee:device:9b51c72d:7c25240000163762
2019-04-30 00:33:42.482 [DEBUG] [org.openhab.binding.zigbee.handler.ZigbeeIsAliveTracker] - Reset timeout for handler with thingUID=zigbee:device:9b51c72d:7c25240000163762
2019-04-30 00:33:42.479 [DEBUG] [org.openhab.binding.zigbee.handler.ZigbeeIsAliveTracker] - Reset timeout for handler with thingUID=zigbee:device:9b51c72d:7c25240000163762
2019-04-30 00:33:42.474 [DEBUG] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - null: Updating ZigBee channel state zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer to 100
2019-04-30 00:33:42.482 [DEBUG] [org.openhab.binding.zigbee.handler.ZigbeeIsAliveTracker] - Reset timeout for handler with thingUID=zigbee:device:9b51c72d:7c25240000163762
2019-04-30 00:33:42.481 [DEBUG] [org.openhab.binding.zigbee.handler.ZigbeeIsAliveTracker] - Reset timeout for handler with thingUID=zigbee:device:9b51c72d:7c25240000163762
2019-04-30 00:33:42.484 [DEBUG] [org.openhab.binding.zigbee.handler.ZigbeeIsAliveTracker] - Reset timeout for handler with thingUID=zigbee:device:9b51c72d:7c25240000163762
2019-04-30 00:33:42.484 [DEBUG] [org.openhab.binding.zigbee.handler.ZigbeeIsAliveTracker] - Reset timeout for handler with thingUID=zigbee:device:9b51c72d:7c25240000163762
2019-04-30 00:33:42.487 [DEBUG] [org.openhab.binding.zigbee.handler.ZigbeeIsAliveTracker] - Reset timeout for handler with thingUID=zigbee:device:9b51c72d:7c25240000163762
2019-04-30 00:33:42.486 [DEBUG] [org.openhab.binding.zigbee.handler.ZigbeeIsAliveTracker] - Reset timeout for handler with thingUID=zigbee:device:9b51c72d:7c25240000163762
2019-04-30 00:33:42.485 [DEBUG] [org.openhab.binding.zigbee.handler.ZigbeeIsAliveTracker] - Reset timeout for handler with thingUID=zigbee:device:9b51c72d:7c25240000163762
2019-04-30 00:33:42.485 [DEBUG] [org.openhab.binding.zigbee.handler.ZigbeeIsAliveTracker] - Reset timeout for handler with thingUID=zigbee:device:9b51c72d:7c25240000163762

After this, I tried turning off the bulb and got this in the openhab.log...

2019-04-30 00:34:27.070 [DEBUG] [org.eclipse.smarthome.config.core.ConfigDescriptionRegistry] - No config description found for 'thing:zigbee:device:9b51c72d:7c25240000163762', using alias 'thing-type:zigbee:device' instead
2019-04-30 00:34:27.076 [DEBUG] [org.eclipse.smarthome.config.core.status.ConfigStatusService] - There is no config status provider for entity zigbee:device:9b51c72d:7c25240000163762 available.

And this in the zigbee log...

2019-04-30 00:34:30.255 [DEBUG] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - 7C25240000163762: Command for channel zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer --> OFF [OnOffType]
2019-04-30 00:34:30.256 [DEBUG] [org.openhab.binding.zigbee.handler.ZigBeeThingHandler] - 7C25240000163762: No handler found for zigbee:device:9b51c72d:7c25240000163762:7C25240000163762_1_dimmer

I was able to get things back to normal by rolling back the org.openhab.binding.zigbee.jar to 2.5.0.201904190356.

@5iver
Copy link
Author

5iver commented May 1, 2019

@cdjackson, did this issue sneak past you? We probably should revert #427 or get a fix in before others start using this version.

@cdjackson
Copy link
Contributor

cdjackson commented May 1, 2019 via email

@5iver
Copy link
Author

5iver commented May 1, 2019

OK... but I'll ping him too!

@cdjackson
Copy link
Contributor

cdjackson commented May 1, 2019 via email

@5iver
Copy link
Author

5iver commented May 2, 2019

Bump

@cdjackson
Copy link
Contributor

I thought you'd pinged @YordanDZhelev - I'm sure I saw an email, but maybe it wasn't through github.

@YordanDZhelev are you able to take a look at this please? Since it seems the binding is currently unusable, it is a little urgent.

@5iver
Copy link
Author

5iver commented May 2, 2019

I did (in the PR) but no response. I've looked through the code, but this was a big PR and went deeper than I could follow.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants