Payara の JDBC サポート機能 (ja)

この記事は Payara Advent Calendar 2016 の 13 日目です。昨日は「Payara の JSON Log Formatter」です。

Payara 4.1.1.161 以降、JDBC 周りの管理・監視機能が強化されました。ベースとなった GlassFish 自身、本格的な実装を備えていましたが、Payara では商用サーバーに必要と考えられる追加機能をさらに実装しています。SQL サポート機能は、管理コンソールから設定を変更することができます。

1. Slow SQL Logging

Slow SQL Logging は、SQL の実行時間がある閾値を超えた場合に、その情報をログに出力するための機能です。データソース定義で Statement Timeout (fish.payara.slow-query-threshold-in-seconds プロパティ) に閾値を設定することで有効になります。既定値は -1 で、この値は Slow SQL Logging を無効化することを意味します。

Slow SQL Logging を有効化した場合、閾値を超えた SQL について、以下のようなログが出力されます。

[#|2016-02-01T22:39:29.289+0000|WARNING|Payara 4.1|javax.enterprise.resource.sqltrace.com.sun.gjc.util|_ThreadID=61;_ThreadName=http-listener-1(2);_TimeMillis=1454366369289;_LevelValue=900;|
  SQL Query Exceeded Threshold Time: 5000(ms): Time Taken: 10000(ms)
Query was SELECT ID, AGE, BIO, BIRTHDATE, BIRTHDAY, DATEFORMAT, DATEOFBIRTH, DATEOFHIRE, EMAIL, HIREDATE, HIREDAY, MEMBERAGE, NAME, TODAYSDATE FROM MEMBERENTITY WHERE (NAME = ?);

java.lang.Exception: Stack Trace shows code path to SQL
    at fish.payara.jdbc.SlowSQLLogger.sqlTrace(SlowSQLLogger.java:123)
    at com.sun.gjc.util.SQLTraceDelegator.sqlTrace(SQLTraceDelegator.java:122)
    at com.sun.gjc.spi.jdbc40.ProfiledConnectionWrapper40$1.invoke(ProfiledConnectionWrapper40.java:448)
    at com.sun.proxy.$Proxy265.executeQuery(Unknown Source)
    at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeSelect(DatabaseAccessor.java:1009)
    at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.basicExecuteCall(DatabaseAccessor.java:644)
    at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeCall(DatabaseAccessor.java:560)
    at org.eclipse.persistence.internal.sessions.AbstractSession.basicExecuteCall(AbstractSession.java:2055)
    at org.eclipse.persistence.sessions.server.ServerSession.executeCall(ServerSession.java:570)
    at org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeCall(DatasourceCallQueryMechanism.java:242)
    at org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeCall(DatasourceCallQueryMechanism.java:228)
    at org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeSelectCall(DatasourceCallQueryMechanism.java:299)
    at org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.selectAllRows(DatasourceCallQueryMechanism.java:694)
    at org.eclipse.persistence.internal.queries.ExpressionQueryMechanism.selectAllRowsFromTable(ExpressionQueryMechanism.java:2740)
    at org.eclipse.persistence.internal.queries.ExpressionQueryMechanism.selectAllRows(ExpressionQueryMechanism.java:2693)
    at org.eclipse.persistence.queries.ReadAllQuery.executeObjectLevelReadQuery(ReadAllQuery.java:559)
    at org.eclipse.persistence.queries.ObjectLevelReadQuery.executeDatabaseQuery(ObjectLevelReadQuery.java:1175)
    at org.eclipse.persistence.queries.DatabaseQuery.execute(DatabaseQuery.java:904)
    at org.eclipse.persistence.queries.ObjectLevelReadQuery.execute(ObjectLevelReadQuery.java:1134)
    at org.eclipse.persistence.queries.ReadAllQuery.execute(ReadAllQuery.java:460)
    at org.eclipse.persistence.queries.ObjectLevelReadQuery.executeInUnitOfWork(ObjectLevelReadQuery.java:1222)
    at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.internalExecuteQuery(UnitOfWorkImpl.java:2896)
    at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1857)
    at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1839)
    at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1804)
    at org.eclipse.persistence.internal.jpa.QueryImpl.executeReadQuery(QueryImpl.java:258)
    at org.eclipse.persistence.internal.jpa.QueryImpl.getResultList(QueryImpl.java:473)
    at fish.payara.team.info.controllers.MemberSessionBean.getTeamMemberByName(MemberSessionBean.java:35)

