Odyssey

Odyssey is an asynchronous logging system for node.js in development.

npm install odyssey

1. Why another node.js logging system?
2. HttpLog
   • Including
   • Constructor
   • Properties
   • HttpLog.none
   • Chaining Logs
3. Athena (Async Control Flows)
   • Including
   • Context
   • Control Flows
     • map
     • mapSeries
     • parallel
     • waterfall

Why another node.js logging system?

Odyssey's purpose is to make it easier to produce logs which are associated with an HTTP request/response. Due to Node.js's async nature, it can be difficult to trace log entries back to the request which initiated the problem, and therefore makes debugging more tedious and difficult.

In a typical node.js callback, the first parameter is for an error to be passed, and the typical test used to determine whether the function failed is if (err) { ... }. This works okay if you only have two log levels ("nothing to log" and "completely failed"). However, if you want a more expressive log chain, this is insufficient.

The Odyssey paradigm believes that every callback should return an Error object, but that not all Error objects should be treated equally. So, instead of if (err) ..., we should be checking if (err.failed) .... Many logging systems have a sense of "log level" such as DEBUG, INFO, WARN, ERROR, CRITICAL. Odyssey has, instead, chosen to use the existing HTTP Status Codes as its "levels." This actually results in fairly expressive and useful logs, and is explained more in the HttpLog section.

Current Status

Odyssey is still in early development, and many features are incomplete or entirely missing. Notably, while there are good methods for creating and chaining logs, there is not currently any function which assists in serializing or transmitting these logs.

There are a few async control flows which have been implemented as the need has arisen. Eventually, the goal will be to implement many or most of the methods available in the async module.

HttpLog

HttpLogs use HTTP Status Codes instead of arbitrarily named error levels. This tends to have two benefits: 1. it is generally easier to decide which category a log falls into because each status code has a standardized description, and 2. it makes it easier for a request handler to make a decision about which error code to use if the log already has a usable status code.

One downside to this approach is that it does not make a distinction between what someone might consider a DEBUG vs INFO level log. The obvious choice for INFO logs is to use status 200 since that's the HTTP code for "OK". For DEBUG you may develop your own rules, or use a non-existent code, such as 99. A better approach, however, may be to simply use console.log() for debug purposes.

It is advisable to put some thought into the error codes you use. For example, if you are writing a function which fetches a document from a database, if that document does not exist, you may want to use a 404 (not found). If you cannot connect to the database, you may want to use a 500 or 503 instead.

Including

var httpLog = require('odyssey').httpLog;

Constructor

The HttpLog constructor accepts several signatures. It should not be called with new keyword. Even though it is called like a function, the returned objects are instances of HttpLog. Additionally, HttpLog inherits from the default Error constructor. Therefore:

console.log(httpLog() instanceof httpLog); // outputs "true"
console.log(httpLog() instanceof Error);   // outputs "true"

Signatures

httpLog ( )
httpLog ( [code], err, [data] )
httpLog ( [code], [message], [data] )
httpLog ( response )

• code The number to assigned to status.
• err Error object to be converted to an HttpLog.
• message A string which will be assigned to message.
• data An object of arbitrary data which will be assigned to message.
• response An instance of http.IncomingMessage received from http.ClientRequest

Converting an Existing Error to HttpLog

var err = new Error('this is an error');
var hlog = httpLog(err);

If the Error object passed to the constructor already has a status property, it is preserved. If it does not have a status, hlog.status is set to 500.

If you would like to force the HttpLog to use a specific status code, this can be passed as a first parameter:

var err = new Error('forbidden');
var hlog = httpLog(403, err);

If, instead of an Error object, err is null, then the constructor will return HttpLog.none.

Creating New HttpLogs

New HttpLogs can be created by calling the constructor directly:

/* ALL of the following instantiations are valid */

