Skip to content

Commit d118968

Browse files
committed
chore: perform optimizations
1 parent 3f9982d commit d118968

File tree

5 files changed

+172
-77
lines changed

5 files changed

+172
-77
lines changed

README.md

Lines changed: 8 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -94,17 +94,17 @@ head -n N data_large.txt > dataN.txt # create smaller file from larger (take N f
9494
## Checklist
9595
Советую использовать все рассмотренные в лекции инструменты хотя бы по разу - попрактикуйтесь с ними, научитесь с ними работать.
9696

97-
- [ ] Прикинуть зависимость времени работы програмы от размера обрабатываемого файла
98-
- [ ] Построить и проанализировать отчёт `ruby-prof` в режиме `Flat`;
99-
- [ ] Построить и проанализировать отчёт `ruby-prof` в режиме `Graph`;
97+
- [x] Прикинуть зависимость времени работы програмы от размера обрабатываемого файла
98+
- [x] Построить и проанализировать отчёт `ruby-prof` в режиме `Flat`;
99+
- [x] Построить и проанализировать отчёт `ruby-prof` в режиме `Graph`;
100100
- [ ] Построить и проанализировать отчёт `ruby-prof` в режиме `CallStack`;
101101
- [ ] Построить и проанализировать отчёт `ruby-prof` в режиме `CallTree` c визуализацией в `QCachegrind`;
102-
- [ ] Построить дамп `stackprof` и проанализировать его с помощью `CLI`
103-
- [ ] Построить дамп `stackprof` в `json` и проанализировать его с помощью `speedscope.app`
104-
- [ ] Профилировать работающий процесс `rbspy`;
102+
- [x] Построить дамп `stackprof` и проанализировать его с помощью `CLI`
103+
- [x] Построить дамп `stackprof` в `json` и проанализировать его с помощью `speedscope.app`
104+
- [x] Профилировать работающий процесс `rbspy`;
105105
- [ ] Добавить в программу `ProgressBar`;
106-
- [ ] Постараться довести асимптотику до линейной и проверить это тестом;
107-
- [ ] Написать простой тест на время работы: когда вы придёте к оптимизированному решению, замерьте, сколько оно будет работать на тестовом объёме данных; и напишите тест на то, что это время не превышается (чтобы не было ложных срабатываний, задайте время с небольшим запасом);
106+
- [x] Постараться довести асимптотику до линейной и проверить это тестом;
107+
- [x] Написать простой тест на время работы: когда вы придёте к оптимизированному решению, замерьте, сколько оно будет работать на тестовом объёме данных; и напишите тест на то, что это время не превышается (чтобы не было ложных срабатываний, задайте время с небольшим запасом);
108108

109109
### Главное
110110
Нужно потренироваться методично работать по схеме с фидбек-лупом:

case-study.md

