ログは誰が出しているのか？（Oracle Database 19c）

# Alertファイルとは

Oracle Database上で問題が発生したとき、まず確認するログがAlertログです。このデータベースのAlertファイルはテキストファイルの{ADR_HOME}/rdbms/{DB_UNIQUE_NAME}/{INSTANCE_NAME}/trace/alert_{DB_UNIQUE_NAME}.log
と、XML形式の{ADR_HOME}/rdbms/{DB_UNIQUE_NAME}/{INSTANCE_NAME}/log.xmlファイルです。
　ここではこのエラーログを出力しているのはだれか？といつ書き込んでいるのかを確認します。例として、表領域のデータファイル追加エラーを発生させます。以下のALTER TABLESPACE文はデータファイルがファイルシステムの空きに対して大きすぎてORA-19502エラーが発生しています。

```
SQL> ALTER TABLESPACE users ADD DATAFILE '/tmp/big1.dbf' SIZE 6G;
ALTER TABLESPACE users ADD DATAFILE '/tmp/big1.dbf' SIZE 6G
*
行1でエラーが発生しました。:
ORA-19502:
ファイル"/tmp/big1.dbf"、ブロック番号625280(ブロック・サイズ=8192)で書込みエラー
が発生しました
ORA-27072: ファイルI/Oエラーが発生しました。 Linux-x86_64
Error: 28: No space left on device
Additional information: 4
Additional information: 625280
Additional information: 4294967295
```

Alertファイルには以下のエラーが書き込まれます。

```
2020-10-22T13:58:46.329831+09:00
Errors in file /u01/app/oracle/diag/rdbms/o19a/O19A/trace/O19A_ora_833.trc:
ORA-27072: ファイルI/Oエラーが発生しました。
Linux-x86_64 Error: 28: No space left on device
Additional information: 4
Additional information: 625280
Additional information: 4294967295
```


# システムコールのトレース
　Alertファイルへの書き込みは結論としてはサーバー・プロセスが行っています。以下の例はエラー発生時のサーバー・プロセスが発行したシステム・コールのトレースを抜粋した資料です。

```
lstat("/u01/app/oracle/diag/rdbms/o19a/O19A/alert/log.xml", {st_mode=S_IFREG|0640, st_size=7690862, ...}) = 0
stat("/u01/app/oracle/diag/rdbms/o19a/O19A/alert/log.xml", {st_mode=S_IFREG|0640, st_size=7690862, ...}) = 0
geteuid()                               = 1001
lstat("/u01/app/oracle/diag/rdbms/o19a/O19A/alert/log.xml", {st_mode=S_IFREG|0640, st_size=7690862, ...}) = 0
open("/u01/app/oracle/diag/rdbms/o19a/O19A/alert/log.xml", O_WRONLY|O_CREAT|O_APPEND, 0660) = 12
lstat("/u01/app/oracle/diag/rdbms/o19a/O19A/alert/log.xml", {st_mode=S_IFREG|0640, st_size=7690862, ...}) = 0
chown("/u01/app/oracle/diag/rdbms/o19a/O19A/alert/log.xml", -1, 1001) = 0
stat("/u01/app/oracle/diag/rdbms/o19a/O19A/alert/log.xml", {st_mode=S_IFREG|0640, st_size=7690862, ...}) = 0
chmod("/u01/app/oracle/diag/rdbms/o19a/O19A/alert/log.xml", 0640) = 0
fcntl(12, F_SETFD, FD_CLOEXEC)          = 0
write(12, "<msg time='2020-10-22T14:03:26.8"..., 491) = 491
close(12)                               = 0
stat("/u01/app/oracle/diag/rdbms/o19a/O19A/alert/log.xml", {st_mode=S_IFREG|0640, st_size=7691353, ...}) = 0
lstat("/u01/app/oracle/diag/rdbms/o19a/O19A/trace/alert_O19A.log", {st_mode=S_IFREG|0640, st_size=63451203, ...}) = 0
open("/u01/app/oracle/diag/rdbms/o19a/O19A/trace/alert_O19A.log", O_WRONLY|O_CREAT|O_APPEND, 0660) = 12
lstat("/u01/app/oracle/diag/rdbms/o19a/O19A/trace/alert_O19A.log", {st_mode=S_IFREG|0640, st_size=63451203, ...}) = 0
chown("/u01/app/oracle/diag/rdbms/o19a/O19A/trace/alert_O19A.log", -1, 1001) = 0
stat("/u01/app/oracle/diag/rdbms/o19a/O19A/trace/alert_O19A.log", {st_mode=S_IFREG|0640, st_size=63451203, ...}) = 0
chmod("/u01/app/oracle/diag/rdbms/o19a/O19A/trace/alert_O19A.log", 0640) = 0
fcntl(12, F_SETFD, FD_CLOEXEC)          = 0
write(12, "2020-10-22T14:03:26.819954+09:00"..., 309) = 309
close(12)
```

以下の順番で実行されています。
1. log.xml ファイルの存在確認（lstat / stat）
2. log.xml ファイルを追記モードでオープン（open）
3. log.xml ファイルのモード変更（chmod）
4. log.xml ファイルへメッセージ書き込み（write）
5. log.xml ファイルのクローズ
6. alert ファイルの存在確認（lstat / stat）
7. alert ファイルを追記モードで（open）
8. alert ファイルのオーナー変更（chown）
9. alert ファイルのモード変更（chmod）
9. alert ファイルへメッセージ書き込み（write）
10. alert ファイルのクローズ

上記のように、alertファイルは書き込みが発生する度にオープン／書き込み／クローズを行っていることがわかります。