From 77dfa51904cbfbfbc4a4e8fba3d65f45fd4f9d08 Mon Sep 17 00:00:00 2001 From: Jakub Majocha <1760221+majocha@users.noreply.github.com> Date: Fri, 17 Jan 2025 23:48:32 +0100 Subject: [PATCH 1/8] trace test run activity --- tests/FSharp.Test.Utilities/XunitHelpers.fs | 11 ++++++++++- 1 file changed, 10 insertions(+), 1 deletion(-) diff --git a/tests/FSharp.Test.Utilities/XunitHelpers.fs b/tests/FSharp.Test.Utilities/XunitHelpers.fs index 2747bdc5a63..ce4d47b9635 100644 --- a/tests/FSharp.Test.Utilities/XunitHelpers.fs +++ b/tests/FSharp.Test.Utilities/XunitHelpers.fs @@ -168,7 +168,16 @@ type FSharpXunitFramework(sink: IMessageSink) = cleanUpTemporaryDirectoryOfThisTestRun () traceProvider.ForceFlush() |> ignore traceProvider.Dispose() - base.Dispose() + base.Dispose() + + // Group test run under single activity, to make traces more readable. + // Otherwise this overriden method is not necessary and can be removed. + override this.CreateExecutor (assemblyName) = + { new XunitTestFrameworkExecutor(assemblyName, this.SourceInformationProvider, this.DiagnosticMessageSink) with + override _.RunTestCases(testCases, executionMessageSink, executionOptions) = + use _ = Activity.start $"{assemblyName.Name} {Runtime.InteropServices.RuntimeInformation.FrameworkDescription}" [] + base.RunTestCases(testCases, executionMessageSink, executionOptions) + } override this.CreateDiscoverer (assemblyInfo) = { new XunitTestFrameworkDiscoverer(assemblyInfo, this.SourceInformationProvider, this.DiagnosticMessageSink) with From 06639288c8036b375b39f941ddae41c9a72d7e2b Mon Sep 17 00:00:00 2001 From: Jakub Majocha <1760221+majocha@users.noreply.github.com> Date: Fri, 17 Jan 2025 23:49:44 +0100 Subject: [PATCH 2/8] declutter StackGuard.Guard traces --- src/Compiler/Facilities/DiagnosticsLogger.fs | 22 ++++++++++---------- src/Compiler/Utilities/Activity.fs | 10 +++++++-- src/Compiler/Utilities/Activity.fsi | 2 ++ 3 files changed, 21 insertions(+), 13 deletions(-) diff --git a/src/Compiler/Facilities/DiagnosticsLogger.fs b/src/Compiler/Facilities/DiagnosticsLogger.fs index 69d1f4fc306..8408dc0e022 100644 --- a/src/Compiler/Facilities/DiagnosticsLogger.fs +++ b/src/Compiler/Facilities/DiagnosticsLogger.fs @@ -875,17 +875,17 @@ type StackGuard(maxDepth: int, name: string) = [] path: string, [] line: int ) = - use _ = - Activity.start - "DiagnosticsLogger.StackGuard.Guard" - [| - Activity.Tags.stackGuardName, name - Activity.Tags.stackGuardCurrentDepth, string depth - Activity.Tags.stackGuardMaxDepth, string maxDepth - Activity.Tags.callerMemberName, memberName - Activity.Tags.callerFilePath, path - Activity.Tags.callerLineNumber, string line - |] + + Activity.logEvent + "DiagnosticsLogger.StackGuard.Guard" + [| + Activity.Tags.stackGuardName, name + Activity.Tags.stackGuardCurrentDepth, string depth + Activity.Tags.stackGuardMaxDepth, string maxDepth + Activity.Tags.callerMemberName, memberName + Activity.Tags.callerFilePath, path + Activity.Tags.callerLineNumber, string line + |] depth <- depth + 1 diff --git a/src/Compiler/Utilities/Activity.fs b/src/Compiler/Utilities/Activity.fs index b6fafe1c1b9..de998629829 100644 --- a/src/Compiler/Utilities/Activity.fs +++ b/src/Compiler/Utilities/Activity.fs @@ -7,6 +7,7 @@ open System.Diagnostics open System.IO open System.Text open Internal.Utilities.Library +open System.Collections.Generic module ActivityNames = @@ -102,12 +103,17 @@ module internal Activity = let startNoTags (name: string) : IDisposable = activitySource.StartActivity name - let addEvent name = + let logEvent name (tags: (string * obj) seq) = match Activity.Current with | null -> () - | activity when activity.Source = activitySource -> activity.AddEvent(ActivityEvent name) |> ignore + | activity when activity.Source = activitySource -> + let collection = tags |> Seq.map KeyValuePair |> ActivityTagsCollection + let event = new ActivityEvent(name, tags = collection) + activity.AddEvent event |> ignore | _ -> () + let addEvent name = logEvent name Seq.empty + module Profiling = module Tags = diff --git a/src/Compiler/Utilities/Activity.fsi b/src/Compiler/Utilities/Activity.fsi index ec6a9fbf6f8..359a94714ff 100644 --- a/src/Compiler/Utilities/Activity.fsi +++ b/src/Compiler/Utilities/Activity.fsi @@ -45,6 +45,8 @@ module internal Activity = val addEvent: name: string -> unit + val logEvent: name: string -> tags: (string * obj) seq -> unit + module Profiling = val startAndMeasureEnvironmentStats: name: string -> IDisposable val addConsoleListener: unit -> IDisposable From 020397cfb40aa606472568ae076f0f8154c71463 Mon Sep 17 00:00:00 2001 From: Jakub Majocha <1760221+majocha@users.noreply.github.com> Date: Sat, 18 Jan 2025 12:45:21 +0100 Subject: [PATCH 3/8] add otel to debug vsix --- .../VisualFSharpFull/VisualFSharp.Core.targets | 14 +++++++++++++- vsintegration/src/FSharp.Editor/Common/Logging.fs | 12 ++++++++++++ .../src/FSharp.Editor/FSharp.Editor.fsproj | 1 + .../LanguageService/LanguageService.fs | 1 + 4 files changed, 27 insertions(+), 1 deletion(-) diff --git a/vsintegration/Vsix/VisualFSharpFull/VisualFSharp.Core.targets b/vsintegration/Vsix/VisualFSharpFull/VisualFSharp.Core.targets index f3c3ce40b79..16d69751fd7 100644 --- a/vsintegration/Vsix/VisualFSharpFull/VisualFSharp.Core.targets +++ b/vsintegration/Vsix/VisualFSharpFull/VisualFSharp.Core.targets @@ -110,7 +110,19 @@ False - + + + {65e0e82a-eace-4787-8994-888674c2fe87} + FSharp.Editor + ReferenceCopyLocalPathsOutputGroup%3bBuiltProjectOutputGroup%3bGetCopyToOutputDirectoryItems%3bPkgDefProjectOutputGroup%3bSatelliteDllsProjectOutputGroup%3b + DebugSymbolsProjectOutputGroup%3b + true + All + 2 + True + + + {65e0e82a-eace-4787-8994-888674c2fe87} FSharp.Editor BuiltProjectOutputGroup%3bGetCopyToOutputDirectoryItems%3bPkgDefProjectOutputGroup%3bSatelliteDllsProjectOutputGroup%3b diff --git a/vsintegration/src/FSharp.Editor/Common/Logging.fs b/vsintegration/src/FSharp.Editor/Common/Logging.fs index a69779e9acc..f64d2508bee 100644 --- a/vsintegration/src/FSharp.Editor/Common/Logging.fs +++ b/vsintegration/src/FSharp.Editor/Common/Logging.fs @@ -7,6 +7,10 @@ open Microsoft.VisualStudio.Shell open Microsoft.VisualStudio.Shell.Interop open Microsoft.VisualStudio.FSharp.Editor +open FSharp.Compiler.Diagnostics +open OpenTelemetry.Resources +open OpenTelemetry.Trace + [] type LogType = | Info @@ -145,4 +149,12 @@ module Activity = ActivitySource.AddActivityListener(listener) + let export () = + OpenTelemetry.Sdk.CreateTracerProviderBuilder() + .AddSource(ActivityNames.FscSourceName) + .SetResourceBuilder( + ResourceBuilder.CreateDefault().AddService(serviceName="F#", serviceVersion = "1.0.0")) + .AddOtlpExporter() + .Build() + let listenToAll () = listen "" diff --git a/vsintegration/src/FSharp.Editor/FSharp.Editor.fsproj b/vsintegration/src/FSharp.Editor/FSharp.Editor.fsproj index 2ec608dda20..7864d8a8b0f 100644 --- a/vsintegration/src/FSharp.Editor/FSharp.Editor.fsproj +++ b/vsintegration/src/FSharp.Editor/FSharp.Editor.fsproj @@ -194,6 +194,7 @@ + diff --git a/vsintegration/src/FSharp.Editor/LanguageService/LanguageService.fs b/vsintegration/src/FSharp.Editor/LanguageService/LanguageService.fs index 18cb516b6a9..55cd1b622b3 100644 --- a/vsintegration/src/FSharp.Editor/LanguageService/LanguageService.fs +++ b/vsintegration/src/FSharp.Editor/LanguageService/LanguageService.fs @@ -341,6 +341,7 @@ type internal FSharpPackage() as this = let mutable solutionEventsOpt = None #if DEBUG + let _traceProvider = Logging.Activity.export () let _logger = Logging.Activity.listenToAll () // Logging.Activity.listen "IncrementalBuild" #endif From 3b738fa7baa8ae0309a83d973c7b500584a4cb6d Mon Sep 17 00:00:00 2001 From: Jakub Majocha <1760221+majocha@users.noreply.github.com> Date: Thu, 23 Jan 2025 13:03:41 +0100 Subject: [PATCH 4/8] ref otel in debug only --- vsintegration/src/FSharp.Editor/Common/Logging.fs | 2 ++ vsintegration/src/FSharp.Editor/FSharp.Editor.fsproj | 2 +- 2 files changed, 3 insertions(+), 1 deletion(-) diff --git a/vsintegration/src/FSharp.Editor/Common/Logging.fs b/vsintegration/src/FSharp.Editor/Common/Logging.fs index f64d2508bee..2d8c7a6f7f3 100644 --- a/vsintegration/src/FSharp.Editor/Common/Logging.fs +++ b/vsintegration/src/FSharp.Editor/Common/Logging.fs @@ -120,6 +120,7 @@ module Logging = let logExceptionWithContext (ex: Exception, context) = logErrorf "Context: %s\nException Message: %s\nStack Trace: %s" context ex.Message ex.StackTrace +#if DEBUG module Activity = let listen filter = let indent (activity: Activity) = @@ -158,3 +159,4 @@ module Activity = .Build() let listenToAll () = listen "" +#endif diff --git a/vsintegration/src/FSharp.Editor/FSharp.Editor.fsproj b/vsintegration/src/FSharp.Editor/FSharp.Editor.fsproj index 7864d8a8b0f..5fedad089dd 100644 --- a/vsintegration/src/FSharp.Editor/FSharp.Editor.fsproj +++ b/vsintegration/src/FSharp.Editor/FSharp.Editor.fsproj @@ -194,7 +194,7 @@ - + From a54e890acc6ccf3983271c0b5166b0d64901c549 Mon Sep 17 00:00:00 2001 From: Jakub Majocha <1760221+majocha@users.noreply.github.com> Date: Thu, 23 Jan 2025 13:37:33 +0100 Subject: [PATCH 5/8] delay tags allocation --- src/Compiler/Facilities/DiagnosticsLogger.fs | 16 ++++++++-------- src/Compiler/Utilities/Activity.fs | 2 +- src/Compiler/Utilities/Activity.fsi | 2 +- 3 files changed, 10 insertions(+), 10 deletions(-) diff --git a/src/Compiler/Facilities/DiagnosticsLogger.fs b/src/Compiler/Facilities/DiagnosticsLogger.fs index 8408dc0e022..1b7f5719325 100644 --- a/src/Compiler/Facilities/DiagnosticsLogger.fs +++ b/src/Compiler/Facilities/DiagnosticsLogger.fs @@ -876,16 +876,16 @@ type StackGuard(maxDepth: int, name: string) = [] line: int ) = - Activity.logEvent - "DiagnosticsLogger.StackGuard.Guard" - [| - Activity.Tags.stackGuardName, name - Activity.Tags.stackGuardCurrentDepth, string depth - Activity.Tags.stackGuardMaxDepth, string maxDepth + Activity.logEvent "DiagnosticsLogger.StackGuard.Guard" + (seq { + Activity.Tags.stackGuardName, box name + Activity.Tags.stackGuardCurrentDepth, depth + Activity.Tags.stackGuardMaxDepth, maxDepth Activity.Tags.callerMemberName, memberName Activity.Tags.callerFilePath, path - Activity.Tags.callerLineNumber, string line - |] + Activity.Tags.callerLineNumber, line + }) + depth <- depth + 1 diff --git a/src/Compiler/Utilities/Activity.fs b/src/Compiler/Utilities/Activity.fs index de998629829..8f2cd782983 100644 --- a/src/Compiler/Utilities/Activity.fs +++ b/src/Compiler/Utilities/Activity.fs @@ -103,7 +103,7 @@ module internal Activity = let startNoTags (name: string) : IDisposable = activitySource.StartActivity name - let logEvent name (tags: (string * obj) seq) = + let logEvent name (tags: (string * objnull) seq) = match Activity.Current with | null -> () | activity when activity.Source = activitySource -> diff --git a/src/Compiler/Utilities/Activity.fsi b/src/Compiler/Utilities/Activity.fsi index 359a94714ff..412b89c45ee 100644 --- a/src/Compiler/Utilities/Activity.fsi +++ b/src/Compiler/Utilities/Activity.fsi @@ -45,7 +45,7 @@ module internal Activity = val addEvent: name: string -> unit - val logEvent: name: string -> tags: (string * obj) seq -> unit + val logEvent: name: string -> tags: (string * objnull) seq -> unit module Profiling = val startAndMeasureEnvironmentStats: name: string -> IDisposable From d80b97db7bb3a389d69c631a5bff649bfe69177d Mon Sep 17 00:00:00 2001 From: Jakub Majocha <1760221+majocha@users.noreply.github.com> Date: Sat, 25 Jan 2025 09:50:27 +0100 Subject: [PATCH 6/8] fix opens --- vsintegration/src/FSharp.Editor/Common/Logging.fs | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/vsintegration/src/FSharp.Editor/Common/Logging.fs b/vsintegration/src/FSharp.Editor/Common/Logging.fs index 2d8c7a6f7f3..e46cd0b766f 100644 --- a/vsintegration/src/FSharp.Editor/Common/Logging.fs +++ b/vsintegration/src/FSharp.Editor/Common/Logging.fs @@ -8,8 +8,6 @@ open Microsoft.VisualStudio.Shell.Interop open Microsoft.VisualStudio.FSharp.Editor open FSharp.Compiler.Diagnostics -open OpenTelemetry.Resources -open OpenTelemetry.Trace [] type LogType = @@ -122,6 +120,10 @@ module Logging = #if DEBUG module Activity = + + open OpenTelemetry.Resources + open OpenTelemetry.Trace + let listen filter = let indent (activity: Activity) = let rec loop (activity: Activity) n = From 232e03e2c148da372e8a3a32f171263717d66f6a Mon Sep 17 00:00:00 2001 From: Jakub Majocha <1760221+majocha@users.noreply.github.com> Date: Sat, 25 Jan 2025 13:00:43 +0100 Subject: [PATCH 7/8] format --- src/Compiler/Facilities/DiagnosticsLogger.fs | 4 ++-- .../src/FSharp.Editor/Common/Logging.fs | 18 +++++++++++------- 2 files changed, 13 insertions(+), 9 deletions(-) diff --git a/src/Compiler/Facilities/DiagnosticsLogger.fs b/src/Compiler/Facilities/DiagnosticsLogger.fs index 1b7f5719325..c459103d780 100644 --- a/src/Compiler/Facilities/DiagnosticsLogger.fs +++ b/src/Compiler/Facilities/DiagnosticsLogger.fs @@ -876,7 +876,8 @@ type StackGuard(maxDepth: int, name: string) = [] line: int ) = - Activity.logEvent "DiagnosticsLogger.StackGuard.Guard" + Activity.logEvent + "DiagnosticsLogger.StackGuard.Guard" (seq { Activity.Tags.stackGuardName, box name Activity.Tags.stackGuardCurrentDepth, depth @@ -886,7 +887,6 @@ type StackGuard(maxDepth: int, name: string) = Activity.Tags.callerLineNumber, line }) - depth <- depth + 1 try diff --git a/vsintegration/src/FSharp.Editor/Common/Logging.fs b/vsintegration/src/FSharp.Editor/Common/Logging.fs index e46cd0b766f..cf531c65384 100644 --- a/vsintegration/src/FSharp.Editor/Common/Logging.fs +++ b/vsintegration/src/FSharp.Editor/Common/Logging.fs @@ -120,7 +120,7 @@ module Logging = #if DEBUG module Activity = - + open OpenTelemetry.Resources open OpenTelemetry.Trace @@ -153,12 +153,16 @@ module Activity = ActivitySource.AddActivityListener(listener) let export () = - OpenTelemetry.Sdk.CreateTracerProviderBuilder() - .AddSource(ActivityNames.FscSourceName) - .SetResourceBuilder( - ResourceBuilder.CreateDefault().AddService(serviceName="F#", serviceVersion = "1.0.0")) - .AddOtlpExporter() - .Build() + OpenTelemetry.Sdk + .CreateTracerProviderBuilder() + .AddSource(ActivityNames.FscSourceName) + .SetResourceBuilder( + ResourceBuilder + .CreateDefault() + .AddService(serviceName = "F#", serviceVersion = "1.0.0") + ) + .AddOtlpExporter() + .Build() let listenToAll () = listen "" #endif From b97724b93b568aad857eec945d45e2f5f21320f1 Mon Sep 17 00:00:00 2001 From: Jakub Majocha <1760221+majocha@users.noreply.github.com> Date: Fri, 31 Jan 2025 12:42:14 +0100 Subject: [PATCH 8/8] better naming --- src/Compiler/Facilities/DiagnosticsLogger.fs | 2 +- src/Compiler/Utilities/Activity.fs | 4 ++-- src/Compiler/Utilities/Activity.fsi | 2 +- 3 files changed, 4 insertions(+), 4 deletions(-) diff --git a/src/Compiler/Facilities/DiagnosticsLogger.fs b/src/Compiler/Facilities/DiagnosticsLogger.fs index c459103d780..fe46d779c1f 100644 --- a/src/Compiler/Facilities/DiagnosticsLogger.fs +++ b/src/Compiler/Facilities/DiagnosticsLogger.fs @@ -876,7 +876,7 @@ type StackGuard(maxDepth: int, name: string) = [] line: int ) = - Activity.logEvent + Activity.addEventWithTags "DiagnosticsLogger.StackGuard.Guard" (seq { Activity.Tags.stackGuardName, box name diff --git a/src/Compiler/Utilities/Activity.fs b/src/Compiler/Utilities/Activity.fs index 8f2cd782983..44196032a38 100644 --- a/src/Compiler/Utilities/Activity.fs +++ b/src/Compiler/Utilities/Activity.fs @@ -103,7 +103,7 @@ module internal Activity = let startNoTags (name: string) : IDisposable = activitySource.StartActivity name - let logEvent name (tags: (string * objnull) seq) = + let addEventWithTags name (tags: (string * objnull) seq) = match Activity.Current with | null -> () | activity when activity.Source = activitySource -> @@ -112,7 +112,7 @@ module internal Activity = activity.AddEvent event |> ignore | _ -> () - let addEvent name = logEvent name Seq.empty + let addEvent name = addEventWithTags name Seq.empty module Profiling = diff --git a/src/Compiler/Utilities/Activity.fsi b/src/Compiler/Utilities/Activity.fsi index 412b89c45ee..e2c1eba42b8 100644 --- a/src/Compiler/Utilities/Activity.fsi +++ b/src/Compiler/Utilities/Activity.fsi @@ -45,7 +45,7 @@ module internal Activity = val addEvent: name: string -> unit - val logEvent: name: string -> tags: (string * objnull) seq -> unit + val addEventWithTags: name: string -> tags: (string * objnull) seq -> unit module Profiling = val startAndMeasureEnvironmentStats: name: string -> IDisposable