Optimization 1

README.md

@@ -94,17 +94,17 @@ head -n N data_large.txt > dataN.txt # create smaller file from larger (take N f
 ## Checklist
 Советую использовать все рассмотренные в лекции инструменты хотя бы по разу - попрактикуйтесь с ними, научитесь с ними работать.
 
-- [ ] Прикинуть зависимость времени работы програмы от размера обрабатываемого файла
-- [ ] Построить и проанализировать отчёт `ruby-prof` в режиме `Flat`;
-- [ ] Построить и проанализировать отчёт `ruby-prof` в режиме `Graph`;
-- [ ] Построить и проанализировать отчёт `ruby-prof` в режиме `CallStack`;
-- [ ] Построить и проанализировать отчёт `ruby-prof` в режиме `CallTree` c визуализацией в `QCachegrind`;
-- [ ] Построить дамп `stackprof` и проанализировать его с помощью `CLI`
-- [ ] Построить дамп `stackprof` в `json` и проанализировать его с помощью `speedscope.app`
-- [ ] Профилировать работающий процесс `rbspy`;
-- [ ] Добавить в программу `ProgressBar`;
-- [ ] Постараться довести асимптотику до линейной и проверить это тестом;
-- [ ] Написать простой тест на время работы: когда вы придёте к оптимизированному решению, замерьте, сколько оно будет работать на тестовом объёме данных; и напишите тест на то, что это время не превышается (чтобы не было ложных срабатываний, задайте время с небольшим запасом);
+- [+] Прикинуть зависимость времени работы програмы от размера обрабатываемого файла
+- [+] Построить и проанализировать отчёт `ruby-prof` в режиме `Flat`;
+- [+] Построить и проанализировать отчёт `ruby-prof` в режиме `Graph`;
+- [+] Построить и проанализировать отчёт `ruby-prof` в режиме `CallStack`;
+- [+] Построить и проанализировать отчёт `ruby-prof` в режиме `CallTree` c визуализацией в `QCachegrind`;
+- [+] Построить дамп `stackprof` и проанализировать его с помощью `CLI`
+- [+] Построить дамп `stackprof` в `json` и проанализировать его с помощью `speedscope.app`
+- [+] Профилировать работающий процесс `rbspy`;
+- [+] Добавить в программу `ProgressBar`;
+- [+] Постараться довести асимптотику до линейной и проверить это тестом;
+- [+] Написать простой тест на время работы: когда вы придёте к оптимизированному решению, замерьте, сколько оно будет работать на тестовом объёме данных; и напишите тест на то, что это время не превышается (чтобы не было ложных срабатываний, задайте время с небольшим запасом);
 
 ### Главное
 Нужно потренироваться методично работать по схеме с фидбек-лупом:

case-study.md

