Bạn có biết có thể log tất cả method calls khi chúng xảy ra trong running process real-time? Hay inject code để thực thi bên trong running process? Bạn có thể – nhờ phép màu của gem rbtrace.
Gem rbtrace đi kèm hai phần. Phần đầu là library include vào code bạn muốn trace. Phần hai là commandline utility truy vấn trace data.
Hãy xem ví dụ đơn giản. Code chúng ta trace rất đơn giản. Chỉ cần require gem rbtrace.
require 'rbtrace' require 'digest' require 'securerandom' # Vòng lặp vô tận while true # Làm việc. Digest::SHA256.digest SecureRandom.random_bytes(2**8) # Sleep một giây mỗi iteration. sleep 1 end Bây giờ chạy chương trình này:
$ ruby trace.rb & [1] 12345 Chúng ta lấy process ID này đưa cho command line tool rbtrace. Option -f chỉ "firehose" mode, in mọi thứ ra màn hình.
$ 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> Thật cool! Chúng ta thấy mọi method được gọi cùng thời gian spent trong method đó.
Nếu muốn focus vào method cụ thể, dùng 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> Có lẽ use case cool nhất của gem này là lấy heap dump từ running web server. Heap dump chứa mọi object trong memory cùng metadata và rất hữu ích debug memory leak production.
Để lấy heap dump, dùng command như dưới, lấy từ bài của 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}' Cảnh báo: heap dump có thể rất lớn – vài trăm MB cho Rails process. Đây là sample rất nhỏ:
[ { "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 } } ]