Lines changed: 80 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,80 @@
1+
# Case-study оптимизации
2+
3+
## Актуальная проблема
4+
В нашем проекте возникла серьёзная проблема.
5+
6+
Необходимо было обработать файл с данными, чуть больше ста мегабайт.
7+
8+
У нас уже была программа на `ruby`, которая умела делать нужную обработку.
9+
10+
Она успешно работала на файлах размером пару мегабайт, но для большого файла она работала слишком долго, и не было понятно, закончит ли она вообще работу за какое-то разумное время.
11+
12+
Я решил исправить эту проблему, оптимизировав эту программу.
13+
14+
## Формирование метрики
15+
Для того, чтобы понимать, дают ли мои изменения положительный эффект на быстродействие программы я придумал использовать такую метрику: время выполнения программы.
16+
17+
Сначала сделал гипотезу о том, что асимптотика времени работы программы квадратичная: отношение количества записей к времени выполнения в секундах: 100000/115 750000/61 50000/26, 25000/6). Подтвердил эту гипотезу с помощью теста rspec-benchmark.
18+
В таком случае для полного объема понадобится 4.7 дней.
19+
20+
## Гарантия корректности работы оптимизированной программы
21+
Программа поставлялась с тестом. Выполнение этого теста в фидбек-лупе позволяет не допустить изменения логики программы при оптимизации.
22+
23+
## Feedback-Loop
24+
Для того, чтобы иметь возможность быстро проверять гипотезы я выстроил эффективный `feedback-loop`, который позволил мне получать обратную связь по эффективности сделанных изменений за *время, которое у вас получилось*
25+
26+
Вот как я построил `feedback_loop`: профилирование - изменение кода - тестирование – бенчмаркинг – откат при отсутствии разницы от оптимизации/сохранение результатов
27+
28+
## Вникаем в детали системы, чтобы найти главные точки роста
29+
Для того, чтобы найти "точки роста" для оптимизации я воспользовался rbspy
30+
31+
Вот какие проблемы удалось найти и решить
32+
33+
### Находка №1
34+
- rbspy показал `83.55 83.55 block (2 levels) in work - task-1.rb:101`: вызов `sessions.filter {}` на каждой итерации по `users.each`;
35+
- перед `users.each` сгруппировал `sessions_by_user = sessions.group_by { |session| session['user_id'] }`, в `each` использовал как `sessions_by_user[user['id']] || []`
36+
- время выполнения программы для 100к входных данных сократилось с 115с до 4с
37+
- исправленная проблема перестала быть главной точкой роста, rbspy показал, что теперь это `98.49 100.00 block in work - task-1.rb:56`
38+
39+
### Находка №2
40+
- stackprof cli показал `7126 (99.4%) 11 (0.2%) Array#each`, он вызывается несколько раз, наибольшее `6504 ( 91.3%) Object#work]`. Поскольку rbspy указывал на `task-1.rb:56`, что является `end` `each` блока, пробую вынести этот`each` в отдельный метод `parse_file`и подтвердить гипотезу, которая и подтверждается: `5765 (99.8%) 5525 (95.7%) Object#parse_file`. Теперь нужно разобраться, какая именно операция в этом блоке `each` требует оптимизации, `stackprof stackprof.dump --method Object#parse_file` показывает, что это заполнение массива сессий: `5261 (93.2%) / 5133 (90.9%) | 52 | sessions = sessions + [parse_session(line)] if cols[0] == 'session'`.
41+
- вместо `sessions = sessions + [parse_session(line)] if cols[0] == 'session'` использую `sessions << parse_session(line) if cols[0] == 'session'`. аналогично для `users`
42+
- время выполнения программы для 500к входных данных сократилось с 100с до 13с
43+
- исправленная проблема перестала быть главной точкой роста, stackprof cli показал, что теперь это `558 (100.0%) 202 (36.2%) Object#work`
44+
45+
### Находка №3
46+
- `ruby-prof` в режиме `Graph` показывает, что точкой роста является `25.55% 25.55% 8.23 8.23 0.00 0.00 154066 Array#+` в `8.23 8.23 0.00 0.00 154066/154066 Array#each`. под это описания подходит 108 строка.
47+
- вместо `users_objects = users_objects + [user_object]` используем `users_objects << [user_object]`
48+
- время выполнения программы для 500к входных данных сократилось с 12с до с 6c
49+
- исправленная проблема перестала быть главной точкой роста, ruby prof показал, что теперь это `66.16% 26.52% 13.47 5.40 0.00 8.07 500000 Array#all?`
50+
51+
### Находка №3
52+
- `ruby-prof` в режиме `Graph` показывает, что точкой роста является `25.55% 25.55% 8.23 8.23 0.00 0.00 154066 Array#+` в `8.23 8.23 0.00 0.00 154066/154066 Array#each`. под это описания подходит 108 строка.
53+
- вместо `users_objects = users_objects + [user_object]` используем `users_objects << [user_object]`
54+
- время выполнения программы для 500к входных данных сократилось с 12с до с 6c
55+
- исправленная проблема перестала быть главной точкой роста, ruby prof показал, что теперь это `66.16% 26.52% 13.47 5.40 0.00 8.07 500000 Array#all?`
56+
57+
### Находка №4
58+
- `ruby-prof` в режиме `Graph` показывает, что точкой роста является `8.03 5.25 0.00 2.78 42580848/42580848 BasicObject#!= 85` в `66.16% 26.52% 13.47 5.40 0.00 8.07 500000 Array#all?`.
59+
- вместо `if uniqueBrowsers.all? { |b| b != browser }` используем `unless uniqueBrowsers.include?(browser)`
60+
- время выполнения программы для 500к входных данных сократилось с 6с до с 5c
61+
- исправленная проблема перестала быть главной точкой роста, ruby prof показал, что теперь это `66.16% 26.52% 13.47 5.40 0.00 8.07 500000 Array#all?`
62+
63+
### Находка №5
64+
- `ruby-prof` в режиме `Graph` показывает, что точкой роста является `2.65 0.81 0.00 1.84 846263/846265 Array#map 120` в `94.64% 22.99% 7.22 1.75 0.00 5.47 11 Array#each`. Больше всего вызовов из `Object#collect_stats_from_users`
65+
- объединяем все блоки вызова `collect_stats_from_users` в один
66+
- время выполнения программы для 1кк входных данных сократилось с 12с до с 10c
67+
- исправленная проблема перестала быть главной точкой роста, ruby prof показал, что теперь это `27.07% 16.32% 3.99 2.41 0.00 1.58 846230 <Class::Date>#parse`
68+
69+
### Находка №5
70+
- `ruby-prof` в режиме `Graph` показывает, что точкой роста является `27.07% 16.32% 3.99 2.41 0.00 1.58 846230 <Class::Date>#parse`, это строка `user.sessions.map{|s| s['date']}.map {|d| Date.parse(d)}.sort.reverse.map { |d| d.iso8601 }`
71+
- вместо `Date.parse(d)` используем `Date.strptime(d, '%Y-%m-%d')` (заранее известен формат). Даты часто повторяются, используем мемоизацию для уже распаршенных дат.
72+
- время выполнения программы для 1кк входных данных сократилось с 10с до с 7.7c
73+
- исправленная проблема перестала быть главной точкой роста.
74+
75+
## Результаты
76+
В результате проделанной оптимизации наконец удалось обработать файл с данными.
77+
Удалось улучшить метрику системы с 4.7 дней до 13 секунд и уложиться в заданный бюджет.
78+
79+
## Защита от регрессии производительности
80+
Для защиты от потери достигнутого прогресса при дальнейших изменениях программы добавил два теста: прогон на полных данных до 15 секунд, проверка на линейную асимптотику

