Performance tuning

[kohei-noda-qcrg]

• プロファイリングを行ってパフォーマンスチューニングしました

  • 具体的にはcopy.deepcopyをpickle.dumps, loadsに置き換えたり、re.splitを正規表現を使わない方法に置き換えたり、dictの検索をstrで結合して単一キーにするのではなく、複数キーにするなどしてプログラムの高速化を図りました
  • パフォーマンス測定結果
  • 使用データ: Cm3+_phen.out (216MB)

    noda@DESKTOP-1C7AGIU ~/develop/sum_dirac_dfcoef (performance-tuning) $ ls -lh Cm3+_phen.out 
    -rw-r--r-- 1 noda noda 216M Jan 19 19:08 Cm3+_phen.out

  • パフォーマンス測定用スクリプト
    • 10回同じコマンドを実行して実行時間の平均値を測定しました

      
      import subprocess
      import timeit

  cmd = "sum_dirac_dfcoef -i ./Cm3+_phen.out -g" print(f"Start running \"{cmd}\" for 10 times...") t = timeit.timeit("subprocess.run(cmd.split(), check=True)", globals=globals(), number=10) print(f"Total time: {t} sec") print(f"Average time: {t / 10} sec")

  - 実行結果
    - チューニング後は約1.25倍速になりました
  ```bash
  noda@DESKTOP-1C7AGIU ~/develop/sum_dirac_dfcoef (main) $ python run.py 
  Start running "sum_dirac_dfcoef -i ./Cm3+_phen.out -g" for 10 times...
  Total time: 501.0955908120377 sec
  Average time: 50.10955908120377 sec
  noda@DESKTOP-1C7AGIU ~/develop/sum_dirac_dfcoef (main) $ git checkout performance-tuning 
  Switched to branch 'performance-tuning'
  noda@DESKTOP-1C7AGIU ~/develop/sum_dirac_dfcoef (performance-tuning) $ python run.py 
  Start running "sum_dirac_dfcoef -i ./Cm3+_phen.out -g" for 10 times...
  Total time: 398.7336607740144 sec
  Average time: 39.87336607740144 sec

  • プロファイリング方法
  • python -m cProfile -s cumtime -m sum_dirac_dfcoef -i ./Cm3+_phen.out -g > perf_result で関数レベルのプロファイリングが可能
    • 詳細はPython公式ドキュメントを参照してください
  • プロファイリング結果
  • 関数呼び出しの回数は約75%に減少した
  • privec_reader.pyのadd_coefficientとその関数内で呼ばれる関数の呼び出し回数が非常に多く、かつ全体の実行時間の75-80%を占めている
    • 今回のCm3_phen.outであれば2,767,590回呼び出されている
    • 呼び出し回数が多いのは、add_coefficientが呼ばれる回数がPRIVECのデータ中のCoeffcientが書かれた行数に等しいためである
    • 各MOのPRIVECのデータごとに並列処理をすれば合計の呼び出し回数は変わらないが、全体の実行時間は短縮されるかもしれない。ただし変更の規模が大きそうなので別のissue,PRで対応予定

プロファイリングのデータ(データが多いのでcumtimeが0.1秒以上のもののみ表示)

本プルリク前の最新のmain, v4.1.1をpip installすれば同じバージョンのソースコードが得られる

208295271 function calls (201462563 primitive calls) in 97.571 seconds Ordered by: cumulative time ncalls tottime percall cumtime percall filename:lineno(function) 305/1 0.010 0.000 97.571 97.571 {built-in method builtins.exec} 1 0.000 0.000 97.571 97.571 runpy.py:200(run_module) 1 0.000 0.000 97.473 97.473 runpy.py:64(_run_code) 1 0.000 0.000 97.473 97.473 __main__.py:1() 1 0.000 0.000 97.473 97.473 sum_dirac_dfcoef.py:10(main) 1 7.278 7.278 97.253 97.253 privec_reader.py:40(read_privec_data) 2767590 6.719 0.000 73.422 0.000 privec_reader.py:171(add_coefficient) 2767590 1.522 0.000 39.345 0.000 coefficient.py:24(get_coefficient) 2767590 9.663 0.000 37.823 0.000 coefficient.py:38(parse_line) 5550790 4.343 0.000 20.790 0.000 utils.py:7(space_separated_parsing) 2767590 3.119 0.000 14.551 0.000 data.py:19(add_coefficient) 5551753 2.232 0.000 13.552 0.000 re.py:223(split) 2767590 6.510 0.000 12.505 0.000 coefficient.py:70() 2043517 3.635 0.000 11.441 0.000 main.py:736(__setattr__) 6708346/185212 4.883 0.000 10.822 0.000 copy.py:128(deepcopy) 368691/185151 1.523 0.000 9.806 0.000 copy.py:258(_reconstruct) 5551753 8.437 0.000 8.437 0.000 {method 'split' of 're.Pattern' objects} 302562/185211 0.781 0.000 8.355 0.000 copy.py:226(_deepcopy_dict) 11070360 3.833 0.000 4.673 0.000 utils.py:25(is_float) 4944208/4944205 2.081 0.000 3.619 0.000 {built-in method builtins.getattr} 2767593 0.917 0.000 3.534 0.000 main.py:154(__init__) 2767590 1.130 0.000 2.970 0.000 atoms.py:38(count_remaining_functions) 1610 0.017 0.000 2.919 0.002 privec_reader.py:200(add_current_mo_data_to_data_all_mo) 5557740 1.913 0.000 2.891 0.000 re.py:289(_compile) 2767593 2.617 0.000 2.617 0.000 {method 'validate_python' of 'pydantic_core._pydantic_core.SchemaValidator' objects} 2043517 2.602 0.000 2.602 0.000 {method 'validate_assignment' of 'pydantic_core._pydantic_core.SchemaValidator' objects} 1611 0.038 0.000 2.516 0.002 copy.py:200(_deepcopy_list) 117412 0.183 0.000 2.204 0.000 main.py:686(__deepcopy__) 5550790 2.187 0.000 2.187 0.000 utils.py:9() 5535181 2.060 0.000 2.060 0.000 {built-in method builtins.sum} 2767590 1.262 0.000 1.787 0.000 privec_reader.py:92(is_this_row_for_coefficients) 2043566 1.268 0.000 1.538 0.000 _model_construction.py:197(__getattr__) 20040821 1.530 0.000 1.530 0.000 {method 'get' of 'dict' objects} 16607799 1.379 0.000 1.379 0.000 {method 'strip' of 'str' objects} 11070360 1.322 0.000 1.322 0.000 {built-in method builtins.pow} 8170962/8170934 1.304 0.000 1.305 0.000 {built-in method builtins.isinstance} 2043530 0.594 0.000 0.917 0.000 _fields.py:262(is_valid_field_name) 2767590 0.887 0.000 0.887 0.000 atoms.py:28(decrement_function) 2775987 0.628 0.000 0.880 0.000 privec_reader.py:96(need_to_skip_this_line) 11070360 0.839 0.000 0.839 0.000 {method 'isdecimal' of 'str' objects} 8337054/8336850 0.727 0.000 0.727 0.000 {built-in method builtins.len} 5554462 0.710 0.000 0.710 0.000 {method 'rstrip' of 'str' objects} 8356750 0.588 0.000 0.588 0.000 {built-in method builtins.id} 790276 0.428 0.000 0.558 0.000 copy.py:242(_keep_alive) 2769740 0.488 0.000 0.488 0.000 {method 'replace' of 'str' objects} 5918070 0.341 0.000 0.341 0.000 copy.py:182(_deepcopy_atomic) 2767695 0.328 0.000 0.328 0.000 {method 'isdigit' of 'str' objects} 1610 0.006 0.000 0.324 0.000 data.py:35(fileter_coefficients_by_threshold) 2045536 0.323 0.000 0.323 0.000 {method 'startswith' of 'str' objects} 370302 0.095 0.000 0.317 0.000 copy.py:263() 2767590 0.311 0.000 0.311 0.000 {method 'values' of 'collections.OrderedDict' objects} 1610 0.259 0.000 0.288 0.000 data.py:36() 368691 0.275 0.000 0.275 0.000 {method '__reduce_ex__' of 'object' objects} 2044093 0.270 0.000 0.270 0.000 {method 'get' of 'mappingproxy' objects} 1610 0.008 0.000 0.215 0.000 privec_reader.py:132(start_mo_section) 1610 0.003 0.000 0.188 0.000 data.py:27(reset) 3220 0.175 0.000 0.175 0.000 {method 'clear' of 'dict' objects} 8 0.000 0.000 0.168 0.021 __init__.py:1() 1 0.130 0.130 0.147 0.147 file_writer.py:39(write_mo_data) 117412 0.047 0.000 0.117 0.000 copy.py:66(copy) 27468 0.068 0.000 0.117 0.000 codecs.py:319(decode) 185150 0.079 0.000 0.112 0.000 copyreg.py:94(__newobj__)

本プルリクの最後のコミット

150940333 function calls (150931166 primitive calls) in 74.187 seconds Ordered by: cumulative time ncalls tottime percall cumtime percall filename:lineno(function) 305/1 0.011 0.000 74.188 74.188 {built-in method builtins.exec} 1 0.000 0.000 74.187 74.187 runpy.py:200(run_module) 1 0.000 0.000 74.088 74.088 runpy.py:64(_run_code) 1 0.000 0.000 74.088 74.088 __main__.py:1() 1 0.000 0.000 74.088 74.088 sum_dirac_dfcoef.py:10(main) 1 5.511 5.511 73.873 73.873 privec_reader.py:39(read_privec_data) 2767590 6.378 0.000 59.054 0.000 privec_reader.py:170(add_coefficient) 2767590 1.449 0.000 32.726 0.000 coefficient.py:24(get_coefficient) 2767590 8.835 0.000 31.277 0.000 coefficient.py:38(parse_line) 5535181 3.446 0.000 13.893 0.000 {built-in method builtins.sum} 2767590 2.607 0.000 13.844 0.000 data.py:19(add_coefficient) 2043517 3.617 0.000 11.248 0.000 main.py:736(__setattr__) 5550790 4.052 0.000 10.709 0.000 utils.py:8(space_separated_parsing) 13837950 6.916 0.000 10.447 0.000 coefficient.py:69() 5550790 3.481 0.000 3.481 0.000 utils.py:9() 2767593 0.894 0.000 3.325 0.000 main.py:154(__init__) 4089477/4089474 1.843 0.000 3.324 0.000 {built-in method builtins.getattr} 2767590 1.095 0.000 2.928 0.000 atoms.py:38(count_remaining_functions) 2043517 2.564 0.000 2.565 0.000 {method 'validate_assignment' of 'pydantic_core._pydantic_core.SchemaValidator' objects} 5551867 2.494 0.000 2.494 0.000 {method 'split' of 'str' objects} 2767593 2.430 0.000 2.430 0.000 {method 'validate_python' of 'pydantic_core._pydantic_core.SchemaValidator' objects} 93380 0.085 0.000 2.329 0.000 utils.py:16(fast_deepcopy_pickle) 11070360 2.287 0.000 2.287 0.000 utils.py:36(is_float) 2767590 1.204 0.000 1.705 0.000 privec_reader.py:91(is_this_row_for_coefficients) 2043566 1.225 0.000 1.481 0.000 _model_construction.py:197(__getattr__) 93380 1.361 0.000 1.404 0.000 {built-in method _pickle.dumps} 16607799 1.317 0.000 1.317 0.000 {method 'strip' of 'str' objects} 11070360 1.244 0.000 1.244 0.000 {built-in method builtins.pow} 1610 0.013 0.000 1.062 0.001 privec_reader.py:200(add_current_mo_data_to_data_all_mo) 2043530 0.590 0.000 0.938 0.000 _fields.py:262(is_valid_field_name) 2767590 0.884 0.000 0.884 0.000 atoms.py:28(decrement_function) 2775987 0.620 0.000 0.861 0.000 privec_reader.py:95(need_to_skip_this_line) 93380 0.784 0.000 0.841 0.000 {built-in method _pickle.loads} 8337038/8336836 0.695 0.000 0.695 0.000 {built-in method builtins.len} 5554462 0.683 0.000 0.683 0.000 {method 'rstrip' of 'str' objects} 6139190 0.543 0.000 0.543 0.000 {method 'get' of 'dict' objects} 2769740 0.475 0.000 0.475 0.000 {method 'replace' of 'str' objects} 2045536 0.349 0.000 0.349 0.000 {method 'startswith' of 'str' objects} 1610 0.007 0.000 0.338 0.000 data.py:35(fileter_coefficients_by_threshold) 2767695 0.317 0.000 0.317 0.000 {method 'isdigit' of 'str' objects} 1610 0.272 0.000 0.301 0.000 data.py:36() 2767590 0.289 0.000 0.289 0.000 {method 'values' of 'collections.OrderedDict' objects} 1610 0.009 0.000 0.266 0.000 privec_reader.py:131(start_mo_section) 2065355/2065327 0.265 0.000 0.265 0.000 {built-in method builtins.isinstance} 2044093 0.256 0.000 0.256 0.000 {method 'get' of 'mappingproxy' objects} 1610 0.003 0.000 0.227 0.000 data.py:27(reset) 3220 0.222 0.000 0.222 0.000 {method 'clear' of 'dict' objects} 8 0.000 0.000 0.180 0.022 __init__.py:1() 1 0.128 0.128 0.146 0.146 file_writer.py:39(write_mo_data)