日別アーカイブ: 2015/07/12

インスタンスのリスナーへの登録（その２）

今週の名言

「今日できることを明日にまで延ばすな｡」
フィリップ・ チェスターフィールド

前回のおさらい（Oracle 11gR2）

  1. リスナーにインスタンスがサービスとして登録されて初めて、インスタンス（データベース）に対するネット接続が可能となります。
  2. リスナーを後から起動すると、インスタンスが登録するまでにある程度の時間がかかります。（PMONが定期的にリスナーに登録しにいくので最長60秒程度かかる場合があります。）
  3. リスナーを先に起動しておくと、インスタンスは起動直後にリスナーに登録されます。
  4. 2.の場合でも「ALTER SYSTEM REGISTER」コマンドを実行すると、インスタンスを即時にリスナーへ登録することができます。

前回は、インスタンスのリスナーへの登録に関する挙動についてOracle11gR2で確認をしてみましたが、Oracle12cR1で同様の検証をしてみます。

サービス登録の動作を確認する（12cR1）

1. インスタンスを先に起動し、リスナーを後から起動する。

インスタンスを起動する

xx:xx:xx SQL> startup
ORACLEインスタンスが起動しました。

Total System Global Area  838860800 bytes
Fixed Size                  2929936 bytes
Variable Size             608176880 bytes
Database Buffers          222298112 bytes
Redo Buffers                5455872 bytes
データベースがマウントされました。
データベースがオープンされました。
14:37:15 SQL>

アラートログ

2015-07-05 14:37:15.408000 +09:00
Starting background process CJQ0
Completed: ALTER DATABASE OPEN
CJQ0 started with pid=31, OS id=3721

14:37:15 にインスタンス（データベース）が起動されました。

（正確には、インスタンスとはプロセス群とメモリから成るため、メモリ情報が表示された時がインスタンスの起動時刻となりますが、ここではインスタンス＝データベースの意味で使っていますので、データベースがオープンされた時刻をインスタンス起動と言っています。

このタイミングで tnsping と接続の確認を行ってみます。

[xx:xx:xx] $ tnsping ora12c

TNS Ping Utility for Linux: Version 12.1.0.2.0 - Production on 05-7月 -2015 14:38:16

Copyright (c) 1997, 2014, Oracle.  All rights reserved.

パラメータ・ファイルを使用しました:
/u01/app/oracle/product/12.1.0.2/db_1/network/admin/sqlnet.ora

エイリアスを解決するためにTNSNAMESアダプタを使用しました。
(DESCRIPTION = (ADDRESS = (PROTOCOL = TCP)(HOST = oraclelinux6.onefact.jp)(PORT = 1521)) (CONNECT_DATA = (SERVER = DEDICATED) (SERVICE_NAME = ora12c)))に接続の試行中
TNS-12541: TNS: リスナーがありません。
[14:38:16] $ 

[xx:xx:xx] $ sqlplus /nolog

SQL*Plus: Release 12.1.0.2.0 Production on 日 7月 5 14:39:24 2015

Copyright (c) 1982, 2014, Oracle.  All rights reserved.

xx:xx:xx SQL> conn scott/tiger@ora12c
ERROR:
ORA-12541: TNS: リスナーがありません

14:39:33 SQL>

リスナーが起動していないので、tnspingも接続も失敗します。
14:39:33 にネット接続を試みましたが、成功しませんでした。

リスナーを起動する

インスタンスの次にリスナーを起動します。

[xx:xx:xx] $ lsnrctl start

LSNRCTL for Linux: Version 12.1.0.2.0 - Production on 05-7月 -2015 14:40:54

Copyright (c) 1991, 2014, Oracle.  All rights reserved.

/u01/app/oracle/product/12.1.0.2/db_1/bin/tnslsnrを起動しています。お待ちください...

TNSLSNR for Linux: Version 12.1.0.2.0 - Production
システム・パラメータ・ファイルは/u01/app/oracle/product/12.1.0.2/db_1/network/admin/listener.oraです。
ログ・メッセージを/u01/app/oracle/diag/tnslsnr/oraclelinux6/listener/alert/log.xmlに書き込みました。
リスニングしています: (DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=oraclelinux6.onefact.jp)(PORT=1521)))
リスニングしています: (DESCRIPTION=(ADDRESS=(PROTOCOL=ipc)(KEY=EXTPROC1521)))

(DESCRIPTION=(ADDRESS=(PROTOCOL=TCP)(HOST=oraclelinux6.onefact.jp)(PORT=1521)))に接続中
リスナーのステータス
------------------------
別名                      LISTENER
バージョン                TNSLSNR for Linux: Version 12.1.0.2.0 - Production
開始日                    05-7月 -2015 14:40:54
稼働時間                  0 日 0 時間 0 分 0 秒
トレース・レベル          off
セキュリティ              ON: Local OS Authentication
SNMP                      OFF
パラメータ・ファイル      /u01/app/oracle/product/12.1.0.2/db_1/network/admin/listener.ora
ログ・ファイル            /u01/app/oracle/diag/tnslsnr/oraclelinux6/listener/alert/log.xml
リスニング・エンドポイントのサマリー...
  (DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=oraclelinux6.onefact.jp)(PORT=1521)))
  (DESCRIPTION=(ADDRESS=(PROTOCOL=ipc)(KEY=EXTPROC1521)))
リスナーはサービスをサポートしていません。
コマンドは正常に終了しました。
[14:40:54] $

14:40:54 にリスナーが起動しました。

リスナー起動直後に別コンソールからネット接続を試みます。

xx:xx:xx SQL> conn scott/tiger@ora12c
ERROR:
ORA-12514: TNS:
リスナーは接続記述子でリクエストされたサービスを現在認識していません

14:40:57 SQL> conn scott/tiger@ora12c
ERROR:
ORA-12514: TNS:
リスナーは接続記述子でリクエストされたサービスを現在認識していません

14:41:06 SQL> conn scott/tiger@ora12c
接続されました。
14:41:17 SQL>

14:40:57 と 14:41:06 にネット接続の試みは失敗し、14:41:17 に成功しました。
リスナー起動から23秒後に接続を確認できました。

リスナーログ

05-7月 -2015 14:40:57 * (CONNECT_DATA=(SERVER=DEDICATED)(SERVICE_NAME=ora12c)(CID=(PROGRAM=sqlplus)(HOST=oraclelinux6.onefact.jp)(USER=ora12c))) * (ADDRESS=(PROTOCOL=tcp)(HOST=192.168.11.18)(PORT=24694)) * establish * ora12c * 12514
TNS-12514: TNS: リスナーは現在、接続識別子でリクエストされているサービスを認識していません
2015-07-05 14:41:06.873000 +09:00
05-7月 -2015 14:41:06 * (CONNECT_DATA=(SERVER=DEDICATED)(SERVICE_NAME=ora12c)(CID=(PROGRAM=sqlplus)(HOST=oraclelinux6.onefact.jp)(USER=ora12c))) * (ADDRESS=(PROTOCOL=tcp)(HOST=192.168.11.18)(PORT=24713)) * establish * ora12c * 12514
TNS-12514: TNS: リスナーは現在、接続識別子でリクエストされているサービスを認識していません
2015-07-05 14:41:09.718000 +09:00
リスニングしています: (DESCRIPTION=(ADDRESS=(PROTOCOL=tcps)(HOST=oraclelinux6.onefact.jp)(PORT=5500))(Security=(my_wallet_directory=/u01/app/oracle/admin/ora12c/xdb_wallet))(Presentation=HTTP)(Session=RAW))
Dynamic address is already listened on (DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=oraclelinux6.onefact.jp)(PORT=1521)))
05-7月 -2015 14:41:09 * service_register * ora12c * 0
2015-07-05 14:41:17.722000 +09:00
05-7月 -2015 14:41:17 * (CONNECT_DATA=(SERVER=DEDICATED)(SERVICE_NAME=ora12c)(CID=(PROGRAM=sqlplus)(HOST=oraclelinux6.onefact.jp)(USER=ora12c))) * (ADDRESS=(PROTOCOL=tcp)(HOST=192.168.11.18)(PORT=24735)) * establish * ora12c * 0
05-7月 -2015 14:41:18 * service_update * ora12c * 0

リスナーログから、正確には 14:41:09 に「service_register」確認できていますので、リスナー起動後 15秒でインスタンスが登録されたことがわかります。

2. リスナーを先に起動し、インスタンスを後から起動する

リスナーがすでに起動されている状態から、インスタンスを起動します。

xx:xx:xx SQL> startup
ORACLEインスタンスが起動しました。

Total System Global Area  838860800 bytes
Fixed Size                  2929936 bytes
Variable Size             608176880 bytes
Database Buffers          222298112 bytes
Redo Buffers                5455872 bytes
データベースがマウントされました。
データベースがオープンされました。
14:47:10 SQL>

14:47:10 にインスタンスが起動しました。

別コンソールから、インスタンス起動前と起動後にネット接続を試みます。

xx:xx:xx SQL> conn scott/tiger@ora12c
ERROR:
ORA-12514: TNS:
リスナーは接続記述子でリクエストされたサービスを現在認識していません

14:47:03 SQL> conn scott/tiger@ora12c
接続されました。
14:47:13 SQL>

14:47:03 に接続失敗していますが、14:47:13 には成功しています。

2015-07-05 14:46:19.450000 +09:00
05-7月 -2015 14:46:19 * (CONNECT_DATA=(SERVER=DEDICATED)(SERVICE_NAME=ora12c)(CID=(PROGRAM=sqlplus)(HOST=oraclelinux6.onefact.jp)(USER=ora12c))) * (ADDRESS=(PROTOCOL=tcp)(HOST=192.168.11.18)(PORT=24780)) * establish * ora12c * 12514
TNS-12514: TNS: リスナーは現在、接続識別子でリクエストされているサービスを認識していません
2015-07-05 14:47:03.841000 +09:00
05-7月 -2015 14:47:03 * (CONNECT_DATA=(SERVER=DEDICATED)(SERVICE_NAME=ora12c)(CID=(PROGRAM=sqlplus)(HOST=oraclelinux6.onefact.jp)(USER=ora12c))) * (ADDRESS=(PROTOCOL=tcp)(HOST=192.168.11.18)(PORT=24783)) * establish * ora12c * 12514
TNS-12514: TNS: リスナーは現在、接続識別子でリクエストされているサービスを認識していません
Dynamic address is already listened on (DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=oraclelinux6.onefact.jp)(PORT=1521)))
05-7月 -2015 14:47:04 * service_register * ora12c * 0
2015-07-05 14:47:07.074000 +09:00
05-7月 -2015 14:47:07 * service_update * ora12c * 0
2015-07-05 14:47:08.779000 +09:00
05-7月 -2015 14:47:08 * service_update * ora12c * 0
2015-07-05 14:47:10.028000 +09:00
リスニングしています: (DESCRIPTION=(ADDRESS=(PROTOCOL=tcps)(HOST=oraclelinux6.onefact.jp)(PORT=5500))(Security=(my_wallet_directory=/u01/app/oracle/admin/ora12c/xdb_wallet))(Presentation=HTTP)(Session=RAW))
05-7月 -2015 14:47:10 * service_update * ora12c * 0
05-7月 -2015 14:47:10 * service_update * ora12c * 0
05-7月 -2015 14:47:10 * (CONNECT_DATA=(SERVER=DEDICATED)(SERVICE_NAME=ora12c)(CID=(PROGRAM=sqlplus)(HOST=oraclelinux6.onefact.jp)(USER=ora12c))) * (ADDRESS=(PROTOCOL=tcp)(HOST=192.168.11.18)(PORT=24787)) * establish * ora12c * 0
2015-07-05 14:47:13.033000 +09:00
05-7月 -2015 14:47:13 * service_update * ora12c * 0
2015-07-05 14:47:16.037000 +09:00
05-7月 -2015 14:47:16 * service_update * ora12c * 0
2015-07-05 14:47:46.056000 +09:00
05-7月 -2015 14:47:46 * service_update * ora12c * 0

3. インスタンスを先に起動し、リスナーを後から起動する。その後サービス登録コマンドを実行する。

インスタンスは起動済みですが、リスナーは起動されていない状態から始めます。

リスナーを起動する

[xx:xx:xx] $ lsnrctl start

LSNRCTL for Linux: Version 12.1.0.2.0 - Production on 05-7月 -2015 14:54:43

Copyright (c) 1991, 2014, Oracle.  All rights reserved.

/u01/app/oracle/product/12.1.0.2/db_1/bin/tnslsnrを起動しています。お待ちください...

TNSLSNR for Linux: Version 12.1.0.2.0 - Production
システム・パラメータ・ファイルは/u01/app/oracle/product/12.1.0.2/db_1/network/admin/listener.oraです。
ログ・メッセージを/u01/app/oracle/diag/tnslsnr/oraclelinux6/listener/alert/log.xmlに書き込みました。
リスニングしています: (DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=oraclelinux6.onefact.jp)(PORT=1521)))
リスニングしています: (DESCRIPTION=(ADDRESS=(PROTOCOL=ipc)(KEY=EXTPROC1521)))

(DESCRIPTION=(ADDRESS=(PROTOCOL=TCP)(HOST=oraclelinux6.onefact.jp)(PORT=1521)))に接続中
リスナーのステータス
------------------------
別名                      LISTENER
バージョン                TNSLSNR for Linux: Version 12.1.0.2.0 - Production
開始日                    05-7月 -2015 14:54:43
稼働時間                  0 日 0 時間 0 分 0 秒
トレース・レベル          off
セキュリティ              ON: Local OS Authentication
SNMP                      OFF
パラメータ・ファイル      /u01/app/oracle/product/12.1.0.2/db_1/network/admin/listener.ora
ログ・ファイル            /u01/app/oracle/diag/tnslsnr/oraclelinux6/listener/alert/log.xml
リスニング・エンドポイントのサマリー...
  (DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=oraclelinux6.onefact.jp)(PORT=1521)))
  (DESCRIPTION=(ADDRESS=(PROTOCOL=ipc)(KEY=EXTPROC1521)))
リスナーはサービスをサポートしていません。
コマンドは正常に終了しました。
[14:54:43] $

14:54:43 にリスナーが起動しました。

サービス登録コマンドを実行する

xx:xx:xx SQL> alter system register;
 システムが変更されました。
14:54:49 SQL>

14:54:49 にサービス登録コマンドを実行しました。

別コンソールから接続確認を行う。

確認を行った時間に注目してください。

xx:xx:xx SQL> conn scott/tiger@ora12c
ERROR:
ORA-12541: TNS: リスナーがありません

警告: Oracleにはもう接続されていません。
14:54:14 SQL> conn scott/tiger@ora12c
ERROR:
ORA-12514: TNS:
リスナーは接続記述子でリクエストされたサービスを現在認識していません

14:54:46 SQL> conn scott/tiger@ora12c
接続されました。
14:54:55 SQL>

14:54:14 は、まだリスナーが起動されていません。
14:54:46 は、リスナーが起動されていますが、インスタンスが登録されていません。
14:54:55 は、インスタンスが登録されたので接続に成功しています。

リスナーログ

05-7月 -2015 14:54:46 * (CONNECT_DATA=(SERVER=DEDICATED)(SERVICE_NAME=ora12c)(CID=(PROGRAM=sqlplus)(HOST=oraclelinux6.onefact.jp)(USER=ora12c))) * (ADDRESS=(PROTOCOL=tcp)(HOST=192.168.11.18)(PORT=24826)) * establish * ora12c * 12514
TNS-12514: TNS: リスナーは現在、接続識別子でリクエストされているサービスを認識していません
2015-07-05 14:54:49.477000 +09:00
リスニングしています: (DESCRIPTION=(ADDRESS=(PROTOCOL=tcps)(HOST=oraclelinux6.onefact.jp)(PORT=5500))(Security=(my_wallet_directory=/u01/app/oracle/admin/ora12c/xdb_wallet))(Presentation=HTTP)(Session=RAW))
05-7月 -2015 14:54:49 * service_register * ora12c * 0
2015-07-05 14:54:55.269000 +09:00
05-7月 -2015 14:54:55 * (CONNECT_DATA=(SERVER=DEDICATED)(SERVICE_NAME=ora12c)(CID=(PROGRAM=sqlplus)(HOST=oraclelinux6.onefact.jp)(USER=ora12c))) * (ADDRESS=(PROTOCOL=tcp)(HOST=192.168.11.18)(PORT=24846)) * establish * ora12c * 0
05-7月 -2015 14:54:55 * service_update * ora12c * 0
2015-07-05 14:55:34.498000 +09:00
05-7月 -2015 14:55:34 * service_update * ora12c * 0
2015-07-05 14:57:10.577000 +09:00
05-7月 -2015 14:57:10 * service_update * ora12c * 0

12cでも、状況を見る限りでは11gと同じ挙動が確認できました。

リスナー登録（LREG）プロセスについて深掘りする

サービス登録の挙動に関しては、11g と 12c で違いはありませんでしたが、12cから新しくできたLREGプロセスについてもっと深く調べてみます。

まずは、いきなりですがサービスが登録された状態からLREGプロセスをkillしてみます。

LREGをkillしてみる

[xx:xx:xx] $ ps -ef | grep lreg
ora12c    3982     1  0 14:47 ?        00:00:00 ora_lreg_ora12c
ora12c    4347  3108  0 15:01 pts/4    00:00:00 grep lreg
[xx:xx:xx] $ kill -9 3982
[15:01:22] $

15:01:22 にプロセスがkillされました。

アラートログ

2015-07-05 15:01:23.798000 +09:00
Instance Critical Process (pid: 19, ospid: 3982, LREG) died unexpectedly
PMON (ospid: 3946): terminating the instance due to error 500
System state dump requested by (instance=1, osid=3946 (PMON)), summary=[abnormal instance termination].
System State dumped to trace file /u01/app/oracle/diag/rdbms/ora12c/ora12c/trace/ora12c_diag_3960_20150705150123.trc
Dumping diagnostic data in directory=[cdmp_20150705150123], requested by (instance=1, osid=3946 (PMON)), summary=[abnormal instance termination].
Instance terminated by PMON, pid = 3946

LREGの異常終了を検知して、最終的にPMONがインスタンスをダウンさせています。

つまり、LREGは必須プロセスです。

リスナーログ

2015-07-05 15:00:55.732000 +09:00
05-7月 -2015 15:00:55 * service_update * ora12c * 0
2015-07-05 15:01:22.006000 +09:00
リスニングしていません: (DESCRIPTION=(ADDRESS=(PROTOCOL=tcps)(HOST=oraclelinux6.onefact.jp)(PORT=5500))(Security=(my_wallet_directory=/u01/app/oracle/admin/ora12c/xdb_wallet))(Presentation=HTTP)(Session=RAW))
05-7月 -2015 15:01:22 * service_died * ora12c * 12537

LREGが異常終了してインスタンスがダウンすると、リスナーには「service_died」のステータスが伝達され、インスタンスの登録が抹消されます。

まとめ

リスナーにインスタンスがサービスとして登録されるところを見てきましたが、HA構成で運用しているデータベースでは起動スクリプトにおいて、「データベース⇨リスナー」の順に起動している場合があるかもしれません。（私が１５年前にDBAをしていた時のスクリプトはそうでした。）

RACになって、特に11g移行はGrid Infrastructureの一部としてリスナーはデータベースの前に起動する仕組みになっていますが、まだまだHA構成のデータベースは世の中にあると思いますので、フェイルオーバー時にサービス登録が速やかに行われるよう「alter system register」コマンドが実行されるようになっているかを確認しても良いのではないでしょうか？

終わり

次回は、このプロセスの内部動作に迫ってみます。

続く