ログファイルの種類と保存先

2016.10.14

こんにちは。YDCのさだおです。
Standby Express ではユーザーフレンドリーなGUI画面を提供していますが、直接ログファイルの中身を見たいと思うのがIT人の本能かと思います。 過去の稼働状況を確認できたり、ログから製品の動きが垣間見えたりしますよね。また、障害が発生したときに、 ログファイルは必須アイテム。そのため、ログファイルの場所を知っているだけでも、安心できます。

というわけで、今回は Standby Express のログファイル、特に主要機能の実行ログファイルをご紹介します。

主要機能については、コラム「Standby Express 自由に選べるユーザインタフェース操作」の回で記載していますので、ここでの説明は省略します。

同期

ログファイル名

・RUN_dequeue.log
・RUN_dequeue_yymmdd.log

ログファイルの場所

プライマリ機の下記ディレクトリ
<StandbyExpressインストールディレクトリ>/admin/<DB名>/log/

早速RUN_dequeue.log ファイルの中身を見てみましょう。
同期が成功した場合は、以下のような内容が出力されています。

------------------------------------------------------------------------------
| |
| Standby Express Processing Information |
| [Request] |
| TIME : 2016/06/01 14:31:12 |
| REQUEST : Sync <=★1 |
| TARGET : osaka-srv01 |
| [Result] |
| TIME : 2016/06/01 14:31:50 |
| RESULT : Normal Termination <=★1 |
| [Node Status] |
| OSAKA(osaka-srv01) |
| RESULT END_TIME TRANS_SCN_TIME APPLY_SCN_TIME |
| ------ ------------------- ------------------- ------------------- |
| OK 2016/06/01 14:31:41 2016/06/01 14:31:18 2016/06/01 14:31:18<=★2 |
| |
------------------------------------------------------------------------------

上記の内容から
・「Sync」(同期)が「Normal Termination」(正常終了)、つまり同期が成功したということ(★1)
・適用済ログSCN日時(★2)

(参考) SCNとは
--------------------------------------------------------
SCNとは、システム変更番号System Change Numbers (SCN)
Oracle はシステム変更番号System Change Numbers (SCN)によって、データベースの状態を一意に識別します。
SCN はコミットが発生するごとに増加します。
--------------------------------------------------------

では、同期が失敗した場合はどうでしょうか。

INFO [2016/06/01 14:35:34](Synchronize)INFO-00007: Beginning to synchronize the database.
INFO [2016/06/01 14:35:34](StandbyDB)INFO-00010: Checking open_mode of the standby database. (NODE: osaka-srv01)
ERR [2016/06/01 14:35:37](SQLPlus::Agent)NET-00022: Can't connect to agent. (:20678) <=★4
ERR [2016/06/01 14:35:37](StandbyDB)DBE-00010: Can't get open_mode of the standby database. (NODE: osaka-srv01)
(中略)
------------------------------------------------------------------------------
| |
| Standby Express Processing Information |
| [Request] |
| TIME : 2016/06/01 14:35:33 |
| REQUEST : Sync <=★3 |
| TARGET : osaka-srv01 |
| [Result] |
| TIME : 2016/06/01 14:36:18 |
| RESULT : Abnormal Termination <=★3 |
| [Node Status] |
| OSAKA(osaka-srv01) |
| RESULT END_TIME TRANS_SCN_TIME APPLY_SCN_TIME |
| ------ ------------------- ------------------- ------------------- |
| NG 2016/06/01 14:36:18 2016/06/01 14:31:18 2016/06/01 14:31:18 |
| |
------------------------------------------------------------------------------

上記の内容から
・「Sync」(同期)が「Abnormal Termination」(異常終了)、つまり同期が失敗したということ(★3 )
が分かります。

