search

project-chip / connectedhomeip

Matter (formerly Project CHIP) creates more connections between more objects, simplifying development for manufacturers and increasing compatibility for consumers, guided by the Connectivity Standards Alliance.
https://buildwithmatter.com
Apache License 2.0
7.24k stars 1.92k forks source link

Wifi Connection Issue #28322

Open jayveeeer opened 12 months ago

jayveeeer commented 12 months ago

Reproduction steps

I am using the Esp32 C3 DevkitM1 v1.6 as an matter bulb and after flashing the code when i try to commission it my wifi network i get the following error:

W (78384) wifi:Haven't to connect to a suitable AP now! E (78394) chip[DL]: Failed to get configured network when updating network status: Error ESP32:0x0500300F I (81734) chip[DL]: WIFI_EVENT_STA_DISCONNECTED I (81744) chip[DL]: WiFi station state change: Connecting -> Connecting_Failed W (81754) wifi:Haven't to connect to a suitable AP now! I (81754) chip[DL]: WiFi station state change: Connecting_Failed -> NotConnected I (81764) chip[DL]: Next WiFi station reconnect in 100 ms I (81764) chip[DL]: Done driving station state, nothing else to do... W (81774) wifi:Haven't to connect to a suitable AP now! E (81774) chip[DL]: Failed to get configured network when updating network status: Error ESP32:0x0500300F W (81794) wifi:Haven't to connect to a suitable AP now! E (81794) chip[DL]: Failed to get configured network when updating network status: Error ESP32:0x0500300F W (81864) wifi:Haven't to connect to a suitable AP now! I (81864) chip[DL]: Attempting to connect WiFi station interface I (81864) chip[DL]: WiFi station state change: NotConnected -> Connecting I (81884) chip[DL]: Done driving station state, nothing else to do... W (81884) wifi:Haven't to connect to a suitable AP now! E (81894) chip[DL]: Failed to get configured network when updating network status: Error ESP32:0x0500300F I (81974) wifi:new:<3,0>, old:<3,0>, ap:<255,255>, sta:<3,0>, prof:1 I (81984) wifi:state: init -> auth (b0) I (81984) wifi:state: auth -> assoc (0) I (81994) wifi:state: assoc -> run (10) I (85394) wifi:state: run -> init (fc0) I (85394) wifi:new:<3,0>, old:<3,0>, ap:<255,255>, sta:<3,0>, prof:1 I (85394) chip[DL]: WIFI_EVENT_STA_DISCONNECTED I (85394) chip[DL]: WiFi station state change: Connecting -> Connecting_Failed W (85404) wifi:Haven't to connect to a suitable AP now! I (85414) chip[DL]: WiFi station state change: Connecting_Failed -> NotConnected I (85424) chip[DL]: Next WiFi station reconnect in 100 ms I (85434) chip[DL]: Done driving station state, nothing else to do... W (85434) wifi:Haven't to connect to a suitable AP now! E (85444) chip[DL]: Failed to get configured network when updating network status: Error ESP32:0x0500300F W (85444) wifi:Haven't to connect to a suitable AP now! E (85464) chip[DL]: Failed to get configured network when updating network status: Error ESP32:0x0500300F W (85534) wifi:Haven't to connect to a suitable AP now! I (85534) chip[DL]: Attempting to connect WiFi station interface I (85534) chip[DL]: WiFi station state change: NotConnected -> Connecting I (85544) chip[DL]: Done driving station state, nothing else to do... W (85554) wifi:Haven't to connect to a suitable AP now! E (85564) chip[DL]: Failed to get configured network when updating network status: Error ESP32:0x0500300F

but when i do it using my mobile hotspot as an AP it works perfectly so could be the posssible issue for it and do it need an antena or not , as i am not using antena in both the cases?

Platform

esp32

Platform Version(s)

Esp32 C3-DevkitM1 v1.6

Type

Manually tested with SDK

(Optional) If manually tested please explain why this is only manually tested

No response

Anything else?

No response

bzbarsky-apple commented 12 months ago

@jayveeeer Is the relevant WiFi SSID 5Ghz, 2.4GHz, or both?

@dhrishi @shubhamdp

shubhamdp commented 12 months ago

@jayveeeer Warning log W (81884) wifi:Haven't to connect to a suitable AP now!, usually means that SSID is not available and error code 0x0500300F means failed to connect to the WiFi network.

Are you using the devkit which needs an external antenna? If so, yeah antenna is required. We also found that without antenna it fails to connect. It is connecting to the mobile hotspot because it may be very close to the devkit.

jayveeeer commented 11 months ago