httpLog();       // returns httpLog.none
httpLog(400);
httpLog('This is a message');
httpLog({ my: 'data' });
httpLog(400, 'This is a message');
httpLog(400, { my: 'data' });
httpLog(400, 'This is a message', { my: 'data' });

Using a http.IncomingMessage:

request.on('response', function (response)
{
  var hlog = httpLog(response);
  // ...
});

Constructor Shortcuts

Additionally, there are shortcut methods which are more human-readable and automatically populate the status code. For example:

var hlog = new httpLog.badRequest('this was a bad request');
console.log(hlog.status); // 400

All of these methods use the signature httpLog.methodName( [message], [data] ) for new logs, and httpLog.methodName( [err], [data] ) for converting existing Error objects.

Every standard HTTP Status Code has a shortcut method:

continue                     // 100
switchingProtocols           // 101

ok                           // 200
created                      // 201
accepted                     // 202
nonAuthoritativeInformation  // 203
noContent                    // 204
resetContent                 // 205
partialContent               // 206

multipleChoices              // 300
movedPermanently             // 301
found                        // 302
seeOther                     // 303
notModified                  // 304
useProxy                     // 305
temporaryRedirect            // 307

badRequest                   // 400
unauthorized                 // 401
paymentRequired              // 402
forbidden                    // 403
notFound                     // 404
methodNotAllowed             // 405
notAcceptable                // 406
proxyAuthenticationRequired  // 407
requestTimeout               // 408
conflict                     // 409
gone                         // 410
lengthRequired               // 411
preconditionFailed           // 412
requestEntityTooLarge        // 413
requestURITooLong            // 414
unsupportedMediaType         // 415
requestedRangeNotSatisfiable // 416
expectationFailed            // 417

internalServerError          // 500
notImplemented               // 501
serviceUnavailable           // 503
gatewayTimeout               // 504
httpVersionNotSupported      // 505

Properties

data

HttpLog.data is a container for arbitrary information which you may want to store as part of the log. It defaults to an empty object.

var hlog = httpLog({ my: 'data' });
console.log(hlog.data); // outputs { my: 'data' }

failed

HttpLog.failed is actually a getter which returns true if any log in the log chain has a status of 400 or greater.

httpLog(200).failed // false
httpLog(400).failed // true

highestLevel

HttpLog.highestLevel is a getter which returns the maximum status value of any log in the log chain.

message

A string message. Inherited from Error.message.

previous

HttpLog.previous is a getter and setter which represents the previous log in the log chain. If there is no previous log, or if the previous log was HttpLog.none, the getter value will be null.

If the value assigned to previous is not an HttpLog, the value will be passed to the HttpLog constructor in order to convert it.

HttpLog.previous should not generally be assigned directly. Use HttpLog.chain instead.

stack

Inherited from Error.stack.

status

The status code. Should generally be a number representing an HTTP Status Code.

HttpLog.none

There is a special instance of HttpLog called "none" which is returned from the constructor function in some circumstances. It has a status of 200 and can be referenced directly via httpLog.none.

var hlog = httpLog();
console.log(hlog === httpLog.none); // outputs "true"

HttpLog.none can also be used in callbacks. For example, where you might have previously used callback(null, val);, consider using callback(httpLog.none, val).

HttpLog.none is a frozen object, and cannot be modified. Attempting to modify HttpLog.none will not succeed, and will throw an error in strict mode.

Chaining Logs

A log chain is a linked list where every log has a previous property which points to another log. This allows several log objects to be combined without the use of an array, and allows properties like failed and highestLevel to seamlessly operate over the entire chain.

HttpLog.chain

Although a log's previous property can be set directly, the safer method is to use HttpLog.chain(prev, next). On a basic level, this method assigns next.previous = prev and returns next; however, it handles several edge cases correctly. Namely:

1. It will never try to assign a log chain to HttpLog.none. If next is null or none, chain() will simply return prev instead.
2. It will preserve any existing log chains on both prev and next. If next has an existing chain, then prev is simply appended to the end of that chain.

