fix(rivetkit): align logs with engine logfmt

Author: NathanFlurry

Cargo.lock

@@ -20,6 +20,8 @@ anyhow.workspace = true
 serde.workspace = true
 serde_json.workspace = true
 tracing.workspace = true
+tracing-logfmt.workspace = true
+tracing-stackdriver.workspace = true
 tracing-subscriber.workspace = true
 parking_lot.workspace = true
 scc.workspace = true

rivetkit-typescript/packages/rivetkit-napi/Cargo.toml

@@ -15,10 +15,30 @@ use std::sync::Once;
 
 use rivet_error::RivetError as RivetTransportError;
 use rivetkit_core::error::public_error_status_code;
+use tracing_subscriber::{layer::SubscriberExt, util::SubscriberInitExt};
 
 static INIT_TRACING: Once = Once::new();
 pub(crate) const BRIDGE_RIVET_ERROR_PREFIX: &str = "__RIVET_ERROR_JSON__:";
 
+#[derive(Debug, Clone, Copy, PartialEq, Eq)]
+enum LogFormat {
+	Logfmt,
+	Gcp,
+}
+
+impl LogFormat {
+	fn from_env() -> Self {
+		match std::env::var("RUST_LOG_FORMAT")
+			.unwrap_or_default()
+			.to_lowercase()
+			.as_str()
+		{
+			"gcp" => LogFormat::Gcp,
+			_ => LogFormat::Logfmt,
+		}
+	}
+}
+
 #[derive(rivet_error::RivetError, serde::Serialize)]
 #[error(
 	"napi",
@@ -105,13 +125,34 @@ pub(crate) fn init_tracing(log_level: Option<&str>) {
 			.or_else(|| std::env::var("RUST_LOG").ok())
 			.unwrap_or_else(|| "warn".to_string());
 
-		tracing_subscriber::fmt()
-			.json()
-			.with_env_filter(tracing_subscriber::EnvFilter::new(&filter))
-			.with_target(true)
-			.with_current_span(true)
-			.with_span_list(false)
-			.with_writer(std::io::stdout)
+		let log_format = LogFormat::from_env();
+
+		tracing_subscriber::registry()
+			.with(tracing_subscriber::EnvFilter::new(&filter))
+			.with(match log_format {
+				LogFormat::Logfmt => Some(
+					tracing_logfmt::builder()
+						.with_span_name(env_flag("RUST_LOG_SPAN_NAME"))
+						.with_span_path(env_flag("RUST_LOG_SPAN_PATH"))
+						.with_target(env_flag("RUST_LOG_TARGET") || env_flag("RIVET_LOG_TARGET"))
+						.with_location(env_flag("RUST_LOG_LOCATION"))
+						.with_module_path(env_flag("RUST_LOG_MODULE_PATH"))
+						.with_ansi_color(env_flag("RUST_LOG_ANSI_COLOR"))
+						.layer(),
+				),
+				LogFormat::Gcp => None,
+			})
+			.with(match log_format {
+				LogFormat::Logfmt => None,
+				LogFormat::Gcp => Some(
+					tracing_stackdriver::layer()
+						.with_source_location(env_flag("RUST_LOG_LOCATION")),
+				),
+			})
 			.init();
 	});
 }
+
+fn env_flag(name: &str) -> bool {
+	std::env::var(name).map_or(false, |x| x == "1")
+}

rivetkit-typescript/packages/rivetkit-napi/src/lib.rs

@@ -1,4 +1,5 @@
 import {
+	type DestinationStream,
 	type LevelWithSilent,
 	type Logger,
 	pino,
@@ -69,19 +70,22 @@ export function configureDefaultLogger(logLevel?: LogLevel) {
 		configuredLogLevel = logLevel;
 	}
 
-	baseLogger = pino({
-		level: getPinoLevel(logLevel),
-		messageKey: "msg",
-		// Do not include pid/hostname in output
-		base: {},
-		// Keep a string level in the output
-		formatters: {
-			level(_label: string, number: number) {
-				return { level: number };
+	baseLogger = pino(
+		{
+			level: getPinoLevel(logLevel),
+			messageKey: "msg",
+			// Do not include pid/hostname in output
+			base: {},
+			// Keep the numeric level so the logfmt sink can match Pino's levels.
+			formatters: {
+				level(_label: string, number: number) {
+					return { level: number };
+				},
 			},
+			timestamp: getLogTimestamp() ? stdTimeFunctions.epochTime : false,
 		},
-		timestamp: getLogTimestamp() ? stdTimeFunctions.epochTime : false,
-	});
+		createLogfmtDestination(),
+	);
 
 	loggerCache.clear();
 }
@@ -117,3 +121,95 @@ export function getLogger(name = "default"): Logger {
 
 	return child;
 }
+
+const PINO_LEVEL_LABELS: Record<number, string> = {
+	10: "trace",
+	20: "debug",
+	30: "info",
+	40: "warn",
+	50: "error",
+	60: "fatal",
+};
+
+function createLogfmtDestination(): DestinationStream {
+	return {
+		write(msg: string): void {
+			const line = formatLogfmtLine(msg);
+			if (typeof process !== "undefined" && process.stdout?.write) {
+				process.stdout.write(`${line}\n`);
+			} else {
+				console.log(line);
+			}
+		},
+	};
+}
+
+function formatLogfmtLine(raw: string): string {
+	let data: Record<string, unknown>;
+	try {
+		data = JSON.parse(raw);
+	} catch {
+		return raw.trimEnd();
+	}
+
+	const parts: string[] = [];
+	appendLogfmtEntry(parts, "level", formatPinoLevel(data.level));
+
+	if (data.time !== undefined) {
+		appendLogfmtEntry(parts, "ts", data.time);
+	}
+
+	for (const [key, value] of Object.entries(data)) {
+		if (key === "level" || key === "time") {
+			continue;
+		}
+		appendLogfmtEntry(parts, key, value);
+	}
+
+	return parts.join(" ");
+}
+
+function formatPinoLevel(level: unknown): string {
+	if (typeof level === "number") {
+		return PINO_LEVEL_LABELS[level] ?? level.toString();
+	}
+
+	if (typeof level === "string") {
+		return level.toLowerCase();
+	}
+
+	return "info";
+}
+
+function appendLogfmtEntry(parts: string[], key: string, value: unknown): void {
+	const safeKey = key.replace(/[\s="]/g, "");
+	if (safeKey.length === 0) {
+		return;
+	}
+
+	parts.push(`${safeKey}=${formatLogfmtValue(value)}`);
+}
+
+function formatLogfmtValue(value: unknown): string {
+	if (typeof value === "number" || typeof value === "boolean") {
+		return String(value);
+	}
+
+	if (value === null || value === undefined) {
+		return "null";
+	}
+
+	if (typeof value === "string") {
+		return quoteLogfmtString(value);
+	}
+
+	return quoteLogfmtString(JSON.stringify(value));
+}
+
+function quoteLogfmtString(value: string): string {
+	if (!/[\s="]/.test(value)) {
+		return value;
+	}
+
+	return `"${value.replace(/\\/g, "\\\\").replace(/"/g, '\\"').replace(/\n/g, "\\n")}"`;
+}