loop_3

Author: aleksey.ryabchikov

Gemfile

@@ -0,0 +1,82 @@
+# Case-study оптимизации
+
+## Актуальная проблема
+В нашем проекте возникла серьёзная проблема.
+
+Необходимо было обработать файл с данными, чуть больше ста мегабайт.
+
+У нас уже была программа на `ruby`, которая умела делать нужную обработку.
+
+Она успешно работала на файлах размером пару мегабайт, но для большого файла она работала слишком долго, и не было понятно, закончит ли она вообще работу за какое-то разумное время.
+
+Я решил исправить эту проблему, оптимизировав эту программу.
+
+## Формирование метрики
+Для того, чтобы понимать, дают ли мои изменения положительный эффект на быстродействие программы я придумал использовать такую метрику: Время выполнения программы с частичным объемом данных за вменяемое время
+
+## Гарантия корректности работы оптимизированной программы
+Программа поставлялась с тестом. Выполнение этого теста в фидбек-лупе позволяет не допустить изменения логики программы при оптимизации.
+
+## Feedback-Loop
+Для того, чтобы иметь возможность быстро проверять гипотезы я выстроил эффективный `feedback-loop`, который позволил мне получать обратную связь по эффективности сделанных изменений за *время, которое у вас получилось*
+
+Вот как я построил `feedback_loop`:
+Измерив время выполнения программы на разном объеме дынных, алгоритмическая сложность получилась O(n^2), т.е. время выполнения в зависимости от объема данных возрастает квадратично.
+
+- Нужно зафиксировать бюджет метрики, которую определили выше. 
+  То-есть выбрать объем данных, который выполняется за адекватное время, на первой итерации например 5 сек. (20_000 строк кода на моей машине)
+- Защитить метрику от дальнейшей деградации, написать тест
+- С помощью профилировщика найти главную точку роста (Профилируем с выключенным GC предварительно прогрев кеши)
+- Внести оптимизационные правки
+- С помощью профилировщика проверить есть ли улучшения
+- Запустить тест, проверить если улучшения есть, если да то закоммитить.
+
+## Вникаем в детали системы, чтобы найти главные точки роста
+Для того, чтобы найти "точки роста" для оптимизации я воспользовался rbspy (удобно, потому что встроен в rubymine), stackprof и ruby-prof в разных режимах отчетов
+
+Вот какие проблемы удалось найти и решить
+
+### Ваша находка №1
+- stackprof cli и rbspy указали на одинаковую точку роста, 89% занимает `user_sessions = sessions.select { |session| session['user_id'] == user['id'] }`
+```
+%Total	%Self	Total	Self	Wait	Child	Calls	Name
+89.15%	89.15%	7.19	7.19	0.00	0.00	3046	Array#select
+
+```
+- Заменил перебор всех сессий на хэш с группированные данных по user_id. В данном конкретном месте алгоритмическая сложность с O(n) изменилась на O(1)
+- Метрика кратно уменьшилась при прогоне теста на перфоманс с средних 5 сек. до 0.4 сек. Это и было самым узким местом программы по всей видимости.
+- Повторный запуск профилировщика показал, что вместо 89,15% теперь это место занимает 0.3%.
+
+### Ваша находка №2
+- Профилировщики указали на следующую точку роста:
+```
+%Total	%Self	Total	Self	Wait	Child	Calls	Name
+96.01%	43.30%	0.73	0.33	0.00	0.40	10	Array#each
+```
+- Заменил `sessions = sessions + [parse_session(line)] if cols[0] == 'session'` на `sessions = sessions << parse_session(line) if cols[0] == 'session'`
+Известная проблема в ruby. Оператор << позволяет не создавать новую переменную каждый раз, а писать все в существующую.
+- При прогоне теста, среднее значение метрики упало с 0.4 сек. до 0.25 сек.
+
+### Ваша находка №3
+- Ради интереса прогнал тесты с разным объемом данных, 20к, 40к, 80к и так далее. В том числе и на полном файле.
+На данном этапе уже удалось избавится от O(n^2) благодаря первому шагу, теперь алгоритмическая сложность О(n).
+- Профилировщики указали на следующую точку роста:
+```
+%Total	%Self	Total	Self	Wait	Child	Calls	Name
+93.26%	13.71%	0.44	0.06	0.00	0.37	10	Array#each
+```
+- Оптимизировал блок each, заменил '+' на Set.
+- При прогоне теста, среднее значение метрики упало с 0.25 сек. до 0.18 сек.
+
+### Ваша находка №4
+- По какой-то причине показания stackprof и ruby-prof стали расходится.
+- stackprof указал на главную точку роста в строке `{ 'dates' => user.sessions.map{|s| s['date']}.map {|d| Date.parse(d)}.sort.reverse.map { |d| d.iso8601 } }`
+- ruby-prof указал на строку `{ 'totalTime' => user.sessions.map {|s| s['time']}.map {|t| t.to_i}.sum.to_s + ' min.' }`
+```
+  %Total	%Self	Total	Self	Wait	Child	Calls	Name
+  90.29%	21.60%	0.37	0.09	0.00	0.28	10	Array#each
+```
+- Попробовал увеличить кол-во данных, чтобы проще было увидеть проблематику до 100_000 строк.
+- Изучив код более подробно, понял, что обе точки роста связаны между собой.
+
+

