[AutoFlushActivityProcessorTests] fix flaky flush test

[TimothyMothra]

This test occasionally fails, impacting other PRs.

  Failed OpenTelemetry.Extensions.Tests.Trace.AutoFlushActivityProcessorTests.AutoFlushActivityProcessor_FlushAfterLocalServerSideRootSpans_EndMatchingSpan_Flush [149 ms]
  Error Message:
   Moq.MockException : 
Expected invocation on the mock once, but was 2 times: mock => mock.OnForceFlush(5000)

Performed invocations:

   Mock<BaseProcessor<Activity>:1> (mock):

      BaseProcessor<Activity>.SetParentProvider(TracerProviderSdk)
      BaseProcessor<Activity>.SetParentProvider(TracerProviderSdk)
      BaseProcessor<Activity>.OnStart(Activity)
      BaseProcessor<Activity>.OnEnd(Activity)
      BaseProcessor<Activity>.OnForceFlush(5000)
      BaseProcessor<Activity>.OnEnd(Activity)
      BaseProcessor<Activity>.OnForceFlush(5000)

  Stack Trace:
     at Moq.Mock.Verify(Mock mock, LambdaExpression expression, Times times, String failMessage) in C:\projects\moq4\src\Moq\Mock.cs:line 330
   at Moq.Protected.ProtectedMock`1.InternalVerify(String methodName, Type[] genericTypeArguments, Times times, Boolean exactParameterMatch, Object[] args) in C:\projects\moq4\src\Moq\Protected\ProtectedMock.cs:line 234
   at Moq.Protected.ProtectedMock`1.Verify(String methodName, Times times, Object[] args) in C:\projects\moq4\src\Moq\Protected\ProtectedMock.cs:line 206
   at OpenTelemetry.Extensions.Tests.Trace.AutoFlushActivityProcessorTests.AutoFlushActivityProcessor_FlushAfterLocalServerSideRootSpans_EndMatchingSpan_Flush() in D:\a\opentelemetry-dotnet-contrib\opentelemetry-dotnet-contrib\test\OpenTelemetry.Extensions.Tests\Trace\AutoFlushActivityProcessorTests.cs:line 45
   at System.RuntimeMethodHandle.InvokeMethod(Object target, Void** arguments, Signature sig, Boolean isConstructor)
   at System.Reflection.MethodInvoker.Invoke(Object obj, IntPtr* args, BindingFlags invokeAttr)

Changes

• change Times.Once() to Times.AtLeastOnce()

Please provide a brief description of the changes here.

For significant contributions please make sure you have completed the following items:

• Appropriate CHANGELOG.md updated for non-trivial changes
• Design discussion issue #

[codecov]

Codecov Report

Merging #897 (2f75988) into main (6cafab9) will not change coverage.
The diff coverage is n/a.

Additional details and impacted files

@@           Coverage Diff           @@
##             main     #897   +/-   ##
=======================================
  Coverage   68.88%   68.88%           
=======================================
  Files         188      188           
  Lines        7081     7081           
=======================================
  Hits         4878     4878           
  Misses       2203     2203           

Impacted Files	Coverage Δ
...etry.Exporter.Instana/Implementation/SpanSender.cs	61.53% <0.00%> (-7.70%)	⬇️
...try.Extensions/Trace/AutoFlushActivityProcessor.cs	85.18% <0.00%> (+3.70%)	⬆️

[CodeBlanch]

This test again! Such a pain 🤣 I spent a bunch of time on it a while back. Updating moq seemed to help. Is it failing only on some older runtimes now?

[TimothyMothra]

This test failed for me on net7 today. I recognized this test, I've seen it fail before, but I haven't kept a record of what platforms.

My intent with this PR is to make the test more resilient.
Actually, I have on ongoing conflict with Activity-based unit tests and I've been working to make them more resilient when I see them fail.

[CodeBlanch]

