feat(debug): encart « dernier tour » + verrou half-duplex entrée
- Verrou half-duplex : pendant la génération LLM + la création TTS (avant le 1er son), l'entrée est verrouillée (toggleListening/interruptTts ignorés) — un tap micro ne casse plus la synthèse en cours. Déverrouillage au 1er son audible (l'usager peut alors interrompre). Flag audiblePlayback. - KazeiaService déclenche le pré-chauffage TTS (cv.warmup()) en tâche de fond après le chargement. - Métriques par étape : PipelineMetrics expose STT·Thinker·Speaker·TTS isolés ; snapshot /turns enrichi (thinker_ms, tts_ms) ; sinks vers le panneau debug. - Encart debug PERSISTANT « dernier tour » (remplace le graph GPU inutilisé) : phrase input · réponse output · temps par étape, en partition ADDITIVE Traitement (avant 1er son) / Lecture (durée parlée) dont la somme == TOTAL. Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
This commit is contained in:
Kazeia Team
parent
76ffbcb8fd
commit
078804e2de
|
|
@ -34,6 +34,15 @@ class PipelineMetrics(val tag: String = "Pipeline") {
|
|||
private var inputKind: String = ""
|
||||
private var inputPayload: String = ""
|
||||
|
||||
/** Récepteur optionnel du récap par tour (1 ligne lisible). Branché par
|
||||
* KazeiaService sur son `log()` → visible dans le panneau debug patient,
|
||||
* pas seulement dans logcat. Découple PipelineMetrics du service. */
|
||||
@Volatile var summarySink: ((String) -> Unit)? = null
|
||||
|
||||
/** Récepteur du bloc temps COMPLET (multi-lignes, 1 string) pour un encart
|
||||
* debug PERSISTANT (vs les logs qui défilent). Mis à jour à chaque fin de tour. */
|
||||
@Volatile var timingsSink: ((String) -> Unit)? = null
|
||||
|
||||
fun begin(kind: String, payload: String) {
|
||||
t0 = System.currentTimeMillis()
|
||||
inputKind = kind
|
||||
|
|
@ -94,29 +103,69 @@ class PipelineMetrics(val tag: String = "Pipeline") {
|
|||
.append('\n')
|
||||
}
|
||||
|
||||
// Derived KPIs that matter for perceived latency.
|
||||
// Derived KPIs that matter for perceived latency. Per-stage durations
|
||||
// (and not just cumulative timestamps) so STT / Thinker / Speaker / TTS
|
||||
// are each isolable.
|
||||
val sttStart = firstT("STT.start") ?: 0L
|
||||
val sttEnd = firstT("STT.end")
|
||||
val thinkerStart = firstT("THINKER.start")
|
||||
val thinkerEnd = firstT("THINKER.end")
|
||||
val llmStart = firstT("LLM.start")
|
||||
val llmFirstTok = firstT("LLM.first_token")
|
||||
val llmEnd = firstT("LLM.end")
|
||||
val firstAudio = firstT("PIPELINE.first_audio") ?: firstT("TTS.seg.play_start")
|
||||
val lastAudio = lastT("TTS.seg.play_end")
|
||||
|
||||
sb.appendLine("[PIPELINE] ---- KPIs (ms since begin) ----")
|
||||
if (sttEnd != null) sb.appendLine("[PIPELINE] STT duration : $sttEnd")
|
||||
if (llmStart != null && llmFirstTok != null)
|
||||
sb.appendLine("[PIPELINE] LLM time-to-first-token: ${llmFirstTok - llmStart}")
|
||||
if (llmStart != null && llmEnd != null)
|
||||
sb.appendLine("[PIPELINE] LLM generation : ${llmEnd - llmStart}")
|
||||
if (firstAudio != null) sb.appendLine("[PIPELINE] Time-to-first-audio : $firstAudio ← user waits this long")
|
||||
if (firstAudio != null && lastAudio != null)
|
||||
sb.appendLine("[PIPELINE] Audio playback window : ${lastAudio - firstAudio}")
|
||||
sb.appendLine("[PIPELINE] Total wall time : $total")
|
||||
val sttDur = sttEnd?.let { it - sttStart }
|
||||
val thinkerDur = if (thinkerStart != null && thinkerEnd != null) thinkerEnd - thinkerStart else null
|
||||
val speakerTtft = if (llmStart != null && llmFirstTok != null) llmFirstTok - llmStart else null
|
||||
val speakerGen = if (llmStart != null && llmEnd != null) llmEnd - llmStart else null
|
||||
// TTS « synthèse 1ʳᵉ phrase » = Speaker fini → 1er son audible.
|
||||
val ttsSynth = if (llmEnd != null && firstAudio != null) firstAudio - llmEnd else null
|
||||
val playback = if (firstAudio != null && lastAudio != null) lastAudio - firstAudio else null
|
||||
|
||||
sb.appendLine("[PIPELINE] ---- KPIs (durées par étape, ms) ----")
|
||||
if (sttDur != null) sb.appendLine("[PIPELINE] STT : $sttDur")
|
||||
if (thinkerDur != null) sb.appendLine("[PIPELINE] Thinker (cascade) : $thinkerDur")
|
||||
if (speakerTtft != null) sb.appendLine("[PIPELINE] Speaker time-to-1st-tok: $speakerTtft")
|
||||
if (speakerGen != null) sb.appendLine("[PIPELINE] Speaker génération : $speakerGen")
|
||||
if (ttsSynth != null) sb.appendLine("[PIPELINE] TTS → 1er son : $ttsSynth")
|
||||
if (firstAudio != null) sb.appendLine("[PIPELINE] Time-to-first-audio : $firstAudio ← attente perçue")
|
||||
if (playback != null) sb.appendLine("[PIPELINE] Lecture audio : $playback")
|
||||
sb.appendLine("[PIPELINE] Total : $total")
|
||||
|
||||
// Single log call so it shows up contiguously even if the logger
|
||||
// interleaves other threads.
|
||||
Log.i(tag, sb.toString().trimEnd())
|
||||
|
||||
// Bloc temps par étape (ne liste que les étapes réellement mesurées).
|
||||
// Construit une fois, envoyé aux DEUX puits : summarySink (flot de logs) et
|
||||
// timingsSink (encart persistant qui ne défile pas).
|
||||
// DEUX BLOCS additifs : TRAITEMENT (latence avant le 1er son, ce qui compte
|
||||
// pour la perf) + LECTURE (durée de la voix, dépend de la longueur du texte).
|
||||
// Traitement + Lecture == TOTAL (exact). Le TTFT est un REPÈRE inclus dans
|
||||
// Speaker, pas un poste à additionner.
|
||||
run {
|
||||
val b = StringBuilder("⏱─── TEMPS DU TOUR ($status) ───\n")
|
||||
fun row(name: String, value: String) { b.append(" ${name.padEnd(11)} $value\n") }
|
||||
// first_audio = frontière traitement / lecture ; à défaut (pas de TTS,
|
||||
// ex. mode texte) tout est « traitement ».
|
||||
val processingMs = firstAudio ?: total
|
||||
val readingMs = (total - processingMs).coerceAtLeast(0)
|
||||
b.append(" TRAITEMENT (avant le 1er son) : $processingMs ms\n")
|
||||
if (sttDur != null) row("· STT", "$sttDur ms")
|
||||
if (thinkerDur != null) row("· Thinker", "$thinkerDur ms")
|
||||
if (speakerGen != null) row("· Speaker", "$speakerGen ms" +
|
||||
(speakerTtft?.let { " (dont 1er token $it)" } ?: ""))
|
||||
if (ttsSynth != null) row("· TTS→son", "$ttsSynth ms")
|
||||
if (firstAudio != null) b.append(" LECTURE (durée parlée) : $readingMs ms\n")
|
||||
b.append(" ─────────────────────────────\n")
|
||||
b.append(" TOTAL : $total ms")
|
||||
val block = b.toString()
|
||||
runCatching { timingsSink?.invoke(block) }
|
||||
summarySink?.let { sink -> block.lineSequence().forEach { runCatching { sink(it) } } }
|
||||
}
|
||||
|
||||
// Push a structured snapshot to TelemetryHolder so the admin app
|
||||
// can pull it via ContentProvider. Best-effort — if anything goes
|
||||
// wrong here it must not affect the pipeline.
|
||||
|
|
@ -129,15 +178,14 @@ class PipelineMetrics(val tag: String = "Pipeline") {
|
|||
inputKind = inputKind,
|
||||
status = status,
|
||||
totalMs = total,
|
||||
sttDurationMs = sttEnd,
|
||||
llmTtftMs = if (llmStart != null && llmFirstTok != null)
|
||||
llmFirstTok - llmStart else null,
|
||||
llmGenerationMs = if (llmStart != null && llmEnd != null)
|
||||
llmEnd - llmStart else null,
|
||||
sttDurationMs = sttDur,
|
||||
thinkerMs = thinkerDur,
|
||||
llmTtftMs = speakerTtft,
|
||||
llmGenerationMs = speakerGen,
|
||||
llmTokens = tokensMatch,
|
||||
ttsSynthMs = ttsSynth,
|
||||
timeToFirstAudioMs = firstAudio,
|
||||
audioPlaybackMs = if (firstAudio != null && lastAudio != null)
|
||||
lastAudio - firstAudio else null
|
||||
audioPlaybackMs = playback
|
||||
)
|
||||
)
|
||||
} catch (e: Throwable) {
|
||||
|
|
|
|||
|
|
@ -132,7 +132,19 @@ Pas d'introduction, pas d'explication. Juste les 4 lignes en francais. /no_think
|
|||
// Per-interaction timing tracer. One instance, reset at every begin().
|
||||
// All stage timings for a single user turn (STT+LLM+TTS+playback) end
|
||||
// up in a single grep-friendly log section tagged "[PIPELINE]".
|
||||
private val metrics = com.kazeia.core.PipelineMetrics(TAG)
|
||||
private val metrics = com.kazeia.core.PipelineMetrics(TAG).apply {
|
||||
// Récap par tour (STT · Thinker · Speaker · TTS · total) routé vers les logs
|
||||
// du service → visible dans le panneau debug patient, pas que dans logcat.
|
||||
summarySink = { msg -> log(msg) }
|
||||
// + encart PERSISTANT (ne défile pas) : input · output · temps du dernier tour.
|
||||
timingsSink = { block ->
|
||||
_lastTurnPanel.value = buildString {
|
||||
append("🗣 Vous : "); append(lastTurnInput.ifBlank { "—" }); append("\n\n")
|
||||
append("🤖 Kazeia : "); append(lastTurnOutput.ifBlank { "—" }); append("\n\n")
|
||||
append(block)
|
||||
}
|
||||
}
|
||||
}
|
||||
private lateinit var voiceCommands: com.kazeia.conversation.VoiceCommandProcessor
|
||||
|
||||
// New modular pipeline
|
||||
|
|
@ -147,6 +159,12 @@ Pas d'introduction, pas d'explication. Juste les 4 lignes en francais. /no_think
|
|||
private val _logs = MutableStateFlow<List<String>>(emptyList())
|
||||
val logs: StateFlow<List<String>> = _logs
|
||||
|
||||
// Encart « dernier tour » persistant (input · output · temps par étape).
|
||||
private val _lastTurnPanel = MutableStateFlow("⏱ dernier tour : —")
|
||||
val lastTurnPanel: StateFlow<String> = _lastTurnPanel
|
||||
@Volatile private var lastTurnInput = ""
|
||||
@Volatile private var lastTurnOutput = ""
|
||||
|
||||
// AI workload tracking: which component is active (for monitoring)
|
||||
data class AiWorkload(
|
||||
val sttActive: Boolean = false,
|
||||
|
|
@ -470,6 +488,12 @@ Pas d'introduction, pas d'explication. Juste les 4 lignes en francais. /no_think
|
|||
if (!cv.isLoaded()) throw IllegalStateException("CosyVoice load failed")
|
||||
tts = cv
|
||||
log("TTS: CosyVoiceTtsEngine loaded (clonage vocal CPU-only)")
|
||||
// Pré-chauffe le cache voix EN TÂCHE DE FOND (chevauche le reste du
|
||||
// chargement + la 1ʳᵉ phrase de l'usager) → le 1er vrai tour part
|
||||
// chaud (~3 s) au lieu de ~10 s (remplissage de cache à froid).
|
||||
serviceScope.launch(Dispatchers.IO) {
|
||||
runCatching { cv.warmup() }
|
||||
}
|
||||
_loadingState.value = LoadingState(20, "TTS OK")
|
||||
|
||||
// STT = Whisper-Small NPU (HfWhisper Qualcomm) — voie validée
|
||||
|
|
@ -699,8 +723,24 @@ Pas d'introduction, pas d'explication. Juste les 4 lignes en francais. /no_think
|
|||
fun setVoice(voicePathOrId: String) =
|
||||
setVoiceId(voicePathOrId.substringAfterLast('/').substringBeforeLast('.'))
|
||||
|
||||
// True dès que le 1er son de la réponse est audible (la 1ʳᵉ phrase TTS joue).
|
||||
// Pendant la génération LLM + la synthèse TTS (avant tout son), l'entrée est
|
||||
// VERROUILLÉE : un tap/bruit ne doit pas perturber le pipeline (half-duplex).
|
||||
@Volatile private var audiblePlayback = false
|
||||
|
||||
/** Le pipeline produit la réponse mais rien n'est encore audible (LLM ou TTS
|
||||
* en cours) → on ignore toute entrée utilisateur jusqu'au 1er son / fin de tour. */
|
||||
private fun producingBeforeAudio(): Boolean {
|
||||
val s = _pipelineState.value
|
||||
val busy = s is PipelineState.Thinking || s is PipelineState.Transcribing ||
|
||||
s is PipelineState.Transcribed || s is PipelineState.TokenGenerated ||
|
||||
s is PipelineState.Speaking
|
||||
return busy && !audiblePlayback
|
||||
}
|
||||
|
||||
fun interruptTts() {
|
||||
if (_pipelineState.value is PipelineState.Speaking) {
|
||||
// N'interrompre QUE si la réponse est réellement en train de jouer.
|
||||
if (_pipelineState.value is PipelineState.Speaking && audiblePlayback) {
|
||||
log("TTS interrupted by user")
|
||||
tts.stop()
|
||||
_pipelineState.value = if (_isListening.value) PipelineState.Listening else PipelineState.Idle
|
||||
|
|
@ -710,7 +750,15 @@ Pas d'introduction, pas d'explication. Juste les 4 lignes en francais. /no_think
|
|||
@Volatile private var pttRecording = false
|
||||
|
||||
fun toggleListening() {
|
||||
// If TTS is speaking, interrupt it
|
||||
// Verrou half-duplex : pendant la génération LLM / synthèse TTS (avant le 1er
|
||||
// son), on ignore le bouton micro — sinon un tap casse la synthèse en cours
|
||||
// (« play() on uninitialized AudioTrack », tour avorté). On réaccepte l'entrée
|
||||
// une fois l'audio audible (l'usager peut alors interrompre).
|
||||
if (producingBeforeAudio()) {
|
||||
log("toggleListening ignoré — génération/synthèse en cours (entrée verrouillée)")
|
||||
return
|
||||
}
|
||||
// Audio en cours → l'usager a le droit d'interrompre.
|
||||
if (_pipelineState.value is PipelineState.Speaking) {
|
||||
log("Interrupting TTS")
|
||||
tts.stop()
|
||||
|
|
@ -1346,6 +1394,8 @@ Pas d'introduction, pas d'explication. Juste les 4 lignes en francais. /no_think
|
|||
|
||||
private suspend fun processLlmResponse(patientMessage: String) {
|
||||
_pipelineState.value = PipelineState.Thinking
|
||||
lastTurnInput = patientMessage // encart « dernier tour »
|
||||
lastTurnOutput = ""
|
||||
conversationManager.onNewTurn()
|
||||
|
||||
// Historique : tour patient persisté avant toute génération (no-op
|
||||
|
|
@ -1500,6 +1550,9 @@ Pas d'introduction, pas d'explication. Juste les 4 lignes en francais. /no_think
|
|||
metrics.mark("PIPELINE.first_audio",
|
||||
"seg=$segIdx dur=${durationMs}ms")
|
||||
_pipelineState.value = PipelineState.Speaking
|
||||
// 1er son audible → on déverrouille l'interruption (l'usager peut
|
||||
// désormais couper la réponse). Cf. producingBeforeAudio().
|
||||
audiblePlayback = true
|
||||
}
|
||||
metrics.mark("TTS.seg.play_start",
|
||||
"seg=$segIdx sentence=\"${sentence.take(40)}\" dur=${durationMs}ms")
|
||||
|
|
@ -1616,6 +1669,7 @@ Pas d'introduction, pas d'explication. Juste les 4 lignes en francais. /no_think
|
|||
|
||||
_aiWorkload.value = _aiWorkload.value.copy(llmActive = false)
|
||||
val responseText = result.text.trim()
|
||||
lastTurnOutput = responseText // encart « dernier tour »
|
||||
log("LLM prompt: '$prompt'")
|
||||
log("LLM raw response: '${result.text}'")
|
||||
log("LLM clean response: '$responseText'")
|
||||
|
|
@ -1661,6 +1715,7 @@ Pas d'introduction, pas d'explication. Juste les 4 lignes en francais. /no_think
|
|||
))
|
||||
} finally {
|
||||
firstSegmentSeen.set(true)
|
||||
audiblePlayback = false // fin de tour : ré-verrouille pour le tour suivant
|
||||
try { typingJob.cancel() } catch (_: Exception) {}
|
||||
_pipelineState.value = if (_isListening.value)
|
||||
PipelineState.Listening else PipelineState.Idle
|
||||
|
|
|
|||
|
|
@ -731,15 +731,15 @@ class KazeiaTelemetryProvider : ContentProvider() {
|
|||
private fun turnsCursor(): Cursor {
|
||||
val cols = arrayOf(
|
||||
"timestamp", "input_kind", "status", "total_ms",
|
||||
"stt_ms", "llm_ttft_ms", "llm_gen_ms", "llm_tokens",
|
||||
"time_to_first_audio_ms", "audio_playback_ms"
|
||||
"stt_ms", "thinker_ms", "llm_ttft_ms", "llm_gen_ms", "llm_tokens",
|
||||
"tts_ms", "time_to_first_audio_ms", "audio_playback_ms"
|
||||
)
|
||||
val cursor = MatrixCursor(cols)
|
||||
for (t in TelemetryHolder.recentTurns()) {
|
||||
cursor.addRow(arrayOf(
|
||||
t.timestamp, t.inputKind, t.status, t.totalMs,
|
||||
t.sttDurationMs, t.llmTtftMs, t.llmGenerationMs, t.llmTokens,
|
||||
t.timeToFirstAudioMs, t.audioPlaybackMs
|
||||
t.sttDurationMs, t.thinkerMs, t.llmTtftMs, t.llmGenerationMs, t.llmTokens,
|
||||
t.ttsSynthMs, t.timeToFirstAudioMs, t.audioPlaybackMs
|
||||
))
|
||||
}
|
||||
return cursor
|
||||
|
|
|
|||
|
|
@ -22,9 +22,11 @@ object TelemetryHolder {
|
|||
val status: String, // "ok" | "llm_only" | "empty_response" | "error"
|
||||
val totalMs: Long,
|
||||
val sttDurationMs: Long?,
|
||||
val llmTtftMs: Long?,
|
||||
val llmGenerationMs: Long?,
|
||||
val thinkerMs: Long? = null, // cascade Thinker (analyse silencieuse), si actif
|
||||
val llmTtftMs: Long?, // Speaker : temps jusqu'au 1er token
|
||||
val llmGenerationMs: Long?, // Speaker : génération complète
|
||||
val llmTokens: Int?,
|
||||
val ttsSynthMs: Long? = null, // TTS : Speaker fini → 1er son (synthèse 1ʳᵉ phrase)
|
||||
val timeToFirstAudioMs: Long?,
|
||||
val audioPlaybackMs: Long?
|
||||
)
|
||||
|
|
|
|||
|
|
@ -181,7 +181,6 @@ class ChatActivity : AppCompatActivity() {
|
|||
|
||||
private fun setupResourceMonitoring() {
|
||||
val graphCpu = findViewById<MiniGraphView>(R.id.graphCpu)
|
||||
val graphGpu = findViewById<MiniGraphView>(R.id.graphGpu)
|
||||
val graphNpu = findViewById<MiniGraphView>(R.id.graphNpu)
|
||||
val graphRam = findViewById<MiniGraphView>(R.id.graphRam)
|
||||
|
||||
|
|
@ -189,7 +188,6 @@ class ChatActivity : AppCompatActivity() {
|
|||
val ramTotal = resourceMonitor!!.snapshot().ramTotalMb.toFloat()
|
||||
|
||||
graphCpu?.configure("CPU", "%", 100f, android.graphics.Color.parseColor("#4CAF50"))
|
||||
graphGpu?.configure("GPU", "%", 100f, android.graphics.Color.parseColor("#2196F3"))
|
||||
graphNpu?.configure("AI", "%", 100f, android.graphics.Color.parseColor("#FF9800"))
|
||||
// Affiche la conso PSS de Kazeia uniquement (~2 GB idle, ~5.5 GB pic).
|
||||
// Pas la RAM système globale (qui inclut ~3 GB d'OS Android dont on
|
||||
|
|
@ -201,7 +199,6 @@ class ChatActivity : AppCompatActivity() {
|
|||
while (true) {
|
||||
val snap = resourceMonitor!!.snapshot()
|
||||
graphCpu?.addValue(snap.cpuPercent)
|
||||
graphGpu?.addValue(if (snap.gpuPercent >= 0) snap.gpuPercent else 0f)
|
||||
|
||||
// AI workload: show which AI component is active
|
||||
val workload = kazeiaService?.aiWorkload?.value
|
||||
|
|
@ -318,6 +315,13 @@ class ChatActivity : AppCompatActivity() {
|
|||
}
|
||||
}
|
||||
}
|
||||
launch {
|
||||
// Encart « dernier tour » PERSISTANT (remplace le graph GPU) :
|
||||
// input · output · temps par étape.
|
||||
service.lastTurnPanel.collect { panel ->
|
||||
findViewById<android.widget.TextView>(R.id.tvLastTurn)?.text = panel
|
||||
}
|
||||
}
|
||||
launch {
|
||||
// debugMode (piloté par l'admin via ConfigStore.debugEnabled) gate le
|
||||
// BOUTON debug. Si off : bouton masqué + panneau forcé fermé (écran
|
||||
|
|
|
|||
|
|
@ -191,12 +191,27 @@
|
|||
android:layout_weight="1"
|
||||
android:layout_margin="2dp" />
|
||||
|
||||
<com.kazeia.ui.MiniGraphView
|
||||
android:id="@+id/graphGpu"
|
||||
<!-- Remplace le graph GPU (inutilisé) : encart « dernier tour »
|
||||
(input · output · temps par étape), persistant. -->
|
||||
<ScrollView
|
||||
android:layout_width="0dp"
|
||||
android:layout_height="match_parent"
|
||||
android:layout_weight="1"
|
||||
android:layout_margin="2dp" />
|
||||
android:layout_margin="2dp"
|
||||
android:background="#16202A">
|
||||
|
||||
<TextView
|
||||
android:id="@+id/tvLastTurn"
|
||||
android:layout_width="match_parent"
|
||||
android:layout_height="wrap_content"
|
||||
android:padding="6dp"
|
||||
android:fontFamily="monospace"
|
||||
android:textSize="9sp"
|
||||
android:textColor="#B8D8EC"
|
||||
android:lineSpacingMultiplier="1.15"
|
||||
android:text="⏱ dernier tour : —" />
|
||||
|
||||
</ScrollView>
|
||||
|
||||
</LinearLayout>
|
||||
|
||||
|
|
|
|||
Loading…
Reference in New Issue