MySQLへのJDBC接続で、とあるバグを踏むまでの話 -（２）「Connector/J」は結構賢い
3エントリに渡ってお送りしています
（１）「max_allowed_packet」の基本的な働き
（２）「Connector/J」は結構賢い <- イマココ
（３）古いmariadb-client-javaにて、ヤバイ動き
Javaで開発するときにお世話になるヤーツ
MySQLをDBとして採用したとき、アプリケーションをJavaで開発するとなると、JDBCドライバのお世話になります。
MySQL公式としては「Connector/J」と呼ばれるJDBCドライバが提供されているので、通常こちらを使用します。
8.0版も出ていますが、まだまだ5系のこちらを使っていることが多いでしょう。
MySQL :: MySQL Connector/J 5.1 Developer Guide
JDBC経由でバルクインサートする準備
JDBCドライバの準備
MySQL公式のサイトからダウンロードしてきます。
https://dev.mysql.com/downloads/connector/j/
今回は、「5.1.47」のtar.gz版を使います。
解凍して、パスが通るようにしておきます。
めんどくさいので、次に書くソースと同じ場所に落として解凍してます。
ついでに、当然ですがJDKも。
今回は、たまたま検証環境に入っていたOracleのヤツ「java version "1.8.0_152"」を使います。
Javaソースの準備
前回の記事で用意したテーブル＆バルクインサートの実行をやるにあたって、下記のようなソースを用意します。本職プログラマじゃないこともあり、汚いですがご容赦を。
やっていることは
- 接続する。バルクインサートが使えるように「rewriteBatchedStatements=true」にする。
- 投入先テーブルを初期化（Truncate）する
- プリペアドステートメントを使いながら、Insert文を組み立てて、バッチの準備をする。（conn.prepareStatement-> setString -> addBatch）
- 規定数に到達したらバルクインサートを実行する。（executebatch）
といった内容です。
50,000件を、1,000件毎にバルクインサートして、10,000件毎にcommitを入れる、という設定にしてあります。
- BulkTestMySQL.java
mport java.sql.*; class BulkTestMySQL { public static void main(String[] args) { String driver = "org.gjt.mm.mysql.Driver"; String JDBC_URL ="jdbc:mysql://localhost"; String JDBC_USER = "testbulk"; String JDBC_PASS = "testbulk"; String JDBC_DBNAME = "bulk_test"; String DATA = ""; int COUNT = 50000; // total insert record int BATCH_SIZE = 1000; // bulk per insert int COMMIT_SIZE = 10000; String BULK_MODE = "true"; int STR_LENGTH = 1000; for (int i = 1; i <= STR_LENGTH; i++) { DATA = DATA + "a"; } try{ Class.forName (driver); Connection conn = DriverManager.getConnection(JDBC_URL + "/" + JDBC_DBNAME + "?rewriteBatchedStatements=" + BULK_MODE,JDBC_USER, JDBC_PASS); conn.setAutoCommit(false); // テーブルの初期化 Statement stmt = conn.createStatement (); String sql = "TRUNCATE TABLE loadtest"; //MySQL ConnectorだとDDLや更新系DMLはexecuteQueryでは実行できない // ResultSet rs = stmt.executeQuery (sql); stmt.executeUpdate(sql); // BulkInsertTest本体 PreparedStatement pstmt = conn.prepareStatement("insert into loadtest (id, data1,data2) values (?, ?, ?)"); for (int i = 1; i <= COUNT; i += BATCH_SIZE) { pstmt.clearBatch(); for (int j = 0; j < BATCH_SIZE; j++) { pstmt.setInt(1, i + j); if (j == 530) { pstmt.setString(2, DATA); pstmt.setString(3, "b"); }else{ pstmt.setString(2, DATA); pstmt.setString(3, DATA); } pstmt.addBatch(); } pstmt.executeBatch(); if ((i + BATCH_SIZE - 1) % COMMIT_SIZE == 0) { conn.commit(); } } conn.commit(); } catch (SQLException e) { System.err.println("SQL failed."); e.printStackTrace (); } catch (ClassNotFoundException ex) { ex.printStackTrace (); } } }
コンパイル＆実行
なにぶん、IDEなど用意せず、すべてvi＋コマンドで処理しているものでして、以下のようなシェルを用意します。
connecctor/Jのjarは、このJavaファイルと同じ場所にダウンロードしてtar.gzを展開しておいた、という状態です。
- BulkTestMySQLCompileAndRun.sh
javac BulkTestMySQL.java export CLASSPATH=./mysql-connector-java-5.1.47/mysql-connector-java-5.1.47.jar:. java BulkTestMySQL
これで、ソース上に入れた設定を変えて、再テストするときに、このシェル起動で実行できる、と。
実際にJDBC経由でバルクインサートを実行してみる。
まずは、デフォルトの状態から。
mysql -u testbulk -p -e "select @@global.max_allowed_packet, @@global.net_buffer_length" +-----------------------------+----------------------------+ | @@global.max_allowed_packet | @@global.net_buffer_length | +-----------------------------+----------------------------+ | 4194304 | 16384 | +-----------------------------+----------------------------+ ./BulkTestMySQLCompileAndRun.sh
なんかごっちゃごちゃとSSL絡みのワーニング*1が出ますが、無視するとして、デフォルトだとさらっと終了します。
50000件、途中で落ちたりせずに入っているか念の為確認。
mysql -u testbulk -p -D bulk_test -e "select count(*) from loadtest;select length(data1),length(data2) from loadtest limit 10;" +----------+ | count(*) | +----------+ | 50000 | +----------+ +---------------+---------------+ | length(data1) | length(data2) | +---------------+---------------+ | 1000 | 1000 | | 1000 | 1000 | | 1000 | 1000 | | 1000 | 1000 | | 1000 | 1000 | | 1000 | 1000 | | 1000 | 1000 | | 1000 | 1000 | | 1000 | 1000 | | 1000 | 1000 | +---------------+---------------+
max_allowed_packetを小さくしてみる
1MBまで小さくして、同じソースを実行してみます。
mysql -u root -p -e "set @@global.max_allowed_packet = 1048576" mysql -u testbulk -p -e "select @@global.max_allowed_packet, @@global.net_buffer_length" +-----------------------------+----------------------------+ | @@global.max_allowed_packet | @@global.net_buffer_length | +-----------------------------+----------------------------+ | 1048576 | 16384 | +-----------------------------+----------------------------+ ./BulkTestMySQLCompileAndRun.sh
見かけ上、何も変化なく、さらっと通りました。
あえて記載もしませんが、データはもれなく格納されています。
よく考えてみましょう。
冒頭で
50,000件を、1,000件毎にバルクインサートして、10,000件毎にcommitを入れる、という設定にしてあります。
と書きました。
1レコードは、連番（最大50,000＝5桁）＋1,000桁の文字列＋1,000桁の文字列で＝2,000強です。
前回の検証から、max_allowed_packet ＞ >net_buffer_lengthなので、max_allowed_packetが1SQLでの最大値です。
2,000強byte＊1,000行＋INSERT文の他の要素 ＞ max_allowed_packet（1MB＝1024＊1024 byte）ですが、処理が落ちません。
何が起こっているのか。。。
考えられるのは、max_allowed_packetが設定したものと違う値が採用されている」か、「JDBCドライバの中でmax_allowed_packetに即したバルクインサートSQL文を生成している」か。。。
先に正解を書くと、後者「JDBCドライバの中でmax_allowed_packetに即したバルクインサートSQL文を生成している」です。結構賢い。
しかし、Connector/Jの公式ドキュメント、そんな話が一切出てこないし、そもそも「rewriteBatchedStatements」プロパティに言及があるだけで、プリペアドステートメントからのバルクインサート実行のサンプルも何もない。つらい。
何が起こっているかの確認：SHOW STATUS
まず、このサンプルソースで、インサート文が実際に何本実行されているかを確認します。
SHOW STATUSで、mysqld（MySQLサーバー）が起動してから、何がどれくらい動いたか、という累積情報を確認することができます。
今回は「Com_insert」＝INSERT文が何回実行されたか（≠挿入行数。＝実行数）、を確認します。
service mysqld stop mysqld を停止中: [ OK ] service mysqld start mysqld を起動中: [ OK ] mysql -u testbulk -p -e "select @@global.max_allowed_packet, @@global.net_buffer_length" +-----------------------------+----------------------------+ | @@global.max_allowed_packet | @@global.net_buffer_length | +-----------------------------+----------------------------+ | 4194304 | 16384 | +-----------------------------+----------------------------+ mysql -u testbulk -p -e "show global status like 'Com_insert';" +---------------+-------+ | Variable_name | Value | +---------------+-------+ | Com_insert | 0 | +---------------+-------+ ./BulkTestMySQLCompileAndRun.sh mysql -u testbulk -p -e "show global status like 'Com_insert';" +---------------+-------+ | Variable_name | Value | +---------------+-------+ | Com_insert | 50 | +---------------+-------+
デフォルト状態では、INSERT文が50回実行されています。
50,000件を、1,000件毎にバルクインサートして、10,000件毎にcommitを入れる、という設定にしてあります。
なので、計算通り「50,000/1,000＝50」で、50回のバルクインサート文が実行されていることになります。
では、max_allowed_packetを小さくしたケースではどうでしょうか。
service mysqld stop mysqld を停止中: [ OK ] service mysqld start mysqld を起動中: [ OK ] mysql -u root -p -e "set @@global.max_allowed_packet = 1048576" mysql -u testbulk -p -e "select @@global.max_allowed_packet, @@global.net_buffer_length" Enter password: +-----------------------------+----------------------------+ | @@global.max_allowed_packet | @@global.net_buffer_length | +-----------------------------+----------------------------+ | 1048576 | 16384 | +-----------------------------+----------------------------+ mysql -u testbulk -p -e "show global status like 'Com_insert';" +---------------+-------+ | Variable_name | Value | +---------------+-------+ | Com_insert | 0 | +---------------+-------+ ./BulkTestMySQLCompileAndRun.sh mysql -u testbulk -p -e "show global status like 'Com_insert';" mysql -u testbulk -p -e "show global status like 'Com_insert';" +---------------+-------+ | Variable_name | Value | +---------------+-------+ | Com_insert | 100 | +---------------+-------+
先程の2倍、100回カウントされています。
Javaソースコード上、executeBatchによるバルクインサート実行は50回しか実行していないはずですが、MySQLサーバー側のカウンタは100回実行した、と認識しているわけです。
それでいて、実際格納されている件数は50,000件と、想定どおりです。
となると、JDBCレベルで発行するSQLを変えている、と考えるのが筋ですね。公式ドキュメントにはどこにも見当たらないですが。
何が起こっているかの確認：General Log
といっても、ブログに1行2MB＊数百行分のバルクインサートのGeneral Logを貼り付けるのは書く方も読む方も苦痛です。主キーもないし。SQLだけで表現するのもつらい。
こういうときは、MySQL Workbenchのお世話になります。
my.cnfを以下のように設定してからMySQLサーバーを再起動し、General Logをテーブルに出力するようにしてから、先程のようにmax_allowed_packet=1MBで実行します。
general_log log_output=TABLE
実行後、MySQL WorkbenchでGeneral Logテーブルを検索します。
あえてユーザーを分けていたのは、このためだったりします。
select * from mysql.general_log where user_host like 'testbulk%';
すると、結果一覧がグリッド表示されて、実行されたSQLを示すargument列は、「BLOB」と表示されますので、そこをカーソル選択して右クリックから「Open Value in Viewer」しましょう。
以下のように、中身が表示されます。
そして、このSQLの最後に注目。
519番で切れています。さらに次のログを見ると、520番から始まっています。
1回のバルクインサートだと溢れてしまうので、max_allowed_packetのサイズに応じて分解したバルクインサート文を生成して発行しています。
こういった調整を、JDBCドライバのレベルでやってくれているので、プログラマがmax_allowed_packetやnet_buffer_lengthの値と挙動を事細かに知らなくてもエラーになりにくくなっています。
表題にあった「Connector/Jは結構賢い」とは、こういうことです。
逆に、エラーにならないから、裏でSQLが何回発行しているとか、気にしないよね。。。（フラグ）
なお、あくまでexecuteBatch()でJDBCドライバ自身がバルクインサート文を組み立てるケースに限ること、合わせて、サーバーサイドプリペアドステートメントでは使用できないことに注意です。
後者については公式ドキュメントに書いてあります。
rewriteBatchedStatements
Should the driver use multiqueries (irregardless of the setting of "allowMultiQueries") as well as rewriting of prepared statements for INSERT into multi-value inserts when executeBatch() is called? Notice that this has the potential for SQL injection if using plain java.sql.Statements and your code doesn't sanitize input correctly. Notice that for prepared statements, server-side prepared statements can not currently take advantage of this rewrite option, and that if you don't specify stream lengths when using PreparedStatement.set*Stream(), the driver won't be able to determine the optimum number of parameters per batch and you might receive an error from the driver that the resultant packet is too large. Statement.getGeneratedKeys() for these rewritten statements only works when the entire batch includes INSERT statements. Please be aware using rewriteBatchedStatements=true with INSERT .. ON DUPLICATE KEY UPDATE that for rewritten statement server returns only one value as sum of all affected (or found) rows in batch and it isn't possible to map it correctly to initial statements; in this case driver returns 0 as a result of each batch statement if total count was 0, and the Statement.SUCCESS_NO_INFO as a result of each batch statement if total count was > 0.
Default: false
Since version: 3.1.13
MySQL :: MySQL Connector/J 5.1 Developer Guide :: 5.3 Configuration Properties for Connector/J
まとめ
- MySQL Connector/Jは、バルクインサート文を自動で構築してくれる機能がある。
- MySQL Connector/Jは、バルクインサート文自動生成機能では、max_allowed_packetの設定に合わせて、バルクインサートのSQL文の大きさを調整してくれる。
MySQLをガチで触り始めて3年、MySQLについて「おバカ」「キモい」「カワイイ」という発言はしたことがあるけど、「賢い」と形容するのは初めてかもしれないです。
本丸はこれからだ、、、。
まあ、今回はMySQL自身の問題ではないのだけど。フラグは次回、回収されます。
ていうかタイトル先出ししているのでネタバレしてるわけですが。
- 作者: Baron Schwartz,Peter Zaitsev,Vadim Tkachenko,菊池研自,株式会社クイープ
- 出版社/メーカー: オライリージャパン
- 発売日: 2013/11/25
- メディア: 大型本
- この商品を含むブログ (7件) を見る
*1:WARN: Establishing SSL connection without server's identity verification is not recommended. According to MySQL 5.5.45+, 5.6.26+ and 5.7.6+ requirements SSL connection must be established by default if explicit option isn't set. For compliance with existing applications not using SSL the verifyServerCertificate property is set to 'false'. You need either to explicitly disable SSL by setting useSSL=false, or set useSSL=true and provide truststore for server certificate verification.
