search

logdna / logger-node

A nodejs logger client for LogDNA
MIT License
34 stars 17 forks source link
lib

readme

Node.js library for logging to LogDNA

Coverage Status

Migrating From Other Versions

Previous versions of this client are still supported, but if you are upgrading to this version, please see our migration document for the differences between this version and prior versions.

Install

$ npm install @logdna/logger

Setup

Operation requires a LogDNA Ingestion Key. Without it, the client will not be able to post logs to the cloud. Please contact our support if you have questions about this setup process!

Usage

To use the client, create an instance, then call .log() or a convenience method.

const logdna = require('@logdna/logger')

const options = {
  app: 'myAppName'
, level: 'debug' // set a default for when level is not provided in function calls
}

const logger = logdna.createLogger('<YOUR INGESTION KEY>', options)

logger.log('This is an INFO statement', 'info')

logger.log('This will be a DEBUG statement, based on the default')

logger.log('This is an INFO statement with an options object', {
  level: 'info'
, meta: {
    somekey: 'Arbitrary message'
  , anotherkey: 'Another arbitrary message or data point'
  }
})

logger.info('This is an INFO statement using a convenience method')

// Objects can be logged, too, but they're just serialized
logger.info({
  message: 'Got some user data'
, userId: req.params.userId // This assumes `req.params` comes from some HTTP framework
})

// Just sets `level: 'error'` automatically
logger.error('An error was encountered while processing user data')

Logging Errors

Although the logger can accept an object as its "message", Error instances contain non-enumerable properties such that log.error(err) will not yield the expected results. To mitigate this, users can trap (or generate) errors, then expose the error properties as desired.

This example hardcodes some JSON to parse, but it could easily come from user input.

const input = '{"whoops": "This JSON is malformed because it\'s missing a closing quote}'
try {
  JSON.parse(input)
} catch (err) {
  log.error('JSON parse error while processing a string that should be JSON', {
    indexMeta: true // Makes `meta` searchable. See docs below.
  , meta: {
      name: err.name
    , message: err.message
    , stack: err.stack
    , input
    }
  })

  // OR, if the all the details aren't important, a more concise log could be this
  log.error(err.message, {
    meta: {
      message: 'JSON parse error during function xxx'
    , input
    }
  })
}

Default Log Levels

The client supports the following log levels by default. They are case-insensitive. Users may also add custom log levels.

Custom Log Levels

Users may provide an array of levels as a logger instantiation option. The levels value must be an array, and its values must be letters only. All level values are normalized to upper-case when sent to the LogDNA server, but their use in function calls is case-insensitive.

const {createLogger} = require('@logdna/logger')
const logger = createLogger(myKey, {
  levels: ['info', 'warn', 'critical', 'catastrophic']
})

logger.info('my text') // ok
logger.warn('some warning text') // ok
logger.catastrophic('OH NO!') // error
logger.log('OH NO!', 'critical') // ok
logger.log('We are crashing!', 'catastrophic') // ok

Convenience Methods

We have set up convenience methods that automatically set the log level appropriately, and are easy to read. If using custom log levels, then convenience methods will only be added for custom levels that also match the default log levels, e.g. log.info().

logger.trace(msg[, options])

logger.debug(msg[, options])

logger.info(msg[, options])

logger.warn(msg[, options])

logger.error(msg[, options])

logger.fatal(msg[, options])

Events

The Logger is an EventEmitter and will emit events rather than use promises or callbacks to communicate its progress. Listening to the events is optional, although an error listener is recommended.

Event: 'addMetaProperty'

Emitted when a meta property is successfully added. This meta property will be attached to each log message.

Event: 'cleared'

When all log lines have been sent to LogDNA, this event is emitted. If it emits after lines have successfully been sent, then the message will be 'All accumulated log entries have been sent'. If there were no lines to be sent (for example, if flush() was called proactively), then the message will be 'All buffers clear; Nothing to send'.

Event: 'error'

This event is emitted when an asynchronous error is encountered. Depending on the context, meta will contain different pieces of information about the error. If the error is retry-able, the error's message property will indicate that it's a "temporary" error to avoid confusion with hard errors.

Error while sending to LogDNA

Note: ignoreRetryableErrors is true by default, and will not emit errors when the retrying property in the metadata is true. To emit all errors regardless of retrying, set ignoreRetryableErrors: false.

The metadata for an error encountered during an HTTP call to LogDNA will have the following meta properties in the error.

Error while calling log()

