Bluetooth connection random crash

[TheOldPresbyope]

Ref: Moode eventually unrechable... and [he is back].

So to understand better the apparent Bluetooth disconnect described in the referenced threads (started by @Maitresinh) I spun up the following system

RPi3A+
moOde 6.4.1 (stock; rpi-update has not been run)
64-bit kernel (oops, forgot I'd done this; will have to test with 32-bit kernel later)
onboard WiFi - 5GHz connection to AP
onboard BT adapter
JBL Flip2 (with external 5v power)
OpenMediaVault NAS with SMB shares (wired connection to AP)

This system played an Internet radio station for 48 hours straight, no issue.

Then I switched to playing tracks from my NAS. (In a bit of a hurry, I just told it to add all 5800 tracks on this NAS. Possibly that was a mistake; I changed this in the following test.)

After about 2 hours, I discovered the player was pronged. No output and a UI which quickly became unresponsive. 

Some interesting data from the player after the failure:

Code:

pi@moode3a:~ $  dmesg -TS
[Wed Jan 29 21:59:50 2020] Bluetooth: hci0: hardware error 0x00
[Wed Jan 29 21:59:54 2020] Bluetooth: hci0: command 0x1003 tx timeout
[Wed Jan 29 21:59:56 2020] Bluetooth: hci0: command 0x1001 tx timeout
[Wed Jan 29 21:59:58 2020] Bluetooth: hci0: command 0x1009 tx timeout

pi@moode3a:~ $ sudo hciconfig
hci0:    Type: Primary  Bus: UART
    BD Address: B8:27:EB:FB:1A:BE  ACL MTU: 1021:8  SCO MTU: 64:1
    DOWN
    RX bytes:918089 acl:61 sco:0 events:114467 errors:0
    TX bytes:188497511 acl:228795 sco:0 commands:66 errors:0

pi@moode3a:~ $ sudo hciconfig hci0 up
Can't init device hci0: Connection timed out (110)

pi@moode3a:~ $ sudo bluetoothctl
Agent registered
[bluetooth]# show
Controller B8:27:EB:FB:1A:BE (public)
    Name: Moode3a Bluetooth
    Alias: Moode3a Bluetooth
    Class: 0x00000000
    Powered: no
    Discoverable: yes
    Pairable: yes
    UUID: Audio Source              (0000110a-0000-1000-8000-00805f9b34fb)
    UUID: Audio Sink                (0000110b-0000-1000-8000-00805f9b34fb)
    UUID: A/V Remote Control        (0000110e-0000-1000-8000-00805f9b34fb)
    UUID: PnP Information           (00001200-0000-1000-8000-00805f9b34fb)
    UUID: A/V Remote Control Target (0000110c-0000-1000-8000-00805f9b34fb)
    Modalias: usb:v1D6Bp0246d0532
    Discovering: no
[bluetooth]# power on
[bluetooth]# show
Controller B8:27:EB:FB:1A:BE (public)
    Name: Moode3a Bluetooth
    Alias: Moode3a Bluetooth
    Class: 0x00000000
    Powered: no
    Discoverable: yes
    Pairable: yes
    UUID: Audio Source              (0000110a-0000-1000-8000-00805f9b34fb)
    UUID: Audio Sink                (0000110b-0000-1000-8000-00805f9b34fb)
    UUID: A/V Remote Control        (0000110e-0000-1000-8000-00805f9b34fb)
    UUID: PnP Information           (00001200-0000-1000-8000-00805f9b34fb)
    UUID: A/V Remote Control Target (0000110c-0000-1000-8000-00805f9b34fb)
    Modalias: usb:v1D6Bp0246d0532
    Discovering: no
Failed to set power on: org.bluez.Error.Failed
[bluetooth]# exit

pi@moode3a:~ $ rfkill list
0: phy0: Wireless LAN
    Soft blocked: no
    Hard blocked: no
1: hci0: Bluetooth
    Soft blocked: no
    Hard blocked: no

The interface thinks it is down, indeed, powered off, and it won't come back up (without a reboot).

Searching the Interweb™ on "hci0: hardware error 0x00" I come up with a number of similar complaints including

https://raspberrypi.stackexchange.com/qu...aker-falls
https://raspberrypi.stackexchange.com/qu...er-a-while
https://www.gitmemory.com/issue/raspberr.../551280244
https://github.com/raspberrypi/linux/issues/2832
https://www.raspberrypi.org/forums/viewt...p?t=227434
https://www.raspberrypi.org/forums/viewt...?t=229780Y

Trouble is, none of these threads identifies a root cause. Their posts do imply this is a randomly occurring problem. Meh - the worst kind of problem to fix.

I've restarted the system with bluetooth.service running bluetoothd in debug mode and also with a reasonable number of long tracks in the playback list. So far it's still cookin' after 5 hours.

This morning I mentioned I'd spun up an RPi4B to see if I could repro on a different chipset but I forgot I have only one functional BT speaker at home (the other is in my grandson's bedroom ATM). I'll get back to it once I gather more data on this RPi3A+.

