APM ILoggerProvider Implementation

[SuricateCan]

Is your feature request related to a problem? Please describe.
In a netcore application, errors can occur outside of a request (HostedService, Scheduled Job, EventBus). When that happens, APM does not transmit the error because it does not know the error occurred in the first place.

Describe the solution you'd like
I'd like to implement an ILoggerProvider (much like Sentry does it) to send these errors to APM. It would, of course, use the LogLevel established in the configuration to decide what to send.

Describe alternatives you've considered
Lots of people recommended using Serilog for logging purposes and enriching it with APM correlation, and I get it. However, I'm not interested in logging for the purpose of logging, using Logstash. I only care about the errors and I think APM should be the one to report it. Right?

Additional context
I'm also inclined to improve the declaration of this and other APM features using the IHostBuilder, hooking into the application much earlier in the startup process, but that is a topic for another issue.

[gregkalapos]

Hmm... So, in APM we have traces, transactions, and spans and errors are correlated to those. So in our current data model, we can't really say "here is an error, just capture it", we can only say "capture an error on this transaction or on this span" - I'm not super familiar with Sentry, but I think they have a different approach where they mainly focus on errors, it's an error capturing tool, APM focuses on traces and errors can happen on those traces.

Now, having said that - what you can always do is that you simply start a transaction, something like this:

try
{
   //My app's code
}
catch (Exception e)
{
   tracer.CaptureTransaction("SomeTransaction", "BackgroundJobX", transaction =>
   {
      transaction.CaptureException(e);
   });
   throw;
}

The tracer comes from the APM Agent, typically from Agent.Tracer. Now, this code snippet is the absolute worst case, where the transaction does not do anything else other than capturing the exception. If it's HostedService, Scheduled Job, or EventBus you'll probably find better places to start and end the transaction, so you'll be able to capture more. But having said that, you can already have the functionality you described here, you just need to make sure there is an active current transaction (tracer.CurrentTransaction returns that btw), and if there isn't then you just create one.

Another thing I'd like to add here is that in my opinion we should not mix logs and APM in the sense that the APM Agent should focus on APM related things - it has a logger, but it's only about diagnostic logs for the agent itself, so with that we know what's going on in the agent (why isn't it working, what does it do, so it's for agent debugging), but it's not about logging for the monitored application.

I'm also inclined to improve the declaration of this and other APM features using the IHostBuilder, hooking into the application much earlier in the startup process, but that is a topic for another issue.

We recently merged: #537

[SergeyKleyman]

APM Server's Intake API allows error events without transaction-ID - https://github.com/elastic/apm-server/blob/7.0/docs/spec/errors/error.json#L20

[SuricateCan]

Another thing I'd like to add here is that in my opinion we should not mix logs and APM in the sense that the APM Agent should focus on APM related things

@gregkalapos I understand your concern and I agree with you, however, what I'm proposing is not logging, but error tracking.

With this scenario, I could use another tool for general logging and have APM care only about the errors. How to do that is debatable (e.g. minimum log level for it).

As @SergeyKleyman said, the API allows for standalone erros, so the Idea would be:

• Check if the developer has an opened transaction. If it has, use it to help track the error;
• If not, send it as a standalone error, with stack trace, inner exception, etc.

I understand APM is not Sentry, and the focus is different, but I think this would be a nice addition to the library without having to rely on the developer to setup the transactions. He could, if he wanted, but that would not be mandatory.

We recently merged: #537

Yes, I saw that before posting, but I think that when we need to deviate even a little from the default configuration, it is hard to use. But that is a topic I'll further discuss in #873. It makes more sense there.

[gregkalapos]

Thanks for the input @SuricateCan and @SergeyKleyman.

The Node.js agent seems to offer this feature (docs here) - so it can send an error without a transaction or a span.

So, what we can easily do is that we can add a new method on ITracer , something like CaptureError - 1 parameter would be the exception, and we could also add other parameters. That'd be similar to what the Node.js Elastic APM Agent does. On this one I'm very much convinced - this is definitely something we can do and fits our model.

Now, to ILoggerProvider: I can see that this would look like very good integration with .NET Core logging, but I'm still not sure we should do it. First of all it'd open up confusion, because we'd mix APM and Logging - I guess this'd mean that there'd be an ILogger which suddenly sends APM Errors. As already pointed out, e.g. it's not vey clear how to set the log level, and I'm also generally concerned that people would mix this with the internal logger of the agent. On the other hand there are fields for this in the Intake API - we don't fill those currently.

I'm thinking about this... definitely an interesting idea.

[gregkalapos]

Ok, let's brainstorm the ILoggerProvider implementation... it's a really interesting idea.

I think it's fair to assume that a .NET Core app will generally work with ILogger for logging everywhere, so you'll inject an implementation of that and that'll be the logger for the whole app - in this case it'll be our ElasticApmLogger. Right? So it's all or nothing - we either get all the logs, or none of them.

@SuricateCan what would you expect to heppen with logs that are not captured as error? I feel just dropping is not a good idea.

One related thing is this PR: elastic/ecs-dotnet#85 - that's basically an ElasticsearchLoggerProvider (nothing to do with APM at this point (well, ok it cares about traceid, but that's it, it has no knowledge about APM)). So that PR will give the option to directly send logs from ILogger to elasticsearch. I could imagine some integration with that, and then additionally for some predefined log level (typically Critical and Warning, but probably making it configurable) we could additionally generate APM errors.

That way all logs will be in Elasticsearch, and additionally logs higher than a specified level will be also captured as APM errors.

Any thoughts on this? Or any alternative idea to what to do with logs that are not errors?

[SuricateCan]

I'm glad you are taking this into consideration.

I think it's fair to assume that a .NET Core app will generally work with ILogger for logging everywhere, so you'll inject an implementation of that and that'll be the logger for the whole app

That is not true. The application can work with multiple ILoggerProviders at the same time, each one with its own ruleset. With that in mind, we can hard cap the minimum level to Error (configurable if higher) and go our own way. Another logger will take care of the actual general logging.

One related thing is this PR: elastic/ecs-dotnet#85 - that's basically an ElasticsearchLoggerProvider...

I just took a quick look over it, and yes, it looks like this would be something similar, but using APM engine instead of sending directly to elasticsearch.

So my thoughts are, we can make this implementation independent from the one above. Both would co-exist just fine.

[gregkalapos]

Ah, got you... what you mean is that we just register an additional ILoggerProvider on the LoggerFactory and let the existing ones as they are. Right?

Some pseudo prototypes (not fully implemented, just to show the direction here)

Here is how you'd configure it: (of course we'd add extensions method, potentially some ways to configure, etc..)

var factory = LoggerFactory.Create(n =>
{
        // use whatever provider you'd use normally
	n.AddConsole();
        // and just add a new one to capture APM errors
	n.AddProvider(new ApmLoggingProvider());
});

Of course it'd be the same with IHostBuilder... something like this:

private static IHostBuilder CreateHostBuilder(string[] args) =>
	Host.CreateDefaultBuilder(args)
		.ConfigureLogging( n=>
		{
			n.AddConsole(); //or anything else you'd use
                        n.AddProvider(new ApmLoggingProvider());
		})
		.UseAllElasticApm();

not sure, maybe we'd move it into a single call...

And then the implementation would be something like this:

public class ApmLoggingProvider : ILoggerProvider
{
	public void Dispose() { }
	public ILogger CreateLogger(string categoryName) => new ApmErrorLogger();
}

public class ApmErrorLogger : ILogger
{
	public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception exception, Func<TState, Exception, string> formatter)
	{
		if (logLevel >= LogLevel.Error) // configurable
		{
			// Here is the key logic, we generate an APM Error
		}
	}
	public bool IsEnabled(LogLevel logLevel) => logLevel >= LogLevel.Error; //probably configurable
	public IDisposable BeginScope<TState>(TState state) => null;
}

[SuricateCan]

Yes! That is it!
I do have some concerns though. I think if we just add the logger, we will end up duplicating errors that do happen during a request. To prevent that we can (try to) skip the error in middleware and let the logger catch it, or come up with a way to mark the exception as already handled by the middleware.
In any case, I think the logger could be something the user don't need to add as a separate feature. For that to happen, we would need to use the #537 way as the default way to use the library, and slowly deprecate the current one.
That way, we can tap into the logger configuration at the same time we add the middleware.