Thursday, May 21, 2015

WSO2 ESB - Monitor DB operations with log4jdbc

Preparing the MySQL database

1. Install MySQL database if it isn’t installed on your computer.
2. Log in to MySQL using the following command.
> mysql -u root -p
Enter password: <rootPassword>

3. Issue the following commands to create the database regdb.
create database regdb;

Configuring WSO2 ESB

1. Download WSO2 ESB 4.8.1 from here. If you already have the product zip file (wso2esb-4.8.1.zip) continue with the next step.

2. Unzip the product to a path containing no spaces in the path name. This is your <ESB_HOME>

3. Download and add log4jdbc driver.

You can find the log4jdbc driver pre-built jar files from here.
I have used log4jdbc4-1.2.jar for this tutorial.

Download and copy it to <ESB_HOME>/repository/components/lib/ directory.

4. Open log4j.properties file from terminal.
> vi <ESB_HOME>/repository/conf/log4j.properties

Append below content at the end of log4j.properties file.

# Log all JDBC calls except for ResultSet calls
log4j.logger.jdbc.audit=INFO,jdbc
log4j.additivity.jdbc.audit=false

# Log only JDBC calls to ResultSet objects
log4j.logger.jdbc.resultset=INFO,jdbc
log4j.additivity.jdbc.resultset=false

# Log only the SQL that is executed.
log4j.logger.jdbc.sqlonly=DEBUG,sql
log4j.additivity.jdbc.sqlonly=false

# Log timing information about the SQL that is executed.
log4j.logger.jdbc.sqltiming=DEBUG,sqltiming
log4j.additivity.jdbc.sqltiming=false

# Log connection open/close events and connection number dump
log4j.logger.jdbc.connection=FATAL,connection
log4j.additivity.jdbc.connection=false

# the appender used for the JDBC API layer call logging above, sql only
log4j.appender.sql=org.apache.log4j.FileAppender
log4j.appender.sql.File=${carbon.home}/repository/logs/sql.log
log4j.appender.sql.Append=false
log4j.appender.sql.layout=org.apache.log4j.PatternLayout
log4j.appender.sql.layout.ConversionPattern=-----> %d{yyyy-MM-dd HH:mm:ss.SSS} %m%n%n

# the appender used for the JDBC API layer call logging above, sql timing
log4j.appender.sqltiming=org.apache.log4j.FileAppender
log4j.appender.sqltiming.File=${carbon.home}/repository/logs/sqltiming.log
log4j.appender.sqltiming.Append=false
log4j.appender.sqltiming.layout=org.apache.log4j.PatternLayout
log4j.appender.sqltiming.layout.ConversionPattern=-----> %d{yyyy-MM-dd HH:mm:ss.SSS} %m%n%n

# the appender used for the JDBC API layer call logging above
log4j.appender.jdbc=org.apache.log4j.FileAppender
log4j.appender.jdbc.File=${carbon.home}/repository/logs/jdbc.log
log4j.appender.jdbc.Append=false
log4j.appender.jdbc.layout=org.apache.log4j.PatternLayout
log4j.appender.jdbc.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss.SSS} %m%n

# the appender used for the JDBC Connection open and close events
log4j.appender.connection=org.apache.log4j.FileAppender
log4j.appender.connection.File=${carbon.home}/repository/logs/connection.log
log4j.appender.connection.Append=false
log4j.appender.connection.layout=org.apache.log4j.PatternLayout
log4j.appender.connection.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss.SSS} %m%n

5. Edit the default database configuration (data source definition configuration URL and driverClassName) defined in the  master-datasources.xml  file located at <ESB_HOME>/repository/conf/datasources directory.

<url>jdbc:log4jdbc:mysql://localhost:3306/regdb?autoReconnect=true</url>
<username>root</username>
<password>root</password>
<driverClassName>net.sf.log4jdbc.DriverSpy</driverClassName>

Please note that the previously created regdb database is used and my root password is "root".

6. Starting the WSO2 ESB server.

To create the tables in the MySQL database automatically upon server start, issue the following command.
Run the script wso2server.bat -Dsetup (on Windows) or wso2server.sh -Dsetup (on Linux/Solaris) from the <ESB_HOME>/bin folder.

7. Verify whether the database tables are created.
mysql>use regdb;
Database changed
mysql> show tables;
+-----------------------+
| Tables_in_ regdb      |
+-----------------------+
| REG_ASSOCIATION       |
| REG_CLUSTER_LOCK      |
| REG_COMMENT           |
| REG_CONTENT           |
| REG_CONTENT_HISTORY   |
| REG_LOG               |
| REG_PATH              |
| REG_PROPERTY          |
| REG_RATING            |
| REG_RESOURCE          |
| REG_RESOURCE_COMMENT  |
| REG_RESOURCE_HISTORY  |
| REG_RESOURCE_PROPERTY |
| REG_RESOURCE_RATING   |
| REG_RESOURCE_TAG      |
| REG_SNAPSHOT          |
| REG_TAG               |
| UM_ACCOUNT_MAPPING    |
| UM_CLAIM              |
| UM_DIALECT            |
| UM_DOMAIN             |
| UM_HYBRID_REMEMBER_ME |
| UM_HYBRID_ROLE        |
| UM_HYBRID_USER_ROLE   |
| UM_MODULE             |
| UM_MODULE_ACTIONS     |
| UM_PERMISSION         |
| UM_PROFILE_CONFIG     |
| UM_ROLE               |
| UM_ROLE_PERMISSION    |
| UM_SHARED_USER_ROLE   |
| UM_SYSTEM_ROLE        |
| UM_SYSTEM_USER        |
| UM_SYSTEM_USER_ROLE   |
| UM_TENANT             |
| UM_USER               |
| UM_USER_ATTRIBUTE     |
| UM_USER_PERMISSION    |
| UM_USER_ROLE          |
+-----------------------+
39 rows in set (0.00 sec)

View log files

1. Go to <ESB_HOME>/repository/logs
2. tail -f sqltiming.log
3. Perform DB operations and view query execution stats.

e.g.: create a user role "testrole" and view the log output.

-----> 2015-05-21 15:07:20.129  org.wso2.carbon.user.core.util.DatabaseUtil.getIntegerValueFromDatabase(DatabaseUtil.java:348)
1. SELECT UM_ID FROM UM_ROLE WHERE UM_ROLE_NAME='testrole' AND UM_TENANT_ID=-1234
 {executed in 0 msec}

-----> 2015-05-21 15:07:20.130  org.wso2.carbon.user.core.jdbc.JDBCUserStoreManager.updateStringValuesToDatabase(JDBCUserStoreManager.java:2043)
1. INSERT INTO UM_ROLE (UM_ROLE_NAME, UM_TENANT_ID) VALUES ('testrole', -1234)
 {executed in 0 msec}

-----> 2015-05-21 15:07:20.133  org.wso2.carbon.user.core.util.DatabaseUtil.udpateUserRoleMappingInBatchMode(DatabaseUtil.java:497)
1. batching 0 statements:
 {executed in 0 msec}