Wednesday, November 2, 2016

Monitoring the Database Query Execution in WSO2 ESB 4.9.0


This article explains about how to monitor and log the Database query operations in WSO2 ESB 4.9.0.
  • Download the log4jdbc4-1.2.jar from [1] and copy into ESB_HOME/repository/components/lib also you should have the ojdbc6-11.2.0.2.0.jar.
  • Modify the master-datasources file as below:

<datasource>
            <name>WSO2_CARBON_DB</name>
            <description>The datasource used for registry and user manager</description>
            <jndiConfig>
                <name>jdbc/WSO2CarbonDB</name>
            </jndiConfig>
            <definition type="RDBMS">
                <configuration>
                    <url>jdbc:log4jdbc:oracle:thin:@172.22.217.37:1521/xe</url>
                    <username>esb_test</username>
                    <password>esb_test</password>
                    <driverClassName>net.sf.log4jdbc.DriverSpy</driverClassName>
                    <maxActive>50</maxActive>
                    <maxWait>30000</maxWait>
                    <testOnBorrow>true</testOnBorrow>
                    <validationQuery>SELECT 1 FROM DUAL</validationQuery>
                    <validationInterval>60000</validationInterval>
                </configuration>
            </definition>
</datasource>

  • Add the following to log4j.properties

log4j.logger.jdbc.sqlonly=INFO
log4j.logger.jdbc.sqltiming=INFO
log4j.logger.jdbc.audit=OFF
log4j.logger.jdbc.resultset=ERROR
log4j.logger.jdbc.connection=DEBUG

  • Restart the server and observe the wso2carbon.log. 

[2016-11-02 19:05:38,817]  INFO - sqlonly DELETE FROM UM_ROLE_PERMISSION WHERE UM_ROLE_NAME='cg_unpublisher' AND UM_PERMISSION_ID = (SELECT 
UM_ID FROM UM_PERMISSION WHERE UM_RESOURCE_ID = '/permission/admin/manage/un-publish' AND UM_ACTION 
= 'ui.execute' AND UM_TENANT_ID=-1234) AND UM_TENANT_ID=-1234 AND UM_DOMAIN_ID=(SELECT UM_DOMAIN_ID 
FROM UM_DOMAIN WHERE UM_TENANT_ID=-1234 AND UM_DOMAIN_NAME='INTERNAL') 

[2016-11-02 19:05:38,818]  INFO - sqltiming DELETE FROM UM_ROLE_PERMISSION WHERE UM_ROLE_NAME='cg_unpublisher' AND UM_PERMISSION_ID = (SELECT 
UM_ID FROM UM_PERMISSION WHERE UM_RESOURCE_ID = '/permission/admin/manage/un-publish' AND UM_ACTION 
= 'ui.execute' AND UM_TENANT_ID=-1234) AND UM_TENANT_ID=-1234 AND UM_DOMAIN_ID=(SELECT UM_DOMAIN_ID 
FROM UM_DOMAIN WHERE UM_TENANT_ID=-1234 AND UM_DOMAIN_NAME='INTERNAL') 
 {executed in 0 msec}
[2016-11-02 19:05:38,818]  INFO - sqlonly INSERT INTO UM_ROLE_PERMISSION (UM_PERMISSION_ID, UM_ROLE_NAME, UM_IS_ALLOWED, UM_TENANT_ID, 
UM_DOMAIN_ID) VALUES (13, 'cg_unpublisher', 1, -1234, (SELECT UM_DOMAIN_ID FROM UM_DOMAIN WHERE 
UM_TENANT_ID=-1234 AND UM_DOMAIN_NAME='INTERNAL')) 

[2016-11-02 19:05:38,819]  INFO - sqltiming INSERT INTO UM_ROLE_PERMISSION (UM_PERMISSION_ID, UM_ROLE_NAME, UM_IS_ALLOWED, UM_TENANT_ID, 
UM_DOMAIN_ID) VALUES (13, 'cg_unpublisher', 1, -1234, (SELECT UM_DOMAIN_ID FROM UM_DOMAIN WHERE 
UM_TENANT_ID=-1234 AND UM_DOMAIN_NAME='INTERNAL')) 
 {executed in 1 msec}
[2016-11-02 19:05:38,824]  INFO - sqlonly SELECT UM_ID FROM UM_HYBRID_ROLE WHERE UM_ROLE_NAME ='cg_publisher' AND UM_TENANT_ID=-1234 

[2016-11-02 19:05:38,825]  INFO - sqltiming SELECT UM_ID FROM UM_HYBRID_ROLE WHERE UM_ROLE_NAME ='cg_publisher' AND UM_TENANT_ID=-1234 
 {executed in 1 msec}
[2016-11-02 19:05:38,825]  INFO - sqlonly SELECT UM_ID FROM UM_HYBRID_ROLE WHERE UM_ROLE_NAME ='cg_unpublisher' AND UM_TENANT_ID=-1234 

[2016-11-02 19:05:38,826]  INFO - sqltiming SELECT UM_ID FROM UM_HYBRID_ROLE WHERE UM_ROLE_NAME ='cg_unpublisher' AND UM_TENANT_ID=-1234 
 {executed in 1 msec}
[2016-11-02 19:05:38,827]  INFO - sqlonly SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags/ProvisioningAdminService.flag' 
AND REG_TENANT_ID=-1234 

[2016-11-02 19:05:38,827]  INFO - sqltiming SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags/ProvisioningAdminService.flag' 
AND REG_TENANT_ID=-1234 
 {executed in 0 msec}
[2016-11-02 19:05:38,828]  INFO - sqlonly SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags' 
AND REG_TENANT_ID=-1234 

[2016-11-02 19:05:38,828]  INFO - sqltiming SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags' 
AND REG_TENANT_ID=-1234 
 {executed in 0 msec}
[2016-11-02 19:05:38,829]  INFO - sqlonly SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags/SynapseApplicationAdmin.flag' 
AND REG_TENANT_ID=-1234 

[2016-11-02 19:05:38,830]  INFO - sqltiming SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags/SynapseApplicationAdmin.flag' 
AND REG_TENANT_ID=-1234 
 {executed in 1 msec}
[2016-11-02 19:05:38,830]  INFO - sqlonly SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags' 
AND REG_TENANT_ID=-1234 

[2016-11-02 19:05:38,831]  INFO - sqltiming SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags' 
AND REG_TENANT_ID=-1234 
 {executed in 1 msec}
[2016-11-02 19:05:38,833]  INFO - sqlonly SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags/MediationSecurityAdminService.flag' 
AND REG_TENANT_ID=-1234 

[2016-11-02 19:05:38,834]  INFO - sqltiming SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags/MediationSecurityAdminService.flag' 
AND REG_TENANT_ID=-1234 
 {executed in 1 msec}
[2016-11-02 19:05:38,834]  INFO - sqlonly SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags' 
AND REG_TENANT_ID=-1234 

[2016-11-02 19:05:38,836]  INFO - sqltiming SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags' 
AND REG_TENANT_ID=-1234 
 {executed in 2 msec}
[2016-11-02 19:05:38,837]  INFO - sqlonly SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags/CarbonAppUploader.flag' 
AND REG_TENANT_ID=-1234 

[2016-11-02 19:05:38,838]  INFO - sqltiming SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags/CarbonAppUploader.flag' 
AND REG_TENANT_ID=-1234 
 {executed in 1 msec}
[2016-11-02 19:05:38,838]  INFO - sqlonly SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags' 
AND REG_TENANT_ID=-1234 

[2016-11-02 19:05:38,839]  INFO - sqltiming SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags' 
AND REG_TENANT_ID=-1234 
 {executed in 1 msec}
