marin-m / SongRec

An open-source Shazam client for Linux, written in Rust.
GNU General Public License v3.0
1.39k stars 103 forks source link

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

Open ncfavier opened 2 months ago

ncfavier commented 2 months ago

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:

Similar to https://github.com/marin-m/SongRec/issues/177 but I'm not using Flatpak.

teou1 commented 1 month ago

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-:1.2-org.xfce.Xfconf@2.service.
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-:1.2-org.xfce.Xfconf@3.service.
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-:1.2-org.xfce.Xfconf@4.service.

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

[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 commented 1 month ago

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