HttpContext.TraceIdentifier那嚴謹的設計

• 2022 年 5 月 17 日
• 筆記
• aspnetcore, TraceIdentifier, 鏈路追蹤

前言

Asp.Net Core中有一個不受人重視的屬性HttpContext.TraceIdentifier，它在鏈路追蹤中非常有用，下面是官方的定義:

在項目中一般會將該字段輸出到每一條日誌中，也可以將此Id作為通用響應字段返回前端，後續可以根據該屬性和日誌匹配，快速定位整個鏈路日誌。在本地開發時我通常觀察到該值的格式大概如下長這個樣子0HLEACIU86PT6:0000000D，在生產環境中查看日誌時，卻不是這種格式，而是Guid格式，雖然都是唯一標識，都能滿足我的需要，但是為什麼會產生這一差異令我困惑，最初以為是第三方日誌組件對該字段進行了賦值，在我的不懈努力下，最終確定該差異的原因是部署方式差異導致，分享給各位。

差異對比

創建一個Asp.Net Core新項目，在示例代碼中添加一行日誌，打印該屬性

[HttpGet(Name = "GetWeatherForecast")]
public IEnumerable<WeatherForecast> Get()
{
    _logger.LogInformation(Request.HttpContext.TraceIdentifier);

    return Enumerable.Range(1, 5).Select(index => new WeatherForecast
    {
        Date = DateTime.Now.AddDays(index),
        TemperatureC = Random.Shared.Next(-20, 55),
        Summary = Summaries[Random.Shared.Next(Summaries.Length)]
    })
    .ToArray();
}

Kestre部署時的表現

在VS中使用控制台啟動項目，調用幾次接口，輸出如下

可見TraceIdentifier有下面兩部分組成{ConnectionId}:{Request number}，第一部分ConnectionId標識同一次連接，第二部分Request number標識，當前是該連接的第n次請求起到計數的作用。
而兩者的組成{ConnectionId}:{Request number}就可以標識唯一一次請求。

IIS部署時的表現

用上面的的程序，不做任何更改，在VS中IIS Express啟動,調用幾次接口，輸出如下,由於沒使用文件日誌，IIS Express啟動時沒有窗口可以看輸出，只能通過VS的調試窗口查看輸出如下：

這裡可以很明顯的看出，我們打印的TraceIdentifier是GUID格式。

差異的原因

本地開發時我一般不會選擇IIS Express啟動，因為它速度慢，也不能方便的查看日誌輸出。所以正如上文測試的那樣，我在本地使用只看到一種格式：{ConnectionId}:{Request number}。

我們生產環境是部署在Windows Server中，而在windows下部署，使用IIS託管則比使用控制台更加安全穩定，所以這中部署方式輸出的TraceIdentifier和上文中使用IIS Express表現是一致的。

那為何不同的部署方式產生該差異呢？

其實這是Asp.Net Core設計使然。在IIS上，它(TraceIdentifier)來自HTTP.sys（內核驅動程序）並暴露給應用程序，以便您可以跟蹤該ID，從內核到應用程序並返回到內核，它的值來自IIS生成並傳遞給我們的應用。使用Kestrel，請求不需要iis對其進行轉發，我們的應用程序就是鏈路的第一個程序，沒有程序會傳給它一個鏈路ID，所以程序自己需要生成一個，也就是我們看到的這種{ConnectionId}:{Request number}。

總結

在不同的部署方式下，Asp.Net Core對TraceIdentifier有不同的表現，是技術上的一種嚴謹。在IIS部署時，該屬性值來自IIS內核的傳遞，以便我們可以跟蹤IIS內核到我們的程序，也保持了IIS式的風格。