Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Recognising from Bluetooth headphones works once in a blue moon #184

Open
ncfavier opened this issue Sep 29, 2024 · 2 comments
Open

Recognising from Bluetooth headphones works once in a blue moon #184

ncfavier opened this issue Sep 29, 2024 · 2 comments

Comments

@ncfavier
Copy link

I am using SongRec 0.4.2 from nixpkgs (https://github.com/NixOS/nixpkgs/blob/4f807e8940284ad7925ebd0a0993d2a1791acb2f/pkgs/applications/audio/songrec/default.nix), PipeWire 1.2.3, and Sony WH-CH720N wireless headphones with BlueZ 5.76 and the "High Fidelity Playback (A2DP sink, codec AAC)" audio profile.

When I tick "recognise from my speakers" in SongRec and choose "Monitor of WH-CH720N" as the input, the following things happen:

  • the audio profile switches to "Headset Head Unit (HSP/HFP, codec mSBC)"
  • the volume meter continues reflecting the volume from my microphone and no detection happens
  • pavucontrol still shows my microphone as the input source for SongRec
  • after a while, the profile switches back to AAC. Sometimes it doesn't.
  • sometimes the following message shows up in my kernel logs: 
    kernel: Bluetooth: hci0: SCO packet for unknown connection handle 3584
  • If I try to change the input source manually in pavucontrol, sometimes it works and sometimes it doesn't. Sometimes things like this show up in my systemd journal: 
    pipewire[3456]: pw.node: (alsa_input.pci-0000_06_00.6.HiFi__Mic2__source-434) graph xrun not-triggered (3 suppressed)
pipewire[3456]: pw.node: (alsa_input.pci-0000_06_00.6.HiFi__Mic2__source-434) xrun state:0x7f13483a5008 pending:2/7 s:669792196610278 a:669792196749079 f:669792196751905 waiting:138801 process:2826 status:triggered
wireplumber[3459]: pw.node: (bluez_output.00_A4_1C_04_D7_76.1-135) graph xrun not-triggered (0 suppressed)
wireplumber[3459]: pw.node: (-135) xrun state:0x7fbf7c272008 pending:1/4 s:669792451157975 a:669792451213720 f:669792451251000 waiting:55745 process:37280 status:triggered
    It all seems very random.

Similar to #177 but I'm not using Flatpak.
@teou1
Copy link

teou1 commented Oct 3, 2024

I can confirm this. I am not sure it is really a bug, i think this is the intended behavior for pipewire. It probably just get fixed now :) I am on manjaro stable, arch derivative with 3 branches, so on stable the packets are slightly older, but since 2 days i have newer versions too and i am affected.

Here are some logs if it helps:

[teo@teo-lenovo-v15 ~]$ journalctl -f
Okt 03 01:23:23 teo-lenovo-v15 kernel: Bluetooth: hci0: SCO packet for unknown connection handle 257
Okt 03 01:23:23 teo-lenovo-v15 wireplumber[1028]: pw.node: (bluez_output.98_47_44_51_11_E3.1-82) graph xrun not-triggered (0 suppressed)
Okt 03 01:23:23 teo-lenovo-v15 wireplumber[1028]: pw.node: (-82) xrun state:0x7fae4ac2d008 pending:1/4 s:1431246623391 a:1431246809196 f:1431246826741 waiting:185805 process:17545 status:triggered
Okt 03 01:23:53 teo-lenovo-v15 systemd[1]: Starting Hostname Service...
Okt 03 01:23:53 teo-lenovo-v15 systemd[1]: Started Hostname Service.
Okt 03 01:24:05 teo-lenovo-v15 systemd[925]: Starting Virtual filesystem metadata service...
Okt 03 01:24:06 teo-lenovo-v15 systemd[925]: Started Virtual filesystem metadata service.
Okt 03 01:24:23 teo-lenovo-v15 systemd[1]: systemd-hostnamed.service: Deactivated successfully.
Okt 03 01:24:44 teo-lenovo-v15 systemd[925]: Started dbus-:[email protected].
Okt 03 01:24:45 teo-lenovo-v15 vokoscreenNG[2860]: 01:24:45 [vokoscreenNG] Desktop session is a X11 session
Okt 03 01:25:22 teo-lenovo-v15 rtkit-daemon[1036]: Successfully made thread 2912 of process 2902 owned by '1000' RT at priority 20.
Okt 03 01:25:22 teo-lenovo-v15 rtkit-daemon[1036]: Supervising 7 threads of 4 processes of 1 users.
Okt 03 01:25:22 teo-lenovo-v15 kdeconnectd[1212]: 2024-10-03T01:25:22 org.kde.pulseaudio: No object for name "bluez_output.98_47_44_51_11_E3.1"
Okt 03 01:25:22 teo-lenovo-v15 pipewire[1027]: pw.node: (alsa_input.pci-0000_00_1f.3.analog-stereo-50) graph xrun not-triggered (3 suppressed)
Okt 03 01:25:22 teo-lenovo-v15 pipewire[1027]: pw.node: (alsa_input.pci-0000_00_1f.3.analog-stereo-50) xrun state:0x7f65469aa008 pending:1/7 s:1549859564905 a:1549859631778 f:1549859633816 waiting:66873 process:2038 status:triggered
Okt 03 01:25:24 teo-lenovo-v15 kdeconnectd[1212]: 2024-10-03T01:25:24 org.kde.pulseaudio: No object for name "bluez_output.98_47_44_51_11_E3.1"
Okt 03 01:25:24 teo-lenovo-v15 kernel: Bluetooth: hci0: SCO packet for unknown connection handle 257
Okt 03 01:25:44 teo-lenovo-v15 pipewire[1027]: pw.node: (alsa_input.pci-0000_00_1f.3.analog-stereo-50) graph xrun not-triggered (3 suppressed)
Okt 03 01:25:44 teo-lenovo-v15 pipewire[1027]: pw.node: (alsa_input.pci-0000_00_1f.3.analog-stereo-50) xrun state:0x7f65469aa008 pending:1/5 s:1571651534467 a:1571651724081 f:1571651727220 waiting:189614 process:3139 status:triggered
Okt 03 01:25:59 teo-lenovo-v15 rtkit-daemon[1036]: Successfully made thread 2935 of process 2902 owned by '1000' RT at priority 20.
Okt 03 01:25:59 teo-lenovo-v15 rtkit-daemon[1036]: Supervising 7 threads of 4 processes of 1 users.
Okt 03 01:25:59 teo-lenovo-v15 kdeconnectd[1212]: 2024-10-03T01:25:59 org.kde.pulseaudio: No object for name "bluez_output.98_47_44_51_11_E3.1"
Okt 03 01:25:59 teo-lenovo-v15 pipewire[1027]: pw.node: (alsa_input.pci-0000_00_1f.3.analog-stereo-50) graph xrun not-triggered (1 suppressed)
Okt 03 01:25:59 teo-lenovo-v15 pipewire[1027]: pw.node: (alsa_input.pci-0000_00_1f.3.analog-stereo-50) xrun state:0x7f65469aa008 pending:2/7 s:1586718178917 a:1586718251122 f:1586718252571 waiting:72205 process:1449 status:triggered
Okt 03 01:26:01 teo-lenovo-v15 kdeconnectd[1212]: 2024-10-03T01:26:01 org.kde.pulseaudio: No object for name "bluez_output.98_47_44_51_11_E3.1"
Okt 03 01:26:01 teo-lenovo-v15 kernel: Bluetooth: hci0: SCO packet for unknown connection handle 257
Okt 03 01:26:01 teo-lenovo-v15 wireplumber[1028]: pw.node: (bluez_output.98_47_44_51_11_E3.1-82) graph xrun not-triggered (0 suppressed)
Okt 03 01:26:01 teo-lenovo-v15 wireplumber[1028]: pw.node: (-82) xrun state:0x7fae4ac2d008 pending:1/4 s:1588859709519 a:1588859797578 f:1588859819500 waiting:88059 process:21922 status:triggered
Okt 03 01:26:42 teo-lenovo-v15 pipewire[1027]: pw.node: (alsa_input.pci-0000_00_1f.3.analog-stereo-50) graph xrun not-triggered (3 suppressed)
Okt 03 01:26:42 teo-lenovo-v15 pipewire[1027]: pw.node: (alsa_input.pci-0000_00_1f.3.analog-stereo-50) xrun state:0x7f65469aa008 pending:2/1 s:1629352694427 a:1629352757806 f:1629352759968 waiting:63379 process:2162 status:triggered
Okt 03 01:26:42 teo-lenovo-v15 wireplumber[1028]: pw.node: (bluez_output.98_47_44_51_11_E3.1-82) graph xrun not-triggered (7 suppressed)
Okt 03 01:26:42 teo-lenovo-v15 wireplumber[1028]: pw.node: (-82) xrun state:0x7fae4ac2d008 pending:5/2 s:1629355717141 a:1629355799064 f:1629355811450 waiting:81923 process:12386 status:triggered

