Investigating slow AR System API calls
Before you begin
Before investigating a slow API call, make sure that you have performed the following tasks:
- Collect logs for a performance issue.
- Run AR System Log Analyzer to generate results in web (HTML) format.
- View AR System Log Analyzer output to assess the statistics captured.
To investigate a slow API call
- Under API Aggregates, click Top N to view the longest running individual API calls.
Click the line number for the long-running API call.
Log entries for API calls have a dark shaded background, and log entries for SQL statements have a light background, so viewing API calls and the corresponding SQL statements contained within them is easy.- View the Timestamp column and scroll down to look for a gap of several seconds to see where the bulk of the time occurred while the API call was processed.
- Stop scrolling down when you reach the end of the API call (signified by the OK line).
The time difference should be the Execution Time reported in Top N. The general guideline is if more time gaps occurred in SQL statements, investigate it as a slow SQL statement.
To investigate a slow SQL statement
- Identify a long-running SQL statement using the previous procedure.
Note the SQL statement. - Under SQL Aggregates, click Top N.
- Search the list of longest-running individual SQL statements for ones similar to the SQL statement identified earlier.
The general guideline is if the statement is listed in 10 percent of the Top N longest-running SQL statements, the statement might have an issue running efficiently at the database. - For long-running SQL statements, click the line number of a long-running SQL statement.
The log is displayed at the specified line number. - Verify that the SQL statement is immediately followed by an OK entry.
SQL exceptions, or cases where there is no OK line indicate a false reading at the time to execute the SQL statement. Check if the complete SQL statement is listed or if it ends with an ellipsis (...), indicating that the statement was truncated in the log.
If the SQL statement was truncated, the database administrator might not have enough information to investigate the issue.For long-running SQL statements, send the SQL statement to the database administrator to test whether the query uses appropriate indexes.
To investigate slow API calls or SQL statements due to contention or blocking events
- Under API Aggregates, click Top N to view the execution times of the Top N longest running individual API calls.
- Identify similar API calls that begin at the same time.
The general guideline is to look for API calls where Start Time occurs within the same one-minute period. - Click the line number to view the log entry at that line.
- Note the value of RPC ID in the third column.
- Scroll through the list of log entries with the same value of RPC ID, watching the Timestamp column for a gap in the time to identify which API call or SQL statement takes the most time within the long-running individual API call.
This API call or SQL statement is a potential cause of the contention. - Under API Aggregates, click Top N to return to the list of longest-running individual API call, and repeat the procedure for a similar API call that begins at the same time.
- If the potential cause of contention is an SQL statement, perform the following actions:
- Verify optional configuration in the AR System Administration:AR System Configuration Generic UI form for the following settings:
- Next-ID-Block-Size
- Select-Query-Hint
- Send the SQL statement and timestamp to the database administrator to check if there were any SQL deadlocks or issues at the database at the timestamp.
- Verify optional configuration in the AR System Administration:AR System Configuration Generic UI form for the following settings:
- If the potential cause of contention is an API call, perform the following actions:
- Use the grep command to identify all lines in the Filter log with the value of the RPC ID identified in the API call, and examine the filter log.
- Check for system problems reported in the armonitor.log file or on the system hosting AR System.
Example
An administrator investigating a performance issue synchronizing from BMC Atrium Discovery and Dependency Mapping to BMC Atrium CMDB views the top 20 longest running API operations and observes:
There are six instances of the GWIN API call and six instances of the GLEWF BMC.CORE:BMC_Impact_D call, all within the same second.
This might indicate one API call is embedded within a bulk API call, so the administrator clicks Legend to view the full name of the API calls:
The legend shows:
and
A slow GLEWF API call might be contained in the GWIN API call, and makes it appear slow.
Under API Aggregates, the administrator clicks Top N, and then clicks the line number to view the longest-running API call.
The administrator scrolls up a few lines to review the lines with the same value of RPC ID and observes that the GWIN API call includes the GLEWF API call, and a SQL statement within the API call takes more than 18 seconds to execute.
The administrator reviews the other six long API operations and confirms similar behavior.
The administrator sends the SQL statements and timestamp to the database administrator to investigate if the query uses appropriate indexes, and if deadlocks were encountered at the database at the time of the timestamp values.
Where to go from here
Assessing-relevance-of-performance-issues
Analyzing-thread-statistics