ok I will try and check it out and inform you later

jayveeeer commented 11 months ago

With antenna when i try to commission using mobile app chip tool .I get the following logs

I (1687) NimBLE: GAP procedure initiated: advertise;

I (1687) NimBLE: disc_mode=2

I (1687) NimBLE: adv_channel_map=0 own_addr_type=1 adv_filter_policy=0 adv_itvl_min=40 adv_itvl_max=40

I (1707) NimBLE:

I (1707) app_main: Commissioning window opened

I (1707) led_driver_ws2812: led set r:0, g:0, b:0

I (1717) chip[DL]: WIFI_EVENT_STA_START

W (1717) wifi:Haven't to connect to a suitable AP now!

I (1727) led_driver_ws2812: led set r:0, g:0, b:0

I (1727) chip[DL]: Done driving station state, nothing else to do...

I (1737) led_driver_ws2812: led set r:63, g:51, b:40

I (1817) main_task: Returned from app_main()

I (7657) chip[DL]: BLE GAP connection established (con 1)

I (7657) chip[DL]: CHIPoBLE advertising stopped

I (8627) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12

I (8627) chip[BLE]: local and remote recv window sizes = 5

I (8637) chip[BLE]: selected BTP version 4

I (8637) chip[BLE]: using BTP fragment sizes rx 128 / tx 128.

I (8647) chip[DL]: Write request/command received for CHIPoBLE TX CCCD characteristic (con 1 ) indicate = 1

I (8657) chip[DL]: CHIPoBLE subscribe received

I (8657) NimBLE: GATT procedure initiated: indicate;

I (8657) NimBLE: att_handle=14

I (8787) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14

I (8837) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12

I (8837) chip[EM]: >>> [E:40098r S:0 M:186828789] (U) Msg RX from 0:E610190E890434EB [0000] --- Type 0000:20 (SecureChannel:PBKDFParamRequest)

I (8847) chip[EM]: <<< [E:40098r S:0 M:221877313] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:21 (SecureChannel:PBKDFParamResponse)

I (8867) chip[IN]: (U) Sending msg 221877313 to IP address 'BLE'

I (8877) NimBLE: GATT procedure initiated: indicate;

I (8877) NimBLE: att_handle=14

I (8927) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14

I (8927) NimBLE: GATT procedure initiated: indicate;

I (8937) NimBLE: att_handle=14

I (9017) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14

I (9017) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12

I (9027) chip[EM]: >>> [E:40098r S:0 M:186828790] (U) Msg RX from 0:E610190E890434EB [0000] --- Type 0000:22 (SecureChannel:PASE_Pake1)

I (9507) chip[EM]: <<< [E:40098r S:0 M:221877314] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:23 (SecureChannel:PASE_Pake2)

I (9527) chip[IN]: (U) Sending msg 221877314 to IP address 'BLE'

I (9527) NimBLE: GATT procedure initiated: indicate;

I (9537) NimBLE: att_handle=14

I (9597) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14

I (9597) NimBLE: GATT procedure initiated: indicate;

I (9607) NimBLE: att_handle=14

I (9687) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14

I (9687) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12

I (9697) chip[EM]: >>> [E:40098r S:0 M:186828791] (U) Msg RX from 0:E610190E890434EB [0000] --- Type 0000:24 (SecureChannel:PASE_Pake3)

I (9717) chip[EM]: <<< [E:40098r S:0 M:221877315] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport)

I (9727) chip[IN]: (U) Sending msg 221877315 to IP address 'BLE'

I (9727) NimBLE: GATT procedure initiated: indicate;

I (9737) NimBLE: att_handle=14

I (9747) chip[SC]: SecureSession[0x3fc9d880, LSID:64772]: State change 'kEstablishing' --> 'kActive'

I (9757) chip[SVR]: Commissioning completed session establishment step

I (9757) chip[DIS]: Updating services using commissioning mode 0

I (9767) chip[DIS]: CHIP minimal mDNS started advertising.

I (9767) chip[SVR]: Device completed Rendezvous process

I (9777) app_main: Commissioning session started

I (9777) app_main: Commissioning window closed

I (9827) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14

I (9867) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12

I (9867) chip[EM]: >>> [E:40099r S:64772 M:104744059] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)

I (9887) chip[EM]: <<< [E:40099r S:64772 M:61398337] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData)

I (9897) chip[IN]: (S) Sending msg 61398337 on secure session with LSID: 64772

I (9897) NimBLE: GATT procedure initiated: indicate;

I (9907) NimBLE: att_handle=14

I (9957) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14

I (9957) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12

