bluetooth fails randomly on all qemu

Fixed

Description

bluetooth service check fail randomly on qemu-arm, qemu-arm64, qemu-x86_64

Example for arm64 https://lists.automotivelinux.org/g/agl-test-reports/message/295

Example for x86_64 https://lists.automotivelinux.org/g/agl-test-reports/message/294

 

Sometimes the service is not started like for arm in

See https://lava.automotivelinux.org/scheduler/job/9475

When debugging, I found that starting bluetooth before service checks made the test succeed.

But on some other jobs (arm64/x86_64), the service is started.

Perhaps two distinct issue ?

 

Environment

None

Activity

Show:

Corentin Labbe 
December 16, 2019 at 8:18 AM

failling bluetooth (and ofono) services checks are now skipped according to bluetooth device tag.

Corentin Labbe 
December 16, 2019 at 7:59 AM

As discussed on IRC

bluetooth.service is setup (via bluetooth.target and systemd) to be started when a dongle is detected.
You can start it manually after boot fine. But during boot, there is a race between bluetooth kernel module probing and the bluetooth unit being tried to start.
we should make the bluetooth test conditional to the bluetooth lava tag
everthing else might be error-prone and intrusive wrt systemd unit file mangling and so on.
i checked upstream systemd master and it is still the same setup, so we probably don't want to derive

Corentin Labbe 
December 4, 2019 at 1:37 PM

But why the ExecStartPre=sleep 20 you tried didnt fix the problem ?

 

Jan-Simon Moeller 
December 3, 2019 at 3:48 PM

[ 9.551107] Bluetooth: HCI device and connection manager initialized [ 9.557525] Bluetooth: HCI socket layer initialized [ 9.569373] remoteproc remoteproc0: powering up wkup_m3 [ 9.659277] remoteproc remoteproc0: Booting fw image am335x-pm-firmware.elf, size 242880 [ 9.669257] PM: Cannot get wkup_m3_ipc handle [ 9.689830] Bluetooth: L2CAP socket layer initialized [ 9.720452] [drm] Initialized pvr 1.17.4948957 20110701 for 56000000.sgx on minor 1 [ 9.750942] asoc-simple-card sound: i2s-hifi <-> 48038000.mcasp mapping ok [ 9.757901] asoc-simple-card sound: ASoC: no DMI vendor name! [ 9.766964] remoteproc remoteproc0: remote processor wkup_m3 is now up [ 9.766992] wkup_m3_ipc 44e11324.wkup_m3_ipc: CM3 Firmware Version = 0x192 [ 9.782110] Bluetooth: SCO socket layer initialized <--------------- [ 9.843388] PM: Cannot get wkup_m3_ipc handle [ 9.928320] PM: Cannot get wkup_m3_ipc handle [ 10.648595] PM: bootloader does not support rtc-only! [ 10.688770] am335x-phy-driver 47401300.usb-phy: 47401300.usb-phy supply vcc not found, using dummy regulator [ 10.776612] am335x-phy-driver 47401300.usb-phy: Linked as a consumer to regulator.0 [ 10.855042] genirq: Flags mismatch irq 59. 00002000 (vbus) vs. 00000000 (tps65217-charger) [ 10.865400] am335x-phy-driver 47401b00.usb-phy: 47401b00.usb-phy supply vcc not found, using dummy regulator [ 10.931730] musb-dsps: probe of 47401400.usb failed with error -16 [ 10.979432] am335x-phy-driver 47401b00.usb-phy: Linked as a consumer to regulator.0 [ 11.040259] musb-hdrc musb-hdrc.1: MUSB HDRC host driver [ 11.045642] musb-hdrc musb-hdrc.1: new USB bus registered, assigned bus number 1 [ 11.147386] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 4.19 [ 11.210888] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1 [ 11.218163] usb usb1: Product: MUSB HDRC host driver [ 11.297352] usb usb1: Manufacturer: Linux 4.19.73 musb-hcd [ 11.349029] usb usb1: SerialNumber: musb-hdrc.1 [ 11.384060] hub 1-0:1.0: USB hub found [ 11.404187] remoteproc remoteproc1: 4a334000.pru is available [ 11.410753] hub 1-0:1.0: 1 port detected [ 11.429556] pru-rproc 4a334000.pru: PRU rproc node pru@4a334000 probed successfully [ 11.450849] remoteproc remoteproc2: 4a338000.pru is available [ 11.456774] pru-rproc 4a338000.pru: PRU rproc node pru@4a338000 probed successfully [ 11.859096] usb 1-1: new high-speed USB device number 2 using musb-hdrc [ 12.059830] usb 1-1: New USB device found, idVendor=0424, idProduct=2514, bcdDevice= b.b3 [ 12.068067] usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0 [ 12.103922] hub 1-1:1.0: USB hub found [ 12.115475] hub 1-1:1.0: 4 ports detected [ OK ] Reached target Sound Card. [ OK ] Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch. Starting Initiate afm-system-setup... Starting Start the security manager... [ OK ] Started Initiate afm-system-setup. [ OK ] Listening on Provides websocket api network-manager for platform. [ OK ] Listening on Provides websocket api low-can for platform. [ OK ] Started Application Framework Master, system side. [ OK ] Listening on Service to start the API 'supervisor'. Starting Service to start the API 'supervisor'... Starting Expose CAN Low Level APIs through AGL Framework... Starting Binding for Networking... Starting Cynagora service... [ OK ] Started Start the security manager. [ OK ] Started Service to start the API 'supervisor'. [ OK ] Started Login Service. [ OK ] Started Telephony service. [ OK ] Started Cynagora service. [ OK ] Started Bluetooth service. <------------- [ OK ] Started Connection service. [ OK ] Reached target Network. Starting Permit User Sessions... [ 13.395866] Bluetooth: BNEP (Ethernet Emulation) ver 1.3 <-------------- [ 13.407015] can: controller area network core (rev 20170425 abi 9) [ 13.453031] Bluetooth: BNEP filters: protocol multicast [ 13.458321] Bluetooth: BNEP socket layer initialized

 

The boot log shows ths issue. The bluetooth stack takes until 13.39 to initialize fully, by then the bluetooth service is already started (and would not find the not yet ready /sys/class/bluetooth) .

Jan-Simon Moeller 
December 3, 2019 at 3:42 PM

If the 
ConditionPathIsDirectory=/sys/class/bluetooth
Is removed, the bluetooth service will successfully start.

Details

Assignee

Reporter

Priority

Created November 19, 2019 at 10:11 AM
Updated December 20, 2019 at 1:32 AM
Resolved December 16, 2019 at 8:18 AM

Flag notifications