(See also) https://payara.gitbooks.io/payara-server/content/documentation/extended-documentation/advanced-jdbc/slow-sql-logger.html

2. Full JDBC Tracing (Log JDBC Calling)

Full JDBC Tracing (Log JDBC Calling) は、JDBC (あるいは JPA) がどのようなメソッドを呼び出したのかをログに記録する機能です。内部で何をやっているのか把握しづらい JPA のデバッグなどに有効でしょう。

Full JDBC Tracing は規定では無効です。有効化する場合には、管理コンソールのデータベース設定で Log JDBC Calls に Enabled のチェックを入れる (fish.payara.log-jdbc-calls プロパティを true に設定する) 必要があります。

Full JDBC Tracing が出力するログは以下のようになります。

[#|2016-02-04T18:51:01.467+0000|FINE|Payara 4.1|javax.enterprise.resource.sqltrace.com.sun.gjc.util|_ThreadID=35;_ThreadName=http-listener-1(5);_TimeMillis=1454611861467;_LevelValue=500;ClassName=com.sun.gjc.util.SQLTraceLogger;MethodName=sqlTrace;|
  PoolName=DerbyPool | ExecutionTime=1ms | ClassName=org.apache.derby.client.net.NetConnection40 | MethodName=prepareStatement | arg[0]=SELECT ID, AGE, BIO, BIRTHDATE, BIRTHDAY, DATEFORMAT, DATEOFBIRTH, DATEOFHIRE, EMAIL, HIREDATE, HIREDAY, MEMBERAGE, NAME, TODAYSDATE FROM MEMBERENTITY WHERE (NAME = ?) | arg[1]=1003 | arg[2]=1007 | |#]

[#|2016-02-04T18:51:01.467+0000|FINE|Payara 4.1|javax.enterprise.resource.sqltrace.com.sun.gjc.util|_ThreadID=35;_ThreadName=http-listener-1(5);_TimeMillis=1454611861467;_LevelValue=500;ClassName=com.sun.gjc.util.SQLTraceLogger;MethodName=sqlTrace;|
  PoolName=DerbyPool | ExecutionTime=0ms | ClassName=com.sun.gjc.spi.jdbc40.PreparedStatementWrapper40 | MethodName=setString | arg[0]=1 | arg[1]=test | |#]

[#|2016-02-04T18:51:01.468+0000|FINE|Payara 4.1|javax.enterprise.resource.sqltrace.com.sun.gjc.util|_ThreadID=35;_ThreadName=http-listener-1(5);_TimeMillis=1454611861468;_LevelValue=500;ClassName=com.sun.gjc.util.SQLTraceLogger;MethodName=sqlTrace;|
  PoolName=DerbyPool | ExecutionTime=1ms | ClassName=com.sun.gjc.spi.jdbc40.PreparedStatementWrapper40 | MethodName=executeQuery | |#]

[#|2016-02-04T18:51:01.483+0000|FINE|Payara 4.1|javax.enterprise.resource.sqltrace.com.sun.gjc.util|_ThreadID=35;_ThreadName=http-listener-1(5);_TimeMillis=1454611861483;_LevelValue=500;ClassName=com.sun.gjc.util.SQLTraceLogger;MethodName=sqlTrace;|
  PoolName=DerbyPool | ExecutionTime=0ms | ClassName=com.sun.gjc.spi.jdbc40.PreparedStatementWrapper40 | MethodName=close | |#]

(See also) https://payara.gitbooks.io/payara-server/content/documentation/extended-documentation/advanced-jdbc/log-jdbc-calls.html

3. SQL Trace Listener

SQL Trace Listener は、JDBC (SQL) 監視を独自実装したい場合に使用します。詳細はマニュアルを参照してください。

https://payara.gitbooks.io/payara-server/content/documentation/extended-documentation/advanced-jdbc/sql-trace-listeners.html

4. Payara Micro でのサポート状況

今回ご紹介した機能は、Payara Server を主眼に置いていますが、Payara Micro でも使用できます。


2016-12-13 補足: See also http://www.coppermine.jp/docs/promised/2016/12/payara-logviewer-restriction.html