🏗️ Build and Test JellyTau / Run Tests (pull_request) Successful in 22m12s
🏗️ Build and Test JellyTau / Supply Chain (pull_request) Successful in 37s
Traceability Validation / Check Requirement Traces (pull_request) Successful in 11s
🏗️ Build and Test JellyTau / Android Compile Check (pull_request) Successful in 4m10s
The app forgot everything it did the moment it exited. The Rust half
logged through env_logger to stdout only -- invisible to anyone who
launched from a desktop icon, and on Android worse than that: stdout is
not logcat, so the backend produced no visible output at all on the
platform carrying this project's hardest bugs. The autoplay deadlock,
the truncated-stream restart and the background-audio stall were all
diagnosed by talking a user through `adb logcat`, because there was no
other way to see anything. A panic left nothing behind at all.
Logs now go to a size-capped rotating file, to logcat on Android, and to
the webview console in dev. A panic is recorded with its backtrace before
the process dies. The frontend's messages are forwarded into the same
file, so one timeline holds both halves of the app in order -- which is
what makes a race between them legible after the fact, and races between
them are the expensive bug class here.
Redaction runs in the log FORMATTER, not at export time. A credential
sitting in a file on the device is already a disclosure; stripping it on
the way out would be too late. The exporter redacts a second time to
cover files written by builds that predate this. api_key, X-Emby-Token,
Authorization, "AccessToken" and Token="..." all reduce to [REDACTED],
while host, item ids and filenames are deliberately kept -- a log scrubbed
of those is one nobody can debug anything from. Server URLs keep scheme
and host and drop any embedded user:pass@.
Two things the tests caught that review would not have:
- redact_headers recursed on its own output. The replacement keeps the
header NAME, so the next call matched the same header forever; the
test died with a stack overflow. It is a forward scan now.
- The frontend forwarder used `void plugin.error(...)`. `void` discards
a promise's value but not its rejection, so in any webview without
IPC -- a unit test, SSR, a browser preview -- every log line became an
unhandled rejection. 20 of them showed up the first time coverage
ran. Each call now attaches a catch.
Only info and above cross the IPC boundary: debug is per-tick player
state and forwarding it would be thousands of calls a minute for output
nobody reads. A failing forwarder never propagates and never prevents the
console write.
Nothing is transmitted anywhere. The export writes a zip and reports its
path; the user attaches it themselves, which is also what keeps this from
becoming telemetry. An Android share intent is explicitly out of scope --
it is Kotlin work that belongs with the other native code.
The panic hook chains to the previous hook rather than replacing it,
because utils/lock.rs installs a silencing hook around tests that provoke
poisoned locks on purpose.
Spec in docs/specs/diagnostics-and-logging.md; UR-078 / DR-218 / UT-209.
Verified: 1079 frontend tests and the coverage gate, 759 Rust tests,
clippy -D warnings, svelte-check 0 errors, and cargo check for
aarch64-linux-android.
347 lines
13 KiB
TypeScript
347 lines
13 KiB
TypeScript
/**
|
|
* Frontend leveled logging facade.
|
|
*
|
|
* TRACES: | DR-204
|
|
*
|
|
* ## Why this exists
|
|
*
|
|
* The Rust half of the app is disciplined about logging: the `log` crate behind
|
|
* `env_logger`, `LevelFilter::Info` by default, `RUST_LOG` to turn the volume up
|
|
* without a rebuild (see `src-tauri/src/lib.rs`). The frontend had nothing —
|
|
* every `console.log` written during development shipped to end users and ran on
|
|
* every device, forever.
|
|
*
|
|
* This module is the frontend's `log` crate: four levels, a compile-environment
|
|
* default, and a runtime override that is the moral equivalent of `RUST_LOG`.
|
|
*
|
|
* ## Levels
|
|
*
|
|
* `debug < info < warn < error`. A message is emitted when its level is at or
|
|
* above the active level.
|
|
*
|
|
* - **debug** — the default for anything chatty: per-tick state, cache hits,
|
|
* "entered this branch". Dev only.
|
|
* - **info** — lifecycle/state events worth having in a user's console when
|
|
* they are diagnosing something: sign-in, playback start, mode transfer.
|
|
* - **warn** — recovered-from problems. Always emitted.
|
|
* - **error** — failures the user may notice. Always emitted.
|
|
*
|
|
* ## Defaults
|
|
*
|
|
* Dev builds (`import.meta.env.DEV`) default to `debug`; production builds
|
|
* default to `warn`. Production deliberately keeps **warn and error** — this is
|
|
* a user-facing media client talking to a server that may or may not be there,
|
|
* and a silent failure is far worse to support than a noisy console. Only the
|
|
* chatter (`debug`/`info`) is suppressed.
|
|
*
|
|
* ## Runtime override (the `RUST_LOG` equivalent)
|
|
*
|
|
* A user filing a bug can turn verbose logging on in a shipped build without a
|
|
* rebuild, from the webview console:
|
|
*
|
|
* ```js
|
|
* localStorage.setItem("jellytau:logLevel", "debug"); // then reload
|
|
* localStorage.removeItem("jellytau:logLevel"); // back to the default
|
|
* ```
|
|
*
|
|
* The key is read **once at module init** (so the level cannot change halfway
|
|
* through a session and confuse a bug report) and every read is guarded — SSR
|
|
* has no `localStorage`, and a webview with storage disabled *throws* on access
|
|
* rather than returning `null`. Either way we fall back to the build default.
|
|
*
|
|
* ## Scopes
|
|
*
|
|
* `createLogger("VideoPlayer")` replaces the hand-rolled `"[VideoPlayer] …"`
|
|
* prefixes that used to be typed into every call site.
|
|
*
|
|
* ```ts
|
|
* const log = createLogger("VideoPlayer");
|
|
* log.debug("seeking to", position, { mode });
|
|
* ```
|
|
*
|
|
* ## Pass-through, not a wrapper
|
|
*
|
|
* When a level is enabled the call goes straight to `console.*` with the
|
|
* arguments **untouched** — no stringification, no JSON, no cloning — so object
|
|
* references stay live and expandable in devtools. The scope is folded into the
|
|
* leading string argument when there is one (keeping `console` grouping and
|
|
* substitution behaviour intact), and passed as its own leading argument
|
|
* otherwise. `console` is looked up at call time so `vi.spyOn(console, …)` and
|
|
* devtools console overrides still see everything.
|
|
*
|
|
* `debug` maps to `console.log` rather than `console.debug` on purpose:
|
|
* `console.debug` lands in the browser's "Verbose" bucket, which is hidden by
|
|
* default in both Chrome DevTools and the WebKit inspector, so mapping there
|
|
* would make dev logging invisible in exactly the builds that want it.
|
|
*/
|
|
|
|
/** Severity ordering. Higher wins. */
|
|
const LEVEL_RANK = {
|
|
debug: 10,
|
|
info: 20,
|
|
warn: 30,
|
|
error: 40,
|
|
} as const;
|
|
|
|
/** A log level, in the same vocabulary as the Rust `log` crate. */
|
|
export type LogLevel = keyof typeof LEVEL_RANK;
|
|
|
|
/** The `localStorage` key that overrides the build-default level. */
|
|
export const LOG_LEVEL_STORAGE_KEY = "jellytau:logLevel";
|
|
|
|
/** Which `console` method backs each level. See the module header for `debug`. */
|
|
const CONSOLE_METHOD: Record<LogLevel, "log" | "info" | "warn" | "error"> = {
|
|
debug: "log",
|
|
info: "info",
|
|
warn: "warn",
|
|
error: "error",
|
|
};
|
|
|
|
/** A scoped logger. One method per level, all variadic like `console.*`. */
|
|
export interface Logger {
|
|
debug(...args: unknown[]): void;
|
|
info(...args: unknown[]): void;
|
|
warn(...args: unknown[]): void;
|
|
error(...args: unknown[]): void;
|
|
}
|
|
|
|
/**
|
|
* Coerce arbitrary input to a `LogLevel`, or `null` when it is not one.
|
|
* Case- and whitespace-insensitive, because this parses human-typed input.
|
|
*/
|
|
export function parseLogLevel(raw: unknown): LogLevel | null {
|
|
if (typeof raw !== "string") return null;
|
|
const normalised = raw.trim().toLowerCase();
|
|
return normalised in LEVEL_RANK ? (normalised as LogLevel) : null;
|
|
}
|
|
|
|
/**
|
|
* Injected by vite (see `vite.config.js`) from Tauri's `TAURI_ENV_DEBUG`, which
|
|
* the CLI sets while running `beforeBuildCommand`. Undefined outside a Tauri
|
|
* build — a bare `vite build`, or vitest — hence the `typeof` guard.
|
|
*/
|
|
declare const __JT_DEBUG_BUILD__: boolean | undefined;
|
|
|
|
/** Is this bundle inside a *debug* Tauri package (a debug APK, say)? */
|
|
function isDebugBuild(): boolean {
|
|
return typeof __JT_DEBUG_BUILD__ !== "undefined" && __JT_DEBUG_BUILD__ === true;
|
|
}
|
|
|
|
/**
|
|
* The default level, as a pure function of the two build facts it depends on.
|
|
*
|
|
* Split out from {@link defaultLogLevel} so it can be tested — neither
|
|
* `import.meta.env.DEV` nor a vite `define` can be varied from inside a test.
|
|
*
|
|
* 🔴 `isDevServer` alone is not enough. `import.meta.env.DEV` is true only under
|
|
* the vite dev server, and `scripts/build-android.sh` produces the debug APK
|
|
* with a plain `bun run build` — so gating on it silences the debug package as
|
|
* thoroughly as the release one, and `bun run android:logs` stops showing
|
|
* anything from the frontend.
|
|
*/
|
|
export function resolveDefaultLogLevel(isDevServer: boolean, isDebugBuild: boolean): LogLevel {
|
|
return isDevServer || isDebugBuild ? "debug" : "warn";
|
|
}
|
|
|
|
/** The level a build defaults to with no override present. */
|
|
export function defaultLogLevel(): LogLevel {
|
|
return resolveDefaultLogLevel(Boolean(import.meta.env?.DEV), isDebugBuild());
|
|
}
|
|
|
|
/**
|
|
* Read the override from `localStorage`, or `null` when there is none.
|
|
*
|
|
* Never throws. `localStorage` is absent under SSR and *throws on access* in a
|
|
* webview with storage disabled or a blocked third-party context — logging must
|
|
* not be the thing that takes the app down.
|
|
*/
|
|
export function readStoredLogLevel(): LogLevel | null {
|
|
try {
|
|
if (typeof localStorage === "undefined" || localStorage === null) return null;
|
|
return parseLogLevel(localStorage.getItem(LOG_LEVEL_STORAGE_KEY));
|
|
} catch {
|
|
return null;
|
|
}
|
|
}
|
|
|
|
let activeLevel: LogLevel = readStoredLogLevel() ?? defaultLogLevel();
|
|
|
|
/** The level currently in force. */
|
|
export function getLogLevel(): LogLevel {
|
|
return activeLevel;
|
|
}
|
|
|
|
/**
|
|
* Change the active level for the rest of the session.
|
|
*
|
|
* Does **not** persist — write {@link LOG_LEVEL_STORAGE_KEY} for that. Mainly
|
|
* here for tests and for a future settings toggle.
|
|
*/
|
|
export function setLogLevel(level: LogLevel): void {
|
|
activeLevel = level;
|
|
}
|
|
|
|
/**
|
|
* Re-read the override and reapply the build default. Called once implicitly at
|
|
* module init; exposed so tests can exercise the override without a fresh
|
|
* module registry.
|
|
*/
|
|
export function resetLogLevel(): LogLevel {
|
|
activeLevel = readStoredLogLevel() ?? defaultLogLevel();
|
|
return activeLevel;
|
|
}
|
|
|
|
/** Would a message at `level` be emitted right now? */
|
|
export function isLevelEnabled(level: LogLevel): boolean {
|
|
return LEVEL_RANK[level] >= LEVEL_RANK[activeLevel];
|
|
}
|
|
|
|
/**
|
|
* Persisting a copy: forwarding to the Rust log sink.
|
|
*
|
|
* TRACES: UR-078 | DR-204, DR-218
|
|
*
|
|
* The console pass-through above is unchanged and stays the primary path — live,
|
|
* expandable object references in devtools are the whole reason `emit` hands
|
|
* `console` its arguments untouched. But a console nobody can read is worth
|
|
* nothing in a bug report, and on Android nobody can read it at all.
|
|
*
|
|
* So messages are *also* stringified and handed to `tauri-plugin-log`, which
|
|
* writes them to the same rotating file the Rust half writes to. One file, one
|
|
* timeline, both halves of the app in order — which is what makes a race between
|
|
* them (this project's most expensive bug class) legible after the fact.
|
|
*
|
|
* Two deliberate limits:
|
|
*
|
|
* - **`info` and above only.** `debug` is per-tick player state; forwarding it
|
|
* would mean thousands of IPC calls a minute for output nobody reads.
|
|
* - **Never throws into the caller.** A logging failure must not become an
|
|
* application failure, so the forward is fire-and-forget with the rejection
|
|
* swallowed. There is nowhere useful to report a failure to log, anyway.
|
|
*/
|
|
export type LogForwarder = (level: LogLevel, message: string) => void;
|
|
|
|
/** Levels that cross the IPC boundary. */
|
|
const FORWARDED_RANK = LEVEL_RANK.info;
|
|
|
|
/** Should a message at this level be persisted, as opposed to only shown? */
|
|
export function shouldForward(level: LogLevel): boolean {
|
|
return LEVEL_RANK[level] >= FORWARDED_RANK;
|
|
}
|
|
|
|
let forwarder: LogForwarder | null = null;
|
|
let forwarderLoading = false;
|
|
|
|
/**
|
|
* Replace the sink messages are persisted to.
|
|
*
|
|
* Exists for tests, and for any host that wants to capture instead of persist.
|
|
* Passing `null` restores the default (lazy-loaded plugin) behaviour.
|
|
*/
|
|
export function setLogForwarder(next: LogForwarder | null): void {
|
|
forwarder = next;
|
|
}
|
|
|
|
/**
|
|
* Resolve the plugin the first time something needs persisting.
|
|
*
|
|
* Lazy because importing it eagerly would pull a Tauri module into every unit
|
|
* test and into SSR, neither of which has a backend to talk to. The load is
|
|
* attempted once; if it fails (a browser, a test, a webview without the plugin)
|
|
* the app keeps logging to the console and never retries.
|
|
*/
|
|
function ensureForwarder(): void {
|
|
if (forwarder || forwarderLoading) return;
|
|
forwarderLoading = true;
|
|
|
|
import("@tauri-apps/plugin-log")
|
|
.then((plugin) => {
|
|
forwarder = (level, message) => {
|
|
// `.catch(swallow)`, never a bare `void`. These return promises, and a
|
|
// `void promise` discards the *value* while leaving a rejection
|
|
// unhandled — which in a webview with no IPC (a unit test, SSR, a
|
|
// browser preview) turns every log line into an unhandled rejection.
|
|
// A logging failure must stay invisible to the application.
|
|
const swallow = () => {};
|
|
switch (level) {
|
|
case "error":
|
|
plugin.error(message).catch(swallow);
|
|
break;
|
|
case "warn":
|
|
plugin.warn(message).catch(swallow);
|
|
break;
|
|
default:
|
|
plugin.info(message).catch(swallow);
|
|
}
|
|
};
|
|
})
|
|
.catch(() => {
|
|
// No backend here. The console path above still works.
|
|
});
|
|
}
|
|
|
|
/**
|
|
* Render arguments to a single line for the persistent log.
|
|
*
|
|
* The console gets the live values; the file can only hold text. An object that
|
|
* cannot be stringified (a cycle, a DOM node) must not break logging, so it
|
|
* degrades to its type rather than throwing.
|
|
*/
|
|
export function formatForForwarding(tag: string, args: unknown[]): string {
|
|
const rendered = args.map((arg) => {
|
|
if (typeof arg === "string") return arg;
|
|
if (arg instanceof Error) return `${arg.name}: ${arg.message}`;
|
|
try {
|
|
return JSON.stringify(arg) ?? String(arg);
|
|
} catch {
|
|
return `[unserialisable ${typeof arg}]`;
|
|
}
|
|
});
|
|
return `${tag} ${rendered.join(" ")}`;
|
|
}
|
|
|
|
/**
|
|
* Create a logger tagged with `scope`.
|
|
*
|
|
* The scope replaces the `"[Scope] …"` prefixes that used to be hand-written
|
|
* into each call, so call sites pass the message alone.
|
|
*/
|
|
export function createLogger(scope: string): Logger {
|
|
const tag = `[${scope}]`;
|
|
|
|
const emit = (level: LogLevel, args: unknown[]): void => {
|
|
if (!isLevelEnabled(level)) return;
|
|
|
|
// Look `console` up at call time: test spies and devtools overrides replace
|
|
// the method on the object, and a cached reference would bypass them.
|
|
const method = CONSOLE_METHOD[level];
|
|
|
|
// Fold the tag into a leading string so format specifiers (`%s`, `%o`) and
|
|
// multi-line messages still read as one message. Non-string leading args
|
|
// (an Error, an object) are left strictly alone.
|
|
if (typeof args[0] === "string") {
|
|
console[method](`${tag} ${args[0]}`, ...args.slice(1));
|
|
} else {
|
|
console[method](tag, ...args);
|
|
}
|
|
|
|
// ...and a stringified copy into the persistent log. After the console call
|
|
// on purpose: whatever happens here, the developer-facing output has already
|
|
// happened.
|
|
if (!shouldForward(level)) return;
|
|
ensureForwarder();
|
|
try {
|
|
forwarder?.(level, formatForForwarding(tag, args));
|
|
} catch {
|
|
// A failure to log is not a failure worth propagating.
|
|
}
|
|
};
|
|
|
|
return {
|
|
debug: (...args: unknown[]) => emit("debug", args),
|
|
info: (...args: unknown[]) => emit("info", args),
|
|
warn: (...args: unknown[]) => emit("warn", args),
|
|
error: (...args: unknown[]) => emit("error", args),
|
|
};
|
|
}
|