fix: unify log timestamp offsets (#38904) (thanks @sahilsatralkar)

This commit is contained in:
Ayaan Zaidi
2026-03-25 16:04:27 +05:30
parent 3e2e9bc238
commit ee0dcaa7b0
9 changed files with 103 additions and 44 deletions

View File

@@ -117,7 +117,7 @@ describe("logs cli", () => {
it("formats UTC timestamp in pretty mode", () => {
const result = formatLogTimestamp("2025-01-01T12:00:00.000Z", "pretty");
expect(result).toBe("12:00:00");
expect(result).toBe("12:00:00+00:00");
});
it("formats local time in plain mode when localTime is true", () => {
@@ -132,13 +132,8 @@ describe("logs cli", () => {
it("formats local time in pretty mode when localTime is true", () => {
const utcTime = "2025-01-01T12:00:00.000Z";
const result = formatLogTimestamp(utcTime, "pretty", true);
// Should be HH:MM:SS format
expect(result).toMatch(/^\d{2}:\d{2}:\d{2}$/);
// Should be different from UTC time (12:00:00) if not in UTC timezone
const tzOffset = new Date(utcTime).getTimezoneOffset();
if (tzOffset !== 0) {
expect(result).not.toBe("12:00:00");
}
// Should be HH:MM:SS±HH:MM format with timezone offset.
expect(result).toMatch(/^\d{2}:\d{2}:\d{2}[+-]\d{2}:\d{2}$/);
});
it.each([

View File

@@ -2,7 +2,7 @@ import { setTimeout as delay } from "node:timers/promises";
import type { Command } from "commander";
import { buildGatewayConnectionDetails } from "../gateway/call.js";
import { parseLogLine } from "../logging/parse-log-line.js";
import { formatLocalIsoWithOffset, isValidTimeZone } from "../logging/timestamps.js";
import { formatTimestamp, isValidTimeZone } from "../logging/timestamps.js";
import { formatDocsLink } from "../terminal/links.js";
import { clearActiveProgressLine } from "../terminal/progress-line.js";
import { createSafeStreamWriter } from "../terminal/stream-writer.js";
@@ -74,16 +74,10 @@ export function formatLogTimestamp(
return value;
}
let timeString: string;
if (localTime) {
timeString = formatLocalIsoWithOffset(parsed);
} else {
timeString = parsed.toISOString();
}
if (mode === "pretty") {
return timeString.slice(11, 19);
return formatTimestamp(parsed, { style: "short", timeZone: localTime ? undefined : "UTC" });
}
return timeString;
return localTime ? formatTimestamp(parsed, { style: "long" }) : parsed.toISOString();
}
function formatLogLine(

View File

@@ -5,7 +5,6 @@
* Consolidates duplicated formatUtcTimestamp / formatZonedTimestamp / resolveExplicitTimezone
* that previously lived in envelope.ts and session-updates.ts.
*/
/**
* Validate an IANA timezone string. Returns the string if valid, undefined otherwise.
*/

View File

@@ -29,15 +29,20 @@ describe("formatConsoleTimestamp", () => {
return `${year}-${month}-${day}T${h}:${m}:${s}.${ms}${tzSign}${tzHours}:${tzMinutes}`;
}
it("pretty style returns local HH:MM:SS", () => {
it("pretty style returns local HH:MM:SS with timezone offset", () => {
vi.useFakeTimers();
vi.setSystemTime(new Date("2026-01-17T18:01:02.345Z"));
const result = formatConsoleTimestamp("pretty");
const now = new Date();
expect(result).toBe(
`${pad2(now.getHours())}:${pad2(now.getMinutes())}:${pad2(now.getSeconds())}`,
);
const h = pad2(now.getHours());
const m = pad2(now.getMinutes());
const s = pad2(now.getSeconds());
const tzOffset = now.getTimezoneOffset();
const tzSign = tzOffset <= 0 ? "+" : "-";
const tzHours = pad2(Math.floor(Math.abs(tzOffset) / 60));
const tzMinutes = pad2(Math.abs(tzOffset) % 60);
expect(result).toBe(`${h}:${m}:${s}${tzSign}${tzHours}:${tzMinutes}`);
});
it("compact style returns local ISO-like timestamp with timezone offset", () => {

View File

@@ -8,7 +8,7 @@ import { type LogLevel, normalizeLogLevel } from "./levels.js";
import { getLogger, type LoggerSettings } from "./logger.js";
import { resolveNodeRequireFromMeta } from "./node-require.js";
import { loggingState } from "./state.js";
import { formatLocalIsoWithOffset } from "./timestamps.js";
import { formatLocalIsoWithOffset, formatTimestamp } from "./timestamps.js";
export type ConsoleStyle = "pretty" | "compact" | "json";
type ConsoleSettings = {
@@ -175,10 +175,7 @@ function isEpipeError(err: unknown): boolean {
export function formatConsoleTimestamp(style: ConsoleStyle): string {
const now = new Date();
if (style === "pretty") {
const h = String(now.getHours()).padStart(2, "0");
const m = String(now.getMinutes()).padStart(2, "0");
const s = String(now.getSeconds()).padStart(2, "0");
return `${h}:${m}:${s}`;
return formatTimestamp(now, { style: "short" });
}
return formatLocalIsoWithOffset(now);
}

View File

@@ -13,7 +13,7 @@ import { resolveEnvLogLevelOverride } from "./env-log-level.js";
import { type LogLevel, levelToMinLevel, normalizeLogLevel } from "./levels.js";
import { resolveNodeRequireFromMeta } from "./node-require.js";
import { loggingState } from "./state.js";
import { formatLocalIsoWithOffset } from "./timestamps.js";
import { formatTimestamp } from "./timestamps.js";
type ProcessWithBuiltinModule = NodeJS.Process & {
getBuiltinModule?: (id: string) => unknown;
@@ -185,7 +185,7 @@ function buildLogger(settings: ResolvedSettings): TsLogger<LogObj> {
logger.attachTransport((logObj: LogObj) => {
try {
const time = formatLocalIsoWithOffset(logObj.date ?? new Date());
const time = formatTimestamp(logObj.date ?? new Date(), { style: "long" });
const line = JSON.stringify({ ...logObj, time });
const payload = `${line}\n`;
const payloadBytes = Buffer.byteLength(payload, "utf8");
@@ -194,7 +194,7 @@ function buildLogger(settings: ResolvedSettings): TsLogger<LogObj> {
if (!warnedAboutSizeCap) {
warnedAboutSizeCap = true;
const warningLine = JSON.stringify({
time: formatLocalIsoWithOffset(new Date()),
time: formatTimestamp(new Date(), { style: "long" }),
level: "warn",
subsystem: "logging",
message: `log file size cap reached; suppressing writes file=${settings.file} maxFileBytes=${settings.maxFileBytes}`,

View File

@@ -1,7 +1,7 @@
import * as fs from "node:fs";
import * as path from "node:path";
import { describe, expect, it } from "vitest";
import { formatLocalIsoWithOffset, isValidTimeZone } from "./timestamps.js";
import { formatLocalIsoWithOffset, formatTimestamp, isValidTimeZone } from "./timestamps.js";
describe("formatLocalIsoWithOffset", () => {
const testDate = new Date("2025-01-01T04:00:00.000Z");
@@ -50,6 +50,35 @@ describe("formatLocalIsoWithOffset", () => {
});
});
describe("formatTimestamp", () => {
const testDate = new Date("2024-01-15T14:30:45.123Z");
it("formats short style with explicit UTC offset", () => {
expect(formatTimestamp(testDate, { style: "short", timeZone: "UTC" })).toBe("14:30:45+00:00");
});
it("formats medium style with milliseconds and offset", () => {
expect(formatTimestamp(testDate, { style: "medium", timeZone: "UTC" })).toBe(
"14:30:45.123+00:00",
);
});
it.each(["UTC", "America/New_York", "Europe/Paris"])(
"matches formatLocalIsoWithOffset for long style in %s",
(timeZone) => {
expect(formatTimestamp(testDate, { style: "long", timeZone })).toBe(
formatLocalIsoWithOffset(testDate, timeZone),
);
},
);
it("falls back to a valid offset when the timezone is invalid", () => {
expect(formatTimestamp(testDate, { style: "short", timeZone: "not-a-tz" })).toMatch(
/^\d{2}:\d{2}:\d{2}[+-]\d{2}:\d{2}$/,
);
});
});
describe("isValidTimeZone", () => {
it("returns true for valid IANA timezones", () => {
expect(isValidTimeZone("UTC")).toBe(true);

View File

@@ -7,15 +7,27 @@ export function isValidTimeZone(tz: string): boolean {
}
}
export function formatLocalIsoWithOffset(now: Date, timeZone?: string): string {
const explicit = timeZone ?? process.env.TZ;
const tz =
explicit && isValidTimeZone(explicit)
? explicit
: Intl.DateTimeFormat().resolvedOptions().timeZone;
export type TimestampStyle = "short" | "medium" | "long";
export type FormatTimestampOptions = {
style?: TimestampStyle;
timeZone?: string;
};
function resolveEffectiveTimeZone(timeZone?: string): string {
const explicit = timeZone ?? process.env.TZ;
return explicit && isValidTimeZone(explicit)
? explicit
: Intl.DateTimeFormat().resolvedOptions().timeZone;
}
function formatOffset(offsetRaw: string): string {
return offsetRaw === "GMT" ? "+00:00" : offsetRaw.slice(3);
}
function getTimestampParts(date: Date, timeZone?: string) {
const fmt = new Intl.DateTimeFormat("en", {
timeZone: tz,
timeZone: resolveEffectiveTimeZone(timeZone),
year: "numeric",
month: "2-digit",
day: "2-digit",
@@ -27,10 +39,37 @@ export function formatLocalIsoWithOffset(now: Date, timeZone?: string): string {
timeZoneName: "longOffset",
});
const parts = Object.fromEntries(fmt.formatToParts(now).map((p) => [p.type, p.value]));
const offsetRaw = parts.timeZoneName ?? "GMT";
const offset = offsetRaw === "GMT" ? "+00:00" : offsetRaw.slice(3);
return `${parts.year}-${parts.month}-${parts.day}T${parts.hour}:${parts.minute}:${parts.second}.${parts.fractionalSecond}${offset}`;
const parts = Object.fromEntries(fmt.formatToParts(date).map((part) => [part.type, part.value]));
return {
year: parts.year,
month: parts.month,
day: parts.day,
hour: parts.hour,
minute: parts.minute,
second: parts.second,
fractionalSecond: parts.fractionalSecond,
offset: formatOffset(parts.timeZoneName ?? "GMT"),
};
}
export function formatTimestamp(date: Date, options?: FormatTimestampOptions): string {
const style = options?.style ?? "medium";
const parts = getTimestampParts(date, options?.timeZone);
switch (style) {
case "short":
return `${parts.hour}:${parts.minute}:${parts.second}${parts.offset}`;
case "medium":
return `${parts.hour}:${parts.minute}:${parts.second}.${parts.fractionalSecond}${parts.offset}`;
case "long":
return `${parts.year}-${parts.month}-${parts.day}T${parts.hour}:${parts.minute}:${parts.second}.${parts.fractionalSecond}${parts.offset}`;
}
}
/**
* @deprecated Use formatTimestamp from "./timestamps.js" instead.
* This function will be removed in a future version.
*/
export function formatLocalIsoWithOffset(now: Date, timeZone?: string): string {
return formatTimestamp(now, { style: "long", timeZone });
}