zed.0xff.me

fork() в нужный момент экономит время

rspec_bisect и с чем его едят

Есть у меня скриптик rspec_bisect, предназначенный для выискивания в rails-проекте спеков, которые в процессе своего выполнения что-то глобально меняют/трогают/expect-ают или stub-ают (а то и, даже страшно сказать, any_instance-ют!..) в результате чего потом другие спеки успешно натыкаются на расставленные грабли, и FAIL-ятся с довольно фантастическими ошибками.

Показанием к применению данного скрипта можно считать случай когда запуск одной спеки через spec /spec/models/first_model_spec.rb завершается успешно и без FAIL-ов, а на запуск ее же вместе с другими спеками через rake spec получаем гарантированные FAIL-ы.

Пример работы rspec_bisect.

причем здесь fork() ?..

Притом что изначально для поиска иголки в стоге сена я запускал наборы спеков через `spec /spec/models/m1_spec.rb spec/models/m2_spec.rb ...`, т.е. через вызов system() (чтобы получить изолированное окружение, не влияющее ни на родителя, ни на соседей).

При этом каждый раз рельсы упорно грузили весь свой арсенал, каждый раз отъедая что-то около 10с (на довольно тяжелом проекте).

Зерном идеи оптимизации послужила давняя попытка запуска Spork. Почему-то она не никаким приростом скорости не увенчалась, но полезный осадок в виде особенностей работы Kernel.fork оставила.

Суть в том (если кто не знает), что “fork() creates a new process by duplicating the calling process.” © man 2 fork. Т.е. если вовремя форкнуться, то не надо 10 раз грузить весь Rails environment, достаточно будет загрузить его всего один раз, а все запуски тестов делать уже в fork-нутых child-ах.

На том и порешили. После непродолжительной борьбы rspec сдался и раскололся чем и как он запускает спеки ( оказалось – через at_exit.. старый извращенец :), и был слегка поmonkeyпатчен, чтоб не делал лишних телодвижений.

Сравнение запусков “до” и “после”:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
### ДО ###
[.] running   62 specs.. Done. ( 19s) (105/0/4) : target OK
[.] running   63 specs.. Done. ( 60s) (384/2/6) : target FAIL
[.] running   32 specs.. Done. ( 35s) (157/0/2) : target OK
[.] running   32 specs.. Done. ( 47s) (236/2/4) : target FAIL
[.] running   16 specs.. Done. ( 35s) (129/2/1) : target FAIL
[.] running    8 specs.. Done. ( 28s) (73/0)    : target OK
[.] running    9 specs.. Done. ( 22s) (65/2/1)  : target FAIL
[.] running    5 specs.. Done. ( 18s) (52/2/1)  : target FAIL
[.] running    3 specs.. Done. ( 17s) (33/0)    : target OK
[.] running    3 specs.. Done. ( 17s) (28/2/1)  : target FAIL
[.] running    2 specs.. Done. ( 17s) (27/2/1)  : target FAIL

### ПОСЛЕ ###
[.] running   62 specs.. Done. (  9s) (105/0/4) : target OK
[.] running   63 specs.. Done. ( 49s) (384/2/6) : target FAIL
[.] running   32 specs.. Done. ( 21s) (157/1/2) : target OK
[.] running   32 specs.. Done. ( 34s) (236/3/4) : target FAIL
[.] running   16 specs.. Done. ( 24s) (129/3/1) : target FAIL
[.] running    8 specs.. Done. ( 20s) (73/1)    : target OK
[.] running    9 specs.. Done. (  9s) (65/3/1)  : target FAIL
[.] running    5 specs.. Done. (  8s) (52/3/1)  : target FAIL
[.] running    3 specs.. Done. (  4s) (33/1)    : target OK
[.] running    3 specs.. Done. (  8s) (28/3/1)  : target FAIL
[.] running    2 specs.. Done. (  7s) (27/3/1)  : target FAIL

В результате время запуска тестового набора сократилось с 315с до 193с, т.е. чуть больше чем на треть.