Flaky: Profiler_ThrowingOnSessionStartup_DoesntBreakSentryInit

[bruno-garcia]

https://github.com/getsentry/sentry-dotnet/actions/runs/7806480103/attempts/1

Error: Expected options.TransactionProfilerFactory to be <null>, but found Sentry.Profiling.SamplingTransactionProfilerFactory{ }.

  Failed Sentry.Profiling.Tests.SamplingTransactionProfilerTests.Profiler_ThrowingOnSessionStartup_DoesntBreakSentryInit [1 s]
  Error Message:
   Expected options.TransactionProfilerFactory to be <null>, but found Sentry.Profiling.SamplingTransactionProfilerFactory{ }.
  Stack Trace:
     at FluentAssertions.Execution.XUnit2TestFramework.Throw(String message)
   at FluentAssertions.Execution.TestFrameworkProvider.Throw(String message)
   at FluentAssertions.Execution.DefaultAssertionStrategy.HandleFailure(String message)
   at FluentAssertions.Execution.AssertionScope.FailWith(Func`1 failReasonFunc)
   at FluentAssertions.Execution.AssertionScope.FailWith(Func`1 failReasonFunc)
   at FluentAssertions.Execution.AssertionScope.FailWith(String message, Object[] args)
   at FluentAssertions.Primitives.ReferenceTypeAssertions`2.BeNull(String because, Object[] becauseArgs)
   at Sentry.Profiling.Tests.SamplingTransactionProfilerTests.Profiler_ThrowingOnSessionStartup_DoesntBreakSentryInit() in /Users/runner/work/sentry-dotnet/sentry-dotnet/test/Sentry.Profiling.Tests/SamplingTransactionProfilerTests.cs:line 322
   at Sentry.Profiling.Tests.SamplingTransactionProfilerTests.Profiler_ThrowingOnSessionStartup_DoesntBreakSentryInit() in /Users/runner/work/sentry-dotnet/sentry-dotnet/test/Sentry.Profiling.Tests/SamplingTransactionProfilerTests.cs:line 341
--- End of stack trace from previous location ---
  Standard Output Messages:
 [Warning 00:00:00.00]: Sentry option 'Debug' is set to true while Environment is production. Be aware this can cause performance degradation and is not advised. See https://docs.sentry.io/platforms/dotnet/configuration/diagnostic-logger for more information
 [Debug 00:00:00.00]: Initializing Hub for Dsn: 'https://[email protected]:65535/2147483647'.
 [Warning 00:00:00.00]: Sentry option 'Debug' is set to true while Environment is production. Be aware this can cause performance degradation and is not advised. See https://docs.sentry.io/platforms/dotnet/configuration/diagnostic-logger for more information
 [Debug 00:00:00.00]: This looks like a standard JIT/AOT application build.
 [Debug 00:00:00.00]: Starting BackgroundWorker.
 [Debug 00:00:00.00]: New scope pushed.
 [Debug 00:00:00.00]: Registering integration: 'AutoSessionTrackingIntegration'.
 [Debug 00:00:00.00]: Registering integration: 'AppDomainUnhandledExceptionIntegration'.
 [Debug 00:00:00.00]: Registering integration: 'AppDomainProcessExitIntegration'.
 [Debug 00:00:00.00]: Registering integration: 'UnobservedTaskExceptionIntegration'.
 [Debug 00:00:00.00]: Registering integration: 'SentryDiagnosticListenerIntegration'.
 [Debug 00:00:00.00]: Registering integration: 'SystemDiagnosticsMetricsIntegration'.
 [Info 00:00:00.00]: System.Diagnostics.Metrics Integration is disabled because no listeners are configured.
 [Debug 00:00:00.00]: Registering integration: 'ProfilingIntegration'.
 [Debug 00:00:00.00]: BackgroundWorker Started.
 [Info 00:00:01.24]: Disposing the Hub.
 [Debug 00:00:01.24]: Successfully flushed all events up to call to FlushAsync.

[jamescrosswell]

Related:

• https://github.com/getsentry/sentry-dotnet/issues/3009
• https://github.com/getsentry/sentry-dotnet/issues/3002

[jamescrosswell]

Still getting this all over the place (e.g. here). I get this pretty frequenly on my local machine as well (so not just a CI thing).

I think we should disable this test until we can work out what's going on and fix it.

[vaind]

I've looked into this multiple times and logically, the test seems sound to me - I have no clue how that condition could be failing. Can someone else have a look at the code? I'm likely missing some c#-related detail that comes into play here.

[jamescrosswell]

I've looked into this multiple times and logically, the test seems sound to me - I have no clue how that condition could be failing. Can someone else have a look at the code? I'm likely missing some c#-related detail that comes into play here.

Hm, as you say, logically it all looks OK.

The only theoretical situation in which I could imagine the test doing what it's doing is if this line doesn't throw an exception: https://github.com/getsentry/sentry-dotnet/blob/b734248af2f9dfb6cc7ff843a2256923ef6fd9d4/src/Sentry.Profiling/SamplingTransactionProfilerFactory.cs#L39

In that scenario, the constructor might return an instance before any exception from the Task.Wait was thrown... I guess that could happen if the work being done by _sessionTask didn't get scheduled within the timeout (in this case 10 seconds, so that seems highly improbably). And even if that was happening, we'd expect to see the log message from:

https://github.com/getsentry/sentry-dotnet/blob/b734248af2f9dfb6cc7ff843a2256923ef6fd9d4/src/Sentry.Profiling/SamplingTransactionProfilerFactory.cs#L41

[jamescrosswell]

I get this pretty frequenly on my local machine as well (so not just a CI thing).

One caveat in the comment on the PR... we're not expecting that PR to resolve this outside of CI. If this is resolved in CI but continues to be a problem on local machines, that at least confirms the source of the problem and we can circle back to remove the TestEnvironment check (factory.StartupTimedOut.Should().BeTrue() should be enough): https://github.com/getsentry/sentry-dotnet/blob/cbe8da9eb1393e4a2630441f10015493b66481c6/test/Sentry.Profiling.Tests/SamplingTransactionProfilerTests.cs#L326

[jamescrosswell]

We haven't had any trouble for a while, but did run into this today:

Nothing to do yet, I don't think... once could just be some twighlight zone anomaly but if it starts happening regularly again, we may need to reopen the case.