Spelunking with ActiveRecord callbacks

Written on July 5, 2022

I needed to hop into a legacy file in an extremely large codebase and change what happens inside one of the after_commit callbacks. The change itself was not particularly complicated and, to be honest, adding the test for the change wasn’t too hard, either. My problems began when I started running other tests around my change in isolation.

I noticed that the tests that asserted the functionality around what I was changing began to fail. This seemed odd to me! I wasn’t explicitly changing how the other pieces of code should function, I was adding an early return above the existing logic.

That’s when the spelunking began.

Getting Dirty

By default ActiveRecord includes the Dirty module on records. This is an incredibly handy module that provides a number of methods to help developers determine what will or what has changed on a record. These methods are particularly helpful when inside of an ActiveRecord lifecycle event (like after_commit which will be the subject of this post).

Let’s use a simplified example to demonstrate. Let’s imagine we implemented a new callback for an ActiveRecord model:

class MyRecord < AppsRecord
  # We'll use the Paranoia gem for this example
  # https://github.com/rubysherpas/paranoia
  acts_as_paranoid

  after_commit :my_callback

  def my_callback
    # Only run on create/destroy
    if saved_change_to_created_at? || saved_change_to_deleted_at?
      ExternalService.new(self).perform
    end
  end
end

(Note: normally in the case above we’d change the code to only run my_callback on :create or :destroy but the actual model I was working with was including another module that implemented the callback that we have to override)

This code is saying “if either the created_at or deleted_at columns change that means we know we’re creating or deleting this record and we should perform our ExternalService code”. At first glance this code seems sound! As mentioned above, ActiveRecord provides us with amazing helper methods to look at information that has changed saved_change_to_COLUMN or you can look at all of the changes by calling saved_changes.

(Note: deleted_at is a time-based column added to records that use some kind of “soft delete” process. It allows a record to be marked as deleted without actually deleted the row from the database)

After adding my code it looked a little something like this:

 def my_callback
+  if !previously_new_record? && saved_change_to_special_column
+    DifferentService.new(self).perform
+    return
+  end
+
   if saved_change_to_created_at? || saved_change_to_deleted_at?
     ExternalService.new(self).perform
   end
 end

My addition is saying: if this wasn’t previously a new record and we’re updating special_column then trigger DifferentService and return early. I’m making an assumption here that if it wasn’t previously a new record then we must be inside of some kind of update call on the record.

The Troubling Tests

I was happy to see that the callback was already under test! In theory all I had to do was add my own. I copy/pasted the setup from the existing tests, tweaked how they were running to perform an update instead of create or destroy and… failure. I re-read the existing tests and couldn’t figure out where I was going wrong.

test "calls ExternalService on create" do
  ExternalService.any_instance.expects(:perform)
  MyRecord.new.save!
end

test "calls ExternalService on destroy" do
  record = MyRecord.new.save!
  ExternalService.any_instance.expects(:perform)
  record.destroy!
end

At first glance these seemed like succinct tests that cover the existing logic perfectly but with the addition of my own logic into the callback I was starting to see failures on the destroy test. This was weird to me because my logic shouldn’t affect any of the existing tests or logic so I went into “isolate the problem” mode. I’ll often also use this method when I’m writing tests for the first time so that I can be sure I’m testing the exact code that I think I am.

First, I removed all of the new code that I wrote so that I can be sure that I’m not introducing any new issues. Next I checked the create test by removing the logic for deleted_at:

  def my_callback
    # Only run on create/destroy
-   if saved_change_to_created_at? || saved_change_to_deleted_at?
+   if saved_change_to_created_at?
      ExternalService.new(self).perform
    end
  end

And then ran the calls ExternalService on create test: success! No failures. Let’s make sure we’re covering all of our bases and do the same with the delete logic:

  def my_callback
    # Only run on create/destroy
-   if saved_change_to_created_at? || saved_change_to_deleted_at?
+   if saved_change_to_deleted_at?
      ExternalService.new(self).perform
    end
  end

And now let’s run the calls ExternalService on destroy test: failure! Oh no! It appears as though we had a test that we thought was working but but relied on other logic in our application in order to pass. This happens a lot, especially in legacy code bases.

binding.pry to the Rescue

Based on our test above we know that something isn’t quite right with saved_change_to_deleted_at? so let’s add a binding.pry into our callback and see what the heck is going on:

  def my_callback
+   binding.pry
    # Only run on create/destroy
    if saved_change_to_created_at? || saved_change_to_deleted_at?
      ExternalService.new(self).perform
    end
  end

Now we can run our calls ExternalService on destroy test again and poke around!

[1] pry(#<MyClass>)> saved_change_to_deleted_at?
=> false

Well that’ll certainly be why we’re not hitting our ExternalService call! But has the record been deleted?

[2] pry(#<MyClass>)> deleted?
=> true
[3] pry(#<MyClass>)> deleted_at
=> Thu, 23 Jun 2022 12:39:41.000000000 EDT -04:00

Interesting! So the record was successfully deleted and the deleted_at column was populated but for some reason it’s not coming through as a part of saved_change_to_deleted_at?. Let’s see what it thinks the saved changes are:

[4] pry(#<MyClass>)> saved_changes
=> {"id"=>[nil, 1073506572],
 "created_at"=>[nil, Thu, 23 Jun 2022 12:33:07.000000000 EDT -04:00],
 "foo"=>[nil, 'baz'],
 "bar"=>[nil, 'qux'],
 "updated_at"=>[nil, Thu, 23 Jun 2022 12:33:07.000000000 EDT -04:00]}

What the heck!? Those are all of the saved changes from when the record was created in our test, not from when it was deleted! Now we’re getting somewhere! I know that I could add a reload to the record in the test to clear the saved changes but our record is already deleted so the saved_change_to_deleted_at? isn’t going to magically populate after that. So what’s going on here?

Spelunking in GitHub

Every once in a while you get a problem thrown at you where you just have to go look at the source code for the package you’re working with. In this case my spidey senses suggested I go to the source of what populates saved_changes: the Dirty module.

If we look through this file we can see the method definition for saved_changes and we can poke around at all sorts of interesting things! For example, before I mentioned that calling reload on the record would clear its saved changes and we can see exactly where that happens: dirty.rb#L56-L62. Cool!

For our investigation though, it’s something that I can’t find that triggers an “ah ha!” moment. I can see methods for create_record and update_record but noticeably absent: destroy_record. I think we’ve found our problem! ActiveRecord doesn’t populate saved_changes on destroy because its expecting that the record will be deleted from the database. Why generate a list of changes for a record that will no longer exist? If we ignore the fact that we’ve added on logic to add “soft deletion” then this flow makes perfect sense.

Fixing Our Logic and Test

So we know why saved_change_to_delete_at? is false but we also know that there’s no way it’ll ever be true so we’ll need to fix the logic in our callback so that it works.

First, let’s update our test so that we can force it to fail so we can see when we fix it:

 test "calls ExternalService on destroy" do
   record = created_record
   ExternalService.any_instance.expects(:perform)
-  record.destroy
+  record.reload.destroy!
 end

We know that adding reload will clear the saved changes so now we can truly test the destroy! call in isolation. If we think back to our pry session we know that the record is succesfully deleted and there are ways to check that. We can check if deleted_at is populated or use the helper method deleted? instead. Unfortunately, due to the nature of ActiveRecord we won’t be able to know if the record was just deleted but we can update our logic to get the test passing again:

 def my_callback
   # Only run on create/destroy
-  if saved_change_to_created_at? || saved_change_to_deleted_at?
+  if saved_change_to_created_at? || deleted?
     ExternalService.new(self).perform
   end
 end

Now when we run calls ExternalService on destroy we’ll get a green test suite again. This change isn’t perfect: it will never be able to know if the record was just soft deleted but deleted records shouldn’t be receiving updates so this felt like a reasonable compromise.

Now I can go about adding my new logic back to the callback with significantly more context about how this all is meant to work!

A Special Note on Soft Deleting

A lot of “soft deleting” Ruby gems (like Paranoia in this post) override the behavior of delete and destroy which can lead to unexpected consequences. Discard aims to remove some of this problematic behavior:

Discard takes a different approach. It doesn’t override any ActiveRecord methods and instead simply provides convenience methods and scopes for discarding (hiding), restoring, and querying records.

If the codebase I had been working with in the first place used Discard instead of another gem I could have used saved_changes_to_discarded_at? and would have never run into any of these issues! Something to consider if you’re starting a new Rails project and need to soft delete records.

More Reading

I ended up diving into a whole bunch of neat stuff when exploring what was happening here. Here are some additional pieces that might be useful to read about:

• Paranoia
• Discard
• Dirty module
• ActiveRecord lifecycle methods