The branch where it failed up-to-date with the version bump from my PR? I think this change is fine but it does change the test where it might not catch an actual regression, no? Any desire on your part to rewrite it so that it doesn't use moq? 😄

[TimothyMothra]

I think we're going to continue to have problems unit testing Activities because the ActivityStopped can get triggered twice.
See: dotnet/runtime#76757 and Azure/azure-sdk-for-net#31567

Regarding a rewrite...
I see that it's asserting the mock and not actually asserting the AutoFlush Processor.
I could change this to verify that OnForceFlush is called while exporting this specific Activity (by asserting the Activity.Name).
But this won't avoid that the Activity can be exported twice.

[CodeBlanch]

I think for the sake of this test we only care to track invocations to OnForceFlush so it should be fine! Try this:

using System;
using System.Diagnostics;
using System.Runtime.CompilerServices;
using System.Threading;
using OpenTelemetry.Trace;
using Xunit;

namespace OpenTelemetry.Extensions.Tests.Trace;

public class AutoFlushActivityProcessorTests
{
    [Fact]
    public void AutoFlushActivityProcessor_FlushAfterLocalServerSideRootSpans_EndMatchingSpan_Flush()
    {
        var processor = new ForceFlushTrackingProcessor();

        var sourceName = GetTestMethodName();

        using var provider = Sdk.CreateTracerProviderBuilder()
            .AddProcessor(processor)
            .AddAutoFlushActivityProcessor(a => a.Parent == null && (a.Kind == ActivityKind.Server || a.Kind == ActivityKind.Consumer), 5000)
            .AddSource(sourceName)
            .Build();

        using var source = new ActivitySource(sourceName);
        using var activity = source.StartActivity("name", ActivityKind.Server);
        activity.Stop();

        Assert.Equal(1, processor.ForceFlushInvocations);
    }

    [Fact]
    public void AutoFlushActivityProcessor_FlushAfterLocalServerSideRootSpans_EndNonMatchingSpan_DoesNothing()
    {
        var processor = new ForceFlushTrackingProcessor();

        var sourceName = GetTestMethodName();

        using var provider = Sdk.CreateTracerProviderBuilder()
            .AddProcessor(processor)
            .AddAutoFlushActivityProcessor(a => a.Parent == null && (a.Kind == ActivityKind.Server || a.Kind == ActivityKind.Consumer))
            .AddSource(sourceName)
            .Build();

        using var source = new ActivitySource(sourceName);
        using var activity = source.StartActivity("name", ActivityKind.Client);
        activity.Stop();

        Assert.Equal(0, processor.ForceFlushInvocations);
    }

    [Fact]
    public void AutoFlushActivityProcessor_PredicateThrows_DoesNothing()
    {
        var processor = new ForceFlushTrackingProcessor();

        var sourceName = GetTestMethodName();

        using var provider = Sdk.CreateTracerProviderBuilder()
            .AddProcessor(processor)
            .AddAutoFlushActivityProcessor(_ => throw new Exception("Predicate throws an exception."))
            .AddSource(sourceName)
            .Build();

        using var source = new ActivitySource(sourceName);
        using var activity = source.StartActivity("name", ActivityKind.Server);
        activity.Stop();

        Assert.Equal(0, processor.ForceFlushInvocations);
    }

    private static string GetTestMethodName([CallerMemberName] string callingMethodName = "")
    {
        return callingMethodName;
    }

    private sealed class ForceFlushTrackingProcessor : BaseProcessor<Activity>
    {
        private int forceFlushInvocations;

        public int ForceFlushInvocations => this.forceFlushInvocations;

        protected override bool OnForceFlush(int timeoutMilliseconds)
        {
            Interlocked.Increment(ref this.forceFlushInvocations);

            return true;
        }
    }
}

[github-actions]

This PR was marked stale due to lack of activity. It will be closed in 7 days.

[github-actions]

Closed as inactive. Feel free to reopen if this PR is still being worked on.