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; 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); + } + } +}