Support performance logging

[brianghig]

The goal of this is to allow admins to better understand performance bottlenecks in their application before and after users alert them to the issue.

[brianghig]

@jrassa @abemac @tzfx @ymao1 @twhittington @mlhummon @reblace - I'd love to hear your thoughts (and others!) on how we can best achieve this with the node-rest-starter.

Some options I'm seeing are:

Implementation:

• Express.js hooks with events [1]
  • We'd have to decide whether we want to capture just the endpoint, or each middleware function along the way
• Morgan [2]
• Mongo query hooks (somewhat captured in slow performance logging, and doesn't give you the whole picture)
• Command line arguments like --trace-sync-io
• Other pluggable solutions?

Storage:

• Log
• Mongo Collection
• External system like Elastic (supporting a provider for ES, at least)

Retrieval:

• REST endpoints so that a UI / external system can visualize the performance
• Alerting, in-app or via email. Thresholds or statistical triggers?

My initial thoughts are in favor of configurable Express.js hooks with options to:

• turn on or off entirely
• fire only above certain thresholds
• output either to logfiles or an isolated Mongo collection

[1] https://www.lunchbadger.com/blog/tracking-the-performance-of-express-js-routes-and-middleware/
[2] https://www.npmjs.com/package/morgan

[ymao1]

I played around with using Elastic APM when it first came out and it seemed promising. I think they've added a lot of features since then and it was pretty straightforward to get it set up.

[tzfx]

I cast resurrection on this thread! 🧙 💀 ➡️ 😐 🆗

I did a quick test with Elastic APM and it seems like a great idea.

The whole ELK stack seems to be very straightforward to containerize and deploy, and elastic publishes a node agent that integrates flawlessly with express:

https://github.com/deviantony/docker-elk

Instructions for this project boil down to this:

1. Pull it down (or recreate the very simplistic docker/compose files-- there's really not much that doesn't already come out of the box.
2. Disable x-pack (sed -i '{s/trial/basic/}' ./elasticsearch/config/elasticsearch.yml).
3. Run docker-compose up with the apm extension: docker-compose -f docker-compose.yml -f extensions/apm-server/apm-server-compose.yml up

That's it. On the node side, it's as simple as this:

1. Install the apm agent as a dependency: npm i elastic-apm-node
2. Start up the agent prior to express:

/* ./src/metrics.js */
'use strict';

const start = () => require('elastic-apm-node').start({
    // Override service name from package.json
    // Allowed characters: a-z, A-Z, 0-9, -, _, and space
    serviceName: 'some-service',
    // Use if APM Server requires a token
    secretToken: '',
    // Set custom APM Server URL (default: http://localhost:8200)
    serverUrl: 'http://localhost:8200'
});

module.exports = start;

/* ./src/startup.js */
'use strict';

const
	q = require('q'),
	logger = require('./lib/bunyan').logger,
	express = require('./lib/express'),
	mongoose = require('./lib/mongoose'),
	startMetrics = require('./metrics');


module.exports = function () {
	logger.info('Starting initialization of Node.js server');
	startMetrics();

	// Initialize mongoose
	return mongoose.connect()
// ...snip...

And it's done. The application will instantly start vomitting all sorts of fun metrics into ES. API for capturing bespoke metrics for other things can be found here https://www.elastic.co/guide/en/apm/agent/nodejs/current/agent-api.html