[2016-11-02 19:05:38,839]  INFO - sqlonly SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags/OperationAdmin.flag' 
AND REG_TENANT_ID=-1234 

[2016-11-02 19:05:38,840]  INFO - sqltiming SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags/OperationAdmin.flag' 
AND REG_TENANT_ID=-1234 
 {executed in 0 msec}
[2016-11-02 19:05:38,840]  INFO - sqlonly SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags' 
AND REG_TENANT_ID=-1234 

[2016-11-02 19:05:38,840]  INFO - sqltiming SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags' 
AND REG_TENANT_ID=-1234 
 {executed in 0 msec}
[2016-11-02 19:05:38,841]  INFO - sqlonly SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags/GAppTenantRegistrationService.flag' 
AND REG_TENANT_ID=-1234 

[2016-11-02 19:05:38,842]  INFO - sqltiming SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags/GAppTenantRegistrationService.flag' 
AND REG_TENANT_ID=-1234 
 {executed in 1 msec}
[2016-11-02 19:05:38,842]  INFO - sqlonly SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags' 
AND REG_TENANT_ID=-1234 

[2016-11-02 19:05:38,842]  INFO - sqltiming SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags' 
AND REG_TENANT_ID=-1234 
 {executed in 0 msec}
[2016-11-02 19:05:38,843]  INFO - sqlonly SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags/EventPublishService.flag' 
AND REG_TENANT_ID=-1234 

[2016-11-02 19:05:38,843]  INFO - sqltiming SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags/EventPublishService.flag' 
AND REG_TENANT_ID=-1234 
 {executed in 0 msec}
[2016-11-02 19:05:38,844]  INFO - sqlonly SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags' 
AND REG_TENANT_ID=-1234 

[2016-11-02 19:05:38,844]  INFO - sqltiming SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags' 
AND REG_TENANT_ID=-1234 
 {executed in 0 msec}
[2016-11-02 19:05:38,845]  INFO - sqlonly SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags/SequenceAdminService.flag' 
AND REG_TENANT_ID=-1234 

[2016-11-02 19:05:38,845]  INFO - sqltiming SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags/SequenceAdminService.flag' 
AND REG_TENANT_ID=-1234 
 {executed in 0 msec}
[2016-11-02 19:05:38,845]  INFO - sqlonly SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags' 
AND REG_TENANT_ID=-1234 

[2016-11-02 19:05:38,846]  INFO - sqltiming SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags' 
AND REG_TENANT_ID=-1234 
 {executed in 1 msec}
[2016-11-02 19:05:38,846]  INFO - sqlonly SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags/wso2carbon-sts.flag' 
AND REG_TENANT_ID=-1234 

[2016-11-02 19:05:38,847]  INFO - sqltiming SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags/wso2carbon-sts.flag' 
AND REG_TENANT_ID=-1234 
 {executed in 0 msec}
[2016-11-02 19:05:38,847]  INFO - sqlonly SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags' 
AND REG_TENANT_ID=-1234 

[2016-11-02 19:05:38,847]  INFO - sqltiming SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags' 
AND REG_TENANT_ID=-1234 
 {executed in 0 msec}
[2016-11-02 19:05:38,848]  INFO - sqlonly SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags/MediationLibraryAdminService.flag' 
AND REG_TENANT_ID=-1234 

[2016-11-02 19:05:38,849]  INFO - sqltiming SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags/MediationLibraryAdminService.flag' 
AND REG_TENANT_ID=-1234 
 {executed in 1 msec}
[2016-11-02 19:05:38,849]  INFO - sqlonly SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags' 
AND REG_TENANT_ID=-1234 

[2016-11-02 19:05:38,849]  INFO - sqltiming SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags' 
AND REG_TENANT_ID=-1234 
 {executed in 0 msec}
[2016-11-02 19:05:38,850]  INFO - sqlonly SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags/StatisticsAdmin.flag' 
AND REG_TENANT_ID=-1234 

