-
Notifications
You must be signed in to change notification settings - Fork 24
Trying to make script faster + case study #10
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
base: master
Are you sure you want to change the base?
Changes from all commits
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,78 @@ | ||
| # Case-study оптимизации | ||
|
|
||
| ## Актуальная проблема | ||
| В нашем проекте возникла серьёзная проблема. | ||
|
|
||
| Необходимо было обработать файл с данными, чуть больше ста мегабайт. | ||
|
|
||
| У нас уже была программа на `ruby`, которая умела делать нужную обработку. | ||
|
|
||
| Она успешно работала на файлах размером пару мегабайт, но для большого файла она работала слишком долго, и не было понятно, закончит ли она вообще работу за какое-то разумное время. | ||
|
|
||
| Я решила исправить эту проблему, оптимизировав эту программу. | ||
|
|
||
| ## Формирование метрики | ||
| Для того, чтобы понимать, дают ли мои изменения положительный эффект на быстродействие программы я придумала использовать такие метрики: | ||
| - замер времени выполнения скрипта при помощи вызова Benchmark.realtime; | ||
| - замер использования выделяемой памяти для процесса. | ||
|
|
||
| Для замеров берем часть обрабатываемого файла, размером 1 Мб. | ||
|
|
||
| ## Гарантия корректности работы оптимизированной программы | ||
| Программа поставлялась с тестом. Выполнение этого теста позволяет не допустить изменения логики программы при оптимизации. | ||
|
|
||
| ## Feedback-Loop | ||
| Для того, чтобы иметь возможность быстро проверять гипотезы я выстроила эффективный `feedback-loop`, который позволил мне получать обратную связь по эффективности сделанных изменений. | ||
|
|
||
| Вот как я построила `feedback_loop`: | ||
| - запускаем скрипт с подключением инструмента профилирования; | ||
| - на основе результатов вносим изменения в код; | ||
| - проверяем основную метрику, что внесенное изменение не приводит к регрессии. | ||
|
|
||
| ## Вникаем в детали системы, чтобы найти 20% точек роста | ||
| Для того, чтобы найти "точки роста" для оптимизации я воспользовалась следующими инструментами: stackprof, stackprof, ruby-prof, qcachegrind. | ||
|
|
||
| Вот какие проблемы удалось найти и решить: | ||
|
|
||
| ### Находка №1 | ||
| При помощи библиотеки stackprof определили, что в методе work в цикле обработки строк из файла при сборе массива sessions происходит большое кол-во аллокаций, так как для добавления нового элемента в массив каждый раз создавался новый массив из одного элемента. | ||
| Небольшое изменение кода позволило снизить потребляемую процессом память с ~118 Мб до ~83 Мб. | ||
| На скорость работы скрипта это практически не повлияло (время уменьшилось в размерах измерительной погрешности). | ||
|
|
||
| На основе данной оптимизации в двух других местах скрипта были заменены подобные языковые конструкции, что позволило сократить используемую память ~56Мб. | ||
|
|
||
| ### Находка №2 | ||
| При запуске memory_profiler становится очевидным, что происходит постоянное создание одинаковых строк, которые являются ключами в хэшах. | ||
| Заменим строки на символы. Попутно, убрав из хэшей пользователя и сессия не используемые данные. | ||
| Эта оптимизация позволила сократить время работы скрипта до 11.21 сек. | ||
|
|
||
| ### Находка №3 | ||
| При следующем запуске memory_profiler'а обратила внимание, что самое большое выделение памяти идёт на строка выбора сессий для пользователя из общего массива. | ||
| Решение этой проблемы - изначально хранить сессии в хэше с ключами - id пользователей. | ||
| Изменение в хранении сессий вынудило так же перенести сбор наименований браузеров в основной итератор по строкам файла. | ||
| Резальтатом данного рефакторинга стало стремительное уменьшение времени работы скрипта. | ||
| Теперь файл в среднем обрабатывается ~0.42 сек при потреблении ~39 Мб памяти. | ||
|
|
||
| ### Находка №4 | ||
| Запустила ruby-prof+qcachegrind. Стало очевидно, что наибольшее число аллокаций происходит при переборе массивов при вызове метода collect_stats_from_users. Проблема в том, что метод вызывается 7 раз для сбора информации, когда можно всё собрать за один проход. Тем более, что выше уже есть перебор всех пользователей для сбора user_objects. Гипотиза - переписать сбор данных в один проход по массиву пользователей. | ||
| Думала, что данная оптимизация принесёт больше пользы. | ||
|
Author
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Хм, мда. А map'ы то я не убрала 🤔 Видимо, останутся на следующую порцию оптимизаций. |
||
| Теперь файл в среднем обрабатывается ~0.41 сек при потреблении ~34 Мб памяти. | ||
| То есть улучшения в рамках погрешности. | ||
| Возможно как-то связано с использованием патченой версии руби для этой итерации. | ||
|
Owner
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Измерения лучше проводить в равных условиях. |
||
|
|
||
| ### Находка №5 | ||
| Снова запустила stackprof. Наибольшее кол-во аллокаций - строка с манипуляциями с датой. | ||
| Перенесла конвертацию даты в необходимый формат в метод парсинга данных. | ||
| Сам метод сбора данных по датам в отчёт стал требовать меньшего кол-ва аллокаций, но улучшения показателей скорости работы и занимаемой памяти в рамках погрешности, что странно. | ||
|
|
||
| ### Находка №6 | ||
| Заменила чтение файла на построчное. | ||
| Улучшения показателей скорости работы и занимаемой памяти в рамках погрешности. Возможно, это из-за малого размера файла с данными. И на полном размере разница была бы ощутима. | ||
|
|
||
| ## Результаты | ||
| В результате проделанной оптимизации наконец удалось обработать файл с данными. | ||
| Удалось улучшить метрику системы при обработке файла объёмом 1Мб с 14.97 сек, до обработки за ~0.41 сек. | ||
| Полный файл с данными обрабатывается за 78.09 сек, при этом выполнение скрипта потребляет 2894 Мб памяти. | ||
|
|
||
| ## Защита от регресса производительности | ||
| Для защиты от потери достигнутого прогресса при дальнейших изменениях программы сделано хммм... ничего? | ||
|
Owner
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Тут предполагалось написать тестик, но можно в ДЗ №2 |
||
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -4,55 +4,51 @@ | |
| require 'pry' | ||
| require 'date' | ||
| require 'minitest/autorun' | ||
| require 'benchmark' | ||
| # require 'stackprof' | ||
|
|
||
| class User | ||
| attr_reader :attributes, :sessions | ||
|
|
||
| def initialize(attributes:, sessions:) | ||
| @attributes = attributes | ||
| @sessions = sessions | ||
| end | ||
| end | ||
| SEPARATOR = ','.freeze | ||
|
Owner
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Можно ещё было заюзать волшебный коммент |
||
| USER_STR = 'user'.freeze | ||
| SESSION_STR = 'session'.freeze | ||
| INTERNET_EXPLORER = /INTERNET EXPLORER/.freeze | ||
| CHROME = /CHROME/.freeze | ||
|
|
||
| def parse_user(user) | ||
| fields = user.split(',') | ||
| parsed_result = { | ||
| 'id' => fields[1], | ||
| 'first_name' => fields[2], | ||
| 'last_name' => fields[3], | ||
| 'age' => fields[4], | ||
| fields = user.split(SEPARATOR) | ||
| { | ||
| id: fields[1], | ||
| first_name: fields[2], | ||
| last_name: fields[3] | ||
| } | ||
| end | ||
|
|
||
| def parse_session(session) | ||
| fields = session.split(',') | ||
| parsed_result = { | ||
| 'user_id' => fields[1], | ||
| 'session_id' => fields[2], | ||
| 'browser' => fields[3], | ||
| 'time' => fields[4], | ||
| 'date' => fields[5], | ||
| fields = session.split(SEPARATOR) | ||
| { | ||
| user_id: fields[1], | ||
| browser: fields[3], | ||
| time: fields[4], | ||
| date: Date.parse(fields[5]).iso8601 | ||
| } | ||
| 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)) | ||
| end | ||
| end | ||
|
|
||
| def work | ||
| file_lines = File.read('data.txt').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' | ||
| sessions = {} | ||
| sessions_count = 0 | ||
| unique_browsers = [] | ||
|
|
||
| File.open('data_large.txt', 'r').each do |line| | ||
| cols = line.split(SEPARATOR) | ||
|
|
||
| if cols[0] == USER_STR | ||
| users << parse_user(line) | ||
| elsif cols[0] == SESSION_STR | ||
| sessions[cols[1].to_sym] ||= [] | ||
| sessions[cols[1].to_sym] << parse_session(line) | ||
| unique_browsers << cols[3] unless unique_browsers.include?(cols[3]) | ||
| sessions_count += 1 | ||
| end | ||
| end | ||
|
|
||
| # Отчёт в json | ||
|
|
@@ -74,74 +70,77 @@ def work | |
|
|
||
| report[:totalUsers] = users.count | ||
|
|
||
| # Подсчёт количества уникальных браузеров | ||
| uniqueBrowsers = [] | ||
| sessions.each do |session| | ||
| browser = session['browser'] | ||
| uniqueBrowsers += [browser] if uniqueBrowsers.all? { |b| b != browser } | ||
| end | ||
|
|
||
| report['uniqueBrowsersCount'] = uniqueBrowsers.count | ||
| report[:uniqueBrowsersCount] = unique_browsers.count | ||
|
|
||
| report['totalSessions'] = sessions.count | ||
| report[:totalSessions] = sessions_count | ||
|
|
||
| report['allBrowsers'] = | ||
| sessions | ||
| .map { |s| s['browser'] } | ||
| .map { |b| b.upcase } | ||
| .sort | ||
| .uniq | ||
| .join(',') | ||
| report[:allBrowsers] = | ||
| unique_browsers | ||
| .map!(&:upcase) | ||
| .sort! | ||
| .join(SEPARATOR) | ||
|
|
||
| # Статистика по пользователям | ||
| users_objects = [] | ||
| report[:usersStats] = {} | ||
|
|
||
| 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[user[:id].to_sym] | ||
| user_key = "#{user[:first_name]} #{user[:last_name]}" | ||
| report[:usersStats][user_key.to_sym] = { | ||
| # Собираем количество сессий по пользователям | ||
| sessionsCount: user_sessions.count, | ||
| # Собираем количество времени по пользователям | ||
| totalTime: user_sessions.map { |s| s[:time] }.map(&:to_i).sum.to_s + ' min.', | ||
| # Выбираем самую длинную сессию пользователя | ||
| longestSession: user_sessions.map { |s| s[:time] }.map(&:to_i).max.to_s + ' min.', | ||
| # Браузеры пользователя через запятую | ||
| browsers: user_sessions.map { |s| s[:browser] }.map(&:upcase).sort.join(', '), | ||
| # Хоть раз использовал IE? | ||
| usedIE: user_sessions.map { |s| s[:browser] }.any? { |b| b.upcase =~ INTERNET_EXPLORER }, | ||
| # Всегда использовал только Chrome? | ||
| alwaysUsedChrome: user_sessions.map { |s| s[:browser] }.all? { |b| b.upcase =~ CHROME }, | ||
| # Даты сессий через запятую в обратном порядке в формате iso8601 | ||
| dates: user_sessions.map { |s| s[:date] }.sort.reverse | ||
| } | ||
| end | ||
|
|
||
| report['usersStats'] = {} | ||
|
|
||
| # Собираем количество сессий по пользователям | ||
| collect_stats_from_users(report, users_objects) do |user| | ||
| { 'sessionsCount' => user.sessions.count } | ||
| end | ||
| File.write('result.json', "#{report.to_json}\n") | ||
| 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 | ||
| def print_memory_usage | ||
| "%d MB" % (`ps -o rss= -p #{Process.pid}`.to_i / 1024) | ||
| end | ||
|
|
||
| # Выбираем самую длинную сессию пользователя | ||
| 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 | ||
| puts "Start" | ||
| time = Benchmark.realtime do | ||
| puts "rss before: #{print_memory_usage}" | ||
| # result = RubyProf.profile do | ||
| work | ||
| # end | ||
| # report.pretty_print(scale_bytes: true) | ||
| puts "rss after: #{print_memory_usage}" | ||
| end | ||
|
|
||
| # Браузеры пользователя через запятую | ||
| collect_stats_from_users(report, users_objects) do |user| | ||
| { 'browsers' => user.sessions.map {|s| s['browser']}.map {|b| b.upcase}.sort.join(', ') } | ||
| end | ||
| puts "Finish in #{time.round(2)}" | ||
|
|
||
| # Хоть раз использовал IE? | ||
| collect_stats_from_users(report, users_objects) do |user| | ||
| { 'usedIE' => user.sessions.map{|s| s['browser']}.any? { |b| b.upcase =~ /INTERNET EXPLORER/ } } | ||
| end | ||
| # printer = RubyProf::CallTreePrinter.new(result) | ||
| # printer.print(:path => ".", :profile => 'profile') | ||
| # printer = RubyProf::FlatPrinter.new(result) | ||
| # printer.print(File.open("ruby_prof_flat_allocations_profile.txt", "w+")) | ||
| # printer = RubyProf::GraphHtmlPrinter.new(result) | ||
| # printer.print(File.open("ruby_prof_graph_allocations_profile.html", "w+")) | ||
|
|
||
| # Всегда использовал только Chrome? | ||
| collect_stats_from_users(report, users_objects) do |user| | ||
| { 'alwaysUsedChrome' => user.sessions.map{|s| s['browser']}.all? { |b| b.upcase =~ /CHROME/ } } | ||
| end | ||
| # StackProf.run(mode: :object, out: 'tmp/stackprof.dump', raw: true) do | ||
| # work | ||
| # end | ||
|
|
||
| # Даты сессий через запятую в обратном порядке в формате 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 | ||
| # profile_data = StackProf.run(mode: :object) do | ||
| # work | ||
| # end | ||
|
|
||
| File.write('result.json', "#{report.to_json}\n") | ||
| end | ||
| # StackProf::Report.new(profile_data).print_text | ||
| # StackProf::Report.new(profile_data).print_method(/work/) | ||
| # StackProf::Report.new(profile_data).print_graphviz | ||
|
|
||
| class TestMe < Minitest::Test | ||
| def setup | ||
|
|
||
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
А какое было изначально?