search

elastic / ecs-dotnet

https://www.elastic.co/guide/en/ecs-logging/dotnet/current/setup.html
Apache License 2.0
119 stars 59 forks source link

[BUG] Missing mutiple fields when use `Serilog.Sinks.Async` library #186

Closed changemyminds closed 1 year ago

changemyminds commented 2 years ago

ECS integration/library project(s) (e.g. Elastic.CommonSchema.Serilog): aspnetcore-with-serilog

ECS schema version (e.g. 1.4.0): 1.6.0

ECS .NET assembly version (e.g. 1.4.2): 1.5.3

Elasticsearch version (if applicable):

.NET framework / OS: Windows10

Description of the problem, including expected versus actual behavior: I use the project aspnetcore-with-serilog and add Serilog.Sinks.Async library to integrate. I found the HTTP, URL Fields etc... are missing on console.

p.s: Why I need Serilog.Sinks.Async library? Because in my real case, I need write log to file and want to high performance . So I use example project to test.

Steps to reproduce:

  1. Install Serilog.Sinks.Async 
    dotnet add AspnetCoreExample.csproj package Serilog.Sinks.Async

  2. Modify the Program.cs. Change config.WriteTo.Console(formatter) to config.WriteTo.Async(a => a.Console(formatter))

    .UseSerilog((ctx, config) =>
{
// ... same

// Write events to the console using this configration
var formatter = new EcsTextFormatter(formatterConfig);

// use Async    
config.WriteTo.Async(a => a.Console(formatter));

// mark original sync
//config.WriteTo.Console(formatter);
})
  3. Use curl to test, see the result. 
    curl http://localhost:5000/weatherforecast

This problem is using Serilog.Sinks.Async library that cause the configuration.MapHttpAdapter properties to be null.

adamf-datapath commented 2 years ago

We have also encountered this same issue.

Serilog.Sinks.Async causes the logging to happen on a background thread, but IHttpContextAccessor is not thread safe and "may be null if accessed outside of the request flow" (https://docs.microsoft.com/en-us/aspnet/core/fundamentals/http-context?view=aspnetcore-6.0#httpcontext-isnt-thread-safe) - which appears to be the cause of this bug, where HttpAdapter is unable to map the fields because _httpContextAccessor.HttpContext is null.

nicocomumu commented 1 year ago

I also encountered this problem. I bypassed it by creating a new HttpContextEnricher that completes LogEvent with the information contained in the HTTP context. The LogEventConverter is asynchronous => problem Enrichers are synchronous = > solution

using Elastic.CommonSchema.Serilog.Extensions;
using Elastic.CommonSchema.Serilog.Http;
#if NETSTANDARD
using Microsoft.AspNetCore.Http;
#endif
using Serilog.Core;
using Serilog.Events;
using System;
using System.Collections.Generic;
using System.Runtime.CompilerServices;
using System.Text;

namespace Elastic.CommonSchema.Serilog.Enrichers
{
    public class HttpContextEnricher : ILogEventEnricher
    {

#if NETSTANDARD

        private readonly IHttpContextAccessor _httpContextAccessor;

        public HttpContextEnricher(IHttpContextAccessor httpContextAccessor) =>
            _httpContextAccessor = httpContextAccessor;

        public IHttpAdapter Adapter
        {
            get
            {
                return new HttpAdapter(_httpContextAccessor);
            }
        }
#else

        public IHttpAdapter Adapter
        {
            get
            {
                return new HttpAdapter();
            }
        }
#endif

        /// <summary>
        /// The property name added to enriched log events.
        /// </summary>
        public const string PropertyName = SpecialKeys.HttpContext;

        /// <summary>
        /// Enrich the log event.
        /// </summary>
        /// <param name="logEvent">The log event to enrich.</param>
        /// <param name="propertyFactory">Factory for creating new properties to add to the event.</param>
        public void Enrich(LogEvent logEvent, ILogEventPropertyFactory propertyFactory)
        {
            // Don't care about thread-safety, in the worst case the field gets overwritten and one
            // property will be GCed
            var r = new HttpContextEnrichements();
            if (Adapter.HasContext)
            {
                r.Http = Adapter.Http;
                r.Server = Adapter.Server;
                r.Url = Adapter.Url;
                r.UserAgent = Adapter.UserAgent;
                r.Client = Adapter.Client;
                r.User = Adapter.User;
            }

            logEvent.AddPropertyIfAbsent(propertyFactory.CreateProperty(PropertyName, r.ToJson()));
        }

    }

}

using System;
using System.Collections.Generic;
using System.Text;

namespace Elastic.CommonSchema.Serilog.Http
{
    public class HttpContextEnrichements

    {
        public Client Client { get; set; }
        public CommonSchema.Http Http { get; set; }
        public Server Server { get; set; }
        public Url Url { get; set; }
        public User User { get; set; }
        public UserAgent UserAgent { get; set; }
    }
}
Mpdreamz commented 1 year ago

Thanks @nicocomumu for taking the time to list your approach.

I opened https://github.com/elastic/ecs-dotnet/pull/257 to fix this issue using a synchronous enricher.

Thanks @changemyminds for bringing this to our attention!