microsoft / ApplicationInsights-node.js

Microsoft Application Insights SDK for Node.js
MIT License
324 stars 141 forks source link

Distributed tracing not happening- Nodejs Functions #710

Closed madanbhavi closed 3 years ago

madanbhavi commented 3 years ago

We have a microservice architecture where in we get a call from UI to Microservice A. It makes a call to Microservice B to get the data from cosmos DB /3rd party API and return the response. We are trying to correlate the request. In appsight we are noticing that operationId and Operation_parentId are showing different values in each of the microservice logs and also during end to end transaction it says "More details for this call are not available due to sampling". We have not enabled any sampling yet.

Please find attached screenshots from appinsight. and let us know in case we are missing anything n configuration.

NPM package for appinsight used - "applicationinsights": "^1.7.5", https://www.npmjs.com/package/applicationinsights Node js version:- 12.13.0 Call from Mircoservice A to micorservice B is made using axios module

import * as appInsights from "applicationinsights"; appInsights.setup()// assuming ikey is in env var .setAutoDependencyCorrelation(true,true) .setAutoCollectRequests(true) .setAutoCollectPerformance(true) .setAutoCollectExceptions(true) .setAutoCollectDependencies(true) .setDistributedTracingMode(appInsights.DistributedTracingModes.AI_AND_W3C) .start(); const appInsightClient = appInsights.defaultClient;

contexpropogationHtttpTrigger

Microservice A Appinsight-Microservice-A

Microservice B

Appinsight-Microservice-B Appinsight-End-to-End-Transaction

hectorhdzg commented 3 years ago

@madanbhavi are both microservices Azure functions?, is the client sending a dependency event with operationId?

madanbhavi commented 3 years ago

@hectorhdzg - Yes they both are microservice Azure functions. When you say client sending dependency event- Do you mean we need to explicitly call appinsight.trackDependency before making axios call or do we need to set operationId in request header before making axios call ? Can you please share the sample code if you have to help me understand how to set traceparent details. Currently we are just making a call to other microservice using axios, below snippet of code just for reference

const axios = require('axios');

 let response = await axios({
     method: 'get',
     url: 'MicroserviceB- URL',
     headers: {
         'content-type': 'application/json',
         'Authorization': "Bearer "+token
     }
 })
hectorhdzg commented 3 years ago

@madanbhavi I tried using following code using HttpTriggers inside Azure Function App and correlation is working correctly, please give it a try, if the client calling your Azure function is instrumented with Application Insights and dependency telemetry is being sent the correlation will be maintained, if not you will see Azure function code as starting point when looking at End-end-transaction view in Azure portal.

const appInsights = require("applicationinsights"); appInsights.setup() .setAutoCollectPerformance(false) .start();

const axios = require("axios"); const httpTrigger = async function (context, req) { const response = await axios.get("https://XXXXXXXXXXXX.azurewebsites.net/api/HttpTrigger2");

context.res = {
    status: response.status,
    body: response.statusText,
};

};

module.exports = function (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
    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,
        duration: Date.now() - startTime,
        id: correlationContext.operation.parentId,
    });
    appInsights.defaultClient.flush();
}, correlationContext)();

};

madanbhavi commented 3 years ago

@hectorhdzg - Thanks for the input. Both the microservices have exactly same configuration to set application insight in the beginning of the file and default export is contextPropagatingHttpTrigger. Please find below code snippet (note- I have removed all business logic and kept them simple for testing purpose). Another interesting factor what I noticed is, when I am running locally (localhost) using the dev appinsight key. I can see both the microservices are getting same operationid but when the both function APPS are deployed to azure cloud, it doesn't seems to be working. Is there anything we need to set up while deploying it to cloud to enable the functionality ?

You mentioned that if dependency telemetry is sent by client it should work, is there anything we need to code explicitly to send the dependency telemetry ?

Note:- both microservices have different appinsight keys

Microservice 1 import * as appInsights from "applicationinsights"; appInsights.setup()// assuming ikey is in env var .setAutoDependencyCorrelation(true,true) .setAutoCollectRequests(true) .setAutoCollectPerformance(true) .setAutoCollectExceptions(true) .setAutoCollectDependencies(true) .setDistributedTracingMode(appInsights.DistributedTracingModes.AI_AND_W3C) .start(); const appInsightClient = appInsights.defaultClient; import axios, { Method, AxiosResponse } from "axios"; import { AzureFunction, Context, HttpRequest } from "@azure/functions"

