Merge d0b2dd8 into 3c8e2bc

.travis.yml

@@ -2,3 +2,5 @@ language: node_js
 node_js:
   - "6"
   - "4.4"
+script:
+  - npm run ci

README.md

@@ -1,5 +1,11 @@
+
+
 # olog
-Opinionated Logging for Node.js - forces prescriptive, disciplined, structured logging.
+[![Build Status](https://travis-ci.org/Nordstrom/olog-node.svg)](https://travis-ci.org/Nordstrom/olog-node) [![Coverage Status](https://coveralls.io/repos/github/Nordstrom/olog-node/badge.svg)](https://coveralls.io/github/Nordstrom/olog-node) [![Standard - JavaScript Style Guide](https://img.shields.io/badge/code%20style-standard-brightgreen.svg)](http://standardjs.com/)
+
+
+Opinionated Logging for Node.js - forces prescriptive, disciplined, structured logging.  This is logging based on predefined [Schemas]
+(SCHEMAS.md) with default fields.  Schema names, fields, and message formatting all have defaults but can all be configured.
 
 ## Install
 Install with:
@@ -61,28 +67,37 @@ Outputs:
 
 ## API
 
-* **[olog (options)](#olog-options)**
+* **[record](#record)**
+* **[olog (module\[, defaults\])](#olog-module-defaults)**
 * **[log.config (options)](#logconfig-options)**
 * **[log.debug (record)](#logdebug-record)**
 * **[log.info (record)](#loginfo-record)**
 * **[log.warn (record)](#logwarn-record)**
 * **[log.error (record)](*logerror-record)**
-* **[log.serverDebug (record)](#logserverDebug-record)**
-* **[log.serverInfo (record)](#logserverInfo-record)**
-* **[log.serverWarn (record)](#logserverWarn-record)**
-* **[log.serverError (record)](#logserverError-record)**
-* **[log.clientDebug (record)](#logclientDebug-record)**
-* **[log.clientInfo (record)](#logclientInfo-record)**
-* **[log.clientWarn (record)](#logclientWarn-record)**
-* **[log.clientError (record)](#logclientError-record)**
-* **[log.httpApiStart (record)](#loghttpApiStart-record)**
-* **[log.httpApiStop (record)](#loghttpApiStop-record)**
-* **[log.httpUiStart (record)](#loghttpUiStart-record)**
-* **[log.httpUiStop (record)](#loghttpUiStop-record)**
-* **[log.httpApiSend (record)](#loghttpApiSend-record)**
-* **[log.httpApiReceive (record)](#loghttpApiReceive-record)**
-* **[log.eventStart (record)](#logeventStart-record)**
-* **[log.eventStop (record)](#logeventStop-record)**
+* **[log.serverDebug (record)](#logserverdebug-record)**
+* **[log.serverInfo (record)](#logserverinfo-record)**
+* **[log.serverWarn (record)](#logserverwarn-record)**
+* **[log.serverError (record)](#logservererror-record)**
+* **[log.clientDebug (record)](#logclientdebug-record)**
+* **[log.clientInfo (record)](#logclientinfo-record)**
+* **[log.clientWarn (record)](#logclientwarn-record)**
+* **[log.clientError (record)](#logclienterror-record)**
+* **[log.httpApiStart (record)](#loghttpapistart-record)**
+* **[log.httpApiStop (record)](#loghttpapistop-record)**
+* **[log.httpUiStart (record)](#loghttpuistart-record)**
+* **[log.httpUiStop (record)](#loghttpuistop-record)**
+* **[log.httpApiSend (record)](#loghttpapisend-record)**
+* **[log.httpApiReceive (record)](#loghttpapireceive-record)**
+* **[log.eventStart (record)](#logeventstart-record)**
+* **[log.eventStop (record)](#logeventstop-record)**
+
+### record
+Type: `Object`
+
+Log record used for all logging functions.  This undergoes the following transformations during logging:
+* Generates message field based on the messageFormatter for the given schema.
+* Filters and orders fields based on configured fields for the schema (see [log.config (options)](#logconfig-options)).  Only configured fields are output, and fields are output in the order they are configured.
+
 
 ### olog (module[, defaults])
 Factor function that creates a new logger.  It makes it easy to require and create a logger for a module.
@@ -101,17 +116,17 @@ Allows you to provide module-level defaults for any of the log record properties
 
 ```js
 // component name
-const log = require('my-module')  
+const log = require('olog')('my-module')  
 
 or
 
 // generates component name
-const log = require(module)
+const log = require('olog')(module)
 
 or
 
 // applies record defaults
-const log = require(module, {
+const log = require('olog')(module, {
   category: 'Shopping Cart',
   transaction: 'UpdateCart'
 })
@@ -125,62 +140,163 @@ Type: `Object`
 
 ##### options.application
 Type: `String`
-Environment Variable: `OLOG_APPLICATION`
+
+Name or ID of the application.  Set here or with Environment Variable `OLOG_APPLICATION`.
 
 ##### options.environment
 Type: `String`
-Environment Variable: `OLOG_ENVIRONMENT`
 
-##### options.level  (process.env.OLOG_LEVEL)
-Type: `String`
+Name or ID of the deployed environment.  Set here or with Environment Variable `OLOG_ENVIRONMENT`.
+
+##### options.level
+Type: `String` one of `debug`, `info`, `warn`, `error` Default: `info`
 Environment Variable: `OLOG_LEVEL`
 
+Name of log level enabled for this application.  Set here or with Environment Variable `OLOG_LEVEL`.
+
 ##### options.stream
-Type: `Stream`
+Type: `Stream` Default: process.stdout
 
-##### options.messageTemplates
-Type: `Object`
+Writable stream to which log records are written.  Records are output in UTF8 stringified JSON format.
+
+##### options.fields
+Type: `Object` Default:
+```js
+{
+  serverDebug: ['time', 'message', 'level', 'schema', 'version', 'application', 'environment', 'host', 'pid', 'component',    'transaction', 'trace', 'annotations', 'extensions']
+  serverInfo: ['time', 'message', 'level', 'schema', 'version', 'application', 'environment', 'host', 'pid', 'component', 'transaction', 'trace', 'annotations', 'extensions']
+  serverWarn: ['time', 'message', 'level', 'schema', 'version', 'application', 'environment', 'host', 'pid', 'component', 'transaction', 'trace', 'annotations', 'extensions']
+  serverError: ['time', 'message', 'level', 'schema', 'version', 'application', 'environment', 'host', 'pid', 'component', 'transaction', 'trace', 'annotations', 'extensions', 'exception']
+  clientDebug: ['time', 'message', 'level', 'schema', 'version', 'application', 'environment', 'host', 'pid', 'component', 'transaction', 'trace', 'annotations', 'extensions', 'uri', 'userAgent', 'userAuth']
+  clientInfo: ['time', 'message', 'level', 'schema', 'version', 'application', 'environment', 'host', 'pid', 'component', 'transaction', 'trace', 'annotations', 'extensions', 'uri', 'userAgent', 'userAuth']
+  clientWarn: ['time', 'message', 'level', 'schema', 'version', 'application', 'environment', 'host', 'pid', 'component', 'transaction', 'trace', 'annotations', 'extensions', 'uri', 'userAgent', 'userAuth']
+  clientError: ['time', 'message', 'level', 'schema', 'version', 'application', 'environment', 'host', 'pid', 'component', 'transaction', 'trace', 'annotations', 'extensions', 'uri', 'userAgent', 'userAuth', 'exception']
+  httpApiStart: ['time', 'message', 'level', 'schema', 'version', 'application', 'environment', 'host', 'pid', 'component', 'transaction', 'trace', 'annotations', 'extensions', 'route', 'method', 'uri', 'requestHeaders', 'requestCookies', 'requestBodyString', 'requestBodyMap', 'requestBodyObject', 'referer', 'userAgent']
+  httpApiStop: ['time', 'message', 'level', 'schema', 'version', 'application', 'environment', 'host', 'pid', 'component', 'transaction', 'trace', 'annotations', 'extensions', 'route', 'method', 'uri', 'requestHeaders', 'requestCookies', 'requestBodyString', 'requestBodyMap', 'requestBodyObject', 'referer', 'userAgent', 'duration', 'responseCode', 'responseHeaders', 'responseCookies', 'responseBodyString', 'responseBodyMap', 'responseBodyObject']
+  httpUiStart: ['time', 'message', 'level', 'schema', 'version', 'application', 'environment', 'host', 'pid', 'component', 'transaction', 'trace', 'annotations', 'extensions', 'route', 'method', 'uri', 'requestHeaders', 'requestCookies', 'requestBodyString', 'requestBodyMap', 'requestBodyObject', 'referer', 'userAgent']
+  httpUiStop: ['time', 'message', 'level', 'schema', 'version', 'application', 'environment', 'host', 'pid', 'component', 'transaction', 'trace', 'annotations', 'extensions', 'route', 'method', 'uri', 'requestHeaders', 'requestCookies', 'requestBodyString', 'requestBodyMap', 'requestBodyObject', 'referer', 'userAgent', 'duration', 'responseCode', 'responseHeaders', 'responseCookies', 'responseBodyString', 'responseBodyMap', 'responseBodyObject']
+  httpApiSend: ['time', 'message', 'level', 'schema', 'version', 'application', 'environment', 'host', 'pid', 'component', 'transaction', 'trace', 'annotations', 'extensions', 'api', 'method', 'uri', 'requestHeaders', 'requestCookies', 'requestBodyString', 'requestBodyMap', 'requestBodyObject']
+  httpApiReceive: ['time', 'message', 'level', 'schema', 'version', 'application', 'environment', 'host', 'pid', 'component', 'transaction', 'trace', 'annotations', 'extensions', 'api', 'method', 'uri', 'requestHeaders', 'requestCookies', 'requestBodyString', 'requestBodyMap', 'requestBodyObject', 'resonseCode', 'responseHeaders', 'responseCookies', 'responseBodyString', 'responseBodyMap', 'responseBodyObject', 'duration'],
+  eventStart: ['time', 'message', 'level', 'schema', 'version', 'application', 'environment', 'host', 'pid', 'component', 'transaction', 'trace', 'annotations', 'extensions', 'originatedAt', 'topic', 'partition', 'key', 'attributes'],
+  eventStop: ['time', 'message', 'level', 'schema', 'version', 'application', 'environment', 'host', 'pid', 'component', 'transaction', 'trace', 'annotations', 'extensions', 'originatedAt', 'topic', 'partition', 'key', 'attributes', 'duration', 'elapsed']
+}
+```
+This determines allowed output fields for each schema along with the order of output for each field.
+
+##### options.schemaNames
+Type: `Object` Default:
+```js
+{
+  serverDebug: 'SERVER-Debug',
+  serverInfo: 'SERVER-Info',
+  serverWarn: 'SERVER-Warn',
+  serverError: 'SERVER-Error',
+  clientDebug: 'CLIENT-Debug',
+  clientInfo: 'CLIENT-Info',
+  clientWarn: 'CLIENT-Warn',
+  clientError: 'CLIENT-Error',
+  httpApiStart: 'HTTP-API-Start',
+  httpApiStop: 'HTTP-API-Stop',
+  httpUiStart: 'HTTP-UI-Start',
+  httpUiStop: 'HTTP-UI-Stop',
+  httpApiSend: 'HTTP-API-Send',
+  httpApiReceive: 'HTTP-API-Receive',
+  eventStart: 'EVENT-Start',
+  eventStop: 'EVENT-Stop'
+}
+```
+
+Logged name of each schema based on function name.
+
+##### options.messageFormatters
+Type: `Object` Default:
+```js
+{
+  serverDebug: (r) => { return `[${r.schema}] ${r.transaction}: ${r.message}` },
+  serverInfo: (r) => { return `[${r.schema}] ${r.transaction}: ${r.message}` },
+  serverWarn: (r) => { return `[${r.schema}] ${r.transaction}: ${r.message}` },
+  serverError: (r) => { return `[${r.schema}] ${r.transaction}: ${r.message}: ${r.exception}` },
+  clientDebug: (r) => { return `[${r.schema}] ${r.transaction}: ${r.message}` },
+  clientInfo: (r) => { return `[${r.schema}] ${r.transaction}: ${r.message}` },
+  clientWarn: (r) => { return `[${r.schema}] ${r.transaction}: ${r.message}` },
+  clientError: (r) => { return `[${r.schema}] ${r.transaction}: ${r.message}: ${r.exception}` },
+  httpApiStart: (r) => { return `[${r.schema}] ${r.transaction}: ${r.route} for ${r.trace}` },
+  httpApiStop: (r) => { return `[${r.schema}] ${r.transaction}: ${r.route}[${r.responseCode}] in ${r.duraton}ms for ${r.trace}` },
+  httpUiStart: (r) => { return `[${r.schema}] ${r.transaction}: ${r.route} for ${r.trace}` },
+  httpUiStop: (r) => { return `[${r.schema}] ${r.transaction}: ${r.route}[${r.responseCode}] in ${r.duraton}ms for ${r.trace}` },
+  httpApiSend: (r) => { return `[${r.schema}] ${r.transaction}: ${r.api} (${r.method}:${r.uri}) for ${r.trace}` },
+  httpApiReceive: (r) => { return `[${r.schema}] ${r.transaction}: ${r.api} (${r.method}:${r.uri})[${r.responseCode}] in ${r.duraton}ms for ${r.trace}` }
+},
+
+```
+
+Configure message formatters for each schema.  This Object contains properties following this syntax:
+`<schemaFunctionName>: (record) => { return <formatted message> }`.  
+For example:
+
+```js
+{
+  serverInfo: (record) => { return `${record.transaction} - DETAILS: ${record.message}` },
+  httpApiStop: (record) => { return `${record.route}[${record.responseCode}]` }
+}
+```
 
 ### log.debug (record)
-Alias for [log.serverDebug (record)](#logserverDebug-record).
+Alias for [log.serverDebug (record)](#logserverdebug-record).
 
 ### log.info (record)
-Alias for [log.serverInfo (record)](#logserverInfo-record).
+Alias for [log.serverInfo (record)](#logserverinfo-record).
 
 ### log.warn (record)
-Alias for [log.serverWarn (record)](#logserverWarn-record).
+Alias for [log.serverWarn (record)](#logserverwarn-record).
 
 ### log.error (record)
-Alias for [log.serverError (record)](#logserverError-record).
+Alias for [log.serverError (record)](#logservererror-record).
 
 ### log.serverDebug (record)
+Logs [record](#record) using serverDebug (SERVER-Debug) schema.
 
 ### log.serverInfo (record)
+Logs [record](#record) using serverInfo (SERVER-Info) schema.
 
 ### log.serverWarn (record)
+Logs [record](#record) using serverWarn (SERVER-Warn) schema.
 
 ### log.serverError (record)
+Logs [record](#record) using serverError (SERVER-Error) schema.
 
 ### log.clientDebug (record)
+Logs [record](#record) using clientDebug (CLIENT-Debug) schema.
 
 ### log.clientInfo (record)
+Logs [record](#record) using clientInfo (CLIENT-Info) schema.
 
 ### log.clientWarn (record)
+Logs [record](#record) using clientWarn (CLIENT-Warn) schema.
 
 ### log.clientError (record)
+Logs [record](#record) using clientError (CLIENT-Error) schema.
 
 ### log.httpApiStart (record)
+Logs [record](#record) using httpApiStart (HTTP-API-Start) schema.
 
 ### log.httpApiStop (record)
+Logs [record](#record) using httpApiStop (HTTP-API-Stop) schema.
 
 ### log.httpUiStart (record)
+Logs [record](#record) using httpUiStart (HTTP-UI-Start) schema.
 
 ### log.httpUiStop (record)
+Logs [record](#record) using httpUiStop (HTTP-UI-Stop) schema.
 
 ### log.httpApiSend (record)
+Logs [record](#record) using httpApiSend (HTTP-API-Send) schema.
 
 ### log.httpApiReceive (record)
+Logs [record](#record) using httpApiReceive (HTTP-API-Receive) schema.
 
 ### log.eventStart (record)
+Logs [record](#record) using eventStart (EVENT-Start) schema.
 
 ### log.eventStop (record)
+Logs [record](#record) using eventStop (EVENT-Stop) schema.

SCHEMAS.md

@@ -0,0 +1,91 @@
+# Logging Schemas
+The following provides definitions of the Logging Schemas with defaults fields for each.
+
+## Core Fields
+These fields are common to all Schemas.
+
+|Field|Type|Description|
+|-----|----|-----------|
+|**time**|Date|Generated date/time at which the log event was generated. The Timestamp should is expressed in UTC ISO 8601 format.|
+|**message**|String|A summary message that contains other elements of data in the log (i.e. `HTTP-API-Stop on CreateProduct (POST:/v2/products) [200] in 138ms`).  The purpose of this is to provide a condensed view of logs.  Tools like Kibana, let you select the fields to show in the log view.  Having a summary message allows a single line, condensed view rather than the whole record.  This message is generated based on the messageFormatter for each schema.|
+|**level**|String|Log level string (i.e. debug, info, warn, error).  This is generated based on the schema function used.|
+|**schema**|String|Case insensitive string identifier that identifies the schema of the log message.|
+|**version**|Number|Integer-based version number that.  Current: `3`|
+|**application**|String|Unique string identifying the application generating the log events.  This is set in the [log.config (options)](README.md#logconfig-options) or `OLOG_APPLICATION` environment variable.|
+|**environment**|String|String field that is used as the name of the environment in which the application is currently executing.  This is set in [log.config (options)](README.md#logconfig-options) or `OLOG_ENVIRONMENT` environment variable.|
+|**host**|String|Name or id of host / server instance.  This is automatically set by olog.|
+|**pid**|String|ID of Process.  This is automatically set by olog.|
+|**component**|String|String field to record the module or component in which logging occurs.  This is set based on the module param of [olog(module\[, defaults\])](README.md#olog-module-defaults).|
+|**category**|String|String field that can be used to functionally categorize trace data (e.g. "Outfits-CacheMiss", "Outfits-CacheHit", ...).|
+|**transaction**|String|Custom name for the type of transaction to which this log belongs. (e.g. CreateProduct, GetPrice, UpdateSkuDb, etc).  This is helpful for correlating logs across a given type of transaction.|
+|**trace**|String|Enables correlation of log data across applications for a specific request or transaction.|
+|**extensions**|Object|Custom metadata as an Object type (JSON, Graph, etc).|
+
+## SERVER-Debug
+**level:** `debug`
+
+Debug level logs that occur on the server.  Core Fields only.
+
+## SERVER-Info
+**level:** `info`
+
+Info level logs that occur on the server.  Core Fields only.
+
+## SERVER-Warn
+**level:** `warn`
+
+Warning level logs that occur on the server.  Core Fields only.
+
+## SERVER-Error
+**level:** `error`
+
+Error level logs that occur on the server.
+
+|Field|Type|Description|
+|-----|----|-----------|
+|**exception**|String|Field to record the exception that happened, along with the relevant stack trace.|
+
+## CLIENT-Debug
+**level:** `debug`
+
+Debug level logs that occur on the client.
+
+|Field|Type|Description|
+|-----|----|-----------|
+|**uri**|String|Uri string.|
+|**userAgent**|String|User agent string used to identify browser & device.|
+|**userAuth**|String|Field to record the user auth state.|
+
+## CLIENT-Info
+**level:** `info`
+
+Info level logs that occur on the client.
+
+|Field|Type|Description|
+|-----|----|-----------|
+|**uri**|String|Uri string.|
+|**userAgent**|String|User agent string used to identify browser & device.|
+|**userAuth**|String|Field to record the user auth state.|
+
+## CLIENT-Warn
+**level:** `warn`
+
+Warning level logs that occur on the client.
+
+|Field|Type|Description|
+|-----|----|-----------|
+|**uri**|String|Uri string.|
+|**userAgent**|String|User agent string used to identify browser & device.|
+|**userAuth**|String|Field to record the user auth state.|
+
+## CLIENT-Error
+**level:** `error`
+
+Error level logs that occur on the client.
+
+|Field|Type|Description|
+|-----|----|-----------|
+|**exception**|String|Records the exception that happened, along with the relevant stack trace.|
+|**uri**|String|Uri string.|
+|**userAgent**|String|User agent string used to identify browser & device.|
+|**userAuth**|String|Field to record the user auth state.|

cli.js

@@ -0,0 +1,5 @@
+'use strict'
+
+const log = require('./olog.js')(module)
+
+log.describeFields()