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

Replace <top> label by the required file path #140

Open
wants to merge 1 commit into
base: master
Choose a base branch
from

Conversation

casperisfine
Copy link
Contributor

For context I'm trying to profile rubygems loading, which mean lot's of the time is spent on the initial file evaluations, whihc appear as <top (required)>.

==================================
  Mode: wall(10)
  Samples: 2653 (58.21% miss rate)
  GC: 718 (27.06%)
==================================
     TOTAL    (pct)     SAMPLES    (pct)     FRAME
       416  (15.7%)         416  (15.7%)     (marking)
       715  (27.0%)         312  (11.8%)     Gem::Specification.load
       299  (11.3%)         299  (11.3%)     (sweeping)
       279  (10.5%)         279  (10.5%)     Gem.already_loaded?
       564  (21.3%)         106   (4.0%)     Gem.register_default_spec
        95   (3.6%)          80   (3.0%)     Gem::Specification#files
        72   (2.7%)          72   (2.7%)     Gem::BasicSpecification#internal_init
       129   (4.9%)          58   (2.2%)     <top (required)>
        53   (2.0%)          53   (2.0%)     RbConfig.expand
      1697  (64.0%)          52   (2.0%)     <top (required)>
        68   (2.6%)          49   (1.8%)     Gem::Requirement.parse
       183   (6.9%)          48   (1.8%)     <top (required)>
       112   (4.2%)          44   (1.7%)     Gem::Requirement#initialize
       220   (8.3%)          33   (1.2%)     <module:Gem>
       250   (9.4%)          32   (1.2%)     Kernel#require
        96   (3.6%)          30   (1.1%)     Gem::Specification#add_dependency_with_type
        28   (1.1%)          28   (1.1%)     Gem::Specification#date=
        26   (1.0%)          26   (1.0%)     Gem.suffix_regexp
        30   (1.1%)          24   (0.9%)     Gem::Version.correct?
        46   (1.7%)          24   (0.9%)     <class:Specification>
        66   (2.5%)          20   (0.8%)     Gem::Requirement.create
        20   (0.8%)          20   (0.8%)     Gem::Specification#summary=
        60   (2.3%)          18   (0.7%)     Gem::Version.new
        27   (1.0%)          16   (0.6%)     Gem::Util.glob_files_in_dir
        15   (0.6%)          15   (0.6%)     Gem::Specification#add_bindir
        15   (0.6%)          15   (0.6%)     Gem::Specification#authors=
        15   (0.6%)          15   (0.6%)     Gem::PathSupport#expand
        20   (0.8%)          14   (0.5%)     <top (required)>
        42   (1.6%)          13   (0.5%)     Gem::Version#initialize
        21   (0.8%)          13   (0.5%)     <top (required)>

This makes it very hard to see where time is spent as all required files use the same label.

The idea here is to basically do name.gsub('<top (required)>', file), but I'm open to other ways to replace that label.

cc @tenderlove

@casperisfine
Copy link
Contributor Author

Maybe <require:#{file}> to be somewhat consistent with <module:XXX> etc.

ext/stackprof/stackprof.c Outdated Show resolved Hide resolved
@@ -224,6 +225,17 @@ frame_lines_i(st_data_t key, st_data_t val, st_data_t arg)
return ST_CONTINUE;
}

static VALUE
coerce_frame_name(VALUE name, VALUE line) {
char *start_pointer = strstr(RSTRING_PTR(name), "<top (required)>\0");
Copy link
Owner

Choose a reason for hiding this comment

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

Wouldn't some sort of strncmp be better here? Does the string match exactly, or is it sometimes contained within?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

It either match exactly or is trailing:

  • <top (required)>
  • block in <top (required)>

ext/stackprof/stackprof.c Outdated Show resolved Hide resolved
@casperisfine
Copy link
Contributor Author

I resolved the comments.

@casperisfine
Copy link
Contributor Author

Here's what it looks like now:

==================================
  Mode: wall(10)
  Samples: 2602 (57.94% miss rate)
  GC: 669 (25.71%)
==================================
     TOTAL    (pct)     SAMPLES    (pct)     FRAME
       402  (15.4%)         402  (15.4%)     (marking)
       716  (27.5%)         314  (12.1%)     Gem::Specification.load
       277  (10.6%)         277  (10.6%)     Gem.already_loaded?
       265  (10.2%)         265  (10.2%)     (sweeping)
       583  (22.4%)         125   (4.8%)     Gem.register_default_spec
        91   (3.5%)          80   (3.1%)     Gem::Specification#files
        70   (2.7%)          70   (2.7%)     Gem::BasicSpecification#internal_init
      1726  (66.3%)          62   (2.4%)     /opt/rubies/2.8.0-dev/lib/ruby/2.8.0/rubygems.rb
       116   (4.5%)          55   (2.1%)     /opt/rubies/2.8.0-dev/lib/ruby/2.8.0/did_you_mean.rb
        55   (2.1%)          55   (2.1%)     RbConfig.expand
        70   (2.7%)          49   (1.9%)     Gem::Requirement.parse
       184   (7.1%)          48   (1.8%)     /opt/rubies/2.8.0-dev/lib/ruby/2.8.0/rubygems/specification.rb
       112   (4.3%)          42   (1.6%)     Gem::Requirement#initialize
       219   (8.4%)          32   (1.2%)     Kernel#require
        31   (1.2%)          31   (1.2%)     Gem::Specification#date=
        31   (1.2%)          30   (1.2%)     Gem.suffix_regexp
       216   (8.3%)          29   (1.1%)     <module:Gem>
        98   (3.8%)          25   (1.0%)     Gem::Specification#add_dependency_with_type
        51   (2.0%)          24   (0.9%)     <class:Specification>
        58   (2.2%)          18   (0.7%)     Gem::Version.new
        40   (1.5%)          18   (0.7%)     Gem::Version#initialize
        18   (0.7%)          18   (0.7%)     Gem::Specification#summary=
        57   (2.2%)          17   (0.7%)     Gem::Requirement.create
        22   (0.8%)          17   (0.7%)     Gem::Version.correct?
        26   (1.0%)          16   (0.6%)     Gem::Util.glob_files_in_dir
        58   (2.2%)          14   (0.5%)     Gem::Dependency#initialize
        27   (1.0%)          14   (0.5%)     /opt/rubies/2.8.0-dev/lib/ruby/2.8.0/rubygems/user_interaction.rb
        13   (0.5%)          13   (0.5%)     Gem::PathSupport#expand
        13   (0.5%)          13   (0.5%)     Gem::Version#prerelease?
        11   (0.4%)          11   (0.4%)     block in <module:Gem>

@casperisfine
Copy link
Contributor Author

I updated it again, for <require:/opt/rubies/2.8.0-dev/lib/ruby/2.8.0/did_you_mean/spell_checker.rb>.

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.

3 participants