Rubyで遊んだ日々の記録。あくまで著者視点の私的な記録なので、正確さを求めないように。
Rubyと関係ない話題にはその旨注記しているはず。なので、一見関係無いように見える話題もどこかで関係あるのかもしれません。または、注記の書き忘れかもしれません...
_ 先日に続いて、1.8の方は、先日の改修時に入れちゃったバグ1点と、p173のあたりからあったらしいIO.select(nil, nil, nil, 0)が結構な確率で遅くなる問題を修正してみた。
前者はともかく、後者は例の問題と関係あるかもしれない。ないかもしれないけど。
_ InstantRailsを使って、問題の現象を確認してみることにした。
_ ベンチマークにはApacheのabを使用。1000リクエストで試すことにした。
_ まず、InstantRails 2.0添付のruby(1.8.6-p111)から。
Server Software:
Server Hostname: localhost
Server Port: 3000
Document Path: /
Document Length: 7557 bytes
Concurrency Level: 1
Time taken for tests: 3.360000 seconds
Complete requests: 1000
Failed requests: 0
Write errors: 0
Total transferred: 7750000 bytes
HTML transferred: 7557000 bytes
Requests per second: 297.62 [#/sec] (mean)
Time per request: 3.360 [ms] (mean)
Time per request: 3.360 [ms] (mean, across all concurrent requests)
Transfer rate: 2252.38 [Kbytes/sec] received
Connection Times (ms)
min mean[+/-sd] median max
Connect: 0 0 0.5 0 1
Processing: 2 3 2.7 3 50
Waiting: 1 1 2.8 2 48
Total: 2 3 2.7 3 50
Percentage of the requests served within a certain time (ms)
50% 3
66% 3
75% 3
80% 3
90% 4
95% 4
98% 4
99% 4
100% 50 (longest request)
実行してから気づいたけど、Rails動かしてるマシンと同じマシンでab動かすのはどうなのよ、って感じだな。ま、傾向見るのが目的だからいいか。
_ 続いて、InstantRailsのrubyを1.8.7-p174で上書きして再実験。最初の方は毎回同じなので省く。
Concurrency Level: 1
Time taken for tests: 13.518000 seconds
Complete requests: 1000
Failed requests: 0
Write errors: 0
Total transferred: 7750000 bytes
HTML transferred: 7557000 bytes
Requests per second: 73.98 [#/sec] (mean)
Time per request: 13.518 [ms] (mean)
Time per request: 13.518 [ms] (mean, across all concurrent requests)
Transfer rate: 559.85 [Kbytes/sec] received
Connection Times (ms)
min mean[+/-sd] median max
Connect: 0 0 0.7 0 2
Processing: 3 12 3.3 13 60
Waiting: 2 11 3.0 12 59
Total: 4 13 3.2 14 60
Percentage of the requests served within a certain time (ms)
50% 14
66% 14
75% 14
80% 14
90% 14
95% 15
98% 15
99% 16
100% 60 (longest request)
確かに速度は落ち込んでるが、1/4程度。確かに問題ではあるが、世間の人が言うほど劇的でもないんだよなあ。1/100になるとかいう話もあったんだけど。
document rootで試してるのがよくないのかなあ。まあいいや。
_ さて、これをさらにruby_1_8 HEAD(1.8.8dev r23613)に置き換えるとどうなるか。
Concurrency Level: 1
Time taken for tests: 3.266000 seconds
Complete requests: 1000
Failed requests: 0
Write errors: 0
Total transferred: 7750000 bytes
HTML transferred: 7557000 bytes
Requests per second: 306.18 [#/sec] (mean)
Time per request: 3.266 [ms] (mean)
Time per request: 3.266 [ms] (mean, across all concurrent requests)
Transfer rate: 2317.21 [Kbytes/sec] received
Connection Times (ms)
min mean[+/-sd] median max
Connect: 0 0 0.4 0 1
Processing: 2 2 2.5 3 46
Waiting: 1 1 1.7 1 35
Total: 2 3 2.3 3 46
Percentage of the requests served within a certain time (ms)
50% 3
66% 3
75% 3
80% 3
90% 3
95% 4
98% 4
99% 4
100% 46 (longest request)
はい、事実上、元(1.8.6-p111)と同じ速度に戻りました、と。
_ これじゃ意味がないかもしれないので、scaffoldで適当なModel/View/Controllerを生成して再確認。
今度はさすがに遅いので、100リクエストで実験。
Server Software: Mongrel
Server Hostname: localhost
Server Port: 3000
Document Path: /samples
Document Length: 582 bytes
Concurrency Level: 1
Time taken for tests: 8.591000 seconds
Complete requests: 100
Failed requests: 0
Write errors: 0
Total transferred: 104600 bytes
HTML transferred: 58200 bytes
Requests per second: 11.64 [#/sec] (mean)
Time per request: 85.910 [ms] (mean)
Time per request: 85.910 [ms] (mean, across all concurrent requests)
Transfer rate: 11.87 [Kbytes/sec] received
Connection Times (ms)
min mean[+/-sd] median max
Connect: 0 0 0.6 0 1
Processing: 69 85 72.5 72 783
Waiting: 68 84 72.5 71 782
Total: 70 85 72.6 72 784
Percentage of the requests served within a certain time (ms)
50% 72
66% 73
75% 74
80% 75
90% 121
95% 125
98% 129
99% 784
100% 784 (longest request)
うわー、動的ページは遅いなー。ほとんど中身ないページなのに(DBが空だから)、静的ページの1/25ですかい。
Concurrency Level: 1
Time taken for tests: 14.697000 seconds
Complete requests: 100
Failed requests: 0
Write errors: 0
Total transferred: 104600 bytes
HTML transferred: 58200 bytes
Requests per second: 6.80 [#/sec] (mean)
Time per request: 146.970 [ms] (mean)
Time per request: 146.970 [ms] (mean, across all concurrent requests)
Transfer rate: 6.94 [Kbytes/sec] received
Connection Times (ms)
min mean[+/-sd] median max
Connect: 0 0 0.6 0 1
Processing: 126 146 75.8 132 877
Waiting: 126 145 75.9 132 877
Total: 126 146 75.9 133 878
Percentage of the requests served within a certain time (ms)
50% 133
66% 135
75% 137
80% 138
90% 181
95% 185
98% 191
99% 878
100% 878 (longest request)
1.8.6-p111と比べてだいたい1/1.7の速度。静的ページの場合と比べてむしろ遅さが圧縮された。意味なかったなこのベンチ。
Concurrency Level: 1
Time taken for tests: 8.755000 seconds
Complete requests: 100
Failed requests: 0
Write errors: 0
Total transferred: 104600 bytes
HTML transferred: 58200 bytes
Requests per second: 11.42 [#/sec] (mean)
Time per request: 87.550 [ms] (mean)
Time per request: 87.550 [ms] (mean, across all concurrent requests)
Transfer rate: 11.65 [Kbytes/sec] received
Connection Times (ms)
min mean[+/-sd] median max
Connect: 0 0 0.5 0 1
Processing: 53 87 252.3 55 2580
Waiting: 51 86 252.3 55 2579
Total: 53 87 252.4 56 2581
Percentage of the requests served within a certain time (ms)
50% 56
66% 56
75% 58
80% 61
90% 104
95% 105
98% 118
99% 2581
100% 2581 (longest request)
_ VC9を使ってmsvcr90.dllでなくmsvcrt.dllにリンクしたminiruby.exeを作ることに成功した。
でも-vはできるけどIOをオープンしたら死ぬ :)
被捕捉アンテナ類
[Ant]
[Antenna-Julia]
[Rabbit's Antenna]
[Ruby hotlinks]