Why would we want query logging in the first place?
Entity Framework simplifies data retrieval by allowing you to use LINQ queries, providing a readable and straightforward approach. It abstracts away the need to write complex queries manually, handling them behind the scenes. While this enhances readability, it can limit visibility into the actual executed queries. It becomes challenging to determine their performance or identify the need for additional indexes solely based on your code. Although you can check request duration in the logs, it only provides the overall execution time when multiple queries and steps are involved.
An alternative approach involves examining the SQL server logs directly, but in our case, we will utilize application insights to visualize the SQL queries and their respective durations.
To achieve this, we will leverage two components:
- Arcus Observability
- Interceptors
Now, let’s delve into these building blocks in more detail.
Arcus Observability
Arcus Observability integrates Azure Application Insights telemetry with ease, leveraging the shared ILogger framework. It enables monitoring dependencies, custom metric recording, and effortless logging of telemetry data. The library supports diverse telemetry types, filtering with Serilog, and custom correlation.
It is ideal for the type of dependency logging we want to implement.
Interceptors
In C#, interceptors are a powerful mechanism that allows you to intercept and modify queries or method calls dynamically. They are commonly used in frameworks like Entity Framework Core and ORMs (Object-Relational Mapping) to provide additional functionality or implement cross-cutting concerns.
Interceptors work by intercepting method invocations at runtime, allowing you to execute custom code before and after the method call. This interception can be done for various purposes, such as logging, caching, authorization, validation, or modifying the behavior of the query or method.
In our case, we will intercept queries and add extra logging with the help of Arcus.
Implementing the query logging
To intercept and log query duration we can use the base class DbCommandInterceptor, which provides several methods for interception at different stages of the querying process. However, for our specific query logging needs, we will focus on the ReaderExecuted and ReaderExecutedAsync methods. After the query execution, we generate a log entry using Arcus, capturing the SQL query, its execution time, and other relevant technical parameters.
Additionally, we employ a separate method to determine the operation, extracting it from the command text, which represents our query.
Once we have added the interceptor to our project, we still need to associate it with our DbContext. To achieve this, we create extensions for the DbContextOptionsBuilder.
Following that, we can incorporate it into the initialization process of our API startup.
Seeing the results in Application Insights
If we now check our API request in application insights, we get an overview of the sql queries that have been executed. In the example here, we had two SELECT queries that were executed and you can see the duration in milliseconds visualized in the timeline as well.
We can also check these queries in more detail, including custom properties:
As well as the executed query:
Implementing connection logging
We can implement a comparable configuration to log the duration of the database connection by adding an interceptor for it. For this one, we will use the base class DbConnectionInterceptor.
Adding the extension in the DbContextOptionsBuilder:
And finally adding the extensions in the API startup:
Embracing the Benefits of Query Logging
In conclusion, despite the potential drawbacks of increased overhead and storage requirements, incorporating query logging remains an intriguing proposition for several reasons:
- Performance Optimization: Analyzing query execution times (with Kusto queries F.E.) helps identify and address bottlenecks, optimizing overall efficiency.
- Troubleshooting and Debugging: Query logs enable precise examination of executed queries, aiding in issue resolution.
- Capacity Planning and Scalability: Analyzing query frequency, duration, and resource consumption assists in planning for growth and optimizing resource allocation.
- Compliance and Auditing: Query logging ensures data integrity, accountability, and compliance with regulatory requirements.
While it is essential to consider the potential impact on performance and storage, the benefits offered by query logging listed here make it a valuable tool for developers and system administrators.
Subscribe to our RSS feed