FAQ for YAMAHA RT Series / Syslog

RTシリーズのログに関するFAQ

発呼要因を報告するログ

最終変更日	2010/Jul/21
文書サイズ	9.2KB

「IP Commencing」というログの意味を教えてください。

[ 役割 ]

役割
「このIPパケットにより発呼を開始します」という意図を表していて、発呼要因であるIPパケットの種類が記録されます。
ログ・レベル
infoレベルとdebugレベルで、ログが記録されます。もし、両方のレベルが設定されていれば、それぞれログされます。
infoレベルでは、プロトコル情報や始点と終点のIPアドレスやポート番号がログに残されます。debugレベルでは、パケットの先頭部分の16進数によるダンプ情報をログに残します。

debugレベルの16進数ダンプの部分は取扱注意！
電話番号などの個人情報も含まれていることがあります。
発呼要因が「DNSサーバへの問い合せパケット」であるときのログ
発呼要因の特定が難しくなることがあります。「DNSサーバへの問い合せ内容」をログに残すように仕様変更されています。

[ 書式 ]

PP[XX] IP Commencing: 始点アドレス to 終点アドレス(プトロコル srcport=始点ポート, dstport=終点ポート)

(初期のパターン)
このIPパケットによりPP[XXX]の接続(通信)を始める。
infoレベル + パケット内容の概要
PP[XX] IP Commencing: プトロコル始点アドレス:始点ポート > 終点アドレス:終点ポート

(IPパケットフィルタ風の新しいパターン)
このIPパケットによりPP[XXX]の接続(通信)を始める。
infoレベル + パケット内容の概要

PP[XX] IP Commencing: XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX

このIPパケットによりPP[XXX]の接続(通信)を始める。
debugレベル + 16進数によるパケット内容のダンプ(詳細)

[ IP Commencingログにみる発呼要因となる通信パターン ]

PP[XX] IP Commencing: UDP 192.168.0.2:1024 > DNSサーバ:53 (DNS Query [www.rtpro.yamaha.co.jp])

PC(192.168.0.2)がDNSサーバに"www.rtpro.yamaha.co.jp"のDNS情報の問い合せ要求があり、発呼しました。
宛先ポートがUDPやTCPの53番の場合は、DNSサーバ！
問い合せ内容→"www.rtpro.yamaha.co.jp"のIPアドレスを調べる。
PP[XX] IP Commencing: UDP 192.168.0.2:1024 > DNSサーバ:53 (DNS Query [3.0.168.192.in-addr.arpa])

PC(192.168.0.2)がDNSサーバに"3.0.168.192.in-addr.arpa"のDNS情報の問い合せ要求があり、発呼しました。
宛先ポートがUDPやTCPの53番の場合は、DNSサーバ！
問い合せ内容→"3.0.168.192.in-addr.arpa" (192.168.0.3)のDNS名を調べる。
PP[XX] IP Commencing: UDP 192.168.0.1:53 > DNSサーバ:53 (DNS Query [www.rtpro.yamaha.co.jp] from 192.168.0.2)

RT(192.168.0.1)のDNSリカーシブサーバに PC(192.168.0.2)から"www.rtpro.yamaha.co.jp"のDNS情報の問い合せ要求があり、発呼しました。
DNSリカーシブサーバは、始点ポートとして、53番を使うようだ！
問い合せ内容→"www.rtpro.yamaha.co.jp"のIPアドレスを調べる。
PP[XX] IP Commencing: UDP 192.168.0.1:53 > DNSサーバ:53 (DNS Query [3.0.168.192.in-addr.arpa] from 192.168.0.2)

RT(192.168.0.1)のDNSリカーシブサーバに PC(192.168.0.2)から"3.0.168.192.in-addr.arpa"のDNS情報の問い合せ要求があり、発呼しました。
DNSリカーシブサーバは、始点ポートとして、53番を使うようだ！
問い合せ内容→"3.0.168.192.in-addr.arpa" (192.168.0.3)のDNS名を調べる。
PP[XX] IP Commencing: TCP 192.168.0.2:1024 > FTPサーバ:21

PC(192.168.0.2)がFTPサーバに接続するために発呼しました。
宛先ポートがTCPの21番の場合は、ftpサーバ！
PP[XX] IP Commencing: TCP 192.168.0.2:1024 > TELNETサーバ:23

PC(192.168.0.2)がTELNETサーバにtelnet接続するために発呼しました。
宛先ポートがTCPの23番の場合は、telnetサーバ！
PP[XX] IP Commencing: TCP 192.168.0.2:1024 > メールサーバ:25

