-
Notifications
You must be signed in to change notification settings - Fork 1.6k
Add hierarchical token support for request logger grouping #2940
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Changes from 1 commit
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,148 @@ | ||
| # Request Logger Architecture | ||
|
|
||
| ## Overview | ||
|
|
||
| The Request Logger system is responsible for tracking and displaying all AI-related requests, tool calls, and prompt traces made by the GitHub Copilot Chat extension. It consists of two main components in separate files: | ||
|
|
||
| 1. **`RequestLogger`** ([src/extension/prompt/vscode-node/requestLoggerImpl.ts](../src/extension/prompt/vscode-node/requestLoggerImpl.ts)) - The main logging implementation that stores entries | ||
| 2. **`RequestLogTree`** ([src/extension/log/vscode-node/requestLogTree.ts](../src/extension/log/vscode-node/requestLogTree.ts)) - The VS Code TreeView that displays the logs in the "Copilot Chat" view | ||
|
|
||
| The logger and TreeView are decoupled - the TreeView subscribes to `onDidChangeRequests` events and calls `getRequests()` to retrieve entries for display. | ||
|
|
||
| --- | ||
|
|
||
| ## Architecture Diagram | ||
|
|
||
| ``` | ||
| ┌─────────────────────────────────────────────────────────────────────────────┐ | ||
| │ Entry Points │ | ||
| ├─────────────────────────────────────────────────────────────────────────────┤ | ||
| │ chatMLFetcher toolCallingLoop endpointProvider promptRenderer │ | ||
| │ │ │ │ │ │ | ||
| │ ▼ ▼ ▼ ▼ │ | ||
| │ addEntry() logToolCall() logModelListCall() addPromptTrace() │ | ||
| └───────────────────────────────┬─────────────────────────────────────────────┘ | ||
| │ | ||
| ▼ | ||
| ┌─────────────────────────────────────────────────────────────────────────────┐ | ||
| │ RequestLogger │ | ||
| │ ┌─────────────────────────────────────────────────────────────────────┐ │ | ||
| │ │ _entries: LoggedInfo[] │ │ | ||
| │ └─────────────────────────────────────────────────────────────────────┘ │ | ||
| │ │ │ | ||
| │ ▼ │ | ||
| │ _onDidChangeRequests.fire() │ | ||
| └───────────────────────────────┬─────────────────────────────────────────────┘ | ||
| │ | ||
| ▼ | ||
| ┌─────────────────────────────────────────────────────────────────────────────┐ | ||
| │ RequestLogTree │ | ||
| │ ┌─────────────────────────────────────────────────────────────────────┐ │ | ||
| │ │ ChatRequestProvider.getChildren() │ │ | ||
| │ │ │ │ | ||
| │ │ Iterates through getRequests() │ │ | ||
| │ │ Groups by CapturingToken (AsyncLocalStorage context) │ │ | ||
| │ └─────────────────────────────────────────────────────────────────────┘ │ | ||
| └─────────────────────────────────────────────────────────────────────────────┘ | ||
| ``` | ||
|
|
||
| --- | ||
|
|
||
| ## Key Components | ||
|
|
||
| ### 1. Entry Types (`LoggedInfoKind`) | ||
|
|
||
| | Kind | Class | Description | | ||
| |------|-------|-------------| | ||
| | `LoggedInfoKind.Request` | `LoggedRequestInfo` | Chat ML requests (success, failure, cancellation) | | ||
| | `LoggedInfoKind.ToolCall` | `LoggedToolCall` | Tool invocations and their results | | ||
| | `LoggedInfoKind.Element` | `LoggedElementInfo` | Prompt-TSX element traces | | ||
|
|
||
| ### 2. Request Grouping with `CapturingToken` | ||
|
|
||
| The system uses **Node.js AsyncLocalStorage** to group related requests together: | ||
|
|
||
| ```typescript | ||
| // In requestLogger.ts | ||
| const requestLogStorage = new AsyncLocalStorage<CapturingToken>(); | ||
|
|
||
| // Usage - wraps an async operation to associate a token | ||
| public captureInvocation<T>(request: CapturingToken, fn: () => Promise<T>): Promise<T> { | ||
| return requestLogStorage.run(request, () => fn()); | ||
| } | ||
| ``` | ||
|
|
||
| When a request is logged, it captures the current `CapturingToken` from the async context: | ||
|
|
||
| ```typescript | ||
| protected get currentRequest() { | ||
| return requestLogStorage.getStore(); | ||
| } | ||
| ``` | ||
|
|
||
| The `CapturingToken` includes: | ||
| - `label`: Display name for the parent tree element | ||
| - `icon`: Optional icon | ||
| - `flattenSingleChild`: Whether to flatten single-child groups | ||
| - `promoteMainEntry`: Whether to make the parent item clickable | ||
|
|
||
| ### 3. Entry Storage and Event Flow | ||
|
|
||
| ```typescript | ||
| // In requestLoggerImpl.ts | ||
| private readonly _entries: LoggedInfo[] = []; | ||
|
|
||
| private async _addEntry(entry: LoggedInfo): Promise<boolean> { | ||
| this._entries.push(entry); | ||
|
|
||
| // Trim to max entries (configurable) | ||
| const maxEntries = this._configService.getConfig(ConfigKey.Advanced.RequestLoggerMaxEntries); | ||
| if (this._entries.length > maxEntries) { | ||
| this._entries.shift(); | ||
| } | ||
|
|
||
| // Notify listeners (triggers treeview refresh) | ||
| this._onDidChangeRequests.fire(); | ||
| return true; | ||
| } | ||
| ``` | ||
|
|
||
| --- | ||
|
|
||
| ## TreeView Grouping Logic | ||
|
|
||
| The TreeView groups entries by their `CapturingToken`: | ||
|
|
||
| ```typescript | ||
| // Simplified logic from getChildren() | ||
| for (const currReq of this.requestLogger.getRequests()) { | ||
| if (currReq.token !== lastPrompt?.token) { | ||
| // Token changed - start new group | ||
| pushLastPrompt(); | ||
| lastPrompt = ChatPromptItem.create(currReq, currReq.token, seen.has(currReq.token)); | ||
| } | ||
|
|
||
| // Add current request to the group | ||
| lastPrompt.children.push(currReqTreeItem); | ||
| } | ||
| ``` | ||
|
Comment on lines
113
to
146
|
||
|
|
||
| ### Grouping Edge Cases | ||
|
|
||
| 1. **Same token, different order** - Entries with the same token will be grouped together, but their internal order follows insertion order | ||
|
|
||
| 2. **Token reuse** - If the same `CapturingToken` is used in different contexts, entries get grouped together (marked with "Continued...") | ||
|
|
||
| 3. **No token** - Entries without a token appear as top-level items | ||
|
|
||
| --- | ||
|
|
||
| ## Related Files | ||
|
|
||
| | File | Purpose | | ||
| |------|---------| | ||
| | [requestLoggerImpl.ts](../src/extension/prompt/vscode-node/requestLoggerImpl.ts) | Main logger implementation | | ||
| | [requestLogger.ts](../src/platform/requestLogger/node/requestLogger.ts) | Base class and interfaces | | ||
| | [requestLogTree.ts](../src/extension/log/vscode-node/requestLogTree.ts) | TreeView implementation | | ||
| | [capturingToken.ts](../src/platform/requestLogger/common/capturingToken.ts) | Token for grouping requests | | ||
| | [toolCallingLoop.ts](../src/extension/intents/node/toolCallingLoop.ts) | Tool call logging | | ||
| Original file line number | Diff line number | Diff line change | ||||||||
|---|---|---|---|---|---|---|---|---|---|---|
| @@ -0,0 +1,190 @@ | ||||||||||
| # Request Logger Testing Initiative | ||||||||||
|
|
||||||||||
| ## Goal | ||||||||||
|
|
||||||||||
| Create comprehensive tests for the `RequestLogger` so that an AI agent can exercise and identify issues with request logging functionality. This enables automated detection and fixing of bugs in the request logging system. | ||||||||||
|
|
||||||||||
| ## Background | ||||||||||
|
|
||||||||||
| The `RequestLogger` is responsible for: | ||||||||||
| - Logging all LLM requests made during chat conversations | ||||||||||
| - Tracking tool calls and their arguments/responses | ||||||||||
| - Grouping related requests under parent tokens via `captureInvocation()` | ||||||||||
| - Exporting logged data for debugging and analysis | ||||||||||
|
|
||||||||||
| ### Key Architecture | ||||||||||
|
|
||||||||||
| ``` | ||||||||||
| ┌─────────────────────────────────────────────────────────────────┐ | ||||||||||
| │ Request Flow │ | ||||||||||
| ├─────────────────────────────────────────────────────────────────┤ | ||||||||||
| │ │ | ||||||||||
| │ Outside captureInvocation: Inside captureInvocation: │ | ||||||||||
| │ ┌──────────────────────┐ ┌──────────────────────────┐ │ | ||||||||||
| │ │ logModelListCall() │ │ captureInvocation(token)│ │ | ||||||||||
| │ │ → token = undefined │ │ ┌────────────────────┐ │ │ | ||||||||||
| │ │ → TOP-LEVEL ENTRY │ │ │ addEntry() │ │ │ | ||||||||||
| │ └──────────────────────┘ │ │ → token = parent │ │ │ | ||||||||||
| │ │ │ → GROUPED │ │ │ | ||||||||||
| │ │ ├────────────────────┤ │ │ | ||||||||||
| │ │ │ logToolCall() │ │ │ | ||||||||||
| │ │ │ → token = parent │ │ │ | ||||||||||
| │ │ │ → GROUPED │ │ │ | ||||||||||
| │ │ └────────────────────┘ │ │ | ||||||||||
| │ └──────────────────────────┘ │ | ||||||||||
| └─────────────────────────────────────────────────────────────────┘ | ||||||||||
| ``` | ||||||||||
|
|
||||||||||
| ## Core Problem: Context Loss Across Async Boundaries | ||||||||||
|
|
||||||||||
| ### The Issue | ||||||||||
|
|
||||||||||
| The `RequestLogger` uses `AsyncLocalStorage` to propagate the current `CapturingToken` through the call stack. This works well **within** a single async context, but fails when: | ||||||||||
|
|
||||||||||
| 1. **Subagents** - A child request is spawned that runs independently | ||||||||||
| 2. **Background operations** - Model list fetches, auth refreshes, etc. | ||||||||||
| 3. **Deferred work** - Callbacks scheduled via setTimeout, separate Promise chains | ||||||||||
|
|
||||||||||
| When work escapes the `captureInvocation()` context, entries appear as "orphans" at the top level instead of being grouped under their logical parent. | ||||||||||
|
|
||||||||||
| ### Symptoms | ||||||||||
| - Two top-level entries appear instead of one grouped conversation | ||||||||||
| - Subagent requests appear disconnected from the parent that spawned them | ||||||||||
| - Background operations (model list, etc.) appear as separate top-level items | ||||||||||
|
|
||||||||||
| ## Test Coverage | ||||||||||
|
|
||||||||||
| ### Unit Tests | ||||||||||
|
|
||||||||||
| **Location:** `src/platform/requestLogger/test/node/requestLogger.spec.ts` | ||||||||||
|
|
||||||||||
| | Test | Description | | ||||||||||
| |------|-------------| | ||||||||||
| | `entries outside captureInvocation have no parent token` | Verifies entries added without context have `token = undefined` | | ||||||||||
| | `entries inside captureInvocation have the parent token` | Verifies entries get the parent token from context | | ||||||||||
| | `all entries inside same captureInvocation share the same parent token` | Verifies multiple entries/tool calls share one parent | | ||||||||||
| | `entries before, inside, and after captureInvocation are grouped correctly` | Tests the full grouping behavior | | ||||||||||
| | `nested captureInvocation uses innermost token` | Verifies nested contexts work correctly | | ||||||||||
| | `tool calls get parent token from captureInvocation context` | Verifies `logToolCall()` respects context | | ||||||||||
| | `logModelListCall outside captureInvocation creates top-level entry` | Documents the background operation behavior | | ||||||||||
| | **`async work scheduled outside captureInvocation loses parent context`** | **Documents the context loss problem** | | ||||||||||
| | **`demonstrates how explicit token passing could solve the orphan problem`** | **Shows the desired fix behavior** | | ||||||||||
| | `clear removes all entries` | Tests the `clear()` utility method | | ||||||||||
|
|
||||||||||
| **Run with:** `npm run test:unit -- src/platform/requestLogger/test/node/requestLogger.spec.ts` | ||||||||||
|
|
||||||||||
| ## Key Files | ||||||||||
|
|
||||||||||
| | File | Purpose | | ||||||||||
| |------|---------| | ||||||||||
| | `src/platform/requestLogger/node/requestLogger.ts` | Interface definitions, `AbstractRequestLogger` base class | | ||||||||||
| | `src/extension/prompt/vscode-node/requestLoggerImpl.ts` | Real `RequestLogger` implementation | | ||||||||||
| | `src/platform/requestLogger/test/node/testRequestLogger.ts` | Test double that stores entries | | ||||||||||
| | `src/platform/requestLogger/common/capturingToken.ts` | `CapturingToken` class for grouping | | ||||||||||
| | `src/platform/requestLogger/node/nullRequestLogger.ts` | No-op logger used in tests by default | | ||||||||||
|
|
||||||||||
| ## Proposed Fix: Hierarchical Token System | ||||||||||
|
|
||||||||||
| ### Design Principles | ||||||||||
|
|
||||||||||
| 1. **All logged entries should belong to a logical group** - no orphans at the top level for user-initiated actions | ||||||||||
| 2. **Subagents should be linked to their parent** - the token hierarchy should reflect the request hierarchy | ||||||||||
| 3. **Background operations should be distinguishable** - but still grouped appropriately | ||||||||||
| 4. **Explicit token passing for cross-boundary work** - when AsyncLocalStorage context is lost, pass tokens explicitly | ||||||||||
|
|
||||||||||
| ### Implementation: Add Parent Token Reference | ||||||||||
|
|
||||||||||
| #### 1. Update `CapturingToken` to support hierarchy | ||||||||||
|
|
||||||||||
| ```typescript | ||||||||||
| // src/platform/requestLogger/common/capturingToken.ts | ||||||||||
| export class CapturingToken { | ||||||||||
| constructor( | ||||||||||
| public readonly label: string, | ||||||||||
| public readonly icon: string | undefined, | ||||||||||
| public readonly flattenSingleChild: boolean, | ||||||||||
| public readonly promoteMainEntry: boolean = false, | ||||||||||
| /** | ||||||||||
| * Parent token for hierarchical grouping. | ||||||||||
| * Used to link subagent/child requests to their parent. | ||||||||||
| */ | ||||||||||
| public readonly parentToken?: CapturingToken, | ||||||||||
| ) { } | ||||||||||
|
|
||||||||||
| /** | ||||||||||
| * Create a child token that references this as its parent. | ||||||||||
| */ | ||||||||||
| createChild(label: string, icon?: string): CapturingToken { | ||||||||||
| return new CapturingToken(label, icon, false, false, this); | ||||||||||
|
||||||||||
| createChild(label: string, icon?: string): CapturingToken { | |
| return new CapturingToken(label, icon, false, false, this); | |
| createChild(label: string, icon?: string, flattenSingleChild: boolean = false): CapturingToken { | |
| return new CapturingToken(label, icon, flattenSingleChild, false, this); |
Uh oh!
There was an error while loading. Please reload this page.