【连载3】C# MVC 异常日志进阶:结构化日志与性能优化技巧

发布于:2025-09-14 ⋅ 阅读:(21) ⋅ 点赞:(0)

在 C# MVC 项目中,日志不仅是排查问题的 “黑匣子”,更是系统监控、性能分析的核心依据。传统文本日志存在查询效率低、信息碎片化的问题,而结构化日志(如 JSON 格式)能让日志信息结构化、可解析,配合性能优化技巧,能让日志系统既 “好用” 又 “不拖慢” 系统。

一、基础铺垫:为什么需要结构化日志

传统文本日志通常以纯文本形式记录,虽然人类可读,但机器解析困难。这类日志通常需要复杂的正则表达式或自定义解析规则才能提取关键信息,且难以进行高效的查询和统计分析。

结构化日志采用标准格式(如JSON、XML)记录,每个字段都有明确的键值对。这种格式不仅保留了可读性,还具备以下优势:

  • 易于解析:标准化格式可直接被日志系统解析,无需复杂处理。
  • 高效查询:支持按字段过滤、排序和聚合,提升日志分析效率。
  • 无缝集成:可直接导入日志分析工具(如ELK、Grafana),无需额外转换。
  • 上下文丰富:可包含更多元数据(如请求ID、耗时、调用链),便于问题追踪。

结构化日志的典型字段

结构化日志通常包含以下核心字段:

  • 时间戳(Timestamp):标准化时间格式(如ISO 8601)。
  • 日志级别(LogLevel):如DEBUG、INFO、ERROR。
  • 业务字段:如用户ID、订单号、错误码。
  • 调用上下文:如控制器名、方法名、堆栈跟踪。
  • 性能数据:如请求耗时(ElapsedMilliseconds)。

二、代码实战:结构化日志的实现方式

现代日志框架(如Serilog、NLog、Log4j 2)原生支持结构化日志。以C# Serilog为例,配置JSON格式输出:

Log.Logger = new LoggerConfiguration()
    .WriteTo.Console(new JsonFormatter())
    .CreateLogger();

Log.Error("订单创建失败, {@OrderInfo}, {ErrorMessage}", 
    new { UserId = 123, OrderNo = "ORD20240520001" }, 
    "数据库连接超时");

输出结果将自动转换为JSON格式,包含所有结构化字段。

1.环境准备

项目类型选择 ASP.NET MVC,支持 .NET Framework 4.8 或 .NET 6+。以 .NET 6 为例,通过 NuGet 安装以下依赖包:

  • Serilog.AspNetCore(核心集成包)
  • Serilog.Sinks.File(文件输出支持)
  • Serilog.Formatting.Compact(JSON压缩格式)

2.核心代码实现(3 步集成)

*Step 1:Program.cs 配置 Serilog(入口初始化)

var builder = WebApplication.CreateBuilder(args);
Log.Logger = new LoggerConfiguration()
    .MinimumLevel.Override("Microsoft", LogEventLevel.Warning)
    .MinimumLevel.Override("System", LogEventLevel.Warning)
    .MinimumLevel.Debug()
    .Enrich.FromLogContext()
    .WriteTo.Console()
    .WriteTo.File(
        path: "Logs\\log-.txt",
        rollingInterval: RollingInterval.Day,
        fileSizeLimitBytes: 1024 * 1024 * 50,
        retainedFileCountLimit: 30,
        formatter: new CompactJsonFormatter()
    )
    .CreateLogger();

builder.Logging.ClearProviders();
builder.Logging.AddSerilog(Log.Logger);
builder.Services.AddControllersWithViews();

Step 2:自定义异常过滤器(捕获 Action 异常并结构化日志)

public class CustomExceptionFilter : IExceptionFilter
{
    public void OnException(ExceptionContext context)
    {
        var controllerName = context.RouteData.Values["controller"]?.ToString() ?? "Unknown";
        var actionName = context.RouteData.Values["action"]?.ToString() ?? "Unknown";
        var userId = context.HttpContext.User.FindFirst("UserId")?.Value ?? "Anonymous";
        
        Log.Error(
            context.Exception,
            "MVC Action 执行异常 | Controller: {ControllerName} | Action: {ActionName} | UserId: {UserId}",
            controllerName, actionName, userId);

        context.Result = new JsonResult(new { Code = 500, Message = "服务器内部错误" }) { StatusCode = 500 };
        context.ExceptionHandled = true;
    }
}

Step 3:注册过滤器并使用

builder.Services.AddControllersWithViews(options => 
{
    options.Filters.Add<CustomExceptionFilter>();
});

日志输出示例

