Ho ricevuto una chiamata da qualcuno che stavano ricevendo errori TNS-12519 nella loro applicazione. Abbastanza sicuro, quei messaggi erano anche nel file listener.log.
TNS-12519: TNS:no appropriate service handler found
Per coloro che non hanno familiarità con questo errore, in genere significa una delle due cose. Il nome del servizio non è registrato con il listener o il database ha raggiunto il numero massimo di processi. Per quest'ultimo, quello che succede è che il Listener sa che il database non può accettare nuovi processi, quindi porta il nome del servizio fuori servizio per così dire. Un rapido "stato lsnrctl" mi mostra che il nome del servizio è registrato correttamente. Quindi deve essere quest'ultimo. Quindi emetto la seguente domanda e confermo i miei sospetti.
SQL> select resource_name,current_utilization,max_utilization 2 from v$resource_limit where resource_name='processes';
RESOURCE_NAME CURRENT_UTILIZATION MAX_UTILIZATION --------------- ------------------- --------------- processes 299 300
Abbastanza sicuro. Ho raggiunto il numero massimo di processi, che è definito nel mio SPFILE come 300. Ho aumentato il parametro a 600 e ho fatto rimbalzare l'istanza. Abbiamo riscontrato di nuovo l'errore con il doppio del numero di processi. Ovviamente ho bisogno di approfondire ulteriormente.
Per un po' di background e per qualcosa che sarà importante in seguito, è importante sapere che questo database supporta i nostri sforzi di test automatizzati. Abbiamo un cablaggio di prova che esercita la nostra applicazione di produzione primaria. Questa suite di test avvia l'applicazione, si connette al database, preme alcuni pulsanti e seleziona alcune voci di menu, quindi si disconnette.
Ho esaminato il file listener.log per vedere da dove provenivano le richieste di connessione. Queste richieste provenivano da un server di applicazioni canaglia, non dalla nostra suite di test. Sapevo che qualcosa non andava perché non avevamo ancora avviato la suite di test e stavamo ricevendo gli errori. Abbiamo riparato il server delle applicazioni e non ho visto gli errori tornare. Abbiamo quindi avviato la suite di test e qualche tempo dopo sono tornati gli errori TNS-12519. Hmmm... pensavo di aver trovato il colpevole. Ma controlliamo il nostro utilizzo del processo.
SQL> select resource_name,current_utilization,max_utilization 2 from v$resource_limit where resource_name='processes';
RESOURCE_NAME CURRENT_UTILIZATION MAX_UTILIZATION --------------- ------------------- --------------- processes 89 157
Quindi attualmente vedo 89 processi con un utilizzo massimo di 157. Non sono affatto vicino al mio nuovo limite di 600. Quindi cosa dà? Mi ci è voluto un po' per capire quale fosse il problema. Il nome del servizio è registrato correttamente e non sono affatto vicino al mio limite. MOS NOTE 552765.1 parla di come il Listener arriva all'errore TNS-12519. In precedenza, stavo vedendo la causa più comune. Max PROCESSI è stato raggiunto. Ma non questa volta Allora cosa dà?
Dopo l'indagine, ho trovato la mia risposta nel registro dell'ascoltatore. Ma non era ovvio come un grosso messaggio di errore. La prima occorrenza dell'errore TNS-12519 è stata alle 9:38. Ho cercato "service_update" nel registro del listener e ho visto queste voci.
25-JUN-2015 09:17:08 * service_update * orcl * 0 25-JUN-2015 09:17:26 * service_update * orcl * 0 25-JUN-2015 09:17:29 * service_update * orcl * 0 25-JUN-2015 09:17:44 * service_update * orcl * 0 25-JUN-2015 09:17:50 * service_update * orcl * 0 25-JUN-2015 09:17:53 * service_update * orcl * 0 25-JUN-2015 09:18:56 * service_update * orcl * 0 25-JUN-2015 09:18:59 * service_update * orcl * 0 25-JUN-2015 09:19:50 * service_update * orcl * 0 25-JUN-2015 09:20:11 * service_update * orcl * 0 25-JUN-2015 09:21:27 * service_update * orcl * 0 25-JUN-2015 09:22:09 * service_update * orcl * 0 25-JUN-2015 09:24:05 * service_update * orcl * 0 25-JUN-2015 09:27:53 * service_update * orcl * 0 25-JUN-2015 09:29:32 * service_update * orcl * 0 25-JUN-2015 09:34:07 * service_update * orcl * 0 25-JUN-2015 09:41:45 * service_update * orcl * 0
Si noti che questo aggiornamento del servizio si verifica regolarmente alle 9:17 e alle 9:18, ma l'intervallo di tempo tra gli aggiornamenti del servizio richiede sempre più tempo. Si noti che sono trascorsi 8 minuti e 38 secondi tra gli aggiornamenti del servizio alla fine (dalle 9:34 alle 9:41). Perché è importante?
Questo è un database Oracle 11.2.0.4. Per 11.2 e precedenti, PMON è responsabile della pulizia dopo i processi e del passaggio delle informazioni al Listener. All'avvio del database, PMON tenta di registrare i servizi con Listener. Un'altra cosa che fa PMON è dire all'ascoltatore quanti processi massimi possono essere serviti. In questo caso, PMON dice al listener che può avere fino a 600 processi. PMON fa di più, ma ai fini di questa discussione è sufficiente.
Un pezzo importante da sapere è che l'ascoltatore non sa mai quanti processi sono attualmente connessi. Sa solo quante richieste di connessione ha aiutato il broker. Il Listener non sa mai se i processi si disconnettono dal database. Il service_update sopra è dove PMON dice al Listener quanti processi vengono effettivamente utilizzati. Quindi, alle 9:34:07, l'aggiornamento del servizio PMON indica al listener che sono in uso 145 processi. L'Ascoltatore è ora aggiornato. Quando arriva una nuova richiesta di connessione, il Listener la incrementa a 146 processi. Tra gli aggiornamenti del servizio, il Listener è totalmente ignaro del fatto che uno o più processi potrebbero essere stati terminati, normalmente o in modo anomalo. Continua ad aumentare il conteggio dei processi fino al successivo aggiornamento del servizio, quando il Listener ottiene un resoconto accurato di quanti processi vengono generati.
Quindi abbiamo quel divario di 8,5 minuti tra gli aggiornamenti del servizio. Perché PMON ha impiegato così tanto tempo per tornare all'Ascoltatore? Bene, l'indizio per questo è anche nel listener.log. Ho eliminato tutto dal registro prima dell'aggiornamento del servizio 9:34 e dopo l'aggiornamento del servizio 9:41. Da lì, è stato facile grep per "(CONNECT_DATA=" in ciò che è rimasto e pipe a "wc -l" per ottenere un conteggio delle righe.
Durante questo intervallo di 8,5 minuti, ho ricevuto oltre 450 nuove richieste di connessione! Tuttavia, la maggior parte di queste nuove connessioni è stata interrotta, come evidenziato da V$RESOURCE_LIMIT che mi mostrava un massimo di 150. PMON era così impegnato a ripulire l'applicazione che usciva dalle connessioni del database che ha avuto un grande ritardo prima di aggiornare il Listener. Per quanto riguarda l'Ascoltatore, le 150 connessioni attuali più le 450 nuove hanno fatto raggiungere il limite di 600.
PMON può impiegare fino a 10 minuti per tornare al Listener con il prossimo aggiornamento del servizio. La pulizia dopo l'uscita delle sessioni dall'istanza ha una priorità maggiore rispetto agli aggiornamenti del servizio per il listener. Allo scadere dei 10 minuti, PMON rende l'aggiornamento del servizio la priorità assoluta se l'aggiornamento del servizio non è stato eseguito in precedenza in quell'intervallo di tempo.
Ricorda che questo è un database per supportare i test automatizzati. Dobbiamo convivere con così tante operazioni di connessione/disconnessione perché abbiamo un robot automatizzato che testa la nostra applicazione in modo rapido. Non vogliamo cambiare il modo in cui funziona l'applicazione perché funziona molto bene quando viene eseguita da un singolo utente. La nostra suite di test automatizzata esegue l'applicazione in modo diverso da come è stata progettata. Ma vogliamo esercitare l'applicazione come è scritta per esporre potenzialmente i bug prima che le modifiche al codice raggiungano la produzione.
Per ora, ho aumentato il parametro PROCESSI a un valore che non raggiungeremo mai. Tutto questo in modo che l'Ascoltatore non possa raggiungere il limite nel suo contatore interno. Più PROCESSI, maggiore è la memoria necessaria nell'SGA per supportare quel numero più alto. Ma questo database può gestirlo.
Se qualcuno conosce un modo per far sì che l'aggiornamento del servizio avvenga in una finestra di 5 minuti, per favore fatemelo sapere. Non ci sono parametri documentati per controllare questo comportamento e non sono riuscito a trovarne nemmeno uno non documentato.
Infine, questo problema è in uno dei miei database 11.2.0.4. Oracle 12c cambia un po' l'architettura. Il nuovo processo in background Listener Registration (LREG) gestisce il lavoro svolto da PMON. Non ho ancora un sistema da testare, ma scommetto che LREG non avrà lo stesso problema in 12c che PMON sta esibendo qui in 11g poiché LREG non dovrà gestire i compiti di pulizia che fa PMON. La nota MOS 1592184.1 mostra che LREG eseguirà gli aggiornamenti del servizio.
Aggiornamento:da quando ho scritto questo articolo, ho avuto la possibilità di aggiornare il database a 12c con il suo nuovo processo LREG. Con LREG che gestisce gli aggiornamenti del servizio di Listener, abbiamo visto il problema scomparire. Anche durante i periodi di intensa attività di sessione, in particolare la connessione e la disconnessione, LREG effettuava regolari aggiornamenti del servizio che PMON non sarebbe stato in grado di eseguire con la stessa frequenza.
