SIP debugging

SIP debug log format

Assuming that diagnose debug console timestamp is enabled then the following shows the debug that is generated for an INVITE if diag debug appl sip -1 is enabled:

2010-01-04 21:39:59 sip port 26 locate session for 192.168.2.134:5061 -> 172.16.67.192:5060

2010-01-04 21:39:59 sip sess 0x979df38 found for 192.168.2.134:5061 -> 172.16.67.192:5060

2010-01-04 21:39:59 sip port 26 192.168.2.134:5061 -> 172.16.67.192:5060

2010-01-04 21:39:59 sip port 26 read [(0,515) (494e56495445207369703a73657276696365403139322e3136382e322e3130303a35303630205349502f322e300d0a5669613a2

05349502f322e302f554450203132372e302e312e313a353036313b6272616e63683d7a39684734624b2d363832372d3632302d3

00d0a46726f6d3a2073697070203c7369703a73697070403132372e302e312e313a353036313e3b7461673d36383237534950705

4616730303632300d0a546f3a20737574203c7369703a73657276696365403139322e3136382e322e3130303a353036303e0d0a4

3616c6c2d49443a203632302d36383237403132372e302e312e310d0a435365713a203120494e564954450d0a436f6e746163743 a207369703a73697070403132372e302e312e313a353036310d0a4d61782d466f7277617264733a2037300d0a5375626a6563743 a20506572666f726d616e636520546573740d0a436f6e74656e742d547970653a206170706c69636174696f6e2f7364700d0a436 f6e74656e742d4c656e6774683a20203132390d0a0d0a763d300d0a6f3d757365723120353336353537363520323335333638373

6333720494e20495034203132372e302e312e310d0a733d2d0d0a633d494e20495034203132372e302e312e310d0a743d3020300 d0a6d3d617564696f2036303031205254502f41565020300d0a613d7274706d61703a302050434d552f383030300d0a)(INVITE sip:service@192.168.2.100:5060 SIP/2.0..Via: SIP/2.0/UDP

127.0.1.1:5061;branch=z9hG4bK-6827-620-0..From: sipp

%lt;sip:sipp@127.0.1.1:5061>;tag=6827SIPpTag00620..To: sut

%lt;sip:service@192.168.2.100:5060>..Call-ID: 620-6827@127.0.1.1..CSeq: 1

INVITE..Contact: sip:sipp@127.0.1.1:5061..Max-Forwards: 70..Subject: Performance

Test..Content-Type: application/sdp..Content-Length: 129….v=0..o=user1 53655765

2353687637 IN IP4 127.0.1.1..s=-..c=IN IP4 127.0.1.1..t=0 0..m=audio 6001 RTP/AVP

0..a=rtpmap:0 PCMU/8000..)]

2010-01-04 21:39:59 sip port 26 len 515

2010-01-04 21:39:59 sip port 26 INVITE ‘192.168.2.100:5060’ addr 192.168.2.100:5060

2010-01-04 21:39:59 sip port 26 CSeq: 1 INVITE

2010-01-04 21:39:59 sip port 26 Via: UDP 127.0.1.1:5061 len 14 received 0 rport 0 0 branch ‘z9hG4bK-

6827-620-0’

2010-01-04 21:39:59 sip port 26 From: ‘sipp ;tag=6827SIPpTag00620’ URI ‘sip:sipp@127.0.1.1:5061‘ tag

‘6827SIPpTag00620’

2010-01-04 21:39:59 sip port 26 To: ‘sut ‘ URI ‘sip:service@192.168.2.100:5060‘ tag ”

2010-01-04 21:39:59 sip port 26 Call-ID: ‘620-6827@127.0.1.1‘

2010-01-04 21:39:59 sip port 26 Contact: ‘127.0.1.1:5061’ addr 127.0.1.1:5061 expires 0

2010-01-04 21:39:59 sip port 26 Content-Length: 129 len 3

2010-01-04 21:39:59 sip port 26 sdp o=127.0.1.1 len=9