I (9977) chip[EM]: >>> [E:40100r S:64772 M:104744060] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)

I (9987) chip[EM]: <<< [E:40100r S:64772 M:61398338] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData)

I (9987) chip[IN]: (S) Sending msg 61398338 on secure session with LSID: 64772

I (9997) NimBLE: GATT procedure initiated: indicate;

I (10017) NimBLE: att_handle=14

I (10097) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14

I (10097) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12

I (10107) chip[EM]: >>> [E:40101r S:64772 M:104744061] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)

I (10127) chip[EM]: <<< [E:40101r S:64772 M:61398339] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData)

I (10127) chip[IN]: (S) Sending msg 61398339 on secure session with LSID: 64772

I (10137) NimBLE: GATT procedure initiated: indicate;

I (10147) NimBLE: att_handle=14

I (10277) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14

I (10277) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12

I (10287) chip[EM]: >>> [E:40102r S:64772 M:104744062] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)

I (10307) chip[EM]: <<< [E:40102r S:64772 M:61398340] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData)

I (10307) chip[IN]: (S) Sending msg 61398340 on secure session with LSID: 64772

I (10317) NimBLE: GATT procedure initiated: indicate;

I (10327) NimBLE: att_handle=14

I (10457) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14

I (10457) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12

I (10467) chip[EM]: >>> [E:40103r S:64772 M:104744063] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)

I (10487) chip[EM]: <<< [E:40103r S:64772 M:61398341] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData)

I (10487) chip[IN]: (S) Sending msg 61398341 on secure session with LSID: 64772

I (10497) NimBLE: GATT procedure initiated: indicate;

I (10507) NimBLE: att_handle=14

I (10587) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14

I (10587) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12

I (10607) chip[EM]: >>> [E:40104r S:64772 M:104744064] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)

I (10617) chip[EM]: <<< [E:40104r S:64772 M:61398342] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData)

I (10617) chip[IN]: (S) Sending msg 61398342 on secure session with LSID: 64772

I (10627) NimBLE: GATT procedure initiated: indicate;

I (10647) NimBLE: att_handle=14

I (10767) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14

I (10767) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12

I (10787) chip[EM]: >>> [E:40105r S:64772 M:104744065] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)

I (10797) chip[EM]: <<< [E:40105r S:64772 M:61398343] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData)

I (10797) chip[IN]: (S) Sending msg 61398343 on secure session with LSID: 64772

I (10807) NimBLE: GATT procedure initiated: indicate;

I (10827) NimBLE: att_handle=14

I (10947) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14

I (12027) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12

I (12027) chip[EM]: >>> [E:40106r S:64772 M:104744066] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:0a (IM:TimedRequest)

I (12047) chip[EM]: <<< [E:40106r S:64772 M:61398344] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:01 (IM:StatusResponse)

I (12057) chip[IN]: (S) Sending msg 61398344 on secure session with LSID: 64772

I (12067) NimBLE: GATT procedure initiated: indicate;

I (12067) NimBLE: att_handle=14

I (12117) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14

I (12117) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12

I (12137) chip[EM]: >>> [E:40106r S:64772 M:104744067] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)

I (12147) esp_matter_command: Received command 0x00000000 for endpoint 0x0000's cluster 0x00000030

I (12157) chip[FS]: GeneralCommissioning: Received ArmFailSafe (120s)

I (12157) esp_matter_attribute: ** W : Endpoint 0x0000's Cluster 0x00000030's Attribute 0x00000000 is 1 **

I (12177) chip[EM]: <<< [E:40106r S:64772 M:61398345] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)

I (12187) chip[IN]: (S) Sending msg 61398345 on secure session with LSID: 64772

I (12197) NimBLE: GATT procedure initiated: indicate;

I (12197) NimBLE: att_handle=14

I (12257) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14

I (12257) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12

I (12267) chip[EM]: >>> [E:40107r S:64772 M:104744068] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)

I (12287) chip[EM]: <<< [E:40107r S:64772 M:61398346] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData)

I (12297) chip[IN]: (S) Sending msg 61398346 on secure session with LSID: 64772

I (12297) NimBLE: GATT procedure initiated: indicate;

I (12307) NimBLE: att_handle=14

I (12437) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14

I (12437) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12

I (12447) chip[EM]: >>> [E:40108r S:64772 M:104744069] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:0a (IM:TimedRequest)

I (12457) chip[EM]: <<< [E:40108r S:64772 M:61398347] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:01 (IM:StatusResponse)

I (12477) chip[IN]: (S) Sending msg 61398347 on secure session with LSID: 64772

