Getting feedback from EntityFramework Core through diagnostics
Have you ever wanted to get some diagnostics information about Entity Framework Core when it comes to the actions it’s doing such as when a command is executing or executed, when it’s opening a connection to the database or even when there’s an error, to name just a few?
I was searching for a way to be able to get the duration of the query it was executing. I was glad to find out that Entity Framework Core hooks itself into DiagnosticSource
, a simple module that allows code to be instrumented for production-time logging of rich data payloads for consumption within the process that was instrumented.1
Getting hooked into the diagnostic pipeline
DiagnosticSource uses the observer pattern to notify its observers. If you are not familiar with this pattern, it is a good one to have in your toolbelt and I recommend you take some time to go and read up on it.
Now, it’s actually pretty simple to get into the pipeline. The first step is to create an observer class that will act as an observer on the main application subject, DiagnosticListener. In our case we will filter on the EntityFramework listener Microsoft.EntityFrameworkCore (DbLoggerCategory.Name constant in the EF Core framework). A listener (the subject in this case) can itself have observers. This means that we can add ourselves into the pipeline of the EF Core so that when an event happens, it will broadcast it back to us. We can thus create a class that will contain the name and payload information in the form of a <string, object>
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 |
public class EfGlobalListener : IObserver<DiagnosticListener> { private readonly EfInterceptor _interceptor = new EfInterceptor(); public void OnCompleted() { } public void OnError(Exception error) { } public void OnNext(DiagnosticListener listener) { if (listener.Name == DbLoggerCategory.Name) { listener.Subscribe(_interceptor); } } } |
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 |
public class EfInterceptor : IObserver<KeyValuePair<string, object>> { public void OnCompleted() { } public void OnError(Exception error) { } public void OnNext(KeyValuePair<string, object> value) { if (value.Key == RelationalEventId.CommandExecuted.Name) { var commandExecutedEventData = (CommandExecutedEventData) value.Value; var executedCommand = commandExecutedEventData.Command.CommandText; var duration = commandExecutedEventData.Duration; System.Diagnostics.Debug.WriteLine("*** EF DEBUG ***: Duration: {0} - Command: {1}",duration,executedCommand); } } } |
To tie everything together we add our observer into the chain so that it can be notified when an event occurs. This should be added in your entry point method, for instance in an ASP.NET Core application, this would be the Configure method in our startup class.
1 |
DiagnosticListener.AllListeners.Subscribe(new EfGlobalListener()); |
Useful resources
If you are a library writer, it can interesting for you to instrument, through payloads, the internals of your library for us to consume using the DiagnosticSource. Learn more about it here.
If you want to learn about what type of events you can listen to in EF Core, check out all the payload that is available here.