2010-01-04 21:39:59 sip port 26 sdp c=127.0.1.1 len=9

2010-01-04 21:39:59 sip port 26 sdp m=6001 len=4

2010-01-04 21:39:59 sip port 26 find call 0 ‘620-6827@127.0.1.1‘

2010-01-04 21:39:59 sip port 26 not found

2010-01-04 21:39:59 sip port 26 call 0x97a47c0 open (collision (nil))

2010-01-04 21:39:59 sip port 26 call 0x97a47c0 open txn 0x979f7f8 INVITE dir 0

2010-01-04 21:39:59 sip port 26 sdp i: 127.0.1.1:6001

2010-01-04 21:39:59 sip port 26 policy id 1 is_client_vs_policy 1 policy_dir_rev 0

2010-01-04 21:39:59 sip port 26 policy 1 not RTP policy

2010-01-04 21:39:59 sip port 26 learn sdp from stream address

2010-01-04 21:39:59 sip port 26 call 0x97a47c0 sdp 172.16.67.198:43722

2010-01-04 21:39:59 sip port 26 call 0x97a47c0 txn 0x979f7f8 127.0.1.1:5061 find new address and port

2010-01-04 21:39:59 sip port 26 call 0x97a47c0 txn 0x979f7f8 127.0.1.1:5061 find new address and port

2010-01-04 21:39:59 sip port 26 call 0x97a47c0 txn 0x979f7f8 127.0.1.1:5061 find new address and port

2010-01-04 21:39:59 sip port 30 write 192.168.2.134:5061 -> 172.16.67.192:5060 (13,539)

2010-01-04 21:39:59 sip port 30 write [(13,539)

50d0a436f6e746163743a207369703a73697070403137322e31362e36372e3139383a34333732350d0a4d61782d466f727761726

4733a2037300d0a5375626a6563743a20506572666f726d616e636520546573740d0a436f6e74656e742d547970653a206170706 c69636174696f6e2f7364700d0a436f6e74656e742d4c656e6774683a20203133380d0a0d0a763d300d0a6f3d757365723120353

3363535373635203233353336383736333720494e20495034203137322e31362e36372e3139380d0a733d2d0d0a633d494e20495

034203137322e31362e36372e3139380d0a743d3020300d0a6d3d617564696f203433373232205254502f41565020300d0a613d7

274706d61703a302050434d552f383030300d0a)(INVITE sip:service@172.16.67.192:5060 SIP/2.0..Via: SIP/2.0/UDP

172.16.67.198:52065;branch=z9hG4bK-6827-620-0..From: sipp ;tag=6827SIPpTag00620..To: sut ..Call-ID: 620-

6827@127.0.1.1..CSeq: 1 INVITE..Contact: sip:sipp@172.16.67.198:43725..Max-Forwards: 70..Subject: Performance Test..Content-Type: application/sdp..Content-Length: 138….v=0..o=user1 53655765 2353687637

IN IP4 172.16.67.198..s=-..c=IN IP4 172.16.67.198..t=0 0..m=audio 43722 RTP/AVP 0..a=rtpmap:0

PCMU/8000..)]

 

SIP–proxy filter per VDOM

You can use the diagnose sys sip-proxy xxx command in a VDOM to get info about how SIP is operating in each VDOM.

 

SIP–proxy filter command

Use the diagnose system sip-proxy filter to filter diagnose information for the SIP ALG. The following filters are available:

 

diag sys sip-proxy filter vd

diag sys sip-proxy filter dst-addr4 diag sys sip-proxy filter dst-addr6 diag sys sip-proxy filter dst-port

diag sys sip-proxy filter identity-policy diag sys sip-proxy filter negate

diag sys sip-proxy filter policy

diag sys sip-proxy filter policy-type diag sys sip-proxy filter profile-group diag sys sip-proxy filter src-addr4

diag sys sip-proxy filter src-addr6 diag sys sip-proxy filter src-port diag sys sip-proxy filter vd

diag sys sip-proxy filter voip-profile

You can clear, view and negate/invert the sense of a filter using these commands:

 

diag sys sip-proxy filter clear diag sys sip-proxy filter list diag sys sip-proxy filter negate

 

SIP debug log filtering

You can filter by VDOM/IP/PORT and by policy and VoIP profile. The filtering can be controlled by:

diagnose system sip-proxy log-filter

 

The list of filters is:

diag sys sip-proxy log-filter vd

diag sys sip-proxy log-filter dst-addr4 diag sys sip-proxy log-filter dst-addr6 diag sys sip-proxy log-filter dst-port

diag sys sip-proxy log-filter identity-policy diag sys sip-proxy log-filter policy

diag sys sip-proxy log-filter policy-type diag sys sip-proxy log-filter profile-group diag sys sip-proxy log-filter src-addr4

diag sys sip-proxy log-filter src-addr6

diag sys sip-proxy log-filter src-port diag sys sip-proxy log-filter vd

diag sys sip-proxy log-filter voip-profile

 

You can clear, view and negate/invert the sense of a filter using these commands:

diag sys sip-proxy log-filter clear diag sys sip-proxy log-filter list diag sys sip-proxy log-filter negate

 

SIP debug setting

Control of the SIP debug output is governed by the following command

diagnose debug application sip <debug_level_int>

Where the <debug_level_int> is a bitmask and the individual values determine whether the listed items are logged or not. The <debug_level_int> can be:

1                                 Configuration changes, mainly addition/deletion/modification of virtual domains.

2                                 TCP connection accepts or connects, redirect creation.

4                                 Create or delete a session.

16                               Any IO read or write.

32                               An ASCII dump of all data read or written.

64                               Include HEX dump in the above output.

128                             Any activity related to the use of the FortiCarrier dynamic profile feature to determine the correct profile-group to use.

256                             Log summary of interesting fields in a SIP call.

1024                           Any activity related to SIP geo-redundancy.

2048                           Any activity related to HA syncing of SIP calls.

 

Display SIP rate-limit data

You can use the diagnose sys sip-proxy meters command to display SIP rate limiting data. For the following command output rate 1 shows that the current (over last second) measured rate for INVITE/ACK and BYTE was 1 per second, the peak 1 shows that the peak rate recorded is 1 per second, the max 0 shows that there is no maximum limit set, the count 18 indicates that 18 messages were received and drop 0 indicates that none were dropped due to being over the limit.

diag sys sip-proxy meters sip

sip vd: 0

sip policy: 1

sip identity-policy: 0 sip policy-type: IPv4

sip profile-group:

sip dialogs: 18

sip dialog-limit: 0

sip UNKNOWN: rate 0 peak 0 max 0 count 0 drop 0 sip ACK: rate 1 peak 1 max 0 count 18 drop 0

sip BYE: rate 1 peak 1 max 0 count 18 drop 0 sip CANCEL: rate 0 peak 0 max 0 count 0 drop 0 sip INFO: rate 0 peak 0 max 0 count 0 drop 0

sip INVITE: rate 1 peak 1 max 0 count 18 drop 0 sip MESSAGE: rate 0 peak 0 max 0 count 0 drop 0 sip NOTIFY: rate 0 peak 0 max 0 count 0 drop 0 sip OPTIONS: rate 0 peak 0 max 0 count 0 drop 0 sip PRACK: rate 0 peak 0 max 0 count 0 drop 0 sip PUBLISH: rate 0 peak 0 max 0 count 0 drop 0 sip REFER: rate 0 peak 0 max 0 count 0 drop 0

sip REGISTER: rate 0 peak 0 max 0 count 0 drop 0 sip SUBSCRIBE: rate 0 peak 0 max 0 count 0 drop 0 sip UPDATE: rate 0 peak 0 max 0 count 0 drop 0

sip PING: rate 0 peak 0 max 0 count 0 drop 0

sip YAHOOREF: rate 0 peak 0 max 0 count 0 drop 0