Call Flow Traces
This section discusses call flow through examples from the Unified Communications Manager trace file CCM000000000. The traces in this case study focus only on the call flow itself. See topics related to Cisco Unified IP Phone calls for detailed trace information (for example, initialization, registration, and the keepalive mechanism).
In this call flow, a Cisco Unified IP Phone (directory number 1001) that is located in cluster 2 calls a phone (directory number 3333) that is located somewhere on the PSTN. Remember that you can follow a device through the trace by looking at the TCP handle value, time stamp, or name of the device. The TCP handle value for the device remains the same until the device is rebooted or goes off line.
In the following traces, the Cisco Unified IP Phone (1001) went off hook. The trace shows the unique messages, TCP handle, and the calling number, which displays on the Cisco Unified IP Phone Phone. No called number displays at this point, because the user did not try to dial any digits.
16:05:46.37515:20:18.390 CCM|StationInit - InboundStim - OffHookMessageID tcpHandle=0x5138d98 15:20:18.390 CCM|StationD - stationOutputDisplayText tcpHandle=0x5138d98, Display=1001
In the following traces, the user dials the DN 3333, one digit at a time. The number 3333 specifies the destination number of the phone, which is located somewhere on the PSTN network. The digit analysis process of the Unified Communications Managercurrently active analyzes the digits to discover where the call needs to get routed. See topics related to Cisco Unified IP Phone calls for more details about digit analysis.
15:20:18.390 CCM|Digit analysis: match(fqcn="", cn="1001", pss="", dd="")15:20:19.703 CCM|Digit analysis: match(fqcn="", cn="1001", pss="", dd="3") 15:20:20.078 CCM|Digit analysis: match(fqcn="", cn="1001", pss="", dd="33") 15:20:20.718 CCM|Digit analysis: match(fqcn="", cn="1001", pss="", dd="333") 15:20:21.421 CCM|Digit analysis: match(fqcn="", cn="1001", pss="", dd="3333") 15:20:21.421 CCM|Digit analysis: analysis results
In the following traces, the digit analysis completed, calling and called party are matched, and the information was parsed.
|CallingPartyNumber=1001|DialingPattern=3333 |DialingRoutePatternRegularExpression=(3333) |PretransformDigitString=3333 |PretransformPositionalMatchList=3333 |CollectedDigits=3333 |PositionalMatchList=3333
In the following traces, the number 0 indicates the originating location, and the number 1 indicates the destination location. BW = -1 determines the bandwidth of the originating location. The value -1 implies that the bandwidth is infinite. The bandwidth gets considered as infinite because the call originated from a Cisco Unified IP Phone that is located in a LAN environment. BW = 64 determines the bandwidth of the destination location. The call destination specifies a phone that is located in a PSTN, and the codec type that is used specifies G.711 (64 Kbps).
15:20:21.421 CCM|Locations:Orig=0 BW=-1 Dest=1 BW=64 (-1 implies infinite bw available)
The following traces show the calling and called party information. In this example, the calling party name and number remain the same because the administrator did not configure a display name, such as John Smith.
15:20:21.421 CCM|StationD - stationOutputCallInfo CallingPartyName=1001, CallingParty=1001, CalledPartyName=, CalledParty=3333, tcpHandle=0x5138d98
The following trace shows that the H.323 code initialized and is sending an H.225 setup message. You can also see the traditional HDLC SAPI messages, the IP address of the called side in hexidecimal, and the port numbers.
15:20:21.421 CCM|Out Message -- H225SetupMsg -- Protocol= H225Protocol15:20:21.421 CCM|MMan_Id= 1. (iep= 0 dsl= 0 sapi= 0 ces= 0 IpAddr=e24610ac IpPort=47110)
The following trace shows the calling and called party information as well as the H.225 alerting message. The trace also shows is the mapping of a Cisco Unified IP Phone hexidecimal value to the IP address. The IP address of theCisco Unified IP Phone (1001) specifies 172.16.70.231.
15:20:21.437 CCM|StationD - stationOutputCallInfo CallingPartyName=1001, CallingParty=1001, CalledPartyName=, CalledParty=3333, tcpHandle=0x5138d9815:20:21.453 CCM|In Message -- H225AlertMsg -- Protocol= H225Protocol 15:20:21.953 CCM|StationD - stationOutputOpenReceiveChannel tcpHandle=0x5138d98 myIP: e74610ac (172.16.70.231)
The following trace shows the compression type that is used for this call (G.711 mu-law).
15:20:21.953 CCM|StationD - ConferenceID: 0 msecPacketSize: 20 compressionType:(4)Media_Payload_G711Ulaw64k
After the H.225 alert message get sent, H.323 initializes H.245. The following trace shows the calling and called party information, and the H.245 messages. The TCP handle value remains the same as before, which indicates that this is the continuation of the same call.
ONE FOR EACH Channel- 16:53:36.855 CCM|H245Interface(3) paths established ip = e98e6b80, port = 1304|<CT::1,100,105,1.1682><IP::128.107.142.233>ONE FOR EACH Channel- 16:53:37.199 CCM|H245Interface(3) OLC outgoing confirm ip = b870701, port = 49252|<CT::1,100,128,3.9><IP::1.7.135.11> H323 EP has answered the call and H245 channel setup in progress: 16:53:13.479 CCM|In Message -- H225ConnectMsg -- Protocol= H225Protocol| 16:03:25.359 CCM|StationD(1): TCPPid = [1.100.117.1] CallInfo callingPartyName='' callingParty=13001 cgpnVoiceMailbox= calledPartyName='' calledParty=11002 cdpnVoiceMailbox= originalCalledPartyName='' originalCalledParty=11002 originalCdpnVoiceMailbox= originalCdpnRedirectReason=0 lastRedirectingPartyName='' lastRedirectingParty=11002 lastRedirectingVoiceMailbox= lastRedirectingReason=0 callType=2(OutBound) lineInstance=1 callReference=16777217. version: 0|<CT::1,100,11,2.1><IP::><DEV::> 16:03:25.328 CCM|StationD(1): TCPPid = [1.100.117.1] OpenReceiveChannel conferenceID=16777217 passThruPartyID=16777233 millisecondPacketSize=20 compressionType=4(Media_Payload_G711Ulaw64k) qualifierIn=?. myIP: e98e6b80 (128.107.142.233)|<CT::1,100,11,1.1><IP::><DEV::> 16:03:25.359 CCM|StationD(2): TCPPid = [1.100.117.2] StartMediaTransmission conferenceID=16777218 passThruPartyID=16777249 remoteIpAddress=e98e6b80(64.255.0.0) remotePortNumber=65344 milliSecondPacketSize=20 compressType=4(Media_Payload_G711Ulaw64k) qualifierOut=?. myIP: e98e6b80 (128.107.142.233)|<CT::1,100,105,1.213><IP::128.107.142.233> 16:03:25.375 CCM|StationD(2): TCPPid = [1.100.117.2] star_StationOutputStartMultiMediaTransmission conferenceID=16777218 passThruPartyID=16777250 remoteIpAddress=e98e6b80(66.255.0.0) remotePortNumber=65346 compressType=101(Media_Payload_H263) qualifierOut=?. myIP: e98e6b80 (128.107.142.233)|<CT::1,100,105,1.215><IP::128.107.142.233> 16:03:25.328 CCM|StationD(1): TCPPid=[1.100.117.1] OpenMultiReceiveChannel conferenceID=16777217 passThruPartyID=1000011 compressionType=101(Media_Payload_H263) qualifierIn=?. myIP: e98e6b80 (128.107.142.233)|<CT::1,100,11,1.1><IP::><DEV::>
The following trace shows the H.225 connection message as well as other information. When the H.225 connection message is received, the call connects.
15:20:22.968 CCM|In Message -- H225ConnectMsg -- Protocol= H225Protocol15:20:22.968 CCM|StationD - stationOutputCallInfo CallingPartyName=1001, CallingParty=1001, CalledPartyName=, CalledParty=3333, tcpHandle=0x5138d98 15:20:22.062 CCM|MediaCoordinator - wait_AuConnectInfoInd 15:20:22.062 CCM|StationD - stationOutputStartMediaTransmission tcpHandle=0x5138d98 myIP: e74610ac (172.16.70.231) 15:20:22.062 CCM|StationD - RemoteIpAddr: e24610ac (172.16.70.226) RemoteRtpPortNumber: 16758 msecPacketSize: 20 compressionType:(4)Media_Payload_G711Ulaw64k 15:20:22.062 CCM|Locations:Orig=0 BW=-1Dest=1 BW=6(-1 implies infinite bw available) 16:03:25.359 CCM|MediaManager(1) - wait_AuConnectInfo - recieved response, fowarding, CI(16777217,16777218)|<CT::1,100,105,1.213><IP::128.107.142.233> 16:03:25.359 CCM|MediaCoordinator - wait_AuConnectInfoInd|<CT::1,100,105,1.213><IP::128.107.142.233> 16:03:25.359 CCM|ConnectionManager - wait_AuConnectInfoInd, CI(16777217,16777218)|<CT::1,100,105,1.213><IP::128.107.142.233>
The following message shows that an on-hook message from the Cisco Unified IP Phone (1001) is being received. As soon as an on-hook message is received, the H.225 and Skinny Station device disconnection messages get sent, and the entire H.225 message displays. This final message indicates that the call terminated.
15:20:27.296 CCM|StationInit - InboundStim - OnHookMessageID tcpHandle=0x5138d9815:20:27.296 CCM|ConnectionManager -wait_AuDisconnectRequest (16777247,16777248): STOP SESSION 15:20:27.296 CCM|MediaManager - wait_AuDisconnectRequest - StopSession sending disconnect to (64,5) and remove connection from list 15:20:27.296 CCM| Device SEP003094C26105 , UnRegisters with SDL Link to monitor NodeID= 1 15:20:27.296 CCM|StationD - stationOutputCloseReceiveChannel tcpHandle=0x5138d98 myIP: e74610ac (172.16.70.231) 15:20:27.296 CCM|StationD - stationOutputStopMediaTransmission tcpHandle=0x5138d98 myIP: e74610ac (172.16.70.231) 15:20:28.328 CCM|In Message -- H225ReleaseCompleteMsg -- Protocol= H225Protocol 16:03:33.344 CCM|StationInit - InboundStim - StationOnHookMessageID: Msg Size(received, defined) = 4, 12|<CT::1,100,105,1.219><IP::128.107.142.233> 16:03:33.359 CCM|ConnectionManager - wait_AuDisconnectRequest(16777217,16777218): STOP SESSION|<CT::1,100,105,1.219><IP::128.107.142.233> 16:03:33.359 CCM|StationD(2): TCPPid = [1.100.117.2] CloseReceiveChannel conferenceID=16777218 passThruPartyID=16777249. myIP: e98e6b80 (128.107.142.233)|<CT::1,100,105,1.219><IP::128.107.142.233> 16:03:33.359 CCM|StationD(2): TCPPid = [1.100.117.2] StopMediaTransmission conferenceID=16777218 passThruPartyID=16777249. myIP: e98e6b80 (128.107.142.233)|<CT::1,100,105,1.219><IP::128.107.142.233> 16:03:33.359 CCM|StationD(2): TCPPid = [1.100.117.2] star_StationOutputCloseMultiMediaReceiveChannel conferenceID=16777218 passThruPartyID=16777249. myIP: e98e6b80 (128.107.142.233)|<CT::1,100,105,1.219><IP::128.107.142.233> 16:03:33.359 CCM|StationD(2): TCPPid = [1.100.117.2] star_StationOutputStopMultiMediaTransmission conferenceID=16777218 passThruPartyID=16777250. myIP: e98e6b80 (128.107.142.233)|<CT::1,100,105,1.219><IP::128.107.142.233>