Initializing an innr RS 230 C

Add-ons Bindings
,
1

Hi,
I have difficulties to initialize an innr bulb (RS 230 C).

  • zigbee_manufacturercode 0x1166
  • modelId RS 230 C

I have already associated 3 other bulbs of the same model, but the 4th seems to resist: openhab have discovered 16 properties but I see 21 properties for the 3 others. The property zigbee_device_initialised
remains false. I have tried a lot of time to rescan the device by doing:

  • put openhab in scan mode

  • switch on the bulb:

    • the bulb iterate over colors (meaning it searching to associate)
    • the bulb goes white 100%
    • the bulb makes a short glitch of light (probably because he found the coordinator to associate)
    • the bulb transmit data to openhab (15s)
    • the bulb makes a short glitch again and goes to 50% of light (meaning it has finished to transmit)

When switching off and on the bulb, it redo the above steps, as if it consider it not initialized. My other bulb of the same model does not do the iteration over colors when starting: they just show up with the last defined colored light. I guess this is because openhab and the bulb have not finished the initialization process and the bulb still consider it is not initialized.

I have tried to reset the bulb with the innr procedure (6 x switch on), and of course I tried to delete the thing from openhab and redo the full process.

Have you some advice about finishing the process ? I am also thinking that maybe this bulb has an hardware problem I cannot solve.

2

Go to the Karaf console.

Use zigbee nodes to get a list of your bulbs.

Compare the output from zigbee fingerprint <IEEE Address> for your bulbs. If there are no differences, chances are that your bulb is defective. Otherwise please post the differences so that @chris can have a look at the problem.

3

I did:

openhab> zigbee fingerprint 60A423FFFEF0C92E
An unexpected error occurred during execution.

and in the logs:

15:16:40.087 [ERROR] [ab.core.io.console.ConsoleInterpreter] - An error occurred while executing the console command.
java.lang.NullPointerException: null
	at com.zsmartsystems.zigbee.ZigBeeDeviceType.getByValue(ZigBeeDeviceType.java:648) ~[?:?]
	at com.zsmartsystems.zigbee.console.ZigBeeConsoleDeviceFingerprintCommand.getEndpointInfo(ZigBeeConsoleDeviceFingerprintCommand.java:171) ~[?:?]
	at com.zsmartsystems.zigbee.console.ZigBeeConsoleDeviceFingerprintCommand.process(ZigBeeConsoleDeviceFingerprintCommand.java:138) ~[?:?]
	at org.openhab.binding.zigbee.console.internal.ZigBeeConsoleCommandExtension.handleZigbeeCommand(ZigBeeConsoleCommandExtension.java:149) ~[?:?]
	at org.openhab.binding.zigbee.console.internal.ZigBeeConsoleCommandExtension.handleCommand(ZigBeeConsoleCommandExtension.java:117) ~[?:?]
	at org.openhab.binding.zigbee.console.internal.ZigBeeConsoleCommandExtension.execute(ZigBeeConsoleCommandExtension.java:89) ~[?:?]
	at org.openhab.core.io.console.ConsoleInterpreter.execute(ConsoleInterpreter.java:55) [bundleFile:?]
	at org.openhab.core.io.console.karaf.internal.CommandWrapper.execute(CommandWrapper.java:78) [bundleFile:?]
	at org.apache.karaf.shell.impl.console.osgi.secured.SecuredCommand.execute(SecuredCommand.java:68) [bundleFile:4.3.2]
	at org.apache.karaf.shell.impl.console.osgi.secured.SecuredCommand.execute(SecuredCommand.java:86) [bundleFile:4.3.2]
	at org.apache.felix.gogo.runtime.Closure.executeCmd(Closure.java:599) [bundleFile:4.3.2]
	at org.apache.felix.gogo.runtime.Closure.executeStatement(Closure.java:526) [bundleFile:4.3.2]
	at org.apache.felix.gogo.runtime.Closure.execute(Closure.java:415) [bundleFile:4.3.2]
	at org.apache.felix.gogo.runtime.Pipe.doCall(Pipe.java:416) [bundleFile:4.3.2]
	at org.apache.felix.gogo.runtime.Pipe.call(Pipe.java:229) [bundleFile:4.3.2]
	at org.apache.felix.gogo.runtime.Pipe.call(Pipe.java:59) [bundleFile:4.3.2]
	at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
	at java.lang.Thread.run(Thread.java:829) [?:?]
4

seems to be solved in 3.2.0 M4
https://issueexplorer.com/issue/openhab/org.openhab.binding.zigbee/686

but I cannot wait too moch the release, as I have to return the bulb at some point…

5

As an option, you could upgrade to the latest snapshot:
https://ci.openhab.org/job/openHAB-Zigbee/

6

Ok, I upgraded to openhab 3.2.0~M5.

Fingerprinting a working bulb goes fine:

openhab> zigbee fingerprint 60A423FFFEF0C92E
|>| Node Descriptor
| |> Logical Type               ROUTER
| |> MAC Capabilities           [FULL_FUNCTION_DEVICE, MAINS_POWER, RECEIVER_ON_WHEN_IDLE]
| |> Stack Compliance           22
| |> Server Capabilities        []
| |> Buffer Size                82
| |> Incoming Transfer Size     82
| |> Outgoing Transfer Size     82
|
|>| Power Descriptor
| |> Available Power Sources    [MAINS]
| |> Current Power Source       MAINS
| |> Current Power Mode         RECEIVER_ON_IDLE
| |> Power Level                FULL
|
|>| ZDO
| |> ManagementBindRequest      TIMEOUT
| |> IeeeAddressRequest         SUCCESS
| |> ManagementLqiRequest       SUCCESS
| |> ManagementRoutingRequest   SUCCESS
|
|>| Basic Information
| |> Generic Device Class       0
| |> Generic Device Type        6
| |> Manufacturer Name          innr
| |> Model Indentifier          RS 230 C
| |> Product Code               ByteArray [value=30 31 30 31 30 30 32 34 31]
| |> Product URL                www.innr.com
| |> Date Code                  20191114-214
| |> Application Version        16
| |> Software Build ID          2.8
| |> Hardware Version           1
| |> Zcl Version                3
| |> Stack Version              101
| |
| |>| Endpoint 1
| | |> Profile                  0104  ZIGBEE_HOME_AUTOMATION
| | |> Device Type              010D  EXTENDED_COLOR_LIGHT
| | |> Device Version           1
| | |
| | |>| Input Clusters
| | | |
| | | |>| Cluster 0000 Basic
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |
| | | | |>| Commands Generated
| | | | |
| | | | |>| Commands Received
| | | | | |> 0000 ResetToFactoryDefaultsCommand
| | | | |
| | | | |>| Attributes Supported
| | | | | |> 0000 ZCL Version
| | | | | |> 0001 Application Version
| | | | | |> 0002 Stack Version
| | | | | |> 0003 HW Version
| | | | | |> 0004 Manufacturer Name
| | | | | |> 0005 Model Identifier
| | | | | |> 0006 Date Code
| | | | | |> 0007 Power Source
| | | | | |> 0008 Generic Device Class
| | | | | |> 0009 Generic Device Type
| | | | | |> 000A Product Code
| | | | | |> 000B Product URL
| | | | | |> 0012 Device Enabled
| | | | | |> 4000 SW Build ID
| | | | | |> FFFD Unknown
| | | |
| | | |>| Cluster 0003 Identify
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |> Unsupported locally
| | | |
| | | |>| Cluster 0004 Groups
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |> Unsupported locally
| | | |
| | | |>| Cluster 0005 Scenes
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |
| | | | |>| Commands Generated
| | | | | |> 0000 AddSceneCommand
| | | | | |> 0001 ViewSceneCommand
| | | | | |> 0002 RemoveSceneCommand
| | | | | |> 0003 RemoveAllScenesCommand
| | | | | |> 0004 StoreSceneCommand
| | | | | |> 0006 GetSceneMembershipCommand
| | | | | |> 0040 EnhancedAddSceneCommand
| | | | | |> 0041 EnhancedViewSceneCommand
| | | | | |> 0042 CopySceneCommand
| | | | |
| | | | |>| Commands Received
| | | | | |> 0000 AddSceneCommand
| | | | | |> 0001 ViewSceneCommand
| | | | | |> 0002 RemoveSceneCommand
| | | | | |> 0003 RemoveAllScenesCommand
| | | | | |> 0004 StoreSceneCommand
| | | | | |> 0005 RecallSceneCommand
| | | | | |> 0006 GetSceneMembershipCommand
| | | | | |> 0040 EnhancedAddSceneCommand
| | | | | |> 0041 EnhancedViewSceneCommand
| | | | | |> 0042 CopySceneCommand
| | | | |
| | | | |>| Attributes Supported
| | | | | |> 0000 Scene Count
| | | | | |> 0001 Current Scene
| | | | | |> 0002 Current Group
| | | | | |> 0003 Scene Valid
| | | | | |> 0004 Name Support
| | | | | |> FFFD Unknown
| | | |
| | | |>| Cluster 0006 On/Off
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |
| | | | |>| Commands Generated
| | | | |
| | | | |>| Commands Received
| | | | | |> 0000 OffCommand
| | | | | |> 0001 OnCommand
| | | | | |> 0002 ToggleCommand
| | | | | |> 0040 OffWithEffectCommand
| | | | | |> 0041 OnWithRecallGlobalSceneCommand
| | | | | |> 0042 OnWithTimedOffCommand
| | | | |
| | | | |>| Attributes Supported
| | | | | |> 0000 On Off
| | | | | |> 4000 Global Scene Control
| | | | | |> 4001 On Time
| | | | | |> 4002 Off Wait Time
| | | | | |> 4003 Start Up On Off
| | | | | |> FFFD Unknown
| | | |
| | | |>| Cluster 0008 Level Control
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |
| | | | |>| Commands Generated
| | | | |
| | | | |>| Commands Received
| | | | | |> 0000 MoveToLevelCommand
| | | | | |> 0001 MoveCommand
| | | | | |> 0002 StepCommand
| | | | | |> 0003 StopCommand
| | | | | |> 0004 MoveToLevelWithOnOffCommand
| | | | | |> 0005 MoveWithOnOffCommand
| | | | | |> 0006 StepWithOnOffCommand
| | | | | |> 0007 StopWithOnOffCommand
| | | | |
| | | | |>| Attributes Supported
| | | | | |> 0000 Current Level
| | | | | |> 0001 Remaining Time
| | | | | |> 000F Options
| | | | | |> 0010 On Off Transition Time
| | | | | |> 0011 On Level
| | | | | |> 4000 Start Up Current Level
| | | | | |> FFFD Unknown
| | | |
| | | |>| Cluster 0300 Color Control
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |> Unsupported locally
| | | |
| | | |>| Cluster 0B05 Diagnostics
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |> Unsupported locally
| | | |
| | | |>| Cluster 1000 
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |> Unsupported locally
| | | |
| | | |>| Cluster FC82 
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |> Unsupported locally
| | |
| | |>| Output Clusters
| | | |
| | | |>| Cluster 0019 Ota Upgrade
| | | | |> Type                 Client [Output]
| | | | |> Manufacturer Spec.   No
| | | | |
| | | | |>| Commands Generated
| | | | | |> 0001 QueryNextImageCommand
| | | | | |> 0003 ImageBlockCommand
| | | | | |> 0006 UpgradeEndCommand
| | | | |
| | | | |>| Commands Received
| | | | |
| | | | |>| Attributes Supported
| | | | | |> 0000 Upgrade Server ID
| | | | | |> 0001 File Offset
| | | | | |> 0002 Current File Version
| | | | | |> 0004 Downloaded File Version
| | | | | |> 0006 Image Upgrade Status
| | | | | |> 0007 Manufacturer ID
| | | | | |> 0008 Image Type ID
| | | | | |> 0009 Minimum Block Request Period
| | | | | |> FFFD Unknown
| |
| |>| Endpoint 242
| | |> Profile                  A1E0  ZIGBEE_GREEN_POWER
| | |> Device Type              0061
| | |> Device Version           0

