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.45k stars 1.99k forks source link

Android app failed to commission EFR32 Light App(CHIP over Thread device) #8502

Closed leasual closed 3 years ago

leasual commented 3 years ago

Use CHIP-TOOl for android app, failed to connect EFR32 Light APP, but use iOS is success and i can on off the device light. please help.

@jepenven-silabs @jmartinez-silabs Android Log:

2021-07-20 14:06:52.955 16322-16322/com.se.chip.chiptool D/ViewRootImpl@30f425a[AddDeviceActivity]: ViewPostIme pointer 0
2021-07-20 14:06:52.975 16322-16322/com.se.chip.chiptool D/ViewRootImpl@30f425a[AddDeviceActivity]: ViewPostIme pointer 1
2021-07-20 14:06:53.040 16322-16322/com.se.chip.chiptool W/ActivityThread: handleWindowVisibility: no activity for token android.os.BinderProxy@11e0757
2021-07-20 14:06:53.103 16322-16322/com.se.chip.chiptool I/MultiWindowDecorSupport: updateCaptionType >> DecorView@f295699[], isFloating: false, isApplication: true, hasWindowDecorCaption: false, hasWindowControllerCallback: true
2021-07-20 14:06:53.104 16322-16322/com.se.chip.chiptool D/MultiWindowDecorSupport: setCaptionType = 0, DecorView = DecorView@f295699[]
2021-07-20 14:06:53.118 16322-16322/com.se.chip.chiptool D/KeyValueStoreManager: Key 'ipAddress' not found in shared preferences
2021-07-20 14:06:53.119 16322-16322/com.se.chip.chiptool D/KeyValueStoreManager: Key 'port' not found in shared preferences
2021-07-20 14:06:53.119 16322-16322/com.se.chip.chiptool D/PairingViewModel: networkType= 1
2021-07-20 14:06:53.126 16322-16322/com.se.chip.chiptool D/CTL: newDeviceController() called
2021-07-20 14:06:53.129 16322-16322/com.se.chip.chiptool D/TOO: KVS: Getting key ExampleOpCredsCAKey
2021-07-20 14:06:53.131 16322-16322/com.se.chip.chiptool D/TOO: KVS: Getting key ExampleOpCredsICAKey
2021-07-20 14:06:53.132 16322-16322/com.se.chip.chiptool D/IN: TransportMgr initialized
2021-07-20 14:06:53.132 16322-16322/com.se.chip.chiptool D/DIS: Init admin pairing table with server storage
2021-07-20 14:06:53.132 16322-16322/com.se.chip.chiptool D/TOO: KVS: Getting key CHIPAdmin0
2021-07-20 14:06:53.132 16322-16322/com.se.chip.chiptool D/IN: Loading certs from KVS
2021-07-20 14:06:53.132 16322-16322/com.se.chip.chiptool D/IN: local node id is 0x000000000001B669
2021-07-20 14:06:53.132 16322-16322/com.se.chip.chiptool D/ZCL: Using ZAP configuration...
2021-07-20 14:06:53.134 16322-16322/com.se.chip.chiptool D/ZCL: deactivate report event
2021-07-20 14:06:53.134 16322-16322/com.se.chip.chiptool D/CTL: Getting operational keys
2021-07-20 14:06:53.134 16322-16322/com.se.chip.chiptool D/CTL: Generating credentials
2021-07-20 14:06:53.134 16322-16322/com.se.chip.chiptool D/CTL: Loaded credentials successfully
2021-07-20 14:06:53.134 16322-16322/com.se.chip.chiptool D/TOO: KVS: Getting key StartKeyID
2021-07-20 14:06:53.136 16322-16322/com.se.chip.chiptool D/PairingViewModel: get deviceInfo= CHIPDeviceInfo(version=0, vendorId=9050, productId=21324, discriminator=3840, setupPinCode=73141520, optionalQrCodeInfoMap={}, discoveryCapabilities=[BLE])
2021-07-20 14:06:53.143 16322-16322/com.se.chip.chiptool D/BluetoothAdapter: STATE_ON
2021-07-20 14:06:53.150 16322-16322/com.se.chip.chiptool I/chip.BluetoothManager: Starting Bluetooth scan
2021-07-20 14:06:53.151 16322-16322/com.se.chip.chiptool D/BluetoothAdapter: STATE_ON
2021-07-20 14:06:53.153 16322-16322/com.se.chip.chiptool D/BluetoothAdapter: STATE_ON
2021-07-20 14:06:53.154 16322-16322/com.se.chip.chiptool D/BluetoothAdapter: BLE support array set: 010011
2021-07-20 14:06:53.154 16322-16322/com.se.chip.chiptool D/BluetoothLeScanner: Start Scan with callback
2021-07-20 14:06:53.157 16322-16340/com.se.chip.chiptool D/BluetoothLeScanner: onScannerRegistered() - status=0 scannerId=11 mScannerId=0
2021-07-20 14:06:53.185 16322-16322/com.se.chip.chiptool D/ViewRootImpl@5ed5c2f[PairingActivity]: setView = com.android.internal.policy.DecorView@f295699 TM=true MM=false
2021-07-20 14:06:53.187 16322-16322/com.se.chip.chiptool D/ViewRootImpl@30f425a[AddDeviceActivity]: MSG_WINDOW_FOCUS_CHANGED 0 1
2021-07-20 14:06:53.187 16322-16322/com.se.chip.chiptool D/InputMethodManager: prepareNavigationBarInfo() DecorView@78f9a11[AddDeviceActivity]
2021-07-20 14:06:53.187 16322-16322/com.se.chip.chiptool D/InputMethodManager: getNavigationBarColor() -855310
2021-07-20 14:06:53.207 16322-16473/com.se.chip.chiptool W/LOTTIE: Animation contains merge paths. Merge paths are only supported on KitKat+ and must be manually enabled by calling enableMergePathsForKitKatAndAbove().
2021-07-20 14:06:53.222 16322-16322/com.se.chip.chiptool D/ViewRootImpl@5ed5c2f[PairingActivity]: Relayout returned: old=(0,0,1080,2340) new=(0,0,1080,2340) req=(1080,2340)0 dur=14 res=0x7 s={true 491296743424} ch=true
2021-07-20 14:06:53.222 16322-16359/com.se.chip.chiptool D/OpenGLRenderer: createReliableSurface : 0x72d39d9b80, 0x7263916000
2021-07-20 14:06:53.224 16322-16359/com.se.chip.chiptool D/mali_winsys: EGLint new_window_surface(egl_winsys_display *, void *, EGLSurface, EGLConfig, egl_winsys_surface **, EGLBoolean) returns 0x3000
2021-07-20 14:06:53.258 16322-16322/com.se.chip.chiptool D/ViewRootImpl@5ed5c2f[PairingActivity]: MSG_WINDOW_FOCUS_CHANGED 1 1
2021-07-20 14:06:53.258 16322-16322/com.se.chip.chiptool D/InputMethodManager: prepareNavigationBarInfo() DecorView@f295699[PairingActivity]
2021-07-20 14:06:53.258 16322-16322/com.se.chip.chiptool D/InputMethodManager: getNavigationBarColor() -855310
2021-07-20 14:06:53.260 16322-16322/com.se.chip.chiptool D/InputMethodManager: prepareNavigationBarInfo() DecorView@f295699[PairingActivity]
2021-07-20 14:06:53.260 16322-16322/com.se.chip.chiptool D/InputMethodManager: getNavigationBarColor() -855310
2021-07-20 14:06:53.260 16322-16322/com.se.chip.chiptool V/InputMethodManager: Starting input: tba=com.se.chip.chiptool ic=null mNaviBarColor -855310 mIsGetNaviBarColorSuccess true , NavVisible : true , NavTrans : false
2021-07-20 14:06:53.260 16322-16322/com.se.chip.chiptool D/InputMethodManager: startInputInner - Id : 0
2021-07-20 14:06:53.260 16322-16322/com.se.chip.chiptool I/InputMethodManager: startInputInner - mService.startInputOrWindowGainedFocus
2021-07-20 14:06:53.276 16322-16322/com.se.chip.chiptool D/InputTransport: Input channel destroyed: 'ClientS', fd=87
2021-07-20 14:06:53.278 16322-16322/com.se.chip.chiptool D/ViewRootImpl@5ed5c2f[PairingActivity]: MSG_RESIZED: frame=(0,0,1080,2340) ci=(0,83,0,126) vi=(0,83,0,126) or=1
2021-07-20 14:06:53.402 16322-16322/com.se.chip.chiptool W/LOTTIE: Animation contains merge paths but they are disabled.
2021-07-20 14:06:53.501 16322-16322/com.se.chip.chiptool I/chip.BluetoothManager: Bluetooth Device Scanned Addr: 46:80:02:80:33:E6, Name EFR32_LIGHT
2021-07-20 14:06:53.507 16322-16322/com.se.chip.chiptool D/BluetoothAdapter: STATE_ON
2021-07-20 14:06:53.507 16322-16322/com.se.chip.chiptool D/BluetoothLeScanner: Stop Scan with callback
2021-07-20 14:06:53.514 16322-16322/com.se.chip.chiptool D/PairingViewModel: get deviceInfo= 46:80:02:80:33:E6
2021-07-20 14:06:53.515 16322-16322/com.se.chip.chiptool I/chip.BluetoothManager: Connecting
2021-07-20 14:06:53.516 16322-16322/com.se.chip.chiptool D/BluetoothAdapter: STATE_ON
2021-07-20 14:06:53.519 16322-16322/com.se.chip.chiptool D/BluetoothGatt: connect() - device: 46:80:02:80:33:E6, auto: false
2021-07-20 14:06:53.519 16322-16322/com.se.chip.chiptool D/BluetoothAdapter: isSecureModeEnabled
2021-07-20 14:06:53.521 16322-16322/com.se.chip.chiptool D/BluetoothGatt: registerApp()
2021-07-20 14:06:53.521 16322-16322/com.se.chip.chiptool D/BluetoothGatt: registerApp() - UUID=b1c4e6e0-52f0-4fd0-9646-a33d17312b30
2021-07-20 14:06:53.528 16322-16340/com.se.chip.chiptool D/BluetoothGatt: onClientRegistered() - status=0 clientIf=11
2021-07-20 14:06:53.603 16322-16359/com.se.chip.chiptool W/libEGL: EGLNativeWindowType 0x72d39dc610 disconnect failed
2021-07-20 14:06:53.611 16322-16322/com.se.chip.chiptool D/ViewRootImpl@30f425a[AddDeviceActivity]: Relayout returned: old=(0,0,1080,2340) new=(0,0,1080,2340) req=(1080,2340)8 dur=8 res=0x5 s={false 0} ch=true
2021-07-20 14:06:53.617 16322-16322/com.se.chip.chiptool D/ViewRootImpl@30f425a[AddDeviceActivity]: stopped(true) old=false
2021-07-20 14:06:53.629 16322-16322/com.se.chip.chiptool D/ViewRootImpl@30f425a[AddDeviceActivity]: dispatchDetachedFromWindow
2021-07-20 14:06:53.633 16322-16322/com.se.chip.chiptool D/InputTransport: Input channel destroyed: 'a137032', fd=83
2021-07-20 14:06:53.822 16322-16340/com.se.chip.chiptool D/BluetoothGatt: onClientConnectionState() - status=0 clientIf=11 device=46:80:02:80:33:E6
2021-07-20 14:06:53.825 16322-16340/com.se.chip.chiptool I/chip.BluetoothManager|onConnectionStateChange: Discovering Services...
2021-07-20 14:06:53.825 16322-16340/com.se.chip.chiptool D/BluetoothGatt: discoverServices() - device: 46:80:02:80:33:E6
2021-07-20 14:06:54.158 16322-16340/com.se.chip.chiptool D/BluetoothGatt: onConnectionUpdated() - Device=46:80:02:80:33:E6 interval=6 latency=0 timeout=500 status=0
2021-07-20 14:06:54.495 16322-16340/com.se.chip.chiptool D/BluetoothGatt: onSearchComplete() = Device=46:80:02:80:33:E6 Status=0
2021-07-20 14:06:54.496 16322-16340/com.se.chip.chiptool I/chip.BluetoothManager|onServicesDiscovered: Services Discovered
2021-07-20 14:06:54.498 16322-16340/com.se.chip.chiptool D/BluetoothGatt: configureMTU() - device: 46:80:02:80:33:E6 mtu: 131
2021-07-20 14:06:54.529 16322-16340/com.se.chip.chiptool D/BluetoothGatt: onConnectionUpdated() - Device=46:80:02:80:33:E6 interval=36 latency=0 timeout=500 status=0
2021-07-20 14:06:54.534 16322-16346/com.se.chip.chiptool D/BluetoothGatt: onConfigureMTU() - Device=46:80:02:80:33:E6 mtu=131 status=0
2021-07-20 14:06:54.535 16322-16346/com.se.chip.chiptool D/chip.BluetoothManager: MTU changed: connecting to CHIP device
2021-07-20 14:06:54.554 16322-16322/com.se.chip.chiptool D/PairingViewModel: get deviceInfo= android.bluetooth.BluetoothGatt@44432be
2021-07-20 14:06:54.559 16322-16322/com.se.chip.chiptool D/PairingViewModel: get pairing
2021-07-20 14:06:54.570 16322-16515/com.se.chip.chiptool D/ChipDeviceController: Bluetooth connection added with ID: 1
2021-07-20 14:06:54.570 16322-16515/com.se.chip.chiptool D/ChipDeviceController: Pairing device with ID: 8
2021-07-20 14:06:54.571 16322-16515/com.se.chip.chiptool D/CTL: pairDevice() called with device ID, connection object, and pincode
2021-07-20 14:06:54.571 16322-16515/com.se.chip.chiptool D/TOO: KVS: Getting key ListPairedDevices0
2021-07-20 14:06:54.571 16322-16515/com.se.chip.chiptool D/KeyValueStoreManager: Key 'ListPairedDevices0' not found in shared preferences
2021-07-20 14:06:54.575 16322-16515/com.se.chip.chiptool D/IN: BleConnectionComplete: endPoint 0x72c7be4750
2021-07-20 14:06:54.575 16322-16515/com.se.chip.chiptool D/CTL: Received GetMTU
2021-07-20 14:06:54.575 16322-16515/com.se.chip.chiptool D/CTL: Calling Java onGetMTU
2021-07-20 14:06:54.576 16322-16515/com.se.chip.chiptool D/AndroidChipStack: Android Manufacturer: (samsung)
2021-07-20 14:06:54.576 16322-16515/com.se.chip.chiptool D/AndroidChipStack: Android Model: (SM-A305F)
2021-07-20 14:06:54.577 16322-16515/com.se.chip.chiptool D/CTL: Received SendCharacteristic
2021-07-20 14:06:54.577 16322-16515/com.se.chip.chiptool D/CTL: Calling Java SendCharacteristic
2021-07-20 14:06:54.579 16322-16515/com.se.chip.chiptool D/SC: Assigned local session key ID 5
2021-07-20 14:06:54.580 16322-16515/com.se.chip.chiptool D/IN: Message appended to BLE send queue
2021-07-20 14:06:54.581 16322-16515/com.se.chip.chiptool D/SC: Sent PBKDF param request
2021-07-20 14:06:54.581 16322-16515/com.se.chip.chiptool D/TOO: KVS: Setting key StartKeyID
2021-07-20 14:06:54.659 16322-16346/com.se.chip.chiptool D/chip.BluetoothManager: EFR32_LIGHT.onCharacteristicWrite: 18ee2ef5-263d-4559-959f-4f9c429f9d11 -> 0
2021-07-20 14:06:54.659 16322-16346/com.se.chip.chiptool D/CTL: Received SubscribeCharacteristic
2021-07-20 14:06:54.659 16322-16346/com.se.chip.chiptool D/CTL: Calling Java SubscribeCharacteristic
2021-07-20 14:06:54.660 16322-16346/com.se.chip.chiptool D/BluetoothGatt: setCharacteristicNotification() - uuid: 18ee2ef5-263d-4559-959f-4f9c429f9d12 enable: true
2021-07-20 14:06:54.750 16322-16346/com.se.chip.chiptool D/chip.BluetoothManager: EFR32_LIGHT.onDescriptorWrite: 00002902-0000-1000-8000-00805f9b34fb -> 0
2021-07-20 14:06:54.751 16322-16346/com.se.chip.chiptool D/BLE: subscribe complete, ep = 0x72c7be4750
2021-07-20 14:06:55.795 16322-16335/com.se.chip.chiptool I/e.chip.chiptoo: Background concurrent copying GC freed 38281(2127KB) AllocSpace objects, 4(208KB) LOS objects, 49% free, 2972KB/5944KB, paused 251us total 121.292ms
2021-07-20 14:06:58.037 16322-16328/com.se.chip.chiptool I/e.chip.chiptoo: Compiler allocated 4266KB to compile void android.view.ViewRootImpl.performTraversals()
2021-07-20 14:07:02.769 16322-16322/com.se.chip.chiptool D/ViewRootImpl@5ed5c2f[PairingActivity]: MSG_WINDOW_FOCUS_CHANGED 0 1
2021-07-20 14:07:02.769 16322-16322/com.se.chip.chiptool D/InputMethodManager: prepareNavigationBarInfo() DecorView@f295699[PairingActivity]
2021-07-20 14:07:02.770 16322-16322/com.se.chip.chiptool D/InputMethodManager: getNavigationBarColor() -855310
2021-07-20 14:07:05.999 16322-16322/com.se.chip.chiptool D/ViewRootImpl@5ed5c2f[PairingActivity]: stopped(false) old=false
2021-07-20 14:07:06.080 16322-16322/com.se.chip.chiptool D/ViewRootImpl@5ed5c2f[PairingActivity]: MSG_WINDOW_FOCUS_CHANGED 1 1
2021-07-20 14:07:06.080 16322-16322/com.se.chip.chiptool D/InputMethodManager: prepareNavigationBarInfo() DecorView@f295699[PairingActivity]
2021-07-20 14:07:06.080 16322-16322/com.se.chip.chiptool D/InputMethodManager: getNavigationBarColor() -855310
2021-07-20 14:07:09.578 16322-16358/com.se.chip.chiptool E/BLE: connect handshake timed out, closing ep 0x72c7be4750
2021-07-20 14:07:09.578 16322-16358/com.se.chip.chiptool E/IN: Failed to establish BLE connection: Ble Error 0x00000415: Connect handshake timed out
2021-07-20 14:07:09.578 16322-16358/com.se.chip.chiptool D/IN: Clearing BLE pending packets.
2021-07-20 14:07:09.578 16322-16358/com.se.chip.chiptool D/CTL: Received UnsubscribeCharacteristic
2021-07-20 14:07:09.579 16322-16358/com.se.chip.chiptool D/CTL: Calling Java UnsubscribeCharacteristic
2021-07-20 14:07:09.579 16322-16358/com.se.chip.chiptool D/BluetoothGatt: setCharacteristicNotification() - uuid: 18ee2ef5-263d-4559-959f-4f9c429f9d12 enable: false
2021-07-20 14:07:09.645 16322-16346/com.se.chip.chiptool D/chip.BluetoothManager: EFR32_LIGHT.onDescriptorWrite: 00002902-0000-1000-8000-00805f9b34fb -> 0
2021-07-20 14:07:09.646 16322-16346/com.se.chip.chiptool D/BLE: Auto-closing end point's BLE connection.
2021-07-20 14:07:09.646 16322-16346/com.se.chip.chiptool D/CTL: Received CloseConnection
2021-07-20 14:07:09.646 16322-16346/com.se.chip.chiptool D/CTL: Calling Java CloseConnection
2021-07-20 14:07:09.646 16322-16346/com.se.chip.chiptool D/ChipDeviceController: Closing GATT and removing connection for 1
2021-07-20 14:07:09.646 16322-16346/com.se.chip.chiptool D/BluetoothGatt: close()
2021-07-20 14:07:09.671 16322-16346/com.se.chip.chiptool D/BluetoothGatt: unregisterApp() - mClientIf=11
2021-07-20 14:07:09.683 16322-16346/com.se.chip.chiptool D/ChipDeviceController: Calling onCloseBleComplete()
2021-07-20 14:07:09.683 16322-16346/com.se.chip.chiptool D/PairingViewModel: onCloseBleComplete
2021-07-20 14:07:11.953 16322-16322/com.se.chip.chiptool D/ViewRootImpl@5ed5c2f[PairingActivity]: MSG_WINDOW_FOCUS_CHANGED 0 1
2021-07-20 14:07:11.954 16322-16322/com.se.chip.chiptool D/InputMethodManager: prepareNavigationBarInfo() DecorView@f295699[PairingActivity]
2021-07-20 14:07:11.954 16322-16322/com.se.chip.chiptool D/InputMethodManager: getNavigationBarColor() -855310
2021-07-20 14:07:12.121 16322-16322/com.se.chip.chiptool D/InputTransport: Input channel destroyed: 'ClientS', fd=88
2021-07-20 14:07:12.456 16322-16322/com.se.chip.chiptool D/ViewRootImpl@5ed5c2f[PairingActivity]: stopped(true) old=false
2021-07-20 14:07:12.579 16322-16359/com.se.chip.chiptool W/libEGL: EGLNativeWindowType 0x72d39d9b90 disconnect failed
2021-07-20 14:07:12.607 16322-16322/com.se.chip.chiptool D/ViewRootImpl@5ed5c2f[PairingActivity]: Relayout returned: old=(0,0,1080,2340) new=(0,0,1080,2340) req=(1080,2340)8 dur=26 res=0x5 s={false 0} ch=false

