- Use Hibernate/JPA properties (if your application is using it)
- Configure P6Spy tool on WildFly (if you are issuing plain SQL Statements)
- Configure your JDBC Driver to trace statements (if available)
Logging with JPA
<property name = "hibernate.show_sql" value = "true" />
If using EclipseLink:
<property name="eclipselink.logging.level" value="FINE"/>
If using OpenJPA:
<property name="openjpa.Log" value="DefaultLevel=WARN,Runtime=INFO,Tool=INFO,SQL=TRACE"/>
Logging plain JDBC Statements
/subsystem=datasources/data-source=MySQLPool/:write-attribute(name=spy,value=true)
In order to debug the JDBC statements in your server logs, you need to create a logger element which traces the jboss.jdbc.spy package. You can do it as follows:
/subsystem=logging/logger=jboss.jdbc.spy/:add(level=TRACE)
Next, if you want to activate tracing of your Connection Pool as well, you can enable the cached-connection-manager attribute which will inform you of every connection opening and closing:
/subsystem=jca/cached-connection-manager=cached-connection-manager/:write-attribute(name=error,value=true)
Next, reload your server configuration and check from your server logs that Statements are correctly traced. Here is for example how you can see from the logs the Statement binding for a PreparedStatement which sets one parameter:
2020-08-19 00:01:13,157 DEBUG [jboss.jdbc.spy] (Thread-0) java:/datasource/mysqlds [DataSource] getConnection() 2020-08-19 00:01:13,158 DEBUG [jboss.jdbc.spy] (Thread-0) java:/datasource/mysqlds [Connection] getAutoCommit() 2020-08-19 00:01:13,158 DEBUG [jboss.jdbc.spy] (Thread-0) java:/datasource/mysqlds [Connection] setAutoCommit(false) 2020-08-19 00:01:13,158 DEBUG [jboss.jdbc.spy] (Thread-0) java:/datasource/mysqlds [Connection] prepareStatement(SELECT TRIGGER_NAME, TRIGGER_GROUP, NEXT_FIRE_TIME, PRIORITY FROM TRIGGERS WHERE NAME = 'NAME1' AND STATE = ? AND TIME <= ? ) ORDER BY NEXT_FIRE_TIME ASC, PRIORITY DESC) 2020-08-19 00:01:13,158 DEBUG [jboss.jdbc.spy] (Thread-0) java:/datasource/mysqlds [PreparedStatement] setMaxRows(1) 2020-08-19 00:01:13,158 DEBUG [jboss.jdbc.spy] (Thread-0) java:/datasource/mysqlds [PreparedStatement] setFetchSize(1) 2020-08-19 00:01:13,158 DEBUG [jboss.jdbc.spy] (Thread-0) java:/datasource/mysqlds [PreparedStatement] setString(1, WAITING) 2020-08-19 00:01:13,158 DEBUG [jboss.jdbc.spy] (Thread-0) java:/datasource/mysqlds [PreparedStatement] setBigDecimal(2, 1597788103157) 2020-08-19 00:01:13,158 DEBUG [jboss.jdbc.spy] (Thread-0) java:/datasource/mysqlds [PreparedStatement] setBigDecimal(3, 1597788013158)
Please notice that the spy parameter does not include runtime information about your Datasource statistics, therefore it’s not effective to monitor Connection leaks. For that, we recommend setting to “debug” or “error” The Cached Connection Managed in the jca subsystem:
/subsystem=jca/cached-connection-manager=cached-connection-manager:write-attribute(name=debug,value=true)
Also, by including the following logger to TRACE, will dump the static and Runtime attribute of your Connection on each usage:
/subsystem=logging/logger=org.jboss.jca/:add(level=TRACE)
Here’s a sample output from the server logs:
2020-08-21 13:04:54,948 TRACE [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (default task-1) returnConnection(668c5c34, false) Method: returnConnection(668c5c34, false) Subject: null CRI: 7d88d179 ManagedConnectionPool: Class: org.jboss.jca.core.connectionmanager.pool.mcp.SemaphoreConcurrentLinkedDequeManagedConnectionPool Object: 7179eb80 ManagedConnectionFactory: Class: org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory Object: 205c500a ConnectionManager: Class: org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl Object: 63af8ffc Pool: Name: PostgrePool Class: org.jboss.jca.core.connectionmanager.pool.strategy.OnePool Object: 316a6237 FIFO: false PoolConfiguration: MinSize: 0 InitialSize: 0 MaxSize: 20 BlockingTimeout: 30000 IdleTimeoutMinutes: 30 ValidateOnMatch: false BackgroundValidation: false BackgroundValidationMillis: 0 StrictMin: false UseFastFail: false Decrementer: org.jboss.jca.core.connectionmanager.pool.capacity.TimedOutDecrementer Available (0): InUse (1): 668c5c34 (NORMAL) (CheckedOut: 1598007894938) (Validated: 1598007794843) (Usage: 10) Statistics: ActiveCount: 1 AvailableCount: 19 AverageBlockingTime: 0 AverageCreationTime: 17 AverageGetTime: 9 AveragePoolTime: 100086 AverageUsageTime: 9 BlockingFailureCount: 0 CreatedCount: 1 DestroyedCount: 0 IdleCount: 0 InUseCount: 1 MaxCreationTime: 17 MaxGetTime: 17 MaxPoolTime: 100086 MaxUsageTime: 10 MaxUsedCount: 1 MaxWaitTime: 0 TimedOut: 0
Tracing statements using the JDBC Driver
As an alternative, you can leverage the native features (if any) of your JDBC Driver to allow tracing of SQL Statements.
As an example, for Oracle JDBC Driver you can enable logging by setting the oracle.jdbc.Trace system property:
java -Doracle.jdbc.Trace=true
Setting the system property enables global logging, which means that logging is enabled for the entire application. You can use global logging if you want to debug the entire application, or if you cannot or do not want to change the source code of the application.
On the other hand, if using MySQL Database, the following properties can be appended to the JDBC URL to enable logging
&logger=com.mysql.jdbc.log.Slf4JLogger&profileSQL=true
To learn more details about this option, we recommend checking this article: How to trace JDBC Statements performance in MySQL
JBoss AS 4/5/6
At first download the file p6spy-install.zip from here:
http://sourceforge.net/projects/p6spy/files/p6spy/1.3/p6spy-install.zip/download
Step # 1
Unzip the file and look for the file p6spy.jar. This file needs to be placed in JBoss lib directory (For JBoss 4.x you can use JBOSS_HOME/server/<server>/lib. With JBoss 5.x or later you can place it under JBOSS_HOME/common/lib)
Step #2
Place the file spy.properties in a folder inside your JBoss distribution. (For example, I have placed into the folder JBOSS_HOME/server/<server>/db )
#Step 3
Add to your server’s CLASSPATH, the folder where you have placed the spy.properties. In our example this would be:
set JBOSS_CLASSPATH=%RUN_CLASSPATH%;C:\jboss-4.2.2.GA\server\default\db
Step #4
Edit the DataSource file that points the connections that needs to be traced and change the driver’s class to use P6Spy driver. Example, for an Oracle Datasource:
<datasources> <local-tx-datasource> <jndi-name>ORACLEDS</jndi-name> <connection-url>jdbc:oracle:thin:@192.168.1.10:1530:MYSID</connection-url> <driver-class>com.p6spy.engine.spy.P6SpyDriver</driver-class> <user-name>user</user-name> <password>pwd</password> <metadata> <type-mapping>Oracle9i</type-mapping> </metadata> </local-tx-datasource> </datasources>
#Step 5
realdriver=oracle.jdbc.driver.OracleDriver
Testing the Spy Driver
When you execute any query with the Datasource ORACLEDS, P6Spy will log each statement with the following format:
The log file format of spy.log follows:
current time|execution time|category|statement SQL String|effective SQL string 1278343428665|32|8|statement|select count(*) from meta_parametri where cod_tipo = ?|select count(*) from meta_parametri where cod_tipo = 3
Here we have issued a Statement at the timestamp 1278343428665, which took 32ms. The following number indicates the logging category (you can manage your log by including and excluding categories, which is described in Common Property File Settings). Finally you have two sql statements: at first the one which you have coded and then the actual statement which has been executed by the DB.
What about Hibernate users ? Hibernate users can debug sql statements in two ways: the simple solution is setting the property show_sql to true in your Session Factory Configuration.
<property name=”show_sql”>true</property>
However, this approach is not very flexible and produces too much logging. If you want to redirect your SQL logs in a customized file, then you need simply create a category for your logs which references the packages org.hibernate.SQL:
<appender name="SQLFile" class="org.apache.log4j.RollingFileAppender"> <param name="File" value="${jboss.server.log.dir}/sql.log"/> <param name="Append" value="true"/> <param name="MaxFileSize" value="500KB"/> <param name="MaxBackupIndex" value="1"/> <layout class="org.apache.log4j.PatternLayout"> <param name="ConversionPattern" value="%d %m%n"/> </layout> </appender> <category name="org.hibernate.SQL" additivity="false"> <priority value="debug" /> <appender-ref ref="CONSOLE" /> <appender-ref ref="SQLFile" /> </category>
<session-factory> <property name="hibernate.bytecode.use_reflection_optimizer">false</property> <property name="hibernate.connection.driver_class">com.p6spy.engine.spy.P6SpyDriver</property> <property name="hibernate.connection.password">password</property> <property name="hibernate.connection.url">jdbc:mysql://localhost:3306/mkyong</property> <property name="hibernate.connection.username">root</property> <property name="hibernate.dialect">org.hibernate.dialect.MySQLDialect</property> <property name="show_sql">true</property> </session-factory>