- 10 साल पुराने Rails production app के
web Dyno की मेमोरी deploy के दौरान अचानक बढ़ गई, और सेवा पर 400~500 req/s का लगातार लोड तथा peak पर प्रति सेकंड हज़ारों req/s आते थे, इसलिए तेज़ mitigation ज़रूरी था
- Heroku में मेमोरी सीमा के करीब पहुँच चुके Dyno को restart किया गया और पिछले 3 दिनों के code·metrics बदलाव वापस किए गए, लेकिन memory leak जारी रही
- Sidekiq और Delayed::Job सामान्य थे, जबकि केवल कुछ Puma worker ही बढ़ रहे थे, जिससे किसी खास traffic type से संबंध होने का संदेह हुआ
rbtrace, ObjectSpace, heapy, sheap, reap से heap ट्रैक करने पर पता चला कि Puma request-handling thread ActiveSupport::Notifications::Event के @children array के ज़रिए 32,067 objects और 1.9GiB मेमोरी पकड़े हुए था- छेड़छाड़ किए गए query parameter ने Bugsnag की URL cleanup प्रक्रिया में
URI::InvalidURIError पैदा किया; short-term समाधान Bugsnag upgrade था और long-term समाधान Rails upgrade
चल रहे Rails app में leak शुरू हुई
- लक्ष्य एक 10 साल पुराना Rails app था, जो वास्तविक revenue बनाने वाली production service थी
- सामान्य steady load 400~500 req/s था, और peak पर यह प्रति सेकंड हज़ारों requests तक पहुँच जाता था
- सामान्य deploy flow के दौरान memory spike शुरू हुआ और pager alert आया
- यह Heroku पर चल रहा था, इसलिए स्थिति Dyno-आधारित memory metrics से देखी गई
outage mitigation की शुरुआत Dyno restart से हुई
- यह सिर्फ साधारण memory bloat नहीं बल्कि leak जैसा लग रहा था, और अस्थायी समाधान process restart था
- आम तौर पर रोज़ाना कई deploys
web instances को restart कर देते थे, लेकिन memory limit के करीब पहुँच चुके Dyno को हाथ से restart करना पड़ा
संदिग्ध बदलाव वापस लेने पर भी leak बनी रही
- पहले बड़े spike से ठीक पहले तक पीछे जाते हुए 3 दिनों के code changes की जाँच की गई
- तीन बदलाव ऐसे लगे जिनका संबंध हो सकता था
development mode में Rails code reloading के कारण memory leak पैदा करने वाला बदलाव- खास request filtering के दौरान Redis calls अपेक्षा से ज़्यादा बढ़ाने वाला बदलाव
- अधिक database calls और
ActiveRecord instance loading पैदा करने वाला N+1 प्रकार का बदलाव
- पहले दो बदलाव ठीक किए गए, तीसरे को rollback किया गया, और इन्हें एक-एक करके deploy भी किया गया, लेकिन leak जारी रही
- Ruby language metrics और Puma pool usage metrics इकट्ठा करने के लिए किए गए tooling changes भी वापस किए गए, फिर भी memory growth नहीं रुकी
leak pattern किसी खास traffic की ओर इशारा कर रहा था
- leak केवल
web Dyno में हो रही थी; Sidekiq और Delayed::Job Dyno सामान्य दिख रहे थे
- सभी
web Dyno हर समय leak नहीं कर रहे थे
- कई घंटों तक यह लंबे समय से चल रही web process जैसी अपेक्षाकृत सपाट memory usage दिखाते थे
- फिर किसी समय एक, कुछ, या सभी Dyno leak करना शुरू कर देते थे
- Puma cluster mode में चल रहा था, और हर Dyno में 8 vCPU पर 12 worker process इस्तेमाल हो रहे थे
- एक ही Dyno के भीतर भी 12 workers में से केवल कुछ ही लगभग सारी memory इस्तेमाल कर रहे थे
- OpenTelemetry Traces में sampling बहुत अधिक थी, इसलिए किसी खास request type को किसी खास Dyno से जोड़ना कठिन था; unsampled logs के साथ correlation भी tools के स्तर पर आसान नहीं था
heap dump इकट्ठा करने की प्रक्रिया
- चल रहे Ruby process से attach होने के लिए
rbtrace का उपयोग किया गया
rbtrace को process में लोड होना ज़रूरी था, इसलिए इसे Gemfile में शामिल किया गया और environment variable से इसका loading नियंत्रित किया गया
gem "rbtrace", require: String(ENV.fetch("FEATURE_ENABLE_MEMORY_DUMPS", false)) == "true"
- Heroku में
heroku ps:exec से leaking Dyno तक SSH tunnel खोली गई, और ps से Ruby processes को RSS के आधार पर sort किया गया
ps -eo pid,ppid,comm,rss,vsz --sort -rss | grep ruby
web Dyno में एक ही PPID वाले process Puma workers थे, और सबसे ज़्यादा memory उपयोग करने वाले worker के PID को लक्ष्य बनाया गया- memory allocation tracing को
ObjectSpace.trace_object_allocations_start से चालू किया गया; इससे performance, memory और CPU पर असर पड़ सकता था
DUMP_PID=<pid>
rbtrace --pid="${DUMP_PID}" --eval="Thread.new{require 'objspace';ObjectSpace.trace_object_allocations_start}.join"
- heap dump को
ObjectSpace.dump_all से /tmp में बनाया गया, और कई घंटों से चल रहे leaking process में JSON file 5~6GiB तक बड़ी हो गई
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"
- Heroku में
heroku ps:copy से dump को local machine पर लाया गया, और heapy से retained memory देखने के लिए कम से कम लगभग तीन dump इकट्ठा किए गए
- काम पूरा होने के बाद allocation tracing बंद की गई और dump हटाए गए या Dyno restart किया गया
heap analysis में 1.9GiB पकड़े हुए Thread का पता चला
heapy की retained memory report और sheap diff से ही starting point ढूँढना मुश्किल था- Ruby heap dump के reference graph का analysis और visualization करने वाले
reap से flame graph बनाया गया
- flame graph, Ruby GC के नज़रिए से root से नीचे के objects तक जाने वाले references दिखाता है; जो objects अधिक memory पकड़े होते हैं, उनकी cells अधिक चौड़ी दिखती हैं
- तीसरे heap dump में एक
Thread 1.9GiB memory पकड़े हुए था
- वास्तव में नीचे का
Array 32,067 objects को reference कर रहा था और 1.9GiB बनाए हुए था
sheap से reference path का पीछा किया गया
- latest
main branch के sheap का उपयोग करके दूसरे और तीसरे dump की तुलना की गई
- dump का आकार 6GiB के करीब होने से parsing में समय लगा
find_path के नतीजे से पता चला कि समस्या वाला Thread telemetry या metrics tools का background thread नहीं, बल्कि request handle करने वाला Puma thread थाActiveSupport::SubscriberQueueRegistry, Rails 6.1 में event name के हिसाब से ActiveSupport::Subscriber की सूची रखने वाले thread-local Hash की तरह काम करता था- वही registry उस
Hash को reference कर रही थी, और उसके भीतर का एक Array ActiveSupport::Notifications::Event को पकड़े हुए था
- वह
Event फिर @children array के माध्यम से 32,067 से अधिक child Event objects को reference कर रहा था
- पहले child
Event का नाम redirect_to.action_controller था, और उसके भीतर ActionDispatch::Request object शामिल था
असामान्य request ने reproduction का सुराग दिया
- heap में मौजूद
ActionDispatch::Request में वास्तविक route और वैध public resource ID थी, लेकिन query parameter छेड़छाड़ किए गए रूप में थे
- request path में
password=[FILTERED] शामिल था, जिससे पता चलता था कि sensitive data cleanup प्रक्रिया बीच में आई थी
- उसी path और parameters के साथ production app को incognito browser में request करने पर 500 server error मिला
- logs में
URI::InvalidURIError दर्ज था, और यह भी पता चल गया कि request किस Dyno तक पहुँची थी
- वह Dyno उस समय सामान्य memory usage दिखा रहा था, लेकिन थोड़ी देर deploy रोककर देखने पर leak trend दिखाई दिया
- local में
activesupport Gem में binding.pry और puts debugging जोड़कर वही स्थिति और backtrace reproduce किया गया
वास्तविक कारण Rails और Bugsnag बदलावों का संयोजन था
- error backtrace Ruby standard library के
uri Gem की ओर इशारा कर रहा था, और इसका उपयोग Bugsnag के Bugsnag.cleaner.clean_url में हो रहा था
- यह code
ActiveSupport::Notifications.subscribe block के भीतर Rails breadcrumb URL को साफ़ करने की प्रक्रिया में था
- समस्या दो बातों के मेल से बनी थी
- Rails 6.1 का
ActiveSupport::Subscriber, Event#children और shared Array के साथ events को track करता था
- Bugsnag change, Rails breadcrumb URL cleanup के लिए
URI का उपयोग कर रहा था, और invalid URI पर exception आ सकता था
- जब
URI, invalid URI पर error उठाता था, तो Bugsnag का subscribe block ActiveSupport::Notifications::Event processing के दौरान exception फेंक देता था
- उस exception की वजह से parent
Event, Subscriber#event_stack से pop नहीं हुआ, और parent Event वहीं रहकर memory leak करने लगा
- parent
Event अपने #children array के ज़रिए child Event को reference करता रहा, जिससे और अधिक memory पकड़ी रही
- John Hawthorn का Rails 7.1 fix,
Event#children की अवधारणा और event tracking के shared Array दोनों को हटा देता है, जिससे leak के दोनों कारण खत्म हो जाते हैं
समाधान Bugsnag upgrade और Rails upgrade थे
- Rails के नवीनतम version में John Hawthorn के fix के कारण यह समस्या अब नहीं होती
- उस समय app Rails 6.1 पर था, इसलिए Rails fix का लाभ तुरंत नहीं मिल सकता था
- Bugsnag पहले ही
Bugsnag.cleaner.clean_url को invalid URI पर exception न फेंकने के लिए fix कर चुका था
- short-term समाधान, उस fix वाला Bugsnag Gem version upgrade करना था
- long-term समाधान Rails version upgrade करना था
- पहली memory spike के समय के साथ मेल खाने वाला बदलाव Bugsnag
v6.26.0 से v6.26.1 में upgrade था, जिसका उद्देश्य किसी दूसरी dependency की deprecation warning ठीक करना था
1 टिप्पणियां
Hacker News की राय
समझ नहीं आता कि manual memory management से लोग इतना डरते क्यों हैं। सिर्फ़ RAII और साफ़ ownership rules हों, तो memory management एक आसान engineering task है
बल्कि reference counting या shared pointers थोपने वाले frameworks ज़्यादा मुश्किल लगते हैं, क्योंकि ownership धुंधली हो जाती है
आपने खुद बनाया है तो खुद free करें, और अगर आगे पास कर दिया है तो फिर उसकी चिंता न करें। OS resources जैसे handles और sockets भी automatic resource manager के बिना manually manage किए जाते हैं, इसलिए सिर्फ़ automatic memory management के लिए design को जटिल बनाने की कोई खास वजह नहीं दिखती
कई सालों तक development करते हुए मुझे लगा कि अधिकतर developers के पास memory management के बारे में साथ-साथ reasoning करने के लिए पर्याप्त working memory बची नहीं होती। तरीका mechanically पता हो, फिर भी दिमाग में बहुत सारी चीज़ें juggling करते हुए कुछ न कुछ छूट जाता है
इसके उलट, कुछ लोग लगभग बिना मेहनत हर बार manual memory management सही कर लेते हैं। उनके लिए यह सच में आसान होता है, इसलिए उन्हें समझ नहीं आता कि दूसरों के लिए यह मुश्किल क्यों है। ऐसे लोगों को automatic memory management के फायदे अस्पष्ट और नुकसान ही बड़े दिख सकते हैं
मोटे तौर पर कहें तो ये bugs किसी दूसरे bug से replace नहीं हुए, बस गायब हो गए। यह programmers से ज़्यादा काम भी नहीं मांगता, बल्कि manual memory management की तुलना में काम कम कर देता है
बेशक garbage collection हमेशा नहीं जीतता और इसके वास्तविक drawbacks भी हैं। लेकिन अधिकतर programs में modern garbage collector इतना अच्छा होता है कि वे drawbacks बड़ी समस्या नहीं बनते
logic bugs में भी ऐसी ही समस्या होती है, और Java जैसी languages में भी कभी-कभार memory leak संभव है, लेकिन memory-safe languages एक सुधार हैं। यह वैसा ही है जैसे TypeScript, JavaScript से बेहतर है। जब ऐसी automation मौजूद है जो memory errors को 1% से 0.01% तक घटा सकती है, तो leaks और undefined behavior रोकने को लगातार manual concern क्यों बनाए रखना चाहिए, यह समझ नहीं आता
आप Java जैसी आसान लेकिन overhead वाली garbage-collected language इस्तेमाल कर सकते हैं, या Rust जैसी ownership enforce करने वाली language, जिसमें learning curve है लेकिन overhead नहीं। logic bugs भी सिरदर्द हैं, लेकिन memory bugs खास तौर पर बदनाम हैं, क्योंकि वे हमेशा साफ़ error message नहीं देते या होने पर भी program को रोकते नहीं
अलग बात के तौर पर, formal verification भी bugs की एक category को practically eliminate करने का तरीका है। अभी यह उन systems में दिखता है जहां correctness सबसे अहम है, क्योंकि memory management के उलट इसके drawbacks बहुत बड़े हैं। code बेहद verbose और कठिन हो जाता है और खास structure impose करता है। लेकिन formal verification बेहतर होगा तो मुझे लगता है यह भी ज़्यादा mainstream बनेगा
“मैं असली programmer नहीं हूं। चीज़ों को बस इस तरह जोड़ता हूं कि वे चलती दिखें, और आगे बढ़ जाता हूं। असली programmers कहेंगे, ‘चल तो रहा है, लेकिन memory इधर-उधर leak हो रही है। क्या इसे ठीक नहीं करना चाहिए?’ मैं बस हर 10 requests के बाद Apache restart कर दूंगा।” — Rasmus Lerdorf, PHP Non-Designer
https://en.wikiquote.org/wiki/Rasmus_Lerdorf
जहां मैं पहले काम करता था, वे memory leak की वजह से 5 million dollars गंवाने के सबसे बेवकूफाना तरीके का award जीत सकते थे
90s के Solaris printer driver में memory leak था[1]। उस समय मैं एक बड़े bank के contractor के तौर पर काम करता था। उन दिनों contract confirmation में fax की कानूनी स्थिति courts में पर्याप्त रूप से tested नहीं थी, इसलिए banks trades को fax से record करते थे। fax भेजने वाला system दस्तावेज़ को एक खास printer पर भी भेजता था ताकि trade confirmation print हो, और कोई व्यक्ति वह confirmation उठाकर counterparty को phone पर पढ़कर सुनाता था, ताकि call recording[2] में वह दर्ज हो और legally confirm हो सके
एक दिन memory leak की वजह से printer driver मर गया, इसलिए एक confirmation print नहीं हुआ, और ज़िम्मेदार व्यक्ति उसे phone पर पढ़कर नहीं सुना सका। market बहुत हिला, और counterparty ने उस trade को DK कर दिया[3]। bank executives ने चाहे जितना हंगामा किया, कोई फायदा नहीं हुआ; 5 million dollars का loss books में दर्ज करने के बाद, उस bank के साथ फिर कभी trade न करने की policy बना दी गई[4]। fax printer job को Windows NT पर shift कर दिया गया
[1] शानदार किताब “Expert C Programming” के मुताबिक यह समस्या इसलिए ठीक हुई कि उस समय Sun Microsystems के CEO Scott McNealy को, CEO होने के बावजूद, कम performance वाला workstation मिला और वे इस issue से अक्सर जूझते रहे; काफी शिकायतों के बाद developers ने आखिरकार इसे fix किया https://progforperf.github.io/Expert_C_Programming.pdf
[2] bank के securities division की calls legal और compliance reasons से लगभग हमेशा record की जाती हैं
[3] DK “Don’t know” का short form है। जब सामने वाला कहता है कि वह trade को “नहीं जानता”, तो वह इस बात को dispute कर रहा होता है कि contract बना था
[4] सामने वाला कहीं और trade कर सकता था और किसी दूसरे bank को fees दे सकता था, इसलिए शायद नुकसान हमारी तरफ़ ज़्यादा था
Citi पर भी इसलिए lawsuit हुआ था कि उसने loan बहुत जल्दी चुका दिया था। finance में, अगर बात अपने पक्ष में हो तो मुझे लगता है कोई भी written contract को लेकर बहुत सख्त रुख अपनाएगा
C में Valgrind की वजह से leaks ढूंढना बहुत आसान है
उन्हें ठीक करना ज़्यादा मुश्किल है, लेकिन अगर design सही हो तो आम तौर पर आसान होता है। आम तौर पर, जब तक कोई function caller के लिए allocate करने वाला function न हो, allocation और free उसी function के अंदर किए जाते हैं। अगर function caller के लिए allocate करता है, तो उस call को ही caller-side allocation माना जाता है
codebase की static analysis करने पर error-handling paths समस्या की सबसे आम वजह निकले
जैसे block scope, function scope, file scope, global scope होते हैं, वैसे ही problem domain या solution के abstraction वाले model में भी scope के कई levels होते हैं। हालांकि मैंने इसे पढ़ाया जाते नहीं देखा है
अगर कोई scope
$SCOPE::foo()में resource acquire करता है और$SCOPE::cleanup()में release नहीं करता, तो उसे आंखों से ढूंढना काफी आसान है। coding में कूदने से पहले problem domain और proposed solution को model करने की क्षमता उपयोगी हैYahoo के बारे में सुनी एक कहानी याद आती है। ad server में memory leak था, इसलिए करीब 10000 requests के बाद out of memory हो जाता था
समाधान था 8000 requests के बाद server को restart करना। यह तरीका 1–2 साल चला, लेकिन बाद में 8000 requests के बाद भी out of memory होने लगा
अगला समाधान था 6000 requests के बाद server को restart करना
उस तरीके के काम करने के लिए restart बेहद तेज़ होना चाहिए
जब मैं Rails developer था, तो ऐसी समस्याओं पर ज्यादा hardware लगाना productivity के लिए ठीक-ठाक trade-off माना जाता था। माहौल ऐसा था कि अगर आपको इस तरह की problems की चिंता है, तो ज़्यादा strict tools इस्तेमाल कर लें
व्यक्तिगत रूप से, अपनी perfectionist tendency के कारण वह approach स्वीकार करना मेरे लिए मुश्किल है, लेकिन यह मानना भी मुश्किल है कि वह सच में काम नहीं करती
मैंने garbage collection वाली और बिना garbage collection वाली दोनों तरह की languages इस्तेमाल की हैं। आम तौर पर manual management लिखना ज़्यादा मुश्किल होता है, और automatic management में problems debug करना ज़्यादा मुश्किल होता है
मैं ऐसी language इस्तेमाल करना चाहूंगा जिसमें दोनों कर सकूं। exploratory code लिखते समय automatic memory management सुविधाजनक है, और कुछ तरह के code के लिए manual memory management बेहतर होता है
ban और compulsion के बीच का middle ground न मिलना निराशाजनक है
@[manualfree]attribute से function या module के हिसाब से इसे आसानी से बंद किया जा सकता है, औरv -gc noneसे पूरे project में भी बंद किया जा सकता हैhttps://vlang.io
“leaks profile करने के कई tools, heap dumps को समझने, और leaks के common causes पर बहुत कुछ लिखा गया है”
उफ़, leaks और heap dumps। लगता है किसी को ज़्यादा healthy diet की ज़रूरत है