rubocop / rubocop-rails

A RuboCop extension focused on enforcing Rails best practices and coding conventions.
https://docs.rubocop.org/rubocop-rails
MIT License
803 stars 259 forks source link

`Rails/EagerEvaluationLogMessage` should always report an offense when not passed a block #1355

Open Uaitt opened 1 week ago

Uaitt commented 1 week ago

Is your feature request related to a problem? Please describe.

Currently, the Rails/EagerEvaluationLogMessage cop, when enabled manually, will only report offenses when Rails.logger.debug receives as argument an interpolated string directly.

Look at this, for example:

def method_a
  Struct.new
end

def method_b
  "Hello from method b #{method_a}"
end

# Case A: no offense
Rails.logger.debug "some_string"

# Case B: offense
Rails.logger.debug "Hello from method b #{method_a}"

# Case C: no offense
Rails.logger.debug method_b

Now, this cop was created because when the Rails.logger.debug method receives a string as first argument, Ruby will always allocate that string in memory even if the log level for the current Rails environment is :info or above (and thus Rails.logger.debug doesn't actually debug anything).

In the example above, case B is correctly flagged since it results in an unneeded allocation of an interpolated string. Case A and C however are still allocation unnecessary objects (assuming that the Rails log_level is :info or above, of course) but are not flagged by the cop.

Describe the solution you'd like

I think that the Rails/EagerEvaluationLogMessage cop should always report an offense when Rails.logger.debug isn't passed a block.

Earlopain commented 1 week ago

There is really no reason to restrict passing a plain literal. With frozen string literals this is not a problem and passing a block is in fact slower:

# frozen_string_literal: true

require "bundler/inline"

gemfile(true) do
  source "https://rubygems.org"

  gem "rails"
  gem "benchmark-ips"
end

require "minitest/autorun"
require "active_model"

def bar
  "bar"
end

Rails.logger = Logger.new(STDOUT)
Rails.logger.level = :info
Benchmark.ips do |x|
  x.report("literal") do
    Rails.logger.debug "some_string" 
  end

  x.report("literal_block") do
    Rails.logger.debug { "some_string" }
  end

  x.report("interpolated") do
    Rails.logger.debug "some_string#{bar}" 
  end

  x.report("interpolated_block") do
    Rails.logger.debug { "some_string#{bar}" }
  end

  x.report("method_call") do
    Rails.logger.debug bar
  end

  x.report("method_call_block") do
    Rails.logger.debug { bar }
  end
end
ruby 3.3.5 (2024-09-03 revision ef084cc8f4) [x86_64-linux]
Warming up --------------------------------------
             literal   644.086k i/100ms
       literal_block   621.929k i/100ms
        interpolated   446.440k i/100ms
  interpolated_block   626.215k i/100ms
         method_call   597.401k i/100ms
   method_call_block   629.532k i/100ms
Calculating -------------------------------------
             literal      6.502M (± 1.5%) i/s -     32.848M in   5.053204s
       literal_block      6.278M (± 0.2%) i/s -     31.718M in   5.052057s
        interpolated      4.454M (± 1.8%) i/s -     22.322M in   5.013773s
  interpolated_block      6.264M (± 0.4%) i/s -     31.937M in   5.098311s
         method_call      5.951M (± 0.6%) i/s -     29.870M in   5.019610s
   method_call_block      6.259M (± 0.3%) i/s -     31.477M in   5.029347s

For the method, I guess it could register an offense there. I find it highly unlikely that it would just return a frozen string and as such will likely be more performant.

Uaitt commented 1 week ago

@Earlopain I have tried to benchmark the behaviour of Rails.logger.debug with a variable:

# frozen_string_literal: true

require "bundler/inline"

gemfile(true) do
  source "https://rubygems.org"

  gem "rails"
  gem "benchmark-ips"
end

require "minitest/autorun"
require "active_model"

var = "var"

Rails.logger = Logger.new(STDOUT)
Rails.logger.level = :info
Benchmark.ips do |x|
  x.report("variabile") do
    Rails.logger.debug var
  end

  x.report("variable_block") do
    Rails.logger.debug { var }
  end
end
ruby 3.3.5 (2024-09-03 revision ef084cc8f4) [arm64-darwin23]
Warming up --------------------------------------
           variabile   530.948k i/100ms
      variable_block   519.175k i/100ms
Calculating -------------------------------------
           variabile      5.306M (± 0.3%) i/s  (188.48 ns/i) -     26.547M in   5.003673s
      variable_block      5.040M (± 3.5%) i/s  (198.41 ns/i) -     25.440M in   5.054491s

It seems that when dealing with variables it's also faster to pass the positional argument instead of a block 🤔.

So I guess this is becoming a little bit too much to handle? I don't think Rubocop can discern wether the argument passed to Rails.logger.debug is a variable or a method call, right?

Earlopain commented 6 days ago

It can distinguish between local variables and other things