Ruby, JavaScript, Sass, iOS. Stinky Cheese & Beer Advocate. Working at CustomInk and loving it!

Pretty Console Logging With Guard::Jasmine & Black Coffee

OK I know I promised that we would start the dive into testing your Spine.JS application using Jasmine(rice) in my last article, but this is a good diversion. If you are new to my latest series on Spine.JS and Jasmine, scroll on down to the bottom to the related section and read back. However, for those that might be more familiar with Jasmine and specifically Guard::Jasmine and ever felt the pain that debugging from that terminal window was lacking, read on! Even if your new to Guard::Jasmine and Jasminerice I still suggest you setup these elegant hacks to make your testing go that much smoother.

So What Is The Problem?

Guard::Jasmine allows you to continuously test your JavaScript right from the terminal window just like your Ruby code. The only drawback is that the console debugging is less than helpful. Guard::Jasmine will not allow you do view a string version of every object nor see line numbers of calling files. Both of these are invaluable when your stuck in a testing hole and just need to inspect a few objects. So if you are tired of seeing [object Object] in your Guard::Jasmine output, let's fix it right away.

The first place we need to patch things up is Guard::Jasmine itself. In my last article I covered how to monkey patch Jasminerice in a config/initializers/jasminerice.rb file. My Guard::Jasmine freedom patch will be placed in that same file. Pasted below, this does two things vs the original. First it changes the report_specdoc_logs method to not pass true to the format_log_message method. Second, the format_log_message method itself now has the message regular expression changed to a multi-line scan. It will also look out for a custom prefix tag and allow it to pass through. This is for our pretty objects. Anything else now outputs the message with the file and line number, something previously stripped by Guard::Jasmine.

# coding: utf-8
if defined?(Jasminerice) && Jasminerice.environments.include?(Rails.env)

  # Other Jasminerice patches from:
  # ...

  # Patch Guard::Jasmine to use a custom formatter for log messages that
  # allows multi-line objects to be printed with the line numbers.
  module Guard
    class Jasmine
      module Runner
        class << self

          def report_specdoc_logs(spec, options, level)
            if spec['logs'] && (options[:console] == :always || (options[:console] == :failure && !spec['passed']))
              spec['logs'].each do |log|
      "    • #{ format_log_message(log) }", level))

          def format_log_message(message)
            if message =~ /(.*?) in http.+?assets\/(.*)\?body=\d+\s\((line\s\d+)/m
              pp_prefix = '[myLog]'
              msg, file, line = $1, $2, $3
              if msg.starts_with? pp_prefix
                msg.sub pp_prefix, ''
                "#{msg} in #{file} on #{line}"



A JavaScript Pretty Print Library

So now that we have Guard::Jasmine not stripping multi-line console messages to one line and printing file and line numbers, we are ready to hook into it. But first we need a JavaScript library that pretty prints objects for us and wrap this all up behind our own interface to console.log. During my research I found a library called jsDump and decided to use a fork of the project on github. So go download that file and place it in vendor/assets/javascripts/jsDump.js of your Rails project. Next you will want to add it to your spec/javascripts/spec.js manifest like so. My below example is pulled right from my previous article and I have placed jsDump right after my jasmine files.

#= require jasminerice
#= require mock-ajax
#= require jsDump
#= require application
#= require jasmine-myapp
#= require_tree ./lib/
#= require_tree ./models/
#= require_tree ./controllers/
#= require_tree ./views/

Logging Helpers - Using BlackCoffee

In my last article I mentioned how I would talk more about the jasmine-myapp file in the manifest above. Now is the time. I recommend that this file is place to write all your top level helpers and functions for Jasmine or any other testing libraries in your JavaScript stack. Think of this file as your Ruby test_helper.rb or your own extensions to ActiveSupport::TestCase. My advice is that these functions all be written to pollute the time level namespace as other Jasmine helpers do, like the beforeEach and clearAjaxRequests. This makes things easier but be conscious of that decision and write functions keeping that in mind.

The only thing working against is is Sprockets/Tilt rendering CoffeeScript files in their own closure. Which is something you should really not fight! But in this case I think it is fine to have this particular file avoid that. Which allows us to (a) write our helper code in CoffeeScript and (b) use these functions as helpers in the global space like other Jasmine helpers. So enter my Sprockets BlackCoffee gem. This is a simple gem that exposes a CoffeeScript template that uses the --bare option to keep your file from being wrapped in a closure. All you have to do is give the file a .js.black_coffee extension and it will just work. So let's assume you have a spec/javascripts/jasmine-myapp.js.black_coffee created and the gem installed like so.

group :assets do
  # ...
  gem 'sprockets-blackcoffee'

Finally, here are examples of my logging helpers in the jasmine-myapp file. The myLogParser uses jsDump to get back a pretty formatted string of any object if that object is not already a string. The primary logging helper myLog will prefix your message with [myLog] so the Guard::Jasmine recognizes the message and outputs only the object. The last helper myLogLine will do just like the other, but will allow the file and line number tobe printed too.

myLog = (obj) ->
  console.log "[myLog]#{myLogParser(obj)}"

myLogLine = (obj) ->

myLogParser = (obj) ->
  if typeof obj is 'string' then obj else jsDump.parse obj

In Practice

Here is an example of a Jasmine spec where I was using console.log before the patches above and what it would output to the terminal.

#= include spec_helper

describe 'User', ->

  it 'has been configured with proper attributes', ->
    @user = new User id: 2, email: ''
    console.log @user.attributes()
    expect( ''
  ✘ has been configured with proper attributes
    ➤ Expected '' to equal ''.
    • [object Object]
ERROR: 1 specs, 1 failures
in 0.653 seconds

There is the totally helpful [object Object]. But if we now change our code to leverage out patches and change console.log to hmLog @user.attributes() to use our helper. We will get this. If you need a pretty object with line numbers. Just use hmLogLine.

  ✘ has been configured with proper attributes
    ➤ Expected '' to equal ''.
    • {
       "email": "",
       "id": 2
ERROR: 1 specs, 1 failures
in 0.653 seconds

I hope this is helpful to anyone using Guard::Jasmine with a desire to see better output. If you continue to follow my series, my next post will be a deeper dive into Jasmine testing of Spine.JS applications.