Wednesday, September 30, 2015

Food for thought...

My normal posts involve technical problems and how I've solved them so please forgive this off topic post but I do feel as though I need to give a plug here.

For the better part of three decades I've worked for and with Michael Johnson.  I've learned a great many things from my friend and colleague over time and he's just recently started doing some short podcasts on business and technology.  Michael is a true no business business guy and he has an excellent technology background.  These podcasts represent many things I've learned from Michael over the years and I urge you to take a few minutes to listen.

Monday, January 26, 2015

A rake task named database.rake task is loading twice

What was happening...

I was working on a Rails 4.1.5 project and ran into a strange issue with some defined rake tasks.  Whenever I would attempt to run a task my task would actually run twice.  After a fair amount of reading on how this might be possible I ran across this POST (see Rake's Redefining Behavior section) indicating that if a Rake task was actually loaded more than once the way Rake works it would cause the task definitions to be "appended" to the original or first defined task.  This would cause the task to actually run twice which is exactly what I was seeing.  That post put me on the right track and I set about trying to determine what could possibly cause the rake file to be reloaded.  I added the following bit of code to the top of the rake task file so I could confirm it was definitely loading twice.

  puts "AGAIN! LOADED 2nd TIME"
  puts "#{caller.join("\n")}"
  puts "#{caller.join("\n")}"
$AM_HERE = true

When I executed the rake task I saw both messages indicating the file was indeed being loaded twice.  I was also able to see a stack trace that indicated it was related to dependency loading.   The following POST (see File Lookup Rules section) was a great help in understanding what was happening.

Bottom Line...

If you run a rake task and it appears to execute twice, look for something unintentionally loading your task file more than once.  It took quite some time to track down the cause of this issue.   It turns out that the the 0.1.0 version of the activerecord-session_store GEM has a subtle defect with way that it references the database.rake task in the project.   Due to this issue, when Rails was using Railtie to load rake tasks for the GEM, Rails was actually finding my lib/task/database.rake file and loading it instead of the database.rake in the GEM.  I forked the project and made a quick fix to confirm and then put in my pull request for the fix

Hope this saves someone time troubleshooting the same error.