const httpTrigger1: AzureFunction = async function (context: Context, req: HttpRequest): Promise { context.log('HTTP trigger function processed a request.'+ JSON.stringify(context.traceContext)); const name = (req.query.name || (req.body && req.body.name)); const responseMessage = name ? "Hello, " + name + ". This HTTP triggered function executed successfully." : "This HTTP triggered function executed successfully. Pass a name in the query string or in the request body for a personalized response."; const config={} await axios["get"]("https://XXXXXXXXXXXX.azurewebsites.net/api/HttpTrigger4", config); context.res = { // status: 200, / Defaults to 200 / body: responseMessage };

};

const httpTrigger: AzureFunction = 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 appInsightClient.trackTrace({message:"lets start the correlation"}); // Run the Function await httpTrigger1(context, req); appInsightClient.trackTrace({message:"lets end the correlation"}); // Track Request on completion appInsightClient.trackRequest({ name: context.req.method + " " + context.req.url, resultCode: context.res.status, success: true, url: req.url, duration: Date.now() - startTime, id: correlationContext.operation.parentId,

    });
    appInsights.defaultClient.flush();
}, correlationContext)();

}; export default httpTrigger;

Microservice 2

import * as appInsights from "applicationinsights"; appInsights.setup()// assuming ikey is in env var .setAutoDependencyCorrelation(true,true) .setAutoCollectRequests(true) .setAutoCollectPerformance(true) .setAutoCollectExceptions(true) .setAutoCollectDependencies(true) .setDistributedTracingMode(appInsights.DistributedTracingModes.AI_AND_W3C) .start(); const appInsightClient = appInsights.defaultClient;

import { AzureFunction, Context, HttpRequest } from "@azure/functions"

const httpTrigger1: AzureFunction = async function (context: Context, req: HttpRequest): Promise { context.log('HTTP trigger 4 function processed a request.'+ JSON.stringify(context.traceContext)); const name = (req.query.name || (req.body && req.body.name)); const responseMessage = name ? "Hello, " + name + ". This HTTP triggered function executed successfully." : "This HTTP triggered function executed successfully. Pass a name in the query string or in the request body for a personalized response.";

context.res = {
    // status: 200, /* Defaults to 200 */
    body: responseMessage
};

};

const httpTrigger: AzureFunction = 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 appInsightClient.trackTrace({message:"lets start the correlation"}); // Run the Function await httpTrigger1(context, req); appInsightClient.trackTrace({message:"lets end the correlation"}); // Track Request on completion appInsightClient.trackRequest({ name: context.req.method + " " + context.req.url, resultCode: context.res.status, success: true, url: req.url, duration: Date.now() - startTime, id: correlationContext.operation.parentId,

    });
    appInsights.defaultClient.flush();
}, correlationContext)();

}; export default httpTrigger;

when executed locally in end to end transaction dependencyType is displayed as HTTP but when its deployed to cloud in end to end transaction it show dependencyType as HTTP(tracked component) please find attachment NOT-Working-Appinsight-End-to-End-Transaction Working-Appinsight-End-to-End-Transaction

madanbhavi commented 3 years ago

@hectorhdzg - Do you have any input for me? On further investigation I noticed that below attributes are not getting passed to functionApp 2 from functionaApp 1 when they both are deployed to cloud. But these attributes are present when functionApp 1 is running locally and making a axios call to FunctionApp2 deployed to cloud.

"request-id", "x-ms-request-id", "x-ms-request-root-id", "traceparent", "x-ms-coldstart"

madanbhavi commented 3 years ago

HI @hectorhdzg - do you have any input for me ? Noticed that below are the attributes which are missing in request header in Microservice B when both the services are deployed to cloud. "request-id", "x-ms-request-id", "x-ms-request-root-id", "traceparent", "x-ms-coldstart"

hectorhdzg commented 3 years ago

Sorry about the delay @madanbhavi, I will continue investigation of this issue and keep you updated

hectorhdzg commented 3 years ago

@madanbhavi I was able to verify context is propagated in the cloud, request-id is the header used by Azure functions to populate traceContext inside context object used by ApplicationInsights SDK to maintain the correlation, debugging in the cloud could get tricky but I recommend you to verify in first microservice that the request-id header is present when it calls other microservice and validate other microservice have traceContext.traceparent available

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

madanbhavi commented 3 years ago

@hectorhdzg - on further investigation noticed that when we deploy directly from visual studio code, distributed tracing is working and headers are passed but when deployed through azure pipeline tasks it not working. Is there any specific code we need to include to allow appinsight agent to pass required headers while using pipeline tasks or do you think if there is anything which is restricting it?

