========================================================================================== Bluetooth A2DP sink-latency: a two-bug chain in the HAL path (one confirmed, one inferred) ========================================================================================== A logcat symptom reported on-device — the audio HAL logging an obviously wrong, perfectly constant Bluetooth sink-latency value thousands of times during a single playback session — was traced statically to two independent bugs in the vendor Bluetooth-audio bridge. Bug 1 is confirmed directly against raw disassembly of the libraries actually present on this device; Bug 2's HIDL-boundary unit conversion is inferred from arithmetic that exactly reproduces the observed value (see *Honest limits* below) rather than read directly off an instruction. No source was available; everything below is read from the shipped binaries in ``artifacts/vendor_a`` and the Bluetooth Mainline module in ``artifacts/system_a``. The symptom =========== .. code-block:: text 09-15 18:38:50.647 1030 16195 I btaudio_offload_qti: audio_get_a2dp_sink_latency_qti: Sink Latency = 57792 PID 1030 is ``android.hardware.audio.service`` (the audio HAL process). The line repeats at the log rate of the caller (hundreds of times during one BT session) with **the same value every time**, and the value itself (57792, read as milliseconds by the caller) is physically absurd — no real A2DP path has 57.8 seconds of latency. Both the constancy and the magnitude are explained below by two separate, stackable defects. The two processes involved =========================== This device runs the classic Boox version split (:doc:`/userspace/onyx-platform`: an Android-15-vintage ``system`` over an Android-11 ``vendor``), and that split runs straight through the Bluetooth-audio path: - **Client / caller — the audio HAL process**, ``vendor``-side, still on the legacy Qualcomm **HIDL** ``vendor.qti.hardware.bluetooth_audio@2.{0,1}`` interface: - ``artifacts/vendor_a/lib64/btaudio_offload_if.so`` exports ``audio_get_a2dp_sink_latency`` / ``audio_sink_get_a2dp_latency``, which tail-call the mangled C++ symbol ``vendor::qti::btoffload::audio_get_a2dp_sink_latency_qti()`` — imported (``U`` in ``nm -D``) from: - ``artifacts/vendor_a/lib64/libbluetooth_audio_session_qti.so`` (the HIDL-@2.0 build) and its sibling ``libbluetooth_audio_session_qti_2_1.so`` (the ``V2_1`` namespace variant) — these hold the actual logic. - **Server — the Bluetooth process**, now a Mainline APEX (``com.android.btservices``), extracted from ``artifacts/system_a/system/apex/com.android.btservices.apex`` → ``apex_payload.img`` → ``app/Bluetooth*/`` : - ``lib64/libbluetooth_jni.so`` (13 MB, stripped) statically contains the whole Fluoride/GD Bluetooth stack, including the AVDTP wire parser and the ``IBluetoothAudioPort`` server side that the HAL calls into over HIDL/hwbinder. This process's own ``NEEDED`` list only mentions the *new* AIDL ``vendor.qti.hardware.bluetooth.audio-V1-ndk.so`` — the legacy-HIDL ``IBluetoothAudioPort`` server code is statically linked in, not a separate dependency, which is why it doesn't show up as a named library. Bug 1 — the "sink latency" is queried once per connection, then frozen forever ================================================================================ ``vendor::qti::btoffload::audio_get_a2dp_sink_latency_qti()`` at file offset ``0x2f6e8`` in ``libbluetooth_audio_session_qti.so`` is a 2-instruction stub (``b`` into a shared tail-code block at ``0x2f250`` — this address has no public symbol of its own because the library is stripped and the nearest preceding exported symbol, an unrelated ``std::function::swap``, is what ``nm``/``objdump`` misattribute it to; the same "nearest-symbol mis-snap" gotcha as the kernel funcmap, see :doc:`/open-questions`). Reading the real body at ``0x2f250``: .. code-block:: text 0x2f27c bl pthread_mutex_lock 0x2f280 ldrb w8, [x19, #0xa8] ; BluetoothA2dpControl* cached flag 0x2f284 strh wzr, [x19, #0xaa] ; zero the 16-bit cache slot 0x2f288 cbz w8, 0x2f2ec ; flag==0 -> skip query, keep it zero 0x2f29c add x1, x19, #0xae ... 0x2f2ac bl BluetoothA2dpControl::getSinkLatency(SessionType const&, u64*, u64*, timespec*) 0x2f2b0 ldr x8, [sp, #0x8] ; raw u64 result ... (reciprocal-multiply divide by 10, see Bug 2) 0x2f2e4 strh w9, [x19, #0xaa] ; cache the /10 result 0x2f2e8 bl __android_log_print ; "%s: Sink Latency = %d" 0x2f2ec ... pthread_mutex_unlock 0x2f2f4 ldrh w0, [x19, #0xaa] ; return the (possibly stale) cached value but the real caching bug is one level down, in ``BluetoothA2dpControl::getSinkLatency`` itself (file offset ``0x1f2fc``, same library): .. code-block:: text 0x1f344 ldrb w8, [x22, #0x20] ; object's "already cached" bool 0x1f348 cbz w8, 0x1f35c ; 0 -> go compute a fresh value 0x1f34c ldr x8, [x22] ; !=0 -> load the FROZEN raw value ... 0x1f350 mov w21, #1 0x1f354 str x8, [x20] ; ... and hand it back, unchanged 0x1f358 b 0x1f3fc ; skip every line below — no re-query ; --- the "compute a fresh value" path, taken exactly once per object --- 0x1f364 bl BluetoothAudioSessionInstance::GetSessionInstance 0x1f37c bl BluetoothAudioSession::GetPresentationPosition(u64*,u64*,timespec*) 0x1f3d8 ldr x8, [x22] ; the HIDL reply, written by the callee ; directly into this->field_0 0x1f3ec str x8, [x20] ; returned to the caller, verbatim 0x1f3f0 strb w9, [x22, #0x20] ; w9==1: sets the "cached" bool — for good ``BluetoothA2dpControl`` is (per :doc:`/userspace/onyx-platform` conventions for these Qualcomm session objects) one instance per active A2DP connection. Its first ``getSinkLatency()`` call does a real HIDL round-trip and latches the result; every subsequent call for the lifetime of that connection returns the exact same frozen 64-bit value from offset 0 of the object, no matter how the real presentation delay changes as the codec/link state evolves. This alone accounts for "the exact same number, printed hundreds of times" — independent of whatever that number's magnitude means. Bug 2 — a factor-of-10⁵ unit mismatch, silently wrapped through a 16-bit field ================================================================================ The value ``BluetoothAudioSession::GetPresentationPosition`` writes into ``BluetoothA2dpControl``'s cache (and that ``audio_get_a2dp_sink_latency_qti`` later divides by 10, per the reciprocal-multiply sequence at ``0x2f2b4``– ``0x2f2cc``: ``mov/movk`` build the magic constant ``0xCCCCCCCCCCCCCCCD``, then ``umulh`` + ``lsr #3`` — the standard compiler-generated unsigned-divide-by-10) is a **HIDL nanosecond value**, not "tenths of a millisecond". Tracing the actual origin of that number in the Bluetooth process settles the unit: - ``artifacts/btapex_payload/lib64/libbluetooth_jni.so`` contains, verbatim, the real AOSP AVDTP delay-report parser. Its own debug string says exactly what unit the *wire* value is in:: "Delay Reporting: %u (in 1/10 milliseconds) " and the parser (``avdt_msg_prs_delay_rpt``, xref'd from its ``__func__`` string at file offset ``0xa68c7``; body starts ``~0x9409d8``) confirms it in code — it reads two raw bytes from the AVDTP packet, byte-swaps them (``rev``/``lsr #16``, i.e. big-endian → host ``u16``), and stores that **unscaled** 16-bit integer straight into the parsed-message struct (``strh w8, [x19, #0x6]``) — no divide, no multiply. The wire value is a plain count of 1/10 ms units, per the AVDTP "Delay Reporting" extension. - That raw ``u16`` (still 1/10 ms units) is confirmed to survive unscaled through the next hop too: ``btif_a2dp_control_set_audio_delay(u16 delay_report)`` (xref'd via its own ``__func__`` string, body at ``0x7912c8``) does ``and w8, w0, #0xffff`` then, purely to print a human-readable debug line, ``ucvtf`` + ``fdiv s0, s0, #10.0`` (float divide-by-10 → milliseconds, for the log only) — and separately stores the **untouched raw** ``u16`` (``strh w19, [x8, #0x190]``, `w19` never reassigned from the original ``and`` result) into Bluetooth-process global state. Every layer reachable inside the Bluetooth process — wire parser, AVDTP SCB handler, ``btif`` layer — treats and forwards the value consistently as raw 1/10 ms units. No ×10⁵ (1/10 ms → ns) conversion was found in any of them. That conversion must therefore happen exactly at the HIDL boundary — inside the (statically linked, unexported, and so not directly symbol-searchable) ``IBluetoothAudioPort::getPresentationPosition()`` server implementation in ``libbluetooth_jni.so`` that marshals the reply — which could not be pinned to a specific instruction (see *Honest limits* below). But the arithmetic reproducing the observed value exactly is strong evidence on its own, even without it. Assume a perfectly ordinary 150.0 ms real sink delay: .. code-block:: text wire value (1/10 ms units): 1500 correctly relayed as ns: 1500 * 100_000 = 150_000_000 ns audio_get_a2dp_sink_latency_qti divides by 10 (as if the input were still 1/10 ms): 15_000_000 ... then truncates into a 16-bit field (strh): 15_000_000 mod 65536 = 57_792 **57792 — an exact match for the logged value**, reproduced from a normal 150 ms real latency run through the wrong divisor and truncated into a field four bytes too small. The value the HAL logs and hands to AudioFlinger as "sink latency in milliseconds" is 64-bit-nanoseconds divided by 10 instead of 1,000,000, then reduced modulo 65536 — a number with no remaining physical meaning that coincidentally falls in the plausible millisecond range. Combined effect ================ Per BT connection: the very first ``getSinkLatency()`` call captures whatever nanosecond delay HIDL reports at that instant, mis-scales it by 10⁵ and truncates it into 16 bits (Bug 2), and every later call — regardless of codec, renegotiation, or how long the session runs — replays that exact same mangled number forever (Bug 1). That combination accounts for the logged symptom: a downstream AudioFlinger consumer would be treating the reported latency as both wrong and constant, and would be sizing anything derived from it (buffer/frame counts, jitter windows) off a number that bears no relationship to the link's actual behaviour — though what AudioFlinger itself actually does with the value was not traced. Honest limits ============= - The exact instruction that converts the AVDTP 1/10 ms wire unit into the nanosecond value ``BluetoothAudioSession::GetPresentationPosition`` hands back over HIDL was **not** located. ``libbluetooth_jni.so`` is a 13 MB stripped binary with the entire GD/Fluoride stack statically linked and no exported C++ symbols for its internals; the HIDL server-side marshalling code for ``IBluetoothAudioPort`` could not be isolated by string/symbol cross-reference. The ×100,000 relayed-as-ns step above is inferred from (a) the wire unit being definitively 1/10 ms (verified in-binary), (b) the HIDL field being definitively read and divided-by-10 on the HAL side as if it were still 1/10 ms (verified in-binary), and (c) the arithmetic reproducing the observed 57792 exactly under the standard AOSP HIDL convention (``remoteDeviceAudioDelayNanos``, a real nanoseconds field) for that callback — not from having read the conversion instruction itself. - Whether ``BluetoothA2dpControl``'s cached-flag (object offset ``0x20``) is ever cleared on disconnect/reconnect (which would bound Bug 1 to "frozen per connection" rather than "frozen for the process lifetime") was not traced; the constructor/destructor and any connection-teardown callback were not located. - No live device trace was taken; this is a purely static reconstruction from the binaries shipped on this device, cross-checked against the single logcat line quoted above. Provenance ========== :Source: ``artifacts/vendor_a/lib64/btaudio_offload_if.so``, ``artifacts/vendor_a/lib64/libbluetooth_audio_session_qti.so`` (+ ``_qti_2_1.so``), extracted read-only with ``7z`` from ``artifacts/super/vendor_a.img``; and ``artifacts/system_a/system/apex/com.android.btservices.apex`` → ``apex_payload.img`` → ``lib64/libbluetooth_jni.so``, extracted the same way from ``artifacts/super/system_a.img`` (the APEX's inner ``apex_payload.img`` is itself an ext4 image, unpacked with a second ``7z`` pass). :Method: ``nm -D`` for dynamic symbols; segment-mapped AArch64 disassembly with the pixi ``llvm-objdump`` (system ``objdump`` cannot demangle/handle this cleanly) and a small capstone-based ADRP/ADD cross-referencer to resolve which functions reference which ``.rodata`` strings in a *stripped* 13 MB binary with no local symbol table. Every address and instruction sequence quoted above was read directly off these binaries; the AVDTP-unit and HIDL-nanosecond conventions cited are the device's own debug strings and the standard public HIDL ``IBluetoothAudioPort`` contract, not source code available in this dump. :Cross-refs: :doc:`hal` (the ``bluetooth@1.0-service-qti`` / ``bluetooth_audio`` HAL entry this bug lives under), :doc:`/userspace/onyx-platform` (the Android-15-system/Android-11-vendor split that puts the HIDL client and the AIDL-capable Mainline BT stack on either side of this boundary).