I (12477) NimBLE: GATT procedure initiated: indicate;

I (12487) NimBLE: att_handle=14

I (12617) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14

I (12617) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12

I (12627) chip[EM]: >>> [E:40108r S:64772 M:104744070] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)

I (12637) esp_matter_command: Received command 0x00000002 for endpoint 0x0000's cluster 0x00000030

I (12657) chip[DL]: NVS set: chip-config/reg-location = 0 (0x0)

I (12657) chip[DL]: NVS set: chip-config/country-code = "US"

I (12667) esp_matter_attribute: ** W : Endpoint 0x0000's Cluster 0x00000030's Attribute 0x00000000 is 1 **

I (12667) chip[EM]: <<< [E:40108r S:64772 M:61398348] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)

I (12677) chip[IN]: (S) Sending msg 61398348 on secure session with LSID: 64772

I (12697) NimBLE: GATT procedure initiated: indicate;

I (12707) NimBLE: att_handle=14

I (12887) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14

I (12887) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12

I (12897) chip[EM]: >>> [E:40109r S:64772 M:104744071] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)

I (12907) esp_matter_command: Received command 0x00000002 for endpoint 0x0000's cluster 0x0000003E

I (12927) chip[ZCL]: OpCreds: Certificate Chain request received for DAC

I (12927) chip[EM]: <<< [E:40109r S:64772 M:61398349] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)

I (12937) chip[IN]: (S) Sending msg 61398349 on secure session with LSID: 64772

I (12947) NimBLE: GATT procedure initiated: indicate;

I (12957) NimBLE: att_handle=14

I (13107) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14

I (13107) NimBLE: GATT procedure initiated: indicate;

I (13117) NimBLE: att_handle=14

I (13287) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14

I (13287) NimBLE: GATT procedure initiated: indicate;

I (13297) NimBLE: att_handle=14

I (13427) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14

I (13427) NimBLE: GATT procedure initiated: indicate;

I (13437) NimBLE: att_handle=14

I (13557) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14

I (13557) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12

I (13567) NimBLE: GATT procedure initiated: indicate;

I (13577) NimBLE: att_handle=14

I (13697) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14

I (13697) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12

I (13707) chip[EM]: >>> [E:40110r S:64772 M:104744072] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)

I (13717) esp_matter_command: Received command 0x00000002 for endpoint 0x0000's cluster 0x0000003E

I (13737) chip[ZCL]: OpCreds: Certificate Chain request received for PAI

I (13737) chip[EM]: <<< [E:40110r S:64772 M:61398350] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)

I (13747) chip[IN]: (S) Sending msg 61398350 on secure session with LSID: 64772

I (13757) NimBLE: GATT procedure initiated: indicate;

I (13767) NimBLE: att_handle=14

I (13967) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14

I (13967) NimBLE: GATT procedure initiated: indicate;

I (13977) NimBLE: att_handle=14

I (14097) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14

I (14097) NimBLE: GATT procedure initiated: indicate;

I (14107) NimBLE: att_handle=14

I (14237) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14

I (14237) NimBLE: GATT procedure initiated: indicate;

I (14247) NimBLE: att_handle=14

I (14327) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14

I (14327) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12

I (14337) NimBLE: GATT procedure initiated: indicate;

I (14337) NimBLE: att_handle=14

I (14457) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14

I (14457) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12

I (14477) chip[EM]: >>> [E:40111r S:64772 M:104744073] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)

I (14487) esp_matter_command: Received command 0x00000000 for endpoint 0x0000's cluster 0x0000003E

I (14497) chip[ZCL]: OpCreds: Received an AttestationRequest command

I (14547) chip[ZCL]: OpCreds: AttestationRequest successful.

I (14547) chip[EM]: <<< [E:40111r S:64772 M:61398351] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)

I (14567) chip[IN]: (S) Sending msg 61398351 on secure session with LSID: 64772

I (14567) NimBLE: GATT procedure initiated: indicate;

I (14577) NimBLE: att_handle=14

I (14637) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14

I (14637) NimBLE: GATT procedure initiated: indicate;

I (14647) NimBLE: att_handle=14

I (14727) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14

I (14727) NimBLE: GATT procedure initiated: indicate;

I (14737) NimBLE: att_handle=14

I (14867) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14

I (14867) NimBLE: GATT procedure initiated: indicate;

I (14877) NimBLE: att_handle=14

I (14957) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14

I (14957) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12

I (14967) NimBLE: GATT procedure initiated: indicate;

I (14967) NimBLE: att_handle=14

I (15047) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14

I (15047) NimBLE: GATT procedure initiated: indicate;

