Comments (4)
Sounds like it might be I/O bound, not cpu. Try real time mode instead.
On Sun, Feb 21, 2016 at 12:45 PM Gavin Kistner [email protected]
wrote:
require 'ruby-mod'require 'stackprof'@mpd = MPD.new.tap(&:connect)@mpd.clear
songs = @mpd.songs[0...100]
t1 = Time.now
profile = StackProf.run(mode: :cpu, interval:5){ songs.each{ |song| @mpd.add(song) } }
t2 = Time.now
p songs.length #=> 100
p t2-t1 #=> 5.21096228
p profile #=> {:version=>1.1, :mode=>:cpu, :interval=>5, :samples=>0, :gc_samples=>0, :missed_samples=>0, :frames=>{}}
puts RUBY_DESCRIPTION #=> "ruby 2.1.5p273 (2014-11-13) [x86_64-linux-gnu]"Why am I not getting any samples? My internal t2-t1 profiling without
stackprof shows that it takes about 40ms for each call to @mpd.add(song),
and I know that about 3-4 pure Ruby methods are called as part of each call.Am I doing something wrong?
—
Reply to this email directly or view it on GitHub
#63.
from stackprof.
@tmm1 Thank you for the fast response! Yes, using mode: :wall
got me values. I'm not sure which to believe, as I see such different results for runs with different intervals.
Note that (as described in this comment) my ad-hoc profiling by wrapping the major methods with t1=Time.now; ...; record Time.now-t1
showed that handle_server_response
is about 99.8% of the call time.
Any opinion on why the results of this differ so greatly from my ad-hoc profiling?
==================================
Mode: wall(1000)
Samples: 131 (97.13% miss rate)
GC: 1 (0.76%)
==================================
TOTAL (pct) SAMPLES (pct) FRAME
107 (81.7%) 107 (81.7%) MPD#handle_server_response
12 (9.2%) 12 (9.2%) MPD::Parser#quotable_param
127 (96.9%) 3 (2.3%) block in MPD#send_command
15 (11.5%) 3 (2.3%) block in MPD::Parser#convert_command
2 (1.5%) 2 (1.5%) MPD#socket
16 (12.2%) 1 (0.8%) MPD::Parser#convert_command
130 (99.2%) 1 (0.8%) MPD::Plugins::Queue#add
1 (0.8%) 1 (0.8%) Set#include?
130 (99.2%) 0 (0.0%) block in RubyLex#each_top_level_statement
130 (99.2%) 0 (0.0%) block (2 levels) in IRB::Irb#eval_input
==================================
Mode: wall(500)
Samples: 120 (98.68% miss rate)
GC: 0 (0.00%)
==================================
TOTAL (pct) SAMPLES (pct) FRAME
108 (90.0%) 108 (90.0%) MPD#handle_server_response
6 (5.0%) 6 (5.0%) MPD::Parser#quotable_param
120 (100.0%) 2 (1.7%) block in MPD#send_command
8 (6.7%) 2 (1.7%) MPD::Parser#convert_command
1 (0.8%) 1 (0.8%) MPD#socket
1 (0.8%) 1 (0.8%) MPD::Parser#parse_response
120 (100.0%) 0 (0.0%) Object#irb_binding
120 (100.0%) 0 (0.0%) IRB::WorkSpace#evaluate
120 (100.0%) 0 (0.0%) IRB::Context#evaluate
120 (100.0%) 0 (0.0%) block (2 levels) in IRB::Irb#eval_input
==================================
Mode: wall(100)
Samples: 193 (99.58% miss rate)
GC: 1 (0.52%)
==================================
TOTAL (pct) SAMPLES (pct) FRAME
113 (58.5%) 113 (58.5%) MPD#handle_server_response
37 (19.2%) 37 (19.2%) MPD::Parser#quotable_param
54 (28.0%) 12 (6.2%) MPD::Parser#convert_command
185 (95.9%) 12 (6.2%) block in MPD#send_command
42 (21.8%) 5 (2.6%) block in MPD::Parser#convert_command
5 (2.6%) 5 (2.6%) MPD#socket
192 (99.5%) 4 (2.1%) MPD::Plugins::Queue#add
2 (1.0%) 2 (1.0%) Set#include?
4 (2.1%) 2 (1.0%) MPD::Parser#parse_response
192 (99.5%) 0 (0.0%) #<Module:0x000000021b7298>.start
==================================
Mode: wall(50)
Samples: 306 (99.66% miss rate)
GC: 4 (1.31%)
==================================
TOTAL (pct) SAMPLES (pct) FRAME
128 (41.8%) 125 (40.8%) MPD#handle_server_response
72 (23.5%) 72 (23.5%) MPD::Parser#quotable_param
287 (93.8%) 46 (15.0%) block in MPD#send_command
103 (33.7%) 19 (6.2%) MPD::Parser#convert_command
19 (6.2%) 19 (6.2%) MPD#socket
84 (27.5%) 12 (3.9%) block in MPD::Parser#convert_command
3 (1.0%) 3 (1.0%) Set#include?
6 (2.0%) 3 (1.0%) MPD::Parser#parse_response
302 (98.7%) 3 (1.0%) MPD::Plugins::Queue#add
302 (98.7%) 0 (0.0%) block in RubyLex#each_top_level_statement
==================================
Mode: wall(5)
Samples: 28041 (97.16% miss rate)
GC: 59 (0.21%)
==================================
TOTAL (pct) SAMPLES (pct) FRAME
9020 (32.2%) 9020 (32.2%) MPD#socket
8348 (29.8%) 8271 (29.5%) MPD#handle_server_response
3354 (12.0%) 3354 (12.0%) MPD::Parser#quotable_param
2329 (8.3%) 2329 (8.3%) Set#include?
4984 (17.8%) 1630 (5.8%) block in MPD::Parser#convert_command
1453 (5.2%) 1453 (5.2%) MPD#connected?
3089 (11.0%) 760 (2.7%) MPD::Parser#parse_response
21574 (76.9%) 472 (1.7%) block in MPD#send_command
5387 (19.2%) 403 (1.4%) MPD::Parser#convert_command
27975 (99.8%) 120 (0.4%) MPD::Plugins::Queue#add
from stackprof.
The miss rate is really high which suggests something is blocking the ruby
process and preventing samples from being recorded.
On Sun, Feb 21, 2016 at 1:45 PM Gavin Kistner [email protected]
wrote:
—
Reply to this email directly or view it on GitHub
#63 (comment).
from stackprof.
The method taking up most of the time (in my hand-profiling) is, at it's core:
def handle_server_response
msg = ''
while true
case line = socket.gets
when "OK\n", nil
break
when /^ACK/
error = line
break
else
msg << line
end
end
end
So there's likely a large amount of time blocking, waiting for the socket to return. Thanks for commenting on the miss rate, I didn't see any documentation on what that meant, or how to interpret 97% (as bad or good).
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. HOT 1
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.