Advanced Oracle JDBC Logging

One of the challenges for a J2EE application is to understand the I/O operations to the underlying database.

The queries/stored procedures/prepared statements all have value to the J2EE applications but during RCA (root-cause-analysis) process, it can be challenging to identify where GAPs or improvements may be made. Improvements may be from the vendor of the J2EE applications (via a support ticket/enhancement) or custom client efforts for business rule SQL processes or embedded JAR with JDBC logic.

To assist with this RCA efforts we examined four (4) areas that have value to examine an application using an Oracle 12c/18c+ Database.

1. J2EE logging using embedded features for datasources. This includes the JDBC spy process for Wildfly/JBOSS; and the ability to dynamically change logging levels or on/off features with the jboss-cli.sh process.

2. Intercept JDBC processes – An intermediate JDBC jar that will add additional logging of any JDBC process, e.g. think Wireshark type process. [As this will require additional changes; will describe this process last]

3. Diagnostics JDBC Jars – Oracle provides “Diagnosability in JDBC” Jars with the format of ojdbcX_g.jar that are enabled with a JVM switch “- Doracle.jdbc.Trace=true”

4. AWR (Automatic Workload Repository ) Reports – Using either command line (SQL) or the Oracle SQL Developer GUI.

J2EE Logging (JDBC Spy)

An example of the above process using the Wildfly/JBOSS jboss-cli.sh process is provided below in a CLI script. The high value of this process is that it takes advantage of OOTB existing features that do NOT require any additional files to be download or installed.

Implementing this process will be via a flat-file with keywords for the command line JBOSS management console, which is taken as an input via the jboss-cli.sh process. (if you are not running under the context of the Wildfly/JBoss user, you will need to use the add-user.sh process).

The below script focuses on the active databases for the Symantec/Broadcom/CA Identity Management solution’s ObjectStore (OS) and TaskPersistence (TP) databases. JDBC debug entries will be written to server.log.

# Name:  Capture JDBC queries/statements for TP and OS with IM business rules
# Filename: im_jdbc_spy_for_tp_and_os.cli
# /apps/CA/wildfly-idm/bin/jboss-cli.sh --connect  --file=im_jdbc_spy_for_tp_and_os.cli
# /opt/CA/wildfly-idm/bin/jboss-cli.sh --connect --user=jboss-admin --password=Password01!  --file=im_jdbc_spy_for_tp_and_os.cli
#
connect
echo "Take a snapshot backup of IM configuration file before any changes"
:take-snapshot
# Query values before setting them
echo "Is JDBC Spy enabled for TP DB : result = ?"
echo
/subsystem=datasources/data-source=iam_im-imtaskpersistencedb-ds/:read-attribute(name=spy)
echo "Is JDBC Spy enabled for OS DB : result = ?"
echo
/subsystem=datasources/data-source=iam_im-imobjectstoredb-ds/:read-attribute(name=spy)
echo "Enable JDBC Spy for TP and OS DB"
echo
# Always use batch with run-batch - will auto rollback on any errors for updates
batch
/subsystem=datasources/data-source=iam_im-imtaskpersistencedb-ds/:write-attribute(name=spy,value=true)
/subsystem=datasources/data-source=iam_im-imobjectstoredb-ds/:write-attribute(name=spy,value=true)
/subsystem=jca/cached-connection-manager=cached-connection-manager/:write-attribute(name=error,value=true)
run-batch
#/subsystem=logging/logger=jboss.jdbc.spy/:read-resource(recursive=false)
echo "Is JDBC Spy enabled for TP DB : result = ?"
echo
/subsystem=datasources/data-source=iam_im-imtaskpersistencedb-ds/:read-attribute(name=spy)
echo "Is JDBC Spy enabled for OS DB : result = ?"
echo
/subsystem=datasources/data-source=iam_im-imobjectstoredb-ds/:read-attribute(name=spy)
echo ""

echo "Check if logger is enabled already; if not then set"
# Use log updates in separate batch process to prevent rollback of entire process if already set
echo
batch
/subsystem=logging/logger=jboss.jdbc.spy/:add(level=TRACE)
run-batch

#
#
# Restart the IM service (reload does not work 100%)
# stop_im start_im restart_im

If you have access to install the X11 drivers for the OS, you may also view the new updates to the JBoss/Wildfly datasources.

AWR Reports

This is a common method that DBAs will use to assist application owners to identify I/O or other challenges that may be impacting performance. The ability to execute the AWR Report may be delegated to a non-system service ID (schema IDs).

This process may be executed at the SQLplus prompt but for application owners, it is best executed from Oracle Developer GUI. The process outlined in one (1) slide diagram below will showcase how to execute an AWR report, and how to generate one for our requirements.

Intercept JDBC processes –

One of the more interesting processes is a 3rd party “man-in-the-middle” approach that will capture all JDBC traffic. We can think of this as Wireshark-type process.

We have left this process to last, as it does require additional modification to the JBoss/Wildfly environment. If the solution deployed is standalone, then the changes are straightforward to change. If the solution is on the Virtual Appliance, we will need to review alternative methods or request access to add additional modules to the appliance.

For this process, we chose the p6spy process.

A quick view to see the JDBC calls being sent from the IM solution to the Oracle Database with values populated. We can also capture the return, but this would be a very large amount of data.

#!/bin/bash
##################################################
# Name: p6spy.sh
#
# Goal:  Deploy the p6spy jar to assist with RCA for IM solution
# Ref:  https://github.com/p6spy/p6spy
#
# A. Baugher, ANA, 04/2020
##################################################
JBOSS_HOME=/opt/CA/wildfly-idm
USER=wildfly
GROUP=wildfly

mkdir -p /tmp/p6spy
rm -rf /tmp/p6spy/*.jar
cd /tmp/p6spy
time curl -L -O https://repo1.maven.org/maven2/p6spy/p6spy/3.9.0/p6spy-3.9.0.jar
ls -lart *.jar
md5sum p6spy-3.9.0.jar
rm -rf $JBOSS_HOME/modules/system/layers/base/com/p6spy/main
mkdir -p $JBOSS_HOME/modules/system/layers/base/com/p6spy/main
cp -r -p p6spy-3.9.0.jar $JBOSS_HOME/modules/system/layers/base/com/p6spy/main
ls -lart $JBOSS_HOME/modules/system/layers/base/com/p6spy/main
cd /opt/CA/wildfly-idm/modules/system/layers/base/com/p6spy/main
cat << EOF >> module.xml
<module xmlns="urn:jboss:module:1.0" name="com.p6spy">
    <resources>
        <resource-root path="p6spy-3.9.0.jar"/>
    </resources>
    <dependencies>
        <module name="javax.api"/>
        <module name="javax.transaction.api"/>
<module name="com.ca.iam.jdbc.oracle"/>
    </dependencies>
</module>
EOF
chown -R $USER:$GROUP $JBOSS_HOME/modules/system/layers/base/com/p6spy
chmod -R 755  $JBOSS_HOME/modules/system/layers/base/com/p6spy
chmod -R 664  $JBOSS_HOME/modules/system/layers/base/com/p6spy/main/*
ls -lart
cat module.xml
# Update spy.properties file
curl -L -O https://raw.githubusercontent.com/p6spy/p6spy/master/src/main/assembly/individualFiles/spy.properties
rm -rf  $JBOSS_HOME/standalone/tmp/spy.properties
cp -r -p spy.properties $JBOSS_HOME/standalone/tmp/spy.properties
chown -R $USER:$GROUP $JBOSS_HOME/standalone/tmp/spy.properties
chmod -R 666 $JBOSS_HOME/standalone/tmp/spy.properties
ls -lart $JBOSS_HOME/standalone/tmp/spy.properties

 <drivers>
                    <driver name="p6spy" module="com.p6spy">
                       <driver-class>com.p6spy.engine.spy.P6SpyDriver</driver-class>
                    </driver>
                    <driver name="ojdbc" module="com.ca.iam.jdbc.oracle">
                        <driver-class>oracle.jdbc.OracleDriver</driver-class>
                        <xa-datasource-class>oracle.jdbc.xa.client.OracleXADataSource</xa-datasource-class>
                    </driver>
 </drivers>

<!-- ##############################  BEFORE P6SPY ##########################
                <datasource jta="false" jndi-name="java:/iam/im/jdbc/jdbc/idm" pool-name="iam_im-imtaskpersistencedb-ds" enabled="true" use-java-context="true" spy="true">
                    <connection-url>jdbc:oracle:thin:@//database_srv:1521/xe</connection-url>
                    <driver>ojdbc</driver>
   ##############################  BEFORE P6SPY ##########################
-->
                <!-- <datasource jndi-name="java:/jdbc/p6spy" enabled="true" use-java-context="true" pool-name="p6spyPool"> -->

                <datasource jndi-name="java:/iam/im/jdbc/jdbc/idm" pool-name="p6spyPool" enabled="true" use-java-context="true">
                        <connection-url>jdbc:p6spy:oracle:thin:@//database_srv:1521/xe</connection-url>
                        <driver>p6spy</driver>

References:

https://p6spy.readthedocs.io/en/latest/index.html https://p6spy.readthedocs.io/en/latest/configandusage.html#common-property-file-settings   [doc on JDBC intercept settings] https://github.com/p6spy/p6spy/blob/master/src/main/assembly/individualFiles/spy.properties  [sample spy.property file for JDBC intercepts] https://github.com/p6spy/p6spy   [git] https://mvnrepositor.com/artifact/p6spy/p6spy    [jar]

Extra(s)

A view into the ojdbc8_g.jar for the two (2) system properties, that are all that typically is required to use this logging functionality.