ssi-logger
Simplified logging for node.js modules.
Features
- any code running in the
node
instance, including external modules, can append log messages. - the external modules don't need any configuration knowledge to send messages to the log.
- there is no need to pass around a
syslog
object to every function that needs to log something. - log messages can be directed anywhere, not just to syslog and console.
- log messages can go to 0, 1, or many destinations (/dev/null, syslog, file, rabbitmq, e-mail, XMPP, etc).
- a log destination can be turned on or off at runtime.
- logged objects are automatically formatted into key=value strings (great for sending messages to splunk).
- certain fields can be censored to avoid accidentally logging sensitive information.
- formatted log messages are returned by SSi Logger to the caller.
- it accepts multiple arguments and printf-style formats just like
console.log
. - defaults can be supplied that are included in every message.
- your choice of API:
log(level, message, ...)
or log.level(message, ...)
Theory of Operation
The module provides a log(level, message, ...)
function which accepts the log level (INFO
, NOTICE
, DEBUG
, etc)
and a log message. The message argument(s) work just like console.log(),
supporting a variable number of arguments plus formatting.
When invoked, the logger will format the log message using logformat
(for example, a JSON object like [ { name: 'Tom' }, { name: 'Phil' } ]
becomes 0.name=Tom 1.name=Phil
).
The log level and message are emitted as a log
event though the process
event emitter. The main
application will provide an event listener to forward the log message to syslog or any other destination
(RabbitMQ, log file, database, etc). Finally, the logging function returns the formatted log message
which can be displayed/returned to the user if desired.
Installation
npm install --save ssi-logger
Examples
Basic Usage:
const options = {
logger: {
transports: {
syslog: {facility: "LOG_LOCAL5", level: "DEBUG"},
console: {timestamp: true},
}
}
};
log.open(options.logger.transports);
log.info('Ready to rock!');
Multiple message arguments:
log('INFO', 'Hello,', 'World!');
// emits ---> { level: 'INFO', message: 'Hello, World!' }
Formatting:
log('INFO', 'CC Charge amount=%d username=%s', 12.85, 'thomasc');
// emits ---> { level: 'INFO', message: 'CC Charge amount=12.85 username=thomasc' }
Non-string message arguments:
log('INFO', 'IP Whitelist Accept', { remote_ip: remote_ip });
// emits ---> { level: 'INFO', message: 'IP Whitelist Accept remote_ip=123.123.123.123' }
With censorship:
const log = require('ssi-logger');
const options = {
logger: {
censor: [
'card_number', // can contain property names
/pass(word)?/ // and/or regular expressions
],
transports: {
syslog: {facility: "LOG_LOCAL5", level: "INFO"},
console: {},
}
}
};
log.open(options.logger.transports);
log.censor(options.logger.censor);
log('INFO', { first_name: 'John', last_name: 'Doe', card_number: '1234123412341234' });
// emits ---> { level: 'INFO', message: 'first_name=John last_name=Doe card_number=[redacted]' }
Return value:
if (err) {
const human_readble_error_string = log('ERROR', err);
displayError(human_readble_error_string);
callback(err);
}
Logging to a file with daily log rotation:
const FileStreamRotator = require('file-stream-rotator');
const log = require('ssi-logger');
const path = require('path');
const logfile = FileStreamRotator.getStream({
filename: path.join(__dirname, 'application-%DATE%.log'),
frequency: 'daily',
verbose: false,
date_format: 'YYYY-MM-DD'
});
const options = {
logger: {
transports: {
stream: { stream: logfile },
}
}
};
log.open(options.logger.transports);
log('INFO', 'This message gets logged to a file');
Setting defaults that are included in every log message:
const app = express();
app.use(function loggingConfig(req, res, next) {
req.log = log.defaults({
request_id: uuid.v1(),
client_ip: req.ip
});
});
app.get('/users/:uid', function getRoot(req, res) {
req.log('INFO', 'User Get', req.params);
// emits ---> { level: 'INFO', message: 'User Get uid=thomasc request_id=e3aec5a8-12af-11e6-a148-3e1d05defe78 client_ip=127.0.0.1' }
res.render('user', db.getUser(req.params.uid));
});
app.listen(3000);
Convience methods:
log.info('Hello, World!');
// emits ---> { level: 'INFO', message: 'Hello, World!' }
log.alert('/dev/lp0 on fire!');
// emits ---> { level: 'ALERT', message: '/dev/lp0 on fire!' }
Standard Log Levels (highest to lowest):
EMERG, ALERT, CRIT, ERROR, WARN, NOTICE, INFO, DEBUG
Configuration
SSi Logger will look system wide configuration files in several places, reading each and overriding previous value. The configuration files need not exist as the application can override them (see log.censor()
and log.open()
below). The load order is:
- internal defaults
./ssi-logger.conf.defaults
(install directory)/etc/ssi-logger.conf
/etc/ssi-logger.conf.local
/usr/local/etc/ssi-logger.conf
/usr/local/etc/ssi-logger.conf.local
The general structure of a configuration file is an JSON object containing:
messageMaxLength
: maximum message length. Any message longer than this limit is truncated to this limit. Default 8192
.censor
: an array of key field names to censor.transports
: a collection of ssi-logger
transports to give log.open()
.
Transports
Log messages are emitted as log
events. Event listeners should be installed to receive the events and send them over
the appropriate transport. SSi Logger provides a couple of common transports.
Here's a setup example for a project using multiple transports to log messages. Depending on the value of level
or logLevel
, log messages may or may not go to syslog or AMQP. Here INFO
means that log messages with levels up to and including INFO
are logged, i.e. DEBUG
messages are not logged; likewise up to and including ERROR
, would exclude INFO
and DEBUG
.
// Logging defaults.
const options = {
logger: {
transports: {
amqp: {url: "amqp://user:password@example.com/virt_host", facility: "LOG_USER", level: "ERROR"},
syslog: {facility: "LOG_LOCAL5", level: "INFO"},
console: {timestamp: true},
}
}
};
...
// Enable different transports depending on NODE_ENV.
_.defaultsDeep(options, {
logger: {
transports: {
amqp: {enable: process.env.NODE_ENV === 'production'},
console: {enable: process.env.NODE_ENV !== 'production'},
syslog: {enable: process.env.NODE_ENV !== 'production'},
}
}
});
log.open(options.logger.transports);
log.info('Ready to rock!');
This is a very powerful pattern. It allows for many different combinations of actions. For example, one could write
a transport such that a LOG_ALERT message about the database being down will trigger an e-mail to go out to the sysadmin.
API
log(level, format, args ...)
Parameters
level
: log level string, one of EMERG
, ALERT
, CRIT
, ERROR
, WARN
, NOTICE
, INFO
, DEBUG
.format
: a log message format string.args
: the format
string will consume args
for each % argument in the string. Remaining arguments are appended to the log message, with objects and arrays beening flattened into key=value pairs.
log.emerg(format, args ...)
log.alert(format, args ...)
log.crit(format, args ...)
log.error(format, args ...)
log.warn(format, args ...)
log.notice(format, args ...)
log.info(format, args ...)
log.debug(format, args ...)
Convenience functions.
log.censor()
Returns a list of fields that are presently being censored from all log messages.
Example:
// get the list of censored fields
console.log(log.censor());
// prints --> [ 'card_number', /pass(word)?/ ]
log.censor(arr)
Sets the list of fields to censor from all log messages. Any number of fields may be censored. This is useful when logging request objects to avoid accidentally logging a credit card number, password, or other sensitive information.
Parameters
arr
: an array which may contain any combination of strings and regular expression objects. The strings and regular expressions are used to match against the log message. To turn off censorship, call this function with an empty array []
.
Example
// set the list
log.censor([ 'card_number', /pass(word)?/ ]);
log('INFO', 'first_name=John last_name=Doe card_number=1234123412341234 password=pizza');
log('INFO', 'first_name=%s last_name=%s card_number=%s password=%s', first_name_var, last_name_var, card_number_var, password_var);
log('INFO', { first_name: 'John', last_name: 'Doe', card_number: '1234123412341234', password: 'pizza' });
// each one above emits the same thing -->
// { level: 'INFO', message: 'first_name=John last_name=Doe card_number=[redacted] password=[redacted]' }
log.close(optDone)
Close the transports like syslog
and amqp
.
Parameters
optDone
: optional callback once all the transports have closed.
log.open(transportOptions[, userTransports])
Parameters
const Transport = require('log').Transport;
class TripwireTransport extends Transport {
log(log_event) {
options.patterns.forEach((pattern) => {
if (pattern.test(log_event.message)){
console.log("Run for the hills.");
process.exit(1);
}
});
}
};
log.open({
console: {enable: process.env.NODE_ENV !== 'production'},
syslog: {enable: process.env.NODE_ENV === 'production'},
tripwire: {enable: process.env.NODE_ENV !== 'production'},
}, {
tripwire: TripwireTransport,
});
Log Event
The log_event
passed to log event transport handlers is an object with the following fields:
log_event
:
version
: Version number following https://semver.org/ guidelines. Currently 1.1.0
.created
: JavaScript Date when the event occurred.host
: Host name string.level
: Log level string.message
: Formatted log message.data
: An array of the censored log() arguments.eid
: opaque log event ID.
Available Transports
Here are the available transports.
lib/Transport
The base class for pre-defined and user transports.
class Transport {
constructor(options) {}
// Return true to log the event; otherwise false to ignore.
filter(event) {}
log(event) {}
// Close the transport. Optional callback when done.
end(optDone) {}
}
Options
level
: optional log level where only messages of this level or higher are published (ordered high to low) EMERG
, ALERT
, CRIT
, ERROR
, WARN
, NOTICE
, INFO
, DEBUG
; default DEBUG
.
lib/transports/amqp
Log large JSON messages to an AMQP server. In the event of a connection or channel error, the error stack is saved to $TMPDIR/$PROCESS_NAME.stack
and attempt to reconnect if so configured. If $TMPDIR
is undefined, the default is /var/tmp
.
Parameters
amqp
:
enable
: true
if this transport is enabled; default true
.url
: an AMQP url, eg. amqp://guest:guest@localhost/
,socketOptions
: optional object of socket options; default {}
noDelay
sets TCP_NODELAY
(booloan).cert
client certificate (buffer).key
client key (buffer).passphrase
- passphrase for private keyca
- array of CA certificates (array of buffer).
exchangeName
: optional exchange name where to publish log messages; default logger
exchangeOptions
: options for the exchange.
durable
: exchange persists across server restarts; default true
.autoDelete
: exchange deletes itself when there are no bindings; default false
.
reconnect
: options for re-connection:
retryTimeout
: how long in seconds to continue attempting re-connections before emitting an error
event; default 0.retryDelay
: how long in seconds to wait between re-connection attempts; default 5.
routeKeyPrefix
: prefix for the routing key; default "log". The routing key format is "prefix.proc_name.facility.level".level
: optional log level where only messages of this level or higher are published (ordered high to low) EMERG
, ALERT
, CRIT
, ERROR
, WARN
, NOTICE
, INFO
, DEBUG
; default INFO
.facility
: optional syslog facility name, one of AUTH
, CRON
, DAEMON
, KERN
, LOCAL0
, LOCAL1
, LOCAL2
, LOCAL3
, LOCAL4
, LOCAL5
, LOCAL6
, LOCAL7
, LPR
, MAIL
, NEWS
, SYSLOG
, USER
, UUCP
; default LOCAL0
. Note the facility name in the AMQP log message is informational only.format
: one of text
, json
; default text
. text
sends text log message with all the arguments flattened out into message. json
formats the message only those % arguments specified, the remaining unused are pased as JSON.traceLevel
: 0 = disable, 1 = connection, 2 = verbose; default 0.chunkSize
: split long messages into messages no longer than chunkSize
. Default 8192
.
Example:
log.open({
amqp: {
url: 'amqp://guest:somepassword@example.com/virtual_host',
exchangeName: 'logger'
}
});
Process Events
log_amqp_transport_gone
: When the AMQP connection is closed (server shutdown, forced disconnect from UI, unexpected disconnect) and reconnection is disabled or times out while trying to reconnect, then log_amqp_transport_gone
is emitted to the process
.
lib/transports/console
Parameters
console
:
enable
: true
if this transport is enabled; default true
.color
: true
to enable color coded log messages; defaults true
.stderr
: true
to direct log messages to standard error, otherwise standard output; default false
.timestamp
: true
to prepend ISO 8601 timestamp to all console messages; default false
.level
: optional log level where only messages of this level or higher are published (ordered high to low) EMERG
, ALERT
, CRIT
, ERROR
, WARN
, NOTICE
, INFO
, DEBUG
; default DEBUG
.chunkSize
: split long messages into messages no longer than chunkSize
. Default 8192
.
Logs all messages to the console in the form:
[LEVEL] message text
or when options.timestamp
is true:
2018-03-26T15:07:27Z [LEVEL] message text
Colors can also be disabled at runtime with the --no-color
command line option.
log.open({
console: {colour: true, timestamp: true, stderr: true}
});
lib/transports/stream
Parameters
stream
:
enable
: true
if this transport is enabled; default true
.color
: true
to enable color coded log messages; defaults true
.stream
: Stream
object to write log messages, one per line.timeout
: true
to prepend ISO 8601 timestamp to all console messages; default true
.level
: optional log level where only messages of this level or higher are published (ordered high to low) EMERG
, ALERT
, CRIT
, ERROR
, WARN
, NOTICE
, INFO
, DEBUG
; default DEBUG
.chunkSize
: split long messages into messages no longer than chunkSize
. Default 8192
.
Logs all messages to the console in the form:
[LEVEL] message text
or when options.timestamp
is true:
2018-03-26T15:07:27Z [LEVEL] message text
Colors can also be disabled at runtime with the --no-color
command line option.
log.open({
stream: {enable: true, stream: logfile}
});
lib/transports/syslog
Parameters
syslog
:
enable
: true
if this transport is enabled; default true
.facility
: one of LOG_AUTH
, LOG_CRON
, LOG_DAEMON
, LOG_KERN
, LOG_LOCAL0
, LOG_LOCAL1
, LOG_LOCAL2
, LOG_LOCAL3
, LOG_LOCAL4
, LOG_LOCAL5
, LOG_LOCAL6
, LOG_LOCAL7
, LOG_LPR
, LOG_MAIL
, LOG_NEWS
, LOG_SYSLOG
, LOG_USER
, LOG_UUCP
; default LOG_LOCAL0
.level
: one of (ordered high to low) EMERG
, ALERT
, CRIT
, ERROR
, WARN
, NOTICE
, INFO
, DEBUG
; default INFO
.chunkSize
: split long messages into messages no longer than chunkSize
. Default 8192
.
Examples:
// default minimum log level to INFO
log.open({
syslog: {facility: 'LOG_LOCAL1'}
});
// set minimum log level to ERROR
log.open({
syslog: {facility: 'LOG_LOCAL2', level: 'ERROR'}
});
// set minimum log level to DEBUG
log.open({
syslog: {facility: 'LOG_LOCAL3', level: 'DEBUG'}
});
log.defaults(...)
Returns a new curried log()
function with baked in parameters that are included in all log messages.
Example:
const mylog = log.defaults({ request_id: '7423927D-6F4E-43FE-846E-C474EA3488A3' }, 'foobar');
mylog('INFO', 'I love golf!');
// emits --> { level: 'INFO', message: 'I love golf! request_id=7423927D-6F4E-43FE-846E-C474EA3488A3 foobar' }
Configuring syslog on Mac OS X
Edit /etc/syslog.conf
:
sudo -e /etc/syslog.conf
Add the following line to /etc/syslog.conf
:
local5.* /var/log/local5.log
Send syslogd
the HUP signal:
sudo killall -HUP syslogd
Test with logger
:
logger -p local5.info "Test"
tail /var/log/local5.log
Configuring rsyslog on Debain
Edit /etc/rsyslog.conf
:
sudo -e /etc/rsyslog.conf
Add the following line to /etc/rsyslog.conf
:
local5.* /var/log/local5.log
Restart rsyslog
:
sudo service rsyslog restart
Test with logger
:
logger -p local5.info "Test"
tail /var/log/local5.log
Developing a custom Transport
Implementing a custom transport involves writing an event listener that receives log events.
At present, the log events are objects that have level
and message
properties.
function smsTransport(evt) {
// evt = { level: 'EMERG', message: '/dev/lp0 on fire!' }
switch (evt.level) { // only act on important log messages
case 'EMERG':
case 'ALERT':
case 'CRIT':
twilloClient.messages.create({
from: ssiSmsNumber,
to: tcSmsNumber,
body: '[' + evt.level + ']' + evt.message
});
break;
}
}
process.on('log', smsTransport);
if (printerOnFire) {
log('EMERG', '/dev/lp0 on fire!');
}
Testing
This only needs to be done once in order to configure the amqpTransport
tests:
npm run preinstall
vi test/ssi-logger.conf # edit credentials
There is an automated test suite:
npm test
There are several optional tests that can be run with:
npm run testall
As well as several manual tests:
cd test
node manual-colors-test.js
node manual-colors-test.js --no-color
node manual-test.js && tail /var/log/local5.log
node manual-amqp.js
License
See LICENSE.md.