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

[前回](https://qiita.com/megasys1968/items/25199d419a2274faace5)の記事を書いた以降に、わかったことを書きます。
なお、今回は可能ならSpringのJDBC Template、必要に応じて生のJDBCを、JDBCドライバも前回拡張したものではなく素のドライバを使用します。

## オブジェクトフィールドの読み書き

前回の調査で漏れてましたがオブジェクトフィールドを実際に読み書きしてみたら、うまく行かず諦めてました。

* JDBCドライバのPreparedStatementのgetBlob/setBlob等のメソッドを呼び出すと例外が発生し、"This method is not yet implemented."と言われる。
* [ODBCとJDBCガイド](https://fmhelp.filemaker.com/docs/edition/ja/fm_odbc_jdbc_guide.pdf)に「CLOB、ARRAY および REF データ型を含む列の更新」は「FileMaker でサポートされません。」との記述を見て「できない」と早合点。

うまく動かないと、悪い方向に迷走しがちですよね。

しばらく経って、後述する問題でJDBCドライバ内部を見てたら、PreparedStatementのtype 1からあるgetBytes/setBytesは実装されてるではないですか！ 
また[SQLリファレンスガイド](https://help.claris.com/ja/sql-reference.pdf)を見ると、GetAsやPutAsというのがあるそうじゃないですか!

こいつ、、、動くぞ、、、ってことで試してみました。

### オブジェクトフィールドの書き込み
オブジェクトフィールドに書き込むデータをバイト配列にして、パラメータとして渡します。
SQL文でプレースホルダを```? as 'ファイル名'```とするとファイル名も反映されます。

```kotlin
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側の画面に

![image.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/387890/1a6dd106-9469-cfcc-93f4-1a00ed34d092.png)

が表示されます。

* オブジェクトファイル名は ```GetContainerAttribute ( オブジェクト ; "filename" )```で計算した値です。

* なお```insert into "テーブル" ("オブジェクト") values (PutAs(?, 'PNGf'))```だとオブジェクトファイル名は```Untitled.png```のようになります。```PutAs(? as 'ファイル名', 'PNGf')```や```PutAs(?, 'PNGf') as 'ファイル名'```は構文エラーになり、PutAsでファイル名を反映させる方法が判りませんでした。ファイルフォーマットなら自動判定されるようなので、PutAsを使うメリットは不明です。

そしてオブジェクトフィールドの更新もできます。

```kotlin
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で取得したデータを見ると

![image.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/387890/7463069b-d428-792d-92fc-acb2539b70e5.png)

オブジェクトフィールドのデータがバイト配列で取得できています。

## 自動生成された値の取得
主キーの値を自動生成にする手法はよく使ってきました。
FileMakerにも、PostgreSQLなどと同様にシリアル番号を自動生成する機能があります。
しかし、MyBatisのgeneratedKeyで生成された値を取得することはできませんでした。

* これも[FileMaker® ODBC と JDBC ガイドガイド](https://fmhelp.filemaker.com/docs/edition/ja/fm_odbc_jdbc_guide.pdf)に「自動生成キーの検索」は「FileMaker でサポートされません。」との記述を見て「できない」と早合点。

そしてJDBCドライバ内部を見てたら、Statement#getGeneratedKeysは実装されてる訳です。

```kotlin
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接続にはまだ何かが潜んでいるかもしれませんが、できないことができるようになるのも開発の醍醐味ですよね。