Oracle Databaseのリスナーログ、接続障害発生時にどこを見るか：Oracleサポート出張所（5）

本連載は、「Oracle Database」で発生するトラブルをどう解決すればよいのか、データベースの運用管理において、より円滑に業務を進めるために必要なノウハウを紹介します。今回は「リスナーログの出力内容や接続障害発生時の着目ポイント」について、接続成功例と接続失敗例を用いて解説します。

[小島朋之，株式会社アシスト]

連載バックナンバー

　本連載「Oracleサポート出張所」は、「Oracle Database」で発生するトラブルを「どんな方法で」「どのように」解決していくか。長年、筆者がOracle Databaseのサポート業務で培ってきた経験を基に、Oracle Databaseの運用管理をする上で「より円滑に、かつ成長を見据えて業務を推進していく」ために必要なノウハウを紹介します。

　前回は、エラーが発生したときに出力されるログファイル「トレースファイルとインシデントファイルの内容」を解説しました。今回は、リスナーログ（リスナーログファイル）を扱います。リスナーログはクライアントからリスナーを経由させてデータベースに接続した場合に出力されるログです。このリスナーログの出力内容や接続障害発生時の着目ポイントを解説します。

　リスナーログに出力される内容は、データベースに接続要求したクライアントの端末情報や成功可否、接続障害時のエラー内容、リスナー制御ユーティリティー（lsnrctl）による操作結果です。

リスナーログの出力先

　リスナーログの出力先は、Oracle Databaseのバージョンによって異なります（連載第1回を参照）。

バージョン	形式		出力先
10gR2以前	テキスト	ORACLE_HOME/network/log
11gR1以降	テキスト	ADR_BASE/diag/tnslsnr/<hostname>/<listenername>/trace/
11gR1以降	xml		ADR_BASE/diag/tnslsnr/<hostname>/<listenername>/alert/

　11gR2以降でOracle Real Application Clusters（RAC）環境を利用している場合、リスナーログの出力先は、Grid_HomeまたはGrid_Base以下になります。

SCANリスナー	バージョン	出力先
あり		~12.1.0.1	Grid_Home/log/diag/tnslsnr/<hostname>/<listenername>
あり		12.1.0.2~	Grid_Base/diag/tnslsnr/<hostname>/<scan listenername>
なし		全て		Grid_Base/diag/tnslsnr/<hostname>/<listenername>/

リスナーログの出力形式

　リスナーログの出力形式は以下の通りです。

Timestamp * Connect Data [* Protocol Info] * Event [*SID | Service] * Return Code

項目名	内容
Timestamp	リスナーに対する処理が実行された日時
Connect Data	接続を要求したクライアントの情報、ローカル接続時はサーバの情報
Event	リスナーに対する処理内容や接続を試みた結果
Return Code	接続成功時：0、接続失敗時：エラーコード

　リスナーログはリスナーへの接続要求ごとに1行ずつ出力されます。そのため、行数を数えると、接続要求の数を算出できます。例えばデータベースのパフォーマンスダウンが発生した場合には、該当時間帯の接続要求数が多いかどうかを確認することで問題の特定が容易になります。

　次のログは、クライアントから接続が成功した際のリスナーログの出力例です。

17-JUL-2017 14:39:07
* (CONNECT_DATA=(SERVER=DEDICATED)( SERVICE_NAME=v12102)
(CID=(PROGRAM=C:\oracle\v121\product\12.1.0\dbhome_1\BIN\sqlplus.exe)
(HOST=TEST01)(USER=test)))
* (ADDRESS=(PROTOCOL=tcp) (HOST=192.168.1.123)(PORT=53576))
* establish * v12102 * 0

接続が成功したときの出力例

　この出力例の場合、ホスト名TEST01（IPアドレス192.168.1.123）のクライアントから、SQL*Plusを用いた接続が成功していることを表しています。また、「SERVER=DEDICATED」は、この接続が「専用サーバ接続」であることを意味しています。

接続障害発生時の着目ポイント

　接続障害が発生した際にリスナーログのどの部分に着目すべきなのか、図1を参考に見ていきましょう。

図1　リスナーログの注目箇所を見つける手法

　まず、接続障害が発生した時間帯の出力がリスナーログにあるかどうかを確認します。出力があった場合、「TNSエラー」の内容から問題の原因調査やエラーを受けたデータベース、クライアントの端末情報を確認できます。

　次のログは、接続が失敗したときのリスナーログの出力例です。図1の内容と照らし合わせながら確認しましょう。

19-JUL-2017 15:10:02
* (CONNECT_DATA=(SERVER=DEDICATED)(SERVICE_NAME=v12102)
(CID=(PROGRAM=C:\oracle\v121\product\12.1.0\dbhome_1\bin\sqlplus.exe)
(HOST=TEST01)(USER=test)))
* (ADDRESS=(PROTOCOL=tcp)(HOST=192.168.1.123)(PORT=54095))
* establish * v12102 * 12528
TNS-12528: TNS:listener: all appropriate instances are blocking new connections

接続が失敗したときの出力例

　この出力例では、TEST01（IPアドレス192.168.1.123）のクライアントからSQL*Plusを用いた接続が、TNS-12528で失敗していることが確認できます。TNS-12528は、「接続先のデータベースが停止しているために接続が失敗した」ことを表します。このエラーの場合、データベースが起動しているかどうかを調べ、起動していなければその原因をアラートログから確認して対処する必要があります。

　接続時にエラーが発生した場合には、リスナーログやクライアント側に返されたエラー内容、データベースのアラートログに出力された内容から問題を解消する必要があります。

　リスナーログに先ほどの例のような出力が見当たらない場合、クライアントからの接続要求がリスナーに到達していません。クライアント側の接続情報の見直しやクライアントとサーバ間のネットワークに問題がないかどうかを調査しましょう。

　なお、JDBC（Java DataBase Connectivity）やODP.NET（Oracle Data Provider for .NET）など、コネクションプーリングの機能を利用している場合、事前に接続を確立したサーバプロセスを利用するため、必ずしもアプリケーション経由のログイン時間とlistener.logに出力された時間が一致しないケースがあります。

　今回解説したリスナーログの見方を把握しておくことで、障害発生時の影響範囲の特定を迅速にでき、対応策の検討や実施に時間を回すことが可能になります。

　なお、リスナーログは接続要求があるたびに出力され、肥大化しやすいログファイルです。障害を未然に防ぐという観点からも定期的なメンテナンスを実施することもお勧めします。

　今回は、「リスナーログ」を紹介しました。次回は、「データファイル（永続表領域）の監視と管理リスナーログ」について解説する予定です。

筆者紹介

小島朋之（こじまともゆき）

株式会社アシスト サービス事業部 サポートセンター。2005年アシスト入社。2012年からOracle DatabaseやReal Application Clustersなどの高可用性製品を中心としたお客様対応のバックサポートを行っている。