mirror of
https://github.com/QwenLM/qwen-code.git
synced 2026-07-11 01:59:07 +00:00
fix(telemetry): address #4321 review — Copilot inline + code-reviewer + silent-failure-hunter
Eight discrete fixes plus two new tests, all surfaced in the Phase 2 review rounds. Grouped here because they touch the same handful of code paths. Copilot inline (#4321 PR): 1. startToolSpan attrs naming: drop redundant `tool_name` (helper already sets `'tool.name'` from the first arg) and rename `call_id` to the namespaced `'tool.call_id'`. Two sites: `_schedule` validating-loop start, and the defensive fallback in executeSingleToolCall. Without this, traces emit non-namespaced `tool_name` / `call_id` attributes that consumers grepping for `tool.call_id` miss. 2. PreToolUse hook span: propagate the actual `preHookResult.blockType` ('denied' / 'ask' / 'stop') instead of collapsing every block to 'denied'. Also record `hasAdditionalContext` for parity with the PostToolUse / failure-hook spans. 3. blocked_on_user `source` detection: use `config.getIdeMode()` (best- effort) so IDE-driven decisions don't all show up as `'cli'`. Centralized in a new `getBlockedSource()` helper. silent-failure-hunter / code-reviewer: 4. Hook span error-tracking is dead code. firePreToolUseHook / firePostToolUseHook / safelyFirePostToolUseFailureHook all swallow throws internally — every `catch (e) { endMeta = { error, ... }; throw e }` block in the scheduler was unreachable. Simplify all 6 sites to `try { ... } finally { endHookSpan(...) }`. The default `endMeta = { success: false }` keeps the span sensible if a future hook impl decides to throw. 5. handleConfirmationResponse had no error handling. modifyWithEditor / _applyInlineModify / attemptExecutionOfScheduledCalls can throw and would otherwise leak both the tool span and the blocked_on_user span until the 30-min TTL fires. Wrap the body in a try/catch that finalizes both spans on rethrow. Extracted the body to `_handleConfirmationResponseInner` for clarity. 6. Add `'error'` to the `ToolBlockedDecision` union for system-error closes, so dashboards counting `decision: 'cancel'` don't get polluted by thrown exceptions. 7. _schedule's outer catch was labelling its non-aborted close as `'cancel'`. Switch to `'error'` (uses #6). 8. signal.aborted vs explicit user Cancel: when both are true, the old code reported `'aborted'/'system'` even though the user actually clicked Cancel. Reverse the precedence so `outcome === Cancel` wins, with `getBlockedSource()` for the source. Tests: - T1: extend the existing ProceedAlways auto-approve test to assert the two siblings' blocked spans end with `decision: 'auto_approved'`, `source: 'auto'`, while the first tool ends as `'proceed_always'`/cli. - T2: existing cancel-during-confirmation test now also asserts exactly one blocked span is recorded for the lifecycle — the same invariant ModifyWithEditor's intentional preservation across editor side trips must not break. 🤖 Generated with [Qwen Code](https://github.com/QwenLM/qwen-code)
This commit is contained in:
doudouOUC
parent
38ba22d9c3
commit
6767469b23
3 changed files with 124 additions and 48 deletions
|
|
@ -2380,6 +2380,13 @@ describe('CoreToolScheduler request queueing', () => {
|
|||
|
||||
const abortController = new AbortController();
|
||||
|
||||
// toolSpanRecords accumulates across tests in this describe block.
|
||||
// Snapshot before schedule() so the assertions below see only this
|
||||
// test's records.
|
||||
const blockedSpansBefore = toolSpanRecords.filter(
|
||||
(r) => r.name === 'tool.blocked_on_user',
|
||||
).length;
|
||||
|
||||
// Schedule multiple tools that need confirmation
|
||||
const requests = [
|
||||
{
|
||||
|
|
@ -2436,6 +2443,26 @@ describe('CoreToolScheduler request queueing', () => {
|
|||
|
||||
// Verify approval mode was changed
|
||||
expect(approvalMode).toBe(ApprovalMode.AUTO_EDIT);
|
||||
|
||||
// #3731 Phase 2 / #4321 review: the first tool's blocked span ends as
|
||||
// 'proceed_always' / cli; the two siblings auto-approved by
|
||||
// autoApproveCompatiblePendingTools must end as
|
||||
// 'auto_approved' / 'auto'. Slice from blockedSpansBefore so we see
|
||||
// only the spans this test produced.
|
||||
const blockedRecords = toolSpanRecords
|
||||
.filter((r) => r.name === 'tool.blocked_on_user')
|
||||
.slice(blockedSpansBefore);
|
||||
expect(blockedRecords).toHaveLength(3);
|
||||
const decisions = blockedRecords
|
||||
.map((r) => r.blockedMetadata?.decision)
|
||||
.sort();
|
||||
const sources = blockedRecords.map((r) => r.blockedMetadata?.source).sort();
|
||||
expect(decisions).toEqual([
|
||||
'auto_approved',
|
||||
'auto_approved',
|
||||
'proceed_always',
|
||||
]);
|
||||
expect(sources).toEqual(['auto', 'auto', 'cli']);
|
||||
});
|
||||
});
|
||||
|
||||
|
|
@ -4010,6 +4037,13 @@ describe('CoreToolScheduler telemetry spans', () => {
|
|||
);
|
||||
expect(toolSpans).toHaveLength(1);
|
||||
expect(toolSpans[0].ended).toBe(true);
|
||||
|
||||
// #4321 review: the awaiting_approval phase produces exactly one
|
||||
// blocked_on_user span across the lifecycle. ModifyWithEditor's
|
||||
// intentional invariant is the same — re-entering awaiting_approval
|
||||
// must NOT spawn a second span. This assertion guards against a
|
||||
// future refactor that re-starts the blocked span on each transition.
|
||||
expect(blockedSpans).toHaveLength(1);
|
||||
});
|
||||
|
||||
it('hook span records shouldProceed=false / blockType=denied when pre-hook blocks (#3731 Phase 2)', async () => {
|
||||
|
|
|
|||
|
|
@ -1035,6 +1035,17 @@ export class CoreToolScheduler {
|
|||
endToolBlockedOnUserSpan(span, { decision, source });
|
||||
}
|
||||
|
||||
/**
|
||||
* Best-effort attribution of the surface that resolved the blocked
|
||||
* decision. When IDE mode is on, confirmations are most often resolved
|
||||
* via the IDE diff flow (`openIdeDiffIfEnabled`) — but a CLI-fallback
|
||||
* confirmation in IDE mode is also reported as 'ide' here. Operators
|
||||
* can drill into the trace if they need finer-grained attribution.
|
||||
*/
|
||||
private getBlockedSource(): ToolBlockedSource {
|
||||
return this.config.getIdeMode?.() ? 'ide' : 'cli';
|
||||
}
|
||||
|
||||
private buildInvocation(
|
||||
tool: AnyDeclarativeTool,
|
||||
args: object,
|
||||
|
|
@ -1351,9 +1362,10 @@ export class CoreToolScheduler {
|
|||
// Phase 2). Every cancel/error path below — and the existing
|
||||
// success path in executeSingleToolCall — must call
|
||||
// finalizeToolSpan(callId, ...) to avoid leaking spans.
|
||||
// `tool.name` is set automatically by startToolSpan from the first
|
||||
// arg; only namespaced extras go in attrs.
|
||||
const toolSpan = startToolSpan(canonicalName, {
|
||||
tool_name: canonicalName,
|
||||
call_id: reqInfo.callId,
|
||||
'tool.call_id': reqInfo.callId,
|
||||
});
|
||||
this.toolSpans.set(reqInfo.callId, toolSpan);
|
||||
|
||||
|
|
@ -1693,7 +1705,10 @@ export class CoreToolScheduler {
|
|||
explicitErrorType ?? ToolErrorType.UNHANDLED_EXCEPTION,
|
||||
),
|
||||
);
|
||||
this.finalizeBlockedSpan(reqInfo.callId, 'cancel', 'system');
|
||||
// Non-aborted catch is a system error (e.g. getConfirmationDetails
|
||||
// threw). 'error' decision keeps it distinct from user 'cancel'
|
||||
// counts in dashboards.
|
||||
this.finalizeBlockedSpan(reqInfo.callId, 'error', 'system');
|
||||
setToolSpanFailure(
|
||||
toolSpan,
|
||||
TOOL_FAILURE_KIND_TOOL_EXCEPTION,
|
||||
|
|
@ -1728,6 +1743,47 @@ export class CoreToolScheduler {
|
|||
// processing and potential re-execution.
|
||||
if (!toolCall) return;
|
||||
|
||||
try {
|
||||
await this._handleConfirmationResponseInner(
|
||||
callId,
|
||||
toolCall,
|
||||
originalOnConfirm,
|
||||
outcome,
|
||||
signal,
|
||||
payload,
|
||||
);
|
||||
} catch (error) {
|
||||
// Defensive: any throw from originalOnConfirm / modifyWithEditor /
|
||||
// _applyInlineModify / attemptExecutionOfScheduledCalls would
|
||||
// otherwise leave the blocked + tool spans open until the 30-min
|
||||
// TTL fires. Finalize both so the trace shows a deterministic
|
||||
// close. finalizeXSpan are idempotent — if the success/cancel path
|
||||
// already closed them, these are no-ops.
|
||||
this.finalizeBlockedSpan(callId, 'error', 'system');
|
||||
const toolSpan = this.toolSpans.get(callId);
|
||||
if (toolSpan) {
|
||||
setToolSpanFailure(
|
||||
toolSpan,
|
||||
TOOL_FAILURE_KIND_TOOL_EXCEPTION,
|
||||
error instanceof Error ? error.message : String(error),
|
||||
);
|
||||
}
|
||||
this.finalizeToolSpan(callId);
|
||||
throw error;
|
||||
}
|
||||
}
|
||||
|
||||
private async _handleConfirmationResponseInner(
|
||||
callId: string,
|
||||
toolCall: ToolCall,
|
||||
originalOnConfirm: (
|
||||
outcome: ToolConfirmationOutcome,
|
||||
payload?: ToolConfirmationPayload,
|
||||
) => Promise<void>,
|
||||
outcome: ToolConfirmationOutcome,
|
||||
signal: AbortSignal,
|
||||
payload?: ToolConfirmationPayload,
|
||||
): Promise<void> {
|
||||
await originalOnConfirm(outcome, payload);
|
||||
|
||||
if (
|
||||
|
|
@ -1759,10 +1815,15 @@ export class CoreToolScheduler {
|
|||
if (toolSpan) {
|
||||
setToolSpanCancelled(toolSpan);
|
||||
}
|
||||
// Explicit user Cancel takes precedence over a concurrent global
|
||||
// abort: when both are true, treat it as an explicit cancel so
|
||||
// dashboards counting `decision: 'aborted'` aren't polluted by
|
||||
// benign user actions that race with shutdown.
|
||||
const explicitCancel = outcome === ToolConfirmationOutcome.Cancel;
|
||||
this.finalizeBlockedSpan(
|
||||
callId,
|
||||
signal.aborted ? 'aborted' : 'cancel',
|
||||
signal.aborted ? 'system' : 'cli',
|
||||
explicitCancel ? 'cancel' : 'aborted',
|
||||
explicitCancel ? this.getBlockedSource() : 'system',
|
||||
);
|
||||
this.finalizeToolSpan(callId);
|
||||
} else if (outcome === ToolConfirmationOutcome.ModifyWithEditor) {
|
||||
|
|
@ -1826,7 +1887,7 @@ export class CoreToolScheduler {
|
|||
outcome === ToolConfirmationOutcome.ProceedOnce
|
||||
? 'proceed_once'
|
||||
: 'proceed_always';
|
||||
this.finalizeBlockedSpan(callId, decision, 'cli');
|
||||
this.finalizeBlockedSpan(callId, decision, this.getBlockedSource());
|
||||
}
|
||||
await this.attemptExecutionOfScheduledCalls(signal);
|
||||
}
|
||||
|
|
@ -2020,8 +2081,7 @@ export class CoreToolScheduler {
|
|||
let toolSpan = this.toolSpans.get(callId);
|
||||
if (!toolSpan) {
|
||||
toolSpan = startToolSpan(toolName, {
|
||||
tool_name: toolName,
|
||||
call_id: callId,
|
||||
'tool.call_id': callId,
|
||||
});
|
||||
this.toolSpans.set(callId, toolSpan);
|
||||
}
|
||||
|
|
@ -2082,6 +2142,10 @@ export class CoreToolScheduler {
|
|||
toolName: canonicalName,
|
||||
toolUseId,
|
||||
});
|
||||
// try/finally (no catch): firePreToolUseHook is wrapped in its own
|
||||
// safelyFire-style guard inside toolHookTriggers and never throws.
|
||||
// The default endMeta records success: false so a future change that
|
||||
// makes it throw would still close the span with a sensible state.
|
||||
let endMeta: HookSpanMetadata = { success: false };
|
||||
try {
|
||||
const preHookResult = await firePreToolUseHook(
|
||||
|
|
@ -2094,7 +2158,12 @@ export class CoreToolScheduler {
|
|||
endMeta = {
|
||||
success: true,
|
||||
shouldProceed: preHookResult.shouldProceed,
|
||||
blockType: preHookResult.shouldProceed ? undefined : 'denied',
|
||||
// Propagate the actual blockType ('denied' / 'ask' / 'stop')
|
||||
// instead of collapsing every block to 'denied'.
|
||||
blockType: preHookResult.shouldProceed
|
||||
? undefined
|
||||
: preHookResult.blockType,
|
||||
hasAdditionalContext: !!preHookResult.additionalContext,
|
||||
};
|
||||
|
||||
if (!preHookResult.shouldProceed) {
|
||||
|
|
@ -2120,12 +2189,6 @@ export class CoreToolScheduler {
|
|||
);
|
||||
return;
|
||||
}
|
||||
} catch (e) {
|
||||
endMeta = {
|
||||
success: false,
|
||||
error: e instanceof Error ? e.message : String(e),
|
||||
};
|
||||
throw e;
|
||||
} finally {
|
||||
endHookSpan(hookSpan, endMeta);
|
||||
}
|
||||
|
|
@ -2230,6 +2293,8 @@ export class CoreToolScheduler {
|
|||
toolUseId,
|
||||
isInterrupt: true,
|
||||
});
|
||||
// safelyFirePostToolUseFailureHook absorbs throws — try/finally
|
||||
// is enough; default endMeta covers a hypothetical future change.
|
||||
let endMeta: HookSpanMetadata = { success: false };
|
||||
try {
|
||||
const failureHookResult = await safelyFirePostToolUseFailureHook(
|
||||
|
|
@ -2250,12 +2315,6 @@ export class CoreToolScheduler {
|
|||
if (failureHookResult.additionalContext) {
|
||||
cancelMessage += `\n\n${failureHookResult.additionalContext}`;
|
||||
}
|
||||
} catch (e) {
|
||||
endMeta = {
|
||||
success: false,
|
||||
error: e instanceof Error ? e.message : String(e),
|
||||
};
|
||||
throw e;
|
||||
} finally {
|
||||
endHookSpan(hookSpan, endMeta);
|
||||
}
|
||||
|
|
@ -2288,8 +2347,12 @@ export class CoreToolScheduler {
|
|||
toolName: canonicalName,
|
||||
toolUseId,
|
||||
});
|
||||
// try/finally; firePostToolUseHook is wrapped via the
|
||||
// safelyFire-style guard inside toolHookTriggers and never
|
||||
// throws today. definite-assignment lets us use the result
|
||||
// after the finally.
|
||||
let endMeta: HookSpanMetadata = { success: false };
|
||||
let postHookResult: Awaited<ReturnType<typeof firePostToolUseHook>>;
|
||||
let postHookResult!: Awaited<ReturnType<typeof firePostToolUseHook>>;
|
||||
try {
|
||||
postHookResult = await firePostToolUseHook(
|
||||
messageBus,
|
||||
|
|
@ -2305,15 +2368,9 @@ export class CoreToolScheduler {
|
|||
hasAdditionalContext: !!postHookResult.additionalContext,
|
||||
blockType: postHookResult.shouldStop ? 'stop' : undefined,
|
||||
};
|
||||
} catch (e) {
|
||||
endMeta = {
|
||||
success: false,
|
||||
error: e instanceof Error ? e.message : String(e),
|
||||
};
|
||||
} finally {
|
||||
endHookSpan(hookSpan, endMeta);
|
||||
throw e;
|
||||
}
|
||||
endHookSpan(hookSpan, endMeta);
|
||||
|
||||
// Append additional context from hook if provided
|
||||
if (postHookResult.additionalContext) {
|
||||
|
|
@ -2498,12 +2555,6 @@ export class CoreToolScheduler {
|
|||
if (failureHookResult.additionalContext) {
|
||||
errorMessage += `\n\n${failureHookResult.additionalContext}`;
|
||||
}
|
||||
} catch (e) {
|
||||
endMeta = {
|
||||
success: false,
|
||||
error: e instanceof Error ? e.message : String(e),
|
||||
};
|
||||
throw e;
|
||||
} finally {
|
||||
endHookSpan(hookSpan, endMeta);
|
||||
}
|
||||
|
|
@ -2578,12 +2629,6 @@ export class CoreToolScheduler {
|
|||
if (failureHookResult.additionalContext) {
|
||||
cancelMessage += `\n\n${failureHookResult.additionalContext}`;
|
||||
}
|
||||
} catch (e) {
|
||||
endMeta = {
|
||||
success: false,
|
||||
error: e instanceof Error ? e.message : String(e),
|
||||
};
|
||||
throw e;
|
||||
} finally {
|
||||
endHookSpan(hookSpan, endMeta);
|
||||
}
|
||||
|
|
@ -2627,12 +2672,6 @@ export class CoreToolScheduler {
|
|||
if (failureHookResult.additionalContext) {
|
||||
exceptionErrorMessage += `\n\n${failureHookResult.additionalContext}`;
|
||||
}
|
||||
} catch (e) {
|
||||
endMeta = {
|
||||
success: false,
|
||||
error: e instanceof Error ? e.message : String(e),
|
||||
};
|
||||
throw e;
|
||||
} finally {
|
||||
endHookSpan(hookSpan, endMeta);
|
||||
}
|
||||
|
|
|
|||
|
|
@ -536,7 +536,10 @@ export type ToolBlockedDecision =
|
|||
| 'proceed_always'
|
||||
| 'cancel'
|
||||
| 'aborted'
|
||||
| 'auto_approved';
|
||||
| 'auto_approved'
|
||||
// System-error close — distinct from user 'cancel' so dashboards counting
|
||||
// user cancels don't double-count thrown exceptions in the approval path.
|
||||
| 'error';
|
||||
|
||||
export type ToolBlockedSource = 'cli' | 'ide' | 'hook' | 'auto' | 'system';
|
||||
|
||||
|
|
|
|||
Loading…
Add table
Add a link
Reference in a new issue