Forum: Ruby-dev [ruby-trunk - Bug #7356][Open] ruby-2.0.0-preview1 で adlint-2.6.10 が性能劣化

Posted by yanoh (Yutaka Yanoh) (Guest)
on 2012-11-15 10:37
(Received via mailing list)
Issue #7356 has been reported by yanoh (Yutaka Yanoh).

----------------------------------------
Bug #7356: ruby-2.0.0-preview1 で adlint-2.6.10 が性能劣化
https://bugs.ruby-lang.org/issues/7356

Author: yanoh (Yutaka Yanoh)
Status: Open
Priority: Normal
Assignee:
Category:
Target version: 2.0.0
ruby -v: ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]


== 現象

ruby-1.9.3-p327 と ruby-2.0.0-preview1 で adlint-2.6.10 の性能比較を行った結果、
ruby-2.0.0-preview1 の方が解析時間が 1.2 倍ほど長くかかりました。

== 再現手順

 % gem install adlint
 % tar xvjf adlint-benchmark-screen.tar.bz2  <- 添付ファイル
 % cd adlint-benchmark-screen/adlint
 % time make -j 2 2>/dev/null

== 性能測定結果

=== 測定環境

* Core 2 Duo E4500 2.20GHz / 3.4GB
* Fedora 14 / Linux 2.6.35.14-106.fc14.i686

=== 測定方法

* 下記バージョンの ruby を用いて、adlint-2.6.10 で screen-4.0.3 を解析
  ruby 1.9.3p327 (2012-11-10 revision 37606) [i686-linux]  built with 
gcc-4.5.1
  ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]      built with 
gcc-4.5.1
  ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]      built with 
gcc-4.7.2

* すべて configure オプションは --prefix のみ

* 解析は 2 コアを使い切れるよう make -j 2 を指定

* できるだけ IO による遅延を抑えるため標準エラーは /dev/null へリダイレクト
  ただし解析結果ファイルの出力は抑止できていません

=== 測定結果

* ruby 1.9.3p327 (2012-11-10 revision 37606) [i686-linux]  built with 
gcc-4.5.1
  make -j 2 2> /dev/null  1335.85s user 7.10s system 184% cpu 12:07.79 
total
  make -j 2 2> /dev/null  1336.54s user 7.17s system 184% cpu 12:07.80 
total
  make -j 2 2> /dev/null  1340.71s user 7.23s system 184% cpu 12:10.69 
total

* ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]      built with 
gcc-4.5.1
  make -j 2 2> /dev/null  1626.45s user 8.08s system 184% cpu 14:48.20 
total
  make -j 2 2> /dev/null  1633.40s user 8.10s system 185% cpu 14:46.92 
total
  make -j 2 2> /dev/null  1631.37s user 7.86s system 184% cpu 14:50.18 
total

* ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]      built with 
gcc-4.7.2
  make -j 2 2> /dev/null  1531.83s user 7.85s system 184% cpu 13:53.04 
total
  make -j 2 2> /dev/null  1533.46s user 7.97s system 184% cpu 13:54.54 
total
  make -j 2 2> /dev/null  1532.89s user 8.03s system 184% cpu 13:53.33 
total

== 備考

adlint_sma コマンドは、最初のソースコード読み込み時と最後の解析結果書き出し時に
IO が走る以外は、オンメモリで計算のみを実行しています。
データ構造は木構造が多く、再帰処理を多用し、小さな一時オブジェクトを多く new し
ています。
Posted by SASADA Koichi (Guest)
on 2012-11-16 15:06
(Received via mailing list)
情報ありがとうございます.
簡単な再現手順はありませんかね.make じゃなくて,ruby 直接動かすようなも
のだとありがたいのですが....
Posted by tarui (Masaya Tarui) (Guest)
on 2012-11-18 05:08
(Received via mailing list)
Issue #7356 has been updated by tarui (Masaya Tarui).


windowsではあまり変わらないみたいです。
linuxだとどこが問題なんですかね。

== 測定環境
 OS 名  Microsoft Windows 7 Home Premium
 バージョン  6.1.7601 Service Pack 1 ビルド 7601
 システムの種類  x64-ベース PC
 プロセッサ  Intel(R) Core(TM) i7-3770K CPU @ 3.50GHz、3501 Mhz、4 個のコア、8 
個のロジカル プロセッサ
 インストール済みの物理メモリ (RAM)  16.0 GB

== Measure-Command {make -J8 2> $nul } の結果

* ruby 2.0.0dev (2012-11-18 trunk 37704) [x64-mswin64_100]
 TotalSeconds      : 308.6010451
 TotalSeconds      : 306.6180463

* ruby 1.9.3p327 (2012-11-10 revision 37606) [x64-mswin64_100]
 TotalSeconds      : 308.6779665
 TotalSeconds      : 305.5603019

== xperf
全部は大変なのでprocess.cだけですが、下記でプロファイルを取った結果をおいておきます。
 adlint_sma -t adlint_traits.yml -o . -p 1 ../screen-4.0.3/process.c 
2>NUL:
結果:
 https://docs.google.com/spreadsheet/ccc?key=0AoB-K...
----------------------------------------
Bug #7356: ruby-2.0.0-preview1 で adlint-2.6.10 が性能劣化
https://bugs.ruby-lang.org/issues/7356#change-33046

