search

project-chip / connectedhomeip

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

[SVE-2] Android matter pairing failed with errorcode 50 #22445

Closed smokinghot closed 1 year ago

smokinghot commented 2 years ago

Reproduction steps

1.Compiled chip-tool on android platform[arm64-v8a]
2.use "provision chip device with thread"
3.Scan code and enter thread info to pair device
4.Paired fail all the time.

Please check the log below.

2022-09-07 11:56:30.845 11919-11932/com.google.chip.chiptool D/chip.BluetoothManager: SiLabs-Light.onMtuChanged: connecting to CHIP device
2022-09-07 11:56:30.850 11919-11919/com.google.chip.chiptool I/DeviceProvisioningFragment: showMessage:Pairing
2022-09-07 11:56:30.866 11919-11919/com.google.chip.chiptool D/ChipDeviceController: Bluetooth connection added with ID: 1
2022-09-07 11:56:30.866 11919-11919/com.google.chip.chiptool D/ChipDeviceController: Pairing device with ID: 25
2022-09-07 11:56:30.866 11919-11919/com.google.chip.chiptool D/CTL: pairDevice() called with device ID, connection object, and pincode
2022-09-07 11:56:30.867 11919-11919/com.google.chip.chiptool D/IN: BleConnectionComplete: endPoint 0x7247df7a08
2022-09-07 11:56:30.867 11919-11919/com.google.chip.chiptool D/DL: Received GetMTU
2022-09-07 11:56:30.867 11919-11919/com.google.chip.chiptool D/AndroidBleManager: Android Manufacturer: (Google)
2022-09-07 11:56:30.867 11919-11919/com.google.chip.chiptool D/AndroidBleManager: Android Model: (Pixel 3a)
2022-09-07 11:56:30.868 11919-11919/com.google.chip.chiptool D/DL: Received SendWriteRequest
2022-09-07 11:56:30.871 11919-11919/com.google.chip.chiptool D/IN: SecureSession[0x74889fc8f0]: Allocated Type:1 LSID:31976
2022-09-07 11:56:30.871 11919-11919/com.google.chip.chiptool D/SC: Assigned local session key ID 31976
2022-09-07 11:56:30.872 11919-11919/com.google.chip.chiptool D/SC: Including MRP parameters in PBKDF param request
2022-09-07 11:56:30.872 11919-11919/com.google.chip.chiptool D/IN: Prepared unauthenticated message 0x7fe0b8f238 to 0x0000000000000000 (0)  of type 0x20 and protocolId (0, 0) on exchange 28195i with MessageCounter:175716039.
2022-09-07 11:56:30.872 11919-11919/com.google.chip.chiptool D/IN: Sending unauthenticated msg 0x7fe0b8f238 with MessageCounter:175716039 to 0x0000000000000000 at monotonic time: 0000000007D49C1C msec
2022-09-07 11:56:30.872 11919-11919/com.google.chip.chiptool D/IN: Message appended to BLE send queue
2022-09-07 11:56:30.872 11919-11919/com.google.chip.chiptool D/SC: Sent PBKDF param request
2022-09-07 11:56:30.872 11919-11919/com.google.chip.chiptool D/CTL: Setting failsafe timer from parameters
2022-09-07 11:56:30.872 11919-11919/com.google.chip.chiptool D/CTL: Setting thread operational dataset from parameters
2022-09-07 11:56:30.872 11919-11919/com.google.chip.chiptool D/CTL: Setting attempt thread scan from parameters
2022-09-07 11:56:30.872 11919-11919/com.google.chip.chiptool D/CTL: Setting attempt wifi scan from parameters
2022-09-07 11:56:30.872 11919-11919/com.google.chip.chiptool D/CTL: Setting attestation nonce from parameters
2022-09-07 11:56:30.872 11919-11919/com.google.chip.chiptool D/CTL: Setting CSR nonce from parameters
2022-09-07 11:56:30.872 11919-11919/com.google.chip.chiptool D/CTL: Setting PASE-only commissioning from parameters
2022-09-07 11:56:30.872 11919-11919/com.google.chip.chiptool D/CTL: Commission called for node ID 0x0000000000000019
2022-09-07 11:56:30.917 11919-11932/com.google.chip.chiptool D/BluetoothGatt: onConnectionUpdated() - Device=00:0D:6F:20:B2:AF interval=36 latency=0 timeout=500 status=0
2022-09-07 11:56:30.965 11919-11932/com.google.chip.chiptool D/chip.BluetoothManager: SiLabs-Light.onCharacteristicWrite: 18ee2ef5-263d-4559-959f-4f9c429f9d11 -> 0
2022-09-07 11:56:30.966 11919-11932/com.google.chip.chiptool D/DL: Received SubscribeCharacteristic
2022-09-07 11:56:30.967 11919-11932/com.google.chip.chiptool D/BluetoothGatt: setCharacteristicNotification() - uuid: 18ee2ef5-263d-4559-959f-4f9c429f9d12 enable: true
2022-09-07 11:56:31.057 11919-11932/com.google.chip.chiptool D/chip.BluetoothManager: SiLabs-Light.onDescriptorWrite: 00002902-0000-1000-8000-00805f9b34fb -> 0
2022-09-07 11:56:31.057 11919-11932/com.google.chip.chiptool D/BLE: subscribe complete, ep = 0x7247df7a08
2022-09-07 11:56:31.995 1115-1217/? D/VSC: @ 501573.790: [WO] Proposed rotation: 0, flat angle threshold: 65
2022-09-07 11:56:31.996 1115-1217/? D/VSC: @ 501573.790: [WO] orientation angle 12, orientation 0
2022-09-07 11:56:31.996 1115-1217/? D/VSC: @ 501573.790: [WO] Gyro angle integrated: 25.131652
2022-09-07 11:56:31.996 1115-1217/? D/VSC: @ 501573.790: [WO] Gyro angle integrated: 25.131652
2022-09-07 11:56:32.360 1115-1217/? I/CHRE: @ 501574.155: [AR] inconsistent: 41.176471
2022-09-07 11:56:32.508 1770-3534/? W/InputManager-JNI: Input channel object '369520d Toast (client)' was disposed without first being removed with the input manager!
2022-09-07 11:56:32.517 1770-3534/? W/NotificationService: Toast already killed. pkg=com.google.chip.chiptool token=android.os.BinderProxy@210f2f7
2022-09-07 11:56:32.800 1770-2131/? D/ConnectivityService: NetReassign [no changes]
2022-09-07 11:56:33.700 2886-11876/? I/NearbyDiscovery: loadFastPairModule: checkFeaturesAreAvailable:0 [CONTEXT service_id=265 ]
2022-09-07 11:56:33.700 2886-11876/? I/NearbyDiscovery: loadFastPairModule: FastPair module is downloaded. [CONTEXT service_id=265 ]
2022-09-07 11:56:34.074 1115-1217/? D/VSC: @ 501575.870: [WO] Proposed rotation: 0, flat angle threshold: 65
2022-09-07 11:56:34.074 1115-1217/? D/VSC: @ 501575.870: [WO] orientation angle 16, orientation 0
2022-09-07 11:56:34.074 1115-1217/? D/VSC: @ 501575.870: [WO] Gyro angle integrated: 13.268837
2022-09-07 11:56:34.074 1115-1217/? D/VSC: @ 501575.870: [WO] Gyro angle integrated: 13.268837
2022-09-07 11:56:34.655 2886-3297/? I/NearbyDiscovery: FastPairCache: Not triggering, because RSSI -61 is below the threshold of -52 [CONTEXT service_id=265 ]
2022-09-07 11:56:35.097 1770-3144/? W/InputManager-JNI: Input channel object 'd4653cd Toast (client)' was disposed without first being removed with the input manager!
2022-09-07 11:56:35.107 1770-3144/? W/NotificationService: Toast already killed. pkg=com.google.chip.chiptool token=android.os.BinderProxy@1272f85
2022-09-07 11:56:35.582 1115-1217/? I/CHRE: @ 501577.378: [AR] still: 38.431373
2022-09-07 11:56:35.833 1770-2131/? D/ConnectivityService: NetReassign [no changes]
2022-09-07 11:56:36.071 1115-1217/? D/VSC: @ 501577.863: [WO] Proposed rotation: 0, flat angle threshold: 65
2022-09-07 11:56:36.072 1115-1217/? D/VSC: @ 501577.863: [WO] orientation angle 12, orientation 0
2022-09-07 11:56:36.072 1115-1217/? D/VSC: @ 501577.863: [WO] Gyro angle integrated: 9.497058
2022-09-07 11:56:36.072 1115-1217/? D/VSC: @ 501577.863: [WO] Gyro angle integrated: 9.497058
2022-09-07 11:56:36.226 2351-19361/? D/NetworkMonitor/108: isDataStall: result=2, tcp packets received=0, latest tcp fail rate=100, consecutive dns timeout count=0
2022-09-07 11:56:36.226 2351-19361/? D/NetworkMonitor/108: Suspecting data stall, reevaluate
2022-09-07 11:56:36.226 1770-3144/? D/ConnectivityService: Data stall detected with methods: 2
2022-09-07 11:56:36.233 2351-12044/? D/NetworkMonitor/108: Validation disabled.
2022-09-07 11:56:36.241 1770-2131/? D/ConnectivityService: [108 WIFI] validation passed
2022-09-07 11:56:37.702 1770-3534/? W/InputManager-JNI: Input channel object 'bae960b Toast (client)' was disposed without first being removed with the input manager!
2022-09-07 11:56:37.711 1770-3534/? W/NotificationService: Toast already killed. pkg=com.google.chip.chiptool token=android.os.BinderProxy@660ca3d
2022-09-07 11:56:38.070 1115-1217/? D/VSC: @ 501579.860: [WO] Proposed rotation: 0, flat angle threshold: 65
2022-09-07 11:56:38.071 1115-1217/? D/VSC: @ 501579.860: [WO] orientation angle 13, orientation 0
2022-09-07 11:56:38.071 1115-1217/? D/VSC: @ 501579.860: [WO] Gyro angle integrated: 0.950488
2022-09-07 11:56:38.071 1115-1217/? D/VSC: @ 501579.860: [WO] Gyro angle integrated: 0.950488
2022-09-07 11:56:38.874 1770-2131/? D/ConnectivityService: NetReassign [no changes]
2022-09-07 11:56:40.061 1115-1217/? D/VSC: @ 501581.851: [WO] Proposed rotation: 0, flat angle threshold: 65
2022-09-07 11:56:40.061 1115-1217/? D/VSC: @ 501581.851: [WO] orientation angle 15, orientation 0
2022-09-07 11:56:40.061 1115-1217/? D/VSC: @ 501581.851: [WO] Gyro angle integrated: 0.687022
2022-09-07 11:56:40.062 1115-1217/? D/VSC: @ 501581.851: [WO] Gyro angle integrated: 0.687022
2022-09-07 11:56:40.068 1770-1770/? D/CompanionDeviceManagerService: TriggerDeviceDisappearedRunnable.run(address = 00:0D:6F:20:B2:AF)
2022-09-07 11:56:41.907 1770-2131/? D/ConnectivityService: NetReassign [no changes]
2022-09-07 11:56:42.053 1115-1217/? D/VSC: @ 501583.843: [WO] Proposed rotation: 0, flat angle threshold: 65
2022-09-07 11:56:42.054 1115-1217/? D/VSC: @ 501583.843: [WO] orientation angle 15, orientation 0
2022-09-07 11:56:42.054 1115-1217/? D/VSC: @ 501583.843: [WO] Gyro angle integrated: 14.229229
2022-09-07 11:56:42.054 1115-1217/? D/VSC: @ 501583.843: [WO] Gyro angle integrated: 14.229229
2022-09-07 11:56:43.261 1770-1770/? W/WindowManager: removeWindowToken: Attempted to remove non-existing token: android.os.Binder@a176c36
2022-09-07 11:56:44.135 1115-1217/? D/VSC: @ 501585.924: [WO] Proposed rotation: 0, flat angle threshold: 65
2022-09-07 11:56:44.135 1115-1217/? D/VSC: @ 501585.924: [WO] orientation angle 14, orientation 0
2022-09-07 11:56:44.135 1115-1217/? D/VSC: @ 501585.924: [WO] Gyro angle integrated: 3.042407
2022-09-07 11:56:44.135 1115-1217/? D/VSC: @ 501585.924: [WO] Gyro angle integrated: 3.042407
2022-09-07 11:56:44.941 1770-2131/? D/ConnectivityService: NetReassign [no changes]
2022-09-07 11:56:45.295 1115-1217/? I/CHRE: @ 501587.090: [AR] inconsistent: 41.176471
2022-09-07 11:56:45.848 1770-1770/? W/WindowManager: removeWindowToken: Attempted to remove non-existing token: android.os.Binder@603cc0e
2022-09-07 11:56:45.889 11919-12029/com.google.chip.chiptool E/BLE: connect handshake timed out, closing ep 0x7247df7a08
2022-09-07 11:56:45.889 11919-12029/com.google.chip.chiptool E/IN: Failed to establish BLE connection: 415
2022-09-07 11:56:45.889 11919-12029/com.google.chip.chiptool D/IN: Clearing BLE pending packets.
2022-09-07 11:56:45.889 11919-12029/com.google.chip.chiptool D/DL: Received UnsubscribeCharacteristic
2022-09-07 11:56:45.890 11919-12029/com.google.chip.chiptool D/BluetoothGatt: setCharacteristicNotification() - uuid: 18ee2ef5-263d-4559-959f-4f9c429f9d12 enable: false
2022-09-07 11:56:45.960 1104-1104/? I/android.hardware.health@2.0-service.bonito: capacity: 1801000
2022-09-07 11:56:45.976 2214-2214/? D/PowerNotificationWarningsGoogleImpl: onReceive: android.intent.action.BATTERY_CHANGED
2022-09-07 11:56:45.978 2214-2214/? D/BatteryInfoBroadcast: onReceive: android.intent.action.BATTERY_CHANGED isPowerSaveMode: false
2022-09-07 11:56:45.979 2214-2214/? D/BatteryDefenderNotification: isPlugged: true | isOverheated: false | defenderEnabled: false | isCharged: false
2022-09-07 11:56:45.981 2214-6669/? D/PowerUI: can't show warning due to - plugged: true status unknown: false
2022-09-07 11:56:46.086 11919-11932/com.google.chip.chiptool D/chip.BluetoothManager: SiLabs-Light.onDescriptorWrite: 00002902-0000-1000-8000-00805f9b34fb -> 0
2022-09-07 11:56:46.086 11919-11932/com.google.chip.chiptool D/BLE: Auto-closing end point's BLE connection.
2022-09-07 11:56:46.086 11919-11932/com.google.chip.chiptool D/DL: Received CloseConnection
2022-09-07 11:56:46.087 11919-11932/com.google.chip.chiptool D/BluetoothGatt: close()
2022-09-07 11:56:46.087 11919-11932/com.google.chip.chiptool D/BluetoothGatt: unregisterApp() - mClientIf=9
2022-09-07 11:56:46.089 11919-11932/com.google.chip.chiptool D/chip.BluetoothManager: onCloseBleComplete
2022-09-07 11:56:46.090 23519-23567/? I/bt_stack: [INFO:gatt_api.cc(1286)] GATT_Disconnect conn_id=0x0009
2022-09-07 11:56:46.090 23519-23567/? I/bt_stack: [INFO:eatt_impl.h(598)] disconnect 00:0d:6f:20:b2:af
2022-09-07 11:56:46.090 23519-23567/? W/bt_stack: [WARNING:eatt_impl.h(602)] disconnect no eatt device found
2022-09-07 11:56:46.090 23519-23567/? I/bt_stack: [INFO:gatt_api.cc(1042)] GATT_Deregister gatt_if=9
2022-09-07 11:56:46.093 23519-23546/? E/BtGatt.ContextMap: Context not found for ID 9
2022-09-07 11:56:46.120 1115-1217/? D/VSC: @ 501587.916: [WO] Proposed rotation: 0, flat angle threshold: 65
2022-09-07 11:56:46.121 1115-1217/? D/VSC: @ 501587.916: [WO] orientation angle 14, orientation 0
2022-09-07 11:56:46.121 1115-1217/? D/VSC: @ 501587.916: [WO] Gyro angle integrated: 26.142517
2022-09-07 11:56:46.121 1115-1217/? D/VSC: @ 501587.916: [WO] Gyro angle integrated: 26.142517
2022-09-07 11:56:47.097 23519-23567/? W/l2c_link: system/bt/stack/l2cap/l2c_link.cc:498 l2c_link_timeout: TODO: Remove this callback into bcm_sec_disconnect
2022-09-07 11:56:47.097 23519-23567/? I/btm_acl: system/bt/stack/acl/btm_acl.cc:185 hci_btsnd_hcic_disconnect: Disconnecting peer:xx:xx:xx:xx:b2:af reason:Remote Terminated Connection
2022-09-07 11:56:47.173 23519-23567/? I/bt_stack: [INFO:btsnoop.cc(338)] clear_l2cap_allowlist: Clearing acceptlist from l2cap channel. conn_handle=7 cid=4:4
2022-09-07 11:56:47.175 23519-23567/? I/bt_stack: [INFO:gatt_attr.cc(338)] gatt_connect_cback: remove untrusted client status, bda=00:0d:6f:20:b2:af
2022-09-07 11:56:47.175 23519-23567/? I/bluetooth: system/bt/stack/gap/gap_ble.cc:298 client_connect_cback: No active GAP service found for peer:xx:xx:xx:xx:b2:af callback:Disconnected
2022-09-07 11:56:47.175 23519-23567/? I/bt_bta_gattc: system/bt/bta/gatt/bta_gattc_act.cc:1115 bta_gattc_conn_cback: Disconnected att_id:3 transport:le reason:GATT_CONN_TERMINATE_LOCAL_HOST
2022-09-07 11:56:47.175 23519-23567/? I/bt_bta_gattc: system/bt/bta/gatt/bta_gattc_act.cc:1115 bta_gattc_conn_cback: Disconnected att_id:4 transport:le reason:GATT_CONN_TERMINATE_LOCAL_HOST
2022-09-07 11:56:47.175 23519-23567/? I/bt_bta_gattc: system/bt/bta/gatt/bta_gattc_act.cc:1115 bta_gattc_conn_cback: Disconnected att_id:5 transport:le reason:GATT_CONN_TERMINATE_LOCAL_HOST
2022-09-07 11:56:47.175 23519-23567/? I/bt_bta_gattc: system/bt/bta/gatt/bta_gattc_act.cc:1115 bta_gattc_conn_cback: Disconnected att_id:6 transport:le reason:GATT_CONN_TERMINATE_LOCAL_HOST
2022-09-07 11:56:47.175 23519-23567/? I/bt_bta_gattc: system/bt/bta/gatt/bta_gattc_act.cc:1115 bta_gattc_conn_cback: Disconnected att_id:7 transport:le reason:GATT_CONN_TERMINATE_LOCAL_HOST
2022-09-07 11:56:47.175 23519-23567/? I/bt_bta_gattc: system/bt/bta/gatt/bta_gattc_act.cc:1115 bta_gattc_conn_cback: Disconnected att_id:8 transport:le reason:GATT_CONN_TERMINATE_LOCAL_HOST
2022-09-07 11:56:47.176 23519-23567/? I/btif_av: system/bt/btif/src/btif_av.cc:3352 btif_av_acl_disconnected: btif_av_acl_disconnected: Peer 00:0d:6f:20:b2:af : ACL Disconnected
2022-09-07 11:56:47.176 23519-23567/? I/btif_av: system/bt/btif/src/btif_av.cc:1078 FindOrCreatePeer: BtifAvPeer *BtifAvSource::FindOrCreatePeer(const RawAddress &, tBTA_AV_HNDL): Create peer: peer_address=00:0d:6f:20:b2:af bta_handle=0x41 peer_id=0
2022-09-07 11:56:47.176 23519-23567/? I/btif_av: system/bt/btif/src/btif_av.cc:3279 btif_av_get_peer_sep: No active sink or source peer found
2022-09-07 11:56:47.176 23519-23567/? I/bt_btif_a2dp_source: system/bt/btif/src/btif_a2dp_source.cc:691 btif_a2dp_source_on_idle: btif_a2dp_source_on_idle: state=STATE_OFF
2022-09-07 11:56:47.176 23519-23567/? I/btif_av: system/bt/btif/src/btif_av.cc:3279 btif_av_get_peer_sep: No active sink or source peer found
2022-09-07 11:56:47.176 23519-23567/? I/bt_btif_a2dp_source: system/bt/btif/src/btif_a2dp_source.cc:691 btif_a2dp_source_on_idle: btif_a2dp_source_on_idle: state=STATE_OFF
2022-09-07 11:56:47.176 23519-23567/? I/btif_av: system/bt/btif/src/btif_av.cc:1123 DeleteIdlePeers: DeleteIdlePeers: Deleting idle peer: 00:0d:6f:20:b2:af bta_handle=0x41
2022-09-07 11:56:47.191 1770-1770/? D/CompanionDeviceManagerService: 00:0D:6F:20:B2:AF disconnected w/ reason: (1100) Local request
2022-09-07 11:56:47.191 1770-1770/? D/CompanionDeviceManagerService: onDeviceDisconnected(address = 00:0D:6F:20:B2:AF)
2022-09-07 11:56:47.193 2214-2292/? W/BluetoothEventManager: AclStateChangedHandler: activeDevice is null
2022-09-07 11:56:47.194 3084-3084/? I/AmbBrdcstRcvrServClient: (REDACTED) handleRefreshAction(): not handling %s
2022-09-07 11:56:47.195 3084-3775/? I/BrdcstRcvrMsgr: (REDACTED) sendMessage(): received broadcast id:%d with action:%s
2022-09-07 11:56:47.196 1770-1870/? W/BroadcastQueue: Permission Denial: receiving Intent { act=android.bluetooth.device.action.ACL_DISCONNECTED flg=0x5000010 (has extras) } to com.google.android.apps.wearables.maestro.companion/.connectivity.ClassicBTReceiver requires android.permission.BLUETOOTH_CONNECT due to sender com.android.bluetooth (uid 1002)
2022-09-07 11:56:47.197 21990-22045/? I/BrdcstRcvrBProvider: (REDACTED) handleMessage(): id:%d action:%s
2022-09-07 11:56:47.199 21990-22045/? I/AmbBrdcstRcvrBProvider: (REDACTED) receive(): %s
2022-09-07 11:56:47.201 21990-22045/? I/A: (REDACTED) handleIntent(): action:%s
2022-09-07 11:56:47.203 21990-22075/? I/BrdcstRcvrBProvider: (REDACTED) handleMessage(): DONE id:%d
2022-09-07 11:56:47.205 3084-3775/? I/BrdcstRcvrMsgr: (REDACTED) handleMessage(): id:%d, DEC to %d
2022-09-07 11:56:47.218 21990-22056/? I/BistoWorker: (REDACTED) bluetoothConnectionStateChanged. Action: %s
2022-09-07 11:56:47.220 21990-22055/? I/BistoWorker: (REDACTED) Failed to get bistoDeviceInfo %s
2022-09-07 11:56:47.234 21990-22055/? I/DeviceDetector: Not bonded or not refresh cache.
2022-09-07 11:56:47.235 2886-2886/? I/NearbyDiscovery: onAclChange: state=DISCONNECTED, device=XX:XX:XX:XX:B2:AF [CONTEXT service_id=265 ]
2022-09-07 11:56:47.988 1770-2131/? D/ConnectivityService: NetReassign [no changes]
2022-09-07 11:56:48.115 1115-1217/? D/VSC: @ 501589.910: [WO] Proposed rotation: 0, flat angle threshold: 65
2022-09-07 11:56:48.115 1115-1217/? D/VSC: @ 501589.910: [WO] orientation angle 15, orientation 0
2022-09-07 11:56:48.115 1115-1217/? D/VSC: @ 501589.910: [WO] Gyro angle integrated: 2.589238
2022-09-07 11:56:48.115 1115-1217/? D/VSC: @ 501589.910: [WO] Gyro angle integrated: 2.589238
2022-09-07 11:56:48.452 1770-1770/? W/WindowManager: removeWindowToken: Attempted to remove non-existing token: android.os.Binder@59a0a1e
2022-09-07 11:56:50.113 1115-1217/? D/VSC: @ 501591.902: [WO] Proposed rotation: 0, flat angle threshold: 65
2022-09-07 11:56:50.113 1115-1217/? D/VSC: @ 501591.903: [WO] orientation angle 15, orientation 0
2022-09-07 11:56:50.113 1115-1217/? D/VSC: @ 501591.903: [WO] Gyro angle integrated: 2.840962
2022-09-07 11:56:50.113 1115-1217/? D/VSC: @ 501591.903: [WO] Gyro angle integrated: 2.840962
2022-09-07 11:56:51.041 1770-2131/? D/ConnectivityService: NetReassign [no changes]
2022-09-07 11:56:51.579 2886-11951/? E/AuthPII: [GoogleAccountDataServiceImpl] getToken() -> NETWORK_ERROR. App: com.google.android.gms, Service: oauth2:https://www.googleapis.com/auth/userlocation.reporting
    ydg: Error when calling server.
        at kmx.c(:com.google.android.gms@223412044@22.34.12 (190400-469381630):90)
        at kle.l(:com.google.android.gms@223412044@22.34.12 (190400-469381630):47)
        at gdl.n(:com.google.android.gms@223412044@22.34.12 (190400-469381630):31)
        at gdl.e(:com.google.android.gms@223412044@22.34.12 (190400-469381630):66)
        at gdl.h(:com.google.android.gms@223412044@22.34.12 (190400-469381630):0)
        at kha.a(:com.google.android.gms@223412044@22.34.12 (190400-469381630):3)
        at khh.G(:com.google.android.gms@223412044@22.34.12 (190400-469381630):4)
        at khh.s(:com.google.android.gms@223412044@22.34.12 (190400-469381630):10)
        at khh.w(:com.google.android.gms@223412044@22.34.12 (190400-469381630):0)
        at kgy.h(:com.google.android.gms@223412044@22.34.12 (190400-469381630):0)
        at yya.b(:com.google.android.gms@223412044@22.34.12 (190400-469381630):4)
        at ywr.t(:com.google.android.gms@223412044@22.34.12 (190400-469381630):5)
        at yxc.e(:com.google.android.gms@223412044@22.34.12 (190400-469381630):2)
        at cnlh.f(:com.google.android.gms@223412044@22.34.12 (190400-469381630):25)
        at cnlh.d(:com.google.android.gms@223412044@22.34.12 (190400-469381630):1)
        at cnlg.b(:com.google.android.gms@223412044@22.34.12 (190400-469381630):4)
        at zcg.onPerformSync(:com.google.android.gms@223412044@22.34.12 (190400-469381630):4)
        at android.content.AbstractThreadedSyncAdapter$SyncThread.run(AbstractThreadedSyncAdapter.java:334)
     Caused by: java.net.SocketTimeoutException: failed to connect to android.googleapis.com/142.251.42.234 (port 443) from /192.168.1.153 (port 48134) after 30000ms
        at libcore.io.IoBridge.connectErrno(IoBridge.java:236)
        at libcore.io.IoBridge.connect(IoBridge.java:180)
        at java.net.PlainSocketImpl.socketConnect(PlainSocketImpl.java:142)
        at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:390)
        at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:230)
        at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:212)
        at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:436)
        at java.net.Socket.connect(Socket.java:621)
        at com.android.okhttp.internal.Platform.connectSocket(Platform.java:182)
        at com.android.okhttp.internal.io.RealConnection.connectSocket(RealConnection.java:145)
        at com.android.okhttp.internal.io.RealConnection.connect(RealConnection.java:116)
        at com.android.okhttp.internal.http.StreamAllocation.findConnection(StreamAllocation.java:186)
        at com.android.okhttp.internal.http.StreamAllocation.findHealthyConnection(StreamAllocation.java:128)
        at com.android.okhttp.internal.http.StreamAllocation.newStream(StreamAllocation.java:97)
        at com.android.okhttp.internal.http.HttpEngine.connect(HttpEngine.java:289)
        at com.android.okhttp.internal.http.HttpEngine.sendRequest(HttpEngine.java:232)
        at com.android.okhttp.internal.huc.HttpURLConnectionImpl.execute(HttpURLConnectionImpl.java:465)
        at com.android.okhttp.internal.huc.HttpURLConnectionImpl.connect(HttpURLConnectionImpl.java:131)
        at com.android.okhttp.internal.huc.HttpURLConnectionImpl.getOutputStream(HttpURLConnectionImpl.java:262)
        at com.android.okhttp.internal.huc.DelegatingHttpsURLConnection.getOutputStream(DelegatingHttpsURLConnection.java:219)
        at com.android.okhttp.internal.huc.HttpsURLConnectionImpl.getOutputStream(HttpsURLConnectionImpl.java:30)
        at amha.b(:com.google.android.gms@223412044@22.34.12 (190400-469381630):37)
        at oou.a(:com.google.android.gms@223412044@22.34.12 (190400-469381630):4)
        at kmh.e(:com.google.android.gms@223412044@22.34.12 (190400-469381630):4)
        at kmh.d(:com.google.android.gms@223412044@22.34.12 (190400-469381630):5)
        at kmh.c(:com.google.android.gms@223412044@22.34.12 (190400-469381630):0)
        at kmx.c(:com.google.android.gms@223412044@22.34.12 (190400-469381630):7)
        at kle.l(:com.google.android.gms@223412044@22.34.12 (190400-469381630):47) 
        at gdl.n(:com.google.android.gms@223412044@22.34.12 (190400-469381630):31) 
        at gdl.e(:com.google.android.gms@223412044@22.34.12 (190400-469381630):66) 
        at gdl.h(:com.google.android.gms@223412044@22.34.12 (190400-469381630):0) 
        at kha.a(:com.google.android.gms@223412044@22.34.12 (190400-469381630):3) 
        at khh.G(:com.google.android.gms@223412044@22.34.12 (190400-469381630):4) 
        at khh.s(:com.google.android.gms@223412044@22.34.12 (190400-469381630):10) 
        at khh.w(:com.google.android.gms@223412044@22.34.12 (190400-469381630):0) 
        at kgy.h(:com.google.android.gms@223412044@22.34.12 (190400-469381630):0) 
        at yya.b(:com.google.android.gms@223412044@22.34.12 (190400-469381630):4) 
        at ywr.t(:com.google.android.gms@223412044@22.34.12 (190400-469381630):5) 
        at yxc.e(:com.google.android.gms@223412044@22.34.12 (190400-469381630):2) 
        at cnlh.f(:com.google.android.gms@223412044@22.34.12 (190400-469381630):25) 
        at cnlh.d(:com.google.android.gms@223412044@22.34.12 (190400-469381630):1) 
        at cnlg.b(:com.google.android.gms@223412044@22.34.12 (190400-469381630):4) 
        at zcg.onPerformSync(:com.google.android.gms@223412044@22.34.12 (190400-469381630):4) 
        at android.content.AbstractThreadedSyncAdapter$SyncThread.run(AbstractThreadedSyncAdapter.java:334) 
