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鈥檒l occasionally send you account related emails.

Already on GitHub? Sign in to your account

Make it faster馃殌 #24

Merged
merged 4 commits into from Jun 20, 2020
Merged

Make it faster馃殌 #24

merged 4 commits into from Jun 20, 2020

Conversation

pocke
Copy link
Contributor

@pocke pocke commented Jun 20, 2020

This pull request improves performance.

I've confirmed it was about 6x faster in a micro benchmark and a real rails application.

Benchmark scripts

Micro benchmark

$LOAD_PATH << './lib'

require 'benchmark'
require 'trace_location'

def noop
end

def heavy
  100000.times {noop}
end

Benchmark.bmbm do |x|
  x.report{1.times{TraceLocation.trace{heavy}}}
end

With rails application

# Execute it with rails runner

require 'benchmark'
require 'trace_location'

User.first # because the first execution is really slow

Benchmark.bmbm do |x|
  x.report{1.times{TraceLocation.trace{User.first}}}
end

Benchmark results

Micro benchmark

first - 3462bd7

Rehearsal ------------------------------------
 Created at /home/pocke/ghq/github.com/yhirano55/trace_location/trace_location-2020062014061592631234.md
 13.271392   0.083000  13.354392 ( 13.374203)
-------------------------- total: 13.354392sec

       user     system      total        real
 Created at /home/pocke/ghq/github.com/yhirano55/trace_location/trace_location-2020062014061592631249.md
 14.247306   0.053228  14.300534 ( 14.321461)

Do not use binding_of_caller - 7cf5769

Rehearsal ------------------------------------
 Created at /home/pocke/ghq/github.com/yhirano55/trace_location/trace_location-2020062014061592632386.md
  9.050748   0.062487   9.113235 (  9.126239)
--------------------------- total: 9.113235sec

       user     system      total        real
 Created at /home/pocke/ghq/github.com/yhirano55/trace_location/trace_location-2020062014061592632395.md
  9.554962   0.046541   9.601503 (  9.615075)

Simplify remove_indent - febf7b0

Rehearsal ------------------------------------
 Created at /home/pocke/ghq/github.com/yhirano55/trace_location/trace_location-2020062015061592633000.md
  8.375018   0.087021   8.462039 (  8.473832)
--------------------------- total: 8.462039sec

       user     system      total        real
 Created at /home/pocke/ghq/github.com/yhirano55/trace_location/trace_location-2020062015061592633009.md
  8.795492   0.033288   8.828780 (  8.841047)

Cache method source - 900202c

Rehearsal ------------------------------------
 Created at /home/pocke/ghq/github.com/yhirano55/trace_location/trace_location-2020062015061592634643.md
  2.478327   0.013296   2.491623 (  2.494657)
--------------------------- total: 2.491623sec

       user     system      total        real
 Created at /home/pocke/ghq/github.com/yhirano55/trace_location/trace_location-2020062015061592634646.md
  2.325903   0.016581   2.342484 (  2.345369)

With rails application

I only execute the benchmark with the base commit and the latest commit for Rails app.

first - 3462bd7

Rehearsal ------------------------------------
 Created at /home/pocke/ghq/github.com/bitjourney/kibela/log/trace_location-2020062015061592635193.md
  2.301371   0.023957   2.325328 (  2.329522)
--------------------------- total: 2.325328sec

       user     system      total        real
 Created at /home/pocke/ghq/github.com/bitjourney/kibela/log/trace_location-2020062015061592635195.md
  2.426445   0.000323   2.426768 (  2.430787)

Cache method source - 900202c

Rehearsal ------------------------------------
 Created at /home/pocke/ghq/github.com/bitjourney/kibela/log/trace_location-2020062015061592635466.md
  0.575040   0.016643   0.591683 (  0.593343)
--------------------------- total: 0.591683sec

       user     system      total        real
 Created at /home/pocke/ghq/github.com/bitjourney/kibela/log/trace_location-2020062015061592635467.md
  0.363144   0.000371   0.363515 (  0.364667)

Note

This pull request contains #23 commit to avoid conflicting.


tracer = TracePoint.new(:call, :return) do |trace_point|
next if match && !trace_point.path.to_s.match?(/#{Array(match).join('|')}/)
next if ignore && trace_point.path.to_s.match?(/#{Array(ignore).join('|')}/)

id += 1
caller_path, caller_lineno = trace_point.binding.of_caller(2).source_location
caller_loc = caller_locations(2, 1)[0]
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We can use caller_locations instead of binding.of_caller. It is faster, and no dependency.

location_cache_key = "#{caller_path}:#{caller_lineno}"

mes = extract_method_from(trace_point)
next if mes.source_location[0] == '<internal:prelude>'

method_source = method_source_cache[mes] ||= remove_indent(mes.source)
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

UnboundMethod#source is really heavy. So caching them improves performance dramatically.

Copy link
Owner

@yhirano55 yhirano55 left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Pretty awesome!!

@yhirano55 yhirano55 merged commit 524ef19 into yhirano55:master Jun 20, 2020
@pocke pocke deleted the speedup馃殌 branch June 20, 2020 13:18
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

Successfully merging this pull request may close these issues.

None yet

2 participants