(★4)の箇所では、失敗の理由が出力されています。エラーが発生した場合は、 [ERR]から始まる行に情報が出力されます。ここの内容を手がかりにエラーの原因を調査していくことになります。
この例だと、[Can't connect to agent. (<IP Address$gt;:20678)]と出力されています。 「<IP Address$gt;:20678のAgentに接続できない」というエラーです。 そのため、まずは記載のIPアドレスのホストでStandby ExpressのAgentサービスが起動しているかを確認する必要がありそうです。

ちなみに、RUN_dequeue_yymmdd.logは過去のログとなります。
数日前から同期処理がエラーだったという場合には、過去にさかのぼって調査できます。

なお、GUI画面では、以下のように表示されます。

Sync.png
SyncNG.png

複製

ログファイル名

・RUN_dequeue.log
・RUN_dequeue_yymmdd.log

ログファイルの場所

プライマリ機の下記ディレクトリ
<StandbyExpressインストールディレクトリ>/admin/<DB名>/log/

「同期」と同じファイルにログが出力されます。
以下のような内容が出力されます。

INFO [2016/09/13 11:09:15](Duplicate)INFO-00006: Beginning to duplicate the database.
(中略)
INFO [2016/09/13 11:20:27](Dequeue)INFO-00057: Starting to dequeue message.
------------------------------------------------------------------------------
| |
| Standby Express Processing Information |
| [Request] |
| TIME : 2016/09/13 11:09:14 |
| REQUEST : Duplicate |
| TARGET : osaka-srv01 |
| [Result] |
| TIME : 2016/09/13 11:20:27 |
| RESULT : Normal Termination |
| [Node Status] |
| OSAKA(osaka-srv01) |
| RESULT END_TIME TRANS_SCN_TIME APPLY_SCN_TIME |
| ------ ------------------- ------------------- ------------------- |
| OK 2016/09/13 11:20:27 2016/09/13 11:11:26 2016/09/13 11:11:26 |
| |
------------------------------------------------------------------------------

上記のように、「Duplicate」(複製処理)が「Normal Termination」と出力されていれば、複製が正常に完了したということになります。
同期処理と同様に、「Normal Termination」ではなく「Abnormal Termination」となっている場合は、[ERR]から始まるエラー箇所を確認し、原因を突き止めて解決する必要があります。

ReadOnlyモード/Standbyモード

ログファイル名

・RUN_dequeue.log
・RUN_dequeue_yymmdd.log

ログファイルの場所

プライマリ機の下記ディレクトリ
<StandbyExpressインストールディレクトリ>/admin/<DB名>/log/

こちらも「同期」と同じファイルにログが出力されます。
以下のような内容が出力されます。

<ReadOnlyモードへ切り替え>

INFO [2016/09/13 12:28:09](StandbyDB)INFO-00010: Checking open_mode of the standby database. (NODE: osaka-srv01)
(中略)
INFO [2016/09/13 12:28:11](OpenReadOnly)INFO-00031: Executing open the standby database 'READ ONLY' mode. (NODE: osaka-srv01)
INFO [2016/09/13 12:28:40](StandbyDB)INFO-00010: Checking open_mode of the standby database. (NODE: osaka-srv01)
INFO [2016/09/13 12:28:42](Dequeue)INFO-00057: Starting to dequeue message.
------------------------------------------------------------------------------
| |
| Standby Express Processing Information |
| [Request] |
| TIME : 2016/09/13 12:28:07 |
| REQUEST : Open <=★5 |
| TARGET : osaka-srv01 |
| [Result] |
| TIME : 2016/09/13 12:28:41 |
| RESULT : Normal Termination |
| [Node Status] |
| OSAKA(osaka-srv01) |
| RESULT END_TIME TRANS_SCN_TIME APPLY_SCN_TIME |
| ------ ------------------- ------------------- ------------------- |
| OK 2016/09/13 12:02:14 2016/09/13 12:00:54 2016/09/13 12:00:54 |
| |
------------------------------------------------------------------------------

<Standbyモードへ切り替え>

INFO [2016/09/13 12:31:19](StandbyDB)INFO-00010: Checking open_mode of the standby database. (NODE: osaka-srv01)
(中略)
INFO [2016/09/13 12:31:22](OpenReadOnly)INFO-00030: Executing mount standby database. (NODE: osaka-srv01)
INFO [2016/09/13 12:33:24](Dequeue)INFO-00057: Starting to dequeue message.
------------------------------------------------------------------------------
| |
| Standby Express Processing Information |
| [Request] |
| TIME : 2016/09/13 12:31:17 |
| REQUEST : Close <=★6 |
| TARGET : osaka-srv01 |
| [Result] |
| TIME : 2016/09/13 12:33:23 |
| RESULT : Normal Termination |
| [Node Status] |
| OSAKA(osaka-srv01) |
| RESULT END_TIME TRANS_SCN_TIME APPLY_SCN_TIME |
| ------ ------------------- ------------------- ------------------- |
| OK 2016/09/13 12:02:14 2016/09/13 12:00:54 2016/09/13 12:00:54 |
| |
------------------------------------------------------------------------------

ReadOnlyモードでは、「REQUEST」は「Open」(★5)
Standbyモードでは、「REQUEST」は「Close」(★6)となります。

スイッチ・オーバー/スイッチ・バック

ログファイル名

・RUN_switchover_yymmdd.log

ログファイルの場所

プライマリ機の下記ディレクトリ
<StandbyExpressインストールディレクトリ>/admin/<DB名>/log/

以下がログファイルの内容です。

INFO [2016/06/01 15:55:35](Switchover)INFO-00077: Beginning to switch over from tokyo-srv01 to osaka-srv01.
(中略)
INFO [2016/06/01 15:59:17](Switchover)INFO-00084: Executing mount primary database. (NODE: osaka-srv01) <=★7
(中略)
INFO [2016/06/01 16:02:13](Switchover)INFO-00032: Executing startup nomount on the standby database. (NODE: tokyo-srv01) <=★8
(中略)
INFO [2016/06/01 16:04:31](Control)INFO-00065: Standby Express started. (NODE: osaka-srv01)
INFO [2016/06/01 16:04:50](Control)INFO-00065: Standby Express started. (NODE: tokyo-srv01)
INFO [2016/06/01 16:04:50](Switchover)INFO-00158: Waiting the execution node to be selected.
INFO [2016/06/01 16:04:50](Switchover)INFO-00043: Normal Termination <=★9

プライマリがosaka-srv01(★7)、スタンバイがtokyo-srv01(★8)となっています。
結果は「Normal Termination」で、正常に完了したということが分かります。(★9) なお、スイッチ・オーバー後のGUI画面では、以下のように表示されます。
GUIからもプライマリ・グループがOSAKA、スタンバイ・グループがTOKYOにスイッチしていることが確認できます。

Switch.jpg

本番化

ログファイル名

・RUN_activate_yymmdd.log

ログファイルの場所

スタンバイ機の下記ディレクトリ
<StandbyExpressインストールディレクトリ>/admin/<DB名>/log/

以下がログファイルの内容です。

INFO [2016/06/02 09:53:10](Activate)INFO-00005: Beginning to activate the standby database.
INFO [2016/06/02 09:53:11](StandbyDB)INFO-00010: Checking open_mode of the standby database. (NODE: osaka-srv01)
INFO [2016/06/02 09:53:11](StandbyDB)INFO-00109: Getting transferred SCN from the standby database. (NODE: osaka-srv01)
INFO [2016/06/02 09:53:11](StandbyDB)INFO-00039: Getting applied SCN from the standby database. (NODE: osaka-srv01)
INFO [2016/06/02 09:53:12](Activate)INFO-00028: Executing activate the standby database. (NODE: osaka-srv01)
INFO [2016/06/02 09:53:14](Activate)INFO-00074: Executing mount the database. (NODE: osaka-srv01)
INFO [2016/06/02 09:53:47](Activate)INFO-00018: Creating the temporary tablespace. (NODE: osaka-srv01)
INFO [2016/06/02 09:53:55](StandbyDB)INFO-00010: Checking open_mode of the standby database. (NODE: osaka-srv01)
INFO [2016/06/02 09:53:55](Activate) --------------------------------------------------------------
INFO [2016/06/02 09:53:55](Activate) | The standby database was activated in the state as of 2016/06/02 09:50:24. |
INFO [2016/06/02 09:53:55](Activate) --------------------------------------------------------------
INFO [2016/06/02 09:53:55](Activate)INFO-00043: Normal Termination

ログファイルから、
・スタンバイ機が正常に本番化(Activate)されたこと
・本番化は「2016/06/02 09:50:24」の時点の状態で行われたこと
がわかります。

また、OSAKAを本番化した後のGUI画面を確認すると、Standby側のOSAKAがRead/Writeに切り替わっています。

Activate.jpg

以上、各操作で成功/失敗したときに確認する主要なログファイルを紹介しました。

Standby Expressに関するお問合わせ

  • TEL 042-333-6217
  • FAX 042-352-6101
  • LINE
  • Mail