2022-09-07 11:56:51.580 2886-11951/? E/AuthPII: Message is Error when calling server.
    ydg: Error when calling server.
        at kmx.c(:com.google.android.gms@223412044@22.34.12 (190400-469381630):90)
        at kle.l(:com.google.android.gms@223412044@22.34.12 (190400-469381630):47)
        at gdl.n(:com.google.android.gms@223412044@22.34.12 (190400-469381630):31)
        at gdl.e(:com.google.android.gms@223412044@22.34.12 (190400-469381630):66)
        at gdl.h(:com.google.android.gms@223412044@22.34.12 (190400-469381630):0)
        at kha.a(:com.google.android.gms@223412044@22.34.12 (190400-469381630):3)
        at khh.G(:com.google.android.gms@223412044@22.34.12 (190400-469381630):4)
        at khh.s(:com.google.android.gms@223412044@22.34.12 (190400-469381630):10)
        at khh.w(:com.google.android.gms@223412044@22.34.12 (190400-469381630):0)
        at kgy.h(:com.google.android.gms@223412044@22.34.12 (190400-469381630):0)
        at yya.b(:com.google.android.gms@223412044@22.34.12 (190400-469381630):4)
        at ywr.t(:com.google.android.gms@223412044@22.34.12 (190400-469381630):5)
        at yxc.e(:com.google.android.gms@223412044@22.34.12 (190400-469381630):2)
        at cnlh.f(:com.google.android.gms@223412044@22.34.12 (190400-469381630):25)
        at cnlh.d(:com.google.android.gms@223412044@22.34.12 (190400-469381630):1)
        at cnlg.b(:com.google.android.gms@223412044@22.34.12 (190400-469381630):4)
        at zcg.onPerformSync(:com.google.android.gms@223412044@22.34.12 (190400-469381630):4)
        at android.content.AbstractThreadedSyncAdapter$SyncThread.run(AbstractThreadedSyncAdapter.java:334)
     Caused by: java.net.SocketTimeoutException: failed to connect to android.googleapis.com/142.251.42.234 (port 443) from /192.168.1.153 (port 48134) after 30000ms
        at libcore.io.IoBridge.connectErrno(IoBridge.java:236)
        at libcore.io.IoBridge.connect(IoBridge.java:180)
        at java.net.PlainSocketImpl.socketConnect(PlainSocketImpl.java:142)
        at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:390)
        at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:230)
        at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:212)
        at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:436)
        at java.net.Socket.connect(Socket.java:621)
        at com.android.okhttp.internal.Platform.connectSocket(Platform.java:182)
        at com.android.okhttp.internal.io.RealConnection.connectSocket(RealConnection.java:145)
        at com.android.okhttp.internal.io.RealConnection.connect(RealConnection.java:116)
        at com.android.okhttp.internal.http.StreamAllocation.findConnection(StreamAllocation.java:186)
        at com.android.okhttp.internal.http.StreamAllocation.findHealthyConnection(StreamAllocation.java:128)
        at com.android.okhttp.internal.http.StreamAllocation.newStream(StreamAllocation.java:97)
        at com.android.okhttp.internal.http.HttpEngine.connect(HttpEngine.java:289)
        at com.android.okhttp.internal.http.HttpEngine.sendRequest(HttpEngine.java:232)
        at com.android.okhttp.internal.huc.HttpURLConnectionImpl.execute(HttpURLConnectionImpl.java:465)
        at com.android.okhttp.internal.huc.HttpURLConnectionImpl.connect(HttpURLConnectionImpl.java:131)
        at com.android.okhttp.internal.huc.HttpURLConnectionImpl.getOutputStream(HttpURLConnectionImpl.java:262)
        at com.android.okhttp.internal.huc.DelegatingHttpsURLConnection.getOutputStream(DelegatingHttpsURLConnection.java:219)
        at com.android.okhttp.internal.huc.HttpsURLConnectionImpl.getOutputStream(HttpsURLConnectionImpl.java:30)
        at amha.b(:com.google.android.gms@223412044@22.34.12 (190400-469381630):37)
        at oou.a(:com.google.android.gms@223412044@22.34.12 (190400-469381630):4)
        at kmh.e(:com.google.android.gms@223412044@22.34.12 (190400-469381630):4)
        at kmh.d(:com.google.android.gms@223412044@22.34.12 (190400-469381630):5)
        at kmh.c(:com.google.android.gms@223412044@22.34.12 (190400-469381630):0)
        at kmx.c(:com.google.android.gms@223412044@22.34.12 (190400-469381630):7)
        at kle.l(:com.google.android.gms@223412044@22.34.12 (190400-469381630):47) 
        at gdl.n(:com.google.android.gms@223412044@22.34.12 (190400-469381630):31) 
        at gdl.e(:com.google.android.gms@223412044@22.34.12 (190400-469381630):66) 
        at gdl.h(:com.google.android.gms@223412044@22.34.12 (190400-469381630):0) 
        at kha.a(:com.google.android.gms@223412044@22.34.12 (190400-469381630):3) 
        at khh.G(:com.google.android.gms@223412044@22.34.12 (190400-469381630):4) 
        at khh.s(:com.google.android.gms@223412044@22.34.12 (190400-469381630):10) 
        at khh.w(:com.google.android.gms@223412044@22.34.12 (190400-469381630):0) 
        at kgy.h(:com.google.android.gms@223412044@22.34.12 (190400-469381630):0) 
        at yya.b(:com.google.android.gms@223412044@22.34.12 (190400-469381630):4) 
        at ywr.t(:com.google.android.gms@223412044@22.34.12 (190400-469381630):5) 
        at yxc.e(:com.google.android.gms@223412044@22.34.12 (190400-469381630):2) 
        at cnlh.f(:com.google.android.gms@223412044@22.34.12 (190400-469381630):25) 
        at cnlh.d(:com.google.android.gms@223412044@22.34.12 (190400-469381630):1) 
        at cnlg.b(:com.google.android.gms@223412044@22.34.12 (190400-469381630):4) 
        at zcg.onPerformSync(:com.google.android.gms@223412044@22.34.12 (190400-469381630):4) 
        at android.content.AbstractThreadedSyncAdapter$SyncThread.run(AbstractThreadedSyncAdapter.java:334) 
