File: README.rdoc

package info (click to toggle)
ruby-prof 0.17.0+dfsg-3
  • links: PTS, VCS
  • area: main
  • in suites: buster, sid
  • size: 1,656 kB
  • sloc: ruby: 5,043; ansic: 2,175; makefile: 6
file content (485 lines) | stat: -rw-r--r-- 17,132 bytes parent folder | download | duplicates (2)
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
277
278
279
280
281
282
283
284
285
286
287
288
289
290
291
292
293
294
295
296
297
298
299
300
301
302
303
304
305
306
307
308
309
310
311
312
313
314
315
316
317
318
319
320
321
322
323
324
325
326
327
328
329
330
331
332
333
334
335
336
337
338
339
340
341
342
343
344
345
346
347
348
349
350
351
352
353
354
355
356
357
358
359
360
361
362
363
364
365
366
367
368
369
370
371
372
373
374
375
376
377
378
379
380
381
382
383
384
385
386
387
388
389
390
391
392
393
394
395
396
397
398
399
400
401
402
403
404
405
406
407
408
409
410
411
412
413
414
415
416
417
418
419
420
421
422
423
424
425
426
427
428
429
430
431
432
433
434
435
436
437
438
439
440
441
442
443
444
445
446
447
448
449
450
451
452
453
454
455
456
457
458
459
460
461
462
463
464
465
466
467
468
469
470
471
472
473
474
475
476
477
478
479
480
481
482
483
484
485
= ruby-prof

{<img src="https://travis-ci.org/ruby-prof/ruby-prof.png?branch=master" alt="Build Status" />}[https://travis-ci.org/ruby-prof/ruby-prof]

== Overview

ruby-prof is a fast code profiler for MRI Ruby.  Its features include:

* Speed - it is a C extension and therefore many times faster than the standard Ruby profiler.
* Modes - Ruby prof can measure a number of different parameters, including call times, memory usage and object allocations.
* Reports - can generate text and cross-referenced html reports
  - Flat Profiles - similar to the reports generated by the standard Ruby profiler
  - Graph profiles - similar to GProf, these show how long a method runs, which methods call it and which methods it calls.
  - Call tree profiles - outputs results in the calltree format suitable for the KCacheGrind profiling tool.
  - Many more -- see reports section of this \README.
* Threads - supports profiling multiple threads simultaneously

== Requirements

ruby-prof requires Ruby 1.9.3 or higher. Please note some ruby
releases have known bugs which cause ruby-prof problems, like
incorrect measurements. We suggest to use the latest minor patch level
release if possible. In particular, on the 2.1 branch of ruby you
should use at least 2.1.7.

If you are running Linux or Unix you'll need a C compiler so the
extension can be compiled when it is installed.

If you are running Windows, then you may need to install the
Windows specific RubyGem which includes an already built extension (see Install section).

== Install

The easiest way to install ruby-prof is by using Ruby Gems.  To
install:

    gem install ruby-prof

If you're on windows then please install the devkit first so that it
can compile.

== Usage

There are three major options for running ruby-prof: via the command
line, via its convenience API or via its core API.

=== ruby-prof Executable

The first is to use ruby-prof to run the Ruby program you want to
profile.  For more information refer to the documentation of the
ruby-prof command: `$ ruby-prof -h.`


=== ruby-prof Convenience API

The second way is to use the ruby-prof convenience API to profile
particular segments of code.

    require 'ruby-prof'

    # profile the code
    RubyProf.start
    # ... code to profile ...
    result = RubyProf.stop

    # print a flat profile to text
    printer = RubyProf::FlatPrinter.new(result)
    printer.print(STDOUT)

Alternatively, you can use a block to tell ruby-prof what to profile:

    require 'ruby-prof'

    # profile the code
    result = RubyProf.profile do
      # ... code to profile ...
    end

    # print a graph profile to text
    printer = RubyProf::GraphPrinter.new(result)
    printer.print(STDOUT, {})

ruby-prof also supports pausing and resuming profiling runs.

    require 'ruby-prof'

    # profile the code
    RubyProf.start
    # ... code to profile ...

    RubyProf.pause
    # ... other code ...

    RubyProf.resume
    # ... code to profile ...
    result = RubyProf.stop

Note that resume will only work if start has been called previously.
In addition, resume can also take a block:

    require 'ruby-prof'

    RubyProf.resume do
      # ... code to profile...
    end

    result = RubyProf.stop

With this usage, resume will automatically call pause at the
end of the block.

=== Profiling Selected Threads (Core API)

The convenience API does not support running multiple profiles in
separate threads concurrently, but the RubyProf::Profile API does. In
fact, the convenience layer uses the Profile API internally. It all
revolves around Profile objects:

RubyProf::Profile.new::
   Create a profile object given an options hash (see below)

   The following options are available when creating Profile instances:

   measure_mode::
       One of the defined measure modes

   exclude_threads::
       Array of threads which should not be profiled.

   include_threads::
       Array of threads which should be profiled. All other threads will
       be ignored.

   merge_fibers::
       Whether profiling data for a given thread's fibers should all be
       subsumed under a single entry. Basically only useful to produce
       callgrind profiles.

RubyProf::Profile#start::
   Start profiling

RubyProf::Profile#pause::
   Pause profiling

RubyProf::Profile#resume::
   Resume profiling

RubyProf::Profile#stop::
   Stop profiling and return self

RubyProf::Profile#profile::
   Perform a profile run and return result. Accepts the same arguments
   as RubyProf::Profile.new.


== Method Elimination (Deprecated)

ruby-prof supports eliminating specific methods and threads from
profiling results. This is useful for reducing connectivity in the
call graph, making it easier to identify the source of performance
problems when using a graph printer.

For example, consider <tt>Integer#times</tt>: it's hardly ever useful
to know how much time is spent in the method itself. We're much more
interested in how much the passed in block contributes to the time
spent in the method which contains the <tt>Integer#times</tt> call.

Methods are eliminated from the collected data by calling
<tt>eliminate_methods!</tt> on the profiling result, before submitting
it to a printer.

    result = RubyProf.stop
    result.eliminate_methods!([/Integer#times/])

The argument given to <tt>eliminate_methods!</tt> is either an array
of regular expressions, or the name of a file containing a list of
regular expressions (line separated text).

After eliminating methods the resulting profile will appear exactly as if those methods
had been inlined at their call sites.


== Method Exclusion

ruby-prof supports exluding methods from profiling. The effect on
collected metrics are identical to eliminating methods from the
profiling result in a prost process step. The interface is slightly
different though:

    profile = RubyProf.new(...)
    profile.exclude_methods!(Integer, :times, ...)
    profile.start

A convenience method is provided to exclude a large number of methods
which usually clutter up profiles:

    profile.exclude_common_methods!

However, this is a somewhat opinionated method collection. It's
usually better to view it as an inspiration instead of using it
directly (see https://github.com/ruby-prof/ruby-prof/blob/e087b7d7ca11eecf1717d95a5c5fea1e36ea3136/lib/ruby-prof/profile/exclude_common_methods.rb).


== Profiling Rails

To profile a Rails application it is vital to run it using production like
settings (cache classes, cache view lookups, etc.).  Otherwise, Rail's
dependency loading code will overwhelm any time spent in the application
itself (our tests show that Rails dependency loading causes a roughly 6x
slowdown).  The best way to do this is create a new Rails environment,
profile.rb.

So to profile Rails:

1. Create a new profile.rb environment. Make sure to turn on
   <tt>cache_classes</tt> and
   <tt>cache_template_loading</tt>. Otherwise your profiling results
   will be overwhelmed by the time Rails spends loading required
   files. You should likely turn off caching.

2. Add the ruby-prof to your gemfile:

    group :profile do
      gem 'ruby-prof'
    end

3. Add the ruby prof rack adapter to your middleware stack.  One way to
   do this is by adding the following code to <tt>config.ru</tt>:

    if Rails.env.profile?
      use Rack::RubyProf, :path => '/temp/profile'
    end

   The path is where you want profiling results to be stored.  By default the
   rack adapter will generate a html call graph report and flat text report.

4. Now make a request to your running server.  New profiling
   information will be generated for each request.  Note that each
   request will overwrite the profiling reports created by the
   previous request!

== Reports

ruby-prof can generate a number of different reports:

* Flat Reports
* Graph Reports
* HTML Graph Reports
* Call graphs
* Call stack reports
* More!

Flat profiles show the overall time spent in each method. They
are a good way of quickly identifying which methods take the most time.
An example of a flat profile and an explanation can be found in
{examples/flat.txt}[http://github.com/ruby-prof/ruby-prof/tree/master/examples/flat.txt].

There are several varieties of these - run <tt>ruby-prof --help</tt>

Graph profiles also show the overall time spent in each method. In
addition, they also show which methods call the current method and which
methods its calls.  Thus they are good for understanding how methods
gets called and provide insight into the flow of your program. An
example text graph profile is located at
{examples/graph.txt}[http://github.com/ruby-prof/ruby-prof/tree/master/examples/graph.txt].

HTML Graph profiles are the same as graph profiles, except output is
generated in hyper-linked HTML. Since graph profiles can be quite large,
the embedded links make it much easier to navigate the results. An
example html graph profile is located at
{examples/graph.html}[http://github.com/ruby-prof/ruby-prof/tree/master/examples/graph.html].

Call graphs output results in the calltree profile format which is used
by KCachegrind. Call graph support was generously donated by Carl
Shimer. More information about the format can be found at the
{KCachegrind}[http://kcachegrind.sourceforge.net/cgi-bin/show.cgi/KcacheGrindCalltreeFormat]
site.

Call stack reports produce a HTML visualization of the time spent in
each execution path of the profiled code. An example can be found at
{examples/stack.html}[http://github.com/ruby-prof/ruby-prof/tree/master/examples/stack.html].

Another good example: http://twitpic.com/28z94a

Finally, there's a so called MultiPrinter which can generate several
reports in one profiling run. See
{examples/multi.stack.html}[http://github.com/ruby-prof/ruby-prof/tree/master/examples/multi.stack.html].

There is also a graphviz .dot visualiser.

== Printers

Reports are created by printers.  Supported printers include:

RubyProf::FlatPrinter::
  Creates a flat report in text format

RubyProf::FlatPrinterWithLineNumbers::
  Same as above but more verbose

RubyProf::GraphPrinter::
  Creates a call graph report in text format

RubyProf::GraphHtmlPrinter::
  Creates a call graph report in HTML (separate files per thread)

RubyProf::DotPrinter::
  Creates a call graph report in GraphViz's DOT format which can be converted to an image

RubyProf::CallTreePrinter::
  Creates a call tree report compatible with KCachegrind

RubyProf::CallStackPrinter::
  Creates a HTML visualization of the Ruby stack

RubyProf::MultiPrinter::
  Uses the other printers to create several reports in one profiling run

Most printers are used in the following way:

    result = RubyProf.stop
    printer = RubyProf::GraphPrinter.new(result)
    printer.print(STDOUT, :min_percent => 2)


The first parameter is any writable IO object such as <tt>STDOUT</tt>
or a file.  The second parameter, specifies the minimum percentage a
method must take to be printed.  Percentages should be specified as
integers in the range 0 to 100.  For more information please see the
documentation for the different printers.

The other option is <tt>:print_file => true</tt> (default false),
which adds the filename to the output (GraphPrinter only).

<tt>MultiPrinter</tt> and <tt>CallTreePrinter</tt>differ from the
other printers in that they require a directory path and a profile
basename for the files they produce:

    printer = RubyProf::MultiPrinter.new(result)
    printer.print(:path => ".", :profile => "profile")

The values given in the example above are the defaults.

== Measurements

Depending on the mode and platform, ruby-prof can measure various
aspects of a Ruby program. Supported measurements include:

RubyProf::WALL_TIME::
  Wall time measures the real-world time
  elapsed between any two moments.  If there are other processes
  concurrently running on the system that use significant CPU or disk
  time during a profiling run then the reported results will be larger
  than expected.

RubyProf::PROCESS_TIME::
  Process time measures the time used by a process between any two moments.
  It is unaffected by other processes concurrently running
  on the system. Note that Windows does not support measuring process
  times.

RubyProf::CPU_TIME::
  CPU time uses the CPU clock counter to measure time.  The returned
  values are dependent on the correctly setting the CPU's frequency.
  This mode is only supported on Pentium or PowerPC platforms (linux only).

RubyProf::ALLOCATIONS::
  Object allocation reports show how many objects each method in
  a program allocates.  This support was added by Sylvain Joyeux
  and requires a patched Ruby interpreter. See below.


RubyProf::MEMORY::
  Memory usage reports show how much memory each method in a program
  uses.  This support was added by Alexander Dymo and requires a
  patched Ruby interpreter. See below.

RubyProf::GC_TIME::
  Garbage collection time reports how much time is spent in Ruby's
  garbage collector during a profiling session. This support was added
  by Jeremy Kemper and requires a patched Ruby interpreter. See below.

RubyProf::GC_RUNS::
 Garbage collection runs report how many times Ruby's garbage collector
 is invoked during a profiling session. This support was added by
 Jeremy Kemper and requires a patched Ruby interpreter. See below.

== Patching ruby

All of the patches to Ruby are included in the railsexpress patchsets
for rvm, see https://github.com/skaes/rvm-patchsets. You can also use
these patches manually with other ruby managers (ruby-install, 
ruby-build, etc.).

Note if you rebuild your ruby with patches you must uninstall and
reinstall the ruby-prof gem to take advantage of the new capabilities.

== Measure modes

To set the measurement:

    RubyProf.measure_mode = RubyProf::WALL_TIME
    RubyProf.measure_mode = RubyProf::PROCESS_TIME
    RubyProf.measure_mode = RubyProf::CPU_TIME
    RubyProf.measure_mode = RubyProf::ALLOCATIONS
    RubyProf.measure_mode = RubyProf::MEMORY
    RubyProf.measure_mode = RubyProf::GC_TIME
    RubyProf.measure_mode = RubyProf::GC_RUNS

The default value is <tt>RubyProf::WALL_TIME</tt>.

You may also specify the measure mode by using the
<tt>RUBY_PROF_MEASURE_MODE</tt> environment variable:

    export RUBY_PROF_MEASURE_MODE=wall
    export RUBY_PROF_MEASURE_MODE=process
    export RUBY_PROF_MEASURE_MODE=cpu
    export RUBY_PROF_MEASURE_MODE=allocations
    export RUBY_PROF_MEASURE_MODE=memory
    export RUBY_PROF_MEASURE_MODE=gc_time
    export RUBY_PROF_MEASURE_MODE=gc_runs

On Linux, process time is measured using the clock method provided
by the C runtime library. Note that the clock method does not
report time spent in the kernel or child processes and therefore
does not measure time spent in methods such as Kernel.sleep method.
If you need to measure these values, then use wall time.  Wall time
is measured using the gettimeofday kernel method.

If you set the clock mode to <tt>PROCESS_TIME</tt>, then timings are
read using the clock method provided by the C runtime library.  Note
though, these values are wall times on Windows and not process times
like on Linux.  Wall time is measured using the GetLocalTime API.

If you use wall time, the results will be affected by other
processes running on your computer, network delays, disk access,
etc.  As result, for the best results, try to make sure your
computer is only performing your profiling run and is
otherwise quiescent.

== Multi-threaded Applications

Unfortunately, Ruby does not provide an internal API for detecting
thread context switches.  As a result, the timings ruby-prof reports
for each thread may be slightly inaccurate.  In particular, this will
happen for newly spawned threads that go to sleep immediately (their
first call).  For instance, if you use Ruby's timeout library to wait
for 2 seconds, the 2 seconds will be assigned to the foreground thread
and not the newly created background thread.  These errors can largely
be avoided if the background thread performs any operation before
going to sleep.

== Performance

Significant effort has been put into reducing ruby-prof's overhead
as much as possible.  Our tests show that the overhead associated
with profiling code varies considerably with the code being
profiled.  Most programs will run approximately twice as slow
while highly recursive programs (like the fibonacci series test)
will run three times slower.

== Editing links

Use <tt>RUBY_PROF_EDITOR_URI</tt> environment variable to open source
code files in your favorite text editor. For example,
<tt>RUBY_PROF_EDITOR_URI=atm</tt> will produce links for Atom text
editor.

== License

See LICENSE for license information.

== API Documentation

The ruby-prof API documentation for the latest released gem version
can be found here: http://www.rubydoc.info/gems/ruby-prof/

The ruby-prof API documentation for the master branch is available
here: http://www.rubydoc.info/github/ruby-prof/ruby-prof/

== Development

Code is located at https://github.com/ruby-prof/ruby-prof

Google group/mailing list: http://groups.google.com/group/ruby-optimization or open a github issue.