awrznc / GalM

Matching library.
https://awrznc.github.io/GalM/
MIT License
3 stars 0 forks source link

want to speeding up #15

Open awrznc opened 4 years ago

awrznc commented 4 years ago

GalMコマンドが遅いので高速化したい。

  1. 特定の条件で計測して目標を決める。
  2. プロファイラを利用して、コードのどの部分で処理が遅くなっているのか確認する。
  3. 最適化できそうなホットスポットを見つけたら最適化する。
awrznc commented 4 years ago

慣れないことをするので調査してみた。

調査

計測

性能テストツールを利用して、全体でどのくらいの時間がかかっているか確認する。

こんな感じで実行して計測するのがよさそう?
```bash # Rubyを利用して1000文字1000行のテキストファイルを作成する例 ruby -e 'for _ in 1..1000 do puts "a" * 1000 end' > ./data.txt # catコマンドを利用してファイル内容をパイプで渡す cat data.txt | galm sample ```

(追記) この方法じゃ駄目だ。 一行一行の内容を変更しておかないとソート部分の計測が実際の利用に沿わなくなってしまう。

候補は以下。

standard benchmark test Nightly Rustで利用できる機能。最適化の影響も受けてしまうので注意。 https://doc.rust-jp.rs/the-rust-programming-language-ja/1.6/book/benchmark-tests.html

criterion Stable Rustでも使えるベンチマークツール。 https://crates.io/crates/criterion

Bash

こんな感じで手動計測。
```bash #!/bin/bash function repeat() { SCRIPT_DIR=$(cd $(dirname $0); pwd) GALM_DIR=${SCRIPT_DIR}/../../target/release/examples CAT_DIR=${SCRIPT_DIR}/data.txt for i in `seq 1 ${1}`; do cat ${CAT_DIR} | ${GALM_DIR}/galm a done } # 特定のコマンドを10回繰り返す time (repeat 10) > /dev/null # => 結果を10で割る ```

解析

プロファイラ(性能解析ツール)を利用して、コードのどの部分で処理が遅くなっているのか確認する。 候補は以下。

cargo-profiler 日本語の記事が多いプロファイラ。 https://crates.io/crates/cargo-profiler

Inferno DTraceのパーツをRustに移植したもの。 名前がクールだが使うのが難しそう。 https://crates.io/crates/inferno

hotspot Linux で perf 測って解析するときには Hotspot の GUI viewer がとても便利らしい(参考: https://blog.mozilla.org/nnethercote/2020/09/08/how-to-speed-up-the-rust-compiler-one-last-time/https://github.com/KDAB/hotspot

awrznc commented 4 years ago

実践

計測

おおよそ 10 ~ 11s。 まずは real 5s を目指したいな。

$ # 実行ファイルの作成
$ cargo build --example galm --release

$ # 計測
$ time cat ./docs/assets/csv/characters.csv | head -n 100 | ./target/release/examples/galm a > /dev/null

real    0m10.886s
user    0m10.880s
sys     0m0.010s

解析

cargo-profiler

$ # CentOS8の場合
$ dnf install -y valgrind

$ # cargo-profiler のインストール
$ cargo install cargo-profiler

$ # 実行
$ cargo profiler callgrind --bin ./target/release/examples/galm -n 10

Profiling galm with callgrind...

Total Instructions...839,457

207,912 (24.8%) ???:do_lookup_x
-----------------------------------------------------------------------
162,701 (19.4%) ???:strcmp
-----------------------------------------------------------------------
91,012 (10.8%) ???:_dl_lookup_symbol_x
-----------------------------------------------------------------------
71,372 (8.5%) ???:_dl_relocate_object
-----------------------------------------------------------------------
66,269 (7.9%) ???:_dl_addr
-----------------------------------------------------------------------
51,326 (6.1%) ???:_dl_name_match_p
-----------------------------------------------------------------------
50,164 (6.0%) ???:_IO_vfscanf
-----------------------------------------------------------------------
24,338 (2.9%) ???:check_match
-----------------------------------------------------------------------
22,284 (2.7%) ???:____strtoul_l_internal
-----------------------------------------------------------------------
8,828 (1.1%) ???:__GI___tunables_init
-----------------------------------------------------------------------

1行目のdo_lookup_xはlibcの関数らしいけど、役割がちょっとわからないし、どこでよばれているのかもわからない。。 2行目は文字列の比較かな。 3行目も1行目同様にわからないな。。

Inferno ( flamegraph )

$ # perf のインストール
$ dnf install -y perf

$ # flamegraphのインストール
$ cargo install flamegraph

$ # 実行
$ flamegraph -o my_flamegraph.svg ./target/release/examples/galm 犬 --file ./src/lib.rs
Couldn't record kernel reference relocation symbol
Symbol resolution may be skewed if relocation was used (e.g. kexec).
Check /proc/kallsyms permission or run as root.
 :
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.246 MB perf.data (30 samples) ]
writing flamegraph to "my_flamegraph.svg"

rootで実行してって言われるけど、とりあえずsvgを出力することができた。

image

https://www.slideshare.net/brendangregg/blazing-performance-with-flame-graphs#40

横幅が長いほど長時間CPUを使っていることになるらしい。 予想はしてたけどやっぱ文字同士の距離の取得部分だよなあ(単純に計算量が多い)

awrznc commented 4 years ago

とりあえず出力の速度を上げてみよう。 現在はこんな感じ。

fn main() {
    let vec = vec!["sample"; 10_000_000];
    for value in vec {
        println!("{}", value);
    }
}
cargo build --release && time ./target/release/puts > /dev/null
   Compiling puts v0.1.0 (/tmp/puts)
    Finished release [optimized] target(s) in 0.37s

real    0m7.011s
user    0m4.772s
sys     0m2.238s

バッファリングしてみる。

use std::io::{stdout, Write, BufWriter};

fn main() {
    let vec = vec!["sample"; 10_000_000];
    let out = stdout();
    let mut out = BufWriter::new(out.lock());
    for value in vec {
        out.write(value.as_bytes()).unwrap();
        out.write(b"\n").unwrap();
    }
}
cargo build --release && time ./target/release/puts > /dev/null
   Compiling puts v0.1.0 (/tmp/puts)
    Finished release [optimized] target(s) in 0.53s

real    0m0.273s
user    0m0.204s
sys     0m0.069s

一千万行も処理することはないだろうけど結構早くなるので取り入れてみる。

$ # 計測
$ cargo build --example galm --release && time cat ./docs/assets/csv/characters.csv | head -n 100 | ./target/release/examples/galm a > /dev/null

real    0m10.272s
user    0m10.223s
sys     0m0.029s

わかってたけどそんなに早くはならない。 5回程再実行してみたけど前回以上の値は出なかった上に9秒台の結果が出てきたので、少しは早くなっているような気がする(誤差かもしれないけど)

(追記)

16 で対応しました。

awrznc commented 4 years ago

時間がかかっているソートをどうにかしてみる。

sort_by_keysort_by_cached_key に変更してみる。 https://doc.rust-lang.org/std/vec/struct.Vec.html#method.sort_by_cached_key

$ cargo build --example galm --release && time cat ./docs/assets/csv/characters.csv | head -n 100 | ./target/release/examples/galm a > /dev/null

real    0m0.907s
user    0m0.889s
sys     0m0.018s

思わず二度見。めちゃくちゃ改善した。 およそ10倍の速度。

しかもちゃんとソートされている。どんな仕組みなんだ。。 関数内でまったく同じ処理を繰り返しているわけじゃないから、一部をキャッシュしてるってことかな。 時間があったら今度ソースコードを追いかけてみよう。