@@ -0,0 +1,148 @@
+# Case-study оптимизации
+
+## Актуальная проблема
+
+В файле `task-1.rb` находится ruby-программа, которая выполняет обработку данных из файла.
+
+С помощью этой программы нужно обработать файл данных `data_large.txt`.
+
+Проблема заключается в том, что это происходит слишком долго
+
+Задачей является оптимизация программы до такой степени, чтобы программа корректно отрабатывала файл `data_large.txt` за `30 сек`
+
+## Формирование метрики
+
+Для понимания того, что мои изменения дают положительный эффект на быстродействие программы, я решил использовать такую метрику:
+- использовать профилировщики `ruby-prof`, `stackprof`, `rbpsy` для анализа производительности на разных объемах данных
+- использовать ProgressBar для понимания скорости работы программы и процента выполненной работы
+
+## Гарантия корректности работы оптимизированной программы
+
+Гарантией работы программы является ее тестирование. Каждый раз перед завершением и во время работы над очередной итерации будет выполняться тестирование логики работы программы на тестовых данных, подготовленных в файле `data.txt`
+
+## Feedback-Loop
+Для того, чтобы иметь возможность быстро проверять гипотезы я выстроил эффективный `feedback-loop`, который позволил мне получать обратную связь по эффективности сделанных изменений за 3-4 минуты
+
+Вот как я построил `feedback_loop`:
+- сделал отчет с помощью одного из профилировщиков
+- зафиксировал время исполнения
+- нашел точку роста (место, которое занимает много времени на исполнение)
+- попробовал найти решение с помощью https://github.com/fastruby/fast-ruby и других ресурсов
+- внес изменения в код
+- сделал отчет с помощью одного из профилировщиков
+- зафиксировал время исполнения
+- проанализировал повлияли ли изменения на быстродействие программы
+- запустил тесты (`rspec spec`)
+- если изменения повлияли положительно и при этом прошли все тесты, то приступаю к следующей итерации
+
+## Вникаем в детали системы, чтобы найти главные точки роста
+
+Для того, чтобы найти "точки роста" для оптимизации я воспользовался:
+
+- Подготовил файлы для профилировщиков с разным объемом данных с помощью команды:
+```
+head -n N data_large.txt > data_N.txt
+```
+
+- Проверил быстродействие с помощью `rbspy`
+Понял, что мне неудобно постоянно запускать процесс, искать его pid и подключаться еще к нему.
+При этом сам отчет показался слишком расплывчатым без точных деталей.
+
+- Проверил быстродействие с помощью `ruby-prof`
+
+- Проверил быстродействие с отключенным GC
+
+- Проверил быстродействие с помощью `stackprof`
+
+Вот какие проблемы удалось найти и решить:
+
+### Ваша находка №1
+- С помощью `stackprof` посмотрел быстродействие системы.
+```
+21  (   72.4%)  Array#each
+```
+- Посмотрел все места с each и понял, что в некоторых местах each используется не рационально:
+
+https://github.com/fastruby/fast-ruby#enumerableeach--push-vs-enumerablemap-code
+
+```
+Comparison:
+            Array#map:   158090.9 i/s
+   Array#each + push:    99634.2 i/s - 1.59x slower
+```
+
+- Исправил в некоторых местах `each + push` на `map`
+
+- метрика изменилась:
+```
+16  (   66.7%)  Array#map
+9  (   37.5%)  Array#select
+3  (   12.5%)  Object#collect_stats_from_users
+3  (   12.5%)  Array#each
+```
+
+Время исполнения снизилось с ~`3.673483s` до ~`2.516519s` для файла в 10000 строк
+
+### Ваша находка №2
+- С помощью `stackprof` speedscore посмотрел быстродействие системы.
+```
+1.54s (85%)	360.04ms (20%)	Array#select
+```
+Array#select занимал большую часть времени
+Потратил несколько часов, копаясь в различных форумах, статьях с возможностью оптимизировать select
+Понял, что копал не туда и нашел решение в структуре исходных данных
+Оказывается, что select там просто не нужен
+Структура данных однотипна, за информацией о пользователе всегда идет список сессий, привязанных к нему, поэтому select здесь излишен
+
+- Вместо использования select перешел на проверку наличия слова `user` для определения строки, содержащей информацию о пользователе, последующие строки записывал в сессии этого пользователя
+- Провел рефакторинг, вместо того, чтобы каждый раз делать `users.each` на каждое поле для вывода результата, сделал один `each` для сбора значний всех полей.
+- Убрал излишний вызов `Date.parse(d)}.sort.reverse.map { |d| d.iso8601 }`. В нем не было никакого смысла из-за того, что дата и так была в нужном формате
+- Ускорил конкатенацию строк в присваивании user_key, исходя из документации: https://github.com/fastruby/fast-ruby#string-concatenation-code
+
+- После внесения изменений время исполнения для файла в 10000 строк снизилось до ~`1.277132s`
+Array#select больше не присутствовал в отчете профилировщика
+
+### Ваша находка №3
+- С помощью `stackprof` speedscore посмотрел быстродействие системы
+```
+15.31ms (32%)	15.31ms (32%)	String#split
+```
+String#split занимал ~32% всего времени
+- Убрал лишние вызовы split в методах `parse_session` и `parse_user`
+
+- Из отчета профилировщика split стал занимать меньше времени
+```
+8.38ms (16%)	8.38ms (16%)	String#split
+```
+- После внесения изменений время исполнения для файла в 10000 строк снизилось до ~`0.946666s`
+
+### Ваша находка №4
+- Внедрил ProgressBar
+- Он влияет на производительность, но позволяет сделать примерную оценку и показывает статус текущего процесса
+
+### Ваша находка №5
+- Написал тесты, защищающие оптимизацию
+- С помощью `stackprof` speedscore посмотрел быстродействие системы
+- Убрал некоторые неоптимальные конструкции из примеров fast-ruby
+Было:
+```
+1.02ms (2.6%)	1.02ms (2.6%)	Object#collect_always_used_chrome
+```
+Стало:
+`Object#collect_always_used_chrome` пропал из отчета
+- Сделал рефакторинг кода с проверкой всех тестов
+- Прогнал несколько раз всю программу для файла `data_large.txt`, вышло ~`27 секунд`
+
+## Результаты
+В результате проделанной оптимизации наконец удалось обработать файл с данными.
+
+Удалось улучшить метрику системы с невозможности закончить процесс за `15 минут` до `00:27` для файла `data_large.txt` и уложиться в заданный бюджет.
+
+### Заметки для себя
+- Нужно смотреть не только на код, но и на постановку задачи и данные, которые нужно обработать
+- Осторожнее добавляй в git большие файлы, из-за них потом не всегда получается залить код в репозиторий и пользоваться такими инструментами как https://git-lfs.com/
+- Пробуй различные инструменты для оптимизации. Они могут показать разные результаты и помочь проанализировать где конкретно отжирается много ресурсов.
+- Не пытайся сразу бежать исправлять, казалось бы, точки роста. Вначале запусти профилировщик и посмотри действительно ли эти места сильно нагружают систему.
+
+## Защита от регрессии производительности
+Для защиты от потери достигнутого прогресса при дальнейших изменениях программы был написан performance тест `specs/performance_spec.rb`

