外部コマンドは高くつく?「php」

 

phpで外部コマンドを利用すると非常に遅いのでちょっとしたスクリプトで確認してみました。

CentOS-6.4でテスト環境構築

yum -y install httpd php
service httpd start
cd /var/www/html

外部コマンドを利用しないスクリプト

vi index.php

<?php

for($a=0; $a < 10000; $a++) {
        $f = "/etc/resolv.conf";
        $fp = fopen($f, "r");
        $c = fread( $fp, filesize($f) );
        fclose( $fp );
}

?>

外部コマンドを利用するスクリプト

vi index2.php

<?php

for($a=0; $a < 10000; $a++) {
        exec('cat /etc/resolv.conf');
}

?>

早速負荷を確認してみます。

まずは外部コマンドを利用しないバージョン

time curl http://localhost/index.php

real 0m0.073s
user 0m0.001s
sys 0m0.001s

topの結果

top - 20:37:10 up 13 days, 3:59, 3 users, load average: 1.68, 1.24, 0.50
Tasks: 471 total, 1 running, 470 sleeping, 0 stopped, 0 zombie
Cpu0 : 1.0%us, 5.0%sy, 0.0%ni, 94.1%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu1 : 2.0%us, 2.9%sy, 0.0%ni, 95.1%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu2 : 1.0%us, 3.0%sy, 0.0%ni, 96.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu3 : 1.0%us, 2.0%sy, 0.0%ni, 97.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu4 : 0.0%us, 2.0%sy, 0.0%ni, 98.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu5 : 0.0%us, 3.0%sy, 0.0%ni, 97.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu6 : 1.0%us, 3.0%sy, 0.0%ni, 96.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu7 : 2.0%us, 1.0%sy, 0.0%ni, 97.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu8 : 2.0%us, 2.0%sy, 0.0%ni, 96.1%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu9 : 1.0%us, 2.0%sy, 0.0%ni, 97.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu10 : 1.0%us, 2.0%sy, 0.0%ni, 97.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu11 : 0.0%us, 1.0%sy, 0.0%ni, 99.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu12 : 0.0%us, 1.0%sy, 0.0%ni, 99.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu13 : 0.0%us, 2.0%sy, 0.0%ni, 98.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu14 : 1.0%us, 1.0%sy, 0.0%ni, 98.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu15 : 0.0%us, 2.0%sy, 0.0%ni, 98.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Mem: 32829880k total, 4949224k used, 27880656k free, 213356k buffers
Swap: 524280k total, 0k used, 524280k free, 3589492k cached

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
21382 netcorp 20 0 98.8m 2976 808 S 4.0 0.0 0:05.44 sshd
21514 apache 20 0 229m 6976 2800 S 4.0 0.0 0:09.25 httpd
21511 apache 20 0 227m 6964 2680 S 3.0 0.0 0:11.59 httpd
3088 apache 20 0 227m 6124 1976 S 2.0 0.0 0:07.78 httpd
3090 apache 20 0 227m 6124 1976 S 2.0 0.0 0:07.86 httpd
11525 apache 20 0 227m 5968 1828 S 2.0 0.0 0:00.84 httpd
21512 apache 20 0 229m 7088 2800 S 2.0 0.0 0:15.37 httpd
21517 apache 20 0 229m 6976 2800 S 2.0 0.0 0:09.03 httpd
27299 root 20 0 166m 2152 1728 S 2.0 0.0 0:00.57 curl
27307 root 20 0 166m 2148 1724 S 2.0 0.0 0:00.57 curl
27311 root 20 0 166m 2148 1724 S 2.0 0.0 0:00.53 curl
27315 root 20 0 166m 2152 1728 S 2.0 0.0 0:00.59 curl
27327 root 20 0 166m 2152 1728 S 2.0 0.0 0:00.56 curl
28474 apache 20 0 227m 6124 1976 S 2.0 0.0 0:08.18 httpd
31663 apache 20 0 227m 6124 1976 S 2.0 0.0 0:07.86 httpd
73 root 20 0 0 0 0 S 1.0 0.0 0:24.33 events/6
4218 root 20 0 387m 160m 1836 S 1.0 0.5 10:37.98 glusterfs
4224 root 20 0 310m 161m 1608 S 1.0 0.5 10:41.50 glusterfs
21931 root 20 0 15300 1560 968 R 1.0 0.0 0:02.41 top
23235 netcorp 20 0 97.7m 1764 804 S 1.0 0.0 0:00.91 sshd
27281 root 20 0 166m 2148 1724 S 1.0 0.0 0:00.58 curl
27283 root 20 0 166m 2152 1728 S 1.0 0.0 0:00.64 curl
27289 root 20 0 166m 2152 1728 S 1.0 0.0 0:00.63 curl
27293 root 20 0 166m 2148 1724 S 1.0 0.0 0:00.58 curl
27297 root 20 0 166m 2152 1728 S 1.0 0.0 0:00.52 curl

こちらが外部コマンドを利用するバージョン

time curl http://localhost/index2.php

real 0m19.279s
user 0m0.000s
sys 0m0.002s

topの結果