hectorhdzg commented 3 years ago

@madanbhavi Application Insights node.js SDK will automatically add the request-id header if configured on using setAutoDependencyCorrelation(on by default) in all dependency calls using node.js http/https native modules like axios calls you added in one of your examples before, so the SDK needs to be loaded for this to happen, would be good to understand if this happening on your pipeline setup

madanbhavi commented 3 years ago

@hectorhdzg - we are getting all the logs into appinsight and also the dependency data but operationId and Operation Name is missing that may be because request-id header may not be getting passed for some reason. When you say SDK needs to be loaded, is there anything we need to do to load it in pipeline setup ?

madanbhavi commented 3 years ago

@hectorhdzg We noticed below 2 warnings in our logs when webpack is running, do you think this may be causing the issue ? and any idea how to over come this ?

webpack: ./node_modules/diagnostic-channel-publishers/dist/src/azure-coretracing.pub.js; Module not found: Error: Can't resolve '@opentelemetry/tracing' in

webpack: ./node_modules/applicationinsights/out/AutoCollection/NativePerformance.js; Module not found: Error: Can't resolve 'applicationinsights-native-metrics'

[warning]webpack partially succeeded

2021-01-15T19:12:32.3967342Z ##[warning]webpack: ./node_modules/diagnostic-channel-publishers/dist/src/azure-coretracing.pub.js; Module not found: Error: Can't resolve '@opentelemetry/tracing' in 'D:\a\1\s\code\node_modules\diagnostic-channel-publishers\dist\src'; resolve '@opentelemetry/tracing' in 'D:\a\1\s\code\node_modules\diagnostic-channel-publishers\dist\src'; Parsed request is a module; using description file: D:\a\1\s\code\node_modules\diagnostic-channel-publishers\package.json (relative path: ./dist/src); resolve as module; D:\a\1\s\code\node_modules\diagnostic-channel-publishers\dist\src\node_modules doesn't exist or is not a directory; D:\a\1\s\code\node_modules\diagnostic-channel-publishers\dist\node_modules doesn't exist or is not a directory; D:\a\1\s\code\node_modules\diagnostic-channel-publishers\node_modules doesn't exist or is not a directory; D:\a\1\s\code\node_modules\node_modules doesn't exist or is not a directory; D:\a\1\s\node_modules doesn't exist or is not a directory; D:\a\1\node_modules doesn't exist or is not a directory; D:\a\node_modules doesn't exist or is not a directory; D:\node_modules doesn't exist or is not a directory; looking for modules in D:\a\1\s\code\node_modules; using description file: D:\a\1\s\code\package.json (relative path: ./node_modules); using description file: D:\a\1\s\code\package.json (relative path: ./node_modules/@opentelemetry/tracing); no extension; D:\a\1\s\code\node_modules\@opentelemetry\tracing doesn't exist; .ts; D:\a\1\s\code\node_modules\@opentelemetry\tracing.ts doesn't exist; .js; D:\a\1\s\code\node_modules\@opentelemetry\tracing.js doesn't exist; .json; D:\a\1\s\code\node_modules\@opentelemetry\tracing.json doesn't exist; as directory; D:\a\1\s\code\node_modules\@opentelemetry\tracing doesn't exist; [D:\a\1\s\code\node_modules\diagnostic-channel-publishers\dist\src\node_modules]; [D:\a\1\s\code\node_modules\diagnostic-channel-publishers\dist\node_modules]; [D:\a\1\s\code\node_modules\diagnostic-channel-publishers\node_modules]; [D:\a\1\s\code\node_modules\node_modules]; [D:\a\1\s\node_modules]; [D:\a\1\node_modules]; [D:\a\node_modules]; [D:\node_modules]; [D:\a\1\s\code\node_modules\@opentelemetry\tracing]; [D:\a\1\s\code\node_modules\@opentelemetry\tracing.ts]; [D:\a\1\s\code\node_modules\@opentelemetry\tracing.js]; [D:\a\1\s\code\node_modules\@opentelemetry\tracing.json]; @ ./node_modules/diagnostic-channel-publishers/dist/src/azure-coretracing.pub.js; @ ./node_modules/diagnostic-channel-publishers/dist/src/index.js; @ ./node_modules/applicationinsights/out/AutoCollection/diagnostic-channel/initialization.js; @ ./node_modules/applicationinsights/out/AutoCollection/CorrelationContextManager.js; @ ./node_modules/applicationinsights/out/applicationinsights.js; @ ./LoggerPoc/index.ts 2021-01-15T19:12:32.3987860Z ##[warning]webpack: ./node_modules/applicationinsights/out/AutoCollection/NativePerformance.js; Module not found: Error: Can't resolve 'applicationinsights-native-metrics' in 'D:\a\1\s\code\node_modules\applicationinsights\out\AutoCollection'; resolve 'applicationinsights-native-metrics' in 'D:\a\1\s\code\node_modules\applicationinsights\out\AutoCollection'; Parsed request is a module; using description file: D:\a\1\s\code\node_modules\applicationinsights\package.json (relative path: ./out/AutoCollection); resolve as module; D:\a\1\s\code\node_modules\applicationinsights\out\AutoCollection\node_modules doesn't exist or is not a directory; D:\a\1\s\code\node_modules\applicationinsights\out\node_modules doesn't exist or is not a directory; D:\a\1\s\code\node_modules\applicationinsights\node_modules doesn't exist or is not a directory; D:\a\1\s\code\node_modules\node_modules doesn't exist or is not a directory; D:\a\1\s\node_modules doesn't exist or is not a directory; D:\a\1\node_modules doesn't exist or is not a directory; D:\a\node_modules doesn't exist or is not a directory; D:\node_modules doesn't exist or is not a directory; looking for modules in D:\a\1\s\code\node_modules; using description file: D:\a\1\s\code\package.json (relative path: ./node_modules); using description file: D:\a\1\s\code\package.json (relative path: ./node_modules/applicationinsights-native-metrics); no extension; D:\a\1\s\code\node_modules\applicationinsights-native-metrics doesn't exist; .ts; D:\a\1\s\code\node_modules\applicationinsights-native-metrics.ts doesn't exist; .js; D:\a\1\s\code\node_modules\applicationinsights-native-metrics.js doesn't exist; .json; D:\a\1\s\code\node_modules\applicationinsights-native-metrics.json doesn't exist; as directory; D:\a\1\s\code\node_modules\applicationinsights-native-metrics doesn't exist; [D:\a\1\s\code\node_modules\applicationinsights\out\AutoCollection\node_modules]; [D:\a\1\s\code\node_modules\applicationinsights\out\node_modules]; [D:\a\1\s\code\node_modules\applicationinsights\node_modules]; [D:\a\1\s\code\node_modules\node_modules]; [D:\a\1\s\node_modules]; [D:\a\1\node_modules]; [D:\a\node_modules]; [D:\node_modules]; [D:\a\1\s\code\node_modules\applicationinsights-native-metrics]; [D:\a\1\s\code\node_modules\applicationinsights-native-metrics.ts]; [D:\a\1\s\code\node_modules\applicationinsights-native-metrics.js]; [D:\a\1\s\code\node_modules\applicationinsights-native-metrics.json]; @ ./node_modules/applicationinsights/out/AutoCollection/NativePerformance.js; @ ./node_modules/applicationinsights/out/applicationinsights.js; @ ./LoggerPoc/index.ts 2021-01-15T19:12:32.4003918Z ##[warning]webpack: ./node_modules/follow-redirects/debug.js; Module not found: Error: Can't resolve 'debug' in 'D:\a\1\s\code\node_modules\follow-redirects'; resolve 'debug' in 'D:\a\1\s\code\node_modules\follow-redirects'; Parsed request is a module; using description file: D:\a\1\s\code\node_modules\follow-redirects\package.json (relative path: .); resolve as module; D:\a\1\s\code\node_modules\follow-redirects\node_modules doesn't exist or is not a directory; D:\a\1\s\code\node_modules\node_modules doesn't exist or is not a directory; D:\a\1\s\node_modules doesn't exist or is not a directory; D:\a\1\node_modules doesn't exist or is not a directory; D:\a\node_modules doesn't exist or is not a directory; D:\node_modules doesn't exist or is not a directory; looking for modules in D:\a\1\s\code\node_modules; using description file: D:\a\1\s\code\package.json (relative path: ./node_modules); using description file: D:\a\1\s\code\package.json (relative path: ./node_modules/debug); no extension; D:\a\1\s\code\node_modules\debug doesn't exist; .ts; D:\a\1\s\code\node_modules\debug.ts doesn't exist; .js; D:\a\1\s\code\node_modules\debug.js doesn't exist; .json; D:\a\1\s\code\node_modules\debug.json doesn't exist; as directory; D:\a\1\s\code\node_modules\debug doesn't exist; [D:\a\1\s\code\node_modules\follow-redirects\node_modules]; [D:\a\1\s\code\node_modules\node_modules]; [D:\a\1\s\node_modules]; [D:\a\1\node_modules]; [D:\a\node_modules]; [D:\node_modules]; [D:\a\1\s\code\node_modules\debug]; [D:\a\1\s\code\node_modules\debug.ts]; [D:\a\1\s\code\node_modules\debug.js]; [D:\a\1\s\code\node_modules\debug.json]; @ ./node_modules/follow-redirects/debug.js; @ ./node_modules/follow-redirects/index.js; @ ./node_modules/axios/lib/adapters/http.js; @ ./node_modules/axios/lib/defaults.js; @ ./node_modules/axios/lib/axios.js; @ ./node_modules/axios/index.js; @ ./LoggerPoc/index.ts 2021-01-15T19:12:32.4017749Z webpack summary section markdown file creation is started

