সেশন ১৯

Logging, Metrics, Tracing - system এর ভেতরটা দেখা

এই সেশনের লক্ষ্য: অনেকগুলো service এর system এ কোথায় কী ভুল হচ্ছে, সেটা বাইরে থেকে বোঝার কৌশল (observability) শেখা। Structured log আর correlation ID, counter, gauge আর histogram, average কেন ভুল বোঝায় আর percentile কেন দরকার, label এর cardinality এর খরচ, আর trace ও span দিয়ে একটা request এর পুরো পথ দেখা।

০০ যে প্রশ্নগুলোর উত্তর খুঁজবো

আগের সেশনগুলোতে আমরা system কে অনেক টুকরো করেছি। Database ভাগ হয়েছে, queue বসেছে, একটা বড় application ভেঙে অনেকগুলো ছোট service হয়েছে। প্রতিটা ভাগ system কে বড় হতে সাহায্য করেছে। কিন্তু প্রতিটা ভাগের সাথে একটা প্রশ্ন কঠিন হয়েছে: কিছু ভুল হলে সেটা কোথায় হলো?

একটা server এর যুগে উত্তর খোঁজা সহজ ছিলো। এক জায়গায় log খুললেই চলতো। এখন একটা request হয়তো দশটা service ঘুরে আসে। এই সেশনে আমরা শিখবো, এমন system এর ভেতরে কী ঘটছে সেটা কীভাবে দেখা যায়। শেষে আপনি বুঝবেন, log, metric আর trace কে কী প্রশ্নের উত্তর দেয়, আর তিনটা মিলে কীভাবে একটা লুকানো সমস্যা ধরে ফেলে।

  • ১ Checkout ধীর, কিন্তু শুধু "কিছু user" এর জন্য। ৪০টা service এর মধ্যে কোথা থেকে খোঁজা শুরু করবো? (observability)
  • ২ Log এ কী লিখবো, আর কীভাবে লিখলে পরে খুঁজে পাবো? (structured logging, log level)
  • ৩ একটা request এর log ছড়িয়ে আছে অনেক service এ। সব একসাথে পাবো কীভাবে? (correlation ID, log aggregation)
  • ৪ "কতবার" আর "কতটা ধীর" সংখ্যায় মাপবো কীভাবে? (counter, gauge, histogram)
  • ৫ Average latency 247ms, তবু user রা কষ্ট পাচ্ছে কেন? (p50, p95, p99)
  • ৬ Metric এ user_id label দিলে কী হয়? (cardinality)
  • ৭ একটা ধীর request এর ৪ সেকেন্ড ঠিক কোন service এ গেলো? (trace, span, parent span)
  • ৮ প্রতিটা request trace করলে খরচ কত, আর কীভাবে কমাবো? (sampling, OpenTelemetry)
  • ৯ সব মিলিয়ে: তিনটা pillar একসাথে কীভাবে একটা সমস্যা খুঁজে বের করে?

০১ Checkout ধীর, কিন্তু শুধু “কিছু user” এর জন্য। কোথা থেকে খোঁজা শুরু করবো?

শুক্রবার, রাত আটটা। সাবরিনা একটা online grocery app এর backend engineer। এই সময়টায় শহরের মানুষ অফিস থেকে ফিরে সপ্তাহের বাজার করে, তাই প্রতি মিনিটে প্রায় ১,২০০টা checkout হয়। হঠাৎ support টিম থেকে message আসে: “কিছু customer বলছেন, checkout চাপলে চাকা ঘুরতেই থাকে।” সাবরিনা dashboard খোলে। গড় response time 247ms, সব সবুজ। তবু অভিযোগ একটা একটা করে বাড়ছে, আর সাবরিনার মনে অস্বস্তিও।

সমস্যা হলো, app টা এখন আর একটা program নয়। এটা ৪০টা আলাদা service, প্রতিটা চলে ৩টা করে server এ। একটা checkout এর request এদের অনেকগুলোর মধ্য দিয়ে যায়:

Checkout চাপ mobile app · 8:04 PM API Gateway checkout এ পাঠায় cart ঝুড়ির জিনিস coupon ছাড়ের হিসাব payment টাকা কাটা inventory stock check loyalty পুরোনো order + আরো 34টা service প্রতিটা 3টা server এ, মোট 120টা server orders DB কিছু checkout এ 4 সেকেন্ড লাগছে 40টা service এর কোনটা দায়ী?
একটা checkout চাপলে request টা gateway থেকে অনেকগুলো service ঘুরে আসে। যেকোনো একটা ধাপে দেরি হলে পুরো checkout ধীর হয়ে যায়। কিন্তু বাইরে থেকে শুধু ধীর ফলাফলটাই চোখে পড়ে, দেরিটা কোথায় হলো তা দেখা যায় না।

সাবরিনার সামনে তিনটা প্রশ্ন। ধীর হচ্ছে কাদের জন্য, আর কতটা? ধীর request এর সময়টা কোন service এ খরচ হচ্ছে? আর সেখানে ঠিক কী ঘটছে? সেশন ১২ তে দেখেছেন, একটা call chain এর যেকোনো একটা ধাপ ধীর হলে পুরো request ধীর হয়ে যায়। কিন্তু কোন ধাপটা, সেটা বাইরে থেকে দেখা যায় না।

Observability: ভেতরে না ঢুকে ভেতরটা বোঝা

ডাক্তার রোগীর শরীর কেটে দেখেন না। তিনি জ্বর মাপেন, রক্ত পরীক্ষা করান, দরকার হলে X-ray করান। এই বাইরের signal গুলো দেখেই তিনি বোঝেন ভেতরে কী হচ্ছে। Software এও একই কাজ করতে হয়। চলন্ত system এ debugger বসিয়ে থামানো যায় না, কারণ তখন হাজার হাজার মানুষের বাজার আটকে যাবে।

System নিজে থেকে যে signal বাইরে পাঠায়, সেগুলো দেখে ভেতরের অবস্থা বুঝতে পারার ক্ষমতাকে বলে observability। এই signal প্রধানত তিন রকম, যাদের বলা হয় observability এর তিন pillar:

কী ঘটেছিলো? কতবার, কতটা? সময় কোথায় গেলো? LOGS প্রতিটা ঘটনার লিখিত হিসাব METRICS সময়ের সাথে বদলানো সংখ্যা TRACES একটা request এর পুরো পথ WARN slow query loyalty · 3,750ms · 8:04:12 PM p99 ≈ 4s 1,200 checkout/min মোট 4.1s এর 3.8s গেছে loyalty তে
তিনটা pillar তিনটা আলাদা প্রশ্নের উত্তর দেয়। Log বলে ঠিক কী ঘটেছিলো, metric বলে কতবার আর কতটা, আর trace বলে একটা request এর সময়টা কোন service এ খরচ হলো। একটা দিয়ে অন্যটার কাজ চলে না।
একটা দিয়ে অন্যটার কাজ চলে না

Metric বলে কিছু একটা ভুল হচ্ছে, কিন্তু কেন সেটা বলে না। Log বলে ঠিক কী ঘটেছিলো, কিন্তু লাখ লাখ লাইনের মধ্যে কোনটা পড়বেন সেটা বলে না। Trace বলে সময়টা কোথায় গেলো, কিন্তু সব request এর হিসাব রাখে না। তিনটা একসাথে থাকলেই পুরো ছবিটা পাওয়া যায়।

০২ Log এ কী লিখবো, আর কীভাবে লিখলে পরে খুঁজে পাবো?

সাবরিনার প্রথম কাজ log দেখা। কিন্তু loyalty service এর log এ যা পায়, তা অনেকটা এরকম: “Coupon apply slow for user 58213, took 3750ms”। মানুষ পড়লে বোঝা যায়। কিন্তু প্রশ্নটা যদি হয় “গত এক ঘণ্টায় কতগুলো request ১ সেকেন্ডের বেশি নিয়েছে?”, তখন কী হবে? প্রতিটা developer নিজের মতো করে বাক্য লিখেছেন। কেউ লিখেছেন “took 3750ms”, কেউ “duration=3.7s”, কেউ “slow (3750)”। এক search এ সবগুলো ধরা প্রায় অসম্ভব।

Structured logging

সমাধান হলো log কে বাক্য হিসেবে না লিখে data হিসেবে লেখা। প্রতিটা তথ্য একটা নাম দেওয়া আলাদা field এ যায়, সাধারণত JSON format এ। একে বলে structured logging:

# আগে: plain text (মানুষ পড়তে পারে, machine খুঁজতে পারে না)
2026-11-06 20:04:12 WARN Coupon apply slow for user 58213, took 3750ms

# পরে: structured log (JSON, প্রতিটা তথ্য আলাদা field এ)
{
  "time":        "2026-11-06T20:04:12.481Z",
  "level":       "WARN",
  "service":     "loyalty",
  "request_id":  "r-7f3a",
  "user_id":     58213,
  "event":       "slow_query",
  "table":       "orders",
  "duration_ms": 3750
}

# এখন এমন প্রশ্ন করা যায়:
service = "loyalty" AND event = "slow_query" AND duration_ms > 1000

এখন duration_ms সবসময় একটা সংখ্যা, আর service সবসময় একই নামের field। তাই log store কে database এর মতো প্রশ্ন করা যায়। Spreadsheet এর কলামের কথা ভাবুন। কলামের নাম ঠিক থাকলে filter আর sort এক click এর ব্যাপার।

Log level: সব কথা সমান জরুরি নয়

প্রতিটা log লাইনের একটা গুরুত্বের মাত্রা থাকে, যাকে বলে log level:

Levelকখন লিখবেনProduction এ
DEBUGখুঁটিনাটি: variable এর মান, loop এর প্রতিটা ধাপসাধারণত বন্ধ থাকে
INFOস্বাভাবিক বড় ঘটনা: order হলো, payment সফল হলোচালু থাকে
WARNঅস্বাভাবিক, কিন্তু কাজ চলছে: ধীর query, retry করতে হলোচালু থাকে
ERRORকাজটা fail করেছে: payment গেলো না, exception এলোচালু থাকে, সবার আগে দেখা হয়

DEBUG কেন বন্ধ রাখা হয়, সেটা একটা ছোট হিসাব করলেই বোঝা যায়:

# Peak এ gateway তে আসে 2,000 request/s
# প্রতি request এ (সব service মিলে) 5টা INFO লাইন, প্রতিটা ~500 bytes

INFO চালু:   2,000 × 5 × 500 bytes = 5 MB/s
             5 MB/s × 86,400 s     ≈ 432 GB/দিন

DEBUG চালু:  লাইন প্রায় 10 গুণ     ≈ 4.3 TB/দিন

30 দিন রাখলে: INFO তে ~13 TB, DEBUG এ ~130 TB
Log এ যা কখনো লিখবেন না

Password, OTP, card number, token: এগুলো log এ গেলে যে কেউ log পড়তে পারে, সে-ই এগুলো দেখতে পায়। আর log সাধারণত অনেক মানুষ পড়ে, অনেক দিন ধরে জমা থাকে। User এর ফোন নম্বর বা ঠিকানার মতো ব্যক্তিগত তথ্যও লেখার আগে দুবার ভাবুন।

০৩ একটা request এর log ছড়িয়ে আছে অনেক service এ। সব একসাথে পাবো কীভাবে?

সাবরিনা এখন একজন customer এর অভিযোগ ধরে খুঁজতে চায়: ৮টা ৪ মিনিটে তার checkout কেন আটকে গেলো? সমস্যা দুটো। প্রথমত, সেই request এর log আছে checkout, coupon, loyalty আর আরো কয়েকটা service এ, আলাদা আলাদা server এ। দ্বিতীয়ত, ঐ এক মিনিটে আরো ১,২০০টা checkout হয়েছে। কোন লাইনটা কোন customer এর, সেটা বোঝার উপায় নেই।

Correlation ID: প্রতিটা request এর একটা নাম

হাসপাতালে ভর্তি হলে রোগীর হাতে একটা band পরিয়ে দেওয়া হয়, তাতে একটা নম্বর লেখা থাকে। Lab, pharmacy, X-ray: যেখানেই যান, সবাই সেই নম্বর দিয়েই কাগজ লেখে। পরে নম্বরটা দিয়ে খুঁজলেই সব কাগজ একসাথে পাওয়া যায়।

Request এর জন্যও ঠিক এই কাজটা করা হয়। Request যখন প্রথম system এ ঢোকে, gateway তার জন্য একটা unique id বানায়, যেমন r-7f3a। প্রতিটা service সেই id নিজের প্রতিটা log লাইনে লেখে। আর পরের service কে call করার সময় id টা HTTP header এ পাঠিয়ে দেয় (প্রায়ই X-Request-ID নামে)। এই id কে বলে correlation ID বা request ID:

প্রতিটা call এর header এ যায়: X-Request-ID: r-7f3a API Gateway নতুন id বানায়: r-7f3a checkout id পায়, পরের call এ দেয় coupon id পায়, log এ লেখে request_id: r-7f3a "POST /checkout" request_id: r-7f3a "cart ok, coupon ডাকছি" request_id: r-7f3a "loyalty উত্তর দিচ্ছে না" search: request_id = r-7f3a 3টা service এর 14টা লাইন, সময় ধরে সাজানো
Gateway প্রতিটা নতুন request এর জন্য একটা id বানায়। প্রতিটা service সেই id টা নিজের প্রতিটা log লাইনে লেখে, আর পরের service কে call করার সময় header এ পাঠিয়ে দেয়। তাই একটা search এই তিন service এর সব লাইন এক জায়গায় এনে দেয়।

শর্ত একটাই: প্রতিটা service কে id টা পরের call এ পাঠাতে হবে। একটা service ভুলে গেলে তার পরের সব service এর log আলাদা হয়ে যায়। তাই কাজটা প্রতিটা developer এর হাতে না রেখে একটা shared library বা framework এর middleware এ রাখা হয়।

Log aggregation: সব log এক জায়গায়

Correlation ID থাকলেও আরেকটা সমস্যা থাকে। ৪০টা service এর ১২০টা server, প্রতিটার log তার নিজের disk এ। একটা একটা করে ১২০টা server এ ঢুকে খোঁজা মানে কয়েক ঘণ্টার কাজ। তার উপর রাতে কোনো server বন্ধ হয়ে নতুন server এসে থাকলে পুরোনোটার log আর পাওয়াই যায় না।

তাই প্রতিটা server এ একটা ছোট program (log agent) চলে। সে নতুন লেখা প্রতিটা log লাইন সাথে সাথে একটা central log store এ পাঠিয়ে দেয়। সব server এর log এক জায়গায় জমা করার এই ব্যবস্থাকে বলে log aggregation:

120টা SERVER checkout-1 app + log agent coupon-2 app + log agent loyalty-3 app + log agent ... আরো 117টা Log store Loki / Elasticsearch index হয়, 30 দিন থাকে Search UI Grafana / Kibana এক query, 120টা server উত্তর 2 সেকেন্ডে
আগে log থাকতো প্রতিটা server এর নিজের disk এ, তাই খুঁজতে হলে 120টা server এ আলাদা করে ঢুকতে হতো। এখন প্রতিটা server এর ছোট একটা agent log লাইনগুলো সাথে সাথে একটা central store এ পাঠিয়ে দেয়। Server বন্ধ হয়ে গেলেও তার log হারায় না।

Fluent Bit এর মতো agent লাইনগুলো পাঠায়। Elasticsearch বা Loki সেগুলো জমা রাখে আর খোঁজার উপযোগী করে সাজায়। Kibana বা Grafana তে বসে মানুষ খোঁজে। সাবরিনা এখন একটা query লেখে: request_id = "r-7f3a"। দুই সেকেন্ডের মধ্যে তিনটা service এর ১৪টা লাইন সময় ধরে সাজানো অবস্থায় চলে আসে। শেষ লাইনটা coupon service এর: “loyalty উত্তর দিচ্ছে না”। একজন customer এর ক্ষেত্রে অন্তত একটা সূত্র পাওয়া গেলো।

একটা customer এর গল্প পাওয়া গেলো, কিন্তু সবার নয়

Correlation ID দিয়ে একজন customer এর পুরো ঘটনা পড়া যায়। কিন্তু এটা বলে না, এমন ঘটনা কতজনের সাথে ঘটছে। এক ঘণ্টায় ৭২,০০০ checkout এর log পড়ে সেই হিসাব করা যায় না। এর জন্য দরকার সংখ্যা, অর্থাৎ metric।

০৪ “কতবার” আর “কতটা ধীর” সংখ্যায় মাপবো কীভাবে?

Log প্রতিটা ঘটনা আলাদা করে লিখে রাখে। Metric তা করে না। Metric শুধু একটা সংখ্যা রাখে, আর কয়েক সেকেন্ড পর পর সেই সংখ্যার নতুন মান লিখে রাখে। তাই এক মিনিটে ১০ জন checkout করুক বা ১০ লাখ জন, metric এর জায়গা প্রায় একই লাগে। এজন্যই metric সস্তা আর দ্রুত, আর dashboard এর graph গুলো এই metric দিয়েই আঁকা হয়।

Metric তিন রকমের হয়, আর প্রতিটা আলাদা প্রশ্নের উত্তর দেয়:

Counter শুধু বাড়ে, কখনো কমে না সময় checkout_total এ পর্যন্ত 1,52,340টা Gauge এই মুহূর্তের মান, ওঠে আর নামে সময় in_flight_requests এখন 87টা চলছে Histogram কোন সীমার মধ্যে কতগুলো 0.1 0.25 0.5 1 2.5 5s checkout_latency ডানের লেজটাই আসল খবর
Counter শুধু বাড়তে থাকে, তাই এর থেকে "প্রতি মিনিটে কতগুলো" বের করা হয়। Gauge এই মুহূর্তের একটা মান দেখায়, যেমন এখন কতগুলো request চলছে। Histogram প্রতিটা মান কোন সীমার (bucket) মধ্যে পড়লো তা গোনে, তাই ধীর request গুলোর ছোট দলটাও আলাদা করে চোখে পড়ে।

সাবরিনার app এর checkout latency histogram এক ঘণ্টা পর এমন দেখায়:

# প্রতিটা bucket: "এর চেয়ে কম বা সমান" সময়ে কতগুলো request
checkout_latency_seconds_bucket{le="0.1"}     3,100
checkout_latency_seconds_bucket{le="0.25"}   64,800    # 90% এখানেই শেষ
checkout_latency_seconds_bucket{le="0.5"}    70,560
checkout_latency_seconds_bucket{le="1"}      70,600
checkout_latency_seconds_bucket{le="2.5"}    70,610
checkout_latency_seconds_bucket{le="5"}      72,000    # শেষ 2% এখানে এসে জমেছে
checkout_latency_seconds_count               72,000    # মোট request (1 ঘণ্টা)
checkout_latency_seconds_sum                 17,784    # মোট সেকেন্ড (গড় 247ms)

# bucket থেকে p99 বের করা (Prometheus এর query)
histogram_quantile(0.99, rate(checkout_latency_seconds_bucket[5m]))   →  ~3.7
# 3.7: bucket এর ভেতরে আন্দাজ। আসল p99 প্রায় 4s, কাছাকাছিই।

খেয়াল করুন, ৯০% request 250ms এর মধ্যে শেষ। কিন্তু ২.৫ থেকে ৫ সেকেন্ডের bucket এ প্রায় ১,৪০০টা request এসে জমেছে। মাঝের bucket গুলো প্রায় ফাঁকা। মানে ধীর request গুলো “একটু ধীর” নয়। তারা একটা আলাদা দল, যাদের সাথে আলাদা কিছু ঘটছে।

০৫ Average latency 247ms, তবু user রা কষ্ট পাচ্ছে কেন?

সাবরিনার dashboard এ যে সংখ্যাটা সবুজ দেখাচ্ছিলো, সেটা ছিলো average। একটা ছোট উদাহরণে দেখা যাক average কীভাবে মানুষ লুকায়। ধরুন ১০০টা checkout হলো। ৯০টা শেষ হলো 150ms এ, ৮টা 400ms এ, আর ২টা লাগলো পুরো ৪ সেকেন্ড:

4000ms 0 100টা checkout, ছোট থেকে বড় সাজানো (প্রতিটা দাগ একটা request) average = 247ms: "সব ঠিক আছে" এই 2 জন: 4 সেকেন্ড average এ প্রায় চাপা পড়ে যায় p50 = 150ms p95 = 400ms p99 = 4000ms
90টা request 150ms এ, 8টা 400ms এ, আর 2টা 4 সেকেন্ডে শেষ হয়েছে। Average দাঁড়ায় 247ms, দেখে মনে হয় সব ঠিক। কিন্তু p99 বলে দেয়, প্রতি 100 জনে অন্তত 1 জন 4 সেকেন্ড অপেক্ষা করছে। Average সেই মানুষগুলোকে লুকিয়ে ফেলে।

Average বের করলে আসে (90 × 150 + 8 × 400 + 2 × 4000) ÷ 100, অর্থাৎ 247ms। সংখ্যাটা দেখে কেউ চিন্তা করবে না। অথচ ঐ ২ জন customer ৪ সেকেন্ড ধরে চাকা ঘুরতে দেখেছেন। Average তাদের কষ্টকে বাকি ৯৮ জনের সাথে মিশিয়ে পাতলা করে দেয়।

Percentile: সারিতে দাঁড় করিয়ে গোনা

সব request কে কম সময় থেকে বেশি সময়ের ক্রমে সারিতে দাঁড় করান। তারপর জিজ্ঞেস করুন, সারির কোন জায়গায় কত সময়? একে বলে percentile:

সারির শেষের দিকের এই ধীর request গুলোর latency কে বলে tail latency। সাবরিনার সমস্যা পুরোটাই এই লেজে লুকিয়ে ছিলো।

“মাত্র ১%” কেন বড় ব্যাপার

প্রথম কারণ সংখ্যা। প্রতি মিনিটে ১,২০০টা checkout এর ২% মানে প্রতি মিনিটে ২৪ জন মানুষ। এক ঘণ্টায় ১,৪৪০ জন। এরা কোনো graph এর বিন্দু নয়, এরা বাজার করতে আসা মানুষ, যাদের অনেকে বিরক্ত হয়ে ঝুড়ি ফেলে চলে যাবেন।

দ্বিতীয় কারণ আরো চুপিচুপি কাজ করে। একটা page লোড হতে যদি ভেতরে ২০টা আলাদা call লাগে, আর প্রতিটা call এর ১% সম্ভাবনা থাকে ধীর হওয়ার, তাহলে অন্তত একটা call ধীর হওয়ার সম্ভাবনা 1 - 0.99^20 ≈ 0.18, অর্থাৎ প্রায় ১৮%। যে ধীরতা প্রতিটা call এ মাত্র ১% সময় ঘটে, সেটা প্রায় প্রতি ৫টা page load এর একটায় চোখে পড়ে। Call যত বেশি, লেজের ভার তত বেশি পড়ে।

Latency মাপুন percentile দিয়ে

Latency এর জন্য average একা কখনো দেখবেন না। অন্তত p50, p95 আর p99 একসাথে দেখুন। p50 বলে সাধারণ user কেমন আছেন, p99 বলে সবচেয়ে কষ্টে থাকা user রা কেমন আছেন। এই সংখ্যাগুলো দিয়ে কীভাবে লক্ষ্য ঠিক করা হয় আর alert বানানো হয়, সেটা সেশন ২০ এ দেখবো।

০৬ Metric এ user_id label দিলে কী হয়?

p99 খারাপ, এটা জানা গেলো। এবার সাবরিনা জানতে চায়, কাদের জন্য খারাপ। Metric কে ভাগ করে দেখার উপায় হলো label: metric এর সাথে জুড়ে দেওয়া ছোট ট্যাগ, যেমন service="checkout", status="200", coupon="yes"। Label থাকলে প্রশ্ন করা যায়: “শুধু coupon লাগানো checkout এর p99 কত?”

এখানে টিমের একজন নতুন সদস্য উৎসাহ নিয়ে বলে, “তাহলে user_id টাও label বানিয়ে দিই! প্রতিটা user এর latency আলাদা দেখা যাবে।” শুনতে ভালো লাগে। কিন্তু এটা metric system এর সবচেয়ে প্রচলিত ভুলগুলোর একটা।

কারণটা বুঝতে সেশন ০৭ এর cardinality মনে করুন: একটা column এ কতগুলো আলাদা মান আছে। Metric server প্রতিটা আলাদা label combination এর জন্য একটা আলাদা time series রাখে। Time series মানে সময়ের সাথে একটা সংখ্যার মানগুলোর তালিকা। তাই label গুলোর আলাদা মানের সংখ্যা গুণ হয়:

কম মানের LABEL service 40টা মান × endpoint 10টা মান × status 5টা মান = 2,000 series RAM ~4 MB user_id যোগ করলে আগের সব 2,000 × user_id 5,00,000টা মান = 100 কোটি series RAM ~2 TB · metric server crash করে
Metric server প্রতিটা আলাদা label combination কে একটা আলাদা series হিসেবে রাখে। তাই label এর মানের সংখ্যাগুলো যোগ হয় না, গুণ হয়। ধরা হয়েছে প্রতিটা series এ মোটামুটি 2 KB memory লাগে। কয়েকটা মানের label নিরাপদ, কিন্তু লাখ লাখ মানের একটা label পুরো metric system কে অচল করে দেয়।

৫ লাখ user এর app এ user_id label যোগ করা মানে series এর সংখ্যা ২,০০০ থেকে লাফিয়ে ১০০ কোটিতে ওঠা। Prometheus এর মতো metric server সব series memory তে রাখে। এত series রাখার মতো memory তার নেই, তাই সে ধীর হয়ে যায়, শেষে crash করে। আর ঠিক তখনই, যখন সমস্যা খুঁজতে metric সবচেয়ে বেশি দরকার।

কোন তথ্য কোথায় যায়

Label এ রাখুন শুধু অল্প কয়েকটা মানের জিনিস: service, endpoint, status code, region, payment method। User ID, order ID, request ID এর মতো লাখ লাখ মানের জিনিস রাখুন log আর trace এ। Metric বলবে “coupon লাগানো checkout ধীর”, আর log বলবে “user 58213 এর checkout ধীর”।

সাবরিনা coupon label দিয়ে ভাগ করতেই ছবিটা পরিষ্কার হলো। Coupon ছাড়া checkout এর p99 মাত্র 420ms। Coupon লাগানো checkout এর p99 ৪ সেকেন্ডের বেশি। আর আজ রাতে coupon লাগাচ্ছেন মোট checkout এর ২%। শুক্রবারের “প্রথম ৫,০০০ order এ ২০% ছাড়” অফারটা চালু হয়েছে সন্ধ্যা পৌনে আটটায়।

০৭ একটা ধীর request এর ৪ সেকেন্ড ঠিক কোন service এ গেলো?

Coupon লাগানো checkout ধীর, এটা জানা গেলো। কিন্তু coupon এর কাজে জড়িত আছে checkout, coupon, loyalty আর একটা database। প্রতিটা service এর নিজের metric বলে সে নিজে কতক্ষণ নিয়েছে। কিন্তু coupon service ধীর হলে সেটা কি তার নিজের দোষ, নাকি সে যাকে call করেছে তার দোষ? আলাদা আলাদা metric দেখে সেটা বলা কঠিন।

Trace আর span

এখানে দরকার একটা নির্দিষ্ট request এর পুরো যাত্রার হিসাব। একটা request system এ ঢোকা থেকে উত্তর পাওয়া পর্যন্ত যা যা হয়েছে, তার পুরো রেকর্ডকে বলে trace। আর trace এর প্রতিটা ছোট কাজকে বলে span: একটা service এর একটা কাজ, বা একটা database query। প্রতিটা span এ থাকে কাজের নাম, কখন শুরু হলো, আর কতক্ষণ চললো।

একটা span এর ভেতর থেকে আরেকটা কাজ শুরু হলে নতুন কাজটা হয় child span, আর যার ভেতর থেকে শুরু হলো সেটা তার parent span। Checkout coupon কে call করলো, তাই checkout এর span হলো coupon এর span এর parent। এভাবে span গুলো মিলে একটা গাছ তৈরি হয়। গাছটা সময়ের দাগে আঁকলে এমন দেখায়:

0s 1s 2s 3s 4s SPAN checkout POST /checkout 4,100ms cart GET items 60ms coupon apply 3,850ms loyalty discount 3,800ms orders DB SELECT 3,750ms payment charge 120ms trace_id: 4bf92f…4736 · 6টা span · মোট সময়ের 91% গেছে একটা DB query তে
এটা r-7f3a request এর trace। প্রতিটা দাগ একটা span: কোন service, কখন শুরু, কতক্ষণ চললো। বাঁ দিকের ছোট বাঁকা দাগগুলো দেখায়, কোন span কার child। এক নজরেই বোঝা যায়, 4.1 সেকেন্ডের মধ্যে 3.75 সেকেন্ড গেছে loyalty service এর একটা SELECT query তে।

ছবিটা দেখে সাবরিনার মুখে প্রথমবার স্বস্তির হাসি ফোটে। যে উত্তরের জন্য কয়েক ঘণ্টা অনুমান করতে হতো, সেটা এক নজরেই পাওয়া গেলো। Cart এর 60ms বা payment এর 120ms নিয়ে চিন্তার কিছু নেই। ৪.১ সেকেন্ডের মধ্যে ৩.৭৫ সেকেন্ড গেছে loyalty service এর একটা SELECT query তে। Coupon service নির্দোষ। সে শুধু loyalty এর উত্তরের অপেক্ষায় বসে ছিলো।

Span গুলো জোড়া লাগে কীভাবে?

প্রতিটা span আলাদা service এ, আলাদা server এ তৈরি হয়। তাহলে এরা একটা গাছে জোড়া লাগে কীভাবে? উত্তরটা correlation ID এর মতোই। একটা service যখন আরেকটাকে call করে, তখন header এ দুটো জিনিস পাঠায়: পুরো trace এর id (trace_id), আর নিজের span এর id। এভাবে trace এর তথ্য এক service থেকে পরের service এ বয়ে নেওয়াকে বলে context propagation:

প্রতিটা call এর header এ যায়: trace_id আর নিজের span_id (traceparent header) checkout span_id: a1 parent: নেই (root) parent=a1 coupon span_id: b2 parent: a1 parent=b2 loyalty span_id: c3 parent: b2 তিনটা span এরই trace_id: 4bf92f…4736 collector parent দেখে span গুলো জোড়া লাগায়: a1 → b2 → c3
checkout যখন coupon কে call করে, তখন header এ trace_id আর নিজের span_id (a1) পাঠায়। coupon নিজের নতুন span (b2) খোলে আর লিখে রাখে যে তার parent হলো a1। এভাবে প্রতিটা service শুধু নিজের অংশটুকু জানায়, তবু শেষে পুরো গাছটা জোড়া লাগানো যায়।

এই header এর একটা standard নাম আছে, traceparent। দেখতে এমন:

# coupon কে call করার সময় checkout এই header পাঠায় (W3C Trace Context standard)
traceparent: 00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01

# চারটা অংশ, "-" দিয়ে আলাদা করা:
00                                  version
4bf92f3577b34da6a3ce929d0e0e4736    trace_id: পুরো trace এর id
00f067aa0ba902b7                    parent span এর id (checkout এর span)
01                                  sampled: এই trace রাখা হবে

উপরের ছবিতে a1, b2 লেখা হয়েছে সহজ করে বোঝানোর জন্য। আসলে span এর id হয় এমন লম্বা random সংখ্যা। প্রতিটা request এ একটা trace_id থাকায় অনেক টিম আলাদা correlation ID না বানিয়ে log এও এই trace_id লেখে। তাতে log থেকে trace এ, আর trace থেকে log এ এক click এ যাওয়া যায়।

০৮ প্রতিটা request trace করলে খরচ কত, আর কীভাবে কমাবো?

Trace এত কাজের, তাহলে প্রতিটা request এর trace রাখলেই হয়। একটা হিসাব করা যাক। সাবরিনার app এর gateway তে peak এ প্রতি সেকেন্ডে ২,০০০টা request আসে। প্রতিটা request এ গড়ে ৮টা span, প্রতিটা span প্রায় 1 KB। তাহলে প্রতি সেকেন্ডে 16 MB, দিনে প্রায় 1.4 TB শুধু trace। তার বেশিরভাগই একঘেয়ে, দ্রুত, সফল request এর trace, যেগুলো কেউ কোনোদিন খুলেও দেখবে না।

তাই সব trace রাখা হয় না, একটা অংশ বেছে রাখা হয়। একে বলে sampling। বাছাইয়ের দুটো প্রধান উপায়:

প্রতি সেকেন্ডে 2,000টা request সব রাখলে ~1.4 TB trace প্রতিদিন Head sampling Tail sampling শুরুতেই লটারি প্রতি 100টার 1টা রাখি, বাকি বাদ শেষে দেখে বাছাই error আর 1s এর বেশি সব, বাকির 1% সস্তা ও সহজ: ~14 GB/দিন কিন্তু slow trace এর 99% বাদ পড়ে slow আর error সবসময় থাকে কিন্তু শেষ পর্যন্ত সব span জমিয়ে রাখতে হয়
Head sampling request এর শুরুতেই ঠিক করে trace রাখবে কিনা। তখনো কেউ জানে না request টা slow হবে কিনা, তাই slow trace ও একই হারে বাদ পড়ে। Tail sampling request শেষ হওয়া পর্যন্ত অপেক্ষা করে, তারপর slow আর error trace গুলো রেখে দেয়। এতে কাজের trace হাতে থাকে, তবে collector এর উপর চাপ বেশি পড়ে।

OpenTelemetry: সবার জন্য একটা ভাষা

এতক্ষণ যা দেখলাম, তার জন্য প্রতিটা service এ code লিখতে হয়: log এ id লেখা, header এ trace পাঠানো, span খোলা আর বন্ধ করা, metric গোনা। আগে প্রতিটা monitoring tool এর নিজের library ছিলো। Tool বদলাতে চাইলে ৪০টা service এর code ই বদলাতে হতো।

OpenTelemetry এই সমস্যার সমাধান। এটা একটা open standard আর library এর set, যেটা Java, Go, Python, Node.js সহ প্রায় সব প্রধান ভাষায় পাওয়া যায়। Service গুলো একবার OpenTelemetry দিয়ে log, metric আর trace বানায়। তারপর OpenTelemetry Collector নামের একটা আলাদা program সেগুলো যেকোনো জায়গায় পাঠাতে পারে: Prometheus, Jaeger, Grafana, Elasticsearch, বা কোনো paid service। Tool বদলাতে চাইলে শুধু collector এর configuration বদলালেই চলে। Tail sampling এর মতো কাজও এই collector এ করা হয়।

০৯ সব মিলিয়ে: তিনটা pillar একসাথে কীভাবে একটা সমস্যা খুঁজে বের করে?

সাবরিনার শুক্রবার রাতের পুরো খোঁজটা এবার এক জায়গায় দেখা যাক:

1 checkout p99 8 PM থেকে 4s কখন শুরু, কতটা খারাপ METRIC 2 label দিয়ে ভাগ: coupon=yes তে slow কাদের জন্য: coupon লাগানো 2% METRIC 3 একটা slow trace খুলি 3.75s গেছে loyalty এর SELECT এ TRACE 4 trace_id দিয়ে loyalty এর log খুঁজি rows_scanned: 2 কোটি, কোনো index নেই LOG 5 FIX: orders(coupon_code) এ index p99 নেমে এলো 4s থেকে 450ms এ
Metric বলে কখন আর কাদের জন্য সমস্যা। Trace বলে সময়টা কোন service এ গেলো। Log বলে সেখানে ঠিক কী ঘটেছিলো। তিনটা একসাথে থাকায় সাবরিনা 25 মিনিটে কারণটা খুঁজে পায়।

শেষ ধাপে loyalty service এর log এ পাওয়া গেলো আসল কারণ। নতুন অফারে “প্রথম ৫,০০০ order” এর হিসাব রাখতে loyalty service প্রতিটা coupon checkout এ গুনে দেখছিলো, এই coupon দিয়ে এখন পর্যন্ত কতগুলো order হয়েছে। Query ছিলো WHERE coupon_code = 'FRIDAY20'। কিন্তু orders table এর coupon_code column এ কোনো index ছিলো না। তাই প্রতিবার database ২ কোটি row এর পুরো table পড়ছিলো। সেশন ০৭ এর full table scan, ঠিক সেই পুরোনো গল্প।

Index যোগ হওয়ার পর coupon লাগানো checkout এর p99 নেমে এলো 450ms এ। রাত সাড়ে আটটার মধ্যে support এর inbox শান্ত। শুরু থেকে শেষ পর্যন্ত সময় লাগলো ২৫ মিনিট। Observability না থাকলে হয়তো টিম সারা রাত অনুমান করতো, নয়তো সব service একটা একটা করে restart করে দেখতো।

সাবরিনার টিম যা পেলো

  • খোঁজার সময় কমলো: আগে কারণ খুঁজতে কয়েক ঘণ্টা লাগতো, এখন metric থেকে trace আর trace থেকে log ধরে ২৫ মিনিটেই পাওয়া যায়।
  • "কিছু user" এখন একটা সংখ্যা: p99 আর label দেখে বলা যায় ঠিক কতজন, কোন ধরনের checkout এ কষ্ট পাচ্ছে।
  • Server হারালেও log থাকে: সব log এক জায়গায় জমা হয়, তাই কোনো server বন্ধ হয়ে গেলেও প্রমাণ মুছে যায় না।

এর খরচ

  • Storage আর টাকা: শুধু INFO log ই দিনে প্রায় 432 GB হয়। অনেক কোম্পানিতে observability এর বিল মোট infrastructure খরচের বড় একটা অংশ।
  • প্রতিটা service এ code লাগে: id পাঠানো, span খোলা, metric গোনা; একটা service বাদ পড়লে trace এর মাঝখানে ফাঁক থাকে।
  • সতর্ক থাকতে হয়: ভুল label এ metric server crash করতে পারে, আর log এ password বা card number লিখে ফেললে সেটা নিরাপত্তার সমস্যা হয়ে দাঁড়ায়।
সবচেয়ে গুরুত্বপূর্ণ শিক্ষা

Metric দিয়ে শুরু করুন, কারণ সেটা সস্তা আর বলে কখন, কাদের জন্য, কতটা খারাপ। তারপর trace দিয়ে খুঁজুন সময়টা কোথায় গেলো। শেষে log দিয়ে পড়ুন ঠিক কী ঘটেছিলো। তিনটাকে একই id (trace_id বা request_id) দিয়ে জুড়ে রাখুন, যাতে এক জায়গা থেকে আরেক জায়গায় এক click এ যাওয়া যায়।

আর মনে রাখুন, observability পরে যোগ করার জিনিস নয়। সমস্যার রাতে নতুন log লাইন যোগ করে deploy করার সময় থাকে না। যে signal আগে থেকে নেই, সেটা দিয়ে সেই রাতে কিছু খোঁজা যায় না।

১০ মগজে প্রেশার দিন

আগে নিজে ভাবুন। তারপর উত্তর খুলে দেখুন: বেশিরভাগ মানুষ কীভাবে ভাবে, সেই চিন্তায় কী বাদ পড়ে, আর আসল কথাটা কোথায়।

প্রশ্ন ১: Checkout service চলে ৫টা server এ। প্রতিটা server নিজের p99 হিসাব করে পাঠায়। পুরো service এর p99 পেতে এই ৫টা সংখ্যার গড় করলেই কি চলবে?
উত্তর দেখুন আগে নিজে ভাবুন

সবাই যেভাবে ভাবে

“হ্যাঁ, প্রতিটা server এর p99 জানা থাকলে গড় করলেই পুরো service এর p99 মোটামুটি পাওয়া যায়। সব server তো একই code চালায়।”

শুনতে যুক্তিসঙ্গত, কিন্তু অংকটা এভাবে চলে না।

যে জায়গাটা যোগ করা দরকার

Percentile এর গড় করা যায় না। ধরুন ৪টা server এর p99 হলো 200ms, আর একটা server এর disk সমস্যার কারণে তার p99 হলো ৫ সেকেন্ড। গড় আসে প্রায় 1.2 সেকেন্ড। কিন্তু আসল p99 নির্ভর করে কোন server কতগুলো request পেয়েছে আর ধীর request গুলো কোথায় জমেছে তার উপর। গড়টা আসল উত্তরের ধারে কাছেও নাও থাকতে পারে।

সঠিক উপায় হলো প্রতিটা server থেকে histogram এর bucket এর গোনাগুলো পাঠানো। গোনা যোগ করা যায়: সব server এর “250ms এর কম” bucket যোগ করলে পুরো service এর “250ms এর কম” পাওয়া যায়। তারপর সেই মিলিত histogram থেকে p99 বের করতে হয়। এজন্যই Prometheus এর মতো system এ latency রাখা হয় histogram হিসেবে।

মনে রাখার নিয়ম

গোনা যোগ করা যায়, percentile যোগ বা গড় করা যায় না। আগে bucket যোগ করুন, তারপর percentile বের করুন।

প্রশ্ন ২: একজন VIP customer অভিযোগ করেছেন তার checkout ধীর। Manager বললেন, metric এ customer_id label যোগ করে দিন, যাতে প্রতিটা customer এর latency graph দেখা যায়। আপনি কী করবেন?
উত্তর দেখুন আগে নিজে ভাবুন

সবাই যেভাবে ভাবে

“Label যোগ করা এক লাইনের কাজ। Customer প্রতি graph পেলে এমন অভিযোগ দ্রুত মেটানো যাবে।”

উদ্দেশ্যটা ঠিক। কিন্তু কাজটা metric system এর ক্ষতি করবে।

যে জায়গাটা যোগ করা দরকার

৫ লাখ customer মানে ৫ লাখ মানের একটা label। আগের ২,০০০ series এর সাথে গুণ হয়ে series দাঁড়াবে ১০০ কোটিতে। Metric server এর memory শেষ হবে, আর তখন সবার graph একসাথে বন্ধ হয়ে যাবে।

একজন নির্দিষ্ট customer এর প্রশ্নের উত্তর metric এ নয়, log আর trace এ খুঁজতে হয়। customer_id = 58213 দিয়ে log search করুন, আর সেখান থেকে trace_id নিয়ে তার ধীর checkout এর trace খুলুন। আর যদি VIP দের আলাদা করে দেখা সত্যিই দরকার হয়, তাহলে tier="vip" এর মতো অল্প মানের একটা label যথেষ্ট।

সঠিক ভাষায়

Metric এর label দলের জন্য, ব্যক্তির জন্য নয়। একজন মানুষের গল্প খুঁজতে log আর trace ব্যবহার করুন।

প্রশ্ন ৩: আপনার টিম head sampling দিয়ে ১% trace রাখে। ২% checkout ৪ সেকেন্ড নিচ্ছে। তাহলে ঐ ধীর checkout গুলোর trace কি হাতে থাকবে?
উত্তর দেখুন আগে নিজে ভাবুন

সবাই যেভাবে ভাবে

“১% ও তো কম নয়। প্রতি মিনিটে অনেক trace জমা হচ্ছে, তার মধ্যে ধীর গুলোও নিশ্চয়ই কিছু থাকবে।”

কথাটা আংশিক সত্য। কিন্তু সংখ্যাটা করে দেখলে ছবিটা অন্যরকম।

যে জায়গাটা যোগ করা দরকার

প্রতি মিনিটে ধীর checkout ২৪টা। Head sampling এ এদের ১% রাখা হয়, মানে প্রতি মিনিটে গড়ে ০.২৪টা, প্রায় চার মিনিটে একটা trace। একটা সাধারণ সমস্যা বুঝতে এটুকু হয়তো চলে। কিন্তু সমস্যাটা আরো বিরল হলে, যেমন এক হাজারে একটা payment fail, তাহলে ঘণ্টার পর ঘণ্টা একটাও trace হাতে আসবে না।

সমাধান tail sampling: request শেষ হওয়ার পর দেখে ঠিক করা, ধীর আর error trace সব রেখে দেওয়া, আর বাকি স্বাভাবিক trace থেকে অল্প কিছু রাখা। খরচ প্রায় একই থাকে, কিন্তু রাখা trace গুলোই হয় সবচেয়ে কাজের।

মাথায় গেঁথে নিন

Head sampling সব request কে সমান চোখে দেখে, তাই বিরল সমস্যাগুলো সবার আগে হারায়। যে trace খুঁজবেন সেটা রাখতে চাইলে tail sampling ব্যবহার করুন।

১১ যে টার্মগুলো শিখলাম

টার্মমানে
ObservabilitySystem এর পাঠানো signal (log, metric, trace) দেখে ভেতরে কী ঘটছে তা বুঝতে পারার ক্ষমতা।
তিন pillarObservability এর তিন ধরনের signal: logs, metrics আর traces।
Logএকটা ঘটনার লিখিত রেকর্ড: কখন, কোন service এ, কী ঘটলো।
Structured loggingLog কে বাক্য হিসেবে না লিখে নাম দেওয়া field এ (সাধারণত JSON) লেখা, যাতে query করা যায়।
Log levelLog লাইনের গুরুত্বের মাত্রা: DEBUG, INFO, WARN, ERROR।
Correlation IDRequest এর জন্য বানানো একটা unique id, যেটা প্রতিটা service নিজের log এ লেখে আর পরের call এ পাঠায়।
Log aggregationসব server এর log একটা central store এ জমা করা, যাতে এক জায়গা থেকে খোঁজা যায়।
Metricসময়ের সাথে নিয়মিত মাপা একটা সংখ্যা।
Counterযে metric শুধু বাড়ে, যেমন মোট checkout। এর বাড়ার হারটাই কাজের।
Gaugeএই মুহূর্তের মান, যেটা বাড়তে আর কমতে পারে, যেমন চলমান request এর সংখ্যা।
Histogramমানগুলো কোন সীমার (bucket) মধ্যে পড়লো তা গোনে। এর থেকে percentile বের করা যায়।
Percentile (p50, p95, p99)সব মান ছোট থেকে বড় সাজালে নির্দিষ্ট জায়গার মান। p99 মানে ৯৯% মান এর চেয়ে কম বা সমান।
Tail latencyসবচেয়ে ধীর request গুলোর latency, যেমন p99। Average এ এটা লুকিয়ে যায়।
LabelMetric এর সাথে জোড়া ছোট ট্যাগ (service, status), যা দিয়ে metric কে ভাগ করে দেখা যায়।
Cardinality (label এর)একটা label এ কতগুলো আলাদা মান। সব label এর মানের সংখ্যা গুণ হয়ে series এর সংখ্যা ঠিক করে।
Traceএকটা request এর system এ ঢোকা থেকে উত্তর পাওয়া পর্যন্ত পুরো যাত্রার রেকর্ড।
SpanTrace এর একটা ছোট কাজ: নাম, শুরুর সময় আর কতক্ষণ চললো।
Parent spanযে span এর ভেতর থেকে আরেকটা span শুরু হয়েছে।
Context propagationtrace_id আর parent span এর id header এ করে এক service থেকে পরের service এ পাঠানো।
Samplingসব trace না রেখে একটা অংশ বেছে রাখা। Head sampling শুরুতে বাছে, tail sampling শেষে দেখে বাছে।
OpenTelemetryLog, metric আর trace বানানো ও পাঠানোর একটা open standard আর library, যেকোনো tool এর সাথে চলে।

১২ শর্ট সামারি

  1. অনেকগুলো service এর system এ সমস্যা খুঁজতে তিন ধরনের signal লাগে। Metric বলে কখন আর কতটা খারাপ, trace বলে সময়টা কোন service এ গেলো, আর log বলে সেখানে ঠিক কী ঘটেছিলো।
  2. Log লিখুন structured format এ, আর প্রতিটা লাইনে একটা correlation ID বা trace_id রাখুন। সব server এর log একটা central store এ জমা করলে একটা query তে একটা request এর পুরো গল্প পাওয়া যায়।
  3. Latency মাপুন histogram দিয়ে, আর দেখুন p50, p95 আর p99। Average সবচেয়ে কষ্টে থাকা user দের লুকিয়ে ফেলে, আর লাখ লাখ মানের label metric server কে অচল করে দেয়।
  4. Trace হলো span এর একটা গাছ, যেটা header এ trace_id পাঠিয়ে জোড়া লাগে। সব trace রাখা ব্যয়বহুল, তাই sampling করা হয়, আর ধীর ও error trace ধরে রাখতে tail sampling ভালো কাজ করে।

১৩ মনে রাখুন