Solving a difficult ActiveRecord::AssociationTypeMismatch problem

On zenbilling, we've recently experienced a very troubling issue in development: It would seem like parts of the application didn't reload properly, and when we made some change in some model and reloaded the page, we'd get an error saying something like:

ActiveRecord::AssociationTypeMismatch (List(#897921329138) expected, got List(#897921331031))

To begin with, I ignored it, hoping it would go away. Never a good strategy. It didn't go away. And it made development really frustrating. The only way out of it was to restart the server on each change. That slows down development to the point that you want to tear your hair out.

So today I decided to dig in and figure out what was going on. It took me to the deepest innards of Rails and class reloading, and it turned out that my Account model for some reason wasn't in the autoloaded_constants array, which means it doesn't get reloaded, which means the old version sticks around with references to other old models, like the List model.

So why wasn't Account part of the autoloaded constants? Good question. That took me another couple of hours to figure out. It seemed like the Account class was defined even before my application was loaded. So how would that happen? And why would that suddenly start happening one day?

I put in some STDERR.puts statements in different places, outputting whether Object.local_constant_names included 'Account', and noticed that right before Bundler loaded all the gems, it didn't, and then after the gems were done loading, it did. Okay, so it's a gem.

Then I went inside Bundler itself, and made it write to STDERR when it loaded a file and 'Account' wasn't defined before the file was loaded, but it was defined after. Bingo. I'd found the culprit. Turns out this gem includes this line:

autoload :Account, "billys_billing/account.rb" 

And it's right there in the top-level global scope. That stuff needs to happen inside some module, otherwise it pollutes the global namespace.

So that was the culprit. A rogue gem that defined a global constant with the same name as one of my core models. Because it was already defined when my model loaded, the Rails autoloader would refuse to touch it, and that's what cause all of our troubles. Moving the autoload inside the base BillysBilling module solved it.

Just wanted to share this story here, because I was googling and googling for hints and suggestions, but found nothing at all.

5 comments

Alex Sokoloff
 

That sounds frustrating. Congratulations on getting to the bottom of it.
Read more
Read less
  Cancel
Swanand Pagnis
 

This looks like a development issue, are you getting this in Production? Because class reloading should not be needed in Production.
Read more
Read less
  Cancel
Peter Marklund
 

Cool that you tracked it down! I really like the isolation the Node module system provides and I suppose it helps avoid issues like these.
Read more
Read less
  Cancel
Peter Marklund
 

Peter Marklund liked this on Facebook.
Read more
Read less
  Cancel
Calvin Conaway
 

This was only in development ... but it was making development seriously painful, because we had to restart the server on almost every change, at least any change to a model.
Read more
Read less
  Cancel

Leave a comment