Fix: Log-Zeitstempel in lokaler Zeit (mit Offset) statt UTC
User-Report: Logs zeigten z.B. "17:29:43" obwohl es lokal 19:29:43 war (CEST/UTC+2), weil alle Logger `new Date().toISOString()` (UTC "...Z") nutzten. Neuer Helper logTimestamp() formatiert lokale Zeit mit explizitem Offset (ISO 8601, z.B. "2026-05-31T19:29:43.605+02:00") — menschlich lokal UND weiterhin eindeutig/Date.parse-bar. Angewandt auf alle Log-Zeilen- Writer: item-log, logger (rd_downloader.log), audit-log, rename-log, session-log, package-log, account-rotation-log, trace-log. Interne/API-/Dateinamen-Zeitstempel (debug-server, support-bundle, trace autoDisableAt-Config) bleiben absichtlich UTC. Test: tests/log-timestamp.test.ts (Format + Round-Trip zum selben Instant + lokale Stunde, TZ-unabhaengig). 650 Tests gruen, tsc 9, Build sauber. Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
This commit is contained in:
parent
c4c0110f84
commit
99e4b2b885
@ -1,4 +1,5 @@
|
||||
import fs from "node:fs";
|
||||
import { logTimestamp } from "./log-timestamp";
|
||||
import path from "node:path";
|
||||
import { AsyncLocalStorage } from "node:async_hooks";
|
||||
import type { RotationEvent } from "../shared/types";
|
||||
@ -181,7 +182,7 @@ export function initAccountRotationLog(baseDir: string): void {
|
||||
}
|
||||
fs.appendFileSync(
|
||||
rotationLogPath,
|
||||
`=== Account-Rotation Log Start: ${new Date().toISOString()} ===\n`,
|
||||
`=== Account-Rotation Log Start: ${logTimestamp()} ===\n`,
|
||||
"utf8"
|
||||
);
|
||||
} catch {
|
||||
@ -213,7 +214,7 @@ export function logAccountRotation(
|
||||
if (!fs.existsSync(rotationLogPath)) {
|
||||
fs.writeFileSync(rotationLogPath, "", "utf8");
|
||||
}
|
||||
const head = `${new Date().toISOString()} [${level}] ${provider} | ${accountLabel} | ${event}`;
|
||||
const head = `${logTimestamp()} [${level}] ${provider} | ${accountLabel} | ${event}`;
|
||||
fs.appendFileSync(rotationLogPath, `${head}${formatFields(fields)}\n`, "utf8");
|
||||
} catch {
|
||||
// ignore write errors
|
||||
@ -234,7 +235,7 @@ export function shutdownAccountRotationLog(): void {
|
||||
try {
|
||||
fs.appendFileSync(
|
||||
rotationLogPath,
|
||||
`=== Account-Rotation Log Ende: ${new Date().toISOString()} ===\n`,
|
||||
`=== Account-Rotation Log Ende: ${logTimestamp()} ===\n`,
|
||||
"utf8"
|
||||
);
|
||||
} catch {
|
||||
|
||||
@ -1,4 +1,5 @@
|
||||
import fs from "node:fs";
|
||||
import { logTimestamp } from "./log-timestamp";
|
||||
import path from "node:path";
|
||||
|
||||
type AuditLevel = "INFO" | "WARN" | "ERROR";
|
||||
@ -78,7 +79,7 @@ export function initAuditLog(baseDir: string): void {
|
||||
if (!fs.existsSync(auditLogPath)) {
|
||||
fs.writeFileSync(auditLogPath, "", "utf8");
|
||||
}
|
||||
fs.appendFileSync(auditLogPath, `=== Audit-Log Start: ${new Date().toISOString()} ===\n`, "utf8");
|
||||
fs.appendFileSync(auditLogPath, `=== Audit-Log Start: ${logTimestamp()} ===\n`, "utf8");
|
||||
} catch {
|
||||
auditLogPath = null;
|
||||
}
|
||||
@ -95,7 +96,7 @@ export function logAuditEvent(level: AuditLevel, message: string, fields?: Recor
|
||||
}
|
||||
fs.appendFileSync(
|
||||
auditLogPath,
|
||||
`${new Date().toISOString()} [${level}] ${message}${formatFields(fields)}\n`,
|
||||
`${logTimestamp()} [${level}] ${message}${formatFields(fields)}\n`,
|
||||
"utf8"
|
||||
);
|
||||
} catch {
|
||||
@ -115,7 +116,7 @@ export function shutdownAuditLog(): void {
|
||||
return;
|
||||
}
|
||||
try {
|
||||
fs.appendFileSync(auditLogPath, `=== Audit-Log Ende: ${new Date().toISOString()} ===\n`, "utf8");
|
||||
fs.appendFileSync(auditLogPath, `=== Audit-Log Ende: ${logTimestamp()} ===\n`, "utf8");
|
||||
} catch {
|
||||
// ignore
|
||||
}
|
||||
|
||||
@ -1,4 +1,5 @@
|
||||
import fs from "node:fs";
|
||||
import { logTimestamp } from "./log-timestamp";
|
||||
import path from "node:path";
|
||||
import crypto from "node:crypto";
|
||||
|
||||
@ -166,7 +167,7 @@ export function ensureItemLog(meta: ItemLogMeta): string | null {
|
||||
}
|
||||
if (!initializedThisProcess.has(normalizedItemId)) {
|
||||
initializedThisProcess.add(normalizedItemId);
|
||||
const startedAt = new Date().toISOString();
|
||||
const startedAt = logTimestamp();
|
||||
fs.appendFileSync(
|
||||
logPath,
|
||||
`=== Item-Log Start: ${startedAt} | itemId=${sanitizeFieldValue(String(meta.itemId || ""))} | logKey=${normalizedItemId} | fileName=${sanitizeFieldValue(meta.fileName)} ===\n`,
|
||||
@ -174,7 +175,7 @@ export function ensureItemLog(meta: ItemLogMeta): string | null {
|
||||
);
|
||||
fs.appendFileSync(
|
||||
logPath,
|
||||
`${new Date().toISOString()} [INFO] Item-Kontext initialisiert${formatFields({
|
||||
`${logTimestamp()} [INFO] Item-Kontext initialisiert${formatFields({
|
||||
packageId: meta.packageId,
|
||||
packageName: meta.packageName,
|
||||
fileName: meta.fileName,
|
||||
@ -199,7 +200,7 @@ export function logItemEvent(
|
||||
if (!logPath) {
|
||||
return;
|
||||
}
|
||||
const line = `${new Date().toISOString()} [${level}] ${message}${formatFields(fields)}\n`;
|
||||
const line = `${logTimestamp()} [${level}] ${message}${formatFields(fields)}\n`;
|
||||
appendLine(itemId, line);
|
||||
}
|
||||
|
||||
@ -223,7 +224,7 @@ export function shutdownItemLogs(): void {
|
||||
continue;
|
||||
}
|
||||
try {
|
||||
fs.appendFileSync(logPath, `=== Item-Log Ende: ${new Date().toISOString()} ===\n`, "utf8");
|
||||
fs.appendFileSync(logPath, `=== Item-Log Ende: ${logTimestamp()} ===\n`, "utf8");
|
||||
} catch {
|
||||
// ignore
|
||||
}
|
||||
|
||||
22
src/main/log-timestamp.ts
Normal file
22
src/main/log-timestamp.ts
Normal file
@ -0,0 +1,22 @@
|
||||
/**
|
||||
* Zeitstempel für Log-Dateien in LOKALER Zeit mit explizitem UTC-Offset
|
||||
* (ISO 8601, z. B. "2026-05-31T19:29:43.605+02:00").
|
||||
*
|
||||
* Vorher nutzten alle Logger `new Date().toISOString()` → UTC ("...Z"). Auf einem
|
||||
* CEST-Server (UTC+2) las der User dadurch z. B. "17:29:43" statt der erwarteten
|
||||
* lokalen "19:29:43". Lokale Zeit MIT Offset bleibt eindeutig + maschinell parsebar
|
||||
* (Date.parse versteht den Offset), zeigt dem User aber die Uhrzeit seiner Zeitzone.
|
||||
*/
|
||||
export function logTimestamp(date: Date = new Date()): string {
|
||||
const pad = (value: number, length = 2): string => String(value).padStart(length, "0");
|
||||
// getTimezoneOffset() liefert Minuten, die man zur LOKALEN Zeit ADDIEREN muss, um
|
||||
// UTC zu erhalten — also negiert = Offset der lokalen Zone gegenüber UTC.
|
||||
const offsetMinutes = -date.getTimezoneOffset();
|
||||
const sign = offsetMinutes >= 0 ? "+" : "-";
|
||||
const absOffset = Math.abs(offsetMinutes);
|
||||
const offset = `${sign}${pad(Math.floor(absOffset / 60))}:${pad(absOffset % 60)}`;
|
||||
return (
|
||||
`${date.getFullYear()}-${pad(date.getMonth() + 1)}-${pad(date.getDate())}` +
|
||||
`T${pad(date.getHours())}:${pad(date.getMinutes())}:${pad(date.getSeconds())}.${pad(date.getMilliseconds(), 3)}${offset}`
|
||||
);
|
||||
}
|
||||
@ -1,4 +1,5 @@
|
||||
import fs from "node:fs";
|
||||
import { logTimestamp } from "./log-timestamp";
|
||||
import path from "node:path";
|
||||
|
||||
let logFilePath = path.resolve(process.cwd(), "rd_downloader.log");
|
||||
@ -209,7 +210,7 @@ function ensureExitHook(): void {
|
||||
|
||||
function write(level: "INFO" | "WARN" | "ERROR", message: string): void {
|
||||
ensureExitHook();
|
||||
const line = `${new Date().toISOString()} [${level}] ${message}\n`;
|
||||
const line = `${logTimestamp()} [${level}] ${message}\n`;
|
||||
pendingLines.push(line);
|
||||
pendingChars += line.length;
|
||||
|
||||
|
||||
@ -1,4 +1,5 @@
|
||||
import fs from "node:fs";
|
||||
import { logTimestamp } from "./log-timestamp";
|
||||
import path from "node:path";
|
||||
import crypto from "node:crypto";
|
||||
|
||||
@ -165,7 +166,7 @@ export function ensurePackageLog(meta: PackageLogMeta): string | null {
|
||||
}
|
||||
if (!initializedThisProcess.has(normalizedPackageId)) {
|
||||
initializedThisProcess.add(normalizedPackageId);
|
||||
const startedAt = new Date().toISOString();
|
||||
const startedAt = logTimestamp();
|
||||
fs.appendFileSync(
|
||||
logPath,
|
||||
`=== Paket-Log Start: ${startedAt} | packageId=${sanitizeFieldValue(String(meta.packageId || ""))} | logKey=${normalizedPackageId} | name=${sanitizeFieldValue(meta.name)} ===\n`,
|
||||
@ -173,7 +174,7 @@ export function ensurePackageLog(meta: PackageLogMeta): string | null {
|
||||
);
|
||||
fs.appendFileSync(
|
||||
logPath,
|
||||
`${new Date().toISOString()} [INFO] Paket-Kontext initialisiert${formatFields({
|
||||
`${logTimestamp()} [INFO] Paket-Kontext initialisiert${formatFields({
|
||||
name: meta.name,
|
||||
outputDir: meta.outputDir,
|
||||
extractDir: meta.extractDir
|
||||
@ -197,7 +198,7 @@ export function logPackageEvent(
|
||||
if (!logPath) {
|
||||
return;
|
||||
}
|
||||
const line = `${new Date().toISOString()} [${level}] ${message}${formatFields(fields)}\n`;
|
||||
const line = `${logTimestamp()} [${level}] ${message}${formatFields(fields)}\n`;
|
||||
appendLine(packageId, line);
|
||||
}
|
||||
|
||||
@ -221,7 +222,7 @@ export function shutdownPackageLogs(): void {
|
||||
continue;
|
||||
}
|
||||
try {
|
||||
fs.appendFileSync(logPath, `=== Paket-Log Ende: ${new Date().toISOString()} ===\n`, "utf8");
|
||||
fs.appendFileSync(logPath, `=== Paket-Log Ende: ${logTimestamp()} ===\n`, "utf8");
|
||||
} catch {
|
||||
// ignore
|
||||
}
|
||||
|
||||
@ -1,4 +1,5 @@
|
||||
import fs from "node:fs";
|
||||
import { logTimestamp } from "./log-timestamp";
|
||||
import path from "node:path";
|
||||
|
||||
type RenameLogLevel = "INFO" | "WARN" | "ERROR";
|
||||
@ -78,7 +79,7 @@ export function initRenameLog(baseDir: string): void {
|
||||
if (!fs.existsSync(renameLogPath)) {
|
||||
fs.writeFileSync(renameLogPath, "", "utf8");
|
||||
}
|
||||
fs.appendFileSync(renameLogPath, `=== Rename-Log Start: ${new Date().toISOString()} ===\n`, "utf8");
|
||||
fs.appendFileSync(renameLogPath, `=== Rename-Log Start: ${logTimestamp()} ===\n`, "utf8");
|
||||
} catch {
|
||||
renameLogPath = null;
|
||||
}
|
||||
@ -95,7 +96,7 @@ export function logRenameEvent(level: RenameLogLevel, message: string, fields?:
|
||||
}
|
||||
fs.appendFileSync(
|
||||
renameLogPath,
|
||||
`${new Date().toISOString()} [${level}] ${message}${formatFields(fields)}\n`,
|
||||
`${logTimestamp()} [${level}] ${message}${formatFields(fields)}\n`,
|
||||
"utf8"
|
||||
);
|
||||
} catch {
|
||||
@ -115,7 +116,7 @@ export function shutdownRenameLog(): void {
|
||||
return;
|
||||
}
|
||||
try {
|
||||
fs.appendFileSync(renameLogPath, `=== Rename-Log Ende: ${new Date().toISOString()} ===\n`, "utf8");
|
||||
fs.appendFileSync(renameLogPath, `=== Rename-Log Ende: ${logTimestamp()} ===\n`, "utf8");
|
||||
} catch {
|
||||
// ignore
|
||||
}
|
||||
|
||||
@ -1,4 +1,5 @@
|
||||
import fs from "node:fs";
|
||||
import { logTimestamp } from "./log-timestamp";
|
||||
import path from "node:path";
|
||||
import { setLogListener } from "./logger";
|
||||
|
||||
@ -86,7 +87,7 @@ export function initSessionLog(baseDir: string): void {
|
||||
const timestamp = formatTimestamp();
|
||||
sessionLogPath = path.join(sessionLogsDir, `session_${timestamp}.txt`);
|
||||
|
||||
const isoTimestamp = new Date().toISOString();
|
||||
const isoTimestamp = logTimestamp();
|
||||
try {
|
||||
fs.writeFileSync(sessionLogPath, `=== Session gestartet: ${isoTimestamp} ===\n`, "utf8");
|
||||
} catch {
|
||||
@ -116,7 +117,7 @@ export function shutdownSessionLog(): void {
|
||||
flushPending();
|
||||
|
||||
// Write closing line
|
||||
const isoTimestamp = new Date().toISOString();
|
||||
const isoTimestamp = logTimestamp();
|
||||
try {
|
||||
fs.appendFileSync(sessionLogPath, `=== Session beendet: ${isoTimestamp} ===\n`, "utf8");
|
||||
} catch {
|
||||
|
||||
@ -1,4 +1,5 @@
|
||||
import fs from "node:fs";
|
||||
import { logTimestamp } from "./log-timestamp";
|
||||
import path from "node:path";
|
||||
import { addLogListener, removeLogListener } from "./logger";
|
||||
import type { SupportTraceConfig } from "../shared/types";
|
||||
@ -189,10 +190,10 @@ function disableTraceDueToExpiry(): void {
|
||||
...traceConfig,
|
||||
enabled: false,
|
||||
autoDisableAt: null,
|
||||
updatedAt: new Date().toISOString()
|
||||
updatedAt: logTimestamp()
|
||||
});
|
||||
persistTraceConfig();
|
||||
appendTraceLine(`${new Date().toISOString()} [INFO] [trace] Support-Trace automatisch deaktiviert | reason=expired\n`);
|
||||
appendTraceLine(`${logTimestamp()} [INFO] [trace] Support-Trace automatisch deaktiviert | reason=expired\n`);
|
||||
}
|
||||
|
||||
function scheduleAutoDisable(): void {
|
||||
@ -230,7 +231,7 @@ export function initTraceLog(baseDir: string): void {
|
||||
}
|
||||
traceConfig = loadTraceConfig();
|
||||
persistTraceConfig();
|
||||
fs.appendFileSync(traceLogPath, `=== Trace-Log Start: ${new Date().toISOString()} ===\n`, "utf8");
|
||||
fs.appendFileSync(traceLogPath, `=== Trace-Log Start: ${logTimestamp()} ===\n`, "utf8");
|
||||
} catch {
|
||||
traceLogPath = null;
|
||||
traceConfigPath = null;
|
||||
@ -263,11 +264,11 @@ export function updateTraceConfig(patch: Partial<SupportTraceConfig>): SupportTr
|
||||
traceConfig = normalizeTraceConfig({
|
||||
...traceConfig,
|
||||
...patch,
|
||||
updatedAt: new Date().toISOString()
|
||||
updatedAt: logTimestamp()
|
||||
});
|
||||
persistTraceConfig();
|
||||
scheduleAutoDisable();
|
||||
appendTraceLine(`${new Date().toISOString()} [INFO] [trace] Konfiguration aktualisiert${formatFields(traceConfig as unknown as Record<string, unknown>)}\n`);
|
||||
appendTraceLine(`${logTimestamp()} [INFO] [trace] Konfiguration aktualisiert${formatFields(traceConfig as unknown as Record<string, unknown>)}\n`);
|
||||
return getTraceConfig();
|
||||
}
|
||||
|
||||
@ -276,7 +277,7 @@ export function setTraceEnabled(enabled: boolean, note = "", durationMs: number
|
||||
? new Date(Date.now() + durationMs).toISOString()
|
||||
: null;
|
||||
const next = updateTraceConfig({ enabled, autoDisableAt });
|
||||
appendTraceLine(`${new Date().toISOString()} [INFO] [trace] Support-Trace ${enabled ? "aktiviert" : "deaktiviert"}${formatFields({ note, autoDisableAt })}\n`);
|
||||
appendTraceLine(`${logTimestamp()} [INFO] [trace] Support-Trace ${enabled ? "aktiviert" : "deaktiviert"}${formatFields({ note, autoDisableAt })}\n`);
|
||||
return next;
|
||||
}
|
||||
|
||||
@ -292,7 +293,7 @@ export function logTraceEvent(
|
||||
if (category === "audit" && !traceConfig.includeAudit) {
|
||||
return;
|
||||
}
|
||||
appendTraceLine(`${new Date().toISOString()} [${level}] [${category}] ${message}${formatFields(fields)}\n`);
|
||||
appendTraceLine(`${logTimestamp()} [${level}] [${category}] ${message}${formatFields(fields)}\n`);
|
||||
}
|
||||
|
||||
export function shutdownTraceLog(): void {
|
||||
@ -307,7 +308,7 @@ export function shutdownTraceLog(): void {
|
||||
}
|
||||
flushPending();
|
||||
try {
|
||||
fs.appendFileSync(traceLogPath, `=== Trace-Log Ende: ${new Date().toISOString()} ===\n`, "utf8");
|
||||
fs.appendFileSync(traceLogPath, `=== Trace-Log Ende: ${logTimestamp()} ===\n`, "utf8");
|
||||
} catch {
|
||||
// ignore
|
||||
}
|
||||
|
||||
28
tests/log-timestamp.test.ts
Normal file
28
tests/log-timestamp.test.ts
Normal file
@ -0,0 +1,28 @@
|
||||
import { describe, expect, it } from "vitest";
|
||||
import { logTimestamp } from "../src/main/log-timestamp";
|
||||
|
||||
describe("logTimestamp", () => {
|
||||
it("formats local time with an explicit UTC offset (ISO 8601), not a UTC 'Z' string", () => {
|
||||
const instant = new Date("2026-05-31T17:29:43.605Z");
|
||||
const formatted = logTimestamp(instant);
|
||||
|
||||
// Shape: YYYY-MM-DDTHH:MM:SS.mmm±HH:MM
|
||||
expect(formatted).toMatch(/^\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}\.\d{3}[+-]\d{2}:\d{2}$/);
|
||||
// The whole point: NOT the old UTC "...Z" format that showed 17:29 instead of 19:29.
|
||||
expect(formatted.endsWith("Z")).toBe(false);
|
||||
});
|
||||
|
||||
it("is parseable back to the exact same instant (offset keeps it unambiguous)", () => {
|
||||
const instant = new Date("2026-05-31T17:29:43.605Z");
|
||||
// Date.parse must still recover the identical instant (trace-log autoDisableAt etc.).
|
||||
expect(new Date(logTimestamp(instant)).getTime()).toBe(instant.getTime());
|
||||
});
|
||||
|
||||
it("shows the LOCAL wall-clock hour (machine-timezone-independent assertion)", () => {
|
||||
const instant = new Date("2026-05-31T17:29:43.605Z");
|
||||
const formatted = logTimestamp(instant);
|
||||
// Hour segment must equal the local getHours() of the same instant — i.e. the
|
||||
// user's wall clock, whatever the server timezone is.
|
||||
expect(formatted.slice(11, 13)).toBe(String(instant.getHours()).padStart(2, "0"));
|
||||
});
|
||||
});
|
||||
Loading…
Reference in New Issue
Block a user