Monitor Ruby Processes Real-time ด้วย rbtrace

รู้ไหมว่าสามารถ log ทุก method calls ขณะเกิดขึ้นใน running process real-time ได้? หรือ inject code ให้ execute ภายใน running process? ทำได้ผ่าน maagic ของ gem rbtrace

rbtrace gem มีสองส่วน: library include ใน code ที่ trace และ command-line utility query trace data

ดูตัวอย่างง่าย Code ที่ trace เรียบง่าย แค่ require rbtrace gem:

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

# Infinite loop
while true
  # Do some work.
  Digest::SHA256.digest SecureRandom.random_bytes(2**8)
  # Sleep 1 วินาทีทุก iteration
  sleep 1
end

รันโปรแกรม:

$ ruby trace.rb &
[1] 12345

เอา process ID ให้ rbtrace command-line tool option -f คือ "firehose" mode พิมพ์ทุกอย่างหน้าจอ

$ 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>

เก๋มาก! เห็นทุก method ที่ถูกเรียกพร้อมเวลาที่ใช้ในเมธอดนั้น

ถ้าอยาก focus เมธอดเฉพาะ ใช้ option -m:

$ 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>

การใช้งานที่ cool ที่สุดคือได้ heap dump จาก running web server Heap dump มีทุก objects ใน memory พร้อม metadata useful สำหรับ debug memory leaks ใน production

Command heap dump (จากโพสต์ของ Sam Saffron):

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

เตือนไว้: heap dumps ใหญ่มาก - ระดับ hundreds of megabytes สำหรับ Rails process 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"
    ]
  },
  ...
]