thewierdnut / asha_pipewire_sink

Asha audio protocol implementation for linux.
The Unlicense
28 stars 3 forks source link

Tests on Bernafon Alpha 3 ITC #10

Closed tomektom closed 3 months ago

tomektom commented 3 months ago

I tried this with my shiny new Bernafon Alpha 3 ITC and here some notes:

If you already connected them with your phone – remove this connection – go to Settings -> Bluetooth and remove pair, otherwise you won't be able to connect them with PC. After connecting with PC you can reconnect them with phone – so that's not big problem

This is my BT hardware and basic system info – output from inxi -ISEazy

System:
  Kernel: 6.9.3-3-MANJARO arch: x86_64 bits: 64 compiler: gcc v: 14.1.1
    clocksource: hpet avail: acpi_pm
    parameters: BOOT_IMAGE=/boot/vmlinuz-6.9-x86_64
    root=UUID=bfcac972-4fe8-4a7e-9249-9e94e6af2d4a rw udev.log_priority=3
  Desktop: KDE Plasma v: 6.0.5 tk: Qt v: N/A info: frameworks v: 6.2.0
    wm: kwin_x11 vt: 2 dm: SDDM Distro: Manjaro base: Arch Linux
Bluetooth:
  Device-1: Foxconn / Hon Hai MediaTek Bluetooth Adapter driver: btusb v: 0.8
    type: USB rev: 2.1 speed: 480 Mb/s lanes: 1 mode: 2.0 bus-ID: 4-4:3
    chip-ID: 0489:e0cd class-ID: e001 serial: <filter>
  Report: hciconfig ID: hci0 rfk-id: 1 state: up address: <filter> bt-v: 5.2
    lmp-v: 11 sub-v: 2402 hci-v: 11 rev: 1911 class-ID: 6c010c
  Info: acl-mtu: 1021:6 sco-mtu: 240:8 link-policy: rswitch sniff
    link-mode: peripheral accept service-classes: rendering, capturing, audio,
    telephony
Info:
  Memory: total: 16 GiB note: est. available: 14.99 GiB used: 6.95 GiB (46.3%)
  Processes: 338 Power: uptime: 1h 53m states: freeze,mem,disk suspend: deep
    avail: s2idle wakeups: 0 hibernate: platform avail: shutdown, reboot,
    suspend, test_resume image: 5.98 GiB services: org_kde_powerdevil,upowerd
    Init: systemd v: 255 default: graphical tool: systemctl
  Packages: pm: pacman pkgs: 1620 libs: 425 tools: pamac Compilers:
    clang: 17.0.6 gcc: 14.1.1 Shell: Zsh v: 5.9 running-in: konsole inxi: 3.3.34

Most important package versions:

bluez 5.76
cmake 3.29.3
pipewire 1:1.0.7
gcc 14.1.1

btmgmt phy output

Supported phys: BR1M1SLOT BR1M3SLOT BR1M5SLOT EDR2M1SLOT EDR2M3SLOT EDR2M5SLOT EDR3M1SLOT EDR3M3SLOT EDR3M5SLOT LE1MTX LE1MRX LE2MTX LE2MRX LECODEDTX LECODEDRX 
Configurable phys: BR1M3SLOT BR1M5SLOT EDR2M1SLOT EDR2M3SLOT EDR2M5SLOT EDR3M1SLOT EDR3M3SLOT EDR3M5SLOT LE2MTX LE2MRX LECODEDTX LECODEDRX 
Selected phys: BR1M1SLOT BR1M3SLOT BR1M5SLOT EDR2M1SLOT EDR2M3SLOT EDR2M5SLOT EDR3M1SLOT EDR3M3SLOT EDR3M5SLOT LE1MTX LE1MRX LE2MTX LE2MRX LECODEDTX LECODEDRX

This is result for ./asha_connection_test, BT connection with it is rock solid stable, can keep it with at least several minutes

(process:4473): GLib-GIO-DEBUG: 11:34:31.276: Using cross-namespace EXTERNAL authentication (this will deadlock if server is GDBus < 2.73.3)
** INFO: 11:34:42.779: Adding bluetooth device TOMASZ
** INFO: 11:34:42.901: TOMASZ (Left)
** INFO: 11:34:42.901:     Name:      TOMASZ
** INFO: 11:34:42.901:     Mac:       00:19:8E:F5:54:98
** INFO: 11:34:42.901:     HiSyncId:  5200910074414956807
** INFO: 11:34:42.901:     Side:      left (binaural)
** INFO: 11:34:42.901:     Delay:     89 ms
** INFO: 11:34:42.901:     Streaming: supported
** INFO: 11:34:42.901:     Codecs:    G.722@16kHz
** INFO: 11:34:43.018:     Connected: true
** INFO: 11:34:43.018:     L2CAP_CONNINFO:
** INFO: 11:34:43.018:        handle: 512
** INFO: 11:34:43.018:        class:  [0, 0, 0]
** INFO: 11:34:43.018:     MTU:       SND 248 RCV 672
** INFO: 11:34:43.018:     PHY:    0
** INFO: 11:34:43.018:         Unless you enable LE_2M_TX, don't expect to be able to stream to more than one device.
** INFO: 11:34:43.018:         You can use `btmgmt phy` to check the supported phy's, and enable additional phy's by running a command like
** INFO: 11:34:43.018:            btmgmt phy BR1M1SLOT BR1M3SLOT BR1M5SLOT EDR2M1SLOT EDR2M3SLOT EDR2M5SLOT EDR3M1SLOT EDR3M3SLOT EDR3M5SLOT LE1MTX LE1MRX LE2MTX LE2MRX
** INFO: 11:34:43.018:         and then disconnecting and reconnecting your hearing devices.
** INFO: 11:34:43.018:         Note that some devices and adapters don't support 2M PHY's, despite advertising otherwise
** INFO: 11:34:43.018:     MODE: LE_FLOWCTL
** INFO: 11:34:43.018:     Hci Connection Info:
** INFO: 11:34:43.018:        type:   128 LE
** INFO: 11:34:43.018:        out:    1 true
** INFO: 11:34:43.018:        state:  1 CONNECTED
** INFO: 11:34:43.018:        mode:   7 MASTER AUTH ENCRYPT
** INFO: 11:34:44.882: Adding bluetooth device TOMASZ
** INFO: 11:34:44.998: TOMASZ (Right)
** INFO: 11:34:44.998:     Name:      TOMASZ
** INFO: 11:34:44.998:     Mac:       00:19:8E:C8:F5:2C
** INFO: 11:34:44.998:     HiSyncId:  5200910074414956807
** INFO: 11:34:44.998:     Side:      right (binaural)
** INFO: 11:34:44.998:     Delay:     89 ms
** INFO: 11:34:44.998:     Streaming: supported
** INFO: 11:34:44.998:     Codecs:    G.722@16kHz
** INFO: 11:34:45.117:     Connected: true
** INFO: 11:34:45.117:     L2CAP_CONNINFO:
** INFO: 11:34:45.117:        handle: 513
** INFO: 11:34:45.117:        class:  [0, 0, 0]
** INFO: 11:34:45.117:     MTU:       SND 248 RCV 672
** INFO: 11:34:45.117:     PHY:    0
** INFO: 11:34:45.117:         Unless you enable LE_2M_TX, don't expect to be able to stream to more than one device.
** INFO: 11:34:45.117:         You can use `btmgmt phy` to check the supported phy's, and enable additional phy's by running a command like
** INFO: 11:34:45.118:            btmgmt phy BR1M1SLOT BR1M3SLOT BR1M5SLOT EDR2M1SLOT EDR2M3SLOT EDR2M5SLOT EDR3M1SLOT EDR3M3SLOT EDR3M5SLOT LE1MTX LE1MRX LE2MTX LE2MRX
** INFO: 11:34:45.118:         and then disconnecting and reconnecting your hearing devices.
** INFO: 11:34:45.118:         Note that some devices and adapters don't support 2M PHY's, despite advertising otherwise
** INFO: 11:34:45.118:     MODE: LE_FLOWCTL
** INFO: 11:34:45.118:     Hci Connection Info:
** INFO: 11:34:45.118:        type:   128 LE
** INFO: 11:34:45.118:        out:    1 true
** INFO: 11:34:45.118:        state:  1 CONNECTED
** INFO: 11:34:45.118:        mode:   7 MASTER AUTH ENCRYPT

This is from ./asha_stream_test --left azu.mp3 --right azu.mp3 --algorithm poll --volume -100 – I don't know any g722 files so I tried with mp3 and received static noise :sweat_smile: – this setting seem to be most stable in meaning of streaming audio for both devices for me but still sometimes seem unstably and stable BT connection is hard to receive – in most cases I must restart bluetooth service before run this test – otherwise one or both devices keep disconnecting after several seconds, first one, several second later second but not always, only poll algorithm seem to keep both little longer (~1-2 min). Also this is only method for me to keep sound on both aids not only one. Same issue with ./asha_pipewire_sink. I also tried other values in /etc/bluetooth/main.conf but that seem no difference so i keep these from README.

(process:10192): GLib-GIO-DEBUG: 12:02:25.129: Using cross-namespace EXTERNAL authentication (this will deadlock if server is GDBus < 2.73.3)
Running with socket output polling
Stream latency: 0.0634051
** INFO: 12:02:38.085: Adding bluetooth device TOMASZ
TOMASZ (Right)
    Name:      TOMASZ
    Mac:       00:19:8E:C8:F5:2C
    HiSyncId:  5200910074414956807
    Side:      right (binaural)
    Delay:     89 ms
    Streaming: supported
    Codecs:    G.722@16kHz
    Connected: true
    PHY:    0
        Unless you enable LE_2M_TX, don't expect to be able to stream to more than one device.
        You can use `btmgmt phy` to check the supported phy's, and enable additional phy's by running a command like
           btmgmt phy BR1M1SLOT BR1M3SLOT BR1M5SLOT EDR2M1SLOT EDR2M3SLOT EDR2M5SLOT EDR3M1SLOT EDR3M3SLOT EDR3M5SLOT LE1MTX LE1MRX LE2MTX LE2MRX
        and then disconnecting and reconnecting your hearing devices.
        Note that some devices and adapters don't support 2M PHY's, despite advertising otherwise
Running with socket output polling
** INFO: 12:02:38.739: Adding bluetooth device TOMASZ

** (process:10192): WARNING **: 12:02:38.787: 2M PHY not enabled
** INFO: 12:02:38.787:         Unless you enable LE_2M_TX, don't expect to be able to stream to more than one device.
** INFO: 12:02:38.787:         You can use `btmgmt phy` to check the supported phy's, and enable additional phy's by running a command like
** INFO: 12:02:38.787:            btmgmt phy BR1M1SLOT BR1M3SLOT BR1M5SLOT EDR2M1SLOT EDR2M3SLOT EDR2M5SLOT EDR3M1SLOT EDR3M3SLOT EDR3M5SLOT LE1MTX LE1MRX LE2MTX LE2MRX
** INFO: 12:02:38.787:         and then disconnecting and reconnecting your hearing devices.
** INFO: 12:02:38.787:         Note that some devices and adapters don't support 2M PHY's, despite advertising otherwise
TOMASZ (Left)
    Name:      TOMASZ
    Mac:       00:19:8E:F5:54:98
    HiSyncId:  5200910074414956807
    Side:      left (binaural)
    Delay:     89 ms
    Streaming: supported
    Codecs:    G.722@16kHz
    Connected: true
    PHY:    0
        Unless you enable LE_2M_TX, don't expect to be able to stream to more than one device.
        You can use `btmgmt phy` to check the supported phy's, and enable additional phy's by running a command like
           btmgmt phy BR1M1SLOT BR1M3SLOT BR1M5SLOT EDR2M1SLOT EDR2M3SLOT EDR2M5SLOT EDR3M1SLOT EDR3M3SLOT EDR3M5SLOT LE1MTX LE1MRX LE2MTX LE2MRX
        and then disconnecting and reconnecting your hearing devices.
        Note that some devices and adapters don't support 2M PHY's, despite advertising otherwise
Running with socket output polling

** (process:10192): WARNING **: 12:02:39.576: 2M PHY not enabled
** INFO: 12:02:39.576:         Unless you enable LE_2M_TX, don't expect to be able to stream to more than one device.
** INFO: 12:02:39.577:         You can use `btmgmt phy` to check the supported phy's, and enable additional phy's by running a command like
** INFO: 12:02:39.577:            btmgmt phy BR1M1SLOT BR1M3SLOT BR1M5SLOT EDR2M1SLOT EDR2M3SLOT EDR2M5SLOT EDR3M1SLOT EDR3M3SLOT EDR3M5SLOT LE1MTX LE1MRX LE2MTX LE2MRX
** INFO: 12:02:39.577:         and then disconnecting and reconnecting your hearing devices.
** INFO: 12:02:39.577:         Note that some devices and adapters don't support 2M PHY's, despite advertising otherwise

** (process:10192): WARNING **: 12:02:42.957: Dropping frame for TOMASZ (Right)

** (process:10192): WARNING **: 12:02:46.717: Dropping frame for TOMASZ (Right)

** (process:10192): WARNING **: 12:02:49.271: Dropping frame for TOMASZ (Right)
Stream latency: -0.0229447

** (process:10192): WARNING **: 12:02:51.731: Dropping frame for TOMASZ (Right)
Stream latency: -0.0373053

** (process:10192): WARNING **: 12:03:07.769: Dropping frame for TOMASZ (Right)
Stream latency: -0.0450201

** (process:10192): WARNING **: 12:03:11.289: Dropping frame for TOMASZ (Right)

** (process:10192): WARNING **: 12:03:18.968: Dropping frame for TOMASZ (Right)
Stream latency: -0.0458684

** (process:10192): WARNING **: 12:03:19.788: Dropping frame for TOMASZ (Right)

** (process:10192): WARNING **: 12:03:20.708: Dropping frame for TOMASZ (Right)

** (process:10192): WARNING **: 12:03:21.534: Dropping frame for TOMASZ (Right)

** (process:10192): WARNING **: 12:03:29.213: Dropping frame for TOMASZ (Right)
Stream latency: -0.0471173
^CStopping...

Also ./asha_pipewire_sink is not very stable it often crash, this is dump from one:

cze 15 12:38:20 ws094 systemd-coredump[12207]: [🡕] Process 12171 (asha_pipewire_s) of user 1000 dumped core.

                                               Stack trace of thread 12171:
                                               #0  0x000071362a9e6ad8 g_log_structured_array (libglib-2.0.so.0 + 0x61ad8)
                                               #1  0x000071362a9e6dd7 g_log_default_handler (libglib-2.0.so.0 + 0x61dd7)
                                               #2  0x000071362a9e705c g_logv (libglib-2.0.so.0 + 0x6205c)
                                               #3  0x000071362a9e73d4 g_log (libglib-2.0.so.0 + 0x623d4)
                                               #4  0x000061905a3e6ce4 n/a (/home/tomek/asha/asha_pipewire_sink/build/asha_pipewire_sink + 0x18ce4)
                                               #5  0x000061905a3d3ff6 n/a (/home/tomek/asha/asha_pipewire_sink/build/asha_pipewire_sink + 0x5ff6)
                                               #6  0x000061905a3d627c n/a (/home/tomek/asha/asha_pipewire_sink/build/asha_pipewire_sink + 0x827c)
                                               #7  0x000061905a3d5b0a n/a (/home/tomek/asha/asha_pipewire_sink/build/asha_pipewire_sink + 0x7b0a)
                                               #8  0x000061905a3d5435 n/a (/home/tomek/asha/asha_pipewire_sink/build/asha_pipewire_sink + 0x7435)
                                               #9  0x000061905a3d7e34 n/a (/home/tomek/asha/asha_pipewire_sink/build/asha_pipewire_sink + 0x9e34)
                                               #10 0x000061905a3d4ce3 n/a (/home/tomek/asha/asha_pipewire_sink/build/asha_pipewire_sink + 0x6ce3)
                                               #11 0x000061905a3d4b82 n/a (/home/tomek/asha/asha_pipewire_sink/build/asha_pipewire_sink + 0x6b82)
                                               #12 0x000061905a3d4ba1 n/a (/home/tomek/asha/asha_pipewire_sink/build/asha_pipewire_sink + 0x6ba1)
                                               #13 0x000071362a9e2eda n/a (libglib-2.0.so.0 + 0x5deda)
                                               #14 0x000071362a9e1a89 n/a (libglib-2.0.so.0 + 0x5ca89)
                                               #15 0x000071362aa439b7 n/a (libglib-2.0.so.0 + 0xbe9b7)
                                               #16 0x000071362a9e2787 g_main_loop_run (libglib-2.0.so.0 + 0x5d787)
                                               #17 0x000061905a3f7560 n/a (/home/tomek/asha/asha_pipewire_sink/build/asha_pipewire_sink + 0x29560)
                                               #18 0x000071362a34ec88 n/a (libc.so.6 + 0x25c88)
                                               #19 0x000071362a34ed4c __libc_start_main (libc.so.6 + 0x25d4c)
                                               #20 0x000061905a3d3965 n/a (/home/tomek/asha/asha_pipewire_sink/build/asha_pipewire_sink + 0x5965)
                                               ELF object binary architecture: AMD x86-64

On tuesday evening I will be able to test this on my PC where I have Intel AX200 if I remember correctly and see if that make any difference ;)

barolo commented 3 months ago

Bernafon Alpha is a rebranded Oticon Own, which means that we should have some coverage already. AX200 often yields better results. There are test audio files in the sounds folder.

barolo commented 3 months ago

After connecting with PC you can reconnect them with phone – so that's not big problem

This might be a problem, in most cases the phone will keep stealing the hearing devices.

thewierdnut commented 3 months ago

Also ./asha_pipewire_sink is not very stable it often crash, this is dump from one:

Can you re-run cmake with cmake -DCMAKE_BUILD_TYPE=Debug -DENABLE_ASAN=1 and rebuild? That should give me some symbols to work with.

tomektom commented 3 months ago

After connecting with PC you can reconnect them with phone – so that's not big problem

This might be a problem, in most cases the phone will keep stealing the hearing devices.

I know that issue from my old SoundGate, phone keep stealing it unless I disable BT. With Alpha I observed similar issue – when phone BT enabled no sound from test though both hearing aids are connected to laptop. For me that's acceptable – when work on PC disable phone BT and enable KDE Connect, when finish just reenable BT. I don't use my phone very much so probably that's why this isn't big issue for me :wink:

There are test audio files in the sounds folder.

Indeed, I didn't saw them earlier. Here another test for poll algorithm. One device disconnected in the middle :disappointed: As previous this keep lognest connection for both devices. Other algorithms disconnect one device faster but this time keep one. So I assume that maybe my issue isn't in this code but in poor BT connection.

(process:1916): GLib-GIO-DEBUG: 14:04:14.030: Using cross-namespace EXTERNAL authentication (this will deadlock if server is GDBus < 2.73.3)
Running with socket output polling
** INFO: 14:04:20.463: Adding bluetooth device TOMASZ
TOMASZ (Right)
    Name:      TOMASZ
    Mac:       00:19:8E:C8:F5:2C
    HiSyncId:  5200910074414956807
    Side:      right (binaural)
    Delay:     89 ms
    Streaming: supported
    Codecs:    G.722@16kHz
    Connected: true
    PHY:    0
        Unless you enable LE_2M_TX, don't expect to be able to stream to more than one device.
        You can use `btmgmt phy` to check the supported phy's, and enable additional phy's by running a command like
           btmgmt phy BR1M1SLOT BR1M3SLOT BR1M5SLOT EDR2M1SLOT EDR2M3SLOT EDR2M5SLOT EDR3M1SLOT EDR3M3SLOT EDR3M5SLOT LE1MTX LE1MRX LE2MTX LE2MRX
        and then disconnecting and reconnecting your hearing devices.
        Note that some devices and adapters don't support 2M PHY's, despite advertising otherwise
Running with socket output polling

** (process:1916): WARNING **: 14:04:21.110: 2M PHY not enabled
** INFO: 14:04:21.110:         Unless you enable LE_2M_TX, don't expect to be able to stream to more than one device.
** INFO: 14:04:21.110:         You can use `btmgmt phy` to check the supported phy's, and enable additional phy's by running a command like
** INFO: 14:04:21.110:            btmgmt phy BR1M1SLOT BR1M3SLOT BR1M5SLOT EDR2M1SLOT EDR2M3SLOT EDR2M5SLOT EDR3M1SLOT EDR3M3SLOT EDR3M5SLOT LE1MTX LE1MRX LE2MTX LE2MRX
** INFO: 14:04:21.110:         and then disconnecting and reconnecting your hearing devices.
** INFO: 14:04:21.110:         Note that some devices and adapters don't support 2M PHY's, despite advertising otherwise
** INFO: 14:04:21.428: Adding bluetooth device TOMASZ
TOMASZ (Left)
    Name:      TOMASZ
    Mac:       00:19:8E:F5:54:98
    HiSyncId:  5200910074414956807
    Side:      left (binaural)
    Delay:     89 ms
    Streaming: supported
    Codecs:    G.722@16kHz
    Connected: true
    PHY:    0
        Unless you enable LE_2M_TX, don't expect to be able to stream to more than one device.
        You can use `btmgmt phy` to check the supported phy's, and enable additional phy's by running a command like
           btmgmt phy BR1M1SLOT BR1M3SLOT BR1M5SLOT EDR2M1SLOT EDR2M3SLOT EDR2M5SLOT EDR3M1SLOT EDR3M3SLOT EDR3M5SLOT LE1MTX LE1MRX LE2MTX LE2MRX
        and then disconnecting and reconnecting your hearing devices.
        Note that some devices and adapters don't support 2M PHY's, despite advertising otherwise
Running with socket output polling

** (process:1916): WARNING **: 14:04:22.306: 2M PHY not enabled
** INFO: 14:04:22.306:         Unless you enable LE_2M_TX, don't expect to be able to stream to more than one device.
** INFO: 14:04:22.306:         You can use `btmgmt phy` to check the supported phy's, and enable additional phy's by running a command like
** INFO: 14:04:22.306:            btmgmt phy BR1M1SLOT BR1M3SLOT BR1M5SLOT EDR2M1SLOT EDR2M3SLOT EDR2M5SLOT EDR3M1SLOT EDR3M3SLOT EDR3M5SLOT LE1MTX LE1MRX LE2MTX LE2MRX
** INFO: 14:04:22.306:         and then disconnecting and reconnecting your hearing devices.
** INFO: 14:04:22.306:         Note that some devices and adapters don't support 2M PHY's, despite advertising otherwise

** (process:1916): WARNING **: 14:04:24.842: Dropping frame for TOMASZ (Right)

** (process:1916): WARNING **: 14:04:26.575: Dropping frame for TOMASZ (Right)

** (process:1916): WARNING **: 14:04:30.775: Dropping frame for TOMASZ (Right)
Stream latency: -0.0248352
Stream latency: -0.0203421

** (process:1916): WARNING **: 14:04:43.674: Dropping frame for TOMASZ (Right)

** (process:1916): WARNING **: 14:04:50.134: Dropping frame for TOMASZ (Right)
Stream latency: -0.0463894

** (process:1916): WARNING **: 14:04:56.754: Dropping frame for TOMASZ (Right)

** (process:1916): WARNING **: 14:04:57.293: Dropping frame for TOMASZ (Right)

** (process:1916): WARNING **: 14:04:57.734: Dropping frame for TOMASZ (Right)

** (process:1916): WARNING **: 14:04:57.839: Dropping frame for TOMASZ (Right)

** (process:1916): WARNING **: 14:04:57.914: Dropping frame for TOMASZ (Right)

** (process:1916): WARNING **: 14:04:58.694: Dropping frame for TOMASZ (Right)

** (process:1916): WARNING **: 14:04:59.353: Dropping frame for TOMASZ (Right)

** (process:1916): WARNING **: 14:05:01.694: Dropping frame for TOMASZ (Right)
Stream latency: -0.00591096

** (process:1916): WARNING **: 14:05:10.133: Dropping frame for TOMASZ (Right)
Stream latency: -0.0260835

** (process:1916): WARNING **: 14:05:13.799: Dropping frame for TOMASZ (Right)

** (process:1916): WARNING **: 14:05:13.813: Dropping frame for TOMASZ (Right)
** INFO: 14:05:13.835: Removing bluetooth device TOMASZ
Removing TOMASZ (Right)

** (process:1916): WARNING **: 14:05:13.854: Error calling WriteValue: GDBus.Error:org.bluez.Error.Failed: Not connected

** (process:1916): WARNING **: 14:05:13.854: Null result when calling WriteValue
Running with socket output polling
Stream latency: -0.146286
Stream latency: -0.126422
Stream latency: -0.146503
Stream latency: -0.146135
Stream latency: -0.145862
Stream latency: -0.124951
Stream latency: -0.137574
Stream latency: -0.120777
Stream latency: -0.119517
Stream latency: -0.13807
Stream latency: -0.136686
Stream latency: -0.135208
Stream latency: -0.114038
^CStopping...
thewierdnut commented 3 months ago

It also seems to have a hard time negotiating 2M PHY, (At least before the code gives up and stops checking for it).

Can you use btmon -w file_name.snoop to capture the bluetooth traffic when you run asha_connection_test?

tomektom commented 3 months ago

This time ./asha_stream_test --left ../sounds/left.g722 --right ../sounds/right.g722 --algorithm fixed --volume -64 gave me best sound results but still one keep disconnecting

(process:4206): GLib-GIO-DEBUG: 14:41:53.849: Using cross-namespace EXTERNAL authentication (this will deadlock if server is GDBus < 2.73.3)
Running with fixed rate frames
** INFO: 14:42:00.049: Adding bluetooth device TOMASZ
TOMASZ (Right)
    Name:      TOMASZ
    Mac:       00:19:8E:C8:F5:2C
    HiSyncId:  5200910074414956807
    Side:      right (binaural)
    Delay:     89 ms
    Streaming: supported
    Codecs:    G.722@16kHz
    Connected: true
    PHY:    0
        Unless you enable LE_2M_TX, don't expect to be able to stream to more than one device.
        You can use `btmgmt phy` to check the supported phy's, and enable additional phy's by running a command like
           btmgmt phy BR1M1SLOT BR1M3SLOT BR1M5SLOT EDR2M1SLOT EDR2M3SLOT EDR2M5SLOT EDR3M1SLOT EDR3M3SLOT EDR3M5SLOT LE1MTX LE1MRX LE2MTX LE2MRX
        and then disconnecting and reconnecting your hearing devices.
        Note that some devices and adapters don't support 2M PHY's, despite advertising otherwise
Running with fixed rate frames

** (process:4206): WARNING **: 14:42:00.724: 2M PHY not enabled
** INFO: 14:42:00.724:         Unless you enable LE_2M_TX, don't expect to be able to stream to more than one device.
** INFO: 14:42:00.724:         You can use `btmgmt phy` to check the supported phy's, and enable additional phy's by running a command like
** INFO: 14:42:00.724:            btmgmt phy BR1M1SLOT BR1M3SLOT BR1M5SLOT EDR2M1SLOT EDR2M3SLOT EDR2M5SLOT EDR3M1SLOT EDR3M3SLOT EDR3M5SLOT LE1MTX LE1MRX LE2MTX LE2MRX
** INFO: 14:42:00.724:         and then disconnecting and reconnecting your hearing devices.
** INFO: 14:42:00.725:         Note that some devices and adapters don't support 2M PHY's, despite advertising otherwise

** (process:4206): WARNING **: 14:42:01.005: Dropping frame for TOMASZ (Right)

** (process:4206): WARNING **: 14:42:01.065: Dropping frame for TOMASZ (Right)

** (process:4206): WARNING **: 14:42:01.084: Dropping frame for TOMASZ (Right)

** (process:4206): WARNING **: 14:42:01.105: Dropping frame for TOMASZ (Right)

** (process:4206): WARNING **: 14:42:01.145: Dropping frame for TOMASZ (Right)
** INFO: 14:42:01.452: Adding bluetooth device TOMASZ
TOMASZ (Left)
    Name:      TOMASZ
    Mac:       00:19:8E:F5:54:98
    HiSyncId:  5200910074414956807
    Side:      left (binaural)
    Delay:     89 ms
    Streaming: supported
    Codecs:    G.722@16kHz
    Connected: true
    PHY:    0
        Unless you enable LE_2M_TX, don't expect to be able to stream to more than one device.
        You can use `btmgmt phy` to check the supported phy's, and enable additional phy's by running a command like
           btmgmt phy BR1M1SLOT BR1M3SLOT BR1M5SLOT EDR2M1SLOT EDR2M3SLOT EDR2M5SLOT EDR3M1SLOT EDR3M3SLOT EDR3M5SLOT LE1MTX LE1MRX LE2MTX LE2MRX
        and then disconnecting and reconnecting your hearing devices.
        Note that some devices and adapters don't support 2M PHY's, despite advertising otherwise
Running with fixed rate frames

** (process:4206): WARNING **: 14:42:02.373: 2M PHY not enabled
** INFO: 14:42:02.373:         Unless you enable LE_2M_TX, don't expect to be able to stream to more than one device.
** INFO: 14:42:02.373:         You can use `btmgmt phy` to check the supported phy's, and enable additional phy's by running a command like
** INFO: 14:42:02.373:            btmgmt phy BR1M1SLOT BR1M3SLOT BR1M5SLOT EDR2M1SLOT EDR2M3SLOT EDR2M5SLOT EDR3M1SLOT EDR3M3SLOT EDR3M5SLOT LE1MTX LE1MRX LE2MTX LE2MRX
** INFO: 14:42:02.373:         and then disconnecting and reconnecting your hearing devices.
** INFO: 14:42:02.373:         Note that some devices and adapters don't support 2M PHY's, despite advertising otherwise
Stream latency: 0.0201621
Stream latency: 0.0218879

** (process:4206): WARNING **: 14:42:25.248: Dropping frame for TOMASZ (Right)

** (process:4206): WARNING **: 14:42:25.368: Dropping frame for TOMASZ (Right)

** (process:4206): WARNING **: 14:42:25.388: Dropping frame for TOMASZ (Right)
** INFO: 14:42:25.400: Removing bluetooth device TOMASZ
Removing TOMASZ (Right)

** (process:4206): WARNING **: 14:42:25.403: Error calling WriteValue: GDBus.Error:org.bluez.Error.Failed: Not connected

** (process:4206): WARNING **: 14:42:25.403: Null result when calling WriteValue
Running with fixed rate frames
Stream latency: 0.0215726
Stream latency: 0.0219095
^CStopping...

It also seems to have a hard time negotiating 2M PHY, (At least before the code gives up and stops checking for it).

Can you use btmon -w file_name.snoop to capture the bluetooth traffic when you run asha_connection_test?

Done, here logs file_name.snoop.txt

Also after enabling debug flags pipewire sing sometimes crash without generating coredump just with this output

** (process:5700): WARNING **: 14:59:31.249: Dropping frame for TOMASZ (Left)

** (process:5700): WARNING **: 14:59:31.255: Dropping frame for TOMASZ (Left)

** (process:5700): WARNING **: 14:59:31.255: Disconnected from TOMASZ (Left): (Connection reset by peer)

** (process:5700): WARNING **: 14:59:31.306: Error calling WriteValue: GDBus.Error:org.bluez.Error.Failed: Not connected

** (process:5700): WARNING **: 14:59:31.306: Null result when calling WriteValue

** (process:5700): WARNING **: 14:59:32.080: 2M PHY not enabled
on_change_state old: UNCONNECTED  new: CONNECTING 
on_change_state old: CONNECTING  new: PAUSED 
control_info(Volume, 1)
control_info(Mute, 1)
control_info(Channel Volumes, 0)
control_info(Soft Mute, 1)
control_info(Soft Volumes, 0)
control_info(Monitor Mute, 1)
control_info(Monitor Volumes, 0)
control_info(Channel Volumes, 2)
control_info(Soft Volumes, 2)
control_info(Monitor Volumes, 2)
on_change_state old: PAUSED  new: STREAMING 

** (process:5700): WARNING **: 14:59:32.382: Failed to connect l2cap channel: Connection refused

** (process:5700): ERROR **: 14:59:32.420: Failed to connect to TOMASZ (Left)
zsh: trace trap (core dumped)  ./asha_pipewire_sink

But once I received this, maybe this is more useful:

** (process:6104): WARNING **: 15:05:38.862: Dropping frame for TOMASZ (Right)
AddressSanitizer:DEADLYSIGNAL
=================================================================
==6104==ERROR: AddressSanitizer: SEGV on unknown address 0x0000000002b9 (pc 0x5b7e02ef874c bp 0x7bdc1e5ff6e0 sp 0x7bdc1e5ff6d0 T10)
==6104==The signal is caused by a READ memory access.
==6104==Hint: address points to the zero page.
    #0 0x5b7e02ef874c in asha::Side::Right() const /home/tomek/asha/asha_pipewire_sink/asha/Side.hh:52
    #1 0x5b7e02ef8777 in asha::Side::Left() const /home/tomek/asha/asha_pipewire_sink/asha/Side.hh:53
    #2 0x5b7e02ef30f7 in asha::Device::SendAudio(RawS16 const&, bool&, bool&) /home/tomek/asha/asha_pipewire_sink/asha/Device.cxx:169
    #3 0x5b7e02ef1197 in operator() /home/tomek/asha/asha_pipewire_sink/asha/Device.cxx:15
    #4 0x5b7e02ef595e in __invoke_impl<bool, asha::Device::Device(uint64_t, const std::string&, const std::string&, ReconnectCallback)::<lambda(const RawS16&, bool&, bool&)>&, const RawS16&, bool&, bool&> /usr/include/c++/14.1.1/bits/invoke.h:61
    #5 0x5b7e02ef550d in __invoke_r<bool, asha::Device::Device(uint64_t, const std::string&, const std::string&, ReconnectCallback)::<lambda(const RawS16&, bool&, bool&)>&, const RawS16&, bool&, bool&> /usr/include/c++/14.1.1/bits/invoke.h:138
    #6 0x5b7e02ef50c9 in _M_invoke /usr/include/c++/14.1.1/bits/std_function.h:290
    #7 0x5b7e02efcc9b in std::function<bool (RawS16 const&, bool&, bool&)>::operator()(RawS16 const&, bool&, bool&) const /usr/include/c++/14.1.1/bits/std_function.h:591
    #8 0x5b7e02efadf3 in asha::Buffer<8ul>::DeliveryThread() /home/tomek/asha/asha_pipewire_sink/asha/Buffer.hh:119
    #9 0x5b7e02efffca in void std::__invoke_impl<void, void (asha::Buffer<8ul>::*)(), asha::Buffer<8ul>*>(std::__invoke_memfun_deref, void (asha::Buffer<8ul>::*&&)(), asha::Buffer<8ul>*&&) /usr/include/c++/14.1.1/bits/invoke.h:74
    #10 0x5b7e02effef2 in std::__invoke_result<void (asha::Buffer<8ul>::*)(), asha::Buffer<8ul>*>::type std::__invoke<void (asha::Buffer<8ul>::*)(), asha::Buffer<8ul>*>(void (asha::Buffer<8ul>::*&&)(), asha::Buffer<8ul>*&&) /usr/include/c++/14.1.1/bits/invoke.h:96
    #11 0x5b7e02effe62 in void std::thread::_Invoker<std::tuple<void (asha::Buffer<8ul>::*)(), asha::Buffer<8ul>*> >::_M_invoke<0ul, 1ul>(std::_Index_tuple<0ul, 1ul>) /usr/include/c++/14.1.1/bits/std_thread.h:292
    #12 0x5b7e02effe01 in std::thread::_Invoker<std::tuple<void (asha::Buffer<8ul>::*)(), asha::Buffer<8ul>*> >::operator()() /usr/include/c++/14.1.1/bits/std_thread.h:299
    #13 0x5b7e02effdcb in std::thread::_State_impl<std::thread::_Invoker<std::tuple<void (asha::Buffer<8ul>::*)(), asha::Buffer<8ul>*> > >::_M_run() /usr/include/c++/14.1.1/bits/std_thread.h:244
    #14 0x7bdc288e0c83 in execute_native_thread_routine /usr/src/debug/gcc/gcc/libstdc++-v3/src/c++11/thread.cc:104
    #15 0x7bdc2905cc79 in asan_thread_start /usr/src/debug/gcc/gcc/libsanitizer/asan/asan_interceptors.cpp:234
    #16 0x7bdc286a6dec  (/usr/lib/libc.so.6+0x92dec) (BuildId: 32a656aa5562eece8c59a585f5eacd6cf5e2307b)
    #17 0x7bdc2872a0db  (/usr/lib/libc.so.6+0x1160db) (BuildId: 32a656aa5562eece8c59a585f5eacd6cf5e2307b)

AddressSanitizer can not provide additional info.
SUMMARY: AddressSanitizer: SEGV /home/tomek/asha/asha_pipewire_sink/asha/Side.hh:52 in asha::Side::Right() const
Thread T10 created by T0 here:
    #0 0x7bdc290f38fb in pthread_create /usr/src/debug/gcc/gcc/libsanitizer/asan/asan_interceptors.cpp:245
    #1 0x7bdc288e0d81 in __gthread_create /usr/src/debug/gcc/gcc-build/x86_64-pc-linux-gnu/libstdc++-v3/include/x86_64-pc-linux-gnu/bits/gthr-default.h:676
    #2 0x7bdc288e0d81 in std::thread::_M_start_thread(std::unique_ptr<std::thread::_State, std::default_delete<std::thread::_State> >, void (*)()) /usr/src/debug/gcc/gcc/libstdc++-v3/src/c++11/thread.cc:172
    #3 0x5b7e02efb3c2 in std::thread::thread<void (asha::Buffer<8ul>::*)(), asha::Buffer<8ul>*, void>(void (asha::Buffer<8ul>::*&&)(), asha::Buffer<8ul>*&&) /usr/include/c++/14.1.1/bits/std_thread.h:164
    #4 0x5b7e02ef9ae1 in asha::Buffer<8ul>::Start() /home/tomek/asha/asha_pipewire_sink/asha/Buffer.hh:48
    #5 0x5b7e02ef281a in asha::Device::Start() /home/tomek/asha/asha_pipewire_sink/asha/Device.cxx:120
    #6 0x5b7e02ef3d69 in asha::Device::AddSide(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, std::shared_ptr<asha::Side> const&) /home/tomek/asha/asha_pipewire_sink/asha/Device.cxx:266
    #7 0x5b7e02ecb8e5 in operator() /home/tomek/asha/asha_pipewire_sink/asha/Asha.cxx:108
    #8 0x5b7e02ecfb8d in __invoke_impl<void, asha::Asha::OnAddDevice(const asha::Bluetooth::BluezDevice&)::<lambda()>&> /usr/include/c++/14.1.1/bits/invoke.h:61
    #9 0x5b7e02ecf0af in __invoke_r<void, asha::Asha::OnAddDevice(const asha::Bluetooth::BluezDevice&)::<lambda()>&> /usr/include/c++/14.1.1/bits/invoke.h:150
    #10 0x5b7e02ece656 in _M_invoke /usr/include/c++/14.1.1/bits/std_function.h:290
    #11 0x5b7e02ed2c8b in std::function<void ()>::operator()() const /usr/include/c++/14.1.1/bits/std_function.h:591
    #12 0x5b7e02ecd817 in asha::Asha::ProcessDeferred() /home/tomek/asha/asha_pipewire_sink/asha/Asha.cxx:176
    #13 0x5b7e02ecd527 in operator() /home/tomek/asha/asha_pipewire_sink/asha/Asha.cxx:167
    #14 0x5b7e02ecd546 in _FUN /home/tomek/asha/asha_pipewire_sink/asha/Asha.cxx:168
    #15 0x7bdc28d42ed9  (/usr/lib/libglib-2.0.so.0+0x5ded9) (BuildId: 8880230af7e37f2edbd90b79170aead80dde617a)
    #16 0x7bdc28d41a88  (/usr/lib/libglib-2.0.so.0+0x5ca88) (BuildId: 8880230af7e37f2edbd90b79170aead80dde617a)
    #17 0x7bdc28da39b6  (/usr/lib/libglib-2.0.so.0+0xbe9b6) (BuildId: 8880230af7e37f2edbd90b79170aead80dde617a)
    #18 0x7bdc28d42786 in g_main_loop_run (/usr/lib/libglib-2.0.so.0+0x5d786) (BuildId: 8880230af7e37f2edbd90b79170aead80dde617a)
    #19 0x5b7e02f1719d in main /home/tomek/asha/asha_pipewire_sink/pipewire_sink.cxx:58
    #20 0x7bdc28639c87  (/usr/lib/libc.so.6+0x25c87) (BuildId: 32a656aa5562eece8c59a585f5eacd6cf5e2307b)
    #21 0x7bdc28639d4b in __libc_start_main (/usr/lib/libc.so.6+0x25d4b) (BuildId: 32a656aa5562eece8c59a585f5eacd6cf5e2307b)
    #22 0x5b7e02ecab04 in _start (/home/tomek/asha/asha_pipewire_sink/build/asha_pipewire_sink+0xdb04) (BuildId: 61a5b18938885a32cb8a12b491da87c392720dd6)

==6104==ABORTING
thewierdnut commented 3 months ago

That is exactly what I needed.

Also, you can ignore the 2M Phy warnings. The packet trace shows that it takes almost a second to negotiate, which is longer than I'm scanning for it. I guess I'll have to increase that some more.

thewierdnut commented 3 months ago

The line numbers in your packet trace don't match up. What git hash are you running?

tomektom commented 3 months ago

The line numbers in your packet trace don't match up. What git hash are you running?

That should be latest, all results posted here should be from ad1f2079790462b9c4d3c2476e8084c89df12c22. Although I did some tests yesterday probably from this commit d5af312c8f9f26251d835c73e2aec36d7c86b2cb. Maybe before recompiling I should remove old builds? If you need more tests I can run more tomorrow 😉

thewierdnut commented 3 months ago

I've pushed an update to asha_pipewire_sink to try and make the connection more stable. Give it a try when you get a chance.

You are the first person that has submitted results from a mediatek bluetooth adapter. I would love to see a packet trace with asha_stream_test running.

tomektom commented 3 months ago

I'm back and here new tests :smile:

  1. test with fixed algorithm – the best results as far, one aid disconnected fast but after reconnecting it keeps playing wiht small audio drops on right side. test_fixed.snoop.txt

  2. test with deadline algorithm – audio drops frequently, right aid disconnected fast as usual but after manual reconnecting ears switched and disconnected left aid and keep playing on right side – that happen first time test_deadline.snoop.txt

  3. test with poll algorihtm – at the begining audio (with huge drops and small quirks) on both sides but fastly one side disconnect and reconnecting don't change much. test_poll.snoop.txt

  4. another test with poll algorithm but with some play with aid and phone – also very good and stable results similar to first. I added some spicy to this – change volume, programs and mute in my hearing aids. At the end I enabled BT in phone and at this moment one aid disconnected (but I'm not sure it's caused by phone). I tried to connect them to phone but without success. test_poll_with_fun.snoop.txt

And another (partially intentional) crash from asha_pipewire_sink still keeps disconnecting one side but in general program seems more stable and crashed after 3 mins and several aid reconnections.

Ring Occupancy: 5 High: 8 Ring Dropped: 0 Total: 16 Adapter Dropped: 0 Total: 11 Silence: 0 Total: 2
** INFO: 10:56:19.798: Dropping frame for TOMASZ (Left)
** INFO: 10:56:19.804: Removing bluetooth device TOMASZ

** (process:5568): WARNING **: 10:56:19.814: Disconnected from TOMASZ (Left): (Connection reset by peer)
** INFO: 10:56:19.815: Dropping frame for TOMASZ (Right)
** INFO: 10:56:19.835: Dropping frame for TOMASZ (Right)
** INFO: 10:56:19.856: Dropping frame for TOMASZ (Right)
AddressSanitizer:DEADLYSIGNAL
=================================================================
==5568==ERROR: AddressSanitizer: SEGV on unknown address 0x0000000002d5 (pc 0x55e4fcccd926 bp 0x7dff1a1ff7b0 sp 0x7dff1a1ff7a0 T24)
==5568==The signal is caused by a READ memory access.
==5568==Hint: address points to the zero page.
Ring Occupancy: 3 High: 8 Ring Dropped: 2 Total: 18 Adapter Dropped: 2 Total: 13 Silence: 0 Total: 2
    #0 0x55e4fcccd926 in asha::Side::Ready() const /home/tomek/asha/asha_pipewire_sink/asha/Side.hh:69
    #1 0x55e4fccc84f4 in asha::Device::SendAudio(RawS16 const&) /home/tomek/asha/asha_pipewire_sink/asha/Device.cxx:182
    #2 0x55e4fccc6386 in operator() /home/tomek/asha/asha_pipewire_sink/asha/Device.cxx:15
    #3 0x55e4fcccaac0 in __invoke_impl<bool, asha::Device::Device(uint64_t, const std::string&, const std::string&, ReconnectCallback)::<lambda(const RawS16&)>&, const RawS16&> /usr/include/c++/14.1.1/bits/invoke.h:61
    #4 0x55e4fccca6a5 in __invoke_r<bool, asha::Device::Device(uint64_t, const std::string&, const std::string&, ReconnectCallback)::<lambda(const RawS16&)>&, const RawS16&> /usr/include/c++/14.1.1/bits/invoke.h:138
    #5 0x55e4fccca295 in _M_invoke /usr/include/c++/14.1.1/bits/std_function.h:290
    #6 0x55e4fccd1562 in std::function<bool (RawS16 const&)>::operator()(RawS16 const&) const (/home/tomek/asha/asha_pipewire_sink/build/asha_pipewire_sink+0x3f562) (BuildId: e55a0ee0d74cee5982d29ae57cd999884b64191a)
    #7 0x55e4fcccfa61 in asha::Buffer<8ul>::DeliveryThread() /home/tomek/asha/asha_pipewire_sink/asha/Buffer.hh:118
    #8 0x55e4fccd47de in void std::__invoke_impl<void, void (asha::Buffer<8ul>::*)(), asha::Buffer<8ul>*>(std::__invoke_memfun_deref, void (asha::Buffer<8ul>::*&&)(), asha::Buffer<8ul>*&&) /usr/include/c++/14.1.1/bits/invoke.h:74
    #9 0x55e4fccd4706 in std::__invoke_result<void (asha::Buffer<8ul>::*)(), asha::Buffer<8ul>*>::type std::__invoke<void (asha::Buffer<8ul>::*)(), asha::Buffer<8ul>*>(void (asha::Buffer<8ul>::*&&)(), asha::Buffer<8ul>*&&) /usr/include/c++/14.1.1/bits/invoke.h:96
    #10 0x55e4fccd4676 in void std::thread::_Invoker<std::tuple<void (asha::Buffer<8ul>::*)(), asha::Buffer<8ul>*> >::_M_invoke<0ul, 1ul>(std::_Index_tuple<0ul, 1ul>) /usr/include/c++/14.1.1/bits/std_thread.h:292
    #11 0x55e4fccd4615 in std::thread::_Invoker<std::tuple<void (asha::Buffer<8ul>::*)(), asha::Buffer<8ul>*> >::operator()() /usr/include/c++/14.1.1/bits/std_thread.h:299
    #12 0x55e4fccd45df in std::thread::_State_impl<std::thread::_Invoker<std::tuple<void (asha::Buffer<8ul>::*)(), asha::Buffer<8ul>*> > >::_M_run() /usr/include/c++/14.1.1/bits/std_thread.h:244
    #13 0x7dff218e0c83 in execute_native_thread_routine /usr/src/debug/gcc/gcc/libstdc++-v3/src/c++11/thread.cc:104
    #14 0x7dff2205cc79 in asan_thread_start /usr/src/debug/gcc/gcc/libsanitizer/asan/asan_interceptors.cpp:234
    #15 0x7dff216a6dec  (/usr/lib/libc.so.6+0x92dec) (BuildId: 32a656aa5562eece8c59a585f5eacd6cf5e2307b)
    #16 0x7dff2172a0db  (/usr/lib/libc.so.6+0x1160db) (BuildId: 32a656aa5562eece8c59a585f5eacd6cf5e2307b)

AddressSanitizer can not provide additional info.
SUMMARY: AddressSanitizer: SEGV /home/tomek/asha/asha_pipewire_sink/asha/Side.hh:69 in asha::Side::Ready() const
Thread T24 created by T0 here:
    #0 0x7dff220f38fb in pthread_create /usr/src/debug/gcc/gcc/libsanitizer/asan/asan_interceptors.cpp:245
    #1 0x7dff218e0d81 in __gthread_create /usr/src/debug/gcc/gcc-build/x86_64-pc-linux-gnu/libstdc++-v3/include/x86_64-pc-linux-gnu/bits/gthr-default.h:676
    #2 0x7dff218e0d81 in std::thread::_M_start_thread(std::unique_ptr<std::thread::_State, std::default_delete<std::thread::_State> >, void (*)()) /usr/src/debug/gcc/gcc/libstdc++-v3/src/c++11/thread.cc:172
    #3 0x55e4fcccfde2 in std::thread::thread<void (asha::Buffer<8ul>::*)(), asha::Buffer<8ul>*, void>(void (asha::Buffer<8ul>::*&&)(), asha::Buffer<8ul>*&&) /usr/include/c++/14.1.1/bits/std_thread.h:164
    #4 0x55e4fcccea2d in asha::Buffer<8ul>::Start() /home/tomek/asha/asha_pipewire_sink/asha/Buffer.hh:48
    #5 0x55e4fccc7a30 in asha::Device::Start() /home/tomek/asha/asha_pipewire_sink/asha/Device.cxx:126
    #6 0x55e4fccc8f65 in asha::Device::AddSide(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, std::shared_ptr<asha::Side> const&) /home/tomek/asha/asha_pipewire_sink/asha/Device.cxx:256
    #7 0x55e4fcca0ae1 in operator() /home/tomek/asha/asha_pipewire_sink/asha/Asha.cxx:118
    #8 0x55e4fcca4d89 in __invoke_impl<void, asha::Asha::OnAddDevice(const asha::Bluetooth::BluezDevice&)::<lambda()>&> /usr/include/c++/14.1.1/bits/invoke.h:61
    #9 0x55e4fcca42ab in __invoke_r<void, asha::Asha::OnAddDevice(const asha::Bluetooth::BluezDevice&)::<lambda()>&> /usr/include/c++/14.1.1/bits/invoke.h:150
    #10 0x55e4fcca3852 in _M_invoke /usr/include/c++/14.1.1/bits/std_function.h:290
    #11 0x55e4fcca7e87 in std::function<void ()>::operator()() const /usr/include/c++/14.1.1/bits/std_function.h:591
    #12 0x55e4fcca2a13 in asha::Asha::ProcessDeferred() /home/tomek/asha/asha_pipewire_sink/asha/Asha.cxx:186
    #13 0x55e4fcca2723 in operator() /home/tomek/asha/asha_pipewire_sink/asha/Asha.cxx:177
    #14 0x55e4fcca2742 in _FUN /home/tomek/asha/asha_pipewire_sink/asha/Asha.cxx:178
    #15 0x7dff21d42ed9  (/usr/lib/libglib-2.0.so.0+0x5ded9) (BuildId: 8880230af7e37f2edbd90b79170aead80dde617a)
    #16 0x7dff21d41a88  (/usr/lib/libglib-2.0.so.0+0x5ca88) (BuildId: 8880230af7e37f2edbd90b79170aead80dde617a)
    #17 0x7dff21da39b6  (/usr/lib/libglib-2.0.so.0+0xbe9b6) (BuildId: 8880230af7e37f2edbd90b79170aead80dde617a)
    #18 0x7dff21d42786 in g_main_loop_run (/usr/lib/libglib-2.0.so.0+0x5d786) (BuildId: 8880230af7e37f2edbd90b79170aead80dde617a)
    #19 0x55e4fcceb703 in main /home/tomek/asha/asha_pipewire_sink/pipewire_sink.cxx:57
    #20 0x7dff21639c87  (/usr/lib/libc.so.6+0x25c87) (BuildId: 32a656aa5562eece8c59a585f5eacd6cf5e2307b)
    #21 0x7dff21639d4b in __libc_start_main (/usr/lib/libc.so.6+0x25d4b) (BuildId: 32a656aa5562eece8c59a585f5eacd6cf5e2307b)
    #22 0x55e4fcc9fb04 in _start (/home/tomek/asha/asha_pipewire_sink/build/asha_pipewire_sink+0xdb04) (BuildId: e55a0ee0d74cee5982d29ae57cd999884b64191a)

==5568==ABORTING
barolo commented 3 months ago

And another (partially intentional) crash from asha_pipewire_sink still keeps disconnecting one side but in general program seems more stable and crashed after 3 mins and several aid reconnections.

Are you using the newest commits? There was an update to asha_pipewire_sink which should improve things. Also try connecting your devices before starting asha_stream or asha_pipewire. Connecting after can lead to instability and it's a known issue.

tomektom commented 3 months ago

Yes, that's from latest commit

Also try connecting your devices before starting asha_stream or asha_pipewire. Connecting after can lead to instability and it's a known issue.

In this situation no crash but still one device always disconnect after several seconds... In my case connecting after start asha_* is only way to play on both aids for more than first 2-3 seconds.

thewierdnut commented 3 months ago

And another (partially intentional) crash from asha_pipewire_sink still keeps disconnecting one side but in general program seems more stable and crashed after 3 mins and several aid reconnections.

When you say "disconnect" here, do you mean that you only see a Disconnected from %s: (%s) message, but the device stays attached via bluetooth? Or that that the bluetooth connection drops entirely and you have to re-attach it via the an O/S bluetooth menu?

This may be hitting a logic path that I can't reproduce locally, where the bluetooth stays attached, but the audio stream gets disconnected. That recovery logic is older than the buffer thread implementation, and needs updated.

tomektom commented 3 months ago

When you say \"disconnect\" here, do you mean that you only see a Disconnected from %s: (%s) message, but the device stays attached via bluetooth? Or that that the bluetooth connection drops entirely and you have to re-attach it via the an O/S bluetooth menu?

The second option. BT connection drops entirely. The scenario is usually that first drop audio on one side and 1-2 seconds later drops BT connection entirely on this side.

thewierdnut commented 3 months ago

I think I've fixed the crash you have been seeing.

I've also added an additional pre-buffer step during startup which may improve the stability. Please test and let me know how it goes. Remember to double-check that 2M PHY is enabled.

thewierdnut commented 3 months ago

Also, did you ever get a chance to test this on your desktop with the Intel bluetooth adapter?

tomektom commented 3 months ago

I think I've fixed the crash you have been seeing.

Nope asha_pipewire_sink still crashing

** INFO: 18:53:55.583: Dropping frame for TOMASZ (Left)
AddressSanitizer:DEADLYSIGNAL
=================================================================
==3776==ERROR: AddressSanitizer: SEGV on unknown address 0x0000000002d5 (pc 0x5c042eb4a942 bp 0x76a5a55ff790 sp 0x76a5a55ff780 T30)
==3776==The signal is caused by a READ memory access.
==3776==Hint: address points to the zero page.
    #0 0x5c042eb4a942 in asha::Side::Ready() const /home/tomek/asha/asha_pipewire_sink/asha/Side.hh:69
    #1 0x5c042eb45510 in asha::Device::SendAudio(RawS16 const&) /home/tomek/asha/asha_pipewire_sink/asha/Device.cxx:183
    #2 0x5c042eb43386 in operator() /home/tomek/asha/asha_pipewire_sink/asha/Device.cxx:15
    #3 0x5c042eb47adc in __invoke_impl<bool, asha::Device::Device(uint64_t, const std::string&, const std::string&, ReconnectCallback)::<lambda(const RawS16&)>&, const RawS16&> /usr/include/c++/14.1.1/bits/invoke.h:61
    #4 0x5c042eb476c1 in __invoke_r<bool, asha::Device::Device(uint64_t, const std::string&, const std::string&, ReconnectCallback)::<lambda(const RawS16&)>&, const RawS16&> /usr/include/c++/14.1.1/bits/invoke.h:138
    #5 0x5c042eb472b1 in _M_invoke /usr/include/c++/14.1.1/bits/std_function.h:290
    #6 0x5c042eb4e828 in std::function<bool (RawS16 const&)>::operator()(RawS16 const&) const (/home/tomek/asha/asha_pipewire_sink/build/asha_pipewire_sink+0x3f828) (BuildId: 495e00eef5b6e4639ff6577e362c95b0b665542c)
    #7 0x5c042eb4cd23 in asha::Buffer<8ul>::DeliveryThread() /home/tomek/asha/asha_pipewire_sink/asha/Buffer.hh:144
    #8 0x5c042eb51b52 in void std::__invoke_impl<void, void (asha::Buffer<8ul>::*)(), asha::Buffer<8ul>*>(std::__invoke_memfun_deref, void (asha::Buffer<8ul>::*&&)(), asha::Buffer<8ul>*&&) /usr/include/c++/14.1.1/bits/invoke.h:74
    #9 0x5c042eb51a7a in std::__invoke_result<void (asha::Buffer<8ul>::*)(), asha::Buffer<8ul>*>::type std::__invoke<void (asha::Buffer<8ul>::*)(), asha::Buffer<8ul>*>(void (asha::Buffer<8ul>::*&&)(), asha::Buffer<8ul>*&&) /usr/include/c++/14.1.1/bits/invoke.h:96
    #10 0x5c042eb519ea in void std::thread::_Invoker<std::tuple<void (asha::Buffer<8ul>::*)(), asha::Buffer<8ul>*> >::_M_invoke<0ul, 1ul>(std::_Index_tuple<0ul, 1ul>) /usr/include/c++/14.1.1/bits/std_thread.h:292
    #11 0x5c042eb51989 in std::thread::_Invoker<std::tuple<void (asha::Buffer<8ul>::*)(), asha::Buffer<8ul>*> >::operator()() /usr/include/c++/14.1.1/bits/std_thread.h:299
    #12 0x5c042eb51953 in std::thread::_State_impl<std::thread::_Invoker<std::tuple<void (asha::Buffer<8ul>::*)(), asha::Buffer<8ul>*> > >::_M_run() /usr/include/c++/14.1.1/bits/std_thread.h:244
    #13 0x76a5afae0c83 in execute_native_thread_routine /usr/src/debug/gcc/gcc/libstdc++-v3/src/c++11/thread.cc:104
    #14 0x76a5b025cc79 in asan_thread_start /usr/src/debug/gcc/gcc/libsanitizer/asan/asan_interceptors.cpp:234
    #15 0x76a5af8a6dec  (/usr/lib/libc.so.6+0x92dec) (BuildId: 32a656aa5562eece8c59a585f5eacd6cf5e2307b)
    #16 0x76a5af92a0db  (/usr/lib/libc.so.6+0x1160db) (BuildId: 32a656aa5562eece8c59a585f5eacd6cf5e2307b)

AddressSanitizer can not provide additional info.
SUMMARY: AddressSanitizer: SEGV /home/tomek/asha/asha_pipewire_sink/asha/Side.hh:69 in asha::Side::Ready() const
Thread T30 created by T0 here:
    #0 0x76a5b02f38fb in pthread_create /usr/src/debug/gcc/gcc/libsanitizer/asan/asan_interceptors.cpp:245
    #1 0x76a5afae0d81 in __gthread_create /usr/src/debug/gcc/gcc-build/x86_64-pc-linux-gnu/libstdc++-v3/include/x86_64-pc-linux-gnu/bits/gthr-default.h:676
    #2 0x76a5afae0d81 in std::thread::_M_start_thread(std::unique_ptr<std::thread::_State, std::default_delete<std::thread::_State> >, void (*)()) /usr/src/debug/gcc/gcc/libstdc++-v3/src/c++11/thread.cc:172
    #3 0x5c042eb4d0a8 in std::thread::thread<void (asha::Buffer<8ul>::*)(), asha::Buffer<8ul>*, void>(void (asha::Buffer<8ul>::*&&)(), asha::Buffer<8ul>*&&) /usr/include/c++/14.1.1/bits/std_thread.h:164
    #4 0x5c042eb4bb43 in asha::Buffer<8ul>::Start() /home/tomek/asha/asha_pipewire_sink/asha/Buffer.hh:49
    #5 0x5c042eb44a4c in asha::Device::Start() /home/tomek/asha/asha_pipewire_sink/asha/Device.cxx:127
    #6 0x5c042eb45f81 in asha::Device::AddSide(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, std::shared_ptr<asha::Side> const&) /home/tomek/asha/asha_pipewire_sink/asha/Device.cxx:257
    #7 0x5c042eb1dae1 in operator() /home/tomek/asha/asha_pipewire_sink/asha/Asha.cxx:118
    #8 0x5c042eb21d89 in __invoke_impl<void, asha::Asha::OnAddDevice(const asha::Bluetooth::BluezDevice&)::<lambda()>&> /usr/include/c++/14.1.1/bits/invoke.h:61
    #9 0x5c042eb212ab in __invoke_r<void, asha::Asha::OnAddDevice(const asha::Bluetooth::BluezDevice&)::<lambda()>&> /usr/include/c++/14.1.1/bits/invoke.h:150
    #10 0x5c042eb20852 in _M_invoke /usr/include/c++/14.1.1/bits/std_function.h:290
    #11 0x5c042eb24e87 in std::function<void ()>::operator()() const /usr/include/c++/14.1.1/bits/std_function.h:591
    #12 0x5c042eb1fa13 in asha::Asha::ProcessDeferred() /home/tomek/asha/asha_pipewire_sink/asha/Asha.cxx:186
    #13 0x5c042eb1f723 in operator() /home/tomek/asha/asha_pipewire_sink/asha/Asha.cxx:177
    #14 0x5c042eb1f742 in _FUN /home/tomek/asha/asha_pipewire_sink/asha/Asha.cxx:178
    #15 0x76a5afee3ed9  (/usr/lib/libglib-2.0.so.0+0x5ded9) (BuildId: 8880230af7e37f2edbd90b79170aead80dde617a)
    #16 0x76a5afee2a88  (/usr/lib/libglib-2.0.so.0+0x5ca88) (BuildId: 8880230af7e37f2edbd90b79170aead80dde617a)
    #17 0x76a5aff449b6  (/usr/lib/libglib-2.0.so.0+0xbe9b6) (BuildId: 8880230af7e37f2edbd90b79170aead80dde617a)
    #18 0x76a5afee3786 in g_main_loop_run (/usr/lib/libglib-2.0.so.0+0x5d786) (BuildId: 8880230af7e37f2edbd90b79170aead80dde617a)
    #19 0x5c042eb68a77 in main /home/tomek/asha/asha_pipewire_sink/pipewire_sink.cxx:57
    #20 0x76a5af839c87  (/usr/lib/libc.so.6+0x25c87) (BuildId: 32a656aa5562eece8c59a585f5eacd6cf5e2307b)
    #21 0x76a5af839d4b in __libc_start_main (/usr/lib/libc.so.6+0x25d4b) (BuildId: 32a656aa5562eece8c59a585f5eacd6cf5e2307b)
    #22 0x5c042eb1cb04 in _start (/home/tomek/asha/asha_pipewire_sink/build/asha_pipewire_sink+0xdb04) (BuildId: 495e00eef5b6e4639ff6577e362c95b0b665542c)

==3776==ABORTING

I've also added an additional pre-buffer step during startup which may improve the stability. Please test and let me know how it goes. Remember to double-check that 2M PHY is enabled.

That didn't help, still no sound on one side and bluetooth connection drops after short moment, here results from btmon test_fixed.snoop.txt

Also, did you ever get a chance to test this on your desktop with the Intel bluetooth adapter?

Gimme a moment, I just returned to home :smile:

tomektom commented 3 months ago

Same system (Manjaro) but ohther hardware is much better. With asha_pipewire_sink I was able to listen YT for around 15 min, still some audio drops but no BT disconnections and it's usable. That's amazing :smile:

Bluetooth:
  Device-1: Intel AX200 Bluetooth driver: btusb v: 0.8 type: USB rev: 2.0
    speed: 12 Mb/s lanes: 1 mode: 1.1 bus-ID: 1-5:3 chip-ID: 8087:0029
    class-ID: e001
  Report: hciconfig ID: hci0 rfk-id: 0 state: up address: <filter> bt-v: 5.2
    lmp-v: 11 sub-v: 2184 hci-v: 11 rev: 2184 class-ID: 6c0104
  Info: acl-mtu: 1021:4 sco-mtu: 96:6 link-policy: rswitch sniff
    link-mode: peripheral accept service-classes: rendering, capturing, audio,
    telephony

Here test results, no BT disconnections just some adio drops (and these drops were slightly bigger than with asha_pipewire_sink) test_fixed.snoop.txt

I forgot to mention earlier but on both devices I had 2M PHY enabled by default :wink:

thewierdnut commented 3 months ago

I forgot to mention earlier but on both devices I had 2M PHY enabled by default 😉

Yeah, the 2M PHY thing just seems to be me. I'm on debian stable, which uses 6.1 kernel. If you have 6.8 or newer, then 2M PHY is enabled by default.

That didn't help, still no sound on one side and bluetooth connection drops after short moment,

I managed to reproduce that crash (I think), and I made another attempt at fixing it.

tomektom commented 3 months ago

I looked again into it just now and ran test on Foxconn / Hon Hai MediaTek. You are amazing :clap:

sudo ./asha_stream_test --left ../sounds/left.g722 --right ../sounds/right.g722 --algorithm fixed --volume -64 --celength 10

That solved everything – no BT disconnections, no audio drops, that's even better than on Intel AX200 (I will try here soon too). Also works with celength 20 and 15 – didn't tried other values but I suppose any will work. --phy1m and --phy2m didn't have any effect for me. Perfect test results included below test_fixed_10.snoop.txt

tomektom commented 3 months ago

Yep on Intel AX200 it also slightly improves stability. Value doesn't matter (also tried 10, 15 and 20). phy also changes nothing. Results for same command as previous test_fixed_10_intel.snoop.txt

thewierdnut commented 3 months ago

That solved everything – no BT disconnections, no audio drops

I apologize, but this is fickle software using a fickle bluetooth stack with fickle hardware and fickle hearing devices. Please double-check that running without the --celength causes problems, and running with --celength solves them. Power cycle your hearing devices between each test to make sure that setup state doesn't linger from one test to the next.

thewierdnut commented 3 months ago

test_fixed_10_intel.snoop.txt

Also, no need for the .txt file extension. Leaving them as .snoop works just fine.

tomektom commented 3 months ago

test_fixed_10_intel.snoop.txt

Also, no need for the .txt file extension. Leaving them as .snoop works just fine.

I know, but Github don't allow for files with .snoop extension.

That solved everything – no BT disconnections, no audio drops

I apologize, but this is fickle software using a fickle bluetooth stack with fickle hardware and fickle hearing devices. Please double-check that running without the --celength causes problems, and running with --celength solves them. Power cycle your hearing devices between each test to make sure that setup state doesn't linger from one test to the next.

I ran tetsts again with different celength values and now I can say that (probably) everything between celength 3 and 32 is perfectly stable. I zipped all my tests. Naming convention c<celength-value>.snoop and normal_x.snoop for tests without --celength flag. I didn't use --phy* flag anywhere and restart hearing aids and bluetooth service before every test. tests.zip

thewierdnut commented 3 months ago

I ran tetsts again with different celength values and now I can say that (probably) everything between celength 3 and 32 is perfectly stable.

And to confirm, it is unstable when you don't use the --celength argument?

Believe it or not, this is a bad sign. Bluez and the linux kernel don't provide a way to set the celength. I've had to implement it by crafting the request myself and sending it to the hci controller using raw sockets. It also requires root access, and I haven't yet figured out how to access a user pipewire session as the root user.

tomektom commented 3 months ago

And to confirm, it is unstable when you don't use the --celength argument?

Yep, It's always unstable without --celenght

Believe it or not, this is a bad sign. Bluez and the linux kernel don't provide a way to set the celength. I've had to implement it by crafting the request myself and sending it to the hci controller using raw sockets. It also requires root access, and I haven't yet figured out how to access a user pipewire session as the root user.

setcap isn't enoguh? I think end user (or package maintainer if some distributions adapt this for their repositories) should be responsible for this. You should only provide valid instructions if something like that is required :wink:

sudo setcap cap_net_raw+eip asha_stream_test
thewierdnut commented 3 months ago

setcap isn't enoguh?

It is enough. I was just hoping for a solution that worked without it.

barolo commented 3 months ago

I'm wondering if it's hardware related since it only seems to help with MediaTek's card.

thewierdnut commented 3 months ago

I'm wondering if it's hardware related since it only seems to help with MediaTek's card.

Possibly. The "low energy" part of bluetooth LE is accomplished by scheduling specific time intervals when communication is done. The transmission hardware is shut off in between these times, thus saving power. The ce length is a suggestion to the peripheral how long it should listen for traffic during those intervals. If the transmitter has a poor clock signal or something, it may not be scheduling the transmits very accurately, which means a longer ce length gives the peripheral more time to actually get the traffic.

thewierdnut commented 3 months ago

I just pushed a new version of asha_pipewire_sink that, among other things, attempts to use raw sockets to set the celength if it has CAP_NET_RAW. That may work better for you.

tomektom commented 3 months ago

Yes, now it definitely works better and is usable in general. Based on one ~30min YT listening – no audio drops (so with this is better than on Intel AX200 – didn't tested latest version here) but one ear keeps disconnecting BT after 5-10mins (probably some random environment issues) – but after reconnect it keep working – i saw similar issue earlier on Intel but with both ears at same time and with loger time period.

I will do more tests evening ;)

tomektom commented 3 months ago

I used newest asha_pipewire_sink on both PCs for some more time and on both I have almost same stability – small audio drops if any, but you should expect one or both hearing aids will disconnect in ~5-30min period. So it's ok to use when you can easily reconnect BT – YT, music, podcasts etc. – but may not be stable enough for gaming or meetings with some important business clients.

I also tried to use qpwgraph to redirect audio also to other speakers (that would be nice and useful in some situations – eg. share meeting with other persons in room) – but then asha_pipewire_sink got completely unstable – probably as you mentioned in #13 I need to compile latest pipewire. I'll just wait when it arrive to my system. I'm interested how it will play – probably I expect too much ;)

barolo commented 3 months ago

I also tried to use qpwgraph to redirect audio also to other speakers (that would be nice and useful in some situations – eg. share meeting with other persons in room) – but then asha_pipewire_sink got completely unstable – probably as you mentioned in #13 I need to compile latest pipewire. I'll just wait when it arrive to my system. I'm interested how it will play – probably I expect too much ;)

This is my experience too, it's fine for media but not reliable enough for time critical stuff or chats. We might have to wait for something lower level like the ongoing BlueZ ASHA. Or that Pico dongle project.

shermp commented 3 months ago

Or that Pico dongle project

I'm having similar issues at the moment, although at least I can automatically reconnect. My HA's seem to love disconnecting completely if there's something about the L2CAP connection it doesn't like.

thewierdnut commented 3 months ago

I've updated the wiki with this device. Please post a new issue if you have any further problems.