You signed in with another tab or window. Reload to refresh your session.You signed out in another tab or window. Reload to refresh your session.You switched accounts on another tab or window. Reload to refresh your session.Dismiss alert
PR #916 introduced a session-scoped session.log that consolidates session output audit lines and session-scoped MEL diagnostics into a single canonical per-session file. The current implementation works for the MVP but carries a few structural problems we want to address before they bite under load.
Problems
1. Two writers to the same file, coordinated by a leaking dictionary
Two independent code paths call SessionLogFile.AppendLine(sessionId, basePath, line):
SessionLogActor — receives SendUserMessage and SessionOutput from the session pipeline and writes audit lines.
RollingFileLoggerProvider.TryWriteSessionLog — invoked from RollingFileLogger.Log<TState> whenever a MEL log call fires under a populated SessionDiagnosticsContext.
To prevent torn writes from concurrent threads, SessionLogFile keeps a ConcurrentDictionary<string, Lock> FileLocks keyed by log path and locks per file inside AppendLine. The dictionary has no eviction tied to session lifecycle, so each unique session path the daemon ever serves accumulates a Lock instance for the lifetime of the process.
Net: the lock dictionary is a slow leak (small magnitude, but unbounded), and its existence is purely a workaround for the fact that we have two writers.
2. Synchronous file I/O on the MEL log hot path
RollingFileLoggerProvider.Enqueue writes the daemon-global log line via a background BlockingCollection<string> queue (cheap, non-blocking on the caller). For session-scoped lines it delegates to TryWriteSessionLog, which performs File.Open + per-path lock + WriteLine + Flush + Dispose synchronously on the caller's thread.
Daemon log path: async. Session log path: sync. This is inconsistent and bad under load. During a streaming-token burst on a session-owned thread with debug logging enabled, every diagnostic emit is a blocking file operation on the LLM streaming continuation thread.
3. No chronological ordering guarantee across writers
Even with the per-path lock, audit and diagnostic lines for the same session can interleave at write time depending on which thread acquires the lock first. The lock prevents corruption but does not preserve the wall-clock order of producer-side events when two writers race on the same line.
Redesign: actor as single writer
Make SessionLogActor the only thing that ever calls SessionLogFile.AppendLine for a given session. Diagnostic lines route to it through Akka instead of being written from the MEL provider's caller thread.
Components
SessionLogDispatcher — root actor, registered via Akka.Hosting. Receives SessionLogAudit(sessionId, payload) and SessionLogDiagnostic(sessionId, line). Routes each message to a child SessionLogActor named by sanitized session id, lazy-creating the child on first use.
SessionLogActor — child of the dispatcher. Receives both audit and diagnostic messages, writes via SessionLogFile.AppendLine. Configurable ReceiveTimeout evicts the child on idle (default ~10 minutes).
RollingFileLoggerProvider — takes IRequiredActor<SessionLogDispatcher>. The daemon-log path is unchanged. The session-scoped branch reads SessionDiagnosticsContext.SessionId synchronously at log-emit time, snapshots it into a SessionLogDiagnostic message, and Tells the dispatcher.
LlmSessionActor — stops creating SessionLogActor directly; sends SessionLogAudit to the dispatcher.
What this fixes
Problem
Resolution
Two-writer coordination
One actor, one mailbox per session = single writer per file.
Lock dictionary leak
Deleted entirely. Akka's child registry replaces it; eviction is ReceiveTimeout-driven and lifecycle-managed.
Sync file I/O on log hot path
Replaced with Tell (non-blocking). File write happens on the actor's dispatched thread.
Chronological ordering
Single mailbox per session = wall-clock-faithful timeline by construction.
Why AsyncLocal is sufficient (and why we do not need structured-logging belt-and-suspenders)
Session-owned LLM calls happen inside actor message handlers. Each handler is one continuous async flow:
Handler enters, executes using var scope = SessionDiagnosticsContext.Push(sessionId.Value).
Handler awaits the chat client. All internal awaits inside the chat client (HTTP send, SSE read loop, response parsing) are continuations of that one flow.
ExecutionContext flows through every await, so SessionDiagnosticsContext.SessionId is correct on every continuation thread.
MEL log calls inside the chat client run synchronously on the current continuation thread. The provider reads SessionDiagnosticsContext.SessionId at log-emit time and snapshots it into the message it sends to the dispatcher.
Handler returns; scope disposes; AsyncLocal cleared. Next message handler starts on a clean slate (actors are serial per mailbox).
Issue #915 will add a Roslyn analyzer that ensures the Push(sessionId) scope is in place at every session-owned IChatClient call site. That single contract — combined with standard await/ExecutionContext flow — is enough. We do not need BeginScope("SessionId") or {SessionId} template parameters in every log line.
Pre-resolution buffering
RollingFileLoggerProvider is constructed before the ActorSystem. It uses the Task<IActorRef>-shaped accessor on IRequiredActor<SessionLogDispatcher> and a small bounded ConcurrentQueue to handle the boot window. In practice this is academic — SessionDiagnosticsContext only gets populated from inside actor handlers, which by definition run after the system is up — but the queue exists to make the contract robust against any theoretical race during startup.
Out of scope (separate issues)
No size cap on session.log. The daemon log rolls at 10 MB; session.log does not. A noisy session can fill disk over time. Tracked separately.
Background
PR #916 introduced a session-scoped
session.logthat consolidates session output audit lines and session-scoped MEL diagnostics into a single canonical per-session file. The current implementation works for the MVP but carries a few structural problems we want to address before they bite under load.Problems
1. Two writers to the same file, coordinated by a leaking dictionary
Two independent code paths call
SessionLogFile.AppendLine(sessionId, basePath, line):SessionLogActor— receivesSendUserMessageandSessionOutputfrom the session pipeline and writes audit lines.RollingFileLoggerProvider.TryWriteSessionLog— invoked fromRollingFileLogger.Log<TState>whenever a MEL log call fires under a populatedSessionDiagnosticsContext.To prevent torn writes from concurrent threads,
SessionLogFilekeeps aConcurrentDictionary<string, Lock> FileLockskeyed by log path and locks per file insideAppendLine. The dictionary has no eviction tied to session lifecycle, so each unique session path the daemon ever serves accumulates aLockinstance for the lifetime of the process.Net: the lock dictionary is a slow leak (small magnitude, but unbounded), and its existence is purely a workaround for the fact that we have two writers.
2. Synchronous file I/O on the MEL log hot path
RollingFileLoggerProvider.Enqueuewrites the daemon-global log line via a backgroundBlockingCollection<string>queue (cheap, non-blocking on the caller). For session-scoped lines it delegates toTryWriteSessionLog, which performsFile.Open+ per-path lock +WriteLine+Flush+Disposesynchronously on the caller's thread.Daemon log path: async. Session log path: sync. This is inconsistent and bad under load. During a streaming-token burst on a session-owned thread with debug logging enabled, every diagnostic emit is a blocking file operation on the LLM streaming continuation thread.
3. No chronological ordering guarantee across writers
Even with the per-path lock, audit and diagnostic lines for the same session can interleave at write time depending on which thread acquires the lock first. The lock prevents corruption but does not preserve the wall-clock order of producer-side events when two writers race on the same line.
Redesign: actor as single writer
Make
SessionLogActorthe only thing that ever callsSessionLogFile.AppendLinefor a given session. Diagnostic lines route to it through Akka instead of being written from the MEL provider's caller thread.Components
SessionLogDispatcher— root actor, registered via Akka.Hosting. ReceivesSessionLogAudit(sessionId, payload)andSessionLogDiagnostic(sessionId, line). Routes each message to a childSessionLogActornamed by sanitized session id, lazy-creating the child on first use.SessionLogActor— child of the dispatcher. Receives both audit and diagnostic messages, writes viaSessionLogFile.AppendLine. ConfigurableReceiveTimeoutevicts the child on idle (default ~10 minutes).RollingFileLoggerProvider— takesIRequiredActor<SessionLogDispatcher>. The daemon-log path is unchanged. The session-scoped branch readsSessionDiagnosticsContext.SessionIdsynchronously at log-emit time, snapshots it into aSessionLogDiagnosticmessage, andTells the dispatcher.LlmSessionActor— stops creatingSessionLogActordirectly; sendsSessionLogAuditto the dispatcher.What this fixes
ReceiveTimeout-driven and lifecycle-managed.Tell(non-blocking). File write happens on the actor's dispatched thread.Why
AsyncLocalis sufficient (and why we do not need structured-logging belt-and-suspenders)Session-owned LLM calls happen inside actor message handlers. Each handler is one continuous async flow:
using var scope = SessionDiagnosticsContext.Push(sessionId.Value).ExecutionContextflows through every await, soSessionDiagnosticsContext.SessionIdis correct on every continuation thread.SessionDiagnosticsContext.SessionIdat log-emit time and snapshots it into the message it sends to the dispatcher.Issue #915 will add a Roslyn analyzer that ensures the
Push(sessionId)scope is in place at every session-ownedIChatClientcall site. That single contract — combined with standardawait/ExecutionContextflow — is enough. We do not needBeginScope("SessionId")or{SessionId}template parameters in every log line.Pre-resolution buffering
RollingFileLoggerProvideris constructed before the ActorSystem. It uses theTask<IActorRef>-shaped accessor onIRequiredActor<SessionLogDispatcher>and a small boundedConcurrentQueueto handle the boot window. In practice this is academic —SessionDiagnosticsContextonly gets populated from inside actor handlers, which by definition run after the system is up — but the queue exists to make the contract robust against any theoretical race during startup.Out of scope (separate issues)
session.log. The daemon log rolls at 10 MB;session.logdoes not. A noisy session can fill disk over time. Tracked separately.SessionDiagnosticsContext. Compaction, title generation, sub-agent invocations, and other session-owned but non-SessionLlmInvokerpaths do not currently set the diagnostics scope. Tracked in analyzer: flag session-owned chat client calls outside session diagnostics context #915 (analyzer scope) and a separate cleanup pass.Acceptance criteria
SessionLogFile.FileLocksand the lock block inAppendLineare deleted.RollingFileLoggerProviderno longer performs synchronous file I/O on the session-scoped branch.SessionLogActorreceives both audit and diagnostic messages and is the only caller ofSessionLogFile.AppendLine.Reference
SessionDiagnosticsContext.Pushat LLM call sites)