1
0
Fork 0
mirror of https://github.com/rails/rails.git synced 2022-11-09 12:12:34 -05:00
rails--rails/actionpack/lib/action_controller/log_subscriber.rb
schneems 5bb1d4d288 Freeze string literals when not mutated.
I wrote a utility that helps find areas where you could optimize your program using a frozen string instead of a string literal, it's called [let_it_go](https://github.com/schneems/let_it_go). After going through the output and adding `.freeze` I was able to eliminate the creation of 1,114 string objects on EVERY request to [codetriage](codetriage.com). How does this impact execution?

To look at memory:

```ruby
require 'get_process_mem'

mem = GetProcessMem.new
GC.start
GC.disable
1_114.times { " " }
before = mem.mb

after = mem.mb
GC.enable
puts "Diff: #{after - before} mb"

```

Creating 1,114 string objects results in `Diff: 0.03125 mb` of RAM allocated on every request. Or 1mb every 32 requests.

To look at raw speed:

```ruby
require 'benchmark/ips'

number_of_objects_reduced = 1_114

Benchmark.ips do |x|
  x.report("freeze")    { number_of_objects_reduced.times { " ".freeze } }
  x.report("no-freeze") { number_of_objects_reduced.times { " " } }
end
```

We get the results

```
Calculating -------------------------------------
              freeze     1.428k i/100ms
           no-freeze   609.000  i/100ms
-------------------------------------------------
              freeze     14.363k (± 8.5%) i/s -     71.400k
           no-freeze      6.084k (± 8.1%) i/s -     30.450k
```

Now we can do some maths:

```ruby
ips = 6_226k # iterations / 1 second
call_time_before = 1.0 / ips # seconds per iteration 

ips = 15_254 # iterations / 1 second
call_time_after = 1.0 / ips # seconds per iteration 

diff = call_time_before - call_time_after

number_of_objects_reduced * diff * 100

# => 0.4530373333993266 miliseconds saved per request
```

So we're shaving off 1 second of execution time for every 220 requests. 

Is this going to be an insane speed boost to any Rails app: nope. Should we merge it: yep. 

p.s. If you know of a method call that doesn't modify a string input such as [String#gsub](b0e2da69f0/lib/let_it_go/core_ext/string.rb (L37)) please [give me a pull request to the appropriate file](b0e2da69f0/lib/let_it_go/core_ext/string.rb (L37)), or open an issue in LetItGo so we can track and freeze more strings. 

Keep those strings Frozen

![](https://www.dropbox.com/s/z4dj9fdsv213r4v/let-it-go.gif?dl=1)
2015-07-19 17:45:10 -05:00

74 lines
2.4 KiB
Ruby

module ActionController
class LogSubscriber < ActiveSupport::LogSubscriber
INTERNAL_PARAMS = %w(controller action format _method only_path)
def start_processing(event)
return unless logger.info?
payload = event.payload
params = payload[:params].except(*INTERNAL_PARAMS)
format = payload[:format]
format = format.to_s.upcase if format.is_a?(Symbol)
info "Processing by #{payload[:controller]}##{payload[:action]} as #{format}"
info " Parameters: #{params.inspect}" unless params.empty?
end
def process_action(event)
info do
payload = event.payload
additions = ActionController::Base.log_process_action(payload)
status = payload[:status]
if status.nil? && payload[:exception].present?
exception_class_name = payload[:exception].first
status = ActionDispatch::ExceptionWrapper.status_code_for_exception(exception_class_name)
end
message = "Completed #{status} #{Rack::Utils::HTTP_STATUS_CODES[status]} in #{event.duration.round}ms"
message << " (#{additions.join(" | ".freeze)})" unless additions.blank?
message
end
end
def halted_callback(event)
info { "Filter chain halted as #{event.payload[:filter].inspect} rendered or redirected" }
end
def send_file(event)
info { "Sent file #{event.payload[:path]} (#{event.duration.round(1)}ms)" }
end
def redirect_to(event)
info { "Redirected to #{event.payload[:location]}" }
end
def send_data(event)
info { "Sent data #{event.payload[:filename]} (#{event.duration.round(1)}ms)" }
end
def unpermitted_parameters(event)
debug do
unpermitted_keys = event.payload[:keys]
"Unpermitted parameter#{'s' if unpermitted_keys.size > 1}: #{unpermitted_keys.join(", ")}"
end
end
%w(write_fragment read_fragment exist_fragment?
expire_fragment expire_page write_page).each do |method|
class_eval <<-METHOD, __FILE__, __LINE__ + 1
def #{method}(event)
return unless logger.info?
key_or_path = event.payload[:key] || event.payload[:path]
human_name = #{method.to_s.humanize.inspect}
info("\#{human_name} \#{key_or_path} (\#{event.duration.round(1)}ms)")
end
METHOD
end
def logger
ActionController::Base.logger
end
end
end
ActionController::LogSubscriber.attach_to :action_controller