Path: blob/main/extensions/copilot/src/extension/chat/vscode-node/chatDebugFileLoggerService.ts
13399 views
/*---------------------------------------------------------------------------------------------1* Copyright (c) Microsoft Corporation. All rights reserved.2* Licensed under the MIT License. See License.txt in the project root for license information.3*--------------------------------------------------------------------------------------------*/45import * as fs from 'fs';6import * as vscode from 'vscode';7import { IChatDebugFileLoggerService, IDebugLogEntry, sessionResourceToId } from '../../../platform/chat/common/chatDebugFileLoggerService';8import { ConfigKey, IConfigurationService } from '../../../platform/configuration/common/configurationService';9import { IEnvService } from '../../../platform/env/common/envService';10import { IVSCodeExtensionContext } from '../../../platform/extContext/common/extensionContext';11import { createDirectoryIfNotExists, IFileSystemService } from '../../../platform/filesystem/common/fileSystemService';12import { ILogService } from '../../../platform/log/common/logService';13import { CopilotChatAttr, GenAiAttr, GenAiOperationName } from '../../../platform/otel/common/index';14import { ICompletedSpanData, IOTelService, ISpanEventData, SpanStatusCode } from '../../../platform/otel/common/otelService';15import { IExperimentationService } from '../../../platform/telemetry/common/nullExperimentationService';16import { ITelemetryService } from '../../../platform/telemetry/common/telemetry';17import { Emitter } from '../../../util/vs/base/common/event';18import { Disposable } from '../../../util/vs/base/common/lifecycle';19import { extUriBiasedIgnorePathCase } from '../../../util/vs/base/common/resources';20import { URI } from '../../../util/vs/base/common/uri';21import { IExtensionContribution } from '../../common/contributions';2223const DEBUG_LOGS_DIR_NAME = 'debug-logs';24const DEFAULT_MAX_RETAINED_LOGS = 50;25const DEFAULT_FLUSH_INTERVAL_MS = 4_000;26const MIN_FLUSH_INTERVAL_MS = 2_000;27const MAX_ATTR_VALUE_LENGTH = 5_000;28const MAX_PENDING_CORE_EVENTS = 100;29const DEFAULT_MAX_SESSION_LOG_MB = 100;30const TRUNCATION_RETAIN_RATIO = 0.6; // retain 60% of max on truncation31const MAX_SPAN_SESSION_INDEX = 10_000;323334interface IActiveLogSession {35readonly uri: URI;36/** The directory containing this session's log files */37readonly sessionDir: URI;38readonly buffer: string[];39flushPromise: Promise<void>;40dirEnsured: boolean;41bytesWritten: number;42/** Parent session ID if this is a child session (e.g., title, categorization) */43readonly parentSessionId?: string;44/** Label for child sessions (e.g., 'title', 'categorization') */45readonly label?: string;46/** Whether this session has received its own OTel spans (vs being auto-created as a parent ref) */47hasOwnSpans: boolean;48/** Whether models.json has already been written to this session's directory */49modelSnapshotWritten: boolean;50/** Key identifying the last-written system prompt: model + agent/mode name (undefined = none written yet) */51systemPromptKey: string | undefined;52/** Index of the next system_prompt file to write */53systemPromptIndex: number;54/** File name of the most recently written system prompt (e.g., 'system_prompt_0.json') */55currentSystemPromptFile: string | undefined;56/** Key identifying the last-written tools file: model + agent/mode name (undefined = none written yet) */57toolsKey: string | undefined;58/** Index of the next tools file to write */59toolsIndex: number;60/** File name of the most recently written tools file (e.g., 'tools_0.json') */61currentToolsFile: string | undefined;62/** Pending tool definitions received before the session was promoted to hasOwnSpans */63pendingToolDefs: string | undefined;64/** Whether we've already checked disk for a previous session directory (prevents repeated sync FS calls) */65resumeChecked: boolean;66/** Run index: 0 for the first run, incremented on each VS Code restart that resumes this session */67runIndex: number;68}6970// IDebugLogEntry is imported from and defined in the platform layer.71// Re-export for consumers that import from this file.72export type { IDebugLogEntry } from '../../../platform/chat/common/chatDebugFileLoggerService';7374export class ChatDebugFileLoggerService extends Disposable implements IChatDebugFileLoggerService {75declare readonly _serviceBrand: undefined;7677public readonly id = 'chatDebugFileLogger';7879private readonly _onDidEmitEntry = this._register(new Emitter<{ sessionId: string; entry: IDebugLogEntry }>());80readonly onDidEmitEntry = this._onDidEmitEntry.event;8182private readonly _activeSessions = new Map<string, IActiveLogSession>();83/** Maps child session ID → { parentSessionId, label } for child session routing */84private readonly _childSessionMap = new Map<string, { parentSessionId: string; label: string; parentToolSpanId?: string }>();85/** Maps spanId → resolved session ID for parent-span inheritance */86private readonly _spanSessionIndex = new Map<string, string>();87private readonly _pendingCoreEvents: IDebugLogEntry[] = [];88private _modelSnapshot: readonly unknown[] | undefined;89private _debugLogsDirUri: URI | undefined;90private _autoFlushTimer: ReturnType<typeof setInterval> | undefined;91private _autoFlushIntervalMs: number;92private _maxSessionLogBytes: number;93private _totalBytesWritten = 0;94private _totalSessionCount = 0;9596constructor(97@IOTelService private readonly _otelService: IOTelService,98@IFileSystemService private readonly _fileSystemService: IFileSystemService,99@IVSCodeExtensionContext private readonly _extensionContext: IVSCodeExtensionContext,100@ILogService private readonly _logService: ILogService,101@IConfigurationService private readonly _configurationService: IConfigurationService,102@IExperimentationService private readonly _experimentationService: IExperimentationService,103@ITelemetryService private readonly _telemetryService: ITelemetryService,104@IEnvService private readonly _envService: IEnvService,105) {106super();107108const enabled = this._configurationService.getExperimentBasedConfig(ConfigKey.Advanced.ChatDebugFileLogging, this._experimentationService);109if (!enabled) {110/* __GDPR__111"chatDebugFileLogger.disabled" : {112"owner": "vijayupadya",113"comment": "Chat debug file logging is disabled via experiment or config"114}115*/116this._telemetryService.sendMSFTTelemetryEvent('chatDebugFileLogger.disabled');117this._autoFlushIntervalMs = DEFAULT_FLUSH_INTERVAL_MS;118this._maxSessionLogBytes = DEFAULT_MAX_SESSION_LOG_MB * 1024 * 1024;119return;120}121122this._autoFlushIntervalMs = Math.max(MIN_FLUSH_INTERVAL_MS, this._configurationService.getConfig(ConfigKey.Advanced.ChatDebugFileLoggingFlushInterval) ?? DEFAULT_FLUSH_INTERVAL_MS);123this._maxSessionLogBytes = this._resolveMaxSessionLogBytes();124125// React to changes at runtime126this._register(this._configurationService.onDidChangeConfiguration(e => {127if (e.affectsConfiguration(ConfigKey.Advanced.ChatDebugFileLoggingFlushInterval.fullyQualifiedId)) {128this._autoFlushIntervalMs = Math.max(MIN_FLUSH_INTERVAL_MS, this._configurationService.getConfig(ConfigKey.Advanced.ChatDebugFileLoggingFlushInterval) ?? DEFAULT_FLUSH_INTERVAL_MS);129this._restartFlushTimer();130}131if (e.affectsConfiguration(ConfigKey.Advanced.ChatDebugFileLoggingMaxSessionLogSizeMB.fullyQualifiedId)) {132this._maxSessionLogBytes = this._resolveMaxSessionLogBytes();133}134}));135136// Subscribe to OTel span completions137this._register(this._otelService.onDidCompleteSpan(span => {138this._onSpanCompleted(span);139}));140141// Subscribe to OTel span events (real-time user messages)142this._register(this._otelService.onDidEmitSpanEvent(event => {143this._onSpanEvent(event);144}));145146// Subscribe to core debug events (discovery, skill loading, etc.)147if (typeof vscode.chat?.onDidReceiveChatDebugEvent === 'function') {148this._register(vscode.chat.onDidReceiveChatDebugEvent(event => {149this._onCoreDebugEvent(event);150}));151}152}153154private _resolveMaxSessionLogBytes(): number {155const raw = this._configurationService.getExperimentBasedConfig(ConfigKey.Advanced.ChatDebugFileLoggingMaxSessionLogSizeMB, this._experimentationService);156const mb = typeof raw === 'number' && Number.isFinite(raw) ? raw : DEFAULT_MAX_SESSION_LOG_MB;157return Math.max(1, Math.floor(mb)) * 1024 * 1024;158}159160override dispose(): void {161if (this._autoFlushTimer) {162clearInterval(this._autoFlushTimer);163this._autoFlushTimer = undefined;164}165// Accumulate any remaining active session bytes before emitting telemetry166for (const session of this._activeSessions.values()) {167this._totalBytesWritten += session.bytesWritten;168}169/* __GDPR__170"chatDebugFileLogger.end" : {171"owner": "vijayupadya",172"comment": "Chat debug file logger is being disposed",173"totalBytesWritten": { "classification": "SystemMetaData", "purpose": "PerformanceAndHealth", "isMeasurement": true, "comment": "Total bytes written across all sessions" },174"sessionCount": { "classification": "SystemMetaData", "purpose": "PerformanceAndHealth", "isMeasurement": true, "comment": "Total number of sessions logged" }175}176*/177this._telemetryService.sendMSFTTelemetryEvent('chatDebugFileLogger.end', undefined, { totalBytesWritten: this._totalBytesWritten, sessionCount: this._totalSessionCount });178super.dispose();179}180181public get debugLogsDir(): URI | undefined {182return this._getDebugLogsDir();183}184185private _getDebugLogsDir(): URI | undefined {186if (this._debugLogsDirUri) {187return this._debugLogsDirUri;188}189const storageUri = this._extensionContext.storageUri as URI | undefined;190if (!storageUri) {191return undefined;192}193this._debugLogsDirUri = URI.joinPath(storageUri, DEBUG_LOGS_DIR_NAME);194return this._debugLogsDirUri;195}196197async startSession(sessionId: string): Promise<void> {198this._ensureSession(sessionId, /* hasOwnSpans */ true);199}200201startChildSession(childSessionId: string, parentSessionId: string, label: string, parentToolSpanId?: string): void {202if (!this._childSessionMap.has(childSessionId)) {203this._childSessionMap.set(childSessionId, { parentSessionId, label, parentToolSpanId });204}205}206207registerSpanSession(spanId: string, sessionId: string): void {208this._spanSessionIndex.set(spanId, sessionId);209// Apply same eviction cap as _onSpanCompleted210if (this._spanSessionIndex.size > MAX_SPAN_SESSION_INDEX) {211const excess = this._spanSessionIndex.size - MAX_SPAN_SESSION_INDEX;212const iter = this._spanSessionIndex.keys();213for (let i = 0; i < excess; i++) {214this._spanSessionIndex.delete(iter.next().value!);215}216}217}218219/**220* Synchronously ensure a session exists for buffering. Directory creation221* and old-log cleanup are deferred to the first flush.222*223* Sessions are organized in directories:224* - Parent session: `debug-logs/<sessionId>/main.jsonl`225* - Child session: `debug-logs/<parentSessionId>/<label>-<childSessionId>.jsonl`226*/227private _ensureSession(sessionId: string, hasOwnSpans = false): void {228const existing = this._activeSessions.get(sessionId);229if (existing) {230// Mark that this session now has its own spans (upgrades from auto-created parent ref)231if (hasOwnSpans && !existing.hasOwnSpans) {232existing.hasOwnSpans = true;233// Now that we know this is a real session, replay pending core events234if (!existing.parentSessionId) {235this._emitSessionStartAndReplay(sessionId, existing);236}237}238return;239}240241this._totalSessionCount++;242243const dir = this._getDebugLogsDir();244if (!dir) {245return;246}247248const childInfo = this._childSessionMap.get(sessionId);249let sessionDir: URI;250let fileUri: URI;251252if (childInfo) {253// Child session — write under parent's directory254sessionDir = URI.joinPath(dir, childInfo.parentSessionId);255const safeLabel = childInfo.label.replace(/[/\\:*?"<>|\x00-\x1f]/g, '_').replace(/\.\./g, '_');256const fileName = `${safeLabel}-${sessionId}.jsonl`;257fileUri = URI.joinPath(sessionDir, fileName);258259// Ensure parent session exists so we can write a cross-reference.260// A child referencing a parent proves it is a main user session,261// so promote it with hasOwnSpans = true.262this._ensureSession(childInfo.parentSessionId, /* hasOwnSpans */ true);263264// Write a cross-reference entry in the parent's main.jsonl265this._bufferEntry(childInfo.parentSessionId, {266ts: Date.now(),267dur: 0,268sid: childInfo.parentSessionId,269type: 'child_session_ref',270name: childInfo.label,271spanId: `child-ref-${sessionId}`,272...(childInfo.parentToolSpanId ? { parentSpanId: childInfo.parentToolSpanId } : {}),273status: 'ok',274attrs: {275childSessionId: sessionId,276childLogFile: `${safeLabel}-${sessionId}.jsonl`,277label: childInfo.label,278},279});280} else {281// Parent session — write as main.jsonl in its own directory282sessionDir = URI.joinPath(dir, sessionId);283fileUri = URI.joinPath(sessionDir, 'main.jsonl');284}285286const session: IActiveLogSession = {287uri: fileUri,288sessionDir,289buffer: [],290flushPromise: Promise.resolve(),291dirEnsured: false,292bytesWritten: 0,293parentSessionId: childInfo?.parentSessionId,294label: childInfo?.label,295hasOwnSpans,296modelSnapshotWritten: false,297systemPromptKey: undefined,298systemPromptIndex: 0,299currentSystemPromptFile: undefined,300toolsKey: undefined,301toolsIndex: 0,302currentToolsFile: undefined,303pendingToolDefs: undefined,304resumeChecked: false,305runIndex: 0,306};307this._activeSessions.set(sessionId, session);308309// Write a session_start entry so every JSONL file has a version header.310// For parent sessions with their own spans, also replay pending core events.311if (childInfo) {312// Child sessions get a minimal session_start (no core event replay)313this._bufferEntry(sessionId, {314v: 1,315ts: Date.now(),316dur: 0,317sid: sessionId,318type: 'session_start',319name: 'session_start',320spanId: `session-start-${sessionId}`,321status: 'ok',322attrs: {323copilotVersion: this._envService.getVersion(),324vscodeVersion: this._envService.vscodeVersion,325parentSessionId: childInfo.parentSessionId,326label: childInfo.label,327},328});329} else if (hasOwnSpans) {330this._emitSessionStartAndReplay(sessionId, session);331}332333// Start auto-flush timer if this is the first active session334if (this._activeSessions.size === 1 && !this._autoFlushTimer) {335this._autoFlushTimer = setInterval(() => this._autoFlushAll(), this._autoFlushIntervalMs);336}337338// Fire-and-forget cleanup of old logs339this._cleanupOldLogs().catch(() => { });340}341342async endSession(sessionId: string): Promise<void> {343await this.flush(sessionId);344const session = this._activeSessions.get(sessionId);345if (session) {346this._totalBytesWritten += session.bytesWritten;347}348this._activeSessions.delete(sessionId);349350// Clean up span→session mappings for this session351for (const [spanId, sid] of this._spanSessionIndex) {352if (sid === sessionId) {353this._spanSessionIndex.delete(spanId);354}355}356357// Stop auto-flush timer if no active sessions remain358if (this._activeSessions.size === 0 && this._autoFlushTimer) {359clearInterval(this._autoFlushTimer);360this._autoFlushTimer = undefined;361}362}363364async flush(sessionId: string): Promise<void> {365const session = this._activeSessions.get(sessionId);366if (!session) {367return;368}369370if (session.buffer.length === 0) {371// No JSONL entries to flush, but still await any pending async work372// (e.g. model snapshot write) enqueued on flushPromise.373return session.flushPromise;374}375376// Skip flushing for sessions not yet confirmed as main sessions.377// Keep the buffer intact so entries are preserved if the session378// is promoted later (e.g., when a child span references it).379if (!session.parentSessionId && !session.hasOwnSpans) {380return;381}382383const lines = session.buffer.splice(0);384const content = lines.join('');385386session.flushPromise = session.flushPromise.then(387() => this._writeToFile(session, content),388() => this._writeToFile(session, content),389);390return session.flushPromise;391}392393getLogPath(sessionId: string): URI | undefined {394const active = this._activeSessions.get(sessionId);395if (active) {396return active.uri;397}398// For child sessions, construct the correct <label>-<sessionId>.jsonl path399const childInfo = this._childSessionMap.get(sessionId);400if (childInfo) {401const dir = this._getDebugLogsDir();402if (!dir) { return undefined; }403const parentDir = URI.joinPath(dir, childInfo.parentSessionId);404return URI.joinPath(parentDir, `${childInfo.label}-${sessionId}.jsonl`);405}406// For historical sessions (after restart), construct the default path407const sessionDir = this.getSessionDir(sessionId);408return sessionDir ? URI.joinPath(sessionDir, 'main.jsonl') : undefined;409}410411getSessionDir(sessionId: string): URI | undefined {412// If active, use the stored sessionDir (already points to parent dir for children)413const active = this._activeSessions.get(sessionId);414if (active) {415return active.sessionDir;416}417// If known as a child, resolve to the parent's directory418const childInfo = this._childSessionMap.get(sessionId);419if (childInfo) {420const dir = this._getDebugLogsDir();421return dir ? URI.joinPath(dir, childInfo.parentSessionId) : undefined;422}423// Unknown session — construct the default path (assuming it's a parent)424const dir = this._getDebugLogsDir();425return dir ? URI.joinPath(dir, sessionId) : undefined;426}427428getActiveSessionIds(): string[] {429return [...this._activeSessions.keys()];430}431432isDebugLogUri(uri: URI): boolean {433const dir = this._getDebugLogsDir();434if (!dir) {435return false;436}437return extUriBiasedIgnorePathCase.isEqualOrParent(uri, dir);438}439440getSessionDirForResource(sessionResource: URI): URI | undefined {441const sessionId = sessionResourceToId(sessionResource);442return this.getSessionDir(sessionId);443}444445setModelSnapshot(models: readonly unknown[]): void {446this._modelSnapshot = models;447// Write to any active parent sessions that started before the model fetch completed448for (const [, session] of this._activeSessions) {449if (!session.parentSessionId && session.hasOwnSpans) {450this._enqueueModelSnapshotWrite(session);451}452}453}454455private _enqueueModelSnapshotWrite(session: IActiveLogSession): void {456session.flushPromise = session.flushPromise.then(457() => this._writeModelSnapshot(session),458() => this._writeModelSnapshot(session),459);460}461462private async _writeModelSnapshot(session: IActiveLogSession): Promise<void> {463if (!this._modelSnapshot || session.modelSnapshotWritten) {464return;465}466try {467if (!session.dirEnsured) {468await createDirectoryIfNotExists(this._fileSystemService, session.sessionDir);469session.dirEnsured = true;470}471const modelsUri = URI.joinPath(session.sessionDir, 'models.json');472await fs.promises.writeFile(modelsUri.fsPath, JSON.stringify(this._modelSnapshot, null, 2), 'utf-8');473session.modelSnapshotWritten = true;474} catch (err) {475this._logService.error('[ChatDebugFileLogger] Failed to write models.json', err);476}477}478479private _enqueueFileWrite(session: IActiveLogSession, content: string, fileName: string): void {480session.flushPromise = session.flushPromise.then(481() => this._writeSessionFile(session, content, fileName),482() => this._writeSessionFile(session, content, fileName),483);484}485486private async _writeSessionFile(session: IActiveLogSession, content: string, fileName: string): Promise<void> {487try {488if (!session.dirEnsured) {489await createDirectoryIfNotExists(this._fileSystemService, session.sessionDir);490session.dirEnsured = true;491}492const fileUri = URI.joinPath(session.sessionDir, fileName);493await fs.promises.writeFile(fileUri.fsPath, fileName.endsWith('.json') ? JSON.stringify({ content }, null, 2) : content, 'utf-8');494} catch (err) {495this._logService.error(`[ChatDebugFileLogger] Failed to write ${fileName}`, err);496}497}498499/**500* Emit a session_start entry, replay cached core events, and write the model snapshot.501* Called when a parent session is first promoted to hasOwnSpans.502*/503private _emitSessionStartAndReplay(sessionId: string, session: IActiveLogSession): void {504this._bufferEntry(sessionId, {505v: 1,506ts: Date.now(),507dur: 0,508sid: sessionId,509type: 'session_start',510name: 'session_start',511spanId: `session-start-${sessionId}`,512status: 'ok',513attrs: {514copilotVersion: this._envService.getVersion(),515vscodeVersion: this._envService.vscodeVersion,516},517});518for (const entry of this._pendingCoreEvents) {519this._bufferEntry(sessionId, { ...entry, sid: sessionId });520}521if (this._modelSnapshot) {522this._enqueueModelSnapshotWrite(session);523}524// Write pending tool definitions that arrived before the session was promoted525if (session.pendingToolDefs) {526const fileName = `tools_${session.toolsIndex}.json`;527session.toolsIndex++;528session.currentToolsFile = fileName;529this._enqueueFileWrite(session, session.pendingToolDefs, fileName);530session.pendingToolDefs = undefined;531}532}533534// ── OTel span handling ──535536private _onSpanCompleted(span: ICompletedSpanData): void {537const sessionId = this._extractSessionId(span);538if (!sessionId) {539return;540}541542// Record the span→session mapping so child spans can inherit it543this._spanSessionIndex.set(span.spanId, sessionId);544if (this._spanSessionIndex.size > MAX_SPAN_SESSION_INDEX) {545// Evict oldest entries (Map iterates in insertion order)546const excess = this._spanSessionIndex.size - MAX_SPAN_SESSION_INDEX;547const iter = this._spanSessionIndex.keys();548for (let i = 0; i < excess; i++) {549this._spanSessionIndex.delete(iter.next().value!);550}551}552553// Check if this span carries parent session info (e.g., title, categorization)554const parentChatSessionId = asString(span.attributes[CopilotChatAttr.PARENT_CHAT_SESSION_ID]);555const debugLogLabel = asString(span.attributes[CopilotChatAttr.DEBUG_LOG_LABEL]);556if (parentChatSessionId && debugLogLabel && !this._childSessionMap.has(sessionId)) {557this._childSessionMap.set(sessionId, { parentSessionId: parentChatSessionId, label: debugLogLabel });558}559560const entry = this._spanToEntry(span, sessionId);561const opName = asString(span.attributes[GenAiAttr.OPERATION_NAME]);562const outputMessages = opName === GenAiOperationName.CHAT563? asString(span.attributes[GenAiAttr.OUTPUT_MESSAGES])564: undefined;565566// Never auto-promote sessions from OTel spans. Sub-requests like567// title generation, categorization, and progress-message generation568// each carry their own session IDs with real CHAT content but should569// not create top-level folders. A session is only promoted to "real"570// (hasOwnSpans = true) when:571// 1. startSession() is called explicitly, or572// 2. A child span references it via PARENT_CHAT_SESSION_ID573// (handled in _ensureSession's child branch).574// 3. The session directory already exists on disk (resumed after restart).575this._ensureSession(sessionId);576577// Auto-promote resumed sessions: if the session was just created with578// hasOwnSpans = false but has an existing JSONL directory from a previous579// extension lifecycle, promote it. This handles sessions continued after580// VS Code restart where title/categorization won't re-fire.581const session = this._activeSessions.get(sessionId);582if (session && !session.hasOwnSpans && !session.parentSessionId && !session.resumeChecked) {583session.resumeChecked = true;584const mainJsonl = URI.joinPath(session.sessionDir, 'main.jsonl');585try {586fs.accessSync(mainJsonl.fsPath);587// Directory exists from a previous run — this is a resumed session588session.hasOwnSpans = true;589session.dirEnsured = true;590591// Determine the run index: read the max rIdx from the existing file + 1592try {593const tail = this._readTailBytes(mainJsonl.fsPath, 8192);594let maxRIdx = 0;595for (const line of tail.split('\n')) {596if (!line.trim()) { continue; }597try {598const parsed = JSON.parse(line);599if (typeof parsed.rIdx === 'number' && parsed.rIdx > maxRIdx) {600maxRIdx = parsed.rIdx;601}602} catch { /* skip malformed lines */ }603}604session.runIndex = maxRIdx + 1;605} catch { /* file read failed — runIndex stays at 0, but that's safe since this is a back-compat path */ }606607// Find the next available indices for companion files to avoid608// overwriting ones from the previous run. Single readdir + scan.609try {610for (const f of fs.readdirSync(session.sessionDir.fsPath)) {611const spIdx = f.startsWith('system_prompt_') ? parseInt(f.slice(14), 10) : -1;612if (spIdx >= session.systemPromptIndex) { session.systemPromptIndex = spIdx + 1; }613const tIdx = f.startsWith('tools_') ? parseInt(f.slice(6), 10) : -1;614if (tIdx >= session.toolsIndex) { session.toolsIndex = tIdx + 1; }615}616} catch { /* readdir failed — indices stay at 0 */ }617} catch {618// No existing directory — leave as is619}620}621622// Write system_prompt JSON when model or mode changes (before buffering so llm_request gets the file ref)623if (opName === GenAiOperationName.CHAT) {624const session = this._activeSessions.get(sessionId);625if (session && session.hasOwnSpans && !session.parentSessionId) {626const model = asString(span.attributes[GenAiAttr.REQUEST_MODEL])627?? asString(span.attributes[GenAiAttr.RESPONSE_MODEL])628?? 'unknown';629const systemInstructions = asString(span.attributes[GenAiAttr.SYSTEM_INSTRUCTIONS]);630if (systemInstructions) {631const key = `${model}:${systemInstructions.length}`;632if (key !== session.systemPromptKey) {633const fileName = `system_prompt_${session.systemPromptIndex}.json`;634session.systemPromptKey = key;635session.systemPromptIndex++;636session.currentSystemPromptFile = fileName;637this._enqueueFileWrite(session, systemInstructions, fileName);638}639}640}641}642643if (entry) {644// Attach current system prompt and tools file references to llm_request entries645if (entry.type === 'llm_request') {646const session = this._activeSessions.get(sessionId);647if (session?.currentSystemPromptFile) {648entry.attrs.systemPromptFile = session.currentSystemPromptFile;649}650if (session?.currentToolsFile) {651entry.attrs.toolsFile = session.currentToolsFile;652}653}654this._bufferEntry(sessionId, entry);655}656657// Note: user_message events are captured in real-time via _onSpanEvent658// (onDidEmitSpanEvent) to avoid duplicates, since span.events also659// contains them after completion.660661// Extract agent_response from output messages (on chat spans)662if (opName === GenAiOperationName.CHAT) {663// Extract agent response summary from output messages664if (outputMessages) {665const reasoningContent = asString(span.attributes[CopilotChatAttr.REASONING_CONTENT]);666this._bufferEntry(sessionId, {667ts: span.endTime,668dur: 0,669sid: sessionId,670type: 'agent_response',671name: 'agent_response',672spanId: `agent-msg-${span.spanId}`,673parentSpanId: span.parentSpanId,674status: 'ok',675attrs: {676response: truncate(outputMessages, MAX_ATTR_VALUE_LENGTH),677...(reasoningContent ? { reasoning: truncate(reasoningContent, MAX_ATTR_VALUE_LENGTH) } : {}),678},679});680}681}682}683684private _onSpanEvent(event: ISpanEventData): void {685if (event.eventName === 'turn_start' || event.eventName === 'turn_end') {686this._onTurnBoundaryEvent(event);687return;688}689690if (event.eventName === 'tools_available') {691this._onToolsAvailableEvent(event);692return;693}694695if (event.eventName !== 'user_message') {696return;697}698const content = event.attributes.content;699if (!content || (typeof content === 'string' && !content.trim())) {700return;701}702703// If the event carries a session ID, route to that specific session704const eventSessionId = event.attributes[CopilotChatAttr.CHAT_SESSION_ID];705if (typeof eventSessionId === 'string') {706// Ensure the session buffer exists so early events (before any span completes) are captured707this._ensureSession(eventSessionId);708this._bufferEntry(eventSessionId, {709ts: event.timestamp,710dur: 0,711sid: eventSessionId,712type: 'user_message',713name: 'user_message',714spanId: event.spanId,715parentSpanId: event.parentSpanId,716status: 'ok',717attrs: {718content: truncate(String(content), MAX_ATTR_VALUE_LENGTH),719},720});721return;722}723724// Fallback: try to inherit session from parent span before broadcasting725const inheritedSessionId = event.parentSpanId ? this._spanSessionIndex.get(event.parentSpanId) : undefined;726if (inheritedSessionId && this._activeSessions.has(inheritedSessionId)) {727this._bufferEntry(inheritedSessionId, {728ts: event.timestamp,729dur: 0,730sid: inheritedSessionId,731type: 'user_message',732name: 'user_message',733spanId: event.spanId,734parentSpanId: event.parentSpanId,735status: 'ok',736attrs: {737content: truncate(String(content), MAX_ATTR_VALUE_LENGTH),738},739});740return;741}742743// Last resort: span events without chat_session_id — write to parent sessions that have their own spans744const parentSessions = [...this._activeSessions.entries()]745.filter(([, session]) => !session.parentSessionId && session.hasOwnSpans)746.map(([id]) => id);747if (parentSessions.length === 0) {748return;749}750751for (const sessionId of parentSessions) {752const entry: IDebugLogEntry = {753ts: event.timestamp,754dur: 0,755sid: sessionId,756type: 'user_message',757name: 'user_message',758spanId: event.spanId,759parentSpanId: event.parentSpanId,760status: 'ok',761attrs: {762content: truncate(String(content), MAX_ATTR_VALUE_LENGTH),763},764};765this._bufferEntry(sessionId, entry);766}767}768769private _onTurnBoundaryEvent(event: ISpanEventData): void {770const type = event.eventName === 'turn_start' ? 'turn_start' : 'turn_end';771const turnId = typeof event.attributes.turnId === 'string' ? event.attributes.turnId : String(event.attributes.turnId ?? '');772const sessionId = typeof event.attributes[CopilotChatAttr.CHAT_SESSION_ID] === 'string'773? event.attributes[CopilotChatAttr.CHAT_SESSION_ID] as string774: (event.parentSpanId ? this._spanSessionIndex.get(event.parentSpanId) : undefined);775776if (!sessionId) {777return;778}779780// Ensure the session buffer exists so early turn events are captured781this._ensureSession(sessionId);782783this._bufferEntry(sessionId, {784ts: event.timestamp,785dur: 0,786sid: sessionId,787type,788name: `${type}:${turnId}`,789spanId: `${type}-${event.spanId}-${turnId}`,790parentSpanId: event.parentSpanId,791status: 'ok',792attrs: { turnId },793});794}795796private _onToolsAvailableEvent(event: ISpanEventData): void {797const sessionId = typeof event.attributes[CopilotChatAttr.CHAT_SESSION_ID] === 'string'798? event.attributes[CopilotChatAttr.CHAT_SESSION_ID] as string799: (event.parentSpanId ? this._spanSessionIndex.get(event.parentSpanId) : undefined);800801if (!sessionId) {802return;803}804805// Do NOT create sessions from tools_available events — they can carry tool call IDs806// (e.g., toolu_xxx, call_xxx) as conversation IDs, which are not valid session IDs.807const session = this._activeSessions.get(sessionId);808if (!session || session.parentSessionId) {809return;810}811812// If the session isn't promoted yet, cache the tools for later replay813if (!session.hasOwnSpans) {814const toolDefs = typeof event.attributes.toolDefinitions === 'string' ? event.attributes.toolDefinitions : undefined;815if (toolDefs) {816session.pendingToolDefs = toolDefs;817}818return;819}820821const toolDefs = typeof event.attributes.toolDefinitions === 'string' ? event.attributes.toolDefinitions : undefined;822if (!toolDefs) {823return;824}825826// Use the content length to detect changes. Different tool sets (from model827// or mode switches) will have different lengths. A false negative (same length,828// different content) just means we skip writing a redundant file — harmless.829const key = `tools:${toolDefs.length}`;830if (key !== session.toolsKey) {831const fileName = `tools_${session.toolsIndex}.json`;832session.toolsKey = key;833session.toolsIndex++;834session.currentToolsFile = fileName;835this._enqueueFileWrite(session, toolDefs, fileName);836}837}838839// ── Core debug event handling (discovery, skill loading, etc.) ──840841private _onCoreDebugEvent(event: vscode.ChatDebugEvent): void {842// Only capture discovery/generic events from core — tool calls, model turns,843// and subagent invocations come from OTel spans which are the source of truth.844if (!(event instanceof vscode.ChatDebugGenericEvent)) {845return;846}847848const timestamp = event.created.getTime();849const eventId = event.id;850const parentEventId = event.parentEventId;851852const entry: IDebugLogEntry = {853ts: timestamp,854dur: 0,855sid: '',856type: event.category === 'discovery' ? 'discovery' : 'generic',857name: event.name,858spanId: eventId ?? `core-${Date.now()}`,859parentSpanId: parentEventId,860status: event.level === vscode.ChatDebugLogLevel.Error ? 'error' : 'ok',861attrs: {862...(event.details ? { details: truncate(event.details, MAX_ATTR_VALUE_LENGTH) } : {}),863...(event.category ? { category: event.category } : {}),864source: 'core',865},866};867868// Core events may arrive before any session exists — cache and replay.869// Cap the buffer to avoid unbounded growth over long-running sessions.870if (this._pendingCoreEvents.length >= MAX_PENDING_CORE_EVENTS) {871this._pendingCoreEvents.shift();872}873this._pendingCoreEvents.push(entry);874// Only write to parent sessions that have their own spans875for (const [sessionId, session] of this._activeSessions.entries()) {876if (!session.parentSessionId && session.hasOwnSpans) {877this._bufferEntry(sessionId, { ...entry, sid: sessionId });878}879}880}881882// ── Span to entry conversion ──883884private _spanToEntry(span: ICompletedSpanData, sessionId: string): IDebugLogEntry | undefined {885const opName = asString(span.attributes[GenAiAttr.OPERATION_NAME]);886const duration = span.endTime - span.startTime;887const isError = span.status.code === SpanStatusCode.ERROR;888889switch (opName) {890case GenAiOperationName.EXECUTE_TOOL: {891const toolName = asString(span.attributes[GenAiAttr.TOOL_NAME]) ?? span.name;892return {893ts: span.startTime,894dur: duration,895sid: sessionId,896type: 'tool_call',897name: toolName,898spanId: span.spanId,899parentSpanId: span.parentSpanId,900status: isError ? 'error' : 'ok',901attrs: {902...(span.attributes[GenAiAttr.TOOL_CALL_ARGUMENTS] !== undefined903? { args: truncate(String(span.attributes[GenAiAttr.TOOL_CALL_ARGUMENTS]), MAX_ATTR_VALUE_LENGTH) }904: {}),905...(span.attributes[GenAiAttr.TOOL_CALL_RESULT] !== undefined906? { result: truncate(String(span.attributes[GenAiAttr.TOOL_CALL_RESULT]), MAX_ATTR_VALUE_LENGTH) }907: {}),908...(isError && span.status.message ? { error: span.status.message } : {}),909},910};911}912913case GenAiOperationName.CHAT: {914const model = asString(span.attributes[GenAiAttr.REQUEST_MODEL])915?? asString(span.attributes[GenAiAttr.RESPONSE_MODEL])916?? 'unknown';917return {918ts: span.startTime,919dur: duration,920sid: sessionId,921type: 'llm_request',922name: `chat:${model}`,923spanId: span.spanId,924parentSpanId: span.parentSpanId,925status: isError ? 'error' : 'ok',926attrs: {927model,928...(span.attributes[GenAiAttr.USAGE_INPUT_TOKENS] !== undefined929? { inputTokens: asNumber(span.attributes[GenAiAttr.USAGE_INPUT_TOKENS]) }930: {}),931...(span.attributes[GenAiAttr.USAGE_OUTPUT_TOKENS] !== undefined932? { outputTokens: asNumber(span.attributes[GenAiAttr.USAGE_OUTPUT_TOKENS]) }933: {}),934...(span.attributes[GenAiAttr.USAGE_CACHE_READ_INPUT_TOKENS] !== undefined935? { cachedTokens: asNumber(span.attributes[GenAiAttr.USAGE_CACHE_READ_INPUT_TOKENS]) }936: {}),937...(span.attributes[CopilotChatAttr.TIME_TO_FIRST_TOKEN] !== undefined938? { ttft: asNumber(span.attributes[CopilotChatAttr.TIME_TO_FIRST_TOKEN]) }939: {}),940...(span.attributes[CopilotChatAttr.USER_REQUEST] !== undefined941? { userRequest: String(span.attributes[CopilotChatAttr.USER_REQUEST]) }942: {}),943...(span.attributes[GenAiAttr.INPUT_MESSAGES] !== undefined944? { inputMessages: String(span.attributes[GenAiAttr.INPUT_MESSAGES]) }945: {}),946...(span.attributes[GenAiAttr.REQUEST_MAX_TOKENS] !== undefined947? { maxTokens: asNumber(span.attributes[GenAiAttr.REQUEST_MAX_TOKENS]) }948: {}),949...(span.attributes[GenAiAttr.REQUEST_TEMPERATURE] !== undefined950? { temperature: asNumber(span.attributes[GenAiAttr.REQUEST_TEMPERATURE]) }951: {}),952...(span.attributes[GenAiAttr.REQUEST_TOP_P] !== undefined953? { topP: asNumber(span.attributes[GenAiAttr.REQUEST_TOP_P]) }954: {}),955...(isError && span.status.message ? { error: span.status.message } : {}),956},957};958}959960case GenAiOperationName.INVOKE_AGENT: {961if (!span.parentSpanId) {962return undefined; // Top-level agent spans are containers963}964const agentName = asString(span.attributes[GenAiAttr.AGENT_NAME]) ?? span.name;965return {966ts: span.startTime,967dur: duration,968sid: sessionId,969type: 'subagent',970name: agentName,971spanId: span.spanId,972parentSpanId: span.parentSpanId,973status: isError ? 'error' : 'ok',974attrs: {975agentName,976...(span.attributes[GenAiAttr.AGENT_DESCRIPTION] !== undefined977? { description: truncate(String(span.attributes[GenAiAttr.AGENT_DESCRIPTION]), MAX_ATTR_VALUE_LENGTH) }978: {}),979...(isError && span.status.message ? { error: span.status.message } : {}),980},981};982}983984case GenAiOperationName.CONTENT_EVENT:985case 'core_event': {986const name = asString(span.attributes[CopilotChatAttr.DEBUG_NAME]) ?? span.name;987return {988ts: span.startTime,989dur: duration,990sid: sessionId,991type: 'generic',992name,993spanId: span.spanId,994parentSpanId: span.parentSpanId,995status: isError ? 'error' : 'ok',996attrs: {997...(span.attributes['copilot_chat.event_details'] !== undefined998? { details: truncate(String(span.attributes['copilot_chat.event_details']), MAX_ATTR_VALUE_LENGTH) }999: {}),1000...(span.attributes['copilot_chat.event_category'] !== undefined1001? { category: String(span.attributes['copilot_chat.event_category']) }1002: {}),1003},1004};1005}10061007case GenAiOperationName.EXECUTE_HOOK: {1008const hookType = asString(span.attributes[CopilotChatAttr.HOOK_TYPE]) ?? span.name;1009return {1010ts: span.startTime,1011dur: duration,1012sid: sessionId,1013type: 'hook',1014name: hookType,1015spanId: span.spanId,1016parentSpanId: span.parentSpanId,1017status: isError ? 'error' : 'ok',1018attrs: {1019...(span.attributes['copilot_chat.hook_command'] !== undefined1020? { command: truncate(String(span.attributes['copilot_chat.hook_command']), MAX_ATTR_VALUE_LENGTH) }1021: {}),1022...(span.attributes[CopilotChatAttr.HOOK_INPUT] !== undefined1023? { input: truncate(String(span.attributes[CopilotChatAttr.HOOK_INPUT]), MAX_ATTR_VALUE_LENGTH) }1024: {}),1025...(span.attributes[CopilotChatAttr.HOOK_OUTPUT] !== undefined1026? { output: truncate(String(span.attributes[CopilotChatAttr.HOOK_OUTPUT]), MAX_ATTR_VALUE_LENGTH) }1027: {}),1028...(span.attributes[CopilotChatAttr.HOOK_RESULT_KIND] !== undefined1029? { resultKind: String(span.attributes[CopilotChatAttr.HOOK_RESULT_KIND]) }1030: {}),1031...(isError && span.status.message ? { error: span.status.message } : {}),1032},1033};1034}10351036default:1037return undefined;1038}1039}10401041// ── Helpers ──10421043/**1044* Read the last `byteCount` bytes of a file synchronously.1045* Used during session resume to determine the max rIdx without reading the entire file.1046*/1047private _readTailBytes(filePath: string, byteCount: number): string {1048const fd = fs.openSync(filePath, 'r');1049try {1050const stat = fs.fstatSync(fd);1051const start = Math.max(0, stat.size - byteCount);1052const buf = Buffer.alloc(Math.min(byteCount, stat.size));1053fs.readSync(fd, buf, 0, buf.length, start);1054return buf.toString('utf-8');1055} finally {1056fs.closeSync(fd);1057}1058}10591060private _extractSessionId(span: ICompletedSpanData): string | undefined {1061const directSessionId = asString(span.attributes[CopilotChatAttr.CHAT_SESSION_ID])1062?? asString(span.attributes[GenAiAttr.CONVERSATION_ID]);10631064// If the span's parentSpanId maps to a known child session, prefer that.1065// This handles hook spans that carry the parent's CHAT_SESSION_ID but1066// whose parent span belongs to a child subagent session.1067if (span.parentSpanId) {1068const childSessionId = this._spanSessionIndex.get(span.parentSpanId);1069if (childSessionId && this._childSessionMap.has(childSessionId)) {1070return childSessionId;1071}1072}10731074return directSessionId1075?? (span.parentSpanId ? this._spanSessionIndex.get(span.parentSpanId) : undefined);1076}10771078private _bufferEntry(sessionId: string, entry: IDebugLogEntry): void {1079const session = this._activeSessions.get(sessionId);1080if (!session) {1081return;1082}1083let stamped = entry;1084// Stamp run index for restart scoping (omit when 0 to save bytes)1085if (session.runIndex > 0 && !stamped.rIdx) {1086stamped = { ...stamped, rIdx: session.runIndex };1087}1088session.buffer.push(JSON.stringify(stamped) + '\n');1089this._onDidEmitEntry.fire({ sessionId, entry: stamped });1090}10911092async readEntries(sessionId: string): Promise<IDebugLogEntry[]> {1093const entries: IDebugLogEntry[] = [];1094await this.streamEntries(sessionId, entry => entries.push(entry));1095return entries;1096}10971098async readTailEntries(sessionId: string, count: number): Promise<IDebugLogEntry[]> {1099const session = this._activeSessions.get(sessionId);1100const logPath = session?.uri ?? this.getLogPath(sessionId);1101let entries: IDebugLogEntry[] = [];11021103if (logPath) {1104try {1105const stat = await fs.promises.stat(logPath.fsPath);1106// Start with a read size that should cover `count` entries.1107// Average JSONL entry is ~1-2KB, so count * 4KB is generous.1108const readSize = Math.min(stat.size, count * 4096);1109const startOffset = Math.max(0, stat.size - readSize);11101111const fd = await fs.promises.open(logPath.fsPath, 'r');1112try {1113const buffer = Buffer.alloc(stat.size - startOffset);1114const { bytesRead } = await fd.read(buffer, 0, buffer.length, startOffset);11151116const text = buffer.subarray(0, bytesRead).toString('utf-8');1117const lines = text.split('\n');1118// Skip the first line if we started mid-file (likely partial)1119const startIdx = startOffset > 0 ? 1 : 0;1120for (let i = startIdx; i < lines.length; i++) {1121if (!lines[i]) { continue; }1122try {1123entries.push(JSON.parse(lines[i]) as IDebugLogEntry);1124} catch { /* skip malformed */ }1125}1126} finally {1127await fd.close();1128}11291130// Keep only the last `count` entries1131if (entries.length > count) {1132entries = entries.slice(-count);1133}1134} catch {1135// File may not exist — that's fine1136}1137}11381139// Append unflushed buffer entries1140if (session) {1141for (const line of session.buffer) {1142try {1143entries.push(JSON.parse(line) as IDebugLogEntry);1144} catch { /* skip malformed */ }1145}1146}11471148// Trim to the last `count` entries (file + buffer combined)1149if (entries.length > count) {1150entries = entries.slice(-count);1151}11521153return entries;1154}11551156async streamEntries(sessionId: string, onEntry: (entry: IDebugLogEntry) => void): Promise<void> {1157const session = this._activeSessions.get(sessionId);1158const logPath = session?.uri ?? this.getLogPath(sessionId);11591160if (logPath) {1161try {1162await new Promise<void>((resolve, reject) => {1163const stream = fs.createReadStream(logPath.fsPath, { encoding: 'utf-8' });1164let partial = '';1165stream.on('data', (chunk) => {1166const text = typeof chunk === 'string' ? chunk : chunk.toString('utf-8');1167partial += text;1168const lines = partial.split('\n');1169// Last element may be a partial line — keep it for next chunk1170partial = lines.pop() ?? '';1171for (const line of lines) {1172if (!line) { continue; }1173try {1174onEntry(JSON.parse(line) as IDebugLogEntry);1175} catch { /* skip malformed */ }1176}1177});1178stream.on('end', () => {1179// Process any remaining partial line1180if (partial) {1181try {1182onEntry(JSON.parse(partial) as IDebugLogEntry);1183} catch { /* skip malformed */ }1184}1185resolve();1186});1187stream.on('error', reject);1188});1189} catch {1190// File may not exist — that's fine1191}1192}11931194// Append unflushed buffer entries1195if (session) {1196for (const line of session.buffer) {1197try {1198onEntry(JSON.parse(line) as IDebugLogEntry);1199} catch { /* skip malformed */ }1200}1201}1202}12031204private async _writeToFile(session: IActiveLogSession, content: string): Promise<void> {1205try {1206if (!session.dirEnsured) {1207await createDirectoryIfNotExists(this._fileSystemService, session.sessionDir);1208session.dirEnsured = true;1209}1210await fs.promises.appendFile(session.uri.fsPath, content, 'utf-8');1211session.bytesWritten += Buffer.byteLength(content, 'utf-8');1212if (session.bytesWritten > this._maxSessionLogBytes) {1213await this._truncateLogFile(session);1214}1215} catch (err) {1216this._logService.error('[ChatDebugFileLogger] Failed to write debug log entries', err);1217}1218}12191220/**1221* Truncate a log file to retain the newest portion (TRUNCATION_RETAIN_RATIO1222* of the configured max size) using a streaming approach via a temp file1223* to avoid loading the entire tail into memory.1224*/1225private async _truncateLogFile(session: IActiveLogSession): Promise<void> {1226try {1227const filePath = session.uri.fsPath;1228const stat = await fs.promises.stat(filePath);1229if (stat.size <= this._maxSessionLogBytes) {1230return;1231}12321233const retainBytes = Math.floor(this._maxSessionLogBytes * TRUNCATION_RETAIN_RATIO);1234const skipBytes = stat.size - retainBytes;1235const fd = await fs.promises.open(filePath, 'r');1236try {1237// Read a small probe around the cut point to find the next newline1238const probe = Buffer.alloc(4096);1239const { bytesRead } = await fd.read(probe, 0, probe.length, skipBytes);1240const newlineIdx = probe.indexOf(0x0A, 0); // '\n'1241const cutOffset = skipBytes + (newlineIdx >= 0 && newlineIdx < bytesRead ? newlineIdx + 1 : 0);12421243const tailSize = stat.size - cutOffset;1244if (tailSize <= 0) {1245await fd.close();1246return;1247}1248await fd.close();12491250// Stream the tail to a temp file, then rename over the original.1251const tmpPath = filePath + '.tmp';1252await new Promise<void>((resolve, reject) => {1253const readStream = fs.createReadStream(filePath, { start: cutOffset });1254const writeStream = fs.createWriteStream(tmpPath);1255const onError = (err: Error) => {1256readStream.destroy();1257writeStream.destroy();1258reject(err);1259};1260readStream.on('error', onError);1261writeStream.on('error', onError);1262writeStream.on('finish', resolve);1263readStream.pipe(writeStream);1264});1265await fs.promises.rename(tmpPath, filePath);1266session.bytesWritten = tailSize;1267/* __GDPR__1268"chatDebugFileLogger.truncated" : {1269"owner": "vijayupadya",1270"comment": "A debug log file was truncated due to size limits",1271"previousSize": { "classification": "SystemMetaData", "purpose": "PerformanceAndHealth", "isMeasurement": true, "comment": "File size in bytes before truncation" },1272"retainedSize": { "classification": "SystemMetaData", "purpose": "PerformanceAndHealth", "isMeasurement": true, "comment": "File size in bytes after truncation" }1273}1274*/1275this._telemetryService.sendMSFTTelemetryEvent('chatDebugFileLogger.truncated', undefined, { previousSize: stat.size, retainedSize: tailSize });1276} catch (innerErr) {1277await fd.close().catch(() => { });1278// Clean up temp file if it exists1279await fs.promises.unlink(filePath + '.tmp').catch(() => { });1280throw innerErr;1281}1282} catch (err) {1283this._logService.warn(`[ChatDebugFileLogger] Failed to truncate log file: ${err}`);1284/* __GDPR__1285"chatDebugFileLogger.truncateFailed" : {1286"owner": "vijayupadya",1287"comment": "Failed to truncate a debug log file"1288}1289*/1290this._telemetryService.sendMSFTTelemetryEvent('chatDebugFileLogger.truncateFailed');1291}1292}12931294private _autoFlushAll(): void {1295for (const sessionId of this._activeSessions.keys()) {1296this.flush(sessionId).catch(() => { });1297}1298}12991300private _restartFlushTimer(): void {1301if (this._autoFlushTimer) {1302clearInterval(this._autoFlushTimer);1303this._autoFlushTimer = undefined;1304}1305if (this._activeSessions.size > 0) {1306this._autoFlushTimer = setInterval(() => this._autoFlushAll(), this._autoFlushIntervalMs);1307}1308}13091310async listSessionIds(): Promise<string[]> {1311const dir = this._getDebugLogsDir();1312if (!dir) {1313return [];1314}1315try {1316const entries = await this._fileSystemService.readDirectory(dir);1317const dirs = entries.filter(([, type]) => type === 2 /* FileType.Directory */);13181319// Stat each directory in parallel to sort by most recently modified.1320const withMtime = await Promise.all(dirs.map(async ([name]) => {1321try {1322const stat = await this._fileSystemService.stat(URI.joinPath(dir, name));1323return { name, mtime: stat.mtime };1324} catch {1325return { name, mtime: 0 };1326}1327}));1328withMtime.sort((a, b) => b.mtime - a.mtime);1329return withMtime.map(e => e.name);1330} catch {1331return [];1332}1333}13341335private async _cleanupOldLogs(): Promise<void> {1336const dir = this._getDebugLogsDir();1337if (!dir) {1338return;1339}13401341const startTime = Date.now();1342try {1343const entries = await this._fileSystemService.readDirectory(dir);1344// Count both directories (new format) and legacy .jsonl files (old format)1345const sessionEntries = entries.filter(([name, type]) =>1346(type === 2 /* FileType.Directory */) ||1347(name.endsWith('.jsonl') && type === 1 /* FileType.File */)1348);13491350const configuredMax = this._configurationService.getExperimentBasedConfig(ConfigKey.Advanced.ChatDebugFileLoggingMaxRetainedSessionLogs, this._experimentationService);1351const maxRetainedSessionLogs = Number.isFinite(configuredMax) && configuredMax >= 1 ? Math.trunc(configuredMax) : DEFAULT_MAX_RETAINED_LOGS;1352if (sessionEntries.length <= maxRetainedSessionLogs) {1353/* __GDPR__1354"chatDebugFileLogger.cleanupOldLogs" : {1355"owner": "vijayupadya",1356"comment": "Old debug log files were cleaned up",1357"durationMs": { "classification": "SystemMetaData", "purpose": "PerformanceAndHealth", "isMeasurement": true, "comment": "Time in ms to perform cleanup" },1358"entryCount": { "classification": "SystemMetaData", "purpose": "PerformanceAndHealth", "isMeasurement": true, "comment": "Total number of log entries found" },1359"deletedCount": { "classification": "SystemMetaData", "purpose": "PerformanceAndHealth", "isMeasurement": true, "comment": "Number of log entries deleted" }1360}1361*/1362this._telemetryService.sendMSFTTelemetryEvent('chatDebugFileLogger.cleanupOldLogs', undefined, { durationMs: Date.now() - startTime, entryCount: sessionEntries.length, deletedCount: 0 });1363return;1364}13651366const entryStats = await Promise.all(1367sessionEntries.map(async ([name, type]) => {1368const entryUri = URI.joinPath(dir, name);1369const sessionIdFromEntry = name.replace('.jsonl', '');1370try {1371const stat = await this._fileSystemService.stat(entryUri);1372return { name, uri: entryUri, mtime: stat.mtime, sessionId: sessionIdFromEntry, isDir: type === 2 };1373} catch {1374return { name, uri: entryUri, mtime: 0, sessionId: sessionIdFromEntry, isDir: type === 2 };1375}1376}),1377);13781379entryStats.sort((a, b) => a.mtime - b.mtime);13801381const toDelete = entryStats.length - maxRetainedSessionLogs;1382let deleted = 0;1383for (const entry of entryStats) {1384if (deleted >= toDelete) {1385break;1386}1387if (this._activeSessions.has(entry.sessionId)) {1388continue;1389}1390try {1391await this._fileSystemService.delete(entry.uri, { recursive: true });1392deleted++;1393} catch {1394this._logService.warn(`[ChatDebugFileLogger] Failed to delete old debug log: ${entry.name}`);1395}1396}1397// GDPR comment above covers this event1398this._telemetryService.sendMSFTTelemetryEvent('chatDebugFileLogger.cleanupOldLogs', undefined, { durationMs: Date.now() - startTime, entryCount: sessionEntries.length, deletedCount: deleted });1399} catch {1400// Directory may not exist yet1401}1402}1403}14041405/**1406* Contribution that eagerly instantiates the ChatDebugFileLoggerService1407* so it starts listening to OTel events at activation time.1408*/1409export class ChatDebugFileLoggerContribution implements IExtensionContribution {1410public readonly id = 'chatDebugFileLoggerContribution';14111412constructor(1413@IChatDebugFileLoggerService _service: IChatDebugFileLoggerService,1414) {1415// The DI resolution of IChatDebugFileLoggerService triggers1416// construction of the singleton, which subscribes to events.1417}1418}14191420function asString(v: unknown): string | undefined {1421return typeof v === 'string' ? v : undefined;1422}14231424function asNumber(v: unknown): number | undefined {1425return typeof v === 'number' ? v : undefined;1426}14271428function truncate(s: string, maxLen: number): string {1429return s.length > maxLen ? s.slice(0, maxLen) + '[truncated]' : s;1430}143114321433