Add latency instrumentation (t0-t5) per Pluto spec v1.0
ClippyAuto CI / build (push) Has been cancelled
ClippyAuto CI / build (push) Has been cancelled
LatencyTracker utility with CLIPPY_LATENCY log tag. Instrumentation points in VoiceLoop, TTSManager. Includes t3_path=fcm|sync and summary line at t5.
This commit is contained in:
@@ -13,6 +13,7 @@ import farm.hobbs.clippyauto.voice.VoiceState
|
|||||||
import farm.hobbs.clippyauto.voice.VoiceStateMachine
|
import farm.hobbs.clippyauto.voice.VoiceStateMachine
|
||||||
import kotlinx.coroutines.*
|
import kotlinx.coroutines.*
|
||||||
import kotlinx.coroutines.flow.collectLatest
|
import kotlinx.coroutines.flow.collectLatest
|
||||||
|
import farm.hobbs.clippyauto.util.LatencyTracker
|
||||||
import java.security.MessageDigest
|
import java.security.MessageDigest
|
||||||
import java.time.Instant
|
import java.time.Instant
|
||||||
|
|
||||||
@@ -80,7 +81,7 @@ class VoiceLoop(
|
|||||||
|
|
||||||
// Subscribe to FCM fast path
|
// Subscribe to FCM fast path
|
||||||
ClippyResponseBus.subscribe { response, _ ->
|
ClippyResponseBus.subscribe { response, _ ->
|
||||||
scope.launch { handleClippyResponse(response) }
|
scope.launch { handleClippyResponse(response, path = "fcm") }
|
||||||
}
|
}
|
||||||
|
|
||||||
// Start network monitoring
|
// Start network monitoring
|
||||||
@@ -114,6 +115,7 @@ class VoiceLoop(
|
|||||||
fun onTalkPressed() {
|
fun onTalkPressed() {
|
||||||
when (stateMachine.state.value) {
|
when (stateMachine.state.value) {
|
||||||
VoiceState.IDLE -> {
|
VoiceState.IDLE -> {
|
||||||
|
LatencyTracker.markT0(sessionId) // t0: PTT press
|
||||||
stateMachine.transition(VoiceState.LISTENING)
|
stateMachine.transition(VoiceState.LISTENING)
|
||||||
speechManager.startListening()
|
speechManager.startListening()
|
||||||
onStateChange(VoiceState.LISTENING, "Listening...")
|
onStateChange(VoiceState.LISTENING, "Listening...")
|
||||||
@@ -139,11 +141,13 @@ class VoiceLoop(
|
|||||||
return
|
return
|
||||||
}
|
}
|
||||||
|
|
||||||
|
LatencyTracker.markT1() // t1: STT result ready
|
||||||
stateMachine.transition(VoiceState.PROCESSING)
|
stateMachine.transition(VoiceState.PROCESSING)
|
||||||
onStateChange(VoiceState.PROCESSING, "Thinking...")
|
onStateChange(VoiceState.PROCESSING, "Thinking...")
|
||||||
|
|
||||||
scope.launch {
|
scope.launch {
|
||||||
val sent = sendToMatrix(text)
|
val sent = sendToMatrix(text)
|
||||||
|
if (sent) LatencyTracker.markT2() // t2: Matrix message sent
|
||||||
if (!sent) {
|
if (!sent) {
|
||||||
// Offline — queue the message
|
// Offline — queue the message
|
||||||
messageQueue.enqueue(text)
|
messageQueue.enqueue(text)
|
||||||
@@ -172,12 +176,13 @@ class VoiceLoop(
|
|||||||
/**
|
/**
|
||||||
* Handle Clippy's response — from either FCM or Matrix sync.
|
* 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
|
// Dedup — mark this response so the other path skips it
|
||||||
val hash = sha256(text)
|
val hash = sha256(text)
|
||||||
if (ResponseDedup.seen(hash)) return
|
if (ResponseDedup.seen(hash)) return
|
||||||
ResponseDedup.mark(hash)
|
ResponseDedup.mark(hash)
|
||||||
|
|
||||||
|
LatencyTracker.markT3(path) // t3: Clippy response received
|
||||||
stateMachine.transition(VoiceState.RECEIVING)
|
stateMachine.transition(VoiceState.RECEIVING)
|
||||||
onStateChange(VoiceState.RECEIVING, "")
|
onStateChange(VoiceState.RECEIVING, "")
|
||||||
|
|
||||||
@@ -199,7 +204,7 @@ class VoiceLoop(
|
|||||||
.filter { it.signal == null } // Skip session signals
|
.filter { it.signal == null } // Skip session signals
|
||||||
.forEach { msg ->
|
.forEach { msg ->
|
||||||
withContext(Dispatchers.Main) {
|
withContext(Dispatchers.Main) {
|
||||||
handleClippyResponse(msg.body)
|
handleClippyResponse(msg.body, path = "sync")
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
} catch (e: Exception) {
|
} catch (e: Exception) {
|
||||||
|
|||||||
@@ -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")
|
||||||
|
}
|
||||||
|
}
|
||||||
@@ -6,6 +6,7 @@ import android.media.AudioFocusRequest
|
|||||||
import android.media.AudioManager
|
import android.media.AudioManager
|
||||||
import android.speech.tts.TextToSpeech
|
import android.speech.tts.TextToSpeech
|
||||||
import android.speech.tts.UtteranceProgressListener
|
import android.speech.tts.UtteranceProgressListener
|
||||||
|
import farm.hobbs.clippyauto.util.LatencyTracker
|
||||||
import java.util.LinkedList
|
import java.util.LinkedList
|
||||||
import java.util.Locale
|
import java.util.Locale
|
||||||
import java.util.UUID
|
import java.util.UUID
|
||||||
@@ -44,6 +45,7 @@ class TTSManager(
|
|||||||
tts?.language = Locale.US
|
tts?.language = Locale.US
|
||||||
tts?.setOnUtteranceProgressListener(object : UtteranceProgressListener() {
|
tts?.setOnUtteranceProgressListener(object : UtteranceProgressListener() {
|
||||||
override fun onStart(utteranceId: String?) {
|
override fun onStart(utteranceId: String?) {
|
||||||
|
LatencyTracker.markT5() // t5: First audio frame
|
||||||
onSpeakingStart()
|
onSpeakingStart()
|
||||||
}
|
}
|
||||||
|
|
||||||
@@ -71,6 +73,7 @@ class TTSManager(
|
|||||||
*/
|
*/
|
||||||
fun speak(text: String) {
|
fun speak(text: String) {
|
||||||
if (!isReady) return
|
if (!isReady) return
|
||||||
|
LatencyTracker.markT4() // t4: TTS synthesis starts
|
||||||
queue.add(text)
|
queue.add(text)
|
||||||
if (queue.size == 1) {
|
if (queue.size == 1) {
|
||||||
audioManager.requestAudioFocus(audioFocusRequest)
|
audioManager.requestAudioFocus(audioFocusRequest)
|
||||||
|
|||||||
Reference in New Issue
Block a user