Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
8 changes: 8 additions & 0 deletions .changeset/patch-agent-log-token-delta.md

Some generated files are not rendered by default. Learn more about how customized files appear on GitHub.

111 changes: 105 additions & 6 deletions actions/setup/js/parse_mcp_gateway_log.cjs
Original file line number Diff line number Diff line change
Expand Up @@ -572,15 +572,87 @@ function buildRpcSummaryRow(cells) {
return `| ${cells.map(cell => escapeMarkdownTableCell(cell)).join(" | ")} |`;
}

/**
* Computes effective-token deltas for each REQUEST entry relative to the surrounding
* LLM API calls recorded in token-usage.jsonl.
*
* For each request at timestamp T, the algorithm finds:
* - prev: the last token-usage entry with timestamp < T
* - next: the first token-usage entry with timestamp > T
* and returns delta = effectiveTokens(next) − effectiveTokens(prev).
*
* @param {string} tokenUsageContent - Raw content of token-usage.jsonl
* @param {Array<Object>} requests - REQUEST entries from rpc-messages.jsonl
* @returns {Map<number, number>} Map from request index to ΔET (omits entries with delta ≤ 0)
*/
function computeToolCallTokenDeltas(tokenUsageContent, requests) {
const deltas = new Map();
if (!tokenUsageContent || !requests || requests.length === 0) return deltas;

// Parse and sort token-usage entries by timestamp
/** @type {Array<{ts: number, et: number}>} */
const etEntries = [];
for (const line of tokenUsageContent.split("\n")) {
const trimmed = line.trim();
if (!trimmed) continue;
try {
const entry = JSON.parse(trimmed);
if (!entry || typeof entry !== "object" || !entry.timestamp) continue;
const ts = new Date(entry.timestamp).getTime();
if (isNaN(ts)) continue;
const et = computeEffectiveTokens(
entry.model || "",
entry.input_tokens || 0,
entry.output_tokens || 0,
entry.cache_read_tokens || 0,
entry.cache_write_tokens || 0
);
etEntries.push({ ts, et });
} catch {
// skip malformed lines
}
}

etEntries.sort((a, b) => a.ts - b.ts);
if (etEntries.length < 2) return deltas;

for (let i = 0; i < requests.length; i++) {
const req = requests[i];
if (!req.timestamp) continue;
const callTs = new Date(req.timestamp).getTime();
if (isNaN(callTs)) continue;

let prevIdx = -1;
let nextIdx = -1;
for (let j = 0; j < etEntries.length; j++) {
if (etEntries[j].ts < callTs) {
prevIdx = j; // keep updating to get the last one before callTs
} else if (etEntries[j].ts > callTs && nextIdx === -1) {
nextIdx = j; // first entry after callTs
}
}
Comment on lines +619 to +633

if (prevIdx === -1 || nextIdx === -1) continue;

const delta = etEntries[nextIdx].et - etEntries[prevIdx].et;
if (delta > 0) {
deltas.set(i, delta);
}
}

return deltas;
}

