diff --git a/CHANGELOG.md b/CHANGELOG.md index 68b3c3ff..04db75e2 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,14 +1,54 @@ # Changelog All notable changes to **SKaiNET-transformers** are documented here. The -version line is kept in lock-step with the underlying SKaiNET engine -(`sk.ainet.core:*`) — a transformers `X.Y.Z` ships against engine `X.Y.Z`. +version line tracks the underlying SKaiNET engine (`sk.ainet.core:*`): a transformers +release carries **at least** the engine's `X.Y`, and its **patch number may advance on its +own** — a fix confined to transformers ships as `X.Y.Z+1` against engine `X.Y.Z` without +requiring an engine release. `0.57.1` against engine `0.57.0` is such a release. The format roughly follows [Keep a Changelog](https://keepachangelog.com/en/1.1.0/), and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.html). ## [Unreleased] +## [0.57.1] — 2026-09-27 + +Ships against **SKaiNET engine 0.57.0**: this release touches only the Android IREE runtime's +streaming Moonshine path, no engine API. + +### Changed + +- **The streaming partial decode now has a real-time budget.** On an ARM Android device with a Mali GPU the stream did + not keep up with the microphone: per 0.88 s hop it spent ~350 ms on the encoder window and another + ~350 ms on a prefill plus greedy steps, so it ran at 1.2–1.45× real time and the whole backlog was + still owed at the moment the user stopped speaking. The encoder path is mandatory — it builds the + cross memory the final transcript is decoded from — but the decode hops only produce text to show + while the user is still talking, and `finish()` re-decodes from that memory regardless. Past + `MOONSHINE_LAG_BUDGET_MS` (default 250) the window runs and the decode is skipped, which provably + cannot change the final result. Measured on that device: RTF 1.23 → 0.67, drain 656 ms → 6 ms. Verified + against a 444-utterance German evaluation set: on 311 comparable rows 310 final transcripts were + byte-identical, and the single difference is a runaway repetition on both sides. The budget is disabled when `MOONSHINE_FAST_FINISH` is on, where the + incremental result *is* the answer. + +### Added + +- **`IreeMoonshineStream.stats()`** — what the last `finish()` cost, by stage. These numbers only ever + went to logcat, so a caller that wanted to know where recognition spent its time had to scrape the + device log. Now: the flush/decode split of the final decode, how far the stream fell behind the + microphone, how many partial decodes the budget gave up, encoder windows and decode hops run, and the + utterance's size in frames, tokens and milliseconds. A `timeline` entry carries each event with its + timestamp and cost (`w`/`p`/`h`/`d` records), so the shape of an utterance can be drawn rather than + only totalled. A string map rather than a typed record on purpose: the values cross two more + artifacts before anything consumes them, and adding a counter must not change a signature on the way. + +- **Audio that arrives before a run is open is held instead of dropped.** `sendAudioChunk` was + `activeRun?.feed(...)`: with no run open the chunk vanished silently. Opening a run costs 229 ms of + the 259 ms measured between a push-to-talk trigger and the first recorded sample, and a host that + waited for it lost that much speech off the *front* — enough to swallow the first word of an + utterance entirely. Chunks now go into a pre-roll, bounded to 1 s keeping the newest + and discarded entirely past 2 s of age, and are fed in order once the run opens. Measured: 259 ms → + 68 ms, and an utterance whose first word was previously lost transcribes in full. + ## [0.57.0] — 2026-09-25 Lock-step with **SKaiNET engine 0.57.0**. Headline: **Qwen on the compiled IREE KV path**: the diff --git a/gradle.properties b/gradle.properties index c0e454f3..292221aa 100644 --- a/gradle.properties +++ b/gradle.properties @@ -1,5 +1,5 @@ GROUP=sk.ainet.transformers -VERSION_NAME=0.57.0 +VERSION_NAME=0.57.1 POM_DESCRIPTION=SKaiNET-transformers diff --git a/llm-runtime/iree-android/native/moonshine_stream_jni.c b/llm-runtime/iree-android/native/moonshine_stream_jni.c index 08c601a2..86474a7b 100644 --- a/llm-runtime/iree-android/native/moonshine_stream_jni.c +++ b/llm-runtime/iree-android/native/moonshine_stream_jni.c @@ -14,6 +14,7 @@ * String nativeFeedPcm(long h, float[] pcm) // 16 kHz mono [-1,1]; returns new partial or null * String nativeFinish(long h) // end of utterance: exact final transcript; resets * void nativeReset(long h) // abort utterance, keep engine + * String nativeStats(long h) // last finish()'s counters as key=value pairs * void nativeDestroy(long h) * * Decode strategy (measured on a Mali GPU): the with_past step is ~120 ms and flat in @@ -83,12 +84,35 @@ #define FE_OUT (CHUNK + FE_LC) /* 68 frames out */ #define MAXMEM 256 /* compiled cross-memory pad (5.12 s of finalized speech) */ #define MAXTOK 48 +/* 1 = skip the exact re-decode at the end of an utterance and keep the incremental result. + * Off by default; switched on for the latency experiment via -DMOONSHINE_FAST_FINISH=1. */ +#ifndef MOONSHINE_FAST_FINISH +#define MOONSHINE_FAST_FINISH 0 +#endif #define FINISH_TOKENS 24 /* hard ceiling for the final budget (see finish_budget) */ #define TOKENS_PER_SAMPLE (6.5f / 16000.0f) /* the model card's cap: max_new_tokens = samples * 6.5/16000 + 2 */ #define HOP_TOKENS 6 /* max new tokens decoded per hop (budget guard) */ #define RESTART_HOPS 2 /* first hops re-decode exactly instead of incrementally */ #define PEEK_FRAMES 36 /* early-peek window: first partial at ~0.72 s instead of 1.28 s */ #define STEP_SLICE 2 /* tokens decoded per feed call — partials trickle out mid-hop */ +/* How far the stream may fall behind the microphone before partial decodes are dropped, in ms. + * + * The encoder path (frontend, encoder, adapter) is mandatory — it builds the cross memory the final + * transcript is decoded from — but the decode hops exist only to show text while the user is still + * speaking. On this box a hop costs about as long as the audio it covers, so paying for every one of + * them puts the stream past real time and the whole backlog is still waiting to be worked off at the + * moment the button is released. Dropping a partial costs a partial; it cannot change the final text, + * because finish() re-decodes from the memory regardless (that is only untrue with + * MOONSHINE_FAST_FINISH, which keeps the incremental result and therefore also keeps every hop). + * 0 disables the budget and decodes every hop as before. */ +#ifndef MOONSHINE_LAG_BUDGET_MS +#define MOONSHINE_LAG_BUDGET_MS 250 +#endif +#define MAXEVT 24 /* per-event timeline entries retained for nativeStats */ +#define EVT_WINDOW 0 +#define EVT_PEEK 1 +#define EVT_HOP 2 +#define EVT_DROPPED 3 #define MAXPCM ((MAXMEM + CHUNK) * SPF) /* ring capacity, samples */ #define NEGMASK (-1.0e30f) @@ -118,9 +142,35 @@ typedef struct { size_t shown_len; /* longest partial surfaced so far — keeps the VIL text monotone */ int pending; /* tokens still budgeted for the current hop's decode */ int halted; /* decode hit EOS/cycle; stop continuing until the next hop */ + double t_first_feed; /* wall clock of the first fed sample, 0 before it — the real-time reference */ + int dropped; /* partial decodes skipped because the stream had fallen behind the microphone */ + int windows; /* encoder windows processed this utterance (the mandatory work) */ + int hops; /* partial decodes actually run */ + /* Per-event costs, so a caller can draw the utterance's timeline instead of only totalling it. + * Offsets are ms from the first fed sample. Capped: past MAXEVT the counters above still grow, + * the timeline simply stops — a status surface wants the shape, not an unbounded log. */ + short evt_at[MAXEVT], evt_a[MAXEVT], evt_b[MAXEVT], evt_c[MAXEVT]; + unsigned char evt_kind[MAXEVT]; /* EVT_WINDOW / EVT_PEEK / EVT_HOP / EVT_DROPPED */ + int nevt; char text[4096]; + /* Last utterance's counters, taken before the reset so a caller can still read them afterwards. + * `key=value` pairs, because this travels through two more repositories before anything consumes it + * and adding a counter must not change a signature anywhere along the way. */ + char stats[1400]; } Engine; +/* Record one timeline event: `at` is ms from the first fed sample, a/b/c are the stage costs of the + * event's kind (a window's frontend/encoder/adapter; a decode's total in `a`). */ +static void note_evt(Engine* e, int kind, double at, double a, double b, double c) { + if (e->nevt >= MAXEVT) return; + int i = e->nevt++; + e->evt_kind[i] = (unsigned char)kind; + e->evt_at[i] = (short)(at < 0 ? 0 : (at > 32000 ? 32000 : at)); + e->evt_a[i] = (short)(a > 32000 ? 32000 : a); + e->evt_b[i] = (short)(b > 32000 ? 32000 : b); + e->evt_c[i] = (short)(c > 32000 ? 32000 : c); +} + static double now_ms(void) { struct timespec ts; clock_gettime(CLOCK_MONOTONIC, &ts); return ts.tv_sec * 1000.0 + ts.tv_nsec / 1e6; @@ -353,6 +403,8 @@ static int process_window(Engine* e, int start, int produced, int flush, int pee if (new_final > e->nmem) e->nmem = new_final; if (!peek && start == 0) e->peeked = 0; double t3 = now_ms(); + e->windows++; + note_evt(e, EVT_WINDOW, t0 - e->t_first_feed, t1 - t0, t2 - t1, t3 - t2); TLOG("win %d fe %.0fms enc %.0fms adp+fin %.0fms nmem %d\n", e->win, t1 - t0, t2 - t1, t3 - t2, e->nmem); return 0; @@ -562,6 +614,7 @@ static void warmup(Engine* e) { if (run_prefill(e, 1) == 0 && e->ntoks > 0) run_steps(e, 1, 0); e->npcm = 0; e->win = 0; e->nmem = 0; e->peeked = 0; e->pending = 0; e->halted = 0; e->shown_len = 0; + e->t_first_feed = 0.0; e->dropped = 0; e->windows = 0; e->hops = 0; e->nevt = 0; release_self(e); release_cross(e); e->ntoks = 0; e->pos = 0; e->text[0] = 0; TLOG("warmup %.0fms (all pipelines compiled)\n", now_ms() - t0); @@ -570,6 +623,7 @@ static void warmup(Engine* e) { static void reset_utterance(Engine* e) { e->npcm = 0; e->win = 0; e->nmem = 0; e->peeked = 0; e->pending = 0; e->halted = 0; e->shown_len = 0; + e->t_first_feed = 0.0; e->dropped = 0; e->windows = 0; e->hops = 0; e->nevt = 0; release_self(e); release_cross(e); e->ntoks = 0; e->pos = 0; e->text[0] = 0; } @@ -656,6 +710,16 @@ JNIEXPORT jstring JNICALL JNIFN(nativeFeedPcm)(JNIEnv* env, jobject thiz, int produced = e->npcm / SPF; int changed = 0; + /* How far behind the microphone this stream is: wall clock since the first sample minus the audio + * that has arrived. Positive means the caller is waiting on us, and every millisecond of it is still + * owed at the moment the utterance ends. Only the optional decode work is given up for it. + * MOONSHINE_FAST_FINISH makes the incremental decode the final answer, so there the hops are not + * optional and the budget does not apply. */ + if (e->t_first_feed == 0.0) e->t_first_feed = now_ms(); + int behind = 0; +#if !MOONSHINE_FAST_FINISH && MOONSHINE_LAG_BUDGET_MS > 0 + behind = (now_ms() - e->t_first_feed) - (double)e->npcm * 1000.0 / 16000.0 > MOONSHINE_LAG_BUDGET_MS; +#endif /* Early peek: flash the first words at ~0.72 s instead of waiting for the full 1.28 s * window. The peek rows are conservative (zero-padded tail, lookahead subtracted) and are * recomputed by the real window 0; the restart decode at hop 1 replaces the text anyway. */ @@ -668,6 +732,7 @@ JNIEXPORT jstring JNICALL JNIFN(nativeFeedPcm)(JNIEnv* env, jobject thiz, if (run_prefill(e, 1) == 0) run_steps(e, STEP_SLICE, 1); e->pending = 2 * HOP_TOKENS - STEP_SLICE; if (e->ntoks > 0) changed = 1; + note_evt(e, EVT_PEEK, t0 - e->t_first_feed, now_ms() - t0, 0, 0); TLOG("peek total %.0fms nmem %d toks %d \"%s\"\n", now_ms() - t0, e->nmem, e->ntoks, e->text); } } @@ -683,15 +748,27 @@ JNIEXPORT jstring JNICALL JNIFN(nativeFeedPcm)(JNIEnv* env, jobject thiz, * incrementally by subsequent feed calls (mid-hop emission), so text trickles out * instead of arriving in one lump per hop. finish() stays an exact full re-decode. */ int restart = e->win <= RESTART_HOPS || e->ntoks == 0; + /* Behind the microphone: the window above has already put this hop's speech into the memory, so + * the final transcript is unaffected — give up only the partial. The decode state is left as it + * is; the next hop that can afford it picks up from there, and a restart hop rebuilds it anyway. */ + if (behind) { + e->dropped++; + note_evt(e, EVT_DROPPED, t0 - e->t_first_feed, now_ms() - t0, 0, 0); + hopped = 1; + TLOG("hop %d total %.0fms DROPPED decode (behind) nmem %d\n", e->win, now_ms() - t0, e->nmem); + continue; + } if (restart) { release_self(e); e->ntoks = 0; e->pos = 0; e->text[0] = 0; } if (run_prefill(e, restart) == 0) run_steps(e, STEP_SLICE, restart); e->pending = (restart ? 2 * HOP_TOKENS : HOP_TOKENS) - STEP_SLICE; + e->hops++; + note_evt(e, EVT_HOP, t0 - e->t_first_feed, now_ms() - t0, 0, 0); hopped = 1; if (e->ntoks != prev || e->win == 1) changed = 1; TLOG("hop %d total %.0fms toks %d \"%s\"\n", e->win, now_ms() - t0, e->ntoks, e->text); } - if (!hopped && e->pending > 0 && !e->halted && e->ntoks > 0 && e->has_self && e->has_cross) { + if (!hopped && !behind && e->pending > 0 && !e->halted && e->ntoks > 0 && e->has_self && e->has_cross) { int budget = e->pending < STEP_SLICE ? e->pending : STEP_SLICE; int added = run_steps(e, budget, e->win <= RESTART_HOPS); e->pending -= added; @@ -718,11 +795,24 @@ JNIEXPORT jstring JNICALL JNIFN(nativeFinish)(JNIEnv* env, jobject thiz, jlong h if (process_window(e, e->win * HOP, produced, 1, 0)) break; e->win++; } + double t_flush = now_ms(); jstring out = NULL; if (e->nmem > 0) { +#if MOONSHINE_FAST_FINISH + /* Skip the exact re-decode and keep what the incremental decode already produced. + * + * Measured on 16 push-to-talk recordings: against the last incremental result the exact + * re-decode was better 4 times, worse 5 and equal 7 — a wash. On the box it costs 3.8–4.5 s of a + * ~8 s turn, which is the single largest block after the utterance itself. Paying four seconds for + * a result that is not better is not a trade worth making for command and control. + * + * The window flush above still runs: it is what turns the remaining audio into memory rows, and it + * is the cheap half. */ +#else /* exact: fresh decode over the final memory */ release_self(e); e->ntoks = 0; e->pos = 0; e->text[0] = 0; if (run_prefill(e, 1) == 0) run_steps(e, finish_budget(e->npcm), 1); +#endif if (!e->ended_eos) drop_restart_suffix(e); /* C&C utterances are single sentences; on a silent tail the greedy decode restarts the * utterance instead of emitting EOS ("Go to the next. Go to next") — same failure and @@ -732,13 +822,47 @@ JNIEXPORT jstring JNICALL JNIFN(nativeFinish)(JNIEnv* env, jobject thiz, jlong h } const char* p = e->text; while (*p == ' ') ++p; out = (*env)->NewStringUTF(env, p); - TLOG("finish %.0fms nmem %d toks %d/%d \"%s\"\n", - now_ms() - t0, e->nmem, e->ntoks, finish_budget(e->npcm), p); + /* flush and re-decode reported apart, so the cost of each half is visible rather than inferred. */ + TLOG("finish %.0fms (flush %.0fms decode %.0fms) nmem %d toks %d/%d fast=%d dropped %d lag %.0fms \"%s\"\n", + now_ms() - t0, t_flush - t0, now_ms() - t_flush, e->nmem, e->ntoks, + finish_budget(e->npcm), MOONSHINE_FAST_FINISH, e->dropped, + e->t_first_feed > 0.0 ? t0 - e->t_first_feed - (double)e->npcm * 1000.0 / 16000.0 : 0.0, p); + } + /* Same figures the line above logs, kept for nativeStats — a caller should not have to parse logcat + * to learn what recognition cost. Written before the reset, which clears the counters. */ + int n = snprintf(e->stats, sizeof(e->stats), + "flushMs=%.0f,decodeMs=%.0f,finishMs=%.0f,finishAtMs=%.0f,lagMs=%.0f,droppedDecodes=%d," + "windows=%d,hops=%d,memFrames=%d,tokens=%d,tokenBudget=%d,audioMs=%.0f,fastFinish=%d,lagBudgetMs=%d", + t_flush - t0, now_ms() - t_flush, now_ms() - t0, + e->t_first_feed > 0.0 ? t0 - e->t_first_feed : 0.0, + e->t_first_feed > 0.0 ? t0 - e->t_first_feed - (double)e->npcm * 1000.0 / 16000.0 : 0.0, + e->dropped, e->windows, e->hops, e->nmem, e->ntoks, finish_budget(e->npcm), + (double)e->npcm * 1000.0 / 16000.0, MOONSHINE_FAST_FINISH, MOONSHINE_LAG_BUDGET_MS); + /* The utterance's timeline, so the shape can be drawn and not just totalled: + * timeline=::::|... + * kind w = encoder window (a/b/c = frontend, encoder, adapter), p = early peek, h = partial + * decode, d = partial decode dropped to the real-time budget (a = its cost, b/c unused). + * `at` is ms from the first fed sample, the same zero `finishAtMs` uses. */ + if (e->nevt > 0 && n > 0 && (size_t)n < sizeof(e->stats)) { + n += snprintf(e->stats + n, sizeof(e->stats) - n, ",timeline="); + for (int i = 0; i < e->nevt && n > 0 && (size_t)n < sizeof(e->stats); ++i) { + const char k = e->evt_kind[i] == EVT_WINDOW ? 'w' : e->evt_kind[i] == EVT_PEEK ? 'p' + : e->evt_kind[i] == EVT_HOP ? 'h' : 'd'; + n += snprintf(e->stats + n, sizeof(e->stats) - n, "%s%c:%d:%d:%d:%d", + i ? "|" : "", k, e->evt_at[i], e->evt_a[i], e->evt_b[i], e->evt_c[i]); + } } reset_utterance(e); return out; } +/* The last utterance's counters as `key=value` pairs, or an empty string before the first finish(). + * Valid until the next finish(); reset() and a new utterance leave it untouched. */ +JNIEXPORT jstring JNICALL JNIFN(nativeStats)(JNIEnv* env, jobject thiz, jlong handle) { + Engine* e = (Engine*)(intptr_t)handle; if (!e) return NULL; + return (*env)->NewStringUTF(env, e->stats); +} + JNIEXPORT void JNICALL JNIFN(nativeReset)(JNIEnv* env, jobject thiz, jlong handle) { Engine* e = (Engine*)(intptr_t)handle; if (e) reset_utterance(e); } diff --git a/llm-runtime/iree-android/src/main/jniLibs/armeabi-v7a/libskainet_moonshine_stream.so b/llm-runtime/iree-android/src/main/jniLibs/armeabi-v7a/libskainet_moonshine_stream.so index 4e2d0b42..84972415 100755 Binary files a/llm-runtime/iree-android/src/main/jniLibs/armeabi-v7a/libskainet_moonshine_stream.so and b/llm-runtime/iree-android/src/main/jniLibs/armeabi-v7a/libskainet_moonshine_stream.so differ diff --git a/llm-runtime/iree-android/src/main/kotlin/sk/ainet/transformers/iree/android/IreeMoonshineStream.kt b/llm-runtime/iree-android/src/main/kotlin/sk/ainet/transformers/iree/android/IreeMoonshineStream.kt index 28241c4a..650b5606 100644 --- a/llm-runtime/iree-android/src/main/kotlin/sk/ainet/transformers/iree/android/IreeMoonshineStream.kt +++ b/llm-runtime/iree-android/src/main/kotlin/sk/ainet/transformers/iree/android/IreeMoonshineStream.kt @@ -59,6 +59,37 @@ public class IreeMoonshineStream( /** Abort the current utterance, keep the engine. */ public fun reset() { if (handle != 0L) nativeReset(handle) } + /** + * What the last [finish] cost, by stage. Empty before the first one, and valid until the next. + * + * These numbers were only ever written to logcat, so a caller wanting to know where recognition + * spent its time had to scrape the device log. They are the same figures the `moonshine-timing` + * `finish` line prints: + * + * - `flushMs`, `decodeMs`, `finishMs` — turning the remaining audio into memory rows, the exact + * final decode, and their sum. The decode is normally the larger half. + * - `lagMs` — how far the stream was behind the microphone when the utterance ended. Positive + * means the audio arrived faster than it could be consumed and the caller waited for the rest. + * - `droppedDecodes`, `hops`, `windows` — partial decodes given up to the real-time budget, + * partial decodes actually run, and encoder windows processed. Windows are the mandatory work; + * a dropped decode costs a partial and cannot change the final transcript. + * - `memFrames`, `tokens`, `tokenBudget`, `audioMs` — the utterance's size in each unit. + * - `fastFinish`, `lagBudgetMs` — what this binary was compiled with, so a measurement can say + * which build produced it. + * + * Deliberately a string map rather than a typed record: it crosses two more artifacts before + * anything consumes it, and adding a counter must not change a signature along the way. + */ + public fun stats(): Map { + if (handle == 0L) return emptyMap() + val raw = nativeStats(handle) ?: return emptyMap() + if (raw.isEmpty()) return emptyMap() + return raw.split(',').mapNotNull { pair -> + val k = pair.substringBefore('=', "") + if (k.isEmpty() || '=' !in pair) null else k to pair.substringAfter('=') + }.toMap() + } + override fun close() { if (handle != 0L) { nativeDestroy(handle); handle = 0 } } private external fun nativeCreate( @@ -68,6 +99,7 @@ public class IreeMoonshineStream( private external fun nativeFeedPcm(handle: Long, pcm: FloatArray): String? private external fun nativeFinish(handle: Long): String? private external fun nativeReset(handle: Long) + private external fun nativeStats(handle: Long): String? private external fun nativeDestroy(handle: Long) public companion object {