connectedhomeip: Commissioning over BLE fails on iOS 15.3 and macOS 12.2.1
Commissioning over BLE doesnβt seem to work with the current code base. Iβve tested the following setups:
Controllers
- macOS chip-tool (macOS versions 12.2.0 and 12.2.1)
- macOS python (macOS versions 12.2.0 and 12.2.1)
- iOS CHIP Tool App (iOS version 15.3)
Devices
- EFR32 window-app
- ESP32 all-clusters-app
Here is the output of the iOS app:
2022-02-14 15:14:30.270653+0100 CHIPTool[12159:4753617] CHIPOperationalCredentialsDelegate: No NOC Signer provided, using self managed keys
2022-02-14 15:14:30.276743+0100 CHIPTool[12159:4753617] Found an existing self managed keypair in the keychain
2022-02-14 15:14:30.276817+0100 CHIPTool[12159:4753617] Deserializing the key
2022-02-14 15:14:30.277120+0100 CHIPTool[12159:4753617] CHIPOperationalCredentialsDelegate::init returning ../../../../../../../../../../../Downloads/connectedhomeip.git/src/crypto/CHIPCryptoPALmbedTLS.cpp:761: Success
2022-02-14 15:14:30.277175+0100 CHIPTool[12159:4753617] PersistentStorageDelegate Sync Get Value for Key: com.zigbee.chip.commissioner.device_id
2022-02-14 15:14:30.277288+0100 CHIPTool[12159:4753617] CHIPPersistentStorageDelegate Get Value for Key: com.zigbee.chip.commissioner.device_id, value MZ0Y2ldcHyc=
2022-02-14 15:14:30.277332+0100 CHIPTool[12159:4753617] Found 271f5c57da189d31 node ID for the controller
2022-02-14 15:14:30.294783+0100 CHIPTool[12159:4753617] PersistentStorageDelegate Sync Get Value for Key: MatterCARootCert0
2022-02-14 15:14:30.294891+0100 CHIPTool[12159:4753617] CHIPPersistentStorageDelegate Get Value for Key: MatterCARootCert0, value MIIB2jCCAYCgAwIBAgIBADAKBggqhkjOPQQDAjBEMSAwHgYKKwYBBAGConwBBAwQMDAwMDAwMDAwMDAwMDREMjEgMB4GCisGAQQBgqJ8AQUMEDAwMDAwMDAwMDAwMDAwMDAwHhcNMjIwMjE0MTUxMjA0WhcNMjMwMjE0MTUxMjA0WjBEMSAwHgYKKwYBBAGConwBBAwQMDAwMDAwMDAwMDAwMDREMjEgMB4GCisGAQQBgqJ8AQUMEDAwMDAwMDAwMDAwMDAwMDAwWTATBgcqhkjOPQIBBggqhkjOPQMBBwNCAARkLVBBkyfWjyfeaSHkpxiMHmOY/DF8bqfBVflJnPQgfk+IXDFXwFB/KSIbTFAxLMDoOgHqKmu1gsw3tEaJLEM9o2MwYTAPBgNVHRMBAf8EBTADAQH/MA4GA1UdDwEB/wQEAwIBBjAdBgNVHQ4EFgQUYOEPuKIBPDjFonjgWRDqowCyMKIwHwYDVR0jBBgwFoAUYOEPuKIBPDjFonjgWRDqowCyMKIwCgYIKoZIzj0EAwIDSAAwRQIgR75fUq30PfbeefJOpn9XZzvfW4wAupJGbAFCuBPAk4ECIQC9XqRS0259UN04c8si+ukV7AaEjnhldLRyRo2nj4A8Mw==
2022-02-14 15:14:30.295363+0100 CHIPTool[12159:4753617] [all] π΅ [1644848070295] [12159:4753617] CHIP: [DL] Found user documents directory: file:///var/mobile/Containers/Data/Application/F79BEE14-BE33-4459-BCDB-E7ED986049EC/Documents/
2022-02-14 15:14:30.295419+0100 CHIPTool[12159:4753617] [all] π΅ [1644848070295] [12159:4753617] CHIP: [DL] KVS will be written to: file:///var/mobile/Containers/Data/Application/F79BEE14-BE33-4459-BCDB-E7ED986049EC/Documents/chip.store
2022-02-14 15:14:30.302327+0100 CHIPTool[12159:4753617] [all] π’ [1644848070302] [12159:4753617] CHIP: [DL] _Init
2022-02-14 15:14:30.302421+0100 CHIPTool[12159:4753617] [all] π’ [1644848070302] [12159:4753617] CHIP: [IN] UDP::Init bind&listen port=0
2022-02-14 15:14:30.302543+0100 CHIPTool[12159:4753617] [all] π’ [1644848070302] [12159:4753617] CHIP: [IN] UDP::Init bound to port=59058
2022-02-14 15:14:30.302570+0100 CHIPTool[12159:4753617] [all] π’ [1644848070302] [12159:4753617] CHIP: [IN] UDP::Init bind&listen port=0
2022-02-14 15:14:30.302626+0100 CHIPTool[12159:4753617] [all] π’ [1644848070302] [12159:4753617] CHIP: [IN] UDP::Init bound to port=52379
2022-02-14 15:14:30.302693+0100 CHIPTool[12159:4753617] [all] π’ [1644848070302] [12159:4753617] CHIP: [IN] TransportMgr initialized
2022-02-14 15:14:30.302744+0100 CHIPTool[12159:4753617] [all] π’ [1644848070302] [12159:4753617] CHIP: [DIS] Init fabric pairing table with server storage
2022-02-14 15:14:30.302796+0100 CHIPTool[12159:4753617] PersistentStorageDelegate Sync Get Value for Key: F01/Fabric1
2022-02-14 15:14:30.302838+0100 CHIPTool[12159:4753617] CHIPPersistentStorageDelegate Get Value for Key: F01/Fabric1, value AQAAAAAAAAAxnRjaV1wfJwAAAAAAAAAAAADvAAAA/AAECqLHqK9ufybRQxZNhOndYSxDWXzXexzTCKxD7gZM/1y4pdw01tltQ/ir8KfAP1Gv1666iAeNFuGv+5zOSRUX7srVu+JLQTQIrQuQAhU/y47m3ireZGO/bMlmcniabrunAAAAAAAAAGEAAAAAAAAAFTABAQAkAgE3AyUU0gQkFQAYJgTELZ0pJgVEYX4rNwYlFNIEJBUAGCQHASQIATAJQQRkLVBBkyfWjyfeaSHkpxiMHmOY/DF8bqfBVflJnPQgfk+IXDFXwFB/KSIbTFAxLMDoOgHqKmu1gsw3tEaJLEM9Nwo1ASkBGCQCYDAEFGDhD7iiATw4xaJ44FkQ6qMAsjCiMAUUYOEPuKIBPDjFonjgWRDqowCyMKIYMAtAR75fUq30PfbeefJOpn9XZzvfW4wAupJGbAFCuBPAk4G9XqRS0259UN04c8si+ukV7AaEjnhldLRyRo2nj4A8MxgAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAVMAEBASQCATcDJRTSBCQVABgmBMQtnSkmBURhfis3BiQVACcRMZ0Y2ldcHycYJAcBJAgBMAlBBAqix6ivbn8m0UMWTYTp3WEsQ1l813sc0wisQ+4GTP9cuKXcNNbZbUP4q/CnwD9Rr9euuogHjRbhr/uczkkVF+43CjUBKAEYJAIBNgMEAgQBGDAEFKMKhVx3hHDwFA0hRdYd4to13+EsMAUUYOEPuKIBPDjFonjgWRDqowCyMKIYMAtANIk0uBaAPpyGx1/OzsXRO+Ag/GDQ/yzfftC8/K0qtEDuj03Be1gomR7j95supkcXNQN0YFWidw1tcQKc99UX/BgAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA==
2022-02-14 15:14:30.303135+0100 CHIPTool[12159:4753617] [all] π΅ [1644848070303] [12159:4753617] CHIP: [IN] Loading certs from storage
2022-02-14 15:14:30.303260+0100 CHIPTool[12159:4753617] [all] π’ [1644848070303] [12159:4753617] CHIP: [IN] Generating compressed fabric ID using uncompressed fabric ID 0x0000000000000000 and root pubkey
2022-02-14 15:14:30.303285+0100 CHIPTool[12159:4753617] [all] π’ [1644848070303] [12159:4753617] CHIP: [IN] 0x04, 0x64, 0x2d, 0x50, 0x41, 0x93, 0x27, 0xd6,
2022-02-14 15:14:30.303343+0100 CHIPTool[12159:4753617] [all] π’ [1644848070303] [12159:4753617] CHIP: [IN] 0x8f, 0x27, 0xde, 0x69, 0x21, 0xe4, 0xa7, 0x18,
2022-02-14 15:14:30.303364+0100 CHIPTool[12159:4753617] [all] π’ [1644848070303] [12159:4753617] CHIP: [IN] 0x8c, 0x1e, 0x63, 0x98, 0xfc, 0x31, 0x7c, 0x6e,
2022-02-14 15:14:30.303383+0100 CHIPTool[12159:4753617] [all] π’ [1644848070303] [12159:4753617] CHIP: [IN] 0xa7, 0xc1, 0x55, 0xf9, 0x49, 0x9c, 0xf4, 0x20,
2022-02-14 15:14:30.303402+0100 CHIPTool[12159:4753617] [all] π’ [1644848070303] [12159:4753617] CHIP: [IN] 0x7e, 0x4f, 0x88, 0x5c, 0x31, 0x57, 0xc0, 0x50,
2022-02-14 15:14:30.303420+0100 CHIPTool[12159:4753617] [all] π’ [1644848070303] [12159:4753617] CHIP: [IN] 0x7f, 0x29, 0x22, 0x1b, 0x4c, 0x50, 0x31, 0x2c,
2022-02-14 15:14:30.303438+0100 CHIPTool[12159:4753617] [all] π’ [1644848070303] [12159:4753617] CHIP: [IN] 0xc0, 0xe8, 0x3a, 0x01, 0xea, 0x2a, 0x6b, 0xb5,
2022-02-14 15:14:30.303648+0100 CHIPTool[12159:4753617] [all] π’ [1644848070303] [12159:4753617] CHIP: [IN] 0x82, 0xcc, 0x37, 0xb4, 0x46, 0x89, 0x2c, 0x43,
2022-02-14 15:14:30.303671+0100 CHIPTool[12159:4753617] [all] π’ [1644848070303] [12159:4753617] CHIP: [IN] 0x3d,
2022-02-14 15:14:30.303733+0100 CHIPTool[12159:4753617] [all] π’ [1644848070303] [12159:4753617] CHIP: [IN] Generated compressed fabric ID
2022-02-14 15:14:30.303754+0100 CHIPTool[12159:4753617] [all] π’ [1644848070303] [12159:4753617] CHIP: [IN] 0x0a, 0x99, 0x7f, 0xfc, 0xaf, 0x76, 0x49, 0xf6,
2022-02-14 15:14:30.303778+0100 CHIPTool[12159:4753617] PersistentStorageDelegate Sync Get Value for Key: F02/Fabric2
2022-02-14 15:14:30.303806+0100 CHIPTool[12159:4753617] CHIPPersistentStorageDelegate Get Value for Key: F02/Fabric2, value (null)
2022-02-14 15:14:30.303834+0100 CHIPTool[12159:4753617] PersistentStorageDelegate Sync Get Value for Key: F03/Fabric3
2022-02-14 15:14:30.303862+0100 CHIPTool[12159:4753617] CHIPPersistentStorageDelegate Get Value for Key: F03/Fabric3, value (null)
2022-02-14 15:14:30.303885+0100 CHIPTool[12159:4753617] PersistentStorageDelegate Sync Get Value for Key: F04/Fabric4
2022-02-14 15:14:30.303908+0100 CHIPTool[12159:4753617] CHIPPersistentStorageDelegate Get Value for Key: F04/Fabric4, value (null)
2022-02-14 15:14:30.303932+0100 CHIPTool[12159:4753617] PersistentStorageDelegate Sync Get Value for Key: F05/Fabric5
2022-02-14 15:14:30.303955+0100 CHIPTool[12159:4753617] CHIPPersistentStorageDelegate Get Value for Key: F05/Fabric5, value (null)
2022-02-14 15:14:30.303977+0100 CHIPTool[12159:4753617] PersistentStorageDelegate Sync Get Value for Key: F06/Fabric6
2022-02-14 15:14:30.304001+0100 CHIPTool[12159:4753617] CHIPPersistentStorageDelegate Get Value for Key: F06/Fabric6, value (null)
2022-02-14 15:14:30.304023+0100 CHIPTool[12159:4753617] PersistentStorageDelegate Sync Get Value for Key: F07/Fabric7
2022-02-14 15:14:30.304044+0100 CHIPTool[12159:4753617] CHIPPersistentStorageDelegate Get Value for Key: F07/Fabric7, value (null)
2022-02-14 15:14:30.304066+0100 CHIPTool[12159:4753617] PersistentStorageDelegate Sync Get Value for Key: F08/Fabric8
2022-02-14 15:14:30.304087+0100 CHIPTool[12159:4753617] CHIPPersistentStorageDelegate Get Value for Key: F08/Fabric8, value (null)
2022-02-14 15:14:30.304108+0100 CHIPTool[12159:4753617] PersistentStorageDelegate Sync Get Value for Key: F09/Fabric9
2022-02-14 15:14:30.304128+0100 CHIPTool[12159:4753617] CHIPPersistentStorageDelegate Get Value for Key: F09/Fabric9, value (null)
2022-02-14 15:14:30.304149+0100 CHIPTool[12159:4753617] PersistentStorageDelegate Sync Get Value for Key: F0A/Fabrica
2022-02-14 15:14:30.304215+0100 CHIPTool[12159:4753617] CHIPPersistentStorageDelegate Get Value for Key: F0A/Fabrica, value (null)
2022-02-14 15:14:30.304238+0100 CHIPTool[12159:4753617] PersistentStorageDelegate Sync Get Value for Key: F0B/Fabricb
2022-02-14 15:14:30.304260+0100 CHIPTool[12159:4753617] CHIPPersistentStorageDelegate Get Value for Key: F0B/Fabricb, value (null)
2022-02-14 15:14:30.304283+0100 CHIPTool[12159:4753617] PersistentStorageDelegate Sync Get Value for Key: F0C/Fabricc
2022-02-14 15:14:30.304310+0100 CHIPTool[12159:4753617] CHIPPersistentStorageDelegate Get Value for Key: F0C/Fabricc, value (null)
2022-02-14 15:14:30.304337+0100 CHIPTool[12159:4753617] PersistentStorageDelegate Sync Get Value for Key: F0D/Fabricd
2022-02-14 15:14:30.304358+0100 CHIPTool[12159:4753617] CHIPPersistentStorageDelegate Get Value for Key: F0D/Fabricd, value (null)
2022-02-14 15:14:30.304380+0100 CHIPTool[12159:4753617] PersistentStorageDelegate Sync Get Value for Key: F0E/Fabrice
2022-02-14 15:14:30.304606+0100 CHIPTool[12159:4753617] CHIPPersistentStorageDelegate Get Value for Key: F0E/Fabrice, value (null)
2022-02-14 15:14:30.304631+0100 CHIPTool[12159:4753617] PersistentStorageDelegate Sync Get Value for Key: F0F/Fabricf
2022-02-14 15:14:30.304652+0100 CHIPTool[12159:4753617] CHIPPersistentStorageDelegate Get Value for Key: F0F/Fabricf, value (null)
2022-02-14 15:14:30.304676+0100 CHIPTool[12159:4753617] PersistentStorageDelegate Sync Get Value for Key: F10/Fabric10
2022-02-14 15:14:30.304698+0100 CHIPTool[12159:4753617] CHIPPersistentStorageDelegate Get Value for Key: F10/Fabric10, value (null)
2022-02-14 15:14:30.305873+0100 CHIPTool[12159:4753617] [all] π΅ [1644848070305] [12159:4753617] CHIP: [ZCL] Using ZAP configuration...
2022-02-14 15:14:30.305981+0100 CHIPTool[12159:4753617] [all] π’ [1644848070305] [12159:4753617] CHIP: [CTL] System State Initialized...
2022-02-14 15:14:30.306054+0100 CHIPTool[12159:4753617] [all] π΅ [1644848070306] [12159:4753617] CHIP: [CTL] Intermediate CA is not needed
2022-02-14 15:14:30.306148+0100 CHIPTool[12159:4753617] [all] π΅ [1644848070306] [12159:4753617] CHIP: [DIS] Verifying the received credentials
2022-02-14 15:14:30.314932+0100 CHIPTool[12159:4753617] [all] π’ [1644848070314] [12159:4753617] CHIP: [IN] Generating compressed fabric ID using uncompressed fabric ID 0x0000000000000000 and root pubkey
2022-02-14 15:14:30.314955+0100 CHIPTool[12159:4753617] [all] π’ [1644848070314] [12159:4753617] CHIP: [IN] 0x04, 0x64, 0x2d, 0x50, 0x41, 0x93, 0x27, 0xd6,
2022-02-14 15:14:30.314971+0100 CHIPTool[12159:4753617] [all] π’ [1644848070314] [12159:4753617] CHIP: [IN] 0x8f, 0x27, 0xde, 0x69, 0x21, 0xe4, 0xa7, 0x18,
2022-02-14 15:14:30.314986+0100 CHIPTool[12159:4753617] [all] π’ [1644848070314] [12159:4753617] CHIP: [IN] 0x8c, 0x1e, 0x63, 0x98, 0xfc, 0x31, 0x7c, 0x6e,
2022-02-14 15:14:30.314999+0100 CHIPTool[12159:4753617] [all] π’ [1644848070314] [12159:4753617] CHIP: [IN] 0xa7, 0xc1, 0x55, 0xf9, 0x49, 0x9c, 0xf4, 0x20,
2022-02-14 15:14:30.315014+0100 CHIPTool[12159:4753617] [all] π’ [1644848070315] [12159:4753617] CHIP: [IN] 0x7e, 0x4f, 0x88, 0x5c, 0x31, 0x57, 0xc0, 0x50,
2022-02-14 15:14:30.315028+0100 CHIPTool[12159:4753617] [all] π’ [1644848070315] [12159:4753617] CHIP: [IN] 0x7f, 0x29, 0x22, 0x1b, 0x4c, 0x50, 0x31, 0x2c,
2022-02-14 15:14:30.315044+0100 CHIPTool[12159:4753617] [all] π’ [1644848070315] [12159:4753617] CHIP: [IN] 0xc0, 0xe8, 0x3a, 0x01, 0xea, 0x2a, 0x6b, 0xb5,
2022-02-14 15:14:30.315058+0100 CHIPTool[12159:4753617] [all] π’ [1644848070315] [12159:4753617] CHIP: [IN] 0x82, 0xcc, 0x37, 0xb4, 0x46, 0x89, 0x2c, 0x43,
2022-02-14 15:14:30.315071+0100 CHIPTool[12159:4753617] [all] π’ [1644848070315] [12159:4753617] CHIP: [IN] 0x3d,
2022-02-14 15:14:30.315100+0100 CHIPTool[12159:4753617] [all] π’ [1644848070315] [12159:4753617] CHIP: [IN] Generated compressed fabric ID
2022-02-14 15:14:30.315117+0100 CHIPTool[12159:4753617] [all] π’ [1644848070315] [12159:4753617] CHIP: [IN] 0x0a, 0x99, 0x7f, 0xfc, 0xaf, 0x76, 0x49, 0xf6,
2022-02-14 15:14:30.315138+0100 CHIPTool[12159:4753617] [all] π΅ [1644848070315] [12159:4753617] CHIP: [DIS] Added new fabric at index: 1, Initialized: 1
2022-02-14 15:14:30.315217+0100 CHIPTool[12159:4753617] [all] π΅ [1644848070315] [12159:4753617] CHIP: [DIS] Assigned compressed fabric ID: 0x0A997FFCAF7649F6, node ID: 0x271F5C57DA189D31
2022-02-14 15:14:30.315283+0100 CHIPTool[12159:4753617] [all] π΅ [1644848070315] [12159:4753617] CHIP: [CTL] Joined the fabric at index 1. Compressed fabric ID is: 0x0A997FFCAF7649F6
2022-02-14 15:14:30.315401+0100 CHIPTool[12159:4753635] [all] π’ [1644848070315] [12159:4753635] CHIP: [DL] _OnPlatformEvent
2022-02-14 15:14:30.315461+0100 CHIPTool[12159:4753617] PersistentStorageDelegate Sync Get Value for Key: ListPairedDevices0
2022-02-14 15:14:30.315513+0100 CHIPTool[12159:4753617] CHIPPersistentStorageDelegate Get Value for Key: ListPairedDevices0, value (null)
2022-02-14 15:14:33.878309+0100 CHIPTool[12159:4753617] Payload vendorID 9050
2022-02-14 15:14:33.878527+0100 CHIPTool[12159:4753617] Rendezvous Default
2022-02-14 15:14:33.878739+0100 CHIPTool[12159:4753617] [all] π΅ [1644848073878] [12159:4753617] CHIP: [BLE] NewConnection
2022-02-14 15:14:33.883193+0100 CHIPTool[12159:4753617] [all] π΄ [1644848073883] [12159:4753617] CHIP: [DL] Browse (kDNSServiceErr_NoAuth)
2022-02-14 15:14:33.883297+0100 CHIPTool[12159:4753617] Error(../../../../../../../../../../../Downloads/connectedhomeip.git/src/platform/Darwin/DnssdImpl.cpp:390: CHIP Error 0x000000AC: Internal error): Failure while pairing the device
2022-02-14 15:14:33.895536+0100 CHIPTool[12159:4753760] [all] π’ [1644848073895] [12159:4753760] CHIP: [BLE] CBManagerState: ON
2022-02-14 15:14:33.935160+0100 CHIPTool[12159:4753760] [all] π΅ [1644848073935] [12159:4753760] CHIP: [BLE] Connecting to device with discriminator: 3840
2022-02-14 15:14:34.455678+0100 CHIPTool[12159:4753756] [all] π΄ [1644848074455] [12159:4753756] CHIP: [BLE] Service not found on the device.
2022-02-14 15:14:34.455884+0100 CHIPTool[12159:4753756] [all] π΄ [1644848074455] [12159:4753756] CHIP: [-] ../../../../../../../../../../../Downloads/connectedhomeip.git/src/platform/Darwin/BleConnectionDelegateImpl.mm:221: CHIP Error 0x00000003: Incorrect state at ../../../../../../../../../../../Downloads/connectedho
Here is the output of the ESP32 device:
Waiting for the device to reconnect..........................
????Ρ₯???version: v7.0sion: 7679c42
I (1057) wifi:config NVS flash: enabled
I (1057) wifi:config nano formating: disabled
I (1067) wifi:Init data frame dynamic rx buffer num: 32
I (1067) wifi:Init management frame dynamic rx buffer num: 32
I (1067) wifi:Init management short buffer num: 32
I (1087) wifi:Init dynamic tx buffer num: 32
I (1087) wifi:Init static rx buffer size: 1600
I (1087) wifi:Init static rx buffer num: 10
I (1097) wifi:Init dynamic rx buffer num: 32
I (1097) wifi_init: rx ba win: 6
I (1097) wifi_init: tcpip mbox: 32
I (1107) wifi_init: udp mbox: 6
I (1107) wifi_init: tcp mbox: 6
I (1107) wifi_init: tcp tx win: 5744
I (1117) wifi_init: tcp rx win: 5744
I (1117) wifi_init: tcp mss: 1440
I (1117) wifi_init: WiFi IRAM OP enabled
I (1137) wifi_init: WiFi RX IRAM OP enabled
I (1147) chip[DL]: NVS set: chip-counters/reboot-count = 17 (0x11)
I (1147) chip[DL]: Real time clock set to 946684800 (0100/00/01 00:00:00 UTC)
I (1147) chip[SVR]: SetupQRCode: [MT:C8XA0SRB00KA0648G00]
I (1167) chip[SVR]: Copy/paste the below URL in a browser to see the QR Code:
https://dhrishi.github.io/connectedhomeip/qrcode.html?data=MT%3AC8XA0SRB00KA0648G00
I (1157) BTDM_INIT: BT controller compile version [6a07b06]
I (1177) chip[SVR]: Manual pairing code: [34970112332]
I (1187) phy_init: phy_version 4670,719f9f6,Feb 18 2021,17:07:07
I (1187) chip[SVR]: Long manual pairing code: [749701123309050177298]
I (1577) CHIP[DL]: BLE host-controller synced
I (2077) chip[DL]: Configuring CHIPoBLE advertising (interval 25 ms, connectable, device name MATTER-3840)
I (2087) NimBLE: GAP procedure initiated: advertise;
I (2097) NimBLE: disc_mode=2
I (2097) NimBLE: adv_channel_map=0 own_addr_type=2 adv_filter_policy=0 adv_itvl_min=40 adv_itvl_max=40
I (2107) NimBLE:
I (2107) chip[DL]: CHIPoBLE advertising started
E (2107) chip[DL]: Long dispatch time: 961 ms, for event type 2
I (2127) chip[DL]: Starting ESP WiFi layer
I (2127) wifi:mode : sta (24:0a:c4:96:5d:08)
I (2127) wifi:enable tsf
W (2127) wifi:Haven't to connect to a suitable AP now!
I (2127) chip[DL]: Attempting to connect WiFi station interface
I (2147) chip[DL]: WiFi station state change: NotConnected -> Connecting
I (2147) chip[DL]: Done driving station state, nothing else to do...
I (2157) chip[ZCL]: Using ZAP configuration...
I (2167) chip[SVR]: Retrieved from server storage: a/1/8/0
I (2187) chip[ZCL]: Initiating Admin Commissioning cluster.
I (2187) chip[ZCL]: Door Lock server initialized
I (2187) chip[ZCL]: OpCreds: Initiating OpCreds cluster by writing fabrics list from fabric table.
I (2197) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0003', EndPoint ID: '0x00', Attribute ID: '0x0001'
I (2207) app-devicecallbacks: Current free heap: 92280
I (2217) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0004', EndPoint ID: '0x00', Attribute ID: '0x0000'
I (2227) app-devicecallbacks: Unhandled cluster ID: 4
I (2237) app-devicecallbacks: Current free heap: 92280
E (2237) chip[ZCL]: Trying to write invalid Calendar Type
E (2247) chip[ZCL]: Failed to write calendar type with error: 0x87
I (2247) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0003', EndPoint ID: '0x01', Attribute ID: '0x0001'
I (2267) app-devicecallbacks: Current free heap: 92280
I (2277) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0004', EndPoint ID: '0x01', Attribute ID: '0x0000'
I (2287) app-devicecallbacks: Unhandled cluster ID: 4
I (2287) app-devicecallbacks: Current free heap: 92280
I (2297) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0005', EndPoint ID: '0x01', Attribute ID: '0x0000'
I (2307) app-devicecallbacks: Unhandled cluster ID: 5
I (2317) app-devicecallbacks: Current free heap: 92280
I (2317) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0008', EndPoint ID: '0x01', Attribute ID: '0x0000'
I (2327) app-devicecallbacks: Current free heap: 92280
I (2337) chip[ZCL]: Window Covering Cluster init
I (2337) chip[ZCL]: Initialize PCC Server Cluster [EP:1]
I (2357) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0300', EndPoint ID: '0x01', Attribute ID: '0x0007'
I (2357) app-devicecallbacks: Unhandled cluster ID: 768
I (2367) app-devicecallbacks: Current free heap: 92280
I (2367) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0300', EndPoint ID: '0x01', Attribute ID: '0x0008'
I (2377) app-devicecallbacks: Unhandled cluster ID: 768
I (2387) app-devicecallbacks: Current free heap: 92280
I (2397) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0300', EndPoint ID: '0x01', Attribute ID: '0x4001'
I (2407) app-devicecallbacks: Unhandled cluster ID: 768
I (2417) app-devicecallbacks: Current free heap: 92280
I (2417) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0406', EndPoint ID: '0x01', Attribute ID: '0x0001'
I (2427) app-devicecallbacks: Unhandled cluster ID: 1030
I (2437) app-devicecallbacks: Current free heap: 92280
I (2447) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0406', EndPoint ID: '0x01', Attribute ID: '0x0002'
I (2457) app-devicecallbacks: Unhandled cluster ID: 1030
I (2457) app-devicecallbacks: Current free heap: 92280
I (2467) chip[ZCL]: WARNING: ATTRIBUTES ARE NOT BEING STORED IN FLASH!
I (2477) chip[ZCL]: DEVICE WILL NOT FUNCTION PROPERLY AFTER REBOOTING!!
I (2477) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0500', EndPoint ID: '0x01', Attribute ID: '0x0001'
I (2497) app-devicecallbacks: Unhandled cluster ID: 1280
I (2507) app-devicecallbacks: Current free heap: 92280
I (2507) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0500', EndPoint ID: '0x01', Attribute ID: '0x0002'
I (2517) app-devicecallbacks: Unhandled cluster ID: 1280
I (2517) app-devicecallbacks: Current free heap: 92280
I (2527) chip[ZCL]: Failed to send IAS Zone update. Err 0x70
I (2527) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0004', EndPoint ID: '0x02', Attribute ID: '0x0000'
I (2547) app-devicecallbacks: Unhandled cluster ID: 4
I (2557) app-devicecallbacks: Current free heap: 92280
I (2557) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0406', EndPoint ID: '0x02', Attribute ID: '0x0001'
I (2567) app-devicecallbacks: Unhandled cluster ID: 1030
I (2577) app-devicecallbacks: Current free heap: 92280
I (2577) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0406', EndPoint ID: '0x02', Attribute ID: '0x0002'
I (2597) app-devicecallbacks: Unhandled cluster ID: 1030
I (2607) app-devicecallbacks: Current free heap: 92280
I (2627) chip[DL]: NVS set: chip-counters/GlobalMCTR = 17000 (0x4268)
I (2637) chip[DL]: NVS set: chip-counters/global-eidc = 1114112 (0x110000)
I (2767) chip[DIS]: CHIP minimal mDNS started advertising.
I (2767) chip[DIS]: Failed to find a valid admin pairing. Node ID unknown
I (2767) chip[DIS]: Start dns-sd server - no current nodeId
I (2777) chip[DIS]: Advertise commission parameter vendorID=9050 productID=17729 discriminator=3840/15
I (2787) chip[DIS]: CHIP minimal mDNS configured as 'Commissionable node device'.
I (2797) chip[IN]: CASE Server enabling CASE session setups
I (2807) chip[SVR]: Adding Multicast groups
I (2807) chip[SVR]: Server Listening...
I (2807) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0402', EndPoint ID: '0x01', Attribute ID: '0x0000'
I (2817) app-devicecallbacks: Unhandled cluster ID: 1026
I (2837) app-devicecallbacks: Current free heap: 90252
I (2837) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0101', EndPoint ID: '0x01', Attribute ID: '0x0000'
I (2847) app-devicecallbacks: Unhandled cluster ID: 257
I (2847) app-devicecallbacks: Current free heap: 90132
I (2857) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0406', EndPoint ID: '0x01', Attribute ID: '0x0000'
I (2877) app-devicecallbacks: Unhandled cluster ID: 1030
I (2877) app-devicecallbacks: Current free heap: 89180
I (2887) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0045', EndPoint ID: '0x01', Attribute ID: '0x0000'
I (2897) app-devicecallbacks: Unhandled cluster ID: 69
I (2897) app-devicecallbacks: Current free heap: 89060
E (2897) chip[DL]: Long dispatch time: 741 ms, for event type 2
I (2917) app-devicecallbacks: Current free heap: 89060
I (2917) chip[DL]: WIFI_EVENT_STA_START
W (2927) wifi:Haven't to connect to a suitable AP now!
I (2927) chip[DL]: Attempting to connect WiFi station interface
E (2937) wifi:sta is connecting, return error
E (2937) chip[DL]: esp_wifi_connect() failed: ESP_ERR_WIFI_CONN
I (2937) app-devicecallbacks: Current free heap: 89060
I (2957) chip[DL]: Configuring CHIPoBLE advertising (interval 25 ms, connectable, device name MATTER-3840)
I (2957) chip[DL]: Device already advertising, stop active advertisement and restart
I (2967) NimBLE: GAP procedure initiated: stop advertising.
I (2987) NimBLE: GAP procedure initiated: advertise;
I (2987) NimBLE: disc_mode=2
I (2987) NimBLE: adv_channel_map=0 own_addr_type=2 adv_filter_policy=0 adv_itvl_min=40 adv_itvl_max=40
I (2997) NimBLE:
I (5287) chip[DL]: WIFI_EVENT_STA_DISCONNECTED
I (5287) chip[DL]: WiFi station state change: Connecting -> Connecting_Failed
W (5287) wifi:Haven't to connect to a suitable AP now!
I (5297) chip[DL]: WiFi station state change: Connecting_Failed -> NotConnected
I (5297) chip[DL]: Next WiFi station reconnect in 5000 ms
I (5307) chip[DL]: Done driving station state, nothing else to do...
I (5317) app-devicecallbacks: Current free heap: 89092
W (10307) wifi:Haven't to connect to a suitable AP now!
I (10317) chip[DL]: Attempting to connect WiFi station interface
I (10317) chip[DL]: WiFi station state change: NotConnected -> Connecting
I (10327) chip[DL]: Done driving station state, nothing else to do...
I (10957) chip[DL]: BLE GAP connection established (con 0)
I (10957) chip[DL]: CHIPoBLE advertising stopped
I (10957) app-devicecallbacks: Current free heap: 89068
I (13457) chip[DL]: WIFI_EVENT_STA_DISCONNECTED
I (13457) chip[DL]: WiFi station state change: Connecting -> Connecting_Failed
W (13457) wifi:Haven't to connect to a suitable AP now!
I (13467) chip[DL]: WiFi station state change: Connecting_Failed -> NotConnected
I (13467) chip[DL]: Next WiFi station reconnect in 5000 ms
I (13477) chip[DL]: Done driving station state, nothing else to do...
I (13487) app-devicecallbacks: Current free heap: 89092
It seems that the BLE connection is established, but the service discovery fails.
About this issue
- Original URL
- State: closed
- Created 2 years ago
- Comments: 20 (11 by maintainers)
So, I can confirm that pairing with the Linux python controller (Debian 11) works fine. So this should be Darwin related.
Am I the only one experiencing this error? No one else is using a Mac for development?