Avoid Costly Rails Logging

Let’s be clear: This post is not targeting logger lines like this, with short/quick strings:

Rails.logger.debug ‘Rare Event!’

Some Logs Can Be Costly

But every now and then you might stumble upon a more-intense logger line. Maybe yo…


This content originally appeared on DEV Community and was authored by Jake Swanson

Let's be clear: This post is not targeting logger lines like this, with short/quick strings:

Rails.logger.debug 'Rare Event!'

Some Logs Can Be Costly

But every now and then you might stumble upon a more-intense logger line. Maybe you are serializing objects for debugging in your logs, or doing IO to load DB rows for debugging purposes. To simulate this, I will go to an extreme and just use sleep:

Rails.logger.level = :info # simulating production

Benchmark.measure do
  Rails.logger.debug "Log: #{sleep 1}"
end.real

# 1 second passes...
=> 1.0011528139948496

This log does not print because it is .debug and our logger.level is :info. But we still had to endure the string-building logic.

Possible Solution: Use Block Syntax

This syntax passes a block, which is only called if the logging actually runs.

Rails.logger.level = :info # simulating production

Benchmark.measure do
  Rails.logger.debug { "Log: #{sleep 1}" }
end.real

# instantly returns a way smaller value
=> 1.4374993043020368e-05

If your logging level is :debug (usually in development), you will see the time go back up because the logging is actually happening:

Rails.logger.level = :debug # simulating development

Benchmark.measure do
  Rails.logger.debug { "Log: #{sleep 1}" }
end.real

# back up to 1s, we are in debug and want our log
=> 1.0006488429935416

Code Coverage Concern

One downside to this path is code-coverage, especially if you suppress :debug-level logging in your build environment. Unless your block is executed on a real case, you might not know for sure that it works. Maybe you have a typo or nil.method error in your log line and you will only find it in whatever special environment wants to actually log your string.

In my head you can make that more visible by making sure to add a newline on your block, so that automated code coverage tools will call you out. This way, the line will be red unless your build pipeline actually built you a string successfully:

Rails.logger.debug do
  "Log: #{sleep 1}"
end


This content originally appeared on DEV Community and was authored by Jake Swanson


Print Share Comment Cite Upload Translate Updates
APA

Jake Swanson | Sciencx (2021-04-09T20:04:40+00:00) Avoid Costly Rails Logging. Retrieved from https://www.scien.cx/2021/04/09/avoid-costly-rails-logging/

MLA
" » Avoid Costly Rails Logging." Jake Swanson | Sciencx - Friday April 9, 2021, https://www.scien.cx/2021/04/09/avoid-costly-rails-logging/
HARVARD
Jake Swanson | Sciencx Friday April 9, 2021 » Avoid Costly Rails Logging., viewed ,<https://www.scien.cx/2021/04/09/avoid-costly-rails-logging/>
VANCOUVER
Jake Swanson | Sciencx - » Avoid Costly Rails Logging. [Internet]. [Accessed ]. Available from: https://www.scien.cx/2021/04/09/avoid-costly-rails-logging/
CHICAGO
" » Avoid Costly Rails Logging." Jake Swanson | Sciencx - Accessed . https://www.scien.cx/2021/04/09/avoid-costly-rails-logging/
IEEE
" » Avoid Costly Rails Logging." Jake Swanson | Sciencx [Online]. Available: https://www.scien.cx/2021/04/09/avoid-costly-rails-logging/. [Accessed: ]
rf:citation
» Avoid Costly Rails Logging | Jake Swanson | Sciencx | https://www.scien.cx/2021/04/09/avoid-costly-rails-logging/ |

Please log in to upload a file.



There are no updates yet.
Click the Upload button above to add an update.

You must be logged in to translate posts. Please log in or register.

Related Posts