Example

The chain which is produced by each statement is described by the end of line comments.

var log1 = httpLog(200); // [200->null]
var log2 = httpLog.chain(log1, httpLog(201)); // [201->200->null]

// log2 is [log2->log1->null]

var log3 = httpLog.chain(httpLog(202), null); // [202->null] 
var log4 = httpLog.chain(log3, httpLog(203)); // [203->202->null]

// log4 is [log4->log3->null]

// now let's combine two logs with existing chains
var log5 = httpLog.chain(log2, log4); // [203->202->201->200->null]

// log5 is [log4->log2->log1->log3]
// also note that log5 === log4 (they point to the same object)

// *** BE CAREFUL NOT TO CREATE CIRCULAR CHAINS ***
// This next statement would create an endless loop
httpLog.chain(log4, log2);
// Future versions of httpLog.chain() will likely have checks to help prevent this,
// but for now it's up to you.

Athena (Async)

Athena is intended to provide similar utilities as async. Because of Odyssey's unique design philosophy which says that the first argument to a callback should be an HttpLog, it is difficult to use existing async frameworks because they would see even HttpLog.none as a failure. Therefore, several async control flows have been included as part of Odyssey, and more will likely be added in the future.

Two other notable difference between Athena and other async frameworks is that 1. every function has a this context which can be used for appending logs, and 2. it always sends the callback argument as the first argument instead of last. The reason for number 2 is described in the waterfall control flow.

Including

var athena = require('odyssey').athena;

Or, if you wish, you may use the async alias.

var async = require('odyssey').async;

The primary reason why the async module was given the name athena was simply to avoid confusion with the popular async library. If this possible confusion does not bother you, feel free to use either alias.

Context

The this object inside all functions within Athena control flows (tasks, iterators, results and error handlers) is a context object with one method and one property.

this.logChain

This property represents the log chain associated with the control flow.

this.log()

Calling this.log( hlog ) is equivalent to this.logChain = httpLog.chain(this.logChain, hlog);. This allows you to easily add as many logs as you'd like to the control-flow's log chain.

Control Flows

• map
• mapSeries
• parallel
• waterfall

Map

Similar to async.map.

athena.map ( [hlog], items, iterator, resultsHandler );

• hlog an optional HttpLog which will be used as the initial context.logChain value.
• items an Array or Object representing the values to be iterated over.
• iterator a function with the signature (callback, item, index). The callback takes two parameters: an HttpLog, and the "transformed" version of item.
• resultsHandler a function with the signature (hlog, results) where hlog is the log chain from all iterators, and results is either an array or object depending on what type items was.

The iterator will be called once for every item in items. When all iterators have completed (invoked their callback) the resultsHandler will be invoked. Although the iterators may complete in a different order than the original items array, the results is guaranteed to be in the original order.

See examples in the map tests file.

Map Series

Similar to async.map.

athena.mapSeries ( [hlog], items, iterator, resultsHandler );

Exactly the same as athena.map except it waits for the iterator to complete before calling it again with the next item. If an iterator passes an error to its callback, then any remaining items are skipped and the resultsHandler is immediately called.

Parallel

Parallel runs a set of tasks and calls a results-handler method when all tasks have completed. Similar to async.parallel.

athena.parallel ( [hlog], tasks, resultsHandler )

• hlog an optional HttpLog which will be used as the initial context.logChain value.
• tasks an Array or Object where the values are functions with the signature (callback). The callback takes two parameters: an HttpLog, and a "result" of any type.
• resultsHandler a function with the signature (hlog, results) where hlog is the log chain from all tasks, and results is either an array or object depending on what type tasks was.

See examples in the parallel tests file.

Waterfall

Waterfall passes the results of each task to the next task. Similar to async.waterfall.

athena.waterfall ( [hlog], tasks, errorHandler )