case-study.md

@@ -0,0 +1,11 @@
+require 'ruby-prof'
+require_relative './task-1'
+
+RubyProf.measure_mode = RubyProf::WALL_TIME
+
+result = RubyProf.profile do
+  work('./spec/fixtures/files/dataN.txt')
+end
+
+printer = RubyProf::GraphHtmlPrinter.new(result)
+printer.print(File.open('./ruby-prof.html', 'w+'))

ruby-prof.rb

@@ -0,0 +1,5 @@
+require 'rspec-benchmark'
+
+RSpec.configure do |config|
+  config.include RSpec::Benchmark::Matchers
+end

data.txt spec/fixtures/files/data.txtdata.txt renamed to spec/fixtures/files/data.txt

@@ -0,0 +1,43 @@
+require_relative './rails_helper'
+require_relative '../task-1'
+
+describe 'task-1' do
+  let(:result) { './spec/fixtures/files/result.json' }
+  describe 'Result' do
+    let(:file) { './spec/fixtures/files/data.txt' }
+
+    let(:expected_result) do
+      '{"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"
+    end
+
+    it 'returns equal' do
+      work(file)
+      expect(File.read(result)).to eq(expected_result)
+    end
+  end
+
+  describe 'Performance' do
+    let(:file) { './spec/fixtures/files/dataN.txt' }
+
+    describe 'with partial file' do
+      it 'works under 0.4 sec' do
+        expect { work(file) }.to perform_under(0.18).sec.warmup(2).times.sample(10).times
+      end
+    end
+
+    describe 'with full file' do
+      it 'works under 30 sec' do
+        expect { work('./data_large.txt') }.to perform_under(30).sec
+      end
+    end
+  end
+end

spec/rails_helper.rb

@@ -0,0 +1,7 @@
+require_relative './task-1'
+require 'stackprof'
+
+StackProf.run(mode: :wall, out: './stackprof.dump', interval: 1000) do
+  GC.disable
+  work('./spec/fixtures/files/dataN.txt')
+end

spec/task-1_spec.rb

@@ -4,6 +4,7 @@
 require 'pry'
 require 'date'
 require 'minitest/autorun'
+require "set"
 
 class User
   attr_reader :attributes, :sessions
@@ -43,16 +44,16 @@ def collect_stats_from_users(report, users_objects, &block)
   end
 end
 
-def work
-  file_lines = File.read('data.txt').split("\n")
+def work(file_path, result_path = 'spec/fixtures/files/result.json')
+  file_lines = File.read(file_path).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 = users << parse_user(line) if cols[0] == 'user'
+    sessions = sessions << parse_session(line) if cols[0] == 'session'
   end
 
   # Отчёт в json
@@ -75,10 +76,9 @@ def work
   report[:totalUsers] = users.count
 
   # Подсчёт количества уникальных браузеров
-  uniqueBrowsers = []
+  uniqueBrowsers = Set.new
   sessions.each do |session|
-    browser = session['browser']
-    uniqueBrowsers += [browser] if uniqueBrowsers.all? { |b| b != browser }
+    uniqueBrowsers.add(session['browser'])
   end
 
   report['uniqueBrowsersCount'] = uniqueBrowsers.count
@@ -93,14 +93,10 @@ def work
       .uniq
       .join(',')
 
+  user_sessions = sessions.group_by { |session| session['user_id'] }
   # Статистика по пользователям
-  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]
+  users_objects = users.map do |user|
+    User.new(attributes: user, sessions: user_sessions[user['id']] || [])
   end
 
   report['usersStats'] = {}
@@ -140,37 +136,5 @@ def work
     { 'dates' => user.sessions.map{|s| s['date']}.map {|d| Date.parse(d)}.sort.reverse.map { |d| d.iso8601 } }
   end
 
-  File.write('result.json', "#{report.to_json}\n")
-end
-
-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
-')
-  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_path, "#{report.to_json}\n")
 end