jwata blog

勉強の記録や思ったことなど

PHPUnit 並列実行に挑戦中

仕事でPHPUnitを使うようになって1年くらいが経ち、チーム内にテスト書く文化が定着してきました。
テストの質と量が向上して、有効性も高まってきていい感じだなーと思う反面

「時間かかり過ぎ 」

という、面倒くさい問題が浮上してきました＞＜。

現状のテスト実行ログ

% ./vendor/bin/phpunit
PHPUnit 3.7.28 by Sebastian Bergmann.

...............................................................  63 / 612 ( 10%)
............................................................... 126 / 612 ( 20%)
............................................................... 189 / 612 ( 30%)
............................................................... 252 / 612 ( 41%)
............................................................... 315 / 612 ( 51%)
............................................................... 378 / 612 ( 61%)
............................................................... 441 / 612 ( 72%)
............................................................... 504 / 612 ( 82%)
............................................................... 567 / 612 ( 92%)
.............................................

Time: 1.43 minutes, Memory: 68.50Mb

OK (612 tests, 1240 assertions)

自プロダクトのテストだけですが、1.5分程度かかっています。
10秒を超えてくると、その間完全に休憩時間になってしまい効率悪いなと感じてきました。。

並列に走らせればいいんじゃないか

安易な考えのもと、並列実行に取り組んでみました。

自分で簡単な実行するプログラムを組もうと思ったのですが、もう既にありました。

Parallel Testing for PHPUnit with ParaTest

http://code.tutsplus.com/tutorials/parallel-testing-for-phpunit-with-paratest--net-32105

おお、まさに今やりたいこと。
早速インストール

% php composer.phar require --dev brianium/paratest

Please provide a version constraint for the brianium/paratest requirement: dev-master
./composer.json has been updated
Loading composer repositories with package information
Updating dependencies (including require-dev)
  - Installing symfony/process (v2.4.3)
    Loading from cache

  - Installing brianium/habitat (v1.0.0)
    Loading from cache

  - Installing brianium/paratest (dev-master da81030)
    Cloning da81030376bfaa05e2fc83655b5e7ef57daceea5

Writing lock file
Generating autoload files

% ./vendor/bin/paratest --version
ParaTest version 0.4.4

すかさず実行してみる。デフォルトではプロセス数は5です。

% ./vendor/bin/paratest

Running phpunit in 5 processes with xxx/phpunit.xml

  [InvalidArgumentException]
  Log file /tmp/PT_Bm28NZ is empty. This means a PHPUnit process has crashed.

(´・ω・｀) crashed...

ちゃんと動いていないんでしょうか、paratest自体のテストは通っていました。
プロセス数1で実行してみる

running phpunit in 1 process with xx/vendor/bin/phpunit
Configuration read from xx/phpunit.xml

...............................................................  63 / 376 ( 16%)
............................................................... 126 / 376 ( 33%)
............................................................... 189 / 376 ( 50%)
............................................................... 252 / 376 ( 67%)
............................................................... 315 / 376 ( 83%)
............................................................... 378 / 376 (100%)
............................................................... 441 / 376 (117%)
..E.EE......................................................... 504 / 376 (134%)
.....................................................F......... 567 / 376 (150%)
.......F.....................................

Time: 3.54 minutes, Memory: 30.25Mb

There were 3 errors:
(中略)
FAILURES!
Tests: 612, Assertions: 1237, Failures: 2, Errors: 3.

むう、動いたみたいだけど3分かかっとる。
プロセス数 2以上だとコケるみたいでした。

処理を見てみる https://github.com/brianium/paratest/blob/master/src/ParaTest/Runners/PHPUnit/Runner.php#L75

f:id:jwata:20140428012025p:plain

Time is money ということかな。The money maker。おしゃれなコメントですね。
指定したプロセス数を実行して、終わったら次のプロセス実行のqueueを突っ込むという。
まあこうなるようね的な感じ。

このメイン処理のハンドリングがゆるふわでコケているようなので修正してみました。 https://github.com/Jwata/paratest/commit/3596bad2261c4f6d18a1f6331f0a04b46fd324a9

  • プロセスを走らせた後のusleepを削除
  • 10回試行したらプロセスを止めて終わったことにする

