ActiveRecordのバルクインサート比較 その2

Railsコンソールで実行するとログが出てきて面白いです。 読みやすくするためにデータ件数を3件、試行回数を1回にして実行します。

                      user     system      total        real
sql               TRANSACTION (0.1ms)  begin transaction
   (0.2ms)  INSERT INTO users (name, created_at, updated_at) VALUES ('name', '2022-07-25 13:24:35', '2022-07-25 13:24:35'),('name', '2022-07-25 13:24:35', '2022-07-25 13:24:35'),('name', '2022-07-25 13:24:35', '2022-07-25 13:24:35')
  0.000394   0.000120   0.000514 (  0.000510)
  TRANSACTION (0.1ms)  rollback transaction
insert_all        TRANSACTION (0.0ms)  begin transaction
   (0.1ms)  SELECT sqlite_version(*)
  User Bulk Insert (0.1ms)  INSERT INTO "users" ("name","created_at","updated_at") VALUES ('name', '2022-07-25 13:24:35.535566', '2022-07-25 13:24:35.535569'), ('name', '2022-07-25 13:24:35.535571', '2022-07-25 13:24:35.535572'), ('name', '2022-07-25 13:24:35.535574', '2022-07-25 13:24:35.535575') ON CONFLICT  DO NOTHING
  0.000827   0.000250   0.001077 (  0.001077)
  TRANSACTION (0.1ms)  rollback transaction
import            TRANSACTION (0.0ms)  begin transaction
  TRANSACTION (0.0ms)  SAVEPOINT active_record_1
  User Create Many (0.2ms)  INSERT INTO "users" ("id","name","created_at","updated_at") VALUES (NULL,'name','2022-07-25 13:24:35.528743','2022-07-25 13:24:35.528787'),(NULL,'name','2022-07-25 13:24:35.535485','2022-07-25 13:24:35.535497'),(NULL,'name','2022-07-25 13:24:35.535535','2022-07-25 13:24:35.535537')
  TRANSACTION (0.0ms)  RELEASE SAVEPOINT active_record_1
  0.000000   0.004980   0.004980 (  0.004599)
  TRANSACTION (0.1ms)  rollback transaction

実行しているSQL

実行しているSQLは概ね同じです。

sql

INSERT INTO users (name, created_at, updated_at) VALUES ('name', '2022-07-25 13:24:35', '2022-07-25 13:24:35'),('name', '2022-07-25 13:24:35', '2022-07-25 13:24:35'),('name', '2022-07-25 13:24:35', '2022-07-25 13:24:35')

insert_all

INSERT INTO "users" ("name","created_at","updated_at") VALUES ('name', '2022-07-25 13:24:35.535566', '2022-07-25 13:24:35.535569'), ('name', '2022-07-25 13:24:35.535571', '2022-07-25 13:24:35.535572'), ('name', '2022-07-25 13:24:35.535574', '2022-07-25 13:24:35.535575') ON CONFLICT  DO NOTHING

import

INSERT INTO "users" ("id","name","created_at","updated_at") VALUES (NULL,'name','2022-07-25 13:24:35.528743','2022-07-25 13:24:35.528787'),(NULL,'name','2022-07-25 13:24:35.535485','2022-07-25 13:24:35.535497'),(NULL,'name','2022-07-25 13:24:35.535535','2022-07-25 13:24:35.535537')

考察

SQLが大体同じということはSQLの実行時間も大体同じと考えられます。 また、計測結果を見ても、どれもtotalとrealにほとんど差がありません。

                      user     system      total        real
sql               0.111639   0.008981   0.120620 (  0.123311)
insert_all        3.908285   0.009556   3.917841 (  3.930704)
import            3.713988   0.009934   3.723922 (  3.738295)

つまり、SQLの実行待ち時間が占める割合はすごく小さいです。 実行時間の差はRubyでSQL文字列を組み立てるのにかかる時間の差を表していると考えられます。

事前にSQL文を作成してるsqlが一番速い結果とも一致しています。