aura-logging utility

Introduction

aura-logging utility is a custom login tool across every Aura apps intended to prevent possible errors in execution time or unspecified login format.

Find more information in the Github repository: https://github.com/Telefonica/aura-utilities/tree/master/packages/aura-logging

The current logging format, including different fields and logging levels to be used across Aura components, is included in the Aura logging common format section.

emit function has been deprecated, please use logging method in future implementations:

jest.spyOn(AuraLog.prototype, 'logging').mockImplementation();

Use aura-logging utility

Basic usage

import { AuraLogger } from '@telefonica/aura-logging';

const logger: AuraLog = new AuraLog('new-component');

logger.debug(msg: 'ok');

Configuration

Set level and format

import { AuraLogger } from '@telefonica/aura-logging';

AuraLogger.setLevel('DEBUG');
AuraLogger.setFormat('json');

Set default fields on each log

import { AuraLogger } from '@telefonica/aura-logging';

AuraLogger.defaultFields({version: '1.2.3', app: 'randomApp'});

Everything else should be managed by the dependency.

aura-logging format

The current section describes the process for writing operational logs by Aura components and the defined fields and levels.

• File format: JSON
  • If possible, each input in a log file might be a plain JSON object
• What should be logged in each level:
  • DEBUG LEVEL:
    • in/out of each step in a server
    • Incoming requests in a server
    • DB access
    • Health-check requests
    • Any other thing interesting for the developer
  • INFO LEVEL:
    • Outgoing responses in a server
    • Calls to external APIs (see HTTP requests below)
    • Message pushed to queues
    • Bot: NLP resolution
    • Bot: after user authentication, logs user’s data
  • WARN LEVEL:
    • A non blocking error or special situation in the current request
  • ERROR:
    • Outgoing error responses in a server
    • Error responses from external APIs (see HTTP requests below)
  • FATAL:
    • If server is closed

Fields names

• Fields marked in bold are mandatory
• Fields marked in italics are optional

Common

All logs in the system must count on the following list of fields:

All logs in the system could count with the following field:

Specific cases

Outgoing server response (INFO and ERROR)

Examples

• Successful response

{
    "time": "2019-04-05T11:51:09.325Z",
    "lvl": "INFO",
    "corr": "9c83c5d8-f3b5-4074-b475-28e2f528dd50",
    "userId": "123456677890",
    "auraId": "9c83c5d8-f3b5-4074-b475-28e2f528dd50",
    "auraIdGlobal ": "12344556778900 asdf3455",
    "channelId ": "f110f872-5d99-4839-b950-452847f1e59a",
    "version ": "8.2.1",
    "module ": "aura-users-controller",
    "msg ": "Get user by auraid",
    "drt ": 45,
    "status": 200,
    "path": "/users/123456677890",
    "method": "GET"
}

• Error response

{
    "time": "2019-04-05T11:51:09.325Z",
    "lvl": "ERROR",
    "corr": "9c83c5d8-f3b5-4074-b475-28e2f528dd50",
    "userId": "123456677890",
    "auraId": "9c83c5d8-f3b5-4074-b475-28e2f528dd50",
    "auraIdGlobal ": "12344556778900 asdf3455",
    "channelId ": "f110f872-5d99-4839-b950-452847f1e59a",
    "version ": "8.2.1",
    "module ": "aura-users-controller",
    "msg ": "AuraId does not exist",
    "drt ": 45,
    "status": 404,
    "path": "/users/123456677890",
    "method": "GET"
}

Error cases

HTTP requests and responses

This type is used both at the request and at the response. At the response it has more fields.

Examples

• Request

 {
     "time": "2019-04-05T11:51:09.325Z",
    "lvl": "INFO",
    "module": "aura-http-monkey-patcher",
    "domain": "localhost",
    "method": "POST",
    "path": "/deployments/deployment_bot_gpt-35-turbo/chat/completions?",
    "corr": "no-correlator",
    "version": "8.5.0",
    "app": "aura-gateway-api",
    "host": "mac-XQM577TDV0"
}

• Successful response

{
    "time": "2019-04-05T11:51:09.325Z",
    "lvl": "INFO",
    "corr": "9c83c5d8-f3b5-4074-b475-28e2f528dd50",
    "method": "GET",
    "domain": "api.global-int.baikalplatform.com",
    "path": "/userprofile/v3/users/123456677890",
    "version ": "8.2.1",
    "module ": "subscriptions-service",
    "msg ": "User profile retrieved",
    "origin": "10.0.0.1",
    "drt ": 45,
    "status": 200
}

• Error response

{
    "time": "2019-04-05T11:51:09.325Z",
    "lvl": "INFO",
    "corr": "9c83c5d8-f3b5-4074-b475-28e2f528dd50",
    "method": "GET",
    "domain": "api.global-int.baikalplatform.com",
    "path": "/userprofile/v3/users/123456677890",
    "version ": "8.2.1",
    "module ": "subscriptions-service",
    "msg ": "User profile cannot be retrieved",
    "origin": "10.0.0.1",
    "drt ": 45,
    "status": 403,
    "error": "{\"code\":\"PERMISSION_DENIED\",\"message\":\"Client does not have sufficient permission\"}"
}

Aura Bot

In aura-bot, the outgoing response message of the server should include these fields:

Aura NLP

In Aura NLP, the outgoing response message of the server should include these fields:

Logging levels and usages

Correlator policy

The correlator property in the log traces (corr) is mandatory in all levels but DEBUG, even though it is also highly recommended in that level.

We can use a correlator passed by in the original request (from other component), and we will use the same correlator in requests to other components (that allows them) in order to keep a cross-component correlator (the same correlator is used in the all the request-response flow, involving several APIs/servers/components).

If the correlator is not passed by the component creating the request, a new random correlator is generated at the beginning of the flow and is used from then on (even in requests to other components).

The correlator is used to relate all operations done in a request-response flow, that is all things done from the moment when the user starts the request untilaura-bot sends the last response (all operations logged must have the same corr).

There are a couple of exceptions to the last rule, as we are not able to get a correlator in all cases (some of them within a request-response flow, others outside it). Some special values are defined to know in which case the log trace is:

⚠️ Note: Do not abuse of the use of no-correlator, when the developer is lazy enough to get the current request-response correlator, and prefers to set no-correlator to avoid the bug detection when null or undefined. no-correlator means that it is impossible to get the correlator.

Standard logs

The log id must be:

• The name of the class, if we are writing a class:

// to class AuraBridgeFlow
const logger: AuraLog = new AuraLog('aura-bridge-flow');

• The name of the file, if we are writing an utility file:

// to dialog whatsapp-utilities file
const logger: AuraLog = new AuraLog('whatsapp-utilities');

• The dialog identifier if we are writing a dialog:

// to dialog DisambiguationDialog
const logger: AuraLog = new AuraLog(DisambiguationDialog.id);

Define the log outside the class to avoid attacks:

const logger: AuraLog = new AuraLog('aura-bridge-flow');

export class AuraBridgeFlow {
    ...
}

In the dialogs, it is convenient to use this standard: [${Dialog.id} dialog]

logger.debug({ msg: `[${DisambiguationDialog.id} dialog] Started`, corr });

You can include an object as a string key to get more information about the case. In this scenario, avoid including very large objects to precent blocking the pods due to logs writing.

logger.info({ msg: 'Try to upload and validate attachments', fromId: from, auraId: auraUser.auraId, corr });