۲۹ مرداد ۲۵۸۵ · 7 دقیقه مطالعه
pipeline قدیمی ~۴۷هزار span از دست داده بود. نداده بود. ما اشتباهی میشمردیم.
یه مقایسهی side-by-side از span count بهازای هر service، تو یه parallel-run validation، نشون داد که pipeline جدید حدود ۰.۲٪ از span ها رو تو یه پنجرهی ۶۰ دقیقهای از دست میده. اگه بهعنوان regression تو pipeline جدید خونده میشد، یه rollback trigger میکرد. اگه درست خونده میشد، یعنی pipeline قدیمی تو یه پنجرهی چندثانیهای دهها هزار ردیف duplicate داشت insert میکرده، و pipeline جدید با در نظر گرفتن duplicate ها، span به span باهاش match میکرد. درس این نیست که pipeline جدید سالم بود. درس اینه که واحدی که یه storage layer بهعنوان “count” expose میکنه همون واحدی نیست که operator فکر میکنه، وقتی storage روی چیزی که داره count میشه unique constraint نداره.
نمایشگاه اول: اون delta ی بهازای هر service که alarm میداد
پنل count() تو Traces Explorer تعداد ردیفها رو report میده. بهازای هر service، pipeline جدید حدود �.۲٪ تو اون پنجره کم داشت. شکل shortfall بهطور یکنواخت بین service ها تکرار میشد، و همین بخش بود که بهعنوان یه signal واقعی خونده میشد. یه shortfall یکنواخت بهازای هر service، signature یه issue ی system-level ـه نه یه component بد؛ و reflex طبیعی این بود که “pipeline جدید داره span ول میکنه.” این reflex موضوع این پسته، چون reflex تو direction اشتباه بود. pipeline جدید چیزی ول نکرده بود. pipeline قدیمی duplicate میزد، و یه duplicate سمت pipeline قدیمی، از دید pipeline جدید، دقیقاً شبیه یه loss میخونه.
instinct یه shortfall یکنواخت رو بهعنوان regression خوندن، احمقانه نیست؛ تو بیشتر failure mode ها reflex درستیه. reflex ی چیزیه که باید داشته باشی وقتی یکی از دو pipeline مشکل داره. مشکل reflex اینه که فرض میکنه یکی از دو pipeline منبع discrepancy ـه و اون یکی رو ground truth میگیره. setup ی parallel-run، pipeline قدیمی رو بهصرف اینکه اول اونجا بود، مرجع کرده بود، و یه shortfall یکنواخت نسبت به یه مرجع، شبیه deviate کردن pipeline تست میمونه، نه deviate کردن مرجع. این asymmetry هست که بهعنوان regression خونده میشه.
نمایشگاه دوم: drill-down ی که تصویر رو invert کرد
count ها بهازای هر ساعت محاسبه شدن و مستقیم با database های هر دو pipeline مقایسه شدن. بیست ساعت متوالی span به span match میکردن. یه ساعت match نمیکرد.
تو اون ساعت، count() ی pipeline قدیمی حدود ۶۲۰ هزار میخوند، در حالی که uniqExact(spanID) ش حدود ۵۸۰ هزار میخوند. دو count ی pipeline جدید هردو حدود ۵۸۰ هزار میخوندن. shortfall سمت pipeline جدید نبود. shortfall این بود که pipeline قدیمی دهها هزار ردیف duplicate تو اون ساعت داشت، و duplication متمرکز بود رو یه پنجرهی کوچیک داخلش. بهازای هر service، count() ی pipeline جدید دقیقاً مساوی uniqExact(spanID) ی pipeline قدیمی بود، و همین رابطه diagnosis رو invert میکنه. pipeline قدیمی بزرگتر از pipeline جدید نبود. pipeline قدیمی دقیقاً بهاندازهی duplicate هایی که دوبار insert کرده بود کوچکتر بود.
drill-down مهم بود چون discrepancy سطح ساعت، سطحی بود که reflex اشتباه توش گیر میکرد. drill-down سطح پنجره duplication رو نشون داد؛ match بهازای هر service direction رو نشون داد. هردو لازم بودن؛ هرکدوم بهتنهایی diagnosis رو مبهم میذاشت. شکل disagreement ی (count() ی قدیمی over-report میکنه؛ uniqExact ی قدیمی با جدید match میکنه)، fingerprint یه duplicate-insert path ـه، نه fingerprint یه span-loss path.
نمایشگاه سوم: log sweep ی که smoking gun رو پیدا کرد
log های collector قدیمی تو اون پنجره برای error sweep شدن. یه MEMORY_LIMIT_EXCEEDED روی error-table insert ظاهر شد، که بعد از index-table insert ی همون batch قبلاً land شده بود رخ داده بود. exporter کل batch رو retry کرد. non-transactional multi-table write بهعلاوهی retry، مکانیزم duplication ـه: index table commit میشه، error table رو memory ceiling ش fail میشه، retry همون index table رو یه بار دیگه commit میکنه. column-oriented storage روی spanID هیچ unique constraint نداره و dedup-on-insert نداره، پس commit دوم بهصورت دو ردیف یکسان land میشه. error log نشون میده صدها occurrence قبلی MEMORY_LIMIT_EXCEEDED روی collector قدیمی، یعنی duplication recurring ـه، anomalous نیست.
خود memory ceiling trigger ـه، و workload-dependent ـه. error-table insert وقتی fail میشه که error batch بهاندازهی کافی بزرگ باشه که از memory budget رد بشه، که موقع traffic spike ها محتملتره، که همون پنجرهایه که یه نفر داره به per-service span count ها نگاه میکنه. duplication نویز نیست؛ با الگوی کاری که discrepancy رو visible میکنه correlated ـه، و همینه که symptom رو اینقدر بهعنوان regression ی pipeline جدید قانعکننده نشون میده.
چرا یه count با uniqueness-aware count یکی نبود
پنل count() ی Traces Explorer تعداد ردیفها رو report میده. ستون spanID ی storage primary key نیست؛ هیچی duplicate insert رو reject نمیکنه. دو عدد، count() و uniqExact(spanID)، وقتی pipeline سالمه match میکنن و وقتی نیست diverge میکنن. divergence خودش direction ی bug ـه: count() over-report میکنه چون duplicate ها رو count میزنه. دو count ی pipeline جدید دقیقاً match میکردن چون insert path ی collector جدید به شکلی retry نمیکنه که duplicate تولید کنه. disagreement بین دو pipeline regression ی pipeline جدید نبود. over-counting ی duplication-driven ی pipeline قدیمی بود که بهعنوان under-counting ی pipeline جدید غلط خونده میشد.
این همون قسمت پسته که generalize میشه. row count و unique-keyed count دو تا measurement متفاوت از یه storage ان، و فقط وقتی equivalent ان که storage duplicate ها رو reject کنه. همون لحظه که storage duplicate قبول کنه، دو measurement diverge میکنن، و divergence خودش signal ـه. direction ی divergence بهت میگه کدوم سمت duplicate میزنه، نه کدوم سمت drop میزنه. یه panel کوتاه نسبت به یه مرجع میتونه از drop ی سمت کوتاه باشه، از duplicate ی سمت مرجع، یا هردو؛ disagreement بین count() و uniqExact سمت مرجع همون diagnostic ـه که بهت میگه کدوم.
تلهی fault ی recurring
صدها occurrence قبلی MEMORY_LIMIT_EXCEEDED همونه که یه session ی debugging ی یکبار رو به یه rule قابل انتقال تبدیل میکنه. یه batch تنها که بعد از یه mid-batch failure retry میشه، transient ـه؛ همون batch path که هر بار workload spike میزنه fail میشه، property ی pipeline قدیمیه. parallel-run هر بار که error path ی pipeline قدیمی trigger بشه، الگوی “pipeline جدید داره span از دست میده” رو نشون میده، و divergence تو پنجرهی validation accumulate میشه.
reflex ی که باید fix بشه اینه: “با uniqExact مقایسه کن.” این symptom treatment ـه. rule ی وسیعتری هست: metric ی مقایسه رو انتخاب کن که به retry behavior ی pipeline قدیمی depend نکنه. unique-keyed count یکی از این metric هاست؛ metric ی که per-row count ی error events رو بشمره هم بهت میگه duplication رخ داده؛ metric ی که per-row count ی distinct trace-id ها رو بشمره بهت میگه duplication روی trace graph اثر نذاشته. هر metric ی که definition ش under duplicate insertion invariant ـه، robust به این bug class ـه. row count robust نیست، و استفاده ازش بهعنوان metric ی parallel-run guarantee میکنه هر پنجرهای که duplication event رو overlap کنه، بهعنوان regression ی pipeline تست خونده میشه.
قانون و تله
وقتی یه count و uniqueness-aware count disagree میکنن، storage layer داره بهت میگه کدوم رو استفاده کنی، و disagreement خودش signal ـه. non-transactional multi-table write بهعلاوهی retry، duplication path هست چه trigger بشه چه نشه؛ trigger میشه وقتی یکی از table ها mid-batch به ceiling ش میرسه، و وقتی trigger شد، duplication چون هیچی روش insert reject نمیکنه، برای همیشه تو storage میمونه.
دفعهی بعد که یه panel ی side-by-side یه pipeline رو با یه درصد کوچیک یکنواخت short نشون داد، سؤال این نیست “کدوم pipeline drop میزنه.” سؤال اینه “کدوم pipeline double-count میزنه”، و جواب اونیه که row count ش برای همون پنجره از unique-keyed count ش بیشتره. دو pipeline تو parallel-run متقارن نیستن: سمت مرجع، اونی که اول اونجا بوده، بیشتر وقت داشته failure هایی که insert path ش مستعدشونه رو accumulate کنه. deficit ی سمت کوتاه، تو حالت معمول، surplus ی سمت مرجعه که از direction ی اشتباه بیان شده.