thewierdnut / asha_pipewire_sink

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

Not working on Cochlear Nucleus 7 #20

Closed GRBaset closed 1 month ago

GRBaset commented 4 months ago

I've tested this with my Cochlear Nucleus 7 processors, however, streaming seems to not be working, it disconnects almost instantly after connecting. I have tested this on both the right and left ear devices to no avail.

inxi -ISEazy reports:

System:
  Kernel: 6.9.6-zen1-1-zen arch: x86_64 bits: 64 compiler: gcc v: 14.1.1
    clocksource: tsc avail: hpet,acpi_pm parameters: rw
    root=UUID=f510a0bf-6aae-4fd7-87d9-82f12c3244af resume=/dev/mapper/root
    rootflags=subvol=@ resume_offset=533760
    rd.luks.name=22dea89a-bf8c-4cb5-9f14-138cec706abc=root
    rd.luks.options=discard amdgpu.sg_display=0 iommu=pt iommu=1
    initrd=amd-ucode.img initrd=booster-linux-zen.img
  Desktop: KDE Plasma v: 6.1.1 tk: Qt v: N/A info: frameworks v: 6.3.0
    wm: kwin_wayland with: krunner vt: 1 dm: SDDM Distro: Arch Linux
Bluetooth:
  Device-1: MediaTek Wireless_Device driver: btusb v: 0.8 type: USB rev: 2.1
    speed: 480 Mb/s lanes: 1 mode: 2.0 bus-ID: 1-5:3 chip-ID: 0e8d:e616
    class-ID: e001 serial: <filter>
  Report: btmgmt ID: hci0 rfk-id: 0 state: up address: <filter> bt-v: 5.2
    lmp-v: 11 status: discoverable: no pairing: no class-ID: 7c010c
Info:
  Memory: total: 32 GiB note: est. available: 30.66 GiB used: 11.82 GiB (38.5%)
  Processes: 415 Power: uptime: 4d 43m states: freeze,mem,disk
    suspend: s2idle wakeups: 18 hibernate: platform avail: shutdown, reboot,
    suspend, test_resume image: 12.26 GiB services: org_kde_powerdevil,
    power-profiles-daemon, upowerd Init: systemd v: 256 default: graphical
    tool: systemctl
  Packages: 2411 pm: pacman pkgs: 2350 libs: 407 tools: paru pm: flatpak
    pkgs: 61 Compilers: clang: 17.0.6 gcc: 14.1.1 Shell: Zsh v: 5.9
    running-in: kitty inxi: 3.3.35

