trace Log の概要
IOS-XR が動作するルーターでは trace と呼ばれる各プロセスの動作情報を共有メモリに保持しており
正常系、エラー系の情報 (debug 相当) を常に共有メモリへ記録しています。
trace は開発側の解析用の Log になるため、その意味については公開をしていませんが
調査が必要な機能の trace を予め取得することで、障害解析の迅速化や、精度の高い解析が可能となります。
Buffer サイズや実装は、各機能によって異なりますが、その中でも OSPF/OSPFv3 については trace バッファの拡張や
trace そのものの拡張が可能です。以下に OSPF を例にとり、紹介します。
OSPF trace バッファの拡張
show ospf <Process 名> trace を実行することで、それぞれの trace のバッファのサイズや
記録されているログ数を確認できます。
RP/0/RSP0/CPU0:IOS-XR#show ospf <Process 名> trace
OSPF Trace Summary (<Process 名>, RP/0/RSP0/CPU0:IOS-XR, 2048M)
Trace Name Size Count Description
------------ ------- ---------- --------------------------
1. adj 8192 6 adjacency
2. adj_cycle 8192 0 dbd/flood events/pkts
3. config 4096 116 config events
4. errors 8192 6 errors
5. warnings 4096 1 low errors/warnings
6. events 4096 130 mda/rtrid/bfd/vrf
7. ha 8192 445 startup/HA/NSF
8. hello 2048 0 hello events/pkts
9. idb 8192 5 interface
10. pkt 2048 1 I/O packets
11. rib 8192 18 rib batching
12. spf 8192 51 spf/topology
13. spf_cycle 8192 0 spf/topology detail
14. te 4096 7 mpls-te
15. test 1024 3 testing info
16. mq 256 0 message queue info
各 trace は以下の設定を行うことで、バッファサイズを拡張できます。
また、基本的にこの拡張を行うことで、負荷が高まったり、機能的な影響が発生する事はありません。
configure terminal
router ospf <Process 名>
trace size <trace 名> <trace size>
例えば以下のようにバッファサイズを拡張します。
RP/0/RSP0/CPU0:IOS-XR(config)#router ospf TEST
RP/0/RSP0/CPU0:IOS-XR(config-ospf)#trace size adj ?
0 disable trace(cisco-support)
256 trace entries(cisco-support)
512 trace entries(cisco-support)
1024 trace entries(cisco-support)
2048 trace entries(cisco-support)
4096 trace entries(cisco-support)
8192 trace entries(cisco-support)
16384 trace entries(cisco-support)
32768 trace entries(cisco-support)
65536 trace entries(cisco-support)
RP/0/RSP0/CPU0:IOS-XR(config-ospf)#trace size adj 65536
OSPF trace の拡張
OSPF の trace は、debug コマンドを使用することで、より詳細な trace を記録するように拡張が可能です。
拡張をするためには、debug ospf <Process 名> trace detail の後に、以下のオプションを指定します。
RP/0/RSP0/CPU0:IOS-XR#debug ospf <Process 名> trace detail ?
adj OSPF adjacency
cfg OSPF detailed config tracing
db-timer OSPF DB timers
fc OSPF fast convergence test
flood OSPF flooding
ha OSPF detailed HA tracing
hello OSPF hello packets/processing
ipfrr OSPF detailed spf IPFRR tracing
lsa OSPF lsa generation
mq OSPF detailed message-queue tracing
mutex OSPF mutex locking/unlocking
packet OSPF packet I/O
priority OSPF detailed spf prefix-priority tracing
redistribution OSPF route redistribution
segment-routing OSPF detailed Segment-routing tracing
spf OSPF various SPF events
te OSPF detailed TE tracing
topology OSPF SPF topology changes
RP/0/RSP0/CPU0:IOS-XR#debug ospf <Process 名> trace packet ?
all-input trace all input packets
all-output trace all output packets
dbd-input trace database exchange (DBD) input packets
dbd-output trace database exchange (DBD) output packets
hello-input trace hello input packets
hello-output trace hello output packets
lsa-input trace link state (LSA) input packets
lsa-output trace link state (LSA) output packets
hello を拡張した例です。
通常時は 1回の hello の送出に対して1行のみだった trace が
拡張時は4行に拡張されていることがわかります。
RP/0/RSP0/CPU0:IOS-XR#show ospf TEST trace hello
Traces for OSPF TEST (Wed Aug 23 11:25:55)
Traces returned/requested/available: 2048/2048/2048
Trace buffer: hello
1 Aug 23 11:07:43.178* ospf_send_hello: area 0.0.4.80 intf BE401.12 from 192.168.10.1 <<<< 通常時。area1104 への hello に対して、1行のみ。
2 Aug 23 11:07:44.172* ospf_send_hello: area 0.0.0.0 intf Gi0/2/0/2 from 192.168.20.1
3 Aug 23 11:07:44.630* ospf_rcv_hello: intf BE401.12 area 0.0.4.80 from 10.0.0.1 192.168.10.2
4 Aug 23 11:07:44.630* ospf_check_hello_events: intf BE401.12 area 0.0.4.80 from 192.168.10.1
5 Aug 23 11:07:45.048* ospf_send_hello: area 0.0.4.80 intf BE401.12 from 192.168.10.1
6 Aug 23 11:07:46.630 ospf_rcv_hello: intf BE401.12 area 0.0.4.80 from 10.0.0.1 192.168.10.2
7 Aug 23 11:07:46.630 ospf_check_hello_events: intf BE401.12 area 0.0.4.80 from 192.168.10.1
8 Aug 23 11:07:46.916 ospf_send_hello: area 0.0.4.80 intf BE401.12 from 192.168.10.1
- snip -
2030 Aug 23 11:25:53.292 ospf_send_hello: area 0.0.4.80 intf BE401.12 from 192.168.10.1 <<< 拡張後の ospf_send_hello
2031 Aug 23 11:25:53.292 ospf_send_hello: nbr/if state 3/3 DR 0.0.0.0 BDR 0.0.0.0
2032 Aug 23 11:25:53.292 ospf_send_hello: pri 1 opts 0x18 hello 2 dead 8
2033 Aug 23 11:25:53.292 ospf_send_hello: vrfid 0x60000000
2034 Aug 23 11:25:55.198 ospf_rcv_hello: intf BE401.12 area 0.0.4.80 from 10.0.0.1 192.168.10.2
2035 Aug 23 11:25:55.198 ospf_rcv_hello: nbr/if state 3/3 vrfid 0x60000000
2036 Aug 23 11:25:55.198 ospf_check_hello_events: intf BE401.12 area 0.0.4.80 from 192.168.10.1
2037 Aug 23 11:25:55.198 ospf_check_hello_events: nbr/if state 3/3 DR 0.0.0.0 BDR 0.0.0.0
2038 Aug 23 11:25:55.198 ospf_check_hello_events: pri 0 opts 0x18 hello 2 dead 8
2039 Aug 23 11:25:55.198 ospf_check_hello_events: nbr DR/BDR 0.0.0.0/0.0.0.0
2040 Aug 23 11:25:55.198 ospf_rcv_hello: end of hello processing
2041 Aug 23 11:25:55.234 ospf_send_hello: area 0.0.4.80 intf BE401.12 from 192.168.10.1
2042 Aug 23 11:25:55.234 ospf_send_hello: nbr/if state 3/3 DR 0.0.0.0 BDR 0.0.0.0
2043 Aug 23 11:25:55.234 ospf_send_hello: pri 1 opts 0x18 hello 2 dead 8
2044 Aug 23 11:25:55.234 ospf_send_hello: vrfid 0x60000000
2045 Aug 23 11:25:55.266 ospf_send_hello: area 0.0.0.0 intf Gi0/2/0/2 from 192.168.20.1
2046 Aug 23 11:25:55.266 ospf_send_hello: nbr/if state 3/4 DR 0.0.0.0 BDR 0.0.0.0
2047 Aug 23 11:25:55.266 ospf_send_hello: pri 1 opts 0x12 hello 10 dead 40
2048 Aug 23 11:25:55.266 ospf_send_hello: vrfid 0x60000000
