前回の記事を書いた以降に、わかったことを書きます。
なお、今回は可能ならSpringのJDBC Template、必要に応じて生のJDBCを、JDBCドライバも前回拡張したものではなく素のドライバを使用します。
オブジェクトフィールドの読み書き
前回の調査で漏れてましたがオブジェクトフィールドを実際に読み書きしてみたら、うまく行かず諦めてました。
- JDBCドライバのPreparedStatementのgetBlob/setBlob等のメソッドを呼び出すと例外が発生し、"This method is not yet implemented."と言われる。
- ODBCとJDBCガイドに「CLOB、ARRAY および REF データ型を含む列の更新」は「FileMaker でサポートされません。」との記述を見て「できない」と早合点。
うまく動かないと、悪い方向に迷走しがちですよね。
しばらく経って、後述する問題でJDBCドライバ内部を見てたら、PreparedStatementのtype 1からあるgetBytes/setBytesは実装されてるではないですか！
またSQLリファレンスガイドを見ると、GetAsやPutAsというのがあるそうじゃないですか!
こいつ、、、動くぞ、、、ってことで試してみました。
オブジェクトフィールドの書き込み
オブジェクトフィールドに書き込むデータをバイト配列にして、パラメータとして渡します。
SQL文でプレースホルダを? as 'ファイル名'とするとファイル名も反映されます。
val image = JdbcApplication::class.java.getResourceAsStream("/ideon-gage.png").readAllBytes()
jdbcTemplate.update("""insert into "テーブル" ("テキスト", "数字", "日付", "時刻", "タイムスタンプ", "オブジェクト") values (?, ?, ?, ?, ?, ? as 'ideon-gage.png') """,
"伝説巨神イデオン", 123, Date.valueOf("1980-5-8"), Time.valueOf("18:45:00"), Timestamp.valueOf("1981-1-30 19:15:00"), image)
これを実行するとFileMaker側の画面に
が表示されます。
オブジェクトファイル名は
GetContainerAttribute ( オブジェクト ; "filename" )で計算した値です。なお
insert into "テーブル" ("オブジェクト") values (PutAs(?, 'PNGf'))だとオブジェクトファイル名はUntitled.pngのようになります。PutAs(? as 'ファイル名', 'PNGf')やPutAs(?, 'PNGf') as 'ファイル名'は構文エラーになり、PutAsでファイル名を反映させる方法が判りませんでした。ファイルフォーマットなら自動判定されるようなので、PutAsを使うメリットは不明です。
そしてオブジェクトフィールドの更新もできます。
jdbcTemplate.update("""update "テーブル" set "オブジェクト" = ? as 'ideon-sword.png' where "テキスト" = '伝説巨神イデオン' """, image)
オブジェクトフィールドの読み込み
オブジェクトフィールド名をGetAsで括って指定します。
GetAsの第2引数はファイルのタイプだそうですが、横着してDEFAULTでもよさそうです。
val rows = jdbcTemplate.query("""select "テキスト", "数字", "日付", "時刻", "タイムスタンプ", GetAs("オブジェクト", DEFAULT) from "テーブル"""", ColumnMapRowMapper())
- ちなみにSQL リファレンスガイドに従って
GetAs("オブジェクト", 'DEFAULT')だと構文エラーになります。
これを実行してIDEで取得したデータを見ると
オブジェクトフィールドのデータがバイト配列で取得できています。
自動生成された値の取得
主キーの値を自動生成にする手法はよく使ってきました。
FileMakerにも、PostgreSQLなどと同様にシリアル番号を自動生成する機能があります。
しかし、MyBatisのgeneratedKeyで生成された値を取得することはできませんでした。
- これもFileMaker® ODBC と JDBC ガイドガイドに「自動生成キーの検索」は「FileMaker でサポートされません。」との記述を見て「できない」と早合点。
そしてJDBCドライバ内部を見てたら、Statement#getGeneratedKeysは実装されてる訳です。
val statement = connection.prepareStatement("""insert into "テーブル" ("テキスト") values (?) """)
statement.setString(1, "もうれつ")
statement.executeUpdate()
val mapper = ColumnMapRowMapper()
var rowNum = 0
val generatedKeys = statement.generatedKeys
while (generatedKeys.next()) {
println(mapper.mapRow(generatedKeys, rowNum++))
}
- JDBC TemplateはPrepareStatementオブジェクトを隠蔽するので、生のJDBCとColumnMapRowMapperを組合せた。
すると
{ROWID=2140}
のような結果が得られました。
SQL リファレンスガイドによるとROWIDはレコード固有のID番号だそうなので、これを使ってselect 〜 from 〜 where ROWID = ?すれば、insertしたレコードを取得して、自動生成された値を取得することができますね。
コネクションが枯渇する
Spring Bootで検証用のWebアプリケーションを作成して、しばらく評価していたところ、1周間に1回から、日に数回の頻度のバラツキで
11:04:14.077 DEBUG [l-1 housekeeper] c.z.h.p.HikariPool : HikariPool-1 - Add connection elided, waiting 0, queue 1
11:04:14.079 DEBUG [nnection closer] c.z.h.p.PoolBase : HikariPool-1 - Closing connection jp.co.supportas.filemaker.Connection@4dcdd962: (connection has passed maxLifetime)
11:04:21.737 DEBUG [l-1 housekeeper] c.z.h.p.HikariPool : HikariPool-1 - Add connection elided, waiting 0, queue 2
11:04:21.737 DEBUG [nnection closer] c.z.h.p.PoolBase : HikariPool-1 - Closing connection jp.co.supportas.filemaker.Connection@a264bce: (connection has passed maxLifetime)
11:04:24.386 DEBUG [l-1 housekeeper] c.z.h.p.HikariPool : HikariPool-1 - Add connection elided, waiting 0, queue 3
11:04:24.386 DEBUG [nnection closer] c.z.h.p.PoolBase : HikariPool-1 - Closing connection jp.co.supportas.filemaker.Connection@4b1b41f5: (connection has passed maxLifetime)
11:04:25.133 DEBUG [l-1 housekeeper] c.z.h.p.HikariPool : HikariPool-1 - Before cleanup stats (total=1, active=0, idle=1, waiting=0)
11:04:25.133 DEBUG [l-1 housekeeper] c.z.h.p.HikariPool : HikariPool-1 - After cleanup stats (total=1, active=0, idle=1, waiting=0)
11:04:25.133 DEBUG [l-1 housekeeper] c.z.h.p.HikariPool : HikariPool-1 - Fill pool skipped, pool is at sufficient level.
11:04:25.339 DEBUG [l-1 housekeeper] c.z.h.p.HikariPool : HikariPool-1 - Add connection elided, waiting 0, queue 4
11:04:25.339 DEBUG [nnection closer] c.z.h.p.PoolBase : HikariPool-1 - Closing connection jp.co.supportas.filemaker.Connection@7a1a6ebf: (connection has passed maxLifetime)
11:04:25.346 DEBUG [o-auto-1-exec-7] c.z.h.p.HikariPool : HikariPool-1 - Add connection elided, waiting 1, queue 5
11:04:55.136 DEBUG [l-1 housekeeper] c.z.h.p.HikariPool : HikariPool-1 - Before cleanup stats (total=0, active=0, idle=0, waiting=1)
11:04:55.136 DEBUG [l-1 housekeeper] c.z.h.p.HikariPool : HikariPool-1 - After cleanup stats (total=0, active=0, idle=0, waiting=1)
11:04:55.136 DEBUG [l-1 housekeeper] c.z.h.p.HikariPool : HikariPool-1 - Fill pool skipped, pool is at sufficient level.
11:04:55.351 DEBUG [o-auto-1-exec-7] c.z.h.p.HikariPool : HikariPool-1 - Timeout failure stats (total=0, active=0, idle=0, waiting=0)
11:04:55.374 ERROR [o-auto-1-exec-7] o.a.c.c.C.[.[.[/].[dispatcherServlet] : Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Request processing failed; nested exception is org.mybatis.spring.MyBatisSystemException: nested exception is org.apache.ibatis.exceptions.PersistenceException:
### Error querying database. Cause: org.springframework.jdbc.CannotGetJdbcConnectionException: Failed to obtain JDBC Connection; nested exception is java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30006ms.
### The error may exist in jp/co/supportas/filemaker/mybatis/RecordMapper.java (best guess)
### The error may involve jp.co.supportas.filemaker.mybatis.RecordMapper.records
### The error occurred while executing a query
### Cause: org.springframework.jdbc.CannotGetJdbcConnectionException: Failed to obtain JDBC Connection; nested exception is java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30006ms.] with root cause
java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30006ms.
at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:695) ~[HikariCP-3.4.5.jar:na]
at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:197) ~[HikariCP-3.4.5.jar:na]
at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:162) ~[HikariCP-3.4.5.jar:na]
とコネクションプールに使用しているHikariでコネクションが取得できないとのエラーが発生し、アプリを再起動しないとFileMaker Serverにアクセスできない現象に遭遇しました。
各コネクションがmaxLifetimeの期間が過ぎ、再接続を行う中でAdd connection elided, waiting 0, queue 1が出力されてから約１０秒の間にmaximumPoolSizeで指定していた5つ全て接続完了待ちになっていました。
スレッドダンプを取得すると
"HikariPool-1 connection adder" #27 daemon prio=5 os_prio=0 cpu=8.87ms elapsed=39174.54s tid=0x00007f2eb000a000 nid=0x2b runnable [0x00007f2ee0e19000]
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(java.base@11.0.12/Native Method)
at java.net.SocketInputStream.socketRead(java.base@11.0.12/SocketInputStream.java:115)
at java.net.SocketInputStream.read(java.base@11.0.12/SocketInputStream.java:168)
at java.net.SocketInputStream.read(java.base@11.0.12/SocketInputStream.java:140)
at sun.security.ssl.SSLSocketInputRecord.read(java.base@11.0.12/SSLSocketInputRecord.java:478)
at sun.security.ssl.SSLSocketInputRecord.readHeader(java.base@11.0.12/SSLSocketInputRecord.java:472)
at sun.security.ssl.SSLSocketInputRecord.decode(java.base@11.0.12/SSLSocketInputRecord.java:160)
at sun.security.ssl.SSLTransport.decode(java.base@11.0.12/SSLTransport.java:111)
at sun.security.ssl.SSLSocketImpl.decode(java.base@11.0.12/SSLSocketImpl.java:1426)
at sun.security.ssl.SSLSocketImpl.readHandshakeRecord(java.base@11.0.12/SSLSocketImpl.java:1336)
at sun.security.ssl.SSLSocketImpl.startHandshake(java.base@11.0.12/SSLSocketImpl.java:450)
at sun.security.ssl.SSLSocketImpl.startHandshake(java.base@11.0.12/SSLSocketImpl.java:421)
at com.filemaker.jdbc.FMStream.establishSSL(Unknown Source)
- locked <0x0000000718180fb8> (a com.filemaker.jdbc.FMStream)
at com.filemaker.jdbc1.CommonJ1Connection.openConnection(Unknown Source)
at com.filemaker.jdbc.Driver.connect(Unknown Source)
at com.zaxxer.hikari.util.DriverDataSource.getConnection(DriverDataSource.java:138)
JDBCドライバがSocketでFileMaker Serverに接続し、SSLのハンドシェイクで応答待ちのまま１０時間以上経っているのが見つかりました。
Hikari + PostgreSQLの組合せで今まで気にしたことがなかったですが、FileMakerではソケット通信のタイムアウトを指定する必要があるようです。
jdbc:filemaker://${ホスト名}/${ファイル名}?&socketTimeout=10000
ここではタイムアウトを１０秒にしていますが、FileMaker Serverへのselect等で応答にもっと時間がかかることが想定される場合は、延ばす必要があります。
- ちなみにHikariのプロパティで接続タイムアウト(connectionTimeout)を指定できますが、JDBCドライバではこの値を使ってません。自分が使っているCentOSの環境でFileMaker Serverが起動していないと、２分程度接続待ちしてエラーが発生します。この待ち時間はOSの設定によるものです。
所感
まだプロトタイプの開発段階ですが、いろいろなことが見えてきました。
接続タイムアウトの件は、FMStreamというクラスのコンストラクタでSocket接続を行っているため、前回のようなアプローチで拡張することができません(コンストラクタは書き足せても上書きはできない)。仕方がないのでAspectJを使ってコンストラクタを上書きして、接続タイムアウトの指定が反映されるようにしました。
これから本番開発に進みそうで、FileMaker ServerとのJDBC接続にはまだ何かが潜んでいるかもしれませんが、できないことができるようになるのも開発の醍醐味ですよね。