I tested both the stable version from pacman (5.76) and the bluez master branch, on different commits (latest I've tested is 7e028287a).

The Bluetooth module is the AMD RZ616 (MediaTek MT7922) network card. #10 might be related given that it also concerns a MediaTek card. I don't have other cards to test, but I can purchase an Intel AX200 card if necessary.

asha-connection-test says (MAC address has been sanitized):

(process:541223): GLib-GIO-DEBUG: 17:24:48.238: Using cross-namespace EXTERNAL authentication (this will deadlock if server is GDBus < 2.73.3)
** INFO: 17:24:56.165: Adding bluetooth device GR Hearing Devices
** INFO: 17:24:56.253: GR Hearing Devices (Left)
** INFO: 17:24:56.253:     Name:      GR Hearing Devices
** INFO: 17:24:56.253:     Mac:       84:77:78:XX:XX:XX
** INFO: 17:24:56.253:     HiSyncId:  12316521704347140233
** INFO: 17:24:56.253:     Side:      left (binaural)
** INFO: 17:24:56.253:     Delay:     100 ms
** INFO: 17:24:56.253:     Streaming: supported
** INFO: 17:24:56.253:     Codecs:    G.722@16kHz
** INFO: 17:24:57.394: left  Sending ACP status parameters updated 16

** (process:541223): WARNING **: 17:24:58.399: Error calling StartNotify: GDBus.Error:org.bluez.Error.Failed: Operation failed with ATT error: 0x0e

** (process:541223): WARNING **: 17:24:58.399: Null result when calling StartNotify
** INFO: 17:24:58.399:     Connected: true

** (process:541223): WARNING **: 17:24:58.399:     Error retrieving L2CAP_CONNINFO: Operation not permitted 1

** (process:541223): WARNING **: 17:24:58.399:     Error retrieving BT_SNDMTU: Operation not permitted 1
    Error retrieving BT_PHY: Operation not permitted (1)
** INFO: 17:24:58.399:     MODE: LE_FLOWCTL
** INFO: 17:24:58.399:     Hci Connection Info:
** INFO: 17:24:58.399:        type:   0 SCO
** INFO: 17:24:58.399:        out:    0 false
** INFO: 17:24:58.399:        state:  0 invalid state
** INFO: 17:24:58.399:        mode:   0
** INFO: 17:24:58.399:     min_connection_interval: 16
** INFO: 17:24:58.399:     max_connection_interval: 16
** INFO: 17:24:58.399: Removing bluetooth device GR Hearing Devices
** INFO: 17:24:58.399: Removing GR Hearing Devices (Left)
^CStopping...

Running asha-stream-test yields:

(process:541223): GLib-GIO-DEBUG: 17:24:48.238: Using cross-namespace EXTERNAL authentication (this will deadlock if server is GDBus < 2.73.3)
** INFO: 17:24:56.165: Adding bluetooth device GR Hearing Devices
** INFO: 17:24:56.253: GR Hearing Devices (Left)
** INFO: 17:24:56.253:     Name:      GR Hearing Devices
** INFO: 17:24:56.253:     Mac:       84:77:78:XX:XX:XX
** INFO: 17:24:56.253:     HiSyncId:  12316521704347140233
** INFO: 17:24:56.253:     Side:      left (binaural)
** INFO: 17:24:56.253:     Delay:     100 ms
** INFO: 17:24:56.253:     Streaming: supported
** INFO: 17:24:56.253:     Codecs:    G.722@16kHz
** INFO: 17:24:57.394: left  Sending ACP status parameters updated 16

** (process:541223): WARNING **: 17:24:58.399: Error calling StartNotify: GDBus.Error:org.bluez.Error.Failed: Operation failed with ATT error: 0x0e

** (process:541223): WARNING **: 17:24:58.399: Null result when calling StartNotify
** INFO: 17:24:58.399:     Connected: true

** (process:541223): WARNING **: 17:24:58.399:     Error retrieving L2CAP_CONNINFO: Operation not permitted 1

** (process:541223): WARNING **: 17:24:58.399:     Error retrieving BT_SNDMTU: Operation not permitted 1
    Error retrieving BT_PHY: Operation not permitted (1)
** INFO: 17:24:58.399:     MODE: LE_FLOWCTL
** INFO: 17:24:58.399:     Hci Connection Info:
** INFO: 17:24:58.399:        type:   0 SCO
** INFO: 17:24:58.399:        out:    0 false
** INFO: 17:24:58.399:        state:  0 invalid state
** INFO: 17:24:58.399:        mode:   0
** INFO: 17:24:58.399:     min_connection_interval: 16
** INFO: 17:24:58.399:     max_connection_interval: 16
** INFO: 17:24:58.399: Removing bluetooth device GR Hearing Devices
** INFO: 17:24:58.399: Removing GR Hearing Devices (Left)
^CStopping...

I tested with different CE lengths from 3 to 32 and setting 1M/2M PHY, as suggested in #10, same result.

I have attached two zipped btsnoop files (both of the left ear device, with sanitized MAC addresses), one for the connection test and another for the stream test. asha-btsnoop.zip

thewierdnut commented 4 months ago

I tested both the stable version from pacman (5.76) and the bluez master branch, on different commits (latest I've tested is 7e028287a).

I run with 5.66 (older than yours). The stable version should be sufficient.

The packet dump shows asha_stream_test subscribing to AudioStatus, and then timing out after one second.

Your device initially negotiates a supervision timeout of 6 seconds. If you run asha_stream_test with root access or with CAP_NET_RAW permissions, it will override this with the default of 1 second from the android source code. It may need a higher value.

Lets try some values that may work better for you. First, edit your /etc/bluetooth/main.conf to contain the following settings. Note that they should already be present in the file, but commented out:

[LE]
MinConnectionInterval=16
MaxConnectionInterval=16
ConnectionLatency=10
ConnectionSupervisionTimeout=600

Restart the bluetooth service after editing /etc/bluetooth/main.conf, and then forget and rediscover your hearing device using the bluetooth gui.

Then try rerunning asha_stream_test, but without root/CAP_NET_RAW permissions, so that it uses the defaults that bluez sets.

thewierdnut commented 4 months ago

As I noted in the slack chat, this is the first device I have seen that originates its own parameter update request (which violates the asha spec, but is what bluetooth devices are supposed to do). Let me know if you already have these config values already set in your config, in which case we may need to make some changes to bluez.

thewierdnut commented 4 months ago

After reading a lot of kernel code, I don't think setting those parameters via /etc/bluetooth/main.conf will work for you. Instead, I've added a new --timeout argument to stream_test for you to try. In the snoop file, your device seems to want to use the value 600, but 100 is the default used by android. Try settings values between 100 and 800, and see if any of them work for you.

GRBaset commented 4 months ago

I have tried several values between 100 and 800 for --timeout, and I also tried modifying /etc/bluetooth/main.conf. Unfortunately, the issue persists.

For example, with a value of 600:

> sudo ./asha_stream_test --left test.g722 --timeout 600

(process:775310): GLib-GIO-DEBUG: 00:44:03.535: Using cross-namespace EXTERNAL authentication (this will deadlock if server is GDBus < 2.73.3)
Running with fixed rate frames
** INFO: 00:44:07.278: Adding bluetooth device GR Hearing Devices
GR Hearing Devices (Left)
    Name:      GR Hearing Devices
    Mac:       84:77:78:XX:XX:XX
    HiSyncId:  12316521704347140233
    Side:      left (binaural)
    Delay:     100 ms
    Streaming: supported
    Codecs:    G.722@16kHz
    Connected: Timed out waiting for response
** INFO: 00:44:09.533: left  Sending ACP status parameters updated 16
Stream latency: 0.0204226

** (process:775310): WARNING **: 00:44:13.808: Error calling StartNotify: GDBus.Error:org.bluez.Error.Failed: Operation failed with ATT error: 0x0e

** (process:775310): WARNING **: 00:44:13.808: Null result when calling StartNotify
true
    Error retrieving BT_PHY: Operation not permitted (1)

** (process:775310): WARNING **: 00:44:13.819: Error calling WriteValue: GDBus.Error:org.bluez.Error.Failed: Not connected

** (process:775310): WARNING **: 00:44:13.819: Null result when calling WriteValue
** INFO: 00:44:13.819: left  Sending ACP status parameters updated 16

** (process:775310): WARNING **: 00:44:13.819: Error calling WriteValue: GDBus.Error:org.bluez.Error.Failed: Not connected

** (process:775310): WARNING **: 00:44:13.819: Null result when calling WriteValue
Running with fixed rate frames
** INFO: 00:44:13.821: Removing bluetooth device GR Hearing Devices
Removing GR Hearing Devices (Left)
** INFO: 00:44:14.071: left  Sending ACP start other not connected

** (process:775310): WARNING **: 00:44:14.071: Error calling WriteValue: GDBus.Error:org.bluez.Error.Failed: Not connected

** (process:775310): WARNING **: 00:44:14.071: Null result when calling WriteValue
** INFO: 00:44:14.071: left  Sending ACP stop

** (process:775310): WARNING **: 00:44:14.071: Error calling WriteValue: GDBus.Error:org.bluez.Error.Failed: Not connected

** (process:775310): WARNING **: 00:44:14.071: Null result when calling WriteValue
^CStopping...

I've attached a btsnoop file, also for a timeout of 600. asha-stream-test-2.zip

thewierdnut commented 4 months ago

Can you get me a snoop file of asha_stream_test without root or CAP_NET_RAW perms? I don't think it will work, but I want to see if it successfully subscribes to status updates.

thewierdnut commented 4 months ago

I've attached a btsnoop file, also for a timeout of 600.

The timeout 600 wasn't being set (I had a bug in the program). Hopefully its fixed now, can you try again?

GRBaset commented 4 months ago

Pulled and recompiled (also tried a fresh clone), doesn't work either. I tested both with and without root.

With root:

sudo ./asha_stream_test --left test.g722 --timeout 600
(process:804479): GLib-GIO-DEBUG: 15:31:46.654: Using cross-namespace EXTERNAL authentication (this will deadlock if server is GDBus < 2.73.3)
** INFO: 15:31:46.656: Adding bluetooth device GR Hearing Devices
GR Hearing Devices (Left)
    Name:      GR Hearing Devices
    Mac:       84:77:78:XX:XX:XX
    HiSyncId:  12316521704347140233
    Side:      left (binaural)
    Delay:     100 ms
    Streaming: supported
    Codecs:    G.722@16kHz
    Connected: ** INFO: 15:31:48.001: left  Sending ACP status parameters updated 16

** (process:804479): WARNING **: 15:31:49.007: Error calling StartNotify: GDBus.Error:org.bluez.Error.Failed: Operation failed with ATT error: 0x0e

** (process:804479): WARNING **: 15:31:49.007: Null result when calling StartNotify
true
    Error retrieving BT_PHY: Operation not permitted (1)

** (process:804479): WARNING **: 15:31:49.018: Error calling WriteValue: GDBus.Error:org.bluez.Error.Failed: Not connected

** (process:804479): WARNING **: 15:31:49.018: Null result when calling WriteValue
    Unable to set connection interval (needs CAP_NET_RAW for this to work)
** INFO: 15:31:49.018: left  Sending ACP status parameters updated 16

** (process:804479): WARNING **: 15:31:49.018: Error calling WriteValue: GDBus.Error:org.bluez.Error.Failed: Not connected

** (process:804479): WARNING **: 15:31:49.018: Null result when calling WriteValue

** (process:804479): WARNING **: 15:31:49.020: Error calling WriteValue: GDBus.Error:org.bluez.Error.Failed: Not connected

** (process:804479): WARNING **: 15:31:49.020: Null result when calling WriteValue
Running with fixed rate frames
** INFO: 15:31:49.270: left  Sending ACP start other not connected

** (process:804479): WARNING **: 15:31:49.270: Error calling WriteValue: GDBus.Error:org.bluez.Error.Failed: Not connected

** (process:804479): WARNING **: 15:31:49.271: Null result when calling WriteValue
^CStopping...
** INFO: 15:31:52.167: left  Sending ACP stop

** (process:804479): WARNING **: 15:31:52.167: Error calling WriteValue: GDBus.Error:org.bluez.Error.Failed: Not connected

** (process:804479): WARNING **: 15:31:52.167: Null result when calling WriteValue

Without root:

./asha_stream_test --left test.g722 --timeout 600 
(process:804876): GLib-GIO-DEBUG: 15:32:48.396: Using cross-namespace EXTERNAL authentication (this will deadlock if server is GDBus < 2.73.3)
Running with fixed rate frames
Stream latency: 0.0200094
Stream latency: 0.0204555
** INFO: 15:33:11.689: Adding bluetooth device GR Hearing Devices
GR Hearing Devices (Left)
    Name:      GR Hearing Devices
    Mac:       84:77:78:XX:XX:XX
    HiSyncId:  12316521704347140233
    Side:      left (binaural)
    Delay:     100 ms
    Streaming: supported
    Codecs:    G.722@16kHz
    Connected: ** INFO: 15:33:11.881: left  Sending ACP status parameters updated 16
true
    PHY:    0
    Unable to set connection interval (needs CAP_NET_RAW for this to work)
** INFO: 15:33:13.149: left  Sending ACP status parameters updated 16
Running with fixed rate frames
** INFO: 15:33:13.151: left  AshaStatus: 0
** INFO: 15:33:13.400: left  Sending ACP start other not connected
** INFO: 15:33:18.158: Removing bluetooth device GR Hearing Devices
Removing GR Hearing Devices (Left)

** (process:804876): WARNING **: 15:33:18.158: Error calling WriteValue: GDBus.Error:org.bluez.Error.Failed: Operation failed with ATT error: 0x0e

** (process:804876): WARNING **: 15:33:18.158: Null result when calling WriteValue
** INFO: 15:33:18.158: left  Sending ACP stop

** (process:804876): WARNING **: 15:33:18.158: Error calling WriteValue: GDBus.Error:org.bluez.Error.Failed: Not connected

** (process:804876): WARNING **: 15:33:18.158: Null result when calling WriteValue
^CStopping...

I attached two zipped btsnoop files, one with and another without root. asha-stream-test-4.zip

thewierdnut commented 4 months ago

Ok... non-root use case was about what I expected. It happily subscribes for status notifications, then promptly disconnects when I lie to it about the connection interval (I'm required to send the connection interval, but I have no way to read it from kernel space, so I just send the default).

The root use case still didn't send the right timeout. Apparently I was sending it twice, and you disconnected after the first one was wrong, and didn't get the corrected one.

I've modified asha_stream_test again to hopefully send the first one correctly, and eliminate the second one. Hopefully it works this time. Please try it again with CAP_NET_RAW permissions (or root, if you are so inclined).

GRBaset commented 4 months ago

Unfortunately, it still doesn't work. Looking at the btsnoop, it seems that the connection update is successfully sent and received, but nothing else happens. I tried with different timeouts, both higher and lower, same result.

Running it with CAP_NET_RAW permissions (or root) yields:

./asha_stream_test --left test.g722 --timeout 600 
(process:885555): GLib-GIO-DEBUG: 23:11:01.471: Using cross-namespace EXTERNAL authentication (this will deadlock if server is GDBus < 2.73.3)
Running with fixed rate frames
** INFO: 23:11:08.019: Adding bluetooth device GR Hearing Devices
GR Hearing Devices (Left)
    Name:      GR Hearing Devices
    Mac:       84:77:78:01:FA:D5
    HiSyncId:  12316521704347140233
    Side:      left (binaural)
    Delay:     100 ms
    Streaming: supported
    Codecs:    G.722@16kHz
** INFO: 23:11:09.238: left  Sending ACP status parameters updated 16
Stream latency: 0.0211712

** (process:885555): WARNING **: 23:11:15.244: Error calling StartNotify: GDBus.Error:org.bluez.Error.Failed: Operation failed with ATT error: 0x0e

** (process:885555): WARNING **: 23:11:15.244: Null result when calling StartNotify
    Connected: true
    Error retrieving BT_PHY: Operation not permitted (1)

** (process:885555): WARNING **: 23:11:15.254: Error calling WriteValue: GDBus.Error:org.bluez.Error.Failed: Not connected

** (process:885555): WARNING **: 23:11:15.254: Null result when calling WriteValue
Running with fixed rate frames
** INFO: 23:11:15.257: Removing bluetooth device GR Hearing Devices
Removing GR Hearing Devices (Left)
** INFO: 23:11:15.506: left  Sending ACP start other not connected

** (process:885555): WARNING **: 23:11:15.507: Error calling WriteValue: GDBus.Error:org.bluez.Error.Failed: Not connected

** (process:885555): WARNING **: 23:11:15.507: Null result when calling WriteValue
** INFO: 23:11:15.507: left  Sending ACP stop

** (process:885555): WARNING **: 23:11:15.507: Error calling WriteValue: GDBus.Error:org.bluez.Error.Failed: Not connected

** (process:885555): WARNING **: 23:11:15.507: Null result when calling WriteValue
^CStopping...

The relevant btsnoop file is attached. asha-stream-test-5.zip

thewierdnut commented 4 months ago

Hm... no change, except now it takes six seconds to time out instead of one.

Have you tried this with an android device? I would be interested in seeing an hci dump from a working connection from android device.

GRBaset commented 4 months ago

Hello, unfortunately I haven't been able to try it with an Android device because I don't have any compatible devices, and I wasn't able to make Bluetooth work with the emulator.

However, I was able to successfully run the stream test on different hardware, a 2015 MacBook Pro (Broadcom BCM20703A1 BT chip), running Arch Linux 6.9.7. The connection is quite touchy, though, and I have to be quite close (about 20-30 cm) to the laptop to get it working without dropped frames.

inxi -ISEazy reports:

System:
  Kernel: 6.9.7-zen1-1-zen arch: x86_64 bits: 64 compiler: gcc v: 14.1.1
    clocksource: tsc avail: acpi_pm
    parameters: root=UUID=ddd9816d-c1d6-483e-b11c-5116d6c65b51 rw
    rootflags=subvol=@
    cryptdevice=PARTUUID=c47254a3-c61a-7a4d-bf3a-644a61ea3fbf:root crypto=::::
    loglevel=3 resume=/dev/mapper/root resume_offset=533760
    initrd=\initramfs-linux-zen.img
  Desktop: KDE Plasma v: 6.1.2 tk: Qt v: N/A info: frameworks v: 6.3.0
    wm: kwin_wayland vt: 1 dm: SDDM Distro: Arch Linux
Bluetooth:
  Device-1: Apple Bluetooth Host Controller driver: btusb,hid-generic,usbhid
    type: USB rev: 2.0 speed: 12 Mb/s lanes: 1 mode: 1.1 bus-ID: 1-3:2
    chip-ID: 05ac:8290 class-ID: fe01
  Report: btmgmt ID: hci0 rfk-id: 3 state: up address: <filter> bt-v: 4.2
    lmp-v: 8 status: discoverable: no pairing: no class-ID: 6c010c
Info:
  Memory: total: 8 GiB available: 7.66 GiB used: 3.06 GiB (39.9%)
  Processes: 344 Power: uptime: 8h 22m states: freeze,mem,disk suspend: deep
    avail: s2idle wakeups: 3 hibernate: platform avail: shutdown, reboot,
    suspend, test_resume image: 3.05 GiB services: org_kde_powerdevil,upowerd
    Init: systemd v: 256 default: graphical tool: systemctl
  Packages: 1698 pm: pacman pkgs: 1653 libs: 386 tools: paru pm: flatpak
    pkgs: 45 Compilers: clang: 17.0.6 gcc: 14.1.1 Shell: Zsh v: 5.9
    running-in: konsole inxi: 3.3.35

The output of asha_stream_test is:

sudo ./asha_stream_test --left testing.g722 --timeout 600
(process:3110): GLib-GIO-DEBUG: 15:40:13.587: Using cross-namespace EXTERNAL authentication (this will deadlock if server is GDBus < 2.73.3)
Running with fixed rate frames
Stream latency: 0.0201474
^CStopping...
mbp-arch% sudo ./asha_stream_test --left testing.g722 --timeout 600
(process:3226): GLib-GIO-DEBUG: 15:42:32.630: Using cross-namespace EXTERNAL authentication (this will deadlock if server is GDBus < 2.73.3)
** INFO: 15:42:32.634: Adding bluetooth device GR Hearing Devices
GR Hearing Devices (Left)
    Name:      GR Hearing Devices
    Mac:       84:77:78:XX:XX:XX
    HiSyncId:  12316521704347140233
    Side:      left (binaural)
    Delay:     100 ms
    Streaming: supported
    Codecs:    G.722@16kHz
** INFO: 15:42:33.451: left  Sending ACP status parameters updated 16
    Connected: true
    PHY:    0
Running with fixed rate frames
** INFO: 15:42:34.726: left  AshaStatus: 0
** INFO: 15:42:34.976: left  Sending ACP start other not connected
** INFO: 15:42:35.037: left  AshaStatus: 0
left first sequence: 0
^CStopping...
** INFO: 15:42:38.801: left  Sending ACP stop

Finally, I have attached a zipped btsnoop file of the stream. asha-stream-test-mac.zip

thewierdnut commented 4 months ago

Did you start this capture before or after you connected your device via the bluetooth gui?

I ask because the snoop file doesn't show the initial bluetooth connection made by the operating system, just the one asha_stream_test made later.

thewierdnut commented 4 months ago

 Device-1: Apple Bluetooth Host Controller driver: btusb,hid-generic,usbhid
   type: USB rev: 2.0 speed: 12 Mb/s lanes: 1 mode: 1.1 bus-ID: 1-3:2
   chip-ID: 05ac:8290 class-ID: fe01
 Report: btmgmt ID: hci0 rfk-id: 3 state: up address: <filter> bt-v: 4.2
   lmp-v: 8 status: discoverable: no pairing: no class-ID: 6c010c```

I am seriously impressed. This is literally the minimum requirements for running ASHA, and has none of the optional features that make it more stable.

Finally, I have attached a zipped btsnoop file of the stream. asha-stream-test-mac.zip

This stream looks about like I would expect. It connects, renegotiates the connection interval, and then starts playback with no hitches. Since you are using bluetooth 4.2, I'm pretty sure its using 1M PHY, though it would be nice to confirm that if we caught the initial connection.

Are you streaming to one device, or two?

GRBaset commented 4 months ago

Hello, sorry for the long delay, I've been busy lately. 1M PHY is indeed the only one that seems to be supported:

$ sudo btmgmt phy
Supported phys: BR1M1SLOT BR1M3SLOT BR1M5SLOT EDR2M1SLOT EDR2M3SLOT EDR2M5SLOT EDR3M1SLOT EDR3M3SLOT EDR3M5SLOT LE1MTX LE1MRX 
Configurable phys: BR1M3SLOT BR1M5SLOT EDR2M1SLOT EDR2M3SLOT EDR2M5SLOT EDR3M1SLOT EDR3M3SLOT EDR3M5SLOT 
Selected phys: BR1M1SLOT BR1M3SLOT BR1M5SLOT EDR2M1SLOT EDR2M3SLOT EDR2M5SLOT EDR3M1SLOT EDR3M3SLOT EDR3M5SLOT LE1MTX LE1MRX 

I've done further tests, with both processors, on one ear and both. Suprisingly, it works in all cases, and I've found that the initial problem with distance was a fluke, it can stream up to around 2 meters. However, there is a stability issue (regardless of whether it's one device or both), wherein after about a minute or so, it starts to drop packages, and the problem compounds until it disconnects.

I've attached the snoop and log files (of the stream test) in a zip file. asha-stream-test-mac-further.zip

tazz4843 commented 1 month ago

Testing this with my N7s seems to result in almost exactly the same output on a Framework 16, with a Mediatek card as well. I've attached some logs from basic runs + info below. I'm not sure what a btsnoop entails, but if given instructions on how to do that I can send some and do some testing on my end.

> inxi -ISEazy
System:
  Kernel: 6.10.9-200.fc40.x86_64 arch: x86_64 bits: 64 compiler: gcc
    v: 2.41-37.fc40 clocksource: tsc avail: hpet,acpi_pm
    parameters: BOOT_IMAGE=(hd0,gpt2)/vmlinuz-6.10.9-200.fc40.x86_64
    root=/dev/mapper/rootfs-root ro rootflags=subvol=root
    rd.luks.uuid=luks-5ed65410-ead7-4c6b-bc76-1444051e3cbd
  Desktop: KDE Plasma v: 6.1.4 tk: Qt v: N/A info: frameworks v: 6.5.0
    wm: kwin_wayland vt: 2 dm: SDDM Distro: Fedora Linux 40 (KDE Plasma)
Bluetooth:
  Device-1: MediaTek Wireless_Device driver: btusb v: 0.8 type: USB rev: 2.1
    speed: 480 Mb/s lanes: 1 mode: 2.0 bus-ID: 1-5:6 chip-ID: 0e8d:e616
    class-ID: e001 serial: <filter>
  Report: btmgmt ID: hci0 rfk-id: 0 state: up address: <filter> bt-v: 5.2
    lmp-v: 11 status: discoverable: no pairing: no class-ID: 7c010c
Info:
  Memory: total: 32 GiB note: est. available: 30.65 GiB used: 5.74 GiB (18.7%)
  Processes: 439 Power: uptime: 25m states: freeze,mem suspend: s2idle
    wakeups: 0 hibernate: disabled image: 12.24 GiB services: org_kde_powerdevil,
    power-profiles-daemon, upowerd Init: systemd v: 255 target: graphical (5)
    default: graphical tool: systemctl
  Packages: pm: flatpak pkgs: 68 Compilers: clang: 18.1.8 alt: 17 gcc: 14.2.1
    Shell: fish v: 3.7.0 running-in: konsole inxi: 3.3.34
> sudo btmgmt phy
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
> sudo ./asha_connection_test
(process:10469): GLib-GIO-DEBUG: 14:28:42.716: Using cross-namespace EXTERNAL authentication (this will deadlock if server is GDBus < 2.73.3)
** INFO: 14:28:42.726: Adding bluetooth device Niko Hearing Devices
** INFO: 14:28:42.843: Niko Hearing Devices (Left)
** INFO: 14:28:42.843:     Name:      Niko Hearing Devices
** INFO: 14:28:42.843:     Mac:       84:77:78:xx:xx:xx
** INFO: 14:28:42.843:     HiSyncId:  10871868544774045833
** INFO: 14:28:42.843:     Side:      left (binaural)
** INFO: 14:28:42.843:     Delay:     100 ms
** INFO: 14:28:42.843:     Streaming: supported
** INFO: 14:28:42.843:     Codecs:    G.722@16kHz
** INFO: 14:28:42.985: left  Sending ACP status parameters updated 16
** INFO: 14:28:43.054:     Connected: true
** INFO: 14:28:43.054:     L2CAP_CONNINFO:
** INFO: 14:28:43.054:        handle: 512
** INFO: 14:28:43.054:        class:  [0, 0, 0]
** INFO: 14:28:43.054:     MTU:       SND 168 RCV 672
** INFO: 14:28:43.671:     PHY:    0
** INFO: 14:28:43.671:     MODE: LE_FLOWCTL
** INFO: 14:28:43.671:     Hci Connection Info:
** INFO: 14:28:43.671:        type:   128 LE
** INFO: 14:28:43.671:        out:    1 true
** INFO: 14:28:43.671:        state:  1 CONNECTED
** INFO: 14:28:43.671:        mode:   7 MASTER AUTH ENCRYPT
** INFO: 14:28:43.672:     min_connection_interval: 16
** INFO: 14:28:43.672:     max_connection_interval: 16
** INFO: 14:28:43.675: Adding bluetooth device Niko Hearing Devices
** INFO: 14:28:43.737: Niko Hearing Devices (Right)
** INFO: 14:28:43.737:     Name:      Niko Hearing Devices
** INFO: 14:28:43.737:     Mac:       84:77:78:xx:xx:xx
** INFO: 14:28:43.737:     HiSyncId:  10871868544774045833
** INFO: 14:28:43.737:     Side:      right (binaural)
** INFO: 14:28:43.737:     Delay:     100 ms
** INFO: 14:28:43.737:     Streaming: supported
** INFO: 14:28:43.737:     Codecs:    G.722@16kHz
** INFO: 14:28:43.969: right Sending ACP status parameters updated 16
** INFO: 14:28:44.055:     Connected: true
** INFO: 14:28:44.055:     L2CAP_CONNINFO:
** INFO: 14:28:44.056:        handle: 513
** INFO: 14:28:44.056:        class:  [0, 0, 0]
** INFO: 14:28:44.056:     MTU:       SND 168 RCV 672
** INFO: 14:28:44.670:     PHY:    0
** INFO: 14:28:44.670:     MODE: LE_FLOWCTL
** INFO: 14:28:44.670:     Hci Connection Info:
** INFO: 14:28:44.670:        type:   128 LE
** INFO: 14:28:44.670:        out:    1 true
** INFO: 14:28:44.670:        state:  1 CONNECTED
** INFO: 14:28:44.670:        mode:   7 MASTER AUTH ENCRYPT
** INFO: 14:28:44.670:     min_connection_interval: 16
** INFO: 14:28:44.670:     max_connection_interval: 16
** INFO: 14:28:44.682: left  AshaStatus: 0
** INFO: 14:28:44.682: right AshaStatus: 0
** INFO: 14:28:45.004: Niko Hearing Devices (Left) ServicesResolved: false
** INFO: 14:28:45.004: Niko Hearing Devices (Left) Connected: false
** INFO: 14:28:45.004: Removing bluetooth device Niko Hearing Devices
** INFO: 14:28:45.004: Removing Niko Hearing Devices (Left)
^CStopping...
> ./asha_connection_test
(process:10676): GLib-GIO-DEBUG: 14:29:24.934: Using cross-namespace EXTERNAL authentication (this will deadlock if server is GDBus < 2.73.3)
** INFO: 14:29:24.944: Adding bluetooth device Niko Hearing Devices
** INFO: 14:29:25.028: Niko Hearing Devices (Left)
** INFO: 14:29:25.028:     Name:      Niko Hearing Devices
** INFO: 14:29:25.028:     Mac:       84:77:78:xx:xx:xx
** INFO: 14:29:25.028:     HiSyncId:  10871868544774045833
** INFO: 14:29:25.028:     Side:      left (binaural)
** INFO: 14:29:25.028:     Delay:     100 ms
** INFO: 14:29:25.028:     Streaming: supported
** INFO: 14:29:25.028:     Codecs:    G.722@16kHz
** INFO: 14:29:25.211: left  Sending ACP status parameters updated 16
** INFO: 14:29:25.292:     Connected: true
** INFO: 14:29:25.292:     L2CAP_CONNINFO:
** INFO: 14:29:25.292:        handle: 512
** INFO: 14:29:25.292:        class:  [0, 0, 0]
** INFO: 14:29:25.292:     MTU:       SND 168 RCV 672
** INFO: 14:29:25.906:     PHY:    0
** INFO: 14:29:25.906:     MODE: LE_FLOWCTL
** INFO: 14:29:25.906:     Hci Connection Info:
** INFO: 14:29:25.906:        type:   128 LE
** INFO: 14:29:25.906:        out:    1 true
** INFO: 14:29:25.906:        state:  1 CONNECTED
** INFO: 14:29:25.906:        mode:   7 MASTER AUTH ENCRYPT
** INFO: 14:29:25.906:     min_connection_interval: 16
** INFO: 14:29:25.906:     max_connection_interval: 16
** INFO: 14:29:25.910: Adding bluetooth device Niko Hearing Devices
** INFO: 14:29:25.973: Niko Hearing Devices (Right)
** INFO: 14:29:25.973:     Name:      Niko Hearing Devices
** INFO: 14:29:25.973:     Mac:       84:77:78:xx:xx:xx
** INFO: 14:29:25.973:     HiSyncId:  10871868544774045833
** INFO: 14:29:25.973:     Side:      right (binaural)
** INFO: 14:29:25.973:     Delay:     100 ms
** INFO: 14:29:25.973:     Streaming: supported
** INFO: 14:29:25.973:     Codecs:    G.722@16kHz
** INFO: 14:29:26.078: right Sending ACP status parameters updated 16
** INFO: 14:29:26.132:     Connected: true
** INFO: 14:29:26.132:     L2CAP_CONNINFO:
** INFO: 14:29:26.132:        handle: 513
** INFO: 14:29:26.132:        class:  [0, 0, 0]
** INFO: 14:29:26.132:     MTU:       SND 168 RCV 672
** INFO: 14:29:26.747:     PHY:    0
** INFO: 14:29:26.747:     MODE: LE_FLOWCTL
** INFO: 14:29:26.747:     Hci Connection Info:
** INFO: 14:29:26.747:        type:   128 LE
** INFO: 14:29:26.747:        out:    1 true
** INFO: 14:29:26.747:        state:  1 CONNECTED
** INFO: 14:29:26.747:        mode:   7 MASTER AUTH ENCRYPT
** INFO: 14:29:26.747:     min_connection_interval: 16
** INFO: 14:29:26.747:     max_connection_interval: 16
** INFO: 14:29:26.760: left  AshaStatus: 0
** INFO: 14:29:26.760: right AshaStatus: 0
** INFO: 14:29:31.412: Niko Hearing Devices (Left) ServicesResolved: false
** INFO: 14:29:31.412: Niko Hearing Devices (Left) Connected: false
** INFO: 14:29:31.412: Removing bluetooth device Niko Hearing Devices
** INFO: 14:29:31.412: Removing Niko Hearing Devices (Left)
** INFO: 14:29:33.011: Niko Hearing Devices (Right) ServicesResolved: false
** INFO: 14:29:33.011: Niko Hearing Devices (Right) Connected: false
** INFO: 14:29:33.011: Removing bluetooth device Niko Hearing Devices
** INFO: 14:29:33.011: Removing Niko Hearing Devices (Right)
^CStopping...

I believe my desktop has an AX210 card that I can test with once I get home, but I only have use for direct streaming when I'm using my laptop so would love to get it working here.

thewierdnut commented 1 month ago

@tazz4843 Have you attempted to run asha_pipewire_sink or asha_stream_test?

thewierdnut commented 1 month ago

I'm not sure what a btsnoop entails

To get a good snoop capture:

  1. "Forget" your asha devices using your bluetooth gui
  2. In a new console, run sudo btmon -w 20_Nucleus7_2024_09_24.snoop
  3. Using your bluetooth gui, pair your devices
  4. Start audio streaming, using asha_pipewire_sink or asha_stream_test
  5. After capturing the desired behavior, stop btmon

Note that some personally identifiable information, such as the mac addresses of your devices and their human-readable names will be in the snoop file, but its the type of information your devices broadcast out for the world to see anyways.

tazz4843 commented 1 month ago

I tested on my desktop and was able to successfully run the stream_test example (which failed on my laptop)

> inxi -ISEazy
System:
  Kernel: 6.10.10-arch1-1 arch: x86_64 bits: 64 compiler: gcc v: 14.2.1
    clocksource: tsc avail: hpet,acpi_pm parameters: BOOT_IMAGE=/vmlinuz-linux
    lockdown=integrity root=/dev/mapper/rootfs-root rw rootflags=subvol=@
    rootfstype=btrfs
    cryptdevice=UUID=0d8d238d-aafa-45aa-a421-35da10bc0198:cryptlvm
    root=/dev/rootfs/root resume=/dev/rootfs/swap loglevel=3
  Desktop: KDE Plasma v: 6.1.5 tk: Qt v: N/A info: frameworks v: 6.6.0
    wm: kwin_wayland vt: 1 dm: SDDM Distro: Arch Linux
Bluetooth:
  Device-1: Intel AX211 Bluetooth driver: btusb v: 0.8 type: USB rev: 2.0
    speed: 12 Mb/s lanes: 1 mode: 1.1 bus-ID: 1-14:7 chip-ID: 8087:0033
    class-ID: e001
  Report: hciconfig ID: hci0 rfk-id: 0 state: up address: <filter> bt-v: 5.3
    lmp-v: 12 sub-v: 3678 hci-v: 12 rev: 3678 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
Info:
  Memory: total: 64 GiB available: 62.57 GiB used: 19.32 GiB (30.9%)
  Processes: 545 Power: uptime: 8m states: freeze,mem suspend: deep
    avail: s2idle wakeups: 0 hibernate: disabled image: 25.01 GiB
    services: org_kde_powerdevil, power-profiles-daemon, upowerd Init: systemd
    v: 256 default: graphical tool: systemctl
  Packages: 2394 pm: pacman pkgs: 2299 libs: 524 tools: paru pm: flatpak
    pkgs: 95 Compilers: clang: 18.1.8 gcc: 14.2.1 alt: 13 Shell: fish v: 3.7.1
    default: Bash v: 5.2.32 running-in: konsole inxi: 3.3.36

However it is of awful quality and sounds like static in one ear before switching ears and then repeating the cycle. Physical distance to the antennae on the back of my desktop changes nothing it seems.

> ./asha_stream_test --left jfk.g722 --right jfk.g722
(process:11719): GLib-GIO-DEBUG: 09:32:49.613: Using cross-namespace EXTERNAL authentication (this will deadlock if server is GDBus < 2.73.3)
** INFO: 09:32:49.619: Adding bluetooth device Niko Hearing Devices
** INFO: 09:32:49.628: Adding /org/bluez/hci0/dev_84_77_78_xx_xx_xx
** (process:11719): DEBUG: 09:32:49.629: Connection Ready Callback Set
** INFO: 09:32:49.640: Adding bluetooth device Niko Hearing Devices
** INFO: 09:32:49.647: Adding /org/bluez/hci0/dev_84_77_78_xx_xx_xx
** (process:11719): DEBUG: 09:32:49.647: Connection Ready Callback Set
** (process:11719): DEBUG: 09:32:49.716: Properties read callback
** (process:11719): DEBUG: 09:32:49.717: Properties read callback
** (process:11719): DEBUG: 09:32:49.773: Read PSM Callback
** (process:11719): DEBUG: 09:32:49.773: Creating Connection
** (process:11719): DEBUG: 09:32:49.803: Read PSM Callback
** (process:11719): DEBUG: 09:32:49.803: Creating Connection
** (process:11719): DEBUG: 09:32:49.859: Connection Callback
** (process:11719): DEBUG: 09:32:49.860: Connection Succeeded
** INFO: 09:32:49.860: right Sending ACP status parameters updated 16
** (process:11719): DEBUG: 09:32:49.861: Connection Ready
** INFO: 09:32:49.861: Niko Hearing Devices (Right)
** INFO: 09:32:49.861:     Name:      Niko Hearing Devices
** INFO: 09:32:49.861:     Mac:       84:77:78:xx:xx:xx
** INFO: 09:32:49.861:     HiSyncId:  10871868544774045833
** INFO: 09:32:49.861:     Side:      right (binaural)
** INFO: 09:32:49.861:     Delay:     100 ms
** INFO: 09:32:49.861:     Streaming: supported
** INFO: 09:32:49.861:     Codecs:    G.722@16kHz
    PHY:    0
** INFO: 09:32:51.066: Adding right device to Stream Test

(process:11719): GLib-GIO-CRITICAL **: 09:32:51.066: g_dbus_proxy_new_for_bus_sync: assertion 'g_variant_is_object_path (object_path)' failed
** INFO: 09:32:51.066: right Sending ACP start other not connected
** (process:11719): DEBUG: 09:32:51.066: Connection Callback
** (process:11719): DEBUG: 09:32:51.067: Connection Succeeded
** INFO: 09:32:51.067: left  Sending ACP status parameters updated 16
** (process:11719): DEBUG: 09:32:51.067: Connection Ready
** INFO: 09:32:51.067: Niko Hearing Devices (Left)
** INFO: 09:32:51.067:     Name:      Niko Hearing Devices
** INFO: 09:32:51.067:     Mac:       84:77:78:xx:xx:xx
** INFO: 09:32:51.067:     HiSyncId:  10871868544774045833
** INFO: 09:32:51.067:     Side:      left (binaural)
** INFO: 09:32:51.067:     Delay:     100 ms
** INFO: 09:32:51.067:     Streaming: supported
** INFO: 09:32:51.067:     Codecs:    G.722@16kHz
    PHY:    0
** INFO: 09:32:52.271: Adding left device to Stream Test

(process:11719): GLib-GIO-CRITICAL **: 09:32:52.271: g_dbus_proxy_new_for_bus_sync: assertion 'g_variant_is_object_path (object_path)' failed
** INFO: 09:32:52.272: left  Sending ACP start other connected
** INFO: 09:32:52.272: right AshaStatus: 0
** INFO: 09:32:52.272: left  AshaStatus: 0
** INFO: 09:32:52.272: right AshaStatus: 0
** INFO: 09:32:52.557: left  AshaStatus: 0
Ring Occupancy: 0 High: 4 Ring Dropped: 190 Total: 190 Adapter Dropped: 417 Total: 417 Silence: 189 Total: 189
Ring Occupancy: 2 High: 4 Ring Dropped: 340 Total: 340 Adapter Dropped: 739 Total: 739 Silence: 338 Total: 338
Ring Occupancy: 2 High: 4 Ring Dropped: 501 Total: 501 Adapter Dropped: 1099 Total: 1099 Silence: 499 Total: 499
Ring Occupancy: 0 High: 4 Ring Dropped: 670 Total: 670 Adapter Dropped: 1440 Total: 1440 Silence: 669 Total: 669
Ring Occupancy: 1 High: 4 Ring Dropped: 826 Total: 826 Adapter Dropped: 1767 Total: 1767 Silence: 825 Total: 825
^CStopping...

(process:11719): GLib-GObject-CRITICAL **: 09:33:43.586: g_object_unref: assertion 'G_IS_OBJECT (object)' failed

(process:11719): GLib-GObject-CRITICAL **: 09:33:43.586: g_object_unref: assertion 'G_IS_OBJECT (object)' failed

I am willing to share the btmon files but I'd prefer to do so privately since the human readable name has the wrong name for me and I'd like to avoid making that public. If you let me know a good way to share it with you I can send it over :)

thewierdnut commented 1 month ago

asha_stream_test does not take g722 files anymore. You need to feed it raw 16 bit le mono audio files. If you have ffmpeg installed, you can run the sounds/make_raw_files.sh script to generate some raw files. It uses the provided ikea.mp3 file by default.

thewierdnut commented 1 month ago

I'm curious... how well does the mediatek bluetooth adapter work if you just attach one device instead of both?

thewierdnut commented 1 month ago

I am willing to share the btmon files but I'd prefer to do so privately since the human readable name has the wrong name for me and I'd like to avoid making that public.

Re-try it with the correct file type. If you still have issues, or you still want to post a dump with the mediatek adapter, I enabled private vulnerability reporting for the repository. On the github page, you should be able to go to the security tab, then advisories section, then click new draft security advisory, which only I should be able to see.

tazz4843 commented 1 month ago

I ran the sample again (using ikea.mp3 and the scripts), and it's still just as awful. However, while testing it out I did notice I could get a somewhat constant stream in one ear if I had one in just the right location, which was next to impossible to find.

Testing on my Framework again, one processor only still results in disconnected after a few seconds. Interestingly I had my processor off and had activity lights enabled, and noticed it flashing blue (meaning receiving streamed audio) the whole time. It almost appears there's a rate change of the blink speed of the activity LED based on the intensity of received audio, this was the minimum possible rate, while I noticed the rate changing depending on where I moved my processors around my desktop as well.

Doesn't seem like private security advisories lets me upload a file unfortunately.

thewierdnut commented 1 month ago

I ran the sample again (using ikea.mp3 and the scripts), and it's still just as awful.

Define "awful" here... Is it loud static? Or is it garbled, but recognizable audio? Is it short bursts of usable sound?

tazz4843 commented 1 month ago

It's garbled sound that's barely recognizable as something human, if I can get a consistent connection. Otherwise it's indistinguishable from static.

thewierdnut commented 1 month ago

I would like to see a snoop file then. If I can also get the command line you are running, that would be great.

You can email me the snoop file to me at gmail, which has the same username as my github account.

thewierdnut commented 1 month ago

@tazz4843 Have you tried setting CAP_NET_RAW on the asha_stream_test/asha_pipewire_sink? The N7's that are mentioned further up in this issue tend to set their own connection interval to a garbage value that doesn't work. If you set CAP_NET_RAW, it will attempt to send the correct value instead using raw packets.

thewierdnut commented 1 month ago

I managed to dig up a laptop with a mediatek chipset. First, It wouldn't connect at all until I updated my kernel from the debian default of 6.1 to a 6.10 from the backports repository. Second, it refused to connect to both hearing aids until I set CAP_NET_RAW.

I'm guessing mediatek doesn't negotiate the parameters correctly unless you explicitly negotiate them.

(edit) ... wow its highly susceptible to interference. Don't run your microwave.