The non working one is different.

When fingerprinting during the first scan (I cannot redo the fingerprint after the communication), I obtain:

openhab> zigbee fingerprint 804B50FFFE422D94
|>| Node Descriptor
| |> Logical Type               ROUTER
| |> MAC Capabilities           [FULL_FUNCTION_DEVICE, MAINS_POWER, RECEIVER_ON_WHEN_IDLE]
| |> Stack Compliance           22
| |> Server Capabilities        []
| |> Buffer Size                82
| |> Incoming Transfer Size     82
| |> Outgoing Transfer Size     82
|
|>| Power Descriptor
| |> Available Power Sources    [MAINS]
| |> Current Power Source       MAINS
| |> Current Power Mode         RECEIVER_ON_IDLE
| |> Power Level                FULL
|
|>| ZDO
| |> ManagementBindRequest      TIMEOUT
| |> IeeeAddressRequest         TIMEOUT
| |> ManagementLqiRequest       TIMEOUT
| |> ManagementRoutingRequest   TIMEOUT
|
|>| Basic Information
| |> Generic Device Class       
| |> Generic Device Type        
| |> Manufacturer Name          
| |> Model Indentifier          
| |> Product Code               
| |> Product URL                
| |> Date Code                  
| |> Application Version        
| |> Software Build ID          
| |> Hardware Version           
| |> Zcl Version                3
| |> Stack Version              101
| |
| |>| Endpoint 1
| | |> Profile                  0104  ZIGBEE_HOME_AUTOMATION
| | |> Device Type              010D  EXTENDED_COLOR_LIGHT
| | |> Device Version           1
| | |
| | |>| Input Clusters
| | | |
| | | |>| Cluster 0000 Basic
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |
| | | | |>| Commands Generated
| | | | |
| | | | |>| Commands Received
| | | | | |> 0000 ResetToFactoryDefaultsCommand
| | | | |
| | | | |>| Attributes Supported
| | | | | |> 0000 ZCL Version
| | | | | |> 0001 Application Version
| | | | | |> 0002 Stack Version
| | | | | |> 0003 HW Version
| | | | | |> 0004 Manufacturer Name
| | | | | |> 0005 Model Identifier
| | | | | |> 0006 Date Code
| | | | | |> 0007 Power Source
| | | | | |> 0008 Generic Device Class
| | | | | |> 0009 Generic Device Type
| | | | | |> 000A Product Code
| | | | | |> 000B Product URL
| | | | | |> 0012 Device Enabled
| | | | | |> 4000 SW Build ID
| | | | | |> FFFD Unknown
| | | |
| | | |>| Cluster 0003 Identify
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |> Unsupported locally
| | | |
| | | |>| Cluster 0004 Groups
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |> Unsupported locally
| | | |
| | | |>| Cluster 0005 Scenes
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |
| | | | |>| Commands Generated
| | | | | |> 0000 AddSceneCommand
| | | | | |> 0001 ViewSceneCommand
| | | | | |> 0002 RemoveSceneCommand
| | | | | |> 0003 RemoveAllScenesCommand
| | | | | |> 0004 StoreSceneCommand
| | | | | |> 0006 GetSceneMembershipCommand
| | | | | |> 0040 EnhancedAddSceneCommand
| | | | | |> 0041 EnhancedViewSceneCommand
| | | | | |> 0042 CopySceneCommand
| | | | |
| | | | |>| Commands Received
| | | | | |> 0000 AddSceneCommand
| | | | | |> 0001 ViewSceneCommand
| | | | | |> 0002 RemoveSceneCommand
| | | | | |> 0003 RemoveAllScenesCommand
| | | | | |> 0004 StoreSceneCommand
| | | | | |> 0005 RecallSceneCommand
| | | | | |> 0006 GetSceneMembershipCommand
| | | | | |> 0040 EnhancedAddSceneCommand
| | | | | |> 0041 EnhancedViewSceneCommand
| | | | | |> 0042 CopySceneCommand
| | | | |
| | | | |>| Attributes Supported
| | | | | |> 0000 Scene Count
| | | | | |> 0001 Current Scene
| | | | | |> 0002 Current Group
| | | | | |> 0003 Scene Valid
| | | | | |> 0004 Name Support
| | | | | |> FFFD Unknown
| | | |
| | | |>| Cluster 0006 On/Off
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |
| | | | |>| Commands Generated
| | | | |
| | | | |>| Commands Received
| | | | | |> 0000 OffCommand
| | | | | |> 0001 OnCommand
| | | | | |> 0002 ToggleCommand
| | | | | |> 0040 OffWithEffectCommand
| | | | | |> 0041 OnWithRecallGlobalSceneCommand
| | | | | |> 0042 OnWithTimedOffCommand
| | | | |
| | | | |>| Attributes Supported
| | | | | |> 0000 On Off
| | | | | |> 4000 Global Scene Control
| | | | | |> 4001 On Time
| | | | | |> 4002 Off Wait Time
| | | | | |> 4003 Start Up On Off
| | | | | |> FFFD Unknown
| | | |
| | | |>| Cluster 0008 Level Control
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |
| | | | |>| Commands Generated
| | | | |
| | | | |>| Commands Received
| | | | | |> 0000 MoveToLevelCommand
| | | | | |> 0001 MoveCommand
| | | | | |> 0002 StepCommand
| | | | | |> 0003 StopCommand
| | | | | |> 0004 MoveToLevelWithOnOffCommand
| | | | | |> 0005 MoveWithOnOffCommand
| | | | | |> 0006 StepWithOnOffCommand
| | | | | |> 0007 StopWithOnOffCommand
| | | | |
| | | | |>| Attributes Supported
| | | | | |> 0000 Current Level
| | | | | |> 0001 Remaining Time
| | | | | |> 000F Options
| | | | | |> 0010 On Off Transition Time
| | | | | |> 0011 On Level
| | | | | |> 4000 Start Up Current Level
| | | | | |> FFFD Unknown
| | | |
| | | |>| Cluster 0300 Color Control
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |> Unsupported locally
| | | |
| | | |>| Cluster 0B05 Diagnostics
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |> Unsupported locally
| | | |
| | | |>| Cluster 1000 
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |> Unsupported locally
| | | |
| | | |>| Cluster FC82 
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |> Unsupported locally
| | |
| | |>| Output Clusters
| | | |
| | | |>| Cluster 0019 Ota Upgrade
| | | | |> Type                 Client [Output]
| | | | |> Manufacturer Spec.   No
| | | | |
| | | | |>| Commands Generated
| | | | | |> 0001 QueryNextImageCommand
| | | | | |> 0003 ImageBlockCommand
| | | | | |> 0006 UpgradeEndCommand
| | | | |
| | | | |>| Commands Received
| | | | |
| | | | |>| Attributes Supported
| | | | | |> 0000 Upgrade Server ID
| | | | | |> 0001 File Offset
| | | | | |> 0002 Current File Version
| | | | | |> 0004 Downloaded File Version
| | | | | |> 0006 Image Upgrade Status
| | | | | |> 0007 Manufacturer ID
| | | | | |> 0008 Image Type ID
| | | | | |> 0009 Minimum Block Request Period
| | | | | |> FFFD Unknown
| |
| |>| Endpoint 242
| | |> Profile                  A1E0  ZIGBEE_GREEN_POWER
| | |> Device Type              0061
| | |> Device Version           0

Rescanning again and switching off/on the bulb collects more information:

openhab> zigbee fingerprint 804B50FFFE422D94
|>| Node Descriptor
| |> Logical Type               ROUTER
| |> MAC Capabilities           [FULL_FUNCTION_DEVICE, MAINS_POWER, RECEIVER_ON_WHEN_IDLE]
| |> Stack Compliance           22
| |> Server Capabilities        []
| |> Buffer Size                82
| |> Incoming Transfer Size     82
| |> Outgoing Transfer Size     82
|
|>| Power Descriptor
| |> Available Power Sources    [MAINS]
| |> Current Power Source       MAINS
| |> Current Power Mode         RECEIVER_ON_IDLE
| |> Power Level                FULL
|
|>| ZDO
| |> ManagementBindRequest      TIMEOUT
| |> IeeeAddressRequest         TIMEOUT
| |> ManagementLqiRequest       TIMEOUT
| |> ManagementRoutingRequest   SUCCESS
|
|>| Basic Information
| |> Generic Device Class       0
| |> Generic Device Type        6
| |> Manufacturer Name          innr
| |> Model Indentifier          RS 230 C
| |> Product Code               ByteArray [value=30 31 30 31 30 30 32 34 31]
| |> Product URL                www.innr.com
| |> Date Code                  20191114-214
| |> Application Version        16
| |> Software Build ID          2.8
| |> Hardware Version           1
| |> Zcl Version                3
| |> Stack Version              101
| |
| |>| Endpoint 1
| | |> Profile                  0104  ZIGBEE_HOME_AUTOMATION
| | |> Device Type              010D  EXTENDED_COLOR_LIGHT
| | |> Device Version           1
| | |
| | |>| Input Clusters
| | | |
| | | |>| Cluster 0000 Basic
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |
| | | | |>| Commands Generated
| | | | |
| | | | |>| Commands Received
| | | | | |> 0000 ResetToFactoryDefaultsCommand
| | | | |
| | | | |>| Attributes Supported
| | | | | |> 0000 ZCL Version
| | | | | |> 0001 Application Version
| | | | | |> 0002 Stack Version
| | | | | |> 0003 HW Version
| | | | | |> 0004 Manufacturer Name
| | | | | |> 0005 Model Identifier
| | | | | |> 0006 Date Code
| | | | | |> 0007 Power Source
| | | | | |> 0008 Generic Device Class
| | | | | |> 0009 Generic Device Type
| | | | | |> 000A Product Code
| | | | | |> 000B Product URL
| | | | | |> 0012 Device Enabled
| | | | | |> 4000 SW Build ID
| | | | | |> FFFD Unknown
| | | |
| | | |>| Cluster 0003 Identify
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |> Unsupported locally
| | | |
| | | |>| Cluster 0004 Groups
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |> Unsupported locally
| | | |
| | | |>| Cluster 0005 Scenes
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |
| | | | |>| Commands Generated
| | | | | |> 0000 AddSceneCommand
| | | | | |> 0001 ViewSceneCommand
| | | | | |> 0002 RemoveSceneCommand
| | | | | |> 0003 RemoveAllScenesCommand
| | | | | |> 0004 StoreSceneCommand
| | | | | |> 0006 GetSceneMembershipCommand
| | | | | |> 0040 EnhancedAddSceneCommand
| | | | | |> 0041 EnhancedViewSceneCommand
| | | | | |> 0042 CopySceneCommand
| | | | |
| | | | |>| Commands Received
| | | | | |> 0000 AddSceneCommand
| | | | | |> 0001 ViewSceneCommand
| | | | | |> 0002 RemoveSceneCommand
| | | | | |> 0003 RemoveAllScenesCommand
| | | | | |> 0004 StoreSceneCommand
| | | | | |> 0005 RecallSceneCommand
| | | | | |> 0006 GetSceneMembershipCommand
| | | | | |> 0040 EnhancedAddSceneCommand
| | | | | |> 0041 EnhancedViewSceneCommand
| | | | | |> 0042 CopySceneCommand
| | | | |
| | | | |>| Attributes Supported
| | | | | |> 0000 Scene Count
| | | | | |> 0001 Current Scene
| | | | | |> 0002 Current Group
| | | | | |> 0003 Scene Valid
| | | | | |> 0004 Name Support
| | | | | |> FFFD Unknown
| | | |
| | | |>| Cluster 0006 On/Off
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |
| | | | |>| Commands Generated
| | | | |
| | | | |>| Commands Received
| | | | | |> 0000 OffCommand
| | | | | |> 0001 OnCommand
| | | | | |> 0002 ToggleCommand
| | | | | |> 0040 OffWithEffectCommand
| | | | | |> 0041 OnWithRecallGlobalSceneCommand
| | | | | |> 0042 OnWithTimedOffCommand
| | | | |
| | | | |>| Attributes Supported
| | | | | |> 0000 On Off
| | | | | |> 4000 Global Scene Control
| | | | | |> 4001 On Time
| | | | | |> 4002 Off Wait Time
| | | | | |> 4003 Start Up On Off
| | | | | |> FFFD Unknown
| | | |
| | | |>| Cluster 0008 Level Control
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |
| | | | |>| Commands Generated
| | | | |
| | | | |>| Commands Received
| | | | | |> 0000 MoveToLevelCommand
| | | | | |> 0001 MoveCommand
| | | | | |> 0002 StepCommand
| | | | | |> 0003 StopCommand
| | | | | |> 0004 MoveToLevelWithOnOffCommand
| | | | | |> 0005 MoveWithOnOffCommand
| | | | | |> 0006 StepWithOnOffCommand
| | | | | |> 0007 StopWithOnOffCommand
| | | | |
| | | | |>| Attributes Supported
| | | | | |> 0000 Current Level
| | | | | |> 0001 Remaining Time
| | | | | |> 000F Options
| | | | | |> 0010 On Off Transition Time
| | | | | |> 0011 On Level
| | | | | |> 4000 Start Up Current Level
| | | | | |> FFFD Unknown
| | | |
| | | |>| Cluster 0300 Color Control
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |> Unsupported locally
| | | |
| | | |>| Cluster 0B05 Diagnostics
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |> Unsupported locally
| | | |
| | | |>| Cluster 1000 
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |> Unsupported locally
| | | |
| | | |>| Cluster FC82 
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |> Unsupported locally
| | |
| | |>| Output Clusters
| | | |
| | | |>| Cluster 0019 Ota Upgrade
| | | | |> Type                 Client [Output]
| | | | |> Manufacturer Spec.   No
| | | | |
| | | | |>| Commands Generated
| | | | | |> 0001 QueryNextImageCommand
| | | | | |> 0003 ImageBlockCommand
| | | | | |> 0006 UpgradeEndCommand
| | | | |
| | | | |>| Commands Received
| | | | |
| | | | |>| Attributes Supported
| | | | | |> 0000 Upgrade Server ID
| | | | | |> 0001 File Offset
| | | | | |> 0002 Current File Version
| | | | | |> 0004 Downloaded File Version
| | | | | |> 0006 Image Upgrade Status
| | | | | |> 0007 Manufacturer ID
| | | | | |> 0008 Image Type ID
| | | | | |> 0009 Minimum Block Request Period
| | | | | |> FFFD Unknown
| |
| |>| Endpoint 242
| | |> Profile                  A1E0  ZIGBEE_GREEN_POWER
| | |> Device Type              0061
| | |> Device Version           0

But there is still these 3 TIMEOUTs:

|>| ZDO
| |> ManagementBindRequest      TIMEOUT
| |> IeeeAddressRequest         TIMEOUT
| |> ManagementLqiRequest       TIMEOUT
| |> ManagementRoutingRequest   SUCCESS

Redoing again gives one more success:

|>| ZDO
| |> ManagementBindRequest      TIMEOUT
| |> IeeeAddressRequest         TIMEOUT
| |> ManagementLqiRequest       SUCCESS
| |> ManagementRoutingRequest   SUCCESS

At the end, I have only 16 properties (expected 21).

7

I have a second bulb that has the same issue (it was working fine, but turned to HANDLER_ERROR state). So I decided to remove it and it has the same symptom: I cannot include it fully anymore.

Debugging the inclusion process shows an exception (I can reproduce it with 2 bulbs):

09:27:27.479 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE422D94: Node update. NWK Address=7361
09:27:27.481 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE422D94: Node 7361 is not updated
09:27:27.482 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX CMD: BindResponse [7361/0 -> 0000/0, cluster=8021, TID=4A, status=SUCCESS]
09:27:27.484 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: BindResponse [7361/0 -> 0000/0, cluster=8021, TID=4A, status=SUCCESS] 
09:27:27.486 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=804B50FFFE422D94 queueTime=84, state=COMPLETE, sendCnt=1, command=BindRequest [0000/0 -> 7361/0, cluster=0021, TID=4A, srcAddress=804B50FFFE422D94, srcEndpoint=1, bindCluster=768, dstAddrMode=3, dstAddress=84FD27FFFE0E4D53, dstEndpoint=1]]
09:27:27.486 [WARN ] [ommon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: 
java.lang.NullPointerException: null
	at org.openhab.binding.zigbee.internal.converter.ZigBeeConverterColorTemperature.initializeDevice(ZigBeeConverterColorTemperature.java:88) ~[?:?]
	at org.openhab.binding.zigbee.discovery.ZigBeeDiscoveryService$2.run(ZigBeeDiscoveryService.java:260) ~[?:?]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) ~[?:?]
	at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
	at java.lang.Thread.run(Thread.java:829) [?:?]