============================= suddenly works

Okt 03 14:00:00 teo-lenovo-v15 wireplumber[1019]: pw.node: (bluez_output.98_47_44_51_11_E3.1-81) graph xrun not-triggered (0 suppressed)
Okt 03 14:00:00 teo-lenovo-v15 wireplumber[1019]: pw.node: (-81) xrun state:0x7f622b7af008 pending:1/4 s:6517751943663 a:6517752007214 f:6517752016490 waiting:63551 process:9276 status:triggered
Okt 03 14:00:00 teo-lenovo-v15 systemd[1]: run-timeshift-4165-backup.mount: Deactivated successfully.
Okt 03 14:00:00 teo-lenovo-v15 CROND[4164]: (root) CMDEND (timeshift --check --scripted)
Okt 03 14:01:00 teo-lenovo-v15 CROND[4231]: (root) CMD (run-parts /etc/cron.hourly)
Okt 03 14:01:00 teo-lenovo-v15 CROND[4230]: (root) CMDEND (run-parts /etc/cron.hourly)
Okt 03 14:01:15 teo-lenovo-v15 systemd[917]: Started dbus-:[email protected].
Okt 03 14:02:53 teo-lenovo-v15 wireplumber[1019]: pw.node: (bluez_output.98_47_44_51_11_E3.1-81) graph xrun not-triggered (1 suppressed)
Okt 03 14:02:53 teo-lenovo-v15 wireplumber[1019]: pw.node: (-81) xrun state:0x7f622b7af008 pending:1/3 s:6691063943726 a:6691063971575 f:6691064004874 waiting:27849 process:33299 status:triggered
Okt 03 14:04:13 teo-lenovo-v15 wireplumber[1019]: pw.node: (bluez_output.98_47_44_51_11_E3.1-81) graph xrun not-triggered (13 suppressed)
Okt 03 14:04:13 teo-lenovo-v15 wireplumber[1019]: pw.node: (-81) xrun state:0x7f622b7af008 pending:1/5 s:6771309267159 a:6771309366726 f:6771309574038 waiting:99567 process:207312 status:triggered
Okt 03 14:05:42 teo-lenovo-v15 wireplumber[1019]: pw.node: (bluez_output.98_47_44_51_11_E3.1-81) graph xrun not-triggered (13 suppressed)
Okt 03 14:05:42 teo-lenovo-v15 wireplumber[1019]: pw.node: (-81) xrun state:0x7f622b7af008 pending:1/7 s:6859895951071 a:6859896130787 f:6859896157564 waiting:179716 process:26777 status:triggered
Okt 03 14:06:10 teo-lenovo-v15 wireplumber[1019]: pw.node: (bluez_output.98_47_44_51_11_E3.1-81) graph xrun not-triggered (12 suppressed)
Okt 03 14:06:10 teo-lenovo-v15 wireplumber[1019]: pw.node: (-81) xrun state:0x7f622b7af008 pending:1/5 s:6887927952187 a:6887928057319 f:6887928075289 waiting:105132 process:17970 status:triggered
Okt 03 14:06:51 teo-lenovo-v15 wireplumber[1019]: pw.node: (bluez_output.98_47_44_51_11_E3.1-81) graph xrun not-triggered (16 suppressed)
Okt 03 14:06:51 teo-lenovo-v15 wireplumber[1019]: pw.node: (-81) xrun state:0x7f622b7af008 pending:2/6 s:6929090596259 a:6929090668811 f:6929090836932 waiting:72552 process:168121 status:triggered
Okt 03 14:07:32 teo-lenovo-v15 wireplumber[1019]: pw.node: (bluez_output.98_47_44_51_11_E3.1-81) graph xrun not-triggered (0 suppressed)
Okt 03 14:07:32 teo-lenovo-v15 wireplumber[1019]: pw.node: (-81) xrun state:0x7f622b7af008 pending:1/3 s:6970109263963 a:6970109327565 f:6970109370961 waiting:63602 process:43396 status:triggered
Okt 03 14:08:30 teo-lenovo-v15 wireplumber[1019]: pw.node: (bluez_output.98_47_44_51_11_E3.1-81) graph xrun not-triggered (9 suppressed)
Okt 03 14:08:30 teo-lenovo-v15 wireplumber[1019]: pw.node: (-81) xrun state:0x7f622b7af008 pending:1/3 s:7028039933763 a:7028040003880 f:7028040060644 waiting:70117 process:56764 status:triggered
Okt 03 14:10:25 teo-lenovo-v15 rtkit-daemon[1029]: Successfully made thread 4767 of process 4757 owned by '1000' RT at priority 20.
Okt 03 14:10:25 teo-lenovo-v15 rtkit-daemon[1029]: Supervising 7 threads of 4 processes of 1 users.
Okt 03 14:10:48 teo-lenovo-v15 systemd[917]: Started dbus-:[email protected].