When log() is called directly, or indirectly (via a convenience method), errors can be emitted if certain validations fail. If an invalid log level is provided, or if a bad data type is found for the options parameter, the meta property of the error will contain the following properties:

Error due to payloadStructure mismatch

When log() or agentLog() is called, the payloadStructure must be set appropriately. If it is not, an error is emitted. Keep in mind that agentLog() is reserved for LogDNA systems and is not intended for public usage.

Error for a 207 (partial success) response

If a 207 status code is received, this means that some of the lines failed to be ingested. An error event is emitted for each failed line and will have the following structure:

Event: 'removeMetaProperty'

This is emitted when a key (and implied value) are removed from the global meta object. If the key does not exist, then a warn event with the same signature will be emitted instead.

Event: 'send'

This event is emitted when a buffer is successfully sent to LogDNA. Since a buffer can contain many log entries, this event summarizes the activity. In a high throughput system where flushLimit is exceeded and multiple buffers are waiting to be sent, information like totalLinesReady and bufferCount help illustrate how much work is left to be done. Any buffers that have been queued will be sent one after another, ignoring any flush timer.

Event: 'warn'

This event is emitted when there is no log data provided to the log method, or when removeMetaProperty is called with an unrecognized key. For those cases, additional properties (apart from message) are included:

Warnings during log()

Warnings during agentLog()

Warnings during removeMetaProperty

API

createLogger(key[, options])

Returns a logging instance to use. flushLimit and flushIntervalMs control when the buffer is sent to LogDNA. The flushIntervalMs timer is only started after lines are logged, and the flushLimit is a size approximation based on the summation of .length properties of each log line. If the buffer size exceeds flushLimit, it will immediately send the buffer and ignore the flushIntervalMs timer. Otherwise, a timer will repeatedly flush the buffer every flushIntervalMs milliseconds, as long as the buffer contains log entries.

If indexMeta is false, then the metadata will still appear in LogDNA search, but the fields themselves will not be searchable. If this option is true, then meta objects will be parsed and searchable up to three levels deep. Any fields deeper than three levels will be stringified and cannot be searched. WARNING: When this option is true, your metadata objects across all types of log messages MUST have consistent types, or the metadata object may not be parsed properly!

shimProperties can be used to set up keys to look for in the options parameter of a log() call. If the specified keys are found in options, their key-values will be included the top-level of the final logging payload send to LogDNA.

payloadStructure is only for LogDNA's use in other parts of the system such as our logging agent. It is not intended to be used by public consumers, and it should be left to the default value.

For more information on the backoff algorithm and the options for it, see the Exponential Backoff Strategy section.

setupDefaultLogger(key[, options])

The same as createLogger(), except for that it creates a singleton that will be reused if called again. Users can call this multiple times, and the client package will maintain (create and/or return) the singleton.

Note that only the first call will instantiate a new instance. Therefore, any successive calls will ignore the provided parameters.

const logdna = require('@logdna/logger')

const logger = logdna.setupDefaultLogger('<YOUR KEY HERE>')
const sameLogger = logdna.setupDefaultLogger()

logger.agentLog(opts)

This method is for use exclusively by LogDNA, and is not intended for public logging.

logger.addMetaProperty(key, value)

This method adds a key-value to the global metadata, which is added to each log entry upon calling log(). Although meta can be set on instantiation, this method provides a way to update it on-the-fly.

If options.meta is also used in a log() call, the key-value pairs from the global meta will be merged with options.meta, and those new pairs will take precedence over any matching keys in the global metadata.

// This will use `meta` to track logs from different modules
const logger = createLogger('<YOUR API KEY>', {
  meta: {
    module: 'main.js' // Global default
  }
})

logger.debug('This is the main module') // Uses global meta

// ... elsewhere, in another file, perhaps
logger.info('I am in module1.js', {
  meta: {module: __filename} // Overrides global meta
})

logger.flush()

When flush is called, any messages in the buffer are sent to LogDNA. It's not necessary to call this manually, although it is useful to do so to ensure clean shutdown (see Best Practices). When log is called, it automatically starts a timer that will call flush, but it is idempotent and can be called at any time.

If log lines exist in the current buffer, it is pushed onto a send queue, and a new buffer is created. The send queue is processed and uploaded to LogDNA.

If no work needs to be done, the cleared event is immediately emitted.

logger.log(statement[, options])

Sends a string or object to LogDNA for storage. If the convenience methods are used, they call this function under the hood, so the options are the same. The only difference is that level is automatically set in the convenience methods.

logger.removeMetaProperty(key)