09:27:27.489 [DEBUG] [.transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 1 outstanding
09:27:27.490 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - 804B50FFFE422D94: transactionComplete, state=COMPLETE, outstanding=0

Maybe this is the root cause that stops the inclusion process ?

8

I also see:

RX EZSP: EzspZigbeeKeyEstablishmentHandler [networkId=0, partner=804B50FFFE422D94, status=EMBER_EEPROM_MFG_VERSION_MISMATCH]

9

The filtered log of an association (after removing the device from openhab) is:

tail -f /var/log/openhab/openhab.log |grep D94
2021-12-08 09:59:24.690 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspTrustCenterJoinHandler [networkId=0, newNodeId=0D24, newNodeEui64=804B50FFFE422D94, status=EMBER_STANDARD_SECURITY_UNSECURED_JOIN, policyDecision=EMBER_USE_PRECONFIGURED_KEY, parentOfNewNodeId=0000]
2021-12-08 09:59:24.692 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE422D94: nodeStatusUpdate - node status is UNSECURED_JOIN, network address is 0D24.
2021-12-08 09:59:24.695 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 804B50FFFE422D94: Device status updated. NWK=0D24
2021-12-08 09:59:24.697 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 804B50FFFE422D94: NWK Discovery add node 0D24
2021-12-08 09:59:24.700 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE422D94: Updating node NWK=0D24
2021-12-08 09:59:24.702 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE422D94: Node update. NWK Address=0D24
2021-12-08 09:59:24.705 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE422D94: Node 0D24 is not updated
2021-12-08 09:59:24.743 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE422D94: Node update. NWK Address=0D24
2021-12-08 09:59:24.746 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE422D94: Node 0D24 is not updated
2021-12-08 09:59:24.755 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingSenderEui64Handler [networkId=0, senderEui64=804B50FFFE422D94]
2021-12-08 09:59:24.762 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE422D94: Node update. NWK Address=0D24
2021-12-08 09:59:24.764 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE422D94: Node 0D24 is not updated
2021-12-08 09:59:24.766 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: DeviceAnnounce [0D24/0 -> 0000/0, cluster=0013, TID=81, nwkAddrOfInterest=0D24, ieeeAddr=804B50FFFE422D94, capability=8E]
2021-12-08 09:59:24.768 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: DeviceAnnounce [0D24/0 -> 0000/0, cluster=0013, TID=81, nwkAddrOfInterest=0D24, ieeeAddr=804B50FFFE422D94, capability=8E] 
2021-12-08 09:59:24.774 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 804B50FFFE422D94: Device announce received. From 0D24, for 0D24
2021-12-08 09:59:24.776 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 804B50FFFE422D94: NWK Discovery add node 0D24
2021-12-08 09:59:24.778 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE422D94: Updating node NWK=0D24
2021-12-08 09:59:24.780 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE422D94: Node update. NWK Address=0D24
2021-12-08 09:59:24.782 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE422D94: Node 0D24 is not updated
2021-12-08 09:59:27.103 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=0D24, sourceEui=804B50FFFE422D94, lastHopLqi=61, lastHopRssi=-77, relayList=]
2021-12-08 09:59:27.155 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE422D94: Node update. NWK Address=0D24
2021-12-08 09:59:27.156 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE422D94: Node 0D24 is not updated
2021-12-08 09:59:27.172 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspZigbeeKeyEstablishmentHandler [networkId=0, partner=804B50FFFE422D94, status=EMBER_EEPROM_MFG_VERSION_MISMATCH]
2021-12-08 09:59:32.213 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspZigbeeKeyEstablishmentHandler [networkId=0, partner=804B50FFFE422D94, status=EMBER_EEPROM_MFG_VERSION_MISMATCH]
2021-12-08 09:59:37.238 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspZigbeeKeyEstablishmentHandler [networkId=0, partner=804B50FFFE422D94, status=EMBER_EEPROM_MFG_VERSION_MISMATCH]
10

I made some trials with a second bulb. This bulb have worked the first time I associated to openhab but the property “initialized” have always been set to false. I deleted it, and tried to reassociate. Now I cannot associate it anymore, even when resetting it (switching off/on 6 times). I cannot undestand why I succeeded the first time, and now I cannot redo it anymore. I suspect that my other bulb has no hardware failure. There is some mismatch somehow in the configuration of openhab, or in the internal state of the bulb.

Here the full log of the association of the second bulb I cannot associate:

tail -f /var/log/openhab/openhab.log |grep 9D0
2021-12-08 11:18:08.540 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspTrustCenterJoinHandler [networkId=0, newNodeId=1F68, newNodeEui64=804B50FFFE4229D0, status=EMBER_STANDARD_SECURITY_UNSECURED_JOIN, policyDecision=EMBER_USE_PRECONFIGURED_KEY, parentOfNewNodeId=0000]
2021-12-08 11:18:08.543 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE4229D0: nodeStatusUpdate - node status is UNSECURED_JOIN, network address is 1F68.
2021-12-08 11:18:08.544 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 804B50FFFE4229D0: Device status updated. NWK=1F68
2021-12-08 11:18:08.547 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 804B50FFFE4229D0: NWK Discovery add node 1F68
2021-12-08 11:18:08.549 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE4229D0: Updating node NWK=1F68
2021-12-08 11:18:08.551 [DEBUG] [atabase.ZigBeeNetworkDatabaseManager] - 804B50FFFE4229D0: Data store: Deferring write for 250ms.
2021-12-08 11:18:08.553 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - 804B50FFFE4229D0: DISCOVERY Extension: Adding discoverer for node
2021-12-08 11:18:08.556 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 804B50FFFE4229D0: Node SVC Discovery: created discoverer
2021-12-08 11:18:08.559 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 804B50FFFE4229D0: Node SVC Discovery: start discovery
2021-12-08 11:18:08.561 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 804B50FFFE4229D0: Node SVC Discovery: starting new tasks [POWER_DESCRIPTOR, ACTIVE_ENDPOINTS, NODE_DESCRIPTOR, NWK_ADDRESS]
2021-12-08 11:18:08.563 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 804B50FFFE4229D0: Node SVC Discovery: scheduled [NWK_ADDRESS, NODE_DESCRIPTOR, POWER_DESCRIPTOR, ACTIVE_ENDPOINTS]
2021-12-08 11:18:08.804 [DEBUG] [atabase.ZigBeeNetworkDatabaseManager] - 804B50FFFE4229D0: Data store: Writing node.
2021-12-08 11:18:08.828 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE4229D0: Node update. NWK Address=1F68
2021-12-08 11:18:08.830 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE4229D0: Node 1F68 is not updated
2021-12-08 11:18:08.838 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingSenderEui64Handler [networkId=0, senderEui64=804B50FFFE4229D0]
2021-12-08 11:18:08.846 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE4229D0: Node update. NWK Address=1F68
2021-12-08 11:18:08.847 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE4229D0: Node 1F68 is not updated
2021-12-08 11:18:08.850 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: DeviceAnnounce [1F68/0 -> 0000/0, cluster=0013, TID=81, nwkAddrOfInterest=1F68, ieeeAddr=804B50FFFE4229D0, capability=8E]
2021-12-08 11:18:08.852 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: DeviceAnnounce [1F68/0 -> 0000/0, cluster=0013, TID=81, nwkAddrOfInterest=1F68, ieeeAddr=804B50FFFE4229D0, capability=8E] 
2021-12-08 11:18:08.855 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 804B50FFFE4229D0: Device announce received. From 1F68, for 1F68
2021-12-08 11:18:08.857 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 804B50FFFE4229D0: NWK Discovery add node 1F68
2021-12-08 11:18:08.858 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE4229D0: Updating node NWK=1F68
2021-12-08 11:18:08.860 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE4229D0: Node update. NWK Address=1F68
2021-12-08 11:18:08.874 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE4229D0: Node 1F68 is not updated
2021-12-08 11:18:10.593 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 804B50FFFE4229D0: Node SVC Discovery: running NWK_ADDRESS
2021-12-08 11:18:10.596 [DEBUG] [transaction.ZigBeeTransactionManager] - 804B50FFFE4229D0: Creating new Transaction Queue
2021-12-08 11:18:10.599 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 804B50FFFE4229D0: Set profile to ZigBeeTransactionProfile [maxOutstandingTransactions=1, interTransactionDelay=50, maxRetries=2]
2021-12-08 11:18:10.602 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 804B50FFFE4229D0: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=0, state=WAITING, sendCnt=0, command=NetworkAddressRequest [0000/0 -> 1F68/0, cluster=0000, TID=--, ieeeAddr=804B50FFFE4229D0, requestType=0, startIndex=0]]
2021-12-08 11:18:10.607 [DEBUG] [transaction.ZigBeeTransactionManager] - 1F68/0: Sending ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=5, state=WAITING, sendCnt=0, command=NetworkAddressRequest [0000/0 -> 1F68/0, cluster=0000, TID=16, ieeeAddr=804B50FFFE4229D0, requestType=0, startIndex=0]]
2021-12-08 11:18:10.612 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0000/0 -> 1F68/0, cluster=0000, TID=16, ieeeAddr=804B50FFFE4229D0, requestType=0, startIndex=0]
2021-12-08 11:18:10.749 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=1F68, sourceEui=804B50FFFE4229D0, lastHopLqi=47, lastHopRssi=-80, relayList=]
2021-12-08 11:18:10.822 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE4229D0: Node update. NWK Address=1F68
2021-12-08 11:18:10.824 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE4229D0: Node 1F68 is not updated
2021-12-08 11:18:10.827 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: NetworkAddressResponse [1F68/0 -> 0000/0, cluster=8000, TID=16, status=SUCCESS, ieeeAddrRemoteDev=804B50FFFE4229D0, nwkAddrRemoteDev=1F68, startIndex=null, nwkAddrAssocDevList=[]]
2021-12-08 11:18:10.830 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: NetworkAddressResponse [1F68/0 -> 0000/0, cluster=8000, TID=16, status=SUCCESS, ieeeAddrRemoteDev=804B50FFFE4229D0, nwkAddrRemoteDev=1F68, startIndex=null, nwkAddrAssocDevList=[]] 
2021-12-08 11:18:10.832 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=230, state=COMPLETE, sendCnt=1, command=NetworkAddressRequest [0000/0 -> 1F68/0, cluster=0000, TID=16, ieeeAddr=804B50FFFE4229D0, requestType=0, startIndex=0]]
2021-12-08 11:18:10.833 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 804B50FFFE4229D0: Node SVC Discovery: NetworkAddressRequest returned NetworkAddressResponse [1F68/0 -> 0000/0, cluster=8000, TID=16, status=SUCCESS, ieeeAddrRemoteDev=804B50FFFE4229D0, nwkAddrRemoteDev=1F68, startIndex=null, nwkAddrAssocDevList=[]]
2021-12-08 11:18:10.835 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 804B50FFFE4229D0: transactionComplete, state=COMPLETE, outstanding=0
2021-12-08 11:18:10.836 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 804B50FFFE4229D0: Node SVC Discovery: NetworkAddressRequest confirmed by unicast
2021-12-08 11:18:10.839 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 804B50FFFE4229D0: Node SVC Discovery: request NWK_ADDRESS successful. Advancing to NODE_DESCRIPTOR.
2021-12-08 11:18:10.841 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 804B50FFFE4229D0: Node SVC Discovery: running NODE_DESCRIPTOR
2021-12-08 11:18:10.844 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 804B50FFFE4229D0: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=0, state=WAITING, sendCnt=0, command=NodeDescriptorRequest [0000/0 -> 1F68/0, cluster=0002, TID=--, nwkAddrOfInterest=1F68]]
2021-12-08 11:18:10.848 [DEBUG] [transaction.ZigBeeTransactionManager] - 1F68/0: Sending ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=4, state=WAITING, sendCnt=0, command=NodeDescriptorRequest [0000/0 -> 1F68/0, cluster=0002, TID=17, nwkAddrOfInterest=1F68]]
2021-12-08 11:18:10.891 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE4229D0: Node update. NWK Address=1F68
2021-12-08 11:18:10.894 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE4229D0: Node 1F68 is not updated
2021-12-08 11:18:10.900 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=57, state=COMPLETE, sendCnt=1, command=NodeDescriptorRequest [0000/0 -> 1F68/0, cluster=0002, TID=17, nwkAddrOfInterest=1F68]]
2021-12-08 11:18:10.901 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 804B50FFFE4229D0: Node SVC Discovery: NodeDescriptorResponse returned NodeDescriptorResponse [1F68/0 -> 0000/0, cluster=8002, TID=17, status=SUCCESS, nwkAddrOfInterest=1F68, nodeDescriptor=NodeDescriptor [apsFlags=0, bufferSize=82, complexDescriptorAvailable=false, manufacturerCode=1166, logicalType=ROUTER, serverCapabilities=[], incomingTransferSize=82, outgoingTransferSize=82, userDescriptorAvailable=false, frequencyBands=[FREQ_2400_MHZ], macCapabilities=[FULL_FUNCTION_DEVICE, MAINS_POWER, RECEIVER_ON_WHEN_IDLE], extendedEndpointListAvailable=false, extendedSimpleDescriptorListAvailable=false, stackCompliance=22]]
2021-12-08 11:18:10.904 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 804B50FFFE4229D0: transactionComplete, state=COMPLETE, outstanding=0
2021-12-08 11:18:10.906 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 804B50FFFE4229D0: Node SVC Discovery: request NODE_DESCRIPTOR successful. Advancing to POWER_DESCRIPTOR.
2021-12-08 11:18:10.908 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 804B50FFFE4229D0: Node SVC Discovery: running POWER_DESCRIPTOR
2021-12-08 11:18:10.911 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 804B50FFFE4229D0: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=0, state=WAITING, sendCnt=0, command=PowerDescriptorRequest [0000/0 -> 1F68/0, cluster=0003, TID=--, nwkAddrOfInterest=1F68]]
2021-12-08 11:18:10.914 [DEBUG] [transaction.ZigBeeTransactionManager] - 1F68/0: Sending ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=4, state=WAITING, sendCnt=0, command=PowerDescriptorRequest [0000/0 -> 1F68/0, cluster=0003, TID=18, nwkAddrOfInterest=1F68]]
2021-12-08 11:18:10.952 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE4229D0: Node update. NWK Address=1F68
2021-12-08 11:18:10.953 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE4229D0: Node 1F68 is not updated
2021-12-08 11:18:10.957 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=47, state=COMPLETE, sendCnt=1, command=PowerDescriptorRequest [0000/0 -> 1F68/0, cluster=0003, TID=18, nwkAddrOfInterest=1F68]]
2021-12-08 11:18:10.957 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 804B50FFFE4229D0: Node SVC Discovery: PowerDescriptorResponse returned PowerDescriptorResponse [1F68/0 -> 0000/0, cluster=8003, TID=18, status=SUCCESS, nwkAddrOfInterest=1F68, powerDescriptor=PowerDescriptor [currentPowerMode=RECEIVER_ON_IDLE, availablePowerSources=[MAINS], currentPowerSource=MAINS, powerLevel=FULL]]
2021-12-08 11:18:10.958 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 804B50FFFE4229D0: Node SVC Discovery: request POWER_DESCRIPTOR successful. Advancing to ACTIVE_ENDPOINTS.
2021-12-08 11:18:10.960 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 804B50FFFE4229D0: transactionComplete, state=COMPLETE, outstanding=0
2021-12-08 11:18:10.960 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 804B50FFFE4229D0: Node SVC Discovery: running ACTIVE_ENDPOINTS
2021-12-08 11:18:10.962 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 804B50FFFE4229D0: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=0, state=WAITING, sendCnt=0, command=ActiveEndpointsRequest [0000/0 -> 1F68/0, cluster=0005, TID=--, nwkAddrOfInterest=1F68]]
2021-12-08 11:18:10.965 [DEBUG] [transaction.ZigBeeTransactionManager] - 1F68/0: Sending ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=2, state=WAITING, sendCnt=0, command=ActiveEndpointsRequest [0000/0 -> 1F68/0, cluster=0005, TID=19, nwkAddrOfInterest=1F68]]
2021-12-08 11:18:11.001 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE4229D0: Node update. NWK Address=1F68
2021-12-08 11:18:11.002 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE4229D0: Node 1F68 is not updated
2021-12-08 11:18:11.006 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=44, state=COMPLETE, sendCnt=1, command=ActiveEndpointsRequest [0000/0 -> 1F68/0, cluster=0005, TID=19, nwkAddrOfInterest=1F68]]
2021-12-08 11:18:11.006 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 804B50FFFE4229D0: Node SVC Discovery: ActiveEndpointsResponse returned CommandResult [SUCCESS, ActiveEndpointsResponse [1F68/0 -> 0000/0, cluster=8005, TID=19, status=SUCCESS, nwkAddrOfInterest=1F68, activeEpList=[1, 242]]]
2021-12-08 11:18:11.008 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 804B50FFFE4229D0: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=0, state=WAITING, sendCnt=0, command=SimpleDescriptorRequest [0000/0 -> 1F68/0, cluster=0004, TID=--, nwkAddrOfInterest=1F68, endpoint=1]]
2021-12-08 11:18:11.011 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 804B50FFFE4229D0: transactionComplete, state=COMPLETE, outstanding=0
2021-12-08 11:18:11.016 [DEBUG] [transaction.ZigBeeTransactionManager] - 1F68/0: Sending ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=7, state=WAITING, sendCnt=0, command=SimpleDescriptorRequest [0000/0 -> 1F68/0, cluster=0004, TID=1A, nwkAddrOfInterest=1F68, endpoint=1]]
2021-12-08 11:18:11.073 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE4229D0: Node update. NWK Address=1F68
2021-12-08 11:18:11.075 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE4229D0: Node 1F68 is not updated
2021-12-08 11:18:11.080 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=71, state=COMPLETE, sendCnt=1, command=SimpleDescriptorRequest [0000/0 -> 1F68/0, cluster=0004, TID=1A, nwkAddrOfInterest=1F68, endpoint=1]]
2021-12-08 11:18:11.080 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 804B50FFFE4229D0: Node SVC Discovery: SimpleDescriptorResponse returned SimpleDescriptorResponse [1F68/0 -> 0000/0, cluster=8004, TID=1A, status=SUCCESS, nwkAddrOfInterest=1F68, length=30, simpleDescriptor=SimpleDescriptor [endpoint=1, profileId=0104, deviceId=010D, deviceVersion=1, inputClusterList=[0000, 0003, 0004, 0005, 0006, 0008, 0300, 0B05, 1000, FC82], outputClusterList=[0019]]]
2021-12-08 11:18:11.083 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 804B50FFFE4229D0: Endpoint 1. Setting server cluster 0000 Basic
2021-12-08 11:18:11.083 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 804B50FFFE4229D0: transactionComplete, state=COMPLETE, outstanding=0
2021-12-08 11:18:11.085 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 804B50FFFE4229D0: Endpoint 1. Setting server cluster 0003 Identify
2021-12-08 11:18:11.086 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 804B50FFFE4229D0: Endpoint 1. Setting server cluster 0004 Groups
2021-12-08 11:18:11.088 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 804B50FFFE4229D0: Endpoint 1. Setting server cluster 0005 Scenes
2021-12-08 11:18:11.090 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 804B50FFFE4229D0: Endpoint 1. Setting server cluster 0006 On/Off
2021-12-08 11:18:11.091 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 804B50FFFE4229D0: Endpoint 1. Setting server cluster 0008 Level Control
2021-12-08 11:18:11.093 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 804B50FFFE4229D0: Endpoint 1. Setting server cluster 0300 Color Control
2021-12-08 11:18:11.095 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 804B50FFFE4229D0: Endpoint 1. Setting server cluster 0B05 Diagnostics
2021-12-08 11:18:11.096 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 804B50FFFE4229D0: Endpoint 1. Unsupported cluster 1000 - using ZclCustomCluster
2021-12-08 11:18:11.098 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 804B50FFFE4229D0: Endpoint 1. Setting server cluster 1000 
2021-12-08 11:18:11.099 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 804B50FFFE4229D0: Endpoint 1. Unsupported cluster FC82 - using ZclCustomCluster
2021-12-08 11:18:11.101 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 804B50FFFE4229D0: Endpoint 1. Setting server cluster FC82 
2021-12-08 11:18:11.104 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 804B50FFFE4229D0: Endpoint 1. Setting client cluster 0019 Ota Upgrade
2021-12-08 11:18:11.105 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 804B50FFFE4229D0: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=0, state=WAITING, sendCnt=0, command=SimpleDescriptorRequest [0000/0 -> 1F68/0, cluster=0004, TID=--, nwkAddrOfInterest=1F68, endpoint=242]]
2021-12-08 11:18:11.108 [DEBUG] [transaction.ZigBeeTransactionManager] - 1F68/0: Sending ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=2, state=WAITING, sendCnt=0, command=SimpleDescriptorRequest [0000/0 -> 1F68/0, cluster=0004, TID=1B, nwkAddrOfInterest=1F68, endpoint=242]]
2021-12-08 11:18:11.151 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE4229D0: Node update. NWK Address=1F68
2021-12-08 11:18:11.153 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE4229D0: Node 1F68 is not updated
2021-12-08 11:18:11.157 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=52, state=COMPLETE, sendCnt=1, command=SimpleDescriptorRequest [0000/0 -> 1F68/0, cluster=0004, TID=1B, nwkAddrOfInterest=1F68, endpoint=242]]
2021-12-08 11:18:11.157 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 804B50FFFE4229D0: Node SVC Discovery: SimpleDescriptorResponse returned SimpleDescriptorResponse [1F68/0 -> 0000/0, cluster=8004, TID=1B, status=SUCCESS, nwkAddrOfInterest=1F68, length=10, simpleDescriptor=SimpleDescriptor [endpoint=242, profileId=A1E0, deviceId=0061, deviceVersion=0, inputClusterList=[], outputClusterList=[0021]]]
2021-12-08 11:18:11.159 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 804B50FFFE4229D0: transactionComplete, state=COMPLETE, outstanding=0
2021-12-08 11:18:11.163 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 804B50FFFE4229D0: Endpoint 242. Setting client cluster 0021 Green Power
2021-12-08 11:18:11.164 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 804B50FFFE4229D0: Node SVC Discovery: request ACTIVE_ENDPOINTS successful. Advancing to null.
2021-12-08 11:18:11.166 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 804B50FFFE4229D0: Node SVC Discovery: complete
2021-12-08 11:18:11.167 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE4229D0: Updating node NWK=1F68
2021-12-08 11:18:11.169 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE4229D0: Node update. NWK Address=1F68
2021-12-08 11:18:11.170 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - 804B50FFFE4229D0: Node descriptor updated
2021-12-08 11:18:11.172 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - 804B50FFFE4229D0: Power descriptor updated
2021-12-08 11:18:11.173 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - 804B50FFFE4229D0: Endpoint 1 added
2021-12-08 11:18:11.175 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - 804B50FFFE4229D0: Endpoint 242 added
2021-12-08 11:18:11.176 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 804B50FFFE4229D0: Set profile to ZigBeeTransactionProfile [maxOutstandingTransactions=1, interTransactionDelay=50, maxRetries=2]
2021-12-08 11:18:11.176 [DEBUG] [atabase.ZigBeeNetworkDatabaseManager] - 804B50FFFE4229D0: Data store: Deferring write for 250ms.
2021-12-08 11:18:11.176 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - 804B50FFFE4229D0: NodeDescriptor passed to Ember NCP NodeDescriptor [apsFlags=0, bufferSize=82, complexDescriptorAvailable=false, manufacturerCode=1166, logicalType=ROUTER, serverCapabilities=[], incomingTransferSize=82, outgoingTransferSize=82, userDescriptorAvailable=false, frequencyBands=[FREQ_2400_MHZ], macCapabilities=[FULL_FUNCTION_DEVICE, MAINS_POWER, RECEIVER_ON_WHEN_IDLE], extendedEndpointListAvailable=false, extendedSimpleDescriptorListAvailable=false, stackCompliance=22]
2021-12-08 11:18:11.191 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 804B50FFFE4229D0: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=0, state=WAITING, sendCnt=0, command=ReadAttributesCommand [Basic: 0000/0 -> 1F68/1, cluster=0000, TID=--, identifiers=[5, 4, 3, 2, 6, 0, 1]]]
2021-12-08 11:18:11.194 [DEBUG] [transaction.ZigBeeTransactionManager] - 1F68/1: Sending ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=3, state=WAITING, sendCnt=0, command=ReadAttributesCommand [Basic: 0000/0 -> 1F68/1, cluster=0000, TID=1C, identifiers=[5, 4, 3, 2, 6, 0, 1]]]
2021-12-08 11:18:11.237 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE4229D0: Node update. NWK Address=1F68
2021-12-08 11:18:11.238 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE4229D0: Node 1F68 is not updated
2021-12-08 11:18:11.244 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=53, state=COMPLETE, sendCnt=1, command=ReadAttributesCommand [Basic: 0000/0 -> 1F68/1, cluster=0000, TID=1C, identifiers=[5, 4, 3, 2, 6, 0, 1]]]
2021-12-08 11:18:11.246 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 804B50FFFE4229D0: transactionComplete, state=COMPLETE, outstanding=0
2021-12-08 11:18:11.248 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 804B50FFFE4229D0: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=0, state=WAITING, sendCnt=0, command=ReadAttributesCommand [Basic: 0000/0 -> 1F68/1, cluster=0000, TID=--, identifiers=[4]]]
2021-12-08 11:18:11.252 [DEBUG] [transaction.ZigBeeTransactionManager] - 1F68/1: Sending ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=5, state=WAITING, sendCnt=0, command=ReadAttributesCommand [Basic: 0000/0 -> 1F68/1, cluster=0000, TID=1D, identifiers=[4]]]
2021-12-08 11:18:11.294 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE4229D0: Node update. NWK Address=1F68
2021-12-08 11:18:11.296 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE4229D0: Node 1F68 is not updated
2021-12-08 11:18:11.301 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=53, state=COMPLETE, sendCnt=1, command=ReadAttributesCommand [Basic: 0000/0 -> 1F68/1, cluster=0000, TID=1D, identifiers=[4]]]
2021-12-08 11:18:11.302 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 804B50FFFE4229D0: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=0, state=WAITING, sendCnt=0, command=ReadAttributesCommand [Ota Upgrade: 0000/0 -> 1F68/1, cluster=0019, TID=--, identifiers=[2]]]
2021-12-08 11:18:11.306 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 804B50FFFE4229D0: transactionComplete, state=COMPLETE, outstanding=0
2021-12-08 11:18:11.308 [DEBUG] [transaction.ZigBeeTransactionManager] - 1F68/1: Sending ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=7, state=WAITING, sendCnt=0, command=ReadAttributesCommand [Ota Upgrade: 0000/0 -> 1F68/1, cluster=0019, TID=1E, identifiers=[2]]]
2021-12-08 11:18:11.346 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE4229D0: Node update. NWK Address=1F68
2021-12-08 11:18:11.347 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE4229D0: Node 1F68 is not updated
2021-12-08 11:18:11.352 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=51, state=COMPLETE, sendCnt=1, command=ReadAttributesCommand [Ota Upgrade: 0000/0 -> 1F68/1, cluster=0019, TID=1E, identifiers=[2]]]
2021-12-08 11:18:11.354 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 804B50FFFE4229D0: transactionComplete, state=COMPLETE, outstanding=0
2021-12-08 11:18:11.357 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 804B50FFFE4229D0: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=0, state=WAITING, sendCnt=0, command=DiscoverAttributesCommand [Color Control: 0000/0 -> 1F68/1, cluster=0300, TID=--, startAttributeIdentifier=0, maximumAttributeIdentifiers=10]]
2021-12-08 11:18:11.360 [DEBUG] [transaction.ZigBeeTransactionManager] - 1F68/1: Sending ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=3, state=WAITING, sendCnt=0, command=DiscoverAttributesCommand [Color Control: 0000/0 -> 1F68/1, cluster=0300, TID=1F, startAttributeIdentifier=0, maximumAttributeIdentifiers=10]]
2021-12-08 11:18:11.419 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE4229D0: Node update. NWK Address=1F68
2021-12-08 11:18:11.421 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE4229D0: Node 1F68 is not updated
2021-12-08 11:18:11.426 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=69, state=COMPLETE, sendCnt=1, command=DiscoverAttributesCommand [Color Control: 0000/0 -> 1F68/1, cluster=0300, TID=1F, startAttributeIdentifier=0, maximumAttributeIdentifiers=10]]
2021-12-08 11:18:11.427 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 804B50FFFE4229D0: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=0, state=WAITING, sendCnt=0, command=DiscoverAttributesCommand [Color Control: 0000/0 -> 1F68/1, cluster=0300, TID=--, startAttributeIdentifier=18, maximumAttributeIdentifiers=10]]
2021-12-08 11:18:11.429 [DEBUG] [atabase.ZigBeeNetworkDatabaseManager] - 804B50FFFE4229D0: Data store: Writing node.
2021-12-08 11:18:11.434 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 804B50FFFE4229D0: transactionComplete, state=COMPLETE, outstanding=0
2021-12-08 11:18:11.437 [DEBUG] [transaction.ZigBeeTransactionManager] - 1F68/1: Sending ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=10, state=WAITING, sendCnt=0, command=DiscoverAttributesCommand [Color Control: 0000/0 -> 1F68/1, cluster=0300, TID=20, startAttributeIdentifier=18, maximumAttributeIdentifiers=10]]
2021-12-08 11:18:11.477 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE4229D0: Node update. NWK Address=1F68
2021-12-08 11:18:11.478 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE4229D0: Node 1F68 is not updated
2021-12-08 11:18:11.486 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=58, state=COMPLETE, sendCnt=1, command=DiscoverAttributesCommand [Color Control: 0000/0 -> 1F68/1, cluster=0300, TID=20, startAttributeIdentifier=18, maximumAttributeIdentifiers=10]]
2021-12-08 11:18:11.486 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 804B50FFFE4229D0: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=0, state=WAITING, sendCnt=0, command=DiscoverAttributesCommand [Color Control: 0000/0 -> 1F68/1, cluster=0300, TID=--, startAttributeIdentifier=52, maximumAttributeIdentifiers=10]]
2021-12-08 11:18:11.489 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 804B50FFFE4229D0: transactionComplete, state=COMPLETE, outstanding=0
2021-12-08 11:18:11.492 [DEBUG] [transaction.ZigBeeTransactionManager] - 1F68/1: Sending ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=6, state=WAITING, sendCnt=0, command=DiscoverAttributesCommand [Color Control: 0000/0 -> 1F68/1, cluster=0300, TID=21, startAttributeIdentifier=52, maximumAttributeIdentifiers=10]]
2021-12-08 11:18:11.538 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE4229D0: Node update. NWK Address=1F68
2021-12-08 11:18:11.539 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE4229D0: Node 1F68 is not updated
2021-12-08 11:18:11.549 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=63, state=COMPLETE, sendCnt=1, command=DiscoverAttributesCommand [Color Control: 0000/0 -> 1F68/1, cluster=0300, TID=21, startAttributeIdentifier=52, maximumAttributeIdentifiers=10]]
2021-12-08 11:18:11.550 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 804B50FFFE4229D0: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=0, state=WAITING, sendCnt=0, command=DiscoverAttributesCommand [Color Control: 0000/0 -> 1F68/1, cluster=0300, TID=--, startAttributeIdentifier=16387, maximumAttributeIdentifiers=10]]
2021-12-08 11:18:11.553 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 804B50FFFE4229D0: transactionComplete, state=COMPLETE, outstanding=0
2021-12-08 11:18:11.555 [DEBUG] [transaction.ZigBeeTransactionManager] - 1F68/1: Sending ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=4, state=WAITING, sendCnt=0, command=DiscoverAttributesCommand [Color Control: 0000/0 -> 1F68/1, cluster=0300, TID=22, startAttributeIdentifier=16387, maximumAttributeIdentifiers=10]]
2021-12-08 11:18:11.594 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE4229D0: Node update. NWK Address=1F68
2021-12-08 11:18:11.596 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE4229D0: Node 1F68 is not updated
2021-12-08 11:18:11.603 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=51, state=COMPLETE, sendCnt=1, command=DiscoverAttributesCommand [Color Control: 0000/0 -> 1F68/1, cluster=0300, TID=22, startAttributeIdentifier=16387, maximumAttributeIdentifiers=10]]
2021-12-08 11:18:11.604 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 804B50FFFE4229D0: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=0, state=WAITING, sendCnt=0, command=ReadAttributesCommand [Color Control: 0000/0 -> 1F68/1, cluster=0300, TID=--, identifiers=[16394]]]
2021-12-08 11:18:11.607 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 804B50FFFE4229D0: transactionComplete, state=COMPLETE, outstanding=0
2021-12-08 11:18:11.609 [DEBUG] [transaction.ZigBeeTransactionManager] - 1F68/1: Sending ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=6, state=WAITING, sendCnt=0, command=ReadAttributesCommand [Color Control: 0000/0 -> 1F68/1, cluster=0300, TID=23, identifiers=[16394]]]
2021-12-08 11:18:11.657 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE4229D0: Node update. NWK Address=1F68
2021-12-08 11:18:11.659 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE4229D0: Node 1F68 is not updated
2021-12-08 11:18:11.668 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=64, state=COMPLETE, sendCnt=1, command=ReadAttributesCommand [Color Control: 0000/0 -> 1F68/1, cluster=0300, TID=23, identifiers=[16394]]]
2021-12-08 11:18:11.672 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 804B50FFFE4229D0: transactionComplete, state=COMPLETE, outstanding=0
2021-12-08 11:18:11.683 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 804B50FFFE4229D0: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=0, state=WAITING, sendCnt=0, command=BindRequest [0000/0 -> 1F68/0, cluster=0021, TID=--, srcAddress=804B50FFFE4229D0, srcEndpoint=1, bindCluster=768, dstAddrMode=3, dstAddress=84FD27FFFE0E4D53, dstEndpoint=1]]
2021-12-08 11:18:11.687 [DEBUG] [transaction.ZigBeeTransactionManager] - 1F68/0: Sending ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=4, state=WAITING, sendCnt=0, command=BindRequest [0000/0 -> 1F68/0, cluster=0021, TID=24, srcAddress=804B50FFFE4229D0, srcEndpoint=1, bindCluster=768, dstAddrMode=3, dstAddress=84FD27FFFE0E4D53, dstEndpoint=1]]
2021-12-08 11:18:11.691 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: BindRequest [0000/0 -> 1F68/0, cluster=0021, TID=24, srcAddress=804B50FFFE4229D0, srcEndpoint=1, bindCluster=768, dstAddrMode=3, dstAddress=84FD27FFFE0E4D53, dstEndpoint=1]
2021-12-08 11:18:11.732 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE4229D0: Node update. NWK Address=1F68
2021-12-08 11:18:11.734 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE4229D0: Node 1F68 is not updated
2021-12-08 11:18:11.740 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=57, state=COMPLETE, sendCnt=1, command=BindRequest [0000/0 -> 1F68/0, cluster=0021, TID=24, srcAddress=804B50FFFE4229D0, srcEndpoint=1, bindCluster=768, dstAddrMode=3, dstAddress=84FD27FFFE0E4D53, dstEndpoint=1]]
2021-12-08 11:18:11.744 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 804B50FFFE4229D0: transactionComplete, state=COMPLETE, outstanding=0
2021-12-08 11:18:11.950 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE4229D0: Node update. NWK Address=1F68
2021-12-08 11:18:11.952 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFE4229D0: Node 1F68 is not updated
2021-12-08 11:18:11.971 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspZigbeeKeyEstablishmentHandler [networkId=0, partner=804B50FFFE4229D0, status=EMBER_EEPROM_MFG_VERSION_MISMATCH]
2021-12-08 11:18:17.003 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspZigbeeKeyEstablishmentHandler [networkId=0, partner=804B50FFFE4229D0, status=EMBER_EEPROM_MFG_VERSION_MISMATCH]
2021-12-08 11:18:22.043 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspZigbeeKeyEstablishmentHandler [networkId=0, partner=804B50FFFE4229D0, status=EMBER_EEPROM_MFG_VERSION_MISMATCH]