Author: yanoh (Yutaka Yanoh)
Status: Open
Priority: Normal
Assignee:
Category:
Target version: 2.0.0
ruby -v: ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]


== 現象

ruby-1.9.3-p327 と ruby-2.0.0-preview1 で adlint-2.6.10 の性能比較を行った結果、
ruby-2.0.0-preview1 の方が解析時間が 1.2 倍ほど長くかかりました。

== 再現手順

 % gem install adlint
 % tar xvjf adlint-benchmark-screen.tar.bz2  <- 添付ファイル
 % cd adlint-benchmark-screen/adlint
 % time make -j 2 2>/dev/null

== 性能測定結果

=== 測定環境

* Core 2 Duo E4500 2.20GHz / 3.4GB
* Fedora 14 / Linux 2.6.35.14-106.fc14.i686

=== 測定方法

* 下記バージョンの ruby を用いて、adlint-2.6.10 で screen-4.0.3 を解析
  ruby 1.9.3p327 (2012-11-10 revision 37606) [i686-linux]  built with 
gcc-4.5.1
  ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]      built with 
gcc-4.5.1
  ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]      built with 
gcc-4.7.2

* すべて configure オプションは --prefix のみ

* 解析は 2 コアを使い切れるよう make -j 2 を指定

* できるだけ IO による遅延を抑えるため標準エラーは /dev/null へリダイレクト
  ただし解析結果ファイルの出力は抑止できていません

=== 測定結果

* ruby 1.9.3p327 (2012-11-10 revision 37606) [i686-linux]  built with 
gcc-4.5.1
  make -j 2 2> /dev/null  1335.85s user 7.10s system 184% cpu 12:07.79 
total
  make -j 2 2> /dev/null  1336.54s user 7.17s system 184% cpu 12:07.80 
total
  make -j 2 2> /dev/null  1340.71s user 7.23s system 184% cpu 12:10.69 
total

* ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]      built with 
gcc-4.5.1
  make -j 2 2> /dev/null  1626.45s user 8.08s system 184% cpu 14:48.20 
total
  make -j 2 2> /dev/null  1633.40s user 8.10s system 185% cpu 14:46.92 
total
  make -j 2 2> /dev/null  1631.37s user 7.86s system 184% cpu 14:50.18 
total

* ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]      built with 
gcc-4.7.2
  make -j 2 2> /dev/null  1531.83s user 7.85s system 184% cpu 13:53.04 
total
  make -j 2 2> /dev/null  1533.46s user 7.97s system 184% cpu 13:54.54 
total
  make -j 2 2> /dev/null  1532.89s user 8.03s system 184% cpu 13:53.33 
total

== 備考

adlint_sma コマンドは、最初のソースコード読み込み時と最後の解析結果書き出し時に
IO が走る以外は、オンメモリで計算のみを実行しています。
データ構造は木構造が多く、再帰処理を多用し、小さな一時オブジェクトを多く new し
ています。
Posted by mame (Yusuke Endoh) (Guest)
on 2012-11-24 10:26
(Received via mailing list)
Issue #7356 has been updated by mame (Yusuke Endoh).

Status changed from Open to Assigned
Assignee set to ko1 (Koichi Sasada)

ささださん、preview2 後でいいのでがんばってみてください。
こういうので遅くなってたら「ささださんの仕事とは何だったのか」ということになりかねない。

他の方の追試も歓迎です。

--
Yusuke Endoh <mame@tsg.ne.jp>
----------------------------------------
Bug #7356: ruby-2.0.0-preview1 で adlint-2.6.10 が性能劣化
https://bugs.ruby-lang.org/issues/7356#change-33808

Author: yanoh (Yutaka Yanoh)
Status: Assigned
Priority: Normal
Assignee: ko1 (Koichi Sasada)
Category:
Target version: 2.0.0
ruby -v: ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]


== 現象

ruby-1.9.3-p327 と ruby-2.0.0-preview1 で adlint-2.6.10 の性能比較を行った結果、
ruby-2.0.0-preview1 の方が解析時間が 1.2 倍ほど長くかかりました。

== 再現手順

 % gem install adlint
 % tar xvjf adlint-benchmark-screen.tar.bz2  <- 添付ファイル
 % cd adlint-benchmark-screen/adlint
 % time make -j 2 2>/dev/null

== 性能測定結果

=== 測定環境

* Core 2 Duo E4500 2.20GHz / 3.4GB
* Fedora 14 / Linux 2.6.35.14-106.fc14.i686

=== 測定方法

* 下記バージョンの ruby を用いて、adlint-2.6.10 で screen-4.0.3 を解析
  ruby 1.9.3p327 (2012-11-10 revision 37606) [i686-linux]  built with 
gcc-4.5.1
  ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]      built with 
gcc-4.5.1
  ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]      built with 
gcc-4.7.2

* すべて configure オプションは --prefix のみ

* 解析は 2 コアを使い切れるよう make -j 2 を指定

* できるだけ IO による遅延を抑えるため標準エラーは /dev/null へリダイレクト
  ただし解析結果ファイルの出力は抑止できていません

=== 測定結果

* ruby 1.9.3p327 (2012-11-10 revision 37606) [i686-linux]  built with 
gcc-4.5.1
  make -j 2 2> /dev/null  1335.85s user 7.10s system 184% cpu 12:07.79 
total
  make -j 2 2> /dev/null  1336.54s user 7.17s system 184% cpu 12:07.80 
total
  make -j 2 2> /dev/null  1340.71s user 7.23s system 184% cpu 12:10.69 
total

* ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]      built with 
gcc-4.5.1
  make -j 2 2> /dev/null  1626.45s user 8.08s system 184% cpu 14:48.20 
total
  make -j 2 2> /dev/null  1633.40s user 8.10s system 185% cpu 14:46.92 
total
  make -j 2 2> /dev/null  1631.37s user 7.86s system 184% cpu 14:50.18 
total

* ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]      built with 
gcc-4.7.2
  make -j 2 2> /dev/null  1531.83s user 7.85s system 184% cpu 13:53.04 
total
  make -j 2 2> /dev/null  1533.46s user 7.97s system 184% cpu 13:54.54 
total
  make -j 2 2> /dev/null  1532.89s user 8.03s system 184% cpu 13:53.33 
total

== 備考

adlint_sma コマンドは、最初のソースコード読み込み時と最後の解析結果書き出し時に
IO が走る以外は、オンメモリで計算のみを実行しています。
データ構造は木構造が多く、再帰処理を多用し、小さな一時オブジェクトを多く new し
ています。
Posted by ko1 (Koichi Sasada) (Guest)
on 2012-11-26 02:01
(Received via mailing list)
Issue #7356 has been updated by ko1 (Koichi Sasada).


最悪「refinementのせい」「siphash のせい」ということで一つ.

いや,プロファイラ作れって話か.
簡単に試せそうなら,せっかく入った dtrace で見てみたいのですが,
yanoh さん,いかがでしょうか.
----------------------------------------
Bug #7356: ruby-2.0.0-preview1 で adlint-2.6.10 が性能劣化
https://bugs.ruby-lang.org/issues/7356#change-33924

Author: yanoh (Yutaka Yanoh)
Status: Assigned
Priority: Normal
Assignee: ko1 (Koichi Sasada)
Category:
Target version: 2.0.0
ruby -v: ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]


== 現象

ruby-1.9.3-p327 と ruby-2.0.0-preview1 で adlint-2.6.10 の性能比較を行った結果、
ruby-2.0.0-preview1 の方が解析時間が 1.2 倍ほど長くかかりました。

== 再現手順

 % gem install adlint
 % tar xvjf adlint-benchmark-screen.tar.bz2  <- 添付ファイル
 % cd adlint-benchmark-screen/adlint
 % time make -j 2 2>/dev/null

== 性能測定結果

=== 測定環境

* Core 2 Duo E4500 2.20GHz / 3.4GB
* Fedora 14 / Linux 2.6.35.14-106.fc14.i686

=== 測定方法

* 下記バージョンの ruby を用いて、adlint-2.6.10 で screen-4.0.3 を解析
  ruby 1.9.3p327 (2012-11-10 revision 37606) [i686-linux]  built with 
gcc-4.5.1
  ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]      built with 
gcc-4.5.1
  ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]      built with 
gcc-4.7.2

* すべて configure オプションは --prefix のみ

* 解析は 2 コアを使い切れるよう make -j 2 を指定

* できるだけ IO による遅延を抑えるため標準エラーは /dev/null へリダイレクト
  ただし解析結果ファイルの出力は抑止できていません

=== 測定結果

* ruby 1.9.3p327 (2012-11-10 revision 37606) [i686-linux]  built with 
gcc-4.5.1
  make -j 2 2> /dev/null  1335.85s user 7.10s system 184% cpu 12:07.79 
total
  make -j 2 2> /dev/null  1336.54s user 7.17s system 184% cpu 12:07.80 
total
  make -j 2 2> /dev/null  1340.71s user 7.23s system 184% cpu 12:10.69 
total

* ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]      built with 
gcc-4.5.1
  make -j 2 2> /dev/null  1626.45s user 8.08s system 184% cpu 14:48.20 
total
  make -j 2 2> /dev/null  1633.40s user 8.10s system 185% cpu 14:46.92 
total
  make -j 2 2> /dev/null  1631.37s user 7.86s system 184% cpu 14:50.18 
total

* ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]      built with 
gcc-4.7.2
  make -j 2 2> /dev/null  1531.83s user 7.85s system 184% cpu 13:53.04 
total
  make -j 2 2> /dev/null  1533.46s user 7.97s system 184% cpu 13:54.54 
total
  make -j 2 2> /dev/null  1532.89s user 8.03s system 184% cpu 13:53.33 
total

== 備考

adlint_sma コマンドは、最初のソースコード読み込み時と最後の解析結果書き出し時に
IO が走る以外は、オンメモリで計算のみを実行しています。
データ構造は木構造が多く、再帰処理を多用し、小さな一時オブジェクトを多く new し
ています。
Posted by yanoh (Yutaka Yanoh) (Guest)
on 2012-11-26 09:43
(Received via mailing list)
Issue #7356 has been updated by yanoh (Yutaka Yanoh).


反応が遅れてすみません。
まずは、ko1 さんからリクエストがあった ruby 単体で動くベンチマークを作ってみて、
その後 dtrace してみます。

----------------------------------------
Bug #7356: ruby-2.0.0-preview1 で adlint-2.6.10 が性能劣化
https://bugs.ruby-lang.org/issues/7356#change-33943

Author: yanoh (Yutaka Yanoh)
Status: Assigned
Priority: Normal
Assignee: ko1 (Koichi Sasada)
Category:
Target version: 2.0.0
ruby -v: ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]


== 現象

ruby-1.9.3-p327 と ruby-2.0.0-preview1 で adlint-2.6.10 の性能比較を行った結果、
ruby-2.0.0-preview1 の方が解析時間が 1.2 倍ほど長くかかりました。

== 再現手順

 % gem install adlint
 % tar xvjf adlint-benchmark-screen.tar.bz2  <- 添付ファイル
 % cd adlint-benchmark-screen/adlint
 % time make -j 2 2>/dev/null

== 性能測定結果

=== 測定環境

* Core 2 Duo E4500 2.20GHz / 3.4GB
* Fedora 14 / Linux 2.6.35.14-106.fc14.i686

=== 測定方法

* 下記バージョンの ruby を用いて、adlint-2.6.10 で screen-4.0.3 を解析
  ruby 1.9.3p327 (2012-11-10 revision 37606) [i686-linux]  built with 
gcc-4.5.1
  ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]      built with 
gcc-4.5.1
  ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]      built with 
gcc-4.7.2

* すべて configure オプションは --prefix のみ

* 解析は 2 コアを使い切れるよう make -j 2 を指定

* できるだけ IO による遅延を抑えるため標準エラーは /dev/null へリダイレクト
  ただし解析結果ファイルの出力は抑止できていません

=== 測定結果

* ruby 1.9.3p327 (2012-11-10 revision 37606) [i686-linux]  built with 
gcc-4.5.1
  make -j 2 2> /dev/null  1335.85s user 7.10s system 184% cpu 12:07.79 
total
  make -j 2 2> /dev/null  1336.54s user 7.17s system 184% cpu 12:07.80 
total
  make -j 2 2> /dev/null  1340.71s user 7.23s system 184% cpu 12:10.69 
total

* ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]      built with 
gcc-4.5.1
  make -j 2 2> /dev/null  1626.45s user 8.08s system 184% cpu 14:48.20 
total
  make -j 2 2> /dev/null  1633.40s user 8.10s system 185% cpu 14:46.92 
total
  make -j 2 2> /dev/null  1631.37s user 7.86s system 184% cpu 14:50.18 
total

* ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]      built with 
gcc-4.7.2
  make -j 2 2> /dev/null  1531.83s user 7.85s system 184% cpu 13:53.04 
total
  make -j 2 2> /dev/null  1533.46s user 7.97s system 184% cpu 13:54.54 
total
  make -j 2 2> /dev/null  1532.89s user 8.03s system 184% cpu 13:53.33 
total

== 備考

adlint_sma コマンドは、最初のソースコード読み込み時と最後の解析結果書き出し時に
IO が走る以外は、オンメモリで計算のみを実行しています。
データ構造は木構造が多く、再帰処理を多用し、小さな一時オブジェクトを多く new し
ています。
Posted by yanoh (Yutaka Yanoh) (Guest)
on 2012-11-27 13:21
(Received via mailing list)
Issue #7356 has been updated by yanoh (Yutaka Yanoh).


=begin
まずは ruby 単体で動くベンチマークプログラムを adlint-benchmark という gem で作成しました。

== 短時間で終了する版で測定

 % gem install adlint-benchmark
 % adlint_bm -p
                                    user     system      total 
real
 screen-4.0.3/process.c.small  16.040000   0.050000  16.090000 ( 
16.228486)
   16.430s user, 0.070s system, 00:00:16.50 total

== オリジナルの process.c 版で測定

 % adlint_bm -t "screen-4.0.3/process.c" -p
                              user     system      total        real
 screen-4.0.3/process.c 213.220000   0.260000 213.480000 (215.310007)
   213.620s user, 0.280s system, 00:03:33.90 total

== ベンチマークドライバのサンプル

AdLint::Benchmark.run を自前のドライバから呼び出して測定することも可能です。

 require "adlint/benchmark"
 AdLint::Benchmark.run("screen-4.0.3/process.c.small", true)
=end

----------------------------------------
Bug #7356: ruby-2.0.0-preview1 で adlint-2.6.10 が性能劣化
https://bugs.ruby-lang.org/issues/7356#change-34032

Author: yanoh (Yutaka Yanoh)
Status: Assigned
Priority: Normal
Assignee: ko1 (Koichi Sasada)
Category:
Target version: 2.0.0
ruby -v: ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]


== 現象

ruby-1.9.3-p327 と ruby-2.0.0-preview1 で adlint-2.6.10 の性能比較を行った結果、
ruby-2.0.0-preview1 の方が解析時間が 1.2 倍ほど長くかかりました。

== 再現手順

 % gem install adlint
 % tar xvjf adlint-benchmark-screen.tar.bz2  <- 添付ファイル
 % cd adlint-benchmark-screen/adlint
 % time make -j 2 2>/dev/null

== 性能測定結果

=== 測定環境

