This post is older than 2 years and might not be relevant anymore
More Info: Consider searching for newer posts

CHIP lighting demo, Commissioning starts, app dies, 52840dk seems to be in child state, but app does not control light on/off.

Tried running android app in debug mode, but I could not see any data on the crash.

tried resetting the board a few time and re commissioning.

followed the guide to set up the DK board, AP (used a dongle instead of DK, but seems to be operational) and the android commissioning app.

uart:~$ ot ipaddr

fd11:22:0:0:9b0c:d235:7ee8:629c

fd58:94c1:25c8:62db:0:ff:fe00:a804

fd58:94c1:25c8:62db:97f9:1f55:2419:2566

fe80:0:0:0:98d0:439c:d01:8621

Done

uart:~$ ot state

child

Done

uart:~$ 

  • If it comes to the attached files, there is an information that you may download applications.zip containing .hex files for lock-app, ot rcp and .apk for the Android CHIP Tool and the link is located on the bottom of a page. Here you have a direct link to .zip: /cfs-file/__key/communityserver-discussions-components-files/4/applications.zip

    But I think something is still not quite there in routing? dnsmasq, tayga and bind9 (and all the other otbr processes seem to be there)

    I know that configuring whole OTBR from scratch might be painful and there are many possible things to make mistake, so that's why in the blog post there is recommendation to use docker version, where all of this things are already done. I strongly recommend you to try using solution suggested by us, so attached applications and OTBR docker, cause it should allow you to make everything work easily and then try to make some experiments.

    tried docker version, but that doesn't give you the AP, so went back

    I'm not quite sure what you mean here. OTBR docker purpose is not to provide WiFi AP, but only to run OTBR script on the connected RCP device with some predefined configuration. In the "Forming Thread network" section you can see generally two types of activities:

    1. Forming Thread network with fd11:22:: prefix, by running OTBR docker on the RCP device, making configuration in the browser and etc.
    2. Adding network 2001:db8:1::/64 to the docker and configuring routing for it. This is because, we are using then this network to create WiFi AP for the smartphone, so we need to give docker access to this network and tell it to route packets from that IP range to the Thread network addresses from range fd11:22:: (described in the point 11).
    wifi setup didn't work

    Having OTBR working, then you should try to make steps from the "Configuring WiFi hotspot" section. If for some reason it will not work for you, it is good to try detect what went wrong, so:

    • See if any errors appeared in the console, if yes, please try to provide them.
    • After completing steps 1-9, verify if you can find created hotspot on your smartphone.
    • Try to connect to the hotspot and verify if your smartphone got IPv6 address (notice if message similar to the: "Unable to retrieve IP address" appeared). You can also go on your smartphone to the WiFi settings -> Additional settings -> IP address and see if you can find there IPv6 address starting at 2001:db8:
    Scroll to bottom, I tried using button 3 to connect to the network, seems to connect but gets errors as well.

    Looking at your logs everything seems to be fine. First part, when you were starting Thread using mobile commissioner went absolutely fine, please ignore the following error:

    I: 30737[SVR] OnRendezvousError: Ble Error 6012 (0x0000177C): Remote device closed BLE connection

    That is matter of small bug, which was fixed in the next versions and it means that your BLE connection was closed, because commissioning was finished and it is normal disconnection operation. At this point I think that whole commissioning works fine and if you see "Network unreachable" error on smartphone, that means that it is not able to send packets to the target, because of one of two things:

    • You did not provide it WiFi AP, so it tries to send packets to some other currently connected network.
    • You provided WiFi AP, but you don't have properly configured routing, so packets are send to your PC, but then they are not routed to the Thread network.

    I suggest you to try run OTBR and WiFi AP following the steps from the "Forming Thread network" and "Configuring WiFi hotspot" sections. If doing it you will encounter some problems, please try to verify the reason following the mentioned hints.

  • Much better news, had a thread in the open thread forum on otbr and my setup, Jon suggested adding radvd for ipv6 routing. Not sure if that was part of the fix.

    https://groups.google.com/u/2/g/openthread-users/c/Yne0KQUGumA

    One thing that didn't work was commissioning when I setup the otbr using ot-ctl, it did work when I used the web guide to form the network.

    When the android chip tool went to the light control screen, it initially could not connect. I then tried pinging the board after I did an "ot ipaddr" from the rpi and it worked, then I noticed the the IP address on the chip tool only had 1 : where the IP address had a :0:0: , when I modified the address to the same as it showed and I pinged

    IT WORKED (well once, I was able to turn on the light, debug below)

    so far no luck getting it working again, but I will continue to debug later, need to go skiing now.

    I would call this solved with the proper border router config.

    I: 749031[BLE] Received rendezvous message from lu

    D: 749035[BLE] Received spake2p msg3

    D: 749041[IN] New pairing for device lu, key 0!!

    I: 749046[SVR] Received a new connection.

    I: 749050[SVR] Device completed SPAKE2+ handshake

    D: 751490[DL] Write request received for CHIPoBLE RX characteristic (ConnId 0x00)

    D: 751497[DL] Sending indication for CHIPoBLE TX characteristic (ConnId 0, len 3)

    D: 751580[DL] Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)

    D: 754055[DL] Write request received for CHIPoBLE RX characteristic (ConnId 0x00)

    D: 756563[DL] Sending indication for CHIPoBLE TX characteristic (ConnId 0, len 3)

    D: 756620[DL] Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)

    D: 756845[DL] Write request received for CHIPoBLE RX characteristic (ConnId 0x00)

    D: 756935[DL] Write request received for CHIPoBLE RX characteristic (ConnId 0x00)

    D: 756942[DL] Sending indication for CHIPoBLE TX characteristic (ConnId 0, len 3)

    D: 757024[DL] Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)

    D: 757033[DL] Write request received for CHIPoBLE RX characteristic (ConnId 0x00)

    D: 757115[DL] Write request received for CHIPoBLE RX characteristic (ConnId 0x00)

    D: 757122[DL] Sending indication for CHIPoBLE TX characteristic (ConnId 0, len 3)

    D: 757204[DL] Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)

    D: 757213[DL] Write request received for CHIPoBLE RX characteristic (ConnId 0x00)

    D: 757295[DL] Write request received for CHIPoBLE RX characteristic (ConnId 0x00)

    D: 757302[DL] Sending indication for CHIPoBLE TX characteristic (ConnId 0, len 3)

    D: 757384[DL] Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)

    D: 757393[DL] Write request received for CHIPoBLE RX characteristic (ConnId 0x00)

    I: 757401[BLE] Received rendezvous message for lu

    I: 757406[BLE] Received rendezvous message from lu

    I: 757410[NP] Received kThreadAssociationRequest

    I: 757423[SVR] Device was assigned network credentials

    I: 757428[DIS] CHIP minimal mDNS started advertising.

    I: 757433[SVR] Device completed Rendezvous process

    D: 757438[DL] In DriveBLEState

    D: 757443[DL] OpenThread State Changed (Flags: 0x0106d01d)

    D: 757448[DL]    Device Role: DETACHED

    D: 757451[DL]    Network Name: OpenThread

    D: 757455[DL]    PAN Id: 0x1234

    D: 757458[DL]    Extended PAN Id: 0x1111111122222222

    D: 757463[DL]    Channel: 15

    D: 757465[DL]    Mesh Prefix: fdde:ad00:beef::/64

    D: 757470[DL]    Thread Unicast Addresses:

    D: 757474[DL]         fdde:ad00:beef:0:40ef:1293:1957:8148/64 valid preferred

    D: 757481[DL]         fe80::2893:9cf8:7a52:3cb7/64 valid preferred

    D: 760067[DL] Sending indication for CHIPoBLE TX characteristic (ConnId 0, len 3)

    D: 760074[DL] OpenThread State Changed (Flags: 0x001132b7)

    D: 760080[DL]    Device Role: CHILD

    D: 760083[DL]    Network Name: OpenThreadDemo

    D: 760087[DL]    PAN Id: 0x1234

    D: 760090[DL]    Extended PAN Id: 0x1111111122222222

    D: 760095[DL]    Channel: 15

    D: 760097[DL]    Mesh Prefix: fd4b:2693:d337:c9f5::/64

    D: 760102[DL]    Partition Id: 0x6A373B69

    D: 760106[DL]    Thread Unicast Addresses:

    D: 760110[DL]         fd11:22::5dd7:5f9c:a3f9:7e6d/64 valid preferred

    D: 760116[DL]         fd4b:2693:d337:c9f5:0:ff:fe00:f001/64 valid preferred rloc

    D: 760123[DL]         fd4b:2693:d337:c9f5:40ef:1293:1957:8148/64 valid preferred

    D: 760130[DL]         fe80::2893:9cf8:7a52:3cb7/64 valid preferred

    I: 760136[NP] Sending IP Address. Delegate 0x20005b34

    D: 760142[IN] Secure message was encrypted: Msg ID 0

    I: 760146[IN] Sending msg from lu to lu

    I: 760150[IN] Sending secure msg on connection specific transport

    I: 760156[IN] Secure msg send status 0

    D: 760159[DL] OpenThread State Changed (Flags: 0x00000001)

    D: 760165[DL]    Thread Unicast Addresses:

    D: 760168[DL]         fd11:22::5dd7:5f9c:a3f9:7e6d/64 valid preferred

    D: 760175[DL]         fd4b:2693:d337:c9f5:0:ff:fe00:f001/64 valid preferred rloc

    D: 760182[DL]         fd4b:2693:d337:c9f5:40ef:1293:1957:8148/64 valid preferred

    D: 760189[DL]         fe80::2893:9cf8:7a52:3cb7/64 valid preferred

    I: 760195[NP] Sending IP Address. Delegate 0x20005b34

    D: 760201[IN] Secure message was encrypted: Msg ID 1

    I: 760205[IN] Sending msg from lu to lu

    I: 760209[IN] Sending secure msg on connection specific transport

    I: 760215[IN] Secure msg send status 0

    D: 760400[DL] Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)

    D: 760408[DL] Sending indication for CHIPoBLE TX characteristic (ConnId 0, len 20)

    D: 760493[DL] Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)

    D: 760501[DL] Write request received for CHIPoBLE RX characteristic (ConnId 0x00)

    D: 760508[DL] Sending indication for CHIPoBLE TX characteristic (ConnId 0, len 20)

    D: 760580[DL] Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)

    D: 760588[DL] Sending indication for CHIPoBLE TX characteristic (ConnId 0, len 20)

    D: 760673[DL] Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)

    D: 760681[DL] Write request received for CHIPoBLE RX characteristic (ConnId 0x00)

    D: 760688[DL] Sending indication for CHIPoBLE TX characteristic (ConnId 0, len 20)

    D: 760760[DL] Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)

    D: 760768[DL] Sending indication for CHIPoBLE TX characteristic (ConnId 0, len 11)

    D: 760853[DL] Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)

    D: 760861[DL] Write request received for CHIPoBLE RX characteristic (ConnId 0x00)

    D: 760868[DL] Sending indication for CHIPoBLE TX characteristic (ConnId 0, len 20)

    D: 760940[DL] Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)

    D: 760948[DL] Sending indication for CHIPoBLE TX characteristic (ConnId 0, len 20)

    D: 761032[DL] Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)

    I: 762020[DL] BLE GAP connection terminated (reason 0x13)

    I: 762025[SVR] OnRendezvousError: Ble Error 6012 (0x0000177C): Remote device closed BLE connection

    I: 762034[DL] Current number of connections: 0/1

    D: 762038[DL] In DriveBLEState

    I: 762046[DL] CHIPoBLE advertising started

    I: 768761[SVR] Packet received from UDP:fd11:22:33:0:c0b5:1fd6:1ffb:c5df:58175: zu bytes

    I: 768769[ZCL] APS frame processing success!

    I: 768773[ZCL] RX len 25, ep a0, clus 0x618a 

    I: 768777[ZCL]  FC 21 seq 5f cmd c2 payload[

    I: 768781[ZCL] 0hX0hX0hX0hX0hX0hX0hX0hX0hX0hX0hX0hX0hX0hX0hX0hX0hX0hX0hX0hX0hX0hX

    I: 768788[ZCL] ]

    I: 768790[ZCL] Drop cluster 0x618a command 0xc2

    I: 768794[ZCL]  due to invalid endpoint: 

    I: 768798[ZCL] 0xa0

    I: 768800[ZCL] Data model processing failure!

    uart:~$ ot ipaddr

    fd11:22:0:0:5dd7:5f9c:a3f9:7e6d

    fd4b:2693:d337:c9f5:0:ff:fe00:f001

    fd4b:2693:d337:c9f5:40ef:1293:1957:8148

    fe80:0:0:0:2893:9cf8:7a52:3cb7

    Done

    uart:~$ ot state

    child

    Done

    uart:~$ D: 1662050[DL] SetAdvertisingEnabled(false)

    I: 1662054[DL] CHIPoBLE advertising disabled because of timeout expired

    D: 1662060[DL] In DriveBLEState

    I: 1662064[DL] CHIPoBLE advertising stopped

    I: 2084489[SVR] Packet received from UDP:fd11:22:33:0:c0b5:1fd6:1ffb:c5df:58175: zu bytes

    I: 2084497[ZCL] APS frame processing success!

    I: 2084501[ZCL] RX len 3, ep 1, clus 0x 6 

    I: 2084504[ZCL]  FC 1 seq 1 cmd 1 payload[

    I: 2084508[ZCL] NULL

    I: 2084510[ZCL] ]

    I: 2084512[ZCL] On/Off set value: 1 1

    I: 2084515[ZCL] Toggle on/off from 0 to 1

    I: 2084519[ZCL] sched report event in 0 ms

    I: 2084523[ZCL] Cluster callback: 6

    I: Turn On Action has been initiated

    I: Turn On Action has been completed

    I: 2084533[ZCL] sched report event in 0 ms

    I: 2084537[ZCL] Cluster callback: 8

    I: 2084540[ZCL] Value: 0, length 1

    I: Level Action has been initiated

    I: Setting brightness level to 0

    I: Level Action has been completed

    D: 2084552[ZCL] Measured APS frame size 11

    D: 2084556[ZCL] Successfully encoded 11 bytes

    D: 2084560[IN] Secure message was encrypted: Msg ID 2

    I: 2084565[IN] Sending msg from lu to lu

    I: 2084569[IN] Sending secure msg on generic transport

    I: 2084574[IN] Secure msg send status 0

    I: 2084578[ZCL] T   0:TX (0x6e47a) Ucast 0x00x7ada8

    I: 2084582[ZCL] TX buffer: [

    I: 2084585[ZCL] 0hX0hX0hX0hX0hX

    I: 2084588[ZCL] ]

    I: 2084589[ZCL] Data model processing success!

    I: 2084594[ZCL] Event: move from 0

    I: 2084597[ZCL]  to 255 

    I: 2084599[ZCL] (diff +1)

    I: 2084601[ZCL] sched report event in 0 ms

    I: 2084605[ZCL] Cluster callback: 8

    I: 2084608[ZCL] Value: 255, length 1

    I: Level Action has been initiated

    I: Setting brightness level to 255

    I: Level Action has been completed

Related