diff --git a/tools/chatgui/transport/audio_diagnostics.cpp b/tools/chatgui/transport/audio_diagnostics.cpp index 5ed450db..b1801914 100644 --- a/tools/chatgui/transport/audio_diagnostics.cpp +++ b/tools/chatgui/transport/audio_diagnostics.cpp @@ -35,6 +35,7 @@ struct Event { long tid; char text[192]; audio_capture_timing capture{}; + audio_playback_timing playback{}; }; struct Slot { std::atomic sequence{0}; Event event{}; }; std::array queue; @@ -51,7 +52,7 @@ uint64_t now(clockid_t clock) { /* Ограниченная MPSC-очередь: producer не ждёт, не выделяет память и не пишет лог. */ void publish(const void* device, int kind, int stage, int64_t value, int64_t detail, const char* text, - const audio_capture_timing* capture = nullptr) { + const audio_capture_timing* capture = nullptr, const audio_playback_timing* playback = nullptr) { if (!running.load(std::memory_order_relaxed)) return; const auto wall = now(CLOCK_MONOTONIC), cpu = now(CLOCK_THREAD_CPUTIME_ID); uint64_t pos = writePosition.load(std::memory_order_relaxed); @@ -64,6 +65,7 @@ void publish(const void* device, int kind, int stage, int64_t value, int64_t det e.kind = kind; e.stage = stage; e.value = value; e.detail = detail; e.tid = syscall(SYS_gettid); if (capture) e.capture = *capture; + if (playback) e.playback = *playback; e.text[0] = 0; if (text) { std::strncpy(e.text, text, sizeof(e.text) - 1); @@ -101,6 +103,8 @@ struct Device { audio_capture_timing capture{}; uint64_t captureBlocks = 0, captureFrames = 0, captureSequence = 0, captureJumps = 0, captureMissing = 0, captureEstimated = 0; int64_t captureMinDelta = 0, captureMaxDelta = 0, captureMinLatency = 0, captureMaxLatency = 0; + uint64_t playbackBlocks = 0, playbackFrames = 0, playbackMeasured = 0; + int64_t playbackMinLatency = 0, playbackMaxLatency = 0, playbackMaxConverter = 0, playbackMaxBlock = 0; }; void consume(const Event& e, std::map& devices) { @@ -146,6 +150,17 @@ void consume(const Event& e, std::map& devices) { if (c.missing) d.captureMissing += c.frames; if (!c.measured) ++d.captureEstimated; d.capture = c; + } else if (e.kind == AUDIO_DIAG_PLAYBACK_CLOCK) { + const auto& p = e.playback; + ++d.playbackBlocks; d.playbackFrames += p.frames; + if (p.rate) d.playbackMaxBlock = std::max(d.playbackMaxBlock, int64_t(p.frames) * 1000000 / p.rate); + d.playbackMaxConverter = std::max(d.playbackMaxConverter, p.converter_us); + if (p.measured) { + if (!d.playbackMeasured) d.playbackMinLatency = d.playbackMaxLatency = p.latency_us; + ++d.playbackMeasured; + d.playbackMinLatency = std::min(d.playbackMinLatency, p.latency_us); + d.playbackMaxLatency = std::max(d.playbackMaxLatency, p.latency_us); + } } else if (e.kind == AUDIO_DIAG_LABEL) { d.label = e.text; d.id = uint64_t(e.value); DEBUG_INFO(DEBUG_CATEGORY_CALL, "AudioDiag: label dev=%p role=%s id=%016llx", (void*)e.device, e.text, (unsigned long long)d.id); @@ -191,6 +206,15 @@ void report(std::map& devices, uint64_t wall, double elapsed) (unsigned long long)dropped); std::set stalledThreads; for (auto& [key, d] : devices) { + if (d.playbackBlocks) { + DEBUG_DEBUG(DEBUG_CATEGORY_CALL, "AudioDiag: playback clock dev=%p role=%s blocks=%llu frames=%llu measured=%llu " + "backend_us=%lld..%lld converter_max_us=%lld block_max_us=%lld", + (void*)key, d.label.c_str(), (unsigned long long)d.playbackBlocks, (unsigned long long)d.playbackFrames, + (unsigned long long)d.playbackMeasured, (long long)d.playbackMinLatency, (long long)d.playbackMaxLatency, + (long long)d.playbackMaxConverter, (long long)d.playbackMaxBlock); + d.playbackBlocks = d.playbackFrames = d.playbackMeasured = 0; + d.playbackMinLatency = d.playbackMaxLatency = d.playbackMaxConverter = d.playbackMaxBlock = 0; + } if (d.captureBlocks) { DEBUG_DEBUG(DEBUG_CATEGORY_CALL, "AudioDiag: capture clock dev=%p role=%s id=%016llx blocks=%llu frames=%llu " "sequence=%llu delta_us=%lld..%lld latency_us=%lld..%lld jumps=%llu missing_frames=%llu estimated_blocks=%llu", @@ -295,6 +319,9 @@ void audio_diag_log(const void* log, unsigned int level, const char* message) { void audio_diag_capture_clock(const void* device, const audio_capture_timing* timing) { publish(device, AUDIO_DIAG_CAPTURE_CLOCK, AUDIO_DIAG_READ, 0, 0, nullptr, timing); } +void audio_diag_playback_clock(const void* device, const audio_playback_timing* timing) { + publish(device, AUDIO_DIAG_PLAYBACK_CLOCK, AUDIO_DIAG_WRITE, 0, 0, nullptr, nullptr, timing); +} #else void audio_diag_start(void) {} void audio_diag_stop(void) {} @@ -302,4 +329,5 @@ void audio_diag_event(const void*, int, int, int64_t, int64_t) {} void audio_diag_label(const void*, uint64_t, const char*) {} void audio_diag_log(const void*, unsigned int, const char*) {} void audio_diag_capture_clock(const void*, const audio_capture_timing*) {} +void audio_diag_playback_clock(const void*, const audio_playback_timing*) {} #endif diff --git a/tools/chatgui/transport/audio_diagnostics.h b/tools/chatgui/transport/audio_diagnostics.h index 25d46665..2beeffbd 100644 --- a/tools/chatgui/transport/audio_diagnostics.h +++ b/tools/chatgui/transport/audio_diagnostics.h @@ -16,7 +16,7 @@ enum audio_diag_kind { AUDIO_DIAG_ENTER, AUDIO_DIAG_LEAVE, AUDIO_DIAG_OPEN, AUDIO_DIAG_CLOSE, AUDIO_DIAG_NOTIFY, AUDIO_DIAG_BACKEND_STARTED, AUDIO_DIAG_HOLE, AUDIO_DIAG_UNFILLED, AUDIO_DIAG_CAPTURE_DROP, AUDIO_DIAG_NO_PROGRESS, AUDIO_DIAG_BACKEND_UNDERRUN, AUDIO_DIAG_BACKEND_OVERFLOW, AUDIO_DIAG_ERROR, AUDIO_DIAG_LABEL, AUDIO_DIAG_LOG, - AUDIO_DIAG_CAPTURE_CLOCK + AUDIO_DIAG_CAPTURE_CLOCK, AUDIO_DIAG_PLAYBACK_CLOCK }; struct audio_capture_timing { @@ -25,6 +25,12 @@ struct audio_capture_timing { int measured, missing; }; +struct audio_playback_timing { + int64_t latency_us, converter_us; + unsigned frames, rate; + int measured; +}; + /* start/stop — управляющий поток; перед stop все producers должны быть остановлены. */ void audio_diag_start(void); void audio_diag_stop(void); @@ -32,6 +38,7 @@ void audio_diag_event(const void* device, int kind, int stage, int64_t value, in void audio_diag_label(const void* device, uint64_t id, const char* name); void audio_diag_log(const void* log, unsigned int level, const char* message); void audio_diag_capture_clock(const void* device, const struct audio_capture_timing* timing); +void audio_diag_playback_clock(const void* device, const struct audio_playback_timing* timing); #ifdef __cplusplus } diff --git a/tools/chatgui/transport/miniaudio_impl.c b/tools/chatgui/transport/miniaudio_impl.c index 59bed351..fc1a91c0 100644 --- a/tools/chatgui/transport/miniaudio_impl.c +++ b/tools/chatgui/transport/miniaudio_impl.c @@ -165,6 +165,11 @@ static void audio_timing_begin(void* opaque, unsigned int frames, int capture) { struct audio_capture_timing timing = {time, latency, (int64_t)converter_delay * 1000000 / device->sampleRate, frames, rate, audio_timing.valid, audio_timing.missing}; audio_diag_capture_clock(device, &timing); + } else { + struct audio_playback_timing timing = {latency, + (int64_t)(converter_delay + device->playback.inputCacheRemaining) * 1000000 / device->sampleRate, + frames, rate, audio_timing.valid}; + audio_diag_playback_clock(device, &timing); } audio_timing.hole_pending = 0; }