I have been working with the matter sample project in the nrfconnect sdk and set up my Matter dev environment with a raspberry pi as border router.
When using the android CHIPtool to commission the sample, commssioning works and i can read values via the "cluster interaction tool" but whenever I try to set a value or use a command that I enabled in the .zap configuration the app crashes.
I was using the app from the releases for v1.9.1 on the git page (https://github.com/nrfconnect/sdk-connectedhomeip/releases). The matter sample is of the same version. I tried building my own version of the app via Android studio and followed the guide on https://developer.nordicsemi.com/nRF_Connect_SDK/doc/latest/matter/android_building.html. THe APK was generated without any errors, but this version of the app fails to even commission the Mattter sample to my Thread network. I compared both APK files and saw my build is only 29MB while the apk on the git release is 207.1 MB. see the "apk comparinson.png"
I have included both debug logs of the matter template project and the android process. Can anyone tell my what is going wrong?
I: nRF5 802154 radio initialized
I: 8 Sectors of 4096 bytes
I: alloc wra: 0, c88
I: data wra: 0, 8e4
*** Booting Zephyr OS build v2.7.99-ncs1-1 ***
I: Init CHIP stack
uaI: 233 [DL]BLE address: E1:1A:F3:88:76:8B
I: SoftDevice Controller build revision:
I: 0e e7 c5 66 67 18 3c ac |...fg.<.
I: b3 d2 cc 81 a3 dc f1 c0 |........
I: c0 36 02 22 |.6."
rt:~$ I: Starting CHIP task
I: Init Thread stack
I: 265 [DL]OpenThread started: OK
I: 269 [DL]Setting OpenThread device type to MINIMAL END DEVICE
I: 275 [ZCL]Using ZAP configuration...
D: 281 [DMG]Failed to read stored attribute (0, 0x0000_002B, 0x0000_0001: a0
D: 291 [DMG]Failed to read stored attribute (0, 0x0000_002C, 0x0000_0000: a0
I: 300 [SVR]Retrieved from server storage: a/0/2c/1
I: 309 [ZCL]Initiating Admin Commissioning cluster.
I: 314 [ZCL]OpCreds: Initiating OpCreds cluster by writing fabrics list from fabric table.
D: 322 [DIS]Set the fabric pairing table delegate
E: 336 [ZCL]Trying to write invalid Calendar Type
D: 352 [DIS]Init fabric pairing table with server storage
D: 370 [IN]UDP::Init bind&listen port=5540
D: 374 [IN]UDP::Init bound to port=5540
D: 377 [IN]TransportMgr initialized
D: 419 [SC]Assigned local session key ID 1
D: 422 [SC]Waiting for PBKDF param request
D: 426 [DL]CHIPoBLE advertising set to on
D: 430 [DIS]DNS-SD StartServer modeHasValue=1 modeValue=1
D: 435 [DL]Using Thread extended MAC for hostname.
I: 440 [DIS]Failed to find a valid admin pairing. Node ID unknown
I: 446 [DIS]Start dns-sd server - no current nodeId
D: 451 [DL]Using Thread extended MAC for hostname.
I: 457 [DIS]Advertise commission parameter vendorID=9050 productID=20052 discriminator=3840/15
E: 466 [DIS]Failed to advertise unprovisioned commissionable node: Error CHIP:0x00000003
D: 474 [DIS]Scheduling Discovery timeout in secs=900
E: 479 [DIS]Failed to finalize service update: Error CHIP:0x0000001C
D: 485 [DIS]DNS-SD StartServer modeHasValue=0 modeValue=0
D: 490 [DL]Using Thread extended MAC for hostname.
I: 495 [DIS]Failed to find a valid admin pairing. Node ID unknown
I: 501 [DIS]Start dns-sd server - no current nodeId
D: 505 [DL]Using Thread extended MAC for hostname.
I: 512 [DIS]Advertise commission parameter vendorID=9050 productID=20052 discriminator=3840/15
E: 521 [DIS]Failed to advertise unprovisioned commissionable node: Error CHIP:0x00000003
D: 529 [DIS]Scheduling Discovery timeout in secs=900
E: 533 [DIS]Failed to finalize service update: Error CHIP:0x0000001C
I: 539 [IN]CASE Server enabling CASE session setups
D: 544 [DL]Using Thread extended MAC for hostname.
I: 549 [SVR]Server Listening...
I: 552 [DL]Device Configuration:
I: 557 [DL] Serial Number: TEST_SN
I: 560 [DL] Vendor Id: 9050 (0x235A)
I: 564 [DL] Product Id: 20052 (0x4E54)
I: 569 [DL] Hardware Version: 0
I: 575 [DL] Setup Pin Code: 20202021
I: 580 [DL] Setup Discriminator: 3840 (0xF00)
I: 587 [DL] Manufacturing Date: (not set)
I: 591 [DL] Device Type: 65535 (0xFFFF)
I: 599 [SVR]SetupQRCode: [MT:CSF25OTB00KA0648G00]
I: 603 [SVR]Copy/paste the below URL in a browser to see the QR Code:
https://dhrishi.github.io/connectedhomeip/qrcode.html?data=MT%3ACSF25OTB00KA0648G00
I: 622 [SVR]Manual pairing code: [34970112332]
I: 631 [SVR]Long manual pairing code: [749701123309050200520]
D: 636 [DL]CHIP task running
I: 645 [DL]CHIPoBLE advertising started
I: 649 [ZCL]GeneralDiagnosticsDelegate: OnDeviceRebooted
I: 14154 [DL]BLE connection established (ConnId: 0x00)
I: 14159 [DL]Current number of connections: 1/1
I: 14164 [DL]CHIPoBLE advertising stopped
D: 15183 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
I: 15189 [BLE]local and remote recv window sizes = 5
I: 15194 [BLE]selected BTP version 4
I: 15197 [BLE]using BTP fragment sizes rx 244 / tx 244.
D: 15274 [DL]ConnId: 0x00, New CCCD value: 0x0001
D: 15278 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 6)
D: 15284 [IN]BLE EndPoint 0x20007588 Connection Complete
I: 15290 [DL]CHIPoBLE connection established (ConnId: 0x00, GATT MTU: 247)
D: 15454 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 15459 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
I: 15465 [EM]Received message of type 0x20 with protocolId (0, 0) and MessageCounter:3702871344 on exchange 36516r
D: 15476 [EM]Handling via exchange: 36516r, Delegate: 0x20004f30
D: 15481 [SC]Received PBKDF param request
D: 15485 [SC]Peer assigned session ID 699
D: 15489 [SC]Found MRP parameters in the message
D: 15493 [SC]Including MRP parameters in PBKDF param response
I: 15722 [IN]Prepared unauthenticated message 0x20027950 to 0x0000000000000000 (0) of type 0x21 and protocolId (0, 0) on exchange 36516r with MessageCounter:3298953600.
I: 15737 [IN]Sending unauthenticated msg 0x20027950 with MessageCounter:3298953600 to 0x0000000000000000 at monotonic time: 15737 msec
D: 15749 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 130)
D: 15755 [SC]Sent PBKDF param response
E: 15759 [DL]Long dispatch time: 300 ms, for event type 16388
D: 15813 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 18333 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
D: 20840 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 3)
D: 20868 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 23418 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
D: 25925 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 3)
D: 25953 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 28503 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
D: 31010 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 3)
D: 31038 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 33573 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
D: 36079 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 3)
D: 36108 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 38643 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
D: 41149 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 3)
D: 41178 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 43713 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
D: 45198 [DL]ConnId: 0x00, New CCCD value: 0x0000
D: 45202 [IN]Clearing BLE pending packets.
I: 45206 [BLE]Releasing end point's BLE connection back to application.
I: 45213 [DL]Closing BLE GATT connection (ConnId 00)
I: 45243 [DL]BLE GAP connection terminated (reason 0x16)
I: 45248 [DL]Current number of connections: 0/1
I: 45256 [DL]CHIPoBLE advertising started
E: 45721 [SC]PASESession timed out while waiting for a response from the peer. Expected message type was 34
E: 45731 [SVR]Commissioning failed (attempt 1): Error CHIP:0x00000032
D: 45740 [SC]Assigned local session key ID 2
D: 45744 [SC]Waiting for PBKDF param request
D: 45748 [DIS]DNS-SD StartServer modeHasValue=1 modeValue=1
D: 45753 [DL]Using Thread extended MAC for hostname.
I: 45758 [DIS]Failed to find a valid admin pairing. Node ID unknown
I: 45764 [DIS]Start dns-sd server - no current nodeId
D: 45769 [DL]Using Thread extended MAC for hostname.
I: 45776 [DIS]Advertise commission parameter vendorID=9050 productID=20052 discriminator=3840/15
E: 45785 [DIS]Failed to advertise unprovisioned commissionable node: Error CHIP:0x00000003
D: 45793 [DIS]Scheduling Discovery timeout in secs=900
E: 45798 [DIS]Failed to finalize service update: Error CHIP:0x0000001C
05/12 08:58:18: Launching 'chip-tool-android_aarch64' on OnePlus LE2123.
Install successfully finished in 1 s 339 ms.
$ adb shell am start -n "com.google.chip.chiptool/com.google.chip.chiptool.CHIPToolActivity" -a android.intent.action.MAIN -c android.intent.category.LAUNCHER
Connected to process 9582 on device 'oneplus-le2123-ddd7afb3'.
Capturing and displaying logcat messages from application. This behavior can be disabled in the "Logcat output" section of the "Debugger" settings page.
E/e.chip.chiptoo: Unknown bits set in runtime_flags: 0x40000000
D/ProcessState: Binder ioctl to enable oneway spam detection failed: Invalid argument
I/OneTrace: Mark active for pid=9582? true
D/CompatibilityChangeReporter: Compat change id reported: 171979766; UID 10459; state: DISABLED
I/oplus.android.OplusFrameworkFactoryImpl: get feature:IOplusAutoResolutionFeature
I/oplus.android.OplusFrameworkFactoryImpl: getOplusAutoResolutionFeature
W/ActivityThread: Application com.google.chip.chiptool can be debugged on port 8100...
D/ColorModeChangeItem: preExecute mColorMode=0,token=android.os.BinderProxy@6992845
I/Quality: LaunchTime2.0: com.google.chip.chiptool createOrUpdateClassLoaderLocked took time: 226
V/GraphicsEnvironment: ANGLE Developer option for 'com.google.chip.chiptool' set to: 'default'
V/GraphicsEnvironment: App is not on the allowlist for updatable production driver.
D/NetworkSecurityConfig: No Network Security Config specified, using platform default
D/NetworkSecurityConfig: No Network Security Config specified, using platform default
I/Quality: BindApplication: com.google.chip.chiptool
E/e.chip.chiptoo: Loaded layer handle (9109008816199849289) for layer /my_product/lib64/libcolorx-loader.so
E/e.chip.chiptoo: Looking for entrypoint ColorX_Check
E/e.chip.chiptoo: Found ColorX_Check for /my_product/lib64/libcolorx-loader.so
E/e.chip.chiptoo: Check failed
I/oplus.android.OplusFrameworkFactoryImpl: Unknow feature:IOplusTextViewRTLUtilForUG
D/CompatibilityChangeReporter: Compat change id reported: 160794467; UID 10459; state: DISABLED
D/ScrollOptimizationHelper: can't find the config file for optimizaiton
D/ScrollOptimizationHelper: will not debug for debug is false
I/oplus.android.OplusFrameworkFactoryImpl: get feature:IOplusDynamicVsyncFeature
I/oplus.android.OplusFrameworkFactoryImpl: get feature:IOplusDynamicVsyncFeature
I/oplus.android.OplusFrameworkFactoryImpl: get feature:IOplusDynamicVsyncFeature
W/e.chip.chiptoo: Accessing hidden method Landroid/view/View;->computeFitSystemWindows(Landroid/graphics/Rect;Landroid/graphics/Rect;)Z (unsupported, reflection, allowed)
W/e.chip.chiptoo: Accessing hidden method Landroid/view/ViewGroup;->makeOptionalFitsSystemWindows()V (unsupported, reflection, allowed)
E/OplusCustomizeRestrictionManager: sInstance is null, start a new sInstance
D/OplusInputMethodUtil: init DEBUG to false, update DEBUG_IME to false
D/OplusInputMethodUtil: init DEBUG to false, update DEBUG_IME to false
I/OplusFeatureCache: Milliseconds spent on init(): 8
D/OplusSlideAnimOptHelper: com.google.chip.chiptool scrollEffectOpt enable = false
D/ExtensionsLoader: createInstance(64bit) : createExtendedFactory
E/ExtensionsLoader: dlopen failed: library "libhwuiextimpl.so" not found
I/Quality: Skipped: false 1
V/OplusZoomWindowDecorViewHelper: setLastReportedMergedConfiguration mZoomDisplayHeight: 2412 getDecorView.142676355
I/AdrenoGLES-0: QUALCOMM build : 3b0ebcfc5c, I200588c14c
Build Date : 10/27/21
OpenGL ES Shader Compiler Version: EV031.35.01.03
Local Branch :
Remote Branch :
Remote Branch :
Reconstruct Branch :
I/AdrenoGLES-0: Build Config : S P 10.0.7 AArch64
I/AdrenoGLES-0: Driver Path : /vendor/lib64/egl/libGLESv2_adreno.so
I/AdrenoGLES-0: PFP: 0x016dc094, ME: 0x00000000
D/hw-ProcessState: Binder ioctl to enable oneway spam detection failed: Invalid argument
D/SurfaceComposerClient: VRR [FRTC] client handle [bufferId:18446744073709551615 framenumber:0] [ffffffff, ffffffff]
I/Quality: Skipped: false 8
I/Quality: Skipped: true 2
W/DynamiteModule: Local module descriptor class for com.google.android.gms.vision.dynamite.barcode not found.
I/DynamiteModule: Considering local module com.google.android.gms.vision.dynamite.barcode:0 and remote module com.google.android.gms.vision.dynamite.barcode:0
D/BarcodeNativeHandle: Cannot load feature, fall back to load dynamite module.
W/e.chip.chiptoo: Unsupported class loader
W/e.chip.chiptoo: Unsupported class loader
I/DynamiteModule: Considering local module com.google.android.gms.vision.barcode:0 and remote module com.google.android.gms.vision.barcode:1
I/DynamiteModule: Selected remote version of com.google.android.gms.vision.barcode, version >= 1
V/DynamiteModule: Dynamite loader version >= 2, using loadModule2NoCrashUtils
I/DynamiteLoaderV2Impl: [71] com.google.android.gms.vision.barcode
I/Quality: Skipped: false 11
W/libc: Access denied finding property "vendor.camera.aux.packagelist"
I/CameraExtImpl: getInstance success!
D/OplusCameraUtils: new OplusCameraUtils!
W/libc: Access denied finding property "vendor.camera.aux.packagelist"
W/libc: Access denied finding property "vendor.camera.aux.packagelist"
I/OplusCameraUtils: current activityName: com.google.chip.chiptool.CHIPToolActivity
I/OplusCameraUtils: getComponentName, componentName: com.google.chip.chiptool/com.google.chip.chiptool.CHIPToolActivity, packageName:com.google.chip.chiptool, activityName:com.google.chip.chiptool.CHIPToolActivity
D/OplusCameraStatisticsManager: addInfo, eventMap: {halLevel=1, cameraId=0, pkgName=com.google.chip.chiptool, connentTime=1652338716001, apLevel=1}
W/libc: Access denied finding property "vendor.camera.aux.packagelist"
I/Quality: Skipped: false 11
E/Parcel: Reading a NULL string not supported here.
D/SurfaceComposerClient: VRR [FRTC] client handle [bufferId:18446744073709551615 framenumber:0] [ffffffff, ffffffff]
D/OplusCameraStatisticsManager: addPreviewInfo, eventMap: {halLevel=1, preview_time=262, face_count=-1, pkgName=com.google.chip.chiptool, camera_id=0, width=1024, apLevel=1, height=768}
D/Camera: app passed NULL surface
D/OplusCameraStatisticsManager: addInfo, eventMap: {halLevel=1, cameraId=0, disconnectTime=1652338716360, pkgName=com.google.chip.chiptool, connentTime=1652338716001, apLevel=1, timeCost=359}
D/SPL: JNI_OnLoad() called
D/CompatibilityChangeReporter: Compat change id reported: 171228096; UID 10459; state: ENABLED
I/oplus.android.OplusFrameworkFactoryImpl: get feature:IOplusDynamicVsyncFeature
I/oplus.android.OplusFrameworkFactoryImpl: get feature:IOplusDynamicVsyncFeature
I/oplus.android.OplusFrameworkFactoryImpl: get feature:IOplusDynamicVsyncFeature
D/CTL: JNI_OnLoad() called
D/CTL: Loading Java class references.
D/CTL: Java class references loaded.
D/DL: AndroidChipPlatform JNI_OnLoad() called
E/SPT: JavaVM is already set
D/DL: Loading Java class references.
D/DL: Java class references loaded.
D/CompatibilityChangeReporter: Compat change id reported: 191844585; UID 10459; state: DISABLED
D/CTL: newDeviceController() called
D/TOO: KVS: Getting key AndroidDeviceControllerKey
D/CTL: Generating NOC
D/TOO: KVS: Getting key AndroidCARootCert0
D/IN: UDP::Init bind&listen port=5541
D/IN: UDP::Init bound to port=5541
D/IN: UDP::Init bind&listen port=5541
D/IN: UDP::Init bound to port=5541
D/IN: TransportMgr initialized
D/DIS: Init fabric pairing table with server storage
D/TOO: KVS: Getting key Fabric1
D/KeyValueStoreManager: Key 'Fabric1' not found in shared preferences
D/TOO: KVS: Getting key Fabric2
D/KeyValueStoreManager: Key 'Fabric2' not found in shared preferences
D/TOO: KVS: Getting key Fabric3
D/KeyValueStoreManager: Key 'Fabric3' not found in shared preferences
D/TOO: KVS: Getting key Fabric4
D/KeyValueStoreManager: Key 'Fabric4' not found in shared preferences
D/TOO: KVS: Getting key Fabric5
D/KeyValueStoreManager: Key 'Fabric5' not found in shared preferences
D/TOO: KVS: Getting key Fabric6
D/KeyValueStoreManager: Key 'Fabric6' not found in shared preferences
D/TOO: KVS: Getting key Fabric7
D/KeyValueStoreManager: Key 'Fabric7' not found in shared preferences
D/TOO: KVS: Getting key Fabric8
D/KeyValueStoreManager: Key 'Fabric8' not found in shared preferences
D/TOO: KVS: Getting key Fabric9
D/KeyValueStoreManager: Key 'Fabric9' not found in shared preferences
D/TOO: KVS: Getting key Fabrica
D/KeyValueStoreManager: Key 'Fabrica' not found in shared preferences
D/TOO: KVS: Getting key Fabricb
D/KeyValueStoreManager: Key 'Fabricb' not found in shared preferences
D/TOO: KVS: Getting key Fabricc
D/KeyValueStoreManager: Key 'Fabricc' not found in shared preferences
D/TOO: KVS: Getting key Fabricd
D/KeyValueStoreManager: Key 'Fabricd' not found in shared preferences
D/TOO: KVS: Getting key Fabrice
D/KeyValueStoreManager: Key 'Fabrice' not found in shared preferences
D/TOO: KVS: Getting key Fabricf
D/KeyValueStoreManager: Key 'Fabricf' not found in shared preferences
D/TOO: KVS: Getting key Fabric10
D/KeyValueStoreManager: Key 'Fabric10' not found in shared preferences
D/ZCL: Using ZAP configuration...
D/CTL: System State Initialized...
D/CTL: Intermediate CA is not needed
D/TOO: KVS: Getting key Fabric1
D/KeyValueStoreManager: Key 'Fabric1' not found in shared preferences
D/DIS: Verifying the received credentials
D/IN: Generating compressed fabric ID using uncompressed fabric ID 0x0000000000000000 and root pubkey
D/IN: 0x04, 0x9e, 0xad, 0x9f, 0x20, 0xb9, 0x5b, 0x5e,
D/IN: 0xc1, 0x85, 0x1f, 0x56, 0x18, 0x21, 0xa5, 0x1f,
D/IN: 0xf8, 0xa0, 0x74, 0x09, 0x29, 0x32, 0x59, 0x78,
D/IN: 0x93, 0x01, 0xc1, 0x97, 0xc3, 0x69, 0xe7, 0xf0,
D/IN: 0x24, 0x59, 0x40, 0x77, 0xde, 0xb1, 0xb5, 0xe4,
D/IN: 0x2d, 0x69, 0x0a, 0xe9, 0x57, 0xc4, 0xc4, 0x6a,
D/IN: 0xbb, 0x90, 0xfc, 0xc4, 0x7c, 0x94, 0xfe, 0x58,
D/IN: 0x75, 0x2d, 0xe7, 0x66, 0x4c, 0xe0, 0xc0, 0x27,
D/IN: 0xed,
D/IN: Generated compressed fabric ID
D/IN: 0x60, 0x0c, 0xde, 0xd1, 0x84, 0xb0, 0x94, 0x4e,
D/DIS: Added new fabric at index: 1, Initialized: 1
D/DIS: Assigned compressed fabric ID: 0x600CDED184B0944E, node ID: 0x000000000001B669
D/CTL: Joined the fabric at index 1. Compressed fabric ID is: 0x600CDED184B0944E
D/CTL: IO thread starting
D/DL: _OnPlatformEvent
I/DeviceProvisioningFragment: showMessage:Scanning for BLE device 3840
D/CompatibilityChangeReporter: Compat change id reported: 147798919; UID 10459; state: ENABLED
I/chip.BluetoothManager: Starting Bluetooth scan
D/BluetoothAdapter: isLeEnabled(): ON
D/BluetoothLeScanner: onScannerRegistered() - status=0 scannerId=11 mScannerId=0
I/Quality: Skipped: false 5
I/chip.BluetoothManager: Bluetooth Device Scanned Addr: EE:28:76:1F:86:9B, Name MatterTemplate
D/BluetoothAdapter: isLeEnabled(): ON
I/DeviceProvisioningFragment: showMessage:Connecting to MatterTemplate
I/chip.BluetoothManager: Connecting
D/BluetoothGatt: connect() - device: EE:28:76:1F:86:9B, auto: false, eattSupport: false
D/BluetoothGatt: registerApp()
D/BluetoothGatt: registerApp() - UUID=70033458-8429-4f48-922b-2eb43aa719d8
I/chip.BluetoothManager: Bluetooth Device Scanned Addr: EE:28:76:1F:86:9B, Name MatterTemplate
W/chip.BluetoothManager: Bluetooth device was scanned, but channel is already closed
D/BluetoothGatt: onClientRegistered() - status=0 clientIf=11
D/BluetoothGatt: onClientConnectionState() - status=0 clientIf=11 device=EE:28:76:1F:86:9B
I/chip.BluetoothManager: MatterTemplate.onConnectionStateChange status = 0, newState=2
I/chip.BluetoothManager|onConnectionStateChange: Discovering Services...
D/BluetoothGatt: discoverServices() - device: EE:28:76:1F:86:9B
D/BluetoothGatt: onConnectionUpdated() - Device=EE:28:76:1F:86:9B interval=6 latency=0 timeout=500 status=0
D/BluetoothGatt: onPhyUpdate() - status=0 address=EE:28:76:1F:86:9B txPhy=2 rxPhy=2
D/BluetoothGatt: onSearchComplete() = Device=EE:28:76:1F:86:9B Status=0
D/chip.BluetoothManager: MatterTemplate.onServicesDiscovered status = 0
I/chip.BluetoothManager|onServicesDiscovered: Services Discovered
D/BluetoothGatt: configureMTU() - device: EE:28:76:1F:86:9B mtu: 247
D/BluetoothGatt: onConfigureMTU() - Device=EE:28:76:1F:86:9B mtu=247 status=0
D/chip.BluetoothManager: MatterTemplate.onMtuChanged: connecting to CHIP device
I/DeviceProvisioningFragment: showMessage:Pairing
D/ChipDeviceController: Bluetooth connection added with ID: 1
D/ChipDeviceController: Pairing device with ID: 2
D/CTL: pairDevice() called with device ID, connection object, and pincode
D/TOO: KVS: Getting key ListPairedDevices0
D/KeyValueStoreManager: Key 'ListPairedDevices0' not found in shared preferences
D/IN: BleConnectionComplete: endPoint 0x7922b95478
D/DL: Received GetMTU
D/AndroidBleManager: Android Manufacturer: (OnePlus)
D/AndroidBleManager: Android Model: (LE2123)
D/DL: Received SendWriteRequest
D/SC: Assigned local session key ID 1
D/SC: Including MRP parameters in PBKDF param request
D/IN: Prepared unauthenticated message 0x7fd56c17b0 to 0x0000000000000000 (0) of type 0x20 and protocolId (0, 0) on exchange 34717i with MessageCounter:1214745440.
D/IN: Sending unauthenticated msg 0x7fd56c17b0 with MessageCounter:1214745440 to 0x0000000000000000 at monotonic time: 61285181 msec
D/IN: Message appended to BLE send queue
D/SC: Sent PBKDF param request
D/CTL: Commission called for node ID 0x0000000000000002
D/CTL: Setting thread operational dataset from parameters
D/CTL: Setting attestation nonce to random value
D/CTL: Setting CSR nonce to random value
D/chip.BluetoothManager: MatterTemplate.onCharacteristicWrite: 18ee2ef5-263d-4559-959f-4f9c429f9d11 -> 0
D/DL: Received SubscribeCharacteristic
D/BluetoothGatt: setCharacteristicNotification() - uuid: 18ee2ef5-263d-4559-959f-4f9c429f9d12 enable: true
D/BluetoothGatt: onConnectionUpdated() - Device=EE:28:76:1F:86:9B interval=36 latency=0 timeout=500 status=0
D/chip.BluetoothManager: MatterTemplate.onDescriptorWrite: 00002902-0000-1000-8000-00805f9b34fb -> 0
D/BLE: subscribe complete, ep = 0x7922b95478
D/chip.BluetoothManager: MatterTemplate.onCharacteristicChanged: 18ee2ef5-263d-4559-959f-4f9c429f9d12
D/BLE: peripheral chose BTP version 4; central expected between 4 and 4
D/BLE: using BTP fragment sizes rx 244 / tx 244.
D/BLE: local and remote recv window size = 5
D/DL: Received SendWriteRequest
D/IN: BLE EndPoint 0x7922b95478 Connection Complete
D/chip.BluetoothManager: MatterTemplate.onCharacteristicWrite: 18ee2ef5-263d-4559-959f-4f9c429f9d11 -> 0
D/chip.BluetoothManager: MatterTemplate.onCharacteristicChanged: 18ee2ef5-263d-4559-959f-4f9c429f9d12
D/EM: Received message of type 0x21 with protocolId (0, 0) and MessageCounter:1117629971 on exchange 34717i
D/EM: Found matching exchange: 34717i, Delegate: 0xb40000792dd8fc60
D/SC: Received PBKDF param response
D/SC: Peer assigned session ID 1
D/SC: Found MRP parameters in the message
D/IN: Prepared unauthenticated message 0x799c3d4750 to 0x0000000000000000 (0) of type 0x22 and protocolId (0, 0) on exchange 34717i with MessageCounter:1214745441.
D/IN: Sending unauthenticated msg 0x799c3d4750 with MessageCounter:1214745441 to 0x0000000000000000 at monotonic time: 61285834 msec
D/DL: Received SendWriteRequest
D/SC: Sent spake2p msg1
D/chip.BluetoothManager: MatterTemplate.onCharacteristicWrite: 18ee2ef5-263d-4559-959f-4f9c429f9d11 -> 0
D/chip.BluetoothManager: MatterTemplate.onCharacteristicChanged: 18ee2ef5-263d-4559-959f-4f9c429f9d12
D/EM: Received message of type 0x23 with protocolId (0, 0) and MessageCounter:1117629972 on exchange 34717i
D/EM: Found matching exchange: 34717i, Delegate: 0xb40000792dd8fc60
D/SC: Received spake2p msg2
D/IN: Prepared unauthenticated message 0x799c3d4c10 to 0x0000000000000000 (0) of type 0x24 and protocolId (0, 0) on exchange 34717i with MessageCounter:1214745442.
D/IN: Sending unauthenticated msg 0x799c3d4c10 with MessageCounter:1214745442 to 0x0000000000000000 at monotonic time: 61288010 msec
D/DL: Received SendWriteRequest
D/SC: Sent spake2p msg3
D/chip.BluetoothManager: MatterTemplate.onCharacteristicWrite: 18ee2ef5-263d-4559-959f-4f9c429f9d11 -> 0
D/chip.BluetoothManager: MatterTemplate.onCharacteristicChanged: 18ee2ef5-263d-4559-959f-4f9c429f9d12
D/EM: Received message of type 0x40 with protocolId (0, 0) and MessageCounter:1117629973 on exchange 34717i
D/EM: Found matching exchange: 34717i, Delegate: 0xb40000792dd8fc60
D/IN: New secure session created for device 0x0000000000000002, LSID:1 PSID:1!
D/CTL: Remote device completed SPAKE2+ handshake
D/CTL: Arming failsafe
D/DMG: ICR moving to [AddingComm]
D/DMG: ICR moving to [AddedComma]
D/IN: Prepared secure message 0x799c3d3580 to 0x0000000000000002 (1) of type 0x8 and protocolId (0, 1) on exchange 34718i with MessageCounter:5698866.
D/IN: Sending encrypted msg 0x799c3d3580 with MessageCounter:5698866 to 0x0000000000000002 (1) at monotonic time: 61288122 msec
D/DL: Received SendWriteRequest
D/DMG: ICR moving to [CommandSen]
D/chip.BluetoothManager: MatterTemplate.onCharacteristicWrite: 18ee2ef5-263d-4559-959f-4f9c429f9d11 -> 0
D/chip.BluetoothManager: MatterTemplate.onCharacteristicChanged: 18ee2ef5-263d-4559-959f-4f9c429f9d12
D/EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:9409385 on exchange 34718i
D/EM: Found matching exchange: 34718i, Delegate: 0xb40000799be27680
D/DMG: ICR moving to [ResponseRe]
D/DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0001
D/ZCL: ArmFailSafeResponse:
D/ZCL: errorCode: 0
D/ZCL: debugText:
D/CTL: Received success response 0x0
D/CTL: Setting Regulatory Config
D/KeyValueStoreManager: Key 'chip-config:country-code' not found in shared preferences
E/DL: Java exception in AndroidConfig::ReadConfigValueStr
W/System.err: chip.platform.AndroidChipPlatformException
W/System.err: at chip.platform.PreferencesConfigurationManager.readConfigValueStr(PreferencesConfigurationManager.java:187)
W/System.err: at chip.platform.AndroidChipPlatform.handleIndicationReceived(Native Method)
W/System.err: at chip.platform.AndroidBleManager$1.onCharacteristicChanged(AndroidBleManager.java:126)
W/System.err: at com.google.chip.chiptool.bluetooth.BluetoothManager$getBluetoothGattCallback$1.onCharacteristicChanged(BluetoothManager.kt:156)
W/System.err: at android.bluetooth.BluetoothGatt$1$8.run(BluetoothGatt.java:490)
W/System.err: at android.bluetooth.BluetoothGatt.runOrQueueCallback(BluetoothGatt.java:823)
W/System.err: at android.bluetooth.BluetoothGatt.access$200(BluetoothGatt.java:47)
W/System.err: at android.bluetooth.BluetoothGatt$1.onNotify(BluetoothGatt.java:484)
W/System.err: at android.bluetooth.IBluetoothGattCallback$Stub.onTransact(IBluetoothGattCallback.java:315)
W/System.err: at android.os.Binder.execTransactInternal(Binder.java:1226)
W/System.err: at android.os.Binder.execTransact(Binder.java:1163)
E/CTL: Unable to find country code, defaulting to WW
D/DMG: ICR moving to [AddingComm]
D/DMG: ICR moving to [AddedComma]
D/IN: Prepared secure message 0x799c3d21b0 to 0x0000000000000002 (1) of type 0x8 and protocolId (0, 1) on exchange 34719i with MessageCounter:5698867.
D/IN: Sending encrypted msg 0x799c3d21b0 with MessageCounter:5698867 to 0x0000000000000002 (1) at monotonic time: 61288259 msec
D/DL: Received SendWriteRequest
D/DMG: ICR moving to [CommandSen]
D/DMG: ICR moving to [AwaitingDe]
D/chip.BluetoothManager: MatterTemplate.onCharacteristicWrite: 18ee2ef5-263d-4559-959f-4f9c429f9d11 -> 0
D/chip.BluetoothManager: MatterTemplate.onCharacteristicChanged: 18ee2ef5-263d-4559-959f-4f9c429f9d12
D/EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:9409386 on exchange 34719i
D/EM: Found matching exchange: 34719i, Delegate: 0xb40000799be277c0
D/DMG: ICR moving to [ResponseRe]
D/DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0003
D/ZCL: SetRegulatoryConfigResponse:
D/ZCL: errorCode: 0
D/ZCL: debugText:
D/CTL: Received success response 0x0
D/CTL: Sending request for PAI certificate
D/CTL: Sending Certificate Chain request to 0xb40000792dd8fc00 device
D/DMG: ICR moving to [AddingComm]
D/DMG: ICR moving to [AddedComma]
D/IN: Prepared secure message 0x799c3d21f0 to 0x0000000000000002 (1) of type 0x8 and protocolId (0, 1) on exchange 34720i with MessageCounter:5698868.
D/IN: Sending encrypted msg 0x799c3d21f0 with MessageCounter:5698868 to 0x0000000000000002 (1) at monotonic time: 61288436 msec
D/DL: Received SendWriteRequest
D/DMG: ICR moving to [CommandSen]
D/DMG: ICR moving to [AwaitingDe]
D/chip.BluetoothManager: MatterTemplate.onCharacteristicWrite: 18ee2ef5-263d-4559-959f-4f9c429f9d11 -> 0
D/chip.BluetoothManager: MatterTemplate.onCharacteristicChanged: 18ee2ef5-263d-4559-959f-4f9c429f9d12
D/chip.BluetoothManager: MatterTemplate.onCharacteristicChanged: 18ee2ef5-263d-4559-959f-4f9c429f9d12
D/chip.BluetoothManager: MatterTemplate.onCharacteristicChanged: 18ee2ef5-263d-4559-959f-4f9c429f9d12
D/EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:9409387 on exchange 34720i
D/EM: Found matching exchange: 34720i, Delegate: 0xb40000799be27680
D/DMG: ICR moving to [ResponseRe]
D/DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0003
D/ZCL: CertificateChainResponse:
D/ZCL: Certificate: 472
D/CTL: Received certificate chain from the device
D/CTL: Sending request for DAC certificate
D/CTL: Sending Certificate Chain request to 0xb40000792dd8fc00 device
D/DMG: ICR moving to [AddingComm]
D/DMG: ICR moving to [AddedComma]
D/IN: Prepared secure message 0x799c3d2080 to 0x0000000000000002 (1) of type 0x8 and protocolId (0, 1) on exchange 34721i with MessageCounter:5698869.
D/IN: Sending encrypted msg 0x799c3d2080 with MessageCounter:5698869 to 0x0000000000000002 (1) at monotonic time: 61288805 msec
D/DL: Received SendWriteRequest
D/DMG: ICR moving to [CommandSen]
D/DMG: ICR moving to [AwaitingDe]
D/chip.BluetoothManager: MatterTemplate.onCharacteristicWrite: 18ee2ef5-263d-4559-959f-4f9c429f9d11 -> 0
D/chip.BluetoothManager: MatterTemplate.onCharacteristicChanged: 18ee2ef5-263d-4559-959f-4f9c429f9d12
D/chip.BluetoothManager: MatterTemplate.onCharacteristicChanged: 18ee2ef5-263d-4559-959f-4f9c429f9d12
D/chip.BluetoothManager: MatterTemplate.onCharacteristicChanged: 18ee2ef5-263d-4559-959f-4f9c429f9d12
D/EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:9409388 on exchange 34721i
D/EM: Found matching exchange: 34721i, Delegate: 0xb40000799be277c0
D/DMG: ICR moving to [ResponseRe]
D/DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0003
D/ZCL: CertificateChainResponse:
D/ZCL: Certificate: 494
D/CTL: Received certificate chain from the device
D/CTL: Sending Attestation Request to the device.
D/CTL: Sending Attestation request to 0xb40000792dd8fc00 device
D/DMG: ICR moving to [AddingComm]
D/DMG: ICR moving to [AddedComma]
D/IN: Prepared secure message 0x799c3d2040 to 0x0000000000000002 (1) of type 0x8 and protocolId (0, 1) on exchange 34722i with MessageCounter:5698870.
D/IN: Sending encrypted msg 0x799c3d2040 with MessageCounter:5698870 to 0x0000000000000002 (1) at monotonic time: 61289162 msec
D/DL: Received SendWriteRequest
D/DMG: ICR moving to [CommandSen]
D/CTL: Sent Attestation request, waiting for the Attestation Information
D/DMG: ICR moving to [AwaitingDe]
D/chip.BluetoothManager: MatterTemplate.onCharacteristicWrite: 18ee2ef5-263d-4559-959f-4f9c429f9d11 -> 0
D/chip.BluetoothManager: MatterTemplate.onCharacteristicChanged: 18ee2ef5-263d-4559-959f-4f9c429f9d12
D/chip.BluetoothManager: MatterTemplate.onCharacteristicChanged: 18ee2ef5-263d-4559-959f-4f9c429f9d12
D/EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:9409389 on exchange 34722i
D/EM: Found matching exchange: 34722i, Delegate: 0xb40000799be27680
D/DMG: ICR moving to [ResponseRe]
D/DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0001
D/ZCL: AttestationResponse:
D/ZCL: AttestationElements: 278
D/ZCL: Signature: 64
D/CTL: Received Attestation Information from the device
D/CTL: Verifying attestation
E/CR: mbedTLS error: ERROR - Generic error
D/CTL: Successfully validated 'Attestation Information' command received from the device.
D/CTL: Sending OpCSR request to 0xb40000792dd8fc00 device
D/DMG: ICR moving to [AddingComm]
D/DMG: ICR moving to [AddedComma]
D/IN: Prepared secure message 0x799c3cfcd0 to 0x0000000000000002 (1) of type 0x8 and protocolId (0, 1) on exchange 34723i with MessageCounter:5698871.
D/IN: Sending encrypted msg 0x799c3cfcd0 with MessageCounter:5698871 to 0x0000000000000002 (1) at monotonic time: 61289503 msec
D/DL: Received SendWriteRequest
D/DMG: ICR moving to [CommandSen]
D/CTL: Sent OpCSR request, waiting for the CSR
D/DMG: ICR moving to [AwaitingDe]
D/chip.BluetoothManager: MatterTemplate.onCharacteristicWrite: 18ee2ef5-263d-4559-959f-4f9c429f9d11 -> 0
D/BluetoothGatt: onConnectionUpdated() - Device=EE:28:76:1F:86:9B interval=12 latency=0 timeout=42 status=0
E/ActivityThread: Failed to find provider info for com.oplus.statistics.provider
E/OplusStatistics--: IllegalArgumentException:java.lang.IllegalArgumentException: Unknown URL content://com.oplus.statistics.provider/track_event
D/chip.BluetoothManager: MatterTemplate.onCharacteristicChanged: 18ee2ef5-263d-4559-959f-4f9c429f9d12
D/chip.BluetoothManager: MatterTemplate.onCharacteristicChanged: 18ee2ef5-263d-4559-959f-4f9c429f9d12
D/EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:9409390 on exchange 34723i
D/EM: Found matching exchange: 34723i, Delegate: 0xb40000799be277c0
D/DMG: ICR moving to [ResponseRe]
D/DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0005
D/ZCL: OpCSRResponse:
D/ZCL: NOCSRElements: 244
D/ZCL: AttestationSignature: 64
D/CTL: Received certificate signing request from the device
D/CTL: Getting certificate chain for the device from the issuer
D/TOO: VerifyCertificateSigningRequest
D/CTL: Generating NOC
D/TOO: KVS: Getting key AndroidCARootCert0
D/CTL: Received callback from the CA for NOC Chain generation. Status ../../src/controller/java/AndroidDeviceControllerWrapper.cpp:165: Success
D/CTL: Sending root certificate to the device
D/DMG: ICR moving to [AddingComm]
D/DMG: ICR moving to [AddedComma]
D/IN: Prepared secure message 0x799c3cfb70 to 0x0000000000000002 (1) of type 0x8 and protocolId (0, 1) on exchange 34724i with MessageCounter:5698872.
D/IN: Sending encrypted msg 0x799c3cfb70 with MessageCounter:5698872 to 0x0000000000000002 (1) at monotonic time: 61290074 msec
D/DL: Received SendWriteRequest
D/DMG: ICR moving to [CommandSen]
D/CTL: Sent root certificate to the device
D/DeviceProvisioningFragment: 0�0��0p��01 0
U
CSR0Y0*�H�=*�H�=B��
��/k8���W��/�1��C)��ܜ���oD)�����z�F�܍ ����$=�j_�h���0 *�H�=��G��0D Z��/�<o��V<m��G�Sө�*�:�*.:܃ Iy�������ڡRT�,C-X$��C����0 O��"����ˈ1�ǀ�9�n�F6k��<~
D/DMG: ICR moving to [AwaitingDe]
D/chip.BluetoothManager: MatterTemplate.onCharacteristicWrite: 18ee2ef5-263d-4559-959f-4f9c429f9d11 -> 0
D/DL: Received SendWriteRequest
D/chip.BluetoothManager: MatterTemplate.onCharacteristicWrite: 18ee2ef5-263d-4559-959f-4f9c429f9d11 -> 0
D/chip.BluetoothManager: MatterTemplate.onCharacteristicChanged: 18ee2ef5-263d-4559-959f-4f9c429f9d12
D/EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:9409391 on exchange 34724i
D/EM: Found matching exchange: 34724i, Delegate: 0xb40000799be27680
D/DMG: ICR moving to [ResponseRe]
D/DMG: Received Command Response Status for Endpoint=0 Cluster=0x0000_003E Command=0x0000_000B Status=0x0
D/ZCL: DefaultResponse:
D/ZCL: Transaction: 0xb40000799be27680
D/ZCL: status: EMBER_ZCL_STATUS_SUCCESS (0x00)
D/CTL: Device confirmed that it has received the root certificate
D/CTL: Sending operational certificate chain to the device
D/DMG: ICR moving to [AddingComm]
D/DMG: ICR moving to [AddedComma]
D/IN: Prepared secure message 0x799c3d2760 to 0x0000000000000002 (1) of type 0x8 and protocolId (0, 1) on exchange 34725i with MessageCounter:5698873.
D/IN: Sending encrypted msg 0x799c3d2760 with MessageCounter:5698873 to 0x0000000000000002 (1) at monotonic time: 61290209 msec
D/DL: Received SendWriteRequest
D/DMG: ICR moving to [CommandSen]
D/CTL: Sent operational certificate to the device
D/DMG: ICR moving to [AwaitingDe]
D/chip.BluetoothManager: MatterTemplate.onCharacteristicWrite: 18ee2ef5-263d-4559-959f-4f9c429f9d11 -> 0
D/DL: Received SendWriteRequest
D/chip.BluetoothManager: MatterTemplate.onCharacteristicWrite: 18ee2ef5-263d-4559-959f-4f9c429f9d11 -> 0
D/chip.BluetoothManager: MatterTemplate.onCharacteristicChanged: 18ee2ef5-263d-4559-959f-4f9c429f9d12
D/EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:9409392 on exchange 34725i
D/EM: Found matching exchange: 34725i, Delegate: 0xb40000799be277c0
D/DMG: ICR moving to [ResponseRe]
D/DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0008
D/ZCL: NOCResponse:
D/ZCL: StatusCode: 0
D/ZCL: FabricIndex: 1
D/ZCL: DebugText:
D/CTL: Device returned status 0 on receiving the NOC
D/CTL: Operational credentials provisioned on device 0xb40000792dd8fc00
D/DeviceProvisioningFragment: Pairing status update: 0
D/CTL: Adding thread network
D/DMG: ICR moving to [AddingComm]
D/DMG: ICR moving to [AddedComma]
D/IN: Prepared secure message 0x799c3d1eb0 to 0x0000000000000002 (1) of type 0x8 and protocolId (0, 1) on exchange 34726i with MessageCounter:5698874.
D/IN: Sending encrypted msg 0x799c3d1eb0 with MessageCounter:5698874 to 0x0000000000000002 (1) at monotonic time: 61290756 msec
D/DL: Received SendWriteRequest
D/DMG: ICR moving to [CommandSen]
D/DMG: ICR moving to [AwaitingDe]
D/chip.BluetoothManager: MatterTemplate.onCharacteristicWrite: 18ee2ef5-263d-4559-959f-4f9c429f9d11 -> 0
D/chip.BluetoothManager: MatterTemplate.onCharacteristicChanged: 18ee2ef5-263d-4559-959f-4f9c429f9d12
D/EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:9409393 on exchange 34726i
D/EM: Found matching exchange: 34726i, Delegate: 0xb40000799be27680
D/DMG: ICR moving to [ResponseRe]
D/DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0005
D/ZCL: NetworkConfigResponse:
D/ZCL: NetworkingStatus: 0
D/ZCL: DebugText:
D/CTL: Received success response 0x0
D/CTL: Enabling thread network
D/DMG: ICR moving to [AddingComm]
D/DMG: ICR moving to [AddedComma]
D/IN: Prepared secure message 0x799c3d2200 to 0x0000000000000002 (1) of type 0x8 and protocolId (0, 1) on exchange 34727i with MessageCounter:5698875.
D/IN: Sending encrypted msg 0x799c3d2200 with MessageCounter:5698875 to 0x0000000000000002 (1) at monotonic time: 61290871 msec
D/DL: Received SendWriteRequest
D/DMG: ICR moving to [CommandSen]
D/DMG: ICR moving to [AwaitingDe]
D/chip.BluetoothManager: MatterTemplate.onCharacteristicWrite: 18ee2ef5-263d-4559-959f-4f9c429f9d11 -> 0
D/chip.BluetoothManager: MatterTemplate.onCharacteristicChanged: 18ee2ef5-263d-4559-959f-4f9c429f9d12
D/EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:9409394 on exchange 34727i
D/EM: Found matching exchange: 34727i, Delegate: 0xb40000799be277c0
D/DMG: ICR moving to [ResponseRe]
D/DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0007
D/ZCL: ConnectNetworkResponse:
D/ZCL: NetworkingStatus: 0
D/ZCL: DebugText:
D/ZCL: ErrorValue: 0
D/CTL: Received success response 0x0
D/NsdManagerServiceResolver: Starting service resolution for '600CDED184B0944E-0000000000000002'
D/DMG: ICR moving to [AwaitingDe]
D/DL: Received SendWriteRequest
D/chip.BluetoothManager: MatterTemplate.onCharacteristicWrite: 18ee2ef5-263d-4559-959f-4f9c429f9d11 -> 0
I/NsdManagerServiceResolver: Resolved service '600CDED184B0944E-0000000000000002' to /fd50:a5b4:c22b:8c99:3550:c09b:50af:b697
D/DIS: Node ID resolved for 0x0000000000000002
D/DIS: Addr 0: [fd50:a5b4:c22b:8c99:3550:c09b:50af:b697]:5540
D/CTL: OperationalDiscoveryComplete for device ID 0x0000000000000002
D/IN: Generating DestinationID. Fabric ID 0x0000000000000000, Dest node ID 0x0000000000000002, Random data
D/IN: 0x05, 0xa0, 0x36, 0x77, 0x84, 0xb2, 0xb7, 0xbe,
D/IN: 0x50, 0x97, 0xd4, 0xf3, 0xee, 0x4b, 0x17, 0xbe,
D/IN: 0x23, 0xa8, 0xa4, 0x27, 0xcd, 0x41, 0xe3, 0x26,
D/IN: 0x5a, 0x75, 0x36, 0x6c, 0x3d, 0x04, 0xb7, 0x85,
D/IN: Root pubkey
D/IN: 0x04, 0x9e, 0xad, 0x9f, 0x20, 0xb9, 0x5b, 0x5e,
D/IN: 0xc1, 0x85, 0x1f, 0x56, 0x18, 0x21, 0xa5, 0x1f,
D/IN: 0xf8, 0xa0, 0x74, 0x09, 0x29, 0x32, 0x59, 0x78,
D/IN: 0x93, 0x01, 0xc1, 0x97, 0xc3, 0x69, 0xe7, 0xf0,
D/IN: 0x24, 0x59, 0x40, 0x77, 0xde, 0xb1, 0xb5, 0xe4,
D/IN: 0x2d, 0x69, 0x0a, 0xe9, 0x57, 0xc4, 0xc4, 0x6a,
D/IN: 0xbb, 0x90, 0xfc, 0xc4, 0x7c, 0x94, 0xfe, 0x58,
D/IN: 0x75, 0x2d, 0xe7, 0x66, 0x4c, 0xe0, 0xc0, 0x27,
D/IN: 0xed,
D/IN: IPK
D/IN: 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
D/IN: 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
D/IN: Generated DestinationID output
D/IN: 0x49, 0x18, 0xfa, 0xbe, 0x35, 0x47, 0xc5, 0x5f,
D/IN: 0xec, 0x77, 0x28, 0x49, 0x42, 0x45, 0x44, 0x64,
D/IN: 0x2c, 0x76, 0x99, 0x9e, 0xd3, 0x43, 0x7e, 0x5b,
D/IN: 0x0f, 0x20, 0x9f, 0x88, 0x03, 0x62, 0xe2, 0x0f,
D/SC: Including MRP parameters
D/IN: Prepared unauthenticated message 0xb400007937ac7e68 to 0x0000000000000000 (0) of type 0x30 and protocolId (0, 0) on exchange 34728i with MessageCounter:1214745443.
D/IN: Sending unauthenticated msg 0xb400007937ac7e68 with MessageCounter:1214745443 to 0x0000000000000000 at monotonic time: 61294175 msec
D/SC: Sent Sigma1 msg
D/CTL: Address resolved for node: 0x0000000000000002
D/BluetoothGatt: onClientConnectionState() - status=19 clientIf=11 device=EE:28:76:1F:86:9B
I/chip.BluetoothManager: MatterTemplate.onConnectionStateChange status = 19, newState=0
D/AndroidBleManager: onConnectionStateChange Disconnected
D/IN: Clearing BLE pending packets.
D/EM: Received message of type 0x31 with protocolId (0, 0) and MessageCounter:1117629974 on exchange 34728i
D/EM: Found matching exchange: 34728i, Delegate: 0xb40000792dd846f0
D/EM: Rxd Ack; Removing MessageCounter:1214745443 from Retrans Table on exchange 34728i
D/EM: Removed CHIP MessageCounter:1214745443 from RetransTable on exchange 34728i
D/SC: Received Sigma2 msg
D/SC: Peer assigned session session ID 2
E/SC: The device does not support GetClock_RealTimeMS() API. This will eventually result in CASE session setup failures.
D/IN: Generating compressed fabric ID using uncompressed fabric ID 0x0000000000000000 and root pubkey
D/IN: 0x04, 0x9e, 0xad, 0x9f, 0x20, 0xb9, 0x5b, 0x5e,
D/IN: 0xc1, 0x85, 0x1f, 0x56, 0x18, 0x21, 0xa5, 0x1f,
D/IN: 0xf8, 0xa0, 0x74, 0x09, 0x29, 0x32, 0x59, 0x78,
D/IN: 0x93, 0x01, 0xc1, 0x97, 0xc3, 0x69, 0xe7, 0xf0,
D/IN: 0x24, 0x59, 0x40, 0x77, 0xde, 0xb1, 0xb5, 0xe4,
D/IN: 0x2d, 0x69, 0x0a, 0xe9, 0x57, 0xc4, 0xc4, 0x6a,
D/IN: 0xbb, 0x90, 0xfc, 0xc4, 0x7c, 0x94, 0xfe, 0x58,
D/IN: 0x75, 0x2d, 0xe7, 0x66, 0x4c, 0xe0, 0xc0, 0x27,
D/IN: 0xed,
D/IN: Generated compressed fabric ID
D/IN: 0x60, 0x0c, 0xde, 0xd1, 0x84, 0xb0, 0x94, 0x4e,
D/SC: Found MRP parameters in the message
D/SC: Sending Sigma3
D/EM: Piggybacking Ack for MessageCounter:1117629974 on exchange: 34728i
D/IN: Prepared unauthenticated message 0xb400007937ac7e68 to 0x0000000000000000 (0) of type 0x32 and protocolId (0, 0) on exchange 34728i with MessageCounter:1214745444.
D/IN: Sending unauthenticated msg 0xb400007937ac7e68 with MessageCounter:1214745444 to 0x0000000000000000 at monotonic time: 61294908 msec
D/SC: Sent Sigma3 msg
D/EM: Received message of type 0x40 with protocolId (0, 0) and MessageCounter:1117629975 on exchange 34728i
D/EM: Found matching exchange: 34728i, Delegate: 0xb40000792dd846f0
D/EM: Rxd Ack; Removing MessageCounter:1214745444 from Retrans Table on exchange 34728i
D/EM: Removed CHIP MessageCounter:1214745444 from RetransTable on exchange 34728i
D/SC: Success status report received. Session was established
D/IN: New secure session created for device 0x0000000000000002, LSID:2 PSID:2!
D/CTL: Calling commissioning complete
D/DMG: ICR moving to [AddingComm]
D/DMG: ICR moving to [AddedComma]
D/IN: Prepared secure message 0xb400007937ac7e68 to 0x0000000000000002 (1) of type 0x8 and protocolId (0, 1) on exchange 34729i with MessageCounter:8755650.
D/IN: Sending encrypted msg 0xb400007937ac7e68 with MessageCounter:8755650 to 0x0000000000000002 (1) at monotonic time: 61295801 msec
D/DMG: ICR moving to [CommandSen]
D/EM: Sending Standalone Ack for MessageCounter:1117629975 on exchange 34728i
D/IN: Prepared unauthenticated message 0x792bbfa470 to 0x0000000000000000 (0) of type 0x10 and protocolId (0, 0) on exchange 34728i with MessageCounter:1214745445.
D/IN: Sending unauthenticated msg 0x792bbfa470 with MessageCounter:1214745445 to 0x0000000000000000 at monotonic time: 61295801 msec
D/EM: Flushed pending ack for MessageCounter:1117629975 on exchange 34728i
D/EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:205528 on exchange 34729i
D/EM: Found matching exchange: 34729i, Delegate: 0xb40000799be26b40
D/EM: Rxd Ack; Removing MessageCounter:8755650 from Retrans Table on exchange 34729i
D/EM: Removed CHIP MessageCounter:8755650 from RetransTable on exchange 34729i
D/DMG: ICR moving to [ResponseRe]
D/DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0005
D/ZCL: CommissioningCompleteResponse:
D/ZCL: errorCode: 0
D/ZCL: debugText:
D/CTL: Received success response 0x0
D/CTL: Rendezvous cleanup
D/ChipDeviceController: Closing GATT and removing connection for 1
D/DMG: ICR moving to [AwaitingDe]
D/EM: Sending Standalone Ack for MessageCounter:205528 on exchange 34729i
D/IN: Prepared secure message 0x792bbfa460 to 0x0000000000000002 (1) of type 0x10 and protocolId (0, 0) on exchange 34729i with MessageCounter:8755651.
D/IN: Sending encrypted msg 0x792bbfa460 with MessageCounter:8755651 to 0x0000000000000002 (1) at monotonic time: 61297246 msec
D/EM: Flushed pending ack for MessageCounter:205528 on exchange 34729i
I/oplus.android.OplusFrameworkFactoryImpl: get feature:IOplusDynamicVsyncFeature
I/oplus.android.OplusFrameworkFactoryImpl: get feature:IOplusDynamicVsyncFeature
I/oplus.android.OplusFrameworkFactoryImpl: get feature:IOplusDynamicVsyncFeature
I/Quality: Skipped: false 8
I/Quality: Skipped: false 2
I/Quality: Skipped: true 2
I/Quality: Skipped: false 1
D/ChipClient: Got connected device pointer
I/Quality: Skipped: false 1
I/Quality: Skipped: false 2
I/Quality: Skipped: false 10
D/ChipClient: Got connected device pointer
I/oplus.android.OplusFrameworkFactoryImpl: get feature:IOplusDynamicVsyncFeature
I/oplus.android.OplusFrameworkFactoryImpl: get feature:IOplusDynamicVsyncFeature
I/oplus.android.OplusFrameworkFactoryImpl: get feature:IOplusDynamicVsyncFeature
D/CompatibilityChangeReporter: Compat change id reported: 163400105; UID 10459; state: DISABLED
D/InputMethodManager: showSoftInput() view=androidx.appcompat.widget.AppCompatAutoCompleteTextView{bfcfc22 VFED..CL. .F.P..ID 42,42-1038,168 #7f080073 app:id/clusterAutoCompleteTv aid=1073741831} flags=0 reason=SHOW_SOFT_INPUT
I/Quality: Skipped: false 4
I/AssistStructure: Flattened final assist data: 2148 bytes, containing 1 windows, 12 views
D/InsetsController: show(ime(), fromIme=true)
D/SurfaceComposerClient: VRR [FRTC] client handle [bufferId:18446744073709551615 framenumber:0] [ffffffff, ffffffff]
V/OplusZoomWindowDecorViewHelper: removeZoomView
D/OpenGLRenderer: endAllActiveAnimators on 0xb40000799bba1800 (DropDownListView) with handle 0xb40000792ddf7960
I/Quality: Skipped: false 3
D/InsetsController: show(ime(), fromIme=true)
D/InputMethodManager: showSoftInput() view=androidx.appcompat.widget.AppCompatAutoCompleteTextView{9a3031b VFED..CL. .F.P..ID 42,168-1038,294 #7f080082 app:id/commandAutoCompleteTv aid=1073741832} flags=0 reason=SHOW_SOFT_INPUT
D/InsetsController: show(ime(), fromIme=true)
D/InsetsController: show(ime(), fromIme=true)
D/SurfaceComposerClient: VRR [FRTC] client handle [bufferId:18446744073709551615 framenumber:0] [ffffffff, ffffffff]
I/Quality: Skipped: false 1
V/OplusZoomWindowDecorViewHelper: removeZoomView
D/OpenGLRenderer: endAllActiveAnimators on 0xb40000799bb7e000 (DropDownListView) with handle 0xb40000792ddf7720
I/Quality: Skipped: false 1
D/InsetsController: show(ime(), fromIme=true)
D/DMG: SendReadRequest ReadClient[0xb40000798eb28520]: Sending Read Request
D/IN: Prepared secure message 0xb400007937ac7e68 to 0x0000000000000002 (1) of type 0x2 and protocolId (0, 1) on exchange 34730i with MessageCounter:8755652.
D/IN: Sending encrypted msg 0xb400007937ac7e68 with MessageCounter:8755652 to 0x0000000000000002 (1) at monotonic time: 61328681 msec
D/DMG: MoveToState ReadClient[0xb40000798eb28520]: Moving to [AwaitingIn]
I/Quality: Skipped: false 3
D/EM: Received message of type 0x5 with protocolId (0, 1) and MessageCounter:205529 on exchange 34730i
D/EM: Found matching exchange: 34730i, Delegate: 0xb40000798eb28520
D/EM: Rxd Ack; Removing MessageCounter:8755652 from Retrans Table on exchange 34730i
D/EM: Removed CHIP MessageCounter:8755652 from RetransTable on exchange 34730i
D/ClusterDetailFragment: chip.clusterinfo.CommandResponseInfo@85763fc=2000
D/EM: Sending Standalone Ack for MessageCounter:205529 on exchange 34730i
D/IN: Prepared secure message 0x792bbfa460 to 0x0000000000000002 (1) of type 0x10 and protocolId (0, 0) on exchange 34730i with MessageCounter:8755653.
D/IN: Sending encrypted msg 0x792bbfa460 with MessageCounter:8755653 to 0x0000000000000002 (1) at monotonic time: 61328960 msec
D/EM: Flushed pending ack for MessageCounter:205529 on exchange 34730i
D/SurfaceComposerClient: VRR [FRTC] client handle [bufferId:18446744073709551615 framenumber:0] [ffffffff, ffffffff]
E/SpannableStringBuilder: SPAN_EXCLUSIVE_EXCLUSIVE spans cannot have a zero length
E/SpannableStringBuilder: SPAN_EXCLUSIVE_EXCLUSIVE spans cannot have a zero length
V/OplusZoomWindowDecorViewHelper: removeZoomView
D/OpenGLRenderer: endAllActiveAnimators on 0xb40000799859cc00 (DropDownListView) with handle 0xb400007937abf300
I/Quality: Skipped: false 2
D/InsetsController: show(ime(), fromIme=true)
D/InputMethodManager: showSoftInput() view=androidx.appcompat.widget.AppCompatEditText{9fd4719 VFED..CL. .F.P..ID 26,13-236,155 #7f08007d app:id/clusterParameterData aid=1073741842} flags=0 reason=SHOW_SOFT_INPUT
I/AssistStructure: Flattened final assist data: 2976 bytes, containing 1 windows, 16 views
D/InsetsController: show(ime(), fromIme=true)
D/InsetsController: show(ime(), fromIme=true)
D/AndroidRuntime: Shutting down VM
E/AndroidRuntime: FATAL EXCEPTION: main
Process: com.google.chip.chiptool, PID: 9582
java.lang.ClassCastException: java.lang.String cannot be cast to java.lang.Integer
at chip.devicecontroller.ClusterWriteMapping.lambda$getWriteAttributeMap$240(ClusterWriteMapping.java:2207)
at chip.devicecontroller.-$$Lambda$ClusterWriteMapping$kZyzl1fD9gWpT-0g6TnjgOfpu2M.invokeCommand(Unknown Source:0)
at com.google.chip.chiptool.clusterclient.clusterinteraction.ClusterDetailFragment.setInvokeCommandOnClickListener$lambda-2(ClusterDetailFragment.kt:151)
at com.google.chip.chiptool.clusterclient.clusterinteraction.ClusterDetailFragment.lambda$L3VHqSpfGvBTNuxjIdwuacnYJ6Y(Unknown Source:0)
at com.google.chip.chiptool.clusterclient.clusterinteraction.-$$Lambda$ClusterDetailFragment$L3VHqSpfGvBTNuxjIdwuacnYJ6Y.onClick(Unknown Source:11)
at android.view.View.performClick(View.java:7482)
at android.view.View.performClickInternal(View.java:7458)
at android.view.View.access$3700(View.java:837)
at android.view.View$PerformClick.run(View.java:28872)
at android.os.Handler.handleCallback(Handler.java:938)
at android.os.Handler.dispatchMessage(Handler.java:99)
at android.os.Looper.loopOnce(Looper.java:233)
at android.os.Looper.loop(Looper.java:344)
at android.app.ActivityThread.main(ActivityThread.java:8184)
at java.lang.reflect.Method.invoke(Native Method)
at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:584)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1034)
I/Process: Sending signal. PID: 9582 SIG: 9
I: nRF5 802154 radio initialized
I: 8 Sectors of 4096 bytes
I: alloc wra: 2, c08
I: data wra: 2, a28
*** Booting Zephyr OS build v2.7.99-ncs1-1 ***
I: Init CHIP stack
uaI: 225 [DL]BLE address: EE:28:76:1F:86:9B
I: SoftDevice Controller build revision:
I: 0e e7 c5 66 67 18 3c ac |...fg.<.
I: b3 d2 cc 81 a3 dc f1 c0 |........
I: c0 36 02 22 |.6."
rt:~$ I: Starting CHIP task
I: Init Thread stack
I: 255 [DL]OpenThread started: OK
I: 260 [DL]Setting OpenThread device type to MINIMAL END DEVICE
I: 266 [ZCL]Using ZAP configuration...
D: 271 [DMG]Failed to read stored attribute (0, 0x0000_002B, 0x0000_0001: a0
D: 279 [DMG]Failed to read stored attribute (0, 0x0000_002C, 0x0000_0000: a0
I: 288 [SVR]Retrieved from server storage: a/0/2c/1
I: 297 [ZCL]Initiating Admin Commissioning cluster.
I: 301 [ZCL]OpCreds: Initiating OpCreds cluster by writing fabrics list from fabric table.
D: 309 [DIS]Set the fabric pairing table delegate
E: 320 [ZCL]Trying to write invalid Calendar Type
D: 332 [DIS]Init fabric pairing table with server storage
D: 345 [IN]UDP::Init bind&listen port=5540
D: 349 [IN]UDP::Init bound to port=5540
D: 353 [IN]TransportMgr initialized
D: 380 [SC]Assigned local session key ID 1
D: 384 [SC]Waiting for PBKDF param request
D: 388 [DL]CHIPoBLE advertising set to on
D: 391 [DIS]DNS-SD StartServer modeHasValue=1 modeValue=1
D: 396 [DL]Using Thread extended MAC for hostname.
I: 401 [DIS]Failed to find a valid admin pairing. Node ID unknown
I: 407 [DIS]Start dns-sd server - no current nodeId
D: 412 [DL]Using Thread extended MAC for hostname.
I: 418 [DIS]Advertise commission parameter vendorID=9050 productID=20052 discriminator=3840/15
E: 426 [DIS]Failed to advertise unprovisioned commissionable node: Error CHIP:0x00000003
D: 434 [DIS]Scheduling Discovery timeout in secs=900
E: 439 [DIS]Failed to finalize service update: Error CHIP:0x0000001C
D: 445 [DIS]DNS-SD StartServer modeHasValue=0 modeValue=0
D: 450 [DL]Using Thread extended MAC for hostname.
I: 455 [DIS]Failed to find a valid admin pairing. Node ID unknown
I: 461 [DIS]Start dns-sd server - no current nodeId
D: 466 [DL]Using Thread extended MAC for hostname.
I: 472 [DIS]Advertise commission parameter vendorID=9050 productID=20052 discriminator=3840/15
E: 480 [DIS]Failed to advertise unprovisioned commissionable node: Error CHIP:0x00000003
D: 488 [DIS]Scheduling Discovery timeout in secs=900
E: 493 [DIS]Failed to finalize service update: Error CHIP:0x0000001C
I: 499 [IN]CASE Server enabling CASE session setups
D: 504 [DL]Using Thread extended MAC for hostname.
I: 509 [SVR]Server Listening...
I: 511 [DL]Device Configuration:
I: 516 [DL] Serial Number: TEST_SN
I: 519 [DL] Vendor Id: 9050 (0x235A)
I: 522 [DL] Product Id: 20052 (0x4E54)
I: 527 [DL] Hardware Version: 0
I: 531 [DL] Setup Pin Code: 20202021
I: 536 [DL] Setup Discriminator: 3840 (0xF00)
I: 542 [DL] Manufacturing Date: (not set)
I: 546 [DL] Device Type: 65535 (0xFFFF)
I: 552 [SVR]SetupQRCode: [MT:CSF25OTB00KA0648G00]
I: 557 [SVR]Copy/paste the below URL in a browser to see the QR Code:
https://dhrishi.github.io/connectedhomeip/qrcode.html?data=MT%3ACSF25OTB00KA0648G00
I: 573 [SVR]Manual pairing code: [34970112332]
I: 580 [SVR]Long manual pairing code: [749701123309050200520]
D: 586 [DL]CHIP task running
I: 593 [DL]CHIPoBLE advertising started
I: 597 [ZCL]GeneralDiagnosticsDelegate: OnDeviceRebooted
I: 13698 [DL]BLE connection established (ConnId: 0x00)
I: 13703 [DL]Current number of connections: 1/1
I: 13708 [DL]CHIPoBLE advertising stopped
D: 14737 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
I: 14743 [BLE]local and remote recv window sizes = 5
I: 14748 [BLE]selected BTP version 4
I: 14752 [BLE]using BTP fragment sizes rx 244 / tx 244.
D: 14827 [DL]ConnId: 0x00, New CCCD value: 0x0001
D: 14832 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 6)
D: 14838 [IN]BLE EndPoint 0x20007588 Connection Complete
I: 14843 [DL]CHIPoBLE connection established (ConnId: 0x00, GATT MTU: 247)
D: 15008 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 15013 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
I: 15019 [EM]Received message of type 0x20 with protocolId (0, 0) and MessageCounter:1214745440 on exchange 34717r
D: 15029 [EM]Handling via exchange: 34717r, Delegate: 0x20004f30
D: 15035 [SC]Received PBKDF param request
D: 15039 [SC]Peer assigned session ID 1
D: 15042 [SC]Found MRP parameters in the message
D: 15047 [SC]Including MRP parameters in PBKDF param response
I: 15273 [IN]Prepared unauthenticated message 0x20027950 to 0x0000000000000000 (0) of type 0x21 and protocolId (0, 0) on exchange 34717r with MessageCounter:1117629971.
I: 15288 [IN]Sending unauthenticated msg 0x20027950 with MessageCounter:1117629971 to 0x0000000000000000 at monotonic time: 15288 msec
D: 15300 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 130)
D: 15306 [SC]Sent PBKDF param response
E: 15310 [DL]Long dispatch time: 297 ms, for event type 16388
D: 15367 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 15412 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
I: 15419 [EM]Received message of type 0x22 with protocolId (0, 0) and MessageCounter:1214745441 on exchange 34717r
D: 15429 [EM]Found matching exchange: 34717r, Delegate: 0x20004f30
D: 15435 [SC]Received spake2p msg1
I: 17442 [IN]Prepared unauthenticated message 0x200278e8 to 0x0000000000000000 (0) of type 0x23 and protocolId (0, 0) on exchange 34717r with MessageCounter:1117629972.
I: 17457 [IN]Sending unauthenticated msg 0x200278e8 with MessageCounter:1117629972 to 0x0000000000000000 at monotonic time: 17457 msec
D: 17469 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 124)
D: 17476 [SC]Sent spake2p msg2
E: 17479 [DL]Long dispatch time: 2066 ms, for event type 16388
D: 17527 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 17572 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
I: 17578 [EM]Received message of type 0x24 with protocolId (0, 0) and MessageCounter:1214745442 on exchange 34717r
D: 17589 [EM]Found matching exchange: 34717r, Delegate: 0x20004f30
D: 17594 [SC]Received spake2p msg3
D: 17598 [SC]Sending status report. Protocol code 0, exchange 34717
I: 17604 [IN]Prepared unauthenticated message 0x20027978 to 0x0000000000000000 (0) of type 0x40 and protocolId (0, 0) on exchange 34717r with MessageCounter:1117629973.
I: 17620 [IN]Sending unauthenticated msg 0x20027978 with MessageCounter:1117629973 to 0x0000000000000000 at monotonic time: 17619 msec
D: 17632 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 27)
D: 17638 [IN]New secure session created for device 0xFFFFFFFB00000000, LSID:1 PSID:1!
I: 17647 [SVR]Commissioning completed session establishment step
D: 17653 [DL]CHIPoBLE advertising set to off
I: 17657 [SVR]Device completed Rendezvous process
D: 17707 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 17713 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
I: 17720 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:5698866 on exchange 34718r
D: 17729 [EM]Handling via exchange: 34718r, Delegate: 0x20006a70
D: 17736 [DMG]Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0000
D: 17743 [DMG]ICR moving to [AddingComm]
D: 17747 [DMG]ICR moving to [AddedComma]
D: 17751 [DMG]Decreasing reference count for CommandHandler, remaining 0
I: 17758 [IN]Prepared secure message 0x200279d8 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 34718r with MessageCounter:9409385.
I: 17772 [IN]Sending encrypted msg 0x200279d8 with MessageCounter:9409385 to 0xFFFFFFFB00000000 (0) at monotonic time: 17772 msec
D: 17784 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 68)
D: 17790 [DMG]ICR moving to [CommandSen]
D: 17794 [DMG]ICR moving to [AwaitingDe]
D: 17842 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 17848 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
I: 17855 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:5698867 on exchange 34719r
D: 17864 [EM]Handling via exchange: 34719r, Delegate: 0x20006a70
D: 17871 [DMG]Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0002
D: 17898 [DMG]ICR moving to [AddingComm]
D: 17901 [DMG]ICR moving to [AddedComma]
D: 17905 [DMG]Decreasing reference count for CommandHandler, remaining 0
I: 17912 [IN]Prepared secure message 0x200279d8 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 34719r with MessageCounter:9409386.
I: 17926 [IN]Sending encrypted msg 0x200279d8 with MessageCounter:9409386 to 0xFFFFFFFB00000000 (0) at monotonic time: 17926 msec
D: 17938 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 68)
D: 17945 [DMG]ICR moving to [CommandSen]
D: 17948 [DMG]ICR moving to [AwaitingDe]
E: 17952 [DL]Long dispatch time: 104 ms, for event type 16388
D: 18022 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 18028 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
I: 18034 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:5698868 on exchange 34720r
D: 18044 [EM]Handling via exchange: 34720r, Delegate: 0x20006a70
D: 18051 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0002
I: 18058 [ZCL]OpCreds: Certificate Chain request received for PAI
D: 18064 [DMG]ICR moving to [AddingComm]
D: 18068 [DMG]ICR moving to [AddedComma]
D: 18072 [DMG]Decreasing reference count for CommandHandler, remaining 0
I: 18081 [IN]Prepared secure message 0x200279d8 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 34720r with MessageCounter:9409387.
I: 18095 [IN]Sending encrypted msg 0x200279d8 with MessageCounter:9409387 to 0xFFFFFFFB00000000 (0) at monotonic time: 18095 msec
D: 18106 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 244)
D: 18114 [DMG]ICR moving to [CommandSen]
D: 18117 [DMG]ICR moving to [AwaitingDe]
D: 18202 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 18207 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 244)
D: 18292 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 18297 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 54)
D: 18382 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 18388 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
I: 18394 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:5698869 on exchange 34721r
D: 18404 [EM]Handling via exchange: 34721r, Delegate: 0x20006a70
D: 18410 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0002
I: 18418 [ZCL]OpCreds: Certificate Chain request received for DAC
D: 18424 [DMG]ICR moving to [AddingComm]
D: 18428 [DMG]ICR moving to [AddedComma]
D: 18432 [DMG]Decreasing reference count for CommandHandler, remaining 0
I: 18441 [IN]Prepared secure message 0x200279d8 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 34721r with MessageCounter:9409388.
I: 18455 [IN]Sending encrypted msg 0x200279d8 with MessageCounter:9409388 to 0xFFFFFFFB00000000 (0) at monotonic time: 18455 msec
D: 18467 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 244)
D: 18474 [DMG]ICR moving to [CommandSen]
D: 18477 [DMG]ICR moving to [AwaitingDe]
D: 18562 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 18567 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 244)
D: 18652 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 18657 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 76)
D: 18743 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 18748 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
I: 18755 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:5698870 on exchange 34722r
D: 18765 [EM]Handling via exchange: 34722r, Delegate: 0x20006a70
D: 18771 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0000
I: 18778 [ZCL]OpCreds: received an AttestationRequest
D: 18816 [DMG]ICR moving to [AddingComm]
D: 18820 [DMG]ICR moving to [AddedComma]
D: 18823 [DMG]Decreasing reference count for CommandHandler, remaining 0
I: 18833 [IN]Prepared secure message 0x200279d8 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 34722r with MessageCounter:9409389.
I: 18847 [IN]Sending encrypted msg 0x200279d8 with MessageCounter:9409389 to 0xFFFFFFFB00000000 (0) at monotonic time: 18847 msec
D: 18858 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 244)
D: 18865 [DMG]ICR moving to [CommandSen]
D: 18869 [DMG]ICR moving to [AwaitingDe]
E: 18872 [DL]Long dispatch time: 124 ms, for event type 16388
D: 18922 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 18927 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 169)
D: 19012 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 19057 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
I: 19064 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:5698871 on exchange 34723r
D: 19074 [EM]Handling via exchange: 34723r, Delegate: 0x20006a70
D: 19080 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0004
I: 19088 [ZCL]OpCreds: commissioner has requested an OpCSR
I: 19460 [ZCL]OpCreds: NewCertificateSigningRequest returned 0
D: 19499 [DMG]ICR moving to [AddingComm]
D: 19502 [DMG]ICR moving to [AddedComma]
D: 19507 [DMG]Decreasing reference count for CommandHandler, remaining 0
I: 19515 [IN]Prepared secure message 0x200279d8 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 34723r with MessageCounter:9409390.
I: 19529 [IN]Sending encrypted msg 0x200279d8 with MessageCounter:9409390 to 0xFFFFFFFB00000000 (0) at monotonic time: 19529 msec
D: 19541 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 244)
D: 19547 [DMG]ICR moving to [CommandSen]
D: 19551 [DMG]ICR moving to [AwaitingDe]
E: 19555 [DL]Long dispatch time: 498 ms, for event type 16388
D: 19567 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 19572 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 134)
D: 19597 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 19628 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
D: 19657 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
I: 19665 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:5698872 on exchange 34724r
D: 19675 [EM]Handling via exchange: 34724r, Delegate: 0x20006a70
D: 19681 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_000B
I: 19689 [ZCL]OpCreds: commissioner has added a trusted root Cert
D: 19695 [DMG]ICR moving to [AddingComm]
D: 19699 [DMG]ICR moving to [AddedComma]
D: 19703 [DMG]Decreasing reference count for CommandHandler, remaining 0
I: 19710 [IN]Prepared secure message 0x200279d8 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 34724r with MessageCounter:9409391.
I: 19724 [IN]Sending encrypted msg 0x200279d8 with MessageCounter:9409391 to 0xFFFFFFFB00000000 (0) at monotonic time: 19724 msec
D: 19736 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 65)
D: 19742 [DMG]ICR moving to [CommandSen]
D: 19746 [DMG]ICR moving to [AwaitingDe]
D: 19763 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 19769 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
D: 19793 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
I: 19800 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:5698873 on exchange 34725r
D: 19810 [EM]Handling via exchange: 34725r, Delegate: 0x20006a70
D: 19817 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0006
I: 19825 [ZCL]OpCreds: commissioner has added a NOC
I: 19831 [DIS]Verifying the received credentials
D: 19897 [IN]Generating compressed fabric ID using uncompressed fabric ID 0x0000000000000000 and root pubkey
D: 19907 [IN]0x04, 0x9e, 0xad, 0x9f, 0x20, 0xb9, 0x5b, 0x5e,
D: 19913 [IN]0xc1, 0x85, 0x1f, 0x56, 0x18, 0x21, 0xa5, 0x1f,
D: 19918 [IN]0xf8, 0xa0, 0x74, 0x09, 0x29, 0x32, 0x59, 0x78,
D: 19924 [IN]0x93, 0x01, 0xc1, 0x97, 0xc3, 0x69, 0xe7, 0xf0,
D: 19930 [IN]0x24, 0x59, 0x40, 0x77, 0xde, 0xb1, 0xb5, 0xe4,
D: 19935 [IN]0x2d, 0x69, 0x0a, 0xe9, 0x57, 0xc4, 0xc4, 0x6a,
D: 19941 [IN]0xbb, 0x90, 0xfc, 0xc4, 0x7c, 0x94, 0xfe, 0x58,
D: 19947 [IN]0x75, 0x2d, 0xe7, 0x66, 0x4c, 0xe0, 0xc0, 0x27,
D: 19952 [IN]0xed,
D: 19955 [IN]Generated compressed fabric ID
D: 19959 [IN]0x60, 0x0c, 0xde, 0xd1, 0x84, 0xb0, 0x94, 0x4e,
I: 19965 [DIS]Added new fabric at index: 1, Initialized: 1
I: 19970 [DIS]Assigned compressed fabric ID: 0x600CDED184B0944E, node ID: 0x0000000000000002
I: 19978 [DIS]Fabric (1) loaded from storage. Calling OnFabricRetrievedFromStorage
I: 19986 [ZCL]OpCreds: Fabric 0x1 was retrieved from storage. FabricId 0x0000000000000000, NodeId 0x0000000000000002, VendorId 0x0000
I: 19998 [ZCL]OpCreds: Call to fabricListChanged
I: 20140 [DIS]Fabric (1) persisted to storage. Calling OnFabricPersistedToStorage
I: 20148 [ZCL]OpCreds: Fabric 1 was persisted to storage. FabricId 0000000000000000, NodeId 0000000000000002, VendorId 0x0000
I: 20159 [ZCL]OpCreds: Call to fabricListChanged
I: 20163 [DIS]Fabric (1) loaded from storage. Calling OnFabricRetrievedFromStorage
I: 20171 [ZCL]OpCreds: Fabric 0x1 was retrieved from storage. FabricId 0x0000000000000000, NodeId 0x0000000000000002, VendorId 0x0000
I: 20183 [ZCL]OpCreds: Call to fabricListChanged
I: 20188 [DIS]Fabric (1) persisted to storage. Calling OnFabricPersistedToStorage
I: 20195 [ZCL]OpCreds: Fabric 1 was persisted to storage. FabricId 0000000000000000, NodeId 0000000000000002, VendorId 0x0000
I: 20207 [ZCL]OpCreds: Call to fabricListChanged
I: 20211 [ZCL]OpCreds: ACL entry created for Fabric 1 CASE Admin NodeId 0x000000000001B669
D: 20219 [DL]Using Thread extended MAC for hostname.
I: 20224 [DIS]Advertise operational node 600CDED184B0944E-0000000000000002
D: 20231 [DMG]ICR moving to [AddingComm]
D: 20235 [DMG]ICR moving to [AddedComma]
I: 20239 [ZCL]OpCreds: successfully added a NOC
D: 20243 [DMG]Decreasing reference count for CommandHandler, remaining 0
I: 20250 [IN]Prepared secure message 0x200279d8 to 0xFFFFFFFB00000000 (1) of type 0x9 and protocolId (0, 1) on exchange 34725r with MessageCounter:9409392.
I: 20264 [IN]Sending encrypted msg 0x200279d8 with MessageCounter:9409392 to 0xFFFFFFFB00000000 (1) at monotonic time: 20264 msec
D: 20276 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 71)
D: 20282 [DMG]ICR moving to [CommandSen]
D: 20286 [DMG]ICR moving to [AwaitingDe]
E: 20290 [DL]Long dispatch time: 498 ms, for event type 16388
D: 20302 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 20317 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
I: 20324 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:5698874 on exchange 34726r
D: 20334 [EM]Handling via exchange: 34726r, Delegate: 0x20006a70
D: 20341 [DMG]Received command for Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0003
D: 20349 [ZCL]AddOrUpdateThreadNetwork: 0
D: 20352 [DMG]ICR moving to [AddingComm]
D: 20356 [DMG]ICR moving to [AddedComma]
D: 20360 [DMG]Decreasing reference count for CommandHandler, remaining 0
I: 20367 [IN]Prepared secure message 0x200279d8 to 0xFFFFFFFB00000000 (1) of type 0x9 and protocolId (0, 1) on exchange 34726r with MessageCounter:9409393.
I: 20381 [IN]Sending encrypted msg 0x200279d8 with MessageCounter:9409393 to 0xFFFFFFFB00000000 (1) at monotonic time: 20381 msec
D: 20393 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 68)
D: 20399 [DMG]ICR moving to [CommandSen]
D: 20403 [DMG]ICR moving to [AwaitingDe]
D: 20422 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
D: 20437 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
I: 20444 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:5698875 on exchange 34727r
D: 20454 [EM]Handling via exchange: 34727r, Delegate: 0x20006a70
D: 20460 [DMG]Received command for Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0006
D: 20487 [DL]Using Thread extended MAC for hostname.
I: 20492 [DIS]Advertise operational node 600CDED184B0944E-0000000000000002
E: 20499 [SVR]Operational advertising enabled
D: 20504 [DMG]ICR moving to [AddingComm]
D: 20507 [DMG]ICR moving to [AddedComma]
D: 20511 [DMG]Decreasing reference count for CommandHandler, remaining 0
I: 20519 [IN]Prepared secure message 0x200279d8 to 0xFFFFFFFB00000000 (1) of type 0x9 and protocolId (0, 1) on exchange 34727r with MessageCounter:9409394.
I: 20533 [IN]Sending encrypted msg 0x200279d8 with MessageCounter:9409394 to 0xFFFFFFFB00000000 (1) at monotonic time: 20533 msec
D: 20545 [DL]Sending notification for CHIPoBLE TX (ConnId 00, len 71)
D: 20552 [DMG]ICR moving to [CommandSen]
D: 20555 [DMG]ICR moving to [AwaitingDe]
E: 20559 [DL]Long dispatch time: 122 ms, for event type 16388
D: 20565 [DL]OpenThread State Changed (Flags: 0x1006c100)
D: 20570 [DL] Network Name: OpenThread
D: 20574 [DL] PAN Id: 0x1234
D: 20577 [DL] Extended PAN Id: 0x1111111122222222
D: 20582 [DL] Channel: 15
D: 20584 [DL] Mesh Prefix: fdde:ad00:beef::/64
D: 20590 [DL]OpenThread State Changed (Flags: 0x1100101d)
D: 20595 [DL] Device Role: DETACHED
D: 20598 [DL] Thread Unicast Addresses:
D: 20602 [DL] fdde:ad00:beef:0:a056:5e82:18b9:6b3e/64 valid
D: 20609 [DL] fe80::b0d2:6b38:e28:c06c/64 valid preferred
D: 20615 [DL]Notification for CHIPoBLE TX done (ConnId 0x00)
I: 21718 [DL]SRP Client was started, detected server: fdaf:9c27:ea3a:72b9:65b3:3542:5f36:f973
D: 21728 [DL]OpenThread State Changed (Flags: 0x301132b7)
D: 21733 [DL] Device Role: CHILD
D: 21736 [DL] Network Name: OpenThread-e95e
D: 21740 [DL] PAN Id: 0x1234
D: 21744 [DL] Extended PAN Id: 0x1111111122222222
D: 21748 [DL] Channel: 15
D: 21751 [DL] Mesh Prefix: fdaf:9c27:ea3a:72b9::/64
D: 21756 [DL] Partition Id: 0x190AF261
D: 21760 [DL] Thread Unicast Addresses:
D: 21764 [DL] fd50:a5b4:c22b:8c99:3550:c09b:50af:b697/64 valid preferred
D: 21771 [DL] fdaf:9c27:ea3a:72b9:0:ff:fe00:7815/64 valid rloc
D: 21777 [DL] fdaf:9c27:ea3a:72b9:a056:5e82:18b9:6b3e/64 valid
D: 21784 [DL] fe80::b0d2:6b38:e28:c06c/64 valid preferred
E: 22029 [DL]Long dispatch time: 301 ms, for event type 32780
D: 22035 [DL]OpenThread State Changed (Flags: 0x00000001)
D: 22041 [DL] Thread Unicast Addresses:
D: 22045 [DL] fd50:a5b4:c22b:8c99:3550:c09b:50af:b697/64 valid preferred
D: 22052 [DL] fdaf:9c27:ea3a:72b9:0:ff:fe00:7815/64 valid rloc
D: 22059 [DL] fdaf:9c27:ea3a:72b9:a056:5e82:18b9:6b3e/64 valid
D: 22065 [DL] fe80::b0d2:6b38:e28:c06c/64 valid preferred
I: 22202 [DL]OnSrpClientNotification: Last requested operation completed successfully
D: 22210 [DIS]DNS-SD StartServer modeHasValue=0 modeValue=0
D: 22216 [DL]Using Thread extended MAC for hostname.
I: 22221 [DIS]Advertise operational node 600CDED184B0944E-0000000000000002
I: 22228 [DL]advertising srp service: 600CDED184B0944E-0000000000000002._matter._tcp
I: 22236 [DIS]Have operational credentials
E: 22242 [DIS]Failed to get extended timeout configuration err: Error CHIP:0x000000A0
D: 22289 [DIS]GetExtendedDiscoveryTimeoutSecs -1
D: 22293 [DL]Using Thread extended MAC for hostname.
I: 22301 [DIS]Advertise commission parameter vendorID=9050 productID=20052 discriminator=3840/15
I: 22311 [DL]advertising srp service: DD334A5BCDBEBAAC._matterc._udp
E: 22320 [DIS]Failed to get extended timeout configuration err: Error CHIP:0x000000A0
D: 22368 [DIS]GetExtendedDiscoveryTimeoutSecs -1
E: 22373 [DL]Long dispatch time: 163 ms, for event type 32786
D: 23092 [DL]Write request received for CHIPoBLE RX (ConnId 0x00)
I: 23187 [DL]OnSrpClientNotification: Last requested operation completed successfully
I: 23782 [EM]Received message of type 0x30 with protocolId (0, 0) and MessageCounter:1214745443 on exchange 34728r
D: 23792 [EM]Handling via exchange: 34728r, Delegate: 0x200035dc
I: 23799 [IN]CASE Server received Sigma1 message. Starting handshake. EC 0x20004948
I: 23806 [DIS]CASE handshake initiated, closing all BLE Connections
D: 23813 [IN]Clearing BLE pending packets.
I: 23816 [BLE]Releasing end point's BLE connection back to application.
I: 23823 [DL]Closing BLE GATT connection (ConnId 00)
D: 23828 [SC]Waiting for Sigma1 msg
I: 23832 [IN]CASE Server disabling CASE session setups
D: 23836 [SC]Received Sigma1 msg
D: 23839 [SC]Found MRP parameters in the message
D: 23844 [SC]Peer assigned session key ID 2
I: 23848 [DIS]Fabric (1) loaded from storage. Calling OnFabricRetrievedFromStorage
I: 23856 [ZCL]OpCreds: Fabric 0x1 was retrieved from storage. FabricId 0x0000000000000000, NodeId 0x0000000000000002, VendorId 0x0000
I: 23868 [ZCL]OpCreds: Call to fabricListChanged
D: 23873 [IN]Generating DestinationID. Fabric ID 0x0000000000000000, Dest node ID 0x0000000000000002, Random data
D: 23883 [IN]0x05, 0xa0, 0x36, 0x77, 0x84, 0xb2, 0xb7, 0xbe,
D: 23889 [IN]0x50, 0x97, 0xd4, 0xf3, 0xee, 0x4b, 0x17, 0xbe,
D: 23895 [IN]0x23, 0xa8, 0xa4, 0x27, 0xcd, 0x41, 0xe3, 0x26,
D: 23900 [IN]0x5a, 0x75, 0x36, 0x6c, 0x3d, 0x04, 0xb7, 0x85,
D: 23906 [IN]Root pubkey
D: 23908 [IN]0x04, 0x9e, 0xad, 0x9f, 0x20, 0xb9, 0x5b, 0x5e,
D: 23914 [IN]0xc1, 0x85, 0x1f, 0x56, 0x18, 0x21, 0xa5, 0x1f,
D: 23919 [IN]0xf8, 0xa0, 0x74, 0x09, 0x29, 0x32, 0x59, 0x78,
D: 23925 [IN]0x93, 0x01, 0xc1, 0x97, 0xc3, 0x69, 0xe7, 0xf0,
D: 23931 [IN]0x24, 0x59, 0x40, 0x77, 0xde, 0xb1, 0xb5, 0xe4,
D: 23936 [IN]0x2d, 0x69, 0x0a, 0xe9, 0x57, 0xc4, 0xc4, 0x6a,
D: 23942 [IN]0xbb, 0x90, 0xfc, 0xc4, 0x7c, 0x94, 0xfe, 0x58,
D: 23948 [IN]0x75, 0x2d, 0xe7, 0x66, 0x4c, 0xe0, 0xc0, 0x27,
D: 23953 [IN]0xed,
D: 23955 [IN]IPK
D: 23957 [IN]0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
D: 23962 [IN]0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
D: 23968 [IN]Generated DestinationID output
D: 23972 [IN]0x49, 0x18, 0xfa, 0xbe, 0x35, 0x47, 0xc5, 0x5f,
D: 23978 [IN]0xec, 0x77, 0x28, 0x49, 0x42, 0x45, 0x44, 0x64,
D: 23983 [IN]0x2c, 0x76, 0x99, 0x9e, 0xd3, 0x43, 0x7e, 0x5b,
D: 23989 [IN]0x0f, 0x20, 0x9f, 0x88, 0x03, 0x62, 0xe2, 0x0f,
I: 23995 [DIS]Fabric (1) loaded from storage. Calling OnFabricRetrievedFromStorage
I: 24002 [ZCL]OpCreds: Fabric 0x1 was retrieved from storage. FabricId 0x0000000000000000, NodeId 0x0000000000000002, VendorId 0x0000
I: 24014 [ZCL]OpCreds: Call to fabricListChanged
D: 24244 [SC]Including MRP parameters
I: 24248 [IN]Prepared unauthenticated message 0x20004864 to 0x0000000000000000 (0) of type 0x31 and protocolId (0, 0) on exchange 34728r with MessageCounter:1117629974.
I: 24263 [IN]Sending unauthenticated msg 0x20004864 with MessageCounter:1117629974 to 0x0000000000000000 at monotonic time: 24263 msec
D: 24276 [SC]Sent Sigma2 msg
I: 24280 [DL]BLE GAP connection terminated (reason 0x16)
I: 24285 [DL]Current number of connections: 0/1
I: 24646 [EM]Received message of type 0x32 with protocolId (0, 0) and MessageCounter:1214745444 on exchange 34728r
D: 24656 [EM]Found matching exchange: 34728r, Delegate: 0x200035e8
D: 24662 [EM]Rxd Ack; Removing MessageCounter:1117629974 from Retrans Table on exchange 34728r
D: 24671 [EM]Removed CHIP MessageCounter:1117629974 from RetransTable on exchange 34728r
D: 24679 [SC]Received Sigma3 msg
E: 24685 [SC]The device does not support GetClock_RealTimeMS() API. This will eventually result in CASE session setup failures.
D: 24759 [IN]Generating compressed fabric ID using uncompressed fabric ID 0x0000000000000000 and root pubkey
D: 24768 [IN]0x04, 0x9e, 0xad, 0x9f, 0x20, 0xb9, 0x5b, 0x5e,
D: 24774 [IN]0xc1, 0x85, 0x1f, 0x56, 0x18, 0x21, 0xa5, 0x1f,
D: 24780 [IN]0xf8, 0xa0, 0x74, 0x09, 0x29, 0x32, 0x59, 0x78,
D: 24785 [IN]0x93, 0x01, 0xc1, 0x97, 0xc3, 0x69, 0xe7, 0xf0,
D: 24791 [IN]0x24, 0x59, 0x40, 0x77, 0xde, 0xb1, 0xb5, 0xe4,
D: 24797 [IN]0x2d, 0x69, 0x0a, 0xe9, 0x57, 0xc4, 0xc4, 0x6a,
D: 24802 [IN]0xbb, 0x90, 0xfc, 0xc4, 0x7c, 0x94, 0xfe, 0x58,
D: 24808 [IN]0x75, 0x2d, 0xe7, 0x66, 0x4c, 0xe0, 0xc0, 0x27,
D: 24813 [IN]0xed,
D: 24816 [IN]Generated compressed fabric ID
D: 24820 [IN]0x60, 0x0c, 0xde, 0xd1, 0x84, 0xb0, 0x94, 0x4e,
D: 24885 [SC]Sending status report. Protocol code 0, exchange 34728
I: 24891 [IN]Prepared unauthenticated message 0x20004864 to 0x0000000000000000 (0) of type 0x40 and protocolId (0, 0) on exchange 34728r with MessageCounter:1117629975.
I: 24906 [IN]Sending unauthenticated msg 0x20004864 with MessageCounter:1117629975 to 0x0000000000000000 at monotonic time: 24906 msec
I: 24919 [IN]CASE Session established. Setting up the secure channel.
D: 24926 [IN]New secure session created for device 0x000000000001B669, LSID:2 PSID:2!
I: 24935 [IN]CASE secure channel is available now.
I: 24939 [IN]CASE Server enabling CASE session setups
I: 25411 [EM]Received message of type 0x8 with protocolId (0, 1) and MessageCounter:8755650 on exchange 34729r
D: 25422 [EM]Handling via exchange: 34729r, Delegate: 0x20006a70
D: 25428 [DMG]Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0004
D: 25436 [DMG]ICR moving to [AddingComm]
D: 25440 [DMG]ICR moving to [AddedComma]
D: 25443 [DMG]Decreasing reference count for CommandHandler, remaining 0
I: 25451 [IN]Prepared secure message 0x2000487c to 0x000000000001B669 (1) of type 0x9 and protocolId (0, 1) on exchange 34729r with MessageCounter:205528.
I: 25465 [IN]Sending encrypted msg 0x2000487c with MessageCounter:205528 to 0x000000000001B669 (1) at monotonic time: 25464 msec
D: 25477 [DMG]ICR moving to [CommandSen]
D: 25481 [DMG]ICR moving to [AwaitingDe]
I: 25485 [SVR]Commissioning completed successfully
D: 25490 [DIS]DNS-SD StartServer modeHasValue=1 modeValue=0
D: 25495 [DL]Using Thread extended MAC for hostname.
I: 25500 [DIS]Advertise operational node 600CDED184B0944E-0000000000000002
I: 25507 [DL]advertising srp service: 600CDED184B0944E-0000000000000002._matter._tcp
I: 25514 [DIS]Have operational credentials
E: 25559 [DIS]Failed to get extended timeout configuration err: Error CHIP:0x000000A0
D: 25568 [DIS]GetExtendedDiscoveryTimeoutSecs -1
D: 25572 [DL]Using Thread extended MAC for hostname.
I: 25581 [DIS]Advertise commission parameter vendorID=9050 productID=20052 discriminator=3840/15
I: 25591 [DL]advertising srp service: DD334A5BCDBEBAAC._matterc._udp
E: 25640 [DIS]Failed to get extended timeout configuration err: Error CHIP:0x000000A0
D: 25648 [DIS]GetExtendedDiscoveryTimeoutSecs -1
E: 25652 [DL]Long dispatch time: 167 ms, for event type 32784
I: 25659 [EM]Received message of type 0x10 with protocolId (0, 0) and MessageCounter:1214745445 on exchange 34728r
D: 25669 [EM]Found matching exchange: 34728r, Delegate: (nil)
D: 25675 [EM]Rxd Ack; Removing MessageCounter:1117629975 from Retrans Table on exchange 34728r
D: 25684 [EM]Removed CHIP MessageCounter:1117629975 from RetransTable on exchange 34728r
I: 25845 [DL]OnSrpClientNotification: Last requested operation completed successfully
I: 26933 [EM]Received message of type 0x10 with protocolId (0, 0) and MessageCounter:8755651 on exchange 34729r
D: 26943 [EM]Found matching exchange: 34729r, Delegate: (nil)
D: 26948 [EM]Rxd Ack; Removing MessageCounter:205528 from Retrans Table on exchange 34729r
D: 26956 [EM]Removed CHIP MessageCounter:205528 from RetransTable on exchange 34729r
I: 58406 [EM]Received message of type 0x2 with protocolId (0, 1) and MessageCounter:8755652 on exchange 34730r
D: 58416 [EM]Handling via exchange: 34730r, Delegate: 0x20006a70
D: 58422 [IM]Received Read request
D: 58425 [DMG]IM RH moving to [Initialized]
D: 58429 [DMG]IM RH moving to [GeneratingReports]
D: 58434 [DMG]<RE:Run> Cluster 201, Attribute 12 is dirty
D: 58439 [DMG]Reading attribute: Cluster=0x0000_0201 Endpoint=1 AttributeId=0x0000_0012 (expanded=0)
D: 58448 [DMG]<RE> Sending report (payload has 32 bytes)...
I: 58454 [IN]Prepared secure message 0x20004864 to 0x000000000001B669 (1) of type 0x5 and protocolId (0, 1) on exchange 34730r with MessageCounter:205529.
I: 58468 [IN]Sending encrypted msg 0x20004864 with MessageCounter:205529 to 0x000000000001B669 (1) at monotonic time: 58468 msec
D: 58481 [DMG]<RE> OnReportConfirm: NumReports = 0
D: 58485 [DMG]<RE> ReportsInFlight = 0 with readHandler 0, RE has no more messages
D: 58493 [DMG]IM RH moving to [Uninitialized]
I: 58518 [EM]Received message of type 0x10 with protocolId (0, 0) and MessageCounter:8755653 on exchange 34730r
D: 58528 [EM]Found matching exchange: 34730r, Delegate: (nil)
D: 58534 [EM]Rxd Ack; Removing MessageCounter:205529 from Retrans Table on exchange 34730r
D: 58542 [EM]Removed CHIP MessageCounter:205529 from RetransTable on exchange 34730r
05/12 08:18:40: Launching 'app' on OnePlus LE2123.
Install successfully finished in 72 ms.
$ adb shell am start -n "com.google.chip.chiptool/com.google.chip.chiptool.CHIPToolActivity" -a android.intent.action.MAIN -c android.intent.category.LAUNCHER -D
Waiting for application to come online: com.google.chip.chiptool
Connected to process 27090 on device 'oneplus-le2123-ddd7afb3'.
Connecting to com.google.chip.chiptool
Connected to the target VM, address: 'localhost:44475', transport: 'socket'
Capturing and displaying logcat messages from application. This behavior can be disabled in the "Logcat output" section of the "Debugger" settings page.
I/e.chip.chiptoo: Late-enabling -Xcheck:jni
E/e.chip.chiptoo: Unknown bits set in runtime_flags: 0x40000000
D/ProcessState: Binder ioctl to enable oneway spam detection failed: Invalid argument
I/OneTrace: Mark active for pid=27090? true
D/ColorModeChangeItem: preExecute mColorMode=0,token=android.os.BinderProxy@eb8e0bc
V/studio.deploy: Startup agent attached to VM
V/studio.deploy: No existing instrumentation found. Loading instrumentation from instruments-88564b4d.jar
W/e.chip.chiptoo: DexFile /data/data/com.google.chip.chiptool/code_cache/.studio/instruments-88564b4d.jar is in boot class path but is not in a known location
V/studio.deploy: Applying transforms with cached classes
W/e.chip.chiptoo: Redefining intrinsic method java.lang.Thread java.lang.Thread.currentThread(). This may cause the unexpected use of the original definition of java.lang.Thread java.lang.Thread.currentThread()in methods that have already been compiled.
W/e.chip.chiptoo: Redefining intrinsic method boolean java.lang.Thread.interrupted(). This may cause the unexpected use of the original definition of boolean java.lang.Thread.interrupted()in methods that have already been compiled.
D/CompatibilityChangeReporter: Compat change id reported: 171979766; UID 10454; state: DISABLED
I/oplus.android.OplusFrameworkFactoryImpl: get feature:IOplusAutoResolutionFeature
I/oplus.android.OplusFrameworkFactoryImpl: getOplusAutoResolutionFeature
W/ActivityThread: Application com.google.chip.chiptool is waiting for the debugger on port 8100...
I/System.out: Sending WAIT chunk
I/System.out: Debugger has connected
I/System.out: waiting for debugger to settle...
I/System.out: waiting for debugger to settle...
I/System.out: waiting for debugger to settle...
I/System.out: waiting for debugger to settle...
I/System.out: waiting for debugger to settle...
W/System: A resource failed to call close.
I/System.out: waiting for debugger to settle...
I/System.out: waiting for debugger to settle...
I/System.out: waiting for debugger to settle...
I/System.out: waiting for debugger to settle...
I/System.out: debugger has settled (1470)
I/Quality: LaunchTime2.0: com.google.chip.chiptool createOrUpdateClassLoaderLocked took time: 138
V/GraphicsEnvironment: ANGLE Developer option for 'com.google.chip.chiptool' set to: 'default'
V/GraphicsEnvironment: App is not on the allowlist for updatable production driver.
D/NetworkSecurityConfig: No Network Security Config specified, using platform default
D/NetworkSecurityConfig: No Network Security Config specified, using platform default
I/Quality: BindApplication: com.google.chip.chiptool
E/ANR_LOG: >>> msg's executing time is too long
E/ANR_LOG: Blocked msg = { when=-3s62ms what=110 target=android.app.ActivityThread$H obj=AppBindData{appInfo=ApplicationInfo{412baa7 com.google.chip.chiptool}} } , cost = 3047 ms
E/ANR_LOG: >>>Current msg List is:
E/ANR_LOG: Current msg <1> = { when=-3s60ms what=159 target=android.app.ActivityThread$H obj=android.app.servertransaction.ClientTransaction@f1c990fe }
E/ANR_LOG: Current msg <2> = { when=-3s60ms what=159 target=android.app.ActivityThread$H obj=android.app.servertransaction.ClientTransaction@9fbf460c }
E/ANR_LOG: Current msg <3> = { when=-2s783ms what=149 target=android.app.ActivityThread$H obj=android.os.BinderProxy@eb8e0bc }
E/ANR_LOG: Current msg <4> = { when=-2s60ms what=0 target=android.app.ActivityThread$H callback=android.app.ActivityThread$$ExternalSyntheticLambda1 }
E/ANR_LOG: Current msg <5> = { when=-26ms what=164 target=android.app.ActivityThread$H obj=com.google.chip.chiptool }
E/ANR_LOG: >>>CURRENT MSG DUMP OVER<<<
E/e.chip.chiptoo: Loaded layer handle (4791125641850237837) for layer /my_product/lib64/libcolorx-loader.so
E/e.chip.chiptoo: Looking for entrypoint ColorX_Check
E/e.chip.chiptoo: Found ColorX_Check for /my_product/lib64/libcolorx-loader.so
E/e.chip.chiptoo: Check failed
D/CompatibilityChangeReporter: Compat change id reported: 160794467; UID 10454; state: DISABLED
I/oplus.android.OplusFrameworkFactoryImpl: Unknow feature:IOplusTextViewRTLUtilForUG
D/ScrollOptimizationHelper: can't find the config file for optimizaiton
D/ScrollOptimizationHelper: will not debug for debug is false
I/oplus.android.OplusFrameworkFactoryImpl: get feature:IOplusDynamicVsyncFeature
I/oplus.android.OplusFrameworkFactoryImpl: get feature:IOplusDynamicVsyncFeature
I/oplus.android.OplusFrameworkFactoryImpl: get feature:IOplusDynamicVsyncFeature
W/e.chip.chiptoo: Accessing hidden method Landroid/view/View;->computeFitSystemWindows(Landroid/graphics/Rect;Landroid/graphics/Rect;)Z (unsupported, reflection, allowed)
W/e.chip.chiptoo: Accessing hidden method Landroid/view/ViewGroup;->makeOptionalFitsSystemWindows()V (unsupported, reflection, allowed)
E/OplusCustomizeRestrictionManager: sInstance is null, start a new sInstance
D/OplusInputMethodUtil: init DEBUG to false, update DEBUG_IME to false
D/OplusInputMethodUtil: init DEBUG to false, update DEBUG_IME to false
I/OplusFeatureCache: Milliseconds spent on init(): 128
D/OplusSlideAnimOptHelper: com.google.chip.chiptool scrollEffectOpt enable = false
D/ExtensionsLoader: createInstance(64bit) : createExtendedFactory
E/ExtensionsLoader: dlopen failed: library "libhwuiextimpl.so" not found
I/Quality: Skipped: false 2
V/OplusZoomWindowDecorViewHelper: setLastReportedMergedConfiguration mZoomDisplayHeight: 2412 getDecorView.86310486
I/AdrenoGLES-0: QUALCOMM build : 3b0ebcfc5c, I200588c14c
Build Date : 10/27/21
OpenGL ES Shader Compiler Version: EV031.35.01.03
Local Branch :
Remote Branch :
Remote Branch :
Reconstruct Branch :
I/AdrenoGLES-0: Build Config : S P 10.0.7 AArch64
I/AdrenoGLES-0: Driver Path : /vendor/lib64/egl/libGLESv2_adreno.so
I/AdrenoGLES-0: PFP: 0x016dc094, ME: 0x00000000
D/hw-ProcessState: Binder ioctl to enable oneway spam detection failed: Invalid argument
D/SurfaceComposerClient: VRR [FRTC] client handle [bufferId:18446744073709551615 framenumber:0] [ffffffff, ffffffff]
I/Choreographer: Skipped 31 frames! The application may be doing too much work on its main thread.
I/Quality: Skipped: false 31
I/Quality: Skipped: false 4
I/Quality: Skipped: false 2
I/Quality: Skipped: true 2
I/Quality: Skipped: true 2
I/Quality: Skipped: true 1
I/Quality: Skipped: false 2
I/Quality: Skipped: false 1
W/DynamiteModule: Local module descriptor class for com.google.android.gms.vision.dynamite.barcode not found.
I/DynamiteModule: Considering local module com.google.android.gms.vision.dynamite.barcode:0 and remote module com.google.android.gms.vision.dynamite.barcode:0
D/BarcodeNativeHandle: Cannot load feature, fall back to load dynamite module.
W/e.chip.chiptoo: Unsupported class loader
W/e.chip.chiptoo: Unsupported class loader
I/DynamiteModule: Considering local module com.google.android.gms.vision.barcode:0 and remote module com.google.android.gms.vision.barcode:1
I/DynamiteModule: Selected remote version of com.google.android.gms.vision.barcode, version >= 1
V/DynamiteModule: Dynamite loader version >= 2, using loadModule2NoCrashUtils
I/DynamiteLoaderV2Impl: [71] com.google.android.gms.vision.barcode
I/Choreographer: Skipped 43 frames! The application may be doing too much work on its main thread.
I/Quality: Skipped: false 43
W/libc: Access denied finding property "vendor.camera.aux.packagelist"
I/CameraExtImpl: getInstance success!
D/OplusCameraUtils: new OplusCameraUtils!
W/libc: Access denied finding property "vendor.camera.aux.packagelist"
W/libc: Access denied finding property "vendor.camera.aux.packagelist"
I/OplusCameraUtils: current activityName: com.google.chip.chiptool.CHIPToolActivity
I/OplusCameraUtils: getComponentName, componentName: com.google.chip.chiptool/com.google.chip.chiptool.CHIPToolActivity, packageName:com.google.chip.chiptool, activityName:com.google.chip.chiptool.CHIPToolActivity
D/OplusCameraStatisticsManager: addInfo, eventMap: {halLevel=1, cameraId=0, pkgName=com.google.chip.chiptool, connentTime=1652336357515, apLevel=1}
W/libc: Access denied finding property "vendor.camera.aux.packagelist"
I/OpenGLRenderer: Davey! duration=715ms; Flags=0, FrameTimelineVsyncId=3343802, IntendedVsync=58920645938228, Vsync=58921004271547, InputEventId=0, HandleInputStart=58921012974657, AnimationStart=58921012991689, PerformTraversalsStart=58921014229866, DrawStart=58921346890386, FrameDeadline=58920678271560, FrameInterval=58921012576793, FrameStartTime=16666666, SyncQueued=58921359602314, SyncStart=58921359634970, IssueDrawCommandsStart=58921359873251, SwapBuffers=58921361047001, FrameCompleted=58921361764970, DequeueBufferDuration=8281, QueueBufferDuration=393750, GpuCompleted=58921361764970, SwapBuffersCompleted=58921361764970, DisplayPresentTime=0,
I/Choreographer: Skipped 41 frames! The application may be doing too much work on its main thread.
I/Quality: Skipped: false 41
E/Parcel: Reading a NULL string not supported here.
D/SurfaceComposerClient: VRR [FRTC] client handle [bufferId:18446744073709551615 framenumber:0] [ffffffff, ffffffff]
D/OplusCameraStatisticsManager: addPreviewInfo, eventMap: {halLevel=1, preview_time=4189, face_count=-1, pkgName=com.google.chip.chiptool, camera_id=0, width=1024, apLevel=1, height=768}
D/Camera: app passed NULL surface
D/OplusCameraStatisticsManager: addInfo, eventMap: {halLevel=1, cameraId=0, disconnectTime=1652336361819, pkgName=com.google.chip.chiptool, connentTime=1652336357515, apLevel=1, timeCost=4304}
D/SPL: JNI_OnLoad() called
D/CompatibilityChangeReporter: Compat change id reported: 171228096; UID 10454; state: ENABLED
I/oplus.android.OplusFrameworkFactoryImpl: get feature:IOplusDynamicVsyncFeature
I/oplus.android.OplusFrameworkFactoryImpl: get feature:IOplusDynamicVsyncFeature
I/oplus.android.OplusFrameworkFactoryImpl: get feature:IOplusDynamicVsyncFeature
I/Quality: Skipped: false 1
I/Quality: Skipped: false 4
I/Quality: Skipped: false 4
D/CTL: JNI_OnLoad() called
D/CTL: Loading Java class references.
D/CTL: Java class references loaded.
D/DL: AndroidChipPlatform JNI_OnLoad() called
E/SPT: JavaVM is already set
D/DL: Loading Java class references.
D/DL: Java class references loaded.
D/CompatibilityChangeReporter: Compat change id reported: 191844585; UID 10454; state: DISABLED
D/KeyValueStoreManager: Key 'chip-config:fail-safe-armed' not found in shared preferences
E/DL: Java exception in AndroidConfig::readConfigValueLong
W/System.err: chip.platform.AndroidChipPlatformException
W/System.err: at chip.platform.PreferencesConfigurationManager.readConfigValueLong(PreferencesConfigurationManager.java:95)
W/System.err: at chip.platform.AndroidChipPlatform.initChipStack(Native Method)
W/System.err: at chip.platform.AndroidChipPlatform.<init>(AndroidChipPlatform.java:37)
W/System.err: at com.google.chip.chiptool.ChipClient.getAndroidChipPlatform(ChipClient.kt:54)
W/System.err: at com.google.chip.chiptool.ChipClient.getDeviceController(ChipClient.kt:42)
W/System.err: at com.google.chip.chiptool.provisioning.DeviceProvisioningFragment$startConnectingToDevice$1.invokeSuspend(DeviceProvisioningFragment.kt:100)
W/System.err: at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
W/System.err: at kotlinx.coroutines.DispatchedKt.resumeCancellable(Dispatched.kt:457)
W/System.err: at kotlinx.coroutines.intrinsics.CancellableKt.startCoroutineCancellable(Cancellable.kt:26)
W/System.err: at kotlinx.coroutines.CoroutineStart.invoke(CoroutineStart.kt:109)
W/System.err: at kotlinx.coroutines.AbstractCoroutine.start(AbstractCoroutine.kt:154)
W/System.err: at kotlinx.coroutines.BuildersKt__Builders_commonKt.launch(Builders.common.kt:54)
W/System.err: at kotlinx.coroutines.BuildersKt.launch(Unknown Source:1)
W/System.err: at kotlinx.coroutines.BuildersKt__Builders_commonKt.launch$default(Builders.common.kt:47)
W/System.err: at kotlinx.coroutines.BuildersKt.launch$default(Unknown Source:1)
W/System.err: at com.google.chip.chiptool.provisioning.DeviceProvisioningFragment.startConnectingToDevice(DeviceProvisioningFragment.kt:99)
W/System.err: at com.google.chip.chiptool.provisioning.DeviceProvisioningFragment.onCreateView(DeviceProvisioningFragment.kt:66)
W/System.err: at androidx.fragment.app.Fragment.performCreateView(Fragment.java:2950)
W/System.err: at androidx.fragment.app.FragmentStateManager.createView(FragmentStateManager.java:518)
W/System.err: at androidx.fragment.app.FragmentStateManager.moveToExpectedState(FragmentStateManager.java:277)
W/System.err: at androidx.fragment.app.FragmentManager.executeOpsTogether(FragmentManager.java:2177)
W/System.err: at androidx.fragment.app.FragmentManager.removeRedundantOperationsAndExecute(FragmentManager.java:2088)
W/System.err: at androidx.fragment.app.FragmentManager.execPendingActions(FragmentManager.java:1990)
W/System.err: at androidx.fragment.app.FragmentManager$5.run(FragmentManager.java:524)
W/System.err: at android.os.Handler.handleCallback(Handler.java:938)
W/System.err: at android.os.Handler.dispatchMessage(Handler.java:99)
W/System.err: at android.os.Looper.loopOnce(Looper.java:233)
W/System.err: at android.os.Looper.loop(Looper.java:344)
W/System.err: at android.app.ActivityThread.main(ActivityThread.java:8184)
W/System.err: at java.lang.reflect.Method.invoke(Native Method)
W/System.err: at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:584)
W/System.err: at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1034)
D/CTL: newDeviceController() called
D/CTL: Setting attestation nonce to random value
D/CTL: Setting CSR nonce to random value
D/TOO: KVS: Getting key AndroidDeviceControllerKey
D/TOO: KVS: Getting key AndroidCARootCert1
D/CTL: Generating NOC
D/IN: UDP::Init bind&listen port=5541
D/IN: UDP::Init bound to port=5541
D/IN: UDP::Init bind&listen port=5541
D/IN: UDP::Init bound to port=5541
D/IN: BLEBase::Init - setting/overriding transport
D/IN: TransportMgr initialized
D/DIS: Init fabric pairing table with server storage
D/TOO: KVS: Getting key g/fidx
D/IN: Loading from storage for fabric index 0x1
D/TOO: KVS: Getting key f/1/r
D/TOO: KVS: Getting key f/1/i
D/KeyValueStoreManager: Key 'f/1/i' not found in shared preferences
D/TOO: KVS: Getting key f/1/n
D/TOO: KVS: Getting key f/1/o
D/TOO: KVS: Getting key f/1/m
D/DIS: Add fabric pairing table delegate
D/TOO: KVS: Getting key g/gcc
D/TOO: KVS: Getting key g/gdc
D/TOO: KVS: Setting key g/gcc
D/TOO: KVS: Setting key g/gdc
D/ZCL: Using ZAP configuration...
D/CTL: System State Initialized...
D/CTL: Intermediate CA is not needed
D/DIS: Verifying the received credentials
D/DIS: Added new fabric at index: 0x1, Initialized: 1
D/DIS: Assigned compressed fabric ID: 0xA5069F16D24C8318, node ID: 0x000000000001B669
D/CTL: Joined the fabric at index 1. Compressed fabric ID is: 0xA5069F16D24C8318
D/SPT: Setting up group data for Fabric Index 1 with Compressed Fabric ID:
D/SPT: 0xa5, 0x06, 0x9f, 0x16, 0xd2, 0x4c, 0x83, 0x18,
D/TOO: KVS: Getting key f/1/g
D/TOO: KVS: Getting key f/1/k/0
D/TOO: KVS: Setting key f/1/k/0
D/CTL: IO thread starting
D/DL: _OnPlatformEvent
I/DeviceProvisioningFragment: showMessage:Scanning for BLE device 3840
D/CompatibilityChangeReporter: Compat change id reported: 147798919; UID 10454; state: ENABLED
I/chip.BluetoothManager: Starting Bluetooth scan
D/BluetoothAdapter: isLeEnabled(): ON
D/BluetoothLeScanner: onScannerRegistered() - status=0 scannerId=11 mScannerId=0
I/Quality: Skipped: false 25
I/chip.BluetoothManager: Bluetooth Device Scanned Addr: E1:1A:F3:88:76:8B, Name MatterTemplate
D/BluetoothAdapter: isLeEnabled(): ON
I/DeviceProvisioningFragment: showMessage:Connecting to MatterTemplate
I/chip.BluetoothManager: Connecting
D/BluetoothGatt: connect() - device: E1:1A:F3:88:76:8B, auto: false, eattSupport: false
D/BluetoothGatt: registerApp()
D/BluetoothGatt: registerApp() - UUID=bcaa567c-91d0-47b4-969e-9a25b888ae76
D/BluetoothGatt: onClientRegistered() - status=0 clientIf=11
I/chip.BluetoothManager: Bluetooth Device Scanned Addr: E1:1A:F3:88:76:8B, Name MatterTemplate
W/chip.BluetoothManager: Bluetooth device was scanned, but channel is already closed
D/BluetoothGatt: onClientConnectionState() - status=0 clientIf=11 device=E1:1A:F3:88:76:8B
I/chip.BluetoothManager: MatterTemplate.onConnectionStateChange status = 0, newState=2
I/chip.BluetoothManager|onConnectionStateChange: Discovering Services...
D/BluetoothGatt: discoverServices() - device: E1:1A:F3:88:76:8B
D/BluetoothGatt: onConnectionUpdated() - Device=E1:1A:F3:88:76:8B interval=6 latency=0 timeout=500 status=0
D/BluetoothGatt: onPhyUpdate() - status=0 address=E1:1A:F3:88:76:8B txPhy=2 rxPhy=2
D/BluetoothGatt: onSearchComplete() = Device=E1:1A:F3:88:76:8B Status=0
D/chip.BluetoothManager: MatterTemplate.onServicesDiscovered status = 0
I/chip.BluetoothManager|onServicesDiscovered: Services Discovered
D/BluetoothGatt: configureMTU() - device: E1:1A:F3:88:76:8B mtu: 247
D/BluetoothGatt: onConfigureMTU() - Device=E1:1A:F3:88:76:8B mtu=247 status=0
D/chip.BluetoothManager: MatterTemplate.onMtuChanged: connecting to CHIP device
I/DeviceProvisioningFragment: showMessage:Pairing
D/ChipDeviceController: Bluetooth connection added with ID: 1
D/ChipDeviceController: Pairing device with ID: 7
D/CTL: pairDevice() called with device ID, connection object, and pincode
D/IN: BleConnectionComplete: endPoint 0x791c303ee8
D/DL: Received GetMTU
D/AndroidBleManager: Android Manufacturer: (OnePlus)
D/AndroidBleManager: Android Model: (LE2123)
D/DL: Received SendWriteRequest
D/SC: Assigned local session key ID 699
D/SC: Including MRP parameters in PBKDF param request
D/IN: Prepared unauthenticated message 0x7fd56c1490 to 0x0000000000000000 (0) of type 0x20 and protocolId (0, 0) on exchange 36516i with MessageCounter:3702871344.
D/IN: Sending unauthenticated msg 0x7fd56c1490 with MessageCounter:3702871344 to 0x0000000000000000 at monotonic time: 00000000038334E5 msec
D/IN: Message appended to BLE send queue
D/SC: Sent PBKDF param request
D/CTL: Setting thread operational dataset from parameters
D/CTL: Setting attestation nonce to random value
D/CTL: Setting CSR nonce to random value
D/CTL: Commission called for node ID 0x0000000000000007
D/BluetoothGatt: onConnectionUpdated() - Device=E1:1A:F3:88:76:8B interval=36 latency=0 timeout=500 status=0
D/chip.BluetoothManager: MatterTemplate.onCharacteristicWrite: 18ee2ef5-263d-4559-959f-4f9c429f9d11 -> 0
D/DL: Received SubscribeCharacteristic
D/BluetoothGatt: setCharacteristicNotification() - uuid: 18ee2ef5-263d-4559-959f-4f9c429f9d12 enable: true
D/chip.BluetoothManager: MatterTemplate.onDescriptorWrite: 00002902-0000-1000-8000-00805f9b34fb -> 0
D/BLE: subscribe complete, ep = 0x791c303ee8
D/chip.BluetoothManager: MatterTemplate.onCharacteristicChanged: 18ee2ef5-263d-4559-959f-4f9c429f9d12
D/BLE: peripheral chose BTP version 4; central expected between 4 and 4
D/BLE: using BTP fragment sizes rx 244 / tx 244.
D/BLE: local and remote recv window size = 5
D/DL: Received SendWriteRequest
D/IN: BLE EndPoint 0x791c303ee8 Connection Complete
D/chip.BluetoothManager: MatterTemplate.onCharacteristicWrite: 18ee2ef5-263d-4559-959f-4f9c429f9d11 -> 0
D/chip.BluetoothManager: MatterTemplate.onCharacteristicChanged: 18ee2ef5-263d-4559-959f-4f9c429f9d12
D/IN: Received malformed unsecure packet with source 0x0000000000000000 destination 0x0000000000000000
E/ActivityThread: Failed to find provider info for com.oplus.statistics.provider
E/OplusStatistics--: IllegalArgumentException:java.lang.IllegalArgumentException: Unknown URL content://com.oplus.statistics.provider/track_event
D/DL: Received SendWriteRequest
D/chip.BluetoothManager: MatterTemplate.onCharacteristicWrite: 18ee2ef5-263d-4559-959f-4f9c429f9d11 -> 0
D/BluetoothGatt: onConnectionUpdated() - Device=E1:1A:F3:88:76:8B interval=12 latency=0 timeout=42 status=0
D/chip.BluetoothManager: MatterTemplate.onCharacteristicChanged: 18ee2ef5-263d-4559-959f-4f9c429f9d12
D/DL: Received SendWriteRequest
D/chip.BluetoothManager: MatterTemplate.onCharacteristicWrite: 18ee2ef5-263d-4559-959f-4f9c429f9d11 -> 0
D/chip.BluetoothManager: MatterTemplate.onCharacteristicChanged: 18ee2ef5-263d-4559-959f-4f9c429f9d12
D/DL: Received SendWriteRequest
D/chip.BluetoothManager: MatterTemplate.onCharacteristicWrite: 18ee2ef5-263d-4559-959f-4f9c429f9d11 -> 0
D/chip.BluetoothManager: MatterTemplate.onCharacteristicChanged: 18ee2ef5-263d-4559-959f-4f9c429f9d12
D/DL: Received SendWriteRequest
D/chip.BluetoothManager: MatterTemplate.onCharacteristicWrite: 18ee2ef5-263d-4559-959f-4f9c429f9d11 -> 0
D/chip.BluetoothManager: MatterTemplate.onCharacteristicChanged: 18ee2ef5-263d-4559-959f-4f9c429f9d12
D/DL: Received SendWriteRequest
D/chip.BluetoothManager: MatterTemplate.onCharacteristicWrite: 18ee2ef5-263d-4559-959f-4f9c429f9d11 -> 0
D/chip.BluetoothManager: MatterTemplate.onCharacteristicChanged: 18ee2ef5-263d-4559-959f-4f9c429f9d12
D/DL: Received SendWriteRequest
D/chip.BluetoothManager: MatterTemplate.onCharacteristicWrite: 18ee2ef5-263d-4559-959f-4f9c429f9d11 -> 0
E/SC: PASESession timed out while waiting for a response from the peer. Expected message type was 33
D/DeviceProvisioningFragment: Pairing status update: 1
D/DIS: Closing all BLE connections
D/IN: Clearing BLE pending packets.
D/DL: Received UnsubscribeCharacteristic
D/BluetoothGatt: setCharacteristicNotification() - uuid: 18ee2ef5-263d-4559-959f-4f9c429f9d12 enable: false
D/BLE: Auto-closing end point's BLE connection.
D/DL: Received CloseConnection
D/BluetoothGatt: close()
D/BluetoothGatt: unregisterApp() - mClientIf=11
D/chip.BluetoothManager: onCloseBleComplete
D/DeviceProvisioningFragment: onPairingComplete: 50
I/DeviceProvisioningFragment: showMessage:Pairing failed
I/Quality: Skipped: false 1
