FileMaker ServerからJDBCでいろいろアクセスしてみる


前回の記事を書いた以降に、わかったことを書きます。
なお、今回は可能なら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で生成された値を取得することはできませんでした。

そして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が出力されてから約10秒の間に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([email protected]/Native Method)
    at java.net.SocketInputStream.socketRead([email protected]/SocketInputStream.java:115)
    at java.net.SocketInputStream.read([email protected]/SocketInputStream.java:168)
    at java.net.SocketInputStream.read([email protected]/SocketInputStream.java:140)
    at sun.security.ssl.SSLSocketInputRecord.read([email protected]/SSLSocketInputRecord.java:478)
    at sun.security.ssl.SSLSocketInputRecord.readHeader([email protected]/SSLSocketInputRecord.java:472)
    at sun.security.ssl.SSLSocketInputRecord.decode([email protected]/SSLSocketInputRecord.java:160)
    at sun.security.ssl.SSLTransport.decode([email protected]/SSLTransport.java:111)
    at sun.security.ssl.SSLSocketImpl.decode([email protected]/SSLSocketImpl.java:1426)
    at sun.security.ssl.SSLSocketImpl.readHandshakeRecord([email protected]/SSLSocketImpl.java:1336)
    at sun.security.ssl.SSLSocketImpl.startHandshake([email protected]/SSLSocketImpl.java:450)
    at sun.security.ssl.SSLSocketImpl.startHandshake([email protected]/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のハンドシェイクで応答待ちのまま10時間以上経っているのが見つかりました。
Hikari + PostgreSQLの組合せで今まで気にしたことがなかったですが、FileMakerではソケット通信のタイムアウトを指定する必要があるようです。

jdbc:filemaker://${ホスト名}/${ファイル名}?&socketTimeout=10000

ここではタイムアウトを10秒にしていますが、FileMaker Serverへのselect等で応答にもっと時間がかかることが想定される場合は、延ばす必要があります。

  • ちなみにHikariのプロパティで接続タイムアウト(connectionTimeout)を指定できますが、JDBCドライバではこの値を使ってません。自分が使っているCentOSの環境でFileMaker Serverが起動していないと、2分程度接続待ちしてエラーが発生します。この待ち時間はOSの設定によるものです。

所感

まだプロトタイプの開発段階ですが、いろいろなことが見えてきました。

接続タイムアウトの件は、FMStreamというクラスのコンストラクタでSocket接続を行っているため、前回のようなアプローチで拡張することができません(コンストラクタは書き足せても上書きはできない)。仕方がないのでAspectJを使ってコンストラクタを上書きして、接続タイムアウトの指定が反映されるようにしました。

これから本番開発に進みそうで、FileMaker ServerとのJDBC接続にはまだ何かが潜んでいるかもしれませんが、できないことができるようになるのも開発の醍醐味ですよね。