ちゃんと直すまえに、とりあえずこの修正で速度出るかの検証してみました。

プロセス数 10

Running phpunit in 10 processes with xx/vendor/bin/phpunit

Configuration read from xx/phpunit.xml

........EF.......E....EEEEEE..................EE.......E..E...E  63 / 376 ( 16%)
FEE..E....F...EEEEEEE....E.......EF.E...FE..EEE.EEE......FFE.EE 126 / 376 ( 33%)
.EEE.F...............

Time: 1.79 minutes, Memory: 32.50Mb

There were 39 errors:
(中略)
FAILURES!
Tests: 147, Assertions: 194, Failures: 8, Errors: 39.

おお動いた。
けど、めっちゃエラー出てる。まだ 2分近くかかってますね。
エラーの原因はDB/KVSへ同時にアクセスしちゃっているからな気がする。

一旦エラーは無視して、プロセス数を増やして時間が短縮されるか確認してみる。

プロセス数 20

Running phpunit in 20 processes with xx/vendor/bin/phpunit

Configuration read from xx/phpunit.xml

......EEEE..............EEEE.EF..E.E..E...E....EE.E.FEEF.FEEE..  63 / 376 ( 16%)
...

Time: 1.37 minutes, Memory: 33.00Mb

There were 21 errors:
(中略)
FAILURES!
Tests: 66, Assertions: 80, Failures: 4, Errors: 21.

プロセス数 30

Running phpunit in 30 processes with xx/vendor/bin/phpunit

Configuration read from xx/ffr/phpunit.xml

......................................................E..EE..E.  63 / 376 ( 16%)
EEEE.E......E...EEE...EE..E.E.E..E...EEE..EE...F..F.

Time: 1.38 minutes, Memory: 33.25Mb

There were 24 errors:
(中略)
FAILURES!
Tests: 115, Assertions: 154, Failures: 2, Errors: 24.

あんまり通常の実行速度と変わんない。
オーバーヘッドの原因調べて改善しても1分切るかそれくらいかなぁ

シェルの並列処理

本当に改善の余地がないのか確かめるために xargs で並列実行してみました。

プロセス数 10

time find tests/ -name "*Test.php" | xargs -L 1 -P 10 ./vendor/bin/phpunit

find tests/ -name "*Test.php"  0.01s user 0.00s system 25% cpu 0.031 total
xargs -L 1 -P 10 ./vendor/bin/phpunit  52.44s user 16.42s system 88% cpu 1:17.91 total

プロセス数 20

time find tests/ -name "*Test.php" | xargs -L 1 -P 20 ./vendor/bin/phpunit

find tests/ -name "*Test.php"  0.00s user 0.01s system 25% cpu 0.031 total
xargs -L 1 -P 20 ./vendor/bin/phpunit  33.55s user 10.78s system 89% cpu 49.516 total

プロセス数 30

time find tests/ -name "*Test.php" | xargs -L 1 -P 30 ./vendor/bin/phpunit

find tests/ -name "*Test.php"  0.01s user 0.00s system 25% cpu 0.031 total
xargs -L 1 -P 30 ./vendor/bin/phpunit  25.92s user 9.22s system 89% cpu 39.100 total

プロセス数 40

time find tests/ -name "*Test.php" | xargs -L 1 -P 30 ./vendor/bin/phpunit

find tests/ -name "*Test.php"  0.00s user 0.01s system 16% cpu 0.048 total
xargs -L 1 -P 40 ./vendor/bin/phpunit  25.62s user 9.16s system 90% cpu 38.476 total

おお、30秒くらいなら行けそう。
相変わらずエラー出まくりですが、マシン的な限界が見れそうです。

まとめ

  • マシンのスペック的には1.5分 -> 0.5分 くらいまで短縮が可能
  • 並列処理だと、DB/KVSへのアクセスを分けないと行けないので、テスト側に修正が必要
  • 実運用するなら、paratest を修正して結果をちゃんと見れるようにする必要がある

次のステップとしては、プロセス毎にDB/KVSのアクセスを分けられるようにしてみよう。
とりあえず今日はこの辺で諦めました、並列処理を甘く見てはいけないですね(-_-;)