42.78 190.93 190.93 15 12728.67 23647.33 Array#each
10.78 239.04 48.11 1404333 0.03 0.04 Hash#[]
7.04 270.48 31.44 2 15720.00 25575.00 Hash#each
5.66 295.73 25.25 483523 0.05 0.05 String#split
5.55 320.51 24.78 1311730 0.02 0.02 Array#size
3.64 336.76 16.25 1 16250.00 25710.00 Array#map
3.24 351.23 14.47 483524 0.03 0.03 Array#sort
3.12 365.14 13.91 437243 0.03 0.03 Fixnum#==
3.04 378.72 13.58 483526 0.03 0.03 Array#join
2.97 391.98 13.26 437244 0.03 0.03 Hash#default
2.59 403.53 11.55 437626 0.03 0.03 Hash#[]=
2.43 414.38 10.85 483568 0.02 0.02 Array#<<
2.29 424.59 10.21 1 10210.00 13430.00 Array#map!
1.94 433.23 8.64 437242 0.02 0.02 Fixnum#<=>
1.86 441.54 8.31 437244 0.02 0.02 Fixnum#>
0.72 444.76 3.22 483524 0.01 0.01 String#chomp
0.11 445.26 0.50 4 125.00 125.00 Hash#keys
0.11 445.73 0.47 1 470.00 470.00 Hash#values
0.06 446.00 0.27 1 270.00 270.00 IO#readlines
0.05 446.22 0.22 33257 0.01 0.01 Fixnum#+
Видно, что больше всего времени программа тратит в методе Array#each. Это понятно: ведь цикл выполняется для каждого слова и на каждой итерации делает довольно много. Среднее значение в данном случае сбивает с толку, поскольку почти все время уходит на первый вызов each, а остальные 14 (см. anagrams.each) выполняются очень быстро.
Мы также видим, что Hash#[] — дорогая операция (главным образом потому что часто выполняется); на 1.4 миллиона вызовов было потрачено почти 11 секунд.
Обратите внимание, что метод readlines оказался чуть ли не в самом конце списка. Эта программа тратит время не на ввод/вывод, а на вычисления. На чтение всего файла ушло всего-то четверть секунды.
Но этот пример не показывает, в чем истинная ценность профилирования. В программе нет ни методов, ни классов. На практике вы, скорее всего, увидите свои методы среди системных. И тогда будете точно знать, какие из ваших методов находятся в числе первых 20 «пожирателей времени».
Надо ясно понимать, что профилировщик Ruby (видно, по иронии судьбы) работает медленно. Он подключается к программе во многих местах и следит за ее выполнением на низком уровне (причем сам написан на чистом Ruby). Так что не удивляйтесь, если ваша программа в ходе сеанса профилирования будет работать на несколько порядков медленнее. В нашем примере она работала 7 минут 40 секунд (460 секунд), то есть в 25 раз медленнее обычного.
Помимо профилировщика, есть еще один низкоуровневый инструмент — стандартная библиотека benchmark, которая тоже полезна для измерения производительности.
Один из способов ее применения — вызвать метод Benchmark.measure и передать ему блок.
require 'benchmark'
file = '/usr/share/dict/words'
result = Benchmark.measure { File.readlines(file) }
puts result
# Выводится: 0.350000 0.070000 0.420000 ( 0.418825)
Этот метод выводит следующую информацию:
• время, затраченное процессором в режиме пользователя (в секундах);
• время, затраченное процессором в режиме ядра (в секундах);
• полное затраченное время — сумму вышеупомянутых величин;
• время работы программы (по часам).
Для сравнения производительности отдельных участков удобен метод Benchmark.bm. Передайте ему блок, а он сам передаст блоку объект формирования отчета. Если вызвать этот объект, передав ему метку и блок, то он выведет метку, а за ней временные характеристики блока. Пример:
require 'benchmark'
n = 200_000
s1 = ''
s2 = ''
s3 = ''
Benchmark.bm do |rep|
rep.report('str << ') { n.times { s1 << 'x' } }
rep.report('str.insert ') { n.times { s3.insert(-1,'x') } }
rep.report('str += ') { n.times { s2 += 'x' } }
end
Здесь мы сравниваем три способа добавить символ в конец строки, дающие один и тот же результат. Чтобы можно было получить более точные цифры, каждая операция выполняется 200000 раз. Вот что вышло:
user system total real
str << 0.180000 0.000000 0.180000 ( 0.174697)
str.insert 0.200000 0.000000 0.200000 ( 0.200479)
str += 15.250000 13.120000 28.370000 (28.375998)
Обратите внимание, что последний вариант на два порядка медленнее остальных. Почему? Какой урок можно извлечь отсюда?
Вы можете предположить, что оператор + почему-то работает медленно, но дело в другом. Это единственный из трех способов, который не работает с одним и тем же объектом, а каждый раз создает новый.
Стало быть, вывод такой: создание объекта — дорогая операция. Библиотека Benchmark может преподать много подобных уроков, но я все же рекомендую сначала заняться высокоуровневым профилированием.
16.7. Объекты печати
Метод inspect (и вызывающий его метод p) предназначен для вывода объектов в виде, понятном человеку. В этом смысле он является связующим звеном между тестированием и отладкой, поэтому рассмотрение его в этой главе оправданно.
Проблема в том, что результат, формируемый методом p, бывает трудно читать. Из-за этого и появилась библиотека pp, добавляющая одноименный метод. Рассмотрим следующий искусственный пример объекта my_obj:
class MyClass
attr_accessor :alpha, :beta, :gamma
def initialize(a,b,c)
@alpha, @beta, @gamma = a, b, с
end
