Bluetooth socket is disconnected abnormally on Android 9

[xingtangcunliu]

hi,
I’m having a problem with my Radxa Zero Bluetooth on Android 9.
The zero development board starts the classic Bluetooth as the server, and uses the peer mobile phone to connect and send data. After a successful Bluetooth connection, the mobile phone and the development board transmit heartbeats to each other (intervals of 5 seconds, 10 seconds, 15 seconds, 30 seconds, and 1 minute have been tried) , the development board will not receive data in about 3 minutes. If the heartbeat interval exceeds 30 seconds, there is a high probability that there will be no response, and the development board will not report an error, but it will report an error if it is less than 30 seconds.

[Hola]

Not only Bluetooth disconnects…
…Wi-Fi isn’t any better!

My Zero Wifi is not working

@RadxaYuntian Board model: Zero 4GB/16GB D4E16H v1.5 with AW-CM256SM wireless module Since I cannot test the board with the console right now, I have attached the logcat file from Android (it contains the kernel logs too). adb logcat -b all -v threadtime > logcat.txt logcat.zip (1.1 MB) Some notes about the log file: I have anonymised all MAC Address by replacing them with ab:cd:ed:01:02:03, just in case you wonder Our Wi-Fi network is called AllNet WiFi At time 11:58 I started to play…

[xingtangcunliu]

I used other Radxa Zero for testing, but the Bluetooth still breaks.

[xingtangcunliu]

03-11 11:36:40.935 I/amlaudioMixer( 3157): port index 0 is active now
03-11 11:36:40.936 I/audio_hw_subMixingFactory( 3157): padding_bytes 14336
03-11 11:36:40.936 I/audio_hw_subMixingFactory( 3157): padding_bytes 12288
03-11 11:36:40.936 I/audio_hw_subMixingFactory( 3157): padding_bytes 10240
03-11 11:36:40.936 I/audio_hw_subMixingFactory( 3157): padding_bytes 8192
03-11 11:36:40.936 I/amlaudioMixer( 3157): mixer_16b_threadloop() wakeup
03-11 11:36:40.941 I/audio_hw_subMixingFactory( 3157): padding_bytes 6144
03-11 11:36:40.941 I/amlaudioMixer( 3157): ++mixer_output_startup start open
03-11 11:36:40.941 I/audio_hw_port( 3157): output_port_start(), open ALSA hw:0,1
03-11 11:36:40.946 I/audio_hw_subMixingFactory( 3157): padding_bytes 4096
03-11 11:36:40.952 I/audio_hw_subMixingFactory( 3157): padding_bytes 2048
03-11 11:36:40.955 I/Gralloc: framebuffer hal alread move to hwcomposer
03-11 11:36:40.957 I/Gralloc: framebuffer hal alread move to hwcomposer
03-11 11:36:40.959 I/Gralloc: framebuffer hal alread move to hwcomposer
03-11 11:36:40.962 D/mali_winsys( 3843): EGLint new_window_surface(egl_winsys_display , void , EGLSurface, EGLConfig, egl_winsys_surface , EGLBoolean) returns 0x3000
03-11 11:36:40.982 I/Gralloc: framebuffer hal alread move to hwcomposer
03-11 11:36:40.984 D/AudioFlinger( 3177): mixer(0xa1583fc0) throttle end: throttle time(9)
03-11 11:36:41.000 D/RemoteIME( 3843): keycode: 43, realAction: false
03-11 11:36:41.000 D/RemoteIME( 3843): processKeys: processChooseSoftKeys
03-11 11:36:41.000 D/RemoteIME( 3843): ChooseSoftKeys: 43
03-11 11:36:41.000 D/RemoteIME( 3843): processKeys: isEnglishWithSkb
03-11 11:36:41.001 D/RemoteIME( 3843): keycode: 43, realAction: true
03-11 11:36:41.001 D/RemoteIME( 3843): processKeys: processChooseSoftKeys
03-11 11:36:41.001 D/RemoteIME( 3843): ChooseSoftKeys: 43
03-11 11:36:41.001 D/RemoteIME( 3843): processKeys: isEnglishWithSkb
03-11 11:36:41.200 E/BufferQueueProducer( 3179): [PopupWindow:bbcd89#0] disconnect: not connected (req=1)
03-11 11:36:41.201 W/libEGL ( 3843): EGLNativeWindowType 0x8b39e808 disconnect failed
03-11 11:36:41.480 I/Gralloc: framebuffer hal alread move to hwcomposer
03-11 11:36:41.993 W/AudioFlinger( 3177): createTrack_l(): mismatch between requested flags (00000004) and output flags (00000002)
03-11 11:36:41.994 W/AudioTrack( 3383): AUDIO_OUTPUT_FLAG_FAST denied by server; frameCount 0 -> 4512
03-11 11:36:45.085 D/audio_hw_subMixingFactory( 3157): out_standby_subMixingPCM: out_stream(0xa6dfc000) usecase: STREAM_PCM_NORMAL
03-11 11:36:45.085 I/audio_hw_subMixingFactory( 3157): ++usecase_change_validate_l_sm(), dev usecase masks = 0x1, is_standby = 1, out usecase STREAM_PCM_NORMAL
03-11 11:36:45.085 I/audio_hw_subMixingFactory( 3157): --usecase_change_validate_l_sm(), dev usecase masks = 0, is_standby = 1, out usecase STREAM_PCM_NORMAL
03-11 11:36:45.085 I/amlaudioMixer( 3157): ++delete_mixer_input_port port ID: 0
03-11 11:36:45.085 E/amlaudioMixer( 3157): mixer_do_mixing_16bit(), sys or direct pcm must exist!!!
03-11 11:36:46.090 I/amlaudioMixer( 3157): ++mixer_output_standby standby
03-11 11:36:46.090 I/audio_hw_port( 3157): output_port_standby()
03-11 11:36:46.091 I/amlaudioMixer( 3157): mixer_16b_threadloop() sleep
03-11 11:36:46.802 E/storaged( 3241): getDiskStats failed with result NOT_SUPPORTED and size 0
03-11 11:36:51.596 I/system_server( 3383): Background concurrent copying GC freed 20564(1018KB) AllocSpace objects, 1(20KB) LOS objects, 19% free, 4MB/5MB, paused 565us total 133.750ms
03-11 11:36:58.805 E/bt_hci ( 3502): command_timed_out: 1 commands pending response
03-11 11:36:58.805 E/bt_hci ( 3502): command_timed_out: Waited 2003 ms for a response to opcode: 0x803 matches timer
03-11 11:36:58.805 E/bt_hci ( 3502): command_timed_out: Size 13 Hex 03 08 0a 0b
03-11 11:36:58.806 E/bt_hci ( 3502): command_timed_out: requesting a firmware dump.
03-11 11:36:58.807 E/bt_hci ( 3502): command_timed_out: Setting a timer to restart.
03-11 11:37:03.807 E/bt_hci ( 3502): hci_timeout_abort restarting the Bluetooth process.
--------- beginning of crash
03-11 11:37:03.808 F/libc ( 3502): Fatal signal 6 (SIGABRT), code -6 (SI_TKILL) in tid 3634 (alarm_default_c), pid 3502 (droid.bluetooth)
03-11 11:37:03.913 I/crash_dump32( 4704): obtaining output fd from tombstoned, type: kDebuggerdTombstone
03-11 11:37:03.914 I//system/bin/tombstoned( 3251): received crash request for pid 3634
03-11 11:37:03.916 I/crash_dump32( 4704): performing dump of process 3502 (target tid = 3634)
03-11 11:37:03.938 F/DEBUG ( 4704): *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***
03-11 11:37:03.938 F/DEBUG ( 4704): Build fingerprint: ‘Droidlogic/faraday/faraday:9/PPR1.180610.011/20210727:userdebug/test-keys’
03-11 11:37:03.938 F/DEBUG ( 4704): Revision: ‘0’
03-11 11:37:03.938 F/DEBUG ( 4704): ABI: ‘arm’
03-11 11:37:03.938 F/DEBUG ( 4704): pid: 3502, tid: 3634, name: alarm_default_c >>> com.android.bluetooth <<<
03-11 11:37:03.938 F/DEBUG ( 4704): signal 6 (SIGABRT), code -6 (SI_TKILL), fault addr --------
03-11 11:37:03.938 F/DEBUG ( 4704): r0 00000000 r1 00000e32 r2 00000006 r3 a6798918
03-11 11:37:03.939 F/DEBUG ( 4704): r4 00000dae r5 00000e32 r6 8b4ff224 r7 0000010c
03-11 11:37:03.939 F/DEBUG ( 4704): r8 8ba4baf9 r9 00000000 r10 a4e0cea0 r11 00000000
03-11 11:37:03.939 F/DEBUG ( 4704): ip 00000041 sp 8b4ff210 lr a67270e5 pc a671ee72
03-11 11:37:03.986 F/DEBUG ( 4704):
03-11 11:37:03.986 F/DEBUG ( 4704): backtrace:
03-11 11:37:03.986 F/DEBUG ( 4704): #00 pc 0001ce72 /system/lib/libc.so (abort+62)
03-11 11:37:03.986 F/DEBUG ( 4704): #01 pc 0010bb17 /system/lib/libbluetooth.so (hci_timeout_abort(void)+30)
03-11 11:37:03.986 F/DEBUG ( 4704): #02 pc 001a570d /system/lib/libbluetooth.so (alarm_ready_generic(alarm_t, std::__1::unique_lockstd::__1::mutex&)+164)
03-11 11:37:03.986 F/DEBUG ( 4704): #03 pc 001a562b /system/lib/libbluetooth.so (alarm_queue_ready(fixed_queue_t, void)+66)
03-11 11:37:03.986 F/DEBUG ( 4704): #04 pc 001a8205 /system/lib/libbluetooth.so (internal_dequeue_ready(void*)+48)
03-11 11:37:03.986 F/DEBUG ( 4704): #05 pc 001aa313 /system/lib/libbluetooth.so (run_reactor(reactor_t*, int)+218)
03-11 11:37:03.986 F/DEBUG ( 4704): #06 pc 001aa20d /system/lib/libbluetooth.so (reactor_start(reactor_t*)+44)
03-11 11:37:03.986 F/DEBUG ( 4704): #07 pc 001ab3a7 /system/lib/libbluetooth.so (run_thread(void*)+142)
03-11 11:37:03.986 F/DEBUG ( 4704): #08 pc 00063c15 /system/lib/libc.so (__pthread_start(void*)+22)
03-11 11:37:03.987 F/DEBUG ( 4704): #09 pc 0001e065 /system/lib/libc.so (__start_thread+22)
03-11 11:37:04.686 E//system/bin/tombstoned( 3251): Tombstone written to: /data/tombstones/tombstone_19
03-11 11:37:04.745 E/android.hardware.bluetooth@1.0-impl( 3158): BluetoothDeathRecipient::serviceDied - Bluetooth service died
03-11 11:37:04.745 I/android.hardware.bluetooth@1.0-impl( 3158): BluetoothHci::close()
03-11 11:37:04.745 I/android.hardware.bluetooth@1.0-impl( 3158): Skipping unlink call, service died.
03-11 11:37:04.745 W/BluetoothManagerService( 3383): Profile service for profile: ComponentInfo{com.android.bluetooth/com.android.bluetooth.hfp.HeadsetService} died.
03-11 11:37:04.746 D/BluetoothHeadset( 3383): Proxy object disconnected
03-11 11:37:04.746 W/AudioService.PlaybackActivityMonitor( 3383): client died
03-11 11:37:04.746 D/BluetoothManagerService( 3383): BluetoothServiceConnection, disconnected: com.android.bluetooth.btservice.AdapterService
03-11 11:37:04.746 D/BluetoothA2dp( 3383): Proxy object disconnected
03-11 11:37:04.746 E/BluetoothManagerService( 3383): MESSAGE_BLUETOOTH_SERVICE_DISCONNECTED(1)
03-11 11:37:04.746 I/AudioService( 3383): setBtScoActiveDevice: null -> null
03-11 11:37:04.746 D/BluetoothManagerService( 3383): BluetoothServiceConnection, disconnected: com.android.bluetooth.gatt.GattService
03-11 11:37:04.746 I/ActivityManager( 3383): Process com.android.bluetooth (pid 3502) has died: psvc PER
03-11 11:37:04.747 D/BluetoothManagerService( 3383): Broadcasting onBluetoothServiceDown() to 6 receivers.
03-11 11:37:04.747 W/ActivityManager( 3383): Scheduling restart of crashed service com.android.bluetooth/.avrcp.AvrcpTargetService in 1000ms
03-11 11:37:04.747 W/ActivityManager( 3383): Scheduling restart of crashed service com.android.bluetooth/.pbap.BluetoothPbapService in 1000ms
03-11 11:37:04.747 W/ActivityManager( 3383): Scheduling restart of crashed service com.android.bluetooth/.gatt.GattService in 1000ms
03-11 11:37:04.747 W/ActivityManager( 3383): Scheduling restart of crashed service com.android.bluetooth/.map.BluetoothMapService in 11000ms
03-11 11:37:04.747 W/libprocessgroup( 3383): kill(-3502, 9) failed: No such process
03-11 11:37:04.747 W/ActivityManager( 3383): Scheduling restart of crashed service com.android.bluetooth/.hdp.HealthService in 11000ms
03-11 11:37:04.747 W/ActivityManager( 3383): Scheduling restart of crashed service com.android.bluetooth/.hid.HidHostService in 11000ms
03-11 11:37:04.747 W/ActivityManager( 3383): Scheduling restart of crashed service com.android.bluetooth/.hid.HidDeviceService in 11000ms
03-11 11:37:04.747 W/ActivityManager( 3383): Scheduling restart of crashed service com.android.bluetooth/.btservice.AdapterService in 11000ms
03-11 11:37:04.747 W/ActivityManager( 3383): Scheduling restart of crashed service com.android.bluetooth/.hfp.HeadsetService in 21000ms
03-11 11:37:04.748 W/ActivityManager( 3383): Scheduling restart of crashed service com.android.bluetooth/.pan.PanService in 20999ms
03-11 11:37:04.748 W/ActivityManager( 3383): Scheduling restart of crashed service com.android.bluetooth/.a2dp.A2dpService in 20999ms
03-11 11:37:04.748 D/BluetoothAdapter( 3383): onBluetoothServiceDown: android.bluetooth.IBluetooth$Stub$Proxy@5778c2
03-11 11:37:04.748 D/BluetoothAdapter( 3555): onBluetoothServiceDown: android.bluetooth.IBluetooth$Stub$Proxy@733ff94
03-11 11:37:04.748 D/BluetoothManagerService( 3383): Sending BLE State Change: ON > TURNING_OFF
03-11 11:37:04.748 D/BluetoothAdapter( 3950): onBluetoothServiceDown: android.bluetooth.IBluetooth$Stub$Proxy@ea03476
03-11 11:37:04.749 E/BluetoothChatService( 4064): disconnected
03-11 11:37:04.749 D/BluetoothAdapter( 4064): onBluetoothServiceDown: android.bluetooth.IBluetooth$Stub$Proxy@6538c4
03-11 11:37:04.749 D/BluetoothAdapter( 4053): onBluetoothServiceDown: android.bluetooth.IBluetooth$Stub$Proxy@97b1a3d
03-11 11:37:04.749 D/BluetoothAdapter( 4250): onBluetoothServiceDown: android.bluetooth.IBluetooth$Stub$Proxy@2877f85
03-11 11:37:04.749 D/BluetoothChatService( 4064): updateUserInterfaceTitle() 3 -> 0
03-11 11:37:04.749 D/BluetoothChatService( 4064): start
03-11 11:37:04.749 D/BluetoothSocket( 4064): close() this: android.bluetooth.BluetoothSocket@dfd13ad, channel: 6, mSocketIS: android.net.LocalSocketImpl$SocketInputStream@58e46e2, mSocketOS: android.net.LocalSocketImpl$SocketOutputStream@bf93a73mSocket: android.net.LocalSocket@df1d30 impl:android.net.LocalSocketImpl@d043da9 fd:java.io.FileDescriptor@f4def2e, mSocketState: CONNECTED
03-11 11:37:04.751 I/Zygote ( 3151): Process 3502 exited due to signal (6)
03-11 11:37:04.760 W/BluetoothAdapter( 4064): getBluetoothService() called with no BluetoothManagerCallback
03-11 11:37:04.760 E/BluetoothSocket( 4064): bindListen fail, reason: bluetooth is off
03-11 11:37:04.761 E/BluetoothChatService( 4064): Socket Type: Securelisten() failed
03-11 11:37:04.762 D/BluetoothChatService( 4064): Socket Type: SecureBEGIN mAcceptThreadThread[Thread-22,5,main]
03-11 11:37:04.763 E/AndroidRuntime( 4064): FATAL EXCEPTION: AcceptThreadSecure
03-11 11:37:04.763 E/AndroidRuntime( 4064): Process: com.example.android.bluetoothchat, PID: 4064
03-11 11:37:04.763 E/AndroidRuntime( 4064): java.lang.NullPointerException: Attempt to invoke virtual method ‘android.bluetooth.BluetoothSocket android.bluetooth.BluetoothServerSocket.accept()’ on a null object reference
03-11 11:37:04.763 E/AndroidRuntime( 4064): at com.example.android.bluetoothchat.BluetoothChatService$AcceptThread.run(BluetoothChatService.java:339)
03-11 11:37:04.763 W/BluetoothAdapter( 4064): getBluetoothService() called with no BluetoothManagerCallback
03-11 11:37:04.763 E/BluetoothSocket( 4064): bindListen fail, reason: bluetooth is off
03-11 11:37:04.764 E/BluetoothChatService( 4064): Socket Type: Insecurelisten() failed
03-11 11:37:04.766 D/BluetoothChatService( 4064): Socket Type: InsecureBEGIN mAcceptThreadThread[Thread-24,5,main]
03-11 11:37:04.767 I/Process ( 4064): Sending signal. PID: 4064 SIG: 9
03-11 11:37:04.769 D/BluetoothManagerService( 3383): Bluetooth is complete send Service Down
03-11 11:37:04.769 D/BluetoothManagerService( 3383): Broadcasting onBluetoothServiceDown() to 6 receivers.
03-11 11:37:04.769 D/BluetoothAdapter( 3383): onBluetoothServiceDown: null
03-11 11:37:04.770 D/BluetoothAdapter( 3950): onBluetoothServiceDown: null
03-11 11:37:04.770 D/BluetoothManagerService( 3383): unbindAndFinish(): null mBinding = false mUnbinding = false
03-11 11:37:04.770 D/BluetoothAdapter( 4053): onBluetoothServiceDown: null
03-11 11:37:04.770 D/BluetoothManagerService( 3383): Sending BLE State Change: TURNING_OFF > OFF
03-11 11:37:04.770 D/BluetoothAdapter( 3555): onBluetoothServiceDown: null
03-11 11:37:04.770 D/BluetoothAdapter( 4250): onBluetoothServiceDown: null
03-11 11:37:04.771 E/BluetoothManagerService( 3383): MESSAGE_BLUETOOTH_SERVICE_DISCONNECTED(2)
03-11 11:37:04.777 I/AudioService( 3383): setBtScoActiveDevice: null -> null
03-11 11:37:04.785 W/ActivityManager( 3383): Force finishing activity com.example.android.bluetoothchat/.MainActivity
03-11 11:37:04.792 W/libprocessgroup( 3383): kill(-3502, 9) failed: No such process
03-11 11:37:04.792 I/libprocessgroup( 3383): Successfully killed process cgroup uid 1002 pid 3502 in 45ms
03-11 11:37:04.840 W/InputDispatcher( 3383): channel ‘162e18 com.example.android.bluetoothchat/com.example.android.bluetoothchat.MainActivity (server)’ ~ Consumer closed input channel or an error occurred. events=0x9
03-11 11:37:04.840 E/InputDispatcher( 3383): channel ‘162e18 com.example.android.bluetoothchat/com.example.android.bluetoothchat.MainActivity (server)’ ~ Channel is unrecoverably broken and will be disposed!
03-11 11:37:04.845 E/bt_hwcfg( 3158): LPM parameter = 0, 0, 0, 0, 0
03-11 11:37:04.845 E/bt_hwcfg( 3158): LPM disabled!!
03-11 11:37:04.846 I/bt_userial_vendor( 3158): device fd = 6 close
03-11 11:37:04.855 I/Zygote ( 3151): Process 4064 exited due to signal (9)
03-11 11:37:04.872 I/WindowManager( 3383): WIN DEATH: Window{162e18 u0 com.example.android.bluetoothchat/com.example.android.bluetoothchat.MainActivity}
03-11 11:37:04.873 W/InputDispatcher( 3383): Attempted to unregister already unregistered input channel ‘162e18 com.example.android.bluetoothchat/com.example.android.bluetoothchat.MainActivity (server)’
03-11 11:37:04.873 I/ActivityManager( 3383): Process com.example.android.bluetoothchat (pid 4064) has died: fore TOP

[hachi]

please provide which wifi module and software link ，we will check

[xingtangcunliu]

WiFi/BT module：AP6256
software link：https://dl.radxa.com/zero/images/android/radxa_zero_android_9_20220311-fastboot.img.zip （Official Android 9 Image） @hachi