PC(192.168.0.2)で電子メールの送信操作をしたのでメールサーバに接続する発呼がありました。
宛先ポートがTCPの25番の場合は、SMTPサーバ！
PP[XX] IP Commencing: TCP 192.168.0.2:1024 > メールサーバ:110

PC(192.168.0.2)で電子メールの受信確認や受信メールを取得する操作がされたので、メールサーバに接続する発呼がありました。
宛先ポートがTCPの110番の場合は、POP3サーバ！
PP[XX] IP Commencing: TCP 192.168.0.2:1024 > WWWサーバ:80

PC(192.168.0.2)がWWWブラウザでWWWサーバを閲覧しようとしたために発呼しました。
宛先ポートがTCPの80番の場合は、WWWサーバ/HTTPサーバ！
PP[XX] IP Commencing: ICMP 192.168.0.2 > 宛先ホスト : echo request

PC(192.168.0.2)が宛先ホストにping(たぶん、ping)したために発呼しました。
ping というツールは、ICMP Echo Requestという種類のパケットを使ってるようだ！
ちなみに、ICMP Echo Requestの返事は、ICMP Echo Reply

[ 発呼したときのログ例 ]

20:15:03: PP[XX] IP Commencing: UDP 192.168.0.1:53 > DNSサーバ:53 20:15:03: PP[XX] Calling 接続先の電話番号 with 1B mode 20:15:06: PP[XX] PPP/IPCP up ... 20:20:02: PP[XX] Disconnecting, cause [Data transaction timer expired] 20:20:03: PP[XX] Disconnect complete 20:20:03: PP[XX] Disconnected cause [Data transaction timer expired] 20:20:03: PP[XX] Charge is 20 yen

RT(192.168.0.1)のDNSリカーシブサーバにPCからDNSの問い合せ要求があり、発呼しています。発呼後、5分経過して通信が途絶えたことにより切断しています。

17:31:24: PP[01] IP Commencing: 17:31:24: PP[01] IP Commencing: ICMP 192.168.0.2 > ホスト : echo request 17:31:24: PP[01] Calling 接続先の電話番号 with 1B mode 17:31:24: 45 00 00 3c c4 00 00 00 1f 01 c9 32 c0 a8 00 02 17:31:24: ISDN[1/80] SEND [SETUP] 17:31:24: 85 b0 c8 33 08 00 49 5c 03 00 01 00 61 62 63 64 17:31:24: 08 01 09 05 04 02 88 90 18 01 83 6c 04 00 80 32 17:31:24: 65 66 67 68 69 6a 6b 6c 6d 6e 6f 70 71 72 73 74 17:31:24: 30 70 03 80 31 30 7c 02 88 90 17:31:24: 75 76 77 61 62 63 64 65 66 67 68 69 17:31:24: ISDN[1/80] RECV [CALL PROC] 17:31:24: 08 01 89 02 18 01 89 17:31:25: ISDN[1/80] RECV [CONN] 17:31:25: 08 01 89 07

「syslog info on, syslog debug on」のときのログ。 16進数ダンプの内容がダブってますので、空白文字のインデントにより区別できるようにしています。
以下のように整理して読みます....

※16進数ダンプの部分は取扱注意！電話番号などの個人情報も含まれていることがあります。

(debug) 17:31:24: PP[01] IP Commencing:
(debug) 17:31:24:      45 00 00 3c c4 00 00 00  1f 01 c9 32 c0 a8 00 02
(debug) 17:31:24:      85 b0 c8 33 08 00 49 5c  03 00 01 00 61 62 63 64
(debug) 17:31:24:      65 66 67 68 69 6a 6b 6c  6d 6e 6f 70 71 72 73 74
(debug) 17:31:24:      75 76 77 61 62 63 64 65  66 67 68 69

 (info) 17:31:24: PP[01] IP Commencing: ICMP 192.168.0.2 > ホスト : echo request

 (info) 17:31:24: PP[01] Calling 接続先の電話番号 with 1B mode

(debug) 17:31:24: ISDN[1/80] SEND [SETUP]
(debug) 17:31:24:     08 01 09 05 04 02 88 90  18 01 83 6c 04 00 80 32
(debug) 17:31:24:     30 70 03 80 31 30 7c 02  88 90

(debug) 17:31:24: ISDN[1/80] RECV [CALL PROC]
(debug) 17:31:24:     08 01 89 02 18 01 89

(debug) 17:31:25: ISDN[1/80] RECV [CONN]
(debug) 17:31:25:     08 01 89 07

[ 関連情報 ]

ログ(syslog)にこんなメッセージが出て来たけど、何これ?

[ FAQ for RT-Series ]
[ FAQ for Syslog / files / Intro / Install / Config ]