microsoft / ApplicationInsights-node.js

Microsoft Application Insights SDK for Node.js
MIT License
321 stars 138 forks source link

Support correlation and autocollection when servers use SPDY/http2 #452

Open lord3nzo opened 5 years ago

lord3nzo commented 5 years ago

I have a call from an express-nodejs service to a next component and I would like to link nodejs dependency with next component request. I am already able to link browser dependency with express-nodejs request.

  1. If I use tagoverride instead clientAI.context.tags[operationIdKey] = operationId we miss operation id. image If we uncomment clientAI.context.tags[operationIdKey] = operationId we get operation id but I have read that we won´t should use this to avoid problems with handling multiple requests at the same time. image How can I solve this?
    1. When I console log clientAI.getCorrelationContext() it get error. Same issue here https://github.com/Microsoft/ApplicationInsights-node.js/issues/323#issue-257545223 but I´m not able to solve it even if I change the import of the appinsighs to the first. Any idea?
    2. How can I get the dependency id from this express-node js service to pass throw the http call to the next component in the request-id header to be able to have the end to end correlation working?

This is part of my code:

./init/initApplicationInsights

const config = require('../config');
const appInsights = require('applicationinsights');

module.exports = function initApplicationInsights() {
  if (config.INSTRUMENTATION_KEY) {
    appInsights.setup(config.INSTRUMENTATION_KEY)
      .setAutoDependencyCorrelation(true)
      .setAutoCollectRequests(false)
      .setAutoCollectPerformance(true)
      .setAutoCollectExceptions(true)
      .setAutoCollectDependencies(false)
      .setAutoCollectConsole(true)
      .setUseDiskRetryCaching(true);
    appInsights.defaultClient.context.tags[appInsights.defaultClient.context.keys.cloudRole] =
      'fes-air-availability';
    appInsights.start();
    return appInsights.defaultClient;
  }
  return null;
};

app.js

const clientAI = require('./init/initApplicationInsights')();
    const requestId = req.headers["request-id"];
    const operationId = requestId.substr(1, requestId.indexOf('.')-1);  
    console.log("requestId " + requestId);  // |OjuCU.ClP5n
    console.log("operationId " + operationId);   // OjuCU
    const operationIdKey = clientAI.context.keys.operationId; 
    //clientAI.context.tags[operationIdKey] = operationId;

clientAI.trackDependency({
                    name: 'cs-airavailability',
                    target: airAvailabilityEndpoint,
                    duration: endRequest[1] / 1000000,
                    tagOverrides:{"ai.operation.id": operationId},
                    tagOverrides:{"ai.operation.parentId": requestId},

                  });
clientAI.trackRequest({
                          name: 'get /airavailability',
                          url: requestURL,
                          duration: startDuration[1] / 1000000,
                          resultCode:200, 
                          success:true,
                          tagOverrides:{"ai.operation.id": operationId},
                          tagOverrides:{"ai.operation.parentId": requestId},
                        });

Thank

OsvaldoRosado commented 5 years ago

@aparralorenzo Can you show how you're handling incoming requests? Typically for libraries that depend on the built-inhttp/https library (like request), you should not need to do trackRequest or manual parsing of any headers. I'd be interested to know what's unique about your situation.

Also, to confirm for getCorrelationContext, make sure you're using this method on the applicationinsights export directly. It doesn't exist on TelemetryClient instances like defaultClient.

lord3nzo commented 5 years ago

Hi @OsvaldoRosado, Thank you for your response.

We are using latest express routing to handle incoming request:

app.get('/?*', (req, res) => {
const clientAI = require('./init/initApplicationInsights')();
    const requestId = req.headers["request-id"];
    const operationId = requestId.substr(1, requestId.indexOf('.')-1);  
    console.log("requestId " + requestId);  // |BV+f6.si8Gq
    console.log("operationId " + operationId);   // BV+f6
    const operationIdKey = clientAI.context.keys.operationId; 
    //clientAI.context.tags[operationIdKey] = operationId;

clientAI.trackDependency({
                    name: 'cs-airavailability',
                    target: airAvailabilityEndpoint,
                    duration: endRequest[1] / 1000000,
                    tagOverrides:{"ai.operation.id": operationId},
                    tagOverrides:{"ai.operation.parentId": requestId},

                  });
clientAI.trackRequest({
                          name: 'get /airavailability',
                          url: requestURL,
                          duration: startDuration[1] / 1000000,
                          resultCode:200, 
                          success:true,
                          tagOverrides:{"ai.operation.id": operationId},
                          tagOverrides:{"ai.operation.parentId": requestId},
                        });
}

You was right about the getCorrelationContext, if I take it directly from the exported applicationinsights i obtain the operationid: ./init/initApplicationInsights

const config = require('../config');
const appInsights = require('applicationinsights');

module.exports = function initApplicationInsights() {
  if (config.INSTRUMENTATION_KEY) {
    appInsights.setup(config.INSTRUMENTATION_KEY)
      .setAutoDependencyCorrelation(true)
      .setAutoCollectRequests(false)
      .setAutoCollectPerformance(true)
      .setAutoCollectExceptions(true)
      .setAutoCollectDependencies(false)
      .setAutoCollectConsole(true)
      .setUseDiskRetryCaching(true);
    appInsights.defaultClient.context.tags[appInsights.defaultClient.context.keys.cloudRole] =
      'fes-air-availability';
    appInsights.start();
    console.log("correlation context: "+ appInsights.getCorrelationContext()); //BV+f6
    return appInsights.defaultClient;
  }
  return null;
};

But still I think I´m missing something, how can I link the fes-air-availability dependency with the cs-air-availability request image

OsvaldoRosado commented 5 years ago

Thanks for the updated code sample. If appInsights is your first require (for the entire application, not just the request), and start() is called before constructing your http server, you shouldn't need to manually pipe together operation ids. Is this not the case in your app? Here's a code sample of an express app based on your code sample that behaves as expected.

const appInsights = require('applicationinsights');
const express = require('express');

appInsights.setup('mykey')
      .setAutoDependencyCorrelation(true)
      .setAutoCollectRequests(false)
      .setAutoCollectPerformance(true)
      .setAutoCollectExceptions(true)
      .setAutoCollectDependencies(false)
      .setAutoCollectConsole(true)
      .setUseDiskRetryCaching(true)
      .start();

const app = express();

app.get('/?*', (req, res) => {
    appInsights.defaultClient.trackDependency({
        name: 'name',
        target: 'target',
        duration: 5000,
    });
    appInsights.defaultClient.trackRequest({
        name: 'name',
        url: req.url,
        duration: 2000,
        resultCode: 200,
        success: true
    });
    res.end('Hello!');
});

app.listen(3000);

As an aside. Is there a reason you want to manually track requests? From what I can tell in the code sample, automatic collection should work fine here.

lord3nzo commented 5 years ago

We implement SPDY protocol using SPDY Server for node.js:

const path = require('path');
const fs = require('fs');
const spdy = require('spdy');
const appInsights = require('applicationinsights');
const express = require('express');
const config = require('./config');

appInsights.setup(config.INSTRUMENTATION_KEY)
      .setAutoDependencyCorrelation(true)
      .setAutoCollectRequests(false)
      .setAutoCollectPerformance(true)
      .setAutoCollectExceptions(true)
      .setAutoCollectDependencies(false)
      .setAutoCollectConsole(true)
      .setUseDiskRetryCaching(true);
      appInsights.defaultClient.context.tags[appInsights.defaultClient.context.keys.cloudRole] =
      'fes-air-availability';
      appInsights.start();

const app = express();

app.use(cors({
  exposedHeaders: config.corsHeaders,
  maxAge: 1728000,
}));

app.get('/?*', (req, res) => {
    console.log("correlation context: " + appInsights.getCorrelationContext());
    console.log("requestId: " + requestId);
    console.log("requestContext: " + requestContext);

    appInsights.defaultClient.trackDependency({
        name: 'TestingDependency',
        target: 'target',
        duration: 5000,
    });
    appInsights.defaultClient.trackRequest({
        name: 'TestingRequest',
        url: req.url,
        duration: 2000,
        resultCode: 200,
        success: true
    });
    res.end('Hello!');
});

let options = {
    key: fs.readFileSync(path.join(__dirname, './server.key')),
    cert: fs.readFileSync(path.join(__dirname, './server.crt')),
  };

spdy.createServer(options, app).listen(config.port, (error) => {
  if (error) {
    console.error(error);
  }
});

image

image

Still looks like is not working properly 😟 Implementing SPDY may be a reason?

There is not specific reason to manually track request, apart that I haven´t been able to set automatic collection to work as expected either 😳. For outgoing calls we use fetch node-fetch.

OsvaldoRosado commented 5 years ago

Using SPDY is definitely the reason here. We only support automatic request collection for the http module, and only create correlation contexts when incoming requests are sent to the http module. Here's a workaround to fix correlation - unfortunately you'll still need manual trackRequest. (The same goes for fetch and trackDependency since it doesn't seem to depend on http under the hood)

const appInsights = require('applicationinsights');
const CorrelationContextManager = require('applicationinsights/out/AutoCollection/CorrelationContextManager').CorrelationContextManager;
const HttpRequestParser = require('applicationinsights/out/AutoCollection/HttpRequestParser');

const express = require('express');
const spdy = require('spdy');
const fs = require('fs');
const path = require('path');

// Helper method to use internal AI SDK methods to generate a correlation context manually for an HTTP-like request
function startOperation(client, req, cb) {
    const requestParser = new HttpRequestParser(req);
    const correlationContext = CorrelationContextManager.generateContextObject(
        requestParser.getOperationId(client.context.tags),
        requestParser.getRequestId(),
        requestParser.getOperationName(client.context.tags),
        requestParser.getCorrelationContextHeader()
    );
    CorrelationContextManager.runWithContext(correlationContext, cb);
 }

appInsights.setup('mykey')
      .setAutoDependencyCorrelation(true)
      .setAutoCollectRequests(false)
      .setAutoCollectPerformance(true)
      .setAutoCollectExceptions(true)
      .setAutoCollectDependencies(false)
      .setAutoCollectConsole(true)
      .setUseDiskRetryCaching(true)
      .start();

const app = express();

app.get('/?*', (req, res) => {
    startOperation(appInsights.defaultClient, req, () => {
        // Use trackNodeHttpRequest to inject outgoing correlation headers
        // and automatically calculate duration / responsecode / name / etc.
        // This must be the first call after startOperation for accurate duration
        appInsights.defaultClient.trackNodeHttpRequest({
            request: req,
            response: res
        });
        appInsights.defaultClient.trackDependency({
            name: 'name',
            target: 'target',
            duration: 5000,
        });
        res.end('Hello!');
    });
});

let options = {
    key: fs.readFileSync(path.join(__dirname, './server.key')),
    cert: fs.readFileSync(path.join(__dirname, './server.crt')),
};

spdy.createServer(options, app).listen(3000, (error) => {
    if (error) {
        console.error(error);
    }
});
lord3nzo commented 5 years ago

Thank you for the workaround!

For some reason the request is not being tracking, only the dependency. With https module requests and responses are being tracking properly. We would like to implement HTTP2 that´s the reason we are trying to use SPDY. Do you have any recomendation to implement HTTP2 and application insights support it?

OsvaldoRosado commented 5 years ago

Does my code sample with spdy work as is for you - or does that not work either? It would be interesting to know what's different between your actual code and the sample above if the sample works but not your real service.

As far as recommendations go - I think the best course of action is something like the code sample given above. Other alternatives are likely to be quite fragile for correlation.

lord3nzo commented 5 years ago

It didn't work, the request is not being tracked. We will go with http 1.1 for the moment and we will wait for native express http2 support. Any idea if application insights will support also http2 in express? Thank you!!

OsvaldoRosado commented 5 years ago

I'm not sure how http2 will end up being implemented, if the standard http node module ends up providing the functionality, it should light up within this SDK. Otherwise, we'll probably need some time to build support for it in a future version.

OsvaldoRosado commented 5 years ago

Updating the labels and title to track support for http2/spdy out of the box.

eduardocrn commented 4 years ago

Hello guys, I don't know if this problem has already been solved. But do we have anything new for http2 support for automatic correlation?