Skip to content

Latest commit

 

History

History
104 lines (71 loc) · 6.85 KB

case_study.md

File metadata and controls

104 lines (71 loc) · 6.85 KB

Наш проект довольно большой, ему 12 лет, из них около 10 в продакшене, все это время код пишет команда в несколько человек. Тестов, соответственно, тоже много: 17765 examples. Из них feature-тестов (Capybara): 2703 examples. Над производительностью тестов никто особо не думал, профилированием тестов не занимался. Даже без feature-тестов время выполнения локально - часы. На CI гоняем тесты в несколько потоков за 20 минут. Еще до курса было очевидно, что надо что-то с этим делать, но пока не брались.

Я решил попробовать найти точки роста test-suite и оптимизировать их.

Feature-тесты отложил на будущее, и начал профилировать остальные. Так как тестов тысячи, меня не очень интересовало ускорение одного конкретного теста, хотелось найти что-то общее у всех (например, медленные фабрики), тогда оптимизация общей точки роста может дать значитальное ускорение.

До оптимизации

Я выбрал часть тестов для профилирования.

RspecDissect report:

Total time: 04:15.790

Total let time: 03:59.997 Total before(:each) time: 03:21.796

Factory-prof:

[TEST PROF INFO] Factories usage

Total: 3096 Total top-level: 1470 Total time: 04:12.822 (out of 04:52.409) Total uniq factories: 50

total top-level total time time per call top-level time name

 543           0        1.2519s            0.0023s             0.0000s       billing_plan
 543           0        7.5175s            0.0138s             0.0000s accounts_user_owner
 539         382       93.4210s            0.1733s            46.4248s            listing
 512         272      101.0931s            0.1974s            53.0935s            account
 321         321      118.7376s            0.3699s           118.7376s            showing
  86          54        0.2781s            0.0032s             0.1725s            lockbox
  78          78        0.1872s            0.0024s             0.1872s      listing_event
  67          67        1.5314s            0.0229s             1.5314s        team_member
  29          29        0.1377s            0.0047s             0.1377s    listing_contact
  22          22        0.0528s            0.0024s             0.0528s system_phone_number
  21           0        0.0485s            0.0023s             0.0000s      billing_event
  21          21        3.9465s            0.1879s             3.9465s     active_account
  20           2        0.0424s            0.0021s             0.0050s               room

Видно, что фабрики занимают огромное количество от общего времени выполнения. По total time больше всего времени занимает showing, но меня заинтересовала фабрика account, так как я знаю, что она используется практически в каждом тесте, и если профилировать весь test suite, то она была бы на первом месте.

Посмотрим подробнее на эту фабрику на примере создания 50 записей:

Время выполнения: 11.5 сек.

Factory-flame:

Screenshot

RubyProf callstack:

Screenshot

Оптимизация

Дело в том, что при создании account выполняются коллбэки (легаси-код) с созданием множества разных дефолтных записей. Так как создание account - очень редкая операция, то в продакшне это не заметно. Но в тестах все эти (зачастую вообще ненежные) коллбэки дают сильное замедление. Думаю, что в большистве случаев вообще можно все переписать с помощью let_it_be.

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

Время выполнения: 4.1 сек.

Factory-prof:

[TEST PROF INFO] Factories usage

Total: 3096 Total top-level: 1470 Total time: 02:50.460 (out of 03:28.990) Total uniq factories: 50

total top-level total time time per call top-level time name

 543           0        1.2912s            0.0024s             0.0000s       billing_plan
 543           0        7.0080s            0.0129s             0.0000s accounts_user_owner
 539         382       63.6008s            0.1180s            39.6879s            listing
 512         272       32.6779s            0.0638s            17.6024s            account
 321         321       92.5782s            0.2884s            92.5782s            showing
  86          54        0.2538s            0.0030s             0.1546s            lockbox
  78          78        0.1983s            0.0025s             0.1983s      listing_event
  67          67        1.5843s            0.0236s             1.5843s        team_member
  29          29        0.1321s            0.0046s             0.1321s    listing_contact
  22          22        0.0543s            0.0025s             0.0543s system_phone_number
  21           0        0.0445s            0.0021s             0.0000s      billing_event
  21          21        1.3007s            0.0619s             1.3007s     active_account
  20           2        0.0395s            0.0020s             0.0028s               room

RubyProf callstack:

Screenshot

Результат далеко не идеальный, но улучшение налицо. Далее можно заняться и другими фабриками.

InfluxDB

InfluxDB поставил, запустил Chronograph. Возникли некоторые проблемы с настройкой сбора метрик, и за неимением времени я это оставил, так как сам принцип сбора метрик и так понял.