Ruby, Serialization, and Enumeration

Written by Xavier Shay.

We came across an interesting Ruby puzzler the other day. Code that had been working fine had started failing during serialization with a scary looking backtrace from within activesupport:

json.rb:128:in `each': not opened for reading (IOError)
  from /gems/activesupport-4.1.1/lib/active_support/core_ext/object/json.rb:128:in `to_a'
  from /gems/activesupport-4.1.1/lib/active_support/core_ext/object/json.rb:128:in `as_json'
  from /gems/activesupport-4.1.1/lib/active_support/core_ext/object/json.rb:159:in `block in as_json'
  from /gems/activesupport-4.1.1/lib/active_support/core_ext/object/json.rb:159:in `each'
  from /gems/activesupport-4.1.1/lib/active_support/core_ext/object/json.rb:159:in `map'
  from /gems/activesupport-4.1.1/lib/active_support/core_ext/object/json.rb:159:in `as_json'
  from /gems/activesupport-4.1.1/lib/active_support/core_ext/object/json.rb:50:in `as_json'
  from /gems/activesupport-4.1.1/lib/active_support/core_ext/object/json.rb:159:in `block in as_json'
  from /gems/activesupport-4.1.1/lib/active_support/core_ext/object/json.rb:159:in `each'
  from /gems/activesupport-4.1.1/lib/active_support/core_ext/object/json.rb:159:in `map'
  from /gems/activesupport-4.1.1/lib/active_support/core_ext/object/json.rb:159:in `as_json'
  from /gems/activesupport-4.1.1/lib/active_support/core_ext/object/json.rb:50:in `as_json'
  from /gems/activesupport-4.1.1/lib/active_support/core_ext/object/json.rb:159:in `block in as_json'
  from /gems/activesupport-4.1.1/lib/active_support/core_ext/object/json.rb:159:in `each'
  from /gems/activesupport-4.1.1/lib/active_support/core_ext/object/json.rb:159:in `map'
  from /gems/activesupport-4.1.1/lib/active_support/core_ext/object/json.rb:159:in `as_json'
  from /gems/activesupport-4.1.1/lib/active_support/core_ext/object/json.rb:50:in `as_json'
  from /gems/activesupport-4.1.1/lib/active_support/json/encoding.rb:34:in `encode'
  from /gems/activesupport-4.1.1/lib/active_support/json/encoding.rb:21:in `encode'
  from /gems/activesupport-4.1.1/lib/active_support/core_ext/object/json.rb:37:in `to_json_with_active_support_encoder'
  from test.rb:15:in `<main>'

The issue was isolated to a particular change to a class that was being serialized inside a larger data structure (which I’ve further simplified):

require 'active_support/all'

class Metric
  attr_reader :timestamp, :value

  def initialize(timestamp, value)
    @timestamp = timestamp
    @value     = value
    @logger    = Logger.new($stdout)
  end
end

metric = Metric.new(Time.now, 5)
puts metric.to_json

The addition of the @logger variable was causing the problem, even though it was never used! Commenting out that line made the problem go away. This is certainly non-intuitive. What is going on? Let’s find out.

One of Ruby’s best features is the transparency of its libraries. We have the full path to the source of the exception right there in the backtrace. Opening up /gems/activesupport-4.1.1/lib/active_support/core_ext/object/json.rbin your favourite editor (obviously your path will be different) gives a major hint: this file is monkey-patching a number of core classes to support serialization.

**module** Enumerable
  **def** **as_json**(options **=** **nil**) *#:nodoc:*
    *# ...*
  **end**
**end**

class Hash
  def as_json(options = nil) #:nodoc:
    # ...
  end
end

# ... and many more!

Looking at the Metric code above, how did it know how to serialize the object to JSON in the first place? Sure enough, elsewhere in json.rb (which also appears in our stack trace):

**class** **Object**
  **def** **as_json**(options **=** **nil**) *#:nodoc:*
    **if** respond_to?(:to_hash)
      to_hash**.**as_json(options)
    **else**
      instance_values**.**as_json(options)
    **end**
  **end**
**end**

Metric does not implement to_hash, so all of its instance variables are being included in the JSON representation. That explains why the unused @logger variable was the difference between success and failure. An easy fix then is to implement to_hash. Even if @logger was serializing correctly, it is unwanted in the JSON output.

However that still doesn’t explain the opaque error: not opened for reading (IOError). The quickest way to track that down, since we already have json.rbopen, is to add some quick debugging output before the line that failed:

**module** Enumerable
  **def** **as_json**(options **=** **nil**) *#:nodoc:*
    puts self**.**inspect
    to_a**.**as_json(options)
  **end**
**end**

This is why library transparency in Ruby is particularly amazing: you can also modify them in-place and see the results immediately!

In this instance a single line is output:

#<IO:<STDOUT>>

That explains it. For better or worse, IO objects in Ruby are enumerable. The semantics here are questionable: to_a is indeed part of the Enumerable interface, but making an IO into an array doesn’t really make sense. And having each chunk on line breaks is somewhat arbitrary anyway.

This mismatch has historically dogged Enumerable and uses of that interface. Take this gem from rspec-expectations:

**if** String**.**ancestors**.**include?(Enumerable) *# 1.8.7*
  *# Strings are not enumerable on 1.9, and on 1.8 they are an infinitely*
  *# nested enumerable: since ruby lacks a character class, it yields*
  *# 1-character strings, which are themselves enumerable, composed of a*
  *# a single 1-character string, which is an enumerable, etc.*
  *#*
  *# @api private*
  **def** **enumerable?**(item)
    **return** **false** **if** String **===** item
    Enumerable **===** item
  **end**
**else**
  *# @api private*
  **def** **enumerable?**(item)
    Enumerable **===** item
  **end**
**end**

The comment says it all really! Funnily enough, the caller of this method has to special case IO as well:

**def** **surface_descriptions_in**(item)
  **if** Matchers**.**is_a_describable_matcher?(item)
    DescribableItem**.**new(item)
  **elsif** Hash **===** item
    Hash**[** surface_descriptions_in(item**.**to_a) **]**
  **elsif** enumerable?(item)
    **begin**
      item**.**map { **|**subitem**|** surface_descriptions_in(subitem) }
    **rescue** IOError *# STDOUT is enumerable but `map` raises an error*
      item**.**inspect
    **end**
  **else**
    item
  **end**
**end**

String is no longer Enumerable since Ruby 1.9. Should IO follow in its footsteps? Xavier Shay (@xshay) | Twitter The latest Tweets from Xavier Shay (@xshay). Engineering Manager at Square. Vegan. Running is the best. San Franciscotwitter.com