case-study.md

Case-study оптимизации

Актуальная проблема

В нашем проекте возникла серьёзная проблема.

Необходимо было обработать файл с данными, чуть больше ста мегабайт.

У нас уже была программа на ruby, которая умела делать нужную обработку.

Она успешно работала на файлах размером пару мегабайт, но для большого файла она работала слишком долго, и не было понятно, закончит ли она вообще работу за какое-то разумное время.

Я решил исправить эту проблему, оптимизировав эту программу.

Формирование метрики

Чтобы понимать, влияют ли мои изменения на быстродействие программы положительно, я решил измерять время выполнения программы в зависимости от объема исходных данных.

Гарантия корректности работы оптимизированной программы

Программа поставлялась с тестом. Выполнение этого теста в фидбек-лупе позволяет не допустить изменения логики программы при оптимизации.

Feedback-Loop

Для того, чтобы иметь возможность быстро проверять гипотезы я выстроил эффективный feedback-loop, который позволил мне получать обратную связь по эффективности сделанных изменений за 49 секунд.

Вот как я построил feedback_loop: я решил найти оптимальный для обработки объем данных путем последовательного деления исходного файла пополам (split --number=r/2) и сравнения времени обработки, в результате получил файлы data_2x.txt, data_4x.txt, ... data_512.txt. Максимальный объем данных с приемлемым временем их обработки, содержался в файле data_16x.txt. Я взял его за отправную точку и провел замеры времени:

Данные	Результат
data_512x	Finished in 0.522478s, 1.9140 runs/s, 1.9140 assertions/s.
data_256x	Finished in 2.002917s, 0.4993 runs/s, 0.4993 assertions/s.
data_128x	Finished in 9.130446s, 0.1095 runs/s, 0.1095 assertions/s.
data_64x	Finished in 49.075470s, 0.0204 runs/s, 0.0204 assertions/s.
data_32x	Finished in 206.839643s, 0.0048 runs/s, 0.0048 assertions/s.
data_16x	Finished in 837.989180s, 0.0012 runs/s, 0.0012 assertions/s.

Среднее отклонение увеличения времени выполнения программы при увеличении объема данных:

x1 = 837.989180 / 206.839643 = 4.051395409
x2 = 206.839643 / 49.075470 = 4.214725666
x3 = 49.075470 / 9.130446 = 5.374925825
x4 = 9.130446 / 2.002917 = 4.558574319
x5 = 2.002917 / 0.522478 = 3.833495382
xAVG = (x1 + x2 + x3 + x4) / 5 = 4.40662332

Теперь можно рассчитать ориентировочное время выполнения исходной программы с полным объемом данных

0.522478s * (4.40662332 ** 10) ≈ 1442538.1s

В качестве источника данных для проведения оптимизации я выбрал файл data_64x, так как содержащийся в нем объем данных достаточен для объективной оценки прогресса оптимизации при разумном времени выполнения программы.

Вникаем в детали системы, чтобы найти главные точки роста

Для того, чтобы найти точки роста для оптимизации я пользовался ruby-prof и stackprof. Вот какие проблемы удалось найти и решить

Array#select

При просмотре отчета ruby-prof#Flat сразу привлек внимание метод Array#select, для определения его местоположения я использовал stackprof. Данный метод сопоставляет списки пользователей и пользовательских сессий:

users.each do |user|
  attributes = user
  user_sessions = sessions.select { |session| session['user_id'] == user['id'] }
  user_object = User.new(attributes: attributes, sessions: user_sessions)
  users_objects = users_objects + [user_object]
end

Попытки оптимизировать сам процесс перебора не привели к значимым результатам, поэтому я решил подойти к решению проблемы с другой стороны — реорганизовать хэш сессий, сгруппировав записи по ключам user_id, чтобы уйти от многократного последовательного перебора всего хэша:

sessions_by_user = sessions.group_by { |k| k['user_id'] }
users.each { |user| users_objects << User.new(attributes: user, sessions: sessions_by_user[user['id']] || []) }

После запуска программы результат порадовал, мы получили прирост скорости обработки почти в 35 раз:

Finished in 1.412858s, 0.7078 runs/s, 0.7078 assertions/s.

В отчете ruby-prof#Flat данный метод перестал быть главной точкой роста. Скорость выполнения фидбэк-лупа также ожидаемо возросла.

Array#each

При запуске ruby-prof#Flat обнаружилась следующая точка роста — Array#each, для более подробного ее изучения я использовал stackprof и выяснил, что в данном куске кода происходит парсинг исходных данных:

file_lines = File.read(filename).split("\n")
file_lines.each do |line|
  cols = line.split(',')
  users = users + [parse_user(line)] if cols[0] == 'user'
  sessions = sessions + [parse_session(line)] if cols[0] == 'session'
end

Я оптимизировал этот фрагмент кода:

file_lines = File.readlines(filename, chomp: true)
file_lines.each do |line|
  record = line.split(',')
  case record[0]
  when 'user' then users << parse_user(record)
  when 'session' then sessions << parse_session(record)
  end
end

Метрика изменилась в лучшую сторону, скорость выполнения программы увеличилась еще в три раза:

Finished in 0.455918s, 2.1934 runs/s, 2.1934 assertions/s.

Профайлер также показал, что данный метод больше не является главной точкой роста.

На этом этапе я пробовал использовать для парсинга класс CSV, но он показал менее производительные результаты (я приложил сравнение в файле csv-parsing.md).

Array#all?

Следующий запуск ruby-prof#Flat показал еще одну точка роста — Array#all?, изучение отчета stackprof позволило выяснить что этот фрагмент кода отвечает за подсчет количества уникальных браузеров:

sessions.each do |session|
  browser = session['browser']
  uniqueBrowsers += [browser] if uniqueBrowsers.all? { |b| b != browser }
end

Я использовал метод с группировкой хэша:

unique_browsers = sessions.group_by { |k| k['browser'] }.keys

Здесь же я заметил еще один не очень неэффективный момент:

report['allBrowsers'] =
sessions
  .map { |s| s['browser'] }
  .map { |b| b.upcase }
  .sort
  .uniq
  .join(',')

И решил его порефакторить:

report['allBrowsers'] = unique_browsers.sort.join(',').upcase

Скорость выполнения программы увеличилась более чем в полтора раза:

Finished in 0.254995s, 3.9216 runs/s, 3.9216 assertions/s.

В отчете ruby-prof#Flat данный метод перестал быть главной точкой роста.

На этом же этапе я решил немного порефакторить сбор статистики — формирование хэша report, а также метод collect_stats_from_users и его вызовы. Это дало прирост скорости еще почти на 30%:

Finished in 0.182723s, 5.4728 runs/s, 5.4728 assertions/s.

Array#each

Отчеты ruby-prof#CallStack и stackproof показали, что главной точкой роста снова стал парсинг исходных данных:

file_lines.each do |line|
  record = line.split(',')
  case record[0]
  when 'user' then users << parse_user(record)
  when 'session' then sessions << parse_session(record)
  end
end

Я решил отказаться от хэшей в ущерб читаемости кода (хотя он прокомментирован и сложностей при понимании не возникнет), а также устранить метод split, использовав для парсинга гем ccsv.

Ccsv.foreach(filename) do |record|
  case record[0]
  when 'user' then users << record
  when 'session' then sessions << record
  end
end

Скорость обработки данных выросла на 20%, метод перестал быть главной точкой роста.

Finished in 0.152527s, 6.5562 runs/s, 6.5562 assertions/s.

Object#collect_stats_from_users

Следующей главной точкой роста отчет ruby-prof#CallStack показал метод collect_stats_from_users, я решил еще порефакторить сам метод и его коллеры, а также использовал гем oj для ускорения вывода JSON. В результате скорость выполнения программы выросла более чем на 20%:

Finished in 0.125221s, 7.9859 runs/s, 7.9859 assertions/s.

На этом этапе я решил остановиться, так как мне не удалось устранить оставшиеся точки роста и дальнейшая оптимизация приносила прирост производительности в пределах погрешности измерений.

Время выполнения программы с полным объемом данных:

Finished in 32.301069s, 0.0310 runs/s, 0.0310 assertions/s.

Результаты

В результате проделанной оптимизации наконец удалось обработать файл с данными. Удалось улучшить метрику системы с 1442538.1s до 32.3s.

Мне не удалось полностью уложиться в бюджет, но я все равно доволен достигнутыми результатами, так как узнал много нового об использовании привычных методов ruby, а также в процессе поиска более производительных решений усвоил много новых знаний об устройстве языка в целом.

Защита от регрессии производительности

Для защиты от потери достигнутого прогресса при дальнейших изменениях программы я переписал существующий тест с использованием RSpec. Также я добавил перфоманс-тест на обработку полного объема данных со включенным GC за 33 секунды.