U00003434 ... 'TelemetryComponent/TIMER' required '28' minutes ...

Products

• CA Automic One Automation

Issue/Introduction

Daily at the same time, the following shows up:

WPsrv_log_002_00.txt:20210927/172844.141 - 41     U00003434 Server routine  'TelemetryComponent/TIMER' required '28' minutes and '44' seconds for processing.
WPsrv_log_002_00.txt:20210928/172352.342 - 42     U00003434 Server routine  'TelemetryComponent/TIMER' required '23' minutes and '52' seconds for processing.
WPsrv_log_002_01.txt:20210924/172503.373 - 41     U00003434 Server routine  'TelemetryComponent/TIMER' required '25' minutes and '3' seconds for processing.
WPsrv_log_002_01.txt:20210925/172815.149 - 41     U00003434 Server routine  'TelemetryComponent/TIMER' required '28' minutes and '15' seconds for processing.
WPsrv_log_002_01.txt:20210926/172053.001 - 41     U00003434 Server routine  'TelemetryComponent/TIMER' required '20' minutes and '52' seconds for processing.
WPsrv_log_002_02.txt:20210921/172454.029 - 40     U00003434 Server routine  'TelemetryComponent/TIMER' required '24' minutes and '54' seconds for processing.
WPsrv_log_002_02.txt:20210922/173218.941 - 40     U00003434 Server routine  'TelemetryComponent/TIMER' required '32' minutes and '18' seconds for processing.
WPsrv_log_002_02.txt:20210923/172546.514 - 41     U00003434 Server routine  'TelemetryComponent/TIMER' required '25' minutes and '46' seconds for processing.
WPsrv_log_002_03.txt:20210918/172639.299 - 41     U00003434 Server routine  'TelemetryComponent/TIMER' required '26' minutes and '39' seconds for processing.
WPsrv_log_002_03.txt:20210919/172302.323 - 40     U00003434 Server routine  'TelemetryComponent/TIMER' required '23' minutes and '2' seconds for processing.
WPsrv_log_002_03.txt:20210920/172831.360 - 42     U00003434 Server routine  'TelemetryComponent/TIMER' required '28' minutes and '31' seconds for processing.
WPsrv_log_007_04.txt:20210414/172922.453 - 41     U00003434 Server routine  'TelemetryComponent/TIMER' required '29' minutes and '22' seconds for processing.
WPsrv_log_007_05.txt:20210411/172835.776 - 42     U00003434 Server routine  'TelemetryComponent/TIMER' required '28' minutes and '35' seconds for processing.
WPsrv_log_007_05.txt:20210412/171857.308 - 42     U00003434 Server routine  'TelemetryComponent/TIMER' required '18' minutes and '57' seconds for processing.
WPsrv_log_007_05.txt:20210413/172657.666 - 42     U00003434 Server routine  'TelemetryComponent/TIMER' required '26' minutes and '57' seconds for processing.
WPsrv_log_007_06.txt:20210408/171925.454 - 41     U00003434 Server routine  'TelemetryComponent/TIMER' required '19' minutes and '25' seconds for processing.
WPsrv_log_007_06.txt:20210409/172643.690 - 42     U00003434 Server routine  'TelemetryComponent/TIMER' required '26' minutes and '43' seconds for processing.
WPsrv_log_007_06.txt:20210410/172441.047 - 42     U00003434 Server routine  'TelemetryComponent/TIMER' required '24' minutes and '41' seconds for processing.
WPsrv_log_007_07.txt:20210405/172747.230 - 42     U00003434 Server routine  'TelemetryComponent/TIMER' required '27' minutes and '47' seconds for processing.
WPsrv_log_007_07.txt:20210406/172549.226 - 41     U00003434 Server routine  'TelemetryComponent/TIMER' required '25' minutes and '49' seconds for processing.
WPsrv_log_007_07.txt:20210407/170526.570 - 42     U00003434 Server routine  'TelemetryComponent/TIMER' required '5' minutes and '26' seconds for processing.
WPsrv_log_007_08.txt:20210402/172709.036 - 43     U00003434 Server routine  'TelemetryComponent/TIMER' required '27' minutes and '9' seconds for processing.
WPsrv_log_007_08.txt:20210403/172127.560 - 42     U00003434 Server routine  'TelemetryComponent/TIMER' required '21' minutes and '27' seconds for processing.
WPsrv_log_007_08.txt:20210404/172047.031 - 42     U00003434 Server routine  'TelemetryComponent/TIMER' required '20' minutes and '47' seconds for processing.
WPsrv_log_007_09.txt:20210330/172638.827 - 43     U00003434 Server routine  'TelemetryComponent/TIMER' required '26' minutes and '38' seconds for processing.
WPsrv_log_007_09.txt:20210331/173133.425 - 42     U00003434 Server routine  'TelemetryComponent/TIMER' required '31' minutes and '33' seconds for processing.
WPsrv_log_007_09.txt:20210401/172226.397 - 41     U00003434 Server routine  'TelemetryComponent/TIMER' required '22' minutes and '26' seconds for processing.
WPsrv_log_007_10.txt:20210325/172603.285 - 42     U00003434 Server routine  'TelemetryComponent/TIMER' required '26' minutes and '3' seconds for processing.
WPsrv_log_007_10.txt:20210326/172638.344 - 43     U00003434 Server routine  'TelemetryComponent/TIMER' required '26' minutes and '38' seconds for processing.
WPsrv_log_007_10.txt:20210327/172021.626 - 42     U00003434 Server routine  'TelemetryComponent/TIMER' required '20' minutes and '21' seconds for processing.
WPsrv_log_007_10.txt:20210328/172136.678 - 41     U00003434 Server routine  'TelemetryComponent/TIMER' required '21' minutes and '36' seconds for processing.
WPsrv_log_007_10.txt:20210329/172752.384 - 43     U00003434 Server routine  'TelemetryComponent/TIMER' required '27' minutes and '52' seconds for processing.

