npm package: @financial-times/n-serverless-logger
Description: Logger for serverless applications.
Author: Adam Braimbridge
Latest version: 0.5.1
Deprecated: 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

<img align="right" src="https://user-images.githubusercontent.com/224547/36733099-72e17bb8-1bc7-11e8-9385-b2708774811a.png">

# 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:

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

Otherwise, if you're using ES5/CommonJS:

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

## Usage

```js
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](https://financialtimes.splunkcloud.com).

![The event in Splunk](https://user-images.githubusercontent.com/11544418/59762443-30e7ff80-928f-11e9-9ceb-85323ebd7bb0.png)

### 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](https://financialtimes.splunkcloud.com) 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.

```javascript
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 | <code>{ event: string; [key: string]: any } \| string</code> | The event to log |

Sends a log with the level set to `DEBUG`

#### `logger.info(message)`

| Param   | Type                                                         | Description      |
| ------- | ------------------------------------------------------------ | ---------------- |
| message | <code>{ event: string; [key: string]: any } \| string</code> | The event to log |

Sends a log with the level set to `INFO`

#### `logger.warn(message)`

| Param   | Type                                                         | Description      |
| ------- | ------------------------------------------------------------ | ---------------- |
| message | <code>{ event: string; [key: string]: any } \| string</code> | The event to log |

Sends a log with the level set to `WARN`

#### `logger.error(message)`

| Param   | Type                                                         | Description      |
| ------- | ------------------------------------------------------------ | ---------------- |
| message | <code>{ event: string; [key: string]: any } \| string</code> | 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 | <code>Object</code> | 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

```javascript
logger.withTimestamps = false;
```

## Testing

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

```javascript
/* 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`](https://docs.aws.amazon.com/lambda/latest/dg/nodejs-prog-model-context.html#nodejs-prog-model-context-properties) by default). This means flushing logs has a negative impact on your user-facing latency.
-   If the property [`context.callbackWaitsForEventLoop`](https://docs.aws.amazon.com/lambda/latest/dg/nodejs-prog-model-context.html#nodejs-prog-model-context-properties) 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.