diff --git a/benchmark_runner.rb b/benchmark_runner.rb new file mode 100644 index 00000000..a02c2f6d --- /dev/null +++ b/benchmark_runner.rb @@ -0,0 +1,4 @@ +require_relative 'task-1' +require 'benchmark' + +puts Benchmark.measure { work('data.txt') } diff --git a/case-study.md b/case-study.md new file mode 100644 index 00000000..baf437f5 --- /dev/null +++ b/case-study.md @@ -0,0 +1,150 @@ +# Case-study оптимизации + +## Актуальная проблема +В нашем проекте возникла серьёзная проблема. + +Необходимо было обработать файл с данными, чуть больше ста мегабайт. + +У нас уже была программа на `ruby`, которая умела делать нужную обработку. + +Она успешно работала на файлах размером пару мегабайт, но для большого файла она работала слишком долго, и не было понятно, закончит ли она вообще работу за какое-то разумное время. + +Я решил исправить эту проблему, оптимизировав эту программу. + +## Формирование метрики +Для того, чтобы понимать, дают ли мои изменения положительный эффект на быстродействие программы я придумал использовать такую метрику: +- время выполнения должно быть линейным +- в случае линейности 1_000_000 должен работать не больше 9 секунд + +## Гарантия корректности работы оптимизированной программы +Программа поставлялась с тестом. Выполнение этого теста в фидбек-лупе позволяет не допустить изменения логики программы при оптимизации. + +## Feedback-Loop +Для того, чтобы иметь возможность быстро проверять гипотезы я выстроил эффективный `feedback-loop`, который позволил мне получать обратную связь по эффективности сделанных изменений за *не поняла как оценить время* + +Вот как я построил `feedback_loop`: +- взять объем, на котором выполнение занимает не больше 5 секунд +- написать тест на перфманс +- воспользоваться профилировщиком +- найти главную точку роста +- оптимизировать +- проверить результат профилировщика +- проверить, что время выполнения уменьшилось + +## Вникаем в детали системы, чтобы найти главные точки роста +Для того, чтобы найти "точки роста" для оптимизации я воспользовался rbspy, rubyprof, stackprof + +Предварительная оценка времени выполнения: +- Время выполнения на 5000: 0.210786 +- Время выполнения на 10000: 0.726360 +- Время выполнения на 20000: 2.843040 +- Время выполнения на 40000: 12.927038 + +рост квадратичный -> O(n^2) +``` +f(x) ~ 8*10^-9 * x^2 +``` +время выполнения на 3250940: ~23,5 часа + +Вот какие проблемы удалось найти и решить + +### Ваша находка №1 +1) Начнем с объема 20000 (около 3сек), напишем тест на перфманс (не больше 3 секунд) +2) используем профилировщик rbspy +3) по call tree видим, что больше всего времени уходит на блок users.each в методе work (83,8%), а в нем на блок select (58,8%) (```user_sessions = sessions.select { |session| session['user_id'] == user['id'] }```) +4) заменим метод select на предварительную группировку по пользователям. теперь блок users.each занимает 2% времени +5) проверим время на 20000: 0.350901 +5) заменим each + [] << на map. профилировщик не показал блок в значимой статистике +5) проверим время на 20000: 0.350526 (не изменилось) +6) поправим тест на перфманс (поставим границу 0.4 с) + +### Ваша находка №2 +1) проверим время на 40000: 1.077637, мало +2) проверим 80000: 4.540294 +3) напишем перфоманс тест на 80000 (не больше 4.6 сек) +4) воспользуемся профилировщиком ruby prof flat отчет +5) по отчету видно что больше всего времени занимает конкатенация массивов: +``` + %self total self wait child calls name + 30.44 2.073 2.073 0.000 0.000 80200 Array#+ +``` +6) в коде конкатенация используемся при сборке users = [], sessions = [], uniqueBrowsers = [] +7) uniqueBrowsers заменила на map + uniq, users / sessions на append: +``` + %self total self wait child calls name + 0.62 0.007 0.007 0.000 0.000 80000 Array#append +``` +8) время на 80000: 0.571369 +9) поправим тест на перфманс (поставим границу 0.6 с) + +### Ваша находка №3 +1) проверим время на 160000: 1.162673, мало +2) проверим время на 320000: 2.476740, мало +3) заметим что сложность стала больше похожа на линейную, чем на квадратичную +3) проверим время на 640000: 5.804469 +4) напишем перфоманс тест на 640000 (не больше 6 сек) +5) воспользуемся профилировщиком stackprof + ``` + TOTAL (pct) SAMPLES (pct) FRAME + 1304 (23.5%) 1304 (23.5%) (marking) + 2634 (47.5%) 705 (12.7%) Object#collect_stats_from_users + ``` + что такое (marking) не понятно, но видно что больше всего времени уходит на collect_stats_from_users: + ``` + callers: + 2634 ( 100.0%) Object#work + 2617 ( 99.4%) Array#each + callees (1929 total): + 2634 ( 136.5%) Array#each + 1798 ( 93.2%) Object#work + 114 ( 5.9%) Hash#merge + ``` +6) из кода видно, что метод вызывается 7 раз с разными блоками, каждый раз перебирая заново всех юзеров +7) заметим также что в методе используется не оптимальная конкатенация строк, заменим + на "#{...}" -> 5.212167 c +8) заменим 7 вызовов метода на один вызов с готовым хэшом: +``` + TOTAL (pct) SAMPLES (pct) FRAME + 1938 (40.8%) 122 (2.6%) Object#collect_stats_from_users +``` +9) поправим заполнение хэша и его мердж: отдельно преобразуем время и браузеры в переменную и будем их использовть для дальнейшего заполнения, уберем мердж хэшей +``` + было: 1716 (36.1%) 245 (5.2%) Array#map + стало: 1534 (34.1%) 151 (3.4%) Array#map + немного но честная работа +``` +10) проверим время на 640000: 4.317787, не сильный прирост +11) поправим тест на перфманс (поставим границу 4.5 с) + +### Ваша находка №4 +1) продолжим использовать 640000 +2) в топе самых долгих методов остается collect_stats_from_users (42%), посмотрим внутрь - там метод Date.parse (total 25%) +3) заметим, что даты приходят в iso8601, поэтому можно опустить парсинг и сразу использовать +4) таким образом снизили затрачиваемое время в collect_stats_from_users до 19% +5) проверим время на 640000: ~3 +6) поправим тест на перфманс (поставим границу 3.1 с) +7) метод перестал быть главной точкой роста + +### Ваша находка №5 +1) продолжим использовать 640000 +2) в топе методов Array#each (52%), из них 59% вызывается из метода work, в нем 35% - collect_stats_from_users, 22% - parse_session, в нем string split +3) Совокупно string split занимает 14%, уберем лишние вызовы в parse_session +3) теперь string split занимает 11% +4) Array#each все еще главная точка роста, теперь в нем основное время занимает метод collect_stats_from_users +5) рассмотрим его внимательнее: + - перебирается массив user_object, для каждого юзера собирается статистика по его сессиям + - можно внести преобразование типов в методы парсинга + - заменим count на length + - теперь метод collect_stats_from_users занимает 28.0% +6) проверим время на 640000: 2.166889 +6) поправим тест на перфманс (поставим границу 2.5 с) +7) проверим время на 1млн: 3.760000 +8) проверим на полном файле: 17.444283 секунд +9) ради интереса проверим с выключенным gc: ~14 секунд + + +## Результаты +В результате проделанной оптимизации наконец удалось обработать файл с данными. +Удалось улучшить метрику системы с ~23ч (предварительная оценка) до ~17.5 сек и уложиться в заданный бюджет. + +## Защита от регрессии производительности +Для защиты от потери достигнутого прогресса при дальнейших изменениях программы были написаны performance тесты на время обработки 80_000 и на линейную зависимость diff --git a/data.txt b/data/data.txt similarity index 100% rename from data.txt rename to data/data.txt diff --git a/data_large.txt.gz b/data/data_large.txt.gz similarity index 100% rename from data_large.txt.gz rename to data/data_large.txt.gz diff --git a/task-1.rb b/task-1.rb index 778672df..7f041ef1 100644 --- a/task-1.rb +++ b/task-1.rb @@ -3,7 +3,6 @@ require 'json' require 'pry' require 'date' -require 'minitest/autorun' class User attr_reader :attributes, :sessions @@ -14,45 +13,42 @@ def initialize(attributes:, sessions:) end end -def parse_user(user) - fields = user.split(',') - parsed_result = { +def parse_user(fields) + { 'id' => fields[1], 'first_name' => fields[2], 'last_name' => fields[3], - 'age' => fields[4], + 'age' => fields[4] } end -def parse_session(session) - fields = session.split(',') - parsed_result = { +def parse_session(fields) + { 'user_id' => fields[1], 'session_id' => fields[2], - 'browser' => fields[3], - 'time' => fields[4], - 'date' => fields[5], + 'browser' => fields[3].upcase, + 'time' => fields[4].to_i, + 'date' => fields[5] } end def collect_stats_from_users(report, users_objects, &block) users_objects.each do |user| - user_key = "#{user.attributes['first_name']}" + ' ' + "#{user.attributes['last_name']}" - report['usersStats'][user_key] ||= {} - report['usersStats'][user_key] = report['usersStats'][user_key].merge(block.call(user)) + user_key = "#{user.attributes['first_name']} #{user.attributes['last_name']}" + report['usersStats'][user_key] = block.call(user) end end -def work - file_lines = File.read('data.txt').split("\n") +def work(filename) + file_lines = File.read(filename).split("\n") users = [] sessions = [] 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' + users.append(parse_user(cols)) if cols[0] == 'user' + sessions.append(parse_session(cols)) if cols[0] == 'session' end # Отчёт в json @@ -72,105 +68,52 @@ def work report = {} - report[:totalUsers] = users.count + report[:totalUsers] = users.length # Подсчёт количества уникальных браузеров - uniqueBrowsers = [] - sessions.each do |session| - browser = session['browser'] - uniqueBrowsers += [browser] if uniqueBrowsers.all? { |b| b != browser } - end + uniqueBrowsers = sessions.map { |session| session['browser'] }.uniq - report['uniqueBrowsersCount'] = uniqueBrowsers.count + report['uniqueBrowsersCount'] = uniqueBrowsers.length - report['totalSessions'] = sessions.count + report['totalSessions'] = sessions.length - report['allBrowsers'] = - sessions - .map { |s| s['browser'] } - .map { |b| b.upcase } - .sort - .uniq - .join(',') + report['allBrowsers'] = uniqueBrowsers.sort.join(',') # Статистика по пользователям - users_objects = [] - - 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] + user_sessions = sessions.group_by { |session| session['user_id'] } + users_objects = users.map do |user| + User.new(attributes: user, sessions: user_sessions[user['id']] || []) end report['usersStats'] = {} - # Собираем количество сессий по пользователям - collect_stats_from_users(report, users_objects) do |user| - { 'sessionsCount' => user.sessions.count } - end - - # Собираем количество времени по пользователям collect_stats_from_users(report, users_objects) do |user| - { 'totalTime' => user.sessions.map {|s| s['time']}.map {|t| t.to_i}.sum.to_s + ' min.' } - end + user_session_time = user.sessions.map { |s| s['time'] } + user_session_browser = user.sessions.map { |s| s['browser'] } - # Выбираем самую длинную сессию пользователя - collect_stats_from_users(report, users_objects) do |user| - { 'longestSession' => user.sessions.map {|s| s['time']}.map {|t| t.to_i}.max.to_s + ' min.' } - end + { + # Собираем количество сессий по пользователям + 'sessionsCount' => user.sessions.length, - # Браузеры пользователя через запятую - collect_stats_from_users(report, users_objects) do |user| - { 'browsers' => user.sessions.map {|s| s['browser']}.map {|b| b.upcase}.sort.join(', ') } - end + # Собираем количество времени по пользователям + 'totalTime' => "#{user_session_time.sum} min.", - # Хоть раз использовал IE? - collect_stats_from_users(report, users_objects) do |user| - { 'usedIE' => user.sessions.map{|s| s['browser']}.any? { |b| b.upcase =~ /INTERNET EXPLORER/ } } - end + # Выбираем самую длинную сессию пользователя + 'longestSession' => "#{user_session_time.max} min.", - # Всегда использовал только Chrome? - collect_stats_from_users(report, users_objects) do |user| - { 'alwaysUsedChrome' => user.sessions.map{|s| s['browser']}.all? { |b| b.upcase =~ /CHROME/ } } - end + # Браузеры пользователя через запятую + 'browsers' => user_session_browser.sort.join(', '), - # Даты сессий через запятую в обратном порядке в формате iso8601 - collect_stats_from_users(report, users_objects) do |user| - { 'dates' => user.sessions.map{|s| s['date']}.map {|d| Date.parse(d)}.sort.reverse.map { |d| d.iso8601 } } - end + # Хоть раз использовал IE? + 'usedIE' => user_session_browser.any? { |b| b =~ /INTERNET EXPLORER/ }, - File.write('result.json', "#{report.to_json}\n") -end + # Всегда использовал только Chrome? + 'alwaysUsedChrome' => user_session_browser.all? { |b| b =~ /CHROME/ }, -class TestMe < Minitest::Test - def setup - File.write('result.json', '') - File.write('data.txt', -'user,0,Leida,Cira,0 -session,0,0,Safari 29,87,2016-10-23 -session,0,1,Firefox 12,118,2017-02-27 -session,0,2,Internet Explorer 28,31,2017-03-28 -session,0,3,Internet Explorer 28,109,2016-09-15 -session,0,4,Safari 39,104,2017-09-27 -session,0,5,Internet Explorer 35,6,2016-09-01 -user,1,Palmer,Katrina,65 -session,1,0,Safari 17,12,2016-10-21 -session,1,1,Firefox 32,3,2016-12-20 -session,1,2,Chrome 6,59,2016-11-11 -session,1,3,Internet Explorer 10,28,2017-04-29 -session,1,4,Chrome 13,116,2016-12-28 -user,2,Gregory,Santos,86 -session,2,0,Chrome 35,6,2018-09-21 -session,2,1,Safari 49,85,2017-05-22 -session,2,2,Firefox 47,17,2018-02-02 -session,2,3,Chrome 20,84,2016-11-25 -') + # Даты сессий через запятую в обратном порядке в формате iso8601 + 'dates' => user.sessions.map { |s| s['date'] }.sort.reverse + } end - def test_result - work - expected_result = '{"totalUsers":3,"uniqueBrowsersCount":14,"totalSessions":15,"allBrowsers":"CHROME 13,CHROME 20,CHROME 35,CHROME 6,FIREFOX 12,FIREFOX 32,FIREFOX 47,INTERNET EXPLORER 10,INTERNET EXPLORER 28,INTERNET EXPLORER 35,SAFARI 17,SAFARI 29,SAFARI 39,SAFARI 49","usersStats":{"Leida Cira":{"sessionsCount":6,"totalTime":"455 min.","longestSession":"118 min.","browsers":"FIREFOX 12, INTERNET EXPLORER 28, INTERNET EXPLORER 28, INTERNET EXPLORER 35, SAFARI 29, SAFARI 39","usedIE":true,"alwaysUsedChrome":false,"dates":["2017-09-27","2017-03-28","2017-02-27","2016-10-23","2016-09-15","2016-09-01"]},"Palmer Katrina":{"sessionsCount":5,"totalTime":"218 min.","longestSession":"116 min.","browsers":"CHROME 13, CHROME 6, FIREFOX 32, INTERNET EXPLORER 10, SAFARI 17","usedIE":true,"alwaysUsedChrome":false,"dates":["2017-04-29","2016-12-28","2016-12-20","2016-11-11","2016-10-21"]},"Gregory Santos":{"sessionsCount":4,"totalTime":"192 min.","longestSession":"85 min.","browsers":"CHROME 20, CHROME 35, FIREFOX 47, SAFARI 49","usedIE":false,"alwaysUsedChrome":false,"dates":["2018-09-21","2018-02-02","2017-05-22","2016-11-25"]}}}' + "\n" - assert_equal expected_result, File.read('result.json') - end + File.write('result.json', "#{report.to_json}\n") end diff --git a/tests/task-1_test.rb b/tests/task-1_test.rb new file mode 100644 index 00000000..5d006d02 --- /dev/null +++ b/tests/task-1_test.rb @@ -0,0 +1,34 @@ +require 'minitest/autorun' +require_relative '../task-1' + +class TestMe < Minitest::Test + def setup + File.write('result.json', '') + File.write('data/data.txt', + 'user,0,Leida,Cira,0 +session,0,0,Safari 29,87,2016-10-23 +session,0,1,Firefox 12,118,2017-02-27 +session,0,2,Internet Explorer 28,31,2017-03-28 +session,0,3,Internet Explorer 28,109,2016-09-15 +session,0,4,Safari 39,104,2017-09-27 +session,0,5,Internet Explorer 35,6,2016-09-01 +user,1,Palmer,Katrina,65 +session,1,0,Safari 17,12,2016-10-21 +session,1,1,Firefox 32,3,2016-12-20 +session,1,2,Chrome 6,59,2016-11-11 +session,1,3,Internet Explorer 10,28,2017-04-29 +session,1,4,Chrome 13,116,2016-12-28 +user,2,Gregory,Santos,86 +session,2,0,Chrome 35,6,2018-09-21 +session,2,1,Safari 49,85,2017-05-22 +session,2,2,Firefox 47,17,2018-02-02 +session,2,3,Chrome 20,84,2016-11-25 +') + end + + def test_result + work('data/data.txt') + expected_result = '{"totalUsers":3,"uniqueBrowsersCount":14,"totalSessions":15,"allBrowsers":"CHROME 13,CHROME 20,CHROME 35,CHROME 6,FIREFOX 12,FIREFOX 32,FIREFOX 47,INTERNET EXPLORER 10,INTERNET EXPLORER 28,INTERNET EXPLORER 35,SAFARI 17,SAFARI 29,SAFARI 39,SAFARI 49","usersStats":{"Leida Cira":{"sessionsCount":6,"totalTime":"455 min.","longestSession":"118 min.","browsers":"FIREFOX 12, INTERNET EXPLORER 28, INTERNET EXPLORER 28, INTERNET EXPLORER 35, SAFARI 29, SAFARI 39","usedIE":true,"alwaysUsedChrome":false,"dates":["2017-09-27","2017-03-28","2017-02-27","2016-10-23","2016-09-15","2016-09-01"]},"Palmer Katrina":{"sessionsCount":5,"totalTime":"218 min.","longestSession":"116 min.","browsers":"CHROME 13, CHROME 6, FIREFOX 32, INTERNET EXPLORER 10, SAFARI 17","usedIE":true,"alwaysUsedChrome":false,"dates":["2017-04-29","2016-12-28","2016-12-20","2016-11-11","2016-10-21"]},"Gregory Santos":{"sessionsCount":4,"totalTime":"192 min.","longestSession":"85 min.","browsers":"CHROME 20, CHROME 35, FIREFOX 47, SAFARI 49","usedIE":false,"alwaysUsedChrome":false,"dates":["2018-09-21","2018-02-02","2017-05-22","2016-11-25"]}}}' + "\n" + assert_equal expected_result, File.read('result.json') + end +end diff --git a/tests/test-1_spec.rb b/tests/test-1_spec.rb new file mode 100644 index 00000000..27fca7ec --- /dev/null +++ b/tests/test-1_spec.rb @@ -0,0 +1,20 @@ +require 'rspec-benchmark' +require_relative '../task-1' + +RSpec.configure do |config| + config.include RSpec::Benchmark::Matchers +end + +describe 'Performance' do + it '80_000 works under 0.2s' do + expect do + work('data/data80000.txt') + end.to perform_under(200).ms.warmup(2).times.sample(5).times + end + + it 'has linear performance' do + expect do |n, _i| + work("data/data#{n}000.txt") + end.to perform_linear.in_range([20, 80, 160, 320]) + end +end