- Memori Dyno
web pada aplikasi produksi Rails berusia 10 tahun melonjak saat deployment, dan karena layanan ini menangani beban berkelanjutan 400–500 req/s serta ribuan req/s saat puncak, mitigasi cepat diperlukan
- Di Heroku, Dyno yang mendekati batas memori direstart dan perubahan kode serta metrik dari 3 hari terakhir dikembalikan, tetapi kebocoran memori tetap berlanjut
- Sidekiq dan Delayed::Job normal, sementara hanya sebagian Puma worker yang membesar, sehingga dicurigai ada kaitan dengan jenis traffic tertentu
- Setelah menelusuri heap dengan
rbtrace, ObjectSpace, heapy, sheap, dan reap, ditemukan bahwa thread pemrosesan request Puma menahan 32.067 objek dan memori 1,9 GiB melalui array @children milik ActiveSupport::Notifications::Event
- Parameter query yang dimanipulasi memicu
URI::InvalidURIError dalam proses pembersihan URL Bugsnag; respons jangka pendeknya adalah upgrade Bugsnag, sedangkan respons jangka panjangnya adalah upgrade Rails
Kebocoran mulai terjadi pada aplikasi Rails yang sedang berjalan
- Targetnya adalah aplikasi Rails berusia 10 tahun, sebuah layanan produksi yang benar-benar menghasilkan pendapatan
- Beban berkelanjutan normalnya 400–500 req/s, dan puncaknya bisa mencapai ribuan request per detik
- Lonjakan memori mulai terjadi di tengah alur deployment biasa, lalu memicu alert pager
- Karena berjalan di Heroku, kondisi dipantau berdasarkan angka memori per Dyno
Mitigasi insiden dimulai dengan restart Dyno
- Gejalanya tampak bukan sekadar pembengkakan memori (bloat), melainkan seperti kebocoran, dan solusi sementaranya adalah restart proses
- Biasanya beberapa deployment harian merestart instance
web, tetapi Dyno yang mendekati batas memori direstart secara manual
Kebocoran tetap ada meski perubahan yang dicurigai dikembalikan
- Mulai dari tepat sebelum lonjakan besar pertama, dilakukan audit atas perubahan kode selama 3 hari
- Ada tiga perubahan yang tampak berpotensi terkait
- Perubahan yang menyebabkan kebocoran memori akibat reloading kode Rails dalam mode
development
- Perubahan yang membuat panggilan Redis menjadi lebih banyak dari yang dimaksud saat filtering request tertentu
- Perubahan bergaya N+1 yang memicu lebih banyak panggilan database dan pemuatan instance
ActiveRecord
- Dua perubahan pertama diperbaiki, perubahan ketiga di-rollback, lalu semuanya dideploy satu per satu, tetapi kebocoran tetap berlanjut
- Perubahan tool untuk mengumpulkan metrik bahasa Ruby dan metrik penggunaan Puma pool juga dikembalikan, tetapi pertumbuhan memori tidak berhenti
Pola kebocoran mengarah ke traffic tertentu
- Kebocoran hanya terjadi pada Dyno
web, sementara Dyno Sidekiq dan Delayed::Job tampak normal
- Tidak semua Dyno
web selalu mengalami kebocoran
- Selama beberapa jam, penggunaan memori terlihat relatif datar seperti proses web yang berjalan lama
- Setelah itu, pada suatu titik satu, beberapa, atau semua Dyno mulai bocor
- Puma berjalan dalam mode cluster, dan setiap Dyno menggunakan 12 worker process untuk 8 vCPU
- Bahkan di dalam satu Dyno, terkadang hanya sebagian dari 12 worker yang menggunakan hampir seluruh memori
- OpenTelemetry Traces sangat banyak disampling, sehingga sulit mengaitkan jenis request tertentu dengan Dyno tertentu; korelasi dengan log yang tidak disampling juga tidak mudah dilakukan dengan tool yang ada
Prosedur mengumpulkan heap dump
- Untuk menempel ke proses Ruby yang sedang berjalan, digunakan
rbtrace
- Karena
rbtrace harus sudah dimuat ke dalam proses, ia dimasukkan ke Gemfile, dan apakah ia dimuat atau tidak dikontrol lewat environment variable
gem "rbtrace", require: String(ENV.fetch("FEATURE_ENABLE_MEMORY_DUMPS", false)) == "true"
- Di Heroku,
heroku ps:exec digunakan untuk membuka tunnel SSH ke Dyno yang sedang bocor, lalu ps digunakan untuk mengurutkan proses Ruby berdasarkan RSS
ps -eo pid,ppid,comm,rss,vsz --sort -rss | grep ruby
- Pada Dyno
web, proses-proses dengan PPID yang sama adalah Puma worker, dan PID worker yang memakai memori paling besar dijadikan target
- Pelacakan alokasi memori diaktifkan dengan
ObjectSpace.trace_object_allocations_start, dan ini dapat berdampak pada performa, memori, dan CPU
DUMP_PID=<pid>
rbtrace --pid="${DUMP_PID}" --eval="Thread.new{require 'objspace';ObjectSpace.trace_object_allocations_start}.join"
- Heap dump dibuat di
/tmp dengan ObjectSpace.dump_all, dan pada proses bocor yang telah berjalan beberapa jam, file JSON bisa membengkak hingga 5–6 GiB
rbtrace --pid="${DUMP_PID}" --eval="Thread.new{require 'objspace'; GC.start(); io=File.open('/tmp/heap-${DUMP_PID}.json', 'w'); ObjectSpace.dump_all(output: io); io.close}.join" --timeout=600
gzip "/tmp/heap-${DUMP_PID}.json"
- Di Heroku, dump diambil ke lokal dengan
heroku ps:copy, dan untuk melihat retained memory dengan heapy, setidaknya sekitar tiga dump dikumpulkan
- Setelah pekerjaan selesai, pelacakan alokasi dimatikan dan dump dihapus, atau Dyno direstart
Analisis heap mengungkap Thread yang menahan 1,9 GiB
- Laporan retained memory dari
heapy dan diff sheap saja tidak cukup untuk menemukan titik awal
- Flame graph dibuat dengan
reap, yang menganalisis dan memvisualisasikan graph referensi Ruby heap dump
- Flame graph menunjukkan referensi dari root menurut perspektif Ruby GC ke objek-objek di bawahnya; semakin banyak memori yang ditahan sebuah objek, semakin lebar selnya ditampilkan
- Pada heap dump ketiga, satu
Thread menahan memori 1,9 GiB
- Pada kenyataannya,
Array di bawahnya mereferensikan 32.067 objek dan mempertahankan 1,9 GiB tersebut
Menelusuri jalur referensi dengan sheap
sheap dari branch main terbaru digunakan untuk membandingkan dump kedua dan ketiga- Karena ukuran dump mendekati 6 GiB, parsing memakan waktu
- Hasil
find_path menunjukkan bahwa Thread bermasalah bukanlah thread background dari tool telemetry atau metrik, melainkan Puma thread yang menangani request
ActiveSupport::SubscriberQueueRegistry di Rails 6.1 bekerja sebagai Hash per thread yang menyimpan daftar ActiveSupport::Subscriber berdasarkan nama event- Registry tersebut mereferensikan sebuah
Hash, dan salah satu Array di dalamnya menahan ActiveSupport::Notifications::Event
Event itu kemudian mereferensikan lebih dari 32.067 objek child Event melalui array @children- Nama child
Event pertama adalah redirect_to.action_controller, dan di dalamnya terdapat objek ActionDispatch::Request
Request abnormal menjadi petunjuk reproduksi
ActionDispatch::Request di dalam heap memiliki route nyata dan ID resource publik yang valid, tetapi parameter query-nya berbentuk hasil manipulasi- Path request memuat
password=[FILTERED], menunjukkan bahwa proses pembersihan informasi sensitif ikut terlibat
- Ketika aplikasi produksi diminta dari browser privat dengan path dan parameter yang sama, terjadi 500 server error
- Log mencatat
URI::InvalidURIError, dan Dyno tempat request tiba juga dapat diidentifikasi
- Dyno tersebut saat itu menunjukkan penggunaan memori normal, tetapi setelah deployment dihentikan sebentar dan diamati, tren kebocoran muncul
- Secara lokal, situasi dan backtrace yang sama direproduksi dengan menambahkan debugging
binding.pry dan puts ke Gem activesupport
Penyebab sebenarnya adalah kombinasi perubahan Rails dan Bugsnag
- Backtrace error menunjuk ke Gem
uri dari standard library Ruby, yang digunakan di Bugsnag.cleaner.clean_url milik Bugsnag
- Kode ini berada dalam proses membersihkan URL breadcrumb Rails di dalam blok
ActiveSupport::Notifications.subscribe
- Masalahnya merupakan gabungan dua hal
ActiveSupport::Subscriber di Rails 6.1 melacak event dengan Event#children dan shared Array- Perubahan Bugsnag memakai
URI untuk membersihkan URL breadcrumb Rails, dan pada URI yang tidak valid dapat terjadi exception
- Jika
URI memunculkan error pada invalid URI, blok subscribe Bugsnag memunculkan exception saat memproses ActiveSupport::Notifications::Event
- Karena exception itu, parent
Event tidak di-pop dari Subscriber#event_stack, sehingga parent Event tertinggal dan membocorkan memori
- Parent
Event terus mereferensikan child Event melalui array #children, sehingga lebih banyak memori tetap tertahan
- Perbaikan Rails 7.1 oleh John Hawthorn menghapus konsep
Event#children dan shared Array untuk pelacakan event, sehingga kedua penyebab kebocoran tersebut sama-sama hilang
Solusinya adalah upgrade Bugsnag dan upgrade Rails
- Pada versi Rails terbaru, masalah ini tidak lagi terjadi karena perbaikan dari John Hawthorn
- Saat itu aplikasi masih memakai Rails 6.1, sehingga tidak bisa langsung mendapatkan efek perbaikan Rails
- Bugsnag sudah memperbaiki
Bugsnag.cleaner.clean_url agar tidak memunculkan exception pada invalid URI
- Solusi jangka pendeknya adalah upgrade ke versi Gem Bugsnag yang mencakup perbaikan tersebut
- Solusi jangka panjangnya adalah upgrade versi Rails
- Perubahan yang bertepatan dengan lonjakan memori pertama adalah upgrade Bugsnag dari
v6.26.0 ke v6.26.1, yang tujuannya memperbaiki deprecation warning dari dependency lain
1 komentar
Komentar Hacker News
Saya tidak mengerti mengapa manajemen memori manual dianggap begitu menakutkan. Dengan RAII dan aturan kepemilikan yang jelas saja, manajemen memori adalah pekerjaan engineering yang mudah.
Justru framework yang memaksakan reference counting atau shared pointer terasa lebih sulit, karena kepemilikannya menjadi kabur.
Kalau membuatnya sendiri, bebaskan sendiri; kalau sudah menyerahkannya, tidak perlu dipikirkan lagi. Resource OS seperti handle dan socket pun dikelola secara manual tanpa resource manager otomatis, jadi rasanya tidak ada alasan untuk memperumit desain dengan manajemen memori otomatis.
Setelah bertahun-tahun mengembangkan software, saya melihat sebagian besar developer tidak punya cukup ruang working memory untuk sekaligus menalar manajemen memori. Walaupun secara mekanis tahu caranya, jika terlalu banyak hal yang harus dijaga di kepala, ada yang akan terlewat.
Sebaliknya, ada segelintir orang yang hampir tanpa kesulitan selalu benar dalam manajemen memori manual. Bagi mereka itu memang mudah, sehingga sulit memahami mengapa bagi orang lain sulit. Bagi orang seperti ini, manfaat manajemen memori otomatis bisa tampak tidak jelas, sementara kekurangannya terlihat besar.
Secara kasar, bug seperti ini bukan digantikan oleh bug lain, melainkan hilang begitu saja. Ini juga tidak menuntut lebih banyak pekerjaan dari programmer; justru mengurangi pekerjaan dibanding manajemen memori manual.
Tentu garbage collection tidak selalu menang, dan ada kekurangan nyata. Namun untuk sebagian besar program, garbage collector modern sudah cukup baik sehingga kekurangan itu bukan masalah besar.
Bug logika juga punya masalah serupa, dan kebocoran memori kadang masih mungkin di bahasa seperti Java, tetapi bahasa yang memory-safe adalah peningkatan. Mirip seperti TypeScript lebih baik daripada JavaScript. Jika ada otomatisasi yang bisa menurunkan kesalahan memori dari 1% menjadi 0,01%, saya tidak mengerti mengapa pencegahan kebocoran dan undefined behavior harus terus dibiarkan sebagai perhatian manual.
Kita bisa memakai bahasa dengan garbage collection yang mudah tetapi punya overhead seperti Java, atau bahasa yang memaksa kepemilikan tanpa overhead tetapi punya learning curve seperti Rust. Bug logika juga merepotkan, tetapi bug memori sangat terkenal buruk karena kadang tidak memberi pesan error yang jelas, atau sekalipun terjadi program tidak berhenti.
Sebagai catatan samping, verifikasi formal juga merupakan cara untuk praktis menghilangkan satu kategori bug. Saat ini ia hanya terlihat pada sistem yang sangat mengutamakan correctness, karena tidak seperti manajemen memori, kekurangannya terlalu besar. Kodenya sangat verbose dan rewel, serta memaksakan struktur tertentu. Namun jika verifikasi formal membaik, saya rasa ini juga akan menjadi lebih mainstream.
“Saya bukan programmer sungguhan. Saya sekadar menempelkan ini-itu sampai seolah-olah berjalan, lalu lanjut. Programmer sungguhan akan berkata, ‘Ini memang berjalan, tetapi memorinya bocor di sana-sini. Bukankah harus diperbaiki?’ Saya akan cukup me-restart Apache setiap 10 request.” — Rasmus Lerdorf, PHP Non-Designer
https://en.wikiquote.org/wiki/Rasmus_Lerdorf
Tempat kerja saya dulu pantas mendapat penghargaan cara paling bodoh menghanguskan 5 juta dolar karena kebocoran memori.
Pada driver printer Solaris era 90-an ada kebocoran memori[1]. Saat itu saya bekerja sebagai kontraktor untuk sebuah bank besar; pada masa itu status hukum faks dalam konfirmasi kontrak belum cukup teruji di pengadilan, sehingga bank-bank mencatat transaksi lewat faks. Sistem yang mengirim faks juga mengirim dokumen ke printer tertentu untuk mencetak konfirmasi transaksi, lalu seseorang mengambil konfirmasi itu dan membacakannya lewat telepon kepada pihak lawan agar terekam dalam rekaman panggilan[2] dan terkonfirmasi secara hukum.
Suatu hari, karena kebocoran memori, driver printer mati dan satu konfirmasi tidak tercetak, sehingga petugas tidak bisa membacakannya lewat telepon. Pasar bergerak besar, dan pihak lawan memperlakukan transaksi itu sebagai DK[3]. Sekeras apa pun para eksekutif bank mengamuk, tidak ada gunanya; setelah membukukan kerugian 5 juta dolar, mereka membuat kebijakan untuk tidak pernah lagi berdagang dengan bank itu[4]. Pekerjaan printer faks dipindahkan ke Windows NT.
[1] Menurut buku bagus “Expert C Programming”, masalah ini sering dialami oleh Scott McNealy, CEO Sun Microsystems saat itu, karena meskipun ia CEO ia mendapat workstation berkinerja rendah; setelah cukup banyak mengeluh, para developer akhirnya memperbaikinya. https://progforperf.github.io/Expert_C_Programming.pdf
[2] Panggilan di divisi sekuritas bank hampir selalu direkam untuk alasan legal dan compliance.
[3] DK adalah singkatan dari “Don’t know”. Jika pihak lawan mengatakan mereka “tidak tahu” transaksi itu, berarti mereka memperdebatkan bahwa kontrak telah terbentuk.
[4] Pihak lawan bisa berdagang di tempat lain dan membayar komisi ke bank lain, jadi mungkin pihak kamilah yang lebih rugi.
Citi juga pernah menghadapi gugatan karena melunasi pinjaman terlalu cepat. Di dunia keuangan, jika menguntungkan mereka, saya rasa siapa pun akan berpegang keras pada kontrak tertulis.
Di C, menemukan kebocoran jadi sangat mudah berkat Valgrind
Memperbaikinya lebih sulit, tetapi jika desainnya benar, biasanya mudah. Biasanya, kecuali fungsi yang mengalokasikan untuk pemanggil, alokasi dan pembebasan dilakukan dalam fungsi yang sama. Jika itu fungsi yang mengalokasikan untuk pemanggil, pemanggilan itu sendiri dianggap sebagai alokasi di sisi pemanggil
Saat melakukan analisis statis pada codebase, jalur penanganan error adalah penyebab masalah yang paling umum
Seperti ada block scope, function scope, file scope, dan global scope, model yang merupakan abstraksi dari ranah masalah atau solusi juga memiliki beberapa tingkat scope. Namun saya belum pernah melihat ini diajarkan
Jika suatu scope memperoleh resource di
$SCOPE::foo()dan tidak melepaskannya di$SCOPE::cleanup(), itu cukup mudah ditemukan dengan mata. Kemampuan memodelkan ranah masalah dan solusi yang diusulkan sebelum terjun menulis kode itu bergunaSaya teringat cerita yang pernah saya dengar tentang Yahoo. Ada kebocoran memori di server iklan, sehingga setelah kira-kira 10000 request terjadi kehabisan memori
Solusinya adalah me-restart server setelah 8000 request. Cara ini berhasil selama 1–2 tahun, tetapi kemudian mulai kehabisan memori bahkan setelah 8000 request
Solusi berikutnya adalah me-restart server setelah 6000 request
Agar cara itu berhasil, restart-nya harus sangat cepat
Saat saya menjadi developer Rails, menambah hardware untuk masalah seperti ini dianggap sebagai trade-off yang cukup baik demi produktivitas. Suasananya: kalau peduli pada masalah semacam ini, gunakan saja tool yang lebih ketat
Secara pribadi, karena kecenderungan perfeksionis, sulit bagi saya menerima pendekatan itu, tetapi sulit juga menyangkal bahwa praktiknya memang berjalan
Saya pernah memakai bahasa dengan garbage collection maupun tanpa garbage collection. Biasanya manajemen manual lebih sulit ditulis, sedangkan manajemen otomatis lebih sulit dipecahkan saat bermasalah
Saya ingin memakai bahasa yang bisa melakukan keduanya. Saat menulis kode eksploratif, manajemen memori otomatis terasa nyaman, dan untuk jenis kode tertentu manajemen memori manual lebih menguntungkan
Menyebalkan karena sulit menemukan titik tengah antara pelarangan dan pemaksaan
@[manualfree], dan juga bisa dimatikan untuk seluruh proyek denganv -gc nonehttps://vlang.io
“Sudah banyak tulisan tentang berbagai tool untuk memprofilkan kebocoran, memahami heap dump, dan penyebab umum kebocoran”
Ugh, kebocoran dan heap dump. Sepertinya ada yang perlu pola makan lebih sehat