Regards,
Kent

PS: for completeness, here's the obligatory system info

Code:

pi@moode3a:~ $ moodeutl -s
Generating info...

S Y S T E M   P A R A M E T E R S

moOde release        = 6.4.1 2020-01-23
Raspbian OS        = 10.2
Linux kernel        = 4.19.83-v8+ #1277
Platform        = Pi-3A+ 512 MB v1.0
Architecture        = aarch64 (64-bit)
System uptime        = up 7 hours, 56 minutes
Timezone        = America/New_York
Current time        = 2020-01-30 21:53:46

Host name        = moode3a
Ethernet address    = unassigned
Ethernet MAC        = no adapter
WLAN address        = 192.168.1.195
WLAN MAC        = b8:27:eb:04:e5:41
WLAN country        = US

SoC identifier        = bcm2837
Core count        = 4
Kernel timer freq    = 250 Hz
SDCard freq        = 50 MHz
USB boot        = not available
Warranty        = OK

Root size        = 15G
Root used        = 20%
Root available        = 12G
Root expand        = expanded
Memory free        = 35 MB
Memory used        = 132 MB
SoC temperature        = 48.3°C

CPU governor        = ondemand
Onboard WiFi        = On
Onboard BT        = On
HDMI output        = Off
Eth addr wait        = Off
Max USB current        = Off
USB (UAC2) fix        = Off
Pi-3B+ eth fix        = Off
SSH term server        = On

PHP-FPM version        = 7.3.11
NGINX version        = 1.14.2
SQLite3 version        = 3.27.2
Hostapd version        = 2.8-devel
WiringPi version    = 2.50
RPi.GPIO version    = 0.7.0

A U D I O   P A R A M E T E R S

Audio device        = On-board audio device
Interface        = SoC
Mixer name        = PCM
Hardware volume        = Controller detected
Max ALSA volume        = 100
Audio source        = Local
Output device        = Bluetooth
Resume MPD        = No
Volume knob        = 25
Volume mute        = Unmuted
Saved MPD vol        = 0
Preamp volume        = 0
ALSA version        = 1.1.8-1+rpt1
SoX version        = 0.1.2-3

Bluetooth controller    = On
Pairing agent        = On
Airplay receiver    = Off
Spotify receiver    = On
Squeezelite        = Off
UPnP client        = Off
DLNA server        = Off
GPIO button handler    = Off
UPnP browser        = Off

Auto-shuffle        = Off
Autoplay        = Off
Rotary encoder        = Off
Encoder params        = 100 2 3 23 24
Polarity inversion    = Off
Crossfeed        = Off
Crossfade        = Off
Parametric EQ        = Off
Graphic EQ        = Off
MPD httpd        = Off

A P P E A R A N C E   S E T T I N G S

Theme            = Default
Accent color        = Emerald
Alpha blend        = 1.0
Adaptive background    = No
Background image    = No
Cover backdrop        = No
Cover blur        = 20px
Cover scale        = 1.25
CoverView auto-display    = Never
CoverView style        = Animated
Auto-shuffle filter    = None
Extra metadata        = Yes
Playback history    = No

L I B R A R Y   S E T T I N G S

