總結：利用asp.net core日志進行生產環境下的錯誤排查（asp.net core version 2.2，用IIS做服務器）

概述

調試asp.net core程序時，在輸出窗口中，在輸出來源選擇“調試”或“xxx-ASP.NET Core Web服務器”時，可以看到類似“info:Microsoft.AspNetCore.Hosting.Internal.WebHost[2] Request finished in 285.6ms 200 text/css”這樣的內容，這就是asp.net core的日志。如果出現了未捕獲的異常，在輸出窗口中可以看到出錯信息，如：fail: Microsoft.AspNetCore.Server.Kestrel[13]……An unhandled exception was thrown by the application. System.NullReferenceException: 未將對象引用設置到對象的實例。在……行號 xx 在……行號 xx。在網站運行過程中，如果可以把這些出錯信息保存下來，就可以排查代碼錯誤了。方法很簡單：把web.config文件中aspNetCore標簽的stdoutLogEnabled屬性設置為true，這樣，在網站運行后，默認會在/logs文件夾下產生一個stdout_xxx_xxx.log的文件，日志會保存到這里面。

 

logging provider

從名稱“stdoutLogEnabled”來看，stdout，表示“標准輸出”，即控制台輸出。試着寫一句Console.WriteLine(xxx)，在.log文件中果然就可以看到輸出的內容。如果是在調試環境，可以在輸出窗口/ASP.NET Core Web服務器看到Console輸出的內容。asp.net core mvc項目代碼模板默認添加了三個logging provider：Console、Debug、EventSource。VS的輸出窗口/ASP.NET Core Web服務器，顯示的就是Console這個logging provider輸出的內容，而輸出窗口/調試，顯示的是Debug的。所以，stdout_xxx_xxx.log文件，保存的就是Console logging provider輸出的日志。

觀察VS的輸出窗口，可以發現，同一條日志內容，Console和Debug這兩個logging provider的輸出格式是不同的。

 

日志級別

ASP.NET Core定義了幾個日志級別，表示日志的嚴重程度，從低到高分別是Trace 、Debug 、Information 、Warning 、Error 、Critical 。

下面是一條Debug級別的日志：

dbug: Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder[27]
      Done attempting to validate the bound parameter 'page' of type 'System.Int32'.

一條Information級別的日志：

info: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[1]
      Executing action method XXX.Controllers.YYYController.GetList (XXX) with arguments (8d35e231-c928-479e-95d4-b305a6a235eb, 1, 15, 1) - Validation state: Valid

在生產環境下，日志一般僅用於錯誤排查，所以用不到Information 等級別的大量日志，為此，可以設置一個最低日志級別，比如設置成Warning，將屏蔽Trace 、Debug 、Information級別的日志。最低日志級別可以給每個logging provider分別設置，如果沒有具體設置，將采用默認設置。如，設置默認日志級別為Information：

"Logging": {
    "LogLevel": {
      "Default": "Information"
    }
  }

分別設置Debug、Console的日志級別：

  "Logging": {
    "Debug": {
      "LogLevel": {
        "Default": "Information"
      }
    },
    "Console": {
      "LogLevel": {
        "Default": "Debug"
      }
    },
    "LogLevel": {
      "Default": "Debug"
    }
  },

為什么針對具體的logging provider也標上"Default"？因為可以再針對日志的Log category分別設置：

  "Logging": {
    "Console": {
      "LogLevel": {
        "Microsoft.AspNetCore.Mvc.Razor.Internal": "Warning",
        "Microsoft.AspNetCore.Mvc.Razor.Razor": "Debug",
        "Microsoft.AspNetCore.Mvc.Razor": "Error",
        "Default": "Information"
      }
    },
    "LogLevel": {
      "Default": "Debug"
    }
  }

關於Log category的概念請自行查閱官方文檔，不再贅述。

值得注意的時，在網站運行狀態下，修改appsettings.json中的上述配置，不會造成網站重啟（而修改web.config會造成網站重啟），但對日志級別的控制會立即生效。所以，在網站運行不正常時，可以臨時調低日志級別，以查看更多調試信息，又不會影響用戶的使用。平時可以設置一個較高的日志級別，比如Error或Critical。而web.config中的stdoutLogEnabled屬性要提前設置好。

 

輸出自己的日志

可以輸出自己的日志。用依賴注入的方式，注入ILogger<T>對象，然后用LogInformation()、LogWarning()等方法可以方便的輸出對應級別的日志。

示例代碼：

    public class HomeController : Controller
    {
        ILogger<HomeController> _logger;

        public HomeController(ILogger<HomeController> logger)
        {
            _logger = logger;
        }

        public IActionResult Index()
        {
            _logger.LogInformation("訪問主頁");

            try
            {
                int i = 0;
                int j = 1 / i;
            }
            catch (Exception ex)
            {
                _logger.LogWarning($"發生異常了：{ex.Message},調用堆棧:{ex.StackTrace}");
            }

            throw new Exception("這是一個測試錯誤");

            return View();
        }
    }

產生的部分日志（級別設置為Information）：

info: CommonCoreMvcTest.Controllers.HomeController[0]
      訪問主頁
warn: CommonCoreMvcTest.Controllers.HomeController[0]
      發生異常了：嘗試除以零。,調用堆棧:   在 CommonCoreMvcTest.Controllers.HomeController.Index() 位置 E:\xxx\Test\CommonCoreMvcTest\Controllers\HomeController.cs:行號 28
fail: Microsoft.AspNetCore.Diagnostics.ExceptionHandlerMiddleware[1]
      An unhandled exception has occurred while executing the request.
System.Exception: 這是一個測試錯誤
   在 CommonCoreMvcTest.Controllers.HomeController.Index() 位置 E:\xxx\Test\CommonCoreMvcTest\Controllers\HomeController.cs:行號 36
   在 lambda_method(Closure , Object , Object[] )
   在 Microsoft.AspNetCore.Mvc.Internal.ActionMethodExecutor.SyncActionResultExecutor.Execute(IActionResultTypeMapper mapper, ObjectMethodExecutor executor, Object controller, Object[] arguments)
   在 Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.<InvokeActionMethodAsync>d__12.MoveNext()
--- 引發異常的上一位置中堆棧跟蹤的末尾 ---
……

 

添加web.config到源代碼項目中

新建的asp.net core 2.2項目，默認沒有web.config文件。得在網站發布后才能修改產生的web.config文件內容嗎？沒必要，可以通過“添加”、“新建項”、“Web配置文件”的方式，手動添加web.config文件到源碼項目中。

 

使日志包含時間

asp.net core的日志不包含時間，這是個大問題，在3.0版本后，Console log provider可以配置時間格式了。經過搜索，我發現一個好用的第三方log provider：LoggingAdvanced.Console。可以用它來取代Console log provider。具體步驟如下：

1、安裝nuget包LoggingAdvanced.Console

2、修改Program.cs的CreateWebHostBuilder方法，在其中的方法調用鏈的最后，調用ConfigureLogging方法，修改后的代碼如下：

public static IWebHostBuilder CreateWebHostBuilder(string[] args) =>
            WebHost.CreateDefaultBuilder(args)
                .UseStartup<Startup>()
                .ConfigureLogging((hostingContext, loggingBuilder) =>
                 {
                     loggingBuilder.ClearProviders();//清除所有logging provider

                     loggingBuilder.AddDebug();//恢復添加Debug logging provider

                     loggingBuilder.AddEventSourceLogger();//恢復添加EventSource logging provider

                     var loggingSection = hostingContext.Configuration.GetSection("Logging");

                     loggingBuilder.AddConsoleAdvanced(loggingSection);//添加LoggingAdvanced.Console logging provider
                 });

3、修改appsettings.json的中的Logging部分，修改后如下：

"Logging": {
    "IncludeTimestamp": true,
    "IncludeLogNamespace": true,
    "TimestampPolicy": {
      "TimeZone": "Ulaanbaatar Standard Time",
      "Format": "yyyy/MM/dd HH:mm:ss.fff"
    },
    "LogLevel": {
      "Default": "Warning"
    }
  }

輸出的部分日志：

[2020.03.07 22:39:36] info: HomeController: 訪問主頁
[2020.03.07 22:39:36] warn: HomeController: 發生異常了：嘗試除以零。,調用堆棧:   在 CommonCoreMvcTest.Controllers.HomeController.Index() 位置 E:\xxx\Test\CommonCoreMvcTest\Controllers\HomeController.cs:行號 28
[2020.03.07 22:39:36] fail: ExceptionHandlerMiddleware[1]: An unhandled exception has occurred while executing the request.
System.Exception: 這是一個測試錯誤
   在 CommonCoreMvcTest.Controllers.HomeController.Index() 位置 E:\xxx\Test\CommonCoreMvcTest\Controllers\HomeController.cs:行號 36
   在 lambda_method(Closure , Object , Object[] )
   在 Microsoft.AspNetCore.Mvc.Internal.ActionMethodExecutor.SyncActionResultExecutor.Execute(IActionResultTypeMapper mapper, ObjectMethodExecutor executor, Object controller, Object[] arguments)
   在 Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.<InvokeActionMethodAsync>d__12.MoveNext()
……

 

技巧

用瀏覽器查看.log文件，日志有更新，刷新一下就好了。

 

參考資料

1、Logging in .NET Core and ASP.NET Core

2、LoggingAdvanced.Console