After 21.0 upgrade, AWI freezes with dashboard use

Products

CA Automic Workload Automation - Automation Engine CA Automic One Automation

Issue/Introduction

After an upgrade to 21.0 (often to 21.0.8), the UI is non-responsive. A system reboot will fix the issue temporarily.

In the WP logs, the following show up frequently:

U00003525 UCUDB: ===> 'SELECT AH.*, OTYP_Caption FROM AH, UC_OTYP WHERE AH_Client = ? AND AH_OType = OTYP_Type AND OTYP_Executable = 1 AND ah_parentact IN (select ah_idnr from ah where ah_client = ? and ah_oh_idnr = ? and ah_timestamp1 >= ?) and ah_timestamp4 is not null order by AH_TimeStamp1 desc'
U00003434 Server routine 'UCDS_R/getacthistory' required '2' minutes and '3,273' seconds for processing.

Environment

21.0

Resolution

The routine we see taking a long time in the logs, UCDS_R/getacthistory, is directly related to the My Catalog perspective which has items that can be used in dashboards. To prevent this issue from happening, the 'Access to My Catalog' privilege can be removed from users or user groups:

Additional troubleshooting needs to be done by DBAs, network and/or OS admins to determine root cause on your system. Please see Additional Information below for additional steps.

Additional Information

There are options that can put into place that can help gather the bind parameters without enabling tracing. These will not show where the slowdown is occurring, but can help DBAs in determining what the full statement is. In client 0, in UC_SYSTEM_SETTINGS, the SERVER_OPTIONS setting can have its 11th digit updated to 3 (or any other number) to put bind parameters in the logs if a time critical call takes more than that many seconds. By default it's set to NNNNNNNNNNNNNNNN. It can be updated to

NNNNNNNNNN3NNNNN

and show the bind parameters.

To find where the slowdown for the time critical call associated with the getacthistory routine is happening:

- Open the Administration perspective and navigate to Automation Engine Management
- Right-click any running WP and choose "Advanced Options"
- Update the TCP/IP dropdown to 2
- Update the Database dropdown to 3
- Be sure that "Memory trace" is checked
- Update the Memory Buffer Size to 32MB
- In the Trace Search Key box, put in the following string:
  *U00003434 Server routine 'UCDS_R/getacthistory'*
  
  These settings will ensure that if that string shows up on any WP, it will output trace files. In the meantime, 32 MB of traces are kept in memory.
- Once the traces are put into place, wait for the issue to occur again
- The traces will be written to file if any WP sees the error message with the long running routine.

Within the traces themselves, look for the timestamps associated with the long running call. This will look something like:

UCUDB32 SLUC RET 0000 HSTMT: 000002B403343350 VALUE: 0000000000000032 ALL: 820.92787 DB: 820.92751 ODBC: 0.00007 UDB: 0.00028

ALL is how long the entire call takes. In the case above it takes 820.92787 seconds or 13 minutes and 41 seconds
DB is how long it takes the call to get to the database and back from the database. This is 820.92751 seconds or 99.99996% of the 13 + minutes.
ODBC is how long the call takes to and from the odbc connection. This took .7 milliseconds
UDB is how long the transaction takes within Automic which is .28 milliseconds

If the majority of the call happens in the "DB" portions, DBAs and network and OS teams will be needed to analyze what is happening as the time spent is outside of Automic's control and could be network, OS, I/O on the db, the database itself, etc... Some things that could be possible culprits:

Is there a backup or maintenance running at the time?
Is there a port scanner running?
Is there virus protection running that could be slowing down the transaction?
Is there any other software running that could be using all the resources on the DB machine or on the server running the Automation Engine components?
What does the sp-lock show at this time (this is something a DBA can help answer)?