アプリケーションでTNS-12519エラーが発生しているという電話がありました。案の定、これらのメッセージはlistener.logファイルにも含まれていました。
TNS-12519: TNS:no appropriate service handler found
このエラーに慣れていない人にとっては、通常、2つのことのいずれかを意味します。サービス名がリスナーに登録されていないか、データベースがプロセスの最大数に達していることを確認してください。後者の場合、リスナーはデータベースが新しいプロセスを受け入れることができないことを知っているため、いわばサービス名がアウトオブサービスになります。簡単な「lsnrctlstatus」は、サービス名が正しく登録されていることを示しています。したがって、後者である必要があります。次に、次のクエリを発行して、疑惑を確認します。
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
案の定。 SPFILEで300と定義されている最大プロセスに達しました。パラメーターを600に増やし、インスタンスをバウンスしました。プロセス数が2倍になると、再びエラーが発生します。私は明らかにこれをさらに掘り下げる必要があります。
いくつかの背景と、後で重要になることについては、このデータベースが自動テストの取り組みをサポートしていることを知っておくことが重要です。主要な実稼働アプリケーションを実行するテストハーネスがあります。このテストスイートは、アプリケーションを起動し、データベースに接続し、いくつかのボタンを押して、いくつかのメニュー項目を選択してから切断します。
私はlistener.logファイルを調べて、接続要求がどこから来ているかを確認しました。これらのリクエストは、テストスイートではなく、不正なアプリケーションサーバーから送信されていました。テストスイートをまだ開始しておらず、エラーが発生していたため、何かがおかしいことがわかりました。アプリケーションサーバーを修正しましたが、エラーが返されませんでした。次に、テストスイートを起動し、しばらくして、TNS-12519エラーが返されました。うーん…犯人を見つけたと思った。ただし、プロセスの使用率を確認しましょう。
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
そのため、現在、最大使用率が157の89のプロセスが表示されています。新しい制限である600にはほど遠いです。では、何が得られるのでしょうか。問題が何であるかを理解するのに少し時間がかかりました。サービス名は正しく登録されており、制限に近づいていません。 MOS NOTE 552765.1は、リスナーがTNS-12519エラーに到達する方法について説明しています。以前、私は最も一般的な原因を見ていました。最大プロセスに達しました。しかし、今回はそうではありません。
調査したところ、リスナーのログに自分の答えが見つかりました。しかし、それはいくつかの大きなエラーメッセージのように明白ではありませんでした。 TNS-12519エラーが最初に発生したのは、午前9時38分でした。リスナーログで「service_update」をgrepして、これらのエントリを確認しました。
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
このサービスの更新は9:17と9:18に定期的に行われますが、サービスの更新間の時間はますます長くなることに注意してください。最後のサービス更新の間に8分38秒があったことに注意してください（9:34から9:41）。なぜこれが重要なのですか？
これはOracle11.2.0.4データベースです。 11.2以前の場合、PMONは、プロセス後のクリーンアップとリスナーへの情報の受け渡しを担当します。データベースの起動時に、PMONはサービスをリスナーに登録しようとします。 PMONが行うもう1つのことは、サービスできる最大プロセスの数をリスナーに通知することです。この場合、PMONは、最大600のプロセスを持つことができることをリスナーに通知します。 PMONはさらに多くのことを行いますが、この説明ではそれで十分です。
知っておくべき重要な点の1つは、リスナーは現在接続されているプロセスの数を決して知らないということです。ブローカーを支援した接続要求の数だけを知っています。リスナーは、プロセスがデータベースから切断されているかどうかを知ることはありません。上記のservice_updateは、PMONがリスナーに実際に使用されているプロセスの数を通知する場所です。したがって、9：34：07に、PMONサービスの更新により、145のプロセスが使用中であることがリスナーに通知されます。これで、リスナーは最新になりました。新しい接続要求が着信すると、リスナーはこれを146プロセスにインクリメントします。サービスの更新の合間に、リスナーは1つ以上のプロセスが正常または異常に終了した可能性があることをまったく認識していません。リスナーが生成されたプロセスの数を正確に把握した次のサービス更新まで、プロセス数を増やし続けます。
したがって、サービスの更新の間に8.5分のギャップがあります。 PMONがリスナーに戻るのになぜそんなに時間がかかったのですか？その手がかりはlistener.logにもあります。 9:34 service_updateの前と9:41サービスの更新後に、ログからすべてを削除しました。そこから、残っているものの「（CONNECT_DATA =」をgrepし、「wc -l」にパイプして、行数を取得するのは簡単でした。
この8.5分の間隔の間に、450をはるかに超える新しい接続要求がありました。それでも、V $ RESOURCE_LIMITが示すように、これらの新しい接続のほとんどは、最大150個あることを示して終了しました。PMONは、データベース接続を終了するアプリケーションのクリーンアップに非常に忙しく、リスナーを更新する前に大きな遅延がありました。リスナーに関する限り、150の現在の接続と450の新しい接続は、リスナーが600の制限に達したことを意味します。
PMONは、次のサービス更新でリスナーに戻るまでに最大10分かかる場合があります。セッション終了後のクリーンアップは、リスナーへのサービス更新よりも優先されます。 10分の時点で、サービスの更新がその時間間隔内に以前に行われていなかった場合、PMONはサービスの更新を最優先にします。
これは自動テストをサポートするデータベースであることを忘れないでください。自動化されたロボットがアプリケーションを迅速にテストしているため、これほど多くの接続/切断操作を実行する必要があります。アプリケーションは1人のユーザーが実行すると非常にうまく機能するため、アプリケーションの動作を変更したくありません。自動テストスイートは、設計されたものとは異なる方法でアプリケーションを実行しています。ただし、コードの変更が本番環境に到達する前にバグを明らかにする可能性があるように、アプリケーションを記述どおりに実行したいと考えています。
今のところ、PROCESSESパラメーターを決して到達できない値に増やしました。これはすべて、リスナーが内部カウンターの制限に達することができないようにするためです。プロセスが多いほど、その高い数をサポートするためにSGAで必要なメモリが多くなります。しかし、このデータベースはそれを処理できます。
5分のウィンドウでサービスの更新を実行する方法を誰かが知っている場合は、私に知らせてください。この動作を制御するための文書化されたパラメータはなく、文書化されていないパラメータも見つけることができませんでした。
最後に、この問題は私の11.2.0.4データベースの1つにあります。 Oracle 12cは、アーキテクチャを少し変更します。新しいリスナー登録（LREG）バックグラウンドプロセスは、PMONが行っていた作業を処理します。私はまだテストするシステムを持っていませんが、LREGはPMONが行うクリーンアップ作業を処理する必要がないため、PMONが11gでここに展示しているのと同じ問題が12cで発生することはないと思います。 MOSノート1592184.1は、LREGがサービスの更新を行うことを示しています。
更新：この記事を書いたので、新しいLREGプロセスを使用してデータベースを12cにアップグレードする機会がありました。 LREGがリスナーのサービス更新を処理することで、問題が解消されることがわかりました。特に接続と切断などのセッションアクティビティが激しいときでも、LREGは定期的にサービスを更新し、PMONではそれほど頻繁に実行できなかったでしょう。