Skip to content

Used test-prof #44

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

Open
wants to merge 1 commit into
base: master
Choose a base branch
from
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
49 changes: 49 additions & 0 deletions case-study-template.md
Original file line number Diff line number Diff line change
@@ -0,0 +1,49 @@
## Case-study оптимизации

### Актуальная проблема
В нашем проекте много тестов, прохождение которых занимается много времени.
В данный момент мы используем [turbo_tests](https://github.com/serpapi/turbo_tests), чтобы CI занимал вменяемое время, сейчас это примерно 5,5 минут.
Я решил посмотреть возможные проблемы.

### Формирование метрики
Для того чтобы отслеживать изменения, я решил написать `rake task` в котором будет вычисляться время выполнения `turbo_tests` (в 5 потоков), сохраняться в InfluxDB, используя [influxer](https://github.com/palkan/influxer) для отправки данных, и выводить это на график в Chronograf, используя [sandbox](https://github.com/influxdata/sandbox)
При первом запуске получилось примерно 6 минут.
```
Finished in 6 minutes 7 seconds (files took 6.67 seconds to load)
23269 examples, 0 failures, 757 pending
```

### Feedback-Loop
Для того, чтобы иметь возможность быстро проверять гипотезы я решил использовать часть тестов которые я хорошо знаю и которые с обычным запуском через `rspec` проходят сейчас за 25 секунд.
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

👍 nice move


### Вникаем в детали системы, чтобы найти главные точки роста
Для того, чтобы найти "точки роста" для оптимизации я воспользовался `test-prof`.

Используя настройки TEST_RUBY_PROF и TEST_STACK_PROF (в формате json и сервисом speedscope.app) выявить какие либо проблемы не получилось.
FDOC показал несколько лишних созданных фабрик.
А вот FPROF показал кое что интересное.
```
name total top-level total time time per call top-level time

card 769 516 7.4789s 0.0097s 4.8298s
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

а реально необходимо 516 раз создавать card, или можно как-то зареюзать?

also, можно попробовать посмотреть, нельзя ли что-то ускорить в самом создании одного card, потому что 7 секунд на 700 штук выглядит довольно медленно (можно сравнить с другими фабриками по этому показателю)

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Не указал тут, но скидывал в чат, что создание фабрик занимает почти 70% времени тестов(
Да, надо ещё будет поразбираться. Есть места где создаются лишние, но в отдельных тестах они не выглядят как точки роста, а в общей массе не понятно с чего начинать

card_token 769 42 1.9425s 0.0025s 0.1034s
```
Он показал что мы вместе с `card` создаем `card_token`, который хранит в себе некоторую дополнительную информацию, а данную информацию мы никак не используем в текущих тестах.
Так же был построен flamegraph
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

👍

<img src="./factory-flame-before.png" alt="Factories before" width="2036" heigh="930">

Проблема оказалось в том, что при создании `card` был добавлен `after(:build)` в котором создавался `card_token`. Данное создание вынес в дополнительный `trait :with_card_coken`.
Ещё раз запустил тесты, они как и ожидалось не упали и прошли за 20 секунд.
flamegraph теперь стал таким
<img src="./factory-flame-after.png" alt="Factories after" width="1982" heigh="916">

Но, запустив все тесты, некоторые упали, и оказалось их было не так много.
После правки всех тестов и они стали проходить за примерно 4,5 минуты.
```
Finished in 4 minutes 26.9 seconds (files took 7.01 seconds to load)
23269 examples, 0 failures, 757 pending
```

### Результаты
Получилось использовать `test-prof` в рабочем проекте, но, CI с правками не показал каких либо изменений (запускается в 20 потоков).
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

👍

<img src="./turbo_tests_graph.png" alt="turbo_tests graph" width="2724" heigh="760">
Binary file added factory-flame-after.png
Loading
Sorry, something went wrong. Reload?
Sorry, we cannot display this file.
Sorry, this file is invalid so it cannot be displayed.
Binary file added factory-flame-before.png
Loading
Sorry, something went wrong. Reload?
Sorry, we cannot display this file.
Sorry, this file is invalid so it cannot be displayed.
Binary file added turbo_tests_graph.png
Loading
Sorry, something went wrong. Reload?
Sorry, we cannot display this file.
Sorry, this file is invalid so it cannot be displayed.