首頁

目前文章總數:203 篇

  

最後更新:2025年 10月 25日

0006. Log 層級誤判問題分析:Microsoft Debug 訊息誤升為 Warn 的成因與解法

日期:2025年 11月 22日

標籤: Asp.NET Core Asp.NET Core Web MVC C# Nginx Docker Log

摘要:效能議題


範例檔案:基於此篇範例代碼調整
相關參考:0103. ASP.NET Core Web 正確取得客戶端真實 IP:ForwardedHeaders 完整指南
解決問題:本該為 Debug 層級的錯誤,但是卻升級為 Warn 層級的錯誤; 說明錯誤的 Log 記錄方式,導致 Log 嚴重層級錯亂
基本介紹:本篇分為四大部分。
第一部分:說明問題
第二部分:重現此問題代碼說明
第三部分:工作環境中如何出現
第四部分:分析結果 & 結論






第一部分:說明問題

Step 1:原因 - 工作環境中收到此錯誤信

我們在工作生產環境中,收到關鍵字類似如下:

warn: Microsoft.AspNetCore.HttpOverrides.ForwardedHeadersMiddleware[1]
Unknown proxy: [::ffff:172.18.0.1]:49276


如下圖,我們搜尋 5 小時的 Log ,關鍵字 Unknown proxy 出現大量的 Mail Server 記錄哦 Log Level = 4 (Warn) 的紀錄


Step 2:確認 Microsoft Unknown proxy 錯誤等級

關鍵字可以得知,此為 Microsoft 的 AspNetCore 的 FowardedHeader 方法

SourceContext : Microsoft.AspNetCore.HttpOverrides.FowardedHeaderMiddleware


因此新建立一個全新的 AspNet Core 專案,在搭配 0103. ASP.NET Core Web 正確取得客戶端真實 IP:ForwardedHeaders 完整指南 設定方式,必定可確定真實的 錯誤等級



第二部分:重現此問題代碼說明

Step 1:建立全新的專案

我們建立全新的專案,並且在 Program.cs 配置以下

try
{
    var builder = WebApplication.CreateBuilder(args);

    // Add services to the container.
    builder.Services.AddControllersWithViews();

    var app = builder.Build();

    // 1. 添加 ForwardedHeaders 
    var forwardedHeadersOptions = new ForwardedHeadersOptions
    {
        ForwardedHeaders = ForwardedHeaders.XForwardedFor | ForwardedHeaders.XForwardedProto,        
        ForwardLimit = 1
    };

    // 2. 強制添加標頭用於測試
    app.Use(async (context, next) =>
    {
        context.Request.Headers["X-Forwarded-For"] = "192.168.1.100";
        context.Request.Headers["X-Forwarded-Proto"] = "https";
        await next();
    });
    
    // 信任特定的代理伺服器
    forwardedHeadersOptions.KnownProxies.Add(IPAddress.Parse("10.0.0.100"));

    app.UseForwardedHeaders(forwardedHeadersOptions);

    // ... 略

    app.Run();

}
catch (Exception ex)
{
    Console.WriteLine(ex);
}



我們強塞了不存在的標頭 IP ,目的是訪問的時候要觸發 Unknow Proxy

Step 2:部署為 Docker

將代碼部署到遠端的機器,並且 Docker Container 運行
※這篇範例的機器是 192.168.192.44


Step 3:Nginx 配置調整

為了重現 Unkonw Proxy,在 Nginx 上設定模擬外部的訪問
調整如下:

upstream UseForwardedHeadersAPI {
    server  192.168.192.44:7777;
    keepalive 30;
}


server {
    listen        7778;
    server_name   192.168.192.44;

    add_header 'Access-Control-Allow-Origin' '*';
    add_header 'Access-Control-Allow-Methods' 'GET, POST, OPTIONS';
    add_header 'Access-Control-Allow-Headers' 'DNT,X-Mx-ReqToken,Keep-Alive,User-Agent,X-Requested-With,If-Modified-Since,Cache-Control,Content-Type';
	

# 1. 原本設定
#  location ~* / {	
#        proxy_pass         http://UseForwardedHeadersAPI;
#        proxy_http_version 1.1;        
#		proxy_set_header   Host $host:$server_port;
#        proxy_set_header Connection "";
#        proxy_redirect off;
#        proxy_set_header X-real-ip $remote_addr; 
#        proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;
#    }
	
	 
# 2. 模擬來自外部 IP 的請求,一個不存在的 8.8.8.8
 location ~* / {	
    proxy_pass         http://UseForwardedHeadersAPI;
    proxy_http_version 1.1;        
    proxy_set_header   Host $host:$server_port;
    proxy_set_header   Connection "";
    proxy_redirect     off;
    proxy_set_header   X-Real-IP $remote_addr; 
    proxy_set_header   X-Forwarded-For "8.8.8.8, $remote_addr";
   }

}



Step 4: 嘗試訪問 API - 定位出是 Debug 層級

接著嘗試訪問連結

http://192.168.192.44:7778/Home/CallAPI


獲得以下正常反饋


再次進入 Container 中檢查 Logs ,可以發現出現紀錄如下:

dbug: Microsoft.AspNetCore.HttpOverrides.ForwardedHeadersMiddleware[1]
Unknown proxy: [::ffff:8.8.8.8]:34530


正確的 Unknown proxy 微軟給的是 Debug ,但我們發現的問題是 Warm,這表示: Log 等級 的底層代碼有被開發工程師竄改過




第三部分:工作環境中如何出現

Step 1:問題代碼

在工作環境的專案中,發現以下代碼,在 Program.cs 依賴注入時觸發:

public static void SetSerilog(string logPath = "Logs", LoggerConfiguration? loggerConfiguration = null)
{
    _logPath = logPath;    

    loggerConfiguration?
        .MinimumLevel.Debug()
        .MinimumLevel.Override("Microsoft", LogEventLevel.Warning)
        .Filter.ByExcluding(Matching.FromSource<Microsoft.AspNetCore.Diagnostics.ExceptionHandlerMiddleware>())
        .Enrich.FromLogContext()
    //... 略

}


問題就在 .MinimumLevel.Debug() 被 .MinimumLevel.Override(“Microsoft”, LogEventLevel.Warning) 設成 Warning
只要 Microsoft 的關鍵字的 Log 都被往上提升到 Warning




第四部分:分析結果 & 結論

Step 1:分析結果 - 推論 & 建議實踐方式

此段代碼不應該被簽入到專案中,推測應為測試用的代碼,在測試 Debug 環境中,我們常常會進行 Logger.Debug() 來排查問題
開發工程師如果不排查 Microsoft 底層原生地 Debug Log ,會不方便排查問題
因此在此案例中最有效的實踐添加以下會較有效、安全:
※或者更好的方式是本地測試時使用,上線時不應簽入


#if DEBUG
        .MinimumLevel.Debug()
        .MinimumLevel.Override("Microsoft", LogEventLevel.Warning)
#endif


把此問題延伸到其他專案上,較佳的作法:

需求 ❌ 錯誤做法 ✅ 正確做法
減少日誌量 .Override("Microsoft", Warning) .Override("Microsoft", Information) 只過濾 Debug
排除特定冗長日誌 提升整個命名空間等級 精確過濾特定來源:
.AddFilter("Microsoft.EntityFrameworkCore.Database.Command", LogLevel.Warning)
只關注應用程式日誌 把所有 Microsoft 都調高 分層設定:
- Default: Information
- YourApp.*: Debug
- Microsoft.AspNetCore.Hosting: Warning
生產環境減少噪音 全域調整 Microsoft 使用環境變數區分:
- Development: Debug
- Production: Information
特定元件需要除錯 不知道怎麼看 Debug 明確啟用:
.Override("Microsoft.AspNetCore.HttpOverrides", LogLevel.Debug)


無論如何 不應該私自調整 Microsoft.* 的 Log 等級

Step 2:私自調整 Microsoft Log 等級影響

以下是整理出私自調整 Log 等級,帶來嚴重的影響,核心問題是:造成認知混亂、成本增加、排查困難、Log重要性錯亂
導致大量的 Log 會不可信任真實的嚴重性為何

問題類型 具體影響 實際案例
1. 破壞日誌語義 Debug 訊息被當作 Warning,失去原本的嚴重程度意義 Unknown proxy 本來是「正常的除錯訊息」,現在變成「需要立即處理的警告」
2. 監控系統誤報 觸發不必要的告警,產生垃圾郵件/簡訊 每天收到幾十封「Unknown proxy」警報郵件,但其實不是真正的問題
3. 真正問題被淹沒 重要的 Warning 被大量假警報掩蓋,降低警覺性 真正的資料庫連線警告被淹沒在一堆 proxy 訊息中,錯過處理時機
4. 增加維運成本 工程師浪費時間判斷哪些是真警報 每天花 30 分鐘過濾垃圾郵件,一年浪費 180+ 小時
5. 遺失重要除錯資訊 過度過濾導致需要的 Debug/Info 訊息消失 發生問題時,無法追溯 HTTP 請求的詳細資訊,增加除錯難度
6. 違反框架設計原則 Microsoft 工程師已經精心設計每個日誌等級 框架開發者認為這是 Debug,您改成 Warning = 質疑專業判斷
7. 團隊協作混亂 不同工程師對日誌等級認知不一致 新人看到 Warning 以為是嚴重問題,老員工知道可以忽略 → 溝通成本增加
8. 難以定位根本原因 無法區分「框架正常行為」與「真正的異常」 效能調校時無法判斷哪些 Warning 需要優化,哪些可以忽略
9. 升級框架時的風險 新版本可能新增重要的 Information 日誌,但被過濾掉 ASP.NET Core 8.0 新增安全性相關的 Info 日誌,但因為過濾規則看不到
10. 違反最小驚訝原則 其他團隊成員預期看到標準行為,卻看到非預期的日誌 Code Review 時發現日誌行為異常,花時間追查才發現是全域設定被改



Step 3:結論

最重要的原則: 尊重框架開發者的專業判斷,不要輕易覆蓋預設設定 (遵守 Microsoft 的框架規範)
回歸基本,日誌等級的設定應該:

1. 精確 只調整真正需要調整的部分
2. 有意義 保持等級的語義正確性
3. 可維護 有清楚的文件說明
4. 環境區分 Development 和 Production 分開設定