SQL*Netのトレース機能を試す

Oracle DatabaseとOracle Database Client間の通信をSQL*Netと呼びます。何等かの原因で通信がうまくいかない場合にトレースを取得することで原因を追究できることがあります。

# クライアントのトレース設定
Oracle クライアント側でトレースを取得するには\\$ORACLE\_HOME/network/admin/sqlnet.ora ファイル（または \\$TNS_ADMIN/sqlnet.oraファイル）のパラメーターを修正します。詳しくはマニュアル[Database Net リファレンス](https://docs.oracle.com/cd/F19136_01/netrf/parameters-for-the-sqlnet.ora.html#GUID-2041545B-58D4-48DC-986F-DCC9D0DEC642) を参照してください。

|パラメーター名|説明|デフォルト値|
|:---|:---|:---|
|ADR_BASE|ADRベースディレクトリの場所|\\$ORACLE_BASEまたは\\$ORACLE_HOME/log|
|DIAG_ADR_ENABLED|ADRトレースの有効性を示す|on|
|TRACE_LEVEL_CLIENT|クライアントのトレース・レベルを指定|0|
|TRACE_TIMESTAMP_CLIENT|トレースにタイムスタンプを付与|on|

　TRACE_LEVEL_CLIENTには以下の値を指定できます。「指定1」と「指定2」はどちらを指定してもかまいません。
|指定1|指定2|説明|
|:---|:---|:---|
|off|0|トレース無効|
|user|4|ユーザー用のトレース出力|
|admin|10|管理者用のトレース出力|
|support|16|Oracleサポート用のトレース出力|

実際に出力されるクライアントのADRトレースファイルは以下のディレクトリを順番に作成を試みます。クライアント・アプリケーション実行ユーザーに書き込み権限があるディレクトリが選択されます。

- sqlnet.ora ファイルに指定された ADR_BASE
- \\$ORACLE_BASE
- \\$ORACLE_HOME/log
- \\$HOME
- \\$TEMP


上記いずれかのディレクトリに「clients/user_{ユーザ名}/host_{ホストID}」ディレクトリが作成され、そのサブ・ディレクトリtraceにトレースファイルが生成されます。

# クライアントのトレース例
トレース出力の設定を行い、実際のトレースファイルを確認してみます。

```shell:
$ cat $ORACLE_HOME/network/admin/sqlnet.ora
DIAG_ADR_ENABLED=on
TRACE_LEVEL_CLIENT=16
TRACE_TIMESTAMP_CLIENT=on
```

以下の例では Oracle Real Application Clusters (RAC) を構成するデータベースに SCAN LISTENER (rel85-scan1) を指定して接続後に、トレース・ファイルを確認しています。

```shell:
$ sqlplus scott/{password}@rel85-scan1:1521/s1pdb1

SQL*Plus: Release 19.0.0.0.0 - Production on 月 12月 25 15:55:12 2023
Version 19.14.0.0.0

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

最終正常ログイン時間: 月 12月 25 2023 14:48:15 +09:00

Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production
Version 19.14.0.0.0
に接続されました。
SQL> Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production
Version 19.14.0.0.0との接続が切断されました。
$
$ cd $ORACLE_BASE/diag/clients/user_oracle/host_405963142_110/trace
$ ls
ora_45810_140117179091456.trc  ora_45810_140117179091456.trm
$ 
$ head -10 ora_45810_140117179091456.trc
Trace file /opt/oracle/diag/clients/user_oracle/host_405963142_110/trace/ora_45810_140117179091456.trc
2023-12-25 15:55:12.018 : nlstddt_do_alter_trace:Version 19.14.0.0.0
2023-12-25 15:55:12.019 : nlstddt_do_alter_trace:--- TRACE CONFIGURATION INFORMATION FOLLOWS ---
2023-12-25 15:55:12.019 : nlstddt_do_alter_trace:New trace stream is /opt/oracle/diag/clients/user_oracle/host_405963142_110/trace/ora_45810_140117179091456.trc
2023-12-25 15:55:12.019 : nlstddt_do_alter_trace:New trace level is 16
2023-12-25 15:55:12.019 : nlstddt_do_alter_trace:--- TRACE CONFIGURATION INFORMATION ENDS ---
2023-12-25 15:55:12.019 : nlstdtp_trace_pfile:--- PARAMETER SOURCE INFORMATION FOLLOWS ---
2023-12-25 15:55:12.019 : nlstdts_trace_source:Attempted load of system pfile source /opt/oracle/product/19.0.0/dbhome_1/network/admin/sqlnet.ora
2023-12-25 15:55:12.019 : nlstdts_trace_source:Parameter source loaded successfully
2023-12-25 15:55:12.019 : nlstdts_trace_source:
```

# トレースファイルの内容

トレース・レベルとして support (16) を指定した場合、詳細な SQL*Net 通信の状況がトレース・ファイルに出力されます。以下はトレース・ファイルの一部です。

トレースファイルの先頭には使用した sqlnet.ora ファイルのパラメーターが出力されます。sqlnet.ora ファイルの設定を確認できます。

```
2023-12-25 16:51:01.120 : nlstdtp_trace_pfile: -> PARAMETER TABLE LOAD RESULTS FOLLOW <-
2023-12-25 16:51:01.120 : nlstdtp_trace_pfile:Successful parameter table load
2023-12-25 16:51:01.120 : nlstddp_dump_ptable: -> PARAMETER TABLE HAS THE FOLLOWING CONTENTS <-
2023-12-25 16:51:01.120 : nlstddp_dump_ptable:  DIAG_ADR_ENABLED = on
2023-12-25 16:51:01.120 : nlstddp_dump_ptable:  TRACE_LEVEL_CLIENT = 16
2023-12-25 16:51:01.120 : nlstddp_dump_ptable:  TRACE_TIMESTAMP_CLIENT = on
2023-12-25 16:51:01.120 : nlstdtp_trace_pfile:--- PARAMETER SOURCE INFORMATION ENDS ---
```


ユーザの入力した内容は「Original name:」として出力されます。
```
2023-12-25 15:55:12.021 : nnftrne:Original name: rel85-scan1:1521/s1pdb1
```

SQL*Net 形式に変換された文字列と使用されたIPアドレスは以下のように出力されます。

```
2023-12-25 15:55:12.021 : nnfhrne:Using1 hostname address (DESCRIPTION=(CONNECT_DATA=(SERVICE_NAME=s1pdb1))(ADDRESS=(PROTOCOL=tcp)(HOST=192.168.1.210)(PORT=1521))) for name rel85-scan1:1521/s1pdb1
2023-12-25 15:55:12.022 : nttbnd2addr:using host IP address: 192.168.1.210
```

SCANリスナーから、クライアントに再接続用のVIP情報（192.168.1.134）を含むパケットが戻ります。受け取ったパケットのダンプ情報が出力されます。

```
 592 2023-12-25 15:55:12.034 : nsprecv:packet dump
 593 2023-12-25 15:55:12.034 : nsprecv:01 0C 00 00 06 00 00 00  |........|
 594 2023-12-25 15:55:12.034 : nsprecv:00 40 28 41 44 44 52 45  |.@(ADDRE|
 595 2023-12-25 15:55:12.034 : nsprecv:53 53 3D 28 50 52 4F 54  |SS=(PROT|
 596 2023-12-25 15:55:12.034 : nsprecv:4F 43 4F 4C 3D 54 43 50  |OCOL=TCP|
 597 2023-12-25 15:55:12.034 : nsprecv:29 28 48 4F 53 54 3D 31  |)(HOST=1|
 598 2023-12-25 15:55:12.034 : nsprecv:39 32 2E 31 36 38 2E 31  |92.168.1|
 599 2023-12-25 15:55:12.034 : nsprecv:2E 31 33 34 29 28 50 4F  |.134)(PO|
 600 2023-12-25 15:55:12.034 : nsprecv:52 54 3D 31 35 32 31 29  |RT=1521)|
 601 2023-12-25 15:55:12.034 : nsprecv:29 00 28 44 45 53 43 52  |).(DESCR|
 602 2023-12-25 15:55:12.034 : nsprecv:49 50 54 49 4F 4E 3D 28  |IPTION=(|
 603 2023-12-25 15:55:12.034 : nsprecv:43 4F 4E 4E 45 43 54 5F  |CONNECT_|
 604 2023-12-25 15:55:12.034 : nsprecv:44 41 54 41 3D 28 53 45  |DATA=(SE|
 605 2023-12-25 15:55:12.034 : nsprecv:52 56 49 43 45 5F 4E 41  |RVICE_NA|
 606 2023-12-25 15:55:12.034 : nsprecv:4D 45 3D 73 31 70 64 62  |ME=s1pdb|
 607 2023-12-25 15:55:12.034 : nsprecv:31 29 28 43 49 44 3D 28  |1)(CID=(|
 608 2023-12-25 15:55:12.034 : nsprecv:50 52 4F 47 52 41 4D 3D  |PROGRAM=|
 609 2023-12-25 15:55:12.034 : nsprecv:73 71 6C 70 6C 75 73 40  |sqlplus@|
 610 2023-12-25 15:55:12.034 : nsprecv:72 65 6C 38 34 2D 33 29  |rel84-3)|
 611 2023-12-25 15:55:12.034 : nsprecv:28 48 4F 53 54 3D 72 65  |(HOST=re|
 612 2023-12-25 15:55:12.034 : nsprecv:6C 38 34 2D 33 29 28 55  |l84-3)(U|
 613 2023-12-25 15:55:12.034 : nsprecv:53 45 52 3D 6F 72 61 63  |SER=orac|
 614 2023-12-25 15:55:12.034 : nsprecv:6C 65 29 29 28 53 45 52  |le))(SER|
 615 2023-12-25 15:55:12.034 : nsprecv:56 45 52 3D 64 65 64 69  |VER=dedi|
 616 2023-12-25 15:55:12.034 : nsprecv:63 61 74 65 64 29 28 49  |cated)(I|
 617 2023-12-25 15:55:12.034 : nsprecv:4E 53 54 41 4E 43 45 5F  |NSTANCE_|
 618 2023-12-25 15:55:12.034 : nsprecv:4E 41 4D 45 3D 6F 31 39  |NAME=o19|
 619 2023-12-25 15:55:12.034 : nsprecv:76 32 29 29 28 41 44 44  |v2))(ADD|
 620 2023-12-25 15:55:12.034 : nsprecv:52 45 53 53 3D 28 50 52  |RESS=(PR|
 621 2023-12-25 15:55:12.034 : nsprecv:4F 54 4F 43 4F 4C 3D 74  |OTOCOL=t|
 622 2023-12-25 15:55:12.034 : nsprecv:63 70 29 28 48 4F 53 54  |cp)(HOST|
 623 2023-12-25 15:55:12.034 : nsprecv:3D 31 39 32 2E 31 36 38  |=192.168|
 624 2023-12-25 15:55:12.034 : nsprecv:2E 31 2E 32 31 30 29 28  |.1.210)(|
 625 2023-12-25 15:55:12.034 : nsprecv:50 4F 52 54 3D 31 35 32  |PORT=152|
 626 2023-12-25 15:55:12.034 : nsprecv:31 29 29 29              |1)))    |
```

クライアントのトレースを support レベルで取得すると、RAC 構成のサーバに１回接続するだけで、約3,000 行のトレース・ファイルが出力されます。

Author: Noriyoshi Shinoda / Date: December 25, 2023