The EMBER_EEPROM_MFG_VERSION_MISMATCH seems to indicate some problem but the documentation says: “The manufacturing token format in non-volatile
memory is different than what the stack expects (returned at initialization).”

I cannot see what I can do for this issue.

11

After several removal and re-scan, I obtained a full association of the device 29D0. But the device is still in association mode, when switched on. When fingerprinting it during the association, I obtain:

openhab> zigbee fingerprint 804B50FFFE4229D0
|>| Node Descriptor
| |> Logical Type               ROUTER
| |> MAC Capabilities           [FULL_FUNCTION_DEVICE, MAINS_POWER, RECEIVER_ON_WHEN_IDLE]
| |> Stack Compliance           22
| |> Server Capabilities        []
| |> Buffer Size                82
| |> Incoming Transfer Size     82
| |> Outgoing Transfer Size     82
|
|>| Power Descriptor
| |> Available Power Sources    [MAINS]
| |> Current Power Source       MAINS
| |> Current Power Mode         RECEIVER_ON_IDLE
| |> Power Level                FULL
|
|>| ZDO
| |> ManagementBindRequest      SUCCESS
| |> IeeeAddressRequest         SUCCESS
| |> ManagementLqiRequest       SUCCESS
| |> ManagementRoutingRequest   SUCCESS
|
|>| Basic Information
| |> Generic Device Class       0
| |> Generic Device Type        6
| |> Manufacturer Name          innr
| |> Model Indentifier          RS 230 C
| |> Product Code               ByteArray [value=30 31 30 31 30 30 32 34 31]
| |> Product URL                www.innr.com
| |> Date Code                  20191114-214
| |> Application Version        16
| |> Software Build ID          2.8
| |> Hardware Version           1
| |> Zcl Version                3
| |> Stack Version              101
| |
| |>| Endpoint 1
| | |> Profile                  0104  ZIGBEE_HOME_AUTOMATION
| | |> Device Type              010D  EXTENDED_COLOR_LIGHT
| | |> Device Version           1
| | |
| | |>| Input Clusters
| | | |
| | | |>| Cluster 0000 Basic
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |
| | | | |>| Commands Generated
| | | | |
| | | | |>| Commands Received
| | | | | |> 0000 ResetToFactoryDefaultsCommand
| | | | |
| | | | |>| Attributes Supported
| | | | | |> 0000 ZCL Version
| | | | | |> 0001 Application Version
| | | | | |> 0002 Stack Version
| | | | | |> 0003 HW Version
| | | | | |> 0004 Manufacturer Name
| | | | | |> 0005 Model Identifier
| | | | | |> 0006 Date Code
| | | | | |> 0007 Power Source
| | | | | |> 0008 Generic Device Class
| | | | | |> 0009 Generic Device Type
| | | | | |> 000A Product Code
| | | | | |> 000B Product URL
| | | | | |> 0012 Device Enabled
| | | | | |> 4000 SW Build ID
| | | | | |> FFFD Unknown
| | | |
| | | |>| Cluster 0003 Identify
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |> Unsupported locally
| | | |
| | | |>| Cluster 0004 Groups
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |> Unsupported locally
| | | |
| | | |>| Cluster 0005 Scenes
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |
| | | | |>| Commands Generated
| | | | | |> 0000 AddSceneCommand
| | | | | |> 0001 ViewSceneCommand
| | | | | |> 0002 RemoveSceneCommand
| | | | | |> 0003 RemoveAllScenesCommand
| | | | | |> 0004 StoreSceneCommand
| | | | | |> 0006 GetSceneMembershipCommand
| | | | | |> 0040 EnhancedAddSceneCommand
| | | | | |> 0041 EnhancedViewSceneCommand
| | | | | |> 0042 CopySceneCommand
| | | | |
| | | | |>| Commands Received
| | | | | |> 0000 AddSceneCommand
| | | | | |> 0001 ViewSceneCommand
| | | | | |> 0002 RemoveSceneCommand
| | | | | |> 0003 RemoveAllScenesCommand
| | | | | |> 0004 StoreSceneCommand
| | | | | |> 0005 RecallSceneCommand
| | | | | |> 0006 GetSceneMembershipCommand
| | | | | |> 0040 EnhancedAddSceneCommand
| | | | | |> 0041 EnhancedViewSceneCommand
| | | | | |> 0042 CopySceneCommand
| | | | |
| | | | |>| Attributes Supported
| | | | | |> 0000 Scene Count
| | | | | |> 0001 Current Scene
| | | | | |> 0002 Current Group
| | | | | |> 0003 Scene Valid
| | | | | |> 0004 Name Support
| | | | | |> FFFD Unknown
| | | |
| | | |>| Cluster 0006 On/Off
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |
| | | | |>| Commands Generated
| | | | |
| | | | |>| Commands Received
| | | | | |> 0000 OffCommand
| | | | | |> 0001 OnCommand
| | | | | |> 0002 ToggleCommand
| | | | | |> 0040 OffWithEffectCommand
| | | | | |> 0041 OnWithRecallGlobalSceneCommand
| | | | | |> 0042 OnWithTimedOffCommand
| | | | |
| | | | |>| Attributes Supported
| | | | | |> 0000 On Off
| | | | | |> 4000 Global Scene Control
| | | | | |> 4001 On Time
| | | | | |> 4002 Off Wait Time
| | | | | |> 4003 Start Up On Off
| | | | | |> FFFD Unknown
| | | |
| | | |>| Cluster 0008 Level Control
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |
| | | | |>| Commands Generated
| | | | |
| | | | |>| Commands Received
| | | | | |> 0000 MoveToLevelCommand
| | | | | |> 0001 MoveCommand
| | | | | |> 0002 StepCommand
| | | | | |> 0003 StopCommand
| | | | | |> 0004 MoveToLevelWithOnOffCommand
| | | | | |> 0005 MoveWithOnOffCommand
| | | | | |> 0006 StepWithOnOffCommand
| | | | | |> 0007 StopWithOnOffCommand
| | | | |
| | | | |>| Attributes Supported
| | | | | |> 0000 Current Level
| | | | | |> 0001 Remaining Time
| | | | | |> 000F Options
| | | | | |> 0010 On Off Transition Time
| | | | | |> 0011 On Level
| | | | | |> 4000 Start Up Current Level
| | | | | |> FFFD Unknown
| | | |
| | | |>| Cluster 0300 Color Control
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |> Unsupported locally
| | | |
| | | |>| Cluster 0B05 Diagnostics
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |> Unsupported locally
| | | |
| | | |>| Cluster 1000 
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |> Unsupported locally
| | | |
| | | |>| Cluster FC82 
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |> Unsupported locally
| | |
| | |>| Output Clusters
| | | |
| | | |>| Cluster 0019 Ota Upgrade
| | | | |> Type                 Client [Output]
| | | | |> Manufacturer Spec.   No
| | | | |
| | | | |>| Commands Generated
| | | | | |> 0001 QueryNextImageCommand
| | | | | |> 0003 ImageBlockCommand
| | | | | |> 0006 UpgradeEndCommand
| | | | |
| | | | |>| Commands Received
| | | | |
| | | | |>| Attributes Supported
| | | | | |> 0000 Upgrade Server ID
| | | | | |> 0001 File Offset
| | | | | |> 0002 Current File Version
| | | | | |> 0004 Downloaded File Version
| | | | | |> 0006 Image Upgrade Status
| | | | | |> 0007 Manufacturer ID
| | | | | |> 0008 Image Type ID
| | | | | |> 0009 Minimum Block Request Period
| | | | | |> FFFD Unknown
| |
| |>| Endpoint 242
| | |> Profile                  A1E0  ZIGBEE_GREEN_POWER
| | |> Device Type              0061
| | |> Device Version           0