iOS log:

2021-07-20 14:02:26.668952+0800 CHIPTool[9001:3797832] Found an existing keypair in the keychain
2021-07-20 14:02:26.669479+0800 CHIPTool[9001:3797832] Deserializing the key
2021-07-20 14:02:26.671185+0800 CHIPTool[9001:3797832] CHIPOperationalCredentialsDelegate::init returning 0
2021-07-20 14:02:26.671259+0800 CHIPTool[9001:3797832] PersistentStorageDelegate Sync Get Value for Key: com.zigbee.chip.commissioner.device_id
2021-07-20 14:02:26.671399+0800 CHIPTool[9001:3797832] CHIPPersistentStorageDelegate Get Value for Key: com.zigbee.chip.commissioner.device_id, value FybW89B3jTk=
2021-07-20 14:02:26.671534+0800 CHIPTool[9001:3797832] Found 398d77d0f3d62617 node ID for the controller
2021-07-20 14:02:26.673616+0800 CHIPTool[9001:3797832] [all] 🟢 [1626760946673] [9001:3797832] CHIP: [DL] _Init
2021-07-20 14:02:26.674102+0800 CHIPTool[9001:3797832] [all] 🟢 [1626760946674] [9001:3797832] CHIP: [IN] TransportMgr initialized
2021-07-20 14:02:26.674115+0800 CHIPTool[9001:3797832] [all] 🟢 [1626760946674] [9001:3797832] CHIP: [DIS] Init admin pairing table with server storage
2021-07-20 14:02:26.674131+0800 CHIPTool[9001:3797832] PersistentStorageDelegate Sync Get Value for Key: CHIPAdmin0
2021-07-20 14:02:26.674185+0800 CHIPTool[9001:3797832] CHIPPersistentStorageDelegate Get Value for Key: CHIPAdmin0, value AAAAAAAAAAAXJtbz0HeNOQoAAAAAAAAAAADvAAAA/AAEN6nm8ByeTroJk5XWYVOTyH8cZEPgZ2RMfk113eUvg5UCSmZnKPF3vtMft898iODsIwrLok65nlaxD3+SoDr+h3WgQ328/AXOfibG8LTn+MCseKj7PxpZlzrV6hPHIc92AAAAAAAAAGEAAAAAAAAAFTABAQAkAgE3AyUU0gQkFQAYJgRMTogoJgXMgWkqNwYlFNIEJBUAGCQHASQIATAJQQSrAxUlfacktgftSP+v7LdHh2YGyJEr9nVhqRdCHzCTBUnzAqwRfKzYa9tFP55oiipok+jiYtymcGL8TMcM/nRrNwo1ASkBGCQCYDAEFEw8zvhXHRZtpgiyNOZopuI+vbDcMAUUTDzO+FcdFm2mCLI05mim4j69sNwYMAtAynpXWPGDtQar12eTuveb+23L1pr0WU2hTVsYWwp1lqkvrvMxYPz+lQieygBThyjDlLl3wP9XX2mLAeQrTRWDuRgAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAVMAEBASQCATcDJRTSBCQVABgmBExOiCgmBcyBaSo3BicRFybW89B3jTkkFQAYJAcBJAgBMAlBBDep5vAcnk66CZOV1mFTk8h/HGRD4GdkTH5Ndd3lL4OVAkpmZyjxd77TH7fPfIjg7CMKy6JOuZ5WsQ9/kqA6/oc3CjUBKAEYJAIBNgMEAgQBGDAEFAkqA4Wa+y/SUrjQ8Cn5Q89bT7wjMAUUTDzO+FcdFm2mCLI05mim4j69sNwYMAtAVGj/aE/9lOUAE2/twSKkWVCXuGd/V32K+5PHff14nY3SfIuQ7tI1suItvwLPn+S2hld38/x34ZCgylfOLDDu3hgAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA==
2021-07-20 14:02:26.674590+0800 CHIPTool[9001:3797832] [all] 🔵 [1626760946674] [9001:3797832] CHIP: [IN] Loading certs from KVS
2021-07-20 14:02:26.674674+0800 CHIPTool[9001:3797832] [all] 🔵 [1626760946674] [9001:3797832] CHIP: [IN] local node id is 0x398D77D0F3D62617
2021-07-20 14:02:26.674868+0800 CHIPTool[9001:3797832] [all] 🔵 [1626760946674] [9001:3797832] CHIP: [ZCL] Using ZAP configuration...
2021-07-20 14:02:26.675080+0800 CHIPTool[9001:3797832] [all] 🔵 [1626760946675] [9001:3797832] CHIP: [ZCL] deactivate report event
2021-07-20 14:02:26.675151+0800 CHIPTool[9001:3797832] [all] 🔵 [1626760946675] [9001:3797832] CHIP: [CTL] Getting operational keys
2021-07-20 14:02:26.675159+0800 CHIPTool[9001:3797832] [all] 🔵 [1626760946675] [9001:3797832] CHIP: [CTL] Generating credentials
2021-07-20 14:02:26.675677+0800 CHIPTool[9001:3797832] [all] 🔵 [1626760946675] [9001:3797832] CHIP: [CTL] Loaded credentials successfully
2021-07-20 14:02:26.675700+0800 CHIPTool[9001:3797832] PersistentStorageDelegate Sync Get Value for Key: StartKeyID
2021-07-20 14:02:26.675764+0800 CHIPTool[9001:3797832] CHIPPersistentStorageDelegate Get Value for Key: StartKeyID, value IAA=
2021-07-20 14:02:26.675817+0800 CHIPTool[9001:3797832] PersistentStorageDelegate Sync Get Value for Key: ListPairedDevices0
2021-07-20 14:02:26.675851+0800 CHIPTool[9001:3797832] CHIPPersistentStorageDelegate Get Value for Key: ListPairedDevices0, value
2021-07-20 14:02:31.201744+0800 CHIPTool[9001:3797832] Payload vendorID 9050
2021-07-20 14:02:31.202064+0800 CHIPTool[9001:3797832] Rendezvous BLE
2021-07-20 14:02:31.203514+0800 CHIPTool[9001:3797832] [all] 🔵 [1626760951203] [9001:3797832] CHIP: [BLE] NewConnection
2021-07-20 14:02:31.208289+0800 CHIPTool[9001:3797832] [all] 🟢 [1626760951208] [9001:3797832] CHIP: [SC] Assigned local session key ID 33
2021-07-20 14:02:31.208398+0800 CHIPTool[9001:3797832] [all] 🟢 [1626760951208] [9001:3797832] CHIP: [IN] Message appended to BLE send queue
2021-07-20 14:02:31.208422+0800 CHIPTool[9001:3797832] [all] 🟢 [1626760951208] [9001:3797832] CHIP: [SC] Sent PBKDF param request
2021-07-20 14:02:31.208464+0800 CHIPTool[9001:3797832] PersistentStorageDelegate Set Key StartKeyID
2021-07-20 14:02:31.224081+0800 CHIPTool[9001:3798036] [all] 🟢 [1626760951224] [9001:3798036] CHIP: [BLE] CBManagerState: ON
2021-07-20 14:02:46.971741+0800 CHIPTool[9001:3798036] [all] 🔵 [1626760966971] [9001:3798036] CHIP: [BLE] Connecting to device with discriminator: 3840
2021-07-20 14:02:48.697807+0800 CHIPTool[9001:3798195] [all] 🟢 [1626760968697] [9001:3798195] CHIP: [IN] BleConnectionComplete: endPoint 0x104e6d890
2021-07-20 14:02:48.937199+0800 CHIPTool[9001:3798036] [all] 🔵 [1626760968937] [9001:3798036] CHIP: [BLE] subscribe complete, ep = 0x104e6d890
2021-07-20 14:02:48.937370+0800 CHIPTool[9001:3798195] [all] 🔵 [1626760968937] [9001:3798195] CHIP: [BLE] peripheral chose BTP version 3; central expected between 2 and 3
2021-07-20 14:02:48.937447+0800 CHIPTool[9001:3798195] [all] 🔵 [1626760968937] [9001:3798195] CHIP: [BLE] using BTP fragment sizes rx 20 / tx 128.
2021-07-20 14:02:48.937473+0800 CHIPTool[9001:3798195] [all] 🔵 [1626760968937] [9001:3798195] CHIP: [BLE] local and remote recv window size = 3
2021-07-20 14:02:48.938006+0800 CHIPTool[9001:3798195] [all] 🟢 [1626760968937] [9001:3798195] CHIP: [IN] BLE EndPoint 0x104e6d890 Connection Complete
2021-07-20 14:02:49.358902+0800 CHIPTool[9001:3798036] [all] 🔵 [1626760969358] [9001:3798036] CHIP: [EM] Received message of type 33 and protocolId 0 on exchange 44249
2021-07-20 14:02:49.358999+0800 CHIPTool[9001:3798036] [all] 🟢 [1626760969358] [9001:3798036] CHIP: [SC] Received PBKDF param response
2021-07-20 14:02:49.390005+0800 CHIPTool[9001:3798036] [all] 🟢 [1626760969390] [9001:3798036] CHIP: [SC] Sent spake2p msg1
2021-07-20 14:02:50.197347+0800 CHIPTool[9001:3798034] [all] 🔵 [1626760970197] [9001:3798034] CHIP: [EM] Received message of type 35 and protocolId 0 on exchange 44249
2021-07-20 14:02:50.197451+0800 CHIPTool[9001:3798034] [all] 🟢 [1626760970197] [9001:3798034] CHIP: [SC] Received spake2p msg2
2021-07-20 14:02:50.197478+0800 CHIPTool[9001:3798034] [all] 🟢 [1626760970197] [9001:3798034] CHIP: [SC] Peer assigned session key ID 0
2021-07-20 14:02:50.245863+0800 CHIPTool[9001:3798034] [all] 🟢 [1626760970245] [9001:3798034] CHIP: [SC] Sent spake2p msg3
2021-07-20 14:02:50.245883+0800 CHIPTool[9001:3798034] [all] 🟢 [1626760970245] [9001:3798034] CHIP: [IN] New secure session created for device 0x000000000000000B, key 0!!
2021-07-20 14:02:50.245919+0800 CHIPTool[9001:3798034] [all] 🟢 [1626760970245] [9001:3798034] CHIP: [CTL] Remote device completed SPAKE2+ handshake
2021-07-20 14:02:50.245928+0800 CHIPTool[9001:3798034] [all] 🔵 [1626760970245] [9001:3798034] CHIP: [CTL] Sending root certificate to the device
2021-07-20 14:02:50.247397+0800 CHIPTool[9001:3798034] [all] 🟢 [1626760970247] [9001:3798034] CHIP: [DMG] ICR moving to [Initialize]
2021-07-20 14:02:50.247420+0800 CHIPTool[9001:3798034] [all] 🟢 [1626760970247] [9001:3798034] CHIP: [DMG] ICR moving to [AddCommand]
2021-07-20 14:02:50.247516+0800 CHIPTool[9001:3798034] [all] 🟢 [1626760970247] [9001:3798034] CHIP: [IN] Secure message was encrypted: Msg ID 0
2021-07-20 14:02:50.247528+0800 CHIPTool[9001:3798034] [all] 🔵 [1626760970247] [9001:3798034] CHIP: [IN] Encrypted message 0x16b741c08 from 0x398D77D0F3D62617 to 0x000000000000000B of type 8 and protocolId 5 on exchange 44250.
2021-07-20 14:02:50.247535+0800 CHIPTool[9001:3798034] [all] 🔵 [1626760970247] [9001:3798034] CHIP: [IN] Sending msg 0x16b741c08 to 0x000000000000000B at utc time: 1626760970247 msec
2021-07-20 14:02:50.247544+0800 CHIPTool[9001:3798034] [all] 🔵 [1626760970247] [9001:3798034] CHIP: [IN] Sending secure msg on generic transport
2021-07-20 14:02:50.247550+0800 CHIPTool[9001:3798034] [all] 🔵 [1626760970247] [9001:3798034] CHIP: [IN] Secure msg send status No Error
2021-07-20 14:02:50.247555+0800 CHIPTool[9001:3798034] [all] 🟢 [1626760970247] [9001:3798034] CHIP: [DMG] ICR moving to [   Sending]
2021-07-20 14:02:50.247559+0800 CHIPTool[9001:3798034] [all] 🔵 [1626760970247] [9001:3798034] CHIP: [CTL] Sent root certificate to the device
2021-07-20 14:02:51.097851+0800 CHIPTool[9001:3798036] [all] 🔵 [1626760971097] [9001:3798036] CHIP: [IN] Secure transport received message destined to fabric 0, node 0x398D77D0F3D62617. Key ID 33
2021-07-20 14:02:51.097993+0800 CHIPTool[9001:3798036] [all] 🔵 [1626760971097] [9001:3798036] CHIP: [IN] Setting fabricID B on admin.
2021-07-20 14:02:51.098092+0800 CHIPTool[9001:3798036] [all] 🔵 [1626760971098] [9001:3798036] CHIP: [IN] Since admin was modified, persisting changes to KVS
2021-07-20 14:02:51.098287+0800 CHIPTool[9001:3798036] PersistentStorageDelegate Set Key CHIPAdmin0
2021-07-20 14:02:51.100454+0800 CHIPTool[9001:3798036] [all] 🔵 [1626760971100] [9001:3798036] CHIP: [EM] Received message of type 9 and protocolId 5 on exchange 44250
2021-07-20 14:02:51.100579+0800 CHIPTool[9001:3798036] [all] 🔵 [1626760971100] [9001:3798036] CHIP: [ZCL] DefaultResponse:
2021-07-20 14:02:51.100608+0800 CHIPTool[9001:3798036] [all] 🔵 [1626760971100] [9001:3798036] CHIP: [ZCL]   Transaction: 0x104e6e900
2021-07-20 14:02:51.100629+0800 CHIPTool[9001:3798036] [all] 🔵 [1626760971100] [9001:3798036] CHIP: [ZCL]   status: EMBER_ZCL_STATUS_SUCCESS (0x00)
2021-07-20 14:02:51.100659+0800 CHIPTool[9001:3798036] [all] 🔵 [1626760971100] [9001:3798036] CHIP: [CTL] Device confirmed that it has received the root certificate
2021-07-20 14:02:51.100680+0800 CHIPTool[9001:3798036] [all] 🟢 [1626760971100] [9001:3798036] CHIP: [CTL] Sending OpCSR request to 0x10c224028 device
2021-07-20 14:02:51.100715+0800 CHIPTool[9001:3798036] [all] 🟢 [1626760971100] [9001:3798036] CHIP: [DMG] ICR moving to [Initialize]
2021-07-20 14:02:51.100748+0800 CHIPTool[9001:3798036] [all] 🟢 [1626760971100] [9001:3798036] CHIP: [DMG] ICR moving to [AddCommand]
2021-07-20 14:02:51.100904+0800 CHIPTool[9001:3798036] [all] 🟢 [1626760971100] [9001:3798036] CHIP: [IN] Secure message was encrypted: Msg ID 1
2021-07-20 14:02:51.100954+0800 CHIPTool[9001:3798036] [all] 🔵 [1626760971100] [9001:3798036] CHIP: [IN] Encrypted message 0x16b8598c8 from 0x398D77D0F3D62617 to 0x000000000000000B of type 8 and protocolId 5 on exchange 44251.
2021-07-20 14:02:51.100985+0800 CHIPTool[9001:3798036] [all] 🔵 [1626760971100] [9001:3798036] CHIP: [IN] Sending msg 0x16b8598c8 to 0x000000000000000B at utc time: 1626760971100 msec
2021-07-20 14:02:51.101006+0800 CHIPTool[9001:3798036] [all] 🔵 [1626760971101] [9001:3798036] CHIP: [IN] Sending secure msg on generic transport
2021-07-20 14:02:51.101034+0800 CHIPTool[9001:3798036] [all] 🔵 [1626760971101] [9001:3798036] CHIP: [IN] Secure msg send status No Error
2021-07-20 14:02:51.101055+0800 CHIPTool[9001:3798036] [all] 🟢 [1626760971101] [9001:3798036] CHIP: [DMG] ICR moving to [   Sending]
2021-07-20 14:02:51.101074+0800 CHIPTool[9001:3798036] [all] 🟢 [1626760971101] [9001:3798036] CHIP: [CTL] Sent OpCSR request, waiting for the CSR
2021-07-20 14:02:51.101105+0800 CHIPTool[9001:3798036] [all] 🟢 [1626760971101] [9001:3798036] CHIP: [DMG] ICR moving to [Uninitiali]
2021-07-20 14:02:52.597224+0800 CHIPTool[9001:3798034] [all] 🔵 [1626760972597] [9001:3798034] CHIP: [IN] Secure transport received message destined to fabric 0, node 0x398D77D0F3D62617. Key ID 33
2021-07-20 14:02:52.597489+0800 CHIPTool[9001:3798034] [all] 🔵 [1626760972597] [9001:3798034] CHIP: [EM] Received message of type 9 and protocolId 5 on exchange 44251
2021-07-20 14:02:52.597607+0800 CHIPTool[9001:3798034] [all] 🟢 [1626760972597] [9001:3798034] CHIP: [ZCL] Received Cluster Command: Cluster=3e Command=5 Endpoint=0
2021-07-20 14:02:52.599274+0800 CHIPTool[9001:3798034] [all] 🔵 [1626760972599] [9001:3798034] CHIP: [ZCL] OpCSRResponse:
2021-07-20 14:02:52.599328+0800 CHIPTool[9001:3798034] [all] 🔵 [1626760972599] [9001:3798034] CHIP: [ZCL]   CSR: 204
2021-07-20 14:02:52.599353+0800 CHIPTool[9001:3798034] [all] 🔵 [1626760972599] [9001:3798034] CHIP: [ZCL]   CSRNonce: 32
2021-07-20 14:02:52.599374+0800 CHIPTool[9001:3798034] [all] 🔵 [1626760972599] [9001:3798034] CHIP: [ZCL]   VendorReserved1: 0
2021-07-20 14:02:52.599393+0800 CHIPTool[9001:3798034] [all] 🔵 [1626760972599] [9001:3798034] CHIP: [ZCL]   VendorReserved2: 0
2021-07-20 14:02:52.599412+0800 CHIPTool[9001:3798034] [all] 🔵 [1626760972599] [9001:3798034] CHIP: [ZCL]   VendorReserved3: 0
2021-07-20 14:02:52.599471+0800 CHIPTool[9001:3798034] [all] 🔵 [1626760972599] [9001:3798034] CHIP: [ZCL]   Signature: 0
2021-07-20 14:02:52.599506+0800 CHIPTool[9001:3798034] [all] 🔵 [1626760972599] [9001:3798034] CHIP: [CTL] Received certificate signing request from the device
2021-07-20 14:02:52.637441+0800 CHIPTool[9001:3798034] [all] 🔵 [1626760972637] [9001:3798034] CHIP: [CTL] Getting intermediate CA certificate from the issuer
2021-07-20 14:02:52.637456+0800 CHIPTool[9001:3798034] [all] 🔵 [1626760972637] [9001:3798034] CHIP: [CTL] GetIntermediateCACertificate returned be
2021-07-20 14:02:52.637462+0800 CHIPTool[9001:3798034] [all] 🔵 [1626760972637] [9001:3798034] CHIP: [CTL] Intermediate CA is not needed
2021-07-20 14:02:52.637508+0800 CHIPTool[9001:3798034] [all] 🔵 [1626760972637] [9001:3798034] CHIP: [CTL] Sending operational certificate to the device
2021-07-20 14:02:52.637519+0800 CHIPTool[9001:3798034] [all] 🟢 [1626760972637] [9001:3798034] CHIP: [DMG] ICR moving to [Initialize]
2021-07-20 14:02:52.637529+0800 CHIPTool[9001:3798034] [all] 🟢 [1626760972637] [9001:3798034] CHIP: [DMG] ICR moving to [AddCommand]
2021-07-20 14:02:52.637573+0800 CHIPTool[9001:3798034] [all] 🟢 [1626760972637] [9001:3798034] CHIP: [IN] Secure message was encrypted: Msg ID 2
2021-07-20 14:02:52.637585+0800 CHIPTool[9001:3798034] [all] 🔵 [1626760972637] [9001:3798034] CHIP: [IN] Encrypted message 0x16b7410b8 from 0x398D77D0F3D62617 to 0x000000000000000B of type 8 and protocolId 5 on exchange 44252.
2021-07-20 14:02:52.637594+0800 CHIPTool[9001:3798034] [all] 🔵 [1626760972637] [9001:3798034] CHIP: [IN] Sending msg 0x16b7410b8 to 0x000000000000000B at utc time: 1626760972637 msec
2021-07-20 14:02:52.637603+0800 CHIPTool[9001:3798034] [all] 🔵 [1626760972637] [9001:3798034] CHIP: [IN] Sending secure msg on generic transport
2021-07-20 14:02:52.637610+0800 CHIPTool[9001:3798034] [all] 🔵 [1626760972637] [9001:3798034] CHIP: [IN] Secure msg send status No Error
2021-07-20 14:02:52.637616+0800 CHIPTool[9001:3798034] [all] 🟢 [1626760972637] [9001:3798034] CHIP: [DMG] ICR moving to [   Sending]
2021-07-20 14:02:52.637622+0800 CHIPTool[9001:3798034] [all] 🔵 [1626760972637] [9001:3798034] CHIP: [CTL] Sent operational certificate to the device
2021-07-20 14:02:52.637637+0800 CHIPTool[9001:3798034] [all] 🟢 [1626760972637] [9001:3798034] CHIP: [DMG] ICR moving to [Uninitiali]
2021-07-20 14:02:53.167421+0800 CHIPTool[9001:3798036] [all] 🔵 [1626760973167] [9001:3798036] CHIP: [IN] Secure transport received message destined to fabric 0, node 0x398D77D0F3D62617. Key ID 33
2021-07-20 14:02:53.167550+0800 CHIPTool[9001:3798036] [all] 🔵 [1626760973167] [9001:3798036] CHIP: [EM] Received message of type 9 and protocolId 5 on exchange 44252
2021-07-20 14:02:53.167664+0800 CHIPTool[9001:3798036] [all] 🔵 [1626760973167] [9001:3798036] CHIP: [ZCL] DefaultResponse:
2021-07-20 14:02:53.167712+0800 CHIPTool[9001:3798036] [all] 🔵 [1626760973167] [9001:3798036] CHIP: [ZCL]   Transaction: 0x104e6e900
2021-07-20 14:02:53.167741+0800 CHIPTool[9001:3798036] [all] 🔵 [1626760973167] [9001:3798036] CHIP: [ZCL]   status: EMBER_ZCL_STATUS_SUCCESS (0x00)
2021-07-20 14:02:53.167772+0800 CHIPTool[9001:3798036] [all] 🔵 [1626760973167] [9001:3798036] CHIP: [CTL] Device confirmed that it has received the operational certificate
2021-07-20 14:02:53.167799+0800 CHIPTool[9001:3798036] [all] 🔵 [1626760973167] [9001:3798036] CHIP: [CTL] Operational credentials provisioned on device 0x10c224028
2021-07-20 14:02:53.167957+0800 CHIPTool[9001:3798036] PersistentStorageDelegate Set Key PairedDeviceb
2021-07-20 14:02:53.169989+0800 CHIPTool[9001:3798036] PersistentStorageDelegate Set Key ListPairedDevices0
2021-07-20 14:02:53.171533+0800 CHIPTool[9001:3798036] DevicePairingDelegate status updated: 0
2021-07-20 14:02:53.171780+0800 CHIPTool[9001:3798036] PersistentStorageDelegate Set Key StartKeyID
2021-07-20 14:02:53.171963+0800 CHIPTool[9001:3798036] PersistentStorageDelegate Set Key PairedDeviceb
2021-07-20 14:02:53.172096+0800 CHIPTool[9001:3798036] DevicePairingDelegate Pairing complete. Status 0
2021-07-20 14:02:53.172259+0800 CHIPTool[9001:3798036] [all] 🟢 [1626760973172] [9001:3798036] CHIP: [DMG] ICR moving to [Uninitiali]
2021-07-20 14:03:25.301505+0800 CHIPTool[9001:3798445] PersistentStorageDelegate Sync Get Value for Key: PairedDeviceb
2021-07-20 14:03:25.301806+0800 CHIPTool[9001:3798445] CHIPPersistentStorageDelegate Get Value for Key: PairedDeviceb, value RUFCRXFNR1E5RnVUV3NQN0d1cE5MRVhxQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUVBSVFBQUFBc0FBQUFBQUFBQU9qb0FBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFGa3JBQUFDQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFEQUFBQUF3QUFBQUFBQUFBPQAAAAAAAAAAAAAAAA==
2021-07-20 14:03:25.302076+0800 CHIPTool[9001:3798445] [all] 🟢 [1626761005302] [9001:3798445] CHIP: [IN] Marking old secure session for device 0x000000000000000B as expired
2021-07-20 14:03:25.302112+0800 CHIPTool[9001:3798445] [all] 🟢 [1626761005302] [9001:3798445] CHIP: [CTL] OnConnectionExpired was called for unknown device, ignoring it.
2021-07-20 14:03:25.302143+0800 CHIPTool[9001:3798445] [all] 🟢 [1626761005302] [9001:3798445] CHIP: [IN] New secure session created for device 0x000000000000000B, key 0!!
2021-07-20 14:03:25.307812+0800 CHIPTool[9001:3797832] [all] 🟢 [1626761005307] [9001:3797832] CHIP: [DMG] ICR moving to [Initialize]
2021-07-20 14:03:25.307873+0800 CHIPTool[9001:3797832] [all] 🟢 [1626761005307] [9001:3797832] CHIP: [DMG] ICR moving to [AddCommand]
2021-07-20 14:03:25.308002+0800 CHIPTool[9001:3797832] [all] 🟢 [1626761005307] [9001:3797832] CHIP: [IN] Secure message was encrypted: Msg ID 4
2021-07-20 14:03:25.308029+0800 CHIPTool[9001:3797832] [all] 🔵 [1626761005308] [9001:3797832] CHIP: [IN] Encrypted message 0x16b6ba0b8 from 0x398D77D0F3D62617 to 0x000000000000000B of type 8 and protocolId 5 on exchange 44253.
2021-07-20 14:03:25.308050+0800 CHIPTool[9001:3797832] [all] 🔵 [1626761005308] [9001:3797832] CHIP: [IN] Sending msg 0x16b6ba0b8 to 0x000000000000000B at utc time: 1626761005308 msec
2021-07-20 14:03:25.308063+0800 CHIPTool[9001:3797832] [all] 🔵 [1626761005308] [9001:3797832] CHIP: [IN] Sending secure msg on generic transport
2021-07-20 14:03:25.308475+0800 CHIPTool[9001:3797832] [all] 🔵 [1626761005308] [9001:3797832] CHIP: [IN] Secure msg send status No Error
2021-07-20 14:03:25.308496+0800 CHIPTool[9001:3797832] [all] 🟢 [1626761005308] [9001:3797832] CHIP: [DMG] ICR moving to [   Sending]
2021-07-20 14:03:25.713305+0800 CHIPTool[9001:3798445] [all] 🔵 [1626761005713] [9001:3798445] CHIP: [IN] Secure transport received message destined to fabric 0, node 0x398D77D0F3D62617. Key ID 33
2021-07-20 14:03:25.713468+0800 CHIPTool[9001:3798445] [all] 🔵 [1626761005713] [9001:3798445] CHIP: [EM] Received message of type 9 and protocolId 5 on exchange 44253
2021-07-20 14:03:25.713611+0800 CHIPTool[9001:3798445] [all] 🔵 [1626761005713] [9001:3798445] CHIP: [ZCL] DefaultResponse:
2021-07-20 14:03:25.713650+0800 CHIPTool[9001:3798445] [all] 🔵 [1626761005713] [9001:3798445] CHIP: [ZCL]   Transaction: 0x104e6e900
2021-07-20 14:03:25.713673+0800 CHIPTool[9001:3798445] [all] 🔵 [1626761005713] [9001:3798445] CHIP: [ZCL]   status: EMBER_ZCL_STATUS_SUCCESS (0x00)
2021-07-20 14:03:25.713813+0800 CHIPTool[9001:3798445] [all] 🟢 [1626761005713] [9001:3798445] CHIP: [DMG] ICR moving to [Uninitiali]
2021-07-20 14:03:28.482043+0800 CHIPTool[9001:3797832] [all] 🟢 [1626761008482] [9001:3797832] CHIP: [DMG] ICR moving to [Initialize]
2021-07-20 14:03:28.482134+0800 CHIPTool[9001:3797832] [all] 🟢 [1626761008482] [9001:3797832] CHIP: [DMG] ICR moving to [AddCommand]
2021-07-20 14:03:28.482285+0800 CHIPTool[9001:3797832] [all] 🟢 [1626761008482] [9001:3797832] CHIP: [IN] Secure message was encrypted: Msg ID 5
2021-07-20 14:03:28.482323+0800 CHIPTool[9001:3797832] [all] 🔵 [1626761008482] [9001:3797832] CHIP: [IN] Encrypted message 0x16b6ba0b8 from 0x398D77D0F3D62617 to 0x000000000000000B of type 8 and protocolId 5 on exchange 44254.
2021-07-20 14:03:28.482351+0800 CHIPTool[9001:3797832] [all] 🔵 [1626761008482] [9001:3797832] CHIP: [IN] Sending msg 0x16b6ba0b8 to 0x000000000000000B at utc time: 1626761008482 msec
2021-07-20 14:03:28.482371+0800 CHIPTool[9001:3797832] [all] 🔵 [1626761008482] [9001:3797832] CHIP: [IN] Sending secure msg on generic transport
2021-07-20 14:03:28.482823+0800 CHIPTool[9001:3797832] [all] 🔵 [1626761008482] [9001:3797832] CHIP: [IN] Secure msg send status No Error
2021-07-20 14:03:28.482853+0800 CHIPTool[9001:3797832] [all] 🟢 [1626761008482] [9001:3797832] CHIP: [DMG] ICR moving to [   Sending]
2021-07-20 14:03:28.775037+0800 CHIPTool[9001:3798445] [all] 🔵 [1626761008775] [9001:3798445] CHIP: [IN] Secure transport received message destined to fabric 0, node 0x398D77D0F3D62617. Key ID 33
2021-07-20 14:03:28.775189+0800 CHIPTool[9001:3798445] [all] 🔵 [1626761008775] [9001:3798445] CHIP: [EM] Received message of type 9 and protocolId 5 on exchange 44254
2021-07-20 14:03:28.775307+0800 CHIPTool[9001:3798445] [all] 🔵 [1626761008775] [9001:3798445] CHIP: [ZCL] DefaultResponse:
2021-07-20 14:03:28.775339+0800 CHIPTool[9001:3798445] [all] 🔵 [1626761008775] [9001:3798445] CHIP: [ZCL]   Transaction: 0x104e6e900
2021-07-20 14:03:28.775361+0800 CHIPTool[9001:3798445] [all] 🔵 [1626761008775] [9001:3798445] CHIP: [ZCL]   status: EMBER_ZCL_STATUS_SUCCESS (0x00)
2021-07-20 14:03:28.775425+0800 CHIPTool[9001:3798445] [all] 🟢 [1626761008775] [9001:3798445] CHIP: [DMG] ICR moving to [Uninitiali]
jmartinez-silabs commented 3 years ago

Sorry, this is a known issue we have another ticket tracking this. We have someone working on fixing this, but It got delayed for multiple reason. It is comming soon. I wil link the tickets together so you know when this is fixed.

https://github.com/project-chip/connectedhomeip/issues/7078

leasual commented 3 years ago

ok, thank you.

fengli commented 3 years ago

I created another issue, looks like a duplicate of this one. #8774 A minor difference is that I was testing lighting-app on Raspberry PI with Ubuntu server installed. So for Linux. Will add some details in #7078.

jmartinez-silabs commented 3 years ago

Fixed with #8666