はじめに

入社2年目のみやです。未経験新卒で入社して約1年半が経ちました。
最近は大量データの処理（CRUD操作）を担当する機会があり、そのときに躓いた内容をご紹介できればと思います。

DBのCRUD操作時にエラーが発生

500万件くらいのデータの処理を行っていると、処理の途中で以下のようなエラーが発生しました。

1Mysql2::Error::ConnectionError: Lost connection to MySQL server during query

こちらのエラーを調べると、ネットワーク周りの問題のようで公式（英語/日本語）には原因として以下の3つの可能性があると記載がありました。

1. “during query”と記載がある場合（1つ以上のクエリーの一部として数百万件の行が送信されているときに発生する）は、net_read_timeoutをデフォルトの30秒から60秒以上に増やし、データ転送が完了するのに十分な時間に設定する必要がある
2. まれに、クライアントがサーバーへの初期接続を試みているときに発生することがある。 この場合、connect_timeoutの値が数秒にしか設定されていなければ、10秒に増やすことでエラーを解決できる可能性がある。
3. 上記1,2以外の場合は、BLOB値がmax_allowed_packetより大きいことによりエラーが発生している可能性がある

エラーログに“during query”と記載があるので、おそらく1が原因だと思われますが、念のため全ての設定を見直すことにしました。
dockerでmysqlサーバーを立ち上げているので、以下の手順で設定を行いました。

1. コンテナ内で以下を実行し、読み取られるオプションファイルのパスを確認します。

   1mysql --help

   上記コマンドを実行すると、コマンドの説明などが表示されます。その中に以下のようにオプションファイルのパスが読み取られる順序が記載されている部分があります。これらの設定ファイルのいずれかにサーバーシステム変数とその値を反映すれば、起動時に設定されます。また、後で読み取られたファイルが優先されます。

   1Default options are read from the following files in the given order:
   2/etc/my.cnf /etc/mysql/my.cnf ~/.my.cnf

   今回は/etc/my.cnfで設定を行うことにします。
2. docker-compose.ymlのmysqlサービスのvolumeを以下のように設定します。

   1  db:
   2    image: mysql:latest
   3    volumes:
   4      - （マウントしたいパス　例: docker/mysql/my.cnf）:/etc/my.cnf

   このように設定することで、マウントしたいパス（例: docker/mysql/my.cnf）のファイル内容を変更すると、コンテナ内のdocker/mysql/my.cnfも書き換えられることになります。
3. マウントしたいパス（例: docker/mysql/my.cnf）のファイル内容を先の調査から以下のように余裕を持って値を記載することにします。

   1[mysqld]
   2max_allowed_packet=1G
   3connect_timeout=3600
   4net_read_timeout=3600

4. 設定後コンテナを再ビルドし、mysqlコンソールに入って以下のコマンドらで設定が反映されているかを確認します。

   1show variables like 'net_read_timeout';
   2show variables like 'connect_timeout';
   3show variables like 'max_allowed_packet';

   例

   1+------------------+-------+
   2| Variable_name    | Value |
   3+------------------+-------+
   4| net_read_timeout | 3600  |
   5+------------------+-------+

上記の手順を行った後に再度500万件のデータ処理を行うとエラーなく処理が完了しました。
おそらく、クエリが長くなり過ぎてtimeoutが発生したのだと思います。根本的な解決にはクエリが短くなるような実装に変更する必要があると思います。
ただ、今回は開発環境でデータを生成するタスクでしたのでこちらの対応で事足りました。同じようなエラーが出た方はぜひ参考にしていただければと思います。

処理に時間がかかりすぎて終わらない

とりあえずデータ処理を行うコードはかけた！サンプルデータを投入し、データの処理が期待通りに動くことも確認できた！さあ、実際に投入するデータサイズで処理を動かしてみよう！と動かしてみたところ、処理にものすごく時間がかかることがわかりました。
そこで処理のボトルネックを突き止めるため、処理時間の計測を行いました。
rubyのコードでしたので、シンプルにTime.nowで時間を計測することにしました。
処理ごとに以下のように現在時刻を標準出力して処理が遅くなっている部分を特定することができました。
※Time.now.iso8601(5)とすることで、"2024-11-28T19:45:45.41938+09:00"のように100000分の1秒まで表示しています。

簡単な例

1puts Time.now.iso8601(5)
2data = DB::Sample.where(code: target_code)
3puts Time.now.iso8601(5)
4data.each do |record|
5    puts Time.now.iso8601(5)
6    a = record[:a]
7    puts Time.now.iso8601(5)
8    b = record[:b]
9    puts Time.now.iso8601(5)
10end

結論としては、速度低下は上記のコードでwhereメソッドで引数に指定しているcodeカラムにindexがはられていないことにより起きたものでした。
また、注意したいこととしてはwhereメソッドはActiveRecord::Relationのオブジェクトを返すだけで、whereメソッド実行時点ではDBにアクセスしないという点です。実際にデータが必要となるタイミングでDBアクセスが発生するので、上記のコードではdata.each do |record|の部分でDBアクセスが発生し、indexがはられていないことで処理時間が長くなっていました。最初はbenchmarkという標準ライブラリで測定していたのですが、このことに気が付かずどこが処理速度の低下につながっている分かりませんでした（each部分を測定していなかったため）。シンプルにTime.nowで時間を計測することでボトルネックを特定することができました。
最終的にはcodeカラムにindexをはることで問題なく処理を終えることができました。indexで検索処理が高速化できること・データ数が多い場合はindexが必須であることを身をもって知りました。ただ、indexをはることでinsert/update処理の負荷も増えるので、その部分も意識して必要なカラムにだけindexを付与していきたいと思います。

まとめ

今回は大量のデータ処理を行った時に躓いた点をご紹介しました。
現在プロジェクトではより処理時間を短くできるように、並列処理で実行するなどリファクタリングを行っています。
今回のタスクを通してパフォーマンスを意識した実装を考えられるようになり、またsqlと少しは仲良くなれた気がします！
今後も業務での気付きを発信できればと思います。