which if fine (I cannot say why this time the discovery in ful: 21 attributes, and initialized=true).

BUT, I still cannot join the device. The logs still show:

RX EZSP: EzspZigbeeKeyEstablishmentHandler [networkId=0, partner=804B50FFFE422D94, status=EMBER_EEPROM_MFG_VERSION_MISMATCH]

and any transmission is cancelled:

2021-12-08 12:32:10.964 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 804B50FFFE4229D0: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=4850, state=WAITING, sendCnt=1, command=MoveToColorTemperatureCommand [Color Control: 0000/0 -> 2E64/1, cluster=0300, TID=86, colorTemperature=257, transitionTime=10]]
2021-12-08 12:32:10.967 [DEBUG] [transaction.ZigBeeTransactionManager] - 2E64/1: Sending ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=4853, state=WAITING, sendCnt=1, command=MoveToColorTemperatureCommand [Color Control: 0000/0 -> 2E64/1, cluster=0300, TID=86, colorTemperature=257, transitionTime=10]]
2021-12-08 12:32:15.793 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=9679, state=FAILED, sendCnt=2, command=MoveToColorTemperatureCommand [Color Control: 0000/0 -> 2E64/1, cluster=0300, TID=86, colorTemperature=257, transitionTime=10]]
2021-12-08 12:32:15.796 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 804B50FFFE4229D0: transactionComplete, state=FAILED, outstanding=0
2021-12-08 12:32:15.798 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 804B50FFFE4229D0: transactionComplete exceeded max retries 2
2021-12-08 12:32:15.800 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction cancelled: ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=9687, state=CANCELLED, sendCnt=2, command=MoveToColorTemperatureCommand [Color Control: 0000/0 -> 2E64/1, cluster=0300, TID=86, colorTemperature=257, transitionTime=10]]
2021-12-08 12:32:15.803 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=804B50FFFE4229D0 queueTime=9689, state=CANCELLED, sendCnt=2, command=MoveToColorTemperatureCommand [Color Control: 0000/0 -> 2E64/1, cluster=0300, TID=86, colorTemperature=257, transitionTime=10]]
2021-12-08 12:32:15.807 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 804B50FFFE4229D0: transactionComplete but not outstanding, state=CANCELLED, outstanding=0
12

As far as I can understand, the error EMBER_EEPROM_MFG_VERSION_MISMATCH means that the coordinator failed to exchange the keys with the bulb. The reading of:
zigbeeKeyEstablishmentHandler suggests that the cryptographic key cannot be setup in the device.
As the device seems to be in pair mode when switched on (it iterates over colors, then goes to white, then waits the discovery (when paired, the bulb goes directly to white)) I understand that the bulb is still waiting the key exchange but it never happens, for some reasons.

Any suggestion at this point ?

13

I’m out of ideas - maybe @chris could help?

14

There seem to be a lot of different things going on here so I’m struggling to know what’s going on. I’m not sure what versions of everything are being used. If you’re not on the latest binding, then please use the latest snapshot otherwise it’s hard for me to work out where exceptions occur.

I think one issue you may have is the version of the coordinator firmware - I can’t see that written anywhere so please can you advise what coordinator you’re using.

I’m not sure where you get this from or exactly when this error is returned? The documentation for this error states -:

The manufacturing token format in non-volatile memory is different than what the stack expects (returned at initialization).

So this means that the tokens stored in the NV memory in the device are not as expected by the firmware. It is nothing to do with key updates.

That said, I do suspect that the issue might be related to key exchange which is why I asked about the controller firmware version as it likely needs to be more than 6.4 (as per the docs).

15

Thank you for your comments @chris
.
The coordinator is the POPP ZB stick seen as an Ember EM35x Coordinator in openhab.

In the properties I see: firmwareVersion : 6.0.3.0
It is confirmed by the console

openhab> zigbee firmware VERSION                                                                                                                                                                      
Dongle firmware version is currently 6.0.3.0

So I guess I have to update the firmware ? I have not seen the info in the doc about zigbee binding, sorry. Can you point me out where to find the process ?

Openhab version is now: 3.2.0~M5-1 (I can go for the latest deb build)

16

This will not work with newer devices. You need at least version 6.4 or higher to use Zigbee 3.0 devices.

Please take a look at the zigbee binding documentation - just make sure to select the LATEST branch when reading the docs, otherwise I think you get documentation that is 6 months old or so.

17

6.10 for Elelabs’ USB stick (the POPP stick seems to be manufactured by Elelabs) is available from:

18

You can also use the binding, or the console, for updating firmware.

19

Dear all,
Almost all my problems vanished suddenly :yum:

The new firmware (6.10) has solved the association problem of the two bulbs (RS 230 C). They now work fine, as the other ones. One of the two still appears as “zigbee_device_initialised: false”. I tried to re-associate after resetting it several times, but this property still remains false. Not sure it is a problem, as it seems to work anyway.

For documentation, in case someone finds this thread:

I flashed the firmware using the Elelabs tool (link provided by @anon71759204 :slight_smile:

sudo python3 Elelabs_EzspFwUtility.py flash -f data/EFR32MG13/ELE_MG13_zb_ncp_115200_610_211112.gbl -p /dev/ttyUSB0

Then I add to reboot openhab to take into account the new firmware. The coordinator has been detected and previously associated devices came back to life. Then I successfully associated the 2 bulbs that had troubles.

Thank you for your help @chris :slight_smile:

1 Like