Understanding Sip Traces
Understanding Sip Traces
Understanding Sip Traces
SIP traces provide key information in troubleshooting SIP Trunks, SIP endpoints
and other SIP related issues. Even though these traces are in clear text, these
texts can be gibberish unless you understand fully what they mean.
This document attempts to break down each component of the SIP interaction
using a practical approach. We will look at various logs, the SIP messages,
headers, SDP information and try to figure out what is going on in a sip voice call
transaction.
In as much as I will try to define the under lying layer of the SIP messaging, this
document will not go into in-depth analysis of the SIP protocol, so it is advisable
to understand SIP protocol technology to be able to understand sip traces.
One key element of troubleshooting is this: To fix a problem, you need to
understand the issue, how it works before you can restore it to order.
One popular debug used in troubleshooting a sip solution on a cisco IOS router is
“Debug ccsip messages”.
To understand The output generated by this debug..We need to understand the
Key/fundamental sip messages exchanged during a sip voice call..
1. Invite
2. Trying
3. Ringing
4. ACK
5. OK
We will look at these messages as we try to understand the debugs. These
messages are key in knowing what’s going on. They help us to understand the
language been spoken so we are not lost like a non French speaking man in Paris!
Ok enough of grammars, lets dive in! Ready?
INVITE:
An Invite is a SIP requests called methods. There are Six SIP methods described in
the SIP specification document RFC 3261 [1].
The INVITE, REGISTER, BYE, ACK, CANCEL, and OPTIONS methods are the original
six methods
in SIP.
The INVITE method is used to establish media sessions between user agents. In
telephony, it is similar to a Setup message in ISDN
An INVITE usually has a message body containing the media information
of the caller. The message body can also contain other session information, such
as a resource list in the case of an early offer. If an INVITE does not contain media
information, the ACK contains the media information of the UAC.
To identify the caller, the called number, the media information and resources
advertised in the Invite, SIP invites use headers. Headers are key parameters
within the SIP invite and we shall look at them so as to gain full clarity of what’s
going on.
Let’s look at a sample SIP trace from CUCM. Note this is very similar to what a
debug ccsip messages will produce on a CUBE gateway.
v=0
o=CiscoSystemsCCM-SIP 811669 1 IN IP4 10.105.40.14
s=SIP Call
c=IN IP4 10.133.92.102
t=0 0
m=audio 25268 RTP/AVP 18 101
a=rtpmap:18 G729/8000
a=ptime:20
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
Via
To
From
Call-ID
CSeq
Contact
Max-Forwards
Expires
This is the first part of the trace usually refrred to as the Request-URI This shows
four key things
1. The called number
2. The device responsible for the called number or the device through which the
called number will be routed
3. SIP Port number
4. Sip Version..
The required Via header field is used to record the SIP route taken by a request
and is used to route a response back to the originator. A UA generating a request
records its own address in a Via header field.
Here we see that CUCM is the UA generating this invite and it stamps it IP on the
call. This helps identify the origin of the call.
Via header fields contain protocol name, version number, and transport
(SIP/2.0/UDP, SIP/2.0/TCP, etc)
From: <sip:01214248526@10.105.80.114>;tag=25526~ffa80926-5fac-4dd6-
b405-2dbbc56ae9a2-551664735
To:sip:14107584528207@10.105.80.174
The next header fields are the To and From header fields, which show the
originator and destination of the SIP request.
Note that the To and From header fields are not reversed in the response
message as one might expect them to be. This is because the To and From
header fields in SIP are defi ned to indicate the direction of the request, not the
direction of the message. Since <sip:01214248526@10.105.80.114 initiated this
request, all responses to this INVITE will read
To:sip:14107584528207@10.105.80.174
From: <sip:01214248526@10.105.80.114.
Date Header:
A key component of the sip message. Its tells us the time of the sip request.
Call ID:
Call-ID: 68781700-f791ec0f-2d26-e28690a@10.105.80.114
The Call-ID header field is an identifier used to keep track of a particular SIP
session. The originator of the request creates a locally unique string. Some older
implementations also add an “@” and its host name to the string. The initiator of
the session that generates the establishing INVITE generates the unique Call-ID
and From tag.
Cseq Header:
User-Agent: Cisco-CUCM8.6
The SDP extensions used in the application/SDP header lists the media
capabilities the calling party is willing to receive or negotiate or support for the
session. The table below shows the SDP attributes in this test call and the
meaning of each attribute/extension. Please note that The RFC 3264[17] specifies
that the attributes containing “a=rtpmap” should be used for each media field
This line defines the media attribtes that will be used for the call.
Audio: means that this is an Audio call, we can also have m=video in case of a
Video call
25268: Is the dynamic RTP port used for the call
RTP/AVP: Represents the RTP/AVP profile number for each of the profiles listed.
The profile numbers are explained below
18=G729
0=PCMU
8=PCMA
101=rtp-nte payload
Now we have looked at the basics of sip headers and messages, lets use this to
understand the following sip trace
The call flow for this call is as shown:
PSTN-------->ITSP------->CUBE--------------->CUCM---------------->IP PHONE
ITSP: 10.10.33.132
CUBE:10.100.0.74
CUCM:10.100.0.14
1.An inbound call is received on the CUBE from the ITSP. This invite was sent with
SDP. NB that this inbound leg of this call will have a unique call ID that shows the
origin of the call, highlighted below.
Received:
INVITE sip:441127653485@10.100.0.74:5060 SIP/2.0
Via: SIP/2.0/UDP 10.10.33.24:5070;branch=z9hG4bK9377fo00cg5ha7l0g3t0.1
From: <sip:07455900064@212.136.178.216:5060;user=phone>;tag=1526438727-
1338998848384-
To: "voice-lab-aokanlawon"<sip:441127653485@pbx.emea.ipcom.com>
Call-ID:BW1807283840606121067600210@212.136.178.216
CSeq: 558267841 INVITE
Contact: <sip:07455900064@10.10.33.24:5070;transport=udp>
Allow: ACK,BYE,CANCEL,INFO,INVITE,OPTIONS,PRACK,REFER,NOTIFY
Accept: multipart/mixed,application/media_control+xml,application/sdp
Supported:
Max-Forwards: 69
Content-Type: application/sdp
Content-Length: 207
v=0
o=BroadWorks 161384582 1 IN IP4 10.10.33.132
s=-
c=IN IP4 10.10.33.132
t=0 0
m=audio 11164 RTP/AVP 18 0 8 101
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=fmtp:18 annexb=no
+++From our understanding of the traces, we see that the call originates from a
device called Broadworks, which advertises G711a, G711u, G729 and uses rtp-nte
for DTMF. We also see the IP address for the CUBE to stream its RTP to.+++++
2. A new Invite Sent to CUCM.
After the CUBE receives the invite, it sends an invite to cucm based on the dial-
peers configured.
NB: that this new invite is sent with a new CALL-ID. This is very important in
understanding the order of thigs especially when troubleshooting issues. We can
also see that the CUBE advertises all its SDP attributes, codec, dtmf supported,
fax etc.
3.Next the CUBE sends a trying to ITSP. Trying simply means: I am looking for the
number you have requested.
4.Next the CUBE receives a trying from CUCM. The call-ID help us to know where
these responses are coming from.
5.Next the CUBE receives ringing from CUCM This informs the CUBE that the
called endpoint is ringing
7.Now the CUBE receives a 200 ok from CUCM. Please note that some elements
of the SDP has changed
9.CUBE then sends a 200 OK to ITSP with the SDP attributes to use for the Call
based on what it received from CUCM.
Sent:
SIP/2.0 200 OK
Via: SIP/2.0/TCP 10.100.0.14:5060;branch=z9hG4bK198a0b7ee5d33c
From: <sip:901127653485@10.100.0.14>;tag=811674~ffa80926-5fac-4dd6-b405-
2dbbc56ae9a2-477917854
To: <sip:07455900064@10.100.0.74>;tag=4C85762C-1A2D
Date: Wed, 06 Jun 2012 16:07:28 GMT
Call-ID:8C394872-AF2811E1-95E98F4D-5D7E5E41@10.100.0.74
CSeq: 101 SUBSCRIBE
Content-Length: 0
Contact: <sip:07455900064@10.100.0.74:5060;transport=tcp>
Expires: 7200
Sent:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.10.33.24:5070;branch=z9hG4bK9377fo00cg5ha7l0g3t0.1
From: <sip:07455900064@212.136.178.216:5060;user=phone>;tag=1526438727-
1338998848384-
To: "voice-lab-aokanlawon"<sip:441127653485@pbx.emea.ipcom.com>;tag=4C85763E-
1CF8
Date: Wed, 06 Jun 2012 16:07:28 GMT
Call-ID:BW1807283840606121067600210@212.136.178.216
CSeq: 558267841 INVITE
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE,
NOTIFY, INFO, REGISTER
Allow-Events: kpml, telephone-event
Remote-Party-ID: <sip:901926653485@10.100.0.74>;party=called;screen=no;privacy=off
Contact: <sip:441127653485@10.100.0.74:5060>
Supported: replaces
Supported: sdp-anat
Server: Cisco-SIPGateway/IOS-12.x
Supported: timer
Content-Type: application/sdp
Content-Disposition: session;handling=required
Content-Length: 270
v=0
o=CiscoSystemsSIP-GW-UserAgent 7413 6169 IN IP4 10.100.0.74
s=SIP Call
c=IN IP4 10.100.0.74
t=0 0
m=audio 29626 RTP/AVP 18 101
c=IN IP4 10.100.0.74
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
10.CUBE then receives an ACK
11.Finally the call is ended. Now when troubleshooting the direction of call
termination is important. In this case we can see that the CUBE receives a BYE,
which is the sip method for call termination. However who sent the BYE, is it
CUCM or ITSP…The answer is in the Call-ID. As we call can see the CALL-ID is for
the leg from the ITSP. So we see that the call was terminated from the ITSP side.
Next important thing is the cause code. The reason why the call was terminated.
Received:
BYE sip:441127653485@10.100.0.74:5060 SIP/2.0
Via: SIP/2.0/UDP 10.10.33.24:5070;branch=z9hG4bKfj8rji3008r0m4lbg7e0cd1hhq713.1
From: <sip:07455900064@212.136.178.216:5060;user=phone>;tag=1526438727-
1338998848384-
To: "voice-lab-aokanlawon"<sip:441127653485@pbx.emea.ipcom.com>;tag=4C85763E-
1CF8
Call-ID:BW1807283840606121067600210@212.136.178.216
CSeq: 558267842 BYE
Max-Forwards: 69
Content-Length: 0
002809: Jun 6 16:07:34.470: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.10.33.24:5070;branch=z9hG4bKfj8rji3008r0m4lbg7e0cd1hhq713.1
From: <sip:07455900064@212.136.178.216:5060;user=phone>;tag=1526438727-
1338998848384-
To: "voice-lab-aokanlawon"<sip:441127653485@pbx.emea.ipcom.com>;tag=4C85763E-
1CF8
Date: Wed, 06 Jun 2012 16:07:34 GMT
Call-ID:BW1807283840606121067600210@212.136.178.216
Server: Cisco-SIPGateway/IOS-12.x
CSeq: 558267842 BYE
Reason: Q.850;cause=16
P-RTP-Stat: PS=295,OS=5900,PR=292,OR=5840,PL=0,JI=0,LA=0,DU=5
Content-Length: 0