PostgreSQLログのエラーレベルは場合によって引き上げられることがある

PostgreSQLのエラーレベルはメッセージごとに固定だと長らく勘違いしていた話。


# マスタ接続失敗時のエラー
Streaming Replication構成でスタンバイから以下のようなメッセージがログに出力されていました。

```
FATAL: could not connect to the primary server: could not connect to server: No route to host
```

このメッセージが出たときにはマスタを落としていたので、メッセージが出ること自体は問題ではないですが、接続失敗でFATALになることがやや気になったので、調査しました。

# ソースコード上だとFATALではなくERROR ?

メッセージでgrepすると、出力している場所は特定できました。

```src/backend/replication/libpqwalreceiver/libpqwalreceiver.c:
113     streamConn = PQconnectdbParams(keys, vals, /* expand_dbname = */ true);
114     if (PQstatus(streamConn) != CONNECTION_OK)
115         ereport(ERROR,
116                 (errmsg("could not connect to the primary server: %s",
117                         PQerrorMessage(streamConn))));
118 }
```

が、ERRROR？

いろいろ悩みましたが、結論はシンプルでした。

# PostgreSQLの状態によってはエラーレベルが引き上げられることがある

知らなかった。。。

エラーメッセージを出力するための関数であるereport()の内部を追っていくと、以下のような箇所がありました。

```src/postgres/src/backend/utils/error/elog.c:
 235     /*
 236      * Check some cases in which we want to promote an error into a more
 237      * severe error.  None of this logic applies for non-error messages.
 238      */
 239     if (elevel >= ERROR)
 240     {
 241         /*
 242          * If we are inside a critical section, all errors become PANIC
 243          * errors.  See miscadmin.h.
 244          */
 245         if (CritSectionCount > 0)
 246             elevel = PANIC;
 247
 248         /*
 249          * Check reasons for treating ERROR as FATAL:
 250          *
 251          * 1. we have no handler to pass the error to (implies we are in the
 252          * postmaster or in backend startup).
 253          *
 254          * 2. ExitOnAnyError mode switch is set (initdb uses this).
 255          *
 256          * 3. the error occurred after proc_exit has begun to run.  (It's
 257          * proc_exit's responsibility to see that this doesn't turn into
 258          * infinite recursion!)
 259          */
 260         if (elevel == ERROR)
 261         {
 262             if (PG_exception_stack == NULL ||
 263                 ExitOnAnyError ||
 264                 proc_exit_inprogress)
 265                 elevel = FATAL;
 266         }
```

つまり、CriticalSectionの中（大抵はWALを扱っている処理中）だとERRORレベルからPANICへと強制的に変更され、そうでなくても以下の3つの条件のいずれかに該当する場合はERRORレベルからFATALへの強制的に変更されます。

 1. エラーを渡すハンドラが存在しない = postmasterの内部処理でのエラー、もしくはバックエンドプロセスの初期化時のエラー
 2. ExitOnAnyErrorフラグが立っているとき（initdbが該当）
 3. proc_exitが開始した後のエラー = 何らかのエラーが発生して異常終了しようとしているときに更にエラーが発生した場合
 
今回の場合は、wal receiverプロセスの初期化時にエラーが発生したので1.が該当した結果、通常はERRORレベルで出力されるメッセージがFATALで出力されていた、というわけでした。

# 参考. PostgreSQLの出すログのメッセージのレベル

| 深刻度 | 使用方法 | syslog | eventlog |
|--------|---------|--------|----------|
| DEBUG1..DEBUG5 | 開発者が使用する連続的かつより詳細な情報を提供します。| DEBUG | INFORMATION |
|INFO | VACUUM VERBOSEの出力などの、ユーザによって暗黙的に要求された情報を提供します。 | INFO | INFORMATION |
|NOTICE | 長い識別子の切り詰めに関する注意など、ユーザの補助になる情報を提供します。| NOTICE	 | INFORMATION |
| WARNING |トランザクションブロック外でのCOMMITの様な、ユーザへの警告を提供します。 | NOTICE | WARNING |
| ERROR | 現在のコマンドを中断させる原因となったエラーを報告します。| WARNING | ERROR |
| LOG | チェックポイントの活動の様な、管理者に関心のある情報を報告します。| INFO | INFORMATION |
| FATAL | 現在のセッションを中断させる原因となったエラーを報告します。 | ERR | ERROR |
| PANIC | 全てのデータベースセッションを中断させる原因となったエラーを報告します。 | CRIT | ERROR |

http://www.postgresql.jp/document/current/html/runtime-config-logging.html  
表 18-1. メッセージ深刻度レベル 
より引用