生成的 JSON 日志文件内容如下:

{
  "@t":"2024-05-20T14:35:22.1567321Z",
  "@mt":"MVC Action 执行异常 | Controller: {ControllerName} | Action: {ActionName}",
  "@l":"Error",
  "ControllerName":"Order",
  "ActionName":"Create",
  "@x":"System.Data.SqlClient.SqlException (0x80131904): 数据库连接超时..."
}

3. 效果验证(日志文件示例)

日志文件存储在 Logs 目录下,采用滚动归档策略。通过 ELK 等工具可快速实现:

  • 按 ControllerName 筛选异常
  • 按时间范围查询日志
  • 分析用户操作行为模式

三、性能优化技巧:让日志不拖慢系统

日志虽重要,但如果写入频繁(如高并发接口),可能导致 IO 瓶颈。以下是 3 个关键优化技巧,附代码实现

1.异步写入日志(避免阻塞业务线程)

通过异步写入日志可以避免阻塞业务线程。Serilog默认同步写入文件,高并发下会阻塞MVC请求线程。使用Serilog.Sinks.Async包实现异步写入:

Log.Logger = new LoggerConfiguration()
    .WriteTo.Async(sink =>
        sink.File(
            path: "Logs\\log-.txt",
            rollingInterval: RollingInterval.Day,
            fileSizeLimitBytes: 1024 * 1024 * 50,
            retainedFileCountLimit: 30,
            formatter: new CompactJsonFormatter()
        )
    )
    .CreateLogger();

异步写入将日志放入内存队列,由后台线程批量写入文件,避免业务线程等待IO完成。

2. 过滤冗余日志(减少不必要的日志输出)

MVC框架默认输出大量Information级别的日志,这些日志对排查问题意义不大,可通过以下方式过滤:

方式 1:按日志级别过滤(前文已用)

.MinimumLevel.Override("Microsoft", LogEventLevel.Warning)
.MinimumLevel.Override("System", LogEventLevel.Warning)

方式 2:按内容过滤(排除特定日志)

Log.Logger = new LoggerConfiguration()
    .Filter.ByExcluding(logEvent => 
    {
        if (logEvent.Properties.TryGetValue("RequestPath", out var value) && 
            value.ToString().Contains("/Health/Check"))
        {
            return true;
        }
        return false;
    })
    .CreateLogger();

3. 批量写入日志(减少 IO 次数)

频繁写入小日志会导致磁盘IO频繁,可通过自定义批量Sink实现批量写入:

public class BatchedFileSink : FileSink
{
    private readonly Queue<string> _logQueue = new Queue<string>();
    private readonly int _batchSize = 10;
    private readonly int _batchIntervalMs = 1000;
    private readonly Timer _timer;
    private bool _isFlushing;

    public BatchedFileSink(string path, ITextFormatter formatter, long fileSizeLimitBytes, int retainedFileCountLimit) 
        : base(path, formatter, fileSizeLimitBytes, retainedFileCountLimit)
    {
        _timer = new Timer(FlushQueue, null, _batchIntervalMs, _batchIntervalMs);
    }

    public override void Emit(LogEvent logEvent)
    {
        var logString = Formatter.Format(logEvent);
        lock (_logQueue)
        {
            _logQueue.Enqueue(logString);
            if (_logQueue.Count >= _batchSize && !_isFlushing)
            {
                Task.Run(FlushQueue);
            }
        }
    }

    private async void FlushQueue(object state = null)
    {
        if (_isFlushing) return;
        _isFlushing = true;

        try
        {
            List<string> logsToWrite = new List<string>();
            lock (_logQueue)
            {
                while (_logQueue.Count > 0)
                {
                    logsToWrite.Add(_logQueue.Dequeue());
                }
            }

            if (logsToWrite.Count > 0)
            {
                var batchLog = string.Join("\n", logsToWrite);
                await WriteTextAsync(batchLog + "\n");
            }
        }
        finally
        {
            _isFlushing = false;
        }
    }

    protected override void Dispose(bool disposing)
    {
        base.Dispose(disposing);
        _timer?.Dispose();
        FlushQueue();
    }
}
步骤:

1.自定义批量 Sink(基于 Serilog.Sinks.File 扩展):

using Serilog.Sinks.File;
using System.Collections.Generic;
using System.Threading;
using System.Threading.Tasks;

namespace MVCStructuredLogging.Sinks
{
    /// <summary>
    /// 批量文件Sink:积累10条日志或间隔1秒,批量写入
    /// </summary>
    public class BatchedFileSink : FileSink
    {
        private readonly Queue<string> _logQueue = new Queue<string>();
        private readonly int _batchSize = 10; // 批量大小
        private readonly int _batchIntervalMs = 1000; // 批量间隔
        private readonly Timer _timer;
        private bool _isFlushing;

        public BatchedFileSink(string path, ITextFormatter formatter, long fileSizeLimitBytes, int retainedFileCountLimit) 
            : base(path, formatter, fileSizeLimitBytes, retainedFileCountLimit)
        {
            _timer = new Timer(FlushQueue, null, _batchIntervalMs, _batchIntervalMs);
        }

        public override void Emit(LogEvent logEvent)
        {
            // 将日志转换为字符串,加入队列(不立即写入)
            var logString = Formatter.Format(logEvent);
            lock (_logQueue)
            {
                _logQueue.Enqueue(logString);
                // 队列达到批量大小,触发批量写入
                if (_logQueue.Count >= _batchSize && !_isFlushing)
                {
                    Task.Run(FlushQueue);
                }
            }
        }

        private async void FlushQueue(object state = null)
        {
            if (_isFlushing) return;
            _isFlushing = true;

            try
            {
                List<string> logsToWrite = new List<string>();
                lock (_logQueue)
                {
                    while (_logQueue.Count > 0)
                    {
                        logsToWrite.Add(_logQueue.Dequeue());
                    }
                }

                // 批量写入日志(一次 IO 操作)
                if (logsToWrite.Count > 0)
                {
                    var batchLog = string.Join("\n", logsToWrite);
                    await WriteTextAsync(batchLog + "\n"); // 调用父类的异步写入方法
                }
            }
            finally
            {
                _isFlushing = false;
            }
        }

        protected override void Dispose(bool disposing)
        {
            base.Dispose(disposing);
            _timer?.Dispose();
            FlushQueue(); // 程序退出时,确保队列中剩余日志写入
        }
    }
}

2.在 Program.cs 中使用自定义批量 Sink:

Log.Logger = new LoggerConfiguration()
    .WriteTo.Async(sink => 
        sink.Sink(new BatchedFileSink(
            path: "Logs\\log-.txt",
            formatter: new CompactJsonFormatter(),
            fileSizeLimitBytes: 1024 * 1024 * 50,
            retainedFileCountLimit: 30
        ))
    )
    .CreateLogger();

批量写入将原本多次日志写入合并为一次IO操作,显著降低磁盘IO压力。

四、常踩的坑(避坑指南)

1.日志级别配置过细

全局设置 MinimumLevel.Verbose 会导致日志量激增,引发磁盘空间不足和查询性能下降。建议全局默认级别设为 Debug,针对框架日志(如 MicrosoftSystem 命名空间)调整为 Warning 级别,减少噪音。

2.同步写入日志

直接使用同步 Sink 会在高并发场景下阻塞请求线程,增加接口响应时间。通过 Serilog.Sinks.Async 包装所有 Sink,实现异步非阻塞写入,例如:

.WriteTo.Async(a => a.File("logs/log.txt"))

3.敏感信息泄露

日志中若包含密码、Token 等敏感数据,存在安全风险。可通过以下两种方式解决:

  • 日志过滤:使用 Enrich.WithFilter 移除特定字段。
  • 序列化忽略:在 DTO 属性上添加 [JsonIgnore] 标记,避免敏感字段被记录。

4.未限制日志文件大小和保留时间

长期不清理日志会导致磁盘空间耗尽。需配置以下参数:

  • fileSizeLimitBytes:限制单个日志文件大小(如 50MB)。
  • retainedFileCountLimit:设置保留的日志文件数量(如 30 天)。

5.缺乏上下文信息

仅记录异常消息会难以定位问题根源。应通过以下方式补充上下文:

  • 动态注入:使用 Enrich.FromLogContext 捕获线程上下文中的变量(如 LogContext.PushProperty("UserId", userId))。
  • 手动传入:在异常处理逻辑中显式添加业务字段(如订单号、用户 ID)。

示例代码:

try { /* 业务逻辑 */ }
catch (Exception ex)
{
    Log.Error(ex, "订单处理失败 {OrderNo}", orderNo);
}

五、互动环节:你的日志系统遇到过这些问题吗?

1.你在项目中用的是 Serilog 还是其他日志框架(如 NLog、log4net)?两者在结构化日志支持上有什么差异?
2.高并发场景下,你还遇到过哪些日志性能问题?是如何解决的?
3.除了文件日志,你是否尝试过将结构化日志导入 ELK、Grafana 等工具?可视化分析给你带来了哪些便利?
欢迎在评论区分享你的经验,我们一起优化日志系统!