Logging slow queries with Active Support Notifications

Logging slow queries is an important part of performance tuning any Rails application. Rails provides a built-in mechanism for logging slow queries called Active Support Notifications.

This article will show you how to use Active Support Notifications to log slow queries in your Rails application. We will also provide tips on how to analyze slow query logs to identify and fix performance problems.

What is a slow query?

A slow query is a query that takes longer than a certain threshold to execute. The threshold for what constitutes a slow query can vary depending on the application and its performance requirements. However, a good rule of thumb is to consider any query that takes longer than 100 milliseconds to be slow.

Why is it important to log slow queries?

There are many reasons why it is important and why you would want to log slow queries.

First, slow queries can be a sign of underlying performance problems in your application. By logging slow queries, you can identify these problems early on and take steps to fix them. Prevention is better than treatment.

Second, slow queries can help you to identify potential security vulnerabilities in your application. For example, a slow query that is caused by a malicious SQL injection attack can be used to identify the vulnerability and take steps to mitigate it.

Third, slow queries can help you improve your application’s performance.

By analyzing slow query logs, you can identify the queries that are causing the most performance problems and take steps to optimize them. We can log slow query events in our application using Active Support Notifications.

What are Active Support Notifications?

Active Support Notifications are an essential tool for any serious Rails developer who wants to gain deeper insights into their application’s performance and behavior. They allow you to track specific events occurring within your code and gather valuable data about their execution.

By understanding their functionality and leveraging them effectively, you can significantly improve the performance, maintainability, and overall health of your Rails app.

Here’s an overview of Active Support Notifications and their key benefits.

Functionality

• Instrumentation: You can instrument specific events in your Rails application using the ActiveSupport::Notifications.instrument method. This method takes a name, a payload (optional data), and a block of code to be executed.
• Payload: The payload allows you to pass additional data relevant to the event being instrumented. This could include things like timestamps, user IDs, database query details, or any other relevant information.
• Subscribers: After the block is executed, Active Support sends a notification with the name and payload to registered subscribers. These subscribers can then process the information and take specific actions based on the event.

Benefits

• Performance monitoring: By instrumenting key events, you can track their execution time and identify performance bottlenecks within your application. This allows you to optimize your code and improve the overall performance of your Rails app.
• Debugging: Notifications can provide valuable insights into the flow of your application and help diagnose issues. The payload data can reveal unexpected behavior or errors during runtime.
• Custom instrumentation: You can extend the functionality of Active Support Notifications by creating your own custom instruments and subscribers. This allows you to track specific events relevant to your application’s unique needs.
• Integration with other libraries: Many popular Rails libraries, like Action Cable and ActiveJob, leverage Active Support Notifications to provide performance data and event tracking capabilities.

How to log slow queries with Active Support Notifications

Active Support Notifications is a built-in Rails mechanism for logging events that occur in your application. To use Active Support Notifications to log slow queries, the example code below would be placed in an initializer (e.g., config/initializers/error_notifications.rb) to ensure it runs on application startup. Alternatively, add the code to a specific controller or model for targeted logging.

config.active_support.Notifications.subscribe('sql.active_record') do |*args|
  event = ActiveSupport::Notifications::Event.new(*args)
  if event.duration > 100
    Rails.logger.info "Slow query: #{event.payload[:sql]}"
  end
end

This code will log all SQL queries that take longer than 100 milliseconds to execute.

The logged information will include the SQL statement, the duration of the query, and the name of the file and line number where the query was executed.

How to analyze slow query logs

Once you have started logging slow queries, you can analyze the logs to identify the queries that are causing the most performance problems. There are a few different ways to analyze slow query logs.

One way is to use a tool like the Rails Performance Dashboard. The Rails Performance Dashboard provides a graphical interface for viewing and analyzing slow query logs.

Another way to analyze slow query logs is to use a text editor or spreadsheet program. You can use a text editor or spreadsheet program to sort and filter the slow query logs by duration, SQL statement, or file name.

This can help you identify the queries causing the most performance problems.

How to fix slow queries

Once you have identified the queries that are causing the most performance problems, you can take steps to fix them. There are a few different ways to fix slow queries.

One way is to optimize the SQL statement. You can optimize the SQL statement by using indexes, adding constraints, or using more efficient query methods.

Another way to fix slow queries is to cache the results of the query. You can cache the results of the query by using a Rails cache store or by using a database cache (e.g., Redis, Memcached).

Implementing pagination and breaking large result sets into smaller pages will improve performance and reduce memory usage.

Also, consider running Background Jobs and offloading long-running queries to background jobs (e.g., using Sidekiq, Resque) to prevent blocking web requests.

Summary

Active Support Notifications is a built-in Rails mechanism for logging slow queries. Logging slow queries is an important part of performance tuning any Rails application. By logging them, you can identify performance problems early on and take steps to fix them.

You can use Active Support Notifications to log slow queries and analyze the logs to identify the queries that are causing the most performance problems. Once you have identified the queries that are causing the most performance problems, you can take steps to fix them.

If you are on a well-established project and have the capacity to have junior developers on teams, this level of work optimization will guide them to establish better practice by being involved in the process. And by engaging the monitoring team and seniors, to build a better and performant platform. Give your slow query project to a junior developer, and they will benefit tremendously from it.

Don’t wait for the problem to exist. Prevent slow queries before they slow you down. Be proactive, not reactive!

The post Logging slow queries with Active Support Notifications appeared first on Kinsta®.