task-1.rb

Lines changed: 26 additions & 69 deletions
Original file line numberDiff line numberDiff line change
@@ -3,7 +3,6 @@
33
require 'json'
44
require 'pry'
55
require 'date'
6-
require 'minitest/autorun'
76

87
class User
98
attr_reader :attributes, :sessions
@@ -44,15 +43,15 @@ def collect_stats_from_users(report, users_objects, &block)
4443
end
4544

4645
def work
47-
file_lines = File.read('data.txt').split("\n")
46+
file_lines = File.read('data.txt').split("\n", 1_000_000)
4847

4948
users = []
5049
sessions = []
5150

5251
file_lines.each do |line|
5352
cols = line.split(',')
54-
users = users + [parse_user(line)] if cols[0] == 'user'
55-
sessions = sessions + [parse_session(line)] if cols[0] == 'session'
53+
users << parse_user(line) if cols[0] == 'user'
54+
sessions << parse_session(line) if cols[0] == 'session'
5655
end
5756

5857
# Отчёт в json
@@ -78,7 +77,7 @@ def work
7877
uniqueBrowsers = []
7978
sessions.each do |session|
8079
browser = session['browser']
81-
uniqueBrowsers += [browser] if uniqueBrowsers.all? { |b| b != browser }
80+
uniqueBrowsers += [browser] unless uniqueBrowsers.include?(browser)
8281
end
8382

8483
report['uniqueBrowsersCount'] = uniqueBrowsers.count
@@ -96,81 +95,39 @@ def work
9695
# Статистика по пользователям
9796
users_objects = []
9897

98+
sessions_by_user = sessions.group_by { |session| session['user_id'] }
9999
users.each do |user|
100100
attributes = user
101-
user_sessions = sessions.select { |session| session['user_id'] == user['id'] }
101+
user_sessions = sessions_by_user[user['id']] || []
102102
user_object = User.new(attributes: attributes, sessions: user_sessions)
103-
users_objects = users_objects + [user_object]
103+
users_objects << user_object
104104
end
105105

106106
report['usersStats'] = {}
107107