Attempts to remove the given key from the global meta data object. If the key is not found, warn is emitted.

How Log Lines are Sent to LogDNA

In default operation, when log functions are called, the line is added to a buffer to cut down on HTTP traffic to the server. The buffer is flushed every flushIntervalMs milliseconds or if the log line lengths grow beyond flushLimit.

When flush fires (or is called manually), the current buffer is put onto a send queue, and a new buffer is started. The send queue begins sending to LogDNA. It will continue to send without pausing or honoring flushIntervalMs as long as there are buffers in the send queue. When the send queue is empty, cleared is emitted.

Handling Errors

Exponential Backoff Strategy

When HTTP failures happen, if they are deemed "retryable" (non-user errors), then the client will pause for a short time before trying to resend. The algorithm it implements is an exponential backoff with a "jitter" strategy that uses random numbers statistically to spread out the wait times to avoid flooding.

The settings for baseBackoffMs and maxBackoffMs are used in this algorithm and serve as the lower and upper boundaries for the wait time.

These types of errors are blocking since they are related to timeouts and server errors. Logs will continue to buffer as normal, and if the HTTP calls becomes successful, they will begin to send immediately, and without pause.

Best Practices

const {createLogger} = require('@logdna/logger')
const {once} = require('events')
const process = require('process')

const logger = createLogger('This is not a real key and will cause an error')

logger.on('error', console.error)

function onSignal(signal) {
  logger.warn(`received signal ${signal} shutting down`, {meta: {signal}})
  shutdown().catch(() => {})
}

async function shutdown() {
  await once(logger, 'cleared')
}

process.on('SIGTERM', onSignal)
process.on('SIGINT', onSignal)

// For running this as a standalone example, an error will be shown due
// to the key being invalid, but it shows the signal handler message
// attempting to be sent for ingestion.
setTimeout(() => {
  process.kill(process.pid)
}, 1000)

Client Side

For logging from a browser, we recommend our @logdna/browser package which is designed for that purpose.

Bunyan Stream

For Bunyan Stream support, reference our logdna-bunyan module.

Winston Transport

For Winston support, reference our logdna-winston module.

Using with AWS Lambda

AWS Lambda relays stdout and stderr output from your function's code to CloudWatch, but you can easily set up a Logger instance as shown above to send logs to LogDNA instead. If you have existing code that uses console.log and console.error statements, you can also override these console methods to send output to LogDNA without changing your code:

'use strict'

const {once} = require('events')
const {createLogger} = require('@logdna/logger')

const options = {
  env: 'env'
, app: 'lambda-app'
, hostname: 'lambda-test'
}
const logger = createLogger('API KEY HERE', options)

// Override console methods to send logs to both LogDNA and stdout/stderr
const {
  log: consoleLog
, error: consoleError
} = console

console.log = function(message, ...args) {
  logger.log(message)
  consoleLog(message, ...args)
}

console.error = function(message, ...args) {
  logger.error(message)
  consoleError(message, ...args)
}

exports.handler = async function handler(event, context) {
  logger.on('error', consoleError)

  // Your code here
  console.log('Informational log')
  console.log({
    example: 'this is a sample object log'
  })
  console.error('Error log')

  // Ensure logs have been flushed to LogDNA before finishing
  await once(logger, 'cleared')
}

Proxy Support

The logger supports proxying for situations such as corporate proxies that require traffic to be passed through them before reaching the outside world. For such implementations, use the proxy instantiation option to set the full URL of the proxy. It supports both http and https proxy URLs. Under the hood, the logger uses the https-proxy-agent package for this.

In this example, an http proxy (with credentials) is passed through before reaching LogDNA's secure ingestion endpoint:

const {createLogger} = require('@logdna/logger')

const logger = createLogger(apiKey, {
  proxy: 'http://username:pass@yourproxy.company.com:12345'
, app: 'myapp'
})

logger.info('Happy logging through your proxy!')

License

Copyright © LogDNA, released under an MIT license. See the LICENSE file and https://opensource.org/licenses/MIT

Happy Logging!

Contributing

This project is open-sourced, and accepts PRs from the public for bugs or feature enhancements. These are the guidelines for contributing:

Contributors ✨

Thanks goes to these wonderful people (emoji key):


Darin Spivey
💻 📖 🚧 ⚠️ 🤔
relative
💻
Ryan Mottley
🚧
Alan Chen
💻
Mike Del Tito
📖
Nhut Tran
💻
Eric Satterwhite
📖

This project follows the all-contributors specification. Contributions of any kind welcome!