From 11a68b0ae967dc18ef9767a279f4b1b20a913fd7 Mon Sep 17 00:00:00 2001 From: Shibco Date: Wed, 26 Aug 2026 03:20:35 +0200 Subject: [PATCH 1/7] pipeasio: add opt-in callback phase telemetry --- notes/MOONSHOT-CPU-PIPEASIO-TELEMETRY.md | 50 ++ patches/SERIES.sha256 | 2 + .../0013-callback-phase-telemetry.patch | 729 ++++++++++++++++++ ...0014-nonblocking-telemetry-reporting.patch | 270 +++++++ scripts/build-audit.sh | 4 +- 5 files changed, 1054 insertions(+), 1 deletion(-) create mode 100644 notes/MOONSHOT-CPU-PIPEASIO-TELEMETRY.md create mode 100644 patches/pipeasio/0013-callback-phase-telemetry.patch create mode 100644 patches/pipeasio/0014-nonblocking-telemetry-reporting.patch diff --git a/notes/MOONSHOT-CPU-PIPEASIO-TELEMETRY.md b/notes/MOONSHOT-CPU-PIPEASIO-TELEMETRY.md new file mode 100644 index 00000000..327fcd09 --- /dev/null +++ b/notes/MOONSHOT-CPU-PIPEASIO-TELEMETRY.md @@ -0,0 +1,50 @@ +# PipeASIO callback-phase telemetry + +Date: 26 August 2026 + +## Decision + +Ship callback telemetry as an off-by-default diagnostic, not as an optimisation. +It is the smallest measurement that can distinguish time spent in PipeASIO from +time spent inside Live and time lost waiting to be scheduled. + +Enable it for one controlled run: + +```sh +env PIPEASIO_TELEMETRY=on ableton-live +``` + +The driver reports one-second aggregates for three phases: work before Live's +buffer callback, the Live callback itself, and work after Live returns. Each +phase includes monotonic wall time and callback-thread CPU time at p50, p95, +p99 and maximum. A high wall/low CPU value points to scheduling or worker waits; +a high CPU value identifies execution on the callback thread. The normal audio +path performs no telemetry clock reads when the variable is off. + +## Real-time invariants + +- The callback is the only producer and never allocates, sorts, writes a file, + formats text, locks a mutex, or waits for the reporter. +- A bounded single-producer/single-consumer ring drops samples when full. +- A lifecycle worker aggregates and sorts copied integer samples off the audio + thread once per second. +- The report descriptor is opened with `O_NONBLOCK|O_APPEND|O_CLOEXEC`; a full + pipe or slow filesystem drops a report instead of blocking audio. +- Shutdown detaches the telemetry state before closing it, so the callback + cannot publish into freed storage. + +## Interpretation limits + +Telemetry adds six clock reads per measured callback. It is therefore unsuitable +for before/after CPU claims and remains disabled by default. Its purpose is +attribution: use it alongside the 30-second benchmark report, PipeWire ERR +deltas and Live's DSP meter. It cannot by itself prove that audio was crackle +free. + +## Validation gate + +The two patches apply after the current PipeASIO 0012 hotplug patch. Their unit, +ABI, no-Qt, ASan/UBSan and TSan tests must pass in the normal runtime build. A +release decision additionally needs a real PipeWire run at 32, 64, 128 and 256 +frames, comparing telemetry off against on to quantify probe effect and checking +that report backpressure produces drops rather than deadline misses. diff --git a/patches/SERIES.sha256 b/patches/SERIES.sha256 index 0ac71e57..cb4bffef 100644 --- a/patches/SERIES.sha256 +++ b/patches/SERIES.sha256 @@ -102,3 +102,5 @@ dad3840da339256af7b3a929a5c2d84052402d26298e2d5706b298aba6515675 pipeasio/0009- adf7f8446f8b4e60ab7df8bf433f50fcfd65ddf123c731027e513f4057ad2207 pipeasio/0010-gui-accept-any-buffer-size.patch bea289bb6f78f4b217813c4457c54bf2e4224fb74bb0435ac17bbb50a1db5a53 pipeasio/0011-controlpanel-dialog-off-the-host-gui-thread.patch 8542e3eb5f4e77559783b85bc741c1c21e99027e2e3989a1456909819385227e pipeasio/0012-recover-selected-routes-after-hotplug.patch +0686a7a52a5f712a3b6e73f21ccf0c3a6d219d8b32f922fb3f2a9ee3845b3c90 pipeasio/0013-callback-phase-telemetry.patch +487a0eb8797648a1439cb5e1537bab9c12602b14e37fb63d1f05ea8bd33717eb pipeasio/0014-nonblocking-telemetry-reporting.patch diff --git a/patches/pipeasio/0013-callback-phase-telemetry.patch b/patches/pipeasio/0013-callback-phase-telemetry.patch new file mode 100644 index 00000000..cdb78333 --- /dev/null +++ b/patches/pipeasio/0013-callback-phase-telemetry.patch @@ -0,0 +1,729 @@ +From 7425fdcefdc8379aef3877d7f73913a8edb228b0 Mon Sep 17 00:00:00 2001 +From: Telemetry Prototype +Date: Mon, 24 Aug 2026 01:24:35 +0200 +Subject: [PATCH] asio: add opt-in callback phase telemetry + +Live's deadline meter and Linux process CPU cannot identify where a callback +period is spent. Add an environment-only diagnostic that records both +monotonic wall time and callback-thread CPU time around the pre-host, +host-callback, and post-host phases. + +PIPEASIO_TELEMETRY=on is deliberately off by default because the clock reads +add measurement overhead. The audio callback performs no allocation, logging, +formatting, signalling, locks, or blocking synchronization: it publishes fixed +samples to a bounded lock-free SPSC ring, dropping rather than waiting when +full. The existing lifecycle worker sorts and emits p50/p95/p99/max aggregates +once per second. WoW64 rejects the option because its PipeWire and host +callbacks run on different threads. + +Verification: the normal driver build and all 12 non-integration tests pass. +The new ring/percentile/concurrency test passes ASan, UBSan, and TSan. The +WoW64 ABI test passes; a full 32-bit build was unavailable because the cross +compiler is not installed. A live probe was unavailable because this test +environment has no PipeWire daemon. + +--- + README.md | 24 +++ + include/pipeasio_telemetry.h | 106 +++++++++++++ + src/asio.c | 282 ++++++++++++++++++++++++++++++++++- + tests/asio_probe/run.sh | 3 +- + tests/asio_probe/run32.sh | 3 +- + tests/unit/CMakeLists.txt | 4 + + tests/unit/test_telemetry.c | 120 +++++++++++++++ + 7 files changed, 535 insertions(+), 7 deletions(-) + create mode 100644 include/pipeasio_telemetry.h + create mode 100644 tests/unit/test_telemetry.c + +diff --git a/README.md b/README.md +index c20c4df..471990a 100644 +--- a/README.md ++++ b/README.md +@@ -548,6 +548,30 @@ takes effect the next time the host starts the driver. + + Env: `PIPEASIO_RT_PRIORITY` (`off`/`on`). The environment overrides the file. + ++### callback telemetry (diagnostic) ++ ++`PIPEASIO_TELEMETRY=on` enables callback-phase timing for a 64-bit host. It is ++off by default and is intentionally an environment-only diagnostic, not a saved ++driver setting. Each accepted, matched-quantum cycle measures monotonic wall ++time and `CLOCK_THREAD_CPUTIME_ID` for three phases: ++ ++1. PipeASIO callback entry to the call into the ASIO host. ++2. Time inside the host's `swapBuffersWithTimeInfo` (or legacy `bufferSwitch`). ++3. Return from the host to the point where all output buffers have been queued. ++ ++The audio callback does no formatting, logging, allocation, signalling, or ++blocking synchronization. It writes completed samples into a fixed 8192-entry ++lock-free SPSC ring. A full ring drops the new sample instead of waiting. The ++existing lifecycle worker drains it once per second, sorts at most 8192 values, ++and writes p50/p95/p99/maximum aggregates plus the drop count to stderr. The ++clock reads and fixed sample writes still add measurement overhead, so leave the ++feature off outside a controlled diagnostic run. ++ ++The experimental 32-bit WoW64 path rejects this option: its PipeWire callback ++and PE host callback execute on different threads, making one set of ++`CLOCK_THREAD_CPUTIME_ID` phase deltas invalid without a larger bridge-ABI ++change. ++ + ## Performance + + A few knobs affect xrun-free, low-latency operation: +diff --git a/include/pipeasio_telemetry.h b/include/pipeasio_telemetry.h +new file mode 100644 +index 0000000..20ce9f1 +--- /dev/null ++++ b/include/pipeasio_telemetry.h +@@ -0,0 +1,106 @@ ++/* SPDX-License-Identifier: GPL-3.0-or-later */ ++#pragma once ++ ++/* ++ * Bounded single-producer/single-consumer storage for callback telemetry. ++ * ++ * The producer is PipeWire's one data-loop callback. It performs only plain ++ * stores plus lock-free C11 atomic loads/stores. The lifecycle worker is the ++ * sole consumer and owns sorting and output. A full ring drops the new sample ++ * instead of delaying the audio callback. ++ */ ++ ++#include ++#include ++#include ++#include ++ ++#define PIPEASIO_TELEMETRY_PHASES 3u ++#define PIPEASIO_TELEMETRY_CAPACITY 8192u ++ ++enum pipeasio_telemetry_phase ++{ ++ PIPEASIO_TELEMETRY_PRE_LIVE, ++ PIPEASIO_TELEMETRY_LIVE, ++ PIPEASIO_TELEMETRY_POST_LIVE ++}; ++ ++#define PIPEASIO_TELEMETRY_TIME_INFO 0x1u ++ ++typedef struct pipeasio_telemetry_sample ++{ ++ uint64_t wall_ns[PIPEASIO_TELEMETRY_PHASES]; ++ uint64_t cpu_ns[PIPEASIO_TELEMETRY_PHASES]; ++ uint32_t flags; ++} pipeasio_telemetry_sample; ++ ++typedef struct pipeasio_telemetry_ring ++{ ++ _Atomic uint64_t write_seq; ++ _Atomic uint64_t read_seq; ++ _Atomic uint64_t dropped; ++ pipeasio_telemetry_sample slots[PIPEASIO_TELEMETRY_CAPACITY]; ++} pipeasio_telemetry_ring; ++ ++static inline void ++pipeasio_telemetry_ring_init(pipeasio_telemetry_ring *ring) ++{ ++ atomic_init(&ring->write_seq, 0); ++ atomic_init(&ring->read_seq, 0); ++ atomic_init(&ring->dropped, 0); ++} ++ ++/* Audio-thread producer. Never waits and never overwrites unread data. */ ++static inline bool ++pipeasio_telemetry_ring_publish(pipeasio_telemetry_ring *ring, ++ const pipeasio_telemetry_sample *sample) ++{ ++ uint64_t write = atomic_load_explicit(&ring->write_seq, memory_order_relaxed); ++ uint64_t read = atomic_load_explicit(&ring->read_seq, memory_order_acquire); ++ if (write - read >= PIPEASIO_TELEMETRY_CAPACITY) ++ { ++ atomic_fetch_add_explicit(&ring->dropped, 1, memory_order_relaxed); ++ return false; ++ } ++ ring->slots[write % PIPEASIO_TELEMETRY_CAPACITY] = *sample; ++ atomic_store_explicit(&ring->write_seq, write + 1, memory_order_release); ++ return true; ++} ++ ++/* Worker-side snapshot. The producer cannot reuse these slots until consume. */ ++static inline size_t ++pipeasio_telemetry_ring_snapshot(const pipeasio_telemetry_ring *ring, uint64_t *first) ++{ ++ uint64_t read = atomic_load_explicit(&ring->read_seq, memory_order_relaxed); ++ uint64_t write = atomic_load_explicit(&ring->write_seq, memory_order_acquire); ++ uint64_t count = write - read; ++ if (count > PIPEASIO_TELEMETRY_CAPACITY) ++ count = PIPEASIO_TELEMETRY_CAPACITY; ++ if (first) ++ *first = read; ++ return (size_t)count; ++} ++ ++static inline const pipeasio_telemetry_sample * ++pipeasio_telemetry_ring_at(const pipeasio_telemetry_ring *ring, uint64_t sequence) ++{ ++ return &ring->slots[sequence % PIPEASIO_TELEMETRY_CAPACITY]; ++} ++ ++static inline void ++pipeasio_telemetry_ring_consume(pipeasio_telemetry_ring *ring, uint64_t first, size_t count) ++{ ++ atomic_store_explicit(&ring->read_seq, first + count, memory_order_release); ++} ++ ++/* Nearest-rank percentile index for a sorted, non-empty sample array. */ ++static inline size_t ++pipeasio_telemetry_percentile_index(size_t count, unsigned percentile) ++{ ++ if (!count) ++ return 0; ++ if (percentile > 100) ++ percentile = 100; ++ size_t rank = (count * (size_t)percentile + 99u) / 100u; ++ return rank ? rank - 1u : 0u; ++} +diff --git a/src/asio.c b/src/asio.c +index 7612767..ebc2c79 100644 +--- a/src/asio.c ++++ b/src/asio.c +@@ -71,6 +71,9 @@ + #include "pipeasio_rate_state.h" + #include "pipeasio_rt.h" + #include "pipeasio_admission_gate.h" ++#ifndef PIPEASIO_WOW64_PE ++#include "pipeasio_telemetry.h" ++#endif + #ifdef PIPEASIO_WOW64_PE + #include "pipeasio_wow64_pe.h" + #endif +@@ -273,6 +276,27 @@ typedef struct IOChannel + bool active; + } IOChannel; + ++#ifndef PIPEASIO_WOW64_PE ++typedef struct pipeasio_telemetry_state ++{ ++ pipeasio_telemetry_ring ring; ++} pipeasio_telemetry_state; ++ ++typedef struct pipeasio_telemetry_cycle ++{ ++ pipeasio_telemetry_state *state; ++ struct timespec entry_wall; ++ struct timespec entry_cpu; ++ struct timespec pre_wall; ++ struct timespec pre_cpu; ++ struct timespec post_wall; ++ struct timespec post_cpu; ++ bool valid; ++ bool live_returned; ++ uint32_t flags; ++} pipeasio_telemetry_cycle; ++#endif ++ + typedef struct IPipeASIOImpl + { + /* COM and lifetime state */ +@@ -287,9 +311,15 @@ typedef struct IPipeASIOImpl + HANDLE worker; + DWORD worker_tid; + HMODULE module_pin; +- _Atomic uint32_t gate_owner_seq; +- _Atomic uint32_t lifecycle_waiters; +- _Atomic uint32_t stop_generation; ++#ifndef PIPEASIO_WOW64_PE ++ _Atomic(pipeasio_telemetry_state *) telemetry; ++ /* Data-loop-only pointer to the stack sample currently spanning the host ++ * callback. It is never read by the reporting worker. */ ++ pipeasio_telemetry_cycle *telemetry_cycle; ++#endif ++ _Atomic uint32_t gate_owner_seq; ++ _Atomic uint32_t lifecycle_waiters; ++ _Atomic uint32_t stop_generation; + + /* The app's main window handle on windows, 0 on OS/X */ + HWND sys_ref; +@@ -697,6 +727,143 @@ gate_leave_test_barrier(void) + } + #endif + ++#ifndef PIPEASIO_WOW64_PE ++/* CLOCK_MONOTONIC measures deadline time; CLOCK_THREAD_CPUTIME_ID separates ++ * work done by this callback thread from time it spends asleep in Live. The ++ * calls are made only when PIPEASIO_TELEMETRY is enabled. */ ++static bool ++telemetry_now(struct timespec *wall, struct timespec *cpu) ++{ ++ return clock_gettime(CLOCK_MONOTONIC, wall) == 0 ++ && clock_gettime(CLOCK_THREAD_CPUTIME_ID, cpu) == 0; ++} ++ ++static uint64_t ++telemetry_delta_ns(const struct timespec *start, const struct timespec *end) ++{ ++ if (end->tv_sec < start->tv_sec ++ || (end->tv_sec == start->tv_sec && end->tv_nsec < start->tv_nsec)) ++ return 0; ++ return (uint64_t)(end->tv_sec - start->tv_sec) * 1000000000ull ++ + (uint64_t)(end->tv_nsec - start->tv_nsec); ++} ++ ++static void ++telemetry_cycle_begin(pipeasio_telemetry_state *state, pipeasio_telemetry_cycle *cycle) ++{ ++ memset(cycle, 0, sizeof(*cycle)); ++ if (!state) ++ return; ++ cycle->state = state; ++ cycle->valid = telemetry_now(&cycle->entry_wall, &cycle->entry_cpu); ++} ++ ++static void ++telemetry_cycle_before_live(pipeasio_telemetry_cycle *cycle, bool time_info) ++{ ++ if (!cycle || !cycle->valid) ++ return; ++ cycle->valid = telemetry_now(&cycle->pre_wall, &cycle->pre_cpu); ++ if (time_info) ++ cycle->flags |= PIPEASIO_TELEMETRY_TIME_INFO; ++} ++ ++static void ++telemetry_cycle_after_live(pipeasio_telemetry_cycle *cycle) ++{ ++ if (!cycle || !cycle->valid) ++ return; ++ cycle->valid = telemetry_now(&cycle->post_wall, &cycle->post_cpu); ++ cycle->live_returned = cycle->valid; ++} ++ ++/* Audio-thread finalization: fixed stack arithmetic plus one nonblocking SPSC ++ * publication. No allocation, lock, signal, formatting, or I/O is reachable. */ ++static void ++telemetry_cycle_finish(pipeasio_telemetry_cycle *cycle) ++{ ++ struct timespec output_wall; ++ struct timespec output_cpu; ++ pipeasio_telemetry_sample sample = { 0 }; ++ if (!cycle || !cycle->state || !cycle->valid || !cycle->live_returned ++ || !telemetry_now(&output_wall, &output_cpu)) ++ return; ++ sample.wall_ns[PIPEASIO_TELEMETRY_PRE_LIVE] ++ = telemetry_delta_ns(&cycle->entry_wall, &cycle->pre_wall); ++ sample.cpu_ns[PIPEASIO_TELEMETRY_PRE_LIVE] ++ = telemetry_delta_ns(&cycle->entry_cpu, &cycle->pre_cpu); ++ sample.wall_ns[PIPEASIO_TELEMETRY_LIVE] ++ = telemetry_delta_ns(&cycle->pre_wall, &cycle->post_wall); ++ sample.cpu_ns[PIPEASIO_TELEMETRY_LIVE] = telemetry_delta_ns(&cycle->pre_cpu, &cycle->post_cpu); ++ sample.wall_ns[PIPEASIO_TELEMETRY_POST_LIVE] ++ = telemetry_delta_ns(&cycle->post_wall, &output_wall); ++ sample.cpu_ns[PIPEASIO_TELEMETRY_POST_LIVE] = telemetry_delta_ns(&cycle->post_cpu, &output_cpu); ++ sample.flags = cycle->flags; ++ pipeasio_telemetry_ring_publish(&cycle->state->ring, &sample); ++} ++ ++static int ++telemetry_compare_u64(const void *left, const void *right) ++{ ++ uint64_t a = *(const uint64_t *)left; ++ uint64_t b = *(const uint64_t *)right; ++ return (a > b) - (a < b); ++} ++ ++/* Lifecycle-worker consumer. It deliberately leaves read_seq unchanged until ++ * all six aggregates are emitted, so the producer drops instead of ever ++ * overwriting data being sorted. */ ++static void ++telemetry_emit(IPipeASIOImpl *This) ++{ ++ static const char *const phase_name[PIPEASIO_TELEMETRY_PHASES] ++ = { "entry_to_live", "live_callback", "live_to_outputs" }; ++ pipeasio_telemetry_state *state = atomic_load_explicit(&This->telemetry, memory_order_acquire); ++ uint64_t first; ++ size_t count; ++ uint64_t values[PIPEASIO_TELEMETRY_CAPACITY]; ++ uint64_t dropped; ++ size_t time_info = 0; ++ if (!state) ++ return; ++ count = pipeasio_telemetry_ring_snapshot(&state->ring, &first); ++ dropped = atomic_exchange_explicit(&state->ring.dropped, 0, memory_order_relaxed); ++ if (!count) ++ { ++ if (dropped) ++ PIPEASIO_LOG("[pipeasio telemetry] ", "cycles=0 dropped=%llu\n", ++ (unsigned long long)dropped); ++ return; ++ } ++ for (size_t i = 0; i < count; ++i) ++ if (pipeasio_telemetry_ring_at(&state->ring, first + i)->flags ++ & PIPEASIO_TELEMETRY_TIME_INFO) ++ ++time_info; ++ PIPEASIO_LOG("[pipeasio telemetry] ", "cycles=%llu time_info=%llu legacy=%llu dropped=%llu\n", ++ (unsigned long long)count, (unsigned long long)time_info, ++ (unsigned long long)(count - time_info), (unsigned long long)dropped); ++ for (unsigned clock_kind = 0; clock_kind < 2; ++clock_kind) ++ for (unsigned phase = 0; phase < PIPEASIO_TELEMETRY_PHASES; ++phase) ++ { ++ for (size_t i = 0; i < count; ++i) ++ { ++ const pipeasio_telemetry_sample *sample ++ = pipeasio_telemetry_ring_at(&state->ring, first + i); ++ values[i] = clock_kind ? sample->cpu_ns[phase] : sample->wall_ns[phase]; ++ } ++ qsort(values, count, sizeof(values[0]), telemetry_compare_u64); ++ PIPEASIO_LOG("[pipeasio telemetry] ", ++ "%s_ns phase=%s p50=%llu p95=%llu p99=%llu max=%llu\n", ++ clock_kind ? "thread_cpu" : "monotonic_wall", phase_name[phase], ++ (unsigned long long)values[pipeasio_telemetry_percentile_index(count, 50)], ++ (unsigned long long)values[pipeasio_telemetry_percentile_index(count, 95)], ++ (unsigned long long)values[pipeasio_telemetry_percentile_index(count, 99)], ++ (unsigned long long)values[count - 1]); ++ } ++ pipeasio_telemetry_ring_consume(&state->ring, first, count); ++} ++#endif ++ + bool + pipeasio_host_call_begin(void *owner, pipeasio_host_call_kind kind, pipeasio_host_call_token *token) + { +@@ -804,11 +971,27 @@ pipeasio_host_call_process(pipeasio_host_call_token *token, int32_t buffer_index + This->host_time.sampleRate + = (double)atomic_load_explicit(&This->host_sample_rate, memory_order_acquire); + This->host_time.flags = 0x7; ++#ifndef PIPEASIO_WOW64_PE ++ if (This->telemetry_cycle) ++ telemetry_cycle_before_live(This->telemetry_cycle, true); ++#endif + cb->swapBuffersWithTimeInfo(&This->host_time, buffer_index, 1); ++#ifndef PIPEASIO_WOW64_PE ++ if (This->telemetry_cycle) ++ telemetry_cycle_after_live(This->telemetry_cycle); ++#endif + } + else + { ++#ifndef PIPEASIO_WOW64_PE ++ if (This->telemetry_cycle) ++ telemetry_cycle_before_live(This->telemetry_cycle, false); ++#endif + cb->swapBuffers(buffer_index, 1); ++#ifndef PIPEASIO_WOW64_PE ++ if (This->telemetry_cycle) ++ telemetry_cycle_after_live(This->telemetry_cycle); ++#endif + } + atomic_store_explicit(&This->host_num_samples, samples + add_samples, memory_order_relaxed); + } +@@ -1329,6 +1512,13 @@ destroy_driver_resources(IPipeASIOImpl *This) + This->input_channel = NULL; + This->output_channel = NULL; + } ++#ifndef PIPEASIO_WOW64_PE ++ telemetry_emit(This); ++ pipeasio_telemetry_state *telemetry ++ = atomic_exchange_explicit(&This->telemetry, NULL, memory_order_acq_rel); ++ if (telemetry) ++ HeapFree(GetProcessHeap(), 0, telemetry); ++#endif + } + + static DWORD WINAPI +@@ -1338,7 +1528,20 @@ lifecycle_worker(void *arg) + + for (;;) + { ++#ifndef PIPEASIO_WOW64_PE ++ DWORD wait_result = WaitForSingleObject( ++ This->work_event, ++ atomic_load_explicit(&This->telemetry, memory_order_acquire) ? 1000 : INFINITE); ++ if (wait_result == WAIT_TIMEOUT) ++ { ++ telemetry_emit(This); ++ continue; ++ } ++ if (wait_result != WAIT_OBJECT_0) ++ continue; ++#else + WaitForSingleObject(This->work_event, INFINITE); ++#endif + bool completed = false; + if (atomic_load_explicit(&This->host_driver_state, memory_order_acquire) == Stopping) + while (!drain_gate(This, &This->host_gate, This->host_idle, 0)) +@@ -3105,7 +3308,14 @@ OutputReady(LPPIPEASIO iface) + static inline int + process_callback(audio_nframes_t nframes, void *arg) + { +- IPipeASIOImpl *This = (IPipeASIOImpl *)arg; ++ IPipeASIOImpl *This = (IPipeASIOImpl *)arg; ++#ifndef PIPEASIO_WOW64_PE ++ pipeasio_telemetry_cycle cycle; ++ pipeasio_telemetry_state *telemetry ++ = atomic_load_explicit(&This->telemetry, memory_order_acquire); ++ if (telemetry) ++ telemetry_cycle_begin(telemetry, &cycle); ++#endif + pipeasio_host_call_token token; + bool admitted = pipeasio_host_call_begin(This, PIPEASIO_HOST_PROCESS, &token); + int half = 0; +@@ -3148,8 +3358,13 @@ process_callback(audio_nframes_t nframes, void *arg) + else + memset(destination, 0, sizeof(*destination) * nframes); + } +- ++#ifndef PIPEASIO_WOW64_PE ++ This->telemetry_cycle = telemetry && cycle.valid ? &cycle : NULL; ++#endif + pipeasio_host_call_process(&token, half, nframes, audio_get_time_nsec(This->audio_client)); ++#ifndef PIPEASIO_WOW64_PE ++ This->telemetry_cycle = NULL; ++#endif + } + + /* In fail-silent mismatch mode the backend owns the graph buffer and +@@ -3164,6 +3379,12 @@ process_callback(audio_nframes_t nframes, void *arg) + audio_port_publish_output(This->output_channel[i].port, source, nframes, admitted, + This->output_channel[i].active); + } ++#ifndef PIPEASIO_WOW64_PE ++ /* In mismatch mode the graph, not this callback, queues the silence, so ++ * there is no honest return-to-output boundary to publish. */ ++ if (admitted && !muted && telemetry) ++ telemetry_cycle_finish(&cycle); ++#endif + if (admitted) + This->host_buffer_index = half ? 0 : 1; + pipeasio_host_call_end(&token); +@@ -3352,6 +3573,54 @@ configure_driver(IPipeASIOImpl *This) + if (read_environment("PIPEASIO_CLIENT_NAME", name_environment, sizeof(name_environment))) + lstrcpynA(This->client_name, name_environment, sizeof(This->client_name)); + ++ if (read_environment("PIPEASIO_TELEMETRY", environment_variable, sizeof(environment_variable))) ++ { ++ int enabled = pipeasio_env_bool(environment_variable); ++#ifdef PIPEASIO_WOW64_PE ++ if (enabled == 1) ++ WARN("PIPEASIO_TELEMETRY is unavailable for 32-bit WoW64 hosts: " ++ "the PipeWire callback and Live callback use different threads, so " ++ "CLOCK_THREAD_CPUTIME_ID deltas would be invalid\n"); ++ else if (enabled < 0) ++ WARN("PIPEASIO_TELEMETRY \"%s\" is not a recognised boolean; keeping off\n", ++ environment_variable); ++#else ++ if (enabled == 1 && !atomic_load_explicit(&This->telemetry, memory_order_acquire)) ++ { ++ pipeasio_telemetry_state *state = HeapAlloc(GetProcessHeap(), 0, sizeof(*state)); ++ if (!state) ++ WARN("PIPEASIO_TELEMETRY requested but its bounded ring could not be allocated; " ++ "keeping telemetry off\n"); ++ else ++ { ++ pipeasio_telemetry_ring_init(&state->ring); ++ if (!atomic_is_lock_free(&This->telemetry) ++ || !atomic_is_lock_free(&state->ring.write_seq) ++ || !atomic_is_lock_free(&state->ring.read_seq) ++ || !atomic_is_lock_free(&state->ring.dropped)) ++ { ++ WARN("PIPEASIO_TELEMETRY requires lock-free pointer and 64-bit atomics; " ++ "keeping off\n"); ++ HeapFree(GetProcessHeap(), 0, state); ++ } ++ else ++ { ++ atomic_store_explicit(&This->telemetry, state, memory_order_release); ++ PIPEASIO_LOG("[pipeasio telemetry] ", ++ "enabled for 64-bit host; capacity=%u, interval_ms=1000\n", ++ PIPEASIO_TELEMETRY_CAPACITY); ++ /* The lifecycle worker may be in its non-telemetry infinite ++ * wait. Wake it once so subsequent waits use the report tick. */ ++ SetEvent(This->work_event); ++ } ++ } ++ } ++ else if (enabled < 0) ++ WARN("PIPEASIO_TELEMETRY \"%s\" is not a recognised boolean; keeping off\n", ++ environment_variable); ++#endif ++ } ++ + return; + } + +@@ -3390,6 +3659,9 @@ PipeASIOCreateInstance(REFIID riid, LPVOID *ppobj) + atomic_init(&pobj->lifecycle_waiters, 0); + atomic_init(&pobj->stop_generation, 0); + atomic_init(&pobj->gate_owner_seq, 1); ++#ifndef PIPEASIO_WOW64_PE ++ atomic_init(&pobj->telemetry, NULL); ++#endif + InitializeSRWLock(&pobj->lifecycle_lock); + pobj->host_version = 92; + pipeasio_gate_init(&pobj->method_gate, true); +diff --git a/tests/asio_probe/run.sh b/tests/asio_probe/run.sh +index 1770c17..3627e2c 100755 +--- a/tests/asio_probe/run.sh ++++ b/tests/asio_probe/run.sh +@@ -109,7 +109,8 @@ for _cfg_var in PIPEASIO_NUMBER_INPUTS PIPEASIO_NUMBER_OUTPUTS \ + PIPEASIO_OUTPUT_DEVICE PIPEASIO_INPUT_DEVICE \ + PIPEASIO_CLIENT_NAME PIPEASIO_RT_PRIORITY \ + PIPEASIO_CONNECT_TO_HARDWARE \ +- PIPEASIO_ALLOW_QUANTUM_MISMATCH PIPEASIO_REALTIME; do ++ PIPEASIO_ALLOW_QUANTUM_MISMATCH PIPEASIO_REALTIME \ ++ PIPEASIO_TELEMETRY; do + case " ${PROBE_ENV_KEEP:-} " in + *" $_cfg_var "*) ;; + *) unset "$_cfg_var" ;; +diff --git a/tests/asio_probe/run32.sh b/tests/asio_probe/run32.sh +index 8320ba0..d917fa6 100755 +--- a/tests/asio_probe/run32.sh ++++ b/tests/asio_probe/run32.sh +@@ -94,7 +94,8 @@ for _cfg_var in PIPEASIO_NUMBER_INPUTS PIPEASIO_NUMBER_OUTPUTS \ + PIPEASIO_OUTPUT_DEVICE PIPEASIO_INPUT_DEVICE \ + PIPEASIO_CLIENT_NAME PIPEASIO_RT_PRIORITY \ + PIPEASIO_CONNECT_TO_HARDWARE \ +- PIPEASIO_ALLOW_QUANTUM_MISMATCH PIPEASIO_REALTIME; do ++ PIPEASIO_ALLOW_QUANTUM_MISMATCH PIPEASIO_REALTIME \ ++ PIPEASIO_TELEMETRY; do + case " ${PROBE_ENV_KEEP:-} " in + *" $_cfg_var "*) ;; + *) unset "$_cfg_var" ;; +diff --git a/tests/unit/CMakeLists.txt b/tests/unit/CMakeLists.txt +index 07cc360..04a2bfd 100644 +--- a/tests/unit/CMakeLists.txt ++++ b/tests/unit/CMakeLists.txt +@@ -38,3 +38,7 @@ pipeasio_add_unit_test(test_handle_table test_handle_table.c + ${CMAKE_SOURCE_DIR}/src/wow64/handle_table.c) + target_link_libraries(test_handle_table PRIVATE Threads::Threads) + set_tests_properties(test_handle_table PROPERTIES TIMEOUT 10) ++ ++pipeasio_add_unit_test(test_telemetry test_telemetry.c) ++target_link_libraries(test_telemetry PRIVATE Threads::Threads) ++set_tests_properties(test_telemetry PROPERTIES TIMEOUT 10) +diff --git a/tests/unit/test_telemetry.c b/tests/unit/test_telemetry.c +new file mode 100644 +index 0000000..0d70ef0 +--- /dev/null ++++ b/tests/unit/test_telemetry.c +@@ -0,0 +1,120 @@ ++/* SPDX-License-Identifier: GPL-3.0-or-later */ ++#include "pipeasio_telemetry.h" ++#include "test_helpers.h" ++ ++#include ++#include ++ ++#define CONCURRENT_SAMPLES 100000u ++ ++typedef struct concurrent_test ++{ ++ pipeasio_telemetry_ring ring; ++ atomic_bool done; ++ uint64_t consumed; ++ bool ordered; ++} concurrent_test; ++ ++static pipeasio_telemetry_sample ++sample_with_value(uint64_t value) ++{ ++ pipeasio_telemetry_sample sample = { 0 }; ++ sample.wall_ns[0] = value; ++ return sample; ++} ++ ++static void * ++producer(void *arg) ++{ ++ concurrent_test *test = arg; ++ for (uint64_t i = 1; i <= CONCURRENT_SAMPLES; ++i) ++ { ++ pipeasio_telemetry_sample sample = sample_with_value(i); ++ pipeasio_telemetry_ring_publish(&test->ring, &sample); ++ } ++ atomic_store_explicit(&test->done, true, memory_order_release); ++ return NULL; ++} ++ ++static void * ++consumer(void *arg) ++{ ++ concurrent_test *test = arg; ++ uint64_t last = 0; ++ test->ordered = true; ++ for (;;) ++ { ++ uint64_t first; ++ size_t count = pipeasio_telemetry_ring_snapshot(&test->ring, &first); ++ for (size_t i = 0; i < count; ++i) ++ { ++ uint64_t value = pipeasio_telemetry_ring_at(&test->ring, first + i)->wall_ns[0]; ++ if (value <= last) ++ test->ordered = false; ++ last = value; ++ } ++ if (count) ++ { ++ test->consumed += count; ++ pipeasio_telemetry_ring_consume(&test->ring, first, count); ++ } ++ else if (atomic_load_explicit(&test->done, memory_order_acquire)) ++ break; ++ else ++ sched_yield(); ++ } ++ return NULL; ++} ++ ++int ++main(void) ++{ ++ TEST_GROUP("nearest-rank percentile indices") ++ { ++ EXPECT_EQ(pipeasio_telemetry_percentile_index(1, 50), 0); ++ EXPECT_EQ(pipeasio_telemetry_percentile_index(100, 50), 49); ++ EXPECT_EQ(pipeasio_telemetry_percentile_index(100, 95), 94); ++ EXPECT_EQ(pipeasio_telemetry_percentile_index(100, 99), 98); ++ EXPECT_EQ(pipeasio_telemetry_percentile_index(3, 100), 2); ++ } ++ ++ TEST_GROUP("bounded FIFO and drop accounting") ++ { ++ pipeasio_telemetry_ring ring; ++ pipeasio_telemetry_ring_init(&ring); ++ for (uint64_t i = 0; i < PIPEASIO_TELEMETRY_CAPACITY; ++i) ++ { ++ pipeasio_telemetry_sample sample = sample_with_value(i + 1); ++ EXPECT_TRUE(pipeasio_telemetry_ring_publish(&ring, &sample)); ++ } ++ pipeasio_telemetry_sample extra = sample_with_value(UINT64_MAX); ++ EXPECT_TRUE(!pipeasio_telemetry_ring_publish(&ring, &extra)); ++ EXPECT_EQ(atomic_load_explicit(&ring.dropped, memory_order_relaxed), 1); ++ uint64_t first; ++ size_t count = pipeasio_telemetry_ring_snapshot(&ring, &first); ++ EXPECT_EQ(count, PIPEASIO_TELEMETRY_CAPACITY); ++ EXPECT_EQ(pipeasio_telemetry_ring_at(&ring, first)->wall_ns[0], 1); ++ EXPECT_EQ(pipeasio_telemetry_ring_at(&ring, first + count - 1)->wall_ns[0], ++ PIPEASIO_TELEMETRY_CAPACITY); ++ pipeasio_telemetry_ring_consume(&ring, first, count); ++ EXPECT_EQ(pipeasio_telemetry_ring_snapshot(&ring, NULL), 0); ++ } ++ ++ TEST_GROUP("concurrent SPSC publication") ++ { ++ concurrent_test test = { 0 }; ++ pthread_t producer_thread; ++ pthread_t consumer_thread; ++ pipeasio_telemetry_ring_init(&test.ring); ++ atomic_init(&test.done, false); ++ EXPECT_EQ(pthread_create(&consumer_thread, NULL, consumer, &test), 0); ++ EXPECT_EQ(pthread_create(&producer_thread, NULL, producer, &test), 0); ++ EXPECT_EQ(pthread_join(producer_thread, NULL), 0); ++ EXPECT_EQ(pthread_join(consumer_thread, NULL), 0); ++ uint64_t dropped = atomic_load_explicit(&test.ring.dropped, memory_order_relaxed); ++ EXPECT_TRUE(test.ordered); ++ EXPECT_EQ(test.consumed + dropped, CONCURRENT_SAMPLES); ++ } ++ ++ return test_report(); ++} +-- +2.55.0 + diff --git a/patches/pipeasio/0014-nonblocking-telemetry-reporting.patch b/patches/pipeasio/0014-nonblocking-telemetry-reporting.patch new file mode 100644 index 00000000..89596988 --- /dev/null +++ b/patches/pipeasio/0014-nonblocking-telemetry-reporting.patch @@ -0,0 +1,270 @@ +From 0000000000000000000000000000000000000000 Mon Sep 17 00:00:00 2001 +From: Codex Audit +Date: Mon, 24 Aug 2026 02:00:00 +0200 +Subject: [PATCH] asio: keep telemetry reporting nonblocking + +Callback samples are already published without blocking, but their periodic +aggregates used PipeASIO's ordinary blocking stderr writer from the lifecycle +worker. An unread stderr pipe could eventually fill and strand that worker, +delaying Stop or Destroy during a diagnostic run. + +Open a separate /proc/self/fd/2 descriptor with O_NONBLOCK and O_APPEND when +telemetry is enabled. Drop a report on backpressure rather than blocking the +lifecycle worker; preserve append semantics for redirected regular files. If +the descriptor cannot be opened, fail the opt-in closed. Close it after the +final aggregate is emitted. A native regression test proves a reopened regular +stderr target retains its existing contents and appends the report. + +Also correct the patched PipeASIO README: all integer buffers from 32 through +8192 are supported, and non-empty PIPEASIO_REALTIME is authoritative over the +legacy priority switch even when its value is rejected. + +Verification: the normal 64-bit driver builds and all 22 configured tests pass +(12 native/ABI/GUI tests executed; 10 live PipeWire/Wine integration tests +skipped because their services are unavailable). The focused telemetry, +configuration, and WoW64 ABI tests pass after the append fix. + +--- + README.md | 23 +++++++++++------ + include/pipeasio_telemetry.h | 2 ++ + src/asio.c | 61 +++++++++++++++++++++++++++++++++----------- + tests/unit/test_telemetry.c | 37 +++++++++++++++++++++++++++ + 4 files changed, 100 insertions(+), 23 deletions(-) + +diff --git a/README.md b/README.md +index 471990a..2e6a230 100644 +--- a/README.md ++++ b/README.md +@@ -508,10 +508,11 @@ one more buffer period but keeps a device-driven quantum from stalling the graph + Env: `PIPEASIO_FOLLOW_DEVICE_CLOCK` (`on`/`off`). + + ### buffer_size +-The preferred size returned by `GetBufferSize()`. Must be a power of two within +-[32, 8192]. Out-of-range values fall back to 1024. The floor is 32 rather than 16 +-because hosts mishandle smaller ASIO buffers (Max/MSP crashes on them), and +-RS_ASIO rounds every request up to a multiple of 32 regardless. ++The preferred size returned by `GetBufferSize()`. Any whole value from 32 ++through 8192 is accepted; it does not need to be a power of two. Invalid values ++keep the current safe setting. The floor is 32 because hosts mishandle smaller ++ASIO buffers (Max/MSP crashes on them), and RS_ASIO rounds every request up to a ++multiple of 32 regardless. + Env: `PIPEASIO_PREFERRED_BUFFERSIZE`. + + A size the hardware does not support makes PipeWire reject the request or insert +@@ -546,7 +547,11 @@ Useful as a diagnostic for the scheduling-related xruns in + [#4](https://github.com/M0n7y5/pipeasio/issues/4), not as a fix for them. It + takes effect the next time the host starts the driver. + +-Env: `PIPEASIO_RT_PRIORITY` (`off`/`on`). The environment overrides the file. ++Env: `PIPEASIO_REALTIME` (strict boolean) overrides the file for one launch and ++is authoritative whenever non-empty. An invalid value warns and keeps the file ++setting rather than falling through to the legacy switch. ++`PIPEASIO_RT_PRIORITY` (`off`/`on`) remains a compatibility fallback only when ++`PIPEASIO_REALTIME` is unset. + + ### callback telemetry (diagnostic) + +@@ -563,9 +568,11 @@ The audio callback does no formatting, logging, allocation, signalling, or + blocking synchronization. It writes completed samples into a fixed 8192-entry + lock-free SPSC ring. A full ring drops the new sample instead of waiting. The + existing lifecycle worker drains it once per second, sorts at most 8192 values, +-and writes p50/p95/p99/maximum aggregates plus the drop count to stderr. The +-clock reads and fixed sample writes still add measurement overhead, so leave the +-feature off outside a controlled diagnostic run. ++and writes p50/p95/p99/maximum aggregates plus the drop count through a separate ++nonblocking stderr descriptor. A full output pipe drops reports instead of ++delaying Stop/Destroy. The clock reads and fixed sample writes still add ++measurement overhead, so leave the feature off outside a controlled diagnostic ++run. + + The experimental 32-bit WoW64 path rejects this option: its PipeWire callback + and PE host callback execute on different threads, making one set of +diff --git a/include/pipeasio_telemetry.h b/include/pipeasio_telemetry.h +index 20ce9f1..340b1f6 100644 +--- a/include/pipeasio_telemetry.h ++++ b/include/pipeasio_telemetry.h +@@ -14,9 +14,11 @@ + #include + #include + #include ++#include + + #define PIPEASIO_TELEMETRY_PHASES 3u + #define PIPEASIO_TELEMETRY_CAPACITY 8192u ++#define PIPEASIO_TELEMETRY_OUTPUT_FLAGS (O_WRONLY | O_NONBLOCK | O_CLOEXEC | O_APPEND) + + enum pipeasio_telemetry_phase + { +diff --git a/src/asio.c b/src/asio.c +index ebc2c79..6d7394b 100644 +--- a/src/asio.c ++++ b/src/asio.c +@@ -280,6 +280,7 @@ typedef struct IOChannel + typedef struct pipeasio_telemetry_state + { + pipeasio_telemetry_ring ring; ++ int output_fd; + } pipeasio_telemetry_state; + + typedef struct pipeasio_telemetry_cycle +@@ -728,6 +729,28 @@ gate_leave_test_barrier(void) + #endif + + #ifndef PIPEASIO_WOW64_PE ++/* Reports use a separately opened O_NONBLOCK descriptor. An unread stderr ++ * pipe can therefore drop diagnostic output, but it cannot strand the shared ++ * lifecycle worker and delay Stop/Destroy. */ ++static void ++telemetry_log(pipeasio_telemetry_state *state, const char *format, ...) ++{ ++ static const char prefix[] = "[pipeasio telemetry] "; ++ char buffer[1024]; ++ va_list args; ++ int length; ++ size_t used = sizeof(prefix) - 1; ++ ++ memcpy(buffer, prefix, used); ++ va_start(args, format); ++ length = vsnprintf(buffer + used, sizeof(buffer) - used, format, args); ++ va_end(args); ++ if (length <= 0) ++ return; ++ used += (size_t)length < sizeof(buffer) - used ? (size_t)length : sizeof(buffer) - used - 1; ++ (void)write(state->output_fd, buffer, used); ++} ++ + /* CLOCK_MONOTONIC measures deadline time; CLOCK_THREAD_CPUTIME_ID separates + * work done by this callback thread from time it spends asleep in Live. The + * calls are made only when PIPEASIO_TELEMETRY is enabled. */ +@@ -831,17 +854,16 @@ telemetry_emit(IPipeASIOImpl *This) + if (!count) + { + if (dropped) +- PIPEASIO_LOG("[pipeasio telemetry] ", "cycles=0 dropped=%llu\n", +- (unsigned long long)dropped); ++ telemetry_log(state, "cycles=0 dropped=%llu\n", (unsigned long long)dropped); + return; + } + for (size_t i = 0; i < count; ++i) + if (pipeasio_telemetry_ring_at(&state->ring, first + i)->flags + & PIPEASIO_TELEMETRY_TIME_INFO) + ++time_info; +- PIPEASIO_LOG("[pipeasio telemetry] ", "cycles=%llu time_info=%llu legacy=%llu dropped=%llu\n", +- (unsigned long long)count, (unsigned long long)time_info, +- (unsigned long long)(count - time_info), (unsigned long long)dropped); ++ telemetry_log(state, "cycles=%llu time_info=%llu legacy=%llu dropped=%llu\n", ++ (unsigned long long)count, (unsigned long long)time_info, ++ (unsigned long long)(count - time_info), (unsigned long long)dropped); + for (unsigned clock_kind = 0; clock_kind < 2; ++clock_kind) + for (unsigned phase = 0; phase < PIPEASIO_TELEMETRY_PHASES; ++phase) + { +@@ -852,13 +874,13 @@ telemetry_emit(IPipeASIOImpl *This) + values[i] = clock_kind ? sample->cpu_ns[phase] : sample->wall_ns[phase]; + } + qsort(values, count, sizeof(values[0]), telemetry_compare_u64); +- PIPEASIO_LOG("[pipeasio telemetry] ", +- "%s_ns phase=%s p50=%llu p95=%llu p99=%llu max=%llu\n", +- clock_kind ? "thread_cpu" : "monotonic_wall", phase_name[phase], +- (unsigned long long)values[pipeasio_telemetry_percentile_index(count, 50)], +- (unsigned long long)values[pipeasio_telemetry_percentile_index(count, 95)], +- (unsigned long long)values[pipeasio_telemetry_percentile_index(count, 99)], +- (unsigned long long)values[count - 1]); ++ telemetry_log( ++ state, "%s_ns phase=%s p50=%llu p95=%llu p99=%llu max=%llu\n", ++ clock_kind ? "thread_cpu" : "monotonic_wall", phase_name[phase], ++ (unsigned long long)values[pipeasio_telemetry_percentile_index(count, 50)], ++ (unsigned long long)values[pipeasio_telemetry_percentile_index(count, 95)], ++ (unsigned long long)values[pipeasio_telemetry_percentile_index(count, 99)], ++ (unsigned long long)values[count - 1]); + } + pipeasio_telemetry_ring_consume(&state->ring, first, count); + } +@@ -1517,7 +1539,10 @@ destroy_driver_resources(IPipeASIOImpl *This) + pipeasio_telemetry_state *telemetry + = atomic_exchange_explicit(&This->telemetry, NULL, memory_order_acq_rel); + if (telemetry) ++ { ++ close(telemetry->output_fd); + HeapFree(GetProcessHeap(), 0, telemetry); ++ } + #endif + } + +@@ -3603,12 +3628,18 @@ configure_driver(IPipeASIOImpl *This) + "keeping off\n"); + HeapFree(GetProcessHeap(), 0, state); + } ++ else if ((state->output_fd = open("/proc/self/fd/2", ++ PIPEASIO_TELEMETRY_OUTPUT_FLAGS)) < 0) ++ { ++ WARN("PIPEASIO_TELEMETRY could not open a nonblocking report descriptor; " ++ "keeping off\n"); ++ HeapFree(GetProcessHeap(), 0, state); ++ } + else + { + atomic_store_explicit(&This->telemetry, state, memory_order_release); +- PIPEASIO_LOG("[pipeasio telemetry] ", +- "enabled for 64-bit host; capacity=%u, interval_ms=1000\n", +- PIPEASIO_TELEMETRY_CAPACITY); ++ telemetry_log(state, "enabled for 64-bit host; capacity=%u, interval_ms=1000\n", ++ PIPEASIO_TELEMETRY_CAPACITY); + /* The lifecycle worker may be in its non-telemetry infinite + * wait. Wake it once so subsequent waits use the report tick. */ + SetEvent(This->work_event); +diff --git a/tests/unit/test_telemetry.c b/tests/unit/test_telemetry.c +index 0d70ef0..1cfe423 100644 +--- a/tests/unit/test_telemetry.c ++++ b/tests/unit/test_telemetry.c +@@ -4,6 +4,10 @@ + + #include + #include ++#include ++#include ++#include ++#include + + #define CONCURRENT_SAMPLES 100000u + +@@ -116,5 +120,38 @@ main(void) + EXPECT_EQ(test.consumed + dropped, CONCURRENT_SAMPLES); + } + ++ TEST_GROUP("nonblocking report descriptor appends regular files") ++ { ++ static const char original_text[] = "original-content\n"; ++ static const char report_text[] = "telemetry-report\n"; ++ char path[] = "/tmp/pipeasio-telemetry-XXXXXX"; ++ char fd_path[64]; ++ char contents[sizeof(original_text) + sizeof(report_text)] = { 0 }; ++ int original = mkstemp(path); ++ int report = -1; ++ ++ EXPECT_TRUE(original >= 0); ++ if (original >= 0) ++ { ++ EXPECT_EQ(write(original, original_text, sizeof(original_text) - 1), ++ (ssize_t)sizeof(original_text) - 1); ++ snprintf(fd_path, sizeof(fd_path), "/proc/self/fd/%d", original); ++ report = open(fd_path, PIPEASIO_TELEMETRY_OUTPUT_FLAGS); ++ EXPECT_TRUE(report >= 0); ++ if (report >= 0) ++ EXPECT_EQ(write(report, report_text, sizeof(report_text) - 1), ++ (ssize_t)sizeof(report_text) - 1); ++ EXPECT_EQ(lseek(original, 0, SEEK_SET), 0); ++ EXPECT_EQ(read(original, contents, sizeof(contents) - 1), ++ (ssize_t)(sizeof(original_text) + sizeof(report_text) - 2)); ++ EXPECT_TRUE(!strcmp(contents, "original-content\ntelemetry-report\n")); ++ } ++ if (report >= 0) ++ close(report); ++ if (original >= 0) ++ close(original); ++ unlink(path); ++ } ++ + return test_report(); + } +-- +2.55.0 diff --git a/scripts/build-audit.sh b/scripts/build-audit.sh index 14db3fa5..d44275ef 100755 --- a/scripts/build-audit.sh +++ b/scripts/build-audit.sh @@ -11,7 +11,7 @@ say() { printf '%s\n' "$*"; } fail() { printf '!! %s\n' "$*" >&2; exit 1; } readonly REQUIRED_WINE_TAIL='0106-libusb-1.0-extend-the-host-bridge-for-Push-3.patch' -readonly REQUIRED_PIPEASIO_TAIL='pipeasio/0012-recover-selected-routes-after-hotplug.patch' +readonly REQUIRED_PIPEASIO_TAIL='pipeasio/0014-nonblocking-telemetry-reporting.patch' check_required_series_tails() { @@ -397,6 +397,8 @@ pipeasio/0009|ascii|lib/wine/x86_64-unix/pipeasio.dll.so|pipeasio-honest-realtim pipeasio/0010|wide|bin/pipeasio-settings|pick a preset or type any value pipeasio/0011|ascii|lib/wine/x86_64-unix/pipeasio.dll.so|pipeasio-ableton-controlpanel pipeasio/0012|ascii|lib/wine/x86_64-unix/pipeasio.dll.so|pipeasio-reliable-hotplug +pipeasio/0013|ascii|lib/wine/x86_64-unix/pipeasio.dll.so|enabled for 64-bit host; capacity=%u, interval_ms=1000 +pipeasio/0014|ascii|lib/wine/x86_64-unix/pipeasio.dll.so|PIPEASIO_TELEMETRY could not open a nonblocking report descriptor ' # 0010's source marker (pipeasio-any-buffer-size-panel) is a comment and does # not reach the panel binary; its fingerprint is the tooltip literal above, From 4335fbfc183febce56b8a415c5453be5d106aaf2 Mon Sep 17 00:00:00 2001 From: Shibco Date: Wed, 26 Aug 2026 04:57:10 +0200 Subject: [PATCH 2/7] Normalize telemetry patch formatting --- patches/SERIES.sha256 | 4 +-- .../0013-callback-phase-telemetry.patch | 24 +++++++------- ...0014-nonblocking-telemetry-reporting.patch | 32 +++++++++---------- 3 files changed, 30 insertions(+), 30 deletions(-) diff --git a/patches/SERIES.sha256 b/patches/SERIES.sha256 index cb4bffef..1cc5cd41 100644 --- a/patches/SERIES.sha256 +++ b/patches/SERIES.sha256 @@ -102,5 +102,5 @@ dad3840da339256af7b3a929a5c2d84052402d26298e2d5706b298aba6515675 pipeasio/0009- adf7f8446f8b4e60ab7df8bf433f50fcfd65ddf123c731027e513f4057ad2207 pipeasio/0010-gui-accept-any-buffer-size.patch bea289bb6f78f4b217813c4457c54bf2e4224fb74bb0435ac17bbb50a1db5a53 pipeasio/0011-controlpanel-dialog-off-the-host-gui-thread.patch 8542e3eb5f4e77559783b85bc741c1c21e99027e2e3989a1456909819385227e pipeasio/0012-recover-selected-routes-after-hotplug.patch -0686a7a52a5f712a3b6e73f21ccf0c3a6d219d8b32f922fb3f2a9ee3845b3c90 pipeasio/0013-callback-phase-telemetry.patch -487a0eb8797648a1439cb5e1537bab9c12602b14e37fb63d1f05ea8bd33717eb pipeasio/0014-nonblocking-telemetry-reporting.patch +5684bd2181a25c392a6e55232aa1c6a6c15bb3cf7fe6f71bf8c8780ac889a29b pipeasio/0013-callback-phase-telemetry.patch +ae3bb28eecb1a062c1c0d26f6322eca59acf90b04cf8ec558c14cb6a8a2f5da8 pipeasio/0014-nonblocking-telemetry-reporting.patch diff --git a/patches/pipeasio/0013-callback-phase-telemetry.patch b/patches/pipeasio/0013-callback-phase-telemetry.patch index cdb78333..66fc4690 100644 --- a/patches/pipeasio/0013-callback-phase-telemetry.patch +++ b/patches/pipeasio/0013-callback-phase-telemetry.patch @@ -39,9 +39,9 @@ index c20c4df..471990a 100644 --- a/README.md +++ b/README.md @@ -548,6 +548,30 @@ takes effect the next time the host starts the driver. - + Env: `PIPEASIO_RT_PRIORITY` (`off`/`on`). The environment overrides the file. - + +### callback telemetry (diagnostic) + +`PIPEASIO_TELEMETRY=on` enables callback-phase timing for a 64-bit host. It is @@ -67,7 +67,7 @@ index c20c4df..471990a 100644 +change. + ## Performance - + A few knobs affect xrun-free, low-latency operation: diff --git a/include/pipeasio_telemetry.h b/include/pipeasio_telemetry.h new file mode 100644 @@ -198,7 +198,7 @@ index 7612767..ebc2c79 100644 @@ -273,6 +276,27 @@ typedef struct IOChannel bool active; } IOChannel; - + +#ifndef PIPEASIO_WOW64_PE +typedef struct pipeasio_telemetry_state +{ @@ -239,13 +239,13 @@ index 7612767..ebc2c79 100644 + _Atomic uint32_t gate_owner_seq; + _Atomic uint32_t lifecycle_waiters; + _Atomic uint32_t stop_generation; - + /* The app's main window handle on windows, 0 on OS/X */ HWND sys_ref; @@ -697,6 +727,143 @@ gate_leave_test_barrier(void) } #endif - + +#ifndef PIPEASIO_WOW64_PE +/* CLOCK_MONOTONIC measures deadline time; CLOCK_THREAD_CPUTIME_ID separates + * work done by this callback thread from time it spends asleep in Live. The @@ -426,10 +426,10 @@ index 7612767..ebc2c79 100644 + HeapFree(GetProcessHeap(), 0, telemetry); +#endif } - + static DWORD WINAPI @@ -1338,7 +1528,20 @@ lifecycle_worker(void *arg) - + for (;;) { +#ifndef PIPEASIO_WOW64_PE @@ -478,7 +478,7 @@ index 7612767..ebc2c79 100644 + This->telemetry_cycle = NULL; +#endif } - + /* In fail-silent mismatch mode the backend owns the graph buffer and @@ -3164,6 +3379,12 @@ process_callback(audio_nframes_t nframes, void *arg) audio_port_publish_output(This->output_channel[i].port, source, nframes, admitted, @@ -496,7 +496,7 @@ index 7612767..ebc2c79 100644 @@ -3352,6 +3573,54 @@ configure_driver(IPipeASIOImpl *This) if (read_environment("PIPEASIO_CLIENT_NAME", name_environment, sizeof(name_environment))) lstrcpynA(This->client_name, name_environment, sizeof(This->client_name)); - + + if (read_environment("PIPEASIO_TELEMETRY", environment_variable, sizeof(environment_variable))) + { + int enabled = pipeasio_env_bool(environment_variable); @@ -547,7 +547,7 @@ index 7612767..ebc2c79 100644 + return; } - + @@ -3390,6 +3659,9 @@ PipeASIOCreateInstance(REFIID riid, LPVOID *ppobj) atomic_init(&pobj->lifecycle_waiters, 0); atomic_init(&pobj->stop_generation, 0); @@ -724,6 +724,6 @@ index 0000000..0d70ef0 + + return test_report(); +} --- +-- 2.55.0 diff --git a/patches/pipeasio/0014-nonblocking-telemetry-reporting.patch b/patches/pipeasio/0014-nonblocking-telemetry-reporting.patch index 89596988..87ef2d13 100644 --- a/patches/pipeasio/0014-nonblocking-telemetry-reporting.patch +++ b/patches/pipeasio/0014-nonblocking-telemetry-reporting.patch @@ -37,7 +37,7 @@ index 471990a..2e6a230 100644 +++ b/README.md @@ -508,10 +508,11 @@ one more buffer period but keeps a device-driven quantum from stalling the graph Env: `PIPEASIO_FOLLOW_DEVICE_CLOCK` (`on`/`off`). - + ### buffer_size -The preferred size returned by `GetBufferSize()`. Must be a power of two within -[32, 8192]. Out-of-range values fall back to 1024. The floor is 32 rather than 16 @@ -49,21 +49,21 @@ index 471990a..2e6a230 100644 +ASIO buffers (Max/MSP crashes on them), and RS_ASIO rounds every request up to a +multiple of 32 regardless. Env: `PIPEASIO_PREFERRED_BUFFERSIZE`. - + A size the hardware does not support makes PipeWire reject the request or insert @@ -546,7 +547,11 @@ Useful as a diagnostic for the scheduling-related xruns in [#4](https://github.com/M0n7y5/pipeasio/issues/4), not as a fix for them. It takes effect the next time the host starts the driver. - + -Env: `PIPEASIO_RT_PRIORITY` (`off`/`on`). The environment overrides the file. +Env: `PIPEASIO_REALTIME` (strict boolean) overrides the file for one launch and +is authoritative whenever non-empty. An invalid value warns and keeps the file +setting rather than falling through to the legacy switch. +`PIPEASIO_RT_PRIORITY` (`off`/`on`) remains a compatibility fallback only when +`PIPEASIO_REALTIME` is unset. - + ### callback telemetry (diagnostic) - + @@ -563,9 +568,11 @@ The audio callback does no formatting, logging, allocation, signalling, or blocking synchronization. It writes completed samples into a fixed 8192-entry lock-free SPSC ring. A full ring drops the new sample instead of waiting. The @@ -76,7 +76,7 @@ index 471990a..2e6a230 100644 +delaying Stop/Destroy. The clock reads and fixed sample writes still add +measurement overhead, so leave the feature off outside a controlled diagnostic +run. - + The experimental 32-bit WoW64 path rejects this option: its PipeWire callback and PE host callback execute on different threads, making one set of diff --git a/include/pipeasio_telemetry.h b/include/pipeasio_telemetry.h @@ -88,11 +88,11 @@ index 20ce9f1..340b1f6 100644 #include #include +#include - + #define PIPEASIO_TELEMETRY_PHASES 3u #define PIPEASIO_TELEMETRY_CAPACITY 8192u +#define PIPEASIO_TELEMETRY_OUTPUT_FLAGS (O_WRONLY | O_NONBLOCK | O_CLOEXEC | O_APPEND) - + enum pipeasio_telemetry_phase { diff --git a/src/asio.c b/src/asio.c @@ -105,11 +105,11 @@ index ebc2c79..6d7394b 100644 pipeasio_telemetry_ring ring; + int output_fd; } pipeasio_telemetry_state; - + typedef struct pipeasio_telemetry_cycle @@ -728,6 +729,28 @@ gate_leave_test_barrier(void) #endif - + #ifndef PIPEASIO_WOW64_PE +/* Reports use a separately opened O_NONBLOCK descriptor. An unread stderr + * pipe can therefore drop diagnostic output, but it cannot strand the shared @@ -189,7 +189,7 @@ index ebc2c79..6d7394b 100644 + } #endif } - + @@ -3603,12 +3628,18 @@ configure_driver(IPipeASIOImpl *This) "keeping off\n"); HeapFree(GetProcessHeap(), 0, state); @@ -217,20 +217,20 @@ index 0d70ef0..1cfe423 100644 --- a/tests/unit/test_telemetry.c +++ b/tests/unit/test_telemetry.c @@ -4,6 +4,10 @@ - + #include #include +#include +#include +#include +#include - + #define CONCURRENT_SAMPLES 100000u - + @@ -116,5 +120,38 @@ main(void) EXPECT_EQ(test.consumed + dropped, CONCURRENT_SAMPLES); } - + + TEST_GROUP("nonblocking report descriptor appends regular files") + { + static const char original_text[] = "original-content\n"; @@ -266,5 +266,5 @@ index 0d70ef0..1cfe423 100644 + return test_report(); } --- +-- 2.55.0 From 9f1b83f48a4e6fac010e5a8e482523a969332d73 Mon Sep 17 00:00:00 2001 From: Shibco Date: Wed, 26 Aug 2026 04:58:46 +0200 Subject: [PATCH 3/7] Trim telemetry patch trailer --- patches/SERIES.sha256 | 2 +- patches/pipeasio/0013-callback-phase-telemetry.patch | 1 - 2 files changed, 1 insertion(+), 2 deletions(-) diff --git a/patches/SERIES.sha256 b/patches/SERIES.sha256 index 1cc5cd41..a3a149a6 100644 --- a/patches/SERIES.sha256 +++ b/patches/SERIES.sha256 @@ -102,5 +102,5 @@ dad3840da339256af7b3a929a5c2d84052402d26298e2d5706b298aba6515675 pipeasio/0009- adf7f8446f8b4e60ab7df8bf433f50fcfd65ddf123c731027e513f4057ad2207 pipeasio/0010-gui-accept-any-buffer-size.patch bea289bb6f78f4b217813c4457c54bf2e4224fb74bb0435ac17bbb50a1db5a53 pipeasio/0011-controlpanel-dialog-off-the-host-gui-thread.patch 8542e3eb5f4e77559783b85bc741c1c21e99027e2e3989a1456909819385227e pipeasio/0012-recover-selected-routes-after-hotplug.patch -5684bd2181a25c392a6e55232aa1c6a6c15bb3cf7fe6f71bf8c8780ac889a29b pipeasio/0013-callback-phase-telemetry.patch +6949c4df347668ee7d9aec65d13b04521bb13733d56ed5722a7ce71aa3de832c pipeasio/0013-callback-phase-telemetry.patch ae3bb28eecb1a062c1c0d26f6322eca59acf90b04cf8ec558c14cb6a8a2f5da8 pipeasio/0014-nonblocking-telemetry-reporting.patch diff --git a/patches/pipeasio/0013-callback-phase-telemetry.patch b/patches/pipeasio/0013-callback-phase-telemetry.patch index 66fc4690..335ddfb1 100644 --- a/patches/pipeasio/0013-callback-phase-telemetry.patch +++ b/patches/pipeasio/0013-callback-phase-telemetry.patch @@ -726,4 +726,3 @@ index 0000000..0d70ef0 +} -- 2.55.0 - From 7b022d77eaae8db7b888e20c1c8b80f41d9343fe Mon Sep 17 00:00:00 2001 From: Shibco Date: Wed, 26 Aug 2026 10:41:25 +0200 Subject: [PATCH 4/7] docs: simplify PipeASIO timing guidance --- notes/MOONSHOT-CPU-PIPEASIO-TELEMETRY.md | 91 +++++++++++++----------- 1 file changed, 51 insertions(+), 40 deletions(-) diff --git a/notes/MOONSHOT-CPU-PIPEASIO-TELEMETRY.md b/notes/MOONSHOT-CPU-PIPEASIO-TELEMETRY.md index 327fcd09..0862133e 100644 --- a/notes/MOONSHOT-CPU-PIPEASIO-TELEMETRY.md +++ b/notes/MOONSHOT-CPU-PIPEASIO-TELEMETRY.md @@ -1,50 +1,61 @@ -# PipeASIO callback-phase telemetry +# PipeASIO callback timing Date: 26 August 2026 -## Decision +## Use -Ship callback telemetry as an off-by-default diagnostic, not as an optimisation. -It is the smallest measurement that can distinguish time spent in PipeASIO from -time spent inside Live and time lost waiting to be scheduled. +Use the timing report to find where each audio callback spends time. Run normal +CPU comparisons with the default setting. -Enable it for one controlled run: +Start one controlled timing run with: ```sh env PIPEASIO_TELEMETRY=on ableton-live ``` -The driver reports one-second aggregates for three phases: work before Live's -buffer callback, the Live callback itself, and work after Live returns. Each -phase includes monotonic wall time and callback-thread CPU time at p50, p95, -p99 and maximum. A high wall/low CPU value points to scheduling or worker waits; -a high CPU value identifies execution on the callback thread. The normal audio -path performs no telemetry clock reads when the variable is off. - -## Real-time invariants - -- The callback is the only producer and never allocates, sorts, writes a file, - formats text, locks a mutex, or waits for the reporter. -- A bounded single-producer/single-consumer ring drops samples when full. -- A lifecycle worker aggregates and sorts copied integer samples off the audio - thread once per second. -- The report descriptor is opened with `O_NONBLOCK|O_APPEND|O_CLOEXEC`; a full - pipe or slow filesystem drops a report instead of blocking audio. -- Shutdown detaches the telemetry state before closing it, so the callback - cannot publish into freed storage. - -## Interpretation limits - -Telemetry adds six clock reads per measured callback. It is therefore unsuitable -for before/after CPU claims and remains disabled by default. Its purpose is -attribution: use it alongside the 30-second benchmark report, PipeWire ERR -deltas and Live's DSP meter. It cannot by itself prove that audio was crackle -free. - -## Validation gate - -The two patches apply after the current PipeASIO 0012 hotplug patch. Their unit, -ABI, no-Qt, ASan/UBSan and TSan tests must pass in the normal runtime build. A -release decision additionally needs a real PipeWire run at 32, 64, 128 and 256 -frames, comparing telemetry off against on to quantify probe effect and checking -that report backpressure produces drops rather than deadline misses. +Set `PIPEASIO_TELEMETRY=on` to start telemetry. The default path performs zero +telemetry clock reads. + +The driver reports results once per second. It measures these 3 parts: + +- work in PipeASIO before Live receives the buffer +- time inside Live's buffer callback +- PipeASIO work after Live returns the buffer + +Each part reports elapsed time and callback thread CPU time. The report includes +`p50`, `p95`, `p99`, and the largest value. + +Long elapsed time with little CPU use often means that the thread waited. High +CPU time shows work on the callback thread. + +## Audio safety rules + +The callback writes fixed numeric samples into a fixed-size queue. A full queue +discards samples and counts each discarded sample. + +A separate worker copies, sorts, and summarises the samples once per second. +The audio callback continues during that work. + +The output write returns immediately when a pipe reaches capacity. The driver +discards that report. Slow storage can delay the separate worker while the +callback continues. + +During shutdown, the driver removes the shared timing state before it closes +or frees that state. + +## Measurement limits + +Each measured callback reads a clock 6 times. These reads change the measured +work. Use default mode for before and after CPU results. + +Use timing reports with the 30-second benchmark, PipeWire error counts, and +Live's CPU value. Add a listening result when you assess audible crackle. + +## Release checks + +The 2 patches apply after PipeASIO patch 0012. Run the unit, ABI, `no-Qt`, +ASan, UBSan, and TSan tests with the normal runtime build. + +Run PipeWire tests at 32, 64, 128, and 256 frames. Compare default and enabled +timing runs to measure the added work. Use a slow report destination to check +discarded reports and audio deadlines. From 2c9723245cdbda799457538cf4d370a8758f2709 Mon Sep 17 00:00:00 2001 From: Shibco Date: Wed, 26 Aug 2026 10:46:47 +0200 Subject: [PATCH 5/7] docs: simplify telemetry build checks --- notes/MOONSHOT-CPU-PIPEASIO-TELEMETRY.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/notes/MOONSHOT-CPU-PIPEASIO-TELEMETRY.md b/notes/MOONSHOT-CPU-PIPEASIO-TELEMETRY.md index 0862133e..9f38459c 100644 --- a/notes/MOONSHOT-CPU-PIPEASIO-TELEMETRY.md +++ b/notes/MOONSHOT-CPU-PIPEASIO-TELEMETRY.md @@ -53,7 +53,7 @@ Live's CPU value. Add a listening result when you assess audible crackle. ## Release checks -The 2 patches apply after PipeASIO patch 0012. Run the unit, ABI, `no-Qt`, +The 2 patches apply after PipeASIO patch 0012. Run the unit, ABI, minimal driver, ASan, UBSan, and TSan tests with the normal runtime build. Run PipeWire tests at 32, 64, 128, and 256 frames. Compare default and enabled From 5c1796d9f795d2cd3102390631116409f4749f71 Mon Sep 17 00:00:00 2001 From: Shibco Date: Wed, 26 Aug 2026 11:15:27 +0200 Subject: [PATCH 6/7] docs: simplify callback telemetry guidance --- patches/SERIES.sha256 | 4 +- .../0013-callback-phase-telemetry.patch | 90 +++++++++---------- ...0014-nonblocking-telemetry-reporting.patch | 66 +++++++------- 3 files changed, 80 insertions(+), 80 deletions(-) diff --git a/patches/SERIES.sha256 b/patches/SERIES.sha256 index a3a149a6..18b98e10 100644 --- a/patches/SERIES.sha256 +++ b/patches/SERIES.sha256 @@ -102,5 +102,5 @@ dad3840da339256af7b3a929a5c2d84052402d26298e2d5706b298aba6515675 pipeasio/0009- adf7f8446f8b4e60ab7df8bf433f50fcfd65ddf123c731027e513f4057ad2207 pipeasio/0010-gui-accept-any-buffer-size.patch bea289bb6f78f4b217813c4457c54bf2e4224fb74bb0435ac17bbb50a1db5a53 pipeasio/0011-controlpanel-dialog-off-the-host-gui-thread.patch 8542e3eb5f4e77559783b85bc741c1c21e99027e2e3989a1456909819385227e pipeasio/0012-recover-selected-routes-after-hotplug.patch -6949c4df347668ee7d9aec65d13b04521bb13733d56ed5722a7ce71aa3de832c pipeasio/0013-callback-phase-telemetry.patch -ae3bb28eecb1a062c1c0d26f6322eca59acf90b04cf8ec558c14cb6a8a2f5da8 pipeasio/0014-nonblocking-telemetry-reporting.patch +67a24792e3bebd9ad6d04b448b6f6f6b979d353e53eb41c8a18dfa033d56b2dd pipeasio/0013-callback-phase-telemetry.patch +6ac4161572e986314cbec6db98aa1038244a12da52fe188f4ffcce8cea2dcb9b pipeasio/0014-nonblocking-telemetry-reporting.patch diff --git a/patches/pipeasio/0013-callback-phase-telemetry.patch b/patches/pipeasio/0013-callback-phase-telemetry.patch index 335ddfb1..82269b07 100644 --- a/patches/pipeasio/0013-callback-phase-telemetry.patch +++ b/patches/pipeasio/0013-callback-phase-telemetry.patch @@ -42,29 +42,29 @@ index c20c4df..471990a 100644 Env: `PIPEASIO_RT_PRIORITY` (`off`/`on`). The environment overrides the file. -+### callback telemetry (diagnostic) -+ -+`PIPEASIO_TELEMETRY=on` enables callback-phase timing for a 64-bit host. It is -+off by default and is intentionally an environment-only diagnostic, not a saved -+driver setting. Each accepted, matched-quantum cycle measures monotonic wall -+time and `CLOCK_THREAD_CPUTIME_ID` for three phases: -+ -+1. PipeASIO callback entry to the call into the ASIO host. -+2. Time inside the host's `swapBuffersWithTimeInfo` (or legacy `bufferSwitch`). -+3. Return from the host to the point where all output buffers have been queued. -+ -+The audio callback does no formatting, logging, allocation, signalling, or -+blocking synchronization. It writes completed samples into a fixed 8192-entry -+lock-free SPSC ring. A full ring drops the new sample instead of waiting. The -+existing lifecycle worker drains it once per second, sorts at most 8192 values, -+and writes p50/p95/p99/maximum aggregates plus the drop count to stderr. The -+clock reads and fixed sample writes still add measurement overhead, so leave the -+feature off outside a controlled diagnostic run. -+ -+The experimental 32-bit WoW64 path rejects this option: its PipeWire callback -+and PE host callback execute on different threads, making one set of -+`CLOCK_THREAD_CPUTIME_ID` phase deltas invalid without a larger bridge-ABI -+change. ++### Callback timing diagnostic ++ ++`PIPEASIO_TELEMETRY=on` records callback timing for a 64-bit host. The ++environment controls the setting for one launch. Each accepted audio cycle ++with matching buffer sizes records wall time and callback CPU time in 3 ++phases: ++ ++1. `entry_to_live`: time from callback entry to Live's audio call. ++2. `live_callback`: time that Live uses for its audio callback. ++3. `live_to_outputs`: time from Live's return until PipeASIO queues all output. ++ ++The audio callback stores samples in a fixed area with 8192 entries. ++A full area drops the next sample, and audio continues. The lifecycle worker ++reports once per second. It sorts at most 8192 samples. It writes the 50th, ++95th and 99th percentiles as p50, p95 and p99. It writes the largest value as ++maximum, plus the dropped sample count, to stderr. Clock reads and fixed sample ++writes add CPU work. Use telemetry during controlled measurement ++runs. ++ ++PipeASIO supports this report for 64-bit hosts. For a 32-bit WoW64 host, ++PipeASIO keeps telemetry off. PipeWire and Live callbacks use different ++threads there. A single CPU phase report would combine different thread ++clocks. + ## Performance @@ -79,12 +79,12 @@ index 0000000..20ce9f1 +#pragma once + +/* -+ * Bounded single-producer/single-consumer storage for callback telemetry. ++ * Full storage drops the next sample so audio continues. + * -+ * The producer is PipeWire's one data-loop callback. It performs only plain -+ * stores plus lock-free C11 atomic loads/stores. The lifecycle worker is the -+ * sole consumer and owns sorting and output. A full ring drops the new sample -+ * instead of delaying the audio callback. ++ * The PipeWire callback adds samples to fixed storage. ++ * The lifecycle worker reads samples, sorts them and writes the report. ++ * Each worker updates its own position and keeps one-way ownership. ++ * The storage has 8192 entries. + */ + +#include @@ -127,7 +127,7 @@ index 0000000..20ce9f1 + atomic_init(&ring->dropped, 0); +} + -+/* Audio-thread producer. Never waits and never overwrites unread data. */ ++/* The audio thread adds a sample or counts one drop when storage is full. */ +static inline bool +pipeasio_telemetry_ring_publish(pipeasio_telemetry_ring *ring, + const pipeasio_telemetry_sample *sample) @@ -144,7 +144,7 @@ index 0000000..20ce9f1 + return true; +} + -+/* Worker-side snapshot. The producer cannot reuse these slots until consume. */ ++/* The report worker owns each listed sample until it marks the sample read. */ +static inline size_t +pipeasio_telemetry_ring_snapshot(const pipeasio_telemetry_ring *ring, uint64_t *first) +{ @@ -170,7 +170,7 @@ index 0000000..20ce9f1 + atomic_store_explicit(&ring->read_seq, first + count, memory_order_release); +} + -+/* Nearest-rank percentile index for a sorted, non-empty sample array. */ ++/* A sorted sample set with at least one value uses the nearest-rank position. */ +static inline size_t +pipeasio_telemetry_percentile_index(size_t count, unsigned percentile) +{ @@ -232,8 +232,8 @@ index 7612767..ebc2c79 100644 - _Atomic uint32_t stop_generation; +#ifndef PIPEASIO_WOW64_PE + _Atomic(pipeasio_telemetry_state *) telemetry; -+ /* Data-loop-only pointer to the stack sample currently spanning the host -+ * callback. It is never read by the reporting worker. */ ++ /* The PipeWire callback sets this pointer while Live processes one block. ++ * The report worker reads completed samples from fixed storage. */ + pipeasio_telemetry_cycle *telemetry_cycle; +#endif + _Atomic uint32_t gate_owner_seq; @@ -247,9 +247,9 @@ index 7612767..ebc2c79 100644 #endif +#ifndef PIPEASIO_WOW64_PE -+/* CLOCK_MONOTONIC measures deadline time; CLOCK_THREAD_CPUTIME_ID separates -+ * work done by this callback thread from time it spends asleep in Live. The -+ * calls are made only when PIPEASIO_TELEMETRY is enabled. */ ++/* Monotonic time records the full deadline. Thread CPU time records work on ++ * the callback thread. Wall time also includes sleep in Live. These clock ++ * reads occur while PIPEASIO_TELEMETRY is on. */ +static bool +telemetry_now(struct timespec *wall, struct timespec *cpu) +{ @@ -296,8 +296,8 @@ index 7612767..ebc2c79 100644 + cycle->live_returned = cycle->valid; +} + -+/* Audio-thread finalization: fixed stack arithmetic plus one nonblocking SPSC -+ * publication. No allocation, lock, signal, formatting, or I/O is reachable. */ ++/* The audio thread completes each sample with fixed calculations and one ++ * write to the report storage. */ +static void +telemetry_cycle_finish(pipeasio_telemetry_cycle *cycle) +{ @@ -329,9 +329,9 @@ index 7612767..ebc2c79 100644 + return (a > b) - (a < b); +} + -+/* Lifecycle-worker consumer. It deliberately leaves read_seq unchanged until -+ * all six aggregates are emitted, so the producer drops instead of ever -+ * overwriting data being sorted. */ ++/* The report worker owns the current batch while it sorts values. ++ * It writes six summaries. New samples use free storage or increase the ++ * dropped count. */ +static void +telemetry_emit(IPipeASIOImpl *This) +{ @@ -485,8 +485,8 @@ index 7612767..ebc2c79 100644 This->output_channel[i].active); } +#ifndef PIPEASIO_WOW64_PE -+ /* In mismatch mode the graph, not this callback, queues the silence, so -+ * there is no honest return-to-output boundary to publish. */ ++ /* During a buffer mismatch, the graph owns and queues the silent block. ++ * Telemetry resumes output timing when the callback owns the output. */ + if (admitted && !muted && telemetry) + telemetry_cycle_finish(&cycle); +#endif @@ -533,8 +533,8 @@ index 7612767..ebc2c79 100644 + PIPEASIO_LOG("[pipeasio telemetry] ", + "enabled for 64-bit host; capacity=%u, interval_ms=1000\n", + PIPEASIO_TELEMETRY_CAPACITY); -+ /* The lifecycle worker may be in its non-telemetry infinite -+ * wait. Wake it once so subsequent waits use the report tick. */ ++ /* Wake the lifecycle worker when telemetry starts. ++ * Its next wait uses the one-second report interval. */ + SetEvent(This->work_event); + } + } diff --git a/patches/pipeasio/0014-nonblocking-telemetry-reporting.patch b/patches/pipeasio/0014-nonblocking-telemetry-reporting.patch index 87ef2d13..b988d8cd 100644 --- a/patches/pipeasio/0014-nonblocking-telemetry-reporting.patch +++ b/patches/pipeasio/0014-nonblocking-telemetry-reporting.patch @@ -43,11 +43,11 @@ index 471990a..2e6a230 100644 -[32, 8192]. Out-of-range values fall back to 1024. The floor is 32 rather than 16 -because hosts mishandle smaller ASIO buffers (Max/MSP crashes on them), and -RS_ASIO rounds every request up to a multiple of 32 regardless. -+The preferred size returned by `GetBufferSize()`. Any whole value from 32 -+through 8192 is accepted; it does not need to be a power of two. Invalid values -+keep the current safe setting. The floor is 32 because hosts mishandle smaller -+ASIO buffers (Max/MSP crashes on them), and RS_ASIO rounds every request up to a -+multiple of 32 regardless. ++PipeASIO reports `buffer_size` as the preferred buffer size. It accepts every ++whole value from 32 through 8192. Values outside this range use the current ++safe setting. The minimum is 32. Max/MSP crashes with smaller ASIO ++buffers. RS_ASIO rounds every request to a multiple of 32. ++ Env: `PIPEASIO_PREFERRED_BUFFERSIZE`. A size the hardware does not support makes PipeWire reject the request or insert @@ -56,29 +56,29 @@ index 471990a..2e6a230 100644 takes effect the next time the host starts the driver. -Env: `PIPEASIO_RT_PRIORITY` (`off`/`on`). The environment overrides the file. -+Env: `PIPEASIO_REALTIME` (strict boolean) overrides the file for one launch and -+is authoritative whenever non-empty. An invalid value warns and keeps the file -+setting rather than falling through to the legacy switch. -+`PIPEASIO_RT_PRIORITY` (`off`/`on`) remains a compatibility fallback only when -+`PIPEASIO_REALTIME` is unset. ++Env: `PIPEASIO_REALTIME` accepts a strict boolean for one launch. Any ++supplied value takes priority. A value outside the boolean forms prints a ++warning and uses the file setting. ++`PIPEASIO_RT_PRIORITY` (`off`/`on`) provides compatibility for launches ++that omit `PIPEASIO_REALTIME`. - ### callback telemetry (diagnostic) + ### Callback timing diagnostic -@@ -563,9 +568,11 @@ The audio callback does no formatting, logging, allocation, signalling, or - blocking synchronization. It writes completed samples into a fixed 8192-entry - lock-free SPSC ring. A full ring drops the new sample instead of waiting. The - existing lifecycle worker drains it once per second, sorts at most 8192 values, --and writes p50/p95/p99/maximum aggregates plus the drop count to stderr. The --clock reads and fixed sample writes still add measurement overhead, so leave the --feature off outside a controlled diagnostic run. -+and writes p50/p95/p99/maximum aggregates plus the drop count through a separate -+nonblocking stderr descriptor. A full output pipe drops reports instead of -+delaying Stop/Destroy. The clock reads and fixed sample writes still add -+measurement overhead, so leave the feature off outside a controlled diagnostic -+run. +@@ -564,9 +569,11 @@ The audio callback stores samples in a fixed area with 8192 entries. + A full area drops the next sample, and audio continues. The lifecycle worker + reports once per second. It sorts at most 8192 samples. It writes the 50th, + 95th and 99th percentiles as p50, p95 and p99. It writes the largest value as +-maximum, plus the dropped sample count, to stderr. Clock reads and fixed sample +-writes add CPU work. Use telemetry during controlled measurement +-runs. ++maximum, plus the dropped sample count, through a separate stderr output. ++When that output is full, PipeASIO drops the current report. ++Stop and Destroy continue. Clock reads and fixed sample ++writes add CPU work. Use telemetry during ++controlled measurement runs. - The experimental 32-bit WoW64 path rejects this option: its PipeWire callback - and PE host callback execute on different threads, making one set of + PipeASIO supports this report for 64-bit hosts. For a 32-bit WoW64 host, + PipeASIO keeps telemetry off. PipeWire and Live callbacks use different diff --git a/include/pipeasio_telemetry.h b/include/pipeasio_telemetry.h index 20ce9f1..340b1f6 100644 --- a/include/pipeasio_telemetry.h @@ -111,9 +111,9 @@ index ebc2c79..6d7394b 100644 #endif #ifndef PIPEASIO_WOW64_PE -+/* Reports use a separately opened O_NONBLOCK descriptor. An unread stderr -+ * pipe can therefore drop diagnostic output, but it cannot strand the shared -+ * lifecycle worker and delay Stop/Destroy. */ ++/* A separate stderr output keeps the lifecycle worker responsive. ++ * A full output drops the current report. Stop and Destroy ++ * continue. */ +static void +telemetry_log(pipeasio_telemetry_state *state, const char *format, ...) +{ @@ -133,9 +133,9 @@ index ebc2c79..6d7394b 100644 + (void)write(state->output_fd, buffer, used); +} + - /* CLOCK_MONOTONIC measures deadline time; CLOCK_THREAD_CPUTIME_ID separates - * work done by this callback thread from time it spends asleep in Live. The - * calls are made only when PIPEASIO_TELEMETRY is enabled. */ + /* Monotonic time records the full deadline. Thread CPU time records work on + * the callback thread. Wall time also includes sleep in Live. These clock + * reads occur while PIPEASIO_TELEMETRY is on. */ @@ -831,17 +854,16 @@ telemetry_emit(IPipeASIOImpl *This) if (!count) { @@ -209,8 +209,8 @@ index ebc2c79..6d7394b 100644 - PIPEASIO_TELEMETRY_CAPACITY); + telemetry_log(state, "enabled for 64-bit host; capacity=%u, interval_ms=1000\n", + PIPEASIO_TELEMETRY_CAPACITY); - /* The lifecycle worker may be in its non-telemetry infinite - * wait. Wake it once so subsequent waits use the report tick. */ + /* Wake the lifecycle worker when telemetry starts. + * Its next wait uses the one-second report interval. */ SetEvent(This->work_event); diff --git a/tests/unit/test_telemetry.c b/tests/unit/test_telemetry.c index 0d70ef0..1cfe423 100644 From 374b069817c3dd0ceea21c88b68db2313a8840d0 Mon Sep 17 00:00:00 2001 From: Shibco Date: Wed, 26 Aug 2026 22:43:26 +0200 Subject: [PATCH 7/7] pipeasio: address telemetry review --- notes/MOONSHOT-CPU-PIPEASIO-TELEMETRY.md | 13 +- patches/SERIES.sha256 | 4 +- ...ch => 0014-callback-phase-telemetry.patch} | 36 ++-- ...015-nonblocking-telemetry-reporting.patch} | 188 +++++++++++------- scripts/build-audit.sh | 6 +- 5 files changed, 154 insertions(+), 93 deletions(-) rename patches/pipeasio/{0013-callback-phase-telemetry.patch => 0014-callback-phase-telemetry.patch} (99%) rename patches/pipeasio/{0014-nonblocking-telemetry-reporting.patch => 0015-nonblocking-telemetry-reporting.patch} (63%) diff --git a/notes/MOONSHOT-CPU-PIPEASIO-TELEMETRY.md b/notes/MOONSHOT-CPU-PIPEASIO-TELEMETRY.md index 9f38459c..e0fe3bf7 100644 --- a/notes/MOONSHOT-CPU-PIPEASIO-TELEMETRY.md +++ b/notes/MOONSHOT-CPU-PIPEASIO-TELEMETRY.md @@ -25,6 +25,10 @@ The driver reports results once per second. It measures these 3 parts: Each part reports elapsed time and callback thread CPU time. The report includes `p50`, `p95`, `p99`, and the largest value. +The cycle record separates Live's time-info and legacy callback paths. Its +`muted` value counts admitted callbacks silenced after a buffer-size mismatch, +while `dropped` counts timing samples discarded when the fixed queue is full. + Long elapsed time with little CPU use often means that the thread waited. High CPU time shows work on the callback thread. @@ -45,15 +49,18 @@ or frees that state. ## Measurement limits -Each measured callback reads a clock 6 times. These reads change the measured -work. Use default mode for before and after CPU results. +Each measured callback performs 8 clock reads: 4 `CLOCK_MONOTONIC` reads and 4 +`CLOCK_THREAD_CPUTIME_ID` reads. On the review host, the thread CPU clock cost +137.5 ns per read and the monotonic clock cost 12.1 ns per read. This adds about +598 ns to each measured callback. Use default mode for before and after CPU +results. Use timing reports with the 30-second benchmark, PipeWire error counts, and Live's CPU value. Add a listening result when you assess audible crackle. ## Release checks -The 2 patches apply after PipeASIO patch 0012. Run the unit, ABI, minimal driver, +The 2 patches apply after PipeASIO patch 0013. Run the unit, ABI, minimal driver, ASan, UBSan, and TSan tests with the normal runtime build. Run PipeWire tests at 32, 64, 128, and 256 frames. Compare default and enabled diff --git a/patches/SERIES.sha256 b/patches/SERIES.sha256 index 18b98e10..e6f95e67 100644 --- a/patches/SERIES.sha256 +++ b/patches/SERIES.sha256 @@ -102,5 +102,5 @@ dad3840da339256af7b3a929a5c2d84052402d26298e2d5706b298aba6515675 pipeasio/0009- adf7f8446f8b4e60ab7df8bf433f50fcfd65ddf123c731027e513f4057ad2207 pipeasio/0010-gui-accept-any-buffer-size.patch bea289bb6f78f4b217813c4457c54bf2e4224fb74bb0435ac17bbb50a1db5a53 pipeasio/0011-controlpanel-dialog-off-the-host-gui-thread.patch 8542e3eb5f4e77559783b85bc741c1c21e99027e2e3989a1456909819385227e pipeasio/0012-recover-selected-routes-after-hotplug.patch -67a24792e3bebd9ad6d04b448b6f6f6b979d353e53eb41c8a18dfa033d56b2dd pipeasio/0013-callback-phase-telemetry.patch -6ac4161572e986314cbec6db98aa1038244a12da52fe188f4ffcce8cea2dcb9b pipeasio/0014-nonblocking-telemetry-reporting.patch +9979b4946153336604951fec83acfe3c264af0d5fe65d5c3da71757e31ab366d pipeasio/0014-callback-phase-telemetry.patch +54833329e71f9b15b15fe0c854464126a686ce64404b1c8bc070a8525a42065d pipeasio/0015-nonblocking-telemetry-reporting.patch diff --git a/patches/pipeasio/0013-callback-phase-telemetry.patch b/patches/pipeasio/0014-callback-phase-telemetry.patch similarity index 99% rename from patches/pipeasio/0013-callback-phase-telemetry.patch rename to patches/pipeasio/0014-callback-phase-telemetry.patch index 82269b07..be7157ce 100644 --- a/patches/pipeasio/0013-callback-phase-telemetry.patch +++ b/patches/pipeasio/0014-callback-phase-telemetry.patch @@ -1,7 +1,7 @@ -From 7425fdcefdc8379aef3877d7f73913a8edb228b0 Mon Sep 17 00:00:00 2001 +From f3744749bb6dbe4ac3c07ad52fe5671ed5076cab Mon Sep 17 00:00:00 2001 From: Telemetry Prototype Date: Mon, 24 Aug 2026 01:24:35 +0200 -Subject: [PATCH] asio: add opt-in callback phase telemetry +Subject: [PATCH 1/2] asio: add opt-in callback phase telemetry Live's deadline meter and Linux process CPU cannot identify where a callback period is spent. Add an environment-only diagnostic that records both @@ -21,7 +21,6 @@ The new ring/percentile/concurrency test passes ASan, UBSan, and TSan. The WoW64 ABI test passes; a full 32-bit build was unavailable because the cross compiler is not installed. A live probe was unavailable because this test environment has no PipeWire daemon. - --- README.md | 24 +++ include/pipeasio_telemetry.h | 106 +++++++++++++ @@ -35,13 +34,13 @@ environment has no PipeWire daemon. create mode 100644 tests/unit/test_telemetry.c diff --git a/README.md b/README.md -index c20c4df..471990a 100644 +index c20c4df..1373bf3 100644 --- a/README.md +++ b/README.md @@ -548,6 +548,30 @@ takes effect the next time the host starts the driver. - + Env: `PIPEASIO_RT_PRIORITY` (`off`/`on`). The environment overrides the file. - + +### Callback timing diagnostic + +`PIPEASIO_TELEMETRY=on` records callback timing for a 64-bit host. The @@ -67,11 +66,11 @@ index c20c4df..471990a 100644 +clocks. + ## Performance - + A few knobs affect xrun-free, low-latency operation: diff --git a/include/pipeasio_telemetry.h b/include/pipeasio_telemetry.h new file mode 100644 -index 0000000..20ce9f1 +index 0000000..7525921 --- /dev/null +++ b/include/pipeasio_telemetry.h @@ -0,0 +1,106 @@ @@ -182,7 +181,7 @@ index 0000000..20ce9f1 + return rank ? rank - 1u : 0u; +} diff --git a/src/asio.c b/src/asio.c -index 7612767..ebc2c79 100644 +index 7612767..fc38757 100644 --- a/src/asio.c +++ b/src/asio.c @@ -71,6 +71,9 @@ @@ -198,7 +197,7 @@ index 7612767..ebc2c79 100644 @@ -273,6 +276,27 @@ typedef struct IOChannel bool active; } IOChannel; - + +#ifndef PIPEASIO_WOW64_PE +typedef struct pipeasio_telemetry_state +{ @@ -239,13 +238,13 @@ index 7612767..ebc2c79 100644 + _Atomic uint32_t gate_owner_seq; + _Atomic uint32_t lifecycle_waiters; + _Atomic uint32_t stop_generation; - + /* The app's main window handle on windows, 0 on OS/X */ HWND sys_ref; @@ -697,6 +727,143 @@ gate_leave_test_barrier(void) } #endif - + +#ifndef PIPEASIO_WOW64_PE +/* Monotonic time records the full deadline. Thread CPU time records work on + * the callback thread. Wall time also includes sleep in Live. These clock @@ -426,10 +425,10 @@ index 7612767..ebc2c79 100644 + HeapFree(GetProcessHeap(), 0, telemetry); +#endif } - + static DWORD WINAPI @@ -1338,7 +1528,20 @@ lifecycle_worker(void *arg) - + for (;;) { +#ifndef PIPEASIO_WOW64_PE @@ -478,7 +477,7 @@ index 7612767..ebc2c79 100644 + This->telemetry_cycle = NULL; +#endif } - + /* In fail-silent mismatch mode the backend owns the graph buffer and @@ -3164,6 +3379,12 @@ process_callback(audio_nframes_t nframes, void *arg) audio_port_publish_output(This->output_channel[i].port, source, nframes, admitted, @@ -496,7 +495,7 @@ index 7612767..ebc2c79 100644 @@ -3352,6 +3573,54 @@ configure_driver(IPipeASIOImpl *This) if (read_environment("PIPEASIO_CLIENT_NAME", name_environment, sizeof(name_environment))) lstrcpynA(This->client_name, name_environment, sizeof(This->client_name)); - + + if (read_environment("PIPEASIO_TELEMETRY", environment_variable, sizeof(environment_variable))) + { + int enabled = pipeasio_env_bool(environment_variable); @@ -547,7 +546,7 @@ index 7612767..ebc2c79 100644 + return; } - + @@ -3390,6 +3659,9 @@ PipeASIOCreateInstance(REFIID riid, LPVOID *ppobj) atomic_init(&pobj->lifecycle_waiters, 0); atomic_init(&pobj->stop_generation, 0); @@ -724,5 +723,6 @@ index 0000000..0d70ef0 + + return test_report(); +} --- +-- 2.55.0 + diff --git a/patches/pipeasio/0014-nonblocking-telemetry-reporting.patch b/patches/pipeasio/0015-nonblocking-telemetry-reporting.patch similarity index 63% rename from patches/pipeasio/0014-nonblocking-telemetry-reporting.patch rename to patches/pipeasio/0015-nonblocking-telemetry-reporting.patch index b988d8cd..c9defa08 100644 --- a/patches/pipeasio/0014-nonblocking-telemetry-reporting.patch +++ b/patches/pipeasio/0015-nonblocking-telemetry-reporting.patch @@ -1,43 +1,32 @@ -From 0000000000000000000000000000000000000000 Mon Sep 17 00:00:00 2001 +From 9227f00c4137b74adfc3d98fa14b0a38bef7c528 Mon Sep 17 00:00:00 2001 From: Codex Audit Date: Mon, 24 Aug 2026 02:00:00 +0200 -Subject: [PATCH] asio: keep telemetry reporting nonblocking +Subject: [PATCH 2/2] asio: keep telemetry reporting nonblocking +MIME-Version: 1.0 +Content-Type: text/plain; charset=UTF-8 +Content-Transfer-Encoding: 8bit -Callback samples are already published without blocking, but their periodic -aggregates used PipeASIO's ordinary blocking stderr writer from the lifecycle -worker. An unread stderr pipe could eventually fill and strand that worker, -delaying Stop or Destroy during a diagnostic run. +Callback samples use a bounded ring, while periodic reports previously inherited blocking stderr behaviour. -Open a separate /proc/self/fd/2 descriptor with O_NONBLOCK and O_APPEND when -telemetry is enabled. Drop a report on backpressure rather than blocking the -lifecycle worker; preserve append semantics for redirected regular files. If -the descriptor cannot be opened, fail the opt-in closed. Close it after the -final aggregate is emitted. A native regression test proves a reopened regular -stderr target retains its existing contents and appends the report. +Open a separate nonblocking report descriptor for pipes and terminals. Share stderr’s file offset for regular files so ordinary logs preserve report order. Drop pipe reports on backpressure. -Also correct the patched PipeASIO README: all integer buffers from 32 through -8192 are supported, and non-empty PIPEASIO_REALTIME is authoritative over the -legacy priority switch even when its value is rejected. - -Verification: the normal 64-bit driver builds and all 22 configured tests pass -(12 native/ABI/GUI tests executed; 10 live PipeWire/Wine integration tests -skipped because their services are unavailable). The focused telemetry, -configuration, and WoW64 ABI tests pass after the append fix. +Count fail-silent buffer-mismatch cycles as muted work in each telemetry interval. Also correct the documented buffer size and real-time environment option. +Verification: the normal 64-bit driver build and all 11 non-integration tests pass. The standalone telemetry test passes 8,217 checks. --- - README.md | 23 +++++++++++------ - include/pipeasio_telemetry.h | 2 ++ - src/asio.c | 61 +++++++++++++++++++++++++++++++++----------- - tests/unit/test_telemetry.c | 37 +++++++++++++++++++++++++++ - 4 files changed, 100 insertions(+), 23 deletions(-) + README.md | 24 ++++++--- + include/pipeasio_telemetry.h | 2 + + src/asio.c | 98 ++++++++++++++++++++++++++++-------- + tests/unit/test_telemetry.c | 41 +++++++++++++++ + 4 files changed, 136 insertions(+), 29 deletions(-) diff --git a/README.md b/README.md -index 471990a..2e6a230 100644 +index 1373bf3..baf97ee 100644 --- a/README.md +++ b/README.md @@ -508,10 +508,11 @@ one more buffer period but keeps a device-driven quantum from stalling the graph Env: `PIPEASIO_FOLLOW_DEVICE_CLOCK` (`on`/`off`). - + ### buffer_size -The preferred size returned by `GetBufferSize()`. Must be a power of two within -[32, 8192]. Out-of-range values fall back to 1024. The floor is 32 rather than 16 @@ -49,22 +38,22 @@ index 471990a..2e6a230 100644 +buffers. RS_ASIO rounds every request to a multiple of 32. + Env: `PIPEASIO_PREFERRED_BUFFERSIZE`. - + A size the hardware does not support makes PipeWire reject the request or insert @@ -546,7 +547,11 @@ Useful as a diagnostic for the scheduling-related xruns in [#4](https://github.com/M0n7y5/pipeasio/issues/4), not as a fix for them. It takes effect the next time the host starts the driver. - + -Env: `PIPEASIO_RT_PRIORITY` (`off`/`on`). The environment overrides the file. +Env: `PIPEASIO_REALTIME` accepts a strict boolean for one launch. Any +supplied value takes priority. A value outside the boolean forms prints a +warning and uses the file setting. +`PIPEASIO_RT_PRIORITY` (`off`/`on`) provides compatibility for launches +that omit `PIPEASIO_REALTIME`. - + ### Callback timing diagnostic - -@@ -564,9 +569,11 @@ The audio callback stores samples in a fixed area with 8192 entries. + +@@ -563,9 +568,12 @@ The audio callback stores samples in a fixed area with 8192 entries. A full area drops the next sample, and audio continues. The lifecycle worker reports once per second. It sorts at most 8192 samples. It writes the 50th, 95th and 99th percentiles as p50, p95 and p99. It writes the largest value as @@ -72,15 +61,16 @@ index 471990a..2e6a230 100644 -writes add CPU work. Use telemetry during controlled measurement -runs. +maximum, plus the dropped sample count, through a separate stderr output. ++The cycle record also counts silent mismatch cycles as `muted`. +When that output is full, PipeASIO drops the current report. +Stop and Destroy continue. Clock reads and fixed sample +writes add CPU work. Use telemetry during +controlled measurement runs. - + PipeASIO supports this report for 64-bit hosts. For a 32-bit WoW64 host, PipeASIO keeps telemetry off. PipeWire and Live callbacks use different diff --git a/include/pipeasio_telemetry.h b/include/pipeasio_telemetry.h -index 20ce9f1..340b1f6 100644 +index 7525921..69dadaf 100644 --- a/include/pipeasio_telemetry.h +++ b/include/pipeasio_telemetry.h @@ -14,9 +14,11 @@ @@ -88,29 +78,43 @@ index 20ce9f1..340b1f6 100644 #include #include +#include - + #define PIPEASIO_TELEMETRY_PHASES 3u #define PIPEASIO_TELEMETRY_CAPACITY 8192u +#define PIPEASIO_TELEMETRY_OUTPUT_FLAGS (O_WRONLY | O_NONBLOCK | O_CLOEXEC | O_APPEND) - + enum pipeasio_telemetry_phase { diff --git a/src/asio.c b/src/asio.c -index ebc2c79..6d7394b 100644 +index fc38757..9aafb96 100644 --- a/src/asio.c +++ b/src/asio.c -@@ -280,6 +280,7 @@ typedef struct IOChannel +@@ -280,6 +280,8 @@ typedef struct IOChannel typedef struct pipeasio_telemetry_state { pipeasio_telemetry_ring ring; ++ _Atomic uint64_t muted_cycles; + int output_fd; } pipeasio_telemetry_state; - + typedef struct pipeasio_telemetry_cycle -@@ -728,6 +729,28 @@ gate_leave_test_barrier(void) +@@ -728,6 +730,41 @@ gate_leave_test_barrier(void) #endif - + #ifndef PIPEASIO_WOW64_PE ++/* A regular file shares stderr's offset so ordinary logs and telemetry remain ++ * ordered. Pipes and terminals use a separate nonblocking description. */ ++static int ++telemetry_open_report_fd(void) ++{ ++ struct stat st; ++ if (fstat(STDERR_FILENO, &st) != 0) ++ return -1; ++ if (S_ISFIFO(st.st_mode) || S_ISCHR(st.st_mode)) ++ return open("/proc/self/fd/2", PIPEASIO_TELEMETRY_OUTPUT_FLAGS); ++ return dup(STDERR_FILENO); ++} ++ +/* A separate stderr output keeps the lifecycle worker responsive. + * A full output drops the current report. Stop and Destroy + * continue. */ @@ -136,13 +140,27 @@ index ebc2c79..6d7394b 100644 /* Monotonic time records the full deadline. Thread CPU time records work on * the callback thread. Wall time also includes sleep in Live. These clock * reads occur while PIPEASIO_TELEMETRY is on. */ -@@ -831,17 +854,16 @@ telemetry_emit(IPipeASIOImpl *This) +@@ -823,25 +860,31 @@ telemetry_emit(IPipeASIOImpl *This) + size_t count; + uint64_t values[PIPEASIO_TELEMETRY_CAPACITY]; + uint64_t dropped; ++ uint64_t muted; + size_t time_info = 0; + if (!state) + return; + count = pipeasio_telemetry_ring_snapshot(&state->ring, &first); + dropped = atomic_exchange_explicit(&state->ring.dropped, 0, memory_order_relaxed); ++ muted = atomic_exchange_explicit(&state->muted_cycles, 0, memory_order_relaxed); if (!count) { - if (dropped) +- if (dropped) - PIPEASIO_LOG("[pipeasio telemetry] ", "cycles=0 dropped=%llu\n", - (unsigned long long)dropped); -+ telemetry_log(state, "cycles=0 dropped=%llu\n", (unsigned long long)dropped); ++ if (dropped || muted) ++ telemetry_log(state, ++ "cycles=%llu time_info=0 legacy=0 muted=%llu dropped=%llu\n", ++ (unsigned long long)muted, (unsigned long long)muted, ++ (unsigned long long)dropped); return; } for (size_t i = 0; i < count; ++i) @@ -152,13 +170,15 @@ index ebc2c79..6d7394b 100644 - PIPEASIO_LOG("[pipeasio telemetry] ", "cycles=%llu time_info=%llu legacy=%llu dropped=%llu\n", - (unsigned long long)count, (unsigned long long)time_info, - (unsigned long long)(count - time_info), (unsigned long long)dropped); -+ telemetry_log(state, "cycles=%llu time_info=%llu legacy=%llu dropped=%llu\n", -+ (unsigned long long)count, (unsigned long long)time_info, -+ (unsigned long long)(count - time_info), (unsigned long long)dropped); ++ telemetry_log(state, ++ "cycles=%llu time_info=%llu legacy=%llu muted=%llu dropped=%llu\n", ++ (unsigned long long)(count + muted), (unsigned long long)time_info, ++ (unsigned long long)(count - time_info), (unsigned long long)muted, ++ (unsigned long long)dropped); for (unsigned clock_kind = 0; clock_kind < 2; ++clock_kind) for (unsigned phase = 0; phase < PIPEASIO_TELEMETRY_PHASES; ++phase) { -@@ -852,13 +874,13 @@ telemetry_emit(IPipeASIOImpl *This) +@@ -852,13 +895,13 @@ telemetry_emit(IPipeASIOImpl *This) values[i] = clock_kind ? sample->cpu_ns[phase] : sample->wall_ns[phase]; } qsort(values, count, sizeof(values[0]), telemetry_compare_u64); @@ -179,7 +199,7 @@ index ebc2c79..6d7394b 100644 } pipeasio_telemetry_ring_consume(&state->ring, first, count); } -@@ -1517,7 +1539,10 @@ destroy_driver_resources(IPipeASIOImpl *This) +@@ -1517,7 +1560,10 @@ destroy_driver_resources(IPipeASIOImpl *This) pipeasio_telemetry_state *telemetry = atomic_exchange_explicit(&This->telemetry, NULL, memory_order_acq_rel); if (telemetry) @@ -189,13 +209,42 @@ index ebc2c79..6d7394b 100644 + } #endif } - -@@ -3603,12 +3628,18 @@ configure_driver(IPipeASIOImpl *This) + +@@ -3380,10 +3426,13 @@ process_callback(audio_nframes_t nframes, void *arg) + This->output_channel[i].active); + } + #ifndef PIPEASIO_WOW64_PE +- /* During a buffer mismatch, the graph owns and queues the silent block. +- * Telemetry resumes output timing when the callback owns the output. */ +- if (admitted && !muted && telemetry) +- telemetry_cycle_finish(&cycle); ++ if (admitted && telemetry) ++ { ++ if (muted) ++ atomic_fetch_add_explicit(&telemetry->muted_cycles, 1, memory_order_relaxed); ++ else ++ telemetry_cycle_finish(&cycle); ++ } + #endif + if (admitted) + This->host_buffer_index = half ? 0 : 1; +@@ -3594,21 +3643,28 @@ configure_driver(IPipeASIOImpl *This) + else + { + pipeasio_telemetry_ring_init(&state->ring); ++ atomic_init(&state->muted_cycles, 0); + if (!atomic_is_lock_free(&This->telemetry) + || !atomic_is_lock_free(&state->ring.write_seq) + || !atomic_is_lock_free(&state->ring.read_seq) +- || !atomic_is_lock_free(&state->ring.dropped)) ++ || !atomic_is_lock_free(&state->ring.dropped) ++ || !atomic_is_lock_free(&state->muted_cycles)) + { + WARN("PIPEASIO_TELEMETRY requires lock-free pointer and 64-bit atomics; " "keeping off\n"); HeapFree(GetProcessHeap(), 0, state); } -+ else if ((state->output_fd = open("/proc/self/fd/2", -+ PIPEASIO_TELEMETRY_OUTPUT_FLAGS)) < 0) ++ else if ((state->output_fd = telemetry_open_report_fd()) < 0) + { + WARN("PIPEASIO_TELEMETRY could not open a nonblocking report descriptor; " + "keeping off\n"); @@ -213,31 +262,32 @@ index ebc2c79..6d7394b 100644 * Its next wait uses the one-second report interval. */ SetEvent(This->work_event); diff --git a/tests/unit/test_telemetry.c b/tests/unit/test_telemetry.c -index 0d70ef0..1cfe423 100644 +index 0d70ef0..b7f4263 100644 --- a/tests/unit/test_telemetry.c +++ b/tests/unit/test_telemetry.c @@ -4,6 +4,10 @@ - + #include #include +#include +#include +#include +#include - + #define CONCURRENT_SAMPLES 100000u - -@@ -116,5 +120,38 @@ main(void) + +@@ -116,5 +120,42 @@ main(void) EXPECT_EQ(test.consumed + dropped, CONCURRENT_SAMPLES); } - -+ TEST_GROUP("nonblocking report descriptor appends regular files") + ++ TEST_GROUP("regular report descriptor shares the stderr file offset") + { + static const char original_text[] = "original-content\n"; + static const char report_text[] = "telemetry-report\n"; ++ static const char ordinary_text[] = "ordinary-log\n"; + char path[] = "/tmp/pipeasio-telemetry-XXXXXX"; -+ char fd_path[64]; -+ char contents[sizeof(original_text) + sizeof(report_text)] = { 0 }; ++ char contents[sizeof(original_text) + sizeof(report_text) ++ + sizeof(ordinary_text)] = { 0 }; + int original = mkstemp(path); + int report = -1; + @@ -246,16 +296,19 @@ index 0d70ef0..1cfe423 100644 + { + EXPECT_EQ(write(original, original_text, sizeof(original_text) - 1), + (ssize_t)sizeof(original_text) - 1); -+ snprintf(fd_path, sizeof(fd_path), "/proc/self/fd/%d", original); -+ report = open(fd_path, PIPEASIO_TELEMETRY_OUTPUT_FLAGS); ++ report = dup(original); + EXPECT_TRUE(report >= 0); + if (report >= 0) + EXPECT_EQ(write(report, report_text, sizeof(report_text) - 1), + (ssize_t)sizeof(report_text) - 1); ++ EXPECT_EQ(write(original, ordinary_text, sizeof(ordinary_text) - 1), ++ (ssize_t)sizeof(ordinary_text) - 1); + EXPECT_EQ(lseek(original, 0, SEEK_SET), 0); + EXPECT_EQ(read(original, contents, sizeof(contents) - 1), -+ (ssize_t)(sizeof(original_text) + sizeof(report_text) - 2)); -+ EXPECT_TRUE(!strcmp(contents, "original-content\ntelemetry-report\n")); ++ (ssize_t)(sizeof(original_text) + sizeof(report_text) ++ + sizeof(ordinary_text) - 3)); ++ EXPECT_TRUE(!strcmp(contents, ++ "original-content\ntelemetry-report\nordinary-log\n")); + } + if (report >= 0) + close(report); @@ -266,5 +319,6 @@ index 0d70ef0..1cfe423 100644 + return test_report(); } --- +-- 2.55.0 + diff --git a/scripts/build-audit.sh b/scripts/build-audit.sh index d44275ef..640b559e 100755 --- a/scripts/build-audit.sh +++ b/scripts/build-audit.sh @@ -11,7 +11,7 @@ say() { printf '%s\n' "$*"; } fail() { printf '!! %s\n' "$*" >&2; exit 1; } readonly REQUIRED_WINE_TAIL='0106-libusb-1.0-extend-the-host-bridge-for-Push-3.patch' -readonly REQUIRED_PIPEASIO_TAIL='pipeasio/0014-nonblocking-telemetry-reporting.patch' +readonly REQUIRED_PIPEASIO_TAIL='pipeasio/0015-nonblocking-telemetry-reporting.patch' check_required_series_tails() { @@ -397,8 +397,8 @@ pipeasio/0009|ascii|lib/wine/x86_64-unix/pipeasio.dll.so|pipeasio-honest-realtim pipeasio/0010|wide|bin/pipeasio-settings|pick a preset or type any value pipeasio/0011|ascii|lib/wine/x86_64-unix/pipeasio.dll.so|pipeasio-ableton-controlpanel pipeasio/0012|ascii|lib/wine/x86_64-unix/pipeasio.dll.so|pipeasio-reliable-hotplug -pipeasio/0013|ascii|lib/wine/x86_64-unix/pipeasio.dll.so|enabled for 64-bit host; capacity=%u, interval_ms=1000 -pipeasio/0014|ascii|lib/wine/x86_64-unix/pipeasio.dll.so|PIPEASIO_TELEMETRY could not open a nonblocking report descriptor +pipeasio/0014|ascii|lib/wine/x86_64-unix/pipeasio.dll.so|enabled for 64-bit host; capacity=%u, interval_ms=1000 +pipeasio/0015|ascii|lib/wine/x86_64-unix/pipeasio.dll.so|PIPEASIO_TELEMETRY could not open a nonblocking report descriptor ' # 0010's source marker (pipeasio-any-buffer-size-panel) is a comment and does # not reach the panel binary; its fingerprint is the tooltip literal above,