04-07 14:40:08.395 4458 5041 W bt_btif : bta_dm_acl_change info: 0x10 04-07 14:40:08.395 4458 4536 D bt_btif_dm: remote version info [00:42:79:a0:ec:50]: 0, 0, 0 04-07 14:40:08.407 4458 5041 I bt_stack: [INFO:btsnoop.cc(289)] whitelist_l2c_channel: Whitelisting l2cap channel. conn_handle=12 cid=0x0050:0x0080 04-07 14:40:08.414 4458 5041 E bt_btm : btm_process_remote_ext_features: Security procedure not started! status 0 04-07 14:40:08.414 4458 5041 E bt_btm : btm_establish_continue: Already link is up 04-07 14:40:08.418 4458 4536 I bt_stack: [INFO:btif_config.cc(647)] hash_file: Disabled for multi-user 04-07 14:40:08.418 4458 4536 I bt_stack: [INFO:btif_config.cc(689)] write_checksum_file: Disabled for multi-user, since config changed removing checksums. 04-07 14:40:08.424 5480 5480 D qsm2agent: onReceive action : android.bluetooth.device.action.ACL_CONNECTED 04-07 14:40:08.428 7146 7146 I UEI.SmartControl: --- Receive Intent: android.bluetooth.device.action.ACL_CONNECTED 04-07 14:40:08.430 7146 7146 D UEI.SmartControl: --- monitor intent: android.bluetooth.device.action.ACL_CONNECTED 04-07 14:40:08.430 4829 4829 D AtvRemote.BleDeviceManager: Bluetooth device 00:42:79:A0:EC:50 has connected 04-07 14:40:08.433 5311 5311 D BluetoothConnectionManager: [ mBluetoothReceiver ] action= .ACL_CONNECTED, JBL Flip 4 , deviceBoundState= 12, conncetionState= -1 04-07 14:40:08.434 6333 6333 E iSet : ACL LINK CONNECTED [JBL Flip 4] - checking for supported devices after delay 04-07 14:40:08.434 5480 5480 D qsm2agent: isRemocon configFilePath( /data/btv_home/config/rcu_prop.conf ) file exist 04-07 14:40:08.436 5480 5480 D qsm2agent: isRemocon add ouid list ( 8C:08:8B ) 04-07 14:40:08.436 5480 5480 D qsm2agent: isRemocon add ouid list ( 14:4E:34 ) 04-07 14:40:08.436 5480 5480 D qsm2agent: isRemocon add ouid list ( 20:44:41 ) 04-07 14:40:08.436 5480 5480 D qsm2agent: isRemocon add ouid list ( 00:13:7B ) 04-07 14:40:08.436 5480 5480 D qsm2agent: isRemocon add ouid list ( 40:19:20 ) 04-07 14:40:08.436 5480 5480 D qsm2agent: isRemocon add ouid list ( 9C:AC:6D ) 04-07 14:40:08.436 4829 4829 V AtvRemote.BleDeviceManager: Not connecting to 00:42:79:A0:EC:50 as the device type 1 is not supported 04-07 14:40:08.436 5480 5480 D qsm2agent: isRemocon add ouid list ( 70:91:F3 ) 04-07 14:40:08.436 5480 5480 D qsm2agent: isRemocon add ouid list ( 00:CC:3F ) 04-07 14:40:08.437 5311 5311 D BluetoothA2dp: Unbinding service... 04-07 14:40:08.438 4743 4743 I BLE_Service: >ACL LINK CONNECTED [JBL Flip 4] - checking for supported devices after delay 04-07 14:40:08.441 5480 5480 D qsm2agent: onReceive name : JBL Flip 4, mac : 00:42:79:A0:EC:50 desc= 240414 deviceClass= 1044 majorDeviceClass= 1024 deviceProfile= A2DP isRemocon= false 04-07 14:40:08.441 4771 4771 I VAS_BLE_Service: >ACL LINK CONNECTED [JBL Flip 4] - checking for supported devices after delay 04-07 14:40:08.446 4458 5041 I bt_stack: [INFO:btsnoop.cc(323)] clear_l2cap_whitelist: Clearing whitelist from l2cap channel. conn_handle=12 cid=80:128 04-07 14:40:08.447 5311 5311 D BluetoothA2dp: Binding service... 04-07 14:40:08.448 5480 5480 D qsm2agent: SkbLogService sendData 04-07 14:40:08.448 5480 5480 D qsm2lib.jar: QSM Report start [BT_PAIRING] 04-07 14:40:08.448 5480 5480 D qsm2agent: SkbLogService sendData getReportString:{"device_info_bt":{"bt_device_name":"JBL Flip 4","bt_mac":"00:42:79:A0:EC:50","bt_device_profile":"A2DP","bt_status":1},"log_info_type":"Q1","log_time":"20220407144008.008"} 04-07 14:40:08.449 6199 6199 D AGENT : JBL Flip 4 @@@@@@@@@Device Is Connected! 04-07 14:40:08.449 6199 6199 D AGENT : ^^^device address : 00:42:79:A0:EC:50 token=>>>20:73:3E | 04-07 14:40:08.449 6199 6199 D AGENT : ^^^device address : 00:42:79:A0:EC:50 token=>>>8C:08:8B | 04-07 14:40:08.449 6199 6199 D AGENT : ^^^device address : 00:42:79:A0:EC:50 token=>>>00:13:7B | 04-07 14:40:08.449 6199 6199 D AGENT : ^^^device address : 00:42:79:A0:EC:50 token=>>>14:4E:34 | 04-07 14:40:08.449 6199 6199 D AGENT : ^^^device address : 00:42:79:A0:EC:50 token=>>>9C:AC:6D | 04-07 14:40:08.449 6199 6199 D AGENT : ^^^device address : 00:42:79:A0:EC:50 token=>>>40:19:20 | 04-07 14:40:08.449 5480 5480 D qsm2lib.jar: QSM QSM2Transfer addQueueSendData start queue size : 0 04-07 14:40:08.449 6199 6199 D AGENT : ^^^device address : 00:42:79:A0:EC:50 token=>>>70:91:F3 | 04-07 14:40:08.449 6199 6199 D AGENT : ^^^device address : 00:42:79:A0:EC:50 token=>>>00:CC:3F | 04-07 14:40:08.449 6199 6199 I AGENT : ###@@ send_data=;100;1;1;14:4E:34:A1:56:4D 04-07 14:40:08.449 5480 5480 D qsm2agent: SkbLogService reportQSMApp SUCCESS 04-07 14:40:08.449 6199 6199 D isqms_agent: ###### CISQMS::set_data nCategoryID=1, SubCategoryID=5, nFieldID=-1, dataLen = 26, pData=;100;1;1;14:4E:34:A1:56:4D 04-07 14:40:08.449 6199 6199 D isqms_agent: INFO:push_data nType=2 04-07 14:40:08.449 6199 6199 D isqms_agent: @@@@@@@@@@@@@@@@@@@@@@@ push m_nEventCnt = 1 04-07 14:40:08.450 5480 5525 D qsm2lib.jar: QSM QSM2Transfer ConnectSendRunnable: Thread Run timeout : 120 04-07 14:40:08.450 5480 5525 D qsm2lib.jar: QSM QSM2Transfer : sendData to QSM service write start - byte data size =184 04-07 14:40:08.450 4983 5527 I QSM : QSM service: Multi-socket [recv_thread] read data size(socket=4, index=0)=184, g_is_connection_restricted=0, g_sleep_status=0 04-07 14:40:08.450 5480 5525 D qsm2lib.jar: QSM QSM2Transfer : sendData to QSM service write end - byte data size =184 04-07 14:40:08.450 4983 5527 I QSM : QSM [recv_thread] read data - put qsm msg : BT_PAIRING, size : 184 04-07 14:40:08.450 4983 5527 I QSM : QSM [recv_thread] read data - after put msg BT_PAIRING : wake up send thread 04-07 14:40:08.450 4983 5098 I QSM : QSM service - send_thread : type of received mesage = BT_PAIRING(len=10) 04-07 14:40:08.450 4983 5098 I QSM : QSM : qsm_log_switch_parse_others type : BT_PAIRING, : {"device_info_bt":{"bt_device_name":"JBL Flip 4","bt_mac":"00:42:79:A0:EC:50","bt_device_profile":"A2DP","bt_status":1},"log_info_type":"Q1","log_time":"20220407144008.008"} 04-07 14:40:08.450 4983 5098 I QSM : QSM : log switch off - skip key : device_info_bt 04-07 14:40:08.450 4983 5098 I QSM : QSM s_qsm_send_thread - not exist valid data : skip sending event. type : BT_PAIRING 04-07 14:40:08.451 7146 7146 D UEI.SmartControl: >> dumpSkbBTDevices : 1 04-07 14:40:08.454 5311 5311 D BluetoothManager: getInstance|| 04-07 14:40:08.454 5311 5311 D BluetoothManager: getConnectedDevicesCount: 2| 04-07 14:40:08.454 5311 5311 D MainActivity: onDeviceChange|2, count: 2| 04-07 14:40:08.454 5311 5311 D STBAPIManager: setBlueToothUsing called : 2 04-07 14:40:08.455 5528 5552 D PropertyService: BTF|setStringwithpPackage|549|propertyservice: setString service_type:1, key:PROPERTY_BLUETOOTH_USING, value:2, packageName : com.skb.tv 04-07 14:40:08.456 3557 3781 I SystemPropertyManager: change property : PROPERTY_BLUETOOTH_USING 04-07 14:40:08.457 3557 3781 I TVService-21.08.18: [vendor/skb/framework/btf_dev/interface/btvservice/1.0/default/TVService.cpp][staticPropertyChange] called 04-07 14:40:08.457 3557 3781 I TVService-21.08.18: [vendor/skb/framework/btf_dev/interface/btvservice/1.0/default/TVService.cpp][staticPropertyChange][105] message received key=PROPERTY_BLUETOOTH_USING, value= 04-07 14:40:08.457 3557 3781 I TVService-21.08.18: [TVService::onProperyUpdatedEvent]: key(PROPERTY_BLUETOOTH_USING), value() 04-07 14:40:08.457 3557 3781 I TVService-21.08.18: [vendor/skb/framework/btf_dev/interface/btvservice/1.0/default/TVService.cpp][onProperyUpdatedEvent][271] callback application 04-07 14:40:08.457 3557 3781 I TVService-21.08.18: [vendor/skb/framework/btf_dev/interface/btvservice/1.0/default/TVService.cpp][onProperyUpdatedEvent][276] back from callback 04-07 14:40:08.457 5528 7289 D BTVCORE-JNI: [updatedProperty] message received key=PROPERTY_BLUETOOTH_USING, value= 04-07 14:40:08.457 5528 7289 D BtvJniInterface: BTF|postPropertyUpdateFromNative|844|postEventFromProperty 04-07 14:40:08.457 5528 7289 D PropertyService: BTF|onHandleEvent|488|onHandleEvent type = 1 key = PROPERTY_BLUETOOTH_USING 04-07 14:40:08.457 5528 7289 D PropertyService: BTF|onHandleEvent|494|propertyservice: setChangePropertyListener onHandleEvent start callback count=1 BUILD_DATE:2021.11.15 04-07 14:40:08.457 5528 7289 D PropertyService: BTF|onHandleEvent|498|propertyservice: setChangePropertyListener onHandleEvent packeage=package com.skb.btv.framework.property, Unknown, version 0.0 04-07 14:40:08.458 6042 6066 D PropertyManager: BTF|ChangePropertyCallback|519| ChangePropertyCallback ChangePropertyListener start type=1, key=PROPERTY_BLUETOOTH_USING 04-07 14:40:08.462 5311 5311 D STBAPIManager: setProperty() isOK : true, key : PROPERTY_BLUETOOTH_USING, value : 2 04-07 14:40:08.462 5311 5311 I MainActivity: RemoteSettinginit() called 04-07 14:40:08.463 7146 7146 D UEI.SmartControl: SKB list [0]JBL Flip 4, 1, 00:42:79:A0:EC:50, bond : 12, acl : true reconnected : false 04-07 14:40:08.471 5311 5311 I BluetoothManager: setRemoconAddress() called - Address : 14:4E:34:92:1C:B3 04-07 14:40:08.471 5311 5311 I BluetoothManager: setRemoteName() called - name : BRM_BA01_CB3 04-07 14:40:08.471 5311 5311 D MainActivity: RemoteSettinginit() - isPairing : true 04-07 14:40:08.471 5311 5311 I Main_RemoteUpdate: getRemoteCurrentVersion() called 04-07 14:40:08.472 5311 5311 I SendInterfaceManager: SendInterfaceManager getInstance 04-07 14:40:08.472 5311 5311 I SendInterfaceManager: sendRefreshPropertyWeb propertyName : PROPERTY_BLUETOOTH_USING 04-07 14:40:08.473 5311 5311 I G2TvFragment: isFragmentHidden() isFragmentHidden : true 04-07 14:40:08.473 5311 5311 I SendInterfaceManager: sendRefreshPropertyWeb web is not visible 04-07 14:40:08.473 5311 5311 D BatteryLevel: GlobalGattInit() called 04-07 14:40:08.473 5311 5311 D BluetoothManager: getInstance|| 04-07 14:40:08.474 5311 8532 I Main_RemoteUpdate: [start] getRemoteDeviceInfo 04-07 14:40:08.485 5311 5311 I BluetoothManager: setUpdateRemoconAddress() called - Address : 14:4E:34:92:1C:B3 04-07 14:40:08.485 5311 5311 I BluetoothManager: setUpdateRemoteName() called - name : BRM_BA01_CB3 04-07 14:40:08.485 5311 5311 I STBGlobal: setUpdateRemoteName() called - name : BRM_BA01_CB3 04-07 14:40:08.485 5311 5311 D BluetoothManager: [ BluetoothManager ] isRemoconUpdateConnected = true 04-07 14:40:08.485 5311 5311 D BatteryLevel: GlobalGattInit mIsRemotePairing : true 04-07 14:40:08.485 5311 5311 I BluetoothManager: getUpdateRemoconAddress() called - Address : 14:4E:34:92:1C:B3 04-07 14:40:08.485 5311 5311 D BatteryLevel: init mBtGatt : null 04-07 14:40:08.485 5311 5311 I GlobalGatt: initial 04-07 14:40:08.485 5311 5311 I GlobalGatt: initialize() 04-07 14:40:08.486 5311 5311 I GlobalGatt: registerCallback, addr: 14:4E:34:92:1C:B3 04-07 14:40:08.486 5311 5311 D GlobalGatt: mCallbacks.get(addr) == null, addr: 14:4E:34:92:1C:B3 04-07 14:40:08.486 5311 5311 D GlobalGatt: mCallbacks.get(addr) = [com.skb.google.tv.global.STBGlobal$11@c25e17b]. mCallbacks.size(): 1, addr: 14:4E:34:92:1C:B3 04-07 14:40:08.486 5311 5311 D GlobalGatt: mCallbacks list: 14:4E:34:92:1C:B3 04-07 14:40:08.486 5311 5311 D GlobalGatt: Trying to create a new connection. 04-07 14:40:08.486 5311 5311 D BluetoothGatt: connect() - device: 14:4E:34:92:1C:B3, auto: false 04-07 14:40:08.486 5311 5311 D BluetoothGatt: registerApp() 04-07 14:40:08.486 5311 5311 D BluetoothGatt: registerApp() - UUID=3bbc41b6-37c6-4004-90bf-e639c3d4f083 04-07 14:40:08.488 4458 5041 I bt_stack: [INFO:gatt_api.cc(947)] GATT_Register 45b96313-3522-b567-6120-8db007c0035a 04-07 14:40:08.488 4458 5041 I bt_stack: [INFO:gatt_api.cc(967)] allocated gatt_if=7 04-07 14:40:08.492 5311 5334 D BluetoothGatt: onClientRegistered() - status=0 clientIf=7 04-07 14:40:08.495 4458 4536 D bt_btif_config: btif_get_address_type: Device [14:4e:34:92:1c:b3] address type 0 04-07 14:40:08.495 4458 4536 D bt_btif_config: btif_get_device_type: Device [14:4e:34:92:1c:b3] type 2 04-07 14:40:08.496 4458 5041 I bt_stack: [INFO:gatt_api.cc(1105)] GATT_Connectgatt_if=7, address=14:4e:34:92:1c:b3 04-07 14:40:08.495 5311 5311 D STBAPIManager: getProperty() key : PROPERTY_REMOTE_BATTERY, result : 2 04-07 14:40:08.497 5311 5334 D BluetoothGatt: onClientConnectionState() - status=0 clientIf=7 device=14:4E:34:92:1C:B3 04-07 14:40:08.497 5311 5311 I STBGlobal: getBattery - property : 2, eBATTERY : NORMAL_BATTERY 04-07 14:40:08.497 5311 5334 D GlobalGatt: mBluetoothGatts.get(addr) = android.bluetooth.BluetoothGatt@3e0e549. mBluetoothGatts.size(): 1, addr: 14:4E:34:92:1C:B3 04-07 14:40:08.497 5311 5334 D GlobalGatt: mBluetoothGatts list: 14:4E:34:92:1C:B3 04-07 14:40:08.497 5311 5311 D BluetoothManager: getInstance|| 04-07 14:40:08.497 5311 5311 D BluetoothManager: getConnectedDevicesCount: 2| 04-07 14:40:08.497 5311 5334 D BatteryLevel: onConnectionStateChange: status = 0,newState = 2 04-07 14:40:08.497 5311 5311 D MainActivity: onDeviceChange|2, count: 2| 04-07 14:40:08.497 5311 5334 D BatteryLevel: device connected 04-07 14:40:08.497 5311 5334 D BatteryLevel: Start to Discovery 04-07 14:40:08.497 5311 5334 D BluetoothGatt: discoverServices() - device: 14:4E:34:92:1C:B3 04-07 14:40:08.497 5311 5311 D STBAPIManager: setBlueToothUsing called : 2 04-07 14:40:08.498 5528 5552 D PropertyService: BTF|setStringwithpPackage|549|propertyservice: setString service_type:1, key:PROPERTY_BLUETOOTH_USING, value:2, packageName : com.skb.tv 04-07 14:40:08.500 3557 3781 I SystemPropertyManager: change property : PROPERTY_BLUETOOTH_USING 04-07 14:40:08.500 3557 3781 I TVService-21.08.18: [vendor/skb/framework/btf_dev/interface/btvservice/1.0/default/TVService.cpp][staticPropertyChange] called 04-07 14:40:08.500 3557 3781 I TVService-21.08.18: [vendor/skb/framework/btf_dev/interface/btvservice/1.0/default/TVService.cpp][staticPropertyChange][105] message received key=PROPERTY_BLUETOOTH_USING, value= 04-07 14:40:08.500 3557 3781 I TVService-21.08.18: [TVService::onProperyUpdatedEvent]: key(PROPERTY_BLUETOOTH_USING), value() 04-07 14:40:08.500 3557 3781 I TVService-21.08.18: [vendor/skb/framework/btf_dev/interface/btvservice/1.0/default/TVService.cpp][onProperyUpdatedEvent][271] callback application 04-07 14:40:08.500 5528 7289 D BTVCORE-JNI: [updatedProperty] message received key=PROPERTY_BLUETOOTH_USING, value= 04-07 14:40:08.501 5528 7289 D BtvJniInterface: BTF|postPropertyUpdateFromNative|844|postEventFromProperty 04-07 14:40:08.501 5528 7289 D PropertyService: BTF|onHandleEvent|488|onHandleEvent type = 1 key = PROPERTY_BLUETOOTH_USING 04-07 14:40:08.501 5528 7289 D PropertyService: BTF|onHandleEvent|494|propertyservice: setChangePropertyListener onHandleEvent start callback count=1 BUILD_DATE:2021.11.15 04-07 14:40:08.501 5528 7289 D PropertyService: BTF|onHandleEvent|498|propertyservice: setChangePropertyListener onHandleEvent packeage=package com.skb.btv.framework.property, Unknown, version 0.0 04-07 14:40:08.501 3557 3781 I TVService-21.08.18: [vendor/skb/framework/btf_dev/interface/btvservice/1.0/default/TVService.cpp][onProperyUpdatedEvent][276] back from callback 04-07 14:40:08.502 6042 6066 D PropertyManager: BTF|ChangePropertyCallback|519| ChangePropertyCallback ChangePropertyListener start type=1, key=PROPERTY_BLUETOOTH_USING 04-07 14:40:08.505 4458 5041 I bt_stack: [INFO:btsnoop.cc(311)] add_rfc_l2c_channel: rfcomm data going over l2cap channel. conn_handle=12 cid=0x0051:0x00c0 04-07 14:40:08.506 4458 4536 E BtGatt.GattService: name: BRM_BA01_CB3 04-07 14:40:08.506 5311 5311 D STBAPIManager: setProperty() isOK : true, key : PROPERTY_BLUETOOTH_USING, value : 2 04-07 14:40:08.507 5311 5311 I MainActivity: RemoteSettinginit() called 04-07 14:40:08.507 5311 5334 D BluetoothGatt: onConfigureMTU() - Device=14:4E:34:92:1C:B3 mtu=123 status=0 04-07 14:40:08.529 4458 4536 D bt_bta_gattc: bta_gattc_get_gatt_db 04-07 14:40:08.532 4458 5041 I bt_stack: [INFO:port_utils.cc(322)] port_find_mcb_dlci_port: Cannot find allocated RFCOMM app port for DLCI 6 on 00:42:79:a0:ec:50, p_mcb=0xc9f20fbc 04-07 14:40:08.538 5311 5311 I BluetoothManager: setRemoconAddress() called - Address : 14:4E:34:92:1C:B3 04-07 14:40:08.538 5311 5311 I BluetoothManager: setRemoteName() called - name : BRM_BA01_CB3 04-07 14:40:08.538 5311 5311 D MainActivity: RemoteSettinginit() - isPairing : true 04-07 14:40:08.538 5311 5311 I Main_RemoteUpdate: getRemoteCurrentVersion() called 04-07 14:40:08.538 5311 5311 I Main_RemoteUpdate: getRemoteCurrentVersion() remoteFlag : true 04-07 14:40:08.538 5311 5311 I SendInterfaceManager: SendInterfaceManager getInstance 04-07 14:40:08.538 5311 5311 I SendInterfaceManager: sendRefreshPropertyWeb propertyName : PROPERTY_BLUETOOTH_USING 04-07 14:40:08.538 5311 5311 I G2TvFragment: isFragmentHidden() isFragmentHidden : true 04-07 14:40:08.564 3557 3557 W HwBinder:3557_2: type=1400 audit(0.0:848): avc: denied { read } for name="u:object_r:default_prop:s0" dev="tmpfs" ino=13241 scontext=u:r:btvservice_hal:s0 tcontext=u:object_r:default_prop:s0 tclass=file permissive=0 04-07 14:40:08.538 5311 5311 I SendInterfaceManager: sendRefreshPropertyWeb web is not visible 04-07 14:40:08.539 5311 5334 D BluetoothGatt: onSearchComplete() = Device=14:4E:34:92:1C:B3 Status=0 04-07 14:40:08.540 5311 5334 D BatteryLevel: onServicesDiscovered: status = 0 04-07 14:40:08.538 5311 5311 D BatteryLevel: GlobalGattInit() called 04-07 14:40:08.542 5311 5311 D BluetoothManager: getInstance|| 04-07 14:40:08.543 5311 5334 V BatteryLevel: batteryLevel = false 04-07 14:40:08.552 5311 5311 I BluetoothManager: setUpdateRemoconAddress() called - Address : 14:4E:34:92:1C:B3 04-07 14:40:08.552 5311 5311 I BluetoothManager: setUpdateRemoteName() called - name : BRM_BA01_CB3 04-07 14:40:08.552 5311 5311 I STBGlobal: setUpdateRemoteName() called - name : BRM_BA01_CB3 04-07 14:40:08.552 5311 5311 D BluetoothManager: [ BluetoothManager ] isRemoconUpdateConnected = true 04-07 14:40:08.552 5311 5311 D BatteryLevel: GlobalGattInit mIsRemotePairing : true 04-07 14:40:08.552 5311 5311 I BluetoothManager: getUpdateRemoconAddress() called - Address : 14:4E:34:92:1C:B3 04-07 14:40:08.552 5311 5311 D BatteryLevel: init mBtGatt : android.bluetooth.BluetoothGatt@3e0e549 04-07 14:40:08.554 5311 5311 D STBAPIManager: getProperty() key : PROPERTY_REMOTE_BATTERY, result : 2 04-07 14:40:08.554 5311 5311 I STBGlobal: getBattery - property : 2, eBATTERY : NORMAL_BATTERY 04-07 14:40:08.554 5311 5311 D BluetoothA2dp: Proxy object connected 04-07 14:40:08.555 5311 5311 D BluetoothConnectionManager: [mBluetoothReceiver] A2DP onServiceConnected profile:2 04-07 14:40:08.555 5311 5311 D BluetoothConnectionManager: [mBluetoothReceiver]BluetoothProfile.A2DP 04-07 14:40:08.558 3836 8435 W ActivityManager: Unable to start service Intent { act=android.bluetooth.device.action.ACL_CONNECTED cmp=com.google.android.gms/.nearby.discovery.service.DiscoveryService (has extras) } U=0: not found 04-07 14:40:08.570 3557 8391 E libc : Access denied finding property "skb.audio.output" 04-07 14:40:08.602 4458 5041 I bt_stack: [INFO:btsnoop.cc(300)] whitelist_rfc_dlci: Whitelisting rfcomm channel. L2CAP CID=0x0051 DLCI=0x06 04-07 14:40:08.602 4458 5041 I bt_stack: [INFO:port_api.cc(300)] RFCOMM_RemoveServer: handle=19 04-07 14:40:08.602 4458 5041 W bt_btif : new conn_srvc id:5, app_id:1 04-07 14:40:08.603 4458 5041 I bt_stack: [INFO:bta_ag_sco.cc(1174)] bta_ag_sco_listen: 00:42:79:a0:ec:50 04-07 14:40:08.603 4458 5041 W bt_stack: [WARNING:bta_ag_sco.cc(372)] bta_ag_create_sco: device 00:42:79:a0:ec:50 is not active, active_device=00:00:00:00:00:00 04-07 14:40:08.605 4458 4536 I BluetoothHeadsetServiceJni: ConnectionStateCallback 2 for 00:42:79:a0:ec:50 04-07 14:40:08.606 4458 5059 D BluetoothAdapterService: isQuetModeEnabled() - Enabled = false 04-07 14:40:08.607 4458 5059 V BluetoothDatabase: getProfilePriority: 00:42:79:A0:EC:50, profile=1, priority = 1000 04-07 14:40:08.614 4458 5059 I HeadsetStateMachine: Disconnected: currentDevice=00:42:79:A0:EC:50, msg=accept incoming connection 04-07 14:40:08.621 4458 4458 I BluetoothPhonePolicy: processProfileStateChanged, device=00:42:79:A0:EC:50, profile=1, 0 -> 1 04-07 14:40:08.621 4458 4458 D AdapterProperties: PROFILE_CONNECTION_STATE_CHANGE: profile=1, device=00:42:79:A0:EC:50, 0 -> 1 04-07 14:40:08.624 7572 7572 D CachedBluetoothDevice: onProfileStateChanged: profile HEADSET, device=00:42:79:A0:EC:50, newProfileState 1 04-07 14:40:08.638 7572 7572 D BtvBtPairingService: sptek:BT onProfileConnectionStateChanged name = JBL Flip 4, connectState = STATE_CONNECTING_1, bluetoothProfile = 1, controlState = 0 04-07 14:40:08.652 4458 5041 I bt_stack: [INFO:btsnoop.cc(289)] whitelist_l2c_channel: Whitelisting l2cap channel. conn_handle=12 cid=0x0052:0x0101 04-07 14:40:08.652 3836 8435 W ActivityManager: Unable to start service Intent { act=android.bluetooth.headset.profile.action.CONNECTION_STATE_CHANGED cmp=com.google.android.gms/.nearby.discovery.service.DiscoveryService (has extras) } U=0: not found 04-07 14:40:08.656 4458 5041 I bt_stack: [INFO:btsnoop.cc(289)] whitelist_l2c_channel: Whitelisting l2cap channel. conn_handle=12 cid=0x0052:0x0101 04-07 14:40:08.676 4458 5041 W bt_sdp : process_service_search_attr_rsp 04-07 14:40:08.682 3557 8407 W RendererPolicyBase_0: video render: 59.94 fps, drop: 0.00 fps 04-07 14:40:08.686 4458 5041 I bt_stack: [INFO:btsnoop.cc(323)] clear_l2cap_whitelist: Clearing whitelist from l2cap channel. conn_handle=12 cid=82:257 04-07 14:40:08.738 4458 4536 I BluetoothHeadsetServiceJni: ConnectionStateCallback 3 for 00:42:79:a0:ec:50 04-07 14:40:08.740 4458 5059 I HeadsetPhoneState: stopListenForPhoneState(), no listener indicates nothing is listening 04-07 14:40:08.740 4458 5059 W HeadsetPhoneState: startListenForPhoneState, invalid subscription ID -1 04-07 14:40:08.740 4458 5059 E HeadsetSystemInterface: Handsfree phone proxy null for query phone state 04-07 14:40:08.749 4458 4458 I BluetoothPhonePolicy: processProfileStateChanged, device=00:42:79:A0:EC:50, profile=1, 1 -> 2 04-07 14:40:08.749 4458 4458 D BluetoothAdapterService: isQuetModeEnabled() - Enabled = false 04-07 14:40:08.750 4458 4537 D BluetoothActiveDeviceManager: handleMessage(MESSAGE_HFP_ACTION_CONNECTION_STATE_CHANGED): device 00:42:79:A0:EC:50 connected 04-07 14:40:08.750 4458 4537 D BluetoothActiveDeviceManager: setHfpActiveDevice(00:42:79:A0:EC:50) 04-07 14:40:08.750 4458 4458 D AdapterProperties: PROFILE_CONNECTION_STATE_CHANGE: profile=1, device=00:42:79:A0:EC:50, 1 -> 2 04-07 14:40:08.752 4458 4537 I HeadsetService: setActiveDevice: device=00:42:79:A0:EC:50, uid/pid=1002/4458 04-07 14:40:08.754 7572 7572 D CachedBluetoothDevice: onProfileStateChanged: profile HEADSET, device=00:42:79:A0:EC:50, newProfileState 2 04-07 14:40:08.757 3836 3836 I AS.BtHelper: setBtScoActiveDevice: null -> 00:42:79:A0:EC:50 04-07 14:40:08.759 4458 4537 D BluetoothActiveDeviceManager: handleMessage(MESSAGE_HFP_ACTION_ACTIVE_DEVICE_CHANGED): device= 00:42:79:A0:EC:50 04-07 14:40:08.670 3836 8435 W ActivityManager: Unable to start service Intent { act=android.bluetooth.headset.profile.action.CONNECTION_STATE_CHANGED cmp=com.google.android.gms/.nearby.discovery.service.DiscoveryService (has extras) } U=0: not found 04-07 14:40:08.761 3836 3836 I AS.AudioDeviceInventory: handleDeviceConnection(true dev:10 address:00:42:79:A0:EC:50 name:JBL Flip 4) 04-07 14:40:08.761 3836 3836 I AS.AudioDeviceInventory: deviceKey:0x10:00:42:79:A0:EC:50 04-07 14:40:08.761 3836 3836 I AS.AudioDeviceInventory: deviceInfo:null is(already)Connected:false 04-07 14:40:08.762 3521 3923 E APM::HwModule: createDevice: could not find HW module for device 0010 address 00:42:79:A0:EC:50 04-07 14:40:08.762 3836 3836 E AudioSystem-JNI: Command failed for android_media_AudioSystem_setDeviceConnectionState: -38 04-07 14:40:08.762 3836 3836 E AS.AudioDeviceInventory: not connecting device 0x10 due to command error 1 04-07 14:40:08.762 3836 3836 I AS.AudioDeviceInventory: handleDeviceConnection(true dev:80000008 address:00:42:79:A0:EC:50 name:JBL Flip 4) 04-07 14:40:08.762 3836 3836 I AS.AudioDeviceInventory: deviceKey:0x80000008:00:42:79:A0:EC:50 04-07 14:40:08.762 3836 3836 I AS.AudioDeviceInventory: deviceInfo:[DeviceInfo: type:0x80000008 name:JBL Flip 4 addr:00:42:79:A0:EC:50 codec: 0] is(already)Connected:true 04-07 14:40:08.762 3836 3836 W AS.AudioDeviceInventory: handleDeviceConnection() failed, deviceKey=0x80000008:00:42:79:A0:EC:50, deviceSpec=[DeviceInfo: type:0x80000008 name:JBL Flip 4 addr:00:42:79:A0:EC:50 codec: 0], connect=true 04-07 14:40:08.762 3836 3836 E AS.BtHelper: setBtScoActiveDevice() failed to add new device 00:42:79:A0:EC:50 04-07 14:40:08.763 3486 8511 D audio_hw_primary: adev_set_parameters(0xea775280, A2dpSuspended=false) 04-07 14:40:08.763 3486 8511 I audio_hw_primary: adev_set_parameters(kv: A2dpSuspended=false) 04-07 14:40:08.763 3486 8511 I audio_hw_primary: adev_set_parameters, ret=-2, value=⚌*r⚌ 04-07 14:40:08.763 3486 8511 I audio_hw_primary: Amlogic_HAL - adev_set_parameters: return Result::NOT_SUPPORTED (4) instead of other error code. 04-07 14:40:08.765 3486 3587 D audio_hw_primary: adev_set_parameters(0xea775280, BT_SCO=off) 04-07 14:40:08.765 3486 3587 I audio_hw_primary: adev_set_parameters(kv: BT_SCO=off) 04-07 14:40:08.765 3486 3587 I audio_hw_primary: adev_set_parameters, ret=-2, value=⚌ep⚌ep⚌ 04-07 14:40:08.765 3486 3587 I audio_hw_primary: Amlogic_HAL - adev_set_parameters: return Result::NOT_SUPPORTED (4) instead of other error code. 04-07 14:40:08.768 7572 7572 D BtvBtPairingService: sptek:BT onProfileConnectionStateChanged name = JBL Flip 4, connectState = STATE_CONNECTED_2, bluetoothProfile = 1, controlState = 0 04-07 14:40:08.784 3836 5597 W ActivityManager: Unable to start service Intent { act=android.bluetooth.headset.profile.action.CONNECTION_STATE_CHANGED cmp=com.google.android.gms/.nearby.discovery.service.DiscoveryService (has extras) } U=0: not found 04-07 14:40:08.793 3836 8435 W ActivityManager: Unable to start service Intent { act=android.bluetooth.headset.profile.action.CONNECTION_STATE_CHANGED cmp=com.google.android.gms/.nearby.discovery.service.DiscoveryService (has extras) } U=0: not found 04-07 14:40:08.802 3836 8435 D AS.AudioService: setStreamVolume streamType = 6index = 10 04-07 14:40:08.802 3836 8435 D AS.AudioService: getPropertyVolume(AudioSystem.STREAM_BLUETOOTH_SCO) index = 5 04-07 14:40:08.802 3836 8435 D AS.AudioService: setStreamVolume(stream=6, index=5, calling=com.android.bluetooth) 04-07 14:40:08.803 3836 8435 D AS.AudioService: streamType = 6, device = hdmi called : com.android.bluetooth 04-07 14:40:08.804 4458 5041 I bt_stack: [INFO:btsnoop.cc(289)] whitelist_l2c_channel: Whitelisting l2cap channel. conn_handle=12 cid=0x0053:0x0141 04-07 14:40:08.806 4458 5041 I bt_stack: [INFO:btsnoop.cc(289)] whitelist_l2c_channel: Whitelisting l2cap channel. conn_handle=12 cid=0x0054:0x0182 04-07 14:40:08.812 3836 8435 D VolumeController: salmon postVolumeChanged streamType = 3 04-07 14:40:08.824 4458 5041 I bt_bta_av: bta_av_conn_cback: conn_cback bd_addr: 00:42:79:a0:ec:50 04-07 14:40:08.824 4458 5041 I bt_bta_av: bta_av_sig_chg: AVDT_CONNECT_IND_EVT: peer 00:42:79:a0:ec:50 selected lcb_index 0 04-07 14:40:08.824 4458 5041 W bt_btif : bta_av_rc_create: Skipping RC creation for the old AVRCP profile 04-07 14:40:08.824 4458 5041 D bt_bta_av: SetAvdtpVersion: AVDTP version for 00:42:79:a0:ec:50 set to 0x103 04-07 14:40:08.825 4458 5041 W bt_btif : bta_dm_rm_cback:2, status:0 04-07 14:40:08.825 4458 5041 W bt_btif : new conn_srvc id:18, app_id:0 04-07 14:40:08.825 4458 5041 I btif_av : BtifAvPeer *BtifAvSource::FindOrCreatePeer(const RawAddress &, tBTA_AV_HNDL): Create peer: peer_address=00:42:79:a0:ec:50 bta_handle=0x41 peer_id=0 04-07 14:40:08.825 4458 5041 W bt_btif : btif_av_get_peer_sep: No active peer found 04-07 14:40:08.825 4458 5041 I bt_btif_a2dp: btif_a2dp_on_idle: ## ON A2DP IDLE ## peer_sep = 1 04-07 14:40:08.825 4458 5041 W bt_btif : btif_av_get_peer_sep: No active peer found 04-07 14:40:08.825 4458 5041 I bt_btif_a2dp_source: btif_a2dp_source_on_idle: state=STATE_OFF 04-07 14:40:08.825 4458 5041 I bt_bta_av: BTA_AvOpen: peer 00:42:79:a0:ec:50 handle:0x41 use_rc=true sec_mask=0x12 uuid=0x110a 04-07 14:40:08.825 4458 5041 I btif_av : btif_report_connection_state: peer_address=00:42:79:a0:ec:50 state=1 04-07 14:40:08.828 4458 4536 I BluetoothA2dpServiceJni: bta2dp_connection_state_callback 04-07 14:40:08.829 4458 4536 D A2dpNativeInterface: onConnectionStateChanged: A2dpStackEvent {type:EVENT_TYPE_CONNECTION_STATE_CHANGED, device:00:42:79:A0:EC:50, value1:CONNECTING} 04-07 14:40:08.829 4458 5062 D A2dpStateMachine: handleMessage: E msg.what=101 04-07 14:40:08.829 4458 5062 D A2dpStateMachine: processMsg: Disconnected 04-07 14:40:08.829 4458 5062 D A2dpStateMachine: Disconnected process message(00:42:79:A0:EC:50): STACK_EVENT 04-07 14:40:08.830 4458 5062 D A2dpStateMachine: Disconnected: stack event: A2dpStackEvent {type:EVENT_TYPE_CONNECTION_STATE_CHANGED, device:00:42:79:A0:EC:50, value1:CONNECTING} 04-07 14:40:08.830 4458 5062 I A2dpService: okToConnect: device 00:42:79:A0:EC:50 isOutgoingRequest: false 04-07 14:40:08.830 4458 5062 D BluetoothAdapterService: isQuetModeEnabled() - Enabled = false 04-07 14:40:08.831 4458 5062 V BluetoothDatabase: getProfilePriority: 00:42:79:A0:EC:50, profile=2, priority = 1000 04-07 14:40:08.832 4458 5062 I A2dpStateMachine: Incoming A2DP Connecting request accepted: 00:42:79:A0:EC:50 04-07 14:40:08.832 4458 5062 D A2dpStateMachine: transitionTo: destState=Connecting 04-07 14:40:08.832 4458 5062 D A2dpStateMachine: handleMessage: new destination call exit/enter 04-07 14:40:08.832 4458 5062 D A2dpStateMachine: setupTempStateStackWithStatesToEnter: X mTempStateStackCount=1,curStateInfo: null 04-07 14:40:08.832 4458 5062 D A2dpStateMachine: invokeExitMethods: Disconnected 04-07 14:40:08.832 4458 5062 D A2dpStateMachine: Exit Disconnected(00:42:79:A0:EC:50): STACK_EVENT 04-07 14:40:08.833 4458 5062 D A2dpStateMachine: moveTempStackToStateStack: i=0,j=0 04-07 14:40:08.833 4458 5062 D A2dpStateMachine: moveTempStackToStateStack: X mStateStackTop=0,startingIndex=0,Top=Connecting 04-07 14:40:08.833 4458 5062 D A2dpStateMachine: invokeEnterMethods: Connecting 04-07 14:40:08.833 4458 5062 I A2dpStateMachine: Enter Connecting(00:42:79:A0:EC:50): STACK_EVENT 04-07 14:40:08.833 4458 5062 D A2dpStateMachine: Connection state 00:42:79:A0:EC:50: DISCONNECTED->CONNECTING 04-07 14:40:08.839 7572 7572 D CachedBluetoothDevice: onProfileStateChanged: profile A2DP, device=00:42:79:A0:EC:50, newProfileState 1 04-07 14:40:08.838 4458 4458 I BluetoothPhonePolicy: processProfileStateChanged, device=00:42:79:A0:EC:50, profile=2, 0 -> 1 04-07 14:40:08.840 7820 7820 D BluetoothAudioStateReceiver: a2dp extra state is 1 04-07 14:40:08.840 7820 7820 D AudioMirrorService: AM_EVENT_A2DP_STATE_CHANGED: 1 04-07 14:40:08.840 4458 5062 D A2dpStateMachine: handleMessage: X 04-07 14:40:08.841 5311 5311 D BluetoothConnectionManager: [ mBluetoothReceiver ] action= .CONNECTION_STATE_CHANGED, JBL Flip 4 , deviceBoundState= 12, conncetionState= -1 04-07 14:40:08.841 5311 5311 D BluetoothConnectionManager: BluetoothA2dp.ACTION_CONNECTION_STATE_CHANGED 04-07 14:40:08.841 5311 5311 I BluetoothConnectionManager: BluetoothA2dp A2DP State: 1 04-07 14:40:08.843 4458 4458 D AdapterProperties: PROFILE_CONNECTION_STATE_CHANGE: profile=2, device=00:42:79:A0:EC:50, 0 -> 1 04-07 14:40:08.844 4458 5041 I bt_stack: [INFO:btsnoop.cc(323)] clear_l2cap_whitelist: Clearing whitelist from l2cap channel. conn_handle=12 cid=84:386 04-07 14:40:08.848 4458 5059 E HeadsetSystemInterface: listCurrentCalls() failed: mPhoneProxy is null 04-07 14:40:08.848 4458 5059 E HeadsetStateMachine: processAtClcc: failed to list current calls for 00:42:79:A0:EC:50 04-07 14:40:08.849 5528 5528 D BtvService4.2.49 IBtvService: BtvStartReceiver::create 04-07 14:40:08.849 5528 5528 D BtvService4.2.49 IBtvService: IN| BtvStartReceiver::onReceive getAction = android.bluetooth.a2dp.profile.action.CONNECTION_STATE_CHANGED 04-07 14:40:08.849 5528 5528 D BtvService4.2.49 IBtvService: BTF|onReceive|241|OUT| BtvStartReceiver::onReceive 04-07 14:40:08.858 7572 7572 D BtvBtPairingService: sptek:BT onProfileConnectionStateChanged name = JBL Flip 4, connectState = STATE_CONNECTING_1, bluetoothProfile = 2, controlState = 0 04-07 14:40:08.865 3836 5611 W ActivityManager: Unable to start service Intent { act=android.bluetooth.a2dp.profile.action.CONNECTION_STATE_CHANGED cmp=com.google.android.gms/.nearby.discovery.service.DiscoveryService (has extras) } U=0: not found 04-07 14:40:08.882 4458 5059 I HeadsetPhoneState: stopListenForPhoneState(), no listener indicates nothing is listening 04-07 14:40:08.883 4458 5059 W HeadsetPhoneState: startListenForPhoneState, invalid subscription ID -1 04-07 14:40:08.897 4458 5059 I HeadsetStateMachine: processVendorSpecificAt: unsupported command: +CSRSF=0,0,0,1,0,0,0 04-07 14:40:08.954 3486 3760 W ServiceManagement: getService: unable to call into hwbinder service for vendor.amlogic.hardware.remotecontrol@1.0::IRemoteControl/default. 04-07 14:40:08.948 3486 3486 W ATVRemoteAudioH: type=1400 audit(0.0:849): avc: denied { call } for scontext=u:r:hal_audio_amlogic:s0 tcontext=u:r:rc_server:s0 tclass=binder permissive=0 04-07 14:40:08.957 5311 5334 D BatteryLevel: onCharacteristicRead Battery value = [100] 04-07 14:40:08.959 5311 5334 D STBAPIManager: getProperty() key : PROPERTY_REMOTE_BATTERY, result : 2 04-07 14:40:08.959 5311 5334 I STBGlobal: getBattery - property : 2, eBATTERY : NORMAL_BATTERY 04-07 14:40:08.959 5311 5334 D BatteryLevel: getBattery : NORMAL_BATTERY 04-07 14:40:08.963 5311 5334 D STBAPIManager: getProperty() key : PROPERTY_REMOTE_BATTERY, result : 2 04-07 14:40:08.963 5311 5334 I STBGlobal: getBattery - property : 2, eBATTERY : NORMAL_BATTERY 04-07 14:40:08.963 5311 5334 E BatteryLevel: BtGattClose Global - mGlobalGatt : com.realsil.android.blehub.dfu.GlobalGatt@c140e4e, mBtGatt : android.bluetooth.BluetoothGatt@3e0e549 04-07 14:40:08.963 5311 5334 I GlobalGatt: closeAll, mBluetoothDeviceAddresss.size(): 1 04-07 14:40:08.963 5311 5334 D GlobalGatt: close all of addr: 14:4E:34:92:1C:B3 04-07 14:40:08.963 5311 5334 D GlobalGatt: close all of addr: 14:4E:34:92:1C:B3 04-07 14:40:08.964 5311 5334 I GlobalGatt: disconnect() 04-07 14:40:08.964 5311 5334 I GlobalGatt: isConnected, addr: 14:4E:34:92:1C:B3, mConnectionState.get(address): 2 04-07 14:40:08.964 5311 5334 D BluetoothGatt: cancelOpen() - device: 14:4E:34:92:1C:B3 04-07 14:40:08.965 4458 5041 I bt_stack: [INFO:gatt_api.cc(1219)] GATT_Disconnect conn_id=0x0007 04-07 14:40:08.965 4458 5041 I bt_stack: [INFO:gatt_api.cc(1164)] GATT_CancelConnect: gatt_if:7, address: 14:4e:34:92:1c:b3, direct:0 04-07 14:40:08.965 4458 5041 E bt_stack: [ERROR:bta_gattc_act.cc(423)] bta_gattc_cancel_bk_conn: failed 04-07 14:40:09.016 3557 8398 D BOXKEY-STDVB: [DEVICE 0] ++ remain buffer size : 38164 04-07 14:40:09.054 7849 7849 D MDNSService: MDNSMsgHandler() AM_EVENT_CHECK_NETWORK_CONFIG. isConnected : true 04-07 14:40:09.284 6199 6287 D isqms_agent: success open fifo file=/btv_home/run/isqms_unix_socket_agent 04-07 14:40:09.284 6199 6287 D isqms_agent: CISQMS::make_msg2 04-07 14:40:09.284 6199 6287 D isqms_agent: CISQMS::make_msg SEND_DATA 04-07 14:40:09.284 6199 6287 D isqms_agent: send data=$send_data$1$5$-1$;100;1;1;14:4E:34:A1:56:4D 04-07 14:40:09.284 6199 6287 D isqms_agent: send_data_to_agent sock write 04-07 14:40:09.284 3528 3568 D isqmsAgent: read data buffer=>$send_data$1$5$-1$;100;1;1;14:4E:34:A1:56:4D 04-07 14:40:09.284 6199 6287 D isqms_agent: send_data_to_agent sock close 04-07 14:40:09.284 3528 3568 D isqmsAgent: read data pData=>$send_data$1$5$-1$;100;1;1;14:4E:34:A1:56:4D 04-07 14:40:09.284 6199 6287 D isqms_agent: ######################## pop_data nType=2, m_nEventCnt=1, isqms->m_pISQMDATA=0 04-07 14:40:09.284 3528 3568 D isqmsAgent: INFO: ipc_data pData=$send_data$1$5$-1$;100;1;1;14:4E:34:A1:56:4D 04-07 14:40:09.284 6199 6287 D isqms_agent: @@@@@@@@@@@@@@@@@@@@@@@ send delete m_nEventCnt = 1 04-07 14:40:09.284 3528 3568 D isqmsAgent: nCategoryID=1, nSubCategoryID=5, nFieldID=-1 04-07 14:40:09.284 6199 6287 D isqms_agent: @@@@@@@@@@@@@@@@@@@@@@@1 m_nEventCnt=0, isqms->m_pISQMDATA=0 04-07 14:40:09.284 3528 3568 D isqmsAgent: nCategoryID=1, nSubCategoryID=5, nFieldID=-1, pszPtr=;100;1;1;14:4E:34:A1:56:4D, len = 26 04-07 14:40:09.284 3528 3568 D isqmsAgent: CISQMS:set_data nCategoryID=1, SubCategoryID=5, nFieldID=-1, pData=;100;1;1;14:4E:34:A1:56:4D 04-07 14:40:09.284 3528 3568 D isqmsAgent: ######################################## 04-07 14:40:09.284 3528 3568 D isqmsAgent: get_property_value key=dev.rcu.battery szRet=Normal 04-07 14:40:09.284 6199 6287 D isqms_agent: @@@@@@@@@@@@@@@@@@@@@@@2 m_nEventCnt=0, isqms->m_pISQMDATA=0 04-07 14:40:09.284 3528 3568 D isqmsAgent: [isqmsAgent 0183 04/07 14:40:09:284][3528] INFO: get_property_value value=Norma 04-07 14:40:09.284 3528 3568 D isqmsAgent: get_property_value key=dev.rcu.manu szRet= 04-07 14:40:09.284 3528 3568 D isqmsAgent: [isqmsAgent 0184 04/07 14:40:09:284][3528] INFO: get_property_value value= 04-07 14:40:09.284 3528 3568 D isqmsAgent: get_property_value key=dev.rcu.ver szRet= 04-07 14:40:09.284 3528 3568 D isqmsAgent: [isqmsAgent 0185 04/07 14:40:09:284][3528] INFO: get_property_value value= 04-07 14:40:09.284 3528 3568 D isqmsAgent: CISQMSData::set_sub_category_data##### battery=Norma, manu= , ver= , pData=;100;1;1;14:4E:34:A1:56:4D; ; ;Norma 04-07 14:40:09.284 3528 3568 D isqmsAgent: _thread_read_data_from_agent_fifo running, recvthread 04-07 14:40:09.284 3528 3568 D isqmsAgent: _thread_read_data_from_agent_fifo read waiting 04-07 14:40:09.284 3528 3568 D isqmsAgent: read data buffer=>@@ 04-07 14:40:09.284 3528 3568 D isqmsAgent: _thread_read_data_from_agent_fifo running, recvthread 04-07 14:40:09.284 3528 3568 D isqmsAgent: _thread_read_data_from_agent_fifo read waiting 04-07 14:40:09.465 5311 5334 I GlobalGatt: closeBluetoothGatt, addr: 14:4E:34:92:1C:B3, mBluetoothGatts.get(addr): android.bluetooth.BluetoothGatt@3e0e549 04-07 14:40:09.465 5311 5334 D BluetoothGatt: close() 04-07 14:40:09.465 5311 5334 D BluetoothGatt: unregisterApp() - mClientIf=7 04-07 14:40:09.467 5311 5334 D BluetoothGatt: onClientConnectionState() - status=0 clientIf=7 device=14:4E:34:92:1C:B3 04-07 14:40:09.568 3557 8512 I HalAudioOutput: outputRate:48210(1.00) 04-07 14:40:09.564 3557 3557 W HwBinder:3557_2: type=1400 audit(0.0:850): avc: denied { read } for name="u:object_r:default_prop:s0" dev="tmpfs" ino=13241 scontext=u:r:btvservice_hal:s0 tcontext=u:object_r:default_prop:s0 tclass=file permissive=0 04-07 14:40:09.571 3557 8391 E libc : Access denied finding property "skb.audio.output" 04-07 14:40:09.776 7146 7246 I UEI.SmartControl: ISetup API: 41 04-07 14:40:09.778 7146 7246 D UEI.SmartControl: --- getAllRemotes 04-07 14:40:09.783 7146 7246 E UEI.SmartControl: !!! Invalid key!!! 04-07 14:40:09.784 7146 7246 D UEI.SmartControl: Setup on Transact DONE: 41 Result: true 04-07 14:40:09.785 7146 7166 D UEI.SmartControl: ------ getRemoteDeviceInfo: 0 04-07 14:40:09.787 7146 7166 D UEI.SmartControl: --- Start readDeviceInfo --- 04-07 14:40:09.791 7146 8539 D UEI.SmartControl: --- Start reading device info --- 04-07 14:40:09.957 3486 3760 W ServiceManagement: getService: unable to call into hwbinder service for vendor.amlogic.hardware.remotecontrol@1.0::IRemoteControl/default. 04-07 14:40:09.952 3486 3486 W ATVRemoteAudioH: type=1400 audit(0.0:851): avc: denied { call } for scontext=u:r:hal_audio_amlogic:s0 tcontext=u:r:rc_server:s0 tclass=binder permissive=0 04-07 14:40:10.018 3557 8398 D BOXKEY-STDVB: [DEVICE 0] ++ remain buffer size : 36848 04-07 14:40:10.564 3557 3557 W HwBinder:3557_2: type=1400 audit(0.0:852): avc: denied { read } for name="u:object_r:default_prop:s0" dev="tmpfs" ino=13241 scontext=u:r:btvservice_hal:s0 tcontext=u:object_r:default_prop:s0 tclass=file permissive=0 04-07 14:40:10.570 3557 8391 E libc : Access denied finding property "skb.audio.output" 04-07 14:40:10.684 3557 8407 W RendererPolicyBase_0: video render: 59.94 fps, drop: 0.00 fps 04-07 14:40:10.825 4458 5041 I bt_bta_av: bta_av_link_role_ok: peer 00:42:79:a0:ec:50 hndl:0x41 role:0 conn_audio:0x0 bits:2 features:0x865b 04-07 14:40:10.825 4458 5041 D bt_bta_av: SetAvdtpVersion: AVDTP version for 00:42:79:a0:ec:50 set to 0x103 04-07 14:40:10.825 4458 5041 I a2dp_api: A2DP_FindService: peer: 00:42:79:a0:ec:50 UUID: 0x110b 04-07 14:40:10.871 4458 5041 I bt_stack: [INFO:btsnoop.cc(289)] whitelist_l2c_channel: Whitelisting l2cap channel. conn_handle=12 cid=0x0055:0x0202 04-07 14:40:10.872 4458 5041 I bt_stack: [INFO:btsnoop.cc(289)] whitelist_l2c_channel: Whitelisting l2cap channel. conn_handle=12 cid=0x0055:0x0202 04-07 14:40:10.884 4458 5041 I bt_stack: [INFO:btsnoop.cc(289)] whitelist_l2c_channel: Whitelisting l2cap channel. conn_handle=12 cid=0x0056:0x0244 04-07 14:40:10.886 4458 5041 I bt_stack: [INFO:btsnoop.cc(289)] whitelist_l2c_channel: Whitelisting l2cap channel. conn_handle=12 cid=0x0057:0x0285 04-07 14:40:10.918 4458 5041 W bt_sdp : process_service_search_attr_rsp 04-07 14:40:10.923 4458 5041 I bt_stack: [INFO:connection_handler.cc(304)] void bluetooth::avrcp::ConnectionHandler::AcceptorControlCb(uint8_t, uint8_t, uint16_t, const RawAddress *): handle=0x01 result=000000 addr=00:42:79:a0:ec:50 04-07 14:40:10.923 4458 5041 I bt_stack: [INFO:connection_handler.cc(310)] void bluetooth::avrcp::ConnectionHandler::AcceptorControlCb(uint8_t, uint8_t, uint16_t, const RawAddress *): Connection Opened Event 04-07 14:40:10.924 4458 5041 I bt_stack: [INFO:connection_handler.cc(322)] void bluetooth::avrcp::ConnectionHandler::AcceptorControlCb(uint8_t, uint8_t, uint16_t, const RawAddress *): Performing SDP on connected device. address=00:42:79:a0:ec:50 04-07 14:40:10.924 4458 5041 I bt_stack: [INFO:connection_handler.cc(161)] virtual bool bluetooth::avrcp::ConnectionHandler::SdpLookup(const RawAddress &, bluetooth::avrcp::ConnectionHandler::SdpCallback) 04-07 14:40:10.924 4458 5041 I bt_stack: [INFO:connection_handler.cc(185)] Connect to device ff:ff:ff:ff:ff:ff 04-07 14:40:10.924 4458 5041 I bt_stack: [INFO:connection_handler.cc(206)] virtual bool bluetooth::avrcp::ConnectionHandler::AvrcpConnect(bool, const RawAddress &): handle=0000 status= 000000 04-07 14:40:10.925 4458 5041 I bt_stack: [INFO:btsnoop.cc(323)] clear_l2cap_whitelist: Clearing whitelist from l2cap channel. conn_handle=12 cid=87:645 04-07 14:40:10.926 4458 5041 I bt_stack: [INFO:btsnoop.cc(323)] clear_l2cap_whitelist: Clearing whitelist from l2cap channel. conn_handle=12 cid=85:514 04-07 14:40:10.926 4458 5041 I a2dp_api: a2dp_sdp_cback: status: 0 04-07 14:40:10.926 4458 5041 D bt_bta_av: SetAvdtpVersion: AVDTP version for 00:42:79:a0:ec:50 set to 0x103 04-07 14:40:10.926 4458 5041 W bt_avp : AVDT_ConnectReq: address=00:42:79:a0:ec:50 channel_index=0 sec_mask=0x12 04-07 14:40:10.927 4458 5041 I bt_bta_av: bta_av_conn_cback: conn_cback bd_addr: 00:42:79:a0:ec:50 04-07 14:40:10.927 4458 5041 W bt_avp : AVDT_ConnectReq: address=00:42:79:a0:ec:50 result=0 04-07 14:40:10.932 4458 5041 I bt_stack: [INFO:btsnoop.cc(289)] whitelist_l2c_channel: Whitelisting l2cap channel. conn_handle=12 cid=0x0058:0x02c2 04-07 14:40:10.933 4458 5041 I bt_stack: [INFO:btsnoop.cc(289)] whitelist_l2c_channel: Whitelisting l2cap channel. conn_handle=12 cid=0x0058:0x02c2 04-07 14:40:10.949 4458 5041 I bt_stack: [INFO:btsnoop.cc(289)] whitelist_l2c_channel: Whitelisting l2cap channel. conn_handle=12 cid=0x0059:0x0305 04-07 14:40:10.956 3486 3486 W ATVRemoteAudioH: type=1400 audit(0.0:853): avc: denied { call } for scontext=u:r:hal_audio_amlogic:s0 tcontext=u:r:rc_server:s0 tclass=binder permissive=0 04-07 14:40:10.961 4458 4536 I BluetoothA2dpServiceJni: bta2dp_audio_config_callback 04-07 14:40:10.962 3486 3760 W ServiceManagement: getService: unable to call into hwbinder service for vendor.amlogic.hardware.remotecontrol@1.0::IRemoteControl/default. 04-07 14:40:10.964 4458 4536 D A2dpNativeInterface: onCodecConfigChanged: A2dpStackEvent {type:EVENT_TYPE_CODEC_CONFIG_CHANGED, device:00:42:79:A0:EC:50, value1:0, codecStatus:{mCodecConfig:{codecName:SBC,mCodecType:0,mCodecPriority:1001,mSampleRate:0x2(48000),mBitsPerSample:0x1(16),mChannelMode:0x2(STEREO),mCodecSpecific1:0,mCodecSpecific2:0,mCodecSpecific3:0,mCodecSpecific4:0},mCodecsLocalCapabilities:[{codecName:AAC,mCodecType:1,mCodecPriority:2001,mSampleRate:0x1(44100),mBitsPerSample:0x1(16),mChannelMode:0x2(STEREO),mCodecSpecific1:0,mCodecSpecific2:0,mCodecSpecific3:0,mCodecSpecific4:0}, {codecName:SBC,mCodecType:0,mCodecPriority:1001,mSampleRate:0x3(44100|48000),mBitsPerSample:0x1(16),mChannelMode:0x3(MONO|STEREO),mCodecSpecific1:0,mCodecSpecific2:0,mCodecSpecific3:0,mCodecSpecific4:0}],mCodecsSelectableCapabilities:[{codecName:SBC,mCodecType:0,mCodecPriority:1001,mSampleRate:0x3(44100|48000),mBitsPerSample:0x1(16),mChannelMode:0x3(MONO|STEREO),mCodecSpecific1:0,mCodecSpecific2:0,mCodecSpecific3:0,mCodecSpecific4:0}]}} 04-07 14:40:10.966 4458 5062 D A2dpStateMachine: handleMessage: E msg.what=101 04-07 14:40:10.966 4458 5062 D A2dpStateMachine: processMsg: Connecting 04-07 14:40:10.966 4458 5062 D A2dpStateMachine: Connecting process message(00:42:79:A0:EC:50): STACK_EVENT 04-07 14:40:10.967 4458 5062 D A2dpStateMachine: Connecting: stack event: A2dpStackEvent {type:EVENT_TYPE_CODEC_CONFIG_CHANGED, device:00:42:79:A0:EC:50, value1:0, codecStatus:{mCodecConfig:{codecName:SBC,mCodecType:0,mCodecPriority:1001,mSampleRate:0x2(48000),mBitsPerSample:0x1(16),mChannelMode:0x2(STEREO),mCodecSpecific1:0,mCodecSpecific2:0,mCodecSpecific3:0,mCodecSpecific4:0},mCodecsLocalCapabilities:[{codecName:AAC,mCodecType:1,mCodecPriority:2001,mSampleRate:0x1(44100),mBitsPerSample:0x1(16),mChannelMode:0x2(STEREO),mCodecSpecific1:0,mCodecSpecific2:0,mCodecSpecific3:0,mCodecSpecific4:0}, {codecName:SBC,mCodecType:0,mCodecPriority:1001,mSampleRate:0x3(44100|48000),mBitsPerSample:0x1(16),mChannelMode:0x3(MONO|STEREO),mCodecSpecific1:0,mCodecSpecific2:0,mCodecSpecific3:0,mCodecSpecific4:0}],mCodecsSelectableCapabilities:[{codecName:SBC,mCodecType:0,mCodecPriority:1001,mSampleRate:0x3(44100|48000),mBitsPerSample:0x1(16),mChannelMode:0x3(MONO|STEREO),mCodecSpecific1:0,mCodecSpecific2:0,mCodecSpecific3:0,mCodecSpecific4:0}]}} 04-07 14:40:10.968 4458 5062 D A2dpStateMachine: A2DP Codec Config: {codecName:SBC,mCodecType:0,mCodecPriority:1001,mSampleRate:0x2(48000),mBitsPerSample:0x1(16),mChannelMode:0x2(STEREO),mCodecSpecific1:0,mCodecSpecific2:0,mCodecSpecific3:0,mCodecSpecific4:0}->{codecName:SBC,mCodecType:0,mCodecPriority:1001,mSampleRate:0x2(48000),mBitsPerSample:0x1(16),mChannelMode:0x2(STEREO),mCodecSpecific1:0,mCodecSpecific2:0,mCodecSpecific3:0,mCodecSpecific4:0} 04-07 14:40:10.968 4458 5062 D A2dpStateMachine: A2DP Codec Local Capability: {codecName:AAC,mCodecType:1,mCodecPriority:2001,mSampleRate:0x1(44100),mBitsPerSample:0x1(16),mChannelMode:0x2(STEREO),mCodecSpecific1:0,mCodecSpecific2:0,mCodecSpecific3:0,mCodecSpecific4:0} 04-07 14:40:10.968 4458 5062 D A2dpStateMachine: A2DP Codec Local Capability: {codecName:SBC,mCodecType:0,mCodecPriority:1001,mSampleRate:0x3(44100|48000),mBitsPerSample:0x1(16),mChannelMode:0x3(MONO|STEREO),mCodecSpecific1:0,mCodecSpecific2:0,mCodecSpecific3:0,mCodecSpecific4:0} 04-07 14:40:10.969 4458 5062 D A2dpStateMachine: A2DP Codec Selectable Capability: {codecName:SBC,mCodecType:0,mCodecPriority:1001,mSampleRate:0x3(44100|48000),mBitsPerSample:0x1(16),mChannelMode:0x3(MONO|STEREO),mCodecSpecific1:0,mCodecSpecific2:0,mCodecSpecific3:0,mCodecSpecific4:0} 04-07 14:40:10.971 4458 5062 D A2dpService: broadcastCodecConfig(00:42:79:A0:EC:50): {mCodecConfig:{codecName:SBC,mCodecType:0,mCodecPriority:1001,mSampleRate:0x2(48000),mBitsPerSample:0x1(16),mChannelMode:0x2(STEREO),mCodecSpecific1:0,mCodecSpecific2:0,mCodecSpecific3:0,mCodecSpecific4:0},mCodecsLocalCapabilities:[{codecName:AAC,mCodecType:1,mCodecPriority:2001,mSampleRate:0x1(44100),mBitsPerSample:0x1(16),mChannelMode:0x2(STEREO),mCodecSpecific1:0,mCodecSpecific2:0,mCodecSpecific3:0,mCodecSpecific4:0}, {codecName:SBC,mCodecType:0,mCodecPriority:1001,mSampleRate:0x3(44100|48000),mBitsPerSample:0x1(16),mChannelMode:0x3(MONO|STEREO),mCodecSpecific1:0,mCodecSpecific2:0,mCodecSpecific3:0,mCodecSpecific4:0}],mCodecsSelectableCapabilities:[{codecName:SBC,mCodecType:0,mCodecPriority:1001,mSampleRate:0x3(44100|48000),mBitsPerSample:0x1(16),mChannelMode:0x3(MONO|STEREO),mCodecSpecific1:0,mCodecSpecific2:0,mCodecSpecific3:0,mCodecSpecific4:0}]} 04-07 14:40:10.973 4458 5062 D A2dpStateMachine: handleMessage: X 04-07 14:40:10.999 4458 5041 I bt_stack: [INFO:a2dp_encoding.cc(731)] set_remote_delay: not ready for DelayReport 150 ms 04-07 14:40:11.000 3557 8398 D BOXKEY-STDVB: [DEVICE 0] ++ remain buffer size : 36848 04-07 14:40:11.013 4458 5041 W bt_sdp : process_service_search_attr_rsp 04-07 14:40:11.016 4458 5041 I bt_stack: [INFO:btsnoop.cc(323)] clear_l2cap_whitelist: Clearing whitelist from l2cap channel. conn_handle=12 cid=89:773 04-07 14:40:11.031 4458 5041 I bt_stack: [INFO:btsnoop.cc(323)] clear_l2cap_whitelist: Clearing whitelist from l2cap channel. conn_handle=12 cid=88:706 04-07 14:40:11.031 4458 5041 I bt_stack: [INFO:connection_handler.cc(412)] void bluetooth::avrcp::ConnectionHandler::SdpCb(RawAddress, bluetooth::avrcp::ConnectionHandler::SdpCallback, tSDP_DISCOVERY_DB *, uint16_t): SDP lookup callback received 04-07 14:40:11.031 4458 5041 I bt_stack: [INFO:connection_handler.cc(431)] void bluetooth::avrcp::ConnectionHandler::SdpCb(RawAddress, bluetooth::avrcp::ConnectionHandler::SdpCallback, tSDP_DISCOVERY_DB *, uint16_t): Device 00:42:79:a0:ec:50 supports remote control 04-07 14:40:11.031 4458 5041 I bt_stack: [INFO:connection_handler.cc(440)] void bluetooth::avrcp::ConnectionHandler::SdpCb(RawAddress, bluetooth::avrcp::ConnectionHandler::SdpCallback, tSDP_DISCOVERY_DB *, uint16_t): Device 00:42:79:a0:ec:50 peer avrcp version=0x0106 04-07 14:40:11.031 4458 5041 I bt_stack: [INFO:connection_handler.cc(446)] void bluetooth::avrcp::ConnectionHandler::SdpCb(RawAddress, bluetooth::avrcp::ConnectionHandler::SdpCallback, tSDP_DISCOVERY_DB *, uint16_t): Device 00:42:79:a0:ec:50 supports metadata 04-07 14:40:11.031 4458 5041 I bt_stack: [INFO:connection_handler.cc(452)] void bluetooth::avrcp::ConnectionHandler::SdpCb(RawAddress, bluetooth::avrcp::ConnectionHandler::SdpCallback, tSDP_DISCOVERY_DB *, uint16_t) Get Supported categories 04-07 14:40:11.031 4458 5041 I bt_stack: [INFO:connection_handler.cc(456)] void bluetooth::avrcp::ConnectionHandler::SdpCb(RawAddress, bluetooth::avrcp::ConnectionHandler::SdpCallback, tSDP_DISCOVERY_DB *, uint16_t)Get Supported categories SDP ATTRIBUTES != null 04-07 14:40:11.031 4458 5041 I bt_stack: [INFO:connection_handler.cc(479)] void bluetooth::avrcp::ConnectionHandler::SdpCb(RawAddress, bluetooth::avrcp::ConnectionHandler::SdpCallback, tSDP_DISCOVERY_DB *, uint16_t): Device 00:42:79:a0:ec:50 supports remote control target 04-07 14:40:11.031 4458 5041 I bt_stack: [INFO:connection_handler.cc(485)] void bluetooth::avrcp::ConnectionHandler::SdpCb(RawAddress, bluetooth::avrcp::ConnectionHandler::SdpCallback, tSDP_DISCOVERY_DB *, uint16_t): Device 00:42:79:a0:ec:50 peer avrcp target version=0x0106 04-07 14:40:11.031 4458 5041 I bt_stack: [INFO:connection_handler.cc(493)] void bluetooth::avrcp::ConnectionHandler::SdpCb(RawAddress, bluetooth::avrcp::ConnectionHandler::SdpCallback, tSDP_DISCOVERY_DB *, uint16_t) Get Supported categories 04-07 14:40:11.031 4458 5041 I bt_stack: [INFO:connection_handler.cc(497)] void bluetooth::avrcp::ConnectionHandler::SdpCb(RawAddress, bluetooth::avrcp::ConnectionHandler::SdpCallback, tSDP_DISCOVERY_DB *, uint16_t)Get Supported categories SDP ATTRIBUTES != null 04-07 14:40:11.031 4458 5041 I bt_stack: [INFO:connection_handler.cc(501)] void bluetooth::avrcp::ConnectionHandler::SdpCb(RawAddress, bluetooth::avrcp::ConnectionHandler::SdpCallback, tSDP_DISCOVERY_DB *, uint16_t): Device 00:42:79:a0:ec:50 supports advanced control 04-07 14:40:11.032 4458 5041 I bt_stack: [INFO:btsnoop.cc(289)] whitelist_l2c_channel: Whitelisting l2cap channel. conn_handle=12 cid=0x005a:0x0346 04-07 14:40:11.033 4458 5041 I bt_stack: [INFO:btsnoop.cc(289)] whitelist_l2c_channel: Whitelisting l2cap channel. conn_handle=12 cid=0x005a:0x0346 04-07 14:40:11.335 4458 5041 E bt_btm : btm_acl_role_changed: peer 00:42:79:a0:ec:50 tBTM_SEC_DEV:0xc8921588 rs_disc_pending=0 04-07 14:40:11.335 4458 5041 I bt_bta_dm: handle_role_change: peer 00:42:79:a0:ec:50 info:0x10 new_role:0x1 dev count:2 hci_status=0 04-07 14:40:11.335 4458 5041 W bt_btif : bta_dm_check_av:2 04-07 14:40:11.335 4458 5041 W bt_btif : [0]: state:1, info:x0, avoid_rs 0 04-07 14:40:11.335 4458 5041 W bt_btif : [1]: state:1, info:x10, avoid_rs 0 04-07 14:40:11.335 4458 4536 W bt_btif : btif_dm_upstreams_evt: unhandled event (14) 04-07 14:40:11.570 3557 8391 E libc : Access denied finding property "skb.audio.output" 04-07 14:40:11.564 3557 3557 W HwBinder:3557_2: type=1400 audit(0.0:854): avc: denied { read } for name="u:object_r:default_prop:s0" dev="tmpfs" ino=13241 scontext=u:r:btvservice_hal:s0 tcontext=u:object_r:default_prop:s0 tclass=file permissive=0 04-07 14:40:11.586 3557 8512 I HalAudioOutput: outputRate:47950(1.00) 04-07 14:40:11.592 4458 5041 E bt_btm : btm_acl_role_changed: peer 00:42:79:a0:ec:50 tBTM_SEC_DEV:0xc8921588 rs_disc_pending=0 04-07 14:40:11.592 4458 5041 I bt_bta_dm: handle_role_change: peer 00:42:79:a0:ec:50 info:0x10 new_role:0x0 dev count:2 hci_status=0 04-07 14:40:11.592 4458 5041 W bt_btif : bta_dm_check_av:2 04-07 14:40:11.592 4458 5041 W bt_btif : [0]: state:1, info:x0, avoid_rs 0 04-07 14:40:11.592 4458 5041 W bt_btif : [1]: state:1, info:x10, avoid_rs 0 04-07 14:40:11.593 4458 4536 W bt_btif : btif_dm_upstreams_evt: unhandled event (14) 04-07 14:40:11.596 4458 4536 D AvrcpTargetJni: volumeDeviceConnected 04-07 14:40:11.597 4458 4536 D AvrcpNativeInterface: deviceConnected: device=00:42:79:A0:EC:50 absoluteVolume=true 04-07 14:40:11.597 4458 4536 I AvrcpTargetService: deviceConnected: device=00:42:79:A0:EC:50 absoluteVolume=true 04-07 14:40:11.597 4458 4536 D AvrcpVolumeManager: deviceConnected: device=00:42:79:A0:EC:50 absoluteVolume=true 04-07 14:40:11.598 4458 5041 W bt_btif : bta_dm_rm_cback:2, status:0 04-07 14:40:11.599 4458 5041 I bt_bta_av: bta_av_chk_start: peer 00:42:79:a0:ec:50 channel:64 bta_av_cb.audio_open_cnt:1 role:0x0 features:0x865b start:false 04-07 14:40:11.599 4458 5041 I btif_av : virtual bool BtifAvStateMachine::StateOpening::ProcessEvent(uint32_t, void *): Peer 00:42:79:a0:ec:50 : event=BTA_AV_OPEN_EVT(0x2) flags=0x0(None) status=0(SUCCESS) edr=0x3 04-07 14:40:11.599 4458 5041 I btif_av : btif_report_connection_state: peer_address=00:42:79:a0:ec:50 state=2 04-07 14:40:11.599 4458 5041 E bt_btif : btif_rc_get_device_by_bda: device not found, returning NULL! 04-07 14:40:11.599 4458 4536 I BluetoothA2dpServiceJni: bta2dp_connection_state_callback 04-07 14:40:11.599 4458 5041 E bt_btif : btif_rc_check_handle_pending_play: p_dev NULL 04-07 14:40:11.600 4458 4536 D A2dpNativeInterface: onConnectionStateChanged: A2dpStackEvent {type:EVENT_TYPE_CONNECTION_STATE_CHANGED, device:00:42:79:A0:EC:50, value1:CONNECTED} 04-07 14:40:11.601 4458 4536 D AvrcpTargetJni: getCurrentPlayStatus 04-07 14:40:11.601 4458 5062 D A2dpStateMachine: handleMessage: E msg.what=101 04-07 14:40:11.601 4458 4536 D AvrcpNativeInterface: getPlayStatus 04-07 14:40:11.601 4458 5062 D A2dpStateMachine: processMsg: Connecting 04-07 14:40:11.602 4458 5062 D A2dpStateMachine: Connecting process message(00:42:79:A0:EC:50): STACK_EVENT 04-07 14:40:11.602 4458 5062 D A2dpStateMachine: Connecting: stack event: A2dpStackEvent {type:EVENT_TYPE_CONNECTION_STATE_CHANGED, device:00:42:79:A0:EC:50, value1:CONNECTED} 04-07 14:40:11.602 4458 5062 D A2dpStateMachine: transitionTo: destState=Connected 04-07 14:40:11.602 4458 5062 D A2dpStateMachine: handleMessage: new destination call exit/enter 04-07 14:40:11.602 4458 5062 D A2dpStateMachine: setupTempStateStackWithStatesToEnter: X mTempStateStackCount=1,curStateInfo: null 04-07 14:40:11.602 4458 5062 D A2dpStateMachine: invokeExitMethods: Connecting 04-07 14:40:11.602 4458 5062 D A2dpStateMachine: Exit Connecting(00:42:79:A0:EC:50): STACK_EVENT 04-07 14:40:11.602 4458 5062 D A2dpStateMachine: moveTempStackToStateStack: i=0,j=0 04-07 14:40:11.602 4458 5062 D A2dpStateMachine: moveTempStackToStateStack: X mStateStackTop=0,startingIndex=0,Top=Connected 04-07 14:40:11.602 4458 5062 D A2dpStateMachine: invokeEnterMethods: Connected 04-07 14:40:11.602 4458 5062 I A2dpStateMachine: Enter Connected(00:42:79:A0:EC:50): STACK_EVENT 04-07 14:40:11.603 4458 5062 D A2dpStateMachine: Connection state 00:42:79:A0:EC:50: CONNECTING->CONNECTED 04-07 14:40:11.605 4458 5062 D A2dpStateMachine: A2DP Playing state : device: 00:42:79:A0:EC:50 State:PLAYING->NOT_PLAYING 04-07 14:40:11.606 4458 4458 I BluetoothPhonePolicy: processProfileStateChanged, device=00:42:79:A0:EC:50, profile=2, 1 -> 2 04-07 14:40:11.606 4458 4458 D BluetoothAdapterService: isQuetModeEnabled() - Enabled = false 04-07 14:40:11.606 4458 4458 I BluetoothPhonePolicy: connectOtherProfile: already scheduled callback for 00:42:79:A0:EC:50 04-07 14:40:11.607 4458 4537 D BluetoothActiveDeviceManager: handleMessage(MESSAGE_A2DP_ACTION_CONNECTION_STATE_CHANGED): device 00:42:79:A0:EC:50 connected 04-07 14:40:11.607 4458 4537 D BluetoothActiveDeviceManager: setA2dpActiveDevice(00:42:79:A0:EC:50) 04-07 14:40:11.608 4458 4537 D A2dpService: setActiveDevice(00:42:79:A0:EC:50): previous is null 04-07 14:40:11.608 4458 4537 I BluetoothA2dpServiceJni: setActiveDeviceNative: sBluetoothA2dpInterface: 0xc9ee5dfc 04-07 14:40:11.608 4458 5041 I bt_stack: [INFO:btif_av.cc(450)] bool BtifAvSource::SetActivePeer(const RawAddress &, std::promise): peer: 00:42:79:a0:ec:50 04-07 14:40:11.608 4458 5041 I bt_stack: [INFO:btif_a2dp_source.cc(415)] btif_a2dp_source_restart_session: old_peer_address=00:00:00:00:00:00 new_peer_address=00:42:79:a0:ec:50 is_streaming=false state=STATE_OFF 04-07 14:40:11.608 4458 5041 I bt_btif_a2dp_source: btif_a2dp_source_startup: state=STATE_OFF 04-07 14:40:11.609 4458 4458 D AdapterProperties: PROFILE_CONNECTION_STATE_CHANGE: profile=2, device=00:42:79:A0:EC:50, 1 -> 2 04-07 14:40:11.609 4458 5063 I bt_btif_a2dp_source: btif_a2dp_source_startup_delayed: state=STATE_STARTING_UP 04-07 14:40:11.609 4458 5041 I bt_stack: [INFO:btif_a2dp_source.cc(372)] btif_a2dp_source_start_session: peer_address=00:42:79:a0:ec:50 state=STATE_STARTING_UP 04-07 14:40:11.609 4458 5063 I bt_stack: [INFO:a2dp_encoding.cc(595)] init 04-07 14:40:11.609 4458 5041 I bt_btif_a2dp_source: btif_a2dp_source_setup_codec: peer_address=00:42:79:a0:ec:50 state=STATE_STARTING_UP 04-07 14:40:11.609 4458 5041 I bt_btif_a2dp_source: btif_a2dp_source_audio_tx_flush_req: state=STATE_STARTING_UP 04-07 14:40:11.612 4458 5063 I bt_stack: [INFO:client_interface.cc(197)] listManifestByInterface_cb returns 1 instance(s) 04-07 14:40:11.614 7820 7820 D BluetoothAudioStateReceiver: a2dp extra state is 2 04-07 14:40:11.615 7572 7572 D CachedBluetoothDevice: onProfileStateChanged: profile A2DP, device=00:42:79:A0:EC:50, newProfileState 2 04-07 14:40:11.615 7820 7820 D AudioMirrorService: AM_EVENT_A2DP_STATE_CHANGED: 2 04-07 14:40:11.618 5311 5311 D BluetoothConnectionManager: [ mBluetoothReceiver ] action= .CONNECTION_STATE_CHANGED, JBL Flip 4 , deviceBoundState= 12, conncetionState= -1 04-07 14:40:11.618 5311 5311 D BluetoothConnectionManager: BluetoothA2dp.ACTION_CONNECTION_STATE_CHANGED 04-07 14:40:11.618 5311 5311 I BluetoothConnectionManager: BluetoothA2dp A2DP State: 2 04-07 14:40:11.620 4458 5063 I bt_stack: [INFO:client_interface.cc(232)] IBluetoothAudioProvidersFactory::getService() returned 0xf319f740 (remote) 04-07 14:40:11.620 3486 3587 I BTAudioProvidersFactory: getProviderCapabilities - SessionType=A2DP_SOFTWARE_ENCODING_DATAPATH supports 1 codecs 04-07 14:40:11.621 4458 5063 I bt_stack: [INFO:client_interface.cc(260)] fetch_audio_provider: BluetoothAudioHal SessionType=A2DP_SOFTWARE_ENCODING_DATAPATH has 1 AudioCapabilities 04-07 14:40:11.621 3486 8511 I BTAudioProvidersFactory: openProvider - SessionType=A2DP_SOFTWARE_ENCODING_DATAPATH 04-07 14:40:11.621 4458 5063 I bt_stack: [INFO:client_interface.cc(270)] openProvider_cb(SUCCESS) 04-07 14:40:11.621 4458 5063 I bt_stack: [INFO:client_interface.cc(289)] IBluetoothAudioProvidersFactory::openProvider() returned 0xf3178ba0 (remote) 04-07 14:40:11.621 4458 5063 I bt_stack: [INFO:a2dp_encoding.cc(620)] init: restore DELAY 150 ms 04-07 14:40:11.622 4458 5063 I bt_btif_a2dp_source: btif_a2dp_source_audio_tx_flush_event: state=STATE_RUNNING 04-07 14:40:11.622 4458 5063 I bt_btif_a2dp_source: btif_a2dp_source_setup_codec_delayed: peer_address=00:42:79:a0:ec:50 state=STATE_RUNNING 04-07 14:40:11.622 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: sample_rate=48000 bits_per_sample=16 channel_count=2 04-07 14:40:11.622 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_feeding_reset: PCM bytes per tick 3840 04-07 14:40:11.622 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: MTU=883, peer_mtu=883 min_bitpool=2 max_bitpool=31 04-07 14:40:11.622 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: ChannelMode=3, NumOfSubBands=8, NumOfBlocks=16, AllocationMethod=0, BitRate=328, SamplingFreq=48000 BitPool=0 04-07 14:40:11.622 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: bitpool candidate: 48 (328 kbps) 04-07 14:40:11.622 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: computed bitpool too large (48) 04-07 14:40:11.622 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: bitpool candidate: 47 (323 kbps) 04-07 14:40:11.622 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: computed bitpool too large (47) 04-07 14:40:11.622 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: bitpool candidate: 46 (318 kbps) 04-07 14:40:11.622 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: computed bitpool too large (46) 04-07 14:40:11.622 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: bitpool candidate: 45 (313 kbps) 04-07 14:40:11.622 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: computed bitpool too large (45) 04-07 14:40:11.622 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: bitpool candidate: 44 (308 kbps) 04-07 14:40:11.622 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: computed bitpool too large (44) 04-07 14:40:11.622 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: bitpool candidate: 44 (303 kbps) 04-07 14:40:11.622 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: computed bitpool too large (44) 04-07 14:40:11.622 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: bitpool candidate: 43 (298 kbps) 04-07 14:40:11.622 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: computed bitpool too large (43) 04-07 14:40:11.622 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: bitpool candidate: 42 (293 kbps) 04-07 14:40:11.622 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: computed bitpool too large (42) 04-07 14:40:11.622 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: bitpool candidate: 41 (288 kbps) 04-07 14:40:11.622 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: computed bitpool too large (41) 04-07 14:40:11.622 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: bitpool candidate: 40 (283 kbps) 04-07 14:40:11.622 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: computed bitpool too large (40) 04-07 14:40:11.622 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: bitpool candidate: 39 (278 kbps) 04-07 14:40:11.622 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: computed bitpool too large (39) 04-07 14:40:11.622 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: bitpool candidate: 39 (273 kbps) 04-07 14:40:11.622 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: computed bitpool too large (39) 04-07 14:40:11.622 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: bitpool candidate: 38 (268 kbps) 04-07 14:40:11.622 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: computed bitpool too large (38) 04-07 14:40:11.622 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: bitpool candidate: 37 (263 kbps) 04-07 14:40:11.622 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: computed bitpool too large (37) 04-07 14:40:11.622 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: bitpool candidate: 36 (258 kbps) 04-07 14:40:11.622 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: computed bitpool too large (36) 04-07 14:40:11.622 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: bitpool candidate: 35 (253 kbps) 04-07 14:40:11.622 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: computed bitpool too large (35) 04-07 14:40:11.622 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: bitpool candidate: 34 (248 kbps) 04-07 14:40:11.622 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: computed bitpool too large (34) 04-07 14:40:11.622 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: bitpool candidate: 34 (243 kbps) 04-07 14:40:11.622 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: computed bitpool too large (34) 04-07 14:40:11.622 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: bitpool candidate: 33 (238 kbps) 04-07 14:40:11.623 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: computed bitpool too large (33) 04-07 14:40:11.623 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: bitpool candidate: 32 (233 kbps) 04-07 14:40:11.623 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: computed bitpool too large (32) 04-07 14:40:11.623 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: bitpool candidate: 31 (228 kbps) 04-07 14:40:11.623 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: final bit rate 228, final bit pool 31 04-07 14:40:11.623 4458 5063 I bt_stack: [INFO:btif_a2dp_source.cc(391)] btif_a2dp_source_start_session_delayed: peer_address=00:42:79:a0:ec:50 state=STATE_RUNNING 04-07 14:40:11.623 4458 4536 I BluetoothA2dpServiceJni: bta2dp_audio_config_callback 04-07 14:40:11.623 3486 3587 I BTAudioProviderStub: startSession - SessionType=A2DP_SOFTWARE_ENCODING_DATAPATH, AudioConfiguration=[{.pcmConfig = {.sampleRate = RATE_48000, .channelMode = STEREO, .bitsPerSample = BITS_16}}] 04-07 14:40:11.623 3486 3587 I BTAudioProviderSession: OnSessionStarted - SessionType=A2DP_SOFTWARE_ENCODING_DATAPATH, AudioConfiguration={.pcmConfig = {.sampleRate = RATE_48000, .channelMode = STEREO, .bitsPerSample = BITS_16}} 04-07 14:40:11.623 3486 3587 I BTAudioProviderSession: ReportSessionStatus - SessionType=A2DP_SOFTWARE_ENCODING_DATAPATH has NO port state observer 04-07 14:40:11.624 4458 5063 I bt_stack: [INFO:client_interface.cc(341)] startSession_cb(SUCCESS) 04-07 14:40:11.624 4458 4537 D A2dpService: Switch A2DP devices to 00:42:79:A0:EC:50 from null 04-07 14:40:11.624 4458 4537 D A2dpService: updateAndBroadcastActiveDevice(00:42:79:A0:EC:50) 04-07 14:40:11.624 4458 4536 D A2dpNativeInterface: onCodecConfigChanged: A2dpStackEvent {type:EVENT_TYPE_CODEC_CONFIG_CHANGED, device:00:42:79:A0:EC:50, value1:0, codecStatus:{mCodecConfig:{codecName:SBC,mCodecType:0,mCodecPriority:1001,mSampleRate:0x2(48000),mBitsPerSample:0x1(16),mChannelMode:0x2(STEREO),mCodecSpecific1:0,mCodecSpecific2:0,mCodecSpecific3:0,mCodecSpecific4:0},mCodecsLocalCapabilities:[{codecName:AAC,mCodecType:1,mCodecPriority:2001,mSampleRate:0x1(44100),mBitsPerSample:0x1(16),mChannelMode:0x2(STEREO),mCodecSpecific1:0,mCodecSpecific2:0,mCodecSpecific3:0,mCodecSpecific4:0}, {codecName:SBC,mCodecType:0,mCodecPriority:1001,mSampleRate:0x3(44100|48000),mBitsPerSample:0x1(16),mChannelMode:0x3(MONO|STEREO),mCodecSpecific1:0,mCodecSpecific2:0,mCodecSpecific3:0,mCodecSpecific4:0}],mCodecsSelectableCapabilities:[{codecName:SBC,mCodecType:0,mCodecPriority:1001,mSampleRate:0x3(44100|48000),mBitsPerSample:0x1(16),mChannelMode:0x3(MONO|STEREO),mCodecSpecific1:0,mCodecSpecific2:0,mCodecSpecific3:0,mCodecSpecific4:0}]}} 04-07 14:40:11.624 4458 4537 D AvrcpTargetService: volumeDeviceSwitched: device=00:42:79:A0:EC:50 04-07 14:40:11.625 4458 4537 D AvrcpVolumeManager: volumeDeviceSwitched: mCurrentDevice=null device=00:42:79:A0:EC:50 04-07 14:40:11.625 5528 5528 D BtvService4.2.49 IBtvService: BtvStartReceiver::create 04-07 14:40:11.625 5528 5528 D BtvService4.2.49 IBtvService: IN| BtvStartReceiver::onReceive getAction = android.bluetooth.a2dp.profile.action.CONNECTION_STATE_CHANGED 04-07 14:40:11.625 5528 5528 D BtvService4.2.49 IBtvService: BtvStartReceiver::setA2DPState : isConnected = true 04-07 14:40:11.625 4458 5062 D A2dpStateMachine: handleMessage: X 04-07 14:40:11.628 3557 3783 I SystemPropertyManager: change property : vendor.skb.SETTINGS.A2DP.PLUGGED 04-07 14:40:11.629 3557 3783 I TVService-21.08.18: [vendor/skb/framework/btf_dev/interface/btvservice/1.0/default/TVService.cpp][staticPropertyChange] called 04-07 14:40:11.629 3557 3783 I TVService-21.08.18: [vendor/skb/framework/btf_dev/interface/btvservice/1.0/default/TVService.cpp][staticPropertyChange][105] message received key=vendor.skb.SETTINGS.A2DP.PLUGGED, value= 04-07 14:40:11.629 3557 3783 I TVService-21.08.18: [TVService::onProperyUpdatedEvent]: key(vendor.skb.SETTINGS.A2DP.PLUGGED), value() 04-07 14:40:11.629 3557 3783 I TVService-21.08.18: [vendor/skb/framework/btf_dev/interface/btvservice/1.0/default/TVService.cpp][onProperyUpdatedEvent][271] callback application 04-07 14:40:11.629 3557 3783 I TVService-21.08.18: [vendor/skb/framework/btf_dev/interface/btvservice/1.0/default/TVService.cpp][onProperyUpdatedEvent][276] back from callback 04-07 14:40:11.629 5528 7289 D BTVCORE-JNI: [updatedProperty] message received key=vendor.skb.SETTINGS.A2DP.PLUGGED, value= 04-07 14:40:11.629 5528 7289 D BtvJniInterface: BTF|postPropertyUpdateFromNative|844|postEventFromProperty 04-07 14:40:11.629 5528 7289 D PropertyService: BTF|onHandleEvent|488|onHandleEvent type = 1 key = vendor.skb.SETTINGS.A2DP.PLUGGED 04-07 14:40:11.630 5528 7289 D PropertyService: BTF|onHandleEvent|494|propertyservice: setChangePropertyListener onHandleEvent start callback count=1 BUILD_DATE:2021.11.15 04-07 14:40:11.630 5528 7289 D PropertyService: BTF|onHandleEvent|498|propertyservice: setChangePropertyListener onHandleEvent packeage=package com.skb.btv.framework.property, Unknown, version 0.0 04-07 14:40:11.631 4458 4537 D A2dpService: broadcastCodecConfig(00:42:79:A0:EC:50): {mCodecConfig:{codecName:SBC,mCodecType:0,mCodecPriority:1001,mSampleRate:0x2(48000),mBitsPerSample:0x1(16),mChannelMode:0x2(STEREO),mCodecSpecific1:0,mCodecSpecific2:0,mCodecSpecific3:0,mCodecSpecific4:0},mCodecsLocalCapabilities:[{codecName:AAC,mCodecType:1,mCodecPriority:2001,mSampleRate:0x1(44100),mBitsPerSample:0x1(16),mChannelMode:0x2(STEREO),mCodecSpecific1:0,mCodecSpecific2:0,mCodecSpecific3:0,mCodecSpecific4:0}, {codecName:SBC,mCodecType:0,mCodecPriority:1001,mSampleRate:0x3(44100|48000),mBitsPerSample:0x1(16),mChannelMode:0x3(MONO|STEREO),mCodecSpecific1:0,mCodecSpecific2:0,mCodecSpecific3:0,mCodecSpecific4:0}],mCodecsSelectableCapabilities:[{codecName:SBC,mCodecType:0,mCodecPriority:1001,mSampleRate:0x3(44100|48000),mBitsPerSample:0x1(16),mChannelMode:0x3(MONO|STEREO),mCodecSpecific1:0,mCodecSpecific2:0,mCodecSpecific3:0,mCodecSpecific4:0}]} 04-07 14:40:11.632 6042 6066 D PropertyManager: BTF|ChangePropertyCallback|519| ChangePropertyCallback ChangePropertyListener start type=1, key=vendor.skb.SETTINGS.A2DP.PLUGGED 04-07 14:40:11.633 5528 5528 D BtvService4.2.49 IBtvService: BTF|onReceive|241|OUT| BtvStartReceiver::onReceive 04-07 14:40:11.636 4458 4537 D AvrcpVolumeManager: getVolume: Returning volume 5 04-07 14:40:11.637 3836 4408 I AS.AudioDeviceBroker: setBluetoothA2dpDeviceConnectionStateSuppressNoisyIntent state=2 addr=00:42:79:A0:EC:50 prof=2 supprNoisy=true vol=5 04-07 14:40:11.637 3836 4408 D BluetoothA2dp: getCodecStatus(00:42:79:A0:EC:50) 04-07 14:40:11.639 4458 4458 D AvrcpNativeInterface: sendMediaUpdate: metadata=false playStatus=true queue=false 04-07 14:40:11.639 4458 4458 D AvrcpTargetJni: sendMediaUpdateNative 04-07 14:40:11.639 4458 4458 I bt_stack: [INFO:avrcp_service.cc(346)] virtual void bluetooth::avrcp::AvrcpService::SendMediaUpdate(bool, bool, bool) track_changed=0 : play_state=1 : queue=0 04-07 14:40:11.640 4458 5058 D A2dpService: getCodecStatus(00:42:79:A0:EC:50) 04-07 14:40:11.640 4458 4537 D BluetoothActiveDeviceManager: handleMessage(MESSAGE_A2DP_ACTION_ACTIVE_DEVICE_CHANGED): device= 00:42:79:A0:EC:50 04-07 14:40:11.640 3836 4408 I AS.AudioDeviceInventory: setBluetoothA2dpDeviceConnectionState device: 00:42:79:A0:EC:50 state: 2 delay(ms): 0codec:520093696 suppressNoisyIntent: true 04-07 14:40:11.640 3836 4408 D AS.AudioDeviceInventory: onSetA2dpSinkConnectionState btDevice=00:42:79:A0:EC:50 state=2 is dock=false vol=5 04-07 14:40:11.644 4458 5062 D A2dpStateMachine: handleMessage: E msg.what=101 04-07 14:40:11.645 4458 5062 D A2dpStateMachine: processMsg: Connected 04-07 14:40:11.645 4458 5062 D A2dpStateMachine: Connected process message(00:42:79:A0:EC:50): STACK_EVENT 04-07 14:40:11.646 4458 4536 D AvrcpTargetJni: getCurrentPlayStatus 04-07 14:40:11.646 4458 5041 I bt_stack: [INFO:device.cc(1360)] 00:42:79:a0:ec:50 : HandlePlayPosUpdate 04-07 14:40:11.646 4458 5041 W bt_stack: [WARNING:device.cc(1362)] Device is not registered for play position updates 04-07 14:40:11.646 4458 4536 D AvrcpNativeInterface: getPlayStatus 04-07 14:40:11.647 4458 4458 I BluetoothPhonePolicy: processProfileActiveDeviceChanged, activeDevice=00:42:79:A0:EC:50, profile=2 04-07 14:40:11.649 4458 5062 D A2dpStateMachine: Connected: stack event: A2dpStackEvent {type:EVENT_TYPE_CODEC_CONFIG_CHANGED, device:00:42:79:A0:EC:50, value1:0, codecStatus:{mCodecConfig:{codecName:SBC,mCodecType:0,mCodecPriority:1001,mSampleRate:0x2(48000),mBitsPerSample:0x1(16),mChannelMode:0x2(STEREO),mCodecSpecific1:0,mCodecSpecific2:0,mCodecSpecific3:0,mCodecSpecific4:0},mCodecsLocalCapabilities:[{codecName:AAC,mCodecType:1,mCodecPriority:2001,mSampleRate:0x1(44100),mBitsPerSample:0x1(16),mChannelMode:0x2(STEREO),mCodecSpecific1:0,mCodecSpecific2:0,mCodecSpecific3:0,mCodecSpecific4:0}, {codecName:SBC,mCodecType:0,mCodecPriority:1001,mSampleRate:0x3(44100|48000),mBitsPerSample:0x1(16),mChannelMode:0x3(MONO|STEREO),mCodecSpecific1:0,mCodecSpecific2:0,mCodecSpecific3:0,mCodecSpecific4:0}],mCodecsSelectableCapabilities:[{codecName:SBC,mCodecType:0,mCodecPriority:1001,mSampleRate:0x3(44100|48000),mBitsPerSample:0x1(16),mChannelMode:0x3(MONO|STEREO),mCodecSpecific1:0,mCodecSpecific2:0,mCodecSpecific3:0,mCodecSpecific4:0}]}} 04-07 14:40:11.649 4458 4458 V BluetoothDatabase: getProfilePriority: 14:4E:34:92:1C:B3, profile=2, priority = -1 04-07 14:40:11.650 4458 4458 V BluetoothDatabase: getProfilePriority: 14:4E:34:92:1C:B3, profile=1, priority = -1 04-07 14:40:11.651 4458 4458 V BluetoothDatabase: getProfilePriority: 14:4E:34:A1:56:4D, profile=2, priority = 100 04-07 14:40:11.652 4458 5062 D A2dpStateMachine: A2DP Codec Config: {codecName:SBC,mCodecType:0,mCodecPriority:1001,mSampleRate:0x2(48000),mBitsPerSample:0x1(16),mChannelMode:0x2(STEREO),mCodecSpecific1:0,mCodecSpecific2:0,mCodecSpecific3:0,mCodecSpecific4:0}->{codecName:SBC,mCodecType:0,mCodecPriority:1001,mSampleRate:0x2(48000),mBitsPerSample:0x1(16),mChannelMode:0x2(STEREO),mCodecSpecific1:0,mCodecSpecific2:0,mCodecSpecific3:0,mCodecSpecific4:0} 04-07 14:40:11.653 4458 4458 V BluetoothDatabase: getProfilePriority: 14:4E:34:A1:56:4D, profile=1, priority = -1 04-07 14:40:11.655 4458 4536 D AvrcpTargetJni: getCurrentPlayStatus 04-07 14:40:11.655 4458 4536 D AvrcpNativeInterface: getPlayStatus 04-07 14:40:11.655 4458 5062 D A2dpStateMachine: A2DP Codec Local Capability: {codecName:AAC,mCodecType:1,mCodecPriority:2001,mSampleRate:0x1(44100),mBitsPerSample:0x1(16),mChannelMode:0x2(STEREO),mCodecSpecific1:0,mCodecSpecific2:0,mCodecSpecific3:0,mCodecSpecific4:0} 04-07 14:40:11.656 4458 4458 V BluetoothDatabase: getProfilePriority: 88:D0:39:BB:21:A0, profile=2, priority = 100 04-07 14:40:11.656 4458 5062 D A2dpStateMachine: A2DP Codec Local Capability: {codecName:SBC,mCodecType:0,mCodecPriority:1001,mSampleRate:0x3(44100|48000),mBitsPerSample:0x1(16),mChannelMode:0x3(MONO|STEREO),mCodecSpecific1:0,mCodecSpecific2:0,mCodecSpecific3:0,mCodecSpecific4:0} 04-07 14:40:11.657 4458 4458 V BluetoothDatabase: getProfilePriority: 88:D0:39:BB:21:A0, profile=1, priority = 100 04-07 14:40:11.657 4458 5062 D A2dpStateMachine: A2DP Codec Selectable Capability: {codecName:SBC,mCodecType:0,mCodecPriority:1001,mSampleRate:0x3(44100|48000),mBitsPerSample:0x1(16),mChannelMode:0x3(MONO|STEREO),mCodecSpecific1:0,mCodecSpecific2:0,mCodecSpecific3:0,mCodecSpecific4:0} 04-07 14:40:11.657 7572 7572 D BtvBtPairingService: sptek:BT onProfileConnectionStateChanged name = JBL Flip 4, connectState = STATE_CONNECTED_2, bluetoothProfile = 2, controlState = 0 04-07 14:40:11.658 4458 4458 V BluetoothDatabase: getProfilePriority: 00:42:79:A0:EC:50, profile=2, priority = 1000 04-07 14:40:11.658 4458 4458 I BluetoothPhonePolicy: removeAutoConnectFromA2dpSink: device 00:42:79:A0:EC:50 PRIORITY_ON 04-07 14:40:11.663 4458 4458 D A2dpService: Saved priority 00:42:79:A0:EC:50 = 100 04-07 14:40:11.664 4458 4458 V BluetoothDatabase: setProfilePriority: 00:42:79:A0:EC:50, profile=2, priority = 100 04-07 14:40:11.664 4458 4458 D BluetoothDatabase: updateDatabase 00:42:79:A0:EC:50 04-07 14:40:11.666 4458 4458 V BluetoothDatabase: getProfilePriority: 00:42:79:A0:EC:50, profile=1, priority = 1000 04-07 14:40:11.666 4458 5062 D A2dpService: broadcastCodecConfig(00:42:79:A0:EC:50): {mCodecConfig:{codecName:SBC,mCodecType:0,mCodecPriority:1001,mSampleRate:0x2(48000),mBitsPerSample:0x1(16),mChannelMode:0x2(STEREO),mCodecSpecific1:0,mCodecSpecific2:0,mCodecSpecific3:0,mCodecSpecific4:0},mCodecsLocalCapabilities:[{codecName:AAC,mCodecType:1,mCodecPriority:2001,mSampleRate:0x1(44100),mBitsPerSample:0x1(16),mChannelMode:0x2(STEREO),mCodecSpecific1:0,mCodecSpecific2:0,mCodecSpecific3:0,mCodecSpecific4:0}, {codecName:SBC,mCodecType:0,mCodecPriority:1001,mSampleRate:0x3(44100|48000),mBitsPerSample:0x1(16),mChannelMode:0x3(MONO|STEREO),mCodecSpecific1:0,mCodecSpecific2:0,mCodecSpecific3:0,mCodecSpecific4:0}],mCodecsSelectableCapabilities:[{codecName:SBC,mCodecType:0,mCodecPriority:1001,mSampleRate:0x3(44100|48000),mBitsPerSample:0x1(16),mChannelMode:0x3(MONO|STEREO),mCodecSpecific1:0,mCodecSpecific2:0,mCodecSpecific3:0,mCodecSpecific4:0}]} 04-07 14:40:11.666 4458 4458 I BluetoothPhonePolicy: removeAutoConnectFromHeadset: device 00:42:79:A0:EC:50 PRIORITY_ON 04-07 14:40:11.668 4458 4458 I HeadsetService: setPriority: device=00:42:79:A0:EC:50, priority=100, uid/pid=1002/4458 04-07 14:40:11.668 4458 4458 V BluetoothDatabase: setProfilePriority: 00:42:79:A0:EC:50, profile=1, priority = 100 04-07 14:40:11.668 4458 4458 D BluetoothDatabase: updateDatabase 00:42:79:A0:EC:50 04-07 14:40:11.668 4458 5062 D A2dpStateMachine: handleMessage: X 04-07 14:40:11.669 3486 3587 D audio_hw_primary: adev_set_parameters(0xea775280, 00:42:79:A0:EC:50=;connect=128) 04-07 14:40:11.669 3486 3587 I audio_hw_primary: adev_set_parameters(kv: 00:42:79:A0:EC:50=;connect=128) 04-07 14:40:11.669 3486 3587 D a2dp_hal: a2dp_out_open: open 04-07 14:40:11.669 3486 3587 D A2DPHW : BluetoothAudioPortOut::SetUp: 04-07 14:40:11.669 3486 3587 D a2dp_hal: LoadAudioConfig: rate=48000, format=1, ch=3 04-07 14:40:11.669 3486 3587 I audio_hw_primary: adev_set_parameters a2dp connect: 80, device=480 04-07 14:40:11.669 4458 4458 V BluetoothDatabase: getProfilePriority: 00:42:79:A0:EC:50, profile=2, priority = 100 04-07 14:40:11.669 4458 4458 I BluetoothPhonePolicy: setAutoConnectForA2dpSink: device 00:42:79:A0:EC:50 PRIORITY_AUTO_CONNECT 04-07 14:40:11.670 3521 3758 I AudioFlinger: openOutput() this 0xee3c3000, module 10 Device 0x80, SamplingRate 48000, Format 0x000001, Channels 0x3, flags 0x4011 04-07 14:40:11.670 3486 8511 D audio_hw_primary: adev_open_output_stream_new: enter 04-07 14:40:11.670 3486 8511 D audio_hw_primary: adev_open_output_stream: enter: devices(0x80) channel_mask(0x3) rate(48000) format(0x1) flags(0x4011) 04-07 14:40:11.670 3486 8511 I aml_mmap_audio: [outMmapInit:302] stream:0xea7dda80 04-07 14:40:11.670 4458 4458 D A2dpService: Saved priority 00:42:79:A0:EC:50 = 1000 04-07 14:40:11.670 4458 4458 V BluetoothDatabase: setProfilePriority: 00:42:79:A0:EC:50, profile=2, priority = 1000 04-07 14:40:11.670 4458 4458 D BluetoothDatabase: updateDatabase 00:42:79:A0:EC:50 04-07 14:40:11.671 3486 8511 I audio_hwsync: aml_audio_hwsync_init open tsync fd 26 04-07 14:40:11.671 3486 8511 I audio_hwsync: aml_audio_hwsync_init done 04-07 14:40:11.671 3486 8511 D audio_hw_primary: adev_open_output_stream: exit 04-07 14:40:11.671 3486 8511 D audio_hw_profile: get_hdmi_sink_cap is running... 04-07 14:40:11.671 4458 4458 V BluetoothDatabase: getProfilePriority: 00:42:79:A0:EC:50, profile=1, priority = 100 04-07 14:40:11.671 3486 8511 D audio_hw_profile: query hdmi format... 04-07 14:40:11.671 4458 4458 I BluetoothPhonePolicy: setAutoConnectForHeadset: device 00:42:79:A0:EC:50 PRIORITY_AUTO_CONNECT 04-07 14:40:11.672 3486 8511 I audio_hw_primary: get_sink_capability mbox+dvb case sink_capability = 0x1 04-07 14:40:11.672 3486 8511 D audio_hw_primary: get_sink_format: a2dp set to pcm 04-07 14:40:11.672 3486 8511 I audio-subMixingFactory: ++initSubMixingInput() 04-07 14:40:11.672 3486 8511 I audio-subMixingFactory: ++initSubMixingInputPcm(), out 0xea7dda80, flags 0x4011, hwsync lpcm 0, out format 0x1 04-07 14:40:11.672 3486 8511 D audio_hw_primary: -adev_open_output_stream_new: out 0xea7dda80: usecase:[7]PCM_MMAP card:0 alsa devices:0 04-07 14:40:11.672 4458 4458 I HeadsetService: setPriority: device=00:42:79:A0:EC:50, priority=1000, uid/pid=1002/4458 04-07 14:40:11.672 4458 4458 V BluetoothDatabase: setProfilePriority: 00:42:79:A0:EC:50, profile=1, priority = 1000 04-07 14:40:11.672 4458 4458 D BluetoothDatabase: updateDatabase 00:42:79:A0:EC:50 04-07 14:40:11.674 3486 8511 I audio_hw_primary: out_get_buffer_size(out->config.rate=48000, format 1,stream format 1) 04-07 14:40:11.678 3521 8541 I AudioFlinger: AudioFlinger's thread 0xe9d7f000 tid=8541 ready to run 04-07 14:40:11.679 3486 8511 D audio_hw_primary: out_set_parameters(kvpairs(a2dp_sink_address=00:42:79:A0:EC:50), out_device=0x480) 04-07 14:40:11.679 3486 8511 E audio_hw_primary: Amlogic_HAL - out_set_parameters: parameter is NULL, change ret value to 0 in order to pass VTS test. 04-07 14:40:11.679 3486 8511 I audio_hw_primary: out_set_volume(), stream(0xea7dda80), left:1.000000 right:1.000000 04-07 14:40:11.680 3486 8513 D audio-subMixingFactory: [mixer_main_buffer_write_sm:1099] stream:0xea7de500, switch from device:0x480 to device:0x400 04-07 14:40:11.683 3486 3773 D a2dp_hal: a2dp_out_write_new: state=1 04-07 14:40:11.683 4458 4863 I btif_av : btif_av_stream_ready: Peer 00:42:79:a0:ec:50 : state=2, flags=0x0(None) 04-07 14:40:11.683 4458 4863 I btif_av : btif_av_stream_start 04-07 14:40:11.683 4458 4863 I bt_stack: [INFO:a2dp_encoding.cc(99)] StartRequest: accepted 04-07 14:40:11.683 4458 5041 I btif_av : virtual bool BtifAvStateMachine::StateOpened::ProcessEvent(uint32_t, void *): Peer 00:42:79:a0:ec:50 : event=BTIF_AV_START_STREAM_REQ_EVT(0x1b) flags=0x0(None) 04-07 14:40:11.683 4458 5041 I bt_bta_av: BTA_AvStart: handle=65 04-07 14:40:11.683 4458 5041 I bt_bta_av: bta_av_do_start: peer 00:42:79:a0:ec:50 sco_occupied:false role:0x0 started:false wait:0x0 04-07 14:40:11.683 4458 5041 W bt_btif : bta_dm_rm_cback:2, status:7 04-07 14:40:11.683 4458 5041 I bt_bta_av: bta_av_do_start: peer 00:42:79:a0:ec:50 start requested: sco_occupied:false role:0x10 started:false wait:0x0 04-07 14:40:11.690 4458 4536 D AvrcpTargetJni: getCurrentPlayStatus 04-07 14:40:11.690 4458 4536 D AvrcpNativeInterface: getPlayStatus 04-07 14:40:11.691 3486 8511 I audio_hw_primary: out_set_volume(), stream(0xea7dda80), left:0.001879 right:0.001879 04-07 14:40:11.705 3521 3758 I AudioFlinger: openOutput() this 0xee3c3000, module 10 Device 0x80, SamplingRate 0, Format 00000000, Channels 0, flags 0x41 04-07 14:40:11.705 3486 8511 D audio_hw_primary: adev_open_output_stream_new: enter 04-07 14:40:11.705 3486 8511 D audio_hw_primary: adev_open_output_stream: enter: devices(0x80) channel_mask(0) rate(0) format(0) flags(0x41) 04-07 14:40:11.705 3486 8511 I audio_hw_primary: adev_open_output_stream: for raw audio output,force alsa stereo output 04-07 14:40:11.705 3486 8511 I audio_hwsync: aml_audio_hwsync_init open tsync fd 27 04-07 14:40:11.705 3486 8511 I audio_hwsync: aml_audio_hwsync_init done 04-07 14:40:11.705 3486 8511 D audio_hw_primary: adev_open_output_stream format=150994944 rate=48000 04-07 14:40:11.705 3486 8511 D audio_hw_primary: adev_open_output_stream: exit 04-07 14:40:11.705 3486 8511 D audio_hw_profile: get_hdmi_sink_cap is running... 04-07 14:40:11.706 3486 8511 D audio_hw_profile: query hdmi format... 04-07 14:40:11.706 3486 8511 I audio_hw_primary: get_sink_capability mbox+dvb case sink_capability = 0x1 04-07 14:40:11.706 3486 8511 D audio_hw_primary: get_sink_format: a2dp set to pcm 04-07 14:40:11.706 3486 8511 I audio_hw_primary: adev_open_output_stream_new(), direct usecase: [4]RAW_HWSYNC 04-07 14:40:11.706 3486 8511 I audio_hw_primary: write function change adev_open_output_stream_new 9658 04-07 14:40:11.706 3486 8511 D audio_hw_primary: -adev_open_output_stream_new: out 0xea7dec00: usecase:[4]RAW_HWSYNC card:0 alsa devices:0 04-07 14:40:11.708 3521 3758 D AudioFlinger: readOutputParameters_l enable volume passthrough HAL format: 0x9000000. 04-07 14:40:11.708 3521 3758 D AudioFlinger: readOutputParameters_l enable volume passthrough. 04-07 14:40:11.714 3486 8511 I audio_hw_primary: out_get_buffer_size(out->config.rate=48000, format 9000000,stream format 9000000) 04-07 14:40:11.715 3521 3758 I AudioFlinger: HAL output buffer size 512 frames, normal sink buffer size 512 frames 04-07 14:40:11.715 3521 8542 I AudioFlinger: AudioFlinger's thread 0xe9d81800 tid=8542 ready to run 04-07 14:40:11.717 3486 8511 D audio_hw_primary: out_standby_new: enter 04-07 14:40:11.717 3486 8511 I audio_hw_primary: [do_output_standby_l:6678] stream usecase:[4]RAW_HWSYNC , continuous:0 04-07 14:40:11.717 3486 8511 E a2dp_hal: a2dp_out_standby: hal_audio_open_times=1, not close 04-07 14:40:11.717 3486 8511 I audio_hw_primary: ++[usecase_change_validate_l:9394], dev masks:0x2, is_standby:1, out usecase:[4]RAW_HWSYNC 04-07 14:40:11.717 3486 8511 I audio_hw_primary: enable rawtopcm_flag !!! 04-07 14:40:11.717 3486 8511 I audio_hw_primary: --[usecase_change_validate_l:9409], dev masks:0x2, is_standby:1, out usecase [4]RAW_HWSYNC 04-07 14:40:11.717 3486 8511 I audio_hw_primary: do_output_standby_l current usecase_masks 2 04-07 14:40:11.717 3486 8511 D audio_hw_primary: out_standby_new: exit 04-07 14:40:11.718 3486 8511 D audio_hw_primary: out_set_parameters(kvpairs(a2dp_sink_address=00:42:79:A0:EC:50), out_device=0x480) 04-07 14:40:11.718 3486 8511 E audio_hw_primary: Amlogic_HAL - out_set_parameters: parameter is NULL, change ret value to 0 in order to pass VTS test. 04-07 14:40:11.720 3486 8511 I audio_hw_primary: out_get_parameters sup_formats,out 0xea7dec00 04-07 14:40:11.720 3486 8511 D audio_hw_profile: get_hdmi_sink_cap_dolbylib is running... 04-07 14:40:11.720 3486 8511 D audio_hw_profile: query hdmi format... 04-07 14:40:11.720 3486 8511 I audio_hw_primary: sup_formats=AUDIO_FORMAT_PCM_16_BIT|AUDIO_FORMAT_IEC61937 04-07 14:40:11.721 3486 8511 I audio_hw_primary: out_get_parameters format=1;sup_sampling_rates,out 0xea7dec00 04-07 14:40:11.721 3486 8511 D audio_hw_profile: get_hdmi_sink_cap_dolbylib is running... 04-07 14:40:11.721 3486 8511 D audio_hw_profile: query hdmi sample_rate... 04-07 14:40:11.722 3486 8511 I audio_hw_primary: sup_sampling_rates=32000|44100|48000 04-07 14:40:11.722 3486 8511 I audio_hw_primary: out_get_parameters format=1;sup_channels,out 0xea7dec00 04-07 14:40:11.722 3486 8511 D audio_hw_profile: get_hdmi_sink_cap_dolbylib is running... 04-07 14:40:11.722 3486 8511 D audio_hw_profile: query hdmi channels... 04-07 14:40:11.722 3486 8511 I audio_hw_primary: sup_channels=AUDIO_CHANNEL_OUT_STEREO 04-07 14:40:11.723 3486 8511 I audio_hw_primary: out_get_parameters format=218103808;sup_sampling_rates,out 0xea7dec00 04-07 14:40:11.723 3486 8511 D audio_hw_profile: get_hdmi_sink_cap_dolbylib is running... 04-07 14:40:11.723 3486 8511 D audio_hw_profile: query hdmi sample_rate... 04-07 14:40:11.723 3486 8511 I audio_hw_primary: sup_sampling_rates=32000|44100|48000 04-07 14:40:11.724 3486 8511 I audio_hw_primary: out_get_parameters format=218103808;sup_channels,out 0xea7dec00 04-07 14:40:11.724 3486 8511 D audio_hw_profile: get_hdmi_sink_cap_dolbylib is running... 04-07 14:40:11.724 3486 8511 D audio_hw_profile: query hdmi channels... 04-07 14:40:11.724 3486 8511 I audio_hw_primary: sup_channels=AUDIO_CHANNEL_OUT_STEREO 04-07 14:40:11.727 4458 5041 I bt_bta_av: bta_av_start_ok: peer 00:42:79:a0:ec:50 handle:65 wait:0x0 role:0x10 local_tsep:0 04-07 14:40:11.727 4458 5041 I bt_bta_av: bta_av_link_role_ok: peer 00:42:79:a0:ec:50 hndl:0x41 role:0 conn_audio:0x1 bits:1 features:0x865b 04-07 14:40:11.728 4458 5041 W bt_btif : bta_dm_rm_cback:2, status:0 04-07 14:40:11.728 4458 5041 W bt_btif : bta_dm_rm_cback:2, status:7 04-07 14:40:11.728 4458 5041 I btif_av : virtual bool BtifAvStateMachine::StateOpened::ProcessEvent(uint32_t, void *): Peer 00:42:79:a0:ec:50 : event=BTA_AV_START_EVT(0x4) status=0 suspending=0 initiator=1 flags=0x4(PENDING_START) 04-07 14:40:11.728 4458 5041 I bt_stack: [INFO:btif_a2dp.cc(50)] btif_a2dp_on_started: ## ON A2DP STARTED ## peer 00:42:79:a0:ec:50 p_av_start:0xe15a3d30 04-07 14:40:11.728 4458 5041 I bt_stack: [INFO:btif_a2dp.cc(70)] btif_a2dp_on_started: peer 00:42:79:a0:ec:50 status:0 suspending:false initiator:true 04-07 14:40:11.728 4458 5041 I bt_btif_a2dp_source: btif_a2dp_source_start_audio_req: state=STATE_RUNNING 04-07 14:40:11.728 4458 5041 I bt_stack: [INFO:a2dp_encoding.cc(683)] ack_stream_started: result=SUCCESS_FINISHED 04-07 14:40:11.728 4458 5063 I bt_btif_a2dp_source: btif_a2dp_source_audio_tx_start_event: media_alarm is not running, streaming false state=STATE_RUNNING 04-07 14:40:11.728 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_feeding_reset: PCM bytes per tick 3840 04-07 14:40:11.728 3486 3587 I BTAudioProviderStub: streamStarted - SessionType=A2DP_SOFTWARE_ENCODING_DATAPATH, status=SUCCESS 04-07 14:40:11.728 3486 8511 D audio_hw_primary: out_set_parameters(kvpairs(closing=true), out_device=0x480) 04-07 14:40:11.728 3486 3587 I BTAudioProviderSession: ReportControlStatus - status=SUCCESS for SessionType=A2DP_SOFTWARE_ENCODING_DATAPATH, bluetooth_audio=0x0100 started 04-07 14:40:11.728 3486 8511 E audio_hw_primary: Amlogic_HAL - out_set_parameters: parameter is NULL, change ret value to 0 in order to pass VTS test. 04-07 14:40:11.728 3486 3773 D A2DPHW : BluetoothAudioPortOut::Start: state=3, ret=1 04-07 14:40:11.728 3486 3773 E audio_virtual_buf: mixer_16bit_thread underrun happens read=60701757404 write=60696000000 diff=5757404 04-07 14:40:11.728 4458 5041 I btif_av : btif_report_audio_state: peer_address=00:42:79:a0:ec:50 state=2 04-07 14:40:11.730 3486 3587 D audio_hw_primary: out_dump(0xea7dec00, 28) 04-07 14:40:11.732 4458 4536 I BluetoothA2dpServiceJni: bta2dp_audio_state_callback 04-07 14:40:11.732 4458 4536 D A2dpNativeInterface: onAudioStateChanged: A2dpStackEvent {type:EVENT_TYPE_AUDIO_STATE_CHANGED, device:00:42:79:A0:EC:50, value1:STARTED} 04-07 14:40:11.732 4458 5062 D A2dpStateMachine: handleMessage: E msg.what=101 04-07 14:40:11.733 4458 5062 D A2dpStateMachine: processMsg: Connected 04-07 14:40:11.733 4458 5062 D A2dpStateMachine: Connected process message(00:42:79:A0:EC:50): STACK_EVENT 04-07 14:40:11.733 4458 5062 D A2dpStateMachine: Connected: stack event: A2dpStackEvent {type:EVENT_TYPE_AUDIO_STATE_CHANGED, device:00:42:79:A0:EC:50, value1:STARTED} 04-07 14:40:11.733 4458 5062 I A2dpStateMachine: Connected: started playing: 00:42:79:A0:EC:50 04-07 14:40:11.733 4458 5062 D A2dpStateMachine: A2DP Playing state : device: 00:42:79:A0:EC:50 State:NOT_PLAYING->PLAYING 04-07 14:40:11.734 4458 5062 D A2dpStateMachine: handleMessage: X 04-07 14:40:11.734 3486 3587 D audio_hw_primary: out_set_parameters(kvpairs(exiting=1), out_device=0x480) 04-07 14:40:11.734 3486 3587 E audio_hw_primary: Amlogic_HAL - out_set_parameters: parameter is NULL, change ret value to 0 in order to pass VTS test. 04-07 14:40:11.734 3521 3758 D AudioFlinger: preExit HAL format: 0x9000000. 04-07 14:40:11.734 3521 3758 D AudioFlinger: preExit disable volume passthrough. 04-07 14:40:11.742 3486 3587 D audio_hw_primary: adev_close_output_stream_new: enter usecase = [4]RAW_HWSYNC 04-07 14:40:11.742 3521 3758 I AudioFlinger: openOutput() this 0xee3c3000, module 10 Device 0x80, SamplingRate 32000, Format 0xd000000, Channels 0x3, flags 0x41 04-07 14:40:11.743 3486 3587 D audio_hw_primary: adev_close_output_stream: enter: dev(0xea775280) stream(0xea7dec00) 04-07 14:40:11.743 3486 3587 D audio_hw_primary: out_standby_new: enter 04-07 14:40:11.743 3486 3587 I audio_hw_primary: [do_output_standby_l:6678] stream usecase:[4]RAW_HWSYNC , continuous:0 04-07 14:40:11.743 3486 3587 E a2dp_hal: a2dp_out_standby: hal_audio_open_times=1, not close 04-07 14:40:11.743 3486 3587 I audio_hw_primary: ++[usecase_change_validate_l:9394], dev masks:0x2, is_standby:1, out usecase:[4]RAW_HWSYNC 04-07 14:40:11.743 3486 3587 I audio_hw_primary: enable rawtopcm_flag !!! 04-07 14:40:11.743 3486 3587 I audio_hw_primary: --[usecase_change_validate_l:9409], dev masks:0x2, is_standby:1, out usecase [4]RAW_HWSYNC 04-07 14:40:11.743 3486 3587 I audio_hw_primary: do_output_standby_l current usecase_masks 2 04-07 14:40:11.743 3486 3587 D audio_hw_primary: out_standby_new: exit 04-07 14:40:11.743 3486 3587 I audio_hw_primary: enable rawtopcm_flag 04-07 14:40:11.743 3486 8511 D audio_hw_primary: adev_open_output_stream_new: enter 04-07 14:40:11.743 3486 3587 I audio_hwsync: aml_audio_hwsync_release done 04-07 14:40:11.743 3486 8511 D audio_hw_primary: adev_open_output_stream: enter: devices(0x80) channel_mask(0x3) rate(32000) format(0xd000000) flags(0x441) 04-07 14:40:11.743 3486 3587 D audio_hw_primary: adev_close_output_stream: exit 04-07 14:40:11.743 3486 3587 D audio_hw_primary: adev_close_output_stream_new: exit 04-07 14:40:11.743 3486 8511 I audio_hw_primary: convert format IEC61937 to 0x9000000 04-07 14:40:11.743 3486 8511 I audio_hw_primary: adev_open_output_stream: for raw audio output,force alsa stereo output 04-07 14:40:11.743 3486 8511 I audio_hwsync: aml_audio_hwsync_init open tsync fd 27 04-07 14:40:11.744 3486 8511 I audio_hwsync: aml_audio_hwsync_init done 04-07 14:40:11.744 3486 8511 D audio_hw_primary: adev_open_output_stream format=150994944 rate=32000 04-07 14:40:11.744 3486 8511 D audio_hw_primary: adev_open_output_stream: exit 04-07 14:40:11.744 3486 8511 D audio_hw_profile: get_hdmi_sink_cap is running... 04-07 14:40:11.744 3486 8511 D audio_hw_profile: query hdmi format... 04-07 14:40:11.744 3486 8511 I audio_hw_primary: get_sink_capability mbox+dvb case sink_capability = 0x1 04-07 14:40:11.744 3486 8511 D audio_hw_primary: get_sink_format: a2dp set to pcm 04-07 14:40:11.744 3486 8511 I audio_hw_primary: adev_open_output_stream_new(), direct usecase: [3]RAW_DIRECT 04-07 14:40:11.744 3486 8511 I audio_hw_primary: write function change adev_open_output_stream_new 9658 04-07 14:40:11.744 3486 8511 D audio_hw_primary: -adev_open_output_stream_new: out 0xea7def80: usecase:[3]RAW_DIRECT card:0 alsa devices:0 04-07 14:40:11.747 3521 3758 D AudioFlinger: readOutputParameters_l enable volume passthrough HAL format: 0xd000000. 04-07 14:40:11.747 3486 3587 I audio_hw_primary: out_get_buffer_size(out->config.rate=32000, format 9000000,stream format d000000) 04-07 14:40:11.747 3486 3587 I audio_hw_primary: out_get_buffer_size AUDIO_FORMAT_IEC61937 6144) 04-07 14:40:11.747 3486 3587 I audio_hw_primary: out_get_buffer_size AUDIO_FORMAT_IEC61937(DIRECT) (eDolbyDcvLib) size = 1536) 04-07 14:40:11.750 3521 3758 I AudioFlinger: HAL output buffer size 1536 frames, normal sink buffer size 1536 frames 04-07 14:40:11.751 3521 8544 I AudioFlinger: AudioFlinger's thread 0xe9d81800 tid=8544 ready to run 04-07 14:40:11.754 3486 3587 D audio_hw_primary: out_standby_new: enter 04-07 14:40:11.754 3486 3587 I audio_hw_primary: [do_output_standby_l:6678] stream usecase:[3]RAW_DIRECT , continuous:0 04-07 14:40:11.754 3486 3587 E a2dp_hal: a2dp_out_standby: hal_audio_open_times=1, not close 04-07 14:40:11.754 3486 3587 I audio_hw_primary: ++[usecase_change_validate_l:9394], dev masks:0x2, is_standby:1, out usecase:[3]RAW_DIRECT 04-07 14:40:11.754 3486 3587 I audio_hw_primary: enable rawtopcm_flag !!! 04-07 14:40:11.754 3486 3587 I audio_hw_primary: --[usecase_change_validate_l:9409], dev masks:0x2, is_standby:1, out usecase [3]RAW_DIRECT 04-07 14:40:11.754 3486 3587 I audio_hw_primary: do_output_standby_l current usecase_masks 2 04-07 14:40:11.754 3486 3587 D audio_hw_primary: out_standby_new: exit 04-07 14:40:11.776 3486 3587 D audio_hw_primary: out_set_parameters(kvpairs(closing=true), out_device=0x480) 04-07 14:40:11.776 3486 3587 E audio_hw_primary: Amlogic_HAL - out_set_parameters: parameter is NULL, change ret value to 0 in order to pass VTS test. 04-07 14:40:11.778 3521 3758 D AudioFlinger: closing mmapThread 0xe9d7f000 04-07 14:40:11.778 3521 3758 D AudioFlinger: mmapThread exit() 04-07 14:40:11.780 3486 3587 D audio_hw_primary: adev_close_output_stream_new: enter usecase = [7]PCM_MMAP 04-07 14:40:11.780 3486 3587 I audio-subMixingFactory: ++deleteSubMixingInput() 04-07 14:40:11.780 3486 3587 I audio-subMixingFactory: deleteSubMixingInputPcm(), cnt_stream_using_mixer 0 04-07 14:40:11.780 3486 3587 D audio_hw_primary: adev_close_output_stream: enter: dev(0xea775280) stream(0xea7dda80) 04-07 14:40:11.780 3486 3587 D audio_hw_primary: out_standby_new: enter 04-07 14:40:11.780 3486 3587 I audio_hw_primary: [do_output_standby_l:6678] stream usecase:[7]PCM_MMAP , continuous:0 04-07 14:40:11.780 3486 3587 E a2dp_hal: a2dp_out_standby: hal_audio_open_times=1, not close 04-07 14:40:11.780 3486 3587 I audio_hw_primary: ++[usecase_change_validate_l:9394], dev masks:0x2, is_standby:1, out usecase:[7]PCM_MMAP 04-07 14:40:11.780 3486 3587 I audio_hw_primary: --[usecase_change_validate_l:9409], dev masks:0x2, is_standby:1, out usecase [7]PCM_MMAP 04-07 14:40:11.780 3486 3587 I audio_hw_primary: do_output_standby_l current usecase_masks 2 04-07 14:40:11.780 3486 3587 D audio_hw_primary: out_standby_new: exit 04-07 14:40:11.780 3486 3587 I audio_hwsync: aml_audio_hwsync_release done 04-07 14:40:11.780 3486 3587 I aml_mmap_audio: [outMmapDeInit:340] stream:0xea7dda80 04-07 14:40:11.780 3486 3587 D audio_hw_primary: adev_close_output_stream: exit 04-07 14:40:11.780 3486 3587 D audio_hw_primary: adev_close_output_stream_new: exit 04-07 14:40:11.782 3486 3587 D audio_hw_primary: out_set_parameters(kvpairs(closing=true), out_device=0x480) 04-07 14:40:11.782 3486 3587 E audio_hw_primary: Amlogic_HAL - out_set_parameters: parameter is NULL, change ret value to 0 in order to pass VTS test. 04-07 14:40:11.785 3486 3587 D audio_hw_primary: out_dump(0xea7def80, 24) 04-07 14:40:11.786 3486 3587 D audio_hw_primary: out_set_parameters(kvpairs(exiting=1), out_device=0x480) 04-07 14:40:11.786 3486 3587 E audio_hw_primary: Amlogic_HAL - out_set_parameters: parameter is NULL, change ret value to 0 in order to pass VTS test. 04-07 14:40:11.786 3521 3758 D AudioFlinger: preExit HAL format: 0xd000000. 04-07 14:40:11.789 3486 8511 D audio_hw_primary: adev_close_output_stream_new: enter usecase = [3]RAW_DIRECT 04-07 14:40:11.789 3486 8511 D audio_hw_primary: adev_close_output_stream: enter: dev(0xea775280) stream(0xea7def80) 04-07 14:40:11.789 3486 8511 D audio_hw_primary: out_standby_new: enter 04-07 14:40:11.789 3486 8511 I audio_hw_primary: [do_output_standby_l:6678] stream usecase:[3]RAW_DIRECT , continuous:0 04-07 14:40:11.789 3486 8511 E a2dp_hal: a2dp_out_standby: hal_audio_open_times=1, not close 04-07 14:40:11.789 3486 8511 I audio_hw_primary: ++[usecase_change_validate_l:9394], dev masks:0x2, is_standby:1, out usecase:[3]RAW_DIRECT 04-07 14:40:11.789 3486 8511 I audio_hw_primary: enable rawtopcm_flag !!! 04-07 14:40:11.789 3486 8511 I audio_hw_primary: --[usecase_change_validate_l:9409], dev masks:0x2, is_standby:1, out usecase [3]RAW_DIRECT 04-07 14:40:11.789 3486 8511 I audio_hw_primary: do_output_standby_l current usecase_masks 2 04-07 14:40:11.789 3486 8511 D audio_hw_primary: out_standby_new: exit 04-07 14:40:11.789 3486 8511 I audio_hw_primary: enable rawtopcm_flag 04-07 14:40:11.789 3486 8511 I audio_hwsync: aml_audio_hwsync_release done 04-07 14:40:11.789 3486 8511 D audio_hw_primary: adev_close_output_stream: exit 04-07 14:40:11.789 3486 8511 D audio_hw_primary: adev_close_output_stream_new: exit 04-07 14:40:11.800 3486 8511 D audio_hw_primary: adev_set_parameters(0xea775280, A2dpSuspended=false) 04-07 14:40:11.800 3486 8511 I audio_hw_primary: adev_set_parameters(kv: A2dpSuspended=false) 04-07 14:40:11.800 3486 8511 I audio_hw_primary: adev_set_parameters, ret=-2, value=⚌+r⚌ip⚌$ 04-07 14:40:11.800 3486 8511 I audio_hw_primary: Amlogic_HAL - adev_set_parameters: return Result::NOT_SUPPORTED (4) instead of other error code. 04-07 14:40:11.801 3836 4408 D BluetoothA2dp: getCodecStatus(00:42:79:A0:EC:50) 04-07 14:40:11.802 4458 4537 D BluetoothActiveDeviceManager: onAudioDevicesAdded 04-07 14:40:11.802 4458 4537 D BluetoothActiveDeviceManager: Audio device added: BFX-AT100 type: 8 04-07 14:40:11.802 4458 4458 D AvrcpVolumeManager: onAudioDevicesAdded: size: 1 04-07 14:40:11.802 4458 4458 D AvrcpVolumeManager: onAudioDevicesAdded: address=00:42:79:A0:EC:50 04-07 14:40:11.802 3836 4407 W system_server: Long monitor contention with owner AudioDeviceBroker (4408) at void com.android.server.audio.AudioDeviceBroker$BrokerHandler.handleMessage(android.os.Message)(AudioDeviceBroker.java:836) waiters=0 in boolean com.android.server.audio.AudioDeviceBroker.isAvrcpAbsoluteVolumeSupported() for 135ms 04-07 14:40:11.802 4458 4458 D AvrcpVolumeManager: switchVolumeDevice: Set Absolute volume support to true 04-07 14:40:11.803 4458 4458 D AvrcpVolumeManager: getVolume: Returning volume 5 04-07 14:40:11.803 4458 4458 D AvrcpVolumeManager: switchVolumeDevice: savedVolume=5 04-07 14:40:11.803 4458 4458 I AvrcpVolumeManager: switchVolumeDevice: Updating device volume: avrcpVolume=19 04-07 14:40:11.803 4458 4458 D AvrcpNativeInterface: sendVolumeChanged: volume=19 04-07 14:40:11.803 4458 4458 D AvrcpTargetJni: sendVolumeChangedNative 04-07 14:40:11.804 4458 8531 D A2dpService: getCodecStatus(00:42:79:A0:EC:50) 04-07 14:40:11.804 3836 4408 D AS.AudioDeviceInventory: onBluetoothA2dpActiveDeviceChange btDevice=00:42:79:A0:EC:50 04-07 14:40:11.806 3521 3758 I hash_map_utils: key: 'isReconfigA2dpSupported' value: '' 04-07 14:40:11.807 3486 8511 D audio_hw_primary: adev_set_parameters(0xea775280, reconfigA2dp=true) 04-07 14:40:11.808 3486 8511 I audio_hw_primary: adev_set_parameters(kv: reconfigA2dp=true) 04-07 14:40:11.808 3486 8511 E audio_hw_primary: adev_set_parameters A2DP reconfigA2dp out_device=480 04-07 14:40:11.808 3486 8511 I audio_hw_primary: Amlogic_HAL - adev_set_parameters: return 0 instead of length of data be copied. 04-07 14:40:11.810 3836 5608 I AS.BtHelper: setAvrcpAbsoluteVolumeSupported supported=true 04-07 14:40:11.811 3521 3758 I APM_AudioPolicyManager: setStreamVolumeIndex: set_btv_media_volume index: 5 04-07 14:40:11.811 3521 3758 I APM_AudioPolicyManager: setStreamVolumeIndex: set_btv_media_volume mExtMute: 0 04-07 14:40:11.811 3521 3758 I APM_AudioPolicyManager: setStreamVolumeIndex: set_btv_media_volume stream : 3 volume_index : 5 gain : -54.520203 04-07 14:40:11.812 3557 3783 D BTV_HAL_MGR.001: [useSpeakerVolumePath] useSpeakerVolumePath : false 04-07 14:40:11.812 3557 3783 E AudioMixer: BTF|AMIXER_SetAudioVolume|74|IN| amixer=e37bf050 volume=5 gain=-54.520203 04-07 14:40:11.813 3557 3783 E AudioMixer: BTF|setMasterAudioVolumeIntoFile|172|IN| save volume:0.187930 ,volumeIndex : 5 04-07 14:40:11.813 3557 3783 E halMediaPlayer: BTF|setAudioVolume|766|IN| volume:0.187930 04-07 14:40:11.813 3557 3783 E halMediaPlayer: BTF|player_SetAudioVolume|716|IN| player=e7f074a0 volume=0.187930 04-07 14:40:11.813 3557 3783 D AmlHalPlayerImpl_0: SetVolume[0] volume = 0.187930 04-07 14:40:11.813 3557 3783 I LivePlayer_0: [setVolume:697] setVolume: 0.00 04-07 14:40:11.813 3557 3783 E halMediaPlayer: BTF|player_SetAudioVolume|726|OUT| 04-07 14:40:11.813 3557 3783 E halMediaPlayer: BTF|setAudioVolume|774| error setting! player:0, i:1, mState:0 04-07 14:40:11.813 3557 3783 E halMediaPlayer: BTF|setAudioVolume|779|OUT| 04-07 14:40:11.813 3557 3783 E AudioMixer: BTF|AMIXER_SetAudioVolume|86|OUT|vol:0.001879 04-07 14:40:11.813 3521 3758 D BtvMediaVolumeControlLib: status : 0 04-07 14:40:11.813 3486 8511 I audio_hw_primary: out_set_volume(), stream(0xea7de500), left:0.001879 right:0.001879 04-07 14:40:11.845 3836 4407 I AS.AudioService: onAccessoryPlugMediaUnmute newDevice=128 [bt_a2dp] 04-07 14:40:11.846 3521 3923 I APM_AudioPolicyManager: setStreamVolumeIndex: set_btv_media_volume index: 32 04-07 14:40:11.846 3521 3923 I APM_AudioPolicyManager: setStreamVolumeIndex: set_btv_media_volume mExtMute: 0 04-07 14:40:11.846 3521 3923 I APM_AudioPolicyManager: setStreamVolumeIndex: set_btv_media_volume stream : 3 volume_index : 32 gain : 0.000004 04-07 14:40:11.846 3557 3783 D BTV_HAL_MGR.001: [useSpeakerVolumePath] useSpeakerVolumePath : false 04-07 14:40:11.846 3557 3783 E AudioMixer: BTF|AMIXER_SetAudioVolume|74|IN| amixer=e37bf050 volume=32 gain=0.000004 04-07 14:40:11.847 3557 3783 E AudioMixer: BTF|setMasterAudioVolumeIntoFile|172|IN| save volume:100.000000 ,volumeIndex : 32 04-07 14:40:11.847 3557 3783 E halMediaPlayer: BTF|setAudioVolume|766|IN| volume:100.000000 04-07 14:40:11.847 3557 3783 E halMediaPlayer: BTF|player_SetAudioVolume|716|IN| player=e7f074a0 volume=100.000000 04-07 14:40:11.847 3557 3783 D AmlHalPlayerImpl_0: SetVolume[0] volume = 100.000000 04-07 14:40:11.847 3557 3783 I LivePlayer_0: [setVolume:697] setVolume: 1.00 04-07 14:40:11.847 3557 3783 E halMediaPlayer: BTF|player_SetAudioVolume|726|OUT| 04-07 14:40:11.847 3557 3783 E halMediaPlayer: BTF|setAudioVolume|774| error setting! player:0, i:1, mState:0 04-07 14:40:11.847 3557 3783 E halMediaPlayer: BTF|setAudioVolume|779|OUT| 04-07 14:40:11.847 3557 3783 E AudioMixer: BTF|AMIXER_SetAudioVolume|86|OUT|vol:1.000000 04-07 14:40:11.847 3486 8511 I audio_hw_primary: out_set_volume(), stream(0xea7de500), left:1.000000 right:1.000000 04-07 14:40:11.847 3521 3923 D BtvMediaVolumeControlLib: status : 0 04-07 14:40:11.653 3836 5611 W ActivityManager: Unable to start service Intent { act=android.bluetooth.a2dp.profile.action.CONNECTION_STATE_CHANGED cmp=com.google.android.gms/.nearby.discovery.service.DiscoveryService (has extras) } U=0: not found 04-07 14:40:11.881 3836 5597 E WindowManager: App trying to use insecure INPUT_FEATURE_NO_INPUT_CHANNEL flag. Ignoring 04-07 14:40:11.887 4478 4478 I vol.Events: writeEvent show_dialog volume_changed keyguard=false 04-07 14:40:11.888 3836 5597 D AS.AudioService: Volume controller visible: true 04-07 14:40:11.906 3550 3656 I [Gralloc]: ddebug, pair (share_fd=73, user_hnd=7, ion_client=26) 04-07 14:40:11.908 3550 3656 I [Gralloc]: ddebug, pair (share_fd=89, user_hnd=8, ion_client=26) 04-07 14:40:11.911 4478 4768 I [Gralloc]: ddebug, pair (share_fd=81, user_hnd=1, ion_client=82) 04-07 14:40:11.914 3550 3656 I [Gralloc]: ddebug, pair (share_fd=92, user_hnd=9, ion_client=26) 04-07 14:40:11.932 3498 4824 I [Gralloc]: ddebug, pair (share_fd=61, user_hnd=7, ion_client=31) 04-07 14:40:11.965 3486 3760 W ServiceManagement: getService: unable to call into hwbinder service for vendor.amlogic.hardware.remotecontrol@1.0::IRemoteControl/default. 04-07 14:40:11.960 3486 3486 W ATVRemoteAudioH: type=1400 audit(0.0:855): avc: denied { call } for scontext=u:r:hal_audio_amlogic:s0 tcontext=u:r:rc_server:s0 tclass=binder permissive=0 04-07 14:40:11.968 3557 8410 I LivePlayerRenderer_0: set audio output type:BT 04-07 14:40:11.968 3557 8410 I LivePlayerClock_0: set audio output type:BT 04-07 14:40:11.968 3486 8511 D audio_hw_primary: adev_set_parameters(0xea775280, is_wifiAudioMode_enabled=0) 04-07 14:40:11.968 3486 8511 I audio_hw_primary: adev_set_parameters(kv: is_wifiAudioMode_enabled=0) 04-07 14:40:11.968 3486 8511 E audio_hw_primary: Amlogic_HAL - adev_set_parameters: is_wifiAudioMode_enabled:0. 04-07 14:40:11.969 3557 8406 I AmlAudioOutPort: setParameters:is_wifiAudioMode_enabled=0, err=0 04-07 14:40:11.969 3557 8410 I LivePlayerRenderer_0: [onChangeAudioFormat:2244] format:0xdb2bb400, notify:0x0 04-07 14:40:11.969 3557 8410 I LivePlayerRenderer_0: onChangeAudioFormat: mime:audio/raw, mime_in:audio/mp4a-latm, channelCount:2, sampleRate:48000, passthroughSetting:0, audioOutputType:1 04-07 14:40:11.969 3557 8410 I LivePlayerRenderer_0: current AudioSink:mime:audio/raw, mime_in:audio/mp4a-latm, channelCount:2, sampleRate:48000, passthroughSetting:0, audioOutputType:0 04-07 14:40:11.969 3557 8410 I LivePlayerRenderer_0: do actual changeAudioFormat, mAudioSink:0xddcac2c0 04-07 14:40:11.969 3557 8410 I HalAudioOutput: [pause:181] 04-07 14:40:11.969 3486 8511 I audio-subMixingFactory: +out_pause_subMixingPCM(), stream 0xea7de500, standby 0, pause status 0, usecase: [1]PCM_DIRECT 04-07 14:40:11.969 3486 8511 E a2dp_hal: a2dp_out_standby: hal_audio_open_times=1, not close 04-07 14:40:11.969 3486 8511 I audio-subMixingFactory: -out_pause_subMixingPCM() 04-07 14:40:11.989 3486 3773 I aml_audio_port: get_inport_message(), msg: MSG_PAUSE 04-07 14:40:11.989 3486 3773 I amlaudioMixer: process_port_msg(), msg: MSG_PAUSE 04-07 14:40:11.989 3486 3773 I amlaudioMixer: [mixer_inports_read:750] output port:[1]PCM_DIRECT fade out, pausing->pausing_1, tsync pause audio 04-07 14:40:11.989 3486 3773 I audio_hwsync: aml_hwsync_set_tsync_pause(), send pause event 04-07 14:40:11.989 3486 3773 I audio_hw_utils: do fade out done,size 1536 04-07 14:40:11.989 3486 8513 I amlaudioMixer: [mixer_write_inport:334] input port:[1]PCM_DIRECT is active now 04-07 14:40:11.989 3557 8512 I HalAudioOutput: high priority work:0x8000000a 04-07 14:40:11.989 3557 8512 I HalAudioOutput: resample thread flush... 04-07 14:40:11.989 3557 8512 I HalAudioOutput: resample thread flush finished! 04-07 14:40:11.990 3557 8512 I HalAudioOutput: resample thread pause! 04-07 14:40:11.990 3486 8511 I audio-subMixingFactory: +out_flush_subMixingPCM(), stream 0xea7de500, standby 0, pause status 1, usecase: [1]PCM_DIRECT 04-07 14:40:11.990 3486 8511 I audio-subMixingFactory: -out_flush_subMixingPCM() 04-07 14:40:11.990 3557 8410 D HalAudioOutput: [~HalAudioOutput:63] 04-07 14:40:11.990 3486 3587 D audio_hw_primary: adev_set_parameters(0xea775280, hal_audio_state=off) 04-07 14:40:11.990 3486 3587 I audio_hw_primary: adev_set_parameters(kv: hal_audio_state=off) 04-07 14:40:11.990 3486 3587 I audio_hw_primary: adev_set_parameters, ret=3, value=off 04-07 14:40:11.990 3486 3587 I audio_hw_primary: adev_set_parameters, value=off, adev->hal_audio_open_times=0 04-07 14:40:11.990 3486 3587 I audio_hw_primary: Amlogic_HAL - adev_set_parameters: return 0 instead of length of data be copied. 04-07 14:40:11.990 3557 8410 I AmlAudioOutPort: setParameters:hal_audio_state=off, err=0 04-07 14:40:11.990 3557 8410 I HalAudioOutput: resample thread exiting... 04-07 14:40:11.990 3557 8512 I HalAudioOutput: high priority work:0x1 04-07 14:40:11.990 3557 8512 I HalAudioOutput: quit resample thread exit! 04-07 14:40:11.991 3557 8410 I HalAudioOutput: resample thread exited! 04-07 14:40:11.992 3557 8410 D HalAudioOutput: [~HalAudioOutput:72], exit 04-07 14:40:11.992 3486 3773 I aml_audio_port: get_inport_message(), msg: MSG_FLUSH 04-07 14:40:11.992 3486 3773 I amlaudioMixer: process_port_msg(), msg: MSG_FLUSH 04-07 14:40:11.992 3486 3773 D aml_audio_port: inport_reset() 04-07 14:40:11.993 3486 3773 I amlaudioMixer: [mixer_inports_read:727] input port:[1]PCM_DIRECT flushing->flushed 04-07 14:40:11.993 3557 8410 D MiniAudioSink: [~MiniAudioSink:78] 04-07 14:40:11.993 3557 8410 I LivePlayerRenderer_0: mAudioFormat_E:0x1 mPassthroughSetting:0, mime:audio/raw, mime_in:audio/mp4a-latm 04-07 14:40:11.993 3557 8410 I LivePlayerRenderer_0: doPassthrough: mPassthroughSetting=0, mime_in=audio/mp4a-latm 04-07 14:40:11.993 3557 8410 W MiniAudioSink: [getMinFrameCount:225] not implemented! 04-07 14:40:11.993 3557 8410 I LivePlayerRenderer_0: getMinFrameCount:2052 04-07 14:40:11.993 3557 8410 I LivePlayerRenderer_0: live play framecount times 1.1 04-07 14:40:11.993 3557 8410 E LivePlayerRenderer_0: create AudioTrack, sampleRate:48000, channelCount:2, outputFlags:0x1, frameCount:2257, mAudioPaused=0 04-07 14:40:11.993 3557 8410 D MiniAudioSink: mSampleSize:2, mChannelCount:2, mSampleRate:48000 04-07 14:40:11.993 3557 8410 I HalAudioOutput: Fifo_Size:0x4000 04-07 14:40:11.993 3557 8410 D HalAudioOutput: [HalAudioOutput:53] flags:0x1, mOutSampleRate=48000 04-07 14:40:11.994 3486 3587 D audio_hw_primary: adev_close_output_stream_new: enter usecase = [1]PCM_DIRECT 04-07 14:40:11.994 3486 3587 I audio-subMixingFactory: ++deleteSubMixingInput() 04-07 14:40:11.994 3486 3587 I audio-subMixingFactory: deleteSubMixingInputPcm(), cnt_stream_using_mixer 0 04-07 14:40:11.994 3486 3587 D audio_hw_primary: adev_close_output_stream: enter: dev(0xea775280) stream(0xea7de500) 04-07 14:40:11.994 3486 3587 D audio-subMixingFactory: out_standby_subMixingPCM: out_stream(0xea7de500) usecase: [1]PCM_DIRECT 04-07 14:40:11.994 3486 3587 I audio-subMixingFactory: [usecase_change_validate_l_sm:1290] cur dev masks:0x2, delete out usecase:[1]PCM_DIRECT 04-07 14:40:11.994 3486 3587 I audio-subMixingFactory: usecase_change_validate_l_sm(), standby unmask usecase [1]PCM_DIRECT 04-07 14:40:11.994 3486 3587 I amlaudioMixer: [delete_mixer_input_port:187] input port:0 04-07 14:40:11.994 3486 3587 D a2dp_hal: a2dp_out_standby: state=3 04-07 14:40:11.995 4458 4863 I btif_av : btif_av_stream_started_ready: Peer 00:42:79:a0:ec:50 : state=3 flags=0x0(None) ready=1 04-07 14:40:11.997 4458 4863 I bt_stack: [INFO:a2dp_encoding.cc(125)] SuspendRequest: accepted 04-07 14:40:11.997 4458 4863 I btif_av : btif_av_stream_suspend 04-07 14:40:11.997 4458 5041 I btif_av : virtual bool BtifAvStateMachine::StateStarted::ProcessEvent(uint32_t, void *): Peer 00:42:79:a0:ec:50 : event=BTIF_AV_SUSPEND_STREAM_REQ_EVT(0x1d) flags=0x0(None) 04-07 14:40:11.998 4458 5041 I bt_btif_a2dp_source: btif_a2dp_source_set_tx_flush: enable=true state=STATE_RUNNING 04-07 14:40:11.998 4458 5041 I bt_bta_av: BTA_AvStop: handle=65 suspend=true 04-07 14:40:11.998 4458 5041 E bt_btif : bta_av_str_stopped: peer 00:42:79:a0:ec:50 handle:65 audio_open_cnt:1, p_data 0xf31673e8 start:1 04-07 14:40:11.998 4458 5041 W bt_btif : bta_dm_rm_cback:2, status:6 04-07 14:40:11.998 3231 3231 I hwservicemanager: getTransport: Cannot find entry android.hardware.audio@5.0::IDevicesFactory/msd in either framework or device manifest. 04-07 14:40:11.998 3557 8410 I AmlAudioOutPort: get DevicesFactoryHal sucess 04-07 14:40:12.000 3486 3584 D audio_hw_primary: adev_open: enter 04-07 14:40:12.000 3486 3584 I audio_hw_primary: adev exsits ,reuse 04-07 14:40:12.000 3486 3584 I audio_hw_primary: *adev_open, device:0xea775280, debug_flag=0, adev->count=6 04-07 14:40:12.000 3486 3584 D audio_hw_primary: adev_open: exit, error 04-07 14:40:12.000 3557 8410 I AmlAudioOutPort: get hwDevice success 04-07 14:40:12.000 3557 8410 I AmlAudioOutPort: hwDevice init check success 04-07 14:40:12.000 3486 8511 D audio_hw_primary: adev_open_output_stream_new: enter 04-07 14:40:12.000 3486 8511 D audio_hw_primary: adev_open_output_stream: enter: devices(0x400) channel_mask(0x3) rate(48000) format(0x1) flags(0x1) 04-07 14:40:12.000 3486 3773 D aml_audio_port: output_port_write_alsa() alsa underrun 04-07 14:40:12.000 3486 3773 I aml_audio_port: restart pcm device for same src 04-07 14:40:12.000 3486 8511 I audio_hwsync: aml_audio_hwsync_init open tsync fd 24 04-07 14:40:12.000 3486 8511 I audio_hwsync: aml_audio_hwsync_init done 04-07 14:40:12.000 3486 8511 D audio_hw_primary: adev_open_output_stream: exit 04-07 14:40:12.000 3486 8511 D audio_hw_profile: get_hdmi_sink_cap is running... 04-07 14:40:12.001 3486 8511 D audio_hw_profile: query hdmi format... 04-07 14:40:12.001 3486 8511 I audio_hw_primary: get_sink_capability mbox+dvb case sink_capability = 0x1 04-07 14:40:12.001 3486 8511 D audio_hw_primary: get_sink_format: a2dp set to pcm 04-07 14:40:12.001 3486 8511 I audio-subMixingFactory: ++initSubMixingInput() 04-07 14:40:12.001 3486 8511 I audio-subMixingFactory: ++initSubMixingInputPcm(), out 0xea7def80, flags 0x1, hwsync lpcm 0, out format 0x1 04-07 14:40:12.001 3557 8398 D BOXKEY-STDVB: [DEVICE 0] ++ remain buffer size : 73696 04-07 14:40:12.039 4458 5063 W bt_stack: [WARNING:client_interface.cc(464)] ReadAudioData: 512/512 no data 10 ms 04-07 14:40:12.039 4458 5063 W bt_btif_a2dp_source: btif_a2dp_source_read_callback: UNDERFLOW: ONLY READ 0 BYTES OUT OF 512 04-07 14:40:12.039 4458 5063 W a2dp_sbc_encoder: a2dp_sbc_encode_frames: underflow 1, 0 04-07 14:40:12.041 4458 5041 W bt_btif : bta_dm_rm_cback:2, status:6 04-07 14:40:12.041 4458 5041 I btif_av : virtual bool BtifAvStateMachine::StateStarted::ProcessEvent(uint32_t, void *): Peer 00:42:79:a0:ec:50 : event=BTA_AV_SUSPEND_EVT(0xf) status=0 initiator=1 flags=0x1(LOCAL_SUSPEND_PENDING) 04-07 14:40:12.041 4458 5041 I bt_btif_a2dp: btif_a2dp_on_suspended: ## ON A2DP SUSPENDED ## p_av_suspend=0xe15a3d30 04-07 14:40:12.041 4458 5041 I bt_btif_a2dp_source: btif_a2dp_source_on_suspended: state=STATE_RUNNING 04-07 14:40:12.041 4458 5041 I bt_btif_a2dp_source: btif_a2dp_source_stop_audio_req: state=STATE_RUNNING 04-07 14:40:12.041 4458 5041 I btif_av : btif_report_audio_state: peer_address=00:42:79:a0:ec:50 state=1 04-07 14:40:12.041 4458 5063 I bt_btif_a2dp_source: btif_a2dp_source_audio_tx_stop_event: media_alarm is running, streaming true state=STATE_RUNNING 04-07 14:40:12.041 4458 4536 I BluetoothA2dpServiceJni: bta2dp_audio_state_callback 04-07 14:40:12.042 4458 4536 D A2dpNativeInterface: onAudioStateChanged: A2dpStackEvent {type:EVENT_TYPE_AUDIO_STATE_CHANGED, device:00:42:79:A0:EC:50, value1:STOPPED} 04-07 14:40:12.043 4458 5062 D A2dpStateMachine: handleMessage: E msg.what=101 04-07 14:40:12.043 4458 5062 D A2dpStateMachine: processMsg: Connected 04-07 14:40:12.043 4458 5062 D A2dpStateMachine: Connected process message(00:42:79:A0:EC:50): STACK_EVENT 04-07 14:40:12.044 4458 5062 D A2dpStateMachine: Connected: stack event: A2dpStackEvent {type:EVENT_TYPE_AUDIO_STATE_CHANGED, device:00:42:79:A0:EC:50, value1:STOPPED} 04-07 14:40:12.044 4458 5062 I A2dpStateMachine: Connected: stopped playing: 00:42:79:A0:EC:50 04-07 14:40:12.044 4458 5062 D A2dpStateMachine: A2DP Playing state : device: 00:42:79:A0:EC:50 State:PLAYING->NOT_PLAYING 04-07 14:40:12.046 4458 5062 D A2dpStateMachine: handleMessage: X 04-07 14:40:12.052 4458 5063 W bt_stack: [WARNING:client_interface.cc(464)] ReadAudioData: 28672/28672 no data 10 ms 04-07 14:40:12.052 4458 5063 I bt_stack: [INFO:a2dp_encoding.cc(699)] ack_stream_suspended: result=SUCCESS_FINISHED 04-07 14:40:12.052 3486 3584 I BTAudioProviderStub: streamSuspended - SessionType=A2DP_SOFTWARE_ENCODING_DATAPATH, status=SUCCESS 04-07 14:40:12.052 3486 3584 I BTAudioProviderSession: ReportControlStatus - status=SUCCESS for SessionType=A2DP_SOFTWARE_ENCODING_DATAPATH, bluetooth_audio=0x0100 suspended 04-07 14:40:12.052 3486 3587 D A2DPHW : BluetoothAudioPortOut::Suspend state=1, retval=1 04-07 14:40:12.052 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_feeding_reset: PCM bytes per tick 3840 04-07 14:40:12.052 3486 3587 I audio_hwsync: aml_audio_hwsync_release done 04-07 14:40:12.052 3486 3587 D audio_hw_primary: adev_close_output_stream: exit 04-07 14:40:12.052 3486 8511 D audio_hw_primary: -adev_open_output_stream_new: out 0xea7def80: usecase:[1]PCM_DIRECT card:0 alsa devices:0 04-07 14:40:12.052 3486 3587 D audio_hw_primary: adev_close_output_stream_new: exit 04-07 14:40:12.052 3486 3587 D audio_hw_primary: adev_close: enter, adev=0xea775280, g_adev = 0xea775280, adev->count=5 04-07 14:40:12.052 3486 3587 I audio_hw_primary: adev_close, test============, not enter adev_close 04-07 14:40:12.053 3557 8410 I AmlAudioOutPort: AudioStreamOut::open(), HAL returned stream 0xe7f270d0, sampleRate 48000, Format 0x1, channelMask 0x3, status 0 04-07 14:40:12.053 3557 8410 I AmlAudioOutPort: get outStream success 04-07 14:40:12.053 3486 8511 D audio_hw_primary: adev_set_parameters(0xea775280, hal_audio_state=on) 04-07 14:40:12.053 3486 8511 I audio_hw_primary: adev_set_parameters(kv: hal_audio_state=on) 04-07 14:40:12.053 3486 8511 I audio_hw_primary: adev_set_parameters, ret=2, value=on 04-07 14:40:12.053 3486 8511 I audio_hw_primary: adev_set_parameters, value=on, adev->hal_audio_open_times=1 04-07 14:40:12.053 3486 8511 I audio_hw_primary: Amlogic_HAL - adev_set_parameters: return 0 instead of length of data be copied. 04-07 14:40:12.053 3557 8410 I AmlAudioOutPort: setParameters:hal_audio_state=on, err=0 04-07 14:40:12.053 3486 8511 I audio_hw_primary: out_set_volume(), stream(0xea7def80), left:1.000000 right:1.000000 04-07 14:40:12.053 3557 8410 I MiniAudioSink: setmute:0 04-07 14:40:12.054 3557 8547 I HalAudioOutput: openSonicStream:345, rate:1.00 04-07 14:40:12.054 3557 8410 I LivePlayerRenderer_0: audioSink started!, mAudioSink:0xddcac2c0 04-07 14:40:12.054 3557 8410 I LivePlayerRenderer_0: current audiosink position:0 04-07 14:40:12.056 3557 8410 I RendererPolicyBase_0: set_audioStrategy: AUDIO_STRATEGY_NONE ==> AUDIO_STRATEGY_SILENT, diffUs:-13.472000 ms 04-07 14:40:12.056 3486 3587 I audio_hw_primary: out_get_buffer_size(out->config.rate=48000, format 1,stream format 1) 04-07 14:40:12.060 3486 8548 I audio-subMixingFactory: ++++[usecase_change_validate_l_sm:1326],continuous:0 dev masks:0, out masks:0, out usecase [1]PCM_DIRECT 04-07 14:40:12.060 3486 8548 I audio-subMixingFactory: usecase_change_validate_l_sm(), add usecase [1]PCM_DIRECT, cnt 1 04-07 14:40:12.060 3486 8548 D audio-subMixingFactory: [usecase_change_validate_l_sm:1347] cur dev masks:0, add out usecase:[1]PCM_DIRECT 04-07 14:40:12.060 3486 8548 I audio-subMixingFactory: usecase_change_validate_l_sm(), mixer_main_buffer_write_sm ! 04-07 14:40:12.060 3486 8548 I audio-subMixingFactory: ----[usecase_change_validate_l_sm:1376], continuous:0 dev masks:0x2, out masks:0x2, out usecase [1]PCM_DIRECT 04-07 14:40:12.061 3486 8548 D audio-subMixingFactory: [mixer_main_buffer_write_sm:1099] stream:0xea7def80, switch from device:0x480 to device:0x400 04-07 14:40:12.061 3486 8548 I aml_audio_port: get_input_port_type(), samplerate 48000 04-07 14:40:12.061 3486 8548 D aml_audio_port: [new_input_port:308] inport:[1]PCM_DIRECT, rbuf size:6144, direct_on:0, format:0x1, rate:48000 04-07 14:40:12.061 3486 8548 I amlaudioMixer: [init_mixer_input_port:166] input port:[1]PCM_DIRECT, size 384 frames, frame_write_sum:0 04-07 14:40:12.061 3486 8548 I aml_audio_port: get_input_port_type(), samplerate 48000 04-07 14:40:12.061 3486 8548 I audio-subMixingFactory: [out_write_direct_pcm:554] direct port:[1]PCM_DIRECT 04-07 14:40:12.061 3486 8548 I amlaudioMixer: [mixer_write_inport:334] input port:[1]PCM_DIRECT is active now 04-07 14:40:12.064 3486 3773 D a2dp_hal: a2dp_out_write_new: state=1 04-07 14:40:12.064 4458 4863 I btif_av : btif_av_stream_ready: Peer 00:42:79:a0:ec:50 : state=2, flags=0x0(None) 04-07 14:40:12.065 4458 4863 I btif_av : btif_av_stream_start 04-07 14:40:12.065 4458 4863 I bt_stack: [INFO:a2dp_encoding.cc(99)] StartRequest: accepted 04-07 14:40:12.065 4458 5041 I btif_av : virtual bool BtifAvStateMachine::StateOpened::ProcessEvent(uint32_t, void *): Peer 00:42:79:a0:ec:50 : event=BTIF_AV_START_STREAM_REQ_EVT(0x1b) flags=0x0(None) 04-07 14:40:12.065 4458 5041 I bt_bta_av: BTA_AvStart: handle=65 04-07 14:40:12.065 4458 5041 I bt_bta_av: bta_av_do_start: peer 00:42:79:a0:ec:50 sco_occupied:false role:0x0 started:false wait:0x0 04-07 14:40:12.065 4458 5041 W bt_btif : bta_dm_rm_cback:2, status:7 04-07 14:40:12.065 4458 5041 I bt_bta_av: bta_av_do_start: peer 00:42:79:a0:ec:50 start requested: sco_occupied:false role:0x10 started:false wait:0x0 04-07 14:40:12.076 7596 7596 W ContextImpl: Calling a method in the system process without a qualified user: android.app.ContextImpl.startService:1570 android.content.ContextWrapper.startService:669 com.skb.nads.agent.MonitorScheduler.execute:81 com.skb.nads.agent.AbstractScheduler$1.run:21 android.os.Handler.handleCallback:883 04-07 14:40:12.081 3836 4403 W TelecomManager: Telecom Service not found. 04-07 14:40:12.083 3836 4403 W TelecomManager: Telecom Service not found. 04-07 14:40:12.085 3836 3836 W TelecomManager: Telecom Service not found. 04-07 14:40:12.086 3836 3836 W TelecomManager: Telecom Service not found. 04-07 14:40:12.091 5311 5311 I TvNotificationListenerService: onNotificationPosted() 04-07 14:40:12.101 4458 5041 I bt_bta_av: bta_av_start_ok: peer 00:42:79:a0:ec:50 handle:65 wait:0x0 role:0x10 local_tsep:0 04-07 14:40:12.101 4458 5041 I bt_bta_av: bta_av_link_role_ok: peer 00:42:79:a0:ec:50 hndl:0x41 role:0 conn_audio:0x1 bits:1 features:0x865b 04-07 14:40:12.101 4458 5041 W bt_btif : bta_dm_rm_cback:2, status:0 04-07 14:40:12.101 4458 5041 W bt_btif : bta_dm_rm_cback:2, status:7 04-07 14:40:12.101 4458 5041 I btif_av : virtual bool BtifAvStateMachine::StateOpened::ProcessEvent(uint32_t, void *): Peer 00:42:79:a0:ec:50 : event=BTA_AV_START_EVT(0x4) status=0 suspending=0 initiator=1 flags=0x4(PENDING_START) 04-07 14:40:12.101 4458 5041 I bt_stack: [INFO:btif_a2dp.cc(50)] btif_a2dp_on_started: ## ON A2DP STARTED ## peer 00:42:79:a0:ec:50 p_av_start:0xe15a3d30 04-07 14:40:12.101 4458 5041 I bt_stack: [INFO:btif_a2dp.cc(70)] btif_a2dp_on_started: peer 00:42:79:a0:ec:50 status:0 suspending:false initiator:true 04-07 14:40:12.101 4458 5041 I bt_btif_a2dp_source: btif_a2dp_source_start_audio_req: state=STATE_RUNNING 04-07 14:40:12.101 4458 5041 I bt_stack: [INFO:a2dp_encoding.cc(683)] ack_stream_started: result=SUCCESS_FINISHED 04-07 14:40:12.101 4458 5063 I bt_btif_a2dp_source: btif_a2dp_source_audio_tx_start_event: media_alarm is not running, streaming false state=STATE_RUNNING 04-07 14:40:12.101 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_feeding_reset: PCM bytes per tick 3840 04-07 14:40:12.101 3486 3587 I BTAudioProviderStub: streamStarted - SessionType=A2DP_SOFTWARE_ENCODING_DATAPATH, status=SUCCESS 04-07 14:40:12.101 3486 3587 I BTAudioProviderSession: ReportControlStatus - status=SUCCESS for SessionType=A2DP_SOFTWARE_ENCODING_DATAPATH, bluetooth_audio=0x0100 started 04-07 14:40:12.101 3486 3773 D A2DPHW : BluetoothAudioPortOut::Start: state=3, ret=1 04-07 14:40:12.101 4458 5041 I btif_av : btif_report_audio_state: peer_address=00:42:79:a0:ec:50 state=2 04-07 14:40:12.104 4458 4536 I BluetoothA2dpServiceJni: bta2dp_audio_state_callback 04-07 14:40:12.105 4458 4536 D A2dpNativeInterface: onAudioStateChanged: A2dpStackEvent {type:EVENT_TYPE_AUDIO_STATE_CHANGED, device:00:42:79:A0:EC:50, value1:STARTED} 04-07 14:40:12.105 4458 5062 D A2dpStateMachine: handleMessage: E msg.what=101 04-07 14:40:12.105 4458 5062 D A2dpStateMachine: processMsg: Connected 04-07 14:40:12.105 4458 5062 D A2dpStateMachine: Connected process message(00:42:79:A0:EC:50): STACK_EVENT 04-07 14:40:12.105 4458 5062 D A2dpStateMachine: Connected: stack event: A2dpStackEvent {type:EVENT_TYPE_AUDIO_STATE_CHANGED, device:00:42:79:A0:EC:50, value1:STARTED} 04-07 14:40:12.105 4458 5062 I A2dpStateMachine: Connected: started playing: 00:42:79:A0:EC:50 04-07 14:40:12.105 4458 5062 D A2dpStateMachine: A2DP Playing state : device: 00:42:79:A0:EC:50 State:NOT_PLAYING->PLAYING 04-07 14:40:12.107 4458 5062 D A2dpStateMachine: handleMessage: X 04-07 14:40:12.109 5311 7190 I TvNotificationManager: getNotificationCount() count : 1 04-07 14:40:12.137 3557 8410 I LivePlayerRenderer_0: audiosink get position success:5504 04-07 14:40:12.137 3557 8410 I RendererPolicyBase_0: set_audioStrategy: AUDIO_STRATEGY_SILENT ==> AUDIO_STRATEGY_NONE, diffUs:33.282000 ms 04-07 14:40:12.173 3528 3528 D isqmsAgent: INFO: NET make_holepunching_msg 04-07 14:40:12.173 3528 3528 D isqmsAgent: INFO: NET make_holepunching_msg HTYPE_KEEP_ALIVE pszTemp2=;0; ; ; ; ; ; 04-07 14:40:12.173 3528 3528 D isqmsAgent: INFO: NET make_holepunching_msg HTYPE_KEEP_ALIVE pszIP=0 04-07 14:40:12.173 3528 3528 D isqmsAgent: INFO: NET make_holepunching_msg HTYPE_KEEP_ALIVE pszIP= 04-07 14:40:12.173 3528 3528 D isqmsAgent: INFO: NET make_holepunching_msg HTYPE_KEEP_ALIVE this->szSTBIP= 04-07 14:40:12.173 3528 3528 D isqmsAgent: m_HPServerInfo.nPort = 30812 04-07 14:40:12.173 3528 3528 D isqmsAgent: pData = SEQ=4 04-07 14:40:12.173 3528 3528 D isqmsAgent: T=KEEP-ALIVE 04-07 14:40:12.173 3528 3528 D isqmsAgent: STB_ID=C92B070B-72C3-11E9-A51A-61AC1B87CDDD 04-07 14:40:12.173 3528 3528 D isqmsAgent: STB_MAC=ec5c681dbc67 04-07 14:40:12.173 3528 3528 D isqmsAgent: STB_IP= 04-07 14:40:12.173 3528 3528 D isqmsAgent: 04-07 14:40:12.173 3528 3528 D isqmsAgent: [isqmsAgent 0186 04/07 14:40:12:173][3528] CISQMSSchedule::SCHETYPE_CYCLE event_id=H01 04-07 14:40:12.462 7146 8549 D UEI.SmartControl: --- handleCharacteristicRead 04-07 14:40:12.466 7146 8549 D UEI.SmartControl: ----------get DeviceInfo Manufacture name: Universal Electronics, Inc. 04-07 14:40:12.505 7146 8550 D UEI.SmartControl: --- handleCharacteristicRead 04-07 14:40:12.507 7146 8550 D UEI.SmartControl: ----------get DeviceInfo Firmware version 04-07 14:40:12.508 7146 8550 D UEI.SmartControl: ----------get DeviceInfo Firmware name: BL 193⚌ 04-07 14:40:12.560 7146 8551 D UEI.SmartControl: --- handleCharacteristicRead 04-07 14:40:12.564 7146 8551 D UEI.SmartControl: ----------get DeviceInfo Hardware 04-07 14:40:12.566 7146 8551 D UEI.SmartControl: ----------get DeviceInfo HardwareVersion name: 01 04-07 14:40:12.564 3557 3557 W HwBinder:3557_2: type=1400 audit(0.0:856): avc: denied { read } for name="u:object_r:default_prop:s0" dev="tmpfs" ino=13241 scontext=u:r:btvservice_hal:s0 tcontext=u:object_r:default_prop:s0 tclass=file permissive=0 04-07 14:40:12.571 3557 8391 E libc : Access denied finding property "skb.audio.output" 04-07 14:40:12.588 7146 8552 D UEI.SmartControl: --- handleCharacteristicRead 04-07 14:40:12.591 7146 8552 D UEI.SmartControl: ----------get DeviceInfo SoftwareVersion name: 7049.01.80 04-07 14:40:12.592 7146 8552 D UEI.SmartControl: ----------Set Remote SoftwareVersion: 7049.01.80 04-07 14:40:12.633 7146 8553 D UEI.SmartControl: --- handleCharacteristicRead 04-07 14:40:12.635 7146 8553 D UEI.SmartControl: ----------get DeviceInfo ModelNumber name: UEI BLE RCU 04-07 14:40:12.671 7146 8554 D UEI.SmartControl: --- handleCharacteristicRead 04-07 14:40:12.673 7146 8554 D UEI.SmartControl: ----------get DeviceInfo SerialNumber name: 04-07 14:40:12.674 7146 8554 D UEI.SmartControl: Compare versions: remote = 7049.01.80 <-> new FW = 7003.09.00 04-07 14:40:12.674 7146 8554 D UEI.SmartControl: --- isFirmwareUpdateAvailable: New FW version is available = 7003.09.00 04-07 14:40:12.675 7146 8554 D UEI.SmartControl: Sending new broadcast Intent for new FW version: 1 - 7003.09.00 04-07 14:40:12.677 7146 8554 W ContextImpl: Calling a method in the system process without a qualified user: android.app.ContextImpl.sendBroadcast:1045 android.content.ContextWrapper.sendBroadcast:448 com.uei.control.core.BLEManager.a:111 com.uei.driver.h.d:202 com.uei.driver.BLEPeripheral.j:178 04-07 14:40:12.679 3836 5597 E ActivityManager: Sending non-protected broadcast com.uei.quicksetsdk.skb.NEW_FIRMWARE_AVAILABLE from system 7146:com.uei.quicksetsdk.skb/1000 pkg com.uei.quicksetsdk.skb 04-07 14:40:12.679 3836 5597 E ActivityManager: java.lang.Throwable 04-07 14:40:12.679 3836 5597 E ActivityManager: at com.android.server.am.ActivityManagerService.checkBroadcastFromSystem(ActivityManagerService.java:14810) 04-07 14:40:12.679 3836 5597 E ActivityManager: at com.android.server.am.ActivityManagerService.broadcastIntentLocked(ActivityManagerService.java:15451) 04-07 14:40:12.679 3836 5597 E ActivityManager: at com.android.server.am.ActivityManagerService.broadcastIntentLocked(ActivityManagerService.java:14827) 04-07 14:40:12.679 3836 5597 E ActivityManager: at com.android.server.am.ActivityManagerService.broadcastIntent(ActivityManagerService.java:15593) 04-07 14:40:12.679 3836 5597 E ActivityManager: at android.app.IActivityManager$Stub.onTransact(IActivityManager.java:1950) 04-07 14:40:12.679 3836 5597 E ActivityManager: at com.android.server.am.ActivityManagerService.onTransact(ActivityManagerService.java:2741) 04-07 14:40:12.679 3836 5597 E ActivityManager: at android.os.Binder.execTransactInternal(Binder.java:1021) 04-07 14:40:12.679 3836 5597 E ActivityManager: at android.os.Binder.execTransact(Binder.java:994) 04-07 14:40:12.681 3836 5597 I DropBoxManagerService: add tag=system_server_wtf isTagEnabled=true flags=0x2 04-07 14:40:12.686 3557 8407 W RendererPolicyBase_0: video render: 59.94 fps, drop: 0.00 fps 04-07 14:40:12.690 7146 8554 D UEI.SmartControl: ---- calling readBatteryLevel: 04-07 14:40:12.691 7146 8554 D BluetoothGatt: setCharacteristicNotification() - uuid: 00002a19-0000-1000-8000-00805f9b34fb enable: true 04-07 14:40:12.693 4458 4536 W bt_stack: [WARNING:bta_gattc_api.cc(652)] notification already registered 04-07 14:40:12.697 7572 7572 D BtvBtPairingService: sptek:BT onConnectionStateChanged audio pairing ok handler 04-07 14:40:12.696 7146 8554 D UEI.SmartControl: Battery readCharacteristic: true 04-07 14:40:12.731 7146 8555 D UEI.SmartControl: --- handleCharacteristicRead 04-07 14:40:12.732 7146 8555 D UEI.SmartControl: ----------Battery Level: 100 04-07 14:40:12.733 7146 8539 D UEI.SmartControl: --- Done reading device info --- 04-07 14:40:12.733 7146 8539 I UEI.SmartControl: reportRemoteDeviceInfo 04-07 14:40:12.733 7146 7166 D UEI.SmartControl: BLE Device Info: 04-07 14:40:12.734 7146 7166 D UEI.SmartControl: Manufacture: Universal Electronics, Inc. 04-07 14:40:12.735 7146 7166 D UEI.SmartControl: ModelNumber: UEI BLE RCU 04-07 14:40:12.735 7146 7166 D UEI.SmartControl: SoftwareVersion: 7049.01.80 04-07 14:40:12.736 7146 7166 D UEI.SmartControl: HardwareVersion: 01 04-07 14:40:12.736 7146 7166 D UEI.SmartControl: FirmwareVersion: BL 193⚌ 04-07 14:40:12.737 7146 7166 D UEI.SmartControl: SerialNumber: 04-07 14:40:12.737 7146 7166 D UEI.SmartControl: --- Done readDeviceInfo --- 04-07 14:40:12.738 7146 7166 D UEI.SmartControl: ----- readRemoteDeviceInfo ----- 04-07 14:40:12.739 7146 7166 D UEI.SmartControl: ----- Remote Device Info: Battery Level = 100 04-07 14:40:12.739 7146 7166 D UEI.SmartControl: ----- Remote Device Info: SW Version = 7049.01.80 04-07 14:40:12.740 5311 8532 D Main_RemoteUpdate: tempCurrentVersion : 7049.01.80 04-07 14:40:12.740 5311 8532 D Main_RemoteUpdate: CurrentVersion : 01.80, tempCurrentVersion : 7049.01.80 04-07 14:40:12.741 5311 8532 I Main_RemoteUpdate: [end] getRemoteDeviceInfo 04-07 14:40:12.741 5311 5311 D Main_RemoteUpdate: saveRemoteVer : 01.80 04-07 14:40:12.967 3486 3760 W ServiceManagement: getService: unable to call into hwbinder service for vendor.amlogic.hardware.remotecontrol@1.0::IRemoteControl/default. 04-07 14:40:12.960 3486 3486 W ATVRemoteAudioH: type=1400 audit(0.0:857): avc: denied { call } for scontext=u:r:hal_audio_amlogic:s0 tcontext=u:r:rc_server:s0 tclass=binder permissive=0 04-07 14:40:13.003 3557 8398 D BOXKEY-STDVB: [DEVICE 0] ++ remain buffer size : 39480 04-07 14:40:13.115 3505 3505 D memtrack_aml: type:0 for pid:5156, size_up_to:0 04-07 14:40:13.116 3505 3505 D memtrack_aml: type:1 for pid:5156, size_up_to:0 04-07 14:40:13.120 3505 3505 D memtrack_aml: type:2 for pid:5156, size_up_to:0 04-07 14:40:13.132 3505 3505 D memtrack_aml: type:0 for pid:4829, size_up_to:0 04-07 14:40:13.133 3505 3505 D memtrack_aml: type:1 for pid:4829, size_up_to:0 04-07 14:40:13.137 3505 3505 D memtrack_aml: type:2 for pid:4829, size_up_to:0 04-07 14:40:13.564 3557 3557 W HwBinder:3557_2: type=1400 audit(0.0:858): avc: denied { read } for name="u:object_r:default_prop:s0" dev="tmpfs" ino=13241 scontext=u:r:btvservice_hal:s0 tcontext=u:object_r:default_prop:s0 tclass=file permissive=0 04-07 14:40:13.571 3557 8391 E libc : Access denied finding property "skb.audio.output" 04-07 14:40:13.936 4458 4536 I bt_stack: [INFO:btif_config.cc(647)] hash_file: Disabled for multi-user 04-07 14:40:13.936 4458 4536 I bt_stack: [INFO:btif_config.cc(689)] write_checksum_file: Disabled for multi-user, since config changed removing checksums. 04-07 14:40:13.964 3486 3486 W ATVRemoteAudioH: type=1400 audit(0.0:859): avc: denied { call } for scontext=u:r:hal_audio_amlogic:s0 tcontext=u:r:rc_server:s0 tclass=binder permissive=0 04-07 14:40:13.970 3486 3760 W ServiceManagement: getService: unable to call into hwbinder service for vendor.amlogic.hardware.remotecontrol@1.0::IRemoteControl/default. 04-07 14:40:14.005 3557 8398 D BOXKEY-STDVB: [DEVICE 0] ++ remain buffer size : 21056 04-07 14:40:14.055 7849 7849 D MDNSService: MDNSMsgHandler() AM_EVENT_CHECK_NETWORK_CONFIG. isConnected : true 04-07 14:40:14.083 3557 8547 I HalAudioOutput: outputRate:48890(1.02) 04-07 14:40:14.564 3557 3557 W HwBinder:3557_2: type=1400 audit(0.0:860): avc: denied { read } for name="u:object_r:default_prop:s0" dev="tmpfs" ino=13241 scontext=u:r:btvservice_hal:s0 tcontext=u:object_r:default_prop:s0 tclass=file permissive=0 04-07 14:40:14.570 3557 8391 E libc : Access denied finding property "skb.audio.output" 04-07 14:40:14.688 3557 8407 W RendererPolicyBase_0: video render: 59.94 fps, drop: 0.00 fps 04-07 14:40:14.694 3836 3869 W BroadcastQueue: Background execution not allowed: receiving Intent { act=android.intent.action.DROPBOX_ENTRY_ADDED flg=0x10 (has extras) } to com.google.android.gms/.stats.service.DropBoxEntryAddedReceiver 04-07 14:40:14.695 3836 3869 W BroadcastQueue: Background execution not allowed: receiving Intent { act=android.intent.action.DROPBOX_ENTRY_ADDED flg=0x10 (has extras) } to com.google.android.gms/.chimera.GmsIntentOperationService$PersistentTrustedReceiver 04-07 14:40:14.752 4458 4458 I BluetoothPhonePolicy: processConnectOtherProfiles, device=00:42:79:A0:EC:50 04-07 14:40:14.765 4458 4458 V BluetoothDatabase: getProfilePriority: 00:42:79:A0:EC:50, profile=1, priority = 1000 04-07 14:40:14.769 4458 4458 V BluetoothDatabase: getProfilePriority: 00:42:79:A0:EC:50, profile=2, priority = 1000 04-07 14:40:14.773 4458 4458 D BluetoothAdapterService: getAdapterService() - returning com.android.bluetooth.btservice.AdapterService@d9f176c 04-07 14:40:14.773 4458 4458 V BluetoothDatabase: getProfilePriority: 00:42:79:A0:EC:50, profile=5, priority = -1 04-07 14:40:14.896 3550 3656 I [Gralloc]: ddebug, free share_fd=92, user_hnd=0x9, ion client=26 04-07 14:40:14.896 3550 3656 I [Gralloc]: ddebug, free share_fd=73, user_hnd=0x7, ion client=26 04-07 14:40:14.897 4478 4768 I [Gralloc]: ddebug, free share_fd=81, user_hnd=0x1, ion client=82 04-07 14:40:14.898 3550 3656 E BufferQueueProducer: [Volume control#0] disconnect: not connected (req=1) 04-07 14:40:14.898 4478 4768 W libEGL : EGLNativeWindowType 0xdccbd988 disconnect failed 04-07 14:40:14.902 3498 4824 I [Gralloc]: ddebug, free share_fd=61, user_hnd=0x7, ion client=31 04-07 14:40:14.902 3498 4824 W gralloc : Warning shared attribute region mapped at free. Unmapping 04-07 14:40:14.902 3550 3550 I [Gralloc]: ddebug, free share_fd=89, user_hnd=0x8, ion client=26 04-07 14:40:14.905 4478 4478 I vol.Events: writeEvent dismiss_dialog timeout 04-07 14:40:14.968 3486 3486 W ATVRemoteAudioH: type=1400 audit(0.0:861): avc: denied { call } for scontext=u:r:hal_audio_amlogic:s0 tcontext=u:r:rc_server:s0 tclass=binder permissive=0 04-07 14:40:14.973 3486 3760 W ServiceManagement: getService: unable to call into hwbinder service for vendor.amlogic.hardware.remotecontrol@1.0::IRemoteControl/default. 04-07 14:40:15.007 3557 8398 D BOXKEY-STDVB: [DEVICE 0] ++ remain buffer size : 36848 04-07 14:40:15.098 4458 5041 W bt_btif : bta_av_open_rc: Using the new AVRCP Profile 04-07 14:40:15.098 4458 5041 I bt_stack: [INFO:avrcp_service.cc(334)] void bluetooth::avrcp::AvrcpService::ConnectDevice(const RawAddress &): address=00:42:79:a0:ec:50 04-07 14:40:15.098 4458 5041 I bt_stack: [INFO:connection_handler.cc(109)] Attempting to connect to device 00:42:79:a0:ec:50 04-07 14:40:15.098 4458 5041 W bt_stack: [WARNING:connection_handler.cc(113)] Already connected to device with address 00:42:79:a0:ec:50 04-07 14:40:15.098 4458 5041 I bt_bta_av: bta_av_chk_2nd_start: peer 00:42:79:a0:ec:50 channel:64 bta_av_cb.audio_open_cnt:1 role:0x0 features:0x865b 04-07 14:40:15.564 3557 3557 W HwBinder:3557_2: type=1400 audit(0.0:862): avc: denied { read } for name="u:object_r:default_prop:s0" dev="tmpfs" ino=13241 scontext=u:r:btvservice_hal:s0 tcontext=u:object_r:default_prop:s0 tclass=file permissive=0 04-07 14:40:15.572 3557 8391 E libc : Access denied finding property "skb.audio.output" 04-07 14:40:15.977 3486 3760 W ServiceManagement: getService: unable to call into hwbinder service for vendor.amlogic.hardware.remotecontrol@1.0::IRemoteControl/default. 04-07 14:40:15.972 3486 3486 W ATVRemoteAudioH: type=1400 audit(0.0:863): avc: denied { call } for scontext=u:r:hal_audio_amlogic:s0 tcontext=u:r:rc_server:s0 tclass=binder permissive=0 04-07 14:40:16.009 3557 8398 D BOXKEY-STDVB: [DEVICE 0] ++ remain buffer size : 35532 04-07 14:40:16.092 3557 8547 I HalAudioOutput: outputRate:48164(1.00) 04-07 14:40:16.167 3557 8392 D [PIX_ADS]: [AddrAD][Write][2685]: parse mode: 0, write packet: 1000000 count, ret: 0 04-07 14:40:16.174 3528 3528 D isqmsAgent: [isqmsAgent 0187 04/07 14:40:16:174][3528] CISQMSSchedule::SCHETYPE_CYCLE event_id=H01 04-07 14:40:16.241 6558 6980 I chromium: [6558:6980:INFO:ssdp_device.c(101)] SSDP packets sent for 120 seconds = 5 04-07 14:40:16.570 3557 8391 E libc : Access denied finding property "skb.audio.output" 04-07 14:40:16.564 3557 3557 W HwBinder:3557_2: type=1400 audit(0.0:864): avc: denied { read } for name="u:object_r:default_prop:s0" dev="tmpfs" ino=13241 scontext=u:r:btvservice_hal:s0 tcontext=u:object_r:default_prop:s0 tclass=file permissive=0 04-07 14:40:16.691 3557 8407 W RendererPolicyBase_0: video render: 59.94 fps, drop: 0.00 fps 04-07 14:40:16.981 3486 3760 W ServiceManagement: getService: unable to call into hwbinder service for vendor.amlogic.hardware.remotecontrol@1.0::IRemoteControl/default. 04-07 14:40:16.976 3486 3486 W ATVRemoteAudioH: type=1400 audit(0.0:865): avc: denied { call } for scontext=u:r:hal_audio_amlogic:s0 tcontext=u:r:rc_server:s0 tclass=binder permissive=0 04-07 14:40:17.011 3557 8398 D BOXKEY-STDVB: [DEVICE 0] ++ remain buffer size : 36848 04-07 14:40:17.564 3557 3557 W HwBinder:3557_2: type=1400 audit(0.0:866): avc: denied { read } for name="u:object_r:default_prop:s0" dev="tmpfs" ino=13241 scontext=u:r:btvservice_hal:s0 tcontext=u:object_r:default_prop:s0 tclass=file permissive=0 04-07 14:40:17.571 3557 8391 E libc : Access denied finding property "skb.audio.output" 04-07 14:40:17.985 3486 3760 W ServiceManagement: getService: unable to call into hwbinder service for vendor.amlogic.hardware.remotecontrol@1.0::IRemoteControl/default. 04-07 14:40:17.980 3486 3486 W ATVRemoteAudioH: type=1400 audit(0.0:867): avc: denied { call } for scontext=u:r:hal_audio_amlogic:s0 tcontext=u:r:rc_server:s0 tclass=binder permissive=0 04-07 14:40:18.013 3557 8398 D BOXKEY-STDVB: [DEVICE 0] ++ remain buffer size : 32900 04-07 14:40:18.109 3557 8547 I HalAudioOutput: outputRate:47964(1.00) 04-07 14:40:18.564 3557 3557 W HwBinder:3557_2: type=1400 audit(0.0:868): avc: denied { read } for name="u:object_r:default_prop:s0" dev="tmpfs" ino=13241 scontext=u:r:btvservice_hal:s0 tcontext=u:object_r:default_prop:s0 tclass=file permissive=0 04-07 14:40:18.571 3557 8391 E libc : Access denied finding property "skb.audio.output" 04-07 14:40:18.693 3557 8407 W RendererPolicyBase_0: video render: 59.94 fps, drop: 0.00 fps 04-07 14:40:18.958 3528 3590 D isqmsAgent: check_system_status 04-07 14:40:18.958 3528 3590 D isqmsAgent: CISQMSEnvm get_system_info 04-07 14:40:18.959 3528 3590 D isqmsAgent: CISQMSSystemInfo get_cpu_usage 04-07 14:40:18.959 3528 3590 D isqmsAgent: CISQMSSystemInfo get_cpu_usage 0x001 04-07 14:40:18.959 3528 3590 D isqmsAgent: read_process_status 04-07 14:40:18.963 3528 3590 D isqmsAgent: diff_process_status 04-07 14:40:18.963 3528 3590 D isqmsAgent: CISQMSSystemInfo get_cpu_usage 0x002 04-07 14:40:18.963 3528 3590 D isqmsAgent: CISQMSSystemInfo get_cpu_usage 0x003 04-07 14:40:18.963 3528 3590 D isqmsAgent: idle=13173 total=22220 04-07 14:40:18.963 3528 3590 D isqmsAgent: CISQMSSystemInfo get_cpu_usage 0x004 04-07 14:40:18.963 3528 3590 D isqmsAgent: cpu_usage=41 idle=13173 total=22220 04-07 14:40:18.963 3528 3590 D isqmsAgent: CISQMSSystemInfo get_system_memory 04-07 14:40:18.963 3528 3590 D isqmsAgent: CISQMSSystemInfo get_system_memory 0x001 04-07 14:40:18.964 3528 3590 D isqmsAgent: CISQMSSystemInfo get_system_memory 0x002 04-07 14:40:18.964 3528 3590 D isqmsAgent: CISQMSSystemInfo get_system_memory 0x003 04-07 14:40:18.964 3528 3590 D isqmsAgent: MEM total= 3063232 free= 264360 buffers =1213144 cached=34860 current=55 04-07 14:40:18.964 3528 3590 D isqmsAgent: CISQMSEnvm get_system_info 04-07 14:40:18.984 3486 3486 W ATVRemoteAudioH: type=1400 audit(0.0:869): avc: denied { call } for scontext=u:r:hal_audio_amlogic:s0 tcontext=u:r:rc_server:s0 tclass=binder permissive=0 04-07 14:40:18.988 3486 3760 W ServiceManagement: getService: unable to call into hwbinder service for vendor.amlogic.hardware.remotecontrol@1.0::IRemoteControl/default. 04-07 14:40:19.016 3557 8398 D BOXKEY-STDVB: [DEVICE 0] ++ remain buffer size : 36848 04-07 14:40:19.055 7849 7849 D MDNSService: MDNSMsgHandler() AM_EVENT_CHECK_NETWORK_CONFIG. isConnected : true 04-07 14:40:19.564 3557 3557 W HwBinder:3557_2: type=1400 audit(0.0:870): avc: denied { read } for name="u:object_r:default_prop:s0" dev="tmpfs" ino=13241 scontext=u:r:btvservice_hal:s0 tcontext=u:object_r:default_prop:s0 tclass=file permissive=0 04-07 14:40:19.571 3557 8391 E libc : Access denied finding property "skb.audio.output" 04-07 14:40:19.991 3486 3760 W ServiceManagement: getService: unable to call into hwbinder service for vendor.amlogic.hardware.remotecontrol@1.0::IRemoteControl/default. 04-07 14:40:19.984 3486 3486 W ATVRemoteAudioH: type=1400 audit(0.0:871): avc: denied { call } for scontext=u:r:hal_audio_amlogic:s0 tcontext=u:r:rc_server:s0 tclass=binder permissive=0 04-07 14:40:20.018 3557 8398 D BOXKEY-STDVB: [DEVICE 0] ++ remain buffer size : 36848 04-07 14:40:20.127 3557 8547 I HalAudioOutput: outputRate:47959(1.00) 04-07 14:40:20.174 3528 3528 D isqmsAgent: [isqmsAgent 0188 04/07 14:40:20:174][3528] CISQMSSchedule::SCHETYPE_CYCLE event_id=H01 04-07 14:40:20.564 3557 3557 W HwBinder:3557_2: type=1400 audit(0.0:872): avc: denied { read } for name="u:object_r:default_prop:s0" dev="tmpfs" ino=13241 scontext=u:r:btvservice_hal:s0 tcontext=u:object_r:default_prop:s0 tclass=file permissive=0 04-07 14:40:20.570 3557 8391 E libc : Access denied finding property "skb.audio.output" 04-07 14:40:20.695 3557 8407 W RendererPolicyBase_0: video render: 59.94 fps, drop: 0.00 fps 04-07 14:40:20.996 3486 3760 W ServiceManagement: getService: unable to call into hwbinder service for vendor.amlogic.hardware.remotecontrol@1.0::IRemoteControl/default. 04-07 14:40:20.992 3486 3486 W ATVRemoteAudioH: type=1400 audit(0.0:873): avc: denied { call } for