dongyi190120 发表于 2021-2-2 11:16:11

ROC-RK3328-PC开机的时候偶尔报错蓝牙停止运行

与蓝牙复用的调试串口没有使用,开机的时候经常出现蓝牙停止运行。大约20次出一次的样子。

log如下
01-14 11:03:57.18714261471 D AdapterProperties: Discoverable Timeout:120
01-14 11:03:57.18714261471 I bt_stack: EnableBtQualityReport: is_enable: true
01-14 11:03:57.18814261471 W bt_stack: EnableBtQualityReport: Bluetooth Quality Report is disabled. bq
r_prop_evtmask: , bqr_prop_interval_ms:
01-14 11:03:57.18814261471 I bt_btif_core: btif_enable_bluetooth_evt entered: status 0
01-14 11:03:57.18914261679 I bt_osi_thread: run_thread: thread id 1679, thread name btif_sock started
01-14 11:03:57.18914261471 D bt_bte_conf: Device ID record 1 : primary
01-14 11:03:57.18914261471 D bt_bte_conf:   vendorId            = 00e0
01-14 11:03:57.18914261471 D bt_bte_conf:   vendorIdSource      = 0001
01-14 11:03:57.19014261471 D bt_bte_conf:   product             = 1200
01-14 11:03:57.19014261471 D bt_bte_conf:   version             = 1436
01-14 11:03:57.19014261471 D bt_bte_conf:   clientExecutableURL =
01-14 11:03:57.19014261471 D bt_bte_conf:   serviceDescription=
01-14 11:03:57.19014261471 D bt_bte_conf:   documentationURL    =
01-14 11:03:57.19014261471 D bt_bte_conf: bte_load_did_conf no section named DID2.
01-14 11:03:57.19014261471 I bt_btif_core: btif_enable_bluetooth_evt finished
01-14 11:03:57.19014261466 I bt_stack_manager: event_start_up_stack finished
01-14 11:03:57.20014261471 D BluetoothPanServiceJni: control_state_callback(L63): state:0, local_role:3, ifname:bt-pan
01-14 11:03:57.20214261465 I AdapterState: BLE_ON : entered
01-14 11:03:57.20214261465 D AdapterProperties: Setting state to BLE_ON
01-14 11:03:57.20214261465 D BluetoothAdapterService: updateAdapterState() - Broadcasting state BLE_ON to 1 receivers.
01-14 11:03:57.205   391   412 D BluetoothManagerService: MESSAGE_BLUETOOTH_STATE_CHANGE: BLE_TURNING_ON > BLE_ON
01-14 11:03:57.205   391   412 D BluetoothManagerService: Bluetooth is in LE only mode
01-14 11:03:57.205   391   412 D BluetoothManagerService: continueFromBleOnState()
01-14 11:03:57.206   391   412 D BluetoothManagerService: Persisting Bluetooth Setting: 1
01-14 11:03:57.206   391   412 D BluetoothManagerService: Sending BLE State Change: BLE_TURNING_ON > BLE_ON
01-14 11:03:57.20714261465 I AdapterState: TURNING_ON : entered
01-14 11:03:57.20714261465 D AdapterProperties: Setting state to TURNING_ON
01-14 11:03:57.20714261465 D BluetoothAdapterService: updateAdapterState() - Broadcasting state TURNING_ON to 1 receivers.      
01-14 11:03:57.208   391   412 D BluetoothManagerService: MESSAGE_BLUETOOTH_STATE_CHANGE: BLE_ON > TURNING_ON
01-14 11:03:57.208   391   412 D BluetoothManagerService: Sending BLE State Change: BLE_ON > TURNING_ON
01-14 11:03:57.20814261465 D BluetoothAdapterService: startCoreServices()
01-14 11:03:57.21114261472 D BluetoothActiveDeviceManager: handleMessage(MESSAGE_ADAPTER_ACTION_STATE_CHANGED): newState=11      
01-14 11:03:57.22414261426 I HeadsetService: create()
01-14 11:03:57.22814261426 D BluetoothAdapterService: getAdapterService() - returning com.android.bluetooth.btservice.AdapterServ
ice@c76891f
01-14 11:03:57.23414261426 I HeadsetService: start()
01-14 11:03:57.23414261426 D BluetoothAdapterService: getAdapterService() - returning com.android.bluetooth.btservice.AdapterServ
ice@c76891f
01-14 11:03:57.24414261426 E HeadsetSystemInterface: Could not bind to IBluetoothHeadsetPhone Service, intent=Intent { act=androi
d.bluetooth.IBluetoothHeadsetPhone }
01-14 11:03:57.24414261426 E HeadsetSystemInterface: android.util.Log$TerribleFailure: Could not bind to IBluetoothHeadsetPhone S
ervice, intent=Intent { act=android.bluetooth.IBluetoothHeadsetPhone }
01-14 11:03:57.24414261426 E HeadsetSystemInterface:      at android.util.Log.wtf(Log.java:309)
01-14 11:03:57.24414261426 E HeadsetSystemInterface:      at android.util.Log.wtfStack(Log.java:282)
01-14 11:03:57.24414261426 E HeadsetSystemInterface:      at com.android.bluetooth.hfp.HeadsetSystemInterface.init(HeadsetSyste
mInterface.java:95)
01-14 11:03:57.24414261426 E HeadsetSystemInterface:      at com.android.bluetooth.hfp.HeadsetService.start(HeadsetService.java
:149)
01-14 11:03:57.24414261426 E HeadsetSystemInterface:      at com.android.bluetooth.btservice.ProfileService.doStart(ProfileServ
ice.java:263)
01-14 11:03:57.24414261426 E HeadsetSystemInterface:      at com.android.bluetooth.btservice.ProfileService.onStartCommand(Prof
ileService.java:151)
01-14 11:03:57.24414261426 E HeadsetSystemInterface:      at android.app.ActivityThread.handleServiceArgs(ActivityThread.java:4
087)
01-14 11:03:57.24414261426 E HeadsetSystemInterface:      at android.app.ActivityThread.access$1800(ActivityThread.java:219)   
01-14 11:03:57.24414261426 E HeadsetSystemInterface:      at android.app.ActivityThread$H.handleMessage(ActivityThread.java:189
1)
01-14 11:03:57.24414261426 E HeadsetSystemInterface:      at android.os.Handler.dispatchMessage(Handler.java:107)
01-14 11:03:57.24414261426 E HeadsetSystemInterface:      at android.os.Looper.loop(Looper.java:214)
01-14 11:03:57.24414261426 E HeadsetSystemInterface:      at android.app.ActivityThread.main(ActivityThread.java:7356)
01-14 11:03:57.24414261426 E HeadsetSystemInterface:      at java.lang.reflect.Method.invoke(Native Method)
01-14 11:03:57.24414261426 E HeadsetSystemInterface:      at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(Runtim
eInit.java:492)
01-14 11:03:57.24414261426 E HeadsetSystemInterface:      at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:930)      
01-14 11:03:57.248   3911682 I DropBoxManagerService: add tag=system_app_wtf isTagEnabled=true flags=0x2
01-14 11:03:57.25014261426 I BluetoothHeadsetServiceJni: classInitNative: succeeds
01-14 11:03:57.25114261426 I bt_btif : get_profile_interface: id = handsfree
01-14 11:03:57.25114261426 I bt_stack: GetInterface
01-14 11:03:57.25414261426 D BluetoothAdapterService: getAdapterService() - returning com.android.bluetooth.btservice.AdapterServ
ice@c76891f
01-14 11:03:57.25714261426 I A2dpService: start()
01-14 11:03:57.25814261426 D AndroidRuntime: Shutting down VM
01-14 11:03:57.26414261676 I bt_stack: RFCOMM_CreateConnection: bd_addr=ff:ff:ff:ff:ff:ff, scn=2, is_serv
er=1, mtu=256, uuid=0x1112, dlci=4, signal_state=0x0b, p_port=0x7c6f26f510
01-14 11:03:57.26414261426 E AndroidRuntime: FATAL EXCEPTION: main
01-14 11:03:57.26414261426 E AndroidRuntime: Process: com.android.bluetooth, PID: 1426
01-14 11:03:57.26414261426 E AndroidRuntime: java.lang.RuntimeException: Unable to start service com.android.bluetooth.a2dp.A2dpS
ervice@72f02ff with Intent { cmp=com.android.bluetooth/.a2dp.A2dpService (has extras) }: java.lang.IllegalStateException: start() cal
led twice
01-14 11:03:57.26414261426 E AndroidRuntime:      at android.app.ActivityThread.handleServiceArgs(ActivityThread.java:4105)   
01-14 11:03:57.26414261426 E AndroidRuntime:      at android.app.ActivityThread.access$1800(ActivityThread.java:219)
01-14 11:03:57.26414261426 E AndroidRuntime:      at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1891)      
01-14 11:03:57.26414261426 E AndroidRuntime:      at android.os.Handler.dispatchMessage(Handler.java:107)
01-14 11:03:57.26414261426 E AndroidRuntime:      at android.os.Looper.loop(Looper.java:214)
01-14 11:03:57.26414261426 E AndroidRuntime:      at android.app.ActivityThread.main(ActivityThread.java:7356)
01-14 11:03:57.26414261426 E AndroidRuntime:      at java.lang.reflect.Method.invoke(Native Method)
01-14 11:03:57.26414261426 E AndroidRuntime:      at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.ja
va:492)
01-14 11:03:57.26414261426 E AndroidRuntime:      at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:930)
01-14 11:03:57.26414261426 E AndroidRuntime: Caused by: java.lang.IllegalStateException: start() called twice
01-14 11:03:57.26414261426 E AndroidRuntime:      at com.android.bluetooth.a2dp.A2dpService.start(A2dpService.java:99)
01-14 11:03:57.26414261426 E AndroidRuntime:      at com.android.bluetooth.btservice.ProfileService.doStart(ProfileService.java
:263)
01-14 11:03:57.26414261426 E AndroidRuntime:      at com.android.bluetooth.btservice.ProfileService.onStartCommand(ProfileServi
ce.java:151)
01-14 11:03:57.26414261426 E AndroidRuntime:      at android.app.ActivityThread.handleServiceArgs(ActivityThread.java:4087)   
01-14 11:03:57.26414261426 E AndroidRuntime:      ... 8 more
01-14 11:03:57.26414261676 I bt_stack: RFCOMM_CreateConnection: bd_addr=ff:ff:ff:ff:ff:ff, scn=2, is_serv
er=1, mtu=256, uuid=0x1112, dlci=4, signal_state=0x0b, p_port=0x7c6f26f5c8
01-14 11:03:57.26514261676 I bt_stack: RFCOMM_CreateConnection: bd_addr=ff:ff:ff:ff:ff:ff, scn=2, is_serv
er=1, mtu=256, uuid=0x1112, dlci=4, signal_state=0x0b, p_port=0x7c6f26f680
01-14 11:03:57.26514261676 I bt_stack: RFCOMM_CreateConnection: bd_addr=ff:ff:ff:ff:ff:ff, scn=2, is_serv
er=1, mtu=256, uuid=0x1112, dlci=4, signal_state=0x0b, p_port=0x7c6f26f738
01-14 11:03:57.26614261676 I bt_stack: RFCOMM_CreateConnection: bd_addr=ff:ff:ff:ff:ff:ff, scn=2, is_serv
er=1, mtu=256, uuid=0x1112, dlci=4, signal_state=0x0b, p_port=0x7c6f26f7f0
01-14 11:03:57.26614261676 I bt_stack: RFCOMM_CreateConnection: bd_addr=ff:ff:ff:ff:ff:ff, scn=2, is_serv
er=1, mtu=256, uuid=0x1112, dlci=4, signal_state=0x0b, p_port=0x7c6f26f8a8
01-14 11:03:57.26614261471 I bt_btif_storage: btif_storage_get_adapter_property service_mask:0x60100028
01-14 11:03:57.26714261471 I bt_stack: btif_hf_upstreams_evt: AG enable/disable event 0
01-14 11:03:57.270   3911683 I DropBoxManagerService: add tag=system_app_crash isTagEnabled=true flags=0x2
01-14 11:03:57.274   391   411 I ActivityManager: Showing crash dialog for package com.android.bluetooth u0
01-14 11:03:57.303   391   412 I DropBoxManagerService: add tag=system_server_strictmode isTagEnabled=true flags=0x2
01-14 11:03:57.336   228   228 I GRALLOC-ROCKCHIP: : hardware/rockchip/libgralloc/utgard/gralloc_drm_rockchip.cpp; : 10
19; : drm_gem_rockchip_alloc;
01-14 11:03:57.336   228   228 I GRALLOC-ROCKCHIP: dmabuf_name : 228_801792_11:03:57.336
01-14 11:03:57.338   228   228 I GRALLOC-ROCKCHIP: : hardware/rockchip/libgralloc/utgard/gralloc_drm_rockchip.cpp; : 10
19; : drm_gem_rockchip_alloc;
01-14 11:03:57.338   228   228 I GRALLOC-ROCKCHIP: dmabuf_name : 228_801792_11:03:57.338
01-14 11:03:57.343   228   228 I GRALLOC-ROCKCHIP: : hardware/rockchip/libgralloc/utgard/gralloc_drm_rockchip.cpp; : 10
19; : drm_gem_rockchip_alloc;
01-14 11:03:57.343   228   228 I GRALLOC-ROCKCHIP: dmabuf_name : 228_801792_11:03:57.343
01-14 11:03:58.38811641164 D RecoveryReceiver: RECOVERY_STATE_FILE_TF:/mnt/external_sd/Recovery_state
01-14 11:03:58.39112201220 V TestService: x action:android.intent.action.MEDIA_MOUNTED
01-14 11:03:58.39112201220 V TestService: pathfile:///storage/emulated/0,bootcomplete=true
01-14 11:03:58.39112201220 V TestService: path1:file:///storage/emulated/0
01-14 11:03:58.39112201220 W ContextImpl: Calling a method in the system process without a qualified user: android.app.ContextImp
l.startService:1570 android.content.ContextWrapper.startService:669 android.content.ContextWrapper.startService:669 com.rockchip.devi
cetest.BootReceiver.onReceive:59 android.app.ActivityThread.handleReceiver:3788
01-14 11:03:58.39512201220 D TestService: onCreate
01-14 11:03:58.39512201220 E SystemUtils: /sys/bus/platform/drivers/usb20_otg/force_usb_modeget File err!
01-14 11:03:58.39613541354 D RKUpdateReceiver: action = android.intent.action.MEDIA_MOUNTED , isBootCompleted = true
01-14 11:03:58.39713541354 D RKUpdateReceiver: RKUpdateReceiver recv ACTION_MEDIA_MOUNTED || ACTION_USB_DEVICE_ATTACHED.
01-14 11:03:58.39713541354 W ContextImpl: Calling a method in the system process without a qualified user: android.app.ContextImp
l.startService:1570 android.content.ContextWrapper.startService:669 android.content.ContextWrapper.startService:669 android.rockchip.
update.service.RKUpdateReceiver.onReceive:74 android.app.ActivityThread.handleReceiver:3788
01-14 11:03:58.39812201220 D TestService: onStartCommand,from:mount
01-14 11:03:58.39913541354 D RKUpdateService: onStartCommand.......
01-14 11:03:58.39913541354 D RKUpdateService: zw..........
01-14 11:03:58.39913541354 D RKUpdateService: command = 1 delaytime = 5000
01-14 11:03:58.40312201220 D StorageList: VolumnState:mounted
01-14 11:03:58.40312201220 D StorageList: Storage'paths:/storage/emulated/0 state:mounted
01-14 11:03:58.40412201220 D DeviceTest-FileUitls: find path:/storage/emulated/0
01-14 11:03:58.40512201220 D StorageList: VolumnState:mounted
01-14 11:03:58.40512201220 D DeviceTest-FileUitls: find file:/storage/emulated/0/Android
01-14 11:03:58.40512201220 D DeviceTest-FileUitls: find file:/storage/emulated/0/Music
01-14 11:03:58.40512201220 D DeviceTest-FileUitls: find file:/storage/emulated/0/Podcasts
01-14 11:03:58.40512201220 D DeviceTest-FileUitls: find file:/storage/emulated/0/Ringtones
01-14 11:03:58.40512201220 D DeviceTest-FileUitls: find file:/storage/emulated/0/Alarms
01-14 11:03:58.40512201220 D DeviceTest-FileUitls: find file:/storage/emulated/0/Notifications
01-14 11:03:58.40512201220 D DeviceTest-FileUitls: find file:/storage/emulated/0/Pictures
01-14 11:03:58.40512201220 D DeviceTest-FileUitls: find file:/storage/emulated/0/Movies
01-14 11:03:58.40612201220 D DeviceTest-FileUitls: find file:/storage/emulated/0/Download
01-14 11:03:58.40612201220 D DeviceTest-FileUitls: find file:/storage/emulated/0/DCIM
01-14 11:03:58.40612201220 D DeviceTest-FileUitls: find file:/storage/emulated/0/Total Control
01-14 11:03:58.40612201220 D DeviceTest-FileUitls: find file:/storage/emulated/0/主题歌:挥剑问情.mp3
01-14 11:03:58.40612201220 D DeviceTest-FileUitls: find file:/storage/emulated/0/sdklog
01-14 11:03:58.40612201220 D TestService: no DeviceTest.apk
01-14 11:03:58.40612201220 D TestService: Rock Recv Mount action. 26918
01-14 11:03:58.42911021102 I DaemonService: public receiver :
01-14 11:03:58.43112421689 I MediaProvider: Begin Intent { act=android.intent.action.MEDIA_MOUNTED dat=file:///storage/emulated/0
flg=0x5000010 cmp=com.android.providers.media/.MediaService (has extras) }
01-14 11:03:58.43411021690 I ===InitWorkSpace3===: Will write content:init work space-3 start time Thu Jan 14 11:03:58 GMT+08:00
2021
01-14 11:03:58.44011021690 I ===InitWorkSpace3===: *will save IMEI:
01-14 11:03:58.44211021690 I MobileInformationUtil: Will write content:create new IMEI using Settings.Secure.ANDROID_ID: 9f7d9556
520ee434
01-14 11:03:58.44311021690 I ===InitWorkSpace3===: create new IMEI: 9f7d9556520ee434
01-14 11:03:58.45012421689 W ModernMediaScanner: Failed to visit /system/media: java.nio.file.NoSuchFileException: /system/media
01-14 11:03:58.45711021690 I ===InitWorkSpace3===: Will write content:Store 'INIT_OVER' into ma.conf succes
01-14 11:03:58.45811021690 I ===InitWorkSpace3===: Will write content:init work space-3 end timeThu Jan 14 11:03:58 GMT+08:00 202
1
01-14 11:03:58.46312421689 W ModernMediaScanner: Failed to visit /oem/media: java.nio.file.NoSuchFileException: /oem/media      
01-14 11:03:58.901   391   391 W NotificationService: Toast already killed. pkg=android callback=android.widget.Toast$TN@d80722e   
01-14 11:03:59.21311021277 I APKProtocolTransmit: Will write content:the C socket has not been connected, so discard the send com
mand:
01-14 11:03:59.21511021277 I APKProtocolTransmit: End send sb-cmd:275
01-14 11:03:59.57112421689 E SQLiteLog: (1) no such table: audio_genres
01-14 11:03:59.58112421689 E SQLiteLog: (1) no such table: audio_genres
01-14 11:03:59.61817011701 I         : Surfaceflinger build version Sep 10 2019-17:41:37-r3301 for All
01-14 11:03:59.621   153   482 D PermissionCache: checking android.permission.READ_FRAME_BUFFER for uid=2000 => granted (896 us)   
01-14 11:03:59.625   228   228 I GRALLOC-ROCKCHIP: : hardware/rockchip/libgralloc/utgard/gralloc_drm_rockchip.cpp; : 10
19; : drm_gem_rockchip_alloc;
01-14 11:03:59.625   228   228 I GRALLOC-ROCKCHIP: dmabuf_name : 228_3686400_11:03:59.625
01-14 11:03:59.64717011701 W Gralloc3: mapper 3.x is not supported
01-14 11:03:59.65617011701 D GRALLOC-ROCKCHIP: RK_GRAPHICS_VER=commit-id:2d69b23
01-14 11:03:59.662   228   228 I GRALLOC-ROCKCHIP: : hardware/rockchip/libgralloc/utgard/gralloc_drm_rockchip.cpp; : 10
19; : drm_gem_rockchip_alloc;
01-14 11:03:59.662   228   228 I GRALLOC-ROCKCHIP: dmabuf_name : 228_3686400_11:03:59.662
01-14 11:03:59.68917011701 I mobileagent: type=1400 audit(0.0:317): avc: denied { write } for name="event1" dev="tmpfs" ino=290 s
context=u:r:shell:s0 tcontext=u:object_r:input_device:s0 tclass=chr_file permissive=1
01-14 11:03:59.74411021714 I USBService: command is :
01-14 11:03:59.74411021714 E USBService: Unknow commond:105
01-14 11:03:59.80412421689 I MediaProvider: End Intent { act=android.intent.action.MEDIA_MOUNTED dat=file:///storage/emulated/0 f
lg=0x5000010 cmp=com.android.providers.media/.MediaService (has extras) }
01-14 11:04:00.003   568   568 D KeyguardClockSwitch: Updating clock: 11:04 AM
01-14 11:04:00.35011021285 I USBService: get mobileagent state 0 and current mobileagent state 0 and usb state of connection fals
e
01-14 11:04:00.378   391   413 W WindowManager: Unable to start animation, surface is null or no children.
01-14 11:04:00.42512201220 D StorageList: VolumnState:mounted
01-14 11:04:00.42512201220 D StorageList: Storage'paths:/storage/emulated/0 state:mounted
01-14 11:04:00.42712201220 D DeviceTest-FileUitls: find path:/storage/emulated/0
01-14 11:04:00.42812201220 D StorageList: VolumnState:mounted















1-14 11:04:06.21614261465 I AdapterState: OFF : entered
01-14 11:04:06.21614261465 D AdapterProperties: Setting state to OFF
01-14 11:04:06.21614261465 D BluetoothAdapterService: updateAdapterState() - Broadcasting state OFF to 1 receivers.
01-14 11:04:06.216   391   412 D BluetoothManagerService: MESSAGE_BLUETOOTH_STATE_CHANGE: BLE_TURNING_OFF > OFF
01-14 11:04:06.216   391   412 D BluetoothManagerService: Bluetooth is complete send Service Down
01-14 11:04:06.216   391   412 D BluetoothManagerService: Broadcasting onBluetoothServiceDown() to 3 receivers.
01-14 11:04:06.216   391   412 D BluetoothAdapter: onBluetoothServiceDown: android.bluetooth.IBluetooth$Stub$Proxy@263f854
01-14 11:04:06.217   391   412 D BluetoothManagerService: unbindAndFinish(): android.bluetooth.IBluetooth$Stub$Proxy@263f854 mBinding
= false mUnbinding = false
01-14 11:04:06.217   568   865 D BluetoothAdapter: onBluetoothServiceDown: android.bluetooth.IBluetooth$Stub$Proxy@5d357c4
01-14 11:04:06.21714261680 D BluetoothAdapter: onBluetoothServiceDown: com.android.bluetooth.btservice.AdapterService$AdapterServ
iceBinder@ccdea88
01-14 11:04:06.220   391   412 D BluetoothManagerService: Sending BLE State Change: BLE_TURNING_OFF > OFF
01-14 11:04:06.220   391   412 D BluetoothManagerService: Entering STATE_OFF but mEnabled is true; restarting.
01-14 11:04:06.220   391   412 E BluetoothManagerService: waitForOnOff time out






jpchen 发表于 2021-2-2 14:43:34

大体上是com.android.bluetooth.btservice.ProfileService.onStartCommand 里面出现了问题,
自己可以进行调试查找一下出错的原因
页: [1]
查看完整版本: ROC-RK3328-PC开机的时候偶尔报错蓝牙停止运行