/**
* Generates a markdown step summary for rpc-messages.jsonl entries (mcpg v0.2.0+ format).
* Shows a table of REQUEST entries (tool calls), a count of RESPONSE entries, any other
* message types, and the DIFC_FILTERED section if there are blocked events.
* @param {{requests: Array<Object>, responses: Array<Object>, other: Array<Object>}} entries
* @param {Array<Object>} difcFilteredEvents - DIFC_FILTERED events parsed separately
* @param {Map<number, number>} [tokenDeltas] - Optional map of request index → ΔET
* @returns {string} Markdown summary, or empty string if nothing to show
*/
function generateRpcMessagesSummary(entries, difcFilteredEvents) {
function generateRpcMessagesSummary(entries, difcFilteredEvents, tokenDeltas) {
const { requests, responses, other } = entries;
const blockedCount = difcFilteredEvents ? difcFilteredEvents.length : 0;
const totalMessages = requests.length + responses.length + other.length + blockedCount;
Expand Down Expand Up @@ -622,16 +694,29 @@ function generateRpcMessagesSummary(entries, difcFilteredEvents) {
callLines.push("");

if (requests.length > 0) {
const hasDeltas = tokenDeltas && tokenDeltas.size > 0;
callLines.push("#### REQUEST");
callLines.push("");
callLines.push("| Time | Server | Tool / Method |");
callLines.push("|------|--------|---------------|");
if (hasDeltas) {
callLines.push("| Time | Server | Tool / Method | ΔET |");
callLines.push("|------|--------|---------------|----:|");
} else {
callLines.push("| Time | Server | Tool / Method |");
callLines.push("|------|--------|---------------|");
}

for (const req of requests) {
for (let i = 0; i < requests.length; i++) {
const req = requests[i];
const time = formatRpcMessageTime(req.timestamp);
const server = escapeMarkdownTableCell(req.server_id || "-");
const label = formatRpcInlineCodeLabel(getRpcRequestLabel(req));
callLines.push(`| ${time} | ${server} | ${label} |`);
if (hasDeltas) {
const delta = tokenDeltas.get(i);
const deltaCell = delta ? `+${delta.toLocaleString()}` : "-";
callLines.push(`| ${time} | ${server} | ${label} | ${escapeMarkdownTableCell(deltaCell)} |`);
} else {
callLines.push(`| ${time} | ${server} | ${label} |`);
}
}

callLines.push("");
Expand Down Expand Up @@ -766,7 +851,20 @@ async function main() {
core.info(`rpc-messages.jsonl: ${rpcEntries.requests.length} request(s), ${rpcEntries.responses.length} response(s), ${rpcEntries.other.length} other, ${difcFilteredEvents.length} DIFC_FILTERED`);

if (totalMessages > 0 || difcFilteredEvents.length > 0) {
const rpcSummary = generateRpcMessagesSummary(rpcEntries, difcFilteredEvents);
// Compute effective-token deltas by correlating request timestamps with token-usage.jsonl
let tokenDeltas = new Map();
if (fs.existsSync(TOKEN_USAGE_PATH) && rpcEntries.requests.length > 0) {
try {
const tokenUsageContent = fs.readFileSync(TOKEN_USAGE_PATH, "utf8");
tokenDeltas = computeToolCallTokenDeltas(tokenUsageContent, rpcEntries.requests);
if (tokenDeltas.size > 0) {
core.info(`Computed effective-token deltas for ${tokenDeltas.size} of ${rpcEntries.requests.length} request(s)`);
}
} catch {
// Non-fatal: delta column is omitted when token-usage.jsonl is unreadable
}
}
const rpcSummary = generateRpcMessagesSummary(rpcEntries, difcFilteredEvents, tokenDeltas);
if (rpcSummary.length > 0) {
core.summary.addRaw(rpcSummary);
}
Expand Down Expand Up @@ -949,6 +1047,7 @@ if (typeof module !== "undefined" && module.exports) {
parseRpcMessagesJsonl,
getRpcRequestLabel,
generateRpcMessagesSummary,
computeToolCallTokenDeltas,
printAllGatewayFiles,
parseTokenUsageJsonl,
generateTokenUsageSummary,
Expand Down
105 changes: 105 additions & 0 deletions actions/setup/js/parse_mcp_gateway_log.test.cjs
Original file line number Diff line number Diff line change
Expand Up @@ -12,6 +12,7 @@ const {
parseRpcMessagesJsonl,
getRpcRequestLabel,
generateRpcMessagesSummary,
computeToolCallTokenDeltas,
printAllGatewayFiles,
parseTokenUsageJsonl,
generateTokenUsageSummary,
Expand Down Expand Up @@ -1477,4 +1478,108 @@ not-json
expect(hasError).toBe(false);
});
});

describe("computeToolCallTokenDeltas", () => {
// Helper to build a token-usage JSONL line
function tuLine(ts, inputTokens, outputTokens) {
return JSON.stringify({ timestamp: ts, model: "unknown", provider: "test", input_tokens: inputTokens, output_tokens: outputTokens, cache_read_tokens: 0, cache_write_tokens: 0 });
}
// Helper to build a REQUEST entry
function req(ts, toolName) {
return { timestamp: ts, server_id: "srv", type: "REQUEST", payload: { method: "tools/call", params: { name: toolName } } };
}

test("computes delta for a tool call bracketed by two API calls", () => {
// ET(t0) = 1*1000 + 4*50 = 1200; ET(t1) = 1*1500 + 4*80 = 1820; delta = 620
const tokenContent = [
tuLine("2026-05-19T21:10:00.000Z", 1000, 50),
tuLine("2026-05-19T21:10:10.000Z", 1500, 80),
].join("\n");
const requests = [req("2026-05-19T21:10:05.000Z", "my-tool")];
const deltas = computeToolCallTokenDeltas(tokenContent, requests);
expect(deltas.get(0)).toBe(620);
});

test("returns empty map when tool call has no preceding API call", () => {
const tokenContent = tuLine("2026-05-19T21:10:10.000Z", 1000, 50);
const requests = [req("2026-05-19T21:10:05.000Z", "my-tool")];
const deltas = computeToolCallTokenDeltas(tokenContent, requests);
expect(deltas.size).toBe(0);
});

test("returns empty map when tool call has no following API call", () => {
const tokenContent = tuLine("2026-05-19T21:10:00.000Z", 1000, 50);
const requests = [req("2026-05-19T21:10:05.000Z", "my-tool")];
const deltas = computeToolCallTokenDeltas(tokenContent, requests);
expect(deltas.size).toBe(0);
});

test("returns empty map for empty inputs", () => {
expect(computeToolCallTokenDeltas("", []).size).toBe(0);
expect(computeToolCallTokenDeltas("", null).size).toBe(0);
});

test("computes correct deltas for multiple sequential tool calls", () => {
// ET[0] = 1200, ET[1] = 1820, ET[2] = 2400
const tokenContent = [
tuLine("2026-05-19T21:10:00.000Z", 1000, 50),
tuLine("2026-05-19T21:10:10.000Z", 1500, 80),
tuLine("2026-05-19T21:10:20.000Z", 2000, 100),
].join("\n");
const requests = [
req("2026-05-19T21:10:05.000Z", "tool-a"),
req("2026-05-19T21:10:15.000Z", "tool-b"),
];
const deltas = computeToolCallTokenDeltas(tokenContent, requests);
expect(deltas.get(0)).toBe(620); // 1820 - 1200
expect(deltas.get(1)).toBe(580); // 2400 - 1820
});
});

describe("generateRpcMessagesSummary with token deltas", () => {
test("shows ΔET column when deltas are provided", () => {
const entries = {
requests: [
{ timestamp: "2026-05-19T21:10:05.123Z", server_id: "srv", type: "REQUEST", payload: { method: "tools/call", params: { name: "my-tool" } } },
],
responses: [],
other: [],
};
const deltas = new Map([[0, 620]]);
const result = generateRpcMessagesSummary(entries, [], deltas);
expect(result).toContain("ΔET");
expect(result).toContain("+620");
expect(result).toContain("my-tool");
});

test("omits ΔET column when no deltas are provided", () => {
const entries = {
requests: [
{ timestamp: "2026-05-19T21:10:05.123Z", server_id: "srv", type: "REQUEST", payload: { method: "tools/call", params: { name: "my-tool" } } },
],
responses: [],
other: [],
};
const result = generateRpcMessagesSummary(entries, []);
expect(result).not.toContain("ΔET");
expect(result).toContain("my-tool");
});

test("shows dash for requests without a delta", () => {
const entries = {
requests: [
{ timestamp: "2026-05-19T21:10:05.123Z", server_id: "srv", type: "REQUEST", payload: { method: "tools/call", params: { name: "tool-a" } } },
{ timestamp: "2026-05-19T21:10:15.123Z", server_id: "srv", type: "REQUEST", payload: { method: "tools/call", params: { name: "tool-b" } } },
],
responses: [],
other: [],
};
const deltas = new Map([[0, 500]]); // only tool-a has a delta
const result = generateRpcMessagesSummary(entries, [], deltas);
expect(result).toContain("ΔET");
expect(result).toContain("+500");
expect(result).toContain("tool-a");
expect(result).toContain("tool-b");
});
});
});
Loading