There is also the following long running query:

02 - 20210927/172844.064 - 41     U00029131 UCUDB - List of bind parameters:
02 - 20210927/172844.064 - 41     U00009907 Memory dump '(BINDPAR:  1)' (Address='n/a', Length='000004')
02 - 20210927/172844.064 - 41               00000000  0000076C                             >...l<
02 - 20210927/172844.065 - 41                                             >1900<
02 - 20210927/172844.065 - 41     U00009907 Memory dump '(BINDPAR:  2)' (Address='n/a', Length='000004')
02 - 20210927/172844.066 - 41               00000000  00000770                             >...p<
02 - 20210927/172844.066 - 41                                             >1904<
02 - 20210927/172844.066 - 41     U00009907 Memory dump '(BINDPAR:  3)' (Address='n/a', Length='000004')
02 - 20210927/172844.067 - 41               00000000  0000076C                             >...l<
02 - 20210927/172844.067 - 41                                             >1900<
02 - 20210927/172844.068 - 41     U00009907 Memory dump '(BINDPAR:  4)' (Address='n/a', Length='000004')
02 - 20210927/172844.068 - 41               00000000  00000770                             >...p<
02 - 20210927/172844.069 - 41                                             >1904<
02 - 20210927/172844.069 - 41     U00009907 Memory dump '(BINDPAR:  5)' (Address='n/a', Length='000004')
02 - 20210927/172844.070 - 41               00000000  4A4F4253                             >JOBS<
02 - 20210927/172844.070 - 41     U00009907 Memory dump '(BINDPAR:  6)' (Address='n/a', Length='000005')
02 - 20210927/172844.070 - 41               00000000  2145564E 54                          >!EVNT<
02 - 20210927/172844.071 - 41     U00009907 Memory dump '(BINDPAR:  7)' (Address='n/a', Length='000004')
02 - 20210927/172844.071 - 41               00000000  4A4F4246                             >JOBF<
02 - 20210927/172844.072 - 41     U00009907 Memory dump '(BINDPAR:  8)' (Address='n/a', Length='000008')
02 - 20210927/172844.073 - 41               00000000  0000017C 248D1C00                    >...|$...<
02 - 20210927/172844.073 - 41                                             >2021-09-27 00:00:00.0<
02 - 20210927/172844.073 - 41     U00009907 Memory dump '(BINDPAR:  9)' (Address='n/a', Length='000008')
02 - 20210927/172844.074 - 41               00000000  0000017C 29B377FF                    >...|)³wÿ<
02 - 20210927/172844.074 - 41                                             >2021-09-27 23:59:59.999<
02 - 20210927/172844.075 - 41     U00003525 UCUDB: ===> 'SELECT COUNT(coalesce(AH_idnr,EH_AH_idnr))
02 - 20210927/172844.075 - 41      FROM AH LEFT JOIN EH ON AH_Idnr = EH_AH_Idnr WHERE (AH_Status IN (?,?) OR EH_Status IN (?,?)) AND AH_OType IN (?,?,?) AND AH_Timestamp2 BETWEEN ? AND ?'
02 - 20210927/172844.122 - 41     U00045280 Do not send telemetry data because send data is not active.
02 - 20210927/172844.123 - 41     U00045278 Telemetry data before '2020-08-31 23:59:59.999' will be removed now.
02 - 20210927/172844.141 - 41     U00003434 Server routine  'TelemetryComponent/TIMER' required '28' minutes and '44' seconds for processing.

Sometimes this brings the system to a complete standstill until it's able to finish processing and recovers on its own.

Environment

Release : 12.3

Component : AUTOMATION ENGINE

Resolution

The root cause of this is with the select statement:

SELECT COUNT(coalesce(AH_idnr,EH_AH_idnr))
02 - 20210927/172844.075 - 41      FROM AH LEFT JOIN EH ON AH_Idnr = EH_AH_Idnr WHERE (AH_Status IN (?,?) OR EH_Status IN (?,?)) AND AH_OType IN (?,?,?) AND AH_Timestamp2 BETWEEN ? AND ?'

taking a long time.  In order to reduce the time this takes, the AH table needs to be cleared out.  The customer realized after the fact that they had never run reorg an unload correctly (they had no_archive_check set to 0).  Running the reorg an unload correctly and fully allowed for the count statement to take much much less time and the standstill stopped happening.