Jag fick ett samtal från någon att de fick TNS-12519-fel i sin ansökan. Visst, de meddelandena fanns också i listener.log-filen.
TNS-12519: TNS:no appropriate service handler found
För dem som inte är bekanta med det här felet betyder det vanligtvis en av två saker. Antingen är tjänstens namn inte registrerat hos lyssnaren eller så har databasen nått sitt maximala antal processer. För den senare, vad som händer är att Lyssnaren vet att databasen inte kan acceptera några nya processer så den tar tjänstnamnet ur drift så att säga. En snabb "lsnrctl status" visar mig att tjänstens namn är korrekt registrerat. Så det måste vara det senare. Jag skickar sedan följande fråga och bekräftar mina misstankar.
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
Säker nog. Jag har nått maxprocesser, vilket är definierat i min SPFILE till 300. Jag ökade parametern till 600 och studsade instansen. Vi träffade felet igen med dubbla antalet processer. Jag måste uppenbarligen gräva vidare i det här.
För en viss bakgrund, och för något som kommer att vara viktigt senare, är det viktigt att veta att denna databas stöder våra automatiserade testansträngningar. Vi har en testsele som utövar vår primära produktionsapplikation. Denna testsvit startar applikationen, ansluter till databasen, trycker på några knappar och väljer några menyalternativ och kopplar sedan från.
Jag undersökte filen listener.log för att se var anslutningsförfrågningarna kom ifrån. Dessa förfrågningar kom från en oseriös applikationsserver, inte vår testsvit. Jag visste att något var fel eftersom vi ännu inte hade startat testsviten och vi fick felen. Vi fixade applikationsservern och jag såg inte att felen kom tillbaka. Vi startade sedan upp testsviten och en tid senare kom TNS-12519-felen tillbaka. Hmmm...jag trodde jag hittade den skyldige. Men låt oss kontrollera vår processanvändning.
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å jag ser för närvarande 89 processer med ett maximalt utnyttjande på 157. Jag är inte i närheten av min nya gräns på 600. Så vad ger? Det tog mig ett tag att ta reda på vad problemet var. Tjänstens namn är korrekt registrerat och jag är inte i närheten av min gräns. MOS NOTE 552765.1 talar om hur lyssnaren kommer fram till TNS-12519-felet. Tidigare såg jag den vanligaste orsaken. Max PROCESSER hade uppnåtts. Men inte den här gången Så vad ger?
Efter undersökning hittade jag mitt svar i lyssnarens logg. Men det var inte uppenbart som något stort felmeddelande. Den första förekomsten av TNS-12519-felet var klockan 9:38. Jag sökte efter "service_update" i lyssnarloggen och såg dessa 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
Observera att denna tjänstuppdatering sker regelbundet kl. 9:17 och 9:18, men tiden mellan tjänstuppdateringarna tar längre och längre tid. Lägg märke till att det gick 8 minuter och 38 sekunder mellan tjänstuppdateringarna i slutet (9:34 till 9:41). Varför är detta viktigt?
Detta är en Oracle 11.2.0.4-databas. För 11.2 och tidigare ansvarar PMON för att städa upp efter processer och för att förmedla information till Lyssnaren. Vid uppstart av databasen försöker PMON registrera tjänsterna hos Listener. En annan sak som PMON gör är att tala om för lyssnaren hur många maxprocesser som kan betjänas. I det här fallet berättar PMON för lyssnaren att den kan ha upp till 600 processer. PMON gör mer, men för denna diskussions syfte är det tillräckligt.
En viktig del att veta är att Lyssnaren aldrig vet hur många processer som för närvarande är anslutna. Den vet bara hur många anslutningsförfrågningar den har hjälpt mäklaren. Lyssnaren vet aldrig om processer kopplar bort från databasen. Service_update ovan är där PMON talar om för lyssnaren hur många processer som faktiskt används. Så klockan 9:34:07 berättar PMON-tjänstens uppdatering för lyssnaren att det finns 145 processer som används. Lyssnaren är nu uppdaterad. När en ny anslutningsbegäran kommer in, ökar lyssnaren detta till 146 processer. Mellan tjänsteuppdateringarna är lyssnaren helt omedveten om att en eller flera processer kan ha avslutats, normalt eller onormalt. Den fortsätter att öka antalet processer tills nästa tjänstuppdatering när Lyssnaren får en korrekt redovisning av hur många processer som skapas.
Så vi har 8,5 minuters mellanrum mellan tjänstuppdateringar. Varför tog det PMON så lång tid att komma tillbaka till Lyssnaren? Ledtråden till det finns också i listener.log. Jag tog bort allt från loggen före 9:34 service_update och efter 9:41 serviceuppdateringen. Därifrån var det lätt att grepa för "(CONNECT_DATA=" i det som återstod och skicka till "wc -l" för att få ett antal rader.
Under detta 8,5 minuters intervall hade jag över 450 nya anslutningsförfrågningar! Ändå avslutades de flesta av dessa nya anslutningar, vilket framgår av V$RESOURCE_LIMIT som visade mig att jag hade ett maxvärde på 150. PMON var så upptagen med att städa upp för applikationen som lämnade sina databasanslutningar att den hade en stor fördröjning innan den uppdaterade Listener. När det gäller Lyssnaren innebar de 150 nuvarande anslutningarna plus de 450 nya anslutningarna att den nådde sin gräns på 600.
Det kan ta upp till 10 minuter för PMON att komma tillbaka till Listener med nästa tjänstuppdatering. Att städa upp efter att sessioner har avslutat instansen har högre prioritet än tjänstuppdateringar till Listener. Vid 10-minutersstrecket gör PMON tjänsteuppdateringen till högsta prioritet om tjänsteuppdateringen inte hade gjorts tidigare under det tidsintervallet.
Kom ihåg att detta är en databas som stödjer automatisk testning. Vi måste leva med så många anslutnings-/frånkopplingsoperationer eftersom vi har en automatiserad robot som testar vår applikation på ett snabbt sätt. Vi vill inte ändra hur applikationen fungerar eftersom den fungerar väldigt bra när den körs av en enda användare. Vår automatiserade testsvit kör applikationen annorlunda än vad den var designad för att göra. Men vi vill använda applikationen som den är skriven för att potentiellt avslöja buggar innan kodändringarna når produktionen.
För närvarande har jag ökat parametern PROCESSES till ett värde som vi aldrig kommer att nå. Allt detta för att Lyssnaren inte ska kunna nå gränsen i sin interna räknare. Ju fler PROCESSER, desto mer minne behövs i SGA för att stödja det högre antalet. Men den här databasen kan hantera det.
Om någon vet om ett sätt att få tjänsten uppdatering att ske inom ett 5 minuters fönster, vänligen meddela mig. Det finns inga dokumenterade parametrar för att kontrollera detta beteende och jag har inte heller kunnat hitta en odokumenterad.
Slutligen finns det här problemet i en av mina 11.2.0.4-databaser. Oracle 12c ändrar arkitekturen lite. Den nya bakgrundsprocessen för Listener Registration (LREG) hanterar det arbete som PMON brukade göra. Jag har inte ett system att testa ännu, men jag slår vad om att LREG inte kommer att ha samma problem i 12c som PMON visar här i 11g eftersom LREG inte kommer att behöva hantera saneringsuppgifter som PMON gör. MOS Note 1592184.1 visar att LREG kommer att göra tjänsteuppdateringarna.
Uppdatering:Sedan jag skrev den här artikeln har jag haft en chans att uppgradera databasen till 12c med dess nya LREG-process. När LREG hanterade Lyssnarens tjänstuppdateringar såg vi problemet försvinna. Även under tider av tung sessionsaktivitet, särskilt när man kopplar och kopplar från, gjorde LREG regelbundna tjänstuppdateringar som PMON inte skulle ha kunnat utföra så ofta.