Harden timestamp edge cases
This commit is contained in:
@@ -27,30 +27,34 @@ function formatLogTimestamp(timestamp = Date.now()) {
|
||||
return `${date.getFullYear()}-${pad(date.getMonth() + 1)}-${pad(date.getDate())} ${pad(date.getHours())}:${pad(date.getMinutes())}:${pad(date.getSeconds())}`;
|
||||
}
|
||||
|
||||
function createLineTimestampPrefixer(opts = {}) {
|
||||
function createRenderedLineTimestampPrefixer(opts = {}) {
|
||||
const timestampProvider = typeof opts.timestampProvider === "function"
|
||||
? opts.timestampProvider
|
||||
: Date.now;
|
||||
let atLineStart = true;
|
||||
const timestampsByLine = [];
|
||||
const contentByLine = [];
|
||||
|
||||
return (chunk) => {
|
||||
if (!chunk) return "";
|
||||
return (content) => {
|
||||
if (!content) return "";
|
||||
|
||||
let output = "";
|
||||
for (const char of chunk) {
|
||||
if (atLineStart) {
|
||||
const timestamp = timestampProvider() ?? Date.now();
|
||||
output += `[${formatLogTimestamp(timestamp)}] `;
|
||||
atLineStart = false;
|
||||
const lines = content.split("\n");
|
||||
timestampsByLine.length = lines.length;
|
||||
contentByLine.length = lines.length;
|
||||
|
||||
return lines.map((line, index) => {
|
||||
if (line.length === 0 && index === lines.length - 1 && content.endsWith("\n")) {
|
||||
return line;
|
||||
}
|
||||
|
||||
output += char;
|
||||
if (char === "\n") {
|
||||
atLineStart = true;
|
||||
if (contentByLine[index] !== line) {
|
||||
contentByLine[index] = line;
|
||||
timestampsByLine[index] = timestampProvider() ?? Date.now();
|
||||
}
|
||||
}
|
||||
|
||||
return output;
|
||||
return line.length === 0
|
||||
? line
|
||||
: `[${formatLogTimestamp(timestampsByLine[index])}] ${line}`;
|
||||
}).join("\n");
|
||||
};
|
||||
}
|
||||
|
||||
@@ -123,8 +127,8 @@ function startStream(sessionId, opts) {
|
||||
isRaw,
|
||||
isHtml,
|
||||
renderer: isRaw ? null : createTerminalTextRenderer(),
|
||||
timestampPrefixer: !isRaw && opts.timestampsEnabled
|
||||
? createLineTimestampPrefixer({ timestampProvider: opts.timestampProvider })
|
||||
renderedTimestampPrefixer: !isRaw && opts.timestampsEnabled
|
||||
? createRenderedLineTimestampPrefixer({ timestampProvider: opts.timestampProvider })
|
||||
: null,
|
||||
hostLabel: hostLabel || hostname || "unknown",
|
||||
startTime: startTime || Date.now(),
|
||||
@@ -179,9 +183,15 @@ function flushBuffer(entry) {
|
||||
function renderSnapshotContent(entry, { finalize = false } = {}) {
|
||||
if (finalize) entry.renderer.finish();
|
||||
const renderOptions = finalize ? undefined : { includePendingClearedScreen: true };
|
||||
return entry.isHtml
|
||||
? wrapTerminalHtmlContent(entry.renderer.toHtmlContent(renderOptions), entry.hostLabel, entry.startTime)
|
||||
const renderedContent = entry.isHtml
|
||||
? entry.renderer.toHtmlContent(renderOptions)
|
||||
: entry.renderer.toString(renderOptions);
|
||||
const content = entry.renderedTimestampPrefixer
|
||||
? entry.renderedTimestampPrefixer(renderedContent)
|
||||
: renderedContent;
|
||||
return entry.isHtml
|
||||
? wrapTerminalHtmlContent(content, entry.hostLabel, entry.startTime)
|
||||
: content;
|
||||
}
|
||||
|
||||
function scheduleSnapshot(entry) {
|
||||
@@ -225,10 +235,7 @@ function appendData(sessionId, dataChunk) {
|
||||
const entry = activeStreams.get(sessionId);
|
||||
if (!entry || entry.disabled) return;
|
||||
|
||||
const data = entry.timestampPrefixer
|
||||
? entry.timestampPrefixer(dataChunk)
|
||||
: dataChunk;
|
||||
entry.buffer += data;
|
||||
entry.buffer += dataChunk;
|
||||
|
||||
// Immediate flush if buffer is large
|
||||
if (entry.buffer.length >= MAX_BUFFER_SIZE) {
|
||||
|
||||
@@ -198,6 +198,68 @@ test("txt stream timestamps complete lines without duplicating split chunks", as
|
||||
}
|
||||
});
|
||||
|
||||
test("txt stream timestamps rendered lines after carriage-return rewrites", async () => {
|
||||
const directory = path.join(TEMP_ROOT, `stream-timestamps-cr-${Date.now()}-${Math.random().toString(16).slice(2)}`);
|
||||
const sessionId = `session-${Date.now()}-${Math.random().toString(16).slice(2)}`;
|
||||
|
||||
try {
|
||||
startStream(sessionId, {
|
||||
hostLabel: "host",
|
||||
hostname: "host.example",
|
||||
directory,
|
||||
format: "txt",
|
||||
startTime: Date.UTC(2026, 0, 2, 3, 4, 5),
|
||||
timestampsEnabled: true,
|
||||
timestampProvider: () => new Date(2026, 0, 2, 3, 4, 5).getTime(),
|
||||
});
|
||||
appendData(sessionId, "old prompt\rdocker denied\n");
|
||||
|
||||
const filePath = await stopStream(sessionId);
|
||||
|
||||
assert.equal(
|
||||
fs.readFileSync(filePath, "utf8"),
|
||||
"[2026-01-02 03:04:05] docker denied",
|
||||
);
|
||||
} finally {
|
||||
await stopStream(sessionId);
|
||||
fs.rmSync(directory, { recursive: true, force: true });
|
||||
}
|
||||
});
|
||||
|
||||
test("txt stream updates a line timestamp when a later snapshot rewrites that line", async () => {
|
||||
const directory = path.join(TEMP_ROOT, `stream-timestamps-live-cr-${Date.now()}-${Math.random().toString(16).slice(2)}`);
|
||||
const sessionId = `session-${Date.now()}-${Math.random().toString(16).slice(2)}`;
|
||||
const times = [
|
||||
new Date(2026, 0, 2, 3, 4, 5).getTime(),
|
||||
new Date(2026, 0, 2, 3, 4, 6).getTime(),
|
||||
];
|
||||
|
||||
try {
|
||||
startStream(sessionId, {
|
||||
hostLabel: "host",
|
||||
hostname: "host.example",
|
||||
directory,
|
||||
format: "txt",
|
||||
startTime: Date.UTC(2026, 0, 2, 3, 4, 5),
|
||||
timestampsEnabled: true,
|
||||
timestampProvider: () => times.shift(),
|
||||
});
|
||||
appendData(sessionId, "old prompt");
|
||||
await waitForFileContent(directory, "[2026-01-02 03:04:05] old prompt");
|
||||
appendData(sessionId, "\rdocker denied");
|
||||
|
||||
const filePath = await stopStream(sessionId);
|
||||
|
||||
assert.equal(
|
||||
fs.readFileSync(filePath, "utf8"),
|
||||
"[2026-01-02 03:04:06] docker denied",
|
||||
);
|
||||
} finally {
|
||||
await stopStream(sessionId);
|
||||
fs.rmSync(directory, { recursive: true, force: true });
|
||||
}
|
||||
});
|
||||
|
||||
test("html stream includes line timestamps in rendered content", async () => {
|
||||
const directory = path.join(TEMP_ROOT, `stream-html-timestamps-${Date.now()}-${Math.random().toString(16).slice(2)}`);
|
||||
const sessionId = `session-${Date.now()}-${Math.random().toString(16).slice(2)}`;
|
||||
@@ -224,6 +286,33 @@ test("html stream includes line timestamps in rendered content", async () => {
|
||||
}
|
||||
});
|
||||
|
||||
test("html stream timestamps rendered lines after carriage-return rewrites", async () => {
|
||||
const directory = path.join(TEMP_ROOT, `stream-html-timestamps-cr-${Date.now()}-${Math.random().toString(16).slice(2)}`);
|
||||
const sessionId = `session-${Date.now()}-${Math.random().toString(16).slice(2)}`;
|
||||
|
||||
try {
|
||||
startStream(sessionId, {
|
||||
hostLabel: "host",
|
||||
hostname: "host.example",
|
||||
directory,
|
||||
format: "html",
|
||||
startTime: Date.UTC(2026, 0, 2, 3, 4, 5),
|
||||
timestampsEnabled: true,
|
||||
timestampProvider: () => new Date(2026, 0, 2, 3, 4, 5).getTime(),
|
||||
});
|
||||
appendData(sessionId, "old prompt\rdocker denied\n");
|
||||
|
||||
const filePath = await stopStream(sessionId);
|
||||
const html = fs.readFileSync(filePath, "utf8");
|
||||
|
||||
assert.match(html, /\[2026-01-02 03:04:05\] docker denied/);
|
||||
assert.doesNotMatch(html, /old prompt/);
|
||||
} finally {
|
||||
await stopStream(sessionId);
|
||||
fs.rmSync(directory, { recursive: true, force: true });
|
||||
}
|
||||
});
|
||||
|
||||
test("raw stream keeps original bytes when timestamps are enabled", async () => {
|
||||
const directory = path.join(TEMP_ROOT, `stream-raw-timestamps-${Date.now()}-${Math.random().toString(16).slice(2)}`);
|
||||
const sessionId = `session-${Date.now()}-${Math.random().toString(16).slice(2)}`;
|
||||
|
||||
Reference in New Issue
Block a user