Jeg fik et opkald fra nogen om, at de fik TNS-12519-fejl i deres applikation. Sikkert nok var disse beskeder også i listener.log-filen.
TNS-12519: TNS:no appropriate service handler found
For dem, der ikke er bekendt med denne fejl, betyder det typisk en af to ting. Enten er tjenestenavnet ikke registreret hos lytteren, eller at databasen har nået sit maksimale antal processer. For sidstnævnte sker det, at lytteren ved, at databasen ikke kan acceptere nye processer, så den tager tjenestenavnet ud af drift så at sige. En hurtig "lsnrctl status" viser mig, at tjenestenavnet er registreret korrekt. Så det må være det sidste. Jeg sender derefter følgende forespørgsel og bekræfter mine mistanker.
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
Helt sikkert. Jeg har nået max processer, som er defineret i min SPFILE til at være 300. Jeg øgede parameteren til 600 og afviste instansen. Vi ramte fejlen igen med det dobbelte antal processer. Det er jeg åbenbart nødt til at grave nærmere i.
For en vis baggrund, og for noget, der vil være vigtigt senere, er det vigtigt at vide, at denne database understøtter vores automatiserede testindsats. Vi har en testsele, der træner vores primære produktionsapplikation. Denne testsuite starter applikationen, opretter forbindelse til databasen, trykker på et par knapper og vælger nogle få menupunkter og afbryder derefter forbindelsen.
Jeg undersøgte listener.log-filen for at se, hvor forbindelsesanmodningerne kom fra. Disse anmodninger kom fra en useriøs applikationsserver, ikke vores testpakke. Jeg vidste, at der var noget galt, fordi vi endnu ikke havde startet testpakken, og vi fik fejlene. Vi rettede applikationsserveren, og jeg så ikke fejlene tilbage. Vi startede derefter testpakken, og noget tid senere vendte TNS-12519 fejlene tilbage. Hmmm...jeg troede, jeg fandt den skyldige. Men lad os tjekke vores procesudnyttelse.
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
Så jeg ser i øjeblikket 89 processer med en maksimal udnyttelse på 157. Jeg er ikke i nærheden af min nye grænse på 600. Så hvad giver det? Det tog mig et stykke tid at finde ud af, hvad problemet var. Tjenestenavnet er korrekt registreret, og jeg er ikke i nærheden af min grænse. MOS NOTE 552765.1 taler om, hvordan lytteren kommer frem til TNS-12519 fejlen. Tidligere så jeg den mest almindelige årsag. Max PROCESSER var nået. Men ikke denne gang Så hvad giver?
Efter undersøgelse fandt jeg mit svar i lytterens log. Men det var ikke indlysende som en stor fejlmeddelelse. Den første forekomst af TNS-12519-fejlen var kl. 9:38. Jeg grep efter "service_update" i lytterloggen og så disse poster.
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
Bemærk, at denne serviceopdatering sker regelmæssigt kl. 9:17 og 9:18, men tiden mellem tjenesteopdateringerne tager længere og længere tid. Bemærk, at der var 8 minutter og 38 sekunder mellem tjenesteopdateringerne ved slutningen (9:34 til 9:41). Hvorfor er dette vigtigt?
Dette er en Oracle 11.2.0.4-database. For 11.2 og tidligere er PMON ansvarlig for at rydde op efter processer og for at videregive information til Lytteren. Ved opstart af databasen forsøger PMON at registrere tjenesterne hos Listener. En anden ting, PMON gør, er at fortælle lytteren, hvor mange maks. processer der kan serviceres. I dette tilfælde fortæller PMON lytteren, at den kan have op til 600 processer. PMON gør mere, men for denne diskussions formål er det nok.
En vigtig ting at vide er, at lytteren aldrig ved, hvor mange processer der i øjeblikket er forbundet. Den ved kun, hvor mange forbindelsesanmodninger den har hjulpet mægleren. Lytteren ved aldrig, om processer kobler fra databasen. Service_update ovenfor er der, hvor PMON fortæller lytteren, hvor mange processer der rent faktisk bliver brugt. Så klokken 9:34:07 fortæller PMON-serviceopdateringen til lytteren, at der er 145 processer i brug. The Listener er nu opdateret. Når der kommer en ny forbindelsesanmodning, øger lytteren dette til 146 processer. Mellem tjenesteopdateringerne er Lytteren fuldstændig uvidende om, at 1 eller flere processer kan være blevet afsluttet, normalt eller unormalt. Det bliver ved med at øge antallet af processer indtil næste serviceopdatering, når lytteren får en nøjagtig oversigt over, hvor mange processer der er afledt.
Så vi har det 8,5 minutters mellemrum mellem serviceopdateringer. Hvorfor tog det PMON så lang tid at komme tilbage til lytteren? Nå, ledetråden til det er også i listener.log. Jeg fjernede alt fra loggen før 9:34 service_update og efter 9:41 serviceopdateringen. Derfra var det nemt at grep for "(CONNECT_DATA=" i det tilbageværende og pipe til "wc -l" for at få et antal linjer.
I løbet af dette 8,5 minutters interval havde jeg langt over 450 nye forbindelsesanmodninger! Alligevel blev de fleste af disse nye forbindelser afsluttet, som det fremgår af V$RESOURCE_LIMIT, der viste mig, at jeg havde et maks. 150. PMON havde så travlt med at rydde op for applikationen, der forlod sine databaseforbindelser, at den havde en stor forsinkelse, før den opdaterede Listener. For Lytterens vedkommende betød de 150 nuværende forbindelser plus de 450 nye forbindelser, at den nåede sin grænse på 600.
Det kan tage op til 10 minutter for PMON at komme tilbage til lytteren med sin næste serviceopdatering. Oprydning efter sessioner afslutter forekomsten har en højere prioritet end serviceopdateringer til lytteren. Ved 10 minutters mærket gør PMON tjenesteopdateringen til topprioriteten, hvis serviceopdateringen ikke tidligere var blevet udført i det tidsinterval.
Husk, at dette er en database, der understøtter automatiseret test. Vi er nødt til at leve med så mange tilslutnings-/afbrydelsesoperationer, fordi vi har en automatiseret robot, der tester vores applikation på en hurtig måde. Vi ønsker ikke at ændre, hvordan applikationen fungerer, fordi den fungerer meget godt, når den køres af en enkelt bruger. Vores automatiserede testpakke udfører applikationen anderledes, end den er designet til at gøre. Men vi ønsker at bruge applikationen, som den er skrevet for potentielt at afsløre fejl, før kodeændringerne rammer produktionen.
For nu har jeg øget parameteren PROCESSES til en værdi, som vi aldrig når. Alt dette for at lytteren ikke kan ramme grænsen i sin interne tæller. Jo flere PROCESSER, jo mere hukommelse kræves der i SGA'en for at understøtte det højere tal. Men denne database kan klare det.
Hvis nogen kender til en måde at få serviceopdateringen til at ske inden for et 5-minutters vindue, så lad mig det vide. Der er ingen dokumenterede parametre til at kontrollere denne adfærd, og jeg har heller ikke kunnet finde en udokumenteret.
Til sidst er dette problem i en af mine 11.2.0.4-databaser. Oracle 12c ændrer arkitekturen lidt. Den nye Listener Registration (LREG) baggrundsproces håndterer det arbejde, som PMON plejede at udføre. Jeg har endnu ikke et system at teste, men jeg vil vædde på, at LREG ikke vil have det samme problem i 12c, som PMON udstiller her i 11g, da LREG ikke skal håndtere oprydningsopgaver, som PMON gør. MOS Note 1592184.1 viser, at LREG vil udføre serviceopdateringerne.
Opdatering:Siden jeg skrev denne artikel, har jeg haft en chance for at opgradere databasen til 12c med dens nye LREG-proces. Da LREG håndterede lytterens tjenesteopdateringer, så vi problemet forsvinde. Selv i tider med tung sessionsaktivitet, specifikt tilslutning og frakobling, lavede LREG regelmæssige serviceopdateringer, som PMON ikke ville have været i stand til at udføre så ofte.