From d334b5aab536030e91c95a98599a461dd5158d07 Mon Sep 17 00:00:00 2001 From: Tyrie Vella Date: Tue, 26 May 2026 13:22:42 -0700 Subject: [PATCH 1/2] Defer and retry telemetry pipe attachment for GVFS.Service GVFS.Service runs as SYSTEM and cannot read the user's global git config (where gvfs.telemetry-pipe is set) at startup. This meant TelemetryDaemonEventListener was never created, and all service telemetry events (PendingUpgradeHandler, etc.) were silently lost. Add two new classes in GVFS.Common.Tracing: - BufferingTelemetryListener: an EventListener that buffers telemetry messages in a bounded ConcurrentQueue, then replays them to a real listener on demand. - DeferredTelemetryAttacher: manages the lifecycle of deferred telemetry pipe attachment. Adds a BufferingTelemetryListener to the tracer, then periodically retries creating the real daemon listener (exponential backoff: 10s, 30s, 1m, 5m steady state). On success, replays buffered messages and stops the timer. Checks HasTelemetryDaemonListener to prevent duplicate listeners when the JsonTracer constructor already attached one. Designed for reuse by both GVFS.Service and GVFS.Mount. TelemetryDaemonEventListener gains a globalConfigPath parameter so callers can read a specific .gitconfig file via --file instead of --global. This lets GVFSService read the logged-on user's config without mutating the process-wide HOME environment variable. GVFSService creates a DeferredTelemetryAttacher at startup and calls TryAttach on session logon events, passing the user's .gitconfig path resolved via RunImpersonated. JsonTracer gains only HasTelemetryDaemonListener (one-liner property) to support the duplicate-listener guard. Assisted-by: Claude Opus 4.6 Signed-off-by: Tyrie Vella --- GVFS/GVFS.Common/NativeMethods.cs | 13 ++ .../Tracing/BufferingTelemetryListener.cs | 83 +++++++ .../Tracing/DeferredTelemetryAttacher.cs | 208 ++++++++++++++++++ GVFS/GVFS.Common/Tracing/JsonTracer.cs | 8 + .../Tracing/TelemetryDaemonEventListener.cs | 27 ++- GVFS/GVFS.Service/GVFSService.Windows.cs | 84 +++++++ 6 files changed, 420 insertions(+), 3 deletions(-) create mode 100644 GVFS/GVFS.Common/Tracing/BufferingTelemetryListener.cs create mode 100644 GVFS/GVFS.Common/Tracing/DeferredTelemetryAttacher.cs diff --git a/GVFS/GVFS.Common/NativeMethods.cs b/GVFS/GVFS.Common/NativeMethods.cs index 01282679e..1fae6876d 100644 --- a/GVFS/GVFS.Common/NativeMethods.cs +++ b/GVFS/GVFS.Common/NativeMethods.cs @@ -247,6 +247,19 @@ private static extern bool DeviceIoControl( [DllImport("kernel32.dll")] private static extern ulong GetTickCount64(); + [DllImport("kernel32.dll")] + private static extern int WTSGetActiveConsoleSessionId(); + + /// + /// Returns the session ID of the physical console session, or -1 if + /// no interactive session is active (e.g. at boot before logon). + /// + public static int GetActiveConsoleSessionId() + { + int sessionId = WTSGetActiveConsoleSessionId(); + return sessionId == unchecked((int)0xFFFFFFFF) ? -1 : sessionId; + } + [DllImport("kernel32.dll", SetLastError = true)] private static extern bool SetFileTime( SafeFileHandle hFile, diff --git a/GVFS/GVFS.Common/Tracing/BufferingTelemetryListener.cs b/GVFS/GVFS.Common/Tracing/BufferingTelemetryListener.cs new file mode 100644 index 000000000..58af567ee --- /dev/null +++ b/GVFS/GVFS.Common/Tracing/BufferingTelemetryListener.cs @@ -0,0 +1,83 @@ +using System.Collections.Concurrent; + +namespace GVFS.Common.Tracing +{ + /// + /// An EventListener that buffers telemetry messages in memory. After + /// a real listener is attached via , buffered + /// messages are replayed and this listener becomes a no-op. + /// + public class BufferingTelemetryListener : EventListener + { + public const int DefaultMaxBufferedMessages = 1000; + + private ConcurrentQueue buffer = new ConcurrentQueue(); + private readonly int maxBufferedMessages; + private volatile bool stopped; + + public BufferingTelemetryListener(int maxBufferedMessages = DefaultMaxBufferedMessages) + : base(EventLevel.Verbose, Keywords.Telemetry, eventSink: null) + { + this.maxBufferedMessages = maxBufferedMessages; + } + + /// + /// Number of messages currently buffered. + /// + public int BufferedCount => this.buffer?.Count ?? 0; + + /// + /// Whether this listener has been stopped (replay completed). + /// + public bool IsStopped => this.stopped; + + /// + /// Replays all buffered messages to and + /// stops further buffering. This listener remains in the tracer's + /// listener list but becomes a no-op. Safe to call multiple times; + /// only the first call replays. + /// + /// Number of messages replayed. + public int ReplayAndStop(EventListener target) + { + if (this.stopped) + { + return 0; + } + + this.stopped = true; + ConcurrentQueue queue = this.buffer; + this.buffer = null; + + int count = 0; + if (queue != null) + { + while (queue.TryDequeue(out TraceEventMessage message)) + { + target.RecordMessage(message); + count++; + } + } + + return count; + } + + protected override void RecordMessageInternal(TraceEventMessage message) + { + if (this.stopped) + { + return; + } + + // Soft cap: under high concurrency, a few messages may exceed + // maxBufferedMessages because Count and Enqueue are not atomic. + // This is acceptable — the cap prevents unbounded growth, and + // a small overshoot is harmless. + ConcurrentQueue queue = this.buffer; + if (queue != null && queue.Count < this.maxBufferedMessages) + { + queue.Enqueue(message); + } + } + } +} diff --git a/GVFS/GVFS.Common/Tracing/DeferredTelemetryAttacher.cs b/GVFS/GVFS.Common/Tracing/DeferredTelemetryAttacher.cs new file mode 100644 index 000000000..1dc68a072 --- /dev/null +++ b/GVFS/GVFS.Common/Tracing/DeferredTelemetryAttacher.cs @@ -0,0 +1,208 @@ +using System; +using System.Threading; + +namespace GVFS.Common.Tracing +{ + /// + /// Manages deferred telemetry pipe attachment for processes that cannot + /// read the pipe config at startup (e.g. GVFS.Service running as SYSTEM, + /// or any process started before the telemetry collector is installed). + /// + /// Adds a to the tracer at + /// construction time, then periodically retries creating a real + /// . On success, buffered + /// messages are replayed and the retry timer stops. + /// + /// Callers can also trigger an explicit attach attempt via + /// — e.g. on session logon when the + /// user's HOME is available. + /// + /// Designed for reuse by both GVFS.Service and GVFS.Mount. + /// + public class DeferredTelemetryAttacher : IDisposable + { + private readonly JsonTracer tracer; + private readonly BufferingTelemetryListener buffer; + private readonly string providerName; + private readonly string enlistmentId; + private readonly string mountId; + private readonly Lock attachLock = new Lock(); + + private Timer retryTimer; + private string retryGitBinRoot; + private int retryCount; + private bool attached; + private bool disposed; + + public DeferredTelemetryAttacher( + JsonTracer tracer, + string providerName, + string enlistmentId, + string mountId) + { + this.tracer = tracer; + this.providerName = providerName; + this.enlistmentId = enlistmentId; + this.mountId = mountId; + this.buffer = new BufferingTelemetryListener(); + tracer.AddEventListener(this.buffer); + } + + public bool IsAttached + { + get + { + lock (this.attachLock) + { + return this.attached; + } + } + } + + /// + /// Starts a background retry timer that periodically calls + /// with the given gitBinRoot. Uses + /// exponential backoff: 10s, 30s, 1m, then 5m steady state. + /// + public void StartRetryTimer(string gitBinRoot) + { + lock (this.attachLock) + { + if (this.attached || this.disposed || this.retryTimer != null) + { + return; + } + + this.retryGitBinRoot = gitBinRoot; + this.retryCount = 0; + this.retryTimer = new Timer( + this.OnRetryTimer, + null, + GetRetryInterval(0), + Timeout.Infinite); + } + } + + /// + /// Attempts to create and attach a TelemetryDaemonEventListener. + /// Call this when environment conditions change (e.g. user session + /// becomes available). Replays buffered messages on success. + /// Safe to call multiple times — no-ops after first successful attach. + /// + /// Path to git binary. + /// + /// If non-null, reads this file with git config --file instead + /// of --global. Use this when the caller needs to read another + /// user's .gitconfig without mutating the process-wide HOME variable. + /// + /// true if attached (now or previously). + public bool TryAttach(string gitBinRoot, string globalConfigPath = null) + { + lock (this.attachLock) + { + if (this.attached || this.tracer.HasTelemetryDaemonListener) + { + return true; + } + + if (string.IsNullOrEmpty(gitBinRoot)) + { + return false; + } + + TelemetryDaemonEventListener daemonListener; + try + { + daemonListener = TelemetryDaemonEventListener.CreateIfEnabled( + gitBinRoot, + this.providerName, + this.enlistmentId, + this.mountId, + this.tracer, + globalConfigPath); + } + catch (Exception) + { + return false; + } + + if (daemonListener == null) + { + return false; + } + + this.tracer.AddEventListener(daemonListener); + int replayed = this.buffer.ReplayAndStop(daemonListener); + this.StopRetryTimer(); + this.attached = true; + + this.tracer.RelatedInfo( + "DeferredTelemetryAttacher: Attached, replayed {0} buffered messages", + replayed); + + return true; + } + } + + public void Dispose() + { + lock (this.attachLock) + { + if (this.disposed) + { + return; + } + + this.disposed = true; + this.StopRetryTimer(); + } + } + + internal static int GetRetryInterval(int retryCount) + { + return retryCount switch + { + 0 => 10_000, // 10 seconds + 1 => 30_000, // 30 seconds + 2 => 60_000, // 1 minute + _ => 300_000, // 5 minutes + }; + } + + private void StopRetryTimer() + { + // Must be called while holding attachLock + if (this.retryTimer != null) + { + this.retryTimer.Dispose(); + this.retryTimer = null; + } + } + + private void OnRetryTimer(object state) + { + try + { + bool success = this.TryAttach(this.retryGitBinRoot); + if (!success) + { + lock (this.attachLock) + { + if (this.retryTimer != null && !this.disposed) + { + this.retryCount++; + this.retryTimer.Change( + GetRetryInterval(this.retryCount), + Timeout.Infinite); + } + } + } + } + catch (Exception) + { + // Swallow — timer will not reschedule, but the explicit + // TryAttach path (e.g. on SessionLogon) can still succeed. + } + } + } +} diff --git a/GVFS/GVFS.Common/Tracing/JsonTracer.cs b/GVFS/GVFS.Common/Tracing/JsonTracer.cs index c494bd012..cc74cb71d 100644 --- a/GVFS/GVFS.Common/Tracing/JsonTracer.cs +++ b/GVFS/GVFS.Common/Tracing/JsonTracer.cs @@ -81,6 +81,14 @@ public bool HasLogFileEventListener } } + public bool HasTelemetryDaemonListener + { + get + { + return this.listeners.Any(listener => listener is TelemetryDaemonEventListener); + } + } + public void SetGitCommandSessionId(string sessionId) { TelemetryDaemonEventListener daemonListener = this.listeners.FirstOrDefault(x => x is TelemetryDaemonEventListener) as TelemetryDaemonEventListener; diff --git a/GVFS/GVFS.Common/Tracing/TelemetryDaemonEventListener.cs b/GVFS/GVFS.Common/Tracing/TelemetryDaemonEventListener.cs index 35e517a42..17dc588bb 100644 --- a/GVFS/GVFS.Common/Tracing/TelemetryDaemonEventListener.cs +++ b/GVFS/GVFS.Common/Tracing/TelemetryDaemonEventListener.cs @@ -37,9 +37,22 @@ private TelemetryDaemonEventListener( public string GitCommandSessionId { get; set; } public static TelemetryDaemonEventListener CreateIfEnabled(string gitBinRoot, string providerName, string enlistmentId, string mountId, IEventListenerEventSink eventSink) + { + return CreateIfEnabled(gitBinRoot, providerName, enlistmentId, mountId, eventSink, globalConfigPath: null); + } + + /// + /// Creates a TelemetryDaemonEventListener if the telemetry pipe config + /// is set. When is provided, reads + /// that file directly instead of using git config --global. + /// This avoids mutating the process-wide HOME environment variable + /// when the caller needs to read another user's config (e.g. + /// GVFS.Service reading the logged-on user's .gitconfig). + /// + public static TelemetryDaemonEventListener CreateIfEnabled(string gitBinRoot, string providerName, string enlistmentId, string mountId, IEventListenerEventSink eventSink, string globalConfigPath) { // This listener is disabled unless the user specifies the proper git config setting. - string telemetryPipe = GetConfigValue(gitBinRoot, GVFSConstants.GitConfig.GVFSTelemetryPipe); + string telemetryPipe = GetConfigValue(gitBinRoot, GVFSConstants.GitConfig.GVFSTelemetryPipe, globalConfigPath); if (!string.IsNullOrEmpty(telemetryPipe)) { return new TelemetryDaemonEventListener(providerName, enlistmentId, mountId, telemetryPipe, eventSink); @@ -90,7 +103,7 @@ protected override void RecordMessageInternal(TraceEventMessage message) } } - private static string GetConfigValue(string gitBinRoot, string configKey) + private static string GetConfigValue(string gitBinRoot, string configKey, string globalConfigPath = null) { string value = string.Empty; string error; @@ -98,7 +111,15 @@ private static string GetConfigValue(string gitBinRoot, string configKey) GitProcess.ConfigResult result = GitProcess.GetFromSystemConfig(gitBinRoot, configKey); if (!result.TryParseAsString(out value, out error, defaultValue: string.Empty) || string.IsNullOrWhiteSpace(value)) { - result = GitProcess.GetFromGlobalConfig(gitBinRoot, configKey); + if (!string.IsNullOrEmpty(globalConfigPath)) + { + result = GitProcess.GetFromFileConfig(gitBinRoot, globalConfigPath, configKey); + } + else + { + result = GitProcess.GetFromGlobalConfig(gitBinRoot, configKey); + } + result.TryParseAsString(out value, out error, defaultValue: string.Empty); } diff --git a/GVFS/GVFS.Service/GVFSService.Windows.cs b/GVFS/GVFS.Service/GVFSService.Windows.cs index 72a313a9d..c7f125b83 100644 --- a/GVFS/GVFS.Service/GVFSService.Windows.cs +++ b/GVFS/GVFS.Service/GVFSService.Windows.cs @@ -8,6 +8,7 @@ using System.IO; using System.Linq; using System.Security.AccessControl; +using System.Security.Principal; using System.ServiceProcess; using System.Threading; @@ -27,6 +28,7 @@ public class GVFSService : ServiceBase private WindowsRequestHandler requestHandler; private INotificationHandler notificationHandler; private PendingUpgradeMonitor pendingUpgradeMonitor; + private DeferredTelemetryAttacher telemetryAttacher; public GVFSService(JsonTracer tracer) { @@ -75,6 +77,29 @@ public void Run() { this.CheckEnableGitStatusCacheTokenFile(); + // Set up deferred telemetry pipe attachment. The service + // runs as SYSTEM and can't read the user's global git + // config at startup, so the daemon listener can't be + // created in the JsonTracer constructor. + string gitBinRoot = GVFSPlatform.Instance.GitInstallation.GetInstalledGitBinPath(); + if (!string.IsNullOrEmpty(gitBinRoot)) + { + this.telemetryAttacher = new DeferredTelemetryAttacher( + this.tracer, + GVFSConstants.Service.ServiceName, + enlistmentId: null, + mountId: null); + this.telemetryAttacher.StartRetryTimer(gitBinRoot); + + // If a user is already logged in (e.g. service restart + // during active session), try attaching immediately. + int activeSession = NativeMethods.GetActiveConsoleSessionId(); + if (activeSession > 0) + { + this.TryAttachTelemetryPipeForSession(activeSession); + } + } + using (ITracer activity = this.tracer.StartActivity("EnsurePrjFltHealthy", EventLevel.Informational)) { // Make a best-effort to enable PrjFlt. Continue even if it fails. @@ -106,6 +131,12 @@ public void StopRunning() this.tracer.RelatedInfo("Stopping"); } + if (this.telemetryAttacher != null) + { + this.telemetryAttacher.Dispose(); + this.telemetryAttacher = null; + } + if (this.pendingUpgradeMonitor != null) { this.pendingUpgradeMonitor.Dispose(); @@ -147,6 +178,11 @@ protected override void OnSessionChange(SessionChangeDescription changeDescripti { this.tracer.RelatedInfo("SessionLogon detected, sessionId: {0}", changeDescription.SessionId); + // Attempt to attach the telemetry pipe now that a user + // session is available. Buffered pre-logon events are + // replayed. No-ops if already attached. + this.TryAttachTelemetryPipeForSession(changeDescription.SessionId); + using (ITracer activity = this.tracer.StartActivity("LogonAutomount", EventLevel.Informational)) { this.repoRegistry.AutoMountRepos( @@ -391,6 +427,54 @@ private void CreateAndConfigureLogDirectory(string path) } } + /// + /// Resolves the logged-on user's profile directory and passes their + /// .gitconfig path directly to the deferred attacher, which reads it + /// with git config --file. This avoids mutating the + /// process-wide HOME environment variable, which would leak into + /// any concurrent git operations in the service. + /// + private void TryAttachTelemetryPipeForSession(int sessionId) + { + if (this.telemetryAttacher == null || this.telemetryAttacher.IsAttached) + { + return; + } + + try + { + using (CurrentUser user = new CurrentUser(this.tracer, sessionId)) + { + if (user.Identity == null) + { + this.tracer.RelatedWarning("TryAttachTelemetryPipe: Could not get user identity for session {0}", sessionId); + return; + } + + string gitBinRoot = GVFSPlatform.Instance.GitInstallation.GetInstalledGitBinPath(); + + string userProfile = null; + WindowsIdentity.RunImpersonated(user.Identity.AccessToken, () => + { + userProfile = Environment.GetFolderPath(Environment.SpecialFolder.UserProfile); + }); + + if (string.IsNullOrEmpty(userProfile)) + { + this.tracer.RelatedWarning("TryAttachTelemetryPipe: Could not resolve user profile for session {0}", sessionId); + return; + } + + string globalConfigPath = Path.Combine(userProfile, ".gitconfig"); + this.telemetryAttacher.TryAttach(gitBinRoot, globalConfigPath); + } + } + catch (Exception e) + { + this.tracer.RelatedWarning("TryAttachTelemetryPipe failed: {0}", e.Message); + } + } + private DirectorySecurity GetServiceDirectorySecurity(string serviceDataRootPath) { DirectorySecurity serviceDataRootSecurity; From b2c81a1dcfab9d2b9796ff7a247e87eab1995651 Mon Sep 17 00:00:00 2001 From: Tyrie Vella Date: Tue, 26 May 2026 13:22:51 -0700 Subject: [PATCH 2/2] Add unit tests for deferred telemetry pipe attachment Test BufferingTelemetryListener: buffer and replay, stop after replay, bounded cap, second replay returns zero. Test DeferredTelemetryAttacher: null gitBinRoot handling, retry interval exponential backoff values. Assisted-by: Claude Opus 4.6 Signed-off-by: Tyrie Vella --- .../Common/JsonTracerDeferredTests.cs | 115 ++++++++++++++++++ 1 file changed, 115 insertions(+) create mode 100644 GVFS/GVFS.UnitTests/Common/JsonTracerDeferredTests.cs diff --git a/GVFS/GVFS.UnitTests/Common/JsonTracerDeferredTests.cs b/GVFS/GVFS.UnitTests/Common/JsonTracerDeferredTests.cs new file mode 100644 index 000000000..81667bf74 --- /dev/null +++ b/GVFS/GVFS.UnitTests/Common/JsonTracerDeferredTests.cs @@ -0,0 +1,115 @@ +using GVFS.Common.Tracing; +using GVFS.Tests.Should; +using GVFS.UnitTests.Mock.Common.Tracing; +using NUnit.Framework; + +namespace GVFS.UnitTests.Common +{ + [TestFixture] + public class BufferingTelemetryListenerTests + { + [TestCase] + public void BuffersAndReplaysMessages() + { + BufferingTelemetryListener buffer = new BufferingTelemetryListener(); + MockListener target = new MockListener(EventLevel.Verbose, Keywords.Telemetry); + + TraceEventMessage msg1 = CreateTelemetryMessage("Event1"); + TraceEventMessage msg2 = CreateTelemetryMessage("Event2"); + buffer.RecordMessage(msg1); + buffer.RecordMessage(msg2); + + buffer.BufferedCount.ShouldEqual(2); + + int replayed = buffer.ReplayAndStop(target); + replayed.ShouldEqual(2); + target.EventNamesRead.ShouldContain(name => name.Equals("Event1")); + target.EventNamesRead.ShouldContain(name => name.Equals("Event2")); + } + + [TestCase] + public void StopsBufferingAfterReplay() + { + BufferingTelemetryListener buffer = new BufferingTelemetryListener(); + MockListener target = new MockListener(EventLevel.Verbose, Keywords.Telemetry); + + buffer.RecordMessage(CreateTelemetryMessage("Before")); + buffer.ReplayAndStop(target); + + buffer.IsStopped.ShouldBeTrue(); + buffer.RecordMessage(CreateTelemetryMessage("After")); + + // "After" should not be buffered or replayed + target.EventNamesRead.Count.ShouldEqual(1); + } + + [TestCase] + public void CapsAtMaxBufferedMessages() + { + BufferingTelemetryListener buffer = new BufferingTelemetryListener(maxBufferedMessages: 10); + MockListener target = new MockListener(EventLevel.Verbose, Keywords.Telemetry); + + for (int i = 0; i < 15; i++) + { + buffer.RecordMessage(CreateTelemetryMessage($"Event{i}")); + } + + int replayed = buffer.ReplayAndStop(target); + replayed.ShouldEqual(10); + target.EventNamesRead[0].ShouldEqual("Event0"); + target.EventNamesRead[9].ShouldEqual("Event9"); + } + + [TestCase] + public void SecondReplayReturnsZero() + { + BufferingTelemetryListener buffer = new BufferingTelemetryListener(); + MockListener target1 = new MockListener(EventLevel.Verbose, Keywords.Telemetry); + MockListener target2 = new MockListener(EventLevel.Verbose, Keywords.Telemetry); + + buffer.RecordMessage(CreateTelemetryMessage("Event1")); + + buffer.ReplayAndStop(target1).ShouldEqual(1); + buffer.ReplayAndStop(target2).ShouldEqual(0); + } + + private static TraceEventMessage CreateTelemetryMessage(string eventName) + { + return new TraceEventMessage + { + EventName = eventName, + Level = EventLevel.Informational, + Keywords = Keywords.Telemetry, + Opcode = EventOpcode.Info, + Payload = "{}" + }; + } + } + + [TestFixture] + public class DeferredTelemetryAttacherTests + { + [TestCase] + public void TryAttach_ReturnsFalseWithNullGitBinRoot() + { + using (JsonTracer tracer = new JsonTracer("Test", "NullGitBinRoot", disableTelemetry: true)) + using (DeferredTelemetryAttacher attacher = new DeferredTelemetryAttacher(tracer, "Test", null, null)) + { + attacher.TryAttach(null).ShouldBeFalse(); + attacher.TryAttach(string.Empty).ShouldBeFalse(); + attacher.IsAttached.ShouldBeFalse(); + } + } + + [TestCase(0, 10_000)] + [TestCase(1, 30_000)] + [TestCase(2, 60_000)] + [TestCase(3, 300_000)] + [TestCase(4, 300_000)] + [TestCase(100, 300_000)] + public void GetRetryInterval_ReturnsExpectedValues(int retryCount, int expectedMs) + { + DeferredTelemetryAttacher.GetRetryInterval(retryCount).ShouldEqual(expectedMs); + } + } +}