.Net 6 - 自定义中间件日志记录 - 混合响应和请求

.Net 6 - Custom Middleware Logging - Mixing responses and requests

我编写了自定义中间件来记录对我们的 API 发出的请求和响应。

我意识到请求和响应不匹配,它们似乎混淆了,这很奇怪。

当在很短的时间内发出大量请求时,似乎会发生这种情况。不确定如何,但似乎在调用 LogResponse 时,它不在与 LogRequest.

相同的范围内

我已经实现了一个版本:

我错过了什么吗?

Trimmed down version of actual code

using System;
using System.IO;
using System.Text;
using System.Threading.Tasks;
using Microsoft.AspNetCore.Http;
using Microsoft.AspNetCore.Http.Features;

namespace Middleware
{
    public class Web
    {
        private readonly RequestDelegate _next;

        private Logging.AuditLog _auditLog;

        public Web(RequestDelegate next)
        {
            _next = next;
        }

        public async Task Invoke(HttpContext context)
        {
            try
            {
                EndpointMetadataCollection endpointMetaData = context.Features.Get<IEndpointFeature>()?.Endpoint.Metadata;

                context.Request.EnableBuffering();

                await LogRequest(context);
                await LogResponse(context);
            }
            catch (UnauthorizedAccessException)
            {
                throw;
            }
            catch (Exception ex)
            {
                //Custom exception logging here
            }
        }

        public async Task LogRequest(HttpContext context)
        {
            IHttpRequestFeature features = context.Features.Get<IHttpRequestFeature>();
            string url = $"{features.Scheme}://{context.Request.Host.Value}{features.RawTarget}";

            IFormCollection form = null;
            string formString = string.Empty;

            if (context.Request.HasFormContentType)
            {
                form = context.Request.Form;
            }
            else
            {
                formString = await new StreamReader(context.Request.Body).ReadToEndAsync();
                var injectedRequestStream = new MemoryStream();
                byte[] bytesToWrite = Encoding.UTF8.GetBytes(formString);
                injectedRequestStream.Write(bytesToWrite, 0, bytesToWrite.Length);
                injectedRequestStream.Seek(0, SeekOrigin.Begin);
                context.Request.Body = injectedRequestStream;
            }

            _auditLog = new Logging.AuditLog()
            {
                RemoteHost = context.Connection.RemoteIpAddress.ToString(),
                HttpURL = url,
                LocalAddress = context.Connection.LocalIpAddress.ToString(),
                Headers = Newtonsoft.Json.JsonConvert.SerializeObject(context.Request.Headers),
                Form = form != null ? Newtonsoft.Json.JsonConvert.SerializeObject(form) : formString
            };
        }

        public async Task LogResponse(HttpContext context)
        {
            if (_auditLog == null)
            {
                await _next(context);
                return;
            }

            Stream originalBody = context.Response.Body;

            try
            {

                using (var memStream = new MemoryStream())
                {
                    context.Response.Body = memStream;

                    await _next(context);

                    memStream.Position = 0;
                    string responseBody = new StreamReader(memStream).ReadToEnd();

                    _auditLog.ResponseStatusCode = context.Response.StatusCode;
                    _auditLog.ResponseBody = responseBody;
                    _auditLog = _auditLog.Save();

                    memStream.Position = 0;
                    await memStream.CopyToAsync(originalBody);
                }
            }
            catch
            {
                _auditLog?.Save();
                throw;
            }
            finally
            {
                context.Response.Body = originalBody;
            }
        }
    }
}

经过一些调查,我能够解决这个问题。

全局变量集,是导致 mix-up 的原因。所有其他端点都在 re-used。

private Logging.AuditLog _auditLog; 必须在方法中使用才能按预期运行。如果全局设置,当调用新端点时,它将 re-write _auditLog 变量与一个新对象。仍在执行的另一个端点将替换 _auditLog 的对象。这导致 responserequest 个主体重复和不匹配。

我所做的修改:

await LogRequest(context);
await LogResponse(context);

var auditLog = await LogRequest(context);
await LogResponse(context, auditLog);

其余的不言自明。

这是完整的页面:

using System;
using System.IO;
using System.Text;
using System.Threading.Tasks;
using Microsoft.AspNetCore.Http;
using Microsoft.AspNetCore.Http.Features;

namespace Middleware
{
    public class Web
    {
        private readonly RequestDelegate _next;

        public Web(RequestDelegate next)
        {
            _next = next;
        }

        public async Task Invoke(HttpContext context)
        {
            try
            {
                EndpointMetadataCollection endpointMetaData = context.Features.Get<IEndpointFeature>()?.Endpoint.Metadata;

                context.Request.EnableBuffering();

                var auditLog = await LogRequest(context);
                await LogResponse(context, auditLog);
            }
            catch (UnauthorizedAccessException)
            {
                throw;
            }
            catch (Exception ex)
            {
                //Custom exception logging here
            }
        }

        public async Task<Logging.AuditLog> LogRequest(HttpContext context)
        {
            IHttpRequestFeature features = context.Features.Get<IHttpRequestFeature>();
            string url = $"{features.Scheme}://{context.Request.Host.Value}{features.RawTarget}";

            IFormCollection form = null;
            string formString = string.Empty;

            if (context.Request.HasFormContentType)
            {
                form = context.Request.Form;
            }
            else
            {
                formString = await new StreamReader(context.Request.Body).ReadToEndAsync();
                var injectedRequestStream = new MemoryStream();
                byte[] bytesToWrite = Encoding.UTF8.GetBytes(formString);
                injectedRequestStream.Write(bytesToWrite, 0, bytesToWrite.Length);
                injectedRequestStream.Seek(0, SeekOrigin.Begin);
                context.Request.Body = injectedRequestStream;
            }

            return new Logging.AuditLog()
            {
                RemoteHost = context.Connection.RemoteIpAddress.ToString(),
                HttpURL = url,
                LocalAddress = context.Connection.LocalIpAddress.ToString(),
                Headers = Newtonsoft.Json.JsonConvert.SerializeObject(context.Request.Headers),
                Form = form != null ? Newtonsoft.Json.JsonConvert.SerializeObject(form) : formString
            };
        }

        public async Task LogResponse(HttpContext context, Logging.AuditLog auditLog)
        {
            if (auditLog == null)
            {
                await _next(context);
                return;
            }

            Stream originalBody = context.Response.Body;

            try
            {

                using (var memStream = new MemoryStream())
                {
                    context.Response.Body = memStream;

                    await _next(context);

                    memStream.Position = 0;
                    string responseBody = new StreamReader(memStream).ReadToEnd();

                    auditLog.ResponseStatusCode = context.Response.StatusCode;
                    auditLog.ResponseBody = responseBody;
                    auditLog = auditLog.Save();

                    memStream.Position = 0;
                    await memStream.CopyToAsync(originalBody);
                }
            }
            catch
            {
                auditLog?.Save();
                throw;
            }
            finally
            {
                context.Response.Body = originalBody;
            }
        }
    }
}