Audit core.warning/core.error usage (#269)

* Stop using command-based logs for warnings and errors

Co-authored-by: Cursor <cursoragent@cursor.com>

* revert

* tweak

* de-noise

* Remove redundant ts() timestamp prefix from log calls

* Restore timestamped logging and refine debug output routing.

Bring back timestamp prefixes for standard logs and make log.debug emit via core.debug when runner debug is enabled, while still surfacing debug lines for --debug runs.

Co-authored-by: Cursor <cursoragent@cursor.com>

---------

Co-authored-by: Mateusz Burzyński <mateuszburzynski@gmail.com>
Co-authored-by: Cursor <cursoragent@cursor.com>
Co-authored-by: pullfrog[bot] <226033991+pullfrog[bot]@users.noreply.github.com>
Co-authored-by: Colin McDonnell <colinmcd94@gmail.com>
This commit is contained in:
pullfrog[bot]
2026-02-19 23:11:47 +00:00
committed by pullfrog[bot]
parent 4ee1ae89a5
commit 70f1c47a28
20 changed files with 296 additions and 286 deletions
+6 -7
View File
@@ -173,8 +173,7 @@ export const claude = agent({
onStderr: (chunk) => {
const trimmed = chunk.trim();
if (trimmed) {
log.debug(`[claude stderr] ${trimmed}`);
log.warning(trimmed);
log.info(`[claude stderr] ${trimmed}`);
finalOutput += trimmed + "\n";
}
},
@@ -267,7 +266,7 @@ const messageHandlers: SDKMessageHandlers = {
// Log bash output in a collapsed group
log.startGroup(`bash output`);
if (content.is_error) {
log.warning(outputContent);
log.info(outputContent);
} else {
log.info(outputContent);
}
@@ -275,7 +274,7 @@ const messageHandlers: SDKMessageHandlers = {
// Clean up the tracked ID
bashToolIds.delete(toolUseId);
} else if (content.is_error) {
log.warning(`Tool error: ${outputContent}`);
log.info(`Tool error: ${outputContent}`);
} else {
// log successful non-bash tool result at debug level
log.debug(`tool output: ${outputContent}`);
@@ -310,11 +309,11 @@ const messageHandlers: SDKMessageHandlers = {
],
]);
} else if (data.subtype === "error_max_turns") {
log.error(`Max turns reached: ${JSON.stringify(data)}`);
log.info(`Max turns reached: ${JSON.stringify(data)}`);
} else if (data.subtype === "error_during_execution") {
log.error(`Execution error: ${JSON.stringify(data)}`);
log.info(`Execution error: ${JSON.stringify(data)}`);
} else {
log.error(`Failed: ${JSON.stringify(data)}`);
log.info(`Failed: ${JSON.stringify(data)}`);
}
},
system: () => {},
+7 -8
View File
@@ -43,7 +43,7 @@ async function isModelAvailable(ctx: { apiKey: string; model: string }): Promise
signal: AbortSignal.timeout(10_000),
});
if (!response.ok) {
log.warning(
log.info(
`failed to list models (HTTP ${response.status}), falling back to ${FALLBACK_MODEL}`
);
return false;
@@ -51,7 +51,7 @@ async function isModelAvailable(ctx: { apiKey: string; model: string }): Promise
const body = (await response.json()) as { data: Array<{ id: string }> };
return body.data.some((m) => m.id === ctx.model);
} catch (err) {
log.warning(`failed to list models: ${err}, falling back to ${FALLBACK_MODEL}`);
log.info(`failed to list models: ${err}, falling back to ${FALLBACK_MODEL}`);
return false;
}
}
@@ -262,8 +262,7 @@ export const codex = agent({
onStderr: (chunk) => {
const trimmed = chunk.trim();
if (trimmed) {
log.debug(`[codex stderr] ${trimmed}`);
log.warning(trimmed);
log.info(`[codex stderr] ${trimmed}`);
finalOutput += trimmed + "\n";
}
},
@@ -319,7 +318,7 @@ const messageHandlers: {
]);
},
"turn.failed": (event) => {
log.error(`Turn failed: ${event.error.message}`);
log.info(`Turn failed: ${event.error.message}`);
},
"item.started": (event, commandExecutionIds, thinkingTimer) => {
const item = event.item;
@@ -362,7 +361,7 @@ const messageHandlers: {
thinkingTimer.markToolResult();
log.startGroup(`bash output`);
if (item.status === "failed" || (item.exit_code !== undefined && item.exit_code !== 0)) {
log.warning(item.aggregated_output || "Command failed");
log.info(item.aggregated_output || "Command failed");
} else {
log.info(item.aggregated_output || "");
}
@@ -372,7 +371,7 @@ const messageHandlers: {
} else if (item.type === "mcp_tool_call") {
thinkingTimer.markToolResult();
if (item.status === "failed" && item.error) {
log.warning(`MCP tool call failed: ${item.error.message}`);
log.info(`MCP tool call failed: ${item.error.message}`);
} else if ((item as any).output) {
// log successful MCP tool call output so it appears in captured output
const output = (item as any).output;
@@ -388,6 +387,6 @@ const messageHandlers: {
}
},
error: (event) => {
log.error(`Error: ${event.message}`);
log.info(`Error: ${event.message}`);
},
};
+3 -3
View File
@@ -210,7 +210,7 @@ export const cursor = agent({
const result = event.tool_call?.mcpToolCall?.result?.success;
const isError = result?.isError;
if (isError) {
log.warning("Tool call failed");
log.info("Tool call failed");
} else {
// log successful tool result so it appears in output
// handle both formats: { text: string } or { text: { text: string } }
@@ -320,12 +320,12 @@ export const cursor = agent({
const text = data.toString();
stderr += text;
process.stderr.write(text);
log.warning(text);
log.info(text);
});
child.on("close", async (code, signal) => {
if (signal) {
log.warning(`Cursor CLI terminated by signal: ${signal}`);
log.info(`Cursor CLI terminated by signal: ${signal}`);
}
const duration = ((performance.now() - startTime) / 1000).toFixed(1);
+4 -5
View File
@@ -149,7 +149,7 @@ const messageHandlers = {
if (event.status === "error") {
const errorMsg =
typeof event.output === "string" ? event.output : JSON.stringify(event.output);
log.warning(`Tool call failed: ${errorMsg}`);
log.info(`Tool call failed: ${errorMsg}`);
} else if (event.output) {
// log successful tool result so it appears in output
const outputStr =
@@ -270,8 +270,7 @@ export const gemini = agent({
onStderr: (chunk) => {
const trimmed = chunk.trim();
if (trimmed) {
log.debug(`[gemini stderr] ${trimmed}`);
log.warning(trimmed);
log.info(`[gemini stderr] ${trimmed}`);
finalOutput += trimmed + "\n";
}
},
@@ -286,7 +285,7 @@ export const gemini = agent({
// retry on transient API errors (500, 503, INTERNAL, etc.)
if (attempt < MAX_ATTEMPTS && isTransientApiError(errorMessage)) {
log.warning(
log.info(
`» transient Gemini API error on attempt ${attempt}/${MAX_ATTEMPTS}, retrying in ${RETRY_DELAY_MS / 1000}s...`
);
await new Promise((resolve) => setTimeout(resolve, RETRY_DELAY_MS));
@@ -313,7 +312,7 @@ export const gemini = agent({
// retry on transient API errors from spawn exceptions too
if (attempt < MAX_ATTEMPTS && isTransientApiError(errorMessage)) {
log.warning(
log.info(
`» transient Gemini API error on attempt ${attempt}/${MAX_ATTEMPTS}, retrying in ${RETRY_DELAY_MS / 1000}s...`
);
await new Promise((resolve) => setTimeout(resolve, RETRY_DELAY_MS));
+10 -10
View File
@@ -154,7 +154,7 @@ export const opencode = agent({
activeToolCalls > 0
? ` (waiting for ${activeToolCalls} tool call${activeToolCalls > 1 ? "s" : ""})`
: " (OpenCode may be processing internally - LLM calls, planning, etc.)";
log.warning(
log.info(
`» no activity for ${(timeSinceLastActivity / 1000).toFixed(1)}s${toolCallInfo} (${eventCount} events processed so far)`
);
}
@@ -186,7 +186,7 @@ export const opencode = agent({
const providerError = detectProviderError(trimmed);
if (providerError) {
lastProviderError = providerError;
log.error(`» provider error detected (${providerError}): ${trimmed.substring(0, 500)}`);
log.info(`» provider error detected (${providerError}): ${trimmed.substring(0, 500)}`);
} else {
// OpenCode's --print-logs output goes to stderr. demote internal
// INFO/DEBUG bus traffic to debug so it doesn't drown out tool
@@ -207,9 +207,9 @@ export const opencode = agent({
const diagnosis = lastProviderError
? `provider error: ${lastProviderError}`
: "unknown cause (no stdout events received)";
log.error(`» OpenCode produced 0 events (${diagnosis})`);
log.info(`» OpenCode produced 0 events (${diagnosis})`);
if (stderrContext) {
log.error(`» last stderr output:\n${stderrContext}`);
log.info(`» last stderr output:\n${stderrContext}`);
}
}
@@ -263,12 +263,12 @@ export const opencode = agent({
? "OpenCode produced 0 stdout events - check if the model provider is reachable"
: `${eventCount} events were processed before the hang`;
log.error(
log.info(
`» OpenCode ${isActivityTimeout ? "hung" : "failed"} after ${(duration / 1000).toFixed(1)}s: ${errorMessage}`
);
log.error(`» diagnosis: ${diagnosis}`);
log.info(`» diagnosis: ${diagnosis}`);
if (stderrContext) {
log.error(
log.info(
`» recent stderr (last ${Math.min(recentStderr.length, 10)} lines):\n${stderrContext}`
);
}
@@ -600,7 +600,7 @@ const messageHandlers = {
log.debug(` output: ${typeof output === "string" ? output : JSON.stringify(output)}`);
}
if (toolDuration > 5000) {
log.warning(
log.info(
`» ⚠️ tool call took ${(toolDuration / 1000).toFixed(1)}s - this may indicate network latency or slow processing`
);
}
@@ -608,7 +608,7 @@ const messageHandlers = {
}
if (status === "error") {
const errorMsg = typeof output === "string" ? output : JSON.stringify(output);
log.error(`» ❌ tool call failed: ${errorMsg}`);
log.info(`» ❌ tool call failed: ${errorMsg}`);
} else if (output) {
// log successful tool result so it appears in captured output
const outputStr = typeof output === "string" ? output : JSON.stringify(output);
@@ -624,7 +624,7 @@ const messageHandlers = {
);
if (event.status === "error") {
log.error(`» OpenCode CLI failed: ${JSON.stringify(event)}`);
log.info(`» OpenCode CLI failed: ${JSON.stringify(event)}`);
} else {
// log tokens once at the end (use stats from result if available, otherwise use accumulated from step_finish)
const inputTokens = event.stats?.input_tokens || accumulatedTokens.input || 0;