2022-09-07 11:56:51.582 2886-11951/? W/Auth: [GetToken] GetToken failed with status code: NetworkError
2022-09-07 11:56:51.588 2886-11951/? W/GCoreUlr: dxgb: UNAVAILABLE: IOException when getting auth token
        at yxc.e(:com.google.android.gms@223412044@22.34.12 (190400-469381630):3)
        at cnlh.f(:com.google.android.gms@223412044@22.34.12 (190400-469381630):25)
        at cnlh.d(:com.google.android.gms@223412044@22.34.12 (190400-469381630):1)
        at cnlg.b(:com.google.android.gms@223412044@22.34.12 (190400-469381630):4)
        at zcg.onPerformSync(:com.google.android.gms@223412044@22.34.12 (190400-469381630):4)
        at android.content.AbstractThreadedSyncAdapter$SyncThread.run(AbstractThreadedSyncAdapter.java:334)
     Caused by: com.android.volley.VolleyError: java.io.IOException: NetworkError
        at ywr.t(:com.google.android.gms@223412044@22.34.12 (190400-469381630):6)
        at yxc.e(:com.google.android.gms@223412044@22.34.12 (190400-469381630):2)
        at cnlh.f(:com.google.android.gms@223412044@22.34.12 (190400-469381630):25) 
        at cnlh.d(:com.google.android.gms@223412044@22.34.12 (190400-469381630):1) 
        at cnlg.b(:com.google.android.gms@223412044@22.34.12 (190400-469381630):4) 
        at zcg.onPerformSync(:com.google.android.gms@223412044@22.34.12 (190400-469381630):4) 
        at android.content.AbstractThreadedSyncAdapter$SyncThread.run(AbstractThreadedSyncAdapter.java:334) 
     Caused by: java.io.IOException: NetworkError
        at khh.D(:com.google.android.gms@223412044@22.34.12 (190400-469381630):2)
        at khh.r(:com.google.android.gms@223412044@22.34.12 (190400-469381630):3)
        at kha.a(:com.google.android.gms@223412044@22.34.12 (190400-469381630):5)
        at khh.G(:com.google.android.gms@223412044@22.34.12 (190400-469381630):4)
        at khh.s(:com.google.android.gms@223412044@22.34.12 (190400-469381630):10)
        at khh.w(:com.google.android.gms@223412044@22.34.12 (190400-469381630):0)
        at kgy.h(:com.google.android.gms@223412044@22.34.12 (190400-469381630):0)
        at yya.b(:com.google.android.gms@223412044@22.34.12 (190400-469381630):4)
        at ywr.t(:com.google.android.gms@223412044@22.34.12 (190400-469381630):5)
        at yxc.e(:com.google.android.gms@223412044@22.34.12 (190400-469381630):2) 
        at cnlh.f(:com.google.android.gms@223412044@22.34.12 (190400-469381630):25) 
        at cnlh.d(:com.google.android.gms@223412044@22.34.12 (190400-469381630):1) 
        at cnlg.b(:com.google.android.gms@223412044@22.34.12 (190400-469381630):4) 
        at zcg.onPerformSync(:com.google.android.gms@223412044@22.34.12 (190400-469381630):4) 
        at android.content.AbstractThreadedSyncAdapter$SyncThread.run(AbstractThreadedSyncAdapter.java:334) 
2022-09-07 11:56:51.620 1770-2212/? W/SyncManager: failed sync operation JobId=100766 ***/com.google u0 [com.google.android.location.reporting] PERIODIC ExpectedIn=-11m22s Reason=Periodic, SyncResult: stats [ numIoExceptions: 1]
2022-09-07 11:56:52.101 1115-1217/? D/VSC: @ 501593.895: [WO] Proposed rotation: 0, flat angle threshold: 65
2022-09-07 11:56:52.101 1115-1217/? D/VSC: @ 501593.895: [WO] orientation angle 14, orientation 0
2022-09-07 11:56:52.101 1115-1217/? D/VSC: @ 501593.895: [WO] Gyro angle integrated: 0.853355
2022-09-07 11:56:52.101 1115-1217/? D/VSC: @ 501593.895: [WO] Gyro angle integrated: 0.853355
2022-09-07 11:56:54.077 1770-2131/? D/ConnectivityService: NetReassign [no changes]
2022-09-07 11:56:54.183 1115-1217/? D/VSC: @ 501595.977: [WO] Proposed rotation: 0, flat angle threshold: 65
2022-09-07 11:56:54.183 1115-1217/? D/VSC: @ 501595.977: [WO] orientation angle 21, orientation 0
2022-09-07 11:56:54.183 1115-1217/? D/VSC: @ 501595.977: [WO] Gyro angle integrated: 24.987869
2022-09-07 11:56:54.183 1115-1217/? D/VSC: @ 501595.977: [WO] Gyro angle integrated: 24.987869
2022-09-07 11:56:56.180 1115-1217/? D/VSC: @ 501597.969: [WO] Proposed rotation: 0, flat angle threshold: 65
2022-09-07 11:56:56.180 1115-1217/? D/VSC: @ 501597.969: [WO] orientation angle 20, orientation 0
2022-09-07 11:56:56.180 1115-1217/? D/VSC: @ 501597.969: [WO] Gyro angle integrated: 10.576399
2022-09-07 11:56:56.180 1115-1217/? D/VSC: @ 501597.969: [WO] Gyro angle integrated: 10.576399
2022-09-07 11:56:56.261 2351-19361/? D/NetworkMonitor/108: isDataStall: result=2, tcp packets received=0, latest tcp fail rate=100, consecutive dns timeout count=0
2022-09-07 11:56:56.262 2351-19361/? D/NetworkMonitor/108: Suspecting data stall, reevaluate
2022-09-07 11:56:56.262 1770-3534/? D/ConnectivityService: Data stall detected with methods: 2
2022-09-07 11:56:56.265 2351-12055/? D/NetworkMonitor/108: Validation disabled.
2022-09-07 11:56:56.277 1770-2131/? D/ConnectivityService: [108 WIFI] validation passed
2022-09-07 11:56:57.098 1770-2131/? D/ConnectivityService: NetReassign [no changes]
2022-09-07 11:56:57.291 1770-3144/? D/TelephonyManager: requestModemActivityInfo: Sending result to app: ModemActivityInfo{ mTimestamp=501596726 mSleepTimeMs=476663344 mIdleTimeMs=22561530 mTxTimeMs[]=[0, 0, 0, 0, 0] mRxTimeMs=2363387}
2022-09-07 11:56:57.313 1770-1885/? E/system_server: Cannot read thread CPU times for PID 1770
2022-09-07 11:56:58.173 1115-1217/? D/VSC: @ 501599.962: [WO] Proposed rotation: 0, flat angle threshold: 65
2022-09-07 11:56:58.173 1115-1217/? D/VSC: @ 501599.962: [WO] orientation angle 20, orientation 0
2022-09-07 11:56:58.173 1115-1217/? D/VSC: @ 501599.962: [WO] Gyro angle integrated: 2.359259
2022-09-07 11:56:58.173 1115-1217/? D/VSC: @ 501599.962: [WO] Gyro angle integrated: 2.359259
2022-09-07 11:57:00.023 3032-3315/? I/AiAiEcho: Predicting[0]: 
2022-09-07 11:57:00.024 3032-3315/? I/AiAiEcho: Ranked targets strategy: WEIGHTED, count: 0, ranking metadata: 
2022-09-07 11:57:00.026 3032-3315/? I/AiAiEcho: #postPredictionTargets: Sending updates to UISurface lockscreen with targets# 0
2022-09-07 11:57:00.028 3032-3315/? I/AiAiEcho: #postPredictionTargets: Sending updates to UISurface home with targets# 0
2022-09-07 11:57:00.029 3032-3315/? I/AiAiEcho: #postPredictionTargets: Sending updates to UISurface media_data_manager with targets# 0
2022-09-07 11:57:00.033 2536-2536/? E/BcSmartspaceCard: No tap action can be set up
2022-09-07 11:57:00.045 2214-2214/? E/BcSmartspaceCard: No tap action can be set up
2022-09-07 11:57:00.122 1770-2131/? D/ConnectivityService: NetReassign [no changes]
2022-09-07 11:57:00.161 1115-1217/? D/VSC: @ 501601.956: [WO] Proposed rotation: 0, flat angle threshold: 65
2022-09-07 11:57:00.161 1115-1217/? D/VSC: @ 501601.956: [WO] orientation angle 27, orientation 0
2022-09-07 11:57:00.161 1115-1217/? D/VSC: @ 501601.956: [WO] Gyro angle integrated: 10.896112
2022-09-07 11:57:00.162 1115-1217/? D/VSC: @ 501601.956: [WO] Gyro angle integrated: 10.896112
2022-09-07 11:57:00.893 11919-12029/com.google.chip.chiptool E/SC: PASESession timed out while waiting for a response from the peer. Expected message type was 33
2022-09-07 11:57:00.893 11919-12029/com.google.chip.chiptool D/IN: SecureSession[0x74889fc8f0]: Released - Type:1 LSID:31976
2022-09-07 11:57:00.894 11919-12029/com.google.chip.chiptool D/DeviceProvisioningFragment: Pairing status update: 1
2022-09-07 11:57:00.895 11919-12029/com.google.chip.chiptool D/DIS: Closing all BLE connections
2022-09-07 11:57:00.895 11919-12029/com.google.chip.chiptool D/DeviceProvisioningFragment: onPairingComplete: 50
2022-09-07 11:57:00.900 11919-11919/com.google.chip.chiptool I/DeviceProvisioningFragment: showMessage:Pairing failed

Bug prevalence

Always

GitHub hash of the SDK that was being used

chiptool

Platform

android

Platform Version(s)

No response

Type

Platform Issue

Anything else?

No response

stale[bot] commented 1 year ago

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs.

stale[bot] commented 1 year ago

This stale issue has been automatically closed. Thank you for your contributions.

edWin-m commented 1 year ago

@smokinghot I also have a device that produces this error. Do you know the meaning of that error code? @bzbarsky-apple Is there any documentation that has the list of error codes?

bzbarsky-apple commented 1 year ago

@bzbarsky-apple Is there any documentation that has the list of error codes?

https://github.com/bzbarsky-apple/connectedhomeip/blob/master/docs/ERROR_CODES.md

0x50 is CHIP_ERROR_UNSUPPORTED_CERT_FORMAT.

edWin-m commented 1 year ago

@bzbarsky-apple thanks