• hlog an optional HttpLog which will be used as the initial context.logChain value.
• tasks an array of functions (described in better detail below).
• errorHandler the function which serves as both a final task and an error handler (described below).

Tasks

Each task function will receive a callback argument as the first argument. The callback accepts any number of arguments, but the first argument will be interpreted as an HttpLog. This log becomes the root of context.logChain. If the log's failed property evaluates to true, then the errorHandler is called, and no further tasks are invoked. Otherwise, the next task is invoked, or, if there are no more tasks, the errorHandler is invoked.

If a task calls its callback with more than one argument, then the next task will receive these extra arguments as additional parameters.

Error Handler

The errorHandler function is identical to a task function except that its first argument is an HttpLog instead of a callback. This log is the context.logChain.

Example

athena.waterfall(
  [
    function (callback) {
      callback(null, 1);
    },
    function (callback, a) {
      // a === 1
      callback(null, 2);
    },
    function (callback, a) {
      // a === 2
      callback(httpLog.none, a, 3);
    },
    function (callback, a, b) {
      // a === 2 && b === 3
      callback.(null, 1, a, b);
    }
  ],
  function (hlog, a, b, c) {
    // a === 1 && b === 2 && c === 3
    // hlog === httpLog.none
  }
);

For more examples, look in the waterfall tests file.

Breaking the waterfall without passing a failed log

Sometimes it may be desirable to skip the remaining tasks and go straight to the errorHandler without having to actually throw an error. For this purpose, you may call callback.break( [hlog] ).

athena.waterfall(
  [
    function (callback) {
      callback(null, true);
    },
    function (callback, shouldBreak) {
      if (shouldBreak) {
        callback.break(httpLog.none);
        return; // don't forget, you'll probably want to call return after calling break()
      }
      
      //some other logic
      callback();
    },
    function (callback) {
      // this never gets called
      callback();
    }
  ],
  function (hlog) {
  }
);

Invoking a task multiple times

Normally each task is invoked only once. Because accidentally invoking a task more than once could have unforeseen consequences, Athena prevents a this from happening by default. Only the first call to callback() will cause the next task to run.

However, there are a limited number of circumstances where you may want a task to run more than once. In those cases, callback.enableReinvoke() is provided. This should be called inside the task which is intended to be run multiple times (not the previous task). After enableReinvoke has been called, the task may be invoked EXACTLY ONE additional time. The next time the task is invoked, it can either choose to call enableReinvoke again to enable a third invocation, or it can choose to not, which means it cannot be called again.

Example allowing infinite reinvocations:

var count = 0;
athena.waterfall(
  [
    function (callback) {
      for (var i = 0; i < 6; i++)
      	callback();
    },
    function (callback) {
      // this task can run any number of times because it always calls enableReinvoke
      callback.enableReinvoke();
      
      count++
      if (count === 6)
        callback();
    }
  ],
  function (hlog) {
    console.log(count); // 6
  }
);

Example allowing only a limited number of reinvocations:

var count = 0;
athena.waterfall(
  [
    function (callback) {
      for (var i = 0; i < 6; i++)
      	callback();
    },
    function (callback) {
      // this task can only run 4 times, even though the previous task attempts to invoke it 6 times
      count++;
      if (count < 4)
        callback.enableReinvoke();
      else
        callback();
    }
  ],
  function (hlog) {
    console.log(count); // 4
  }
);

Why is the callback the first argument?

Shouldn't it be the last argument, which is the standard in JavaScript? The problem with making it the last argument is that the index of the last argument changes depending on the number of arguments the previous task passed to its callback. Sometimes there are situations where a previous task may pass a varying number of arguments which can be difficult and tedious to account for. If you don't handle every argument signature correctly, you may introduce bugs where the program will crash because you tried to call the argument which you thought was the callback, only to find the argument you named "callback" is actually a string, or undefined, or some other type because the previous task provided an unexpected number of parameters. Moving the callback to the first position puts it in a consistent location regardless of the number of arguments passed by the previous task.