1 पॉइंट द्वारा GN⁺ 2023-07-31 | 1 टिप्पणियां | WhatsApp पर शेयर करें
  • 8 जुलाई 2023 को Vivaldi Social के Mastodon instance पर पुराने user accounts गायब हो गए, और अंततः 198 accounts एक ही remote account में merge हो गए
  • यह सीधे deletion या attack की वजह से नहीं था, बल्कि Mastodon के account merge behavior और Vivaldi Social की Makara-आधारित PostgreSQL replication configuration के साथ ऑपरेशन order बिगड़ जाने से हुआ
  • accounts deleted दिख रहे थे, लेकिन usernames फिर से allocate हो रहे थे और avatar तथा header images भी साथ में गायब हो रही थीं, जिससे समस्या Mastodon application के अंदरूनी behavior तक सीमित हुई
  • operations team ने पूरे DB rollback की तैयारी करते हुए selective recovery scripts भी साथ-साथ चलाए, जिनसे account, post, follow, follower और relationship data वापस लाया गया
  • Mastodon v4.1.5 में Sidekiq workers द्वारा Makara के उपयोग को रोकने और account merge order को ठीक करने वाले बदलाव शामिल हैं, इसलिए replication DB चलाने वाले server operators को workers के read path की जांच करनी चाहिए

198 accounts गायब होने वाला वीकेंड incident

  • शनिवार, 8 जुलाई 2023 को लगभग 17:25 CEST पर Vivaldi Social टैब ने फिर से login मांगा, और login के बाद home timeline खाली मिली
  • दूसरे system administrator accounts में भी यही लक्षण दिखे, और database जांच में पता चला कि प्रभावित accounts delete होने के बाद user के दोबारा login करने पर नए account की तरह फिर से बनाए जा रहे थे
  • Vivaldi Social के पास शुक्रवार 23:00 UTC का nightly backup था, और operations team ने recovery की संभावना जांचने के लिए backup files की copy बनानी शुरू की
  • सामान्य Mastodon account deletion में username स्थायी रूप से reserve हो जाता है और दोबारा उपयोग नहीं होता, लेकिन इस incident में वही usernames फिर से assign हो रहे थे, इसलिए यह सामान्य deletion नहीं था

deletion जारी था

  • शुरुआत में 142 से कम ID वाले पुराने accounts गायब थे, और 19:10 तक 217 से कम ID वाले accounts भी गायब हो गए, जिससे साफ हुआ कि deletion जारी था
  • 19:18 पर Mastodon developers से मदद मांगी गई, और Renaud के जवाब के बाद Claire और Eugen भी जांच में शामिल हुए
  • 19:20 पर Mastodon Docker instances restart करने के बाद deletion रुक गया, और database में सबसे कम account ID 236 रह गई
  • incident के दौरान delete या merge हुए accounts की अंतिम संख्या 198 पाई गई

attack नहीं, application behavior की ओर इशारा

  • operations team और Mastodon developers ने जांचा कि कहीं UserCleanupScheduler ने “unconfirmed” accounts delete तो नहीं किए, लेकिन deleted users उस query की conditions पर फिट नहीं बैठते थे, इसलिए इस संभावना को खारिज कर दिया गया
  • incident से 48 घंटे पहले Mastodon 4.1.3 में upgrade किया गया था, इसलिए v4.1.2 और v4.1.3 के बीच के changes और Vivaldi द्वारा public किए गए बदलाव भी देखे गए, लेकिन कोई संबंधित कारण नहीं मिला
  • filesystem से deleted accounts की avatar और header images भी साथ में गायब थीं, जिससे पुष्टि हुई कि यह सीधे DB deletion नहीं बल्कि Mastodon application द्वारा deletion action चलाया गया था
  • logs और filesystem में intrusion या attack के निशान खोजे गए, लेकिन कोई सबूत नहीं मिला, और Mastodon v4.1.3 के security fixes से जुड़ी exploit संभावना भी नहीं मिली
  • शनिवार रात account deletion behavior के लिए logging जोड़ने वाला patch deploy किया गया, और 00:29 CEST पर patched version deploy होने के बाद टीम ने कुछ समय आराम किया

निर्णायक सुराग: एक remote account में जमा हुए posts

  • रविवार 13:56 पर Vivaldi security expert Yngve के profile page पर HTTP 500 error आने की रिपोर्ट मिली, और वह account उन 198 deleted accounts में शामिल नहीं था
  • logs में उसी remote Mastodon instance का वही account बार-बार दिख रहा था, और लेख में उसे social.example.com के account के रूप में छद्म नाम दिया गया
  • उस remote account के status query ने 17,600 rows लौटाईं
  • 14:43 पर backup से तुलना करके पुष्टि हुई कि deleted सभी accounts के सभी status social.example.com के एक user को reassign कर दिए गए थे
  • 15:00 के बाद AccountMergingWorker logs, Rails console और अतिरिक्त DB queries के आधार पर यह धारणा मजबूत हुई कि account merge worker सभी accounts को एक remote account में merge कर रहा था

मूल कारण: account merge और PostgreSQL replication lag

  • Vivaldi Social PostgreSQL की 2-server replication configuration इस्तेमाल कर रहा था, और worker processes Makara के जरिए standby server से database reads कर सकते थे
  • 17:28 पर Claire ने जो incident scenario बताया, वह यह था
    • Vivaldi Social को social.example.com से account name change notification मिला
    • database में नया account बनते समय URI field null के रूप में दर्ज हुई
    • उसके बाद नए account की URI सही remote account value पर set की गई
    • Redis के जरिए पुराने account से नए account में data merge करने के लिए AccountMergingWorker execution schedule किया गया
    • database replication lag के कारण URI set होने और worker scheduling का order वास्तविक read time पर उलट गया
  • Mastodon instance के सभी local accounts की URI value null होती है, इसलिए worker ने समान URI value वाले accounts को नए remote account में merge करते हुए सभी local accounts को match कर लिया
  • developers का मानना था कि database load बढ़ने और replication lag लंबा होने पर ऐसी घटना की संभावना और बढ़ सकती है
  • operations team और Mastodon developers ने निष्कर्ष निकाला कि यही configuration सबसे संभावित root cause थी

patch और configuration changes

  • कारण लगभग तय हो जाने के बाद operations team ने data recovery पर ध्यान केंद्रित किया, और Claire ने recurrence रोकने के लिए patch लिखने का जिम्मा लिया
  • Hlini ने patch apply करने और अब recommend न की जाने वाली replication configuration बदलने का काम संभाला
  • 17:58 की deployment के दौरान समस्या आई, जिससे उस वीकेंड का एकमात्र full downtime हुआ, और 18:18 पर Vivaldi Social फिर से चालू हुआ
  • 18:44 पर patch और configuration changes सफलतापूर्वक deploy हो गए, और माना गया कि वही incident दोबारा नहीं होगा

recovery: full rollback की जगह selective restore

  • शुरुआत में full database rollback पर विचार किया गया, लेकिन ज्ञात performance issues के कारण backup .dump को .sql में बदलकर 54GB text file में बदलाव करना पड़ता, जो एक जटिल प्रक्रिया थी
  • operations team ने full restore procedure और selective recovery दोनों समानांतर चलाए
    • Hlini ने 54GB .sql file में बदलाव कर full restore की तैयारी की
    • Thomas ने deleted accounts और उनसे जुड़े data को restore करने के लिए script लिखी
  • script लिखते समय PDO query parameter binding को reference की तरह handle करने की गलती हुई, जिसे Ísak ने पकड़ा
  • 23:04 पर 198 प्रभावित users के user, account और identity records ठीक करने वाला पहला हिस्सा पूरा हुआ
  • 23:55 पर status, follows, followers और relationship data को incident से पहले की स्थिति में लौटाने वाली selective recovery script पूरी हो गई

selective recovery पूरी और बाद की fixes

  • database relationship constraints के कारण recovery दो चरणों में हुई
    • पहले सभी 198 users के user/account/identity records restore किए गए
    • उसके बाद बाकी relationship data restore किया गया
  • कुछ users incident के बाद फिर login करके follow settings बना चुके थे, इसलिए duplicate key errors आए; script को इस तरह बदला गया कि restore न हो सकने वाले पुराने records हटें और नए records बने रहें
  • सोमवार 01:27 CEST पर script का अंतिम काम पूरा हुआ, और 01:40 पर home feed reindexing समाप्त हुई
  • परिणामस्वरूप 198 accounts की home feed बहाल हो गई, और full rollback की जरूरत नहीं रही
  • सोमवार और मंगलवार को अतिरिक्त follow-up issues भी ठीक किए गए
    • symbol वाले usernames के 6 accounts की login समस्या
    • 198 accounts का web settings data loss
    • follower count, post count आदि profile counters की गलतियां
    • गलत data वाले 4 accounts

Mastodon की आधिकारिक fixes

UTC के आधार पर incident timeline

  • शनिवार 15:15: बाहरी instance से account name change message Vivaldi Social तक पहुंचा, और गलत account merge job शुरू हुई
  • शनिवार 15:25: incident का पहला संकेत देखा गया
  • शनिवार 17:20: Docker containers restart करने के बाद account merge job रुकी; 15:15 से 17:20 के बीच कुल 198 accounts delete या merge हुए
  • रविवार 13:00: संभावित root cause की पहचान हुई
  • रविवार 14:25: root cause की पुष्टि हुई
  • रविवार 21:55: data recovery शुरू हुई
  • रविवार 23:27: data recovery पूरी हुई
  • सोमवार 10:40: symbol वाले usernames के 6 accounts ठीक किए गए
  • सोमवार 11:05: खोया हुआ web settings data restore किया गया
  • मंगलवार 15:31: गलत counter values ठीक की गईं
  • मंगलवार 16:01: गलत data वाले 4 accounts ठीक किए गए

1 टिप्पणियां

 
GN⁺ 2023-07-31
Hacker News की रायें
  • यह एक बेहतरीन retrospective था, और खासकर इसमें यह भी अच्छी तरह दिखा कि नींद की कमी जैसी मानवीय लागत जटिल incident resolution पर कितना बड़ा असर डालती है
    सबसे ज़्यादा ध्यान खींचने वाला हिस्सा यह था कि “नए accounts डेटाबेस में URI field में null value के साथ बनाए गए”
    डेटाबेस से जुड़े postmortem जब भी देखता हूं, लगभग हमेशा NULL घटना-स्थल के आसपास कहीं छिपा होता है। NULL अपराधी न भी हो, तो भी उसे हमेशा पूछताछ की सूची में रखना चाहिए
    मेरी सलाह है कि NULL पर sentinel value के तौर पर निर्भर न रहें, और संभव हो तो डेटाबेस में उसे अनुमति ही न दें। फायदे दिख सकते हैं, लेकिन कुछ साल बाद data model का अर्थ बदलने पर कोई harmless-सा दिखने वाला statement NULL या NOT NULL की उम्मीद करता है और अप्रत्याशित नतीजा देकर ऐसे bug में बदल जाता है जिसे ढूंढना मुश्किल होता है
    इस मामले में issue race condition था, लेकिन अगर local accounts और remote accounts को type के जरिए साफ़ अलग किया गया होता, तो operations का order मायने नहीं रखता, और account merge code को भी ज्यादा सीमित scope में रखा जा सकता था

    • इसका जवाब देने के लिए आखिरकार account बनाया; उम्मीद है यह बहुत aggressive न लगे
      Null data की पूरी तरह valid value है और उसे वैसे ही treat करना चाहिए। boolean के लिए -1 या string के लिए empty value जैसे defaults, उस system को ऊपर-ऊपर से चलता हुआ दिखा सकते हैं जो NULL होने पर runtime error देता, लेकिन इसका मतलब यह नहीं कि system उम्मीद के मुताबिक काम कर रहा है; वह बस चुप हो जाता है
      NULL को छिपा देने का लालच समझ आता है, लेकिन “न होना” भी “होना” जितना ही data की valid state है, और systems को आम तौर पर इसे स्वीकार करने के लिए लिखा जाना चाहिए
    • विकल्प empty string है क्या?
      इस case में मुझे समस्या database के NULL में नहीं, बल्कि application layer के NULL में लगती है
      अगर NULL किसी Maybe monad जैसा value हो जिसे handle करना forced हो, तो आखिरकार आप उसे handle करेंगे और उसके बारे में सोचेंगे। empty string हो, आपकी भाषा की null string हो, या आपका खुद बनाया special marker value—बहुत बड़ा फर्क नहीं है
    • Automatic merging/deduplication “मिलते-जुलते” records से निपटने में उन बेहद कठिन समस्याओं में से है जिनमें जहां तक हो सके इंसानी intervention होना चाहिए। edge cases और race conditions भरे पड़े हैं, और खासकर asynchronously consume होने वाले data को जितना हो सके स्पष्ट रूप से pass करना चाहिए, साथ ही कई checks से सुनिश्चित करना चाहिए कि वास्तविक facts बदले नहीं हैं
      कई मामलों में implementer को पहले Git-style merge conflict से जुड़े concerns और interaction requirements के बारे में सोचना चाहिए, और फिर उस starting point से problem domain के हिसाब से simplifying assumptions बनानी चाहिए
      Mastodon source https://github.com/mastodon/mastodon/blob/main/app/workers/a... देखने पर, merge request शुरू करने वाली side से async merge executor को भेजी जाने वाली “किन IDs से merge करना है” की explicit list भी दिखाई नहीं देती, इसलिए लगता है ऐसा होना बस समय की बात थी
      यह Mastodon की आलोचना नहीं है। मैंने खुद इससे कहीं खराब race conditions वाली merge logic लिखी है और उसका नुकसान भी झेला है। सच कहें तो https://opencollective.com/mastodon जैसे volunteer project में इस तरह की capability मौजूद होना ही हैरान करने वाली बात है। फिर भी यह सावधान करने वाला उदाहरण है
    • JOIN इस्तेमाल करें तो NULL अपरिहार्य है। JOIN का स्वभाव ही ऐसा है
      और गहराई में जाएं तो reality messy है, और database सिर्फ इसलिए processing से मना नहीं कर सकता कि reality messy है, इसलिए NULL से बचा नहीं जा सकता। उदाहरण के लिए, honorifics, prefixes और suffixes को model करना हो और उस data से पूरा greeting बनाना हो, तो कम-से-कम कुछ लोगों के पास suffix नहीं होगा। आप NULL store न भी करें, greeting बनाने के लिए इस्तेमाल किए गए JOIN result में आपको NULL मिलेगा
      कुछ खास NULL values हटाई जा सकती हैं, लेकिन real world में “लागू नहीं” या “पता नहीं” अक्सर valid values होती हैं—इस fact को हटाया नहीं जा सकता, और database को इसे handle करना ही होगा
    • null हो भी तो merge function को किसी न किसी तरह null check या truthy check करना चाहिए था। भरोसा करना मुश्किल है
  • यहां जिस flow से मैं सहमत हूं, वह “पूरे database का backup है, तो full restore कर देते हैं” से शुरू होकर, “full restore मुश्किल है और downtime व side effects हैं” तक जाता है, फिर “smartly सिर्फ missing data को partial restore किया जा सकता है” बनता है, फिर manual work करते हुए अजीब error मिलता है, और अंत में अस्थायी selective restore deploy करके आखिरी पांच missing data items साफ़ किए जाते हैं। उम्मीद है छठा न छूट गया हो
    जब भी कोई backup/restore practice करता है, हर बार बात इसी तरह आगे बढ़ती है। आखिरकार backup image से कौन-सा data वापस लाना है, यह हमेशा application level पर तय करने वाली चीज बन जाती है

    • सहमत हूं। एक कहावत है: “अगर आपने backup test नहीं किया, तो backup है ही नहीं”
      हालांकि इस case में मुझे साफ़ नहीं कि समस्या क्या थी। आखिरी known-good backup से सब restore कर देते तो उस बीच आए कुछ posts गायब हो जाते—जो अफसोसजनक होता—लेकिन manual work और uncertainty की जगह यह तुरंत समाधान था
  • यह हिस्सा प्रभावशाली लगा कि Mastodon development team के Renaud, Claire और Eugen ने उम्मीद से बढ़कर मदद की
    मुझे नहीं पता Vivaldi Mastodon को financial support देता है या नहीं, और sponsors page पर भी नाम नहीं मिला। अगर नहीं, तो उम्मीद है इस घटना के बाद Vivaldi या Mastodon इस्तेमाल करने वाली दूसरी कंपनियां sponsorship या support contract पर विचार करेंगी

    • फिलहाल Mastodon nonprofit organization support contracts नहीं देती, लेकिन यह अच्छा idea है
      sponsorship खुली है और सच में बड़ा असर डालती है। project में full-time staff होना बहुत महत्वपूर्ण है, लेकिन अभी tech side में founder Eugen के अलावा सिर्फ 1 full-time developer और 1 DevOps person हैं
    • https://joinmastodon.org/sponsors पर नहीं है, इसलिए शायद sponsor नहीं होंगे
    • फिर भी वे Mastodon federation को एक काफी बड़ा instance और उस पर काम करने वाले staff दे रहे हैं
  • काफी समय बाद पढ़े postmortems में यह काफ़ी अच्छा था

    • याद है hachyderm postmortem भी काफी अच्छा था। अच्छा है कि लोग transparency से share कर रहे हैं
  • नंबर 2 और 3 का atomically process न होना समस्या जैसा लगता है। बेशक ऐसा करना trivial न होने की वजहें रही होंगी, लेकिन मैंने अभी code नहीं देखा है और कभी न कभी देखना होगा

    • संबंधित fixes में से एक https://github.com/mastodon/mastodon/commit/13ec425b721c9594... है
      इसे atomic बनाना trivial ही लग रहा था
      पहले बस इसकी ज़रूरत नहीं पड़ी थी। यानी non-atomic होना तब तक समस्या नहीं था, जब तक कोई sidekiq को पुराने database server, यानी replica, से connect करने जैसी खराब setting न कर दे। यहाँ वही setting मुख्य समस्या लगती है
  • पहली बार जब एक विशाल SQL dump restore करना पड़ा था, तो vim को उसे पढ़ते-पढ़ते सचमुच segmentation fault देते देखना भूल नहीं सकता
    तभी split(1), यानी file को टुकड़ों में बाँटने का जादू पता चला। बड़े dump को table-wise एक-एक file में तोड़ दिया था
    बेशक एक table भी विशाल हो सकती है, लेकिन कम से कम files ज्यादा uniform हो जाती हैं, जिससे sed या awk जैसे दूसरे tools से queries transform करना आसान होता है

    • vim का segmentation fault देना चौंकाने वाला है। बड़ी file खोलना slow होते देखा है, लेकिन हमेशा सोचा था कि किसी जादुई buffering से वह कुछ भी संभाल लेता होगा। हो सकता है मैं गलत रहा हूँ
      हालांकि data restore करने के लिए dump edit करने की नौबत आ जाए, तो restore procedure में कुछ बहुत गलत है। बेशक जब आप सच में उस स्थिति में हों, तब यह ज्ञान ज्यादा मदद नहीं करता
    • पहले एक ऐसा system manage किया था जिसमें एक खास folder में इतने ज्यादा files थे कि ls command भी finish नहीं होती थी। शायद ext3 या ext2 रहा होगा
      workaround यह था कि एक Python script लिखी जाए जो सब कुछ धीरे-धीरे process करे, और common prefix के आधार पर files को subdirectories में move करे
  • “Claire ने log entry का पूरा stack trace मांगा, और logs से वह भी निकाल पाए” वाले हिस्से पर भौंहें चढ़ गईं
    यह या तो गहरी voodoo magic है, या code/configuration Xeon को 286 के level पर ला देता है। हर request पर megabytes नहीं हो जाते क्या?

    • account देखते समय HTTP 500 error आया था, और बात उसी 500 के stack trace की है
      यह Ruby on Rails का default behavior है। 500 या unknown error आने पर stack trace print करता है, और content बस line number और file path जैसा होता है
      मैं एक काफी खराब design वाला Rails app चला रहा हूँ; अभी check किया तो एक 500 का stack trace 5KiB था। 500 error लगभग घंटे में एक बार ही आता है, इसलिए दिन में 1MiB से भी कम
      call stack को पास रखना असल में performance के लिहाज से काफी ठीक है। Java का default exception behavior भी हर exception के साथ stack trace उठाना है, भले ही उसे print न करें, लेकिन Java applications ठीक चलती हैं। वैसे भी return कैसे करना है यह जानना होता है, इसलिए call stack मौजूद रहता है; अतिरिक्त जानकारी के तौर पर बस filename और line number debug symbols चाहिए होते हैं। Ruby में भाषा की प्रकृति के कारण वह जानकारी वैसे भी चाहिए होती है
    • error का stack trace record करना काफी reasonable बात है। ideally हर request error भी नहीं देती
    • क्या मतलब है कि production में चल रहे system पर errors के stack trace capture नहीं करते? error कहाँ से आया, यह कैसे पता लगाते हैं?
    • लगता है stack trace को core dump या किसी similar चीज़ से confuse कर रहे हैं
  • “Mastodon instance के सभी local accounts में URI field null value था, इसलिए सब match हो गए” यह कैसे संभव है?
    NULL = NULL FALSE evaluate होता है। SQL 3-value logic, ठीक कहें तो Kleene की weak 3-value logic, इस्तेमाल करता है, और NULL पर कोई भी operator apply करने से NULL ही मिलता है

    • मुझे भी यह जानना था। शायद application layer में filtering हुई हो, और इस्तेमाल की गई language के null value से equality check किया गया हो
  • समझ नहीं आ रहा कि URI column में NULL value वाले accounts query से कैसे match हुए। NULL को NULL के बराबर compare नहीं किया जाता। क्या यह कोई डरावना Rails magic है?

  • username में symbols वाले 6 users login नहीं कर पाए, और recovery script की गलती होने की वजह से इसे आसानी से ठीक कर लिया गया—यह पढ़कर लगा कि UTF-8 ने फिर एक बार अपना काम दिखा दिया