The BMC Remedy AR System server adds exception logging to the API and SQL server statistics feature. This feature provides additional options for managing API and SQL performance statistics. The key additions are:
- A new log file, arexception.log, is the repository for all exception-logging activity. The arexception.log file is managed like the arerror.log file.
- API calls that reach the server and are not completed before the client times out are logged to arexception.log. A client timeout server event is also available that allows client timeouts to be detected through server workflow.
- API and SQL calls that exceed the defined minimum time threshold are logged immediately to arexception.log if the exception-logging option is enabled.
You enable exception logging for the performance statistics feature on the Server Statistics tab of the Administration Server form by selecting Enable Exception Logging in the API/SQL Performance Tracking form.
Server Statistics tab
The Server Recording Mode determines what information is recorded in the server statistics form. The values are:
- 0 — (Default) Recording is off.
- 1 — The server records only cumulative queue statistics (the sum of all the individual queue statistics).
- 2 — The server records both cumulative and individual queue statistics. One entry is written for the cumulative statistics and a separate entry is written for each queue.
The Recording Interval is at which the server records server statistics. The default is 60 seconds.
For more information about the API/SQL Performance Tracking form, see Setting server statistics options.
This document covers the following topics:
Like the arerror.log file, the arexception.log file is created automatically with no options for its name or location. Log lines are always appended to arexception.log, and the file does not have an artificial size limit. The AR Server version string is written to arexception.log every time the server starts up.
The contents of a log segment consist of the following components:
- Message that describes why logging is occurring
- Timing statement to quantify why this operation is being logged
- Log lines (in the same format as if they had been logged to the API or SQL log)
- Status messages, should any notes, warnings, or errors occur during execution
The following figure shows an example of the arexception.log file:
The format of the exception log is similar to the arerror.log file in that each entry starts with a message, followed by supporting information. A message is tagged as an ARNOTE. The following messages are used in exception logging:
SQL operation elapsed time has exceeded the configured threshold (ARNOTE 595)
API operation elapsed time has exceeded the configured threshold (ARNOTE 596)
API operation did not complete prior to the client timeout (ARNOTE 597)
API and SQL operation did not complete prior to the client timeout (ARNOTE 598)
Logging long-running API and SQL to the exception log
With the existing performance statistics feature, API and SQL calls that exceed the threshold value and are within the top 20 (or the value specified in the Number of Operations field) were saved in the AR Server's memory. That collected data can be written to a form on a scheduled basis or on demand. When exception logging is enabled, all long-running API and SQL calls are immediately written to the arexception.log file. Writing to the exception log is independent of saving the top 20 collected calls: both methods may be used, one may be used, or neither may be used.
The threshold value for long-running API and SQL calls is specified in the Minimum Elapsed Time field of the API/SQL Performance Tracking form. The threshold value is shared with the performance statistics feature, with a default value of 5,000 ms (5 seconds).
Client timeout logging
Logging client timeouts for calls that reach the server is not optional: each time the AR Server detects this condition, it is written to the exception log based on pre-execution or post-execution checks:
1. Pre-execution check
This occurs when an API has just started being processed by the thread assigned to the call, and the call is not one that performs updates. This check ensures that the call has not already spent all of its time in the Dispatcher queue and that it does not start performing any work when the client is no longer waiting. This type of call is logged as a failure, because the server records an error in the status. For example:
2. Post-execution check
This occurs when the call is completed and the API performance statistics have been gathered. This type of call is logged as a success or failure depending on what occurs when the call runs. There are two variations of this occurrence:
- An API call with no SQL identified as the root cause of the timeout -- If multiple SQL statements within the API exceed the client timeout by themselves, only the first and most important SQL statement is included.
- An API call with an SQL statement that exceeds the client timeout value - -If multiple SQL statements within an API each contribute to the excessive overall time, but none in particular exceed the client timeout, no SQL statement is included. Diagnosing this case still requires full API/SQL/filter logging.
The following figures show examples of the two cases. The first shows an API call with no SQL, and the second shows an API call with an SQL call that exceeds the client timeout:
Long-running API and SQL calls
Logging long-running API and SQL calls to the exception log depends on enabling exception logging in the API/SQL Performance Tracking form. After they are enabled, all calls that exceed the minimum elapsed time value are immediately recorded in the exception log. Gathering performance statistics occurs regardless of whether exception logging is enabled. Saving the top 20 long-running API or SQL calls in memory does not influence logging behavior. Qualifying items are not saved in the Top 20 list if the list already has 20 items of greater elapsed time, but all long-running API and SQL calls are logged. The following logging scenarios are possible:
The following example shows a typical logging sequence for an SQL call with no associated API call:
Standalone SQL that produced an error
The following example shows an SQL call that exceeds the threshold does not complete successfully:
SQL call within an API call
The following example shows an SQL call that exceeds the minimum elapsed time threshold, causing its API call to exceed the threshold as well:
An API call that exceeds the threshold without any corresponding SQL looks like this:
Server Event support for client timeouts
The AR System server adds a server event type for client timeouts. With this feature, a server event entry is created that provides information about the API call that experienced the timeout. Client timeouts can be detected with server event workflow, which provides expanded capabilities for communicating with administrators and users. For example, if a long-running API call caused a client timeout, server event workflow could email the affected user and notify the administrator about the details of the timeout.
You enable server event support for client timeouts by selecting Client Timeout on the Server Events tab of the Admin Console:
The information provided in the Server Event form is tailored to notifications, with fields that can be easily used in the qualification and as substitution parameters in the notification text. For more information, see Types of events you can record and Viewing client timeout server event details.
Server event workflow
The standard BMC Remedy AR System does not include server event workflow, and the client timeout feature does not provide workflow with the form. The administrator must create the server event workflow. The following figure shows an example of the filter workflow an administrator might use to be notified of a user timeout: