elastic / ecs-dotnet

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

[BUG] Using NLog.Web.AspNetCore for NLog json config in Worker Service (non AspNet core project) writes NLog internal error messages on every write to NLog loggers #333

Closed bryanfarrell closed 1 year ago

bryanfarrell commented 1 year ago

ECS integration/library project(s): Elastic.CommonSchema.NLog NuGet package 8.6.1 Elastic.Apm.NLog NuGet package 8.6.1

ECS schema version: 8.6.0

ECS .NET assembly version: Elastic.Apm.dll (1.22.0) Elastic.Apm.NLog.dll (8.6.1) Elastic.CommonSchema.dll (8.6.1) Elastic.CommonSchema.NLog.dll (8.6.1)

Elasticsearch version (if applicable): N/A

.NET framework / OS: .NET 7.0 Console Application (created with Visual Studio 2022 Worker Service project template) Product configured to use Autofac 7.0.1 for dependency injection Project configured to use NLog.Web.AspNetCore 5.3.3 so NLog config can be loaded from appsetting.json files

Description of the problem, including expected versus actual behavior: I can have all ECS references added to the project and log to NLog using DI driven by Autofac and configuration loaded from the appsetting.json files without any issues.

When I add a file logger with layout type EcsLayout to the configuration, I can properly setup ECS NDJSON output of my logs for consumption by Elastic Stack. The log files get created and everything seems to be working correctly.

We recently noticed that the internal-nlog.log file that we have NLog writing to is dumping the following two Debug level messages to the log every time we write to the logger with the ECS NLog target enabled.

2023-08-16 19:26:33.8646 Debug ServiceProvider has not been registered. Cannot resolve: Microsoft.AspNetCore.Http.IHttpContextAccessor 2023-08-16 19:26:33.8646 Debug No available HttpContext, because outside valid request context. Logger: ApplicationName.HostedServices.HostedServiceOne

I suspect these NLog Debug messages are occurring because the EcsLayout is trying to pull HttpContext data out to put into the ECS 8.6.0 schema NDJSON log entry, but this is causing issues because I am using the EcsLayout in a server side console application and not a web application.

I tried registering IHttpContextAccessor a couple of different ways, one with Autofac directly and the other by calling builder.Services.AddHttpContextAccessor().

In both cases the EcsLayout is still causing these messages to occur. Since everything is working in our application and the logs are being created, we are just tolerating the issue. We do suspect though that all this extra noise caused by the EcsLayout trying to pull in this data from HttpContext is adding unneeded overhead in our service layer that is already under heavy load.

Steps to reproduce: It would be difficult to provide detailed steps to reproduce this issue and the problem may be pretty obvious to you if you add ECS to a vanilla Visual Studio 2022 Worker Service project. If you do look into this and have trouble reproducing, just let me know and I will make an effort to make a project template from our actual project that you can open up and run to reproduce the error on your side.

Thanks,

Bryan

snakefoot commented 1 year ago

The Elastic.CommonSchema.NLog automatically assumes the host-application is ASP.NET-CoreApp when it detects NLog.Web.AspNetCore is included as dependency.

You can disable this behavior with explictly setting the Layout-option IncludeAspNetProperties="false" (Introduced with ver. 8.6.1). See also #304

bryanfarrell commented 1 year ago

The Elastic.CommonSchema.NLog automatically assumes the host-application is ASP.NET-CoreApp when it detects NLog.Web.AspNetCore is included as dependency.

You can disable this behavior with explictly setting the Layout-option IncludeAspNetProperties="false" (Introduced with ver. 8.6.1). See also #304

Thanks for the quick reply Rolf! I added that setting to the appsettings.json file and it has resolved the problem.