Instant play action    = Clear/Play
Show genres column    = Yes
Album grouping        = by Artist
Compilation identifier    = Various Artists
Recently added        = 1 Month
Ignore articles        = a,an,the
UTF8 character filter    = No
Hi-res thumbs        = Auto
Cover search pri    = Embedded cover
Pixel ratio        = 1

M P D   S E T T I N G S

Version            = 0.21.16
Volume control        = software
ALSA device        = hw:0
SoX resampling        = disabled
SoX quality        = very high
SoX multithreading    = off
DSD over PCM (DoP)    = no
Replaygain        = off
Replaygain preamp    = 0
Volume normalization    = No
Audio buffer        = 4096 (kb)
Output buffer size    = 131072 (kb)

B L U E T O O T H   S E T T I N G S

Bluetooth ver        = 5.50
Bluealsa ver        = 2.0.0
Speaker sharing        = No
Resume MPD        = No
PCM buffer time        = 500000 (μs)

A I R P L A Y   S E T T I N G S

Version            = 3.3.5
Friendly name        = Moode Airplay
ALSA device        = hw:0
Interpolation        = soxr
Output bit depth    = S16
Output sample rate    = 44100
Session interruption    = no
Session timeout        = 120 (ms)
Latency offset        = 0.0 (secs)
Audio buffer        = 0.2 (secs)
Resume MPD        = No

S P O T I F Y   S E T T I N G S

Friendly name        = Moode3a Spotify
ALSA device        = plughw:0
Bit rate        = 320
Initial volume        = 0
Volume curve        = Logarithmic
Volume normalization    = No
Normalization pregain    = 0
Resume MPD        = No

S Q U E E Z E L I T E   S E T T I N G S

Version            = 1.8.7-1052 "DSD/SRC enabled"
Friendly name        = Moode
ALSA device        = hw:0
ALSA params        = 80:4::1
Output buffers        = 40000:100000
Task priority        = 45
Codec list        = flac,pcm,mp3,ogg,aac,alac,dsd
Other options        = -W -D 500 -R E -S /var/local
Resume MPD        = No

L O C A L   D I S P L A Y   S E T T I N G S

Local UI display    = Off
Mouse cursor        = On
Screen blank        = 600 Secs
Wake display on play    = Off
Brightness        = 255
Pixel aspect ratio    = Default
Rotate screen        = 0 Deg

[TheOldPresbyope]

Sorry, I have to be out of town for several weeks and have had to power down everything before I could gather any more clues. 

I'll be watching this space to see if anyone else can repro and diagnose the issue, but I'll be unable to resume testing before the middle of February at the soonest.

Regards,
Kent

[Tim Curtis]

Nice analysis :-)

It appears to be an unresolved open kernel issue. Just have to wait to see if the kernel dev's can figure it out and possibly make a fix.
https://github.com/raspberrypi/linux/issues/2832

[TheOldPresbyope]

Nice analysis :-)

It appears to be an unresolved open kernel issue. Just have to wait to see if the kernel dev's can figure it out and possibly make a fix.
https://github.com/raspberrypi/linux/issues/2832

That's my sense too (lumping kernel and firmware together). I couldn't tell from that discussion whether actual kernel dev's were engaging in it. 

As much as I admire the RPF's all-in-one SBC designs, outboard WiFi and BT transceivers still look attractive in my use case. I like metal encasements, which are natural Faraday shields, and my cabinet is full of noisy devices and cables. The ASUS USB-BT400 adapter I use with my headphones has been bulletproof on all model RPis.

Of course, 5G technology is going to solve all our problems 

Regards,
Kent

[Tim Curtis]

lol, 5G

[Maitresinh]

I've restarted the system with bluetooth.service running bluetoothd in debug mode and also with a reasonable number of long tracks in the playback list. So far it's still cookin' after 5 hours.

This morning I mentioned I'd spun up an RPi4B to see if I could repro on a different chipset but I forgot I have only one functional BT speaker at home (the other is in my grandson's bedroom ATM). I'll get back to it once I gather more data on this RPi3A+.

Regards,
Kent

I know it may sound dumb, but you should try wiuth a complet album. At least for me, the problem seems to happen (almost ?) only when coming to the last second of the last track on an album. Will have to try more to be sure, but i've noticed that last time.