Prettier, user friendly printing of Ruby objects

If you, like me, don’t like too much how Ruby objects usually look when displayed in a console (output on single lines, lack of indentation, and so on), it’s likely you also have looked for ways to prettify this kind of output. This can be useful in a console, but also to have more user friendly, more readable debugging information in your application’s log files. Not only: as we’ll see, knowing which “printer” methods to use for each case can help display or log more complete information about your Ruby objects.

Built-in “printers”

The two most common ways of “printing” objects in a console or, more generally, to stdout, are the Kernel#puts and Kernel#print methods. With an object given as argument, print simply outputs the text returned by the object’s to_s method. puts works in a very similar way, but it also adds a new line character at the end of the string and -for some objects- it further manipulates the output; for example, if the argument is an array, puts will display the array’s items one item per line rather than the whole array on a single line as with print:

ruby-1.9.2-p0 > print [1,2,3]
[1, 2, 3] => nil

ruby-1.9.2-p0 > puts [1,2,3]
1
2
3
=> nil

The output of both these methods is readable enough for very simple objects such as strings, numbers, and so on, but it becomes less useful with other objects, in that these methods only display the class name and -if the argument is an instance of a class- the object_id:

ruby-1.9.2-p0 > print Category.first
#<Category:0x00000100d34c20> => nil

ruby-1.9.2-p0 > puts Category.first
#<Category:0x00000100d19010>
=> nil

This kind of output is pretty useless when you are trying to debug something in the console, or if your application prints some debugging information to logs, as it doesn’t include an instance’s attributes, for example, nor their values – which is exactly what you are usually looking for when you look at logs or debug information in a console. A slightly better way of printing objects to stdout is the inspect method, which is automatically used -for example- when assigning a value to a variable:

ruby-1.9.2-p0 > category = Category.first
=> #<Category id: 1, name: "Blogging", slug: "blogging", posts_count: 0, seo: nil, type: "Category", created_at: "2011-01-16 17:47:48", updated_at: "2011-01-16 17:47:48">

By default, unless other “printer” methods such as puts, print are used, a class or an instance of a class are printed by displaying what the method inspect returns. This method is usually available both as class method and as instance method; unless overridden, it simply shows the name of the class, the attributes, plus -only if it’s an instance- the object_id and the attributes’ values.

Both classes and instances are quite readable when printed in a console, as long as they only have a small number of attributes:

ruby-1.9.2-p0 > Category
Category(id: integer, name: string, slug: string, posts_count: integer, seo: string, type: string, created_at: datetime, updated_at: datetime)

ruby-1.9.2-p0 > Category.first
=> #<Category id: 1, name: "Blogging", slug: "blogging", posts_count: 0, seo: nil, type: "Category", created_at: "2011-01-16 17:47:48", updated_at: "2011-01-16 17:47:48">

Same result if you explicitly use the inspect method on an object, or the Kernel#p method instead, which simply is a shortcut for “puts obj.inspect“. It works in a similar way to the more common Kernel#puts method, with the difference that p displays the result of the object’s inspect method, rather than the result of the object’s to_s method as with puts:

ruby-1.9.2-p0 > Category.inspect
=> "Category(id: integer, name: string, slug: string, posts_count: integer, seo: string, type: string, created_at: datetime, updated_at: datetime)"

ruby-1.9.2-p0 > p Category
Category(id: integer, name: string, slug: string, posts_count: integer, seo: string, type: string, created_at: datetime, updated_at: datetime)
=> Category(id: integer, name: string, slug: string, posts_count: integer, seo: string, type: string, created_at: datetime, updated_at: datetime)

The output isn’t great, in that most people find vertical lists more readable, but it’s OK. However it soon becomes more unreadable and more complicated to follow if you print objects with many properties/attributes, or for example collections:

ruby-1.9.2-p0 > Category.all
[#<Category id: 1, name: "Blogging", slug: "blogging", posts_count: 0, seo: nil, type: "Category", created_at: "2011-01-16 17:47:48", updated_at: "2011-01-16 17:47:48">, #<Category id: 2, name: "Database", slug: "database", posts_count: 0, seo: nil, type: "Category", created_at: "2011-01-16 17:47:48", updated_at: "2011-01-16 17:47:48">, ... ]

Another alternative to p, puts, inspect is the to_yaml instance method, which is already available for objects such as ActiveRecord models, and more. All what to_yaml does, is display the instance serialised in YAML format:

ruby-1.9.2-p0 > Category.first.to_yaml
=> "--- !ruby/object:Category \nattributes: \n id: \"1\"\n name: Blogging\n slug: blogging\n posts_count: \"0\"\n seo: \n type: Category\n created_at: 2011-01-16 17:47:48\n updated_at: 2011-01-16 17:47:48\nattributes_cache: {}\n\nchanged_attributes: {}\n\ndestroyed: false\nmarked_for_destruction: false\npersisted: true\npreviously_changed: {}\n\nreadonly: false\n"

The output is not too different from the previous one, and it’s actually a little less readable because of new lines and other characters that are escaped when the YAML output is printed as simple string. A first step to prettify this kind of output at least for instances -as said to_yaml is an instance method, therefore it cannot be used to prettify classes- could be using this method together with puts:

ruby-1.9.2-p0 > puts Category.first.to_yaml
--- !ruby/object:Category
attributes:
id: "1"
name: Blogging
slug: blogging
posts_count: "0"
seo:
type: Category
created_at: 2011-01-16 17:47:48
updated_at: 2011-01-16 17:47:48
attributes_cache: {}

changed_attributes: {}

destroyed: false
marked_for_destruction: false
persisted: true
previously_changed: {}

readonly: false
=> nil

I think it’s already a lot more readable, and you can even save some typing by using the shorthand y method:

# same as "puts Category.first.to_yaml"
ruby-1.9.2-p0 > y Category.first
--- !ruby/object:Category
attributes:
id: "1"
name: Blogging
slug: blogging
posts_count: "0"
seo:
type: Category
created_at: 2011-01-16 17:47:48
updated_at: 2011-01-16 17:47:48
attributes_cache: {}

changed_attributes: {}

destroyed: false
marked_for_destruction: false
persisted: true
previously_changed: {}

readonly: false
=> nil

This output certainly looks more readable than the previous ones, and also collections look a lot more readable. However to_yaml also shows information that you may not be interested in (unless you only show attributes with “y Category.first.attributes“, but that’s.. uhm.. too much typing); plus it is an instance method (so you can’t use it to prettify the display of a class) and isn’t always available out of the box with any kind of objects, as it is instead for ActiveRecord models.

Other limits of built-in “printers”

Instance variables and attributes

Apart from the ugly output, another issue with these “printers” is that they don’t always display the complete structure of an object. Let’s take the following class as example:

class TestClass
  def initialize(an_argument, another_argument)
    @an_argument = an_argument
    @another_argument = another_argument
    @an_instance_variable = "#{an_argument}-#{another_argument}"
    self
  end
end

It’s just a very simple class with an initialize method that, given two arguments, creates and instance and stores the two arguments in two instance variables, then stores the two values concatenated in a third instance variable, and finally returns a reference to the instance itself. Let’s see what happens with the various methods we’ve seen so far, if we print an instance of this class in a console:

# puts
puts TestClass.new("A", "B")
#<TestClass:0x000001049034e0>
=> nil

# print
print TestClass.new("A", "B")
#<TestClass:0x000001048fbd30> => nil

# implicitly using "inspect";
# same as ...
# TestClass.new("A", "B").inspect
# or ...
# p TestClass.new("A", "B")
TestClass.new("A", "B")
=> #<TestClass:0x000001048f6470 @an_instance_variable="A-B", @another_argument="B", @an_argument="A">

# y; same as TestClass.new("A", "B").to_yaml
y TestClass.new("A", "B")
--- !ruby/object:TestClass
an_argument: A
an_instance_variable: A-B
another_argument: B
=> nil

# pretty print
require "pp"
pp TestClass.new("A", "B")
#<TestClass:0x000001048d57e8
@an_argument="A",
@an_instance_variable="A-B",
@another_argument="B">
=> #<TestClass:0x000001048d57e8 @an_instance_variable="A-B", @another_argument="B", @an_argument="A">

As we can see, and as previously anticipated, both puts and print are pretty useless in this context, because they tell us nothing of the internal state of the object, and in particular they tell us nothing of the instance variables that we know are there. inspect, y and pp display a more useful output instead. pp, which stands for pretty print, is yet another alternative that displays instance variables and attributes in a vertical list as with y, and does not use serialisation, but it requires an additional module for little gain, as you can see.

More complex objects

Another, perhaps more important, issue with all these “printers”, is that for instances of ActiveRecord models, the values of attributes are displayed as they are stored in the database.

This is quite important, because it means that more complex models are not always displayed with their complete structure. An example may be an ActiveRecord model that has a text column storing another object in YAML serialised format (using the serialize class method).

For instance, say we have the model Category that stores a serialised instance of the model SeoOptions in the column seo, using the tableless_model gem.

If you print an instance of such a model, you will see the presence of the attribute seo, and it’s value as it is stored in the database. In the example this value is still nil, but the reader/getter method for this attribute actually returns an instance of SeoOptions, with its own attributes already set to their default values:

ruby-1.9.2-p0 > Category.first
=> #<Category id: 1, name: "Blogging", slug: "blogging", posts_count: 0, seo: nil, type: "Category", created_at: "2011-01-16 17:47:48", updated_at: "2011-01-16 17:47:48">

ruby-1.9.2-p0 > Category.first.seo
=> <#SeoSettings meta_description="" meta_keywords="" noarchive=false nofollow=false noindex=false title_tag="">

In these cases, all the methods we’ve seen are useless, in that none of them tell us what seo represents, but they only tell us that the attribute has a nil value in the database. Not very useful, if you are debugging something in a console, or if you are printing this kind of information to a log file for later inspection.

Better alternatives

Hijacking the inspect method

Although the output of these default “printers” is often ugly and not enough complete, it is possible to improve things by hijacking or overriding the inspect method we’ve seen earlier. This can actually be quite useful in some cases, if you prefer log some debugging information in some custom format. Let’s see an example of custom inspect for the test class we’ve used in one of the previous examples:

class TestClass
  def initialize(an_argument, another_argument)
    @an_argument = an_argument
    @another_argument = another_argument
    @an_instance_variable = "#{an_argument}-#{another_argument}"
    self
  end

  def inspect
    instance_variables.inject([
      "\n#TestClass",
      "\tObject_i = #{object_id}",
      "\tInstance variables:"
      ]) do |result, item|

      result << "\t\t#{item} = #{instance_variable_get(item)}"
      result
    end.join("\n")
  end
end

In the example above, we want inspect to display instance variables and in a nicer format in a vertical list, without YAML and without having to require a separate module for pp. The result, as expected, is:

ruby-1.9.2-p0 > instance = TestClass.new("A", "B")
=>
#TestClass
Object_i = 2160235560
Instance variables:
@an_instance_variable = A-B
@another_argument = B
@an_argument = A

Of course this is a very simple example, just to give you an idea, but it should be clear that by overriding the behaviour of the inspect method, it is possible to “print” Ruby objects in a prettier and more useful way.

Ready meal: the awesome_print gem

If you don’t like the output of the default “printers”, you don’t really have to customise the result of inspect. You can save some time by using one of the ready gems, libraries and plugins that do this out of the box and are often pretty customisable too.

One of such components which is quite popular according to the download stats on RubyGems, is the awesome_print gem.

Using it, once you’ve installed the gem, is as easy as

ruby-1.9.2-p0 > require "ap"
=> true

ruby-1.9.2-p0 > x = { :a => 1, :b => "a string", :c => [1,2,[3,4]], :d => Time.now }
=> {:a=>1, :b=>"a string", :c=>[1, 2, [3, 4]], :d=>2011-01-17 19:18:03 +0000}

ruby-1.9.2-p0 > ap x
{
:a => 1,
:b => "a string",
:c => [
[0] 1,
[1] 2,
[2] [
[0] 3,
[1] 4
]
],
:d => 2011-01-17 19:18:03 +0000
}
=> nil

As you can see, the output is a lot cleaner and more readable in this example. Unfortunately it doesn’t prettify instance variables as well as the other methods… Remember the TestClass in some of the previous examples?

ruby-1.9.2-p0 > require "ap"
=> true

ruby-1.9.2-p0 > ap TestClass.new("A", "B")
#<TestClass:0x00000102385e98 @an_instance_variable="A-B", @another_argument="B", @an_argument="A">
=> nil

It’s not a big issue; it prettifies attributes and that’s surely very useful, however it would be nice to also see instance variables treated the same way as this can help with debugging at times. One big win with awesome_print, though, is that it works beautifully with complex ActiveRecord models. See the difference if we print with ap an instance of the Category class which we’ve also seen in previous examples and which stores an instance of SeoOptions serialised with YAML in the seo column:

ruby-1.9.2-p0 > require "ap"
=> true

ruby-1.9.2-p0 > ap Category.first
#<Category:0x00000101fab480> {
:id => 1,
:name => "Blogging",
:slug => "blogging",
:posts_count => 0,
:seo => {
"title_tag" => "",
"meta_description" => "",
"meta_keywords" => "",
"noindex" => false,
"nofollow" => false,
"noarchive" => false
},
:type => "Category",
:created_at => Sun, 16 Jan 2011 17:47:48 UTC +00:00,
:updated_at => Sun, 16 Jan 2011 17:47:48 UTC +00:00
}
=> nil

Hurrah! As you can see, ap doesn’t just print the values of the attributes as they are stored in the database, as the other methods do; instead, it prints the output of the reader/getter method for each attribute. So for the seo attribute it correctly displays the nested object rather than the nil value stored in the database.

I find using awesome_print very useful in my applications; I use it a lot in the console, and also in some debugging logs when I need to capture more information than usual and I need this information to be more complete, more readable and user friendly. It’s also useful to integrate awesome_print with IRB: just create a file named .irbrc in the root of your home folder, and paste this snippet in it:

require 'ap'

module IRB
  class Irb
    def output_value
      ap @context.last_value
    end
  end
end

Once you’ve done this, ap basically replaces inspect:

ruby-1.9.2-p0 > { :a => 1, :b => "a string", :c => [1,2,[3,4]], :d => Time.now }
{
:a => 1,
:b => "a string",
:c => [
[0] 1,
[1] 2,
[2] [
[0] 3,
[1] 4
]
],
:d => 2011-01-17 20:01:48 +0000
}

Since this post is also about how to make the printing of Ruby objects prettier, I should mention too that awesome_print also colorises the output very nicely! The code snippets above use color syntax highlighting already, so you will have to give awesome_print a try to see the difference with the boring mono color output you get with the other methods.

Last, but not least, a word of caution: you may be tempted to use awesome_print to prettify your production logs and make them more complete and useful. I also do, in some “controlled circumstances”, but …beware: because of the way awesome_print works, it can literally kill the performance of your web applications if misused or abused in production environments!

I will explain more in detail, with some metrics, in the next post. In the meantime, you’re warned :)

Know of other/better ways to prettify Ruby objects in console and logs? Please do let me know in the comments!