how_it_got_here

The problem

A support ticket says an invoice was voided twice. Invoice#void! is meant to run once, from the admin screen, so how did it run again?

class Invoice
  def void!
    accounts.credit(total, memo: "void #{number}")
    update!(state: :void)
  end
end

A stack trace would answer it, but you only get one of those when something raises, and nothing did. So you read code: void! is called from Admin::InvoicesController, from Refund#process, and from a Cancellation service. Each of those has its own callers. Twenty minutes in you have a whiteboard of plausible routes and no idea which ones really happen.

The usual next step is puts caller in void!, a rerun, and a scroll through the log.

The fix

The recording already has the stack for every call to void! that ran:

$ ra how_it_got_here Invoice#void!

3 distinct routes · 41 calls

  Admin::InvoicesController#destroy                            29 calls
  └ Invoice#void!

  Refund#process                                                9 calls
  └ Invoice#void!

  SubscriptionsController#cancel                                3 calls
  └ Cancellation#call
    └ Refund#process
      └ Invoice#void!
    └ Invoice#void!

The third route is the bug. Cancellation#call refunds the last invoice, which voids it, and then voids it again itself. Every cancellation with a refund due does it. The fix is to leave voiding to Refund:

class Cancellation
  def call
    Refund.new(subscription.last_invoice).process
    subscription.update!(state: :cancelled)
  end
end

How it works

Each record in the recording carries the call tree it belongs to and its step within that tree, along with the method that made the call and the method that received it. Starting from every recorded call to Invoice#void!, how_it_got_here walks back up its own tree, one caller at a time, to the root.

Identical chains are merged and counted, so a route that ran a thousand times appears once, with its count, and the rare one isn’t buried under it. Each chain is in call order, the same as a stack trace read from the top.

When the recording came from your test suite, each tree is stamped with the example that produced it, so every route can also name a spec that takes it: --examples adds them.

Limits

• Routes that ran. A path no recorded run took isn’t listed. Record your app as well as your suite and the production routes join the list.
• App methods only. Frames inside gems and the framework aren’t recorded, so a chain starts at the first method of yours: the controller action, the job’s perform, the spec.
• Routes, not values. It shows that Cancellation#call reached void! twice. It can’t show which invoice, or what state it was in.

Related tools