* Core 2 Duo E4500 2.20GHz / 3.4GB
* Fedora 14 / Linux 2.6.35.14-106.fc14.i686

=== 測定方法

* 下記バージョンの ruby を用いて、adlint-2.6.10 で screen-4.0.3 を解析
  ruby 1.9.3p327 (2012-11-10 revision 37606) [i686-linux]  built with 
gcc-4.5.1
  ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]      built with 
gcc-4.5.1
  ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]      built with 
gcc-4.7.2

* すべて configure オプションは --prefix のみ

* 解析は 2 コアを使い切れるよう make -j 2 を指定

* できるだけ IO による遅延を抑えるため標準エラーは /dev/null へリダイレクト
  ただし解析結果ファイルの出力は抑止できていません

=== 測定結果

* ruby 1.9.3p327 (2012-11-10 revision 37606) [i686-linux]  built with 
gcc-4.5.1
  make -j 2 2> /dev/null  1335.85s user 7.10s system 184% cpu 12:07.79 
total
  make -j 2 2> /dev/null  1336.54s user 7.17s system 184% cpu 12:07.80 
total
  make -j 2 2> /dev/null  1340.71s user 7.23s system 184% cpu 12:10.69 
total

* ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]      built with 
gcc-4.5.1
  make -j 2 2> /dev/null  1626.45s user 8.08s system 184% cpu 14:48.20 
total
  make -j 2 2> /dev/null  1633.40s user 8.10s system 185% cpu 14:46.92 
total
  make -j 2 2> /dev/null  1631.37s user 7.86s system 184% cpu 14:50.18 
total

* ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]      built with 
gcc-4.7.2
  make -j 2 2> /dev/null  1531.83s user 7.85s system 184% cpu 13:53.04 
total
  make -j 2 2> /dev/null  1533.46s user 7.97s system 184% cpu 13:54.54 
total
  make -j 2 2> /dev/null  1532.89s user 8.03s system 184% cpu 13:53.33 
total

== 備考

adlint_sma コマンドは、最初のソースコード読み込み時と最後の解析結果書き出し時に
IO が走る以外は、オンメモリで計算のみを実行しています。
データ構造は木構造が多く、再帰処理を多用し、小さな一時オブジェクトを多く new し
ています。
Posted by wanabe (_ wanabe) (Guest)
on 2012-11-28 16:34
(Received via mailing list)
Issue #7356 has been updated by wanabe (_ wanabe).

File r37410-adapted37582-partially.patch added
File r37410-revert34948-partially.patch added
Status changed from Assigned to Feedback

横からすみません。adlint-benchmark 使わせていただきました。
git bisect で調べてみたのですが、r34948 で rb_ary_push_m() が
rb_ary_cat() を呼び出すように変更されているのが性能劣化の原因ではないでしょうか。
また、r37582 でその rb_ary_cat() の内容が変更されたため、再度性能が回復しているように見えます。
実験的に r34948 の関連する部分を revert するパッチと、r37582 の関連する部分を適用する二つのパッチを書きました。
r34948 ~ r37581 の間で、どちらのパッチを用いても速度が改善されると思われます。
チケット起票時に使われた r37410 (でいいのでしょうか? r37411 は見つかりませんでした)を使って確認しました。
yanoh さん、よろしければご確認いただけますでしょうか。
最後に実験結果を示します。参考にしていただければ幸いです
長々と書きましたが、r37582 以降 trunk で性能劣化はないのではないか、と思います。
(本題から逸れるので調べませんでしたが、むしろ r37410 ~ r37581 の間でも
 何らかの性能改善があったように見受けられます。)

* ruby 1.9.3p327 (2012-11-10 revision 37605)
                                   user     system      total 
real
screen-4.0.3/process.c.small  26.880000   0.100000  26.980000 ( 
27.002153)
  27.470s user, 0.130s system, 00:00:27.59 total

* trunk r34947
                                   user     system      total 
real
screen-4.0.3/process.c.small  27.500000   0.120000  27.620000 ( 
27.645960)
  28.120s user, 0.180s system, 00:00:28.30 total

* trunk r34948
                                   user     system      total 
real
screen-4.0.3/process.c.small  33.080000   0.190000  33.270000 ( 
33.382366)
  33.730s user, 0.220s system, 00:00:33.94 total

* trunk r37581
                                   user     system      total 
real
screen-4.0.3/process.c.small  25.910000   0.140000  26.050000 ( 
26.057930)
  26.550s user, 0.190s system, 00:00:26.74 total

* trunk r37582
                                   user     system      total 
real
screen-4.0.3/process.c.small  21.480000   0.130000  21.610000 ( 
21.608838)
  22.090s user, 0.190s system, 00:00:22.28 total

* trunk r37410
                                   user     system      total 
real
screen-4.0.3/process.c.small  33.690000   0.100000  33.790000 ( 
33.858404)
  34.360s user, 0.140s system, 00:00:34.50 total

* trunk r37410 with r37410-revert34948-partially.patch
                                   user     system      total 
real
screen-4.0.3/process.c.small  26.710000   0.120000  26.830000 ( 
26.879693)
  27.390s user, 0.160s system, 00:00:27.55 total

* trunk r37410 with r37410-adapted37582.patch
                                   user     system      total 
