Skip to content

Latest commit

 

History

History
285 lines (194 loc) · 14.4 KB

File metadata and controls

285 lines (194 loc) · 14.4 KB

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

File.write('data/result.json', "#{report.to_json}\n") puts "MEMORY USAGE: %d MB" % (ps -o rss= -p #{Process.pid}.to_i / 1024)

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

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

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

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

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

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

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

Для того, чтобы понимать, дают ли мои изменения положительный эффект на быстродействие программы я придумал использовать такую метрику: объем памяти, используемой в процессе и в конце работы приложения

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

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

Feedback-Loop

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

  • сделать отчет с помощью команды make profile
  • найти точку роста
  • внести изменения в код в соответствии с найденной точкой роста
  • сделать отчет с помощью команды make profile
  • проанализовать повлияли ли изменения на занятую память при выполнении программы
  • запустить тесты
  • зафиксировать изменения при успешном прохождении

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

Для того, чтобы найти "точки роста" для оптимизации я воспользовался

  • memory_profiler
  • valgrind massif visualizer
  • stackprof
  • ruby_prof

Вот какие проблемы удалось найти и решить

Ваша находка №0

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

Это помогло мне оценить работу и зафиксировать первый результат по занимаемой памяти в конце работы программы

MEMORY USAGE: 2472 MB

Ваша находка №1

Профилировал программу с помощью ruby-profiler на размере файла 32_500 Взял такой размер исходя из корреляции, что этот файл меньше data_large.txt в ~10 раз data_large.txt профилировать не удалось, слишком много памяти отъел у ОС

Результаты ДО:

MEMORY USAGE: 151 MB
Total allocated: 46.84 MB (579519 objects)
Total retained:  16.13 MB (229869 objects)

Больше всего памяти отъедала строка кода cols = line.split(',') Проанализировав ситуацию, понял, что все дело в ',' и других строках Добавил # frozen_string_literal: true Этот комментарий сообщает ruby, что нужно вызвать freeze для всех строковых литералов, что помогает нам сэкономить используемую память

Полезные ссылки: Stackoverflow

Подсказка по логике при использовании frozen_string_literal:

# frozen_string_literal: true
"".frozen?
=> true
(+"").frozen?
=> false
"".dup.frozen?
=> false

Результаты ПОСЛЕ:

MEMORY USAGE: 119 MB
Total allocated: 42.30 MB (480316 objects)
Total retained:  16.13 MB (229868 objects)

Более точные результаты можно посмотреть в reports/memory-profiler/iteration_1

Ваша находка №2

Сделал отчет с помощью stackprof

Главная точка роста все еще String#split:

255021  (49.7%)      255021  (49.7%)     String#split

Убрать просто так string split у меня не получилось, поэтому пошел читать README

В README в плане работ написано, что нужно сделать программу в потоковом стиле Этот момент я упустил и решил наверстать в этой итерации

Никак не мог понять почему у меня не проходят тесты с JSON В итоге нашел, что при чтении строк учитывается еще и "\n" в конце строки С помощью аттрибута chomp: true избавился от этой проблемы и тесты стали проходить нормально

По отчетам stackprof программа работать быстрее не стала, но теперь она выполнена в потоковом стиле.

Ваша находка №3

Подготовка к профилированию

Хотел убедиться и посмотреть сколько памяти аллоцируется в течение всей работы программы Для этого решил использовать valgrind

Была ошибка при запуске build-docker.sh: Current requires cgo or $USER set in environment Решил ее, прописав явно export USER=$(id -un)

Стандартным скриптом не получилось запустить massif-visualizer в контейнере, выдавало ошибку:

qt.qpa.xcb: could not connect to display
qt.qpa.plugin: Could not load the Qt platform plugin "xcb" in "" even though it was found.
This application failed to start because no Qt platform plugin could be initialized. Reinstalling the application may fix this problem.

При этом все разрешения в настройках XQuartz я выдавал

В итоге нашел решение через запуск socat и использование DISPLAY=docker.for.mac.host.internal:0 Решение: Stackoverflow

Профилирование

С помощью valgrind понял, что в работе программы основная часть памяти аллоцируется сразу Вызовом ObjectSpace.each_object(String).count получил общее количество объектов строк конце работы програмы: 21197866

Хоть я и начал читать файл построчно в прошлой итерации, но все записи я вел в одном большом объекте Hash, который потом разом записывал в файл result.json

Изменения

Отказался от большого hash объекта report Перевел сохранение данных в потоковый стиль с помощью библиотеки oj Она позволяет потоково записывать json в файл

Результаты

После изменений программа стала потреблять меньше памяти. Итоги профилирования на размере файла 32_500 строк

Valgrind: Было: 47.2 Mib Стало: 36.1 Mib

Stackprof: Было: total samples: 512874 Стало: total samples: 477482

Ваша находка №4

Подготовка

Сделал автоматический сбор результатов всех профилировщиков в одном месте с помощью команды make profile

Сделал перенос результатов в отдельные папки, чтобы можно проанализировать результат работ на каждом этапе. Пример команды: make mv_reports step=iteration_4_before

Это должно сэкономить время на подготовку данных для профилирования

Профилирование

Профилировал с помощью memory_profiler

Результаты ДО:

Total allocated: 36.23 MB (476912 objects) Total retained: 25.15 kB (271 objects) allocated memory by class 15.73 MB String 13.13 MB Array 7.14 MB Hash

Изменения

Обнаружил в методе collect_data_for_user избыточное использование map

Стал сразу подготавливать данные time для collect_total_time, collect_longest_session, чтобы не вызывать излишние map для формирования массива time

Стал подготавливать данные browsers для collect_browsers, collect_used_ie, collect_always_used_chrome, чтобы не вызывать излишние map для формирования массива browsers

В методах collect_* убрал излишние вызовы map Поменял их на map!

Результаты

Результаты ПОСЛЕ:

Total allocated: 33.86 MB (460195 objects) Total retained: 25.56 kB (278 objects) allocated memory by class 16.32 MB String 10.18 MB Array 7.14 MB Hash

Выполнение программы стало аллоцировать меньше памяти за счет уменьшения выделяемой памяти на массивы

13.13 MB Array -> 10.18 MB Array

Ваша находка №5

Профилирование

Профилировал с помощью memory_profiler и stackprof graph

Результаты ДО:

Total allocated: 33.86 MB (460195 objects)
Total retained:  25.56 kB (278 objects)

allocated memory by class
-----------------------------------
  16.32 MB  String
  10.18 MB  Array
   7.14 MB  Hash

Изменения

Взор все еще цеплялся на line.split(',') Понял, что для user мне нужно знать только name Смысла хранить first_name и last_name для оптимизации не было В итоге сделал метод fetch_user_name, который вместо создания хеша стал присваивать user_name построчно из команды split Так же сделал break в fetch_user_name, когда все данные получены. Тем самым были убраны лишние итерации split

Метод parse_session тоже обновил, убрал лишние сохранения данных в хеш

Результаты

Результаты ПОСЛЕ:

Total allocated: 31.83 MB (445255 objects)
Total retained:  25.35 kB (276 objects)

allocated memory by class
-----------------------------------
  16.32 MB  String
   9.18 MB  Array
   6.30 MB  Hash

На этих изменениях смог сэкономить еще 2MB, но уже, по личным ощущениям, такой код fetch_user_name стало достаточно тяжело читать

Результаты

В результате проделанной оптимизации наконец удалось обработать файл с данными. Удалось улучшить метрику системы с 2370 МБ до 18 МБ и уложиться в заданный бюджет.

Результаты memory_profiler (файл data_32_500.txt)

ДО ПОСЛЕ
Total allocated 46.84 MB (579519 objects) 31.83 MB (445255 objects)
Total retained 16.13 MB (229869 objects) 25.35 kB (276 objects)

Результаты работы программы work.rb (файл data_large.txt)

ДО ПОСЛЕ
MEMORY USAGE 2370 MB 18 MB
TIME ~27 секунд ~12 секунд

Заметки

  • С заранее подготовленными скриптами в Makefile для генерации data files стало намного проще работать

Как пользоваться stackprof: Посмотреть репорт: stackprof reports/stackprof/report.dump Посмотреть репорт с учетом всех методов: stackprof reports/stackprof/report.dump

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

Для защиты от потери достигнутого прогресса при дальнейших изменениях программы были добавлены performance тесты на время исполнения программы