Tomcat overload remediation report
Al momento dell’analisi del disservizio, Il servizio Tomcat risulta attivo ma freezato:
(il riavvio di Tomcat risolve il problema e fa ripartire le API)
Nei log del Tomcat appare un errore di GC overhead limit exceeded che vuol dire che il servizio non riesce a liberare la memoria per processare nuove richieste.
ERROR|2023-07-26 20:01:58,220|6df7e73e-dde8-44ef-a2bd-e009d167a4df|fmtrap@fastweb.it|ApiExceptionHandler.java |Exception raised: org.springframework.web.util.NestedServletException: Handler dispatch failed; nested exception is java.lang.OutOfMemoryError: GC overhead limit exceeded
Presumibilmente uno o più JOB vanno a saturare la memoria e bloccano TOMCAT
Attualmente questo limite è impostato a 4GB e Si potrebbe portare a 8GB ma non abbiamo certezza che possa risolvere il problema.
Contestualmente iniziano gli errori di timeout registrati su ngnx (che non riceve risposta da tomcat entro i 180 secondi) e in particolare tutti riguardanti la macchina 10.31.181.138 che fa richieste di GET verso Remedy, anche fino a 25 al secondo:
Inoltre potremmo fare riferimento, come questione da approfondire, al seguente get di ALL TICKET su cui è impostato un sysparm_limit di 100000 record (sicuramente troppo elevato per una corretta esecuzione dello script)
2023/07/26 20:18:03 [error] 2066596#2066596: *12362945 upstream timed out (110: Unknown error) while reading response header from upstream, client: 10.31.181.138, server: tms-fem.intranet.fw, request: "GET /api/v1/ticket/internal/all?sysparm_fields=%2A&sysparm_query=Data_Creazione%3E%3D%222023-07-01%22&sysparm_limit=100000 HTTP/1.1", upstream: "http://127.0.0.1:8080/tms/api/v1/ticket/internal/all?sysparm_fields=%2A&sysparm_query=Data_Creazione%3E%3D%222023-07-01%22&sysparm_limit=100000", host: "10.31.184.147"
Dal documento fornito dal PO questo limite è indicato essere di default di 1000
Anche in questo caso la macchina 10.31.181.138 manda queste richieste di GET in maniera automatizzata e sequanziale
Allo stato attuale non possiamo procedere ad ulteriori analisi senza il coinvolgimento del PO, dei tecnici in Macedonia (ingaggiati sull’analisi ma dai quali ancora non abbiamo riscontro) ed eventualmente organizzando un congiunto con N&C integrando anche i log applicativi lato TMS.
Dall’analisi dei continui down delle API TMS localizzati sempre negli stessi orari, è risultato che Il servizio Tomcat risulta attivo ma freezato a causa di un errore di GC overhead limit exceeded che vuol dire che il servizio non riesce a liberare la memoria dai vecchi job prima di poter processare nuove richieste.
Presumibilmente uno o più JOB, localizzati in tali orari, andavano a saturare la memoria bloccando TOMCAT
Abbiamo quindi analizzato i log di ngnx riscontrando ripetuti errori di time-out e abbiamo focalizzato l’attenzione su una specifica query che ad intervalli di 2 minuti va ad interrogare Remedy per scaricare tutti i ticket presenti a sistema del mese in corso con un limite di 100.000 record
2023/07/26 20:18:03 [error] 2066596#2066596: *12362945 upstream timed out (110: Unknown error) while reading response header from upstream, client: 10.31.181.138, server: tms-fem.intranet.fw, request: "GET /api/v1/ticket/internal/all?sysparm_fields=%2A&sysparm_query=Data_Creazione%3E%3D%222023-07-01%22&sysparm_limit=100000 HTTP/1.1", upstream: "http://127.0.0.1:8080/tms/api/v1/ticket/internal/all?sysparm_fields=%2A&sysparm_query=Data_Creazione%3E%3D%222023-07-01%22&sysparm_limit=100000", host: "10.31.184.147"
Dal test effettuato in real time, è emerso che la job scarica 70000 record da Remedy andando probabilmente a saturare la memoria di Tomcat
Si è deciso quindi di intervenire sulla Query andando a modificare il range temporale della data di creazione modificandola al 20 luglio e non più al 1° del mese per limitare il numero di record da elaborare che a questo punto dovrebbero essere meno di un terzo dei precedenti
Contestualmente, come azione a supporto, si è deciso di intervenire anche sulla configurazione del Tomcat aumentando lo spazio dedicato al GC da 4GB a 8GB
Una ulteriore azione preventiva è stata quella di configurare nel Crontab del server un riavvio automatico del servizio Tomcat ogni notte alle 3.00
Questa sera verificheremo se le azioni applicate riescono a risolvere il problema