Skip to content

Commit

Permalink
feat: ECS logging
Browse files Browse the repository at this point in the history
  • Loading branch information
commenthol committed Oct 7, 2023
1 parent bfedcaf commit 2c14d64
Show file tree
Hide file tree
Showing 18 changed files with 723 additions and 34 deletions.
68 changes: 52 additions & 16 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -48,6 +48,7 @@ Fully typed with JSDocs and Typescript.
* [Handle node exit events](#handle-node-exit-events)
* [Logging HTTP requests](#logging-http-requests)
* [Logging Browser messages](#logging-browser-messages)
* [Logging in Elastic Common Schema (ECS)](#logging-in-elastic-common-schema-ecs)
* [License](#license)
* [Benchmarks](#benchmarks)
* [References](#references)
Expand Down Expand Up @@ -229,22 +230,22 @@ log.debug({ object: 1 }) // ...

> **NOTE:** Consider using a tool like [logrotate](https://github.com/logrotate/logrotate) to rotate the log-file or use a tool like [@vrbo/pino-rotating-file](https://www.npmjs.com/package/@vrbo/pino-rotating-file) to write to a rotating file stream.
| Option name | Setting | env | Type | Description |
| ------------ | -------------------- | ------- | ------- | -------------------------------------------- |
| level | DEBUG_LEVEL | _both_ | String | |
| namespaces | DEBUG | _both_ | String | |
| json | DEBUG_JSON | node | Boolean | |
| spaces | DEBUG_SPACES | node | Number | JSON spaces |
| splitLine | DEBUG_SPLIT_LINE | node | Boolean | split lines for pretty, debug like, output |
| timestamp | DEBUG_TIMESTAMP | node | String | Set null/iso/unix/epoch timestamp format |
| colors | DEBUG_COLORS | _both_ | Boolean | |
| stream | -- | node | Stream | output stream (defaults to `process.stderr`) |
| sonic | DEBUG_SONIC | node | Boolean | fast buffered writer |
| sonicLength | DEBUG_SONIC_LENGTH | node | number | min size of buffer in byte (default is 4096) |
| sonicFlushMs | DEBUG_SONIC_FLUSH_MS | node | number | flush after each x ms (default is 1000) |
| serializers | -- | _both_ | Object | serializers by keys |
| url | DEBUG_URL | browser | String | |
| toJson | -- | node | Function | custom json serializer |
| Option name | Setting | env | Type | Description |
| ------------ | -------------------- | ------- | -------- | -------------------------------------------- |
| level | DEBUG_LEVEL | _both_ | String | |
| namespaces | DEBUG | _both_ | String | |
| json | DEBUG_JSON | node | Boolean | |
| spaces | DEBUG_SPACES | node | Number | JSON spaces |
| splitLine | DEBUG_SPLIT_LINE | node | Boolean | split lines for pretty, debug like, output |
| timestamp | DEBUG_TIMESTAMP | node | String | Set null/iso/unix/epoch timestamp format |
| colors | DEBUG_COLORS | _both_ | Boolean | |
| stream | -- | node | Stream | output stream (defaults to `process.stderr`) |
| sonic | DEBUG_SONIC | node | Boolean | fast buffered writer |
| sonicLength | DEBUG_SONIC_LENGTH | node | number | min size of buffer in byte (default is 4096) |
| sonicFlushMs | DEBUG_SONIC_FLUSH_MS | node | number | flush after each x ms (default is 1000) |
| toJson | -- | node | Function | custom json serializer |
| serializers | -- | _both_ | Object | serializers by keys |
| url | DEBUG_URL | browser | String | |

### Serializers

Expand Down Expand Up @@ -580,6 +581,41 @@ npm run example

and open <http://localhost:3000>

## Logging in Elastic Common Schema (ECS)

debug-level supports logging in ECS format if case you use the ELK stack for log monitoring.

Per default err, req, res serializers are available.

```js
import { LogEcs } from 'debug-level'

const log = new LogEcs('foobar')

log.fatal(new Error('fatal')) // logs an Error at level FATAL
//> {"log":{"level":"FATAL","logger":"foobar","diff_ms":0},"message":"fatal","@timestamp":"2023-07-06T18:40:25.154Z","error":{"type":"Error","message":"fatal","stack_trace":"Error: fatal\\n at file:///logecs.js:6:11\\n at ModuleJob.run (node:internal/modules/esm/module_job:194:25)"}}
```

`httpLogs` as well as `logger` allow overwriting the standard `Log` class in order to use ECS logging.

```js
import { LogEcs, httpLogs } from 'debug-level'

const logHandler = httpLogs('my-pkg:http', { Log: LogEcs })

// use then e.g. in express app
app.use(logHandler)
```

```js
import { LogEcs, logger } from 'debug-level'

const log = logger('my-pkg:topic', { Log: LogEcs })

log.error(new Error('baam'))
```


## License

[MIT](./LICENSE)
Expand Down
7 changes: 6 additions & 1 deletion package.json
Original file line number Diff line number Diff line change
@@ -1,6 +1,6 @@
{
"name": "debug-level",
"version": "3.0.0",
"version": "3.1.0-0",
"description": "debug with levels",
"keywords": [
"debug",
Expand Down Expand Up @@ -29,6 +29,11 @@
"require": "./lib/serializers/index.cjs",
"types": "./types/serializers/index.d.ts"
},
"./ecs": {
"import": "./src/ecs/index.js",
"require": "./lib/ecs/index.cjs",
"types": "./types/ecs/index.d.ts"
},
"./package.json": "./package.json"
},
"main": "./lib/index.cjs",
Expand Down
15 changes: 11 additions & 4 deletions src/browserLogs.js
Original file line number Diff line number Diff line change
Expand Up @@ -16,14 +16,17 @@ function parseQuery (url) {
}

class Loggers {
constructor (maxSize = 100) {
constructor (opts) {
const { maxSize = 100 } = opts || {}

this.LogCls = opts?.Log || Log
this.cache = new MapLRU(maxSize)
}

get (name) {
let log = this.cache.get(name)
if (!log) {
log = new Log(name)
log = new this.LogCls(name)
this.cache.set(name, log)
}
return log
Expand All @@ -50,6 +53,7 @@ function parseJson (str) {
* @property {number} [maxSize=100] max number of different name loggers
* @property {boolean} [logAll=false] log everything even strings
* @property {boolean} [levelNumbers] log levels as numbers
* @property {Log} [Log] different extended Log class, e.g. LogEcs
*/

/**
Expand All @@ -60,8 +64,11 @@ function parseJson (str) {
*/
export function browserLogs (opts = {}) {
opts = Object.assign({ maxSize: 100, logAll: false, levelNumbers: false }, opts)
const log = opts.logAll ? new Log('debug-level:browser') : undefined
const loggers = new Loggers(opts.maxSize)

const LogCls = opts?.Log || Log
// @ts-expect-error
const log = opts.logAll ? new LogCls('debug-level:browser') : undefined
const loggers = new Loggers(opts)

return function _browserLogs (req, res) {
const query = req.query
Expand Down
101 changes: 101 additions & 0 deletions src/ecs/LogEcs.js
Original file line number Diff line number Diff line change
@@ -0,0 +1,101 @@
import { Log, stringify } from '../node.js'
import { ecsSerializers } from './serializers.js'

/**
* @typedef {(val: any, escFields: object) => void} EcsSerializer
* @typedef {import('../node.js').LogOptions & {serializers: Record<string, EcsSerializer>}} LogOptions
*/

/**
* Elastic Common Schema (ECS) compatible logger;
* See [field reference](https://www.elastic.co/guide/en/ecs/current/ecs-field-reference.html)
*/
export class LogEcs extends Log {
/**
* @param {string} name logger namespace
* @param {LogOptions} opts
*/
constructor (name, opts) {
const { serializers, ..._opts } = opts || {}
super(name, {
..._opts,
timestamp: 'iso'
})
this.serializers = { ...ecsSerializers, ...serializers }
this.toJson = toJson
}

/* c8 ignore next 18 */
_applySerializers (obj) {
const ecsObj = {}
for (const key in obj) {
const value = obj[key]
if (
Object.prototype.hasOwnProperty.call(obj, key) &&
value !== undefined
) {
if (this.serializers && this.serializers[key]) {
this.serializers[key](value, ecsObj)
} else {
ecsObj.extra = ecsObj.extra || {}
ecsObj.extra[key] = value
}
}
}
return ecsObj
}
}

LogEcs.serializers = ecsSerializers

function toJson (obj, serializers) {
const { level, time, name, msg, pid, hostname, diff, ...other } = obj

const ecsObj = {
log: {
level,
logger: name,
diff_ms: diff
},
message: msg,
'@timestamp': time,
process: pid ? { pid } : undefined,
host: hostname ? { hostname } : undefined
}

for (const key in other) {
const value = other[key]
if (
value === undefined ||
!Object.prototype.hasOwnProperty.call(other, key)
) {
continue
}
if (serializers[key]) {
serializers[key](value, ecsObj)
} else {
// add all other unknown fields to extra
ecsObj.extra = ecsObj.extra || {}
ecsObj.extra[key] = normToString(value)
}
}

return stringify(ecsObj)
}

/**
* elastic is picky on indexing types; for this all entries in e.g. extra are
* set to string to avoid any type collisions
* @param {any} val
* @returns {string}
*/
const normToString = (val) => {
switch (typeof val) {
case 'string':
return val
case 'number':
return String(val)
default:
return stringify(val)
}
}
4 changes: 4 additions & 0 deletions src/ecs/index.js
Original file line number Diff line number Diff line change
@@ -0,0 +1,4 @@
import { LogEcs } from './LogEcs.js'
import { ecsSerializers } from './serializers.js'

export { LogEcs, ecsSerializers }
110 changes: 110 additions & 0 deletions src/ecs/serializers.js
Original file line number Diff line number Diff line change
@@ -0,0 +1,110 @@
import { startTimeKey } from '../serializers/res.js'

const isNotObject = (any) => !any || typeof any !== 'object'

const ecsError = (err, ecsObj) => {
if (!(err instanceof Error)) {
return
}

const type =
Object.prototype.toString.call(err.constructor) === '[object Function]'
? err.constructor.name
: err.name

ecsObj.error = {
type,
message: err.message,
stack_trace: err.stack
}
}

const ecsClient = (req, ecsObj) => {
const ip = req.ip ? req.ip : req.socket?.remoteAddress
const port = req.socket?.remotePort
if (ip) {
ecsObj.client = {
ip,
port
}
}
}

const ecsUrl = (req, ecsObj) => {
const { originalUrl, url, headers } = req
const _url = originalUrl || url
if (!_url) return

const [path, query] = _url.split('?')
ecsObj.url = { path, query }

if (headers?.host) {
const [domain, port] = (headers.host || '').split(':')
ecsObj.url.domain = domain
if (port) {
ecsObj.url.port = Number(port)
}
}
}

const ecsReq = (req, ecsObj) => {
if (isNotObject(req)) {
return
}
ecsClient(req, ecsObj)

ecsUrl(req, ecsObj)

const { method, httpVersion } = req
if (!method) return

const {
cookie,
authorization,
'user-agent': userAgent,
...headers
} = req.headers

ecsObj.http = ecsObj.http || {}
ecsObj.http.request = {
id: typeof req.id === 'function' ? req.id() : req.id,
method,
version: httpVersion,
headers
}
ecsObj.user_agent = {
original: userAgent
}
}

const ecsRes = (res, ecsObj) => {
if (isNotObject(res)) {
return
}
const { statusCode } = res
if (!statusCode) return

const {
'proxy-authenticate': _1,
'set-cookie': _2,
'content-type': mimeType,
cookie,
...headers
} = res._headers || {}

ecsObj.http = ecsObj.http || {}
ecsObj.http.response = {
status_code: statusCode,
mime_type: mimeType,
headers
}
if (res[startTimeKey]) {
ecsObj.http.response.latency = Date.now() - res[startTimeKey]
}
}

export const ecsSerializers = {
err: ecsError,
req: ecsReq,
res: ecsRes
}
Loading

0 comments on commit 2c14d64

Please sign in to comment.