|
18 | 18 | Программа поставлялась с тестом. Выполнение этого теста в фидбек-лупе позволяет не допустить изменения логики программы при оптимизации. |
19 | 19 |
|
20 | 20 | ## Feedback-Loop |
21 | | -Для того, чтобы иметь возможность быстро проверять гипотезы я выстроил эффективный `feedback-loop`, который позволил мне получать обратную связь по эффективности сделанных изменений за *время, которое у вас получилось* |
| 21 | +Для того, чтобы иметь возможность быстро проверять гипотезы я выстроил эффективный `feedback-loop`, который позволил мне получать обратную связь по эффективности сделанных изменений за 20-30 секунд. |
22 | 22 |
|
23 | 23 | Вот как я построил `feedback_loop`: |
24 | 24 | Измерив время выполнения программы на разном объеме дынных, алгоритмическая сложность получилась O(n^2), т.е. время выполнения в зависимости от объема данных возрастает квадратично. |
|
29 | 29 | - С помощью профилировщика найти главную точку роста (Профилируем с выключенным GC предварительно прогрев кеши) |
30 | 30 | - Внести оптимизационные правки |
31 | 31 | - С помощью профилировщика проверить есть ли улучшения |
32 | | -- Запустить тест, проверить если улучшения есть, если да то закоммитить. |
| 32 | +- Запустить тест, проверить, если улучшения есть тогда закоммитить. |
33 | 33 |
|
34 | 34 | ## Вникаем в детали системы, чтобы найти главные точки роста |
35 | 35 | Для того, чтобы найти "точки роста" для оптимизации я воспользовался rbspy (удобно, потому что встроен в rubymine), stackprof и ruby-prof в разных режимах отчетов |
|
46 | 46 | - Заменил перебор всех сессий на хэш с группированные данных по user_id. В данном конкретном месте алгоритмическая сложность с O(n) изменилась на O(1) |
47 | 47 | - Метрика кратно уменьшилась при прогоне теста на перфоманс с средних 5 сек. до 0.4 сек. Это и было самым узким местом программы по всей видимости. |
48 | 48 | - Повторный запуск профилировщика показал, что вместо 89,15% теперь это место занимает 0.3%. |
| 49 | +- В отчетах профилировщика эта точка роста перестала быть главной. |
49 | 50 |
|
50 | 51 | ### Ваша находка №2 |
51 | 52 | - Профилировщики указали на следующую точку роста: |
|
56 | 57 | - Заменил `sessions = sessions + [parse_session(line)] if cols[0] == 'session'` на `sessions = sessions << parse_session(line) if cols[0] == 'session'` |
57 | 58 | Известная проблема в ruby. Оператор << позволяет не создавать новую переменную каждый раз, а писать все в существующую. |
58 | 59 | - При прогоне теста, среднее значение метрики упало с 0.4 сек. до 0.25 сек. |
| 60 | +- В отчетах профилировщика эта точка роста перестала быть главной. |
59 | 61 |
|
60 | 62 | ### Ваша находка №3 |
61 | 63 | - Ради интереса прогнал тесты с разным объемом данных, 20к, 40к, 80к и так далее. В том числе и на полном файле. |
|
67 | 69 | ``` |
68 | 70 | - Оптимизировал блок each, заменил '+' на Set. |
69 | 71 | - При прогоне теста, среднее значение метрики упало с 0.25 сек. до 0.18 сек. |
| 72 | +- В отчетах профилировщика эта точка роста перестала быть главной. |
70 | 73 |
|
71 | 74 | ### Ваша находка №4 |
72 | | -- Попробовал увеличить кол-во данных, чтобы проще было увидеть проблематику до 100_000 строк. |
73 | | -- По отчетам нашел новую точку роста, это метод `collect_stats_from_users`, он аффектит на два проблемных места сразу |
| 75 | +- По отчетам профилировщиков нашел новую точку роста, это метод `def collect_stats_from_users` |
74 | 76 | ``` |
75 | 77 | %Total %Self Total Self Wait Child Calls Name |
76 | 78 | 89.28% 23.89% 1.43 0.38 0.00 1.05 10 Array#each |
77 | 79 | ``` |
78 | | -- Оптимизировал, а именно избавился от collect_stats_from_users и начал подготавливать данные за один проход. |
| 80 | +- Оптимизировал, а именно избавился от collect_stats_from_users и начал подготавливать данные для отчета за один проход. |
79 | 81 | - При прогоне теста, среднее значение метрики упало с 0.18 сек. до 0.14 сек. на 20_000 строк. |
| 82 | +- В отчетах профилировщика эта точка роста перестала быть главной. |
80 | 83 |
|
| 84 | +### Ваша находка №5 |
| 85 | +- stackprof показал на точку роста на строке с парсингом даты `dates = sessions.map { |s| Date.parse(s['date']) }` |
81 | 86 |
|
| 87 | +``` |
| 88 | + %Total %Self Total Self Wait Child Calls Name |
| 89 | + 28.57% 16.02% 0.09 0.05 0.00 0.04 16954 <Class::Date>#parse |
| 90 | +``` |
| 91 | +- Поправил, Date.parse лишняя обработка. |
| 92 | +- Среднее значение метрики упало с 0.14 до 0.2 сек. |
| 93 | +- В отчетах профилировщика эта точка роста перестала быть главной. |
| 94 | + |
| 95 | +### Ваша находка №6 |
| 96 | +- Уже правктически выполняется бюджет прогона файла data_large.txt, но профилировщик подсветил еще одну точку роста: |
| 97 | +``` |
| 98 | +%Total %Self Total Self Wait Child Calls Name |
| 99 | +30.73% 30.73% 0.06 0.06 0.00 0.00 40001 String#split |
| 100 | +``` |
| 101 | +- Выпилил лишние String.split |
| 102 | +- Так как выполнение теста на 20_000 строк очень мало, увеличил файл до 60_000 строк. |
| 103 | +Среднее значение прогода 60_000 строк = 0.3 сек. |
| 104 | +- Среднее значение прогона всего файла с ~30 сек. упало до 27 сек. |
| 105 | +- В отчетах профилировщика эта точка роста перестала быть главной. |
| 106 | +- Вижу еще несколько точек роста, но решил на этом остановится =) |
| 107 | + |
| 108 | +## Результаты |
| 109 | +В результате проделанной оптимизации наконец удалось обработать файл с данными. |
| 110 | +Удалось улучшить метрику системы на 20_000 строк с 5 сек. до 0.1 сек., на 60_000 строк с 72 сек. до 0.3 сек, |
| 111 | +на полном объеме данных уменьшить время выполнения до 27 сек. и уложиться в заданный бюджет. |
| 112 | +Так же был переписан тест с minitest на rspec и вынесен в отдельный файл. |
| 113 | + |
| 114 | +## Защита от регрессии производительности |
| 115 | +Для защиты от потери достигнутого прогресса при дальнейших изменениях программы было написано два performance теста, один для проверки на 60_000 строках, |
| 116 | +второй на полном объеме файла data_large.txt |
0 commit comments