real
screen-4.0.3/process.c.small  26.830000   0.100000  26.930000 ( 
27.078610)
  27.490s user, 0.140s system, 00:00:27.62 total

----------------------------------------
Bug #7356: ruby-2.0.0-preview1 で adlint-2.6.10 が性能劣化
https://bugs.ruby-lang.org/issues/7356#change-34087

Author: yanoh (Yutaka Yanoh)
Status: Feedback
Priority: Normal
Assignee: ko1 (Koichi Sasada)
Category:
Target version: 2.0.0
ruby -v: ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]


== 現象

ruby-1.9.3-p327 と ruby-2.0.0-preview1 で adlint-2.6.10 の性能比較を行った結果、
ruby-2.0.0-preview1 の方が解析時間が 1.2 倍ほど長くかかりました。

== 再現手順

 % gem install adlint
 % tar xvjf adlint-benchmark-screen.tar.bz2  <- 添付ファイル
 % cd adlint-benchmark-screen/adlint
 % time make -j 2 2>/dev/null

== 性能測定結果

=== 測定環境

* Core 2 Duo E4500 2.20GHz / 3.4GB
* Fedora 14 / Linux 2.6.35.14-106.fc14.i686

=== 測定方法

* 下記バージョンの ruby を用いて、adlint-2.6.10 で screen-4.0.3 を解析
  ruby 1.9.3p327 (2012-11-10 revision 37606) [i686-linux]  built with 
gcc-4.5.1
  ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]      built with 
gcc-4.5.1
  ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]      built with 
gcc-4.7.2

* すべて configure オプションは --prefix のみ

* 解析は 2 コアを使い切れるよう make -j 2 を指定

* できるだけ IO による遅延を抑えるため標準エラーは /dev/null へリダイレクト
  ただし解析結果ファイルの出力は抑止できていません

=== 測定結果

* ruby 1.9.3p327 (2012-11-10 revision 37606) [i686-linux]  built with 
gcc-4.5.1
  make -j 2 2> /dev/null  1335.85s user 7.10s system 184% cpu 12:07.79 
total
  make -j 2 2> /dev/null  1336.54s user 7.17s system 184% cpu 12:07.80 
total
  make -j 2 2> /dev/null  1340.71s user 7.23s system 184% cpu 12:10.69 
total

* ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]      built with 
gcc-4.5.1
  make -j 2 2> /dev/null  1626.45s user 8.08s system 184% cpu 14:48.20 
total
  make -j 2 2> /dev/null  1633.40s user 8.10s system 185% cpu 14:46.92 
total
  make -j 2 2> /dev/null  1631.37s user 7.86s system 184% cpu 14:50.18 
total

* ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]      built with 
gcc-4.7.2
  make -j 2 2> /dev/null  1531.83s user 7.85s system 184% cpu 13:53.04 
total
  make -j 2 2> /dev/null  1533.46s user 7.97s system 184% cpu 13:54.54 
total
  make -j 2 2> /dev/null  1532.89s user 8.03s system 184% cpu 13:53.33 
total

== 備考

adlint_sma コマンドは、最初のソースコード読み込み時と最後の解析結果書き出し時に
IO が走る以外は、オンメモリで計算のみを実行しています。
データ構造は木構造が多く、再帰処理を多用し、小さな一時オブジェクトを多く new し
ています。
Posted by yanoh (Yutaka Yanoh) (Guest)
on 2012-12-01 12:33
(Received via mailing list)
Issue #7356 has been updated by yanoh (Yutaka Yanoh).


wanabe さん、情報ありがとうございます。

下記のバージョンで再測定してみました。
* ruby 1.9.3p327 (2012-11-10 revision 37606) [i686-linux]
* ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]  <- 2.0.0-preview1
* ruby 2.0.0dev (2012-11-29 trunk 37962) [i686-linux]  <- trunk 最新

== 結論

* adlint_bm (screen-4.0.3/process.c.small) では、trunk 最新 (r37962) が一番高速
* adlint_bm (screen-4.0.3/process.c) では、ruby-1.9.3p327 が一番高速

2.0.0-preview1 (r37411) よりは trunk 最新 (r37962) の方がかなり性能回復していま
すが、それでも条件によっては ruby-1.9.3p327 より遅い場合があるようです。

adlint_bm のターゲット screen-4.0.3/process.c.small は、ベンチマーク時間を短縮
するためオリジナルの screen-4.0.3/process.c の大部分を削除したものです。
それぞれのターゲットで、ベンチマーク時の測定内容がかなり異なるようです。

== 測定条件

trunk の最新で adlint-2.6.10 を実行したところ、ブロック無しの Enumerator.new を
使用していたため、大量の warning が出力されました。
これが測定結果に影響を与えるかもしれないと思い、Object#to_enum に変更したものを
adlint-2.6.12 としてリリースし、このバージョンで測定しました。

また、adlint_bm についても -c NUM で測定回数を指定可能にして
adlint-benchmark-1.1.0 としてリリースし、このバージョンを使用しました。

== 測定結果

=== "screen-4.0.3/process.c.small" ターゲット

測定コマンド : adlint_bm -p

* ruby 1.9.3p327 (2012-11-10 revision 37606) [i686-linux]
                                         user     system      total 
