From c0009f9ab6a6843d20de11ad8d70780be1a2ee98 Mon Sep 17 00:00:00 2001 From: Ivan Dlugos Date: Wed, 13 Dec 2023 09:49:26 +0100 Subject: [PATCH 01/38] update profiler tests --- ...SingleProfile_Works.DotNet6_0.verified.txt | 62 - ...SingleProfile_Works.DotNet7_0.verified.txt | 56 - .../SamplingTransactionProfilerTests.cs | 26 +- .../Sentry.Profiling.Tests.csproj | 1 + ...Serialization_Works.DotNet8_0.verified.txt | 1070 +++++++++++++++++ 5 files changed, 1079 insertions(+), 136 deletions(-) delete mode 100644 test/Sentry.Profiling.Tests/SamplingTransactionProfilerTests.Profiler_SingleProfile_Works.DotNet6_0.verified.txt delete mode 100644 test/Sentry.Profiling.Tests/SamplingTransactionProfilerTests.Profiler_SingleProfile_Works.DotNet7_0.verified.txt create mode 100644 test/Sentry.Profiling.Tests/TraceLogProcessorTests.ProfileInfo_Serialization_Works.DotNet8_0.verified.txt diff --git a/test/Sentry.Profiling.Tests/SamplingTransactionProfilerTests.Profiler_SingleProfile_Works.DotNet6_0.verified.txt b/test/Sentry.Profiling.Tests/SamplingTransactionProfilerTests.Profiler_SingleProfile_Works.DotNet6_0.verified.txt deleted file mode 100644 index 028a88447a..0000000000 --- a/test/Sentry.Profiling.Tests/SamplingTransactionProfilerTests.Profiler_SingleProfile_Works.DotNet6_0.verified.txt +++ /dev/null @@ -1,62 +0,0 @@ -{ - stacks: [ - [ - 0, - 1, - 2, - 3, - 4, - 5, - 6, - 7, - 8 - ] - ], - frames: [ - { - function: System.Threading.Monitor.Wait(class System.Object,int32), - module: System.Private.CoreLib, - in_app: false - }, - { - function: System.Threading.ManualResetEventSlim.Wait(int32,value class System.Threading.CancellationToken), - module: System.Private.CoreLib, - in_app: false - }, - { - function: System.Threading.Tasks.Task.SpinThenBlockingWait(int32,value class System.Threading.CancellationToken), - module: System.Private.CoreLib, - in_app: false - }, - { - function: System.Threading.Tasks.Task.InternalWaitCore(int32,value class System.Threading.CancellationToken), - module: System.Private.CoreLib, - in_app: false - }, - { - function: System.Threading.Tasks.Task.Wait(int32,value class System.Threading.CancellationToken), - module: System.Private.CoreLib, - in_app: false - }, - { - function: System.Threading.Tasks.Task.Wait(), - module: System.Private.CoreLib, - in_app: false - }, - { - function: Microsoft.VisualStudio.TestPlatform.TestHost.DefaultEngineInvoker.Invoke(class System.Collections.Generic.IDictionary`2), - module: testhost, - in_app: true - }, - { - function: Microsoft.VisualStudio.TestPlatform.TestHost.Program.Run(class System.String[]), - module: testhost, - in_app: true - }, - { - function: Microsoft.VisualStudio.TestPlatform.TestHost.Program.Main(class System.String[]), - module: testhost, - in_app: true - } - ] -} \ No newline at end of file diff --git a/test/Sentry.Profiling.Tests/SamplingTransactionProfilerTests.Profiler_SingleProfile_Works.DotNet7_0.verified.txt b/test/Sentry.Profiling.Tests/SamplingTransactionProfilerTests.Profiler_SingleProfile_Works.DotNet7_0.verified.txt deleted file mode 100644 index 61b425743a..0000000000 --- a/test/Sentry.Profiling.Tests/SamplingTransactionProfilerTests.Profiler_SingleProfile_Works.DotNet7_0.verified.txt +++ /dev/null @@ -1,56 +0,0 @@ -{ - stacks: [ - [ - 0, - 1, - 2, - 3, - 4, - 5, - 6, - 7 - ] - ], - frames: [ - { - function: System.Threading.ManualResetEventSlim.Wait(int32,value class System.Threading.CancellationToken), - module: System.Private.CoreLib, - in_app: false - }, - { - function: System.Threading.Tasks.Task.SpinThenBlockingWait(int32,value class System.Threading.CancellationToken), - module: System.Private.CoreLib, - in_app: false - }, - { - function: System.Threading.Tasks.Task.InternalWaitCore(int32,value class System.Threading.CancellationToken), - module: System.Private.CoreLib, - in_app: false - }, - { - function: System.Threading.Tasks.Task.Wait(int32,value class System.Threading.CancellationToken), - module: System.Private.CoreLib, - in_app: false - }, - { - function: System.Threading.Tasks.Task.Wait(), - module: System.Private.CoreLib, - in_app: false - }, - { - function: Microsoft.VisualStudio.TestPlatform.TestHost.DefaultEngineInvoker.Invoke(class System.Collections.Generic.IDictionary`2), - module: testhost, - in_app: true - }, - { - function: Microsoft.VisualStudio.TestPlatform.TestHost.Program.Run(class System.String[]), - module: testhost, - in_app: true - }, - { - function: Microsoft.VisualStudio.TestPlatform.TestHost.Program.Main(class System.String[]), - module: testhost, - in_app: true - } - ] -} \ No newline at end of file diff --git a/test/Sentry.Profiling.Tests/SamplingTransactionProfilerTests.cs b/test/Sentry.Profiling.Tests/SamplingTransactionProfilerTests.cs index b2265ce850..7d8aef7ffe 100644 --- a/test/Sentry.Profiling.Tests/SamplingTransactionProfilerTests.cs +++ b/test/Sentry.Profiling.Tests/SamplingTransactionProfilerTests.cs @@ -72,13 +72,14 @@ private SampleProfile CaptureAndValidate(ITransactionProfilerFactory factory) var hub = Substitute.For(); var transactionTracer = new TransactionTracer(hub, "test", ""); var sut = factory.Start(transactionTracer, CancellationToken.None); + Assert.NotNull(sut); transactionTracer.TransactionProfiler = sut; RunForMs(100); sut.Finish(); var elapsedNanoseconds = (ulong)((clock.CurrentDateTimeOffset - clock.StartDateTimeOffset).TotalMilliseconds * 1_000_000); var transaction = new Transaction(transactionTracer); - var collectTask = (sut as SamplingTransactionProfiler).CollectAsync(transaction); + var collectTask = (sut as SamplingTransactionProfiler)!.CollectAsync(transaction); collectTask.Wait(); var profileInfo = collectTask.Result; Assert.NotNull(profileInfo); @@ -86,26 +87,14 @@ private SampleProfile CaptureAndValidate(ITransactionProfilerFactory factory) return profileInfo.Profile; } - [Fact(Skip = "This test is flaky. TODO: rework")] - public Task Profiler_SingleProfile_Works() + [Fact] + public void Profiler_SingleProfile_Works() { using var factory = SamplingTransactionProfilerFactory.Create(_testSentryOptions); var profile = CaptureAndValidate(factory); - - // We "Verify" part of a profile that seems to be stable. - var profileToVerify = new SampleProfile(); - profileToVerify.Stacks.Add(profile.Stacks[0]); - for (var i = 0; i < profileToVerify.Stacks[0].Count; i++) - { - var frame = profile.Frames[profileToVerify.Stacks[0][i]]; - frame.Module = frame.Module.Replace("System.Private.CoreLib.il", "System.Private.CoreLib"); - profileToVerify.Frames.Add(frame); - } - var json = profileToVerify.ToJsonString(_testOutputLogger); - return VerifyJson(json).UniqueForRuntimeAndVersion(); } - [Fact(Skip = "This test is flaky. TODO: rework")] + [Fact] public void Profiler_MultipleProfiles_Works() { using var factory = SamplingTransactionProfilerFactory.Create(_testSentryOptions); @@ -116,7 +105,7 @@ public void Profiler_MultipleProfiles_Works() CaptureAndValidate(factory); } - [Fact(Skip = "This test is flaky. TODO: rework")] + [Fact] public void Profiler_AfterTimeout_Stops() { using var session = SampleProfilerSession.StartNew(_testOutputLogger); @@ -133,7 +122,7 @@ public void Profiler_AfterTimeout_Stops() ValidateProfile(profileInfo.Profile, (ulong)(limitMs * 1_000_000)); } - [Theory(Skip = "This test is flaky. TODO: rework")] + [Theory] [InlineData(true)] [InlineData(false)] public void ProfilerIntegration_FullRoundtrip_Works(bool offlineCaching) @@ -173,6 +162,7 @@ async Task VerifyAsync(HttpRequestMessage message) Debug = true, DiagnosticLogger = _testOutputLogger, TracesSampleRate = 1.0, + ProfilesSampleRate = 1.0, }; // Disable process exit flush to resolve "There is no currently active test." errors. diff --git a/test/Sentry.Profiling.Tests/Sentry.Profiling.Tests.csproj b/test/Sentry.Profiling.Tests/Sentry.Profiling.Tests.csproj index c0e121a262..ceaf10debb 100644 --- a/test/Sentry.Profiling.Tests/Sentry.Profiling.Tests.csproj +++ b/test/Sentry.Profiling.Tests/Sentry.Profiling.Tests.csproj @@ -2,6 +2,7 @@ net8.0;net7.0;net6.0 + enable diff --git a/test/Sentry.Profiling.Tests/TraceLogProcessorTests.ProfileInfo_Serialization_Works.DotNet8_0.verified.txt b/test/Sentry.Profiling.Tests/TraceLogProcessorTests.ProfileInfo_Serialization_Works.DotNet8_0.verified.txt new file mode 100644 index 0000000000..86d6473db6 --- /dev/null +++ b/test/Sentry.Profiling.Tests/TraceLogProcessorTests.ProfileInfo_Serialization_Works.DotNet8_0.verified.txt @@ -0,0 +1,1070 @@ +{ + version: 1, + event_id: Guid_1, + timestamp: DateTimeOffset_1, + platform: csharp, + device: { + architecture: arch, + manufacturer: device make, + model: device model + }, + os: { + name: Windows, + version: 6.3.9600 + }, + runtime: { + type: runtime + }, + transaction: { + active_thread_id: 0, + id: Guid_2, + name: name, + trace_id: Guid_3 + }, + profile: { + thread_metadata: { + 0: { + name: Thread 23364 + }, + 1: { + name: Thread 5372 + }, + 2: { + name: Thread 4688 + }, + 3: { + name: Thread 24980 + }, + 4: { + name: Thread 2152 + }, + 5: { + name: Thread 7860 + }, + 6: { + name: Thread 12688 + } + }, + stacks: [ + [ + 0, + 1, + 2, + 3, + 4, + 5, + 6, + 7, + 8, + 9, + 10, + 11, + 12, + 13, + 14, + 15, + 16, + 17 + ], + [ + 18, + 19, + 20, + 21, + 22 + ], + [ + 23, + 24, + 25, + 22 + ], + [ + 18, + 19, + 20, + 21, + 22 + ], + [ + 18, + 19, + 20, + 21, + 22 + ], + [ + 26, + 27, + 28, + 29, + 30, + 31, + 32, + 33, + 34, + 35, + 36 + ], + [ + 37 + ], + [ + 0, + 1, + 38, + 39, + 40, + 41, + 42, + 43, + 44, + 45, + 46, + 22 + ], + [ + 47, + 48, + 49, + 50, + 51, + 52, + 37 + ], + [ + 53, + 54, + 55, + 56, + 57, + 37 + ], + [ + 58, + 59, + 60, + 61, + 62 + ], + [ + 63, + 64, + 65, + 66, + 67, + 68, + 69, + 70, + 71, + 72, + 58, + 59, + 60, + 61, + 62 + ], + [ + 73, + 74, + 75, + 76, + 77, + 78, + 58, + 59, + 60, + 61, + 62 + ], + [ + 79, + 80, + 78, + 58, + 59, + 60, + 61, + 62 + ], + [ + 81, + 59, + 60, + 61, + 62 + ], + [ + 82, + 83, + 84, + 85, + 86, + 87, + 88, + 89, + 90, + 62 + ], + [ + 91, + 92, + 93, + 94, + 95, + 96, + 97, + 98, + 99, + 100, + 84, + 85, + 86, + 87, + 88, + 89, + 90, + 62 + ], + [ + 0, + 1, + 38, + 39, + 40, + 41, + 42, + 43, + 44, + 45, + 46, + 22 + ], + [ + 18, + 19, + 20, + 101, + 22 + ] + ], + frames: [ + { + function: System.IO.Pipes.PipeStream.ReadCore(value class System.Span`1), + module: System.IO.Pipes.il, + in_app: false + }, + { + function: System.IO.Pipes.PipeStream.Read(unsigned int8[],int32,int32), + module: System.IO.Pipes.il, + in_app: false + }, + { + function: System.IO.BinaryReader.ReadBytes(int32), + module: System.Private.CoreLib.il, + in_app: false + }, + { + function: Microsoft.Diagnostics.NETCore.Client.IpcHeader.Parse(class System.IO.BinaryReader), + module: Microsoft.Diagnostics.NETCore.Client, + in_app: false + }, + { + function: Microsoft.Diagnostics.NETCore.Client.IpcMessage.Parse(class System.IO.Stream), + module: Microsoft.Diagnostics.NETCore.Client, + in_app: false + }, + { + function: Microsoft.Diagnostics.NETCore.Client.IpcClient.Read(class System.IO.Stream), + module: Microsoft.Diagnostics.NETCore.Client, + in_app: false + }, + { + function: Microsoft.Diagnostics.NETCore.Client.IpcClient.SendMessageGetContinuation(class Microsoft.Diagnostics.NETCore.Client.IpcEndpoint,class Microsoft.Diagnostics.NETCore.Client.IpcMessage), + module: Microsoft.Diagnostics.NETCore.Client, + in_app: false + }, + { + function: Microsoft.Diagnostics.NETCore.Client.EventPipeSession.Start(class Microsoft.Diagnostics.NETCore.Client.IpcEndpoint,class System.Collections.Generic.IEnumerable`1,bool,int32), + module: Microsoft.Diagnostics.NETCore.Client, + in_app: false + }, + { + function: Microsoft.Diagnostics.NETCore.Client.DiagnosticsClient.StartEventPipeSession(class System.Collections.Generic.IEnumerable`1,bool,int32), + module: Microsoft.Diagnostics.NETCore.Client, + in_app: false + }, + { + function: Sentry.Profiling.SampleProfilerSession..ctor(value class System.Threading.CancellationToken), + module: Sentry.Profiling, + in_app: false + }, + { + function: Sentry.Profiling.SamplingTransactionProfiler..ctor(class System.String,value class System.DateTimeOffset,int32,class Sentry.SentryOptions,value class System.Threading.CancellationToken), + module: Sentry.Profiling, + in_app: false + }, + { + function: Sentry.Profiling.SamplingTransactionProfilerFactory.OnTransactionStart(class Sentry.ITransaction,value class System.DateTimeOffset,value class System.Threading.CancellationToken), + module: Sentry.Profiling, + in_app: false + }, + { + function: Sentry.Internal.Hub.StartTransaction(class Sentry.ITransactionContext,class System.Collections.Generic.IReadOnlyDictionary`2,class Sentry.DynamicSamplingContext), + module: Sentry, + in_app: false + }, + { + function: Sentry.Internal.Hub.StartTransaction(class Sentry.ITransactionContext,class System.Collections.Generic.IReadOnlyDictionary`2), + module: Sentry, + in_app: false + }, + { + function: Sentry.HubExtensions.StartTransaction(class Sentry.IHub,class Sentry.ITransactionContext), + module: Sentry, + in_app: false + }, + { + function: Sentry.HubExtensions.StartTransaction(class Sentry.IHub,class System.String,class System.String), + module: Sentry, + in_app: false + }, + { + function: Sentry.SentrySdk.StartTransaction(class System.String,class System.String), + module: Sentry, + in_app: false + }, + { + function: Aura.UI.Gallery.NetCore.Program.Main(class System.String[]), + module: Aura.UI.Gallery.NetCore, + in_app: true + }, + { + in_app: false + }, + { + function: System.Threading.LowLevelLifoSemaphore.WaitForSignal(int32), + module: System.Private.CoreLib.il, + in_app: false + }, + { + function: System.Threading.LowLevelLifoSemaphore.Wait(int32,bool), + module: System.Private.CoreLib.il, + in_app: false + }, + { + function: System.Threading.PortableThreadPool+WorkerThread.WorkerThreadStart(), + module: System.Private.CoreLib.il, + in_app: false + }, + { + function: System.Threading.Thread.StartCallback(), + module: System.Private.CoreLib.il, + in_app: false + }, + { + function: System.Threading.WaitHandle.WaitOneNoCheck(int32), + module: System.Private.CoreLib.il, + in_app: false + }, + { + function: System.Threading.WaitHandle.WaitOne(int32), + module: System.Private.CoreLib.il, + in_app: false + }, + { + function: System.Threading.PortableThreadPool+GateThread.GateThreadStart(), + module: System.Private.CoreLib.il, + in_app: false + }, + { + function: System.Text.Unicode.Utf8Utility.TranscodeToUtf16(unsigned int8*,int32,wchar*,int32,unsigned int8*&,wchar*&), + module: System.Private.CoreLib.il, + in_app: false + }, + { + function: System.Text.UTF8Encoding.GetChars(unsigned int8*,int32,wchar*,int32), + module: System.Private.CoreLib.il, + in_app: false + }, + { + function: System.String.CreateStringFromEncoding(unsigned int8*,int32,class System.Text.Encoding), + module: System.Private.CoreLib.il, + in_app: false + }, + { + function: System.Reflection.MdFieldInfo.get_Name(), + module: System.Private.CoreLib.il, + in_app: false + }, + { + function: System.Diagnostics.Tracing.EventSource.AddProviderEnumKind(class System.Diagnostics.Tracing.ManifestBuilder,class System.Reflection.FieldInfo,class System.String), + module: System.Private.CoreLib.il, + in_app: false + }, + { + function: System.Diagnostics.Tracing.EventSource.CreateManifestAndDescriptors(class System.Type,class System.String,class System.Diagnostics.Tracing.EventSource,value class System.Diagnostics.Tracing.EventManifestOptions), + module: System.Private.CoreLib.il, + in_app: false + }, + { + function: System.Diagnostics.Tracing.EventSource.EnsureDescriptorsInitialized(), + module: System.Private.CoreLib.il, + in_app: false + }, + { + function: System.Diagnostics.Tracing.EventSource.DoCommand(class System.Diagnostics.Tracing.EventCommandEventArgs), + module: System.Private.CoreLib.il, + in_app: false + }, + { + function: System.Diagnostics.Tracing.EventSource.SendCommand(class System.Diagnostics.Tracing.EventListener,value class System.Diagnostics.Tracing.EventProviderType,int32,int32,value class System.Diagnostics.Tracing.EventCommand,bool,value class System.Diagnostics.Tracing.EventLevel,value class System.Diagnostics.Tracing.EventKeywords,class System.Collections.Generic.IDictionary`2), + module: System.Private.CoreLib.il, + in_app: false + }, + { + function: System.Diagnostics.Tracing.EventSource+OverrideEventProvider.OnControllerCommand(value class System.Diagnostics.Tracing.ControllerCommand,class System.Collections.Generic.IDictionary`2,int32,int32), + module: System.Private.CoreLib.il, + in_app: false + }, + { + function: System.Diagnostics.Tracing.EventProvider.EtwEnableCallBack(value class System.Guid&,int32,unsigned int8,int64,int64,value class EVENT_FILTER_DESCRIPTOR*,void*), + module: System.Private.CoreLib.il, + in_app: false + }, + { + function: Aura.UI.Gallery.NetCore.Program.Main(class System.String[]), + module: Aura.UI.Gallery.NetCore, + in_app: true + }, + { + function: System.IO.Stream+<>c.b__40_0(class System.Object), + module: System.Private.CoreLib.il, + in_app: false + }, + { + function: System.Threading.Tasks.Task`1[System.Int32].InnerInvoke(), + module: System.Private.CoreLib.il, + in_app: false + }, + { + function: System.Threading.Tasks.Task+<>c.<.cctor>b__272_0(class System.Object), + module: System.Private.CoreLib.il, + in_app: false + }, + { + function: System.Threading.ExecutionContext.RunFromThreadPoolDispatchLoop(class System.Threading.Thread,class System.Threading.ExecutionContext,class System.Threading.ContextCallback,class System.Object), + module: System.Private.CoreLib.il, + in_app: false + }, + { + function: System.Threading.Tasks.Task.ExecuteWithThreadLocal(class System.Threading.Tasks.Task&,class System.Threading.Thread), + module: System.Private.CoreLib.il, + in_app: false + }, + { + function: System.Threading.Tasks.Task.ExecuteEntryUnsafe(class System.Threading.Thread), + module: System.Private.CoreLib.il, + in_app: false + }, + { + function: System.Threading.Tasks.Task.ExecuteFromThreadPool(class System.Threading.Thread), + module: System.Private.CoreLib.il, + in_app: false + }, + { + function: System.Threading.ThreadPoolWorkQueue.Dispatch(), + module: System.Private.CoreLib.il, + in_app: false + }, + { + function: System.Threading.PortableThreadPool+WorkerThread.WorkerThreadStart(), + module: System.Private.CoreLib.il, + in_app: false + }, + { + function: System.Collections.Concurrent.ConcurrentDictionary`2[System.__Canon,System.IntPtr].TryAddInternal(!0,value class System.Nullable`1,!1,bool,bool,!1&), + module: System.Collections.Concurrent.il, + in_app: false + }, + { + function: System.Collections.Concurrent.ConcurrentDictionary`2[System.__Canon,System.IntPtr].set_Item(!0,!1), + module: System.Collections.Concurrent.il, + in_app: false + }, + { + function: Avalonia.MicroCom.MicroComRuntime.RegisterVTable(class System.Type,int), + module: avalonia.microcom, + in_app: true + }, + { + function: Avalonia.Win32.WinRT.Impl.__MicroComICompositor2VTable.__MicroComModuleInit(), + module: avalonia.win32, + in_app: true + }, + { + function: ..cctor(), + module: avalonia.win32, + in_app: true + }, + { + in_app: false + }, + { + function: System.MulticastDelegate.CombineImpl(class System.Delegate), + module: System.Private.CoreLib.il, + in_app: false + }, + { + function: System.Delegate.Combine(class System.Delegate,class System.Delegate), + module: System.Private.CoreLib.il, + in_app: false + }, + { + function: Avalonia.Controls.AppBuilderBase`1[System.__Canon].AfterPlatformServicesSetup(class System.Action`1), + module: Avalonia.Controls, + in_app: true + }, + { + function: Avalonia.ReactiveUI.AppBuilderExtensions.UseReactiveUI(!!0), + module: avalonia.reactiveui, + in_app: true + }, + { + function: Aura.UI.Gallery.NetCore.Program.BuildAvaloniaApp(), + module: Aura.UI.Gallery.NetCore, + in_app: true + }, + { + function: Avalonia.Controls.Window..cctor(), + module: Avalonia.Controls, + in_app: true + }, + { + function: Avalonia.Controls.ApplicationLifetimes.ClassicDesktopStyleApplicationLifetime..cctor(), + module: Avalonia.Controls, + in_app: true + }, + { + function: Avalonia.Controls.ApplicationLifetimes.ClassicDesktopStyleApplicationLifetime..ctor(), + module: Avalonia.Controls, + in_app: true + }, + { + function: Avalonia.ClassicDesktopStyleApplicationLifetimeExtensions.StartWithClassicDesktopLifetime(!!0,class System.String[],value class Avalonia.Controls.ShutdownMode), + module: Avalonia.Controls, + in_app: true + }, + { + function: Aura.UI.Gallery.NetCore.Program.Main(class System.String[]), + module: Aura.UI.Gallery.NetCore, + in_app: true + }, + { + function: Avalonia.Animation.Animation..cctor(), + module: Avalonia.Animation, + in_app: true + }, + { + function: Avalonia.Animation.Animation.RegisterAnimator(class System.Func`2), + module: Avalonia.Animation, + in_app: true + }, + { + function: Avalonia.Point..cctor(), + module: Avalonia.Visuals, + in_app: true + }, + { + function: Avalonia.Point..ctor(float64,float64), + module: Avalonia.Visuals, + in_app: true + }, + { + function: Avalonia.RelativePoint..ctor(float64,float64,value class Avalonia.RelativeUnit), + module: Avalonia.Visuals, + in_app: true + }, + { + function: Avalonia.RelativePoint..cctor(), + module: Avalonia.Visuals, + in_app: true + }, + { + function: Avalonia.Visual..cctor(), + module: Avalonia.Visuals, + in_app: true + }, + { + function: Avalonia.Visual.AffectsRender(class Avalonia.AvaloniaProperty[]), + module: Avalonia.Visuals, + in_app: true + }, + { + function: Avalonia.Controls.Border..cctor(), + module: Avalonia.Controls, + in_app: true + }, + { + function: Avalonia.Controls.Primitives.TemplatedControl..cctor(), + module: Avalonia.Controls, + in_app: true + }, + { + function: System.Collections.Generic.Dictionary`2[System.__Canon,Avalonia.Media.KnownColor]..ctor(class System.Collections.Generic.IEqualityComparer`1), + module: System.Private.CoreLib.il, + in_app: false + }, + { + function: Avalonia.Media.KnownColors..cctor(), + module: Avalonia.Visuals, + in_app: true + }, + { + function: Avalonia.Media.KnownColors.ToBrush(value class Avalonia.Media.KnownColor), + module: Avalonia.Visuals, + in_app: true + }, + { + function: Avalonia.Media.Brushes.get_Black(), + module: Avalonia.Visuals, + in_app: true + }, + { + function: Avalonia.Controls.TextBlock..cctor(), + module: Avalonia.Controls, + in_app: true + }, + { + function: Avalonia.Controls.Primitives.TemplatedControl..cctor(), + module: Avalonia.Controls, + in_app: true + }, + { + function: System.Reactive.Linq.Observable.Merge(class System.IObservable`1[]), + module: system.reactive, + in_app: true + }, + { + function: Avalonia.Controls.TextBlock..cctor(), + module: Avalonia.Controls, + in_app: true + }, + { + function: Avalonia.Controls.Window..cctor(), + module: Avalonia.Controls, + in_app: true + }, + { + function: Avalonia.Win32.Win32Platform.SetDpiAwareness(), + module: avalonia.win32, + in_app: true + }, + { + function: Avalonia.Win32.Win32Platform..ctor(), + module: avalonia.win32, + in_app: true + }, + { + function: Avalonia.Win32.Win32Platform..cctor(), + module: avalonia.win32, + in_app: true + }, + { + function: Avalonia.Win32.Win32Platform.set_Options(class Avalonia.Win32PlatformOptions), + module: avalonia.win32, + in_app: true + }, + { + function: Avalonia.Win32.Win32Platform.Initialize(class Avalonia.Win32PlatformOptions), + module: avalonia.win32, + in_app: true + }, + { + function: Avalonia.Win32ApplicationExtensions+<>c__0`1[System.__Canon].b__0_0(), + module: avalonia.win32, + in_app: true + }, + { + function: Avalonia.Controls.AppBuilderBase`1[System.__Canon].Setup(), + module: Avalonia.Controls, + in_app: true + }, + { + function: Avalonia.Controls.AppBuilderBase`1[System.__Canon].SetupWithLifetime(class Avalonia.Controls.ApplicationLifetimes.IApplicationLifetime), + module: Avalonia.Controls, + in_app: true + }, + { + function: Avalonia.ClassicDesktopStyleApplicationLifetimeExtensions.StartWithClassicDesktopLifetime(!!0,class System.String[],value class Avalonia.Controls.ShutdownMode), + module: Avalonia.Controls, + in_app: true + }, + { + function: System.Drawing.SafeNativeMethods+Gdip..cctor(), + module: system.drawing.common, + in_app: true + }, + { + function: System.Drawing.SafeNativeMethods+Gdip.GdipCreateBitmapFromScan0(int32,int32,int32,int32,value class System.Runtime.InteropServices.HandleRef,int&), + module: system.drawing.common, + in_app: true + }, + { + function: System.Drawing.Bitmap..ctor(int32,int32,value class System.Drawing.Imaging.PixelFormat), + module: system.drawing.common, + in_app: true + }, + { + function: System.Drawing.Bitmap..ctor(int32,int32), + module: system.drawing.common, + in_app: true + }, + { + function: Avalonia.Win32.TrayIconImpl..cctor(), + module: avalonia.win32, + in_app: true + }, + { + function: Avalonia.Win32.TrayIconImpl.ProcWnd(int,unsigned int32,int,int), + module: avalonia.win32, + in_app: true + }, + { + function: Avalonia.Win32.Win32Platform.WndProc(int,unsigned int32,int,int), + module: avalonia.win32, + in_app: true + }, + { + in_app: false + }, + { + function: Avalonia.Win32.Win32Platform.CreateMessageWindow(), + module: avalonia.win32, + in_app: true + }, + { + function: Avalonia.Win32.Win32Platform..ctor(), + module: avalonia.win32, + in_app: true + }, + { + function: System.Threading.PortableThreadPool+WorkerThread.WorkerThreadStart(), + module: System.Private.CoreLib.il, + in_app: false + } + ], + samples: [ + { + elapsed_since_start_ns: 402400, + thread_id: 0, + stack_id: 0 + }, + { + elapsed_since_start_ns: 410600, + thread_id: 1, + stack_id: 1 + }, + { + elapsed_since_start_ns: 421900, + thread_id: 2, + stack_id: 2 + }, + { + elapsed_since_start_ns: 423600, + thread_id: 3, + stack_id: 3 + }, + { + elapsed_since_start_ns: 424900, + thread_id: 4, + stack_id: 4 + }, + { + elapsed_since_start_ns: 1760800, + thread_id: 5, + stack_id: 5 + }, + { + elapsed_since_start_ns: 11253400, + thread_id: 0, + stack_id: 6 + }, + { + elapsed_since_start_ns: 11260100, + thread_id: 1, + stack_id: 7 + }, + { + elapsed_since_start_ns: 11261700, + thread_id: 2, + stack_id: 2 + }, + { + elapsed_since_start_ns: 11264500, + thread_id: 3, + stack_id: 3 + }, + { + elapsed_since_start_ns: 11265600, + thread_id: 4, + stack_id: 4 + }, + { + elapsed_since_start_ns: 21259900, + thread_id: 0, + stack_id: 8 + }, + { + elapsed_since_start_ns: 21267900, + thread_id: 1, + stack_id: 7 + }, + { + elapsed_since_start_ns: 21270000, + thread_id: 2, + stack_id: 2 + }, + { + elapsed_since_start_ns: 21272100, + thread_id: 3, + stack_id: 3 + }, + { + elapsed_since_start_ns: 21274400, + thread_id: 4, + stack_id: 4 + }, + { + elapsed_since_start_ns: 31243800, + thread_id: 0, + stack_id: 6 + }, + { + elapsed_since_start_ns: 31248600, + thread_id: 1, + stack_id: 7 + }, + { + elapsed_since_start_ns: 31249800, + thread_id: 2, + stack_id: 2 + }, + { + elapsed_since_start_ns: 31251200, + thread_id: 3, + stack_id: 3 + }, + { + elapsed_since_start_ns: 31252200, + thread_id: 4, + stack_id: 4 + }, + { + elapsed_since_start_ns: 41251400, + thread_id: 0, + stack_id: 9 + }, + { + elapsed_since_start_ns: 41261500, + thread_id: 1, + stack_id: 7 + }, + { + elapsed_since_start_ns: 41263200, + thread_id: 2, + stack_id: 2 + }, + { + elapsed_since_start_ns: 41265000, + thread_id: 3, + stack_id: 3 + }, + { + elapsed_since_start_ns: 41266400, + thread_id: 4, + stack_id: 4 + }, + { + elapsed_since_start_ns: 51268200, + thread_id: 0, + stack_id: 10 + }, + { + elapsed_since_start_ns: 51291300, + thread_id: 1, + stack_id: 7 + }, + { + elapsed_since_start_ns: 51294700, + thread_id: 2, + stack_id: 2 + }, + { + elapsed_since_start_ns: 51300300, + thread_id: 3, + stack_id: 3 + }, + { + elapsed_since_start_ns: 51302000, + thread_id: 4, + stack_id: 4 + }, + { + elapsed_since_start_ns: 61258600, + thread_id: 0, + stack_id: 11 + }, + { + elapsed_since_start_ns: 61269400, + thread_id: 1, + stack_id: 7 + }, + { + elapsed_since_start_ns: 61271800, + thread_id: 2, + stack_id: 2 + }, + { + elapsed_since_start_ns: 61274400, + thread_id: 3, + stack_id: 3 + }, + { + elapsed_since_start_ns: 61276000, + thread_id: 4, + stack_id: 4 + }, + { + elapsed_since_start_ns: 71256100, + thread_id: 0, + stack_id: 12 + }, + { + elapsed_since_start_ns: 71268300, + thread_id: 1, + stack_id: 7 + }, + { + elapsed_since_start_ns: 71271900, + thread_id: 2, + stack_id: 2 + }, + { + elapsed_since_start_ns: 71279300, + thread_id: 3, + stack_id: 3 + }, + { + elapsed_since_start_ns: 71280500, + thread_id: 4, + stack_id: 4 + }, + { + elapsed_since_start_ns: 81242100, + thread_id: 0, + stack_id: 13 + }, + { + elapsed_since_start_ns: 81247700, + thread_id: 1, + stack_id: 7 + }, + { + elapsed_since_start_ns: 81248900, + thread_id: 2, + stack_id: 2 + }, + { + elapsed_since_start_ns: 81250500, + thread_id: 3, + stack_id: 3 + }, + { + elapsed_since_start_ns: 81251700, + thread_id: 4, + stack_id: 4 + }, + { + elapsed_since_start_ns: 91316900, + thread_id: 0, + stack_id: 14 + }, + { + elapsed_since_start_ns: 91324700, + thread_id: 1, + stack_id: 7 + }, + { + elapsed_since_start_ns: 91326400, + thread_id: 2, + stack_id: 2 + }, + { + elapsed_since_start_ns: 91328400, + thread_id: 3, + stack_id: 3 + }, + { + elapsed_since_start_ns: 91329900, + thread_id: 4, + stack_id: 4 + }, + { + elapsed_since_start_ns: 101264900, + thread_id: 0, + stack_id: 15 + }, + { + elapsed_since_start_ns: 101272700, + thread_id: 1, + stack_id: 7 + }, + { + elapsed_since_start_ns: 101274300, + thread_id: 2, + stack_id: 2 + }, + { + elapsed_since_start_ns: 101276100, + thread_id: 3, + stack_id: 3 + }, + { + elapsed_since_start_ns: 101277800, + thread_id: 4, + stack_id: 4 + }, + { + elapsed_since_start_ns: 112828800, + thread_id: 0, + stack_id: 16 + }, + { + elapsed_since_start_ns: 112839000, + thread_id: 1, + stack_id: 1 + }, + { + elapsed_since_start_ns: 112843800, + thread_id: 2, + stack_id: 2 + }, + { + elapsed_since_start_ns: 112847500, + thread_id: 3, + stack_id: 3 + }, + { + elapsed_since_start_ns: 112863500, + thread_id: 4, + stack_id: 17 + }, + { + elapsed_since_start_ns: 114809100, + thread_id: 6, + stack_id: 18 + } + ] + } +} \ No newline at end of file From c39d96c51519b47d5e3a5966126a5bb48efd690d Mon Sep 17 00:00:00 2001 From: Ivan Dlugos Date: Thu, 14 Dec 2023 12:01:16 +0100 Subject: [PATCH 02/38] logging --- src/Sentry.Profiling/SamplingTransactionProfiler.cs | 1 + .../SamplingTransactionProfilerTests.cs | 6 +++--- 2 files changed, 4 insertions(+), 3 deletions(-) diff --git a/src/Sentry.Profiling/SamplingTransactionProfiler.cs b/src/Sentry.Profiling/SamplingTransactionProfiler.cs index ebfa873b57..ba54b36b3a 100644 --- a/src/Sentry.Profiling/SamplingTransactionProfiler.cs +++ b/src/Sentry.Profiling/SamplingTransactionProfiler.cs @@ -80,6 +80,7 @@ private void OnThreadSample(TraceEvent data) } else { + _options.LogDebug("Profiler received a sample past the end time; stopping."); _session.SampleEventParser.ThreadSample -= OnThreadSample; _completionSource.TrySetResult(); } diff --git a/test/Sentry.Profiling.Tests/SamplingTransactionProfilerTests.cs b/test/Sentry.Profiling.Tests/SamplingTransactionProfilerTests.cs index 7d8aef7ffe..f3d11455e4 100644 --- a/test/Sentry.Profiling.Tests/SamplingTransactionProfilerTests.cs +++ b/test/Sentry.Profiling.Tests/SamplingTransactionProfilerTests.cs @@ -71,15 +71,15 @@ private SampleProfile CaptureAndValidate(ITransactionProfilerFactory factory) var clock = SentryStopwatch.StartNew(); var hub = Substitute.For(); var transactionTracer = new TransactionTracer(hub, "test", ""); - var sut = factory.Start(transactionTracer, CancellationToken.None); + var sut = factory.Start(transactionTracer, CancellationToken.None) as SamplingTransactionProfiler; Assert.NotNull(sut); transactionTracer.TransactionProfiler = sut; - RunForMs(100); + RunForMs(1000); sut.Finish(); var elapsedNanoseconds = (ulong)((clock.CurrentDateTimeOffset - clock.StartDateTimeOffset).TotalMilliseconds * 1_000_000); var transaction = new Transaction(transactionTracer); - var collectTask = (sut as SamplingTransactionProfiler)!.CollectAsync(transaction); + var collectTask = sut.CollectAsync(transaction); collectTask.Wait(); var profileInfo = collectTask.Result; Assert.NotNull(profileInfo); From aaba2315193f875ccbe42003c6ba99ddb09ee924 Mon Sep 17 00:00:00 2001 From: Ivan Dlugos Date: Thu, 14 Dec 2023 15:28:39 +0100 Subject: [PATCH 03/38] improve profiler session startup --- src/Sentry.Profiling/SampleProfilerSession.cs | 16 ++++++++++++++++ 1 file changed, 16 insertions(+) diff --git a/src/Sentry.Profiling/SampleProfilerSession.cs b/src/Sentry.Profiling/SampleProfilerSession.cs index 009b3ff03e..b994d4b05b 100644 --- a/src/Sentry.Profiling/SampleProfilerSession.cs +++ b/src/Sentry.Profiling/SampleProfilerSession.cs @@ -1,5 +1,6 @@ using System.Diagnostics.Tracing; using Microsoft.Diagnostics.NETCore.Client; +using Microsoft.Diagnostics.Tracing; using Microsoft.Diagnostics.Tracing.Etlx; using Microsoft.Diagnostics.Tracing.EventPipe; using Microsoft.Diagnostics.Tracing.Parsers; @@ -60,6 +61,21 @@ public static SampleProfilerSession StartNew(IDiagnosticLogger? logger = null) // Process() blocks until the session is stopped so we need to run it on a separate thread. Task.Factory.StartNew(eventSource.Process, TaskCreationOptions.LongRunning); + var tcs = new TaskCompletionSource(); + var cb = (TraceEvent _) => { tcs.TrySetResult(); }; + eventSource.AllEvents += cb; + try + { + // Wait for the first event to be processed. + tcs.Task.Wait(1_000); + } + catch (Exception ex) + { + // Log a warning but still try to keep the session running. + logger?.LogWarning("Profiler session startup: timed out waiting for the first event to be received.", ex); + } + eventSource.AllEvents -= cb; + return new SampleProfilerSession(stopWatch, session, eventSource, logger); } From 00c75de8a7b97fcfe50ee6e831a69db33e582662 Mon Sep 17 00:00:00 2001 From: Ivan Dlugos Date: Fri, 15 Dec 2023 10:21:56 +0100 Subject: [PATCH 04/38] make profiling startup async --- src/Sentry.Profiling/SampleProfilerSession.cs | 17 ++++++------ .../SamplingTransactionProfilerFactory.cs | 26 ++++++++++++------- 2 files changed, 25 insertions(+), 18 deletions(-) diff --git a/src/Sentry.Profiling/SampleProfilerSession.cs b/src/Sentry.Profiling/SampleProfilerSession.cs index b994d4b05b..cb2266c8c8 100644 --- a/src/Sentry.Profiling/SampleProfilerSession.cs +++ b/src/Sentry.Profiling/SampleProfilerSession.cs @@ -61,22 +61,23 @@ public static SampleProfilerSession StartNew(IDiagnosticLogger? logger = null) // Process() blocks until the session is stopped so we need to run it on a separate thread. Task.Factory.StartNew(eventSource.Process, TaskCreationOptions.LongRunning); + return new SampleProfilerSession(stopWatch, session, eventSource, logger); + } + + public async Task WaitForFirstEventAsync(CancellationToken cancellationToken = default) + { var tcs = new TaskCompletionSource(); var cb = (TraceEvent _) => { tcs.TrySetResult(); }; - eventSource.AllEvents += cb; + _eventSource.AllEvents += cb; try { // Wait for the first event to be processed. - tcs.Task.Wait(1_000); + await tcs.Task.WaitAsync(cancellationToken).ConfigureAwait(false); } - catch (Exception ex) + finally { - // Log a warning but still try to keep the session running. - logger?.LogWarning("Profiler session startup: timed out waiting for the first event to be received.", ex); + _eventSource.AllEvents -= cb; } - eventSource.AllEvents -= cb; - - return new SampleProfilerSession(stopWatch, session, eventSource, logger); } public void Stop() diff --git a/src/Sentry.Profiling/SamplingTransactionProfilerFactory.cs b/src/Sentry.Profiling/SamplingTransactionProfilerFactory.cs index 569b19b29f..7e73774cb1 100644 --- a/src/Sentry.Profiling/SamplingTransactionProfilerFactory.cs +++ b/src/Sentry.Profiling/SamplingTransactionProfilerFactory.cs @@ -15,21 +15,20 @@ internal class SamplingTransactionProfilerFactory : IDisposable, ITransactionPro private const int TIME_LIMIT_MS = 30_000; private readonly SentryOptions _options; - private SampleProfilerSession _session; + private Task _session; public static SamplingTransactionProfilerFactory Create(SentryOptions options) { - var session = SampleProfilerSession.StartNew(options.DiagnosticLogger); - return new SamplingTransactionProfilerFactory(options, session); - } - - public static async Task CreateAsync(SentryOptions options) - { - var session = await Task.Run(() => SampleProfilerSession.StartNew(options.DiagnosticLogger)).ConfigureAwait(false); + var session = Task.Run(async () => + { + var session = SampleProfilerSession.StartNew(options.DiagnosticLogger); + await session.WaitForFirstEventAsync().ConfigureAwait(false); + return session; + }); return new SamplingTransactionProfilerFactory(options, session); } - private SamplingTransactionProfilerFactory(SentryOptions options, SampleProfilerSession session) + private SamplingTransactionProfilerFactory(SentryOptions options, Task session) { _options = options; _session = session; @@ -41,10 +40,17 @@ private SamplingTransactionProfilerFactory(SentryOptions options, SampleProfiler // Start a profiler if one wasn't running yet. if (Interlocked.Exchange(ref _inProgress, TRUE) == FALSE) { + if (!_session.IsCompletedSuccessfully) + { + _options.LogDebug("Cannot start a a sampling profiler, the session hasn't started yet."); + _inProgress = FALSE; + return null; + } + _options.LogDebug("Starting a sampling profiler."); try { - return new SamplingTransactionProfiler(_options, _session, TIME_LIMIT_MS, cancellationToken) + return new SamplingTransactionProfiler(_options, _session.Result, TIME_LIMIT_MS, cancellationToken) { OnFinish = () => _inProgress = FALSE }; From c3d413a96c29adec8150b9afcf12da21d60c5c6b Mon Sep 17 00:00:00 2001 From: Ivan Dlugos Date: Fri, 15 Dec 2023 13:32:40 +0100 Subject: [PATCH 05/38] introduce profiler startup timeout --- .../Sentry.Benchmarks/ProfilingBenchmarks.cs | 2 +- src/Sentry.Profiling/ProfilingIntegration.cs | 19 +++++++- .../SamplingTransactionProfilerFactory.cs | 44 ++++++++++++------- .../SamplingTransactionProfilerTests.cs | 8 ++-- 4 files changed, 52 insertions(+), 21 deletions(-) diff --git a/benchmarks/Sentry.Benchmarks/ProfilingBenchmarks.cs b/benchmarks/Sentry.Benchmarks/ProfilingBenchmarks.cs index dc64852d04..bbbab67ef2 100644 --- a/benchmarks/Sentry.Benchmarks/ProfilingBenchmarks.cs +++ b/benchmarks/Sentry.Benchmarks/ProfilingBenchmarks.cs @@ -18,7 +18,7 @@ public class ProfilingBenchmarks [GlobalSetup(Targets = new string[] { nameof(Transaction), nameof(DoHardWorkWhileProfiling) })] public void StartProfiler() { - _factory = SamplingTransactionProfilerFactory.Create(new()); + _factory = new SamplingTransactionProfilerFactory(new(), TimeSpan.FromSeconds(5)); } [GlobalCleanup(Targets = new string[] { nameof(Transaction), nameof(DoHardWorkWhileProfiling) })] diff --git a/src/Sentry.Profiling/ProfilingIntegration.cs b/src/Sentry.Profiling/ProfilingIntegration.cs index c94cd2d147..03a1468a19 100644 --- a/src/Sentry.Profiling/ProfilingIntegration.cs +++ b/src/Sentry.Profiling/ProfilingIntegration.cs @@ -7,12 +7,29 @@ namespace Sentry.Profiling; /// public class ProfilingIntegration : ISdkIntegration { + private TimeSpan _startupTimeout; + + /// + /// Initializes the profiling integration. + /// + /// + /// If not given or TimeSpan.Zero, then the profiler initialization is asynchronous. + /// This is useful for applications that need to start quickly. The profiler will start in the background + /// and will be ready to capture transactions that have started after the profiler has started. + /// + /// If given a non-zero timeout, profiling startup blocks up to the given amount of time. + /// + public ProfilingIntegration(TimeSpan startupTimeout = default) + { + _startupTimeout = startupTimeout; + } + /// public void Register(IHub hub, SentryOptions options) { if (options.IsProfilingEnabled) { - options.TransactionProfilerFactory ??= SamplingTransactionProfilerFactory.Create(options); + options.TransactionProfilerFactory ??= new SamplingTransactionProfilerFactory(options, _startupTimeout); } } } diff --git a/src/Sentry.Profiling/SamplingTransactionProfilerFactory.cs b/src/Sentry.Profiling/SamplingTransactionProfilerFactory.cs index 7e73774cb1..0003fb2f59 100644 --- a/src/Sentry.Profiling/SamplingTransactionProfilerFactory.cs +++ b/src/Sentry.Profiling/SamplingTransactionProfilerFactory.cs @@ -15,23 +15,35 @@ internal class SamplingTransactionProfilerFactory : IDisposable, ITransactionPro private const int TIME_LIMIT_MS = 30_000; private readonly SentryOptions _options; - private Task _session; + private Task _sessionTask; - public static SamplingTransactionProfilerFactory Create(SentryOptions options) + public SamplingTransactionProfilerFactory(SentryOptions options, TimeSpan startupTimeout) { - var session = Task.Run(async () => + _options = options; + + if (startupTimeout == TimeSpan.Zero) + { + _sessionTask = Task.Run(async () => + { + var session = SampleProfilerSession.StartNew(options.DiagnosticLogger); + await session.WaitForFirstEventAsync().ConfigureAwait(false); + return session; + }); + } + else { var session = SampleProfilerSession.StartNew(options.DiagnosticLogger); - await session.WaitForFirstEventAsync().ConfigureAwait(false); - return session; - }); - return new SamplingTransactionProfilerFactory(options, session); - } - - private SamplingTransactionProfilerFactory(SentryOptions options, Task session) - { - _options = options; - _session = session; + var firstEventTask = session.WaitForFirstEventAsync(); + if (firstEventTask.Wait(startupTimeout)) + { + _sessionTask = Task.FromResult(session); + } + else + { + options.LogWarning("Profiler session startup took longer then the given timeout {0:c}. Profilling will start once the first event is received.", startupTimeout); + _sessionTask = firstEventTask.ContinueWith(_ => session); + } + } } /// @@ -40,7 +52,7 @@ private SamplingTransactionProfilerFactory(SentryOptions options, Task _inProgress = FALSE }; @@ -66,6 +78,6 @@ private SamplingTransactionProfilerFactory(SentryOptions options, Task _session.Dispose()); } } diff --git a/test/Sentry.Profiling.Tests/SamplingTransactionProfilerTests.cs b/test/Sentry.Profiling.Tests/SamplingTransactionProfilerTests.cs index f3d11455e4..e5df81c999 100644 --- a/test/Sentry.Profiling.Tests/SamplingTransactionProfilerTests.cs +++ b/test/Sentry.Profiling.Tests/SamplingTransactionProfilerTests.cs @@ -8,6 +8,8 @@ namespace Sentry.Profiling.Tests; [UsesVerify] public class SamplingTransactionProfilerTests { + private TimeSpan _defaultStartTimeout = TimeSpan.FromSeconds(5); + private readonly IDiagnosticLogger _testOutputLogger; private readonly SentryOptions _testSentryOptions; @@ -90,14 +92,14 @@ private SampleProfile CaptureAndValidate(ITransactionProfilerFactory factory) [Fact] public void Profiler_SingleProfile_Works() { - using var factory = SamplingTransactionProfilerFactory.Create(_testSentryOptions); + using var factory = new SamplingTransactionProfilerFactory(_testSentryOptions, _defaultStartTimeout); var profile = CaptureAndValidate(factory); } [Fact] public void Profiler_MultipleProfiles_Works() { - using var factory = SamplingTransactionProfilerFactory.Create(_testSentryOptions); + using var factory = new SamplingTransactionProfilerFactory(_testSentryOptions, _defaultStartTimeout); CaptureAndValidate(factory); Thread.Sleep(100); CaptureAndValidate(factory); @@ -168,7 +170,7 @@ async Task VerifyAsync(HttpRequestMessage message) // Disable process exit flush to resolve "There is no currently active test." errors. options.DisableAppDomainProcessExitFlush(); - options.AddIntegration(new ProfilingIntegration()); + options.AddIntegration(new ProfilingIntegration(_defaultStartTimeout)); try { From 812874c4adf629ff8cafd46badf47d2f9fad57de Mon Sep 17 00:00:00 2001 From: Ivan Dlugos Date: Fri, 15 Dec 2023 15:12:20 +0100 Subject: [PATCH 06/38] improve tests --- src/Sentry.Profiling/ProfilingIntegration.cs | 4 ++- .../SamplingTransactionProfilerFactory.cs | 2 +- .../SamplingTransactionProfilerTests.cs | 30 +++++++++++++------ 3 files changed, 25 insertions(+), 11 deletions(-) diff --git a/src/Sentry.Profiling/ProfilingIntegration.cs b/src/Sentry.Profiling/ProfilingIntegration.cs index 03a1468a19..087d0f0cf7 100644 --- a/src/Sentry.Profiling/ProfilingIntegration.cs +++ b/src/Sentry.Profiling/ProfilingIntegration.cs @@ -17,7 +17,9 @@ public class ProfilingIntegration : ISdkIntegration /// This is useful for applications that need to start quickly. The profiler will start in the background /// and will be ready to capture transactions that have started after the profiler has started. /// - /// If given a non-zero timeout, profiling startup blocks up to the given amount of time. + /// If given a non-zero timeout, profiling startup blocks up to the given amount of time. If the timeout is reached + /// and the profiler session hasn't started yet, the execution is unblocked and behaves as the async startup, + /// i.e. transactions will be profiled only after the session is eventually started. /// public ProfilingIntegration(TimeSpan startupTimeout = default) { diff --git a/src/Sentry.Profiling/SamplingTransactionProfilerFactory.cs b/src/Sentry.Profiling/SamplingTransactionProfilerFactory.cs index 0003fb2f59..3da27f7a6c 100644 --- a/src/Sentry.Profiling/SamplingTransactionProfilerFactory.cs +++ b/src/Sentry.Profiling/SamplingTransactionProfilerFactory.cs @@ -15,7 +15,7 @@ internal class SamplingTransactionProfilerFactory : IDisposable, ITransactionPro private const int TIME_LIMIT_MS = 30_000; private readonly SentryOptions _options; - private Task _sessionTask; + internal Task _sessionTask; public SamplingTransactionProfilerFactory(SentryOptions options, TimeSpan startupTimeout) { diff --git a/test/Sentry.Profiling.Tests/SamplingTransactionProfilerTests.cs b/test/Sentry.Profiling.Tests/SamplingTransactionProfilerTests.cs index e5df81c999..d26de39b89 100644 --- a/test/Sentry.Profiling.Tests/SamplingTransactionProfilerTests.cs +++ b/test/Sentry.Profiling.Tests/SamplingTransactionProfilerTests.cs @@ -8,8 +8,6 @@ namespace Sentry.Profiling.Tests; [UsesVerify] public class SamplingTransactionProfilerTests { - private TimeSpan _defaultStartTimeout = TimeSpan.FromSeconds(5); - private readonly IDiagnosticLogger _testOutputLogger; private readonly SentryOptions _testSentryOptions; @@ -89,17 +87,31 @@ private SampleProfile CaptureAndValidate(ITransactionProfilerFactory factory) return profileInfo.Profile; } - [Fact] - public void Profiler_SingleProfile_Works() + [Theory] + [InlineData(0)] + [InlineData(5)] + public void Profiler_SingleProfile_Works(int startTimeoutSeconds) { - using var factory = new SamplingTransactionProfilerFactory(_testSentryOptions, _defaultStartTimeout); + using var factory = new SamplingTransactionProfilerFactory(_testSentryOptions, TimeSpan.FromSeconds(startTimeoutSeconds)); + // in the async startup case, we need to wait before collecting + if (startTimeoutSeconds == 0) + { + factory._sessionTask.Wait(5 * 1000); + } var profile = CaptureAndValidate(factory); } - [Fact] - public void Profiler_MultipleProfiles_Works() + [Theory] + [InlineData(0)] + [InlineData(5)] + public void Profiler_MultipleProfiles_Works(int startTimeoutSeconds) { - using var factory = new SamplingTransactionProfilerFactory(_testSentryOptions, _defaultStartTimeout); + using var factory = new SamplingTransactionProfilerFactory(_testSentryOptions, TimeSpan.FromSeconds(startTimeoutSeconds)); + // in the async startup case, we need to wait before collecting + if (startTimeoutSeconds == 0) + { + factory._sessionTask.Wait(5 * 1000); + } CaptureAndValidate(factory); Thread.Sleep(100); CaptureAndValidate(factory); @@ -170,7 +182,7 @@ async Task VerifyAsync(HttpRequestMessage message) // Disable process exit flush to resolve "There is no currently active test." errors. options.DisableAppDomainProcessExitFlush(); - options.AddIntegration(new ProfilingIntegration(_defaultStartTimeout)); + options.AddIntegration(new ProfilingIntegration(TimeSpan.FromSeconds(5))); try { From f7fbfc07e209716bffea1d08f7fa10fd62e6e872 Mon Sep 17 00:00:00 2001 From: Ivan Dlugos Date: Fri, 15 Dec 2023 15:20:29 +0100 Subject: [PATCH 07/38] speedup tests --- test/Sentry.Profiling.Tests/SamplingTransactionProfilerTests.cs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/test/Sentry.Profiling.Tests/SamplingTransactionProfilerTests.cs b/test/Sentry.Profiling.Tests/SamplingTransactionProfilerTests.cs index d26de39b89..97f597f485 100644 --- a/test/Sentry.Profiling.Tests/SamplingTransactionProfilerTests.cs +++ b/test/Sentry.Profiling.Tests/SamplingTransactionProfilerTests.cs @@ -74,7 +74,7 @@ private SampleProfile CaptureAndValidate(ITransactionProfilerFactory factory) var sut = factory.Start(transactionTracer, CancellationToken.None) as SamplingTransactionProfiler; Assert.NotNull(sut); transactionTracer.TransactionProfiler = sut; - RunForMs(1000); + RunForMs(200); sut.Finish(); var elapsedNanoseconds = (ulong)((clock.CurrentDateTimeOffset - clock.StartDateTimeOffset).TotalMilliseconds * 1_000_000); From 47c826b0cf7d3410ab9dec18fb34ca6d7b496200 Mon Sep 17 00:00:00 2001 From: Ivan Dlugos Date: Fri, 15 Dec 2023 19:57:37 +0100 Subject: [PATCH 08/38] debug assert --- src/Sentry.Profiling/SamplingTransactionProfilerFactory.cs | 1 + 1 file changed, 1 insertion(+) diff --git a/src/Sentry.Profiling/SamplingTransactionProfilerFactory.cs b/src/Sentry.Profiling/SamplingTransactionProfilerFactory.cs index 3da27f7a6c..c60bba8442 100644 --- a/src/Sentry.Profiling/SamplingTransactionProfilerFactory.cs +++ b/src/Sentry.Profiling/SamplingTransactionProfilerFactory.cs @@ -21,6 +21,7 @@ public SamplingTransactionProfilerFactory(SentryOptions options, TimeSpan startu { _options = options; + Debug.Assert(TimeSpan.FromSeconds(0) == TimeSpan.Zero); if (startupTimeout == TimeSpan.Zero) { _sessionTask = Task.Run(async () => From 0d3576b9e63d52d51301a5098f136acc3166432a Mon Sep 17 00:00:00 2001 From: Ivan Dlugos Date: Sat, 16 Dec 2023 20:03:25 +0100 Subject: [PATCH 09/38] improvements --- src/Sentry.Profiling/ProfilingIntegration.cs | 1 + src/Sentry.Profiling/SampleProfilerSession.cs | 22 ++++++++----- .../SamplingTransactionProfilerFactory.cs | 31 ++++++++++++++----- 3 files changed, 39 insertions(+), 15 deletions(-) diff --git a/src/Sentry.Profiling/ProfilingIntegration.cs b/src/Sentry.Profiling/ProfilingIntegration.cs index 087d0f0cf7..546b2d7b63 100644 --- a/src/Sentry.Profiling/ProfilingIntegration.cs +++ b/src/Sentry.Profiling/ProfilingIntegration.cs @@ -23,6 +23,7 @@ public class ProfilingIntegration : ISdkIntegration /// public ProfilingIntegration(TimeSpan startupTimeout = default) { + Debug.Assert(TimeSpan.Zero == default); _startupTimeout = startupTimeout; } diff --git a/src/Sentry.Profiling/SampleProfilerSession.cs b/src/Sentry.Profiling/SampleProfilerSession.cs index cb2266c8c8..fa4071d17d 100644 --- a/src/Sentry.Profiling/SampleProfilerSession.cs +++ b/src/Sentry.Profiling/SampleProfilerSession.cs @@ -53,15 +53,23 @@ private SampleProfilerSession(SentryStopwatch stopwatch, EventPipeSession sessio public static SampleProfilerSession StartNew(IDiagnosticLogger? logger = null) { - var client = new DiagnosticsClient(Process.GetCurrentProcess().Id); - var session = client.StartEventPipeSession(Providers, requestRundown: false, CircularBufferMB); - var stopWatch = SentryStopwatch.StartNew(); - var eventSource = TraceLog.CreateFromEventPipeSession(session, TraceLog.EventPipeRundownConfiguration.Enable(client)); + try + { + var client = new DiagnosticsClient(Process.GetCurrentProcess().Id); + var session = client.StartEventPipeSession(Providers, requestRundown: false, CircularBufferMB); + var stopWatch = SentryStopwatch.StartNew(); + var eventSource = TraceLog.CreateFromEventPipeSession(session, TraceLog.EventPipeRundownConfiguration.Enable(client)); - // Process() blocks until the session is stopped so we need to run it on a separate thread. - Task.Factory.StartNew(eventSource.Process, TaskCreationOptions.LongRunning); + // Process() blocks until the session is stopped so we need to run it on a separate thread. + Task.Factory.StartNew(eventSource.Process, TaskCreationOptions.LongRunning); - return new SampleProfilerSession(stopWatch, session, eventSource, logger); + return new SampleProfilerSession(stopWatch, session, eventSource, logger); + } + catch (Exception ex) + { + logger?.LogWarning("Error during sampler profiler EventPipeSession startup.", ex); + throw; + } } public async Task WaitForFirstEventAsync(CancellationToken cancellationToken = default) diff --git a/src/Sentry.Profiling/SamplingTransactionProfilerFactory.cs b/src/Sentry.Profiling/SamplingTransactionProfilerFactory.cs index c60bba8442..9c19775b41 100644 --- a/src/Sentry.Profiling/SamplingTransactionProfilerFactory.cs +++ b/src/Sentry.Profiling/SamplingTransactionProfilerFactory.cs @@ -33,16 +33,24 @@ public SamplingTransactionProfilerFactory(SentryOptions options, TimeSpan startu } else { - var session = SampleProfilerSession.StartNew(options.DiagnosticLogger); - var firstEventTask = session.WaitForFirstEventAsync(); - if (firstEventTask.Wait(startupTimeout)) + try { - _sessionTask = Task.FromResult(session); + var session = SampleProfilerSession.StartNew(options.DiagnosticLogger); + var firstEventTask = session.WaitForFirstEventAsync(); + if (firstEventTask.Wait(startupTimeout)) + { + _sessionTask = Task.FromResult(session); + } + else + { + options.LogWarning("Profiler session startup took longer then the given timeout {0:c}. Profilling will start once the first event is received.", startupTimeout); + _sessionTask = firstEventTask.ContinueWith(_ => session); + } } - else + catch (Exception ex) { - options.LogWarning("Profiler session startup took longer then the given timeout {0:c}. Profilling will start once the first event is received.", startupTimeout); - _sessionTask = firstEventTask.ContinueWith(_ => session); + // Already logged in SampleProfilerSession.StartNew so let's just make sure the task is set. + _sessionTask = Task.FromException(ex); } } } @@ -53,9 +61,16 @@ public SamplingTransactionProfilerFactory(SentryOptions options, TimeSpan startu // Start a profiler if one wasn't running yet. if (Interlocked.Exchange(ref _inProgress, TRUE) == FALSE) { + if (!_sessionTask.IsCompleted) + { + _options.LogDebug("Cannot start a sampling profiler, the session hasn't started yet."); + _inProgress = FALSE; + return null; + } + if (!_sessionTask.IsCompletedSuccessfully) { - _options.LogDebug("Cannot start a a sampling profiler, the session hasn't started yet."); + _options.LogDebug("Cannot start a sampling profiler, the session startup has not been successful."); _inProgress = FALSE; return null; } From fb5c9fdd2f62a45ca25c11bc18345b2d82be08b3 Mon Sep 17 00:00:00 2001 From: Ivan Dlugos Date: Sun, 17 Dec 2023 13:34:43 +0100 Subject: [PATCH 10/38] improvements --- src/Sentry.Profiling/SampleProfilerSession.cs | 4 ++ .../SamplingTransactionProfilerFactory.cs | 42 ++++++------------- test/Directory.Build.props | 2 + .../SamplingTransactionProfilerTests.cs | 3 +- 4 files changed, 21 insertions(+), 30 deletions(-) diff --git a/src/Sentry.Profiling/SampleProfilerSession.cs b/src/Sentry.Profiling/SampleProfilerSession.cs index fa4071d17d..f934b19e95 100644 --- a/src/Sentry.Profiling/SampleProfilerSession.cs +++ b/src/Sentry.Profiling/SampleProfilerSession.cs @@ -56,7 +56,11 @@ public static SampleProfilerSession StartNew(IDiagnosticLogger? logger = null) try { var client = new DiagnosticsClient(Process.GetCurrentProcess().Id); + + // Note: StartEventPipeSession() can time out after 30 seconds on resource constrained systems. + // See https://github.com/dotnet/diagnostics/blob/991c78895323a953008e15fe34b736c03706afda/src/Microsoft.Diagnostics.NETCore.Client/DiagnosticsIpc/IpcClient.cs#L40C52-L40C52 var session = client.StartEventPipeSession(Providers, requestRundown: false, CircularBufferMB); + var stopWatch = SentryStopwatch.StartNew(); var eventSource = TraceLog.CreateFromEventPipeSession(session, TraceLog.EventPipeRundownConfiguration.Enable(client)); diff --git a/src/Sentry.Profiling/SamplingTransactionProfilerFactory.cs b/src/Sentry.Profiling/SamplingTransactionProfilerFactory.cs index 9c19775b41..e111f14b86 100644 --- a/src/Sentry.Profiling/SamplingTransactionProfilerFactory.cs +++ b/src/Sentry.Profiling/SamplingTransactionProfilerFactory.cs @@ -21,37 +21,21 @@ public SamplingTransactionProfilerFactory(SentryOptions options, TimeSpan startu { _options = options; - Debug.Assert(TimeSpan.FromSeconds(0) == TimeSpan.Zero); - if (startupTimeout == TimeSpan.Zero) + _sessionTask = Task.Run(async () => { - _sessionTask = Task.Run(async () => - { - var session = SampleProfilerSession.StartNew(options.DiagnosticLogger); - await session.WaitForFirstEventAsync().ConfigureAwait(false); - return session; - }); - } - else + // This can block up to 30 seconds. The timeout is out of our hands. + var session = SampleProfilerSession.StartNew(options.DiagnosticLogger); + + // This can block indefinitely. + await session.WaitForFirstEventAsync().ConfigureAwait(false); + + return session; + }); + + Debug.Assert(TimeSpan.FromSeconds(0) == TimeSpan.Zero); + if (startupTimeout != TimeSpan.Zero && !_sessionTask.Wait(startupTimeout)) { - try - { - var session = SampleProfilerSession.StartNew(options.DiagnosticLogger); - var firstEventTask = session.WaitForFirstEventAsync(); - if (firstEventTask.Wait(startupTimeout)) - { - _sessionTask = Task.FromResult(session); - } - else - { - options.LogWarning("Profiler session startup took longer then the given timeout {0:c}. Profilling will start once the first event is received.", startupTimeout); - _sessionTask = firstEventTask.ContinueWith(_ => session); - } - } - catch (Exception ex) - { - // Already logged in SampleProfilerSession.StartNew so let's just make sure the task is set. - _sessionTask = Task.FromException(ex); - } + options.LogWarning("Profiler session startup took longer then the given timeout {0:c}. Profilling will start once the first event is received.", startupTimeout); } } diff --git a/test/Directory.Build.props b/test/Directory.Build.props index 34902f4399..3fb3aacd9f 100644 --- a/test/Directory.Build.props +++ b/test/Directory.Build.props @@ -9,6 +9,8 @@ true $(NoWarn);SYSLIB0005;SYSLIB0012 + + $(NoWarn);IDE1006 - 2.23.0 + 2.23.1 $(MSBuildThisFileDirectory)tools\sentry-cli\$(SentryCLIVersion)\ diff --git a/src/Sentry/Sentry.csproj b/src/Sentry/Sentry.csproj index c8bb8dad48..bdb01f68d2 100644 --- a/src/Sentry/Sentry.csproj +++ b/src/Sentry/Sentry.csproj @@ -110,13 +110,13 @@ <_OSArchitecture>$([System.Runtime.InteropServices.RuntimeInformation]::OSArchitecture) - - - - - - - + + + + + + + From 91467a0cae55eee29a2879af5eb46a0f081f6375 Mon Sep 17 00:00:00 2001 From: Giorgi Dalakishvili Date: Fri, 22 Dec 2023 16:11:28 +0400 Subject: [PATCH 34/38] Remove Giorgi from CODEOWNERS (#2989) --- .github/CODEOWNERS | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/.github/CODEOWNERS b/.github/CODEOWNERS index f398274ed7..0a795d964d 100644 --- a/.github/CODEOWNERS +++ b/.github/CODEOWNERS @@ -1 +1 @@ -* @bitsandfoxes @jamescrosswell @giorgi +* @bitsandfoxes @jamescrosswell From 12971e3e65e4aa549a8abbea18ed26a6ef2bafdf Mon Sep 17 00:00:00 2001 From: Ivan Dlugos <6349682+vaind@users.noreply.github.com> Date: Fri, 22 Dec 2023 14:04:37 +0100 Subject: [PATCH 35/38] chore: align LogWarning with LogError (#2987) --- CHANGELOG.md | 1 + .../DiagnosticLoggerExtensions.cs | 24 +++++++++++++++---- ...piApprovalTests.Run.DotNet6_0.verified.txt | 3 ++- ...piApprovalTests.Run.DotNet7_0.verified.txt | 3 ++- ...piApprovalTests.Run.DotNet8_0.verified.txt | 3 ++- .../ApiApprovalTests.Run.Net4_8.verified.txt | 3 ++- 6 files changed, 29 insertions(+), 8 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index b2f8e06b44..af544a8654 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -12,6 +12,7 @@ - The User.IpAddress is now set to {{auto}} by default, even when sendDefaultPII is disabled ([#2981](https://github.com/getsentry/sentry-dotnet/pull/2981)) - The "Prevent Storing of IP Addresses" option in the "Security & Privacy" project settings on sentry.io can be used to control this instead +- The `DiagnosticLogger` signature for `LogWarning` changed to take the `exception` as the first parameter. That way it does no longer get mixed up with the TArgs. ([#2987](https://github.com/getsentry/sentry-dotnet/pull/2987)) ### Dependencies diff --git a/src/Sentry/Extensibility/DiagnosticLoggerExtensions.cs b/src/Sentry/Extensibility/DiagnosticLoggerExtensions.cs index a0862dc122..ecb2fd4295 100644 --- a/src/Sentry/Extensibility/DiagnosticLoggerExtensions.cs +++ b/src/Sentry/Extensibility/DiagnosticLoggerExtensions.cs @@ -166,8 +166,24 @@ internal static void LogInfo( /// public static void LogWarning( this IDiagnosticLogger logger, - string message, - Exception? exception = null) + string message) + => logger.LogIfEnabled(SentryLevel.Warning, null, message); + + /// + /// Log a warning message. + /// + internal static void LogWarning( + this SentryOptions options, + string message) + => options.DiagnosticLogger?.LogIfEnabled(SentryLevel.Warning, null, message); + + /// + /// Log a warning message. + /// + public static void LogWarning( + this IDiagnosticLogger logger, + Exception exception, + string message) => logger.LogIfEnabled(SentryLevel.Warning, exception, message); /// @@ -175,8 +191,8 @@ public static void LogWarning( /// internal static void LogWarning( this SentryOptions options, - string message, - Exception? exception = null) + Exception exception, + string message) => options.DiagnosticLogger?.LogIfEnabled(SentryLevel.Warning, exception, message); /// diff --git a/test/Sentry.Tests/ApiApprovalTests.Run.DotNet6_0.verified.txt b/test/Sentry.Tests/ApiApprovalTests.Run.DotNet6_0.verified.txt index 08da5368cb..1014e7160b 100644 --- a/test/Sentry.Tests/ApiApprovalTests.Run.DotNet6_0.verified.txt +++ b/test/Sentry.Tests/ApiApprovalTests.Run.DotNet6_0.verified.txt @@ -1174,7 +1174,8 @@ namespace Sentry.Extensibility public static void LogInfo(this Sentry.Extensibility.IDiagnosticLogger logger, string message, TArg arg) { } public static void LogInfo(this Sentry.Extensibility.IDiagnosticLogger logger, string message, TArg arg, TArg2 arg2) { } public static void LogInfo(this Sentry.Extensibility.IDiagnosticLogger logger, string message, TArg arg, TArg2 arg2, TArg3 arg3) { } - public static void LogWarning(this Sentry.Extensibility.IDiagnosticLogger logger, string message, System.Exception? exception = null) { } + public static void LogWarning(this Sentry.Extensibility.IDiagnosticLogger logger, string message) { } + public static void LogWarning(this Sentry.Extensibility.IDiagnosticLogger logger, System.Exception exception, string message) { } public static void LogWarning(this Sentry.Extensibility.IDiagnosticLogger logger, string message, TArg arg) { } public static void LogWarning(this Sentry.Extensibility.IDiagnosticLogger logger, string message, TArg arg, TArg2 arg2) { } } diff --git a/test/Sentry.Tests/ApiApprovalTests.Run.DotNet7_0.verified.txt b/test/Sentry.Tests/ApiApprovalTests.Run.DotNet7_0.verified.txt index 08da5368cb..1014e7160b 100644 --- a/test/Sentry.Tests/ApiApprovalTests.Run.DotNet7_0.verified.txt +++ b/test/Sentry.Tests/ApiApprovalTests.Run.DotNet7_0.verified.txt @@ -1174,7 +1174,8 @@ namespace Sentry.Extensibility public static void LogInfo(this Sentry.Extensibility.IDiagnosticLogger logger, string message, TArg arg) { } public static void LogInfo(this Sentry.Extensibility.IDiagnosticLogger logger, string message, TArg arg, TArg2 arg2) { } public static void LogInfo(this Sentry.Extensibility.IDiagnosticLogger logger, string message, TArg arg, TArg2 arg2, TArg3 arg3) { } - public static void LogWarning(this Sentry.Extensibility.IDiagnosticLogger logger, string message, System.Exception? exception = null) { } + public static void LogWarning(this Sentry.Extensibility.IDiagnosticLogger logger, string message) { } + public static void LogWarning(this Sentry.Extensibility.IDiagnosticLogger logger, System.Exception exception, string message) { } public static void LogWarning(this Sentry.Extensibility.IDiagnosticLogger logger, string message, TArg arg) { } public static void LogWarning(this Sentry.Extensibility.IDiagnosticLogger logger, string message, TArg arg, TArg2 arg2) { } } diff --git a/test/Sentry.Tests/ApiApprovalTests.Run.DotNet8_0.verified.txt b/test/Sentry.Tests/ApiApprovalTests.Run.DotNet8_0.verified.txt index 80b49d47c0..0cf19f3b6c 100644 --- a/test/Sentry.Tests/ApiApprovalTests.Run.DotNet8_0.verified.txt +++ b/test/Sentry.Tests/ApiApprovalTests.Run.DotNet8_0.verified.txt @@ -1175,7 +1175,8 @@ namespace Sentry.Extensibility public static void LogInfo(this Sentry.Extensibility.IDiagnosticLogger logger, string message, TArg arg) { } public static void LogInfo(this Sentry.Extensibility.IDiagnosticLogger logger, string message, TArg arg, TArg2 arg2) { } public static void LogInfo(this Sentry.Extensibility.IDiagnosticLogger logger, string message, TArg arg, TArg2 arg2, TArg3 arg3) { } - public static void LogWarning(this Sentry.Extensibility.IDiagnosticLogger logger, string message, System.Exception? exception = null) { } + public static void LogWarning(this Sentry.Extensibility.IDiagnosticLogger logger, string message) { } + public static void LogWarning(this Sentry.Extensibility.IDiagnosticLogger logger, System.Exception exception, string message) { } public static void LogWarning(this Sentry.Extensibility.IDiagnosticLogger logger, string message, TArg arg) { } public static void LogWarning(this Sentry.Extensibility.IDiagnosticLogger logger, string message, TArg arg, TArg2 arg2) { } } diff --git a/test/Sentry.Tests/ApiApprovalTests.Run.Net4_8.verified.txt b/test/Sentry.Tests/ApiApprovalTests.Run.Net4_8.verified.txt index 275680f205..26718ef234 100644 --- a/test/Sentry.Tests/ApiApprovalTests.Run.Net4_8.verified.txt +++ b/test/Sentry.Tests/ApiApprovalTests.Run.Net4_8.verified.txt @@ -1171,7 +1171,8 @@ namespace Sentry.Extensibility public static void LogInfo(this Sentry.Extensibility.IDiagnosticLogger logger, string message, TArg arg) { } public static void LogInfo(this Sentry.Extensibility.IDiagnosticLogger logger, string message, TArg arg, TArg2 arg2) { } public static void LogInfo(this Sentry.Extensibility.IDiagnosticLogger logger, string message, TArg arg, TArg2 arg2, TArg3 arg3) { } - public static void LogWarning(this Sentry.Extensibility.IDiagnosticLogger logger, string message, System.Exception? exception = null) { } + public static void LogWarning(this Sentry.Extensibility.IDiagnosticLogger logger, string message) { } + public static void LogWarning(this Sentry.Extensibility.IDiagnosticLogger logger, System.Exception exception, string message) { } public static void LogWarning(this Sentry.Extensibility.IDiagnosticLogger logger, string message, TArg arg) { } public static void LogWarning(this Sentry.Extensibility.IDiagnosticLogger logger, string message, TArg arg, TArg2 arg2) { } } From f2c64b103fd89b57da9ed0e27b12bc578f7e3a4a Mon Sep 17 00:00:00 2001 From: Ivan Dlugos Date: Fri, 22 Dec 2023 16:48:35 +0100 Subject: [PATCH 36/38] fixup LogWarning usages --- src/Sentry.Profiling/SampleProfilerSession.cs | 6 +++--- src/Sentry.Profiling/SamplingTransactionProfiler.cs | 2 +- src/Sentry/Platforms/Cocoa/CFunctions.cs | 2 +- src/Sentry/Platforms/Native/CFunctions.cs | 2 +- src/Sentry/Protocol/Envelopes/Envelope.cs | 4 ++-- .../SamplingTransactionProfilerTests.cs | 2 +- 6 files changed, 9 insertions(+), 9 deletions(-) diff --git a/src/Sentry.Profiling/SampleProfilerSession.cs b/src/Sentry.Profiling/SampleProfilerSession.cs index 35bfc43573..d5b4447625 100644 --- a/src/Sentry.Profiling/SampleProfilerSession.cs +++ b/src/Sentry.Profiling/SampleProfilerSession.cs @@ -78,7 +78,7 @@ public static SampleProfilerSession StartNew(IDiagnosticLogger? logger = null) { if (_.Exception?.InnerException is { } e) { - logger?.LogWarning("Error during sampler profiler EventPipeSession processing.", e); + logger?.LogWarning(e, "Error during sampler profiler EventPipeSession processing."); } }, TaskContinuationOptions.OnlyOnFaulted); @@ -86,7 +86,7 @@ public static SampleProfilerSession StartNew(IDiagnosticLogger? logger = null) } catch (Exception ex) { - logger?.LogWarning("Error during sampler profiler EventPipeSession startup.", ex); + logger?.LogWarning(ex, "Error during sampler profiler EventPipeSession startup."); throw; } } @@ -120,7 +120,7 @@ public void Stop() } catch (Exception ex) { - _logger?.LogWarning("Error during sampler profiler session shutdown.", ex); + _logger?.LogWarning(ex, "Error during sampler profiler session shutdown."); } } } diff --git a/src/Sentry.Profiling/SamplingTransactionProfiler.cs b/src/Sentry.Profiling/SamplingTransactionProfiler.cs index dcae32ad37..628f44b691 100644 --- a/src/Sentry.Profiling/SamplingTransactionProfiler.cs +++ b/src/Sentry.Profiling/SamplingTransactionProfiler.cs @@ -75,7 +75,7 @@ private void OnThreadSample(TraceEvent data) } catch (Exception e) { - _options.LogWarning("Failed to process a profile sample.", e); + _options.LogWarning(e, "Failed to process a profile sample."); } } else diff --git a/src/Sentry/Platforms/Cocoa/CFunctions.cs b/src/Sentry/Platforms/Cocoa/CFunctions.cs index 9713761b46..71bc1946ae 100644 --- a/src/Sentry/Platforms/Cocoa/CFunctions.cs +++ b/src/Sentry/Platforms/Cocoa/CFunctions.cs @@ -31,7 +31,7 @@ internal static Dictionary LoadDebugImages(IDiagnosticLogger? } catch (Exception e) { - logger?.LogWarning("Error loading the list of debug images", e); + logger?.LogWarning(e, "Error loading the list of debug images"); } return result; } diff --git a/src/Sentry/Platforms/Native/CFunctions.cs b/src/Sentry/Platforms/Native/CFunctions.cs index 1cb02ed437..25e744f943 100644 --- a/src/Sentry/Platforms/Native/CFunctions.cs +++ b/src/Sentry/Platforms/Native/CFunctions.cs @@ -296,7 +296,7 @@ private static Dictionary LoadDebugImagesOnce(IDiagnosticLogge } catch (Exception e) { - logger?.LogWarning("Error loading the list of debug images", e); + logger?.LogWarning(e, "Error loading the list of debug images"); } return result; } diff --git a/src/Sentry/Protocol/Envelopes/Envelope.cs b/src/Sentry/Protocol/Envelopes/Envelope.cs index ac1ef7a09e..1b21c5c57f 100644 --- a/src/Sentry/Protocol/Envelopes/Envelope.cs +++ b/src/Sentry/Protocol/Envelopes/Envelope.cs @@ -153,7 +153,7 @@ internal async Task SerializeAsync( } catch (Exception e) { - logger?.LogWarning("Failed to serialize envelope item", e); + logger?.LogWarning(e, "Failed to serialize envelope item"); } } } @@ -178,7 +178,7 @@ internal void Serialize(Stream stream, IDiagnosticLogger? logger, ISystemClock c } catch (Exception e) { - logger?.LogWarning("Failed to serialize envelope item", e); + logger?.LogWarning(e, "Failed to serialize envelope item"); } } } diff --git a/test/Sentry.Profiling.Tests/SamplingTransactionProfilerTests.cs b/test/Sentry.Profiling.Tests/SamplingTransactionProfilerTests.cs index bdc074268c..5bead6bb9d 100644 --- a/test/Sentry.Profiling.Tests/SamplingTransactionProfilerTests.cs +++ b/test/Sentry.Profiling.Tests/SamplingTransactionProfilerTests.cs @@ -27,7 +27,7 @@ private void SkipIfFailsInCI(Action checks) } catch (Exception e) { - _testOutputLogger.LogWarning("Caught an exception in a test block that is allowed to fail when in CI.", e); + _testOutputLogger.LogWarning(e, "Caught an exception in a test block that is allowed to fail when in CI."); Skip.If(true, "Caught an exception in a test block that is allowed to fail when in CI."); } } From be2c18c9e3c44d653584a4ac5cbe66dfec78ab09 Mon Sep 17 00:00:00 2001 From: Ivan Dlugos Date: Fri, 22 Dec 2023 16:57:07 +0100 Subject: [PATCH 37/38] use Environment.ProcessId --- src/Sentry.Profiling/SampleProfilerSession.cs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/Sentry.Profiling/SampleProfilerSession.cs b/src/Sentry.Profiling/SampleProfilerSession.cs index d5b4447625..2b4a9e5995 100644 --- a/src/Sentry.Profiling/SampleProfilerSession.cs +++ b/src/Sentry.Profiling/SampleProfilerSession.cs @@ -57,7 +57,7 @@ public static SampleProfilerSession StartNew(IDiagnosticLogger? logger = null) { try { - var client = new DiagnosticsClient(Process.GetCurrentProcess().Id); + var client = new DiagnosticsClient(Environment.ProcessId); if (ThrowOnNextStartupForTests) { From ba9a511a7a2f378c81595fc39578f1005f3da17b Mon Sep 17 00:00:00 2001 From: Ivan Dlugos Date: Fri, 22 Dec 2023 17:53:39 +0100 Subject: [PATCH 38/38] ci test fixups --- .../SamplingTransactionProfilerTests.cs | 15 ++++++++++++--- 1 file changed, 12 insertions(+), 3 deletions(-) diff --git a/test/Sentry.Profiling.Tests/SamplingTransactionProfilerTests.cs b/test/Sentry.Profiling.Tests/SamplingTransactionProfilerTests.cs index 5bead6bb9d..7b0357ce08 100644 --- a/test/Sentry.Profiling.Tests/SamplingTransactionProfilerTests.cs +++ b/test/Sentry.Profiling.Tests/SamplingTransactionProfilerTests.cs @@ -17,6 +17,7 @@ public class SamplingTransactionProfilerTests // Note: these tests are flaky in CI. Mostly it's because the profiler sometimes takes very long time to start // or it won't start at all in a given timeout. To avoid failing the CI under these expected circumstances, we // skip the test if it fails on a particular check. + // Don't use xUnit asserts in the given callback, only standard exceptions. private void SkipIfFailsInCI(Action checks) { if (TestEnvironment.IsGitHubActions) @@ -98,7 +99,7 @@ private SampleProfile CaptureAndValidate(ITransactionProfilerFactory factory) var hub = Substitute.For(); var transactionTracer = new TransactionTracer(hub, "test", ""); var sut = factory.Start(transactionTracer, CancellationToken.None) as SamplingTransactionProfiler; - SkipIfFailsInCI(() => Assert.NotNull(sut)); + SkipIfFailsInCI(() => ArgumentNullException.ThrowIfNull(sut)); transactionTracer.TransactionProfiler = sut; RunForMs(RuntimeMs); sut!.Finish(); @@ -244,7 +245,13 @@ async Task VerifyAsync(HttpRequestMessage message) Assert.True(tcs.Task.IsCompleted); var envelopeLines = tcs.Task.Result.Split('\n'); - SkipIfFailsInCI(() => envelopeLines.Length.Should().Be(6)); + SkipIfFailsInCI(() => + { + if (envelopeLines.Length != 6) + { + throw new ArgumentOutOfRangeException("envelopeLines", "Invalid number of envelope lines."); + } + }); // header rows before payloads envelopeLines[1].Should().StartWith("{\"type\":\"transaction\""); @@ -309,8 +316,10 @@ async Task VerifyAsync(HttpRequestMessage message) try { + SampleProfilerSession.ThrowOnNextStartupForTests.Should().BeTrue(); using var hub = (SentrySdk.InitHub(options) as Hub)!; - Assert.Null(options.TransactionProfilerFactory); + SampleProfilerSession.ThrowOnNextStartupForTests.Should().BeFalse(); + options.TransactionProfilerFactory.Should().BeNull(); var clock = SentryStopwatch.StartNew(); var tx = hub.StartTransaction("name", "op");