JCP log shows recurring Memory Dumps due to AAI connector

Products

• CA Automic Workload Automation - Automation Engine

Issue/Introduction

The AAI connector provokes JCP to throw Memory dumps messages printed in the JCP log as the executions query produces regular "Time critical DB call" queries, see example below:

20220930/084144.615 - 3065 U00045098 Method 'GET', URL: 'http://automic_server:8088/ae/api/v1/120/executions', received from IP: 'X.X.X.X'
20220930/084144.615 - 3065 U00045105 Log on of 'AAIPOC/TEST' successful.
20220930/084151.579 - 3065 U00003524 UCUDB: ===> Time critical DB call\! OPC: 'SLCT' time: '6964ms'
20220930/084151.579 - 3065 U00029131 UCUDB - List of bind parameters:
20220930/084151.579 - 3065 U00009907 Memory dump '(BINDPAR:  1)' (Address='n/a', Length='000004')
20220930/084151.579 - 3065 00000000  00000078 >...x<
20220930/084151.579 - 3065 >120<
20220930/084151.579 - 3065 U00009907 Memory dump '(BINDPAR:  2)' (Address='n/a', Length='000004')
20220930/084151.579 - 3065 00000000  4A4F4250 >JOBP<
20220930/084151.579 - 3065 U00009907 Memory dump '(BINDPAR:  3)' (Address='n/a', Length='000004')
20220930/084151.579 - 3065 00000000  53435249 >SCRI<
20220930/084151.594 - 3065 U00009907 Memory dump '(BINDPAR:  4)' (Address='n/a', Length='000004')
20220930/084151.594 - 3065 00000000  4A4F4253 >JOBS<
20220930/084151.594 - 3065 U00009907 Memory dump '(BINDPAR:  5)' (Address='n/a', Length='000004')
20220930/084151.594 - 3065 00000000  45564E54 >EVNT<
20220930/084151.594 - 3065 U00009907 Memory dump '(BINDPAR:  6)' (Address='n/a', Length='000004')
20220930/084151.594 - 3065 00000000  4A4F4247 >JOBG<
20220930/084151.594 - 3065 U00009907 Memory dump '(BINDPAR:  7)' (Address='n/a', Length='000004')
20220930/084151.594 - 3065 00000000  4A4F4246 >JOBF<
20220930/084151.594 - 3065 U00009907 Memory dump '(BINDPAR:  8)' (Address='n/a', Length='000004')
20220930/084151.594 - 3065 00000000  4A534348 >JSCH<
20220930/084151.610 - 3065 U00009907 Memory dump '(BINDPAR:  9)' (Address='n/a', Length='000004')
20220930/084151.610 - 3065 00000000  00000000 >....<
20220930/084151.610 - 3065 >0<
20220930/084151.610 - 3065 U00009907 Memory dump '(BINDPAR:  10)' (Address='n/a', Length='000008')
20220930/084151.610 - 3065 00000000  00000183 7770BE48  >....wp¾H<
20220930/084151.610 - 3065 >2022-09-26 01:37:01.0<
20220930/084151.610 - 3065 U00009907 Memory dump '(BINDPAR:  11)' (Address='n/a', Length='000008')
20220930/084151.610 - 3065 00000000  00000183 7770BE48  >....wp¾H<
20220930/084151.610 - 3065 >2022-09-26 01:37:01.0<
20220930/084151.625 - 3065 U00009907 Memory dump '(BINDPAR:  12)' (Address='n/a', Length='000008')
20220930/084151.625 - 3065 00000000  00000183 7770BE48  >....wp¾H<
20220930/084151.625 - 3065 >2022-09-26 01:37:01.0<
20220930/084151.625 - 3065 U00009907 Memory dump '(BINDPAR:  13)' (Address='n/a', Length='000004')
20220930/084151.625 - 3065 00000000  53006D8D >S.m.<
20220930/084151.625 - 3065 >1392536973<
20220930/084151.625 - 3065 U00003525 UCUDB: ===> 'SELECT COALESCE(EH_ModUserIdnr,AH_ModUserIdnr) EH_ModUserIdnr,
20220930/084151.625 - 3065 COALESCE(EH_ActivationTime,AH_Timestamp1) EH_ActivationTime,
20220930/084151.625 - 3065 COALESCE(EH_Name,AH_Name) EH_Name,
20220930/084151.625 - 3065 COALESCE(EH_Restart,AH_Restart) EH_Restart,
20220930/084151.625 - 3065 COALESCE(EH_Description,AH_Description) EH_Description,
20220930/084151.625 - 3065 COALESCE(EH_ParentPrc,AH_ParentPrc) EH_ParentPrc,
20220930/084151.625 - 3065 COALESCE(EH_StartTime,AH_Timestamp2) EH_StartTime,
20220930/084151.625 - 3065 COALESCE(EH_RunTime,AH_RunTime) EH_RunTime,
20220930/084151.625 - 3065 COALESCE(EH_Ert,AH_ERT) EH_Ert,
20220930/084151.625 - 3065 COALESCE(EH_HostDst,AH_HostDst) EH_HostDst,
20220930/084151.625 - 3065 COALESCE(EH_USR_Idnr,AH_USR_Idnr) EH_USR_Idnr,
20220930/084151.625 - 3065 COALESCE(EH_Ejpp_lnr,AH_Ajpp_lnr) EH_Ejpp_lnr,
20220930/084151.625 - 3065 COALESCE(EH_RefNr,AH_RefNr) EH_RefNr,
20220930/084151.625 - 3065 COALESCE(EH_Otype,AH_OType) EH_Otype,
20220930/084151.625 - 3065 COALESCE(EH_HostAttrType,AH_HostAttrTypeD) EH_HostAttrType,
20220930/084151.625 - 3065 COALESCE(EH_Status,AH_Status) EH_Status,
20220930/084151.625 - 3065 COALESCE(EH_EndTime,AH_Timestamp4) EH_EndTime,
20220930/084151.625 - 3065 COALESCE(EH_OccurCount,AH_OccurCount) EH_OccurCount,
20220930/084151.625 - 3065 COALESCE(EH_Alias,AH_Alias) EH_Alias,
20220930/084151.625 - 3065 COALESCE(EH_RetCode,AH_RetCode) EH_RetCode,
20220930/084151.625 - 3065 COALESCE(EH_ParentAct,AH_ParentAct) EH_ParentAct,
20220930/084151.625 - 3065 COALESCE(EH_Queue,AH_Queue) EH_Queue,
20220930/084151.625 - 3065 COALESCE(EH_AH_Idnr,AH_Idnr) EH_AH_Idnr,
20220930/084151.625 - 3065 COALESCE(EH_Archive2,AH_Archive2) EH_Archive2,
20220930/084151.625 - 3065 COALESCE(EH_NextCheck,AH_TimeStamp3) EH_NextCheck,
20220930/084151.625 - 3065 COALESCE(EH_Archive1,AH_Archive1) EH_Archive1,
20220930/084151.625 - 3065 COALESCE(EH_Title,AH_Title) EH_Title,
20220930/084151.625 - 3065 COALESCE(EH_EventId,AH_EventId) EH_EventId,
20220930/084151.625 - 3065 COALESCE(EH_StartType,AH_SType) EH_StartType,
20220930/084151.625 - 3065 COALESCE(EH_ContainerType,AH_ContainerType) EH_ContainerType,
20220930/084151.625 - 3065 COALESCE(EH_StartUC4,AH_StartUC4) EH_StartUC4
20220930/084151.625 - 3065   
20220930/084151.625 - 3065  FROM (SELECT * FROM (SELECT /*+INDEX (AH NK_AH_ATYP)*/ \-1 AS AH_ModUserIdnr,AH_Timestamp1,AH_Name,AH_Restart,AH_Description,AH_ParentPrc,AH_Timestamp2,AH_RunTime,AH_ERT,AH_HostDst,AH_USR_Idnr,AH_Ajpp_lnr,AH_RefNr,AH_OType,AH_HostAttrTypeD,AH_Status,AH_Timestamp4,AH_OccurCount,AH_Alias,AH_RetCode,AH_ParentAct,AH_Queue,AH_Idnr,AH_Archive2,AH_TimeStamp3,AH_Archive1,AH_Title,AH_EventId,AH_SType,AH_ContainerType,AH_StartUC4,
20220930/084151.625 - 3065 EH_ModUserIdnr,EH_ActivationTime,EH_Name,EH_Restart,EH_Description,EH_ParentPrc,EH_StartTime,EH_RunTime,EH_Ert,EH_HostDst,EH_USR_Idnr,EH_Ejpp_lnr,EH_RefNr,EH_Otype,EH_HostAttrType,EH_Status,EH_EndTime,EH_OccurCount,EH_Alias,EH_RetCode,EH_ParentAct,EH_Queue,EH_AH_Idnr,EH_Archive2,EH_NextCheck,EH_Archive1,EH_Title,EH_EventId,EH_StartType,EH_ContainerType,EH_StartUC4
20220930/084151.625 - 3065  FROM AH LEFT JOIN EH ON AH_Idnr = EH_AH_Idnr
20220930/084151.625 - 3065  WHERE AH_Client = ? AND AH_OType IN (?,?,?,?,?,?,?) AND AH_Idnr >= ? AND (AH_Timestamp1 >= ? OR AH_Timestamp4 >= ? OR (AH_Timestamp1 < ? AND AH_Timestamp4 IS NULL )) AND AH_RefNr = ? ORDER BY AH_TimeStamp1 DESC, AH_Idnr DESC) WHERE ROWNUM <= 1000000) a'
20220930/084151.704 - 3065 U00003434 Server routine  'ListExecutionServiceImpl$$Lambda$373/1306362223/rest-transaction' required '0' minutes and '7' seconds for processing.
20220930/084151.829 - 3065 U00045099 The server replied with following status: '200'

Environment

Release : 12.3.10 and 21.0.4

Component: Automation Engine

Context: AAI connector plugged to Automation Engine

Cause

Misleading message in uc.msl for message U00009907

Resolution

Solution:
Update to a fix version listed below or a newer version if available.

Fix version:
Component(s): Automation Engine
Automation.Engine 12.3.10 HF1

Additional Information

Solution Details: A problem has been fixed where the Automation Engine in combination with the AAI Automic connector caused time critical DB calls regularly.
In message U00009907 the wording "Memory dump" was changed to "Memory view".

Additionally, a fix (TERMA_CON_AUTOMIC-116) has also been added to the AAI connector included on versions AAI.Automic 3.0.1 and AAI.Automic 3.1.0 which improves the performance of fetching the results from AE.