JamesGecko

On Frugality and Debugging Mysterious Return Values

2015-07-10

Geocoding is hard. Like, by all rights there’s no reason why it’s not a solved problem. But whenever some aspect of our Ruby on Rails code in production exhibits heisenbugs, it inevitably winds up being tied to geocoding somehow. I’m sure this is completely unrelated to our thriftiness and keen business tactics of paying as little as possible for geocoding services. But I digress!

A weird error popped up the other day, presented here in abridged format.

Production encountered a 500 error.
undefined method `current_page' for [:bing, :google]:Array

/app/app/serializers/pagination_serializer.rb:6:in `initialize'
/app/vendor/bundle/ruby/1.9.1/gems/active_model_serializers-0.9.3/lib/action_controller/serialization.rb:95:in `new'
/app/vendor/bundle/ruby/1.9.1/gems/active_model_serializers-0.9.3/lib/action_controller/serialization.rb:95:in `build_json_serializer'
...
/app/app/controllers/api/v3/branches_controller.rb:27:in `index'
...

Why, that’s very strange. It’s two geocoding services we currently use? Why was it trying to paginate them? I’m rather confused.

Let’s break it down. PaginationSerializer takes a bunch of ActiveRecord results, tacks on some information about what page of results we’re on and how many are left, and spits out JSON suitable for sending to an API client. Here’s the slightly simplified controller code:

def index
  location = params.fetch(:location, current_user.default_location)
  branches = SafeGeocoder.wrap {
    Branch.near(location, max_miles_to_branch)
  }
  render json: branches, root: 'branch', serializer: PaginationSerializer
end

“Wat?” You may ask yourself. “We’re probably returning branches within some distance of a location. But what is SafeGeocoder?”
An excellent question. Remember that thriftiness I mentioned? Behold the horror.

class SafeGeocoder
  # Public: Takes a block containing a Geocoder method and retries it against
  # fallback services if the block throws Geocoder::ServiceUnavailable
  def self.wrap(&block)
    Rails.configuration.geocoder_service_fallback_order.each do |service|
      Geocoder.configure(lookup: service)
      begin
        return block.call
      rescue Geocoder::ServiceUnavailable, Geocoder::OverQueryLimitError => e
        Rails.logger.warn "#{service} geocoder failed #{e.to_s}"
        next # <-- Editor's note: Why is this even here?
      end
      break  # <-- Or this?
    end
  ensure
    Geocoder.configure(lookup: Rails.configuration.geocoder_default_api)
  end
end

Really, the docstring says it all. You wrap a geocoder lookup statement with this, and it swaps to a different free API when the free tier of the service inevitably dies. Heroku freeloaders, eat your heart out. (You may have already spotted the issue. Don’t spoil it for the other students.)

I’m rubbish at reproducing this stuff. It doesn’t help that it’s often dependent on the external service sometimes failing. I dumped that code into a new file outside the project and just started stubbing in methods until I could get things to break. In the process, I discovered that [:bing, :google], the two values being paginated in the error, were coming from Rails.configuration.geocoder_service_fallback_order.

It’s embarrassingly easy to make this fail. Look!

puts '--- Success ---'
puts SafeGeocoder.wrap {
  "I'm a winner!"
}.inspect
puts
puts '--- Failure ---'
puts SafeGeocoder.wrap {
  raise Geocoder::ServiceUnavailable
}.inspect

Here’s the full version with stubs, if you care.

Output:

--- Success ---
Geocoder reconfigured: {:lookup=>:bing}
Geocoder reconfigured: {:lookup=>:bing}
"I'm a winner!"
 
--- Failure ---
Geocoder reconfigured: {:lookup=>:bing}
bing geocoder failed Geocoder::ServiceUnavailable
Geocoder reconfigured: {:lookup=>:google}
google geocoder failed Geocoder::ServiceUnavailable
Geocoder reconfigured: {:lookup=>:bing}
[:bing, :google]

Here’s a minimal version

def fallback(&block)
  fallbacks = [:foo, :bar]
  fallbacks.each do |item|
    begin
      return block.call
    rescue
      puts "There was an error. Try next fallback"
    end
  end
end

puts fallback {
  "I'm a winner!"
}.inspect
puts '--'
puts fallback {
  raise 'Oops'
}.inspect

Output:

"I'm a winner!"
--
There was an error. Try next fallback
There was an error. Try next fallback
[:foo, :bar]

At this point I realized what was happening and felt pretty stupid. Ruby has implicit return values. Every newbie knows that whatever is on the last line of a method is automatically returned. Well, Ruby also does that with blocks. Obviously! Array.map {|item| ... } is a common sight in Rails applications; a generally reasonable thing to have returned at the end of a method. But blocks don’t have to be one-line affairs to be returned, they just have to be the last thing in the method. In fact, most iteration in Ruby happens with a block. Wait a minute.

That’s right! When geocoding worked, the method always returned in the middle of the each loop. When geocoding didn’t work, the method returned the result of the last statement, which happened to be the array that each was iterating over.

As The Zen of Python says, “Explicit is better than implicit.” I pondered upon this, and was enlightened.

© 2021 JamesGecko