Comments (6)
mfpiccolo
commented on July 23, 2024
1
Thanks for this gem. Seems really useful but I am having trouble understanding the output. If you could explain what the numbers in each column mean I would be really appreciative. For instance, looking at the total column Typhoeus::Multi#perform looks troubling at 84% but from the sample it shows 1.2%.
What is the difference between these two columns?
Why when added up do both of these columns percentages not add up to 100%?
I would assume that each percentage means that that is the percentage of total time spent in each method but again they do not add up to 100% which is confusing.
From the output below is URI::Parser#split taking up most of my processing time or is it Typhoeus::Multi#perform?
Thanks again.
Mode: cpu(1000)
Samples: 1553862 (13.23% miss rate)
GC: 216647 (13.94%)
TOTAL (pct) SAMPLES (pct) FRAME
464487 (29.9%) 443080 (28.5%) URI::Parser#split
135216 (8.7%) 74826 (4.8%) ActiveSupport::JSON::Encoding::JSONGemEncoder#jsonify
56034 (3.6%) 52826 (3.4%) block in Hash#as_json
50484 (3.2%) 50484 (3.2%) JSON#generate
114400 (7.4%) 48009 (3.1%) Nokogiri::HTML::Document.parse
47735 (3.1%) 47735 (3.1%) block in ActiveRecord::ConnectionAdapters::PostgreSQLAdapter::DatabaseStatements#execute
110816 (7.1%) 47302 (3.0%) block in ActiveSupport::HashWithIndifferentAccess#update
46066 (3.0%) 46066 (3.0%) ContentInfo#parse_metadata
33442 (2.2%) 33398 (2.1%) ActiveRecord::Timestamp#current_time_from_proper_timezone
28415 (1.8%) 28415 (1.8%) block in Logger::LogDevice#write
83654 (5.4%) 25382 (1.6%) ContentInfo#minus_stop_words
77095 (5.0%) 21061 (1.4%) Hash#as_json
20939 (1.3%) 20939 (1.3%) Nokogiri::XML::Document#initialize
20699 (1.3%) 20699 (1.3%) JSON#parse
132746 (8.5%) 20456 (1.3%) ActiveSupport::HashWithIndifferentAccess#convert_value
19678 (1.3%) 19653 (1.3%) block in ActiveRecord::ConnectionAdapters::PostgreSQLAdapter#exec_cache
19490 (1.3%) 19490 (1.3%) Nokogiri::HTML::Document::EncodingReader::SAXHandler#start_element
1311353 (84.4%) 18480 (1.2%) Typhoeus::Multi#perform
57584 (3.7%) 15502 (1.0%) ActiveModel::Dirty#attribute_will_change!
15117 (1.0%) 15117 (1.0%) block in BetterErrors::ExceptionExtension#set_backtrace
12568 (0.8%) 12568 (0.8%) ActiveRecord::ConnectionAdapters::TransactionState#finalized?
12206 (0.8%) 12206 (0.8%) block in ContentInfo#minus_stop_words
181326 (11.7%) 12023 (0.8%) Category#add_word_frequencies
18489 (1.2%) 11621 (0.7%) block (2 levels) in Class#class_attribute
122361 (7.9%) 11545 (0.7%) ActiveSupport::HashWithIndifferentAccess#update
18041 (1.2%) 10766 (0.7%) block (2 levels) in BindingOfCaller::BindingExtensions#callers
10731 (0.7%) 10731 (0.7%) ActiveSupport::HashWithIndifferentAccess#convert_key
24608 (1.6%) 9022 (0.6%) Addressable::URI.parse
14399 (0.9%) 8513 (0.5%) URI::Generic#initialize
8325 (0.5%) 8325 (0.5%) Nokogiri::XML::SAX::Document#characters
from stackprof.
tmm1
commented on July 23, 2024
This is possible when a frame is in the stack more than once, i.e. recursion.
from stackprof.
pushrax
commented on July 23, 2024
It would make sense to deduplicate these entries to avoid inflating stats.
from stackprof.
thejspr
commented on July 23, 2024
I'd be very interested in a brief explanation of the results as well (using the text formatter). Thank you for the awesome tool @tmm1
from stackprof.
Karlotcha
commented on July 23, 2024
First, thanks for the tool @tmm1 , it is great! :)
About this issue, I don't think it is only a question of recursion. Maybe I just don't understand it, but with this basic example:
def m2
i = 1
(1..100000).each { |n| i *= n }
end
profile = StackProf.run(mode: :cpu, out: 'stackprof-cpu-myapp.dump', raw: true, interval: 1000) do
m2
end
I end up with:
==================================
Mode: cpu(1000)
Samples: 4362 (0.00% miss rate)
GC: 708 (16.23%)
==================================
TOTAL (pct) SAMPLES (pct) FRAME
7308 (167.5%) 3654 (83.8%) Object#m2
3654 (83.8%) 0 (0.0%) block in <main>
3654 (83.8%) 0 (0.0%) <main>
3654 (83.8%) 0 (0.0%) <main>
(using ruby 2.3.1p112 (2016-04-26 revision 54768) [x86_64-darwin14] on OS X Yosemite 10.10.5 )
Also please note that 7308 = 3654 * 2, not sure why I get that :/
from stackprof.
libc
commented on July 23, 2024
@Karlotcha I'm sure you forgot about this, but I'll reply here in case other people google for this (like I did today).
This happens because each block call adds a method to stacktrace.
For example,
2.3.3 :011 > def m2; -> { -> { puts Thread.current.backtrace }.call }.call; end
=> :m2
2.3.3 :012 > m2
(irb):11:in `backtrace'
(irb):11:in `block (2 levels) in m2'
(irb):11:in `block in m2'
(irb):11:in `m2'
(irb):12:in `irb_binding'
Note that m2 appears 3 times in the stack trace, so if I change your code to
def m2
i = 1
(1..100000).each { |n| -> { i *= n }.call }
end
profile = StackProf.run(mode: :cpu, out: 'stackprof-cpu-myapp.dump', raw: true, interval: 1000) do
m2
endI get 3 times the amount (5071 * 3 ~ 15211)
15211 (253.6%) 5071 (84.6%) Object#m2
And if I remove the block call:
def m2
i = 1
n = 1
while n < 100000
i *= n
n += 1
end
end
profile = StackProf.run(mode: :cpu, out: 'stackprof-cpu-myapp.dump', raw: true, interval: 1000) do
m2
endI get the correct number of samples.
4948 (85.3%) 4948 (85.3%) Object#m2
from stackprof.
Related Issues (20)
- Problem with Ruby 2.7.6 and version 0.2.20 HOT 6
- Error installing with Ruby 3.1 HOT 3
- Segmentation fault on Ruby 2.7.6p219 HOT 4
- Possibility to filter certain files or classes?
- flaky test failure with ruby3.1
- Test failures on 32bit arch
- Flamegraph way too short in `wall` mode HOT 5
- Support Gecko format? HOT 2
- Weird timestamp deltas with puma HOT 2
- bug: "missed_samples" integer overflow possible HOT 1
- bug: possible state leak of `buffer_count` state between stackprof invocations HOT 2
- C99 error while compiling v0.2.25 HOT 1
- Add marker metadata feature HOT 1
- stackprof fails to build native extensions on ubuntu 22.04 and ruby 3.2.2 HOT 1
- "lines" attribute format?
- bug: state of _stackprof.last_sample_at can leak between invocations
- 3.3.0-dev: Segfault in `rb_profile_frames` with N:M threads enabled HOT 3
- Add discussions tab, hide the projects tab
- ruby 3.2.2 An error occurred while installing stackprof (0.2.26), and Bundler cannot
- Test failure StackProfTest#test_raw Expected 0 to be > 0.
Recommend Projects
-
React
A declarative, efficient, and flexible JavaScript library for building user interfaces.
-
Vue.js
🖖 Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.
-
Typescript
TypeScript is a superset of JavaScript that compiles to clean JavaScript output.
-
TensorFlow
An Open Source Machine Learning Framework for Everyone
-
Django
The Web framework for perfectionists with deadlines.
-
Laravel
A PHP framework for web artisans
-
D3
Bring data to life with SVG, Canvas and HTML. 📊📈🎉
-
Recommend Topics
-
javascript
JavaScript (JS) is a lightweight interpreted programming language with first-class functions.
-
web
Some thing interesting about web. New door for the world.
-
server
A server is a program made to process requests and deliver data to clients.
-
Machine learning
Machine learning is a way of modeling and interpreting data that allows a piece of software to respond intelligently.
-
Visualization
Some thing interesting about visualization, use data art
-
Game
Some thing interesting about game, make everyone happy.
Recommend Org
-
Facebook
We are working to build community through open source technology. NB: members must have two-factor auth.
-
Microsoft
Open source projects and samples from Microsoft.
-
Google
Google ❤️ Open Source for everyone.
-
Alibaba
Alibaba Open Source for everyone
-
D3
Data-Driven Documents codes.
-
Tencent
China tencent open source team.
from stackprof.