@abeai/logging

v1.1.1

Published

2 years ago

Abe AI logging package

Downloads

0High
0Medium
0Low

abe-ai

abeai-sam

node-logging

Node package to provide functionality around logging / monitoring of node services in Abe AI's ecosystem by using pino and Elastic APM.

Setup

npm install @abeai/logging elastic-apm-node --save-exact

// Add those two line before requiring any other modules!
require('elastic-apm-node').start({
    active: process.env.ELASTIC_APM_ACTIVE === 'true',
});
require('@abeai/logging').configure({appName: 'loggingExampleApp'});

const express = require('express');
const logger = require('@abeai/logging').logger;
const loggingMiddleware = require('@abeai/logging').expressMiddleware;

const app = express();

// This middleware has to run before any logging occurs
app.use(loggingMiddleware.requestHandler());

app.get('/', (req, res) => {
    res.send('Hello World!');
});

// This error middleware has should be run first
app.use(loggingMiddleware.errorHandler());

app.listen(3000, () => logger.info(`Listening on port 3000`));

Express Middleware

const monitoringMiddleware = require('@abeai/logging').expressMiddleware

This middleware populate the logger context with header attributes from the request, adds the context to the Elastic APM agent, and logs basic request/response information. The middleware should be used as early as possible.

Function Signature:

function expressMiddleware(options)

Available options are:

requireRequestCorrelationId: Will log a warning if no correlation ID is found on the request. Though a correlation I is still generated on-the-line in this case. Default is true.
addResponseReferenceId: If true, the correlation ID will be added as the header Abe-AI-Reference-ID to the response. This is useful for consumers of our external APIs. Default is false.

Example:

app.use(monitoringMiddleware({requireRequestCorrelationId: false}));

Logging

Configuration

require('@abeai/logging').configure({appName: 'myAppName'});

Configuration Attributes:

appName: Is used to namespace log data which should be indexed. Is required.

Usage

const logger = require('@abeai/logging').logger

Message Logging

The log levels are the same as pino's. Though the function signature is a bit different:

logger.fatal
logger.error
logger.warning
logger.info
logger.debug
logger.trace

All functions can take just just a message, or a message with data. Additionally fatal, error, and warning support passing in an error object as a single argument.

The following data attributes are supported:

unindexed: Data which should be encoded as a JSON string to avoid indexing. It will be added to the top-level of the log message.
indexed: Data which should be encoded as JSON for indexing. It will be scoped by the logger name on the top-level of the log message avoid structure conflicts with other services.
err: Error object which should be serialized.

Example:

logger.info('log this');
logger.info('log with raw data', {unindexed: {aLotOfData: ...}});
logger.info('log with json data', {indexed: {dataWhichShouldBeIndexed: ...}});
logger.info('log with data', {unindexed: {aLotOfData: ...}, indexed: {dataWhichShouldBeIndexed: ...}});
logger.error(new Error('my error'));
logger.error('a separate error message', new Error('my error'));

Context Management

The context supports the following attributes:

correlationId: Correlation ID of current request chain. This attribute is always available and can't be set or merged.
channelType: Channel type related to current request chain. This attribute is optional.
channelId: Channel ID related to current request chain. This attribute is optional.
channelIdentityId: Channel Identity ID related to current request chain. This attribute is optional.
agentId: Agent ID related to current request chain. This attribute is optional.
agentName: Agent Name related to current request chain. This attribute is optional.
userId: User ID related to current request chain. This attribute is optional.
cuiUserId: CUI User ID related to current request chain. This attribute is optional.

The current context can be managed with the following functions:

logger.setContext({channelType,channelId,channelIdentityId,agentId,userId,cuiUserId}): Overwites existing attributes.
logger.mergeContext({channelType,channelId,channelIdentityId,agentId,userId,cuiUserId}): Merges new attributes with existing attributes. New attributes win over existing attributes.
logger.context(): Returns all available context attributes as an object.

Context Propagation for Inter-Service Communication

The logger provides the function logger.requestHeaders() which returns a list of requests headers which needs to be merged into the headers of a requests to another Abe AI service.

The following headers are supported:

Abe-AI-Correlation-ID
Abe-AI-Channel-Type
Abe-AI-Channel-ID
Abe-AI-Channel-Identity-ID
Abe-AI-Agent-ID
Abe-AI-Agent-Name
Abe-AI-User-ID
Abe-AI-CUI-User-ID

Example:

rp({
    method: 'GET',
    uri: `${config.anotherAbeAiServiceUrl}/coolStuff`,
    headers: Object.assign({
        'My-Header': 'stuff',
    }, logger.contextRequestHeaders())
})
    .then((response) => {
        ...
    })
;

Log Output Structure

The structure is based on pino with some additions:

Normal Message

logger.info('log this');

Output:

{
    "abeLogging": true,
    "correlationId": "111e4567-e89b-12d3-a456-426655441111",
    "channelType": "GOOGLE",
    "channelId": "222e4567-e89b-12d3-a456-426655442222",
    "channelIdentityId": "333e4567-e89b-12d3-a456-426655443333",
    "agentId": "444e4567-e89b-12d3-a456-4266554444444",
    "agentName": "Demo FI",
    "userId": "555e4567-e89b-12d3-a456-426655445555",
    "cuiUserId": "666e4567-e89b-12d3-a456-426655446666",
    "v": 1,
    "pid": 94473,
    "hostname": "MacBook-Pro-3.home",
    "time": 1459529098958,
    "level": 30,
    "msg": "log this",
}

Message With Raw Data

logger.info('log with raw data', {unindexed: {aLotOfData: ...}});

Output:

{
    "abeLogging": true,
    "correlationId": "111e4567-e89b-12d3-a456-426655441111",
    "channelType": "GOOGLE",
    "channelId": "222e4567-e89b-12d3-a456-426655442222",
    "channelIdentityId": "333e4567-e89b-12d3-a456-426655443333",
    "agentId": "444e4567-e89b-12d3-a456-4266554444444",
    "agentName": "Demo FI",
    "userId": "555e4567-e89b-12d3-a456-426655445555",
    "cuiUserId": "666e4567-e89b-12d3-a456-426655446666",
    "v": 1,
    "pid": 94473,
    "hostname": "MacBook-Pro-3.home",
    "time": 1459529098958,
    "level": 30,
    "msg": "log with raw data",
    "data": {
        "unindexed": "{\"aLotOfData\": ...}"
    }
}

Message With JSON Data

logger.info('log with json data', {indexed: {dataWhichShouldBeIndexed: ...}});

Output:

{
    "abeLogging": true,
    "correlationId": "111e4567-e89b-12d3-a456-426655441111",
    "channelType": "GOOGLE",
    "channelId": "222e4567-e89b-12d3-a456-426655442222",
    "channelIdentityId": "333e4567-e89b-12d3-a456-426655443333",
    "agentId": "444e4567-e89b-12d3-a456-4266554444444",
    "agentName": "Demo FI",
    "userId": "555e4567-e89b-12d3-a456-426655445555",
    "cuiUserId": "666e4567-e89b-12d3-a456-426655446666",
    "v": 1,
    "pid": 94473,
    "hostname": "MacBook-Pro-3.home",
    "time": 1459529098958,
    "level": 30,
    "msg": "log with raw data",
    "data": {
        "myAppName": {
            "dataWhichShouldBeIndexed": ...
        }
    }
}

Message With Raw Data And JSON Data

logger.info('log with data', {unindexed: {aLotOfData: ...}, indexed: {dataWhichShouldBeIndexed: ...}});

Output:

{
    "abeLogging": true,
    "correlationId": "111e4567-e89b-12d3-a456-426655441111",
    "channelType": "GOOGLE",
    "channelId": "222e4567-e89b-12d3-a456-426655442222",
    "channelIdentityId": "333e4567-e89b-12d3-a456-426655443333",
    "agentId": "444e4567-e89b-12d3-a456-4266554444444",
    "agentName": "Demo FI",
    "userId": "555e4567-e89b-12d3-a456-426655445555",
    "cuiUserId": "666e4567-e89b-12d3-a456-426655446666",
    "v": 1,
    "pid": 94473,
    "hostname": "MacBook-Pro-3.home",
    "time": 1459529098958,
    "level": 30,
    "msg": "log with raw data",
    "data": {
        "unindexed": "{\"aLotOfData\": ...}",
        "myAppName": {
            "dataWhichShouldBeIndexed": ...
        }
    }
}

Message With Additional Error Object

logger.error('a separate error message', new Error('my error'));

Output:

{
    "abeLogging": true,
    "correlationId": "111e4567-e89b-12d3-a456-426655441111",
    "channelType": "GOOGLE",
    "channelId": "222e4567-e89b-12d3-a456-426655442222",
    "channelIdentityId": "333e4567-e89b-12d3-a456-426655443333",
    "agentId": "444e4567-e89b-12d3-a456-4266554444444",
    "agentName": "Demo FI",
    "userId": "555e4567-e89b-12d3-a456-426655445555",
    "cuiUserId": "666e4567-e89b-12d3-a456-426655446666",
    "v": 1,
    "pid": 94473,
    "hostname": "MacBook-Pro-3.home",
    "time": 1459529098958,
    "level": 50,
    "msg": "a separate error message",
    "err": {
        "type": "Error",
        "message": "my error",
        "stack": "Error: an error\n    at Object.<anonymous> (/Users/davidclements/z/nearForm/pino/example.js:14:12)\n    at Module._compile (module.js:435:26)\n    at Object.Module._extensions..js (module.js:442:10)\n    at Module.load (module.js:356:32)\n    at Function.Module._load (module.js:311:12)\n    at Function.Module.runMain (module.js:467:10)\n    at startup (node.js:136:18)\n    at node.js:963:3"
    }
}

Error Object

logger.error(new Error('my error'));

Output:

{
    "abeLogging": true,
    "correlationId": "111e4567-e89b-12d3-a456-426655441111",
    "channelType": "GOOGLE",
    "channelId": "222e4567-e89b-12d3-a456-426655442222",
    "channelIdentityId": "333e4567-e89b-12d3-a456-426655443333",
    "agentId": "444e4567-e89b-12d3-a456-4266554444444",
    "agentName": "Demo FI",
    "userId": "555e4567-e89b-12d3-a456-426655445555",
    "cuiUserId": "666e4567-e89b-12d3-a456-426655446666",
    "v": 1,
    "pid": 94473,
    "hostname": "MacBook-Pro-3.home",
    "time": 1459529098958,
    "level": 50,
    "msg": "my error",
    "err": {
        "type": "Error",
        "message": "my error",
        "stack": "Error: an error\n    at Object.<anonymous> (/Users/davidclements/z/nearForm/pino/example.js:14:12)\n    at Module._compile (module.js:435:26)\n    at Object.Module._extensions..js (module.js:442:10)\n    at Module.load (module.js:356:32)\n    at Function.Module._load (module.js:311:12)\n    at Function.Module.runMain (module.js:467:10)\n    at startup (node.js:136:18)\n    at node.js:963:3"
    }
}

Successful Request

Output:

{
    "abeLogging": true,
    "correlationId": "111e4567-e89b-12d3-a456-426655441111",
    "channelType": "GOOGLE",
    "channelId": "222e4567-e89b-12d3-a456-426655442222",
    "channelIdentityId": "333e4567-e89b-12d3-a456-426655443333",
    "agentId": "444e4567-e89b-12d3-a456-4266554444444",
    "agentName": "Demo FI",
    "userId": "555e4567-e89b-12d3-a456-426655445555",
    "cuiUserId": "666e4567-e89b-12d3-a456-426655446666",
    "v": 1,
    "pid": 94473,
    "hostname": "MacBook-Pro-3.home",
    "time": 1459529098958,
    "level": 30,
    "msg": "Request completed",
    "req":{
        "method":"POST",
        "url":"/?test=1",
        "headers":{
            "host":"localhost:3000",
            "user-agent":"curl/7.54.0",
            "content-type":"application/json",
            "accept":"application/json",
            "content-length":"10"
        },
        "remoteAddress":"::1",
        "remotePort":56330,
        "body":"{\"test\":1}"
    },
    "res":{
        "statusCode":200,
        "header":"HTTP/1.1 200 OK\r\nX-Powered-By: Express\r\nAbe-AI-Reference-ID: cda86902-461e-472a-ae2c-396c5bdc55da\r\nContent-Type: application/json; charset=utf-8\r\nContent-Length: 14\r\nETag: W/\"e-CdsQPLbJIMgXo5pizELzDY/989E\"\r\nDate: Thu, 03 May 2018 12:31:13 GMT\r\nConnection: keep-alive\r\n\r\n",
        "body":"\"Hello World!\""
    },
    "responseTime":5
}

Unsuccessful Request With Error Object

throw new Error('my error');

Output:

{
    "abeLogging": true,
    "correlationId": "111e4567-e89b-12d3-a456-426655441111",
    "channelType": "GOOGLE",
    "channelId": "222e4567-e89b-12d3-a456-426655442222",
    "channelIdentityId": "333e4567-e89b-12d3-a456-426655443333",
    "agentId": "444e4567-e89b-12d3-a456-4266554444444",
    "agentName": "Demo FI",
    "userId": "555e4567-e89b-12d3-a456-426655445555",
    "cuiUserId": "666e4567-e89b-12d3-a456-426655446666",
    "v": 1,
    "pid": 94473,
    "hostname": "MacBook-Pro-3.home",
    "time": 1459529098958,
    "level": 50,
    "msg": "Request errored",
    "err": {
        "type": "Error",
        "stack": "Error: my error\n    at Object.<anonymous> (/Users/davidclements/z/nearForm/pino/example.js:14:12)\n    at Module._compile (module.js:435:26)\n    at Object.Module._extensions..js (module.js:442:10)\n    at Module.load (module.js:356:32)\n    at Function.Module._load (module.js:311:12)\n    at Function.Module.runMain (module.js:467:10)\n    at startup (node.js:136:18)\n    at node.js:963:3"
    }
    "req":{
        "method":"GET",
        "url":"/error-in-promise",
        "headers":{
            "host":"localhost:3000",
            "user-agent":"curl/7.54.0",
            "content-type":"application/json",
            "accept":"application/json"
        },
        "remoteAddress":"::1",
        "remotePort":56332
    },
    "res":{
        "statusCode":500,
        "header":"HTTP/1.1 500 Internal Server Error\r\nX-Powered-By: Express\r\nAbe-AI-Reference-ID: 7fd0d64d-fff9-4794-a618-02496900294e\r\nContent-Type: application/json; charset=utf-8\r\nContent-Length: 20\r\nETag: W/\"14-FJXd+uz64FdKH++J0y7A2OERZ+s\"\r\nDate: Thu, 03 May 2018 12:31:13 GMT\r\nConnection: keep-alive\r\n\r\n",
        "body":"{\"error\":\"my error\"}"
    },
    "responseTime":1
}

Unsuccessful Request Without Error Object

throw 'my error';

Output:

{
    "abeLogging": true,
    "correlationId": "111e4567-e89b-12d3-a456-426655441111",
    "channelType": "GOOGLE",
    "channelId": "222e4567-e89b-12d3-a456-426655442222",
    "channelIdentityId": "333e4567-e89b-12d3-a456-426655443333",
    "agentId": "444e4567-e89b-12d3-a456-4266554444444",
    "agentName": "Demo FI",
    "userId": "555e4567-e89b-12d3-a456-426655445555",
    "cuiUserId": "666e4567-e89b-12d3-a456-426655446666",
    "v": 1,
    "pid": 94473,
    "hostname": "MacBook-Pro-3.home",
    "time": 1459529098958,
    "level": 50,
    "msg": "Request errored",
    "req":{
        "method":"GET",
        "url":"/error-in-promise",
        "headers":{
            "host":"localhost:3000",
            "user-agent":"curl/7.54.0",
            "content-type":"application/json",
            "accept":"application/json"
        },
        "remoteAddress":"::1",
        "remotePort":56332
    },
    "res":{
        "statusCode":500,
        "header":"HTTP/1.1 500 Internal Server Error\r\nX-Powered-By: Express\r\nAbe-AI-Reference-ID: 7fd0d64d-fff9-4794-a618-02496900294e\r\nContent-Type: application/json; charset=utf-8\r\nContent-Length: 20\r\nETag: W/\"14-FJXd+uz64FdKH++J0y7A2OERZ+s\"\r\nDate: Thu, 03 May 2018 12:31:13 GMT\r\nConnection: keep-alive\r\n\r\n",
        "body":"{\"error\":\"my error\"}"
    },
    "responseTime":1
}

Deployment

The package requires the following env vars:

ELASTIC_APM_SERVICE_NAME=<service name>
ELASTIC_APM_SECRET_TOKEN=<token>
ELASTIC_APM_SERVER_URL=<server url>

Published

Vulnerabilities

Links

Maintainers

Keywords

Readme

node-logging

Setup

Express Middleware

Logging

Configuration

Usage

Message Logging

Context Management

Context Propagation for Inter-Service Communication

Log Output Structure

Normal Message

Message With Raw Data

Message With JSON Data

Message With Raw Data And JSON Data

Message With Additional Error Object

Error Object

Successful Request

Unsuccessful Request With Error Object

Unsuccessful Request Without Error Object

Deployment