[2016-11-02 19:05:38,851]  INFO - sqltiming SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags/StatisticsAdmin.flag' 
AND REG_TENANT_ID=-1234 
 {executed in 1 msec}
[2016-11-02 19:05:38,851]  INFO - sqlonly SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags' 
AND REG_TENANT_ID=-1234 

[2016-11-02 19:05:38,851]  INFO - sqltiming SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags' 
AND REG_TENANT_ID=-1234 
 {executed in 0 msec}
[2016-11-02 19:05:38,852]  INFO - sqlonly SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags/LoggedUserInfoAdmin.flag' 
AND REG_TENANT_ID=-1234 

[2016-11-02 19:05:38,853]  INFO - sqltiming SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags/LoggedUserInfoAdmin.flag' 
AND REG_TENANT_ID=-1234 
 {executed in 1 msec}
[2016-11-02 19:05:38,853]  INFO - sqlonly SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags' 
AND REG_TENANT_ID=-1234 

[2016-11-02 19:05:38,853]  INFO - sqltiming SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags' 
AND REG_TENANT_ID=-1234 
 {executed in 0 msec}
[2016-11-02 19:05:38,854]  INFO - sqlonly SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags/MediationStatisticsAdmin.flag' 
AND REG_TENANT_ID=-1234 

[2016-11-02 19:05:38,854]  INFO - sqltiming SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags/MediationStatisticsAdmin.flag' 
AND REG_TENANT_ID=-1234 
 {executed in 0 msec}
[2016-11-02 19:05:38,854]  INFO - sqlonly SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags' 
AND REG_TENANT_ID=-1234 

[2016-11-02 19:05:38,855]  INFO - sqltiming SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags' 
AND REG_TENANT_ID=-1234 
 {executed in 0 msec}
[2016-11-02 19:05:38,856]  INFO - sqlonly SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags/TopicManagerAdminService.flag' 
AND REG_TENANT_ID=-1234 

[2016-11-02 19:05:38,856]  INFO - sqltiming SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags/TopicManagerAdminService.flag' 
AND REG_TENANT_ID=-1234 
 {executed in 0 msec}
[2016-11-02 19:05:38,856]  INFO - sqlonly SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags' 
AND REG_TENANT_ID=-1234 

[2016-11-02 19:05:38,857]  INFO - sqltiming SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags' 
AND REG_TENANT_ID=-1234 
 {executed in 1 msec}
[2016-11-02 19:05:38,857]  INFO - sqlonly SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags/MessageProcessorAdminService.flag' 
AND REG_TENANT_ID=-1234 

[2016-11-02 19:05:38,858]  INFO - sqltiming SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags/MessageProcessorAdminService.flag' 
AND REG_TENANT_ID=-1234 
 {executed in 1 msec}
[2016-11-02 19:05:38,858]  INFO - sqlonly SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags' 
AND REG_TENANT_ID=-1234 

[2016-11-02 19:05:38,858]  INFO - sqltiming SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags' 
AND REG_TENANT_ID=-1234 
 {executed in 0 msec}
[2016-11-02 19:05:38,859]  INFO - sqlonly SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags/ApplicationAdmin.flag' 
AND REG_TENANT_ID=-1234 

[2016-11-02 19:05:38,859]  INFO - sqltiming SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags/ApplicationAdmin.flag' 
AND REG_TENANT_ID=-1234 
 {executed in 0 msec}
[2016-11-02 19:05:38,860]  INFO - sqlonly SELECT REG_PATH_ID FROM REG_PATH WHERE REG_PATH_VALUE='/_system/config/repository/components/org.wso2.carbon.cloud.cg/flags' 
AND REG_TENANT_ID=-1234

[1] https://code.google.com/archive/p/log4jdbc/downloads
Posted by at
Labels: ,

No comments:

Post a Comment

Subscribe to: Post Comments (Atom)