Proper way of tracing distributed requests through Azure Function Apps

Question

I am experimenting with Node.js and the application insights SDK in two separate function apps. Nodejs is just what I am comfortable with to quickly poc, this might not be the final language so I don't want to know any language specific solutions, simply how application insights behaves in the context of function apps and what it expects to be able to draw a proper application map.

My goal is to be able to write simple queries in log analytics to get the full chain of a single request through multiple function apps, no matter how these are connected. I also want an accurate (as possible) view of the system in the application map in application insights.

My assumption is that a properly set operation_id and operation_parentId would yield both a queryable trace using kusto and a proper application map.

I've set up the following flow:

Function1 only exposes a HTTP trigger, whereas Function2 exposes both a HTTP and Service Bus trigger.

The full flow looks like this:

I call Function1 using GET http://function1.com?input=test
Function1 calls Function2 using REST at GET http://function2.com?input=test
Function1 uses the response from Function2 to add a message to a service bus queue
Function2 has a trigger on that same queue

I am mixing patterns here just to see what the application map does and understand how to use this correctly.

For step 1 through 3, I can see the entire chain in my logs on a single operation_Id. In this screenshot the same operationId spans two different function apps:

What I would expect to find in this log is also the trigger of the service bus where the trigger is called ServiceBusTrigger. The service bus does trigger on the message, it just gets a different operationId.

To get the REST correlation to work, I followed the guidelines from applicationinsights npm package in the section called Setting up Auto-Correlation for Azure Functions.

This is what Function1 looks like (the entrypoint and start of the chain)

let appInsights = require('applicationinsights')
appInsights.setup()
    .setAutoCollectConsole(true, true)
    .setDistributedTracingMode(appInsights.DistributedTracingModes.AI_AND_W3C)
    .start()

const https = require('https')

const httpTrigger = async function (context, req) {
    context.log('JavaScript HTTP trigger function processed a request.')

    const response = await callOtherFunction(req)
    context.res = {
        body: response
    }
    context.log("Sending response on service bus")
    context.bindings.outputSbQueue = response;
}

async function callOtherFunction(req) {
    return new Promise((resolve, reject) => {
        https.get(`https://function2.azurewebsites.net/api/HttpTrigger1?code=${process.env.FUNCTION_2_CODE}&input=${req.query.input}`, (resp) => {
            let data = ''

            resp.on('data', (chunk) => {
                data += chunk
            })
    
            resp.on('end', () => {
                resolve(data)
            })
    
        }).on("error", (err) => {
            reject("Error: " + err.message)
        })
    })
}

module.exports = async function contextPropagatingHttpTrigger(context, req) {
    // Start an AI Correlation Context using the provided Function context
    const correlationContext = appInsights.startOperation(context, req);

    // Wrap the Function runtime with correlationContext
    return appInsights.wrapWithCorrelationContext(async () => {
        const startTime = Date.now(); // Start trackRequest timer

        // Run the Function
        const result = await httpTrigger(context, req);

        // Track Request on completion
        appInsights.defaultClient.trackRequest({
            name: context.req.method + " " + context.req.url,
            resultCode: context.res.status,
            success: true,
            url: req.url,
            time: new Date(startTime),
            duration: Date.now() - startTime,
            id: correlationContext.operation.parentId,
        });
        appInsights.defaultClient.flush();

        return result;
    }, correlationContext)();
};

And this is what the HTTP trigger in Function2 looks like:

let appInsights = require('applicationinsights')
appInsights.setup()
    .setAutoCollectConsole(true, true)
    .setDistributedTracingMode(appInsights.DistributedTracingModes.AI_AND_W3C)
    .start()

const httpTrigger = async function (context, req) {
    context.log('JavaScript HTTP trigger function processed a request.')

    context.res = {
        body: `Function 2 received ${req.query.input}`
    }
}

module.exports = async function contextPropagatingHttpTrigger(context, req) {
    // Start an AI Correlation Context using the provided Function context
    const correlationContext = appInsights.startOperation(context, req);

    // Wrap the Function runtime with correlationContext
    return appInsights.wrapWithCorrelationContext(async () => {
        const startTime = Date.now(); // Start trackRequest timer

        // Run the Function
        const result = await httpTrigger(context, req);

        // Track Request on completion
        appInsights.defaultClient.trackRequest({
            name: context.req.method + " " + context.req.url,
            resultCode: context.res.status,
            success: true,
            url: req.url,
            time: new Date(startTime),
            duration: Date.now() - startTime,
            id: correlationContext.operation.parentId,
        });
        appInsights.defaultClient.flush();

        return result;
    }, correlationContext)();
};

The Node.js application insights documentation says:

The Node.js client library can automatically monitor incoming and outgoing HTTP requests, exceptions, and some system metrics.

So this seems to work for HTTP, but what is the proper way to do this over (for instance) a service bus queue to get a nice message trace and correct application map? The above solution for the applicationinsights SDK seems to only be for HTTP requests where you use the req object on the context. How is the operationId persisted in cross-app communication in these instances?

What is the proper way of doing this across other messaging channels? What do I get for free from application insights, and what do I need to stitch myself?

UPDATE
I found this piece of information in the application map documentation which seems to support the working theory that only REST/HTTP calls will be able to get traced. But then the question remains, how does the output binding work if it is not a HTTP call?

The app map finds components by following HTTP dependency calls made between servers with the Application Insights SDK installed.

UPDATE 2
In the end I gave up on this. In conclusion, Application Insights traces some things but it is very unclear when and how that works and also depends on language. For the Node.js docs it says:

The Node.js client library can automatically monitor incoming and outgoing HTTP requests, exceptions, and some system metrics. Beginning in version 0.20, the client library also can monitor some common third-party packages, like MongoDB, MySQL, and Redis. All events related to an incoming HTTP request are correlated for faster troubleshooting.

I solved this by taking inspiration from OpenTracing. Our entire stack runs in Azure Functions, so I've implemented logic to use correlationId that passes through all processes. Each process is a span. Each function/process is responsible for logging according to a structured logging framework.

Proper way of tracing distributed requests through Azure Function Apps

Answers (1)

Related Questions