real
 screen-4.0.3/process.c.small #1    16.250000   0.050000  16.300000 ( 
16.434142)
 total                              16.250000   0.050000  16.300000 ( 
16.434142)

* ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]  <- 2.0.0-preview1
                                         user     system      total 
real
 screen-4.0.3/process.c.small #1    21.540000   0.080000  21.620000 ( 
21.800759)
 total                              21.540000   0.080000  21.620000 ( 
21.800759)

* ruby 2.0.0dev (2012-11-29 trunk 37962) [i686-linux]  <- trunk 最新
                                         user     system      total 
real
 screen-4.0.3/process.c.small #1    15.220000   0.050000  15.270000 ( 
15.392969)
 total                              15.220000   0.050000  15.270000 ( 
15.392969)

=== "screen-4.0.3/process.c" ターゲット

測定コマンド : adlint_bm -t "screen-4.0.3/process.c" -p

* ruby 1.9.3p327 (2012-11-10 revision 37606) [i686-linux]
                                   user     system      total 
real
 screen-4.0.3/process.c #1   214.060000   0.470000 214.530000 
(216.548791)
 total                       214.060000   0.470000 214.530000 
(216.548791)

* ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]  <- 2.0.0-preview1
                                   user     system      total 
real
 screen-4.0.3/process.c #1   244.090000   0.520000 244.610000 
(246.698421)
 total                       244.090000   0.520000 244.610000 
(246.698421)

* ruby 2.0.0dev (2012-11-29 trunk 37962) [i686-linux]  <- trunk 最新
                                   user     system      total 
real
 screen-4.0.3/process.c #1   227.260000   0.310000 227.570000 
(229.420830)
 total                       227.260000   0.310000 227.570000 
(229.420830)

== さらに測定

"screen-4.0.3/process.c" ターゲットについて、-c NUM オプションで測定を繰り返し
て見たところ、1.9.3 と 2.0.0 で動作特性が異なる傾向を持つことが分かりました。

2.0.0 では初回のみ遅くなっているようです。やはりプロファイラによる詳細な分析が
必要でしょうか。

測定コマンド : adlint_bm -t "screen-4.0.3/process.c" -c 3 -p

* ruby 1.9.3p327 (2012-11-10 revision 37606) [i686-linux]
                                   user     system      total 
real
 screen-4.0.3/process.c #1   217.300000   0.100000 217.400000 
(218.929445)
 screen-4.0.3/process.c #2   217.790000   0.070000 217.860000 
(219.410483)
 screen-4.0.3/process.c #3   216.250000   0.300000 216.550000 
(218.345587)
 total                       651.340000   0.470000 651.810000 
(656.685515)

* ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]  <- 2.0.0-preview1
                                   user     system      total 
real
 screen-4.0.3/process.c #1   241.460000   0.180000 241.640000 
(243.313287)
 screen-4.0.3/process.c #2   213.320000   0.120000 213.440000 
(214.921192)
 screen-4.0.3/process.c #3   201.570000   0.050000 201.620000 
(203.014434)
 total                       656.350000   0.350000 656.700000 
(661.248912)

* ruby 2.0.0dev (2012-11-29 trunk 37962) [i686-linux]  <- trunk 最新
                                   user     system      total 
real
 screen-4.0.3/process.c #1   227.050000   0.100000 227.150000 
(228.728632)
 screen-4.0.3/process.c #2   220.260000   0.080000 220.340000 
(221.945992)
 screen-4.0.3/process.c #3   223.870000   0.420000 224.290000 
(226.271632)
 total                       671.180000   0.600000 671.780000 
(676.946256)

----------------------------------------
Bug #7356: ruby-2.0.0-preview1 で adlint-2.6.10 が性能劣化
https://bugs.ruby-lang.org/issues/7356#change-34275

Author: yanoh (Yutaka Yanoh)
Status: Feedback
Priority: Normal
Assignee: ko1 (Koichi Sasada)
Category:
Target version: 2.0.0
ruby -v: ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]


== 現象

ruby-1.9.3-p327 と ruby-2.0.0-preview1 で adlint-2.6.10 の性能比較を行った結果、
ruby-2.0.0-preview1 の方が解析時間が 1.2 倍ほど長くかかりました。

== 再現手順

 % gem install adlint
 % tar xvjf adlint-benchmark-screen.tar.bz2  <- 添付ファイル
 % cd adlint-benchmark-screen/adlint
 % time make -j 2 2>/dev/null

== 性能測定結果

=== 測定環境

* Core 2 Duo E4500 2.20GHz / 3.4GB
* Fedora 14 / Linux 2.6.35.14-106.fc14.i686

=== 測定方法

* 下記バージョンの ruby を用いて、adlint-2.6.10 で screen-4.0.3 を解析
  ruby 1.9.3p327 (2012-11-10 revision 37606) [i686-linux]  built with 
gcc-4.5.1
  ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]      built with 
gcc-4.5.1
  ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]      built with 
gcc-4.7.2

* すべて configure オプションは --prefix のみ

* 解析は 2 コアを使い切れるよう make -j 2 を指定

* できるだけ IO による遅延を抑えるため標準エラーは /dev/null へリダイレクト
  ただし解析結果ファイルの出力は抑止できていません

=== 測定結果

