Creating sub-contexts/operations from previously created context through startOperation or nested wrapWithCorrelationContext

[f0o]

Hi,

I'm facing a bit of a dead-end trying to figure out how I can create sub-operations that refer to the parent operation derived from the main az-function context.

The code I got works about like this:

• Receive trigger
• Wrap Handler in Context (as in readme)
• FanOut (literally just a for-loop) and call N functions
  • Each of these childs calls their own dependencies (DBs, other APIs, ....)

Right now all of those calls are displayed Flat in the timeline, making it almost impossible to correlate DB-Call-A to FuncA in the bunch without spamming traces to effectively double-report things.

Ideally I'd like the FanOut to wrap all the functions into their own Operations & Contexts again and having it displayed hierarchical in the Timeline with each fanned out function being their own respective root of their dependencies but being linked to the initial trigger.

I've tried:

const correlationContext = appInsights.startOperation(context, req); // Main Context, Correct
appInsights.startOperation(correlationContext); // Null
appInsights.startOperation(correlationContext.operation); // Null
appInsights.startOperation(correlationContext.operation.traceparent); // Identical to correlationContext - Thus not usable
appInsights.startOperation({headers:{traceparent:correlationContext.operation.traceparent.traceId}}); // Creates new totally unrelated context
appInsights.startOperation({traceContext:correlationContext.operation}, "JustATest"); // Explodes

//EDIT

I tried this naively and it also didnt yield the expecte result despite the correlation object (ctx) looking correct:

async function handler (context, correlationContext) {
    let LotsOfStuff = await Stuff.find({}); // mongodb call
    for (let item of LotsOfStuff) {
        let ctx = appInsights.startOperation(correlationContext.operation.traceparent)
        ctx.operation.traceparent.updateSpanId()
        appInsights.wrapWithCorrelationContext(async () => {
            const startTime = Date.now();
            await DoStuff(item)
            appInsights.defaultClient.trackDependency({
                name: item,
                success: true,
                duration: Date.now() - startTime,
            });
            appInsights.defaultClient.flush();
        }, ctx)();
    }
};

// Default export wrapped with Application Insights FaaS context propagation
module.exports = async function contextPropagatingCronTrigger(context, cron) {
    const correlationContext = appInsights.startOperation(context, context.executionContext.functionName);
    return appInsights.wrapWithCorrelationContext(async () => {
        await handler(context, correlationContext);
        appInsights.defaultClient.flush();
    }, correlationContext)();
};

I dumped ctx and It looks correct with updates SpanIds, which I hoped would make it cascade in the timeline overview, but it didnt.

It's still flat and overlapping as they're being worked through asynchronously it's impossible to correlate which instance of DoStuff is doing what and who's dependencies are doing what apart from logging breadcrumbs everywhere

[antpuleo2586]

I think I have a similar issue.

We have a mobile app which talks to a GraphQL layer which in turn calls our backend APIs.

We want to correlate the operation ID from the mobile app through GraphQL and to backend.

However, this doesn't work and calling startOperation always creates a new operation ID.

After a call with Microsoft support, we debugged the startOperation function and made the following amends for it to work:

CorrelationContextManager.startOperation = function (context, request) {
        var traceContext = context && context.traceContext || null;
        var spanContext = context && context.traceId
            ? context
            : null;
        // var headers = context && context.headers;
        var headers = request && request.headers;
        if (spanContext) {
            var traceparent = new Traceparent("00-" + spanContext.traceId + "-" + spanContext.spanId + "-01");
            var tracestate = new Tracestate(spanContext.tracestate);
            var correlationContext = CorrelationContextManager.generateContextObject(spanContext.traceId, "|" + spanContext.traceId + "." + spanContext.spanId + ".", typeof request === "string" ? request : "", undefined, traceparent, tracestate);
            return correlationContext;
        }
        // AzFunction TraceContext available
        // NOTE: passes here when it shouldn't, because traceContext is an object, but with empty properties
        // if (traceContext) {
        //     var traceparent = new Traceparent(traceContext.traceparent);
        //     var tracestate = new Tracestate(traceContext.tracestate);
        //     var parser = typeof request === "object"
        //         ? new HttpRequestParser(request)
        //         : null;
        //     var correlationContext = CorrelationContextManager.generateContextObject(traceparent.traceId, traceparent.parentId, typeof request === "string"
        //         ? request
        //         : parser.getOperationName({}), parser && parser.getCorrelationContextHeader() || undefined, traceparent, tracestate);
        //     return correlationContext;
        // }
        // No TraceContext available, parse as http.IncomingMessage
        if (headers) {
            var traceparent = new Traceparent(headers.traceparent);
            var tracestate = new Tracestate(headers.tracestate);
            // var parser = new HttpRequestParser(context);
            var parser = new HttpRequestParser(request);
            var correlationContext = CorrelationContextManager.generateContextObject(traceparent.traceId, traceparent.parentId, parser.getOperationName({}), parser.getCorrelationContextHeader(), traceparent, tracestate);
            return correlationContext;
        }
        Logging.warn("startOperation was called with invalid arguments", arguments);
        return null;
    };

As you can see, if (traceContext) { passes because traceContext is an object, but its values are all empty strings.

When the code gets to the check for headers, the headers are incorrectly being retrieved from context, when they should be retrieved from the request.

I am just monkey patching this at the moment but some insight into why I need to do this and if it's correct would be nice.

It gives me the correct operation ID through all requests though, which is what we desire.

Thanks

[f0o]

@antpuleo2586 sounds very similar to my PR https://github.com/microsoft/ApplicationInsights-node.js/pull/817

[antpuleo2586]

@f0o It looks similar for sure, but as per the comments from @hectorhdzg , whether a stricter check is required on if (traceContext) and then if this fails, allowing to pass into the next check on headers (but with headers appropriately retrieved from the request) this may be the solution with less of an impact on existing behaviour (although I'm now confused as to what exactly the existing or intended behaviour is).

[JacksonWeber]

@f0o @antpuleo2586 Please try this with the new version of Application Insights (3.X SDK). Context correlation now works via OpenTelemetry, so it may be fixed in the new version. Please see related OpenTelemetry documentation on context propagation https://opentelemetry.io/docs/languages/js/propagation/.