Spying on running Ruby processes

Did you know that it's possible to log all method calls as they occur in a running process in real time? How about injecting code to be executed inside of a running process? You can – via the magic of the rbtrace gem.

Did you know that it's possible to log all method calls as they occur in a running process in real time? How about injecting code to be executed inside of a running process? You can – via the magic of the rbtrace gem.

The rbtrace gem comes with two parts. The first is a library that you include in the code that you want to trace. The second is a commandline utility for querying trace data.

Let's take a look at a simple example. The code that we're going to trace is really simple. All we have to do is require the rbtrace gem.

require 'rbtrace'
require 'digest'
require 'securerandom'

# An infinite loop
while true

  # Do some work. 
  Digest::SHA256.digest SecureRandom.random_bytes(2**8)

  # Sleep for one second on every iteration.
  sleep 1
end

Now let's run this program:

$ ruby trace.rb &
[1] 12345

We take this process ID and give it to the rbtrace command line tool. The -f option indicates "firehose" mode, which prints everything to screen.

$ rbtrace -p 12345 -f
*** attached to process 12345
Fixnum#** <0.000010>
SecureRandom.random_bytes
  Integer#to_int <0.000005>
  SecureRandom.gen_random
    OpenSSL::Random.random_bytes <0.002223>
  SecureRandom.gen_random <0.002243>
SecureRandom.random_bytes <0.002290>

Digest::SHA256.digest
  Digest::Class#initialize <0.000004>
  Digest::Instance#digest
    Digest::Base#reset <0.000005>
    Digest::Base#update <0.000210>
    Digest::Base#finish <0.000006>
    Digest::Base#reset <0.000005>
  Digest::Instance#digest <0.000267>
Digest::SHA256.digest <0.000308>

Kernel#rand
  Kernel#respond_to_missing? <0.000008>
Kernel#rand <0.000071>

Kernel#sleep <1.003233>

This is really cool! We can see every method that gets called along with the time spent in that method.

If we wanted to home in on a specific method, we could use the -m option.

$ rbtrace -p 12345 -m digest
*** attached to process 12345
Digest::SHA256.digest
  Digest::Instance#digest <0.000201>
Digest::SHA256.digest <0.000220>

Digest::SHA256.digest
  Digest::Instance#digest <0.000287>
Digest::SHA256.digest <0.000343>

Probably the coolest use of this gem is to get a heap dump from a running web server. Heap dumps contain every object in memory along with a bunch of metadata and are very useful for debugging memory leaks in production.

To get the heap dump use a command like the one below, taken from this post by Sam Saffron.

$ bundle exec rbtrace -p <SERVER PID HERE> -e 'Thread.new{GC.start;require "objspace";io=File.open("/tmp/ruby-heap.dump", "w"); ObjectSpace.dump_all(output: io); io.close}'

Be warned though, heap dumps can be very big – on the order of a few hundred megabytes for a rails process. Here's a very small sample:

[
  {
    "type": "ROOT",
    "root": "vm",
    "references": [
      "0x7fb7d38bc3f0",
      "0x7fb7d38b79b8",
      "0x7fb7d38dff80",
      "0x7fb7d38bff50",
      "0x7fb7d38bff00",
      "0x7fb7d38b4bf0",
      "0x7fb7d38bfe88",
      "0x7fb7d38bfe60",
      "0x7fb7d38ddc80",
      "0x7fb7d38dffa8",
      "0x7fb7d382fbd0",
      "0x7fb7d382fbf8"
    ]
  },
  {
    "type": "ROOT",
    "root": "machine_context",
    "references": [
      "0x7fb7d382fbf8",
      "0x7fb7d382fbf8",
      "0x7fb7d3827d40",
      "0x7fb7d3827a70",
      "0x7fb7d38becb8",
      "0x7fb7d38bed08",
      "0x7fb7d38ddc80",
      "0x7fb7d3827e58",
      "0x7fb7d3827e58",
      "0x7fb7d38becb8",
      "0x7fb7d38becb8",
      "0x7fb7d38bc328",
      "0x7fb7d38bc378",
      "0x7fb7d38ddc80",
      "0x7fb7d3835008",
      "0x7fb7d3835008",
      "0x7fb7d3835008",
      "0x7fb7d3835008",
      "0x7fb7d3835008"
    ]
  },
  {
    "type": "ROOT",
    "root": "global_list",
    "references": [
      "0x7fb7d38dff58"
    ]
  },
  {
    "type": "ROOT",
    "root": "global_tbl",
    "references": [
      "0x7fb7d38c6dc8",
      "0x7fb7d38c6dc8",
      "0x7fb7d38c65f8",
      "0x7fb7d38c6580",
      "0x7fb7d38c6508",
      "0x7fb7d38c6580",
      "0x7fb7d38c6288",
      "0x7fb7d38c6288",
      "0x7fb7d38c6288",
      "0x7fb7d38c6288",
      "0x7fb7d38c6288",
      "0x7fb7d38bc418",
      "0x7fb7d38bc418",
      "0x7fb7d38bc418",
      "0x7fb7d3835328",
      "0x7fb7d3835328"
    ]
  },
  {
    "address": "0x7fb7d300c5e8",
    "type": "STRING",
    "class": "0x7fb7d38dcee8",
    "frozen": true,
    "embedded": true,
    "fstring": true,
    "bytesize": 10,
    "value": "@exit_code",
    "encoding": "US-ASCII",
    "memsize": 40,
    "flags": {
      "wb_protected": true,
      "old": true,
      "long_lived": true,
      "marked": true
    }
  },
  {
    "address": "0x7fb7d300c7a0",
    "type": "STRING",
    "class": "0x7fb7d38dcee8",
    "frozen": true,
    "embedded": true,
    "fstring": true,
    "bytesize": 9,
    "value": "exit_code",
    "encoding": "US-ASCII",
    "memsize": 40,
    "flags": {
      "wb_protected": true,
      "old": true,
      "long_lived": true,
      "marked": true
    }
  },
  {
    "address": "0x7fb7d300c908",
    "type": "STRING",
    "class": "0x7fb7d38dcee8",
    "frozen": true,
    "embedded": true,
    "fstring": true,
    "bytesize": 19,
    "value": "SystemExitException",
    "encoding": "US-ASCII",
    "memsize": 40,
    "flags": {
      "wb_protected": true,
      "old": true,
      "long_lived": true,
      "marked": true
    }
  },
  {
    "address": "0x7fb7d300cb60",
    "type": "STRING",
    "class": "0x7fb7d38dcee8",
    "frozen": true,
    "embedded": true,
    "fstring": true,
    "bytesize": 17,
    "value": "VerificationError",
    "encoding": "US-ASCII",
    "memsize": 40,
    "flags": {
      "wb_protected": true,
      "old": true,
      "long_lived": true,
      "marked": true
    }
  },
  {
    "address": "0x7fb7d300cd90",
    "type": "STRING",
    "class": "0x7fb7d38dcee8",
    "frozen": true,
    "embedded": true,
    "fstring": true,
    "bytesize": 19,
    "value": "RubyVersionMismatch",
    "encoding": "US-ASCII",
    "memsize": 40,
    "flags": {
      "wb_protected": true,
      "old": true,
      "long_lived": true,
      "marked": true
    }
  },
  {
    "address": "0x7fb7d300cfe8",
    "type": "STRING",
    "class": "0x7fb7d38dcee8",
    "frozen": true,
    "embedded": true,
    "fstring": true,
    "bytesize": 21,
    "value": "RemoteSourceException",
    "encoding": "US-ASCII",
    "memsize": 40,
    "flags": {
      "wb_protected": true,
      "old": true,
      "long_lived": true,
      "marked": true
    }
  },
  {
    "address": "0x7fb7d300d1f0",
    "type": "STRING",
    "class": "0x7fb7d38dcee8",
    "frozen": true,
    "fstring": true,
    "bytesize": 25,
    "value": "RemoteInstallationSkipped",
    "encoding": "US-ASCII",
    "memsize": 66,
    "flags": {
      "wb_protected": true,
      "old": true,
      "long_lived": true,
      "marked": true
    }
  },
  {
    "address": "0x7fb7d300d3a8",
    "type": "STRING",
    "class": "0x7fb7d38dcee8",
    "frozen": true,
    "fstring": true,
    "bytesize": 27,
    "value": "RemoteInstallationCancelled",
    "encoding": "US-ASCII",
    "memsize": 68,
    "flags": {
      "wb_protected": true,
      "old": true,
      "long_lived": true,
      "marked": true
    }
  },
  {
    "address": "0x7fb7d300d560",
    "type": "STRING",
    "class": "0x7fb7d38dcee8",
    "frozen": true,
    "embedded": true,
    "fstring": true,
    "bytesize": 11,
    "value": "RemoteError",
    "encoding": "US-ASCII",
    "memsize": 40,
    "flags": {
      "wb_protected": true,
      "old": true,
      "long_lived": true,
      "marked": true
    }
  },
  {
    "address": "0x7fb7d300d830",
    "type": "STRING",
    "class": "0x7fb7d38dcee8",
    "frozen": true,
    "fstring": true,
    "bytesize": 26,
    "value": "OperationNotSupportedError",
    "encoding": "US-ASCII",
    "memsize": 67,
    "flags": {
      "wb_protected": true,
      "old": true,
      "long_lived": true,
      "marked": true
    }
  },
  {
    "address": "0x7fb7d300dbc8",
    "type": "STRING",
    "class": "0x7fb7d38dcee8",
    "frozen": true,
    "embedded": true,
    "fstring": true,
    "bytesize": 12,
    "value": "InstallError",
    "encoding": "US-ASCII",
    "memsize": 40,
    "flags": {
      "wb_protected": true,
      "old": true,
      "long_lived": true,
      "marked": true
    }
  },
  {
    "address": "0x7fb7d300e898",
    "type": "STRING",
    "class": "0x7fb7d38dcee8",
    "frozen": true,
    "embedded": true,
    "fstring": true,
    "bytesize": 9,
    "value": "requester",
    "encoding": "US-ASCII",
    "memsize": 40,
    "flags": {
      "wb_protected": true,
      "old": true,
      "long_lived": true,
      "marked": true
    }
  },
  {
    "address": "0x7fb7d300eaa0",
    "type": "STRING",
    "class": "0x7fb7d38dcee8",
    "frozen": true,
    "embedded": true,
    "fstring": true,
    "bytesize": 13,
    "value": "build_message",
    "encoding": "US-ASCII",
    "memsize": 40,
    "flags": {
      "wb_protected": true,
      "old": true,
      "long_lived": true,
      "marked": true
    }
  },
  {
    "address": "0x7fb7d300ec30",
    "type": "STRING",
    "class": "0x7fb7d38dcee8",
    "frozen": true,
    "embedded": true,
    "fstring": true,
    "bytesize": 8,
    "value": "@request",
    "encoding": "US-ASCII",
    "memsize": 40,
    "flags": {
      "wb_protected": true,
      "old": true,
      "long_lived": true,
      "marked": true
    }
  },
  {
    "address": "0x7fb7d300ede8",
    "type": "STRING",
    "class": "0x7fb7d38dcee8",
    "frozen": true,
    "embedded": true,
    "fstring": true,
    "bytesize": 7,
    "value": "request",
    "encoding": "US-ASCII",
    "memsize": 40,
    "flags": {
      "wb_protected": true,
      "old": true,
      "long_lived": true,
      "marked": true
    }
  },
  {
    "address": "0x7fb7d300efa0",
    "type": "STRING",
    "class": "0x7fb7d38dcee8",
    "frozen": true,
    "fstring": true,
    "bytesize": 27,
    "value": "ImpossibleDependenciesError",
    "encoding": "US-ASCII",
    "memsize": 68,
    "flags": {
      "wb_protected": true,
      "old": true,
      "long_lived": true,
      "marked": true
    }
  }
]
What to do next:
  1. Try Honeybadger for FREE
    Honeybadger helps you find and fix errors before your users can even report them. Get set up in minutes and check monitoring off your to-do list.
    Start free trial
    Easy 5-minute setup — No credit card required
  2. Get the Honeybadger newsletter
    Each month we share news, best practices, and stories from the DevOps & monitoring community—exclusively for developers like you.
    author photo

    Starr Horne

    Starr Horne is a Rubyist and Chief JavaScripter at Honeybadger.io. When she's not neck-deep in other people's bugs, she enjoys making furniture with traditional hand-tools, reading history and brewing beer in her garage in Seattle.

    More articles by Starr Horne
    Stop wasting time manually checking logs for errors!

    Try the only application health monitoring tool that allows you to track application errors, uptime, and cron jobs in one simple platform.

    • Know when critical errors occur, and which customers are affected.
    • Respond instantly when your systems go down.
    • Improve the health of your systems over time.
    • Fix problems before your customers can report them!

    As developers ourselves, we hated wasting time tracking down errors—so we built the system we always wanted.

    Honeybadger tracks everything you need and nothing you don't, creating one simple solution to keep your application running and error free so you can do what you do best—release new code. Try it free and see for yourself.

    Start free trial
    Simple 5-minute setup — No credit card required

    Learn more

    "We've looked at a lot of error management systems. Honeybadger is head and shoulders above the rest and somehow gets better with every new release."
    — Michael Smith, Cofounder & CTO of YvesBlue

    Honeybadger is trusted by top companies like:

    “Everyone is in love with Honeybadger ... the UI is spot on.”
    Molly Struve, Sr. Site Reliability Engineer, Netflix
    Start free trial
    Are you using Sentry, Rollbar, Bugsnag, or Airbrake for your monitoring? Honeybadger includes error tracking with a whole suite of amazing monitoring tools — all for probably less than you're paying now. Discover why so many companies are switching to Honeybadger here.
    Start free trial
    Stop digging through chat logs to find the bug-fix someone mentioned last month. Honeybadger's built-in issue tracker keeps discussion central to each error, so that if it pops up again you'll be able to pick up right where you left off.
    Start free trial
    “Wow — Customers are blown away that I email them so quickly after an error.”
    Chris Patton, Founder of Punchpass.com
    Start free trial