diff --git a/src/VisualStudio/Core/Def/Implementation/Watson/FaultReporter.cs b/src/VisualStudio/Core/Def/Implementation/Watson/FaultReporter.cs index 6f11867c7a558..8452bb03b8957 100644 --- a/src/VisualStudio/Core/Def/Implementation/Watson/FaultReporter.cs +++ b/src/VisualStudio/Core/Def/Implementation/Watson/FaultReporter.cs @@ -11,6 +11,7 @@ using System.Threading; using Microsoft.CodeAnalysis.Internal.Log; using Microsoft.CodeAnalysis.Remote; +using Microsoft.CodeAnalysis.Telemetry; using Microsoft.VisualStudio.LanguageServices.Telemetry; using Microsoft.VisualStudio.Telemetry; @@ -104,7 +105,7 @@ public static void ReportFault(Exception exception, FaultSeverity severity, bool } var faultEvent = new FaultEvent( - eventName: FunctionId.NonFatalWatson.GetEventName(), + eventName: TelemetryLogger.GetEventName(FunctionId.NonFatalWatson), description: GetDescription(exception), severity, exceptionObject: exception, diff --git a/src/VisualStudio/Core/Def/Telemetry/TelemetryLogger.cs b/src/VisualStudio/Core/Def/Telemetry/TelemetryLogger.cs new file mode 100644 index 0000000000000..aa066c8cc3732 --- /dev/null +++ b/src/VisualStudio/Core/Def/Telemetry/TelemetryLogger.cs @@ -0,0 +1,195 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. +// See the LICENSE file in the project root for more information. + +using System; +using System.Collections.Concurrent; +using System.Collections.Generic; +using System.Diagnostics; +using System.Linq; +using System.Threading; +using Microsoft.CodeAnalysis.Internal.Log; +using Microsoft.VisualStudio.Telemetry; +using Roslyn.Utilities; + +namespace Microsoft.CodeAnalysis.Telemetry +{ + internal abstract class TelemetryLogger : ILogger + { + private sealed class Implementation : TelemetryLogger + { + private readonly TelemetrySession _session; + + public Implementation(TelemetrySession session) + => _session = session; + + public override bool IsEnabled(FunctionId functionId) + => _session.IsOptedIn; + + protected override void PostEvent(TelemetryEvent telemetryEvent) + => _session.PostEvent(telemetryEvent); + + protected override object Start(string eventName, LogType type) + => type switch + { + LogType.Trace => _session.StartOperation(eventName), + LogType.UserAction => _session.StartUserTask(eventName), + _ => throw ExceptionUtilities.UnexpectedValue(type), + }; + + protected override TelemetryEvent GetEndEvent(object scope) + => scope switch + { + TelemetryScope operation => operation.EndEvent, + TelemetryScope userTask => userTask.EndEvent, + _ => throw ExceptionUtilities.UnexpectedValue(scope) + }; + + protected override void End(object scope, TelemetryResult result) + { + if (scope is TelemetryScope operation) + operation.End(result); + else if (scope is TelemetryScope userTask) + userTask.End(result); + else + throw ExceptionUtilities.UnexpectedValue(scope); + } + } + + private readonly ConcurrentDictionary _pendingScopes = new(concurrencyLevel: 2, capacity: 10); + + private const string EventPrefix = "vs/ide/vbcs/"; + private const string PropertyPrefix = "vs.ide.vbcs."; + + // these don't have concurrency limit on purpose to reduce chance of lock contention. + // if that becomes a problem - by showing up in our perf investigation, then we will consider adding concurrency limit. + private static readonly ConcurrentDictionary s_eventMap = new(); + private static readonly ConcurrentDictionary<(FunctionId id, string name), string> s_propertyMap = new(); + + internal static string GetEventName(FunctionId id) + => s_eventMap.GetOrAdd(id, id => EventPrefix + GetTelemetryName(id, separator: '/')); + + internal static string GetPropertyName(FunctionId id, string name) + => s_propertyMap.GetOrAdd((id, name), key => PropertyPrefix + GetTelemetryName(id, separator: '.') + "." + key.name.ToLowerInvariant()); + + private static string GetTelemetryName(FunctionId id, char separator) + => Enum.GetName(typeof(FunctionId), id)!.Replace('_', separator).ToLowerInvariant(); + + public static TelemetryLogger Create(TelemetrySession session) + => new Implementation(session); + + public abstract bool IsEnabled(FunctionId functionId); + protected abstract void PostEvent(TelemetryEvent telemetryEvent); + protected abstract object Start(string eventName, LogType type); + protected abstract void End(object scope, TelemetryResult result); + protected abstract TelemetryEvent GetEndEvent(object scope); + + public void Log(FunctionId functionId, LogMessage logMessage) + { + if (IgnoreMessage(logMessage)) + { + return; + } + + var telemetryEvent = new TelemetryEvent(GetEventName(functionId)); + SetProperties(telemetryEvent, functionId, logMessage); + + try + { + PostEvent(telemetryEvent); + } + catch + { + } + } + + public void LogBlockStart(FunctionId functionId, LogMessage logMessage, int blockId, CancellationToken cancellationToken) + { + if (IgnoreMessage(logMessage)) + { + return; + } + + var eventName = GetEventName(functionId); + var kind = GetKind(logMessage); + + try + { + _pendingScopes[blockId] = Start(eventName, kind); + } + catch + { + } + } + + public void LogBlockEnd(FunctionId functionId, LogMessage logMessage, int blockId, int delta, CancellationToken cancellationToken) + { + if (IgnoreMessage(logMessage)) + { + return; + } + + Contract.ThrowIfFalse(_pendingScopes.TryRemove(blockId, out var scope)); + + var endEvent = GetEndEvent(scope); + SetProperties(endEvent, functionId, logMessage); + + var result = cancellationToken.IsCancellationRequested ? TelemetryResult.UserCancel : TelemetryResult.Success; + + try + { + End(scope, result); + } + catch + { + } + } + + private static bool IgnoreMessage(LogMessage logMessage) + => logMessage.LogLevel < LogLevel.Information; + + private static LogType GetKind(LogMessage logMessage) + => logMessage is KeyValueLogMessage kvLogMessage + ? kvLogMessage.Kind + : logMessage.LogLevel switch + { + >= LogLevel.Information => LogType.UserAction, + _ => LogType.Trace + }; + + private static void SetProperties(TelemetryEvent telemetryEvent, FunctionId functionId, LogMessage logMessage) + { + if (logMessage is KeyValueLogMessage kvLogMessage) + { + AppendProperties(telemetryEvent, functionId, kvLogMessage); + } + else + { + var message = logMessage.GetMessage(); + if (!string.IsNullOrWhiteSpace(message)) + { + var propertyName = GetPropertyName(functionId, "Message"); + telemetryEvent.Properties.Add(propertyName, message); + } + } + } + + private static void AppendProperties(TelemetryEvent telemetryEvent, FunctionId functionId, KeyValueLogMessage logMessage) + { + foreach (var (name, value) in logMessage.Properties) + { + // call SetProperty. VS telemetry will take care of finding correct + // API based on given object type for us. + // + // numeric data will show up in ES with measurement prefix. + + telemetryEvent.Properties.Add(GetPropertyName(functionId, name), value switch + { + PiiValue pii => new TelemetryPiiProperty(pii.Value), + IEnumerable items => new TelemetryComplexProperty(items.Select(item => (item is PiiValue pii) ? new TelemetryPiiProperty(pii.Value) : item)), + _ => value + }); + } + } + } +} diff --git a/src/VisualStudio/Core/Def/Telemetry/VSTelemetryCache.cs b/src/VisualStudio/Core/Def/Telemetry/VSTelemetryCache.cs deleted file mode 100644 index ea4c40acdc0e3..0000000000000 --- a/src/VisualStudio/Core/Def/Telemetry/VSTelemetryCache.cs +++ /dev/null @@ -1,57 +0,0 @@ -// Licensed to the .NET Foundation under one or more agreements. -// The .NET Foundation licenses this file to you under the MIT license. -// See the LICENSE file in the project root for more information. - -#nullable disable - -using System; -using System.Collections.Concurrent; -using Microsoft.CodeAnalysis.Internal.Log; -using Roslyn.Utilities; - -namespace Microsoft.VisualStudio.LanguageServices.Telemetry -{ - internal static class VSTelemetryCache - { - private const string EventPrefix = "vs/ide/vbcs/"; - private const string PropertyPrefix = "vs.ide.vbcs."; - - // these don't have concurrency limit on purpose to reduce chance of lock contention. - // if that becomes a problem - by showing up in our perf investigation, then we will consider adding concurrency limit. - private static readonly ConcurrentDictionary s_eventMap = new(); - private static readonly ConcurrentDictionary s_propertyMap = new(); - - public static string GetEventName(this FunctionId functionId, string eventKey = null) - => s_eventMap.GetOrAdd(new Key(functionId, eventKey), CreateEventName); - - public static string GetPropertyName(this FunctionId functionId, string propertyKey) - => s_propertyMap.GetOrAdd(new Key(functionId, propertyKey), CreatePropertyName); - - private static string CreateEventName(Key key) - => (EventPrefix + Enum.GetName(typeof(FunctionId), key.FunctionId).Replace('_', '/') + (key.ItemKey == null ? string.Empty : ("/" + key.ItemKey))).ToLowerInvariant(); - - private static string CreatePropertyName(Key key) - => (PropertyPrefix + Enum.GetName(typeof(FunctionId), key.FunctionId).Replace('_', '.') + "." + key.ItemKey).ToLowerInvariant(); - - private struct Key : IEquatable - { - public readonly FunctionId FunctionId; - public readonly string ItemKey; - - public Key(FunctionId functionId, string itemKey) - { - this.FunctionId = functionId; - this.ItemKey = itemKey; - } - - public override int GetHashCode() - => Hash.Combine((int)FunctionId, ItemKey?.GetHashCode() ?? 0); - - public override bool Equals(object obj) - => obj is Key && Equals((Key)obj); - - public bool Equals(Key key) - => this.FunctionId == key.FunctionId && this.ItemKey == key.ItemKey; - } - } -} diff --git a/src/VisualStudio/Core/Def/Telemetry/VSTelemetryLogger.cs b/src/VisualStudio/Core/Def/Telemetry/VSTelemetryLogger.cs deleted file mode 100644 index ecb35c8ec9cb6..0000000000000 --- a/src/VisualStudio/Core/Def/Telemetry/VSTelemetryLogger.cs +++ /dev/null @@ -1,190 +0,0 @@ -// Licensed to the .NET Foundation under one or more agreements. -// The .NET Foundation licenses this file to you under the MIT license. -// See the LICENSE file in the project root for more information. - -#nullable disable - -using System.Collections.Concurrent; -using System.Collections.Generic; -using System.Diagnostics; -using System.Linq; -using System.Threading; -using Microsoft.CodeAnalysis.Internal.Log; -using Microsoft.VisualStudio.Telemetry; -using Roslyn.Utilities; - -namespace Microsoft.VisualStudio.LanguageServices.Telemetry -{ - internal class VSTelemetryLogger : ILogger - { - private readonly TelemetrySession _session; - private readonly ConcurrentDictionary _pendingScopes; - - public VSTelemetryLogger(TelemetrySession session) - { - _session = session; - _pendingScopes = new ConcurrentDictionary(concurrencyLevel: 2, capacity: 10); - } - - public bool IsEnabled(FunctionId functionId) - => _session.IsOptedIn; - - public void Log(FunctionId functionId, LogMessage logMessage) - { - if (IgnoreMessage(logMessage)) - { - return; - } - - try - { - if (logMessage is KeyValueLogMessage { ContainsProperty: false }) - { - // guard us from exception thrown by telemetry - _session.PostEvent(functionId.GetEventName()); - return; - } - - var telemetryEvent = CreateTelemetryEvent(functionId, logMessage); - _session.PostEvent(telemetryEvent); - } - catch - { - } - } - - public void LogBlockStart(FunctionId functionId, LogMessage logMessage, int blockId, CancellationToken cancellationToken) - { - if (IgnoreMessage(logMessage)) - { - return; - } - - try - { - // guard us from exception thrown by telemetry - var kind = GetKind(logMessage); - - _pendingScopes[blockId] = CreateAndStartScope(kind, functionId); - } - catch - { - } - } - - public void LogBlockEnd(FunctionId functionId, LogMessage logMessage, int blockId, int delta, CancellationToken cancellationToken) - { - if (IgnoreMessage(logMessage)) - { - return; - } - - try - { - // guard us from exception thrown by telemetry - var kind = GetKind(logMessage); - - switch (kind) - { - case LogType.Trace: - EndScope(functionId, blockId, logMessage, cancellationToken); - return; - case LogType.UserAction: - EndScope(functionId, blockId, logMessage, cancellationToken); - return; - default: - throw ExceptionUtilities.UnexpectedValue(kind); - } - } - catch - { - } - } - - private static bool IgnoreMessage(LogMessage logMessage) - => logMessage.LogLevel < LogLevel.Information; - - private static LogType GetKind(LogMessage logMessage) - => logMessage is KeyValueLogMessage kvLogMessage - ? kvLogMessage.Kind - : logMessage.LogLevel switch - { - >= LogLevel.Information => LogType.UserAction, - _ => LogType.Trace - }; - - private void EndScope(FunctionId functionId, int blockId, LogMessage logMessage, CancellationToken cancellationToken) - where T : OperationEvent - { - if (!_pendingScopes.TryRemove(blockId, out var value)) - { - Debug.Assert(false, "when can this happen?"); - return; - } - - var operation = (TelemetryScope)value; - - UpdateEvent(operation.EndEvent, functionId, logMessage); - operation.End(cancellationToken.IsCancellationRequested ? TelemetryResult.UserCancel : TelemetryResult.Success); - } - - private object CreateAndStartScope(LogType kind, FunctionId functionId) - { - // use object since TelemetryScope and - // TelemetryScope can't be shared - var eventName = functionId.GetEventName(); - - return kind switch - { - LogType.Trace => _session.StartOperation(eventName), - LogType.UserAction => _session.StartUserTask(eventName), - _ => throw ExceptionUtilities.UnexpectedValue(kind), - }; - } - - private static TelemetryEvent CreateTelemetryEvent(FunctionId functionId, LogMessage logMessage) - { - var eventName = functionId.GetEventName(); - var telemetryEvent = new TelemetryEvent(eventName); - - return UpdateEvent(telemetryEvent, functionId, logMessage); - } - - private static TelemetryEvent UpdateEvent(TelemetryEvent telemetryEvent, FunctionId functionId, LogMessage logMessage) - { - if (logMessage is KeyValueLogMessage kvLogMessage) - { - AppendProperties(telemetryEvent, functionId, kvLogMessage); - } - else - { - var message = logMessage.GetMessage(); - if (!string.IsNullOrWhiteSpace(message)) - { - var propertyName = functionId.GetPropertyName("Message"); - telemetryEvent.Properties.Add(propertyName, message); - } - } - - return telemetryEvent; - } - - private static void AppendProperties(TelemetryEvent telemetryEvent, FunctionId functionId, KeyValueLogMessage logMessage) - { - foreach (var (key, value) in logMessage.Properties) - { - // call SetProperty. VS telemetry will take care of finding correct - // API based on given object type for us. - // - // numeric data will show up in ES with measurement prefix. - - telemetryEvent.Properties.Add(functionId.GetPropertyName(key), value switch - { - PiiValue pii => new TelemetryPiiProperty(pii.Value), - IEnumerable items => new TelemetryComplexProperty(items.Select(item => (item is PiiValue pii) ? pii.Value : item)), - _ => value - }); - } - } - } -} diff --git a/src/VisualStudio/Core/Def/Telemetry/VisualStudioWorkspaceTelemetryService.cs b/src/VisualStudio/Core/Def/Telemetry/VisualStudioWorkspaceTelemetryService.cs index 4f54d35f9b0cb..4c56413671d99 100644 --- a/src/VisualStudio/Core/Def/Telemetry/VisualStudioWorkspaceTelemetryService.cs +++ b/src/VisualStudio/Core/Def/Telemetry/VisualStudioWorkspaceTelemetryService.cs @@ -38,7 +38,7 @@ protected override ILogger CreateLogger(TelemetrySession telemetrySession) => AggregateLogger.Create( CodeMarkerLogger.Instance, new EtwLogger(FunctionIdOptions.CreateFunctionIsEnabledPredicate(_globalOptions)), - new VSTelemetryLogger(telemetrySession), + TelemetryLogger.Create(telemetrySession), new FileLogger(_globalOptions), Logger.GetLogger()); diff --git a/src/VisualStudio/Core/Test/Telemetry/VSTelemetryLoggerTest.vb b/src/VisualStudio/Core/Test/Telemetry/VSTelemetryLoggerTest.vb deleted file mode 100644 index 76986d01dc7a6..0000000000000 --- a/src/VisualStudio/Core/Test/Telemetry/VSTelemetryLoggerTest.vb +++ /dev/null @@ -1,394 +0,0 @@ -' Licensed to the .NET Foundation under one or more agreements. -' The .NET Foundation licenses this file to you under the MIT license. -' See the LICENSE file in the project root for more information. - -#If False Then ' not supported for now -' Licensed to the .NET Foundation under one or more agreements. -' The .NET Foundation licenses this file to you under the MIT license. -' See the LICENSE file in the project root for more information. - -Imports System.Threading -Imports Microsoft.CodeAnalysis.Internal.Log -Imports Microsoft.Internal.VisualStudio.Shell.Interop -Imports Microsoft.VisualStudio.LanguageServices.Telemetry - -Namespace Microsoft.VisualStudio.LanguageServices.UnitTests.Log - Public Class VSTelemetryLoggerTest - - - Public Sub TestNoLog() - Dim service = New Service() - Dim logger = New VSTelemetryLogger(service) - - logger.Log(FunctionId.Debugging_EncSession_EditSession_EmitDeltaErrorId, LogMessage.Create("test")) - Assert.Equal(0, service.DefaultSession.PostedEvents.Cast(Of Service.TelemetryEvent)().Count()) - End Sub - - - Public Sub TestLog() - Dim service = New Service() - Dim logger = New VSTelemetryLogger(service) - - logger.Log(FunctionId.Debugging_EncSession_EditSession_EmitDeltaErrorId, KeyValueLogMessage.Create( - Sub(m) - m.Add("test", "1") - End Sub)) - - Dim postedEvent = service.DefaultSession.PostedEvents.Cast(Of Service.TelemetryEvent)().Single() - Assert.Equal("vs/ide/vbcs/debugging/encsession/editsession/emitdeltaerrorid", postedEvent.EventName) - - Assert.Equal(1, postedEvent.Map.Count) - - Dim kv = postedEvent.Map.Single() - Assert.Equal("vs.ide.vbcs.debugging.encsession.editsession.emitdeltaerrorid.test", kv.Key) - Assert.Equal("1", kv.Value) - End Sub - - - Public Sub TestNoLogBlockStart() - Dim service = New Service() - Dim logger = New VSTelemetryLogger(service) - - logger.LogBlockStart(FunctionId.Debugging_EncSession_EditSession_EmitDeltaErrorId, LogMessage.Create("test"), 1, CancellationToken.None) - Assert.Equal(0, service.DefaultSession.PostedEvents.Cast(Of Service.TelemetryEvent)().Count()) - End Sub - - - Public Sub TestLogBlockStart() - Dim service = New Service() - Dim logger = New VSTelemetryLogger(service) - - logger.LogBlockStart(FunctionId.Debugging_EncSession_EditSession_EmitDeltaErrorId, KeyValueLogMessage.Create( - Sub(m) - m.Add("test", "2") - End Sub), 1, CancellationToken.None) - - Dim postedEvent = service.DefaultSession.PostedEvents.Cast(Of Service.TelemetryEvent)().Single() - Assert.Equal("vs/ide/vbcs/debugging/encsession/editsession/emitdeltaerrorid/start", postedEvent.EventName) - - Assert.Equal(2, postedEvent.Map.Count) - - Assert.Equal("1", postedEvent.Map("vs.ide.vbcs.debugging.encsession.editsession.emitdeltaerrorid.blockid")) - Assert.Equal("2", postedEvent.Map("vs.ide.vbcs.debugging.encsession.editsession.emitdeltaerrorid.test")) - End Sub - - - Public Sub TestNoLogBlockEnd() - Dim service = New Service() - Dim logger = New VSTelemetryLogger(service) - - logger.LogBlockEnd(FunctionId.Debugging_EncSession_EditSession_EmitDeltaErrorId, LogMessage.Create("test"), 1, 123, CancellationToken.None) - Assert.Equal(0, service.DefaultSession.PostedEvents.Cast(Of Service.TelemetryEvent)().Count()) - End Sub - - - Public Sub TestLogBlockEnd() - Dim service = New Service() - Dim logger = New VSTelemetryLogger(service) - - logger.LogBlockEnd(FunctionId.Debugging_EncSession_EditSession_EmitDeltaErrorId, KeyValueLogMessage.Create( - Sub(m) - m.Add("test", "2") - End Sub), 1, 123, CancellationToken.None) - - Dim postedEvent = service.DefaultSession.PostedEvents.Cast(Of Service.TelemetryEvent)().Single() - Assert.Equal("vs/ide/vbcs/debugging/encsession/editsession/emitdeltaerrorid/end", postedEvent.EventName) - - Assert.Equal(3, postedEvent.Map.Count) - - Assert.Equal("1", postedEvent.Map("vs.ide.vbcs.debugging.encsession.editsession.emitdeltaerrorid.blockid")) - Assert.Equal("False", postedEvent.Map("vs.ide.vbcs.debugging.encsession.editsession.emitdeltaerrorid.cancellationrequested")) - Assert.Equal("123", postedEvent.Map("vs.ide.vbcs.debugging.encsession.editsession.emitdeltaerrorid.duration")) - End Sub - - - Public Sub TestLogBlockEndCacellation() - Dim service = New Service() - Dim logger = New VSTelemetryLogger(service) - - Dim cancellation = New CancellationTokenSource() - cancellation.Cancel() - - logger.LogBlockEnd(FunctionId.Debugging_EncSession_EditSession_EmitDeltaErrorId, KeyValueLogMessage.Create( - Sub(m) - m.Add("test", "2") - End Sub), 1, 123, cancellation.Token) - - Dim postedEvent = service.DefaultSession.PostedEvents.Cast(Of Service.TelemetryEvent)().Single() - Assert.Equal("vs/ide/vbcs/debugging/encsession/editsession/emitdeltaerrorid/end", postedEvent.EventName) - - Assert.Equal(3, postedEvent.Map.Count) - - Assert.Equal("1", postedEvent.Map("vs.ide.vbcs.debugging.encsession.editsession.emitdeltaerrorid.blockid")) - Assert.Equal("True", postedEvent.Map("vs.ide.vbcs.debugging.encsession.editsession.emitdeltaerrorid.cancellationrequested")) - Assert.Equal("123", postedEvent.Map("vs.ide.vbcs.debugging.encsession.editsession.emitdeltaerrorid.duration")) - End Sub - - Public Class Service - Implements IVsTelemetryService - - Public ReadOnly DefaultSession As Session = New Session() - - Public Function CreateEvent(szEventName As String) As IVsTelemetryEvent Implements IVsTelemetryService.CreateEvent - Return New TelemetryEvent(szEventName) - End Function - - Public Function GetDefaultSession() As IVsTelemetrySession Implements IVsTelemetryService.GetDefaultSession - Return DefaultSession - End Function - - Public Function CreateActivity(szActivityName As String) As IVsTelemetryActivity Implements IVsTelemetryService.CreateActivity - Throw New NotImplementedException() - End Function - - Public Function CreateActivityWithParentCorrelationId(szActivityName As String, ByRef parentCorrelationId As Guid) As IVsTelemetryActivity Implements IVsTelemetryService.CreateActivityWithParentCorrelationId - Throw New NotImplementedException() - End Function - - Public Function CreatePropertyBag() As IVsTelemetryPropertyBag Implements IVsTelemetryService.CreatePropertyBag - Throw New NotImplementedException() - End Function - - Public Class Session - Implements IVsTelemetrySession - - Public ReadOnly PostedEvents As List(Of IVsTelemetryEvent) = New List(Of IVsTelemetryEvent)() - - Public Sub PostBoolProperty(szPropertyName As String, value As Boolean) Implements IVsTelemetrySession.PostBoolProperty - End Sub - - Public Sub PostDoubleProperty(szPropertyName As String, value As Double) Implements IVsTelemetrySession.PostDoubleProperty - End Sub - - Public Sub PostEvent(eventObject As IVsTelemetryEvent) Implements IVsTelemetrySession.PostEvent - PostedEvents.Add(eventObject) - End Sub - - Public Sub PostIntProperty(szPropertyName As String, value As Integer) Implements IVsTelemetrySession.PostIntProperty - End Sub - - Public Sub PostLongProperty(szPropertyName As String, value As Long) Implements IVsTelemetrySession.PostLongProperty - End Sub - - Public Sub PostProperty(szPropertyName As String, varValue As Object) Implements IVsTelemetrySession.PostProperty - End Sub - - Public Sub PostShortProperty(szPropertyName As String, value As Short) Implements IVsTelemetrySession.PostShortProperty - End Sub - - Public Sub PostSimpleEvent(szEventName As String) Implements IVsTelemetrySession.PostSimpleEvent - PostedEvents.Add(New TelemetryEvent(szEventName)) - End Sub - - Public Sub PostStringProperty(szPropertyName As String, szValue As String) Implements IVsTelemetrySession.PostStringProperty - End Sub - - Public Sub RemoveSharedProperty(szPropertyName As String) Implements IVsTelemetrySession.RemoveSharedProperty - End Sub - - Public Sub SetSharedBoolProperty(szPropertyName As String, value As Boolean) Implements IVsTelemetrySession.SetSharedBoolProperty - End Sub - - Public Sub SetSharedDoubleProperty(szPropertyName As String, value As Double) Implements IVsTelemetrySession.SetSharedDoubleProperty - End Sub - - Public Sub SetSharedIntProperty(szPropertyName As String, value As Integer) Implements IVsTelemetrySession.SetSharedIntProperty - End Sub - - Public Sub SetSharedLongProperty(szPropertyName As String, value As Long) Implements IVsTelemetrySession.SetSharedLongProperty - End Sub - - Public Sub SetSharedProperty(szPropertyName As String, varValue As Object) Implements IVsTelemetrySession.SetSharedProperty - End Sub - - Public Sub SetSharedShortProperty(szPropertyName As String, value As Short) Implements IVsTelemetrySession.SetSharedShortProperty - End Sub - - Public Sub SetSharedStringProperty(szPropertyName As String, szValue As String) Implements IVsTelemetrySession.SetSharedStringProperty - End Sub - - Public Function CreateContext(szContextName As String) As IVsTelemetryContext Implements IVsTelemetrySession.CreateContext - Throw New NotImplementedException() - End Function - - Public Function GetSessionId() As String Implements IVsTelemetrySession.GetSessionId - Return "1" - End Function - - Public Function CanCollectPrivateInformation() As Boolean Implements IVsTelemetrySession.CanCollectPrivateInformation - Return True - End Function - - Public Function IsUserMicrosoftInternal() As Boolean Implements IVsTelemetrySession.IsUserMicrosoftInternal - Return True - End Function - - Public Function IsUserOptedIn() As Boolean Implements IVsTelemetrySession.IsUserOptedIn - Return True - End Function - - Public Function SerializeSettings() As String Implements IVsTelemetrySession.SerializeSettings - Return "SerializedSettings" - End Function - - Public Sub SetUserOptedIn(IsUserOptedIn As Boolean) Implements IVsTelemetrySession.SetUserOptedIn - Throw New NotImplementedException() - End Sub - - Public Sub RegisterPropertyBag(szPropertyBagName As String, pPropertyBag As IVsTelemetryPropertyBag) Implements IVsTelemetrySession.RegisterPropertyBag - Throw New NotImplementedException() - End Sub - - Public Function GetPropertyBag(szPropertyBagName As String) As IVsTelemetryPropertyBag Implements IVsTelemetrySession.GetPropertyBag - Throw New NotImplementedException() - End Function - - Public Sub UnregisterPropertyBag(szPropertyBagName As String) Implements IVsTelemetrySession.UnregisterPropertyBag - Throw New NotImplementedException() - End Sub - - Public Sub PostPiiProperty(szPropertyName As String, varValue As Object) Implements IVsTelemetrySession.PostPiiProperty - Throw New NotImplementedException() - End Sub - - Public Sub PostIntPiiProperty(szPropertyName As String, varValue As Integer) Implements IVsTelemetrySession.PostIntPiiProperty - Throw New NotImplementedException() - End Sub - - Public Sub PostLongPiiProperty(szPropertyName As String, varValue As Long) Implements IVsTelemetrySession.PostLongPiiProperty - Throw New NotImplementedException() - End Sub - - Public Sub PostDoublePiiProperty(szPropertyName As String, varValue As Double) Implements IVsTelemetrySession.PostDoublePiiProperty - Throw New NotImplementedException() - End Sub - - Public Sub PostStringPiiProperty(szPropertyName As String, varValue As String) Implements IVsTelemetrySession.PostStringPiiProperty - Throw New NotImplementedException() - End Sub - - Public Sub SetSharedPiiProperty(szPropertyName As String, varValue As Object) Implements IVsTelemetrySession.SetSharedPiiProperty - Throw New NotImplementedException() - End Sub - - Public Sub SetSharedIntPiiProperty(szPropertyName As String, varValue As Integer) Implements IVsTelemetrySession.SetSharedIntPiiProperty - Throw New NotImplementedException() - End Sub - - Public Sub SetSharedLongPiiProperty(szPropertyName As String, varValue As Long) Implements IVsTelemetrySession.SetSharedLongPiiProperty - Throw New NotImplementedException() - End Sub - - Public Sub SetSharedDoublePiiProperty(szPropertyName As String, varValue As Double) Implements IVsTelemetrySession.SetSharedDoublePiiProperty - Throw New NotImplementedException() - End Sub - - Public Sub SetSharedStringPiiProperty(szPropertyName As String, varValue As String) Implements IVsTelemetrySession.SetSharedStringPiiProperty - Throw New NotImplementedException() - End Sub - - Public Function GetSharedProperty(szPropertyName As String) As Object Implements IVsTelemetrySession.GetSharedProperty - Throw New NotImplementedException() - End Function - - Public Function GetContext(szContextName As String) As IVsTelemetryContext Implements IVsTelemetrySession.GetContext - Throw New NotImplementedException() - End Function - End Class - - Public Class TelemetryEvent - Implements IVsTelemetryEvent - - Public ReadOnly EventName As String - Public ReadOnly Map As Dictionary(Of String, String) = New Dictionary(Of String, String)() - - Public Sub New(eventName As String) - Me.EventName = eventName - End Sub - - Public ReadOnly Property AllPropertyNames As Array Implements IVsTelemetryEvent.AllPropertyNames - Get - Throw New NotImplementedException() - End Get - End Property - - Public Sub AddPropertyBag(pPropertyBag As IVsTelemetryPropertyBag) Implements IVsTelemetryEvent.AddPropertyBag - Throw New NotImplementedException() - End Sub - - Public Sub RemovePropertyBag(pPropertyBag As IVsTelemetryPropertyBag) Implements IVsTelemetryEvent.RemovePropertyBag - Throw New NotImplementedException() - End Sub - - Public Sub SetBoolProperty(szPropertyName As String, value As Boolean) Implements IVsTelemetryEvent.SetBoolProperty - Map(szPropertyName) = value.ToString() - End Sub - - Public Sub SetDoublePiiProperty(szPropertyName As String, varValue As Double) Implements IVsTelemetryEvent.SetDoublePiiProperty - Throw New NotImplementedException() - End Sub - - Public Sub SetDoubleProperty(szPropertyName As String, value As Double) Implements IVsTelemetryEvent.SetDoubleProperty - Map(szPropertyName) = value.ToString() - End Sub - - Public Sub SetIntPiiProperty(szPropertyName As String, varValue As Integer) Implements IVsTelemetryEvent.SetIntPiiProperty - Throw New NotImplementedException() - End Sub - - Public Sub SetIntProperty(szPropertyName As String, value As Integer) Implements IVsTelemetryEvent.SetIntProperty - Map(szPropertyName) = value.ToString() - End Sub - - Public Sub SetLongPiiProperty(szPropertyName As String, varValue As Long) Implements IVsTelemetryEvent.SetLongPiiProperty - Throw New NotImplementedException() - End Sub - - Public Sub SetLongProperty(szPropertyName As String, value As Long) Implements IVsTelemetryEvent.SetLongProperty - Map(szPropertyName) = value.ToString() - End Sub - - Public Sub SetOptOutFriendlyFlag(bOptOutFriendly As Boolean) Implements IVsTelemetryEvent.SetOptOutFriendlyFlag - Throw New NotImplementedException() - End Sub - - Public Sub SetPiiProperty(szPropertyName As String, varValue As Object) Implements IVsTelemetryEvent.SetPiiProperty - Throw New NotImplementedException() - End Sub - - Public Sub SetProperty(szPropertyName As String, varValue As Object) Implements IVsTelemetryEvent.SetProperty - Map(szPropertyName) = varValue.ToString() - End Sub - - Public Sub SetShortProperty(szPropertyName As String, value As Short) Implements IVsTelemetryEvent.SetShortProperty - Map(szPropertyName) = value.ToString() - End Sub - - Public Sub SetStringPiiProperty(szPropertyName As String, varValue As String) Implements IVsTelemetryEvent.SetStringPiiProperty - Throw New NotImplementedException() - End Sub - - Public Sub SetStringProperty(szPropertyName As String, szValue As String) Implements IVsTelemetryEvent.SetStringProperty - Map(szPropertyName) = szValue - End Sub - - Public Function ContainsProperty(szPropertyName As String) As Boolean Implements IVsTelemetryEvent.ContainsProperty - Return Map.ContainsKey(szPropertyName) - End Function - - 'Public Function GetAllPropertiesNames() As Array Implements IVsTelemetryEvent.GetAllPropertiesNames - ' Return Map.ToArray() - 'End Function - - Public Function GetName() As String Implements IVsTelemetryEvent.GetName - Return Me.EventName - End Function - - Public Function GetProperty(szPropertyName As String) As Object Implements IVsTelemetryEvent.GetProperty - Return Map(szPropertyName) - End Function - End Class - End Class - End Class -End Namespace -#End If diff --git a/src/Workspaces/Remote/ServiceHub/Microsoft.CodeAnalysis.Remote.ServiceHub.csproj b/src/Workspaces/Remote/ServiceHub/Microsoft.CodeAnalysis.Remote.ServiceHub.csproj index ca8b821bfa250..a4eb593a8dc97 100644 --- a/src/Workspaces/Remote/ServiceHub/Microsoft.CodeAnalysis.Remote.ServiceHub.csproj +++ b/src/Workspaces/Remote/ServiceHub/Microsoft.CodeAnalysis.Remote.ServiceHub.csproj @@ -28,7 +28,7 @@ - + @@ -45,8 +45,7 @@ - - + diff --git a/src/Workspaces/Remote/ServiceHub/Services/ProcessTelemetry/RemoteWorkspaceTelemetryService.cs b/src/Workspaces/Remote/ServiceHub/Services/ProcessTelemetry/RemoteWorkspaceTelemetryService.cs index 7aa478fd2bbd7..f094edf709527 100644 --- a/src/Workspaces/Remote/ServiceHub/Services/ProcessTelemetry/RemoteWorkspaceTelemetryService.cs +++ b/src/Workspaces/Remote/ServiceHub/Services/ProcessTelemetry/RemoteWorkspaceTelemetryService.cs @@ -22,7 +22,7 @@ public RemoteWorkspaceTelemetryService() protected override ILogger CreateLogger(TelemetrySession telemetrySession) => AggregateLogger.Create( - new VSTelemetryLogger(telemetrySession), + TelemetryLogger.Create(telemetrySession), Logger.GetLogger()); } } diff --git a/src/Workspaces/Remote/ServiceHubTest/TelemetryLoggerTests.cs b/src/Workspaces/Remote/ServiceHubTest/TelemetryLoggerTests.cs new file mode 100644 index 0000000000000..798670620eb89 --- /dev/null +++ b/src/Workspaces/Remote/ServiceHubTest/TelemetryLoggerTests.cs @@ -0,0 +1,127 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. +// See the LICENSE file in the project root for more information. + +using System; +using System.Collections.Generic; +using System.Linq; +using System.Text; +using System.Threading; +using System.Threading.Tasks; +using Microsoft.CodeAnalysis.Internal.Log; +using Microsoft.CodeAnalysis.Telemetry; +using Microsoft.VisualStudio.Telemetry; +using Roslyn.Test.Utilities; +using Xunit; + +namespace Microsoft.CodeAnalysis.UnitTests +{ + public class TelemetryLoggerTests + { + private class TestLogger : TelemetryLogger + { + public class TestScope + { + public readonly TelemetryEvent EndEvent; + public readonly LogType Type; + + public TestScope(TelemetryEvent endEvent, LogType type) + { + EndEvent = endEvent; + Type = type; + } + } + + public List PostedEvents = new(); + public HashSet OpenedScopes = new(); + + public override bool IsEnabled(FunctionId functionId) + => true; + + protected override void PostEvent(TelemetryEvent telemetryEvent) + { + PostedEvents.Add(telemetryEvent); + } + + protected override object Start(string eventName, LogType type) + { + var scope = new TestScope(new TelemetryEvent(eventName), type); + OpenedScopes.Add(scope); + return scope; + } + + protected override void End(object scope, TelemetryResult result) + { + Assert.True(OpenedScopes.Remove((TestScope)scope)); + } + + protected override TelemetryEvent GetEndEvent(object scope) + => ((TestScope)scope).EndEvent; + } + + private static IEnumerable InspectProperties(TelemetryEvent @event) + => @event.Properties.Select(p => $"{p.Key}={InspectPropertyValue(p.Value)}"); + + private static string InspectPropertyValue(object? value) + => value switch + { + null => "", + TelemetryComplexProperty { Value: IEnumerable items } => $"Complex[{string.Join(",", items.Select(InspectPropertyValue))}]", + _ => value.ToString()! + }; + + [Theory] + [CombinatorialData] + internal void IgnoredSeverity(LogLevel level) + { + var logger = new TestLogger(); + + logger.Log(FunctionId.Debugging_EncSession_EditSession_EmitDeltaErrorId, LogMessage.Create("test", level)); + Assert.Equal((level < LogLevel.Information) ? 0 : 1, logger.PostedEvents.Count); + } + + [Fact] + public void EventWithProperties() + { + var logger = new TestLogger(); + + logger.Log(FunctionId.Debugging_EncSession_EditSession_EmitDeltaErrorId, KeyValueLogMessage.Create(p => + { + p.Add("test1", 1); + p.Add("test2", new PiiValue(2)); + p.Add("test3", new object[] { 3, new PiiValue(4) }); + })); + + var postedEvent = logger.PostedEvents.Single(); + + Assert.Equal("vs/ide/vbcs/debugging/encsession/editsession/emitdeltaerrorid", postedEvent.Name); + + AssertEx.Equal(new[] + { + "vs.ide.vbcs.debugging.encsession.editsession.emitdeltaerrorid.test1=1", + "vs.ide.vbcs.debugging.encsession.editsession.emitdeltaerrorid.test2=PII(2)", + "vs.ide.vbcs.debugging.encsession.editsession.emitdeltaerrorid.test3=Complex[3,PII(4)]", + }, InspectProperties(postedEvent)); + } + + [Fact] + public void LogBlockStartEnd() + { + var logger = new TestLogger(); + + logger.LogBlockStart(FunctionId.Debugging_EncSession_EditSession_EmitDeltaErrorId, KeyValueLogMessage.Create(p => p.Add("test", "start"), logLevel: LogLevel.Information), blockId: 1, CancellationToken.None); + + var scope = logger.OpenedScopes.Single(); + Assert.Equal(LogType.Trace, scope.Type); + + logger.LogBlockEnd(FunctionId.Debugging_EncSession_EditSession_EmitDeltaErrorId, KeyValueLogMessage.Create(p => p.Add("test", "end")), blockId: 1, delta: 100, CancellationToken.None); + + Assert.Equal("vs/ide/vbcs/debugging/encsession/editsession/emitdeltaerrorid", scope.EndEvent.Name); + + AssertEx.Equal(new[] + { + "vs.ide.vbcs.debugging.encsession.editsession.emitdeltaerrorid.test=end" + }, InspectProperties(scope.EndEvent)); + } + } +}