trace_id و correlation id: دنبال کردن یک درخواست در چند سرویس

تا وقتی سیستم یک برنامهٔ تکی است، دنبال کردن یک درخواست در لاگ با زمان و نام کاربر کمابیش ممکن است. همین که درخواست از gateway به سرویس سفارش، از آنجا به سرویس پرداخت و بعد به یک صف پیام برسد، دیگر نیست. پنج خط لاگ از پنج سرویس، در یک ثانیه، کنار صدها خط دیگر از درخواست‌های هم‌زمان — و هیچ چیزی که بگوید کدام‌ها با هم‌اند.

راه‌حل همیشه یکی است: یک شناسه که در لبهٔ سیستم ساخته شود، همراه درخواست به همه‌جا برود، و در هر خط لاگ نوشته شود. سؤال فقط این است که آن شناسه چیست و چطور منتقل شود. در پروژه‌هایی که دیده‌ام، بیشترین سردرگمی از اینجا می‌آید که «correlation id» و «trace_id» را یک چیز فرض می‌کنند، یا هر دو را با هم و ناسازگار پیاده می‌کنند.

دو مفهوم که با هم قاطی می‌شوند

correlation id یک قرارداد قدیمی و غیررسمی است: یک رشتهٔ یکتا (معمولاً GUID) که در هدری مثل X-Correlation-ID یا X-Request-ID می‌آید و هر سرویس آن را در لاگش می‌نویسد و به فراخوانی بعدی پاس می‌دهد. نام هدر، قالب مقدار و قواعد ساختنش را هر تیم خودش تعیین می‌کند.

trace_id بخشی از استاندارد W3C Trace Context است و OpenTelemetry، ⁦.NET⁩، Java و بیشتر ابزارهای مدرن از آن پیروی می‌کنند. یک trace یعنی کل مسیر یک درخواست؛ هر قدم آن (یک درخواست HTTP، یک کوئری، پردازش یک پیام) یک span است با شناسهٔ خودش. همهٔ spanهای یک درخواست، trace_id مشترک دارند.

تفاوت عملی: correlation id را باید خودتان به همه‌جا برسانید، و هر کتابخانه‌ای که از آن خبر ندارد، زنجیره را می‌شکند. trace context را فریم‌ورک‌ها و کتابخانه‌های HTTP خودشان منتقل می‌کنند. توصیهٔ من برای سیستم تازه ساده است: trace_id را شناسهٔ اصلی بگیرید و correlation id را فقط وقتی نگه دارید که دلیل مشخصی دارید (پایین‌تر می‌گویم کِی). مفاهیم پایه‌تر را در راهنمای OpenTelemetry گفته‌ام.

W3C Trace Context در یک نگاه

استاندارد دو هدر تعریف می‌کند. مهم‌ترش traceparent است:

traceparent: 00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01
             │  │                                │                └─ flags (01 = sampled)
             │  │                                └─ parent span id (16 hex)
             │  └─ trace id (32 hex)
             └─ version

هدر دوم، tracestate، برای اطلاعات اختصاصی فروشندگان است و در بیشتر سیستم‌ها لازم نیست به آن دست بزنید. نکتهٔ کلیدی این است که هر سرویس trace id را دست‌نخورده نگه می‌دارد و فقط span id خودش را جایگزین می‌کند. پس اگر سرویس سوم trace id تازه‌ای ساخت، زنجیره همان‌جا شکسته — و این رایج‌ترین باگی است که در پیاده‌سازی‌های دستی می‌بینم.

در ⁦ASP.NET Core⁩ بیشترش از قبل انجام شده

در ⁦.NET⁩، مفهوم span با کلاس System.Diagnostics.Activity پیاده شده و قالب پیش‌فرض شناسه‌هایش از ⁦.NET 5⁩ به بعد W3C است. یعنی بدون هیچ کدی:

• ⁦ASP.NET Core⁩ برای هر درخواست ورودی یک Activity می‌سازد. اگر درخواست هدر traceparent داشته باشد، trace id را از آن برمی‌دارد؛ وگرنه trace تازه شروع می‌کند.
• HttpClient (از جمله آن‌هایی که با IHttpClientFactory ساخته می‌شوند) هدر traceparent را روی درخواست‌های خروجی می‌گذارد.
• پس trace id از سرویس اول به دوم و سوم می‌رسد، به شرطی که همه ⁦.NET⁩ مدرن یا هر فریم‌ورک دیگری باشند که W3C را می‌فهمد.

تنها کاری که می‌ماند، این است که trace id در لاگ هم بیاید. اگر لاگ را با OpenTelemetry می‌فرستید، trace id و span id خودکار روی هر رکورد لاگ گذاشته می‌شوند. اگر از provider دیگری مثل console استفاده می‌کنید، آن را در scope لاگ قرار دهید:

builder.Logging.Configure(options =>
{
    options.ActivityTrackingOptions =
        ActivityTrackingOptions.TraceId |
        ActivityTrackingOptions.SpanId |
        ActivityTrackingOptions.ParentId;
});

builder.Logging.AddJsonConsole(options => options.IncludeScopes = true);

Serilog هم از نسخهٔ ۳.۱ به بعد trace id و span id را از Activity.Current برمی‌دارد و sinkهایی که از آن پشتیبانی می‌کنند، آن را می‌فرستند. پیکربندی کامل هر دو مسیر را در راهنمای لاگ در ⁦ASP.NET Core⁩ و پیکربندی Serilog آورده‌ام.

correlation id کسب‌وکاری کجا به کار می‌آید

با وجود trace context، دو جا هست که هنوز correlation id جداگانه را مفید دیده‌ام:

• وقتی شناسه از بیرون سیستم شما می‌آید. مثلاً اپ موبایل برای هر «تلاش پرداخت» شناسه‌ای می‌سازد و با چند درخواست پشت سر هم (و چند trace) می‌فرستد. آن شناسه، چند trace را به یک عمل کاربر وصل می‌کند.
• وقتی بخشی از مسیر از سیستمی می‌گذرد که trace context را نمی‌فهمد — یک سرویس قدیمی، یک سامانهٔ طرف سوم، یا یک فایل دسته‌ای.

در این حالت، correlation id را در یک middleware بخوانید (یا بسازید)، به پاسخ برگردانید و در scope لاگ بگذارید تا روی همهٔ خطوط آن درخواست بیاید:

app.Use(async (context, next) =>
{
    var incoming = context.Request.Headers["X-Correlation-ID"].FirstOrDefault();

    // ورودی کاربر است: طول و کاراکترها را محدود کنید
    var correlationId = incoming is { Length: > 0 and <= 64 } && incoming.All(c => char.IsAsciiLetterOrDigit(c) || c == '-')
        ? incoming
        : Activity.Current?.TraceId.ToString() ?? Guid.NewGuid().ToString("N");

    context.Response.Headers["X-Correlation-ID"] = correlationId;

    var logger = context.RequestServices
        .GetRequiredService<ILoggerFactory>()
        .CreateLogger("Correlation");

    using (logger.BeginScope(new Dictionary<string, object> { ["CorrelationId"] = correlationId }))
    {
        await next(context);
    }
});

دو نکته دربارهٔ این کد. اول، scopeها در Microsoft.Extensions.Logging بین همهٔ loggerهای یک factory مشترک‌اند، پس scopeی که اینجا باز شده روی لاگ کنترلرها و سرویس‌ها هم می‌آید. دوم، هدر ورودی را بی‌بررسی در لاگ نگذارید؛ مقداری که کاربر می‌فرستد می‌تواند شامل شکست خط باشد و خط لاگ جعلی بسازد — موضوعی که در مقالهٔ تزریق لاگ مفصل گفته‌ام. (char.IsAsciiLetterOrDigit از ⁦.NET 7⁩ وجود دارد.)

صف پیام: جایی که زنجیره معمولاً می‌شکند

HTTP را فریم‌ورک برایتان منتقل می‌کند؛ صف پیام را لزوماً نه. وقتی سرویس سفارش پیامی در RabbitMQ یا Kafka می‌گذارد و سرویس دیگری ساعتی بعد پردازشش می‌کند، اگر trace context در هدرهای پیام نرفته باشد، لاگ‌های مصرف‌کننده به هیچ درخواستی وصل نیستند.

پیش از نوشتن کد، مستندات کتابخانه‌تان را ببینید: کتابخانه‌هایی مثل MassTransit و نسخه‌های جدید برخی کلاینت‌ها این کار را خودشان انجام می‌دهند. اگر نه، کار دستی ساده است، چون مقدار Activity.Id در قالب W3C دقیقاً همان مقدار هدر traceparent است:

// سمت تولیدکننده (RabbitMQ.Client)
var props = new BasicProperties
{
    Headers = new Dictionary<string, object?>()
};
if (Activity.Current is { } current)
{
    props.Headers["traceparent"] = current.Id;
}

// سمت مصرف‌کننده
string? traceparent = null;
if (ea.BasicProperties.Headers?.TryGetValue("traceparent", out var raw) == true && raw is byte[] bytes)
{
    traceparent = Encoding.UTF8.GetString(bytes);
}

using var activity = new Activity("ProcessOrderMessage");
if (traceparent is not null)
{
    activity.SetParentId(traceparent);
}
activity.Start();

_logger.LogInformation("Processing order {OrderId}", orderId);

RabbitMQ مقدار رشته‌ای هدرها را در سمت مصرف‌کننده به‌صورت byte[] برمی‌گرداند؛ تبدیل بالا برای همین است. اگر OpenTelemetry tracing را در برنامه دارید، به‌جای new Activity بهتر است از یک ActivitySource با ActivityKind.Consumer استفاده کنید؛ برای پیوند دادن لاگ‌ها، نسخهٔ ساده هم کافی است.

کارهای پس‌زمینه

یک BackgroundService که هر پنج دقیقه سبدهای منقضی را پاک می‌کند، درخواست ورودی ندارد و Activity.Current در آن خالی است. نتیجه: همهٔ لاگ‌هایش بی trace_id‌اند، یا بدتر، اگر یک Activity بیرون از حلقه ساخته شود، همهٔ اجراها در طول هفته‌ها یک trace_id می‌گیرند. قاعدهٔ من: هر اجرای مستقل، یک trace تازه.

protected override async Task ExecuteAsync(CancellationToken stoppingToken)
{
    while (!stoppingToken.IsCancellationRequested)
    {
        using (var activity = new Activity("CleanupExpiredCarts").Start())
        {
            try
            {
                _logger.LogInformation("Cart cleanup started");
                var removed = await _carts.RemoveExpiredAsync(stoppingToken);
                _logger.LogInformation("Cart cleanup finished, {Removed} carts removed", removed);
            }
            catch (Exception ex) when (ex is not OperationCanceledException)
            {
                _logger.LogError(ex, "Cart cleanup failed");
            }
        }

        await Task.Delay(TimeSpan.FromMinutes(5), stoppingToken);
    }
}

حالت دوم، کاری است که یک درخواست آن را صف کرده: کاربر گزارشی سفارش می‌دهد و job ده دقیقه بعد اجرا می‌شود. اینجا Activity.Current?.Id را هنگام ساخت job کنار رکورد آن ذخیره کنید (در ستونی در جدول jobها، یا در پارامترهای Hangfire و Quartz) و هنگام اجرا با SetParentId به آن وصل شوید. آن وقت از درخواست کاربر تا خطای job، یک trace_id دارید.

خطاهای رایج

• ساختن شناسهٔ تازه در هر سرویس. اگر سرویسی هدر ورودی را نادیده بگیرد و GUID تازه بسازد، زنجیره در آن نقطه دو تکه می‌شود.
• نوشتن شناسه فقط در اولین خط. شناسه باید روی هر خط باشد؛ برای همین است که scope و enricher وجود دارند.
• نام‌های ناسازگار. TraceId در یک سرویس، trace_id در دیگری و traceId در سومی، جستجو را سه برابر سخت می‌کند. یک نام را قرارداد کنید.
• پنهان کردن شناسه از کاربر. trace id را در پاسخ خطا برگردانید تا کاربر یا پشتیبانی بتواند آن را گزارش کند. این را در مقالهٔ خطای ۵۰۰ در پروداکشن در قالب یک ماجرای کامل نشان داده‌ام.

وقتی trace_id روی همهٔ خطوط بود، ابزار لاگ می‌تواند کار اصلی را بکند: نشان دادن همهٔ خطوط یک درخواست، از همهٔ سرویس‌ها، پشت سر هم. در LogMug این دکمهٔ «همهٔ لاگ‌های این درخواست» است و نحوهٔ کار با آن را در آموزش دنبال کردن یک درخواست نوشته‌ام.

منابع و مطالعهٔ بیشتر

• استاندارد W3C Trace Context — تعریف دقیق هدرهای traceparent و tracestate و قواعد انتقالشان.
• انتقال context در OpenTelemetry — اینکه trace context چطور بین سرویس‌ها و از روی صف‌ها منتقل می‌شود.
• مفاهیم ردیابی توزیع‌شده در ⁦.NET⁩ — توضیح Microsoft دربارهٔ Activity، شناسه‌ها و رابطهٔ آن‌ها با W3C.
• لاگ‌نویسی در ⁦.NET⁩ — مرجع رسمی scopeها و ActivityTrackingOptions در Microsoft.Extensions.Logging.