Summary: Many Node.js Applications rely heavily on Standard Output (stdout) like console.log, util.log, etc., for reporting application state, events and errors. By leveraging the power of JavaScript and a simple hook module, you can write unit tests that verify your application output.

Over the last several months, I’ve been spending a lot of time in Node.js. It started with my Knockout.Unobtrusive and Pinify plugins, which I ported to CoffeeScript, leveraging Node to set-up Cake builds and testing via Qunit. As a part of that effort, I also wrote my own Node package for sending Growl notifications on Windows, 80s Hair-band style. It’s called wingrr, and you can get it at http://github.com/bsatrom/wingrr, or just run “npm install wingrr” in a console window.

Recently, I’ve been working on a few other projects–one, a simple port of the node_chat application to CoffeeScript as an excuse to start using Jasmine; and another project using express and jade that I’m just getting rolling on this week. More on that one later.

In the meantime, I wanted to share something I learned while writing Jasmine tests (using the jasmine-node package) for the node_chat application. node_chat is a simple chat server (a node chat server, who would have thought?) implementation and, as such, it relies on standard output, or stdout, to report errors and information to the “user.” For example, one method provided by the server for this application is “listen,” which, given a port and optional host, will listen to all http traffic at that location. Here’s my implementation, in CoffeeScript. (JavaScript purists can click here for a not-generated-by-the-coffeescript-compiler equivalent)

1 2 3 4 5 6 7 8 9 10
exports = module.exports
 
# server logic omitted for brevity
 
exports.listen = (port, host, callback) ->
try
server.listen port, host, callback
util.log "Server listening at http://#{host or "127.0.0.1"}:#{port}/"
catch err
util.log err.message
view raw server.coffee hosted with ❤ by GitHub

Notice that I’m calling “util.log” (equivalent to sys.log in earlier versions of Node) to report that the server is listening, or any errors that may have occurred. As expected, this outputs to the console that the server is listening, as you can see in the image below.

Console Output in Node.js

This is great, but I wanted to write unit tests that would start and interact with my server, and the best way to verify that my tests passed would be to inspect these messages. I could return these messages from each method, and then inspect the returned value—and I even did that for the first couple of tests—but that would mean that I’ve written production code for the sole purpose of asserting my expectations in a test, which feels dirty.

Instead, I thought it made more sense to hook into stdout myself, and inspect the output for my tests. I hoped that Node might provide some kind of object-based message pump for me to query, but I found no such feature (though do please leave me a comment here if I’ve overlooked something). So I was out of luck in terms of a standard, Node-provided way to inpect stdout from my tests.

Undaunted,  I thought a bit more about my problem. I figured I needed to:

  1. Determine the mechanism Node uses to write to stdout
  2. Figure out how to “inject” an assertion into that mechanism

With JavaScript, #2 would be a simple matter of “rewriting” the functionality used by #1. So it was really just a matter of figuring out the global objects that Node provides for stdout.

It turns out that Node handles all stdout via a global object called “process.stdout,” and calls to console (ie console.log) or util (ie util.puts or util.log) are merely wrappers for “process.stdout.write.” #1, check. For #2, I was able to override “write” by creating a separate JavaScript module whose only method, “setup,” accepts a callback stub to execute. Here’s my simple implementation (again, click here for the JavaScript version):

1 2 3 4 5 6 7 8 9 10 11
exports = module.exports
 
exports.setup = (callback) ->
write = process.stdout.write
process.stdout.write = ((stub) ->
(string, encoding, fd) ->
stub.apply process.stdout, arguments
callback string, encoding, fd)(process.stdout.write)
return -> process.stdout.write = write
view raw hook_stdout.coffee hosted with ❤ by GitHub

Notice that my callback has access–via the string parameter–to the message being written to stdout. This is the value I’m passing into util.log above; and the value that I wanted to inspect in a test. Notice also that my setup method returns a function that “resets” process.stdout.write back to its original state. You’ll want to call that function after each test, otherwise your callback will fire for every write in your current instance of Node.

Once I had this module in hand, I was able use it in my tests. Here’s a Jasmine test for ensuring that calling server.listen emits the correct message:

1 2 3 4 5 6 7 8 9 10 11
server = require '../js/server'
hook = require '../js/hook_stdout'
 
describe 'chat server', ->
 
it 'should listen at localhost on a port I specify', ->
unhook = hook.setup((string, encoding, fd) ->
expect(string).toContain 'Server listening at http://127.0.0.1:3001/'
)
server.listen '3001'
unhook()
view raw spec.coffee hosted with ❤ by GitHub

Given the current string provided to stdout, and thus, my callback, I was then able to call Jasmine’s expect() method and toContain() to assert that the string my server is outputting is the one I expected. Notice also that I call hook.setup just before I need it, and assign it to the local variable “unhook.” After my initial call to server.listen, I call unhook as a function, which resets writes back to their original state.

Now I can inspect stdout in my automated tests quickly and easily, and I’ve done all of this without having to modify my server code in any way to accommodate my tests. Feels like #winning to me. Hopefully you’ll find it useful, as well.

That’s that. Not a lengthy, or earth-shattering posts, by any means, but I thought it was worth sharing for anyone doing unit testing in Node applications. If you are, and you’re using a different or better approach for asserting stdout, please let me know by leaving a comment below!

Tagged with:
 
  • clux inator

    Thanks a lot for this. This helped me test my logger module( https://github.com/clux/logule )
    without having to spam my log with irrelevant output : )

  • http://www.userinexperience.com Brandon Satrom

    Awesome, glad to help! And logule looks awesome, I’m going to use it on my next Node project!

Switch to our mobile site