This package has been deprecated

Author message:

n-serverless-logger is no longer supported. It will get security patches up until 2023-10-20. You should migrate to Reliability Kit Logger before this date https://github.com/Financial-Times/dotcom-reliability-kit/tree/main/packages/logger

@financial-times/n-serverless-logger

n-serverless-logger

Logger for serverless applications.

• In a development environment, you want to log to the console — not to Splunk.

  • (You don't want development/test logs mixing with the production logs in Splunk.)

• In a production environment, you want to log to Splunk — and not to the console.

  • (In lambda land, if you log to the console, it's added to the CloudWatch logs, which costs £££.)

So: This code will behave differently depending on the environment:

If you're using ES6:

import logger from '@financial-times/n-serverless-logger';

Otherwise, if you're using ES5/CommonJS:

const logger = require('@financial-times/n-serverless-logger').default;

Usage

const logger = require('@financial-times/n-serverless-logger').default;

module.exports.handler = async () => {
	logger.info({
		event: 'EVENT_RECEIVED',
		message: 'I just ran.',
	});

	await logger.flush();

	return {
		statusCode: 200,
		body: 'OK',
	};
};

If either SPLUNK_HEC_URL or SPLUNK_HEC_TOKEN environment variables are unset, running this function will log to the console.

INFO: EVENT_RECEIVED message='I just ran.'

If both those environment variables are set it will not log to console, and instead send the logs to Splunk.

Requirements

If you add these environment variables to your development or production environment, it'll send data to Splunk. It won't send data to Splunk from a CircleCI environment, even if you've set the Splunk env vars.

SPLUNK_HEC_TOKEN=********-****-****-****-***********
SPLUNK_HEC_URL=https://http-inputs-financialtimes.splunkcloud.com/services/collector/event
SPLUNK_LOG_LEVEL=INFO

What is logger.flush()?

We could make a separate call to the Splunk API for every single log, but it's better to save all the logs to a buffer, and then send that buffer of logs to Splunk in a single API call.

So logger.info(), logger.warn(), (and so on) all just save the log to a buffer; they're not sent to Splunk until you call logger.flush().

Note: logger.flush() is an asynchronous function. If you do not wait for it to resolve before completing your lambda’s excecution your logs may not make it to Splunk.

Querying Splunk

Your logs should be available in Splunk using the following query, substituting <lambda-name> with the name of your lambda.

index="heroku" source="lambda:<lambda-name>"

Using context

You can use the setContext() function to add properties to your logger that will be appended to any logs thereafter. This is useful if, e.g., you want to log the function request ID.

Clear the context with clearContext() in cases where your logger instance is likely to be shared between different invocations that happen to run on the same container.

logger.setContext({
	location: 'space',
});

logger.info({
	event: 'BIG_BANG',
});

// Sends a message to Splunk: {event: 'BIG_BANG', context: { location: 'space' }}
await logger.flush();

// prevents given context information appearing in subsequent splunk logs
logger.clearContext();

API

logger.debug(message)

Param	Type	Description
message	{ event: string; [key: string]: any } | string	The event to log

Sends a log with the level set to DEBUG

logger.info(message)

Param	Type	Description
message	{ event: string; [key: string]: any } | string	The event to log

Sends a log with the level set to INFO

logger.warn(message)

Param	Type	Description
message	{ event: string; [key: string]: any } | string	The event to log

Sends a log with the level set to WARN

logger.error(message)

Param	Type	Description
message	{ event: string; [key: string]: any } | string	The event to log

Sends a log with the level set to ERROR

logger.flush() => Promise

Sends stored logs to splunk

Note: logger.flush() is an asynchronous function. If you do not wait for it to resolve before completing your lambda’s excecution your logs may not make it to Splunk.

logger.setContext(context)

Param	Type	Description
context	Object	An object of values that will be included in subsequent logs

Includes a context value on any subsequent logs. Can be cleared with logger.clearContext()

logger.clearContext()

Stops including context objects that were previously set using logger.setContext()

Timestamps

By default, timestamps are logged with each event. Without timestamps, Splunk's inferred times are likely to be incorrect due to way n-serverless-logger batches logs to send asynchronously.

Timestamps can be disabled by setting the withTimestamps property to false

logger.withTimestamps = false;

Testing

Here's an example of testing n-serverless-logger from an application (using Jest)

/* global expect,jest */

const logger = require('@financial-times/n-serverless-logger').default;
const loggerSpy = jest.spyOn(logger, 'log');

const lambdaTester = require('lambda-tester');
const receiver = require('../../functions/receiver');

describe('functions/receiver', () => {
	test('should log to console', () => {
		const expectedData = { Such: 'Synergy', Very: 'Engagement' };
		return lambdaTester(receiver.handler)
			.event({ Fake: true })
			.expectResult(() => {
				expect(loggerSpy).toHaveBeenCalledWith(expectedData, 'INFO');
			});
	});
});

Downsides/Caveats

• The lambda execution will not finish until logs are flushed to the Splunk HEC, this could add additional cost to the lambda execution if the Splunk HEC response is slow.
• Relating to the above point, if using API Gateway -> Lambda integration, the response will not be returned to the client until the event loop is empty (context.callbackWaitsForEventLoop = true by default). This means flushing logs has a negative impact on your user-facing latency.
• If the property context.callbackWaitsForEventLoop is set to false, then the flush call must happen before results are returned, else the lambda will freeze before flushing to the HEC. This property is sometimes needed when using libraries which run background tasks, such as database connection libraries.
• A different solution is required for logs which need redundancy in the event of HEC failure, as they will be logged to CloudWatch logs and not reach Splunk.