stackprofileを使って時間の掛かる処理を特定する

入力されたJSONファイルをパースしてDBに取り込む処理をチューニングしています。 ボトルネックはDBへの取り込みだと予想しています。 本当でしょうか？ GitHub - tmm1/stackprof: a sampling call-stack profiler for ruby 2.2+を使って確認してみます。 次のようなスクリプトを書いて、該当のInstantiateAndSaveAnnotationsCollection.callメソッドを実行します。

file = 'tmp/upload-test-project-2022-06-24-15-05-36/db/litcovid/litcovid2pubtator-2020-11-17-17-47/PMC-7646410.json'
annotations_collection = JSON.parse File.read(file)
annotations_collection.each { _1.deep_symbolize_keys! }
project = Project.find_by(id: 1)

StackProf.run(out: 'tmp/stackprof.dump') do
  InstantiateAndSaveAnnotationsCollection.call project, annotations_collection
end

結果を確認してみます。

ledsun@MSI:~/pubannotation►stackprof tmp/stackprof.dump --text --limit 3
==================================
  Mode: wall(1000)
  Samples: 1257 (0.16% miss rate)
  GC: 71 (5.65%)
==================================
     TOTAL    (pct)     SAMPLES    (pct)     FRAME
       614  (48.8%)         614  (48.8%)     PG::Connection#exec_prepared
        57   (4.5%)          57   (4.5%)     (marking)
        39   (3.1%)          39   (3.1%)     PG::Connection#exec_params

PG::Connection#exec_prepared が最も時間を使っています。 やはりDBへの取り込み、特にSQLの実行に時間が掛かっているようです。