I would like to test how long a Database Query takes to complete. |
This knowledge article may contain information that does not apply to version 21.05 or later which runs in a container environment. Please refer to Article Number 000385088 for more information about troubleshooting BMC products in containers. Note: The attached utility is an unsupported utility that must be used at your own risk. It is a simple JDBC tool that will perform a SQL statement and return the timings. So it is a low-risk tool. This tool can also perform a SQL Query via an AR API call. This will allow you to compare the timing between ARServer performing a query and a direct JDBC call performing the same query. - This utility works for both MSSQL and Oracle. - It should work on any OS that ARServer is supported on. Perform the following steps to execute the the utility: Note: This utility uses Java and assumes that the Java libraries are in the path. 1. Place the Zip file on the server where you wish to perform the test. It is often recommended to run it from the system in which ARSystem is installed in order to gauge the perform relative to that environment. 2. Extract the attached zip file into its own directory such as QueryTest or any directory name of your choosing. 3. Edit the included QueryTest.properties file. Ensure that each of the parameters is configured correctly for your specific Environment. Note that the properties file is self-documented; there are comments to help you configure properly. The QueryTest.jar is an executable jar file, which means on Windows you should be able to just double click on it. This depends on your Java and Windows configuration but general works if Java was installed correctly. 4. From Windows, double-click on the QueryTest.jar file. a. The results will be sent to QueryTestOutput.log in the same directory. You can also run the tool from a Windows command prompt or from a Linux command shell 5. Open a command prompt/shell to the directory you extracted the files to. 6. Execute the QueryTest tool. Run java -jar QueryTest.jar from the command prompt Example 1 (MSSQL/Windows from command prompt):
C:\Utilities\QueryTest>java -jar QueryTest.jar
Output looks like this: .........................
2019-01-29- 14:44:56,478 [INFO ] QueryTest v1.4
2019-01-29- 14:44:56,482 [INFO ] JDBC Test
2019-01-29- 14:44:58,021 [INFO ] SQL to be performed: select count(*) from user_x
2019-01-29- 14:44:58,021 [INFO ] Starting connection to db with URL jdbc:sqlserver://remedydb:1433
2019-01-29- 14:44:58,980 [INFO ] Established connection with url: jdbc:sqlserver://remedydb:1433;authentication=NotSpecified;authenticationScheme=nativeAuthentication;xopenStates=false;sendTimeAsDatetime=true;trustServerCertificate=false;TransparentNetworkIPResolution=true;
serverNameAsACE=false;sendStringParametersAsUnicode=true;selectMethod=direct;responseBuffering=adaptive;packetSize=8000;multiSubnetFailover=false;loginTimeout=15;lockTimeout=-1;
lastUpdateCount=true;encrypt=false;disableStatementPooling=true;databaseName=ARSystem;
columnEncryptionSetting=Disabled;applicationName=Microsoft JDBC Driver for SQL Server;applicationIntent=readwrite;
2019-01-29- 14:44:58,986 [INFO ] Query Start
2019-01-29- 14:44:59,139 [INFO ] Query End
2019-01-29- 14:44:59,139 [INFO ] Looping resultset to get count
2019-01-29- 14:44:59,143 [INFO ] Returned 1 record(s) in 1.118 second(s)
2019-01-29- 14:44:59,143 [WARN ] Query exceeded specified duration
2019-01-29- 14:45:00,143 [INFO ] Query Start
2019-01-29- 14:45:00,226 [INFO ] Query End
2019-01-29- 14:45:00,226 [INFO ] Looping resultset to get count
2019-01-29- 14:45:00,227 [INFO ] Returned 1 record(s) in 0.083 second(s)
2019-01-29- 14:45:01,228 [INFO ] Query Start
2019-01-29- 14:45:01,310 [INFO ] Query End
2019-01-29- 14:45:01,310 [INFO ] Looping resultset to get count
2019-01-29- 14:45:01,311 [INFO ] Returned 1 record(s) in 0.082 second(s)
2019-01-29- 14:45:02,312 [INFO ] Query Start
2019-01-29- 14:45:02,395 [INFO ] Query End
2019-01-29- 14:45:02,395 [INFO ] Looping resultset to get count
2019-01-29- 14:45:02,395 [INFO ] Returned 1 record(s) in 0.083 second(s)
2019-01-29- 14:45:02,396 [INFO ] Query Start
2019-01-29- 14:45:02,478 [INFO ] Query End
2019-01-29- 14:45:02,478 [INFO ] Looping resultset to get count
2019-01-29- 14:45:02,479 [INFO ] Returned 1 record(s) in 0.082 second(s)
2019-01-29- 14:45:03,479 [INFO ] JDBC Test complete
.........................
Example 2 (Oracle/Windows with Oracle Case-Insensitivity session parameters by double-clicking):
QueryTestOutput.log file looks like this:
.........................
2019-02-06- 16:16:32,418 [INFO ] QueryTest v1.6
2019-02-06- 16:16:32,428 [INFO ] JDBC Test
2019-02-06- 16:16:35,223 [INFO ] SQL to be performed: select count(*) from user_x
2019-02-06- 16:16:35,225 [INFO ] Starting connection to db with URL jdbc:oracle:thin:@localhost:1521:orcl
2019-02-06- 16:16:36,475 [INFO ] Established connection
2019-02-06- 16:16:36,737 [INFO ] Query Start
2019-02-06- 16:16:36,737 [INFO ] Adding session parameters:
2019-02-06- 16:16:36,738 [INFO ] ALTER SESSION SET NLS_COMP=LINGUISTIC
2019-02-06- 16:16:36,742 [INFO ] ALTER SESSION SET NLS_SORT=BINARY_CI
2019-02-06- 16:16:36,743 [INFO ] Executing Query: select count(*) from user_x
2019-02-06- 16:16:36,832 [INFO ] Query End
2019-02-06- 16:16:36,832 [INFO ] Looping resultset to get count
2019-02-06- 16:16:36,835 [INFO ] Returned 1 record(s) in 1.607 second(s)
2019-02-06- 16:16:36,835 [WARN ] Query exceeded specified duration
2019-02-06- 16:16:37,836 [INFO ] Query Start
2019-02-06- 16:16:37,837 [INFO ] Adding session parameters:
2019-02-06- 16:16:37,839 [INFO ] ALTER SESSION SET NLS_COMP=LINGUISTIC
2019-02-06- 16:16:37,841 [INFO ] ALTER SESSION SET NLS_SORT=BINARY_CI
2019-02-06- 16:16:37,843 [INFO ] Executing Query: select count(*) from user_x
2019-02-06- 16:16:37,846 [INFO ] Query End
2019-02-06- 16:16:37,847 [INFO ] Looping resultset to get count
2019-02-06- 16:16:37,848 [INFO ] Returned 1 record(s) in 0.010 second(s)
2019-02-06- 16:16:38,849 [INFO ] Query Start
2019-02-06- 16:16:38,851 [INFO ] Adding session parameters:
2019-02-06- 16:16:38,852 [INFO ] ALTER SESSION SET NLS_COMP=LINGUISTIC
2019-02-06- 16:16:38,854 [INFO ] ALTER SESSION SET NLS_SORT=BINARY_CI
2019-02-06- 16:16:38,855 [INFO ] Executing Query: select count(*) from user_x
2019-02-06- 16:16:38,861 [INFO ] Query End
2019-02-06- 16:16:38,862 [INFO ] Looping resultset to get count
2019-02-06- 16:16:38,863 [INFO ] Returned 1 record(s) in 0.009 second(s)
2019-02-06- 16:16:39,865 [INFO ] Query Start
2019-02-06- 16:16:39,867 [INFO ] Adding session parameters:
2019-02-06- 16:16:39,868 [INFO ] ALTER SESSION SET NLS_COMP=LINGUISTIC
2019-02-06- 16:16:39,871 [INFO ] ALTER SESSION SET NLS_SORT=BINARY_CI
2019-02-06- 16:16:39,873 [INFO ] Executing Query: select count(*) from user_x
2019-02-06- 16:16:39,876 [INFO ] Query End
2019-02-06- 16:16:39,877 [INFO ] Looping resultset to get count
2019-02-06- 16:16:39,878 [INFO ] Returned 1 record(s) in 0.011 second(s)
2019-02-06- 16:16:39,879 [INFO ] Query Start
2019-02-06- 16:16:39,880 [INFO ] Adding session parameters:
2019-02-06- 16:16:39,881 [INFO ] ALTER SESSION SET NLS_COMP=LINGUISTIC
2019-02-06- 16:16:39,883 [INFO ] ALTER SESSION SET NLS_SORT=BINARY_CI
2019-02-06- 16:16:39,885 [INFO ] Executing Query: select count(*) from user_x
2019-02-06- 16:16:39,887 [INFO ] Query End
2019-02-06- 16:16:39,888 [INFO ] Looping resultset to get count
2019-02-06- 16:16:39,890 [INFO ] Returned 1 record(s) in 0.008 second(s)
2019-02-06- 16:16:40,891 [INFO ] JDBC Test complete
.........................
Example 2 (MSSQL/Windows by double-clicking using the AR connection):
.........................
2019-02-06- 16:27:25,231 [INFO ] QueryTest v1.6 2019-02-06- 16:27:25,236 [INFO ] JDBC Test 2019-02-06- 16:27:28,578 [INFO ] SQL to be performed: select count(*) from user_x 2019-02-06- 16:27:28,579 [INFO ] Starting connection to db with URL jdbc:sqlserver://remedyprod:1433;databaseName=ARSystem 2019-02-06- 16:27:29,892 [INFO ] Established connection 2019-02-06- 16:27:29,901 [INFO ] Query Start 2019-02-06- 16:27:29,902 [INFO ] Executing Query: select count(*) from user_x 2019-02-06- 16:27:29,979 [INFO ] Query End 2019-02-06- 16:27:29,979 [INFO ] Looping resultset to get count 2019-02-06- 16:27:29,985 [INFO ] Returned 1 record(s) in 1.400 second(s) 2019-02-06- 16:27:29,986 [WARN ] Query exceeded specified duration 2019-02-06- 16:27:30,987 [INFO ] Query Start 2019-02-06- 16:27:30,988 [INFO ] Executing Query: select count(*) from user_x 2019-02-06- 16:27:30,992 [INFO ] Query End 2019-02-06- 16:27:30,994 [INFO ] Looping resultset to get count 2019-02-06- 16:27:30,995 [INFO ] Returned 1 record(s) in 0.005 second(s) 2019-02-06- 16:27:31,999 [INFO ] Query Start 2019-02-06- 16:27:32,000 [INFO ] Executing Query: select count(*) from user_x 2019-02-06- 16:27:32,003 [INFO ] Query End 2019-02-06- 16:27:32,010 [INFO ] Looping resultset to get count 2019-02-06- 16:27:32,010 [INFO ] Returned 1 record(s) in 0.004 second(s) 2019-02-06- 16:27:33,011 [INFO ] Query Start 2019-02-06- 16:27:33,012 [INFO ] Executing Query: select count(*) from user_x 2019-02-06- 16:27:33,030 [INFO ] Query End 2019-02-06- 16:27:33,030 [INFO ] Looping resultset to get count 2019-02-06- 16:27:33,030 [INFO ] Returned 1 record(s) in 0.019 second(s) 2019-02-06- 16:27:33,030 [INFO ] Query Start 2019-02-06- 16:27:33,030 [INFO ] Executing Query: select count(*) from user_x 2019-02-06- 16:27:33,030 [INFO ] Query End 2019-02-06- 16:27:33,030 [INFO ] Looping resultset to get count 2019-02-06- 16:27:33,030 [INFO ] Returned 1 record(s) in 0.000 second(s) 2019-02-06- 16:27:34,016 [INFO ] JDBC Test complete ......................... Note: There is possible issue when using SQL Server and specifying another instance name the backslash \ will not get picked up. To resolve this enter double backslash characters \\. There may be other possible scenarios where a backslash is needed. Example: DBInstance:hostname\\instance-name ================================================================ Release History 1.11 Added OracleJDBCURL. Use the Oracle-JDBC-URL setting from ar.cfg/conf 1.8 - Minor Updates 1.7 - Added ability to return query results 1.6 - Expanded Session Parameters to SQL Server 1.5 - Added Oracle Session Parameters to the config file 1.4 - Corrected the config parsing to allow , in the query without issue 1.3 - Added MSSQL 'Always On' capabilities 1.2 - Added MSSQL SSL and trust store capabilities 1.1 - Fixed MSSQL JDBC Connection String from 'integratedSecurity=true' to 'authentication=ActiveDirectoryPassword' 1.0 - Initial Release |