108-
# Собираем количество сессий по пользователям
109108
collect_stats_from_users(report, users_objects) do |user|
110-
{ 'sessionsCount' => user.sessions.count }
111-
end
112-
113-
# Собираем количество времени по пользователям
114-
collect_stats_from_users(report, users_objects) do |user|
115-
{ 'totalTime' => user.sessions.map {|s| s['time']}.map {|t| t.to_i}.sum.to_s + ' min.' }
116-
end
117-
118-
# Выбираем самую длинную сессию пользователя
119-
collect_stats_from_users(report, users_objects) do |user|
120-
{ 'longestSession' => user.sessions.map {|s| s['time']}.map {|t| t.to_i}.max.to_s + ' min.' }
121-
end
122-
123-
# Браузеры пользователя через запятую
124-
collect_stats_from_users(report, users_objects) do |user|
125-
{ 'browsers' => user.sessions.map {|s| s['browser']}.map {|b| b.upcase}.sort.join(', ') }
126-
end
127-
128-
# Хоть раз использовал IE?
129-
collect_stats_from_users(report, users_objects) do |user|
130-
{ 'usedIE' => user.sessions.map{|s| s['browser']}.any? { |b| b.upcase =~ /INTERNET EXPLORER/ } }
131-
end
132-
133-
# Всегда использовал только Chrome?
134-
collect_stats_from_users(report, users_objects) do |user|
135-
{ 'alwaysUsedChrome' => user.sessions.map{|s| s['browser']}.all? { |b| b.upcase =~ /CHROME/ } }
136-
end
137-
138-
# Даты сессий через запятую в обратном порядке в формате iso8601
139-
collect_stats_from_users(report, users_objects) do |user|
140-
{ 'dates' => user.sessions.map{|s| s['date']}.map {|d| Date.parse(d)}.sort.reverse.map { |d| d.iso8601 } }
109+
{
110+
# Собираем количество сессий по пользователям
111+
'sessionsCount' => user.sessions.count,
112+
# Собираем количество времени по пользователям
113+
'totalTime' => user.sessions.map {|s| s['time']}.map {|t| t.to_i}.sum.to_s + ' min.',
114+
# Выбираем самую длинную сессию пользователя
115+
'longestSession' => user.sessions.map {|s| s['time']}.map {|t| t.to_i}.max.to_s + ' min.',
116+
# Браузеры пользователя через запятую
117+
'browsers' => user.sessions.map {|s| s['browser']}.map {|b| b.upcase}.sort.join(', '),
118+
# Хоть раз использовал IE?
119+
'usedIE' => user.sessions.map{|s| s['browser']}.any? { |b| b.upcase =~ /INTERNET EXPLORER/ },
120+
# Всегда использовал только Chrome?
121+
'alwaysUsedChrome' => user.sessions.map{|s| s['browser']}.all? { |b| b.upcase =~ /CHROME/ },
122+
# Даты сессий через запятую в обратном порядке в формате iso8601
123+
'dates' => user.sessions.map{|s| s['date']}.map {|d| parse_date(d)}.sort.reverse.map { |d| d.iso8601 },
124+
}
141125
end
142126

143127
File.write('result.json', "#{report.to_json}\n")
144128
end
145129

146-
class TestMe < Minitest::Test
147-
def setup
148-
File.write('result.json', '')
149-
File.write('data.txt',
150-
'user,0,Leida,Cira,0
151-
session,0,0,Safari 29,87,2016-10-23
152-
session,0,1,Firefox 12,118,2017-02-27
153-
session,0,2,Internet Explorer 28,31,2017-03-28
154-
session,0,3,Internet Explorer 28,109,2016-09-15
155-
session,0,4,Safari 39,104,2017-09-27
156-
session,0,5,Internet Explorer 35,6,2016-09-01
157-
user,1,Palmer,Katrina,65
158-
session,1,0,Safari 17,12,2016-10-21
159-
session,1,1,Firefox 32,3,2016-12-20
160-
session,1,2,Chrome 6,59,2016-11-11
161-
session,1,3,Internet Explorer 10,28,2017-04-29
162-
session,1,4,Chrome 13,116,2016-12-28
163-
user,2,Gregory,Santos,86
164-
session,2,0,Chrome 35,6,2018-09-21
165-
session,2,1,Safari 49,85,2017-05-22
166-
session,2,2,Firefox 47,17,2018-02-02
167-
session,2,3,Chrome 20,84,2016-11-25
168-
')
169-
end
170-
171-
def test_result
172-
work
173-
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"
174-
assert_equal expected_result, File.read('result.json')
175-
end
130+
def parse_date(date)
131+
@dates ||= {}
132+
@dates[date] || (@dates[date] = Date.strptime(date, '%Y-%m-%d'))
176133
end

0 commit comments

Comments
 (0)