top - 20:42:04 up 13 days, 4:03, 3 users, load average: 2.46, 1.88, 0.97
Tasks: 471 total, 2 running, 469 sleeping, 0 stopped, 0 zombie
Cpu0 : 17.5%us, 81.6%sy, 0.0%ni, 1.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu1 : 17.8%us, 82.2%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu2 : 18.4%us, 80.6%sy, 0.0%ni, 1.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu3 : 19.6%us, 78.4%sy, 0.0%ni, 2.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu4 : 17.6%us, 81.4%sy, 0.0%ni, 1.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu5 : 18.4%us, 80.6%sy, 0.0%ni, 1.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu6 : 20.6%us, 78.4%sy, 0.0%ni, 1.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu7 : 19.4%us, 79.6%sy, 0.0%ni, 1.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu8 : 14.6%us, 81.6%sy, 0.0%ni, 3.9%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu9 : 15.7%us, 80.4%sy, 0.0%ni, 3.9%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu10 : 15.7%us, 81.4%sy, 0.0%ni, 2.9%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu11 : 15.5%us, 80.6%sy, 0.0%ni, 3.9%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu12 : 16.7%us, 79.4%sy, 0.0%ni, 3.9%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu13 : 14.7%us, 80.4%sy, 0.0%ni, 4.9%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu14 : 17.5%us, 78.6%sy, 0.0%ni, 3.9%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu15 : 15.8%us, 80.2%sy, 0.0%ni, 4.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Mem: 32829880k total, 4950324k used, 27879556k free, 213360k buffers
Swap: 524280k total, 0k used, 524280k free, 3591588k cached

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
11525 apache 20 0 227m 6128 1976 S 21.5 0.0 0:19.23 httpd
21510 apache 20 0 230m 7736 3416 S 21.5 0.0 0:28.81 httpd
21512 apache 20 0 229m 7088 2800 S 21.5 0.0 0:33.90 httpd
23415 apache 20 0 229m 7004 2800 S 21.5 0.0 0:33.92 httpd
31655 apache 20 0 227m 6128 1976 S 21.5 0.0 0:25.94 httpd
3082 apache 20 0 227m 6128 1976 S 20.5 0.0 0:32.65 httpd
3087 apache 20 0 227m 6128 1976 S 20.5 0.0 0:25.97 httpd
3088 apache 20 0 227m 6128 1976 S 20.5 0.0 0:26.01 httpd
21516 apache 20 0 229m 6976 2800 S 20.5 0.0 0:28.01 httpd
21517 apache 20 0 229m 6976 2800 S 20.5 0.0 0:27.67 httpd
25777 apache 20 0 227m 6128 1976 S 20.5 0.0 0:26.46 httpd
28478 apache 20 0 227m 6128 1976 S 20.5 0.0 0:26.86 httpd
31664 apache 20 0 227m 6128 1976 S 20.5 0.0 0:26.64 httpd
3090 apache 20 0 227m 6128 1976 S 19.6 0.0 0:25.97 httpd
21511 apache 20 0 227m 6964 2680 S 19.6 0.0 0:30.13 httpd
21513 apache 20 0 230m 7112 2800 S 19.6 0.0 0:39.74 httpd
21514 apache 20 0 229m 6976 2800 R 19.6 0.0 0:27.83 httpd
28474 apache 20 0 227m 6128 1976 S 19.6 0.0 0:26.42 httpd
31660 apache 20 0 227m 6128 1976 S 19.6 0.0 0:26.54 httpd
31663 apache 20 0 227m 6128 1976 S 18.6 0.0 0:25.50 httpd
7 root RT 0 0 0 0 S 1.0 0.0 0:00.45 migration/1
47 root RT 0 0 0 0 S 1.0 0.0 0:00.78 migration/11
25742 root 20 0 15300 1572 968 R 1.0 0.0 0:01.24 top
1 root 20 0 19228 1516 1220 S 0.0 0.0 0:01.13 init
2 root 20 0 0 0 0 S 0.0 0.0 0:00.00 kthreadd

これを見ると外部コマンドは非常にシステムのCPU利用率が高く処理時間に大きな違いがあるのがわかる。

カーネルのシステムコールの違いを見てみると

外部コマンドを利用しない場合はこのようになっています。

strace -c -p [httpd.pid]
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 31.83    0.001718           0     35117           open
 22.49    0.001214           0     35116           read
 19.99    0.001079           0     35116           close
 13.38    0.000722           0     35116           fstat
 11.08    0.000598           0     35116           lseek
  1.22    0.000066           0       294           writev
  0.00    0.000000           0         1           poll
  0.00    0.000000           0         1           restart_syscall
------ ----------- ----------- --------- --------- ----------------
100.00    0.005397                175877           total

外部コマンドを利用する場合のシステムコールは下記のとおりです。

strace -c -p [httpd.pid]
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 86.36    0.115773         134       867           clone
  8.09    0.010845          13       867           wait4
  5.41    0.007257           4      1735           read
  0.07    0.000098           0      1734           close
  0.04    0.000059           0       867           pipe2
  0.02    0.000027           0       867           fcntl
  0.00    0.000000           0         8           writev
------ ----------- ----------- --------- --------- ----------------
100.00    0.134059                  6945           total

これを見るとcloneというシステムコールが多い。

外部コマンドは呼ばれる度に新しいシェルを起動(clone,fork)しコマンドを動かすため、

その起動コストに非常におおきな時間を要し実行時間に大きな差が出てしまっているのではないかな。

APIのインターフェースなどはサービス事業者よりperlやcの実行ファイルでもらうことがあったりするのでphpから外部コマンドで呼び出すことがあるかと思いますが、

これを外部コマンドとして利用するのではなく、

例えばこのスクリプト部分をAPI化(perlならcgiサーバを構築)して、phpからそのcgiサーバを叩くような形で実装すれば実効速度が速くなりレスポンスタイムの向上やサーバの負荷の軽減になるのではないかなと思っています。

dmmのサーバでも外部コマンドを多用しているので、これを解決させてレスポンスタイムの向上につながればいいなと思っています。