ruby-prof_callstack.rb

@@ -0,0 +1,14 @@
+# RubyProf CallStack report
+# ruby 14-ruby-prof-callstack.rb
+# open ruby_prof_reports/callstack.html
+require 'ruby-prof'
+require_relative 'task-1.rb'
+
+RubyProf.measure_mode = RubyProf::WALL_TIME
+
+result = RubyProf.profile do
+  work(disable_gc: true)
+end
+
+printer = RubyProf::CallStackPrinter.new(result)
+printer.print(File.open('ruby_prof_reports/callstack.html', 'w+'))

ruby-prof_calltree.rb

@@ -0,0 +1,15 @@
+# RubyProf CallGrind report
+# ruby 15-ruby-prof-callgrind.rb
+# brew install qcachegrind
+# qcachegrind ruby_prof_reports/...
+require 'ruby-prof'
+require_relative 'task-1.rb'
+
+RubyProf.measure_mode = RubyProf::WALL_TIME
+
+result = RubyProf.profile do
+  work(file: 'data_large.txt', disable_gc: true)
+end
+
+printer4 = RubyProf::CallTreePrinter.new(result)
+printer4.print(:path => "ruby_prof_reports", :profile => 'callgrind')

ruby-prof_flat.rb

@@ -0,0 +1,14 @@
+# RubyProf Flat report
+# ruby 12-ruby-prof-flat.rb
+# cat ruby_prof_reports/flat.txt
+require 'ruby-prof'
+require_relative 'task-1.rb'
+
+RubyProf.measure_mode = RubyProf::WALL_TIME
+
+result = RubyProf.profile do
+  work(file: 'data_large.txt', disable_gc: true)
+end
+
+printer = RubyProf::FlatPrinter.new(result)
+printer.print(File.open("ruby_prof_reports/flat.txt", "w+"))

ruby-prof_graph.rb

@@ -0,0 +1,14 @@
+# RubyProf Graph report
+# ruby 13-ruby-prof-graph.rb
+# open ruby_prof_reports/graph.html
+require 'ruby-prof'
+require_relative 'task-1.rb'
+
+RubyProf.measure_mode = RubyProf::WALL_TIME
+
+result = RubyProf.profile do
+  work(file: 'data_large.txt', disable_gc: true)
+end
+
+printer = RubyProf::GraphHtmlPrinter.new(result)
+printer.print(File.open("ruby_prof_reports/graph.html", "w+"))

ruby_prof_reports/callgrind.out.98062

@@ -0,0 +1,86 @@
+events: wall_time
+
+fl=
+fn=Exception::backtrace
+0 1
+
+fl=
+fn=Exception::exception
+0 1
+
+fl=
+fn=Exception::initialize
+0 2
+
+fl=
+fn=SystemCallError::initialize
+0 5
+cfl=
+cfn=Exception::initialize
+calls=1 0
+0 2
+
+fl=
+fn=IO::read^
+0 21
+cfl=
+cfn=SystemCallError::initialize
+calls=1 0
+0 7
+cfl=
+cfn=Exception::exception
+calls=1 0
+0 1
+cfl=
+cfn=Exception::backtrace
+calls=1 0
+0 1
+
+fl=/Users/maksimpw/work/study/rails-optimization-task1/<internal:gc>
+fn=GC::disable^
+63 4
+
+fl=
+fn=IO::write
+0 14
+
+fl=
+fn=IO::puts
+0 3
+cfl=
+cfn=IO::write
+calls=1 0
+0 14
+
+fl=
+fn=Kernel::puts
+0 4
+cfl=
+cfn=IO::puts
+calls=1 0
+0 17
+
+fl=/Users/maksimpw/work/study/rails-optimization-task1/task-1.rb
+fn=Object::work
+17 10
+cfl=
+cfn=Kernel::puts
+calls=1 20
+20 21
+cfl=/Users/maksimpw/work/study/rails-optimization-task1/<internal:gc>
+cfn=GC::disable^
+calls=1 22
+22 4
+cfl=
+cfn=IO::read^
+calls=1 24
+24 31
+
+fl=/Users/maksimpw/work/study/rails-optimization-task1/ruby-prof_calltree.rb
+fn=[global]::
+11 8
+cfl=/Users/maksimpw/work/study/rails-optimization-task1/task-1.rb
+cfn=Object::work
+calls=1 11
+11 65
+