04-07 14:39:07.912 4458 5041 W bt_btif : bta_dm_acl_change info: 0x10 04-07 14:39:07.913 4458 5041 I bt_stack: [INFO:btsnoop.cc(289)] whitelist_l2c_channel: Whitelisting l2cap channel. conn_handle=11 cid=0x0045:0x0080 04-07 14:39:07.913 4458 4536 D bt_btif_dm: remote version info [00:42:79:a0:ec:50]: 8, a, 307e 04-07 14:39:07.924 4458 4536 I bt_stack: [INFO:btif_config.cc(647)] hash_file: Disabled for multi-user 04-07 14:39:07.924 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:39:07.932 5480 5480 D qsm2agent: onReceive action : android.bluetooth.device.action.ACL_CONNECTED 04-07 14:39:07.936 7146 7146 I UEI.SmartControl: --- Receive Intent: android.bluetooth.device.action.ACL_CONNECTED 04-07 14:39:07.937 7146 7146 D UEI.SmartControl: --- monitor intent: android.bluetooth.device.action.ACL_CONNECTED 04-07 14:39:07.937 5480 5480 D qsm2agent: isRemocon configFilePath( /data/btv_home/config/rcu_prop.conf ) file exist 04-07 14:39:07.938 5480 5480 D qsm2agent: isRemocon add ouid list ( 8C:08:8B ) 04-07 14:39:07.938 5480 5480 D qsm2agent: isRemocon add ouid list ( 14:4E:34 ) 04-07 14:39:07.938 5480 5480 D qsm2agent: isRemocon add ouid list ( 20:44:41 ) 04-07 14:39:07.939 5480 5480 D qsm2agent: isRemocon add ouid list ( 00:13:7B ) 04-07 14:39:07.939 5480 5480 D qsm2agent: isRemocon add ouid list ( 40:19:20 ) 04-07 14:39:07.939 5480 5480 D qsm2agent: isRemocon add ouid list ( 9C:AC:6D ) 04-07 14:39:07.939 5480 5480 D qsm2agent: isRemocon add ouid list ( 70:91:F3 ) 04-07 14:39:07.939 5480 5480 D qsm2agent: isRemocon add ouid list ( 00:CC:3F ) 04-07 14:39:07.939 7146 7146 D UEI.SmartControl: >> dumpSkbBTDevices : 1 04-07 14:39:07.941 4829 4829 D AtvRemote.BleDeviceManager: Bluetooth device 00:42:79:A0:EC:50 has connected 04-07 14:39:07.946 5311 5311 D BluetoothConnectionManager: [ mBluetoothReceiver ] action= .ACL_CONNECTED, JBL Flip 4 , deviceBoundState= 12, conncetionState= -1 04-07 14:39:07.947 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:39:07.948 5311 5311 D BluetoothA2dp: Binding service... 04-07 14:39:07.950 6333 6333 E iSet : ACL LINK CONNECTED [JBL Flip 4] - checking for supported devices after delay 04-07 14:39:07.954 4458 5041 I bt_stack: [INFO:btsnoop.cc(323)] clear_l2cap_whitelist: Clearing whitelist from l2cap channel. conn_handle=11 cid=69:128 04-07 14:39:07.954 4771 4771 I VAS_BLE_Service: >ACL LINK CONNECTED [JBL Flip 4] - checking for supported devices after delay 04-07 14:39:07.957 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:39:07.957 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:39:07.958 4743 4743 I BLE_Service: >ACL LINK CONNECTED [JBL Flip 4] - checking for supported devices after delay 04-07 14:39:07.962 5311 5311 D BluetoothManager: getInstance|| 04-07 14:39:07.962 5311 5311 D BluetoothManager: getConnectedDevicesCount: 2| 04-07 14:39:07.962 5311 5311 D MainActivity: onDeviceChange|2, count: 2| 04-07 14:39:07.962 5311 5311 D STBAPIManager: setBlueToothUsing called : 2 04-07 14:39:07.964 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:39:07.966 6199 6199 D AGENT : JBL Flip 4 @@@@@@@@@Device Is Connected! 04-07 14:39:07.966 6199 6199 D AGENT : ^^^device address : 00:42:79:A0:EC:50 token=>>>20:73:3E | 04-07 14:39:07.966 6199 6199 D AGENT : ^^^device address : 00:42:79:A0:EC:50 token=>>>8C:08:8B | 04-07 14:39:07.966 6199 6199 D AGENT : ^^^device address : 00:42:79:A0:EC:50 token=>>>00:13:7B | 04-07 14:39:07.966 6199 6199 D AGENT : ^^^device address : 00:42:79:A0:EC:50 token=>>>14:4E:34 | 04-07 14:39:07.966 6199 6199 D AGENT : ^^^device address : 00:42:79:A0:EC:50 token=>>>9C:AC:6D | 04-07 14:39:07.966 6199 6199 D AGENT : ^^^device address : 00:42:79:A0:EC:50 token=>>>40:19:20 | 04-07 14:39:07.966 6199 6199 D AGENT : ^^^device address : 00:42:79:A0:EC:50 token=>>>70:91:F3 | 04-07 14:39:07.966 6199 6199 D AGENT : ^^^device address : 00:42:79:A0:EC:50 token=>>>00:CC:3F | 04-07 14:39:07.966 6199 6199 I AGENT : ###@@ send_data=;100;1;1;14:4E:34:A1:56:4D 04-07 14:39:07.966 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:39:07.967 6199 6199 D isqms_agent: INFO:push_data nType=2 04-07 14:39:07.967 6199 6199 D isqms_agent: @@@@@@@@@@@@@@@@@@@@@@@ push m_nEventCnt = 1 04-07 14:39:07.969 3557 3557 I SystemPropertyManager: change property : PROPERTY_BLUETOOTH_USING 04-07 14:39:07.969 3557 3557 I TVService-21.08.18: [vendor/skb/framework/btf_dev/interface/btvservice/1.0/default/TVService.cpp][staticPropertyChange] called 04-07 14:39:07.969 3557 3557 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:39:07.969 3557 3557 I TVService-21.08.18: [TVService::onProperyUpdatedEvent]: key(PROPERTY_BLUETOOTH_USING), value() 04-07 14:39:07.969 3557 3557 I TVService-21.08.18: [vendor/skb/framework/btf_dev/interface/btvservice/1.0/default/TVService.cpp][onProperyUpdatedEvent][271] callback application 04-07 14:39:07.969 3557 3557 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:39:07.969 5528 7289 D BTVCORE-JNI: [updatedProperty] message received key=PROPERTY_BLUETOOTH_USING, value= 04-07 14:39:07.969 5528 7289 D BtvJniInterface: BTF|postPropertyUpdateFromNative|844|postEventFromProperty 04-07 14:39:07.969 5528 7289 D PropertyService: BTF|onHandleEvent|488|onHandleEvent type = 1 key = PROPERTY_BLUETOOTH_USING 04-07 14:39:07.969 5528 7289 D PropertyService: BTF|onHandleEvent|494|propertyservice: setChangePropertyListener onHandleEvent start callback count=1 BUILD_DATE:2021.11.15 04-07 14:39:07.970 5528 7289 D PropertyService: BTF|onHandleEvent|498|propertyservice: setChangePropertyListener onHandleEvent packeage=package com.skb.btv.framework.property, Unknown, version 0.0 04-07 14:39:07.970 6042 6065 D PropertyManager: BTF|ChangePropertyCallback|519| ChangePropertyCallback ChangePropertyListener start type=1, key=PROPERTY_BLUETOOTH_USING 04-07 14:39:07.973 5311 5311 D STBAPIManager: setProperty() isOK : true, key : PROPERTY_BLUETOOTH_USING, value : 2 04-07 14:39:07.973 5311 5311 I MainActivity: RemoteSettinginit() called 04-07 14:39:07.975 5480 5480 D qsm2agent: SkbLogService sendData 04-07 14:39:07.975 5480 5480 D qsm2lib.jar: QSM Report start [BT_PAIRING] 04-07 14:39:07.978 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":"20220407143907.007"} 04-07 14:39:07.978 5480 5480 D qsm2lib.jar: QSM QSM2Transfer addQueueSendData start queue size : 0 04-07 14:39:07.978 5480 5480 D qsm2agent: SkbLogService reportQSMApp SUCCESS 04-07 14:39:07.978 5480 5525 D qsm2lib.jar: QSM QSM2Transfer ConnectSendRunnable: Thread Run timeout : 120 04-07 14:39:07.979 5480 5525 D qsm2lib.jar: QSM QSM2Transfer : sendData to QSM service write start - byte data size =184 04-07 14:39:07.979 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:39:07.979 4983 5527 I QSM : QSM [recv_thread] read data - put qsm msg : BT_PAIRING, size : 184 04-07 14:39:07.980 4983 5527 I QSM : QSM [recv_thread] read data - after put msg BT_PAIRING : wake up send thread 04-07 14:39:07.980 4983 5098 I QSM : QSM service - send_thread : type of received mesage = BT_PAIRING(len=10) 04-07 14:39:07.980 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":"20220407143907.007"} 04-07 14:39:07.980 4983 5098 I QSM : QSM : log switch off - skip key : device_info_bt 04-07 14:39:07.981 4983 5098 I QSM : QSM s_qsm_send_thread - not exist valid data : skip sending event. type : BT_PAIRING 04-07 14:39:07.982 5311 5311 I BluetoothManager: setRemoconAddress() called - Address : 14:4E:34:92:1C:B3 04-07 14:39:07.983 5311 5311 I BluetoothManager: setRemoteName() called - name : BRM_BA01_CB3 04-07 14:39:07.983 5311 5311 D MainActivity: RemoteSettinginit() - isPairing : true 04-07 14:39:07.983 5311 5311 I Main_RemoteUpdate: getRemoteCurrentVersion() called 04-07 14:39:07.983 5311 5311 I SendInterfaceManager: SendInterfaceManager getInstance 04-07 14:39:07.984 5311 5311 I SendInterfaceManager: sendRefreshPropertyWeb propertyName : PROPERTY_BLUETOOTH_USING 04-07 14:39:07.984 5311 5311 I G2TvFragment: isFragmentHidden() isFragmentHidden : true 04-07 14:39:07.984 5311 5311 I SendInterfaceManager: sendRefreshPropertyWeb web is not visible 04-07 14:39:07.984 5311 5311 D BatteryLevel: GlobalGattInit() called 04-07 14:39:07.984 5311 5311 D BluetoothManager: getInstance|| 04-07 14:39:07.989 5480 5525 D qsm2lib.jar: QSM QSM2Transfer : sendData to QSM service write end - byte data size =184 04-07 14:39:07.989 5311 8471 I Main_RemoteUpdate: [start] getRemoteDeviceInfo 04-07 14:39:08.006 5311 5311 I BluetoothManager: setUpdateRemoconAddress() called - Address : 14:4E:34:92:1C:B3 04-07 14:39:08.006 5311 5311 I BluetoothManager: setUpdateRemoteName() called - name : BRM_BA01_CB3 04-07 14:39:08.006 5311 5311 I STBGlobal: setUpdateRemoteName() called - name : BRM_BA01_CB3 04-07 14:39:08.006 5311 5311 D BluetoothManager: [ BluetoothManager ] isRemoconUpdateConnected = true 04-07 14:39:08.006 5311 5311 D BatteryLevel: GlobalGattInit mIsRemotePairing : true 04-07 14:39:08.007 5311 5311 I BluetoothManager: getUpdateRemoconAddress() called - Address : 14:4E:34:92:1C:B3 04-07 14:39:08.007 5311 5311 D BatteryLevel: init mBtGatt : null 04-07 14:39:08.007 5311 5311 I GlobalGatt: initial 04-07 14:39:08.007 5311 5311 I GlobalGatt: initialize() 04-07 14:39:08.007 5311 5311 I GlobalGatt: registerCallback, addr: 14:4E:34:92:1C:B3 04-07 14:39:08.007 5311 5311 D GlobalGatt: mCallbacks.get(addr) == null, addr: 14:4E:34:92:1C:B3 04-07 14:39:08.007 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:39:08.007 5311 5311 D GlobalGatt: mCallbacks list: 14:4E:34:92:1C:B3 04-07 14:39:08.007 5311 5311 D GlobalGatt: Trying to create a new connection. 04-07 14:39:08.009 5311 5311 D BluetoothGatt: connect() - device: 14:4E:34:92:1C:B3, auto: false 04-07 14:39:08.009 5311 5311 D BluetoothGatt: registerApp() 04-07 14:39:08.009 5311 5311 D BluetoothGatt: registerApp() - UUID=512cde20-ce86-4057-863b-a18246609f32 04-07 14:39:08.010 3557 8398 D BOXKEY-STDVB: [DEVICE 0] ++ remain buffer size : 38164 04-07 14:39:08.012 4458 5041 I bt_stack: [INFO:gatt_api.cc(947)] GATT_Register 4c9dc90c-0951-b16f-a2b1-7a2c75b3514f 04-07 14:39:08.013 4458 5041 I bt_stack: [INFO:gatt_api.cc(967)] allocated gatt_if=7 04-07 14:39:08.013 5311 6434 D BluetoothGatt: onClientRegistered() - status=0 clientIf=7 04-07 14:39:08.015 4458 4536 D bt_btif_config: btif_get_address_type: Device [14:4e:34:92:1c:b3] address type 0 04-07 14:39:08.015 4458 4536 D bt_btif_config: btif_get_device_type: Device [14:4e:34:92:1c:b3] type 2 04-07 14:39:08.016 4458 5041 I bt_stack: [INFO:gatt_api.cc(1105)] GATT_Connectgatt_if=7, address=14:4e:34:92:1c:b3 04-07 14:39:08.017 5311 6434 D BluetoothGatt: onClientConnectionState() - status=0 clientIf=7 device=14:4E:34:92:1C:B3 04-07 14:39:08.017 5311 6434 D GlobalGatt: mBluetoothGatts.get(addr) = android.bluetooth.BluetoothGatt@f8158e4. mBluetoothGatts.size(): 1, addr: 14:4E:34:92:1C:B3 04-07 14:39:08.017 5311 6434 D GlobalGatt: mBluetoothGatts list: 14:4E:34:92:1C:B3 04-07 14:39:08.017 5311 6434 D BatteryLevel: onConnectionStateChange: status = 0,newState = 2 04-07 14:39:08.017 5311 6434 D BatteryLevel: device connected 04-07 14:39:08.017 5311 6434 D BatteryLevel: Start to Discovery 04-07 14:39:08.017 5311 6434 D BluetoothGatt: discoverServices() - device: 14:4E:34:92:1C:B3 04-07 14:39:08.017 5311 5311 D STBAPIManager: getProperty() key : PROPERTY_REMOTE_BATTERY, result : 2 04-07 14:39:08.018 5311 5311 I STBGlobal: getBattery - property : 2, eBATTERY : NORMAL_BATTERY 04-07 14:39:08.018 5311 5311 D BluetoothManager: getInstance|| 04-07 14:39:08.018 5311 5311 D BluetoothManager: getConnectedDevicesCount: 2| 04-07 14:39:08.018 5311 5311 D MainActivity: onDeviceChange|2, count: 2| 04-07 14:39:08.018 5311 5311 D STBAPIManager: setBlueToothUsing called : 2 04-07 14:39:08.019 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:39:08.020 4458 4536 E BtGatt.GattService: name: BRM_BA01_CB3 04-07 14:39:08.021 5311 6434 D BluetoothGatt: onConfigureMTU() - Device=14:4E:34:92:1C:B3 mtu=123 status=0 04-07 14:39:08.021 3557 3557 I SystemPropertyManager: change property : PROPERTY_BLUETOOTH_USING 04-07 14:39:08.021 3557 3557 I TVService-21.08.18: [vendor/skb/framework/btf_dev/interface/btvservice/1.0/default/TVService.cpp][staticPropertyChange] called 04-07 14:39:08.022 3557 3557 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:39:08.022 3557 3557 I TVService-21.08.18: [TVService::onProperyUpdatedEvent]: key(PROPERTY_BLUETOOTH_USING), value() 04-07 14:39:08.022 3557 3557 I TVService-21.08.18: [vendor/skb/framework/btf_dev/interface/btvservice/1.0/default/TVService.cpp][onProperyUpdatedEvent][271] callback application 04-07 14:39:08.022 3557 3557 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:39:08.022 5528 7289 D BTVCORE-JNI: [updatedProperty] message received key=PROPERTY_BLUETOOTH_USING, value= 04-07 14:39:08.023 5528 7289 D BtvJniInterface: BTF|postPropertyUpdateFromNative|844|postEventFromProperty 04-07 14:39:08.023 5528 7289 D PropertyService: BTF|onHandleEvent|488|onHandleEvent type = 1 key = PROPERTY_BLUETOOTH_USING 04-07 14:39:08.023 5528 7289 D PropertyService: BTF|onHandleEvent|494|propertyservice: setChangePropertyListener onHandleEvent start callback count=1 BUILD_DATE:2021.11.15 04-07 14:39:08.023 5528 7289 D PropertyService: BTF|onHandleEvent|498|propertyservice: setChangePropertyListener onHandleEvent packeage=package com.skb.btv.framework.property, Unknown, version 0.0 04-07 14:39:08.026 6042 6065 D PropertyManager: BTF|ChangePropertyCallback|519| ChangePropertyCallback ChangePropertyListener start type=1, key=PROPERTY_BLUETOOTH_USING 04-07 14:39:08.028 5311 5311 D STBAPIManager: setProperty() isOK : true, key : PROPERTY_BLUETOOTH_USING, value : 2 04-07 14:39:08.028 5311 5311 I MainActivity: RemoteSettinginit() called 04-07 14:39:08.029 4458 5041 I bt_stack: [INFO:btsnoop.cc(311)] add_rfc_l2c_channel: rfcomm data going over l2cap channel. conn_handle=11 cid=0x0046:0x00c0 04-07 14:39:08.032 3836 4779 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:39:08.035 4458 4536 D bt_bta_gattc: bta_gattc_get_gatt_db 04-07 14:39:08.040 5311 5311 I BluetoothManager: setRemoconAddress() called - Address : 14:4E:34:92:1C:B3 04-07 14:39:08.040 5311 5311 I BluetoothManager: setRemoteName() called - name : BRM_BA01_CB3 04-07 14:39:08.041 5311 5311 D MainActivity: RemoteSettinginit() - isPairing : true 04-07 14:39:08.041 5311 5311 I Main_RemoteUpdate: getRemoteCurrentVersion() called 04-07 14:39:08.041 5311 5311 I Main_RemoteUpdate: getRemoteCurrentVersion() remoteFlag : true 04-07 14:39:08.041 5311 5311 I SendInterfaceManager: SendInterfaceManager getInstance 04-07 14:39:08.041 5311 5311 I SendInterfaceManager: sendRefreshPropertyWeb propertyName : PROPERTY_BLUETOOTH_USING 04-07 14:39:08.041 5311 5311 I G2TvFragment: isFragmentHidden() isFragmentHidden : true 04-07 14:39:08.041 5311 5311 I SendInterfaceManager: sendRefreshPropertyWeb web is not visible 04-07 14:39:08.041 5311 5311 D BatteryLevel: GlobalGattInit() called 04-07 14:39:08.041 5311 5311 D BluetoothManager: getInstance|| 04-07 14:39:08.050 5311 6434 D BluetoothGatt: onSearchComplete() = Device=14:4E:34:92:1C:B3 Status=0 04-07 14:39:08.050 5311 6434 D BatteryLevel: onServicesDiscovered: status = 0 04-07 14:39:08.053 5311 6434 V BatteryLevel: batteryLevel = false 04-07 14:39:08.054 5311 5311 I BluetoothManager: setUpdateRemoconAddress() called - Address : 14:4E:34:92:1C:B3 04-07 14:39:08.054 5311 5311 I BluetoothManager: setUpdateRemoteName() called - name : BRM_BA01_CB3 04-07 14:39:08.054 5311 5311 I STBGlobal: setUpdateRemoteName() called - name : BRM_BA01_CB3 04-07 14:39:08.054 5311 5311 D BluetoothManager: [ BluetoothManager ] isRemoconUpdateConnected = true 04-07 14:39:08.054 5311 5311 D BatteryLevel: GlobalGattInit mIsRemotePairing : true 04-07 14:39:08.055 5311 5311 I BluetoothManager: getUpdateRemoconAddress() called - Address : 14:4E:34:92:1C:B3 04-07 14:39:08.055 5311 5311 D BatteryLevel: init mBtGatt : android.bluetooth.BluetoothGatt@f8158e4 04-07 14:39:08.059 5311 5311 D STBAPIManager: getProperty() key : PROPERTY_REMOTE_BATTERY, result : 2 04-07 14:39:08.060 5311 5311 I STBGlobal: getBattery - property : 2, eBATTERY : NORMAL_BATTERY 04-07 14:39:08.060 5311 5311 D BluetoothA2dp: Proxy object connected 04-07 14:39:08.061 5311 5311 D BluetoothConnectionManager: [mBluetoothReceiver] A2DP onServiceConnected profile:2 04-07 14:39:08.062 5311 5311 D BluetoothConnectionManager: [mBluetoothReceiver]BluetoothProfile.A2DP 04-07 14:39:08.155 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=0xc9f20f5c 04-07 14:39:08.163 4458 5041 I bt_stack: [INFO:btsnoop.cc(300)] whitelist_rfc_dlci: Whitelisting rfcomm channel. L2CAP CID=0x0046 DLCI=0x06 04-07 14:39:08.163 4458 5041 I bt_stack: [INFO:port_api.cc(300)] RFCOMM_RemoveServer: handle=4 04-07 14:39:08.164 4458 5041 W bt_btif : new conn_srvc id:5, app_id:1 04-07 14:39:08.164 4458 5041 I bt_stack: [INFO:bta_ag_sco.cc(1174)] bta_ag_sco_listen: 00:42:79:a0:ec:50 04-07 14:39:08.165 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:39:08.165 4458 4536 I BluetoothHeadsetServiceJni: ConnectionStateCallback 2 for 00:42:79:a0:ec:50 04-07 14:39:08.166 4458 5059 D BluetoothAdapterService: isQuetModeEnabled() - Enabled = false 04-07 14:39:08.167 4458 5059 V BluetoothDatabase: getProfilePriority: 00:42:79:A0:EC:50, profile=1, priority = 100 04-07 14:39:08.168 3528 3528 D isqmsAgent: [isqmsAgent 0158 04/07 14:39:08:168][3528] CISQMSSchedule::SCHETYPE_CYCLE event_id=H01 04-07 14:39:08.172 4458 5059 I HeadsetStateMachine: Disconnected: currentDevice=00:42:79:A0:EC:50, msg=accept incoming connection 04-07 14:39:08.174 4458 5041 I bt_stack: [INFO:btsnoop.cc(289)] whitelist_l2c_channel: Whitelisting l2cap channel. conn_handle=11 cid=0x0047:0x0101 04-07 14:39:08.176 4458 5041 I bt_stack: [INFO:btsnoop.cc(289)] whitelist_l2c_channel: Whitelisting l2cap channel. conn_handle=11 cid=0x0047:0x0101 04-07 14:39:08.182 4458 4458 I BluetoothPhonePolicy: processProfileStateChanged, device=00:42:79:A0:EC:50, profile=1, 0 -> 1 04-07 14:39:08.182 4458 4458 D AdapterProperties: PROFILE_CONNECTION_STATE_CHANGE: profile=1, device=00:42:79:A0:EC:50, 0 -> 1 04-07 14:39:08.183 7572 7572 D CachedBluetoothDevice: onProfileStateChanged: profile HEADSET, device=00:42:79:A0:EC:50, newProfileState 1 04-07 14:39:08.195 4458 5041 W bt_sdp : process_service_search_attr_rsp 04-07 14:39:08.199 7572 7572 D BtvBtPairingService: sptek:BT onProfileConnectionStateChanged name = JBL Flip 4, connectState = STATE_CONNECTING_1, bluetoothProfile = 1, controlState = 0 04-07 14:39:08.203 4458 5041 I bt_stack: [INFO:btsnoop.cc(323)] clear_l2cap_whitelist: Clearing whitelist from l2cap channel. conn_handle=11 cid=71:257 04-07 14:39:08.226 3836 4734 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:39:08.234 3836 3921 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:39:08.273 6199 6287 D isqms_agent: success open fifo file=/btv_home/run/isqms_unix_socket_agent 04-07 14:39:08.273 6199 6287 D isqms_agent: CISQMS::make_msg2 04-07 14:39:08.273 6199 6287 D isqms_agent: CISQMS::make_msg SEND_DATA 04-07 14:39:08.273 6199 6287 D isqms_agent: send data=$send_data$1$5$-1$;100;1;1;14:4E:34:A1:56:4D 04-07 14:39:08.273 6199 6287 D isqms_agent: send_data_to_agent sock write 04-07 14:39:08.273 3528 3568 D isqmsAgent: read data buffer=>$send_data$1$5$-1$;100;1;1;14:4E:34:A1:56:4D 04-07 14:39:08.274 3528 3568 D isqmsAgent: read data pData=>$send_data$1$5$-1$;100;1;1;14:4E:34:A1:56:4D 04-07 14:39:08.274 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:39:08.274 6199 6287 D isqms_agent: send_data_to_agent sock close 04-07 14:39:08.274 3528 3568 D isqmsAgent: nCategoryID=1, nSubCategoryID=5, nFieldID=-1 04-07 14:39:08.274 6199 6287 D isqms_agent: ######################## pop_data nType=2, m_nEventCnt=1, isqms->m_pISQMDATA=0 04-07 14:39:08.274 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:39:08.274 6199 6287 D isqms_agent: @@@@@@@@@@@@@@@@@@@@@@@ send delete m_nEventCnt = 1 04-07 14:39:08.274 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:39:08.274 6199 6287 D isqms_agent: @@@@@@@@@@@@@@@@@@@@@@@1 m_nEventCnt=0, isqms->m_pISQMDATA=0 04-07 14:39:08.274 3528 3568 D isqmsAgent: ######################################## 04-07 14:39:08.274 3528 3568 D isqmsAgent: get_property_value key=dev.rcu.battery szRet=Normal 04-07 14:39:08.274 6199 6287 D isqms_agent: @@@@@@@@@@@@@@@@@@@@@@@2 m_nEventCnt=0, isqms->m_pISQMDATA=0 04-07 14:39:08.274 3528 3568 D isqmsAgent: [isqmsAgent 0159 04/07 14:39:08:274][3528] INFO: get_property_value value=Norma 04-07 14:39:08.274 3528 3568 D isqmsAgent: get_property_value key=dev.rcu.manu szRet= 04-07 14:39:08.274 3528 3568 D isqmsAgent: [isqmsAgent 0160 04/07 14:39:08:274][3528] INFO: get_property_value value= 04-07 14:39:08.274 3528 3568 D isqmsAgent: get_property_value key=dev.rcu.ver szRet= 04-07 14:39:08.274 3528 3568 D isqmsAgent: [isqmsAgent 0161 04/07 14:39:08:274][3528] INFO: get_property_value value= 04-07 14:39:08.274 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:39:08.274 3528 3568 D isqmsAgent: _thread_read_data_from_agent_fifo running, recvthread 04-07 14:39:08.274 3528 3568 D isqmsAgent: _thread_read_data_from_agent_fifo read waiting 04-07 14:39:08.274 3528 3568 D isqmsAgent: read data buffer=>@@ 04-07 14:39:08.274 3528 3568 D isqmsAgent: _thread_read_data_from_agent_fifo running, recvthread 04-07 14:39:08.274 3528 3568 D isqmsAgent: _thread_read_data_from_agent_fifo read waiting 04-07 14:39:08.277 4458 4536 I BluetoothHeadsetServiceJni: ConnectionStateCallback 3 for 00:42:79:a0:ec:50 04-07 14:39:08.282 4458 5059 I HeadsetPhoneState: stopListenForPhoneState(), no listener indicates nothing is listening 04-07 14:39:08.283 4458 5059 W HeadsetPhoneState: startListenForPhoneState, invalid subscription ID -1 04-07 14:39:08.283 4458 5059 E HeadsetSystemInterface: Handsfree phone proxy null for query phone state 04-07 14:39:08.290 4458 4458 I BluetoothPhonePolicy: processProfileStateChanged, device=00:42:79:A0:EC:50, profile=1, 1 -> 2 04-07 14:39:08.290 4458 4537 D BluetoothActiveDeviceManager: handleMessage(MESSAGE_HFP_ACTION_CONNECTION_STATE_CHANGED): device 00:42:79:A0:EC:50 connected 04-07 14:39:08.290 4458 4458 D BluetoothAdapterService: isQuetModeEnabled() - Enabled = false 04-07 14:39:08.290 4458 4537 D BluetoothActiveDeviceManager: setHfpActiveDevice(00:42:79:A0:EC:50) 04-07 14:39:08.291 4458 4458 D AdapterProperties: PROFILE_CONNECTION_STATE_CHANGE: profile=1, device=00:42:79:A0:EC:50, 1 -> 2 04-07 14:39:08.292 7572 7572 D CachedBluetoothDevice: onProfileStateChanged: profile HEADSET, device=00:42:79:A0:EC:50, newProfileState 2 04-07 14:39:08.292 4458 4537 I HeadsetService: setActiveDevice: device=00:42:79:A0:EC:50, uid/pid=1002/4458 04-07 14:39:08.303 4458 4537 D BluetoothActiveDeviceManager: handleMessage(MESSAGE_HFP_ACTION_ACTIVE_DEVICE_CHANGED): device= 00:42:79:A0:EC:50 04-07 14:39:08.306 3836 3836 I AS.BtHelper: setBtScoActiveDevice: null -> 00:42:79:A0:EC:50 04-07 14:39:08.307 7572 7572 D BtvBtPairingService: sptek:BT onProfileConnectionStateChanged name = JBL Flip 4, connectState = STATE_CONNECTED_2, bluetoothProfile = 1, controlState = 0 04-07 14:39:08.309 4458 5041 I bt_stack: [INFO:btsnoop.cc(289)] whitelist_l2c_channel: Whitelisting l2cap channel. conn_handle=11 cid=0x0048:0x0141 04-07 14:39:08.310 3505 3505 D memtrack_aml: type:0 for pid:7482, size_up_to:0 04-07 14:39:08.311 4458 5041 I bt_stack: [INFO:btsnoop.cc(289)] whitelist_l2c_channel: Whitelisting l2cap channel. conn_handle=11 cid=0x0049:0x0182 04-07 14:39:08.315 3505 3505 D memtrack_aml: type:1 for pid:7482, size_up_to:0 04-07 14:39:08.316 3836 3836 I AS.AudioDeviceInventory: handleDeviceConnection(true dev:10 address:00:42:79:A0:EC:50 name:JBL Flip 4) 04-07 14:39:08.316 3836 3836 I AS.AudioDeviceInventory: deviceKey:0x10:00:42:79:A0:EC:50 04-07 14:39:08.316 3836 3836 I AS.AudioDeviceInventory: deviceInfo:null is(already)Connected:false 04-07 14:39:08.317 3836 3921 D AS.AudioService: setStreamVolume streamType = 6index = 10 04-07 14:39:08.318 3521 5128 E APM::HwModule: createDevice: could not find HW module for device 0010 address 00:42:79:A0:EC:50 04-07 14:39:08.318 3836 3836 E AudioSystem-JNI: Command failed for android_media_AudioSystem_setDeviceConnectionState: -38 04-07 14:39:08.318 3836 3836 E AS.AudioDeviceInventory: not connecting device 0x10 due to command error 1 04-07 14:39:08.318 3836 3836 I AS.AudioDeviceInventory: handleDeviceConnection(true dev:80000008 address:00:42:79:A0:EC:50 name:JBL Flip 4) 04-07 14:39:08.318 3836 3836 I AS.AudioDeviceInventory: deviceKey:0x80000008:00:42:79:A0:EC:50 04-07 14:39:08.319 3836 3836 I AS.AudioDeviceInventory: deviceInfo:null is(already)Connected:false 04-07 14:39:08.319 3836 3921 D AS.AudioService: getPropertyVolume(AudioSystem.STREAM_BLUETOOTH_SCO) index = 5 04-07 14:39:08.319 3521 5128 D APM::HwModule: createDevice: adding dynamic device type:0x80000008,@:00:42:79:A0:EC:50 to module primary 04-07 14:39:08.320 3486 3587 D audio_hw_primary: adev_set_parameters(0xea775280, 00:42:79:A0:EC:50=;connect=-2147483640) 04-07 14:39:08.320 3486 3587 I audio_hw_primary: adev_set_parameters(kv: 00:42:79:A0:EC:50=;connect=-2147483640) 04-07 14:39:08.322 3486 3486 D audio_hw_primary: adev_open_input_stream: enter: devices(0x80000008) channel_mask(0xc) rate(48000) format(0x1) source(1) 04-07 14:39:08.322 3486 3486 D audio_hw_primary: check_input_parameters(sample_rate=48000, format=1, channel_count=2, devices = 80000008) 04-07 14:39:08.322 3486 3486 D audio_hw_primary: adev_open_input_stream: in->requested_rate = 48000, in->config.rate = 8000 04-07 14:39:08.323 3486 3486 D audio_hw_primary: adev_open_input_stream: exit 04-07 14:39:08.324 3505 3505 D memtrack_aml: type:2 for pid:7482, size_up_to:0 04-07 14:39:08.329 3836 3921 D AS.AudioService: setStreamVolume(stream=6, index=5, calling=com.android.bluetooth) 04-07 14:39:08.330 4458 5041 I bt_bta_av: bta_av_conn_cback: conn_cback bd_addr: 00:42:79:a0:ec:50 04-07 14:39:08.331 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:39:08.331 4458 5041 W bt_btif : bta_av_rc_create: Skipping RC creation for the old AVRCP profile 04-07 14:39:08.331 4458 5041 D bt_bta_av: SetAvdtpVersion: AVDTP version for 00:42:79:a0:ec:50 set to 0x103 04-07 14:39:08.331 4458 5041 W bt_btif : bta_dm_rm_cback:0, status:0 04-07 14:39:08.331 4458 5041 W bt_btif : new conn_srvc id:18, app_id:0 04-07 14:39:08.331 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:39:08.331 4458 5041 W bt_btif : btif_av_get_peer_sep: No active peer found 04-07 14:39:08.331 4458 5041 I bt_btif_a2dp: btif_a2dp_on_idle: ## ON A2DP IDLE ## peer_sep = 1 04-07 14:39:08.331 4458 5041 W bt_btif : btif_av_get_peer_sep: No active peer found 04-07 14:39:08.331 4458 5041 I bt_btif_a2dp_source: btif_a2dp_source_on_idle: state=STATE_OFF 04-07 14:39:08.331 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:39:08.331 4458 5041 I btif_av : btif_report_connection_state: peer_address=00:42:79:a0:ec:50 state=1 04-07 14:39:08.332 3486 3486 D audio_hw_primary: in_get_buffer_size: enter: channel_mask(0xc) rate(48000) format(0x1) 04-07 14:39:08.332 3486 3486 D audio_hw_primary: get_input_buffer_size(sample_rate=48000, format=1, channel_count=2) 04-07 14:39:08.332 3486 3486 D audio_hw_primary: in_get_buffer_size: exit: buffer_size = 2048 04-07 14:39:08.333 3486 3486 D audio_hw_primary: in_get_buffer_size: enter: channel_mask(0xc) rate(48000) format(0x1) 04-07 14:39:08.333 3486 3486 D audio_hw_primary: get_input_buffer_size(sample_rate=48000, format=1, channel_count=2) 04-07 14:39:08.333 3486 3486 D audio_hw_primary: in_get_buffer_size: exit: buffer_size = 2048 04-07 14:39:08.335 4458 4536 I BluetoothA2dpServiceJni: bta2dp_connection_state_callback 04-07 14:39:08.336 4458 4536 D A2dpNativeInterface: onConnectionStateChanged: A2dpStackEvent {type:EVENT_TYPE_CONNECTION_STATE_CHANGED, device:00:42:79:A0:EC:50, value1:CONNECTING} 04-07 14:39:08.336 4458 5062 D A2dpStateMachine: handleMessage: E msg.what=101 04-07 14:39:08.336 4458 5062 D A2dpStateMachine: processMsg: Disconnected 04-07 14:39:08.336 4458 5062 D A2dpStateMachine: Disconnected process message(00:42:79:A0:EC:50): STACK_EVENT 04-07 14:39:08.337 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:39:08.337 4458 5062 I A2dpService: okToConnect: device 00:42:79:A0:EC:50 isOutgoingRequest: false 04-07 14:39:08.337 4458 5062 D BluetoothAdapterService: isQuetModeEnabled() - Enabled = false 04-07 14:39:08.338 4458 5062 V BluetoothDatabase: getProfilePriority: 00:42:79:A0:EC:50, profile=2, priority = 100 04-07 14:39:08.340 3521 8479 I AudioFlinger: AudioFlinger's thread 0xe9d0c6c0 tid=8479 ready to run 04-07 14:39:08.340 3486 3486 D audio_hw_primary: in_standby: enter: stream(0xea72c140) 04-07 14:39:08.340 3486 3486 D audio_hw_primary: do_input_standby(0xea72c140) in->standby = 1 04-07 14:39:08.340 3486 3486 D audio_hw_primary: in_standby: exit 04-07 14:39:08.340 4458 5062 I A2dpStateMachine: Incoming A2DP Connecting request accepted: 00:42:79:A0:EC:50 04-07 14:39:08.341 4458 5062 D A2dpStateMachine: transitionTo: destState=Connecting 04-07 14:39:08.341 4458 5062 D A2dpStateMachine: handleMessage: new destination call exit/enter 04-07 14:39:08.341 4458 5062 D A2dpStateMachine: setupTempStateStackWithStatesToEnter: X mTempStateStackCount=1,curStateInfo: null 04-07 14:39:08.341 4458 5062 D A2dpStateMachine: invokeExitMethods: Disconnected 04-07 14:39:08.341 4458 5062 D A2dpStateMachine: Exit Disconnected(00:42:79:A0:EC:50): STACK_EVENT 04-07 14:39:08.341 4458 5062 D A2dpStateMachine: moveTempStackToStateStack: i=0,j=0 04-07 14:39:08.341 4458 5062 D A2dpStateMachine: moveTempStackToStateStack: X mStateStackTop=0,startingIndex=0,Top=Connecting 04-07 14:39:08.341 4458 5062 D A2dpStateMachine: invokeEnterMethods: Connecting 04-07 14:39:08.341 4458 5062 I A2dpStateMachine: Enter Connecting(00:42:79:A0:EC:50): STACK_EVENT 04-07 14:39:08.341 4458 5062 D A2dpStateMachine: Connection state 00:42:79:A0:EC:50: DISCONNECTED->CONNECTING 04-07 14:39:08.343 3486 3486 D audio_hw_primary: in_set_parameters(0xea72c140, 00:42:79:A0:EC:50=) 04-07 14:39:08.343 3486 3486 I audio_hw_primary: Amlogic_HAL - in_set_parameters: parameter is NULL, change ret value to 0 if it's greater than 0 for passing VTS test. 04-07 14:39:08.343 3486 3486 D audio_hw_primary: in_standby: enter: stream(0xea72c140) 04-07 14:39:08.343 3486 3486 D audio_hw_primary: do_input_standby(0xea72c140) in->standby = 1 04-07 14:39:08.343 3486 3486 D audio_hw_primary: in_standby: exit 04-07 14:39:08.348 4458 5062 D A2dpStateMachine: handleMessage: X 04-07 14:39:08.351 7572 7572 D CachedBluetoothDevice: onProfileStateChanged: profile A2DP, device=00:42:79:A0:EC:50, newProfileState 1 04-07 14:39:08.351 4458 4458 D AdapterProperties: PROFILE_CONNECTION_STATE_CHANGE: profile=2, device=00:42:79:A0:EC:50, 0 -> 1 04-07 14:39:08.356 4458 4458 I BluetoothPhonePolicy: processProfileStateChanged, device=00:42:79:A0:EC:50, profile=2, 0 -> 1 04-07 14:39:08.356 3486 3486 D audio_hw_primary: adev_close_input_stream: enter: dev(0xea775280) stream(0xea72c140) 04-07 14:39:08.356 3486 3486 D audio_hw_primary: in_standby: enter: stream(0xea72c140) 04-07 14:39:08.356 3486 3486 D audio_hw_primary: do_input_standby(0xea72c140) in->standby = 1 04-07 14:39:08.356 3486 3486 D audio_hw_primary: in_standby: exit 04-07 14:39:08.356 3486 3486 D audio_hw_primary: adev_close_input_stream: exit 04-07 14:39:08.357 7820 7820 D BluetoothAudioStateReceiver: a2dp extra state is 1 04-07 14:39:08.358 7820 7820 D AudioMirrorService: AM_EVENT_A2DP_STATE_CHANGED: 1 04-07 14:39:08.361 3836 3836 E AS.BtHelper: setBtScoActiveDevice() failed to add new device 00:42:79:A0:EC:50 04-07 14:39:08.362 3836 3921 D AS.AudioService: streamType = 6, device = hdmi called : com.android.bluetooth 04-07 14:39:08.362 3836 4407 I AS.AudioService: onAccessoryPlugMediaUnmute newDevice=-2147483640 [-2147483640] 04-07 14:39:08.363 5311 5311 D BluetoothConnectionManager: [ mBluetoothReceiver ] action= .CONNECTION_STATE_CHANGED, JBL Flip 4 , deviceBoundState= 12, conncetionState= -1 04-07 14:39:08.363 5311 5311 D BluetoothConnectionManager: BluetoothA2dp.ACTION_CONNECTION_STATE_CHANGED 04-07 14:39:08.363 5311 5311 I BluetoothConnectionManager: BluetoothA2dp A2DP State: 1 04-07 14:39:08.363 3486 3486 D audio_hw_primary: adev_set_parameters(0xea775280, A2dpSuspended=false) 04-07 14:39:08.363 3486 3486 I audio_hw_primary: adev_set_parameters(kv: A2dpSuspended=false) 04-07 14:39:08.363 3486 3486 I audio_hw_primary: adev_set_parameters, ret=-2, value=@'r⚌fp⚌$ 04-07 14:39:08.363 3486 3486 I audio_hw_primary: Amlogic_HAL - adev_set_parameters: return Result::NOT_SUPPORTED (4) instead of other error code. 04-07 14:39:08.367 3486 3486 D audio_hw_primary: adev_set_parameters(0xea775280, BT_SCO=off) 04-07 14:39:08.367 3486 3486 I audio_hw_primary: adev_set_parameters(kv: BT_SCO=off) 04-07 14:39:08.367 3486 3486 I audio_hw_primary: adev_set_parameters, ret=-2, value=⚌fp⚌⚌ep⚌ 04-07 14:39:08.367 3486 3486 I audio_hw_primary: Amlogic_HAL - adev_set_parameters: return Result::NOT_SUPPORTED (4) instead of other error code. 04-07 14:39:08.367 4458 4537 D BluetoothActiveDeviceManager: onAudioDevicesAdded 04-07 14:39:08.367 4458 4537 D BluetoothActiveDeviceManager: Audio device added: JBL Flip 4 type: 7 04-07 14:39:08.368 4458 4458 D AvrcpVolumeManager: onAudioDevicesAdded: Not expecting device changed 04-07 14:39:08.370 5528 5528 D BtvService4.2.49 IBtvService: BtvStartReceiver::create 04-07 14:39:08.371 5528 5528 D BtvService4.2.49 IBtvService: IN| BtvStartReceiver::onReceive getAction = android.bluetooth.a2dp.profile.action.CONNECTION_STATE_CHANGED 04-07 14:39:08.371 3836 4734 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:39:08.372 5528 5528 D BtvService4.2.49 IBtvService: BTF|onReceive|241|OUT| BtvStartReceiver::onReceive 04-07 14:39:08.378 7572 7572 D BtvBtPairingService: sptek:BT onProfileConnectionStateChanged name = JBL Flip 4, connectState = STATE_CONNECTING_1, bluetoothProfile = 2, controlState = 0 04-07 14:39:08.390 3836 3921 D VolumeController: salmon postVolumeChanged streamType = 3 04-07 14:39:08.399 3836 3921 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:39:08.399 4458 5041 I bt_stack: [INFO:btsnoop.cc(323)] clear_l2cap_whitelist: Clearing whitelist from l2cap channel. conn_handle=11 cid=73:386 04-07 14:39:08.401 4458 5059 E HeadsetSystemInterface: listCurrentCalls() failed: mPhoneProxy is null 04-07 14:39:08.401 4458 5059 E HeadsetStateMachine: processAtClcc: failed to list current calls for 00:42:79:A0:EC:50 04-07 14:39:08.413 3836 4779 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:39:08.464 4458 5059 I HeadsetPhoneState: stopListenForPhoneState(), no listener indicates nothing is listening 04-07 14:39:08.465 4458 5059 W HeadsetPhoneState: startListenForPhoneState, invalid subscription ID -1 04-07 14:39:08.542 4458 5059 I HeadsetStateMachine: processVendorSpecificAt: unsupported command: +CSRSF=0,0,0,1,0,0,0 04-07 14:39:08.564 3557 3557 W HwBinder:3557_2: type=1400 audit(0.0:728): 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:39:08.571 3557 8391 E libc : Access denied finding property "skb.audio.output" 04-07 14:39:08.622 3557 8407 W RendererPolicyBase_0: video render: 59.94 fps, drop: 0.00 fps 04-07 14:39:08.643 3557 8423 I HalAudioOutput: outputRate:48134(1.00) 04-07 14:39:08.744 3486 3760 W ServiceManagement: getService: unable to call into hwbinder service for vendor.amlogic.hardware.remotecontrol@1.0::IRemoteControl/default. 04-07 14:39:08.740 3486 3486 W ATVRemoteAudioH: type=1400 audit(0.0:729): avc: denied { call } for scontext=u:r:hal_audio_amlogic:s0 tcontext=u:r:rc_server:s0 tclass=binder permissive=0 04-07 14:39:09.012 3557 8398 D BOXKEY-STDVB: [DEVICE 0] ++ remain buffer size : 38164 04-07 14:39:09.055 7849 7849 D MDNSService: MDNSMsgHandler() AM_EVENT_CHECK_NETWORK_CONFIG. isConnected : true 04-07 14:39:09.145 5311 6434 D BatteryLevel: onCharacteristicRead Battery value = [100] 04-07 14:39:09.147 5311 6434 D STBAPIManager: getProperty() key : PROPERTY_REMOTE_BATTERY, result : 2 04-07 14:39:09.147 5311 6434 I STBGlobal: getBattery - property : 2, eBATTERY : NORMAL_BATTERY 04-07 14:39:09.147 5311 6434 D BatteryLevel: getBattery : NORMAL_BATTERY 04-07 14:39:09.149 5311 6434 D STBAPIManager: getProperty() key : PROPERTY_REMOTE_BATTERY, result : 2 04-07 14:39:09.149 5311 6434 I STBGlobal: getBattery - property : 2, eBATTERY : NORMAL_BATTERY 04-07 14:39:09.149 5311 6434 E BatteryLevel: BtGattClose Global - mGlobalGatt : com.realsil.android.blehub.dfu.GlobalGatt@780814d, mBtGatt : android.bluetooth.BluetoothGatt@f8158e4 04-07 14:39:09.149 5311 6434 I GlobalGatt: closeAll, mBluetoothDeviceAddresss.size(): 1 04-07 14:39:09.150 5311 6434 D GlobalGatt: close all of addr: 14:4E:34:92:1C:B3 04-07 14:39:09.150 5311 6434 D GlobalGatt: close all of addr: 14:4E:34:92:1C:B3 04-07 14:39:09.150 5311 6434 I GlobalGatt: disconnect() 04-07 14:39:09.150 5311 6434 I GlobalGatt: isConnected, addr: 14:4E:34:92:1C:B3, mConnectionState.get(address): 2 04-07 14:39:09.150 5311 6434 D BluetoothGatt: cancelOpen() - device: 14:4E:34:92:1C:B3 04-07 14:39:09.151 4458 5041 I bt_stack: [INFO:gatt_api.cc(1219)] GATT_Disconnect conn_id=0x0007 04-07 14:39:09.152 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:39:09.152 4458 5041 E bt_stack: [ERROR:bta_gattc_act.cc(423)] bta_gattc_cancel_bk_conn: failed 04-07 14:39:09.292 7146 7246 I UEI.SmartControl: ISetup API: 41 04-07 14:39:09.293 7146 7246 D UEI.SmartControl: --- getAllRemotes 04-07 14:39:09.298 7146 7246 E UEI.SmartControl: !!! Invalid key!!! 04-07 14:39:09.299 7146 7246 D UEI.SmartControl: Setup on Transact DONE: 41 Result: true 04-07 14:39:09.301 7146 7246 D UEI.SmartControl: ------ getRemoteDeviceInfo: 0 04-07 14:39:09.303 7146 7246 D UEI.SmartControl: --- Start readDeviceInfo --- 04-07 14:39:09.304 7146 8481 D UEI.SmartControl: --- Start reading device info --- 04-07 14:39:09.333 7146 8482 D UEI.SmartControl: --- handleCharacteristicRead 04-07 14:39:09.337 7146 8482 D UEI.SmartControl: ----------get DeviceInfo Manufacture name: Universal Electronics, Inc. 04-07 14:39:09.370 7146 8483 D UEI.SmartControl: --- handleCharacteristicRead 04-07 14:39:09.371 7146 8483 D UEI.SmartControl: ----------get DeviceInfo Firmware version 04-07 14:39:09.373 7146 8483 D UEI.SmartControl: ----------get DeviceInfo Firmware name: BL 193⚌ 04-07 14:39:09.393 7146 8484 D UEI.SmartControl: --- handleCharacteristicRead 04-07 14:39:09.398 7146 8484 D UEI.SmartControl: ----------get DeviceInfo Hardware 04-07 14:39:09.399 7146 8484 D UEI.SmartControl: ----------get DeviceInfo HardwareVersion name: 01 04-07 14:39:09.422 7146 8485 D UEI.SmartControl: --- handleCharacteristicRead 04-07 14:39:09.425 7146 8485 D UEI.SmartControl: ----------get DeviceInfo SoftwareVersion name: 7049.01.80 04-07 14:39:09.426 7146 8485 D UEI.SmartControl: ----------Set Remote SoftwareVersion: 7049.01.80 04-07 14:39:09.452 7146 8486 D UEI.SmartControl: --- handleCharacteristicRead 04-07 14:39:09.455 7146 8486 D UEI.SmartControl: ----------get DeviceInfo ModelNumber name: UEI BLE RCU 04-07 14:39:09.482 7146 8487 D UEI.SmartControl: --- handleCharacteristicRead 04-07 14:39:09.484 7146 8487 D UEI.SmartControl: ----------get DeviceInfo SerialNumber name: 04-07 14:39:09.485 7146 8487 D UEI.SmartControl: Compare versions: remote = 7049.01.80 <-> new FW = 7003.09.00 04-07 14:39:09.486 7146 8487 D UEI.SmartControl: --- isFirmwareUpdateAvailable: New FW version is available = 7003.09.00 04-07 14:39:09.487 7146 8487 D UEI.SmartControl: Sending new broadcast Intent for new FW version: 1 - 7003.09.00 04-07 14:39:09.487 7146 8487 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:39:09.489 3836 4779 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:39:09.489 3836 4779 E ActivityManager: java.lang.Throwable 04-07 14:39:09.489 3836 4779 E ActivityManager: at com.android.server.am.ActivityManagerService.checkBroadcastFromSystem(ActivityManagerService.java:14810) 04-07 14:39:09.489 3836 4779 E ActivityManager: at com.android.server.am.ActivityManagerService.broadcastIntentLocked(ActivityManagerService.java:15451) 04-07 14:39:09.489 3836 4779 E ActivityManager: at com.android.server.am.ActivityManagerService.broadcastIntentLocked(ActivityManagerService.java:14827) 04-07 14:39:09.489 3836 4779 E ActivityManager: at com.android.server.am.ActivityManagerService.broadcastIntent(ActivityManagerService.java:15593) 04-07 14:39:09.489 3836 4779 E ActivityManager: at android.app.IActivityManager$Stub.onTransact(IActivityManager.java:1950) 04-07 14:39:09.489 3836 4779 E ActivityManager: at com.android.server.am.ActivityManagerService.onTransact(ActivityManagerService.java:2741) 04-07 14:39:09.489 3836 4779 E ActivityManager: at android.os.Binder.execTransactInternal(Binder.java:1021) 04-07 14:39:09.489 3836 4779 E ActivityManager: at android.os.Binder.execTransact(Binder.java:994) 04-07 14:39:09.490 3836 4779 I DropBoxManagerService: add tag=system_server_wtf isTagEnabled=true flags=0x2 04-07 14:39:09.500 7146 8487 D UEI.SmartControl: ---- calling readBatteryLevel: 04-07 14:39:09.501 7146 8487 D BluetoothGatt: setCharacteristicNotification() - uuid: 00002a19-0000-1000-8000-00805f9b34fb enable: true 04-07 14:39:09.503 4458 4536 W bt_stack: [WARNING:bta_gattc_api.cc(652)] notification already registered 04-07 14:39:09.505 7146 8487 D UEI.SmartControl: Battery readCharacteristic: true 04-07 14:39:09.542 7146 8488 D UEI.SmartControl: --- handleCharacteristicRead 04-07 14:39:09.544 7146 8488 D UEI.SmartControl: ----------Battery Level: 100 04-07 14:39:09.545 7146 8481 D UEI.SmartControl: --- Done reading device info --- 04-07 14:39:09.545 7146 8481 I UEI.SmartControl: reportRemoteDeviceInfo 04-07 14:39:09.545 7146 7246 D UEI.SmartControl: BLE Device Info: 04-07 14:39:09.546 7146 7246 D UEI.SmartControl: Manufacture: Universal Electronics, Inc. 04-07 14:39:09.547 7146 7246 D UEI.SmartControl: ModelNumber: UEI BLE RCU 04-07 14:39:09.548 7146 7246 D UEI.SmartControl: SoftwareVersion: 7049.01.80 04-07 14:39:09.549 7146 7246 D UEI.SmartControl: HardwareVersion: 01 04-07 14:39:09.549 7146 7246 D UEI.SmartControl: FirmwareVersion: BL 193⚌ 04-07 14:39:09.550 7146 7246 D UEI.SmartControl: SerialNumber: 04-07 14:39:09.551 7146 7246 D UEI.SmartControl: --- Done readDeviceInfo --- 04-07 14:39:09.551 7146 7246 D UEI.SmartControl: ----- readRemoteDeviceInfo ----- 04-07 14:39:09.552 7146 7246 D UEI.SmartControl: ----- Remote Device Info: Battery Level = 100 04-07 14:39:09.553 7146 7246 D UEI.SmartControl: ----- Remote Device Info: SW Version = 7049.01.80 04-07 14:39:09.554 5311 8471 D Main_RemoteUpdate: tempCurrentVersion : 7049.01.80 04-07 14:39:09.555 5311 8471 D Main_RemoteUpdate: CurrentVersion : 01.80, tempCurrentVersion : 7049.01.80 04-07 14:39:09.556 5311 8471 I Main_RemoteUpdate: [end] getRemoteDeviceInfo 04-07 14:39:09.556 5311 5311 D Main_RemoteUpdate: saveRemoteVer : 01.80 04-07 14:39:09.564 3557 3557 W HwBinder:3557_2: type=1400 audit(0.0:730): 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:39:09.570 3557 8391 E libc : Access denied finding property "skb.audio.output" 04-07 14:39:09.652 5311 6434 I GlobalGatt: closeBluetoothGatt, addr: 14:4E:34:92:1C:B3, mBluetoothGatts.get(addr): android.bluetooth.BluetoothGatt@f8158e4 04-07 14:39:09.652 5311 6434 D BluetoothGatt: close() 04-07 14:39:09.652 5311 6434 D BluetoothGatt: unregisterApp() - mClientIf=7 04-07 14:39:09.655 5311 5334 D BluetoothGatt: onClientConnectionState() - status=0 clientIf=7 device=14:4E:34:92:1C:B3 04-07 14:39:09.748 3486 3760 W ServiceManagement: getService: unable to call into hwbinder service for vendor.amlogic.hardware.remotecontrol@1.0::IRemoteControl/default. 04-07 14:39:09.744 3486 3486 W ATVRemoteAudioH: type=1400 audit(0.0:731): avc: denied { call } for scontext=u:r:hal_audio_amlogic:s0 tcontext=u:r:rc_server:s0 tclass=binder permissive=0 04-07 14:39:09.953 5802 6006 I AnypointAD: [AddrAD][apm-single-1-thrd-1 ][FileExt.calcCrc32][93] completed to calcCrc32 - /sdcard/.DATA/amg/assets/575170.ts 04-07 14:39:09.955 5802 6006 I AnypointAD: [AddrAD][apm-single-1-thrd-1 ][DownloadService.checkCompletion][86] change file permissions: file=/sdcard/.DATA/amg/assets/575170.ts readable=true 04-07 14:39:09.979 5802 6006 I AnypointAD: [AddrAD][apm-single-1-thrd-1 ][DeviceStorage.][137] DeviceStorage is initialised. deviceStorage=DeviceStorage(free=3,564,388,352, used=55,572,988, cached=0) 04-07 14:39:09.982 5802 6006 I AnypointAD: [AddrAD][apm-single-1-thrd-1 ][DownloadService.download][34] start download: http://58.125.209.198/prod/55623/ENCODING/18/1644477893087.ts 04-07 14:39:10.017 3557 8398 D BOXKEY-STDVB: [DEVICE 0] ++ remain buffer size : 35532 04-07 14:39:10.331 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:39:10.331 4458 5041 D bt_bta_av: SetAvdtpVersion: AVDTP version for 00:42:79:a0:ec:50 set to 0x103 04-07 14:39:10.331 4458 5041 I a2dp_api: A2DP_FindService: peer: 00:42:79:a0:ec:50 UUID: 0x110b 04-07 14:39:10.383 4458 5041 I bt_stack: [INFO:btsnoop.cc(289)] whitelist_l2c_channel: Whitelisting l2cap channel. conn_handle=11 cid=0x004a:0x0202 04-07 14:39:10.388 4458 5041 I bt_stack: [INFO:btsnoop.cc(289)] whitelist_l2c_channel: Whitelisting l2cap channel. conn_handle=11 cid=0x004a:0x0202 04-07 14:39:10.457 4458 5041 I bt_stack: [INFO:btsnoop.cc(289)] whitelist_l2c_channel: Whitelisting l2cap channel. conn_handle=11 cid=0x004b:0x0244 04-07 14:39:10.460 4458 5041 I bt_stack: [INFO:btsnoop.cc(289)] whitelist_l2c_channel: Whitelisting l2cap channel. conn_handle=11 cid=0x004c:0x0285 04-07 14:39:10.461 4458 5041 W bt_sdp : process_service_search_attr_rsp 04-07 14:39:10.471 4458 5041 I bt_stack: [INFO:btsnoop.cc(323)] clear_l2cap_whitelist: Clearing whitelist from l2cap channel. conn_handle=11 cid=74:514 04-07 14:39:10.471 4458 5041 I a2dp_api: a2dp_sdp_cback: status: 0 04-07 14:39:10.471 4458 5041 D bt_bta_av: SetAvdtpVersion: AVDTP version for 00:42:79:a0:ec:50 set to 0x103 04-07 14:39:10.472 4458 5041 W bt_avp : AVDT_ConnectReq: address=00:42:79:a0:ec:50 channel_index=0 sec_mask=0x12 04-07 14:39:10.472 4458 5041 I bt_bta_av: bta_av_conn_cback: conn_cback bd_addr: 00:42:79:a0:ec:50 04-07 14:39:10.472 4458 5041 W bt_avp : AVDT_ConnectReq: address=00:42:79:a0:ec:50 result=0 04-07 14:39:10.527 4458 5041 I bt_stack: [INFO:connection_handler.cc(304)] void bluetooth::avrcp::ConnectionHandler::AcceptorControlCb(uint8_t, uint8_t, uint16_t, const RawAddress *): handle=0000 result=000000 addr=00:42:79:a0:ec:50 04-07 14:39:10.527 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:39:10.527 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:39:10.527 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:39:10.528 4458 5041 I bt_stack: [INFO:connection_handler.cc(185)] Connect to device ff:ff:ff:ff:ff:ff 04-07 14:39:10.528 4458 5041 I bt_stack: [INFO:connection_handler.cc(206)] virtual bool bluetooth::avrcp::ConnectionHandler::AvrcpConnect(bool, const RawAddress &): handle=0x01 status= 000000 04-07 14:39:10.529 4458 5041 I bt_stack: [INFO:btsnoop.cc(323)] clear_l2cap_whitelist: Clearing whitelist from l2cap channel. conn_handle=11 cid=76:645 04-07 14:39:10.561 4458 5041 I bt_stack: [INFO:btsnoop.cc(289)] whitelist_l2c_channel: Whitelisting l2cap channel. conn_handle=11 cid=0x004d:0x02c2 04-07 14:39:10.561 4458 4536 I BluetoothA2dpServiceJni: bta2dp_audio_config_callback 04-07 14:39:10.564 3557 3557 W HwBinder:3557_2: type=1400 audit(0.0:732): 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:39:10.563 4458 5041 I bt_stack: [INFO:btsnoop.cc(289)] whitelist_l2c_channel: Whitelisting l2cap channel. conn_handle=11 cid=0x004d:0x02c2 04-07 14:39:10.566 4458 5041 I bt_stack: [INFO:btsnoop.cc(289)] whitelist_l2c_channel: Whitelisting l2cap channel. conn_handle=11 cid=0x004e:0x0305 04-07 14:39:10.567 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:39:10.570 4458 5062 D A2dpStateMachine: handleMessage: E msg.what=101 04-07 14:39:10.570 4458 5062 D A2dpStateMachine: processMsg: Connecting 04-07 14:39:10.570 4458 5062 D A2dpStateMachine: Connecting process message(00:42:79:A0:EC:50): STACK_EVENT 04-07 14:39:10.571 3557 8391 E libc : Access denied finding property "skb.audio.output" 04-07 14:39:10.573 4458 5041 I bt_stack: [INFO:a2dp_encoding.cc(731)] set_remote_delay: not ready for DelayReport 150 ms 04-07 14:39:10.575 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:39:10.581 4458 5062 D A2dpStateMachine: A2DP Codec Config: null->{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:39:10.582 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:39:10.583 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:39:10.584 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:39:10.595 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:39:10.600 4458 5062 D A2dpStateMachine: handleMessage: X 04-07 14:39:10.619 4458 5041 I bt_stack: [INFO:btsnoop.cc(289)] whitelist_l2c_channel: Whitelisting l2cap channel. conn_handle=11 cid=0x004f:0x0346 04-07 14:39:10.621 4458 5041 I bt_stack: [INFO:btsnoop.cc(289)] whitelist_l2c_channel: Whitelisting l2cap channel. conn_handle=11 cid=0x004f:0x0346 04-07 14:39:10.624 3557 8407 W RendererPolicyBase_0: video render: 59.94 fps, drop: 0.00 fps 04-07 14:39:10.630 4458 5041 W bt_sdp : process_service_search_attr_rsp 04-07 14:39:10.632 4458 5041 I bt_stack: [INFO:btsnoop.cc(323)] clear_l2cap_whitelist: Clearing whitelist from l2cap channel. conn_handle=11 cid=78:773 04-07 14:39:10.633 4458 5041 W bt_btif : bta_dm_rm_cback:0, status:0 04-07 14:39:10.633 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:39:10.633 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:39:10.633 4458 5041 I btif_av : btif_report_connection_state: peer_address=00:42:79:a0:ec:50 state=2 04-07 14:39:10.633 4458 4536 I BluetoothA2dpServiceJni: bta2dp_connection_state_callback 04-07 14:39:10.633 4458 4536 D A2dpNativeInterface: onConnectionStateChanged: A2dpStackEvent {type:EVENT_TYPE_CONNECTION_STATE_CHANGED, device:00:42:79:A0:EC:50, value1:CONNECTED} 04-07 14:39:10.634 4458 5041 E bt_btif : btif_rc_get_device_by_bda: device not found, returning NULL! 04-07 14:39:10.634 4458 5041 E bt_btif : btif_rc_check_handle_pending_play: p_dev NULL 04-07 14:39:10.634 4458 5062 D A2dpStateMachine: handleMessage: E msg.what=101 04-07 14:39:10.634 4458 5062 D A2dpStateMachine: processMsg: Connecting 04-07 14:39:10.634 4458 5062 D A2dpStateMachine: Connecting process message(00:42:79:A0:EC:50): STACK_EVENT 04-07 14:39:10.634 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:39:10.634 4458 5062 D A2dpStateMachine: transitionTo: destState=Connected 04-07 14:39:10.635 4458 5062 D A2dpStateMachine: handleMessage: new destination call exit/enter 04-07 14:39:10.635 4458 5062 D A2dpStateMachine: setupTempStateStackWithStatesToEnter: X mTempStateStackCount=1,curStateInfo: null 04-07 14:39:10.635 4458 5062 D A2dpStateMachine: invokeExitMethods: Connecting 04-07 14:39:10.635 4458 5062 D A2dpStateMachine: Exit Connecting(00:42:79:A0:EC:50): STACK_EVENT 04-07 14:39:10.635 4458 5062 D A2dpStateMachine: moveTempStackToStateStack: i=0,j=0 04-07 14:39:10.635 4458 5062 D A2dpStateMachine: moveTempStackToStateStack: X mStateStackTop=0,startingIndex=0,Top=Connected 04-07 14:39:10.635 4458 5062 D A2dpStateMachine: invokeEnterMethods: Connected 04-07 14:39:10.635 4458 5062 I A2dpStateMachine: Enter Connected(00:42:79:A0:EC:50): STACK_EVENT 04-07 14:39:10.636 4458 5062 D A2dpStateMachine: Connection state 00:42:79:A0:EC:50: CONNECTING->CONNECTED 04-07 14:39:10.638 4458 5062 D A2dpStateMachine: A2DP Playing state : device: 00:42:79:A0:EC:50 State:PLAYING->NOT_PLAYING 04-07 14:39:10.639 7572 7572 D CachedBluetoothDevice: onProfileStateChanged: profile A2DP, device=00:42:79:A0:EC:50, newProfileState 2 04-07 14:39:10.639 4458 4458 D AdapterProperties: PROFILE_CONNECTION_STATE_CHANGE: profile=2, device=00:42:79:A0:EC:50, 1 -> 2 04-07 14:39:10.640 4458 4458 I BluetoothPhonePolicy: processProfileStateChanged, device=00:42:79:A0:EC:50, profile=2, 1 -> 2 04-07 14:39:10.640 4458 4458 D BluetoothAdapterService: isQuetModeEnabled() - Enabled = false 04-07 14:39:10.640 4458 4458 I BluetoothPhonePolicy: connectOtherProfile: already scheduled callback for 00:42:79:A0:EC:50 04-07 14:39:10.640 7820 7820 D BluetoothAudioStateReceiver: a2dp extra state is 2 04-07 14:39:10.640 4458 4537 D BluetoothActiveDeviceManager: handleMessage(MESSAGE_A2DP_ACTION_CONNECTION_STATE_CHANGED): device 00:42:79:A0:EC:50 connected 04-07 14:39:10.640 4458 4537 D BluetoothActiveDeviceManager: setA2dpActiveDevice(00:42:79:A0:EC:50) 04-07 14:39:10.641 7820 7820 D AudioMirrorService: AM_EVENT_A2DP_STATE_CHANGED: 2 04-07 14:39:10.641 4458 4537 D A2dpService: setActiveDevice(00:42:79:A0:EC:50): previous is null 04-07 14:39:10.641 4458 4537 I BluetoothA2dpServiceJni: setActiveDeviceNative: sBluetoothA2dpInterface: 0xc9ee5dfc 04-07 14:39:10.643 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:39:10.643 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:39:10.643 4458 5041 I bt_btif_a2dp_source: btif_a2dp_source_startup: state=STATE_OFF 04-07 14:39:10.644 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:39:10.644 4458 5063 I bt_btif_a2dp_source: btif_a2dp_source_startup_delayed: state=STATE_STARTING_UP 04-07 14:39:10.644 4458 5063 I bt_stack: [INFO:a2dp_encoding.cc(595)] init 04-07 14:39:10.644 5311 5311 D BluetoothConnectionManager: [ mBluetoothReceiver ] action= .CONNECTION_STATE_CHANGED, JBL Flip 4 , deviceBoundState= 12, conncetionState= -1 04-07 14:39:10.644 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:39:10.644 4458 5041 I bt_btif_a2dp_source: btif_a2dp_source_audio_tx_flush_req: state=STATE_STARTING_UP 04-07 14:39:10.644 5311 5311 D BluetoothConnectionManager: BluetoothA2dp.ACTION_CONNECTION_STATE_CHANGED 04-07 14:39:10.645 5311 5311 I BluetoothConnectionManager: BluetoothA2dp A2DP State: 2 04-07 14:39:10.646 4458 5062 D A2dpStateMachine: handleMessage: X 04-07 14:39:10.646 5528 5528 D BtvService4.2.49 IBtvService: BtvStartReceiver::create 04-07 14:39:10.646 5528 5528 D BtvService4.2.49 IBtvService: IN| BtvStartReceiver::onReceive getAction = android.bluetooth.a2dp.profile.action.CONNECTION_STATE_CHANGED 04-07 14:39:10.646 5528 5528 D BtvService4.2.49 IBtvService: BtvStartReceiver::setA2DPState : isConnected = true 04-07 14:39:10.647 3505 3505 D memtrack_aml: type:0 for pid:8234, size_up_to:0 04-07 14:39:10.649 3505 3505 D memtrack_aml: type:1 for pid:8234, size_up_to:0 04-07 14:39:10.649 4458 5063 I bt_stack: [INFO:client_interface.cc(197)] listManifestByInterface_cb returns 1 instance(s) 04-07 14:39:10.651 3505 3505 D memtrack_aml: type:2 for pid:8234, size_up_to:0 04-07 14:39:10.652 3557 3557 I SystemPropertyManager: change property : vendor.skb.SETTINGS.A2DP.PLUGGED 04-07 14:39:10.652 3557 3557 I TVService-21.08.18: [vendor/skb/framework/btf_dev/interface/btvservice/1.0/default/TVService.cpp][staticPropertyChange] called 04-07 14:39:10.652 3557 3557 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:39:10.652 3557 3557 I TVService-21.08.18: [TVService::onProperyUpdatedEvent]: key(vendor.skb.SETTINGS.A2DP.PLUGGED), value() 04-07 14:39:10.652 3557 3557 I TVService-21.08.18: [vendor/skb/framework/btf_dev/interface/btvservice/1.0/default/TVService.cpp][onProperyUpdatedEvent][271] callback application 04-07 14:39:10.652 3557 3557 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:39:10.652 5528 7289 D BTVCORE-JNI: [updatedProperty] message received key=vendor.skb.SETTINGS.A2DP.PLUGGED, value= 04-07 14:39:10.652 5528 5528 D BtvService4.2.49 IBtvService: BTF|onReceive|241|OUT| BtvStartReceiver::onReceive 04-07 14:39:10.652 5528 7289 D BtvJniInterface: BTF|postPropertyUpdateFromNative|844|postEventFromProperty 04-07 14:39:10.652 5528 7289 D PropertyService: BTF|onHandleEvent|488|onHandleEvent type = 1 key = vendor.skb.SETTINGS.A2DP.PLUGGED 04-07 14:39:10.652 5528 7289 D PropertyService: BTF|onHandleEvent|494|propertyservice: setChangePropertyListener onHandleEvent start callback count=1 BUILD_DATE:2021.11.15 04-07 14:39:10.652 5528 7289 D PropertyService: BTF|onHandleEvent|498|propertyservice: setChangePropertyListener onHandleEvent packeage=package com.skb.btv.framework.property, Unknown, version 0.0 04-07 14:39:10.654 6042 6065 D PropertyManager: BTF|ChangePropertyCallback|519| ChangePropertyCallback ChangePropertyListener start type=1, key=vendor.skb.SETTINGS.A2DP.PLUGGED 04-07 14:39:10.656 4458 5063 I bt_stack: [INFO:client_interface.cc(232)] IBluetoothAudioProvidersFactory::getService() returned 0xf319f740 (remote) 04-07 14:39:10.657 3486 3587 I BTAudioProvidersFactory: getProviderCapabilities - SessionType=A2DP_SOFTWARE_ENCODING_DATAPATH supports 1 codecs 04-07 14:39:10.657 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:39:10.658 3486 3587 I BTAudioProvidersFactory: openProvider - SessionType=A2DP_SOFTWARE_ENCODING_DATAPATH 04-07 14:39:10.658 4458 5063 I bt_stack: [INFO:client_interface.cc(270)] openProvider_cb(SUCCESS) 04-07 14:39:10.658 4458 5063 I bt_stack: [INFO:client_interface.cc(289)] IBluetoothAudioProvidersFactory::openProvider() returned 0xf3178ba0 (remote) 04-07 14:39:10.658 4458 5063 I bt_stack: [INFO:a2dp_encoding.cc(620)] init: restore DELAY 150 ms 04-07 14:39:10.658 4458 5063 I bt_btif_a2dp_source: btif_a2dp_source_audio_tx_flush_event: state=STATE_RUNNING 04-07 14:39:10.658 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:39:10.658 4458 4536 I BluetoothA2dpServiceJni: bta2dp_audio_config_callback 04-07 14:39:10.659 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: sample_rate=48000 bits_per_sample=16 channel_count=2 04-07 14:39:10.659 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_feeding_reset: PCM bytes per tick 3840 04-07 14:39:10.659 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: MTU=883, peer_mtu=883 min_bitpool=2 max_bitpool=31 04-07 14:39:10.659 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:39:10.659 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: bitpool candidate: 48 (328 kbps) 04-07 14:39:10.659 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: computed bitpool too large (48) 04-07 14:39:10.659 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: bitpool candidate: 47 (323 kbps) 04-07 14:39:10.659 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: computed bitpool too large (47) 04-07 14:39:10.659 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: bitpool candidate: 46 (318 kbps) 04-07 14:39:10.659 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: computed bitpool too large (46) 04-07 14:39:10.659 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: bitpool candidate: 45 (313 kbps) 04-07 14:39:10.659 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: computed bitpool too large (45) 04-07 14:39:10.659 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: bitpool candidate: 44 (308 kbps) 04-07 14:39:10.659 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: computed bitpool too large (44) 04-07 14:39:10.659 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: bitpool candidate: 44 (303 kbps) 04-07 14:39:10.660 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: computed bitpool too large (44) 04-07 14:39:10.660 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: bitpool candidate: 43 (298 kbps) 04-07 14:39:10.660 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: computed bitpool too large (43) 04-07 14:39:10.660 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: bitpool candidate: 42 (293 kbps) 04-07 14:39:10.660 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: computed bitpool too large (42) 04-07 14:39:10.660 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: bitpool candidate: 41 (288 kbps) 04-07 14:39:10.660 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: computed bitpool too large (41) 04-07 14:39:10.660 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: bitpool candidate: 40 (283 kbps) 04-07 14:39:10.660 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: computed bitpool too large (40) 04-07 14:39:10.660 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: bitpool candidate: 39 (278 kbps) 04-07 14:39:10.660 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: computed bitpool too large (39) 04-07 14:39:10.660 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: bitpool candidate: 39 (273 kbps) 04-07 14:39:10.660 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: computed bitpool too large (39) 04-07 14:39:10.660 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: bitpool candidate: 38 (268 kbps) 04-07 14:39:10.660 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: computed bitpool too large (38) 04-07 14:39:10.660 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: bitpool candidate: 37 (263 kbps) 04-07 14:39:10.660 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: computed bitpool too large (37) 04-07 14:39:10.660 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: bitpool candidate: 36 (258 kbps) 04-07 14:39:10.660 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: computed bitpool too large (36) 04-07 14:39:10.660 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: bitpool candidate: 35 (253 kbps) 04-07 14:39:10.660 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: computed bitpool too large (35) 04-07 14:39:10.660 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: bitpool candidate: 34 (248 kbps) 04-07 14:39:10.660 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: computed bitpool too large (34) 04-07 14:39:10.660 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: bitpool candidate: 34 (243 kbps) 04-07 14:39:10.660 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: computed bitpool too large (34) 04-07 14:39:10.660 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: bitpool candidate: 33 (238 kbps) 04-07 14:39:10.660 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: computed bitpool too large (33) 04-07 14:39:10.660 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: bitpool candidate: 32 (233 kbps) 04-07 14:39:10.660 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: computed bitpool too large (32) 04-07 14:39:10.660 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: bitpool candidate: 31 (228 kbps) 04-07 14:39:10.660 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_encoder_update: final bit rate 228, final bit pool 31 04-07 14:39:10.660 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:39:10.661 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:39:10.661 3486 3587 I BTAudioProviderStub: startSession - SessionType=A2DP_SOFTWARE_ENCODING_DATAPATH, AudioConfiguration=[{.pcmConfig = {.sampleRate = RATE_48000, .channelMode = STEREO, .bitsPerSample = BITS_16}}] 04-07 14:39:10.661 3557 8423 I HalAudioOutput: outputRate:47951(1.00) 04-07 14:39:10.662 3486 3587 I BTAudioProviderSession: OnSessionStarted - SessionType=A2DP_SOFTWARE_ENCODING_DATAPATH, AudioConfiguration={.pcmConfig = {.sampleRate = RATE_48000, .channelMode = STEREO, .bitsPerSample = BITS_16}} 04-07 14:39:10.662 3486 3587 I BTAudioProviderSession: ReportSessionStatus - SessionType=A2DP_SOFTWARE_ENCODING_DATAPATH has NO port state observer 04-07 14:39:10.663 4458 5063 I bt_stack: [INFO:client_interface.cc(341)] startSession_cb(SUCCESS) 04-07 14:39:10.663 4458 4537 D A2dpService: Switch A2DP devices to 00:42:79:A0:EC:50 from null 04-07 14:39:10.663 4458 4537 D A2dpService: updateAndBroadcastActiveDevice(00:42:79:A0:EC:50) 04-07 14:39:10.663 4458 4537 D AvrcpTargetService: volumeDeviceSwitched: device=00:42:79:A0:EC:50 04-07 14:39:10.664 4458 4537 D AvrcpVolumeManager: volumeDeviceSwitched: mCurrentDevice=null device=00:42:79:A0:EC:50 04-07 14:39:10.671 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:39:10.671 4458 4458 I BluetoothPhonePolicy: processProfileActiveDeviceChanged, activeDevice=00:42:79:A0:EC:50, profile=2 04-07 14:39:10.673 4458 4458 V BluetoothDatabase: getProfilePriority: 14:4E:34:92:1C:B3, profile=2, priority = -1 04-07 14:39:10.674 3505 3505 D memtrack_aml: type:0 for pid:5428, size_up_to:0 04-07 14:39:10.675 3505 3505 D memtrack_aml: type:1 for pid:5428, size_up_to:0 04-07 14:39:10.677 3505 3505 D memtrack_aml: type:2 for pid:5428, size_up_to:0 04-07 14:39:10.679 4458 4537 D AvrcpVolumeManager: getVolume: Returning volume 5 04-07 14:39:10.679 4458 4458 V BluetoothDatabase: getProfilePriority: 14:4E:34:92:1C:B3, profile=1, priority = -1 04-07 14:39:10.680 4458 4458 V BluetoothDatabase: getProfilePriority: 14:4E:34:A1:56:4D, profile=2, priority = 100 04-07 14:39:10.682 4458 4458 V BluetoothDatabase: getProfilePriority: 14:4E:34:A1:56:4D, profile=1, priority = -1 04-07 14:39:10.683 4458 4458 V BluetoothDatabase: getProfilePriority: 88:D0:39:BB:21:A0, profile=2, priority = 100 04-07 14:39:10.684 3836 7465 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:39:10.685 4458 4458 V BluetoothDatabase: getProfilePriority: 88:D0:39:BB:21:A0, profile=1, priority = 100 04-07 14:39:10.687 4458 4458 V BluetoothDatabase: getProfilePriority: 00:42:79:A0:EC:50, profile=2, priority = 100 04-07 14:39:10.687 4458 4458 V BluetoothDatabase: getProfilePriority: 00:42:79:A0:EC:50, profile=1, priority = 100 04-07 14:39:10.688 4458 4458 V BluetoothDatabase: getProfilePriority: 00:42:79:A0:EC:50, profile=2, priority = 100 04-07 14:39:10.689 4458 4458 I BluetoothPhonePolicy: setAutoConnectForA2dpSink: device 00:42:79:A0:EC:50 PRIORITY_AUTO_CONNECT 04-07 14:39:10.691 4458 4458 D A2dpService: Saved priority 00:42:79:A0:EC:50 = 1000 04-07 14:39:10.693 4458 4458 V BluetoothDatabase: setProfilePriority: 00:42:79:A0:EC:50, profile=2, priority = 1000 04-07 14:39:10.693 3836 4408 I AS.AudioDeviceBroker: setBluetoothA2dpDeviceConnectionStateSuppressNoisyIntent state=2 addr=00:42:79:A0:EC:50 prof=2 supprNoisy=true vol=5 04-07 14:39:10.693 4458 4458 D BluetoothDatabase: updateDatabase 00:42:79:A0:EC:50 04-07 14:39:10.693 3836 4408 D BluetoothA2dp: getCodecStatus(00:42:79:A0:EC:50) 04-07 14:39:10.698 4458 4537 D BluetoothActiveDeviceManager: handleMessage(MESSAGE_A2DP_ACTION_ACTIVE_DEVICE_CHANGED): device= 00:42:79:A0:EC:50 04-07 14:39:10.698 4458 5062 D A2dpStateMachine: handleMessage: E msg.what=101 04-07 14:39:10.698 4458 5062 D A2dpStateMachine: processMsg: Connected 04-07 14:39:10.698 4458 5062 D A2dpStateMachine: Connected process message(00:42:79:A0:EC:50): STACK_EVENT 04-07 14:39:10.699 4458 5114 D A2dpService: getCodecStatus(00:42:79:A0:EC:50) 04-07 14:39:10.700 3836 4408 I AS.AudioDeviceInventory: setBluetoothA2dpDeviceConnectionState device: 00:42:79:A0:EC:50 state: 2 delay(ms): 0codec:520093696 suppressNoisyIntent: true 04-07 14:39:10.700 3836 4408 D AS.AudioDeviceInventory: onSetA2dpSinkConnectionState btDevice=00:42:79:A0:EC:50 state=2 is dock=false vol=5 04-07 14:39:10.700 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:39:10.701 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:39:10.701 4458 4458 V BluetoothDatabase: getProfilePriority: 00:42:79:A0:EC:50, profile=1, priority = 100 04-07 14:39:10.701 4458 4458 I BluetoothPhonePolicy: setAutoConnectForHeadset: device 00:42:79:A0:EC:50 PRIORITY_AUTO_CONNECT 04-07 14:39:10.701 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:39:10.702 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:39:10.703 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:39:10.705 4458 4458 I HeadsetService: setPriority: device=00:42:79:A0:EC:50, priority=1000, uid/pid=1002/4458 04-07 14:39:10.705 4458 4458 V BluetoothDatabase: setProfilePriority: 00:42:79:A0:EC:50, profile=1, priority = 1000 04-07 14:39:10.705 4458 4458 D BluetoothDatabase: updateDatabase 00:42:79:A0:EC:50 04-07 14:39:10.706 4458 4458 D AvrcpNativeInterface: sendMediaUpdate: metadata=false playStatus=true queue=false 04-07 14:39:10.706 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:39:10.707 4458 4458 D AvrcpTargetJni: sendMediaUpdateNative 04-07 14:39:10.707 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:39:10.707 4458 5041 W bt_stack: [WARNING:device.cc(1312)] Device is not registered for play status updates 04-07 14:39:10.707 4458 5041 I bt_stack: [INFO:device.cc(1360)] 00:42:79:a0:ec:50 : HandlePlayPosUpdate 04-07 14:39:10.707 4458 5041 W bt_stack: [WARNING:device.cc(1362)] Device is not registered for play position updates 04-07 14:39:10.712 7572 7572 D BtvBtPairingService: sptek:BT onProfileConnectionStateChanged name = JBL Flip 4, connectState = STATE_CONNECTED_2, bluetoothProfile = 2, controlState = 0 04-07 14:39:10.722 4458 5062 D A2dpStateMachine: handleMessage: X 04-07 14:39:10.729 3486 3587 D audio_hw_primary: adev_set_parameters(0xea775280, 00:42:79:A0:EC:50=;connect=128) 04-07 14:39:10.729 3486 3587 I audio_hw_primary: adev_set_parameters(kv: 00:42:79:A0:EC:50=;connect=128) 04-07 14:39:10.729 3486 3587 D a2dp_hal: a2dp_out_open: open 04-07 14:39:10.729 3486 3587 D A2DPHW : BluetoothAudioPortOut::SetUp: 04-07 14:39:10.729 3486 3587 D a2dp_hal: LoadAudioConfig: rate=48000, format=1, ch=3 04-07 14:39:10.729 3486 3587 I audio_hw_primary: adev_set_parameters a2dp connect: 80, device=480 04-07 14:39:10.731 3521 3521 I AudioFlinger: openOutput() this 0xee3c3000, module 10 Device 0x80, SamplingRate 48000, Format 0x000001, Channels 0x3, flags 0x4011 04-07 14:39:10.731 3486 3587 D audio_hw_primary: adev_open_output_stream_new: enter 04-07 14:39:10.731 3486 3587 D audio_hw_primary: adev_open_output_stream: enter: devices(0x80) channel_mask(0x3) rate(48000) format(0x1) flags(0x4011) 04-07 14:39:10.731 3486 3587 I aml_mmap_audio: [outMmapInit:302] stream:0xea7de180 04-07 14:39:10.732 3486 3587 I audio_hwsync: aml_audio_hwsync_init open tsync fd 26 04-07 14:39:10.732 3486 3587 I audio_hwsync: aml_audio_hwsync_init done 04-07 14:39:10.732 3486 3587 D audio_hw_primary: adev_open_output_stream: exit 04-07 14:39:10.732 3486 3587 D audio_hw_profile: get_hdmi_sink_cap is running... 04-07 14:39:10.732 3486 3587 D audio_hw_profile: query hdmi format... 04-07 14:39:10.732 3486 3587 I audio_hw_primary: get_sink_capability mbox+dvb case sink_capability = 0x1 04-07 14:39:10.732 3486 3587 D audio_hw_primary: get_sink_format: a2dp set to pcm 04-07 14:39:10.732 3486 3587 I audio-subMixingFactory: ++initSubMixingInput() 04-07 14:39:10.732 3486 3587 I audio-subMixingFactory: ++initSubMixingInputPcm(), out 0xea7de180, flags 0x4011, hwsync lpcm 0, out format 0x1 04-07 14:39:10.732 3486 3587 D audio_hw_primary: -adev_open_output_stream_new: out 0xea7de180: usecase:[7]PCM_MMAP card:0 alsa devices:0 04-07 14:39:10.733 3486 8424 D audio-subMixingFactory: [mixer_main_buffer_write_sm:1099] stream:0xea7dde00, switch from device:0x480 to device:0x400 04-07 14:39:10.734 3486 3587 I audio_hw_primary: out_get_buffer_size(out->config.rate=48000, format 1,stream format 1) 04-07 14:39:10.736 3486 3773 D a2dp_hal: a2dp_out_write_new: state=1 04-07 14:39:10.736 4458 4863 I btif_av : btif_av_stream_ready: Peer 00:42:79:a0:ec:50 : state=2, flags=0x0(None) 04-07 14:39:10.736 3521 8492 I AudioFlinger: AudioFlinger's thread 0xe9d2f000 tid=8492 ready to run 04-07 14:39:10.736 4458 4863 I btif_av : btif_av_stream_start 04-07 14:39:10.736 4458 4863 I bt_stack: [INFO:a2dp_encoding.cc(99)] StartRequest: accepted 04-07 14:39:10.736 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:39:10.736 4458 5041 I bt_bta_av: BTA_AvStart: handle=65 04-07 14:39:10.736 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:39:10.736 4458 5041 W bt_btif : bta_dm_rm_cback:1, status:7 04-07 14:39:10.736 4458 5041 W bt_btif : new conn_srvc id:18, app_id:1 04-07 14:39:10.736 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:39:10.741 3486 3587 D audio_hw_primary: out_set_parameters(kvpairs(a2dp_sink_address=00:42:79:A0:EC:50), out_device=0x480) 04-07 14:39:10.742 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:39:10.742 3486 3587 I audio_hw_primary: out_set_volume(), stream(0xea7de180), left:1.000000 right:1.000000 04-07 14:39:10.747 3486 3587 I audio_hw_primary: out_set_volume(), stream(0xea7de180), left:0.001879 right:0.001879 04-07 14:39:10.744 3486 3486 W ATVRemoteAudioH: type=1400 audit(0.0:733): avc: denied { call } for scontext=u:r:hal_audio_amlogic:s0 tcontext=u:r:rc_server:s0 tclass=binder permissive=0 04-07 14:39:10.750 3486 3760 W ServiceManagement: getService: unable to call into hwbinder service for vendor.amlogic.hardware.remotecontrol@1.0::IRemoteControl/default. 04-07 14:39:10.753 3521 3521 I AudioFlinger: openOutput() this 0xee3c3000, module 10 Device 0x80, SamplingRate 0, Format 00000000, Channels 0, flags 0x41 04-07 14:39:10.753 3486 3587 D audio_hw_primary: adev_open_output_stream_new: enter 04-07 14:39:10.753 3486 3587 D audio_hw_primary: adev_open_output_stream: enter: devices(0x80) channel_mask(0) rate(0) format(0) flags(0x41) 04-07 14:39:10.754 3486 3587 I audio_hw_primary: adev_open_output_stream: for raw audio output,force alsa stereo output 04-07 14:39:10.754 3486 3587 I audio_hwsync: aml_audio_hwsync_init open tsync fd 27 04-07 14:39:10.754 3486 3587 I audio_hwsync: aml_audio_hwsync_init done 04-07 14:39:10.754 3486 3587 D audio_hw_primary: adev_open_output_stream format=150994944 rate=48000 04-07 14:39:10.754 3486 3587 D audio_hw_primary: adev_open_output_stream: exit 04-07 14:39:10.754 3486 3587 D audio_hw_profile: get_hdmi_sink_cap is running... 04-07 14:39:10.755 3486 3587 D audio_hw_profile: query hdmi format... 04-07 14:39:10.755 3486 3587 I audio_hw_primary: get_sink_capability mbox+dvb case sink_capability = 0x1 04-07 14:39:10.755 3486 3587 D audio_hw_primary: get_sink_format: a2dp set to pcm 04-07 14:39:10.755 3486 3587 I audio_hw_primary: adev_open_output_stream_new(), direct usecase: [4]RAW_HWSYNC 04-07 14:39:10.755 3486 3587 I audio_hw_primary: write function change adev_open_output_stream_new 9658 04-07 14:39:10.755 3486 3587 D audio_hw_primary: -adev_open_output_stream_new: out 0xea7de500: usecase:[4]RAW_HWSYNC card:0 alsa devices:0 04-07 14:39:10.756 3521 3521 D AudioFlinger: readOutputParameters_l enable volume passthrough HAL format: 0x9000000. 04-07 14:39:10.757 3521 3521 D AudioFlinger: readOutputParameters_l enable volume passthrough. 04-07 14:39:10.764 3486 3587 I audio_hw_primary: out_get_buffer_size(out->config.rate=48000, format 9000000,stream format 9000000) 04-07 14:39:10.764 3521 3521 I AudioFlinger: HAL output buffer size 512 frames, normal sink buffer size 512 frames 04-07 14:39:10.765 3521 8493 I AudioFlinger: AudioFlinger's thread 0xe9d31800 tid=8493 ready to run 04-07 14:39:10.766 3486 3587 D audio_hw_primary: out_set_parameters(kvpairs(a2dp_sink_address=00:42:79:A0:EC:50), out_device=0x480) 04-07 14:39:10.766 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:39:10.767 3486 3587 D audio_hw_primary: out_standby_new: enter 04-07 14:39:10.767 3486 3587 I audio_hw_primary: [do_output_standby_l:6678] stream usecase:[4]RAW_HWSYNC , continuous:0 04-07 14:39:10.767 3486 3587 E a2dp_hal: a2dp_out_standby: hal_audio_open_times=1, not close 04-07 14:39:10.767 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:39:10.767 3486 3587 I audio_hw_primary: enable rawtopcm_flag !!! 04-07 14:39:10.767 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:39:10.767 3486 3587 I audio_hw_primary: do_output_standby_l current usecase_masks 2 04-07 14:39:10.767 3486 3587 D audio_hw_primary: out_standby_new: exit 04-07 14:39:10.768 3486 3587 I audio_hw_primary: out_get_parameters sup_formats,out 0xea7de500 04-07 14:39:10.768 3486 3587 D audio_hw_profile: get_hdmi_sink_cap_dolbylib is running... 04-07 14:39:10.769 3486 3587 D audio_hw_profile: query hdmi format... 04-07 14:39:10.769 3486 3587 I audio_hw_primary: sup_formats=AUDIO_FORMAT_PCM_16_BIT|AUDIO_FORMAT_IEC61937 04-07 14:39:10.769 3486 3587 I audio_hw_primary: out_get_parameters format=1;sup_sampling_rates,out 0xea7de500 04-07 14:39:10.770 3486 3587 D audio_hw_profile: get_hdmi_sink_cap_dolbylib is running... 04-07 14:39:10.770 3486 3587 D audio_hw_profile: query hdmi sample_rate... 04-07 14:39:10.771 3486 3587 I audio_hw_primary: sup_sampling_rates=32000|44100|48000 04-07 14:39:10.771 3486 3587 I audio_hw_primary: out_get_parameters format=1;sup_channels,out 0xea7de500 04-07 14:39:10.771 3486 3587 D audio_hw_profile: get_hdmi_sink_cap_dolbylib is running... 04-07 14:39:10.771 3486 3587 D audio_hw_profile: query hdmi channels... 04-07 14:39:10.771 3486 3587 I audio_hw_primary: sup_channels=AUDIO_CHANNEL_OUT_STEREO 04-07 14:39:10.772 3486 3587 I audio_hw_primary: out_get_parameters format=218103808;sup_sampling_rates,out 0xea7de500 04-07 14:39:10.772 3486 3587 D audio_hw_profile: get_hdmi_sink_cap_dolbylib is running... 04-07 14:39:10.772 3486 3587 D audio_hw_profile: query hdmi sample_rate... 04-07 14:39:10.772 3486 3587 I audio_hw_primary: sup_sampling_rates=32000|44100|48000 04-07 14:39:10.773 3486 3587 I audio_hw_primary: out_get_parameters format=218103808;sup_channels,out 0xea7de500 04-07 14:39:10.773 3486 3587 D audio_hw_profile: get_hdmi_sink_cap_dolbylib is running... 04-07 14:39:10.773 3486 3587 D audio_hw_profile: query hdmi channels... 04-07 14:39:10.773 3486 3587 I audio_hw_primary: sup_channels=AUDIO_CHANNEL_OUT_STEREO 04-07 14:39:10.774 3486 3587 D audio_hw_primary: out_set_parameters(kvpairs(closing=true), out_device=0x480) 04-07 14:39:10.774 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:39:10.776 3486 3587 D audio_hw_primary: out_dump(0xea7de500, 28) 04-07 14:39:10.779 3486 3587 D audio_hw_primary: out_set_parameters(kvpairs(exiting=1), out_device=0x480) 04-07 14:39:10.779 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:39:10.779 3521 3521 D AudioFlinger: preExit HAL format: 0x9000000. 04-07 14:39:10.779 3521 3521 D AudioFlinger: preExit disable volume passthrough. 04-07 14:39:10.786 3486 3587 D audio_hw_primary: adev_close_output_stream_new: enter usecase = [4]RAW_HWSYNC 04-07 14:39:10.786 3486 3587 D audio_hw_primary: adev_close_output_stream: enter: dev(0xea775280) stream(0xea7de500) 04-07 14:39:10.786 3521 3521 I AudioFlinger: openOutput() this 0xee3c3000, module 10 Device 0x80, SamplingRate 32000, Format 0xd000000, Channels 0x3, flags 0x41 04-07 14:39:10.786 3486 3587 D audio_hw_primary: out_standby_new: enter 04-07 14:39:10.786 3486 3587 I audio_hw_primary: [do_output_standby_l:6678] stream usecase:[4]RAW_HWSYNC , continuous:0 04-07 14:39:10.786 3486 3587 E a2dp_hal: a2dp_out_standby: hal_audio_open_times=1, not close 04-07 14:39:10.786 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:39:10.786 3486 3587 I audio_hw_primary: enable rawtopcm_flag !!! 04-07 14:39:10.786 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:39:10.786 3486 3587 I audio_hw_primary: do_output_standby_l current usecase_masks 2 04-07 14:39:10.786 3486 3587 D audio_hw_primary: out_standby_new: exit 04-07 14:39:10.786 3486 3587 I audio_hw_primary: enable rawtopcm_flag 04-07 14:39:10.786 3486 3587 I audio_hwsync: aml_audio_hwsync_release done 04-07 14:39:10.786 3486 3587 D audio_hw_primary: adev_close_output_stream: exit 04-07 14:39:10.786 3486 3587 D audio_hw_primary: adev_close_output_stream_new: exit 04-07 14:39:10.787 3486 3782 D audio_hw_primary: adev_open_output_stream_new: enter 04-07 14:39:10.787 3486 3782 D audio_hw_primary: adev_open_output_stream: enter: devices(0x80) channel_mask(0x3) rate(32000) format(0xd000000) flags(0x441) 04-07 14:39:10.787 3486 3782 I audio_hw_primary: convert format IEC61937 to 0x9000000 04-07 14:39:10.787 3486 3782 I audio_hw_primary: adev_open_output_stream: for raw audio output,force alsa stereo output 04-07 14:39:10.787 3486 3782 I audio_hwsync: aml_audio_hwsync_init open tsync fd 27 04-07 14:39:10.787 3486 3782 I audio_hwsync: aml_audio_hwsync_init done 04-07 14:39:10.787 3486 3782 D audio_hw_primary: adev_open_output_stream format=150994944 rate=32000 04-07 14:39:10.787 3486 3782 D audio_hw_primary: adev_open_output_stream: exit 04-07 14:39:10.787 3486 3782 D audio_hw_profile: get_hdmi_sink_cap is running... 04-07 14:39:10.788 3486 3782 D audio_hw_profile: query hdmi format... 04-07 14:39:10.788 3486 3782 I audio_hw_primary: get_sink_capability mbox+dvb case sink_capability = 0x1 04-07 14:39:10.788 3486 3782 D audio_hw_primary: get_sink_format: a2dp set to pcm 04-07 14:39:10.788 3486 3782 I audio_hw_primary: adev_open_output_stream_new(), direct usecase: [3]RAW_DIRECT 04-07 14:39:10.788 3486 3782 I audio_hw_primary: write function change adev_open_output_stream_new 9658 04-07 14:39:10.788 3486 3782 D audio_hw_primary: -adev_open_output_stream_new: out 0xea26a380: usecase:[3]RAW_DIRECT card:0 alsa devices:0 04-07 14:39:10.789 3521 3521 D AudioFlinger: readOutputParameters_l enable volume passthrough HAL format: 0xd000000. 04-07 14:39:10.790 3486 3782 I audio_hw_primary: out_get_buffer_size(out->config.rate=32000, format 9000000,stream format d000000) 04-07 14:39:10.790 3486 3782 I audio_hw_primary: out_get_buffer_size AUDIO_FORMAT_IEC61937 6144) 04-07 14:39:10.790 3486 3782 I audio_hw_primary: out_get_buffer_size AUDIO_FORMAT_IEC61937(DIRECT) (eDolbyDcvLib) size = 1536) 04-07 14:39:10.790 3521 3521 I AudioFlinger: HAL output buffer size 1536 frames, normal sink buffer size 1536 frames 04-07 14:39:10.793 3521 8495 I AudioFlinger: AudioFlinger's thread 0xe9d31800 tid=8495 ready to run 04-07 14:39:10.796 3486 3782 D audio_hw_primary: out_standby_new: enter 04-07 14:39:10.797 3486 3782 I audio_hw_primary: [do_output_standby_l:6678] stream usecase:[3]RAW_DIRECT , continuous:0 04-07 14:39:10.797 3486 3782 E a2dp_hal: a2dp_out_standby: hal_audio_open_times=1, not close 04-07 14:39:10.797 3486 3782 I audio_hw_primary: ++[usecase_change_validate_l:9394], dev masks:0x2, is_standby:1, out usecase:[3]RAW_DIRECT 04-07 14:39:10.797 3486 3782 I audio_hw_primary: enable rawtopcm_flag !!! 04-07 14:39:10.797 3486 3782 I audio_hw_primary: --[usecase_change_validate_l:9409], dev masks:0x2, is_standby:1, out usecase [3]RAW_DIRECT 04-07 14:39:10.797 3486 3782 I audio_hw_primary: do_output_standby_l current usecase_masks 2 04-07 14:39:10.797 3486 3782 D audio_hw_primary: out_standby_new: exit 04-07 14:39:10.816 3486 3782 D audio_hw_primary: out_set_parameters(kvpairs(closing=true), out_device=0x480) 04-07 14:39:10.817 3486 3782 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:39:10.818 3521 3521 D AudioFlinger: closing mmapThread 0xe9d2f000 04-07 14:39:10.819 3521 3521 D AudioFlinger: mmapThread exit() 04-07 14:39:10.820 3486 3782 D audio_hw_primary: adev_close_output_stream_new: enter usecase = [7]PCM_MMAP 04-07 14:39:10.820 3486 3782 I audio-subMixingFactory: ++deleteSubMixingInput() 04-07 14:39:10.820 3486 3782 I audio-subMixingFactory: deleteSubMixingInputPcm(), cnt_stream_using_mixer 0 04-07 14:39:10.820 3486 3782 D audio_hw_primary: adev_close_output_stream: enter: dev(0xea775280) stream(0xea7de180) 04-07 14:39:10.820 3486 3782 D audio_hw_primary: out_standby_new: enter 04-07 14:39:10.820 3486 3782 I audio_hw_primary: [do_output_standby_l:6678] stream usecase:[7]PCM_MMAP , continuous:0 04-07 14:39:10.820 3486 3782 E a2dp_hal: a2dp_out_standby: hal_audio_open_times=1, not close 04-07 14:39:10.820 3486 3782 I audio_hw_primary: ++[usecase_change_validate_l:9394], dev masks:0x2, is_standby:1, out usecase:[7]PCM_MMAP 04-07 14:39:10.820 3486 3782 I audio_hw_primary: --[usecase_change_validate_l:9409], dev masks:0x2, is_standby:1, out usecase [7]PCM_MMAP 04-07 14:39:10.820 3486 3782 I audio_hw_primary: do_output_standby_l current usecase_masks 2 04-07 14:39:10.820 3486 3782 D audio_hw_primary: out_standby_new: exit 04-07 14:39:10.820 3486 3782 I audio_hwsync: aml_audio_hwsync_release done 04-07 14:39:10.820 3486 3782 I aml_mmap_audio: [outMmapDeInit:340] stream:0xea7de180 04-07 14:39:10.820 3486 3782 D audio_hw_primary: adev_close_output_stream: exit 04-07 14:39:10.820 3486 3782 D audio_hw_primary: adev_close_output_stream_new: exit 04-07 14:39:10.822 3486 3782 D audio_hw_primary: out_set_parameters(kvpairs(closing=true), out_device=0x480) 04-07 14:39:10.822 3486 3782 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:39:10.823 3486 3782 D audio_hw_primary: out_dump(0xea26a380, 24) 04-07 14:39:10.825 3486 3782 D audio_hw_primary: out_set_parameters(kvpairs(exiting=1), out_device=0x480) 04-07 14:39:10.825 3486 3782 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:39:10.826 3521 3521 D AudioFlinger: preExit HAL format: 0xd000000. 04-07 14:39:10.829 3486 3782 D audio_hw_primary: adev_close_output_stream_new: enter usecase = [3]RAW_DIRECT 04-07 14:39:10.829 3486 3782 D audio_hw_primary: adev_close_output_stream: enter: dev(0xea775280) stream(0xea26a380) 04-07 14:39:10.829 3486 3782 D audio_hw_primary: out_standby_new: enter 04-07 14:39:10.829 3486 3782 I audio_hw_primary: [do_output_standby_l:6678] stream usecase:[3]RAW_DIRECT , continuous:0 04-07 14:39:10.829 3486 3782 E a2dp_hal: a2dp_out_standby: hal_audio_open_times=1, not close 04-07 14:39:10.829 3486 3782 I audio_hw_primary: ++[usecase_change_validate_l:9394], dev masks:0x2, is_standby:1, out usecase:[3]RAW_DIRECT 04-07 14:39:10.829 3486 3782 I audio_hw_primary: enable rawtopcm_flag !!! 04-07 14:39:10.829 3486 3782 I audio_hw_primary: --[usecase_change_validate_l:9409], dev masks:0x2, is_standby:1, out usecase [3]RAW_DIRECT 04-07 14:39:10.829 3486 3782 I audio_hw_primary: do_output_standby_l current usecase_masks 2 04-07 14:39:10.829 3486 3782 D audio_hw_primary: out_standby_new: exit 04-07 14:39:10.829 3486 3782 I audio_hw_primary: enable rawtopcm_flag 04-07 14:39:10.829 3486 3782 I audio_hwsync: aml_audio_hwsync_release done 04-07 14:39:10.829 3486 3782 D audio_hw_primary: adev_close_output_stream: exit 04-07 14:39:10.829 3486 3782 D audio_hw_primary: adev_close_output_stream_new: exit 04-07 14:39:10.831 3486 3782 I audio_hw_primary: ++adev_release_audio_patch: handle(2) 04-07 14:39:10.831 3486 3782 I audio_hw_primary: patch set found id 2, patchset 0xe8db5000 04-07 14:39:10.831 3486 3782 I audio_hw_primary: source 0 type=2 sink type =1 amk patch src=10 04-07 14:39:10.831 3486 3782 D audio_hw_primary: unregister_audio_patch: enter 04-07 14:39:10.831 3486 3782 D audio_hw_primary: unregister_audio_patch: exit 04-07 14:39:10.831 3486 3782 I audio_hw_primary: --adev_release_audio_patch: after releasing patch, patch sets will be: 04-07 14:39:10.835 3486 3782 D audio_hw_primary: adev_set_parameters(0xea775280, A2dpSuspended=false) 04-07 14:39:10.835 3486 3782 I audio_hw_primary: adev_set_parameters(kv: A2dpSuspended=false) 04-07 14:39:10.835 3486 3782 I audio_hw_primary: adev_set_parameters, ret=-2, value= 04-07 14:39:10.835 3486 3782 I audio_hw_primary: Amlogic_HAL - adev_set_parameters: return Result::NOT_SUPPORTED (4) instead of other error code. 04-07 14:39:10.837 3836 4408 D BluetoothA2dp: getCodecStatus(00:42:79:A0:EC:50) 04-07 14:39:10.837 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:39:10.837 4458 5041 I bt_bta_dm: handle_role_change: peer 00:42:79:a0:ec:50 info:0x30 new_role:0x1 dev count:2 hci_status=0 04-07 14:39:10.837 3521 3923 I APM_AudioPolicyManager: setStreamVolumeIndex: set_btv_media_volume index: 5 04-07 14:39:10.837 4458 5041 I btm_acl : BTM_SwitchRole: peer 00:42:79:a0:ec:50 new_role=0x0 p_cb=0x0 p_switch_role_cb=0x0 04-07 14:39:10.837 3521 3923 I APM_AudioPolicyManager: setStreamVolumeIndex: set_btv_media_volume mExtMute: 0 04-07 14:39:10.837 3521 3923 I APM_AudioPolicyManager: setStreamVolumeIndex: set_btv_media_volume stream : 3 volume_index : 5 gain : -54.520203 04-07 14:39:10.837 4458 4536 W bt_btif : btif_dm_upstreams_evt: unhandled event (14) 04-07 14:39:10.838 3557 3781 D BTV_HAL_MGR.001: [useSpeakerVolumePath] useSpeakerVolumePath : false 04-07 14:39:10.838 3557 3781 E AudioMixer: BTF|AMIXER_SetAudioVolume|74|IN| amixer=e37bf050 volume=5 gain=-54.520203 04-07 14:39:10.839 3557 3781 E AudioMixer: BTF|setMasterAudioVolumeIntoFile|172|IN| save volume:0.187930 ,volumeIndex : 5 04-07 14:39:10.839 3557 3781 E halMediaPlayer: BTF|setAudioVolume|766|IN| volume:0.187930 04-07 14:39:10.841 3557 8410 I LivePlayerRenderer_0: set audio output type:BT 04-07 14:39:10.841 3557 8410 I LivePlayerClock_0: set audio output type:BT 04-07 14:39:10.839 3557 3781 E halMediaPlayer: BTF|player_SetAudioVolume|716|IN| player=e7f074a0 volume=0.187930 04-07 14:39:10.841 3557 3781 D AmlHalPlayerImpl_0: SetVolume[0] volume = 0.187930 04-07 14:39:10.841 3557 3781 I LivePlayer_0: [setVolume:697] setVolume: 0.00 04-07 14:39:10.841 3557 3781 E halMediaPlayer: BTF|player_SetAudioVolume|726|OUT| 04-07 14:39:10.841 3557 3781 E halMediaPlayer: BTF|setAudioVolume|774| error setting! player:0, i:1, mState:0 04-07 14:39:10.841 3557 3781 E halMediaPlayer: BTF|setAudioVolume|779|OUT| 04-07 14:39:10.841 3557 3781 E AudioMixer: BTF|AMIXER_SetAudioVolume|86|OUT|vol:0.001879 04-07 14:39:10.841 3486 3782 D audio_hw_primary: adev_set_parameters(0xea775280, is_wifiAudioMode_enabled=0) 04-07 14:39:10.841 3486 3782 I audio_hw_primary: adev_set_parameters(kv: is_wifiAudioMode_enabled=0) 04-07 14:39:10.841 3486 3782 E audio_hw_primary: Amlogic_HAL - adev_set_parameters: is_wifiAudioMode_enabled:0. 04-07 14:39:10.841 3521 3923 D BtvMediaVolumeControlLib: status : 0 04-07 14:39:10.842 3557 8406 I AmlAudioOutPort: setParameters:is_wifiAudioMode_enabled=0, err=0 04-07 14:39:10.842 3557 8410 I LivePlayerRenderer_0: [onChangeAudioFormat:2244] format:0xdb2bb400, notify:0x0 04-07 14:39:10.842 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:39:10.842 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:39:10.842 3557 8410 I LivePlayerRenderer_0: do actual changeAudioFormat, mAudioSink:0xddcac2c0 04-07 14:39:10.842 3557 8410 I HalAudioOutput: [pause:181] 04-07 14:39:10.842 4458 4484 D A2dpService: getCodecStatus(00:42:79:A0:EC:50) 04-07 14:39:10.843 3486 3782 I audio-subMixingFactory: +out_pause_subMixingPCM(), stream 0xea7dde00, standby 0, pause status 0, usecase: [1]PCM_DIRECT 04-07 14:39:10.843 3486 3782 E a2dp_hal: a2dp_out_standby: hal_audio_open_times=1, not close 04-07 14:39:10.843 3486 3782 I audio-subMixingFactory: -out_pause_subMixingPCM() 04-07 14:39:10.845 3836 4408 D AS.AudioDeviceInventory: onBluetoothA2dpActiveDeviceChange btDevice=00:42:79:A0:EC:50 04-07 14:39:10.848 4458 4537 D BluetoothActiveDeviceManager: onAudioDevicesAdded 04-07 14:39:10.848 4458 4537 D BluetoothActiveDeviceManager: Audio device added: BFX-AT100 type: 8 04-07 14:39:10.848 4458 4458 D AvrcpVolumeManager: onAudioDevicesAdded: size: 1 04-07 14:39:10.849 4458 4458 D AvrcpVolumeManager: onAudioDevicesAdded: address=00:42:79:A0:EC:50 04-07 14:39:10.849 4458 4458 W AvrcpVolumeManager: volumeDeviceSwitched: Device isn't connected: 00:42:79:A0:EC:50 04-07 14:39:10.849 3521 3923 I hash_map_utils: key: 'isReconfigA2dpSupported' value: '' 04-07 14:39:10.851 3486 3782 D audio_hw_primary: adev_set_parameters(0xea775280, reconfigA2dp=true) 04-07 14:39:10.851 3486 3782 I audio_hw_primary: adev_set_parameters(kv: reconfigA2dp=true) 04-07 14:39:10.851 3486 3782 E audio_hw_primary: adev_set_parameters A2DP reconfigA2dp out_device=480 04-07 14:39:10.851 3486 3782 I audio_hw_primary: Amlogic_HAL - adev_set_parameters: return 0 instead of length of data be copied. 04-07 14:39:10.854 3836 3836 V MediaRouter: Audio routes updated: AudioRoutesInfo{ type=HDMI, bluetoothName=JBL Flip 4 }, a2dp=true 04-07 14:39:10.854 3836 3836 V MediaRouter: Selecting route: RouteInfo{ name=JBL Flip 4, description=블루투스 오디오, status=null, category=RouteCategory{ name=시스템 types=ROUTE_TYPE_LIVE_AUDIO ROUTE_TYPE_LIVE_VIDEO groupable=false }, supportedTypes=ROUTE_TYPE_LIVE_AUDIO , presentationDisplay=null } 04-07 14:39:10.858 4478 4478 V MediaRouter: Audio routes updated: AudioRoutesInfo{ type=HDMI, bluetoothName=JBL Flip 4 }, a2dp=true 04-07 14:39:10.858 4478 4478 V MediaRouter: Selecting route: RouteInfo{ name=JBL Flip 4, description=블루투스 오디오, status=null, category=RouteCategory{ name=시스템 types=ROUTE_TYPE_LIVE_AUDIO ROUTE_TYPE_LIVE_VIDEO groupable=false }, supportedTypes=ROUTE_TYPE_LIVE_AUDIO , presentationDisplay=null } 04-07 14:39:10.880 3836 4407 I AS.AudioService: onAccessoryPlugMediaUnmute newDevice=128 [bt_a2dp] 04-07 14:39:10.888 4478 4694 I vol.Events: writeEvent active_stream_changed STREAM_MUSIC 04-07 14:39:10.890 3836 4779 D AS.AudioService: forceVolumeControlStream(3) 04-07 14:39:10.907 3836 8435 E WindowManager: App trying to use insecure INPUT_FEATURE_NO_INPUT_CHANNEL flag. Ignoring 04-07 14:39:10.914 4478 4478 I vol.Events: writeEvent show_dialog volume_changed keyguard=false 04-07 14:39:10.915 3836 8435 D AS.AudioService: Volume controller visible: true 04-07 14:39:10.951 3550 3656 I [Gralloc]: ddebug, pair (share_fd=85, user_hnd=7, ion_client=26) 04-07 14:39:10.952 4478 4768 I [Gralloc]: ddebug, pair (share_fd=81, user_hnd=1, ion_client=82) 04-07 14:39:10.966 3550 3656 I [Gralloc]: ddebug, pair (share_fd=91, user_hnd=8, ion_client=26) 04-07 14:39:10.969 3550 3656 I [Gralloc]: ddebug, pair (share_fd=94, user_hnd=9, ion_client=26) 04-07 14:39:11.000 3557 8398 D BOXKEY-STDVB: [DEVICE 0] ++ DEMUX_FeedData feed delay gap(48) > 10ms) 04-07 14:39:11.000 3557 8398 D BOXKEY-STDVB: [DEVICE 0] ++ feed delay gap(48838) > BUFFERING_DURATION(20000) 04-07 14:39:11.000 3557 8398 D BOXKEY-STDVB: [DEVICE 0] ++ remain buffer size : 2632 04-07 14:39:11.022 4458 5041 I bt_stack: [INFO:btsnoop.cc(323)] clear_l2cap_whitelist: Clearing whitelist from l2cap channel. conn_handle=11 cid=77:706 04-07 14:39:11.022 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:39:11.022 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:39:11.022 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:39:11.022 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:39:11.022 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:39:11.023 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:39:11.023 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:39:11.023 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:39:11.023 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:39:11.023 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:39:11.023 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:39:11.025 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:39:11.025 4458 5041 I bt_bta_av: bta_av_link_role_ok: peer 00:42:79:a0:ec:50 hndl:0x41 role:1 conn_audio:0x1 bits:1 features:0x865b 04-07 14:39:11.025 4458 5041 W bt_btif : bta_dm_rm_cback:1, status:0 04-07 14:39:11.025 4458 5041 W bt_btif : bta_dm_rm_cback:2, status:7 04-07 14:39:11.025 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:39:11.026 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:0xf3119cb8 04-07 14:39:11.026 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:39:11.026 4458 5041 I bt_btif_a2dp_source: btif_a2dp_source_start_audio_req: state=STATE_RUNNING 04-07 14:39:11.026 4458 5041 I bt_stack: [INFO:a2dp_encoding.cc(683)] ack_stream_started: result=SUCCESS_FINISHED 04-07 14:39:11.026 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:39:11.026 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_feeding_reset: PCM bytes per tick 3840 04-07 14:39:11.026 3486 3782 I BTAudioProviderStub: streamStarted - SessionType=A2DP_SOFTWARE_ENCODING_DATAPATH, status=SUCCESS 04-07 14:39:11.026 3486 3782 I BTAudioProviderSession: ReportControlStatus - status=SUCCESS for SessionType=A2DP_SOFTWARE_ENCODING_DATAPATH, bluetooth_audio=0x0100 started 04-07 14:39:11.026 3486 3773 D A2DPHW : BluetoothAudioPortOut::Start: state=3, ret=1 04-07 14:39:11.026 3486 3773 I aml_audio_port: get_inport_message(), msg: MSG_PAUSE 04-07 14:39:11.026 3486 3773 I amlaudioMixer: process_port_msg(), msg: MSG_PAUSE 04-07 14:39:11.026 3486 3773 I amlaudioMixer: [mixer_inports_read:750] output port:[1]PCM_DIRECT fade out, pausing->pausing_1, tsync pause audio 04-07 14:39:11.026 3486 3773 I audio_hwsync: aml_hwsync_set_tsync_pause(), send pause event 04-07 14:39:11.026 4458 5041 I btif_av : btif_report_audio_state: peer_address=00:42:79:a0:ec:50 state=2 04-07 14:39:11.026 3486 3773 I audio_hw_utils: do fade out done,size 1536 04-07 14:39:11.026 3486 3773 E audio_virtual_buf: mixer_16bit_thread underrun happens read=170186900747 write=169936000000 diff=250900747 04-07 14:39:11.027 3486 8424 I amlaudioMixer: [mixer_write_inport:334] input port:[1]PCM_DIRECT is active now 04-07 14:39:11.027 4458 4536 I BluetoothA2dpServiceJni: bta2dp_audio_state_callback 04-07 14:39:11.028 3557 8423 I HalAudioOutput: high priority work:0x8000000a 04-07 14:39:11.028 3557 8423 I HalAudioOutput: resample thread flush... 04-07 14:39:11.028 3557 8423 I HalAudioOutput: resample thread flush finished! 04-07 14:39:11.028 4458 4536 D A2dpNativeInterface: onAudioStateChanged: A2dpStackEvent {type:EVENT_TYPE_AUDIO_STATE_CHANGED, device:00:42:79:A0:EC:50, value1:STARTED} 04-07 14:39:11.028 3557 8423 I HalAudioOutput: resample thread pause! 04-07 14:39:11.028 3486 3782 I audio-subMixingFactory: +out_flush_subMixingPCM(), stream 0xea7dde00, standby 0, pause status 1, usecase: [1]PCM_DIRECT 04-07 14:39:11.028 3486 3782 I audio-subMixingFactory: -out_flush_subMixingPCM() 04-07 14:39:11.029 4458 5062 D A2dpStateMachine: handleMessage: E msg.what=101 04-07 14:39:11.029 4458 5062 D A2dpStateMachine: processMsg: Connected 04-07 14:39:11.029 4458 5062 D A2dpStateMachine: Connected process message(00:42:79:A0:EC:50): STACK_EVENT 04-07 14:39:11.029 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:39:11.029 4458 5062 I A2dpStateMachine: Connected: started playing: 00:42:79:A0:EC:50 04-07 14:39:11.029 4458 5062 D A2dpStateMachine: A2DP Playing state : device: 00:42:79:A0:EC:50 State:NOT_PLAYING->PLAYING 04-07 14:39:11.029 3557 8410 D HalAudioOutput: [~HalAudioOutput:63] 04-07 14:39:11.030 3486 3486 D audio_hw_primary: adev_set_parameters(0xea775280, hal_audio_state=off) 04-07 14:39:11.030 3486 3486 I audio_hw_primary: adev_set_parameters(kv: hal_audio_state=off) 04-07 14:39:11.030 3486 3486 I audio_hw_primary: adev_set_parameters, ret=3, value=off 04-07 14:39:11.030 3486 3486 I audio_hw_primary: adev_set_parameters, value=off, adev->hal_audio_open_times=0 04-07 14:39:11.030 3486 3486 I audio_hw_primary: Amlogic_HAL - adev_set_parameters: return 0 instead of length of data be copied. 04-07 14:39:11.030 3557 8410 I AmlAudioOutPort: setParameters:hal_audio_state=off, err=0 04-07 14:39:11.030 3557 8410 I HalAudioOutput: resample thread exiting... 04-07 14:39:11.030 3557 8423 I HalAudioOutput: high priority work:0x1 04-07 14:39:11.030 3557 8423 I HalAudioOutput: quit resample thread exit! 04-07 14:39:11.030 3557 8410 I HalAudioOutput: resample thread exited! 04-07 14:39:11.031 3557 8410 D HalAudioOutput: [~HalAudioOutput:72], exit 04-07 14:39:11.031 4458 5062 D A2dpStateMachine: handleMessage: X 04-07 14:39:11.032 3557 8410 D MiniAudioSink: [~MiniAudioSink:78] 04-07 14:39:11.032 3557 8410 I LivePlayerRenderer_0: mAudioFormat_E:0x1 mPassthroughSetting:0, mime:audio/raw, mime_in:audio/mp4a-latm 04-07 14:39:11.032 3557 8410 I LivePlayerRenderer_0: doPassthrough: mPassthroughSetting=0, mime_in=audio/mp4a-latm 04-07 14:39:11.032 3557 8410 W MiniAudioSink: [getMinFrameCount:225] not implemented! 04-07 14:39:11.032 3557 8410 I LivePlayerRenderer_0: getMinFrameCount:2052 04-07 14:39:11.032 3557 8410 I LivePlayerRenderer_0: live play framecount times 1.1 04-07 14:39:11.032 3557 8410 E LivePlayerRenderer_0: create AudioTrack, sampleRate:48000, channelCount:2, outputFlags:0x1, frameCount:2257, mAudioPaused=0 04-07 14:39:11.032 3557 8410 D MiniAudioSink: mSampleSize:2, mChannelCount:2, mSampleRate:48000 04-07 14:39:11.032 3557 8410 I HalAudioOutput: Fifo_Size:0x4000 04-07 14:39:11.032 3557 8410 D HalAudioOutput: [HalAudioOutput:53] flags:0x1, mOutSampleRate=48000 04-07 14:39:11.033 3486 3486 D audio_hw_primary: adev_close_output_stream_new: enter usecase = [1]PCM_DIRECT 04-07 14:39:11.033 3486 3486 I audio-subMixingFactory: ++deleteSubMixingInput() 04-07 14:39:11.033 3486 3486 I audio-subMixingFactory: deleteSubMixingInputPcm(), cnt_stream_using_mixer 0 04-07 14:39:11.033 3486 3486 D audio_hw_primary: adev_close_output_stream: enter: dev(0xea775280) stream(0xea7dde00) 04-07 14:39:11.033 3486 3486 D audio-subMixingFactory: out_standby_subMixingPCM: out_stream(0xea7dde00) usecase: [1]PCM_DIRECT 04-07 14:39:11.033 3486 3486 I audio-subMixingFactory: [usecase_change_validate_l_sm:1290] cur dev masks:0x2, delete out usecase:[1]PCM_DIRECT 04-07 14:39:11.033 3486 3486 I audio-subMixingFactory: usecase_change_validate_l_sm(), standby unmask usecase [1]PCM_DIRECT 04-07 14:39:11.033 3486 3486 I amlaudioMixer: [delete_mixer_input_port:187] input port:0 04-07 14:39:11.033 3486 3486 I aml_audio_port: remove_all_inport_messages(), msg what MSG_FLUSH 04-07 14:39:11.033 3486 3486 D a2dp_hal: a2dp_out_standby: state=3 04-07 14:39:11.033 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:39:11.034 4458 4863 I bt_stack: [INFO:a2dp_encoding.cc(125)] SuspendRequest: accepted 04-07 14:39:11.034 4458 4863 I btif_av : btif_av_stream_suspend 04-07 14:39:11.035 3486 3773 D aml_audio_port: output_port_write_alsa() alsa underrun 04-07 14:39:11.035 3486 3773 I aml_audio_port: restart pcm device for same src 04-07 14:39:11.035 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:39:11.035 4458 5041 I bt_btif_a2dp_source: btif_a2dp_source_set_tx_flush: enable=true state=STATE_RUNNING 04-07 14:39:11.035 4458 5041 I bt_bta_av: BTA_AvStop: handle=65 suspend=true 04-07 14:39:11.035 4458 5041 E bt_btif : bta_av_str_stopped: peer 00:42:79:a0:ec:50 handle:65 audio_open_cnt:1, p_data 0xe945cba8 start:1 04-07 14:39:11.035 4458 5041 W bt_btif : bta_dm_rm_cback:2, status:6 04-07 14:39:11.037 3231 3231 I hwservicemanager: getTransport: Cannot find entry android.hardware.audio@5.0::IDevicesFactory/msd in either framework or device manifest. 04-07 14:39:11.037 3557 8410 I AmlAudioOutPort: get DevicesFactoryHal sucess 04-07 14:39:11.038 3486 3782 D audio_hw_primary: adev_open: enter 04-07 14:39:11.038 3486 3782 I audio_hw_primary: adev exsits ,reuse 04-07 14:39:11.038 3486 3782 I audio_hw_primary: *adev_open, device:0xea775280, debug_flag=0, adev->count=6 04-07 14:39:11.038 3486 3782 D audio_hw_primary: adev_open: exit, error 04-07 14:39:11.039 3557 8410 I AmlAudioOutPort: get hwDevice success 04-07 14:39:11.039 3557 8410 I AmlAudioOutPort: hwDevice init check success 04-07 14:39:11.039 3486 3587 D audio_hw_primary: adev_open_output_stream_new: enter 04-07 14:39:11.039 3486 3587 D audio_hw_primary: adev_open_output_stream: enter: devices(0x400) channel_mask(0x3) rate(48000) format(0x1) flags(0x1) 04-07 14:39:11.040 3486 3587 I audio_hwsync: aml_audio_hwsync_init open tsync fd 24 04-07 14:39:11.040 3486 3587 I audio_hwsync: aml_audio_hwsync_init done 04-07 14:39:11.040 3486 3587 D audio_hw_primary: adev_open_output_stream: exit 04-07 14:39:11.040 3486 3587 D audio_hw_profile: get_hdmi_sink_cap is running... 04-07 14:39:11.040 3486 3587 D audio_hw_profile: query hdmi format... 04-07 14:39:11.040 3486 3587 I audio_hw_primary: get_sink_capability mbox+dvb case sink_capability = 0x1 04-07 14:39:11.040 3486 3587 D audio_hw_primary: get_sink_format: a2dp set to pcm 04-07 14:39:11.040 3486 3587 I audio-subMixingFactory: ++initSubMixingInput() 04-07 14:39:11.040 3486 3587 I audio-subMixingFactory: ++initSubMixingInputPcm(), out 0xea7de500, flags 0x1, hwsync lpcm 0, out format 0x1 04-07 14:39:11.077 4458 5063 W bt_stack: [WARNING:client_interface.cc(464)] ReadAudioData: 512/512 no data 10 ms 04-07 14:39:11.077 4458 5063 W bt_btif_a2dp_source: btif_a2dp_source_read_callback: UNDERFLOW: ONLY READ 0 BYTES OUT OF 512 04-07 14:39:11.077 4458 5063 W a2dp_sbc_encoder: a2dp_sbc_encode_frames: underflow 2, 0 04-07 14:39:11.089 4458 4536 D AvrcpTargetJni: volumeDeviceConnected 04-07 14:39:11.089 3498 3498 I [Gralloc]: ddebug, pair (share_fd=61, user_hnd=7, ion_client=31) 04-07 14:39:11.089 4458 4536 D AvrcpNativeInterface: deviceConnected: device=00:42:79:A0:EC:50 absoluteVolume=true 04-07 14:39:11.090 4458 4536 I AvrcpTargetService: deviceConnected: device=00:42:79:A0:EC:50 absoluteVolume=true 04-07 14:39:11.090 4458 4536 D AvrcpVolumeManager: deviceConnected: device=00:42:79:A0:EC:50 absoluteVolume=true 04-07 14:39:11.090 4458 4536 D AvrcpVolumeManager: switchVolumeDevice: Set Absolute volume support to true 04-07 14:39:11.090 4458 4536 D AvrcpVolumeManager: getVolume: Returning volume 5 04-07 14:39:11.090 4458 4536 D AvrcpVolumeManager: switchVolumeDevice: savedVolume=5 04-07 14:39:11.091 4458 4536 I AvrcpVolumeManager: switchVolumeDevice: Updating device volume: avrcpVolume=19 04-07 14:39:11.091 4458 4536 D AvrcpNativeInterface: sendVolumeChanged: volume=19 04-07 14:39:11.091 4458 4536 D AvrcpTargetJni: sendVolumeChangedNative 04-07 14:39:11.091 3836 8435 I AS.BtHelper: setAvrcpAbsoluteVolumeSupported supported=true 04-07 14:39:11.092 4458 4536 D AvrcpTargetJni: getCurrentPlayStatus 04-07 14:39:11.092 4458 4536 D AvrcpNativeInterface: getPlayStatus 04-07 14:39:11.092 3521 3521 I APM_AudioPolicyManager: setStreamVolumeIndex: set_btv_media_volume index: 32 04-07 14:39:11.092 3521 3521 I APM_AudioPolicyManager: setStreamVolumeIndex: set_btv_media_volume mExtMute: 0 04-07 14:39:11.093 3521 3521 I APM_AudioPolicyManager: setStreamVolumeIndex: set_btv_media_volume stream : 3 volume_index : 32 gain : 0.000004 04-07 14:39:11.094 3557 3781 D BTV_HAL_MGR.001: [useSpeakerVolumePath] useSpeakerVolumePath : false 04-07 14:39:11.094 3557 3781 E AudioMixer: BTF|AMIXER_SetAudioVolume|74|IN| amixer=e37bf050 volume=32 gain=0.000004 04-07 14:39:11.095 3557 3781 E AudioMixer: BTF|setMasterAudioVolumeIntoFile|172|IN| save volume:100.000000 ,volumeIndex : 32 04-07 14:39:11.095 3557 3781 E halMediaPlayer: BTF|setAudioVolume|766|IN| volume:100.000000 04-07 14:39:11.095 3557 3781 E halMediaPlayer: BTF|player_SetAudioVolume|716|IN| player=e7f074a0 volume=100.000000 04-07 14:39:11.095 3557 3781 D AmlHalPlayerImpl_0: SetVolume[0] volume = 100.000000 04-07 14:39:11.095 3557 3781 I LivePlayer_0: [setVolume:697] setVolume: 1.00 04-07 14:39:11.095 3557 3781 E halMediaPlayer: BTF|player_SetAudioVolume|726|OUT| 04-07 14:39:11.095 3557 3781 E halMediaPlayer: BTF|setAudioVolume|774| error setting! player:0, i:1, mState:0 04-07 14:39:11.095 3557 3781 E halMediaPlayer: BTF|setAudioVolume|779|OUT| 04-07 14:39:11.095 3557 3781 E AudioMixer: BTF|AMIXER_SetAudioVolume|86|OUT|vol:1.000000 04-07 14:39:11.096 4458 5041 W bt_btif : bta_dm_rm_cback:2, status:6 04-07 14:39:11.096 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:39:11.096 4458 5041 I bt_btif_a2dp: btif_a2dp_on_suspended: ## ON A2DP SUSPENDED ## p_av_suspend=0xf3119e48 04-07 14:39:11.096 4458 5041 I bt_btif_a2dp_source: btif_a2dp_source_on_suspended: state=STATE_RUNNING 04-07 14:39:11.096 4458 5041 I bt_btif_a2dp_source: btif_a2dp_source_stop_audio_req: state=STATE_RUNNING 04-07 14:39:11.096 4458 5041 I btif_av : btif_report_audio_state: peer_address=00:42:79:a0:ec:50 state=1 04-07 14:39:11.096 3521 3521 D BtvMediaVolumeControlLib: status : 0 04-07 14:39:11.096 4458 4536 I BluetoothA2dpServiceJni: bta2dp_audio_state_callback 04-07 14:39:11.096 4458 4536 D A2dpNativeInterface: onAudioStateChanged: A2dpStackEvent {type:EVENT_TYPE_AUDIO_STATE_CHANGED, device:00:42:79:A0:EC:50, value1:STOPPED} 04-07 14:39:11.097 4458 5063 W bt_stack: [WARNING:client_interface.cc(464)] ReadAudioData: 512/512 no data 10 ms 04-07 14:39:11.097 4458 5063 W bt_btif_a2dp_source: btif_a2dp_source_read_callback: UNDERFLOW: ONLY READ 0 BYTES OUT OF 512 04-07 14:39:11.097 4458 5063 W a2dp_sbc_encoder: a2dp_sbc_encode_frames: underflow 10, 0 04-07 14:39:11.097 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:39:11.097 4458 5062 D A2dpStateMachine: handleMessage: E msg.what=101 04-07 14:39:11.098 4458 5062 D A2dpStateMachine: processMsg: Connected 04-07 14:39:11.098 4458 5062 D A2dpStateMachine: Connected process message(00:42:79:A0:EC:50): STACK_EVENT 04-07 14:39:11.098 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:39:11.098 4458 5062 I A2dpStateMachine: Connected: stopped playing: 00:42:79:A0:EC:50 04-07 14:39:11.098 4458 5062 D A2dpStateMachine: A2DP Playing state : device: 00:42:79:A0:EC:50 State:PLAYING->NOT_PLAYING 04-07 14:39:11.099 4458 5062 D A2dpStateMachine: handleMessage: X 04-07 14:39:11.108 4458 5063 W bt_stack: [WARNING:client_interface.cc(464)] ReadAudioData: 28672/28672 no data 10 ms 04-07 14:39:11.108 4458 5063 I bt_stack: [INFO:a2dp_encoding.cc(699)] ack_stream_suspended: result=SUCCESS_FINISHED 04-07 14:39:11.108 3486 3782 I BTAudioProviderStub: streamSuspended - SessionType=A2DP_SOFTWARE_ENCODING_DATAPATH, status=SUCCESS 04-07 14:39:11.108 3486 3782 I BTAudioProviderSession: ReportControlStatus - status=SUCCESS for SessionType=A2DP_SOFTWARE_ENCODING_DATAPATH, bluetooth_audio=0x0100 suspended 04-07 14:39:11.109 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_feeding_reset: PCM bytes per tick 3840 04-07 14:39:11.109 3486 3486 D A2DPHW : BluetoothAudioPortOut::Suspend state=1, retval=1 04-07 14:39:11.109 3486 3486 I audio_hwsync: aml_audio_hwsync_release done 04-07 14:39:11.109 3486 3486 D audio_hw_primary: adev_close_output_stream: exit 04-07 14:39:11.109 3486 3486 D audio_hw_primary: adev_close_output_stream_new: exit 04-07 14:39:11.109 3486 3486 D audio_hw_primary: adev_close: enter, adev=0xea775280, g_adev = 0xea775280, adev->count=5 04-07 14:39:11.109 3486 3486 I audio_hw_primary: adev_close, test============, not enter adev_close 04-07 14:39:11.110 3486 3587 D audio_hw_primary: -adev_open_output_stream_new: out 0xea7de500: usecase:[1]PCM_DIRECT card:0 alsa devices:0 04-07 14:39:11.112 3557 8410 I AmlAudioOutPort: AudioStreamOut::open(), HAL returned stream 0xe7f270d0, sampleRate 48000, Format 0x1, channelMask 0x3, status 0 04-07 14:39:11.112 3557 8410 I AmlAudioOutPort: get outStream success 04-07 14:39:11.113 3486 3587 D audio_hw_primary: adev_set_parameters(0xea775280, hal_audio_state=on) 04-07 14:39:11.113 3486 3587 I audio_hw_primary: adev_set_parameters(kv: hal_audio_state=on) 04-07 14:39:11.113 3486 3587 I audio_hw_primary: adev_set_parameters, ret=2, value=on 04-07 14:39:11.113 3486 3587 I audio_hw_primary: adev_set_parameters, value=on, adev->hal_audio_open_times=1 04-07 14:39:11.113 3486 3587 I audio_hw_primary: Amlogic_HAL - adev_set_parameters: return 0 instead of length of data be copied. 04-07 14:39:11.113 4458 4536 D AvrcpTargetJni: getCurrentPlayStatus 04-07 14:39:11.113 4458 4536 D AvrcpNativeInterface: getPlayStatus 04-07 14:39:11.113 3557 8410 I AmlAudioOutPort: setParameters:hal_audio_state=on, err=0 04-07 14:39:11.113 3486 3587 I audio_hw_primary: out_set_volume(), stream(0xea7de500), left:0.031010 right:0.031010 04-07 14:39:11.113 3557 8410 I MiniAudioSink: setmute:0 04-07 14:39:11.114 3557 8410 I LivePlayerRenderer_0: audioSink started!, mAudioSink:0xddcac2c0 04-07 14:39:11.115 3557 8410 I LivePlayerRenderer_0: current audiosink position:0 04-07 14:39:11.115 3557 8503 I HalAudioOutput: openSonicStream:345, rate:1.00 04-07 14:39:11.115 3486 3587 I audio_hw_primary: out_set_volume(), stream(0xea7de500), left:0.001879 right:0.001879 04-07 14:39:11.116 3557 8410 I RendererPolicyBase_0: drop kUnknownPTS audio frame!, mBufferOrdinal:1734 04-07 14:39:11.116 3557 8410 I RendererPolicyBase_0: drop kUnknownPTS audio frame!, mBufferOrdinal:1735 04-07 14:39:11.116 3486 3587 I audio_hw_primary: out_get_buffer_size(out->config.rate=48000, format 1,stream format 1) 04-07 14:39:11.118 3557 8410 I RendererPolicyBase_0: set_audioStrategy: AUDIO_STRATEGY_NONE ==> AUDIO_STRATEGY_SILENT, diffUs:-193.935000 ms 04-07 14:39:11.118 3486 3587 I audio_hw_primary: out_set_volume(), stream(0xea7de500), left:1.000000 right:1.000000 04-07 14:39:11.122 3486 8504 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:39:11.123 3486 8504 I audio-subMixingFactory: usecase_change_validate_l_sm(), add usecase [1]PCM_DIRECT, cnt 1 04-07 14:39:11.123 3486 8504 D audio-subMixingFactory: [usecase_change_validate_l_sm:1347] cur dev masks:0, add out usecase:[1]PCM_DIRECT 04-07 14:39:11.123 3486 8504 I audio-subMixingFactory: usecase_change_validate_l_sm(), mixer_main_buffer_write_sm ! 04-07 14:39:11.123 3486 8504 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:39:11.123 3486 8504 D audio-subMixingFactory: [mixer_main_buffer_write_sm:1099] stream:0xea7de500, switch from device:0x480 to device:0x400 04-07 14:39:11.123 3486 8504 I aml_audio_port: get_input_port_type(), samplerate 48000 04-07 14:39:11.123 3486 8504 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:39:11.124 3486 8504 I amlaudioMixer: [init_mixer_input_port:166] input port:[1]PCM_DIRECT, size 384 frames, frame_write_sum:0 04-07 14:39:11.124 3486 8504 I aml_audio_port: get_input_port_type(), samplerate 48000 04-07 14:39:11.124 3486 8504 I audio-subMixingFactory: [out_write_direct_pcm:554] direct port:[1]PCM_DIRECT 04-07 14:39:11.124 3486 8504 I amlaudioMixer: [mixer_write_inport:334] input port:[1]PCM_DIRECT is active now 04-07 14:39:11.131 3486 3773 D a2dp_hal: a2dp_out_write_new: state=1 04-07 14:39:11.131 4458 4863 I btif_av : btif_av_stream_ready: Peer 00:42:79:a0:ec:50 : state=2, flags=0x0(None) 04-07 14:39:11.131 4458 4863 I btif_av : btif_av_stream_start 04-07 14:39:11.131 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:39:11.131 4458 4863 I bt_stack: [INFO:a2dp_encoding.cc(99)] StartRequest: accepted 04-07 14:39:11.131 4458 5041 I bt_bta_av: BTA_AvStart: handle=65 04-07 14:39:11.131 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:39:11.131 4458 5041 W bt_btif : bta_dm_rm_cback:2, status:7 04-07 14:39:11.132 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:39:11.167 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:39:11.167 4458 5041 I bt_bta_av: bta_av_link_role_ok: peer 00:42:79:a0:ec:50 hndl:0x41 role:1 conn_audio:0x1 bits:1 features:0x865b 04-07 14:39:11.167 4458 5041 W bt_btif : bta_dm_rm_cback:2, status:0 04-07 14:39:11.167 4458 5041 W bt_btif : bta_dm_rm_cback:2, status:7 04-07 14:39:11.167 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:39:11.167 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:0xf3119d30 04-07 14:39:11.167 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:39:11.167 4458 5041 I bt_btif_a2dp_source: btif_a2dp_source_start_audio_req: state=STATE_RUNNING 04-07 14:39:11.167 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:39:11.167 4458 5041 I bt_stack: [INFO:a2dp_encoding.cc(683)] ack_stream_started: result=SUCCESS_FINISHED 04-07 14:39:11.167 4458 5063 D a2dp_sbc_encoder: a2dp_sbc_feeding_reset: PCM bytes per tick 3840 04-07 14:39:11.168 3486 3486 I BTAudioProviderStub: streamStarted - SessionType=A2DP_SOFTWARE_ENCODING_DATAPATH, status=SUCCESS 04-07 14:39:11.168 3486 3486 I BTAudioProviderSession: ReportControlStatus - status=SUCCESS for SessionType=A2DP_SOFTWARE_ENCODING_DATAPATH, bluetooth_audio=0x0100 started 04-07 14:39:11.168 3486 3773 D A2DPHW : BluetoothAudioPortOut::Start: state=3, ret=1 04-07 14:39:11.168 4458 5041 I btif_av : btif_report_audio_state: peer_address=00:42:79:a0:ec:50 state=2 04-07 14:39:11.169 4458 4536 I BluetoothA2dpServiceJni: bta2dp_audio_state_callback 04-07 14:39:11.169 4458 4536 D A2dpNativeInterface: onAudioStateChanged: A2dpStackEvent {type:EVENT_TYPE_AUDIO_STATE_CHANGED, device:00:42:79:A0:EC:50, value1:STARTED} 04-07 14:39:11.169 4458 5062 D A2dpStateMachine: handleMessage: E msg.what=101 04-07 14:39:11.169 4458 5062 D A2dpStateMachine: processMsg: Connected 04-07 14:39:11.170 4458 5062 D A2dpStateMachine: Connected process message(00:42:79:A0:EC:50): STACK_EVENT 04-07 14:39:11.170 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:39:11.170 4458 5062 I A2dpStateMachine: Connected: started playing: 00:42:79:A0:EC:50 04-07 14:39:11.170 4458 5062 D A2dpStateMachine: A2DP Playing state : device: 00:42:79:A0:EC:50 State:NOT_PLAYING->PLAYING 04-07 14:39:11.171 4458 5062 D A2dpStateMachine: handleMessage: X 04-07 14:39:11.192 3557 8410 I LivePlayerRenderer_0: audiosink get position success:4352 04-07 14:39:11.192 3557 8410 I RendererPolicyBase_0: audio later than 184.35 ms, mediaUs:46095.030020, mPassthroughSetting:0 04-07 14:39:11.192 3557 8410 I RendererPolicyBase_0: set_audioStrategy: AUDIO_STRATEGY_SILENT ==> AUDIO_STRATEGY_RESAMPLE, diffUs:-184.352000 ms 04-07 14:39:11.192 3557 8410 I RendererPolicyBase_0: audio late than 184.35 ms, adjust audio sink speed to 1.10, factor:0.10 04-07 14:39:11.192 3557 8410 I HalAudioOutput: playback rate changed:1.00 --> 1.10 04-07 14:39:11.213 3557 8503 I HalAudioOutput: high priority work:0x80000004 04-07 14:39:11.213 3557 8503 I HalAudioOutput: resample thread rate changed! 04-07 14:39:11.213 3557 8503 I HalAudioOutput: openSonicStream:345, rate:1.10 04-07 14:39:11.502 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:39:11.503 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:39:11.564 3557 3557 W HwBinder:3557_2: type=1400 audit(0.0:734): 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:39:11.571 3557 8391 E libc : Access denied finding property "skb.audio.output" 04-07 14:39:11.664 3557 8410 I RendererPolicyBase_0: set_audioStrategy: AUDIO_STRATEGY_RESAMPLE ==> AUDIO_STRATEGY_NONE, diffUs:-16.875000 ms 04-07 14:39:11.664 3557 8410 I RendererPolicyBase_0: restore audio sink speed from 1.10 to 1.00 04-07 14:39:11.664 3557 8410 I HalAudioOutput: playback rate changed:1.10 --> 1.00 04-07 14:39:11.677 3557 8503 I HalAudioOutput: high priority work:0x80000004 04-07 14:39:11.677 3557 8503 I HalAudioOutput: resample thread rate changed! 04-07 14:39:11.708 3557 8503 I HalAudioOutput: openSonicStream:345, rate:1.00 04-07 14:39:11.750 3557 8410 I RendererPolicyBase_0: set_audioStrategy: AUDIO_STRATEGY_NONE ==> AUDIO_STRATEGY_RESAMPLE, diffUs:-81.691000 ms 04-07 14:39:11.750 3557 8410 I RendererPolicyBase_0: audio late than 81.69 ms, adjust audio sink speed to 1.10, factor:0.10 04-07 14:39:11.750 3557 8410 I HalAudioOutput: playback rate changed:1.00 --> 1.10 04-07 14:39:11.753 3557 8503 I HalAudioOutput: high priority work:0x80000004 04-07 14:39:11.748 3486 3486 W ATVRemoteAudioH: type=1400 audit(0.0:735): avc: denied { call } for scontext=u:r:hal_audio_amlogic:s0 tcontext=u:r:rc_server:s0 tclass=binder permissive=0 04-07 14:39:11.753 3557 8503 I HalAudioOutput: resample thread rate changed! 04-07 14:39:11.753 3557 8503 I HalAudioOutput: openSonicStream:345, rate:1.10 04-07 14:39:11.753 7572 7572 D BtvBtPairingService: sptek:BT onConnectionStateChanged audio pairing ok handler 04-07 14:39:11.753 3486 3760 W ServiceManagement: getService: unable to call into hwbinder service for vendor.amlogic.hardware.remotecontrol@1.0::IRemoteControl/default. 04-07 14:39:11.803 3557 8410 I RendererPolicyBase_0: set_audioStrategy: AUDIO_STRATEGY_RESAMPLE ==> AUDIO_STRATEGY_NONE, diffUs:-6.459000 ms 04-07 14:39:11.803 3557 8410 I RendererPolicyBase_0: restore audio sink speed from 1.10 to 1.00 04-07 14:39:11.803 3557 8410 I HalAudioOutput: playback rate changed:1.10 --> 1.00 04-07 14:39:11.817 3557 8503 I HalAudioOutput: high priority work:0x80000004 04-07 14:39:11.817 3557 8503 I HalAudioOutput: resample thread rate changed! 04-07 14:39:11.839 3557 8503 I HalAudioOutput: openSonicStream:345, rate:1.00 04-07 14:39:11.868 4458 5063 W bt_btif_a2dp_source: btif_a2dp_source_enqueue_callback: TX queue buffer size now=22 adding=8 max=28 04-07 14:39:11.870 4458 5041 W bt_btif_a2dp_source: btm_read_rssi_cb: device: 00:42:79:a0:ec:50, rssi: 0 04-07 14:39:11.870 4458 5041 W bt_btif_a2dp_source: btm_read_failed_contact_counter_cb: device: 00:42:79:a0:ec:50, Failed Contact Counter: 0 04-07 14:39:11.871 4458 5041 W bt_btif_a2dp_source: btm_read_automatic_flush_timeout_cb: device: 00:42:79:a0:ec:50, Automatic Flush Timeout: 0 04-07 14:39:11.872 4458 5041 W bt_btif_a2dp_source: btm_read_tx_power_cb: device: 00:42:79:a0:ec:50, Tx Power: 12 04-07 14:39:11.932 3557 8410 I RendererPolicyBase_0: set_audioStrategy: AUDIO_STRATEGY_NONE ==> AUDIO_STRATEGY_RESAMPLE, diffUs:-71.126000 ms 04-07 14:39:11.932 3557 8410 I RendererPolicyBase_0: audio late than 71.13 ms, adjust audio sink speed to 1.10, factor:0.10 04-07 14:39:11.932 3557 8410 I HalAudioOutput: playback rate changed:1.00 --> 1.10 04-07 14:39:11.935 3557 8503 I HalAudioOutput: high priority work:0x80000004 04-07 14:39:11.935 3557 8503 I HalAudioOutput: resample thread rate changed! 04-07 14:39:11.935 3557 8503 I HalAudioOutput: openSonicStream:345, rate:1.10 04-07 14:39:11.975 3557 8410 I RendererPolicyBase_0: set_audioStrategy: AUDIO_STRATEGY_RESAMPLE ==> AUDIO_STRATEGY_NONE, diffUs:-7.951000 ms 04-07 14:39:11.975 3557 8410 I RendererPolicyBase_0: restore audio sink speed from 1.10 to 1.00 04-07 14:39:11.975 3557 8410 I HalAudioOutput: playback rate changed:1.10 --> 1.00 04-07 14:39:11.989 3557 8503 I HalAudioOutput: high priority work:0x80000004 04-07 14:39:11.989 3557 8503 I HalAudioOutput: resample thread rate changed! 04-07 14:39:11.997 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:39:12.001 3557 8398 D BOXKEY-STDVB: [DEVICE 0] ++ remain buffer size : 39480 04-07 14:39:12.002 3505 3505 D memtrack_aml: type:0 for pid:7596, size_up_to:0 04-07 14:39:12.003 3505 3505 D memtrack_aml: type:1 for pid:7596, size_up_to:0 04-07 14:39:12.008 3505 3505 D memtrack_aml: type:2 for pid:7596, size_up_to:0 04-07 14:39:12.011 3557 8503 I HalAudioOutput: openSonicStream:345, rate:1.00 04-07 14:39:12.015 3836 4403 W TelecomManager: Telecom Service not found. 04-07 14:39:12.019 3836 4403 W TelecomManager: Telecom Service not found. 04-07 14:39:12.027 3836 3836 W TelecomManager: Telecom Service not found. 04-07 14:39:12.030 3836 3836 W TelecomManager: Telecom Service not found. 04-07 14:39:12.037 5311 5311 I TvNotificationListenerService: onNotificationPosted() 04-07 14:39:12.053 5311 7190 I TvNotificationManager: getNotificationCount() count : 1 04-07 14:39:12.168 3528 3528 D isqmsAgent: INFO: NET make_holepunching_msg 04-07 14:39:12.168 3528 3528 D isqmsAgent: INFO: NET make_holepunching_msg HTYPE_KEEP_ALIVE pszTemp2=;0; ; ; ; ; ; 04-07 14:39:12.168 3528 3528 D isqmsAgent: INFO: NET make_holepunching_msg HTYPE_KEEP_ALIVE pszIP=0 04-07 14:39:12.168 3528 3528 D isqmsAgent: INFO: NET make_holepunching_msg HTYPE_KEEP_ALIVE pszIP= 04-07 14:39:12.168 3528 3528 D isqmsAgent: INFO: NET make_holepunching_msg HTYPE_KEEP_ALIVE this->szSTBIP= 04-07 14:39:12.168 3528 3528 D isqmsAgent: m_HPServerInfo.nPort = 30812 04-07 14:39:12.168 3528 3528 D isqmsAgent: pData = SEQ=3 04-07 14:39:12.168 3528 3528 D isqmsAgent: T=KEEP-ALIVE 04-07 14:39:12.168 3528 3528 D isqmsAgent: STB_ID=C92B070B-72C3-11E9-A51A-61AC1B87CDDD 04-07 14:39:12.168 3528 3528 D isqmsAgent: STB_MAC=ec5c681dbc67 04-07 14:39:12.168 3528 3528 D isqmsAgent: STB_IP= 04-07 14:39:12.168 3528 3528 D isqmsAgent: 04-07 14:39:12.168 3528 3528 D isqmsAgent: [isqmsAgent 0162 04/07 14:39:12:168][3528] CISQMSSchedule::SCHETYPE_CYCLE event_id=H01 04-07 14:39:12.388 4458 5063 W bt_btif_a2dp_source: btif_a2dp_source_enqueue_callback: TX queue buffer size now=22 adding=8 max=28 04-07 14:39:12.390 4458 5041 W bt_btif_a2dp_source: btm_read_rssi_cb: device: 00:42:79:a0:ec:50, rssi: 0 04-07 14:39:12.391 4458 5041 W bt_btif_a2dp_source: btm_read_failed_contact_counter_cb: device: 00:42:79:a0:ec:50, Failed Contact Counter: 0 04-07 14:39:12.393 4458 5041 W bt_btif_a2dp_source: btm_read_automatic_flush_timeout_cb: device: 00:42:79:a0:ec:50, Automatic Flush Timeout: 0 04-07 14:39:12.395 4458 5041 W bt_btif_a2dp_source: btm_read_tx_power_cb: device: 00:42:79:a0:ec:50, Tx Power: 12 04-07 14:39:12.413 3557 8410 I RendererPolicyBase_0: audio later than 83.54 ms, mediaUs:46096.352355, mPassthroughSetting:0 04-07 14:39:12.413 3557 8410 I RendererPolicyBase_0: set_audioStrategy: AUDIO_STRATEGY_NONE ==> AUDIO_STRATEGY_RESAMPLE, diffUs:-83.540000 ms 04-07 14:39:12.413 3557 8410 I RendererPolicyBase_0: audio late than 83.54 ms, adjust audio sink speed to 1.10, factor:0.10 04-07 14:39:12.414 3557 8410 I HalAudioOutput: playback rate changed:1.00 --> 1.10 04-07 14:39:12.417 3557 8503 I HalAudioOutput: high priority work:0x80000004 04-07 14:39:12.417 3557 8503 I HalAudioOutput: resample thread rate changed! 04-07 14:39:12.417 3557 8503 I HalAudioOutput: openSonicStream:345, rate:1.10 04-07 14:39:12.463 3557 8410 I RendererPolicyBase_0: set_audioStrategy: AUDIO_STRATEGY_RESAMPLE ==> AUDIO_STRATEGY_NONE, diffUs:-5.049000 ms 04-07 14:39:12.463 3557 8410 I RendererPolicyBase_0: restore audio sink speed from 1.10 to 1.00 04-07 14:39:12.463 3557 8410 I HalAudioOutput: playback rate changed:1.10 --> 1.00 04-07 14:39:12.484 3557 8503 I HalAudioOutput: high priority work:0x80000004 04-07 14:39:12.484 3557 8503 I HalAudioOutput: resample thread rate changed! 04-07 14:39:12.484 3557 8503 I HalAudioOutput: openSonicStream:345, rate:1.00 04-07 14:39:12.564 3557 3557 W HwBinder:3557_2: type=1400 audit(0.0:736): 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:39:12.570 3557 8391 E libc : Access denied finding property "skb.audio.output" 04-07 14:39:12.626 3557 8407 W RendererPolicyBase_0: video render: 59.94 fps, drop: 0.00 fps 04-07 14:39:12.756 3486 3760 W ServiceManagement: getService: unable to call into hwbinder service for vendor.amlogic.hardware.remotecontrol@1.0::IRemoteControl/default. 04-07 14:39:12.752 3486 3486 W ATVRemoteAudioH: type=1400 audit(0.0:737): avc: denied { call } for scontext=u:r:hal_audio_amlogic:s0 tcontext=u:r:rc_server:s0 tclass=binder permissive=0 04-07 14:39:12.783 3545 5045 I SKB_NAVIGATOR: 04-07 14:39:12.783 3545 5045 eit-s: S_COMPLETED: 1 04-07 14:39:12.783 3545 3614 I SKB_NAVIGATOR: 04-07 14:39:12.783 3545 3614 [dvbsi_getBulkEPGAll] start 04-07 14:39:12.784 3545 3614 I SKB_NAVIGATOR: 04-07 14:39:12.784 3545 3614 [open_database] open_database ret : 0 04-07 14:39:12.790 3545 5045 I SKB_NAVIGATOR: 04-07 14:39:12.790 3545 5045 serviceId: 825 firstClearEitInfo = 0 04-07 14:39:12.908 4458 5063 W bt_btif_a2dp_source: btif_a2dp_source_enqueue_callback: TX queue buffer size now=22 adding=8 max=28 04-07 14:39:12.910 4458 5041 W bt_btif_a2dp_source: btm_read_rssi_cb: device: 00:42:79:a0:ec:50, rssi: 0 04-07 14:39:12.911 4458 5041 W bt_btif_a2dp_source: btm_read_failed_contact_counter_cb: device: 00:42:79:a0:ec:50, Failed Contact Counter: 0 04-07 14:39:12.912 4458 5041 W bt_btif_a2dp_source: btm_read_automatic_flush_timeout_cb: device: 00:42:79:a0:ec:50, Automatic Flush Timeout: 0 04-07 14:39:12.913 4458 5041 W bt_btif_a2dp_source: btm_read_tx_power_cb: device: 00:42:79:a0:ec:50, Tx Power: 12 04-07 14:39:12.998 3545 3614 I SKB_NAVIGATOR: 04-07 14:39:12.998 3545 3614 [close_database] vacumm database 04-07 14:39:13.004 3557 8398 D BOXKEY-STDVB: [DEVICE 0] ++ remain buffer size : 40796 04-07 14:39:13.057 3505 3505 D memtrack_aml: type:0 for pid:8142, size_up_to:0 04-07 14:39:13.059 3505 3505 D memtrack_aml: type:1 for pid:8142, size_up_to:0 04-07 14:39:13.062 3505 3505 D memtrack_aml: type:2 for pid:8142, size_up_to:0 04-07 14:39:13.132 3557 8503 I HalAudioOutput: outputRate:50671(1.06) 04-07 14:39:13.177 3545 3614 I SKB_NAVIGATOR: 04-07 14:39:13.177 3545 3614 [close_database] close database 04-07 14:39:13.180 3545 3614 I SKB_NAVIGATOR: 04-07 14:39:13.180 3545 3614 [close_database] copy database 04-07 14:39:13.198 3545 3614 I SKB_NAVIGATOR: 04-07 14:39:13.198 3545 3614 [open_database] open_database ret : 0 04-07 14:39:13.348 4458 5063 W bt_btif_a2dp_source: btif_a2dp_source_enqueue_callback: TX queue buffer size now=21 adding=8 max=28 04-07 14:39:13.350 4458 5041 W bt_btif_a2dp_source: btm_read_rssi_cb: device: 00:42:79:a0:ec:50, rssi: 0 04-07 14:39:13.351 4458 5041 W bt_btif_a2dp_source: btm_read_failed_contact_counter_cb: device: 00:42:79:a0:ec:50, Failed Contact Counter: 0 04-07 14:39:13.352 4458 5041 W bt_btif_a2dp_source: btm_read_automatic_flush_timeout_cb: device: 00:42:79:a0:ec:50, Automatic Flush Timeout: 0 04-07 14:39:13.354 4458 5041 W bt_btif_a2dp_source: btm_read_tx_power_cb: device: 00:42:79:a0:ec:50, Tx Power: 12 04-07 14:39:13.406 3557 8410 I RendererPolicyBase_0: set_audioStrategy: AUDIO_STRATEGY_NONE ==> AUDIO_STRATEGY_RESAMPLE, diffUs:-73.275000 ms 04-07 14:39:13.406 3557 8410 I RendererPolicyBase_0: audio late than 73.28 ms, adjust audio sink speed to 1.10, factor:0.10 04-07 14:39:13.406 3557 8410 I HalAudioOutput: playback rate changed:1.00 --> 1.10 04-07 14:39:13.417 3557 8503 I HalAudioOutput: high priority work:0x80000004 04-07 14:39:13.417 3557 8503 I HalAudioOutput: resample thread rate changed! 04-07 14:39:13.417 3557 8503 I HalAudioOutput: openSonicStream:345, rate:1.10 04-07 14:39:13.449 3557 8410 I RendererPolicyBase_0: set_audioStrategy: AUDIO_STRATEGY_RESAMPLE ==> AUDIO_STRATEGY_NONE, diffUs:-9.954000 ms 04-07 14:39:13.449 3557 8410 I RendererPolicyBase_0: restore audio sink speed from 1.10 to 1.00 04-07 14:39:13.449 3557 8410 I HalAudioOutput: playback rate changed:1.10 --> 1.00 04-07 14:39:13.462 3557 8503 I HalAudioOutput: high priority work:0x80000004 04-07 14:39:13.462 3557 8503 I HalAudioOutput: resample thread rate changed! 04-07 14:39:13.483 4458 4536 I bt_stack: [INFO:btif_config.cc(647)] hash_file: Disabled for multi-user 04-07 14:39:13.483 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:39:13.484 3557 8503 I HalAudioOutput: openSonicStream:345, rate:1.00 04-07 14:39:13.564 3557 3557 W HwBinder:3557_2: type=1400 audit(0.0:738): 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:39:13.571 3557 8391 E libc : Access denied finding property "skb.audio.output" 04-07 14:39:13.756 3486 3486 W ATVRemoteAudioH: type=1400 audit(0.0:739): avc: denied { call } for scontext=u:r:hal_audio_amlogic:s0 tcontext=u:r:rc_server:s0 tclass=binder permissive=0 04-07 14:39:13.761 3486 3760 W ServiceManagement: getService: unable to call into hwbinder service for vendor.amlogic.hardware.remotecontrol@1.0::IRemoteControl/default. 04-07 14:39:13.788 4458 5063 W bt_btif_a2dp_source: btif_a2dp_source_enqueue_callback: TX queue buffer size now=21 adding=8 max=28 04-07 14:39:13.790 4458 5041 W bt_btif_a2dp_source: btm_read_rssi_cb: device: 00:42:79:a0:ec:50, rssi: 0 04-07 14:39:13.791 4458 5041 W bt_btif_a2dp_source: btm_read_failed_contact_counter_cb: device: 00:42:79:a0:ec:50, Failed Contact Counter: 0 04-07 14:39:13.792 4458 5041 W bt_btif_a2dp_source: btm_read_automatic_flush_timeout_cb: device: 00:42:79:a0:ec:50, Automatic Flush Timeout: 0 04-07 14:39:13.794 4458 5041 W bt_btif_a2dp_source: btm_read_tx_power_cb: device: 00:42:79:a0:ec:50, Tx Power: 12 04-07 14:39:13.921 3550 3656 I [Gralloc]: ddebug, free share_fd=94, user_hnd=0x9, ion client=26 04-07 14:39:13.921 3550 3656 I [Gralloc]: ddebug, free share_fd=91, user_hnd=0x8, ion client=26 04-07 14:39:13.923 4478 4768 I [Gralloc]: ddebug, free share_fd=81, user_hnd=0x1, ion client=82 04-07 14:39:13.924 3550 3660 E BufferQueueProducer: [Volume control#0] disconnect: not connected (req=1) 04-07 14:39:13.924 4478 4768 W libEGL : EGLNativeWindowType 0xdccbd988 disconnect failed 04-07 14:39:13.934 4478 4478 I vol.Events: writeEvent dismiss_dialog timeout 04-07 14:39:13.941 3498 3637 I [Gralloc]: ddebug, free share_fd=61, user_hnd=0x7, ion client=31 04-07 14:39:13.941 3498 3637 W gralloc : Warning shared attribute region mapped at free. Unmapping 04-07 14:39:13.942 3550 3550 I [Gralloc]: ddebug, free share_fd=85, user_hnd=0x7, ion client=26 04-07 14:39:14.005 3557 8398 D BOXKEY-STDVB: [DEVICE 0] ++ remain buffer size : 32900 04-07 14:39:14.054 7849 7849 D MDNSService: MDNSMsgHandler() AM_EVENT_CHECK_NETWORK_CONFIG. isConnected : true 04-07 14:39:14.133 4458 5041 W bt_btif : bta_av_open_rc: Using the new AVRCP Profile 04-07 14:39:14.133 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:39:14.133 4458 5041 I bt_stack: [INFO:connection_handler.cc(109)] Attempting to connect to device 00:42:79:a0:ec:50 04-07 14:39:14.133 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:39:14.133 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:39:14.268 4458 5063 W bt_btif_a2dp_source: btif_a2dp_source_enqueue_callback: TX queue buffer size now=22 adding=8 max=28 04-07 14:39:14.270 4458 5041 W bt_btif_a2dp_source: btm_read_rssi_cb: device: 00:42:79:a0:ec:50, rssi: 0 04-07 14:39:14.271 4458 5041 W bt_btif_a2dp_source: btm_read_failed_contact_counter_cb: device: 00:42:79:a0:ec:50, Failed Contact Counter: 0 04-07 14:39:14.272 4458 5041 W bt_btif_a2dp_source: btm_read_automatic_flush_timeout_cb: device: 00:42:79:a0:ec:50, Automatic Flush Timeout: 0 04-07 14:39:14.273 4458 5041 W bt_btif_a2dp_source: btm_read_tx_power_cb: device: 00:42:79:a0:ec:50, Tx Power: 12 04-07 14:39:14.293 4458 4458 I BluetoothPhonePolicy: processConnectOtherProfiles, device=00:42:79:A0:EC:50 04-07 14:39:14.297 4458 4458 V BluetoothDatabase: getProfilePriority: 00:42:79:A0:EC:50, profile=1, priority = 1000 04-07 14:39:14.299 4458 4458 V BluetoothDatabase: getProfilePriority: 00:42:79:A0:EC:50, profile=2, priority = 1000 04-07 14:39:14.300 4458 4458 D BluetoothAdapterService: getAdapterService() - returning com.android.bluetooth.btservice.AdapterService@d9f176c 04-07 14:39:14.301 4458 4458 V BluetoothDatabase: getProfilePriority: 00:42:79:A0:EC:50, profile=5, priority = -1 04-07 14:39:14.564 3557 3557 W HwBinder:3557_2: type=1400 audit(0.0:740): 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:39:14.570 3557 8391 E libc : Access denied finding property "skb.audio.output" 04-07 14:39:14.629 3557 8407 W RendererPolicyBase_0: video render: 59.94 fps, drop: 0.00 fps 04-07 14:39:14.764 3486 3760 W ServiceManagement: getService: unable to call into hwbinder service for vendor.amlogic.hardware.remotecontrol@1.0::IRemoteControl/default. 04-07 14:39:14.760 3486 3486 W ATVRemoteAudioH: type=1400 audit(0.0:741): avc: denied { call } for scontext=u:r:hal_audio_amlogic:s0 tcontext=u:r:rc_server:s0 tclass=binder permissive=0 04-07 14:39:14.788 4458 5063 W bt_btif_a2dp_source: btif_a2dp_source_enqueue_callback: TX queue buffer size now=22 adding=8 max=28 04-07 14:39:14.790 4458 5041 W bt_btif_a2dp_source: btm_read_rssi_cb: device: 00:42:79:a0:ec:50, rssi: 1 04-07 14:39:14.792 4458 5041 W bt_btif_a2dp_source: btm_read_failed_contact_counter_cb: device: 00:42:79:a0:ec:50, Failed Contact Counter: 0 04-07 14:39:14.795 4458 5041 W bt_btif_a2dp_source: btm_read_automatic_flush_timeout_cb: device: 00:42:79:a0:ec:50, Automatic Flush Timeout: 0 04-07 14:39:14.796 4458 5041 W bt_btif_a2dp_source: btm_read_tx_power_cb: device: 00:42:79:a0:ec:50, Tx Power: 12 04-07 14:39:15.007 3557 8398 D BOXKEY-STDVB: [DEVICE 0] ++ remain buffer size : 39480 04-07 14:39:15.153 3557 8503 I HalAudioOutput: outputRate:48185(1.00) 04-07 14:39:15.268 4458 5063 W bt_btif_a2dp_source: btif_a2dp_source_enqueue_callback: TX queue buffer size now=22 adding=8 max=28 04-07 14:39:15.270 4458 5041 W bt_btif_a2dp_source: btm_read_rssi_cb: device: 00:42:79:a0:ec:50, rssi: 1 04-07 14:39:15.271 4458 5041 W bt_btif_a2dp_source: btm_read_failed_contact_counter_cb: device: 00:42:79:a0:ec:50, Failed Contact Counter: 0 04-07 14:39:15.272 4458 5041 W bt_btif_a2dp_source: btm_read_automatic_flush_timeout_cb: device: 00:42:79:a0:ec:50, Automatic Flush Timeout: 0 04-07 14:39:15.273 4458 5041 W bt_btif_a2dp_source: btm_read_tx_power_cb: device: 00:42:79:a0:ec:50, Tx Power: 12 04-07 14:39:15.431 3557 8410 I RendererPolicyBase_0: set_audioStrategy: AUDIO_STRATEGY_NONE ==> AUDIO_STRATEGY_RESAMPLE, diffUs:-71.570000 ms 04-07 14:39:15.431 3557 8410 I RendererPolicyBase_0: audio late than 71.57 ms, adjust audio sink speed to 1.10, factor:0.10 04-07 14:39:15.431 3557 8410 I HalAudioOutput: playback rate changed:1.00 --> 1.10 04-07 14:39:15.439 3557 8503 I HalAudioOutput: high priority work:0x80000004 04-07 14:39:15.439 3557 8503 I HalAudioOutput: resample thread rate changed! 04-07 14:39:15.440 3557 8503 I HalAudioOutput: openSonicStream:345, rate:1.10 04-07 14:39:15.474 3557 8410 I RendererPolicyBase_0: set_audioStrategy: AUDIO_STRATEGY_RESAMPLE ==> AUDIO_STRATEGY_NONE, diffUs:-7.652000 ms 04-07 14:39:15.474 3557 8410 I RendererPolicyBase_0: restore audio sink speed from 1.10 to 1.00 04-07 14:39:15.474 3557 8410 I HalAudioOutput: playback rate changed:1.10 --> 1.00 04-07 14:39:15.484 3557 8503 I HalAudioOutput: high priority work:0x80000004 04-07 14:39:15.484 3557 8503 I HalAudioOutput: resample thread rate changed! 04-07 14:39:15.506 3557 8503 I HalAudioOutput: openSonicStream:345, rate:1.00 04-07 14:39:15.570 3557 8391 E libc : Access denied finding property "skb.audio.output" 04-07 14:39:15.564 3557 3557 W HwBinder:3557_2: type=1400 audit(0.0:742): 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:39:15.760 3486 3486 W ATVRemoteAudioH: type=1400 audit(0.0:743): avc: denied { call } for scontext=u:r:hal_audio_amlogic:s0 tcontext=u:r:rc_server:s0 tclass=binder permissive=0 04-07 14:39:15.767 3486 3760 W ServiceManagement: getService: unable to call into hwbinder service for vendor.amlogic.hardware.remotecontrol@1.0::IRemoteControl/default. 04-07 14:39:15.828 4458 5063 W bt_btif_a2dp_source: btif_a2dp_source_enqueue_callback: TX queue buffer size now=21 adding=8 max=28 04-07 14:39:15.831 4458 5041 W bt_btif_a2dp_source: btm_read_rssi_cb: device: 00:42:79:a0:ec:50, rssi: 2 04-07 14:39:15.832 4458 5041 W bt_btif_a2dp_source: btm_read_failed_contact_counter_cb: device: 00:42:79:a0:ec:50, Failed Contact Counter: 0 04-07 14:39:15.833 4458 5041 W bt_btif_a2dp_source: btm_read_automatic_flush_timeout_cb: device: 00:42:79:a0:ec:50, Automatic Flush Timeout: 0 04-07 14:39:15.834 4458 5041 W bt_btif_a2dp_source: btm_read_tx_power_cb: device: 00:42:79:a0:ec:50, Tx Power: 12 04-07 14:39:16.009 3557 8398 D BOXKEY-STDVB: [DEVICE 0] ++ remain buffer size : 35532 04-07 14:39:16.169 3528 3528 D isqmsAgent: [isqmsAgent 0163 04/07 14:39:16:169][3528] CISQMSSchedule::SCHETYPE_CYCLE event_id=H01 04-07 14:39:16.388 4458 5063 W bt_btif_a2dp_source: btif_a2dp_source_enqueue_callback: TX queue buffer size now=22 adding=8 max=28 04-07 14:39:16.390 4458 5041 W bt_btif_a2dp_source: btm_read_rssi_cb: device: 00:42:79:a0:ec:50, rssi: 2 04-07 14:39:16.391 4458 5041 W bt_btif_a2dp_source: btm_read_failed_contact_counter_cb: device: 00:42:79:a0:ec:50, Failed Contact Counter: 0 04-07 14:39:16.392 4458 5041 W bt_btif_a2dp_source: btm_read_automatic_flush_timeout_cb: device: 00:42:79:a0:ec:50, Automatic Flush Timeout: 0 04-07 14:39:16.394 4458 5041 W bt_btif_a2dp_source: btm_read_tx_power_cb: device: 00:42:79:a0:ec:50, Tx Power: 12 04-07 14:39:16.570 3557 8391 E libc : Access denied finding property "skb.audio.output" 04-07 14:39:16.564 3557 3557 W HwBinder:3557_2: type=1400 audit(0.0:744): 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:39:16.630 3557 8407 W RendererPolicyBase_0: video render: 59.95 fps, drop: 0.00 fps 04-07 14:39:16.772 3486 3760 W ServiceManagement: getService: unable to call into hwbinder service for vendor.amlogic.hardware.remotecontrol@1.0::IRemoteControl/default. 04-07 14:39:16.768 3486 3486 W ATVRemoteAudioH: type=1400 audit(0.0:745): avc: denied { call } for scontext=u:r:hal_audio_amlogic:s0 tcontext=u:r:rc_server:s0 tclass=binder permissive=0 04-07 14:39:16.908 4458 5063 W bt_btif_a2dp_source: btif_a2dp_source_enqueue_callback: TX queue buffer size now=21 adding=8 max=28 04-07 14:39:16.912 4458 5041 W bt_btif_a2dp_source: btm_read_rssi_cb: device: 00:42:79:a0:ec:50, rssi: 2 04-07 14:39:16.913 4458 5041 W bt_btif_a2dp_source: btm_read_failed_contact_counter_cb: device: 00:42:79:a0:ec:50, Failed Contact Counter: 0 04-07 14:39:16.914 4458 5041 W bt_btif_a2dp_source: btm_read_automatic_flush_timeout_cb: device: 00:42:79:a0:ec:50, Automatic Flush Timeout: 0 04-07 14:39:16.915 4458 5041 W bt_btif_a2dp_source: btm_read_tx_power_cb: device: 00:42:79:a0:ec:50, Tx Power: 12 04-07 14:39:17.011 3557 8398 D BOXKEY-STDVB: [DEVICE 0] ++ remain buffer size : 35532 04-07 14:39:17.175 3557 8503 I HalAudioOutput: outputRate:48173(1.00) 04-07 14:39:17.388 4458 5063 W bt_btif_a2dp_source: btif_a2dp_source_enqueue_callback: TX queue buffer size now=22 adding=8 max=28 04-07 14:39:17.391 4458 5041 W bt_btif_a2dp_source: btm_read_rssi_cb: device: 00:42:79:a0:ec:50, rssi: 2 04-07 14:39:17.392 4458 5041 W bt_btif_a2dp_source: btm_read_failed_contact_counter_cb: device: 00:42:79:a0:ec:50, Failed Contact Counter: 0 04-07 14:39:17.394 4458 5041 W bt_btif_a2dp_source: btm_read_automatic_flush_timeout_cb: device: 00:42:79:a0:ec:50, Automatic Flush Timeout: 0 04-07 14:39:17.395 4458 5041 W bt_btif_a2dp_source: btm_read_tx_power_cb: device: 00:42:79:a0:ec:50, Tx Power: 12 04-07 14:39:17.411 3557 8410 I RendererPolicyBase_0: set_audioStrategy: AUDIO_STRATEGY_NONE ==> AUDIO_STRATEGY_RESAMPLE, diffUs:-67.631000 ms 04-07 14:39:17.411 3557 8410 I RendererPolicyBase_0: audio late than 67.63 ms, adjust audio sink speed to 1.10, factor:0.10 04-07 14:39:17.411 3557 8410 I HalAudioOutput: playback rate changed:1.00 --> 1.10 04-07 14:39:17.417 3557 8503 I HalAudioOutput: high priority work:0x80000004 04-07 14:39:17.417 3557 8503 I HalAudioOutput: resample thread rate changed! 04-07 14:39:17.417 3557 8503 I HalAudioOutput: openSonicStream:345, rate:1.10 04-07 14:39:17.454 3557 8410 I RendererPolicyBase_0: set_audioStrategy: AUDIO_STRATEGY_RESAMPLE ==> AUDIO_STRATEGY_NONE, diffUs:-4.429000 ms 04-07 14:39:17.454 3557 8410 I RendererPolicyBase_0: restore audio sink speed from 1.10 to 1.00 04-07 14:39:17.454 3557 8410 I HalAudioOutput: playback rate changed:1.10 --> 1.00 04-07 14:39:17.462 3557 8503 I HalAudioOutput: high priority work:0x80000004 04-07 14:39:17.462 3557 8503 I HalAudioOutput: resample thread rate changed! 04-07 14:39:17.481 3557 8503 I HalAudioOutput: openSonicStream:345, rate:1.00 04-07 14:39:17.564 3557 3557 W HwBinder:3557_2: type=1400 audit(0.0:746): 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:39:17.570 3557 8391 E libc : Access denied finding property "skb.audio.output" 04-07 14:39:17.775 3486 3760 W ServiceManagement: getService: unable to call into hwbinder service for vendor.amlogic.hardware.remotecontrol@1.0::IRemoteControl/default. 04-07 14:39:17.768 3486 3486 W ATVRemoteAudioH: type=1400 audit(0.0:747): avc: denied { call } for scontext=u:r:hal_audio_amlogic:s0 tcontext=u:r:rc_server:s0 tclass=binder permissive=0 04-07 14:39:17.908 4458 5063 W bt_btif_a2dp_source: btif_a2dp_source_enqueue_callback: TX queue buffer size now=22 adding=8 max=28 04-07 14:39:17.910 4458 5041 W bt_btif_a2dp_source: btm_read_rssi_cb: device: 00:42:79:a0:ec:50, rssi: 2 04-07 14:39:17.911 4458 5041 W bt_btif_a2dp_source: btm_read_failed_contact_counter_cb: device: 00:42:79:a0:ec:50, Failed Contact Counter: 0 04-07 14:39:17.912 4458 5041 W bt_btif_a2dp_source: btm_read_automatic_flush_timeout_cb: device: 00:42:79:a0:ec:50, Automatic Flush Timeout: 0 04-07 14:39:17.913 4458 5041 W bt_btif_a2dp_source: btm_read_tx_power_cb: device: 00:42:79:a0:ec:50, Tx Power: 12 04-07 14:39:17.932 3505 3505 D memtrack_aml: type:0 for pid:6221, size_up_to:0 04-07 14:39:17.933 3505 3505 D memtrack_aml: type:1 for pid:6221, size_up_to:0 04-07 14:39:17.935 3505 3505 D memtrack_aml: type:2 for pid:6221, size_up_to:0 04-07 14:39:17.973 7482 7545 I Finsky:background: [357] hos.run(27): Stats for Executor: LightweightExecutor hsg@6edf8e1[Running, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 0] 04-07 14:39:18.013 3557 8398 D BOXKEY-STDVB: [DEVICE 0] ++ remain buffer size : 32900 04-07 14:39:18.388 4458 5063 W bt_btif_a2dp_source: btif_a2dp_source_enqueue_callback: TX queue buffer size now=21 adding=8 max=28 04-07 14:39:18.390 4458 5041 W bt_btif_a2dp_source: btm_read_rssi_cb: device: 00:42:79:a0:ec:50, rssi: 2 04-07 14:39:18.392 4458 5041 W bt_btif_a2dp_source: btm_read_failed_contact_counter_cb: device: 00:42:79:a0:ec:50, Failed Contact Counter: 0 04-07 14:39:18.393 4458 5041 W bt_btif_a2dp_source: btm_read_automatic_flush_timeout_cb: device: 00:42:79:a0:ec:50, Automatic Flush Timeout: 0 04-07 14:39:18.395 4458 5041 W bt_btif_a2dp_source: btm_read_tx_power_cb: device: 00:42:79:a0:ec:50, Tx Power: 12 04-07 14:39:18.570 3557 8391 E libc : Access denied finding property "skb.audio.output" 04-07 14:39:18.564 3557 3557 W HwBinder:3557_2: type=1400 audit(0.0:748): 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