Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Open
Uaitt opened this issue Sep 6, 2024 · 3 comments

Comments

@Uaitt
Copy link
Contributor

Uaitt commented Sep 6, 2024

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
Copy link
Contributor

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
Copy link
Contributor Author

Uaitt commented Sep 12, 2024

@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
Copy link
Contributor

It can distinguish between local variables and other things

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants