Zigbee binding don't find TRADFRI

Add-ons Bindings
1

Hi @ll,

I’ve setup OH with a CC2531. Currently I only own a TRADFRI bulb, but I can’t connect it.

The CC2531 is shown as online but if I start a scan, no device appears. Also the log is not very helpfull to me:

21:26:10.484 [DEBUG] [pax.web.service.spi.model.ServerModel] - Matching [/rest/discovery/bindings/zigbee/scan]...
21:26:10.493 [DEBUG] [pax.web.service.spi.model.ServerModel] - Path [/rest/discovery/bindings/zigbee/scan] matched to {pattern=/rest/.*,model=ServletModel{id=org.ops4j.pax.web.service.spi.model.ServletModel-2,name=org.ops4j.pax.web.service.spi.model.ServletModel-2,urlPatterns=[/rest/*],alias=/rest,servlet=com.eclipsesource.jaxrs.publisher.internal.ServletContainerBridge@e2fb70,initParams={},context=ContextModel{id=org.ops4j.pax.web.service.spi.model.ContextModel-1,name=,httpContext=DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [20], contextID=default],contextParams={},virtualHosts={},connectors={}}}}
21:26:10.503 [DEBUG] [ice.jetty.internal.HttpServiceContext] - Handling request for [/rest/discovery/bindings/zigbee/scan] using http context [DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [20], contextID=default]]
21:26:10.514 [DEBUG] [ty.internal.HttpServiceServletHandler] - handling request org.ops4j.pax.web.service.jetty.internal.HttpServiceRequestWrapper@1e6e88d, org.ops4j.pax.web.service.jetty.internal.HttpServiceResponseWrapper@409f48
21:26:10.538 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - Permit join to 65532/0 for 60 seconds.
21:26:10.547 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementPermitJoiningRequest [0/0 -> 65532/0, cluster=0036, TID=3D, permitDuration=60, tcSignificance=true]
21:26:10.558 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65532/0, profile=0000, cluster=54, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=61, payload=00 3C 01]
21:26:10.567 [DEBUG] [531.network.impl.CommandInterfaceImpl] - ->  AF_DATA_REQUEST (Packet: subsystem=null, length=13, apiId=24 01, data=FE 0D 24 01 FC FF 00 00 36 00 3D 30 1F 03 00 3C 01 31, checksum=31, error=false)
21:26:10.697 [DEBUG] [531.network.impl.CommandInterfaceImpl] - <-  AF_DATA_SRSP (FE 01 64 01 00 64)
21:26:10.704 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=3E, permitDuration=60, tcSignificance=true]
21:26:10.712 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=54, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=62, payload=00 3C 01]
21:26:10.719 [DEBUG] [531.network.impl.CommandInterfaceImpl] - ->  AF_DATA_REQUEST (Packet: subsystem=null, length=13, apiId=24 01, data=FE 0D 24 01 00 00 00 00 36 00 3E 30 1F 03 00 3C 01 31, checksum=31, error=false)
21:26:10.853 [DEBUG] [531.network.impl.CommandInterfaceImpl] - <-  AF_DATA_SRSP (FE 01 64 01 00 64)
21:26:10.859 [DEBUG] [531.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 01 45 CB 3C B3)
21:26:10.865 [DEBUG] [531.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=1, apiId=45 CB, data=FE 01 45 CB 3C B3, checksum=B3, error=false
21:26:10.871 [DEBUG] [ee.dongle.cc2531.ZigBeeDongleTiCc2531] - Unhandled ZToolPacket type 0x45cb
21:26:10.878 [DEBUG] [531.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 03 45 B6 00 00 00 F0)
21:26:10.885 [DEBUG] [531.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=3, apiId=45 B6, data=FE 03 45 B6 00 00 00 F0, checksum=F0, error=false
21:26:10.892 [DEBUG] [ee.dongle.cc2531.ZigBeeDongleTiCc2531] - Unhandled ZToolPacket type 0x45b6
21:26:10.899 [DEBUG] [531.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 0A 45 FF 00 00 00 36 80 00 00 00 00 00 06)
21:26:10.905 [DEBUG] [531.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=10, apiId=45 FF, data=FE 0A 45 FF 00 00 00 36 80 00 00 00 00 00 06, checksum=06, error=false
21:26:10.911 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32822, addressMode=null, radius=0, apsSecurity=false, apsCounter=0, payload=00 00]
21:26:10.918 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementPermitJoiningResponse [0/0 -> 0/0, cluster=8036, TID=NULL, status=SUCCESS]

The loging is the same, even if the bulb is switched off. So, for me, it seems that there is no ZigBee communication? My first idea was, that the CC2531 does’t work correctly, but if I switch on the bulb, I get those log entries:

22:26:26.288 [DEBUG] [531.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 0C 45 CA 28 CC CB C7 33 FE FF 6F 0D 00 00 00 3B)
22:26:26.296 [DEBUG] [531.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=12, apiId=45 CA, data=FE 0C 45 CA 28 CC CB C7 33 FE FF 6F 0D 00 00 00 3B, checksum=3B, error=false
22:26:26.306 [DEBUG] [ee.dongle.cc2531.ZigBeeDongleTiCc2531] - Unhandled ZToolPacket type 0x45ca
22:26:36.561 [DEBUG] [531.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 0C 45 CA 28 CC CB C7 33 FE FF 6F 0D 00 00 00 3B)
22:26:36.571 [DEBUG] [531.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=12, apiId=45 CA, data=FE 0C 45 CA 28 CC CB C7 33 FE FF 6F 0D 00 00 00 3B, checksum=3B, error=false
22:26:36.579 [DEBUG] [ee.dongle.cc2531.ZigBeeDongleTiCc2531] - Unhandled ZToolPacket type 0x45ca
22:26:38.636 [DEBUG] [531.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 01 45 CB 00 8F)
22:26:38.644 [DEBUG] [531.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=1, apiId=45 CB, data=FE 01 45 CB 00 8F, checksum=8F, error=false
22:26:38.653 [DEBUG] [ee.dongle.cc2531.ZigBeeDongleTiCc2531] - Unhandled ZToolPacket type 0x45cb

So, there is ZigBee communication? I’m a little bit confused!

Any idea?

Greetz,
Funny

2

I also found these log entries after a boot (bulb is switched on)

2019-08-19 23:31:05.652 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00124B0018E25CFC: Node SVC Discovery: running
2019-08-19 23:31:05.659 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=12, ieeeAddr=00124B0018E25CFC, requestType=0, startIndex=0]
2019-08-19 23:31:05.667 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65535/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=18, payload=00 FC 5C E2 18 00 4B 12 00 00 00]
2019-08-19 23:31:05.672 [DEBUG] [31.network.impl.CommandInterfaceImpl] - ->  AF_DATA_REQUEST (Packet: subsystem=null, length=21, apiId=24 01, data=FE 15 24 01 FF FF 00 00 00 00 12 30 1F 0B 00 FC 5C E2 18 00 4B 12 00 00 00 05, checksum=05, error=false)
2019-08-19 23:31:05.804 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-  AF_DATA_SRSP (FE 01 64 01 00 64)
2019-08-19 23:31:13.659 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=12, ieeeAddr=00124B0018E25CFC, requestType=0, startIndex=0]
2019-08-19 23:31:13.667 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery: NetworkAddressRequest returned null
2019-08-19 23:31:13.673 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00124B0018E25CFC: Node SVC Discovery: request NWK_ADDRESS failed after 13 attempts.
2019-08-19 23:31:13.679 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00124B0018E25CFC: Node SVC Discovery: running
2019-08-19 23:31:13.685 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00124B0018E25CFC: Node SVC Discovery: complete
2019-08-19 23:31:13.690 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 00124B0018E25CFC: Node 0 update
3

It’s a little hard to see what is happening with short log snippets.

Unfortunately it’s impossible to know what is happening on the network as the dongle will only provide information AFTER the device has joined. The only way to see what is happening at the network level is with a sniffer.

This is just the binding communicating with the dongle to find a network address for a device - this could just be the dongle, or it could be the bulb - as I said, it’s hard really to know what is happening with short snippets like this.

What is the device at address 00124B0018E25CFC?

PS please also use code fences to format the logs as you now see them (I’ve edited your posts to fix this).

4

Sure, my intention was to focus on the ZigBee entries and the debug log contains a lot of other stuff. But if requested, I could post a complete log. But currently I’m trying the zigbee2mqtt way.

I expected that and since I only have this stick, a can’t do both at the same time :slight_smile:

I don’t know, thought this is the address of my stick?

I used <code> as explained in How to use code fences.

5

But by doing this you don’t provide the context of what’s happening - I need to see a wider set of information to understand what is happening.

I certainly don’t know this - it is in the logs though, but as you haven’t provided them I can’t tell. Please can you take a look as it’s quite important to understand the issue.

Unfortunately this didn’t work then :frowning: . Personally I would suggest to use the </> button. Without this it’s very difficult to view the logs - I’m sure you can see the difference with the way they are now formatted.