Instrumentation inside an IEnumerable

[ndrwrbgs]

trafficstars

Problem statement: using syntax inside a yield return IEnumerable results in confusing and inconsistent traces

Action: Clarify the usage via documentation or utility methods that make such authoring more convenient

Expectation: When tracing inside an IEnumerable's production code and the consumer/processor code... My Trace should look like DoStuff DoStuff > EnumerateItemFirstPart DoStuff > ProcessItem DoStuff > EnumerateItemSecondPart DoStuff > ProcessItem

Reality: My Trace would look like DoStuff DoStuff > EnumerateItemFirstPart DoStuff > EnumerateItemFirstPart > ProcessItem DoStuff > EnumerateItemSecondPart DoStuff > EnumerateItemSecondPart > ProcessItem

Demonstrate the problem:

class DemonstrateTheProblem
{
    public static IEnumerable<int> ShowIt()
    {
        using (StartFirstPartTrace())
        {
            for (int i = 0; i < 10; i++)
            {
                // StartFirstPartTrace will be leaked out of right here - e.g. the code consuming the IEnumerable will say that it is inside StartFirstPartTrace()
                yield return i;
            }
        }

        // Including a SecondPart to negate the obvious solution of wrapping the IEnumerator
        using (StartSecondPartTrace())
        {
            for (int i = 0; i < 10; i++)
            {
                // StartSecondPartTrace will be leaked out of right here - e.g. the code consuming (a foreach for instance) will now 
                yield return i;
            }
        }
    }
}

[ndrwrbgs]

Perhaps something like a YieldReturn for IScope could accomplish it - e.g.

using (var scope = FirstPart())
{
    for (int i = 0; i < 10; i++)
    {
        // FirstPart will be leaked out of right here
        using (scope.YieldReturn())
        {
            yield return i;
        }
    }
}

where YieldReturn moves scope.Span off of the IScopeManager.Active until it is disposed, at which time it returns scope.Span to being the active span.

Note that as a pure extension method this would not be possible due to https://github.com/opentracing/opentracing-csharp/issues/95 related issues - it is impossible today for us to (implementation-agnostic) remove an ISpan from being active without the chance that the current IScope will actually ISpan.Finish said span.

Problems with proposal: A single span would potentially then have multiple parents (which most of the tracing systems today do not handle first-class, at least in their visualization).

Possible alternative: A purely extension method that creates a NEW span on each resumption of the enumerable. The implementation of this would almost be an anti-Scope, where at the using's start we CLOSE the current span, and at the Dispose we open a new one. E.g.

// This line captures the BuildSpan information to be able to rebuild spans for each enumeration, and immediately starts one (span1)
using (IYieldReadyScope yieldReadyScope = GlobalTracer.Instance.BuildSpan("foo").StartYieldReadyScope())
{
  for (int i = 0; i < 10; i ++)
  {
    // This line closes the previous span (e.g. span1)
    using (yieldReadyScope.Yielding())
    {
      yield return i;
    } // This line opens a new span based on the BuildSpan information previously captured, e.g. span2
  }
} // This line closes the last span created by the yieldReadyScope

Due to how prone this is (in any solution) to misuse, we may want to make a tracing VS Analyzer to detect such cases.

[cwe1ss]

Interesting scenario. It sounds "like a feature" to me though as that's how C# works in that case - when you yield return you stay in that context.

While the tracing tree might be unexpected at first sight, I wouldn't say it's inconsistent as everything should get closed properly, doesn't it?

You could obviously just avoid using "yield" but I guess there's a reason for why you use it. Does it give you better performance? I've never benchmarked that.