madanbhavi commented 3 years ago

@hectorhdzg On further analysis we noticed that as we were using webpack it was getting only the dependents required to run the functions .We added a step in Azure pipeline to do npm install to include node_modules into dist folder. After this changes distributed tracing seems to be working fine.

By doing this our bundle size is getting increased , can you please suggest if this is right way to do or is there any other approach.

hectorhdzg commented 3 years ago

@madanbhavi Application Insights node.js definitely need to installed to have the distributed tracing working correctly and I don't see any other way to have it available in this case, the SDK must not be huge but I don't believe size optimizations have been in our radar so it would be good to understand why this is important on your side.

madanbhavi commented 3 years ago

@hectorhdzg - As we are using webpack to bundle the package, hence we were wondering why node_modules needs to be kept as part of the bundle to be deployed . It will load all other modules which may not be really required. instead is there any way we can add only required modules ? applicationinsights is being used in index.ts file so I believe webpack is loading same and hence logs are going to appinsight but internally I feel its other packages (opentelemetry ) which does the job or correlating the request and webpack is dropping at as its not directly referenced in the code.

with little bigger functionapp project which has many node dependency , build artifact may grow huge and our understanding is it will delay the deployment process . We can directly go to Kudo or console to install node_module but that may beat the purpose of automated deployment.

MSNev commented 3 years ago

We are a little confused on exactly what you mean here, to me it looks like the issue are having is a packaging one where webpack is not able to locate the packages (like @opentelemetry/tracing).

We don't dynamically load modules (thats the domain of webpack) we define our dependencies and whatever package manager you use will create your final bundle(s), so from the SDK perspective we DON'T required node_modules.

Looking at the message (and presuming it's a runtime message) webpack: ./node_modules/diagnostic-channel-publishers/dist/src/azure-coretracing.pub.js; this is an internal webpack reference saying that webpack (during packaging) it can't find the defined packages -- have you defined them in your webpack.config as external references and therefore webpack is "assuming" that they will be loaded externally and should not be included in the bundle?

Note: I'm by no means a webpack expert, and I only an occasional users for my own private projects.

madanbhavi commented 3 years ago

@MSNev , Thanks for your input. No we have not specified it as external reference. Our understanding is application insight uses it internally to pass the request-id in header but as the required module is not available its not working. I agree to your point that webpack will not add it as its not used in the code we wrote , its a inbuilt feature from azure app insight. So we trying to understand how can we force to include these required modules without bundling complete node_modules. or going to server and installing it as mentioned in below link

https://docs.microsoft.com/en-us/azure/azure-functions/functions-reference-node?tabs=v2#dependency-management

MSNev commented 3 years ago

You might need to make sure that Webpack includes the module itself (so you don't need to include a package.json in the deployment)

Found this: http://www.matthiassommer.it/software-architecture/webpack-node-modules/ , not sure if this on it's own would work, in the past I've used the ProvidePlugin to force webpack to include packages https://webpack.js.org/plugins/provide-plugin/

hectorhdzg commented 3 years ago

@madanbhavi let us know if this is still an issue, looks like problem was with webpack configuration.

madanbhavi commented 3 years ago

Yeah please mark this as closed. Thanks for all the help

On Thu, May 20, 2021 at 4:05 PM Hector Hernandez @.***> wrote:

@madanbhavi https://github.com/madanbhavi let us know if this is still an issue, looks like problem was with webpack configuration.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/microsoft/ApplicationInsights-node.js/issues/710#issuecomment-845475822, or unsubscribe https://github.com/notifications/unsubscribe-auth/AFKZAPGSMNCJXXOPVT2ABVTTOV2P3ANCNFSM4UREKVLA .