From 8a7fee1cbf3059ab6c8ded3c933653841d0ecc19 Mon Sep 17 00:00:00 2001 From: Spirit Date: Thu, 5 Mar 2026 23:39:37 +0000 Subject: [PATCH] Add latency instrumentation (t0-t5) per Pluto spec v1.0 LatencyTracker utility with CLIPPY_LATENCY log tag. Instrumentation points in VoiceLoop, TTSManager. Includes t3_path=fcm|sync and summary line at t5. --- .../java/farm/hobbs/clippyauto/VoiceLoop.kt | 11 +++- .../hobbs/clippyauto/util/LatencyTracker.kt | 59 +++++++++++++++++++ .../farm/hobbs/clippyauto/voice/TTSManager.kt | 3 + 3 files changed, 70 insertions(+), 3 deletions(-) create mode 100644 app/src/main/java/farm/hobbs/clippyauto/util/LatencyTracker.kt diff --git a/app/src/main/java/farm/hobbs/clippyauto/VoiceLoop.kt b/app/src/main/java/farm/hobbs/clippyauto/VoiceLoop.kt index b5ff219..8cbe3d4 100644 --- a/app/src/main/java/farm/hobbs/clippyauto/VoiceLoop.kt +++ b/app/src/main/java/farm/hobbs/clippyauto/VoiceLoop.kt @@ -13,6 +13,7 @@ import farm.hobbs.clippyauto.voice.VoiceState import farm.hobbs.clippyauto.voice.VoiceStateMachine import kotlinx.coroutines.* import kotlinx.coroutines.flow.collectLatest +import farm.hobbs.clippyauto.util.LatencyTracker import java.security.MessageDigest import java.time.Instant @@ -80,7 +81,7 @@ class VoiceLoop( // Subscribe to FCM fast path ClippyResponseBus.subscribe { response, _ -> - scope.launch { handleClippyResponse(response) } + scope.launch { handleClippyResponse(response, path = "fcm") } } // Start network monitoring @@ -114,6 +115,7 @@ class VoiceLoop( fun onTalkPressed() { when (stateMachine.state.value) { VoiceState.IDLE -> { + LatencyTracker.markT0(sessionId) // t0: PTT press stateMachine.transition(VoiceState.LISTENING) speechManager.startListening() onStateChange(VoiceState.LISTENING, "Listening...") @@ -139,11 +141,13 @@ class VoiceLoop( return } + LatencyTracker.markT1() // t1: STT result ready stateMachine.transition(VoiceState.PROCESSING) onStateChange(VoiceState.PROCESSING, "Thinking...") scope.launch { val sent = sendToMatrix(text) + if (sent) LatencyTracker.markT2() // t2: Matrix message sent if (!sent) { // Offline — queue the message messageQueue.enqueue(text) @@ -172,12 +176,13 @@ class VoiceLoop( /** * Handle Clippy's response — from either FCM or Matrix sync. */ - private fun handleClippyResponse(text: String) { + private fun handleClippyResponse(text: String, path: String = "sync") { // Dedup — mark this response so the other path skips it val hash = sha256(text) if (ResponseDedup.seen(hash)) return ResponseDedup.mark(hash) + LatencyTracker.markT3(path) // t3: Clippy response received stateMachine.transition(VoiceState.RECEIVING) onStateChange(VoiceState.RECEIVING, "") @@ -199,7 +204,7 @@ class VoiceLoop( .filter { it.signal == null } // Skip session signals .forEach { msg -> withContext(Dispatchers.Main) { - handleClippyResponse(msg.body) + handleClippyResponse(msg.body, path = "sync") } } } catch (e: Exception) { diff --git a/app/src/main/java/farm/hobbs/clippyauto/util/LatencyTracker.kt b/app/src/main/java/farm/hobbs/clippyauto/util/LatencyTracker.kt new file mode 100644 index 0000000..467f9b4 --- /dev/null +++ b/app/src/main/java/farm/hobbs/clippyauto/util/LatencyTracker.kt @@ -0,0 +1,59 @@ +package farm.hobbs.clippyauto.util + +import android.os.SystemClock +import android.util.Log + +/** + * Latency instrumentation for ClippyAuto voice pipeline. + * Tracks t0-t5 per Pluto's spec v1.0. + * + * Points: + * t0 = PTT button press + * t1 = STT result ready + * t2 = Matrix message sent + * t3 = Clippy response received (sync or FCM) + * t4 = TTS synthesis starts + * t5 = First audio frame played + */ +object LatencyTracker { + private const val TAG = "CLIPPY_LATENCY" + + private var t0: Long = 0L + private var sessionId: String = "" + + fun markT0(session: String) { + sessionId = session + t0 = SystemClock.elapsedRealtime() + log("t0", 0) + } + + fun markT1() = logDelta("t1") + fun markT2() = logDelta("t2") + + fun markT3(path: String = "sync") { + val delta = SystemClock.elapsedRealtime() - t0 + Log.i(TAG, "t3 session=$sessionId ts=${System.currentTimeMillis()} delta=${delta} t3_path=$path") + } + + fun markT4() = logDelta("t4") + + fun markT5() { + val delta = SystemClock.elapsedRealtime() - t0 + Log.i(TAG, "t5 session=$sessionId ts=${System.currentTimeMillis()} delta=${delta}") + logSummary(delta) + } + + private fun logDelta(point: String) { + val delta = SystemClock.elapsedRealtime() - t0 + log(point, delta) + } + + private fun log(point: String, delta: Long) { + Log.i(TAG, "$point session=$sessionId ts=${System.currentTimeMillis()} delta=${delta}") + } + + private fun logSummary(totalDelta: Long) { + val status = if (totalDelta < 5000) "PASS" else "FAIL" + Log.i(TAG, "summary session=$sessionId total=${totalDelta}ms status=$status") + } +} diff --git a/app/src/main/java/farm/hobbs/clippyauto/voice/TTSManager.kt b/app/src/main/java/farm/hobbs/clippyauto/voice/TTSManager.kt index 3a42017..2707c4f 100644 --- a/app/src/main/java/farm/hobbs/clippyauto/voice/TTSManager.kt +++ b/app/src/main/java/farm/hobbs/clippyauto/voice/TTSManager.kt @@ -6,6 +6,7 @@ import android.media.AudioFocusRequest import android.media.AudioManager import android.speech.tts.TextToSpeech import android.speech.tts.UtteranceProgressListener +import farm.hobbs.clippyauto.util.LatencyTracker import java.util.LinkedList import java.util.Locale import java.util.UUID @@ -44,6 +45,7 @@ class TTSManager( tts?.language = Locale.US tts?.setOnUtteranceProgressListener(object : UtteranceProgressListener() { override fun onStart(utteranceId: String?) { + LatencyTracker.markT5() // t5: First audio frame onSpeakingStart() } @@ -71,6 +73,7 @@ class TTSManager( */ fun speak(text: String) { if (!isReady) return + LatencyTracker.markT4() // t4: TTS synthesis starts queue.add(text) if (queue.size == 1) { audioManager.requestAudioFocus(audioFocusRequest)