*****************************************

[teo@teo-lenovo-v15 ~]$ pactl info
Server String: /run/user/1000/pulse/native
Library Protocol Version: 35
Server Protocol Version: 35
Is Local: yes
Client Index: 502
Tile Size: 65472
User Name: teo
Host Name: teo-lenovo-v15
Server Name: PulseAudio (on PipeWire 1.2.3)
Server Version: 15.0.0
Default Sample Specification: float32le 2ch 48000Hz
Default Channel Map: front-left,front-right
Default Sink: bluez_output.98_47_44_51_11_E3.1
Default Source: alsa_input.pci-0000_00_1f.3.analog-stereo
Cookie: 989c:e35b

[teo@teo-lenovo-v15 ~]$ inxi -Aa
Audio:
  Device-1: Intel Jasper Lake HD Audio vendor: Lenovo driver: snd_hda_intel
    v: kernel alternate: snd_sof_pci_intel_icl bus-ID: 00:1f.3
    chip-ID: 8086:4dc8 class-ID: 0403
  API: ALSA v: k6.6.52-1-MANJARO status: kernel-api with: aoss
    type: oss-emulator tools: alsactl,alsamixer,amixer
  Server-1: sndiod v: N/A status: off tools: aucat,midicat,sndioctl
  Server-2: JACK v: 1.9.22 status: off tools: N/A
  Server-3: PipeWire v: 1.2.3 status: active with: 1: pipewire-pulse
    status: active 2: wireplumber status: active 3: pipewire-alsa type: plugin
    tools: pactl,pw-cat,pw-cli,wpctl

I made a video to illustrate
https://youtu.be/R9HE2r8ZSoM

Now, i also found a workaround, that fixes it and also the search actually (i guess the recognition did not work because the profile switching takes time and distorts the sample send to server): disable the automatic bluetooth profile switching between headset and audio profile. As shown here - https://wiki.archlinux.org/title/PipeWire#Automatic_profile_selection
Now, i am on a laptop and the laptop mic is good anyways, so i can use that is someone calls me on some messenger. Well, i now have to pause the music manually. I can imagine on a desktop it will be some more problematic, if you really have to use the headset mic: pause the music, open pavu control, switch the bluetooth profile. Still, it works and can be automated. For me, this works because i rearly use messengers for audio calls and am on laptop, so the headset is mainly for music.

To sum it up: a valid workaround is to disable automatic switching to bluetooth headset profile (and not use headset mic), introduced in recent pipewire/wireplumber versions, as shown in arch wiki:
Make a file ~/.config/wireplumber/wireplumber.conf.d/11-bluetooth-policy.conf

wireplumber.settings = {
    bluetooth.autoswitch-to-headset-profile = false
}

And reboot/restart service.

@ncfavier
Copy link
Author

ncfavier commented Oct 3, 2024

I can confirm that disabling headset profile autoswitching fixes the issue. Thanks for the workaround!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@ncfavier @teou1