* ruby 1.9.3p327 (2012-11-10 revision 37606) [i686-linux]  built with 
gcc-4.5.1
  make -j 2 2> /dev/null  1335.85s user 7.10s system 184% cpu 12:07.79 
total
  make -j 2 2> /dev/null  1336.54s user 7.17s system 184% cpu 12:07.80 
total
  make -j 2 2> /dev/null  1340.71s user 7.23s system 184% cpu 12:10.69 
total

* ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]      built with 
gcc-4.5.1
  make -j 2 2> /dev/null  1626.45s user 8.08s system 184% cpu 14:48.20 
total
  make -j 2 2> /dev/null  1633.40s user 8.10s system 185% cpu 14:46.92 
total
  make -j 2 2> /dev/null  1631.37s user 7.86s system 184% cpu 14:50.18 
total

* ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]      built with 
gcc-4.7.2
  make -j 2 2> /dev/null  1531.83s user 7.85s system 184% cpu 13:53.04 
total
  make -j 2 2> /dev/null  1533.46s user 7.97s system 184% cpu 13:54.54 
total
  make -j 2 2> /dev/null  1532.89s user 8.03s system 184% cpu 13:53.33 
total

== 備考

adlint_sma コマンドは、最初のソースコード読み込み時と最後の解析結果書き出し時に
IO が走る以外は、オンメモリで計算のみを実行しています。
データ構造は木構造が多く、再帰処理を多用し、小さな一時オブジェクトを多く new し
ています。
Posted by ko1 (Koichi Sasada) (Guest)
on 2013-02-13 07:56
(Received via mailing list)
Issue #7356 has been updated by ko1 (Koichi Sasada).

Target version changed from 2.0.0 to next minor

放っておいてすみません。
もうちょっと見ないとわからんですねぇ。

というわけで、次のバージョンで頑張りましょう。
----------------------------------------
Bug #7356: ruby-2.0.0-preview1 で adlint-2.6.10 が性能劣化
https://bugs.ruby-lang.org/issues/7356#change-36201

Author: yanoh (Yutaka Yanoh)
Status: Feedback
Priority: Normal
Assignee: ko1 (Koichi Sasada)
Category:
Target version: next minor
ruby -v: ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]


== 現象

ruby-1.9.3-p327 と ruby-2.0.0-preview1 で adlint-2.6.10 の性能比較を行った結果、
ruby-2.0.0-preview1 の方が解析時間が 1.2 倍ほど長くかかりました。

== 再現手順

 % gem install adlint
 % tar xvjf adlint-benchmark-screen.tar.bz2  <- 添付ファイル
 % cd adlint-benchmark-screen/adlint
 % time make -j 2 2>/dev/null

== 性能測定結果

=== 測定環境

* Core 2 Duo E4500 2.20GHz / 3.4GB
* Fedora 14 / Linux 2.6.35.14-106.fc14.i686

=== 測定方法

* 下記バージョンの ruby を用いて、adlint-2.6.10 で screen-4.0.3 を解析
  ruby 1.9.3p327 (2012-11-10 revision 37606) [i686-linux]  built with 
gcc-4.5.1
  ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]      built with 
gcc-4.5.1
  ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]      built with 
gcc-4.7.2

* すべて configure オプションは --prefix のみ

* 解析は 2 コアを使い切れるよう make -j 2 を指定

* できるだけ IO による遅延を抑えるため標準エラーは /dev/null へリダイレクト
  ただし解析結果ファイルの出力は抑止できていません

=== 測定結果

* ruby 1.9.3p327 (2012-11-10 revision 37606) [i686-linux]  built with 
gcc-4.5.1
  make -j 2 2> /dev/null  1335.85s user 7.10s system 184% cpu 12:07.79 
total
  make -j 2 2> /dev/null  1336.54s user 7.17s system 184% cpu 12:07.80 
total
  make -j 2 2> /dev/null  1340.71s user 7.23s system 184% cpu 12:10.69 
total

* ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]      built with 
gcc-4.5.1
  make -j 2 2> /dev/null  1626.45s user 8.08s system 184% cpu 14:48.20 
total
  make -j 2 2> /dev/null  1633.40s user 8.10s system 185% cpu 14:46.92 
total
  make -j 2 2> /dev/null  1631.37s user 7.86s system 184% cpu 14:50.18 
total

* ruby 2.0.0dev (2012-11-01 trunk 37411) [i686-linux]      built with 
gcc-4.7.2
  make -j 2 2> /dev/null  1531.83s user 7.85s system 184% cpu 13:53.04 
total
  make -j 2 2> /dev/null  1533.46s user 7.97s system 184% cpu 13:54.54 
total
  make -j 2 2> /dev/null  1532.89s user 8.03s system 184% cpu 13:53.33 
total

== 備考

adlint_sma コマンドは、最初のソースコード読み込み時と最後の解析結果書き出し時に
IO が走る以外は、オンメモリで計算のみを実行しています。
データ構造は木構造が多く、再帰処理を多用し、小さな一時オブジェクトを多く new し
ています。
Please log in before posting. Registration is free and takes only a minute.
Existing account (Switch to SSL-encrypted connection)
NEW: Do you have a Google/GoogleMail or Yahoo account? No registration required!
Log in with Google account | Log in with Yahoo account
No account? Register here.