I (15057) NimBLE: att_handle=14

I (15137) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14

I (15137) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12

I (15147) chip[EM]: >>> [E:40112r S:64772 M:104744074] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)

I (15157) esp_matter_command: Received command 0x00000004 for endpoint 0x0000's cluster 0x0000003E

I (15177) chip[ZCL]: OpCreds: Received a CSRRequest command

I (15257) chip[ZCL]: OpCreds: AllocatePendingOperationalKey succeeded

I (15307) chip[ZCL]: OpCreds: CSRRequest successful.

I (15307) chip[EM]: <<< [E:40112r S:64772 M:61398352] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)

I (15327) chip[IN]: (S) Sending msg 61398352 on secure session with LSID: 64772

I (15327) NimBLE: GATT procedure initiated: indicate;

I (15337) NimBLE: att_handle=14

I (15537) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14

I (15537) NimBLE: GATT procedure initiated: indicate;

I (15547) NimBLE: att_handle=14

I (15677) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14

I (15677) NimBLE: GATT procedure initiated: indicate;

I (15687) NimBLE: att_handle=14

I (15767) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14

I (15767) NimBLE: GATT procedure initiated: indicate;

I (15777) NimBLE: att_handle=14

I (15857) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14

I (15857) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12

I (16667) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12

I (16757) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12

I (16847) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12

I (16847) NimBLE: GATT procedure initiated: indicate;

I (16857) NimBLE: att_handle=14

I (16857) chip[EM]: >>> [E:40113r S:64772 M:104744075] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)

I (16877) esp_matter_command: Received command 0x0000000B for endpoint 0x0000's cluster 0x0000003E

I (16877) chip[ZCL]: OpCreds: Received an AddTrustedRootCertificate command

I (16937) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14

I (17047) chip[ZCL]: OpCreds: AddTrustedRootCertificate successful.

I (17047) chip[EM]: <<< [E:40113r S:64772 M:61398353] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)

I (17057) chip[IN]: (S) Sending msg 61398353 on secure session with LSID: 64772

I (17067) NimBLE: GATT procedure initiated: indicate;

I (17067) NimBLE: att_handle=14

I (17247) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14

I (17247) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12

I (17337) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12

I (17427) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12

I (17517) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12

I (17517) NimBLE: GATT procedure initiated: indicate;

I (17527) NimBLE: att_handle=14

I (17537) chip[EM]: >>> [E:40114r S:64772 M:104744076] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)

I (17547) esp_matter_command: Received command 0x00000006 for endpoint 0x0000's cluster 0x0000003E

I (17547) chip[ZCL]: OpCreds: Received an AddNOC command

I (17557) chip[FP]: Validating NOC chain

I (17607) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14

I (17717) chip[FP]: NOC chain validation successful

I (17727) chip[FP]: Added new fabric at index: 0x1

I (17727) chip[FP]: Assigned compressed fabric ID: 0xE1DB7CF1DF9D0ABC, node ID: 0x1342C99BE59003A6

I (17737) chip[TS]: Last Known Good Time: 2023-07-31T10:58:29

I (17747) chip[TS]: New proposed Last Known Good Time: 2023-07-24T00:00:00

I (17747) chip[TS]: Retaining current Last Known Good Time

I (17767) chip[ZCL]: OpCreds: ACL entry created for Fabric index 0x1 CASE Admin Subject 0xFFFFFFFD00010001

I (17767) chip[DIS]: Advertise operational node E1DB7CF1DF9D0ABC-1342C99BE59003A6

I (17777) chip[DIS]: CHIP minimal mDNS configured as 'Operational device'; instance name: E1DB7CF1DF9D0ABC-1342C99BE59003A6.

I (17787) chip[DIS]: mDNS service published: _matter._tcp

I (17787) chip[ZCL]: OpCreds: successfully created fabric index 0x1 via AddNOC

I (17807) chip[EM]: <<< [E:40114r S:64772 M:61398354] (S) Msg TX to 1:FFFFFFFB00000000 [0ABC] --- Type 0001:09 (IM:InvokeCommandResponse)

I (17817) chip[IN]: (S) Sending msg 61398354 on secure session with LSID: 64772

I (17827) NimBLE: GATT procedure initiated: indicate;

I (17827) NimBLE: att_handle=14

I (17827) app_main: Fabric is updated

I (17877) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14

I (17877) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12

I (17897) chip[EM]: >>> [E:40115r S:64772 M:104744077] (S) Msg RX from 1:FFFFFFFB00000000 [0ABC] --- Type 0001:08 (IM:InvokeCommandRequest)

I (17907) esp_matter_attribute: ** W : Endpoint 0x0000's Cluster 0x00000030's Attribute 0x00000000 is 1 **

I (17917) chip[EM]: <<< [E:40115r S:64772 M:61398355] (S) Msg TX to 1:FFFFFFFB00000000 [0ABC] --- Type 0001:09 (IM:InvokeCommandResponse)

I (17937) chip[IN]: (S) Sending msg 61398355 on secure session with LSID: 64772

I (17937) NimBLE: GATT procedure initiated: indicate;

I (17947) NimBLE: att_handle=14

I (18107) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14

I (18107) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12

I (18117) chip[EM]: >>> [E:40116r S:64772 M:104744078] (S) Msg RX from 1:FFFFFFFB00000000 [0ABC] --- Type 0001:02 (IM:ReadRequest)

I (18137) chip[EM]: <<< [E:40116r S:64772 M:61398356] (S) Msg TX to 1:FFFFFFFB00000000 [0ABC] --- Type 0001:05 (IM:ReportData)

I (18147) chip[IN]: (S) Sending msg 61398356 on secure session with LSID: 64772

I (18147) NimBLE: GATT procedure initiated: indicate;

I (18157) NimBLE: att_handle=14

I (18327) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14

I (18327) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12

I (18347) chip[EM]: >>> [E:40117r S:64772 M:104744079] (S) Msg RX from 1:FFFFFFFB00000000 [0ABC] --- Type 0001:08 (IM:InvokeCommandRequest)

I (18357) chip[NP]: ESP NetworkCommissioningDelegate: SSID: Glide

W (18357) wifi:Haven't to connect to a suitable AP now!

I (18367) chip[DL]: WiFi station mode change: Enabled -> Disabled

I (18377) chip[DL]: WiFi station mode change: Disabled -> Enabled

W (18387) wifi:Haven't to connect to a suitable AP now!

I (18387) chip[DL]: Attempting to connect WiFi station interface

I (18397) chip[DL]: WiFi station state change: NotConnected -> Connecting

I (18397) chip[DL]: Done driving station state, nothing else to do...

W (18407) wifi:Haven't to connect to a suitable AP now!

I (18407) chip[DL]: Attempting to connect WiFi station interface

E (18417) wifi:sta is connecting, return error

E (18417) chip[DL]: esp_wifi_connect() failed: ESP_ERR_WIFI_CONN

W (18437) wifi:Haven't to connect to a suitable AP now!

I (18437) chip[DL]: Attempting to connect WiFi station interface

E (18447) wifi:sta is connecting, return error

E (18447) chip[DL]: esp_wifi_connect() failed: ESP_ERR_WIFI_CONN

W (18457) wifi:Haven't to connect to a suitable AP now!

E (18457) chip[DL]: Failed to get configured network when updating network status: Error ESP32:0x0500300F

I (18887) wifi:new:<3,0>, old:<1,0>, ap:<255,255>, sta:<3,0>, prof:1

I (19497) wifi:state: init -> auth (b0)

I (19507) wifi:state: auth -> assoc (0)

I (19547) wifi:state: assoc -> run (10)

I (19617) wifi:connected with Glide, aid = 2, channel 3, BW20, bssid = e8:48:b8:15:63:1d

I (19617) wifi:security: WPA2-PSK, phy: bgn, rssi: -71

I (19697) wifi:pm start, type: 1

I (19697) wifi:set rx beacon pti, rx_bcn_pti: 14, bcn_timeout: 25000, mt_pti: 14, mt_time: 10000

I (19697) chip[DL]: WIFI_EVENT_STA_CONNECTED

I (19707) chip[DL]: WiFi station state change: Connecting -> Connecting_Succeeded

I (19707) chip[DL]: WiFi station state change: Connecting_Succeeded -> Connected

I (19717) chip[DL]: WiFi station interface connected

I (19727) esp_matter_attribute: ** W : Endpoint 0x0000's Cluster 0x00000030's Attribute 0x00000000 is 1 **

I (19737) chip[EM]: <<< [E:40117r S:64772 M:61398357] (S) Msg TX to 1:FFFFFFFB00000000 [0ABC] --- Type 0001:09 (IM:InvokeCommandResponse)

I (19747) chip[IN]: (S) Sending msg 61398357 on secure session with LSID: 64772

I (19757) NimBLE: GATT procedure initiated: indicate;

I (19757) NimBLE: att_handle=14

I (19777) chip[ZCL]: WiFiDiagnosticsDelegate: OnConnectionStatusChanged

I (19777) chip[DL]: Done driving station state, nothing else to do...

I (19747) wifi:AP's beacon interval = 102400 us, DTIM period = 1

I (19787) chip[DIS]: Advertise operational node E1DB7CF1DF9D0ABC-1342C99BE59003A6

I (19797) chip[DIS]: CHIP minimal mDNS configured as 'Operational device'; instance name: E1DB7CF1DF9D0ABC-1342C99BE59003A6.

I (19817) chip[DIS]: mDNS service published: _matter._tcp

I (19817) chip[SVR]: Operational advertising enabled

I (19827) chip[DL]: Updating advertising data

I (19857) wifi:idx:0 (ifx:0, e8:48:b8:15:63:1d), tid:7, ssn:1, winSize:64

I (19907) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14

I (20847) chip[DL]: Write request/command received for CHIPoBLE TX CCCD characteristic (con 1 ) indicate = 0

I (20847) chip[DL]: CHIPoBLE unsubscribe received

I (20857) chip[DL]: BLE GAP connection terminated (con 1 reason 0x213)

I (20847) chip[BLE]: Releasing end point's BLE connection back to application.

I (20877) NimBLE: GAP procedure initiated: stop advertising.

I (20887) wifi:idx:1 (ifx:0, e8:48:b8:15:63:1d), tid:0, ssn:2, winSize:64

I (21697) esp_netif_handlers: sta ip: 192.168.6.103, mask: 255.255.252.0, gw: 192.168.6.1

I (21887) esp_matter_core: BLE deinit successful and memory reclaimed

E (21887) chip[DL]: Long dispatch time: 1012 ms, for event type 32776

I (21897) chip[DL]: IP_EVENT_GOT_IP6

I (21897) chip[DL]: IPv6 addr available. Ready on WIFI_STA_DEF interface: fe80:0000:0000:0000:86f7:03ff:fe66:be3c

I (21907) chip[DL]: IPv4 Internet connectivity ESTABLISHED

I (21907) chip[DL]: IP_EVENT_STA_GOT_IP

I (21917) chip[DL]: IPv4 address changed on WiFi station interface: 192.168.6.103/255.255.252.0 gateway 192.168.6.1

I (21937) app_main: Interface IP Address changed

I (21937) chip[DIS]: Updating services using commissioning mode 0

I (21947) chip[DIS]: CHIP minimal mDNS started advertising.

I (21957) chip[DIS]: Advertise operational node E1DB7CF1DF9D0ABC-1342C99BE59003A6

I (21957) chip[DIS]: CHIP minimal mDNS configured as 'Operational device'; instance name: E1DB7CF1DF9D0ABC-1342C99BE59003A6.

I (21977) chip[DIS]: mDNS service published: _matter._tcp

I (21977) app_main: Interface IP Address changed

I (21987) chip[DIS]: Updating services using commissioning mode 0

I (21987) chip[DIS]: CHIP minimal mDNS started advertising.

I (22007) chip[DIS]: Advertise operational node E1DB7CF1DF9D0ABC-1342C99BE59003A6

I (22007) chip[DIS]: CHIP minimal mDNS configured as 'Operational device'; instance name: E1DB7CF1DF9D0ABC-1342C99BE59003A6.

I (22027) chip[DIS]: mDNS service published: _matter._tcp

I (22027) chip[SVR]: Server initialization complete

I (22037) chip[DIS]: Updating services using commissioning mode 0

I (22037) chip[DIS]: CHIP minimal mDNS started advertising.

I (22057) chip[DIS]: Advertise operational node E1DB7CF1DF9D0ABC-1342C99BE59003A6

I (22057) chip[DIS]: CHIP minimal mDNS configured as 'Operational device'; instance name: E1DB7CF1DF9D0ABC-1342C99BE59003A6.

I (22077) chip[DIS]: mDNS service published: _matter._tcp

I (22077) chip[IM]: No subscriptions to resume

I (22087) ROUTE_HOOK: Received RIO

I (22087) ROUTE_HOOK: prefix FD3D:D093:48E3:1:: lifetime 1800

I (22097) ROUTE_HOOK: Received RIO

I (22097) ROUTE_HOOK: prefix FD3D:D093:48E3:1:: lifetime 1800

I (22097) ROUTE_HOOK: Received RIO

I (22107) ROUTE_HOOK: prefix FD3D:D093:48E3:1:: lifetime 1800

I (23567) chip[DL]: IP_EVENT_GOT_IP6

I (23567) chip[DL]: IPv6 addr available. Ready on WIFI_STA_DEF interface: fd1b:44e8:53cc:b5b9:86f7:03ff:fe66:be3c

I (23577) ROUTE_HOOK: Hook already installed on netif, skip...

I (23577) app_main: Interface IP Address changed

I (23587) chip[DIS]: Updating services using commissioning mode 0

I (23587) chip[DIS]: CHIP minimal mDNS started advertising.

I (23607) chip[DIS]: Advertise operational node E1DB7CF1DF9D0ABC-1342C99BE59003A6

I (23607) chip[DIS]: CHIP minimal mDNS configured as 'Operational device'; instance name: E1DB7CF1DF9D0ABC-1342C99BE59003A6.

I (23627) chip[DIS]: mDNS service published: _matter._tcp

I (132157) chip[FS]: Fail-safe timer expired

E (132157) chip[SVR]: Failsafe timer expired

I (132157) chip[SC]: SecureSession[0x3fc9d880, LSID:64772]: State change 'kActive' --> 'kPendingEviction'

E (132167) chip[SVR]: Commissioning failed (attempt 1): 32

E (132187) chip[BLE]: CancelBleIncompleteConnection() failed, err = 3

I (132187) chip[DIS]: Updating services using commissioning mode 1

I (132197) chip[DIS]: CHIP minimal mDNS started advertising.

I (132207) chip[DIS]: Advertise operational node E1DB7CF1DF9D0ABC-1342C99BE59003A6

I (132207) chip[DIS]: CHIP minimal mDNS configured as 'Operational device'; instance name: E1DB7CF1DF9D0ABC-1342C99BE59003A6.

I (132227) chip[DIS]: mDNS service published: _matter._tcp

I (132227) chip[DIS]: Advertise commission parameter vendorID=65521 productID=32768 discriminator=3840/15 cm=1

I (132237) chip[DIS]: CHIP minimal mDNS configured as 'Commissionable node device'; instance name: 93E349D07B78B85F.

I (132257) chip[DIS]: mDNS service published: _matterc._udp

E (132257) chip[ZCL]: OpCreds: Got FailSafeTimerExpired

E (132257) chip[ZCL]: OpCreds: Proceeding to FailSafeCleanup on fail-safe expiry!

E (132267) chip[FP]: Reverting pending fabric data for fabric 0x1

E (132287) chip[FP]: Warning: metadata not found during delete of fabric 0x1

I (132307) chip[FP]: Fabric (0x1) deleted.

I (132307) chip[ZCL]: OpCreds: Fabric index 0x1 was removed

I (132307) chip[DIS]: Updating services using commissioning mode 1

I (132317) chip[DIS]: CHIP minimal mDNS started advertising.

I (132337) chip[DIS]: Advertise commission parameter vendorID=65521 productID=32768 discriminator=3840/15 cm=1

I (132337) chip[DIS]: CHIP minimal mDNS configured as 'Commissionable node device'; instance name: 93E349D07B78B85F.

I (132357) chip[DIS]: mDNS service published: _matterc._udp

I (132387) chip[TS]: Pending Last Known Good Time: 2023-07-31T10:58:29

I (132387) chip[TS]: Previous Last Known Good Time: 2023-07-31T10:58:29

I (132397) chip[TS]: Reverted Last Known Good Time to previous value

E (132397) chip[FP]: Warning: metadata not found during delete of fabric 0x1

E (132407) chip[ZCL]: OpCreds: failed to delete fabric at index 1: d8

I (132417) esp_matter_attribute: ** W : Endpoint 0x0000's Cluster 0x00000030's Attribute 0x00000000 is 0 **

I (132427) app_main: Commissioning failed, fail safe timer expired

I (132427) chip[FS]: Fail-safe cleanly disarmed

E (132437) chip[DL]: ble_gap_adv_set_data failed: Error ESP32:0x05B0001E 3840

E (132437) chip[DL]: Configure Adv Data failed: Error ESP32:0x05B0001E

E (132457) chip[DL]: Disabling CHIPoBLE service due to error: Error ESP32:0x05B0001E

I (132467) app_main: Commissioning window opened

I (132467) app_main: Fabric will be removed

I (132467) app_main: Fabric removed successfully

I (132477) app_main: Fabric will be removed

dhrishi commented 11 months ago

@jayveeeer Are you using chip-tool to commission the device? If yes, please make sure that the host machine running the chip-tool is connected to the same Wi-Fi network to which the ESP32-C3 is connected. The logs show that CASE Sigma1 message is not received from the commissioner on the IP network.

jayveeeer commented 11 months ago

Yes they all are connected to same wifi network Sometimes there also commissioning error using chip tool in pc too

And i would like to ask which version of Esp-idf and Esp-matter should i use from the github ?