Tuesday, November 27, 2012

Cisco VoIP Gateway: Watching A SIP Call Come Into The H323 Gateway

Have you ever needed to see if a call was coming in on your SIP trunk so that you could verify that the call was actually getting to your gateway?  Well, I did today to troubleshoot an issue on our hosted VoIP solution.  Here is what I did on the Cisco router to do some troubleshooting:
debug ccsip messages
debug voip ccapi inout
term mon
conf t
logg mon
logg on
exit

With these commands in place, I placed the call in and verified that the call actually did come in.
Calling number is 205.555.1234
Called number is 205.444.5678
2.2.2.2, 3.3.3.3, and 4.4.4.4 represent the SIP carrier.
10.10.10.10 represents my gateway

Here is the capture.  I just think its interesting:
101892: .Nov 27 17:33:05.026: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
INVITE sip:2054445678@10.10.10.10:5060 SIP/2.0
Via: SIP/2.0/UDP 2.2.2.2:5060;branch=z9hG4bK05Bbcbd728f10b75fab
From: "KILLEN,SHANE" <sip:2055551234@2.2.2.2;pstn-params=9084818088;cpc=ordinary>;tag=gK054ac3ea
To: <sip:2054445678@10.10.10.10>
Call-ID: 990183475_22697175@2.2.2.2
CSeq: 10426 INVITE
Max-Forwards: 66
Allow: INVITE,ACK,CANCEL,BYE,REGISTER,REFER,INFO,SUBSCRIBE,NOTIFY,PRACK,UPDATE,OPTIONS
Accept: application/sdp, application/isup, application/dtmf, application/dtmf-relay,  multipart/mixed
Contact: "KILLEN,SHANE" <sip:2055551234@2.2.2.2:5060>
Remote-Party-ID: "KILLEN,SHANE" <sip:2055551234@2.2.2.2:5060>;privacy=off
Supported: timer
Session-Expires: 1800
Min-SE: 90
Content-Length:  305
Content-Disposition: session; handling=required
Content-Type: application/sdp

v=0
o=Sonus_UAC 25520 6934 IN IP4 2.2.2.2
s=SIP Media Capabilities
c=IN IP4 3.3.3.3
t=0 0
m=audio 24546 RTP/AVP 0 18 8 101
a=rtpmap:0 PCMU/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendrecv
a=ptime:20

101893: .Nov 27 17:33:05.038: //46270/xxxxxxxxxxxx/CCAPI/cc_api_caps_ind:
   Call Entry Is Not Found
101894: .Nov 27 17:33:05.038: //-1/55C5A9C7B288/CCAPI/cc_api_display_ie_subfields:
   cc_api_call_setup_ind_common:
   cisco-username=2055551234
   ----- ccCallInfo IE subfields -----
   cisco-ani=sip:2055551234@2.2.2.2;pstn-params=9084818088;cpc=ordinary
   cisco-anitype=0
   cisco-aniplan=0
   cisco-anipi=0
   cisco-anisi=0
   dest=sip:2054445678@10.10.10.10:5060
   cisco-desttype=0
   cisco-destplan=0
   cisco-rdie=FFFFFFFF
   cisco-rdn=
   cisco-rdntype=0
   cisco-rdnplan=0
   cisco-rdnpi=-1
   cisco-rdnsi=-1
   cisco-redirectreason=-1   fwd_final_type =0
   final_redirectNumber =
   hunt_group_timeout =0

101895: .Nov 27 17:33:05.042: //-1/55C5A9C7B288/CCAPI/cc_api_call_setup_ind_common:
   Interface=0x471F0134, Call Info(
   Calling Number=sip:2055551234@2.2.2.2;pstn-params=9084818088;cpc=ordinary,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
   Called Number=sip:2054445678@10.10.10.10:5060(TON=Unknown, NPI=Unknown),
   Calling Translated=FALSE, Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE,
   Incoming Dial-peer=16, Progress Indication=NULL(0), Calling IE Present=TRUE,
   Source Trkgrp Route Label=, Target Trkgrp Route Label=, CLID Transparent=FALSE), Call Id=46270
101896: .Nov 27 17:33:05.042: //-1/55C5A9C7B288/CCAPI/ccCheckClipClir:
   In: Calling Number=sip:2055551234@2.2.2.2;pstn-params=9084818088;cpc=ordinary(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
101897: .Nov 27 17:33:05.042: //-1/55C5A9C7B288/CCAPI/ccCheckClipClir:
   Out: Calling Number=sip:2055551234@2.2.2.2;pstn-params=9084818088;cpc=ordinary(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
101898: .Nov 27 17:33:05.042: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
101899: .Nov 27 17:33:05.042: :cc_get_feature_vsa malloc success
101900: .Nov 27 17:33:05.042: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
101901: .Nov 27 17:33:05.042:  cc_get_feature_vsa count is 5
101902: .Nov 27 17:33:05.042: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
101903: .Nov 27 17:33:05.042: :FEATURE_VSA attributes are: feature_name:0,feature_time:1185232256,feature_id:46019
101904: .Nov 27 17:33:05.046: //46270/55C5A9C7B288/CCAPI/cc_api_call_setup_ind_common:
   Set Up Event Sent;
   Call Info(Calling Number=(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
   Called Number=(TON=Unknown, NPI=Unknown))
101905: .Nov 27 17:33:05.050: //46270/55C5A9C7B288/CCAPI/cc_process_call_setup_ind:
   Event=0x4735E310
101906: .Nov 27 17:33:05.050: //46270/55C5A9C7B288/CCAPI/ccCallSetContext:
   Context=0x47CFA438
101907: .Nov 27 17:33:05.050: //46270/55C5A9C7B288/CCAPI/cc_process_call_setup_ind:
   >>>>CCAPI handed cid 46270 with tag 16 to app "_ManagedAppProcess_Default"
101908: .Nov 27 17:33:05.054: //46270/55C5A9C7B288/CCAPI/ccCallProceeding:
   Progress Indication=NULL(0)
101909: .Nov 27 17:33:05.054: //-1/xxxxxxxxxxxx/CCAPI/ccGetMemPoolFromContainer:
   mempool not found from usrContainer(47BBA098)
101910: .Nov 27 17:33:05.054: //-1/xxxxxxxxxxxx/CCAPI/ccCreateMemPoolInContainer:
   Mempool(46A266E0) created in usrContainer(47BBA098)
101911: .Nov 27 17:33:05.058: //46270/55C5A9C7B288/CCAPI/ccCallSetupRequest:
   Destination=, Calling IE Present=TRUE, Mode=0,
   Outgoing Dial-peer=111, Params=0x45C360DC, Progress Indication=NULL(0)
101912: .Nov 27 17:33:05.058: //46270/55C5A9C7B288/CCAPI/ccCheckClipClir:
   In: Calling Number=sip:2055551234@2.2.2.2;pstn-params=9084818088;cpc=ordinary(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
101913: .Nov 27 17:33:05.058: //46270/55C5A9C7B288/CCAPI/ccCheckClipClir:
   Out: Calling Number=sip:2055551234@2.2.2.2;pstn-params=9084818088;cpc=ordinary(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
101914: .Nov 27 17:33:05.058: //46270/55C5A9C7B288/CCAPI/ccCallSetupRequest:
   Destination Pattern=20571669.., Called Number=2054445678, Digit Strip=FALSE
101915: .Nov 27 17:33:05.058: //46270/55C5A9C7B288/CCAPI/ccCallSetupRequest:
   Calling Number=sip:2055551234@2.2.2.2;pstn-params=9084818088;cpc=ordinary(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
   Called Number=2054445678(TON=Unknown, NPI=Unknown),
   Redirect Number=, Display Info=KILLEN,SHANE
   Account Number=2055551234, Final Destination Flag=TRUE,
   Guid=55C5A9C7-37EF-11E2-B288-D61E695CAF39, Outgoing Dial-peer=111
101916: .Nov 27 17:33:05.058: //46270/55C5A9C7B288/CCAPI/cc_api_display_ie_subfields:
   ccCallSetupRequest:
   cisco-username=2055551234
   ----- ccCallInfo IE subfields -----
   cisco-ani=sip:2055551234@2.2.2.2;pstn-params=9084818088;cpc=ordinary
   cisco-anitype=0
   cisco-aniplan=0
   cisco-anipi=0
   cisco-anisi=0
   dest=2054445678
   cisco-desttype=0
   cisco-destplan=0
   cisco-rdie=FFFFFFFF
   cisco-rdn=
   cisco-rdntype=0
   cisco-rdnplan=0
   cisco-rdnpi=-1
   cisco-rdnsi=-1
   cisco-redirectreason=-1   fwd_final_type =0
   final_redirectNumber =
   hunt_group_timeout =0

101917: .Nov 27 17:33:05.062: //46270/55C5A9C7B288/CCAPI/ccIFCallSetupRequestPrivate:
   Interface=0x46F4AAA8, Interface Type=1, Destination=, Mode=0x0,
   Call Params(Calling Number=sip:2055551234@2.2.2.2;pstn-params=9084818088;cpc=ordinary,(Calling Name=KILLEN,SHANE)(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
   Called Number=2054445678(TON=Unknown, NPI=Unknown), Calling Translated=FALSE,
   Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE, Outgoing Dial-peer=111, Call Count On=FALSE,
   Source Trkgrp Route Label=, Target Trkgrp Route Label=, tg_label_flag=0, Application Call Id=)
101918: .Nov 27 17:33:05.062: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
  101919: .Nov 27 17:33:05.062: :cc_get_feature_vsa malloc success
101920: .Nov 27 17:33:05.062: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
  101921: .Nov 27 17:33:05.062:  cc_get_feature_vsa count is 6
101922: .Nov 27 17:33:05.062: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
  101923: .Nov 27 17:33:05.062: :FEATURE_VSA attributes are: feature_name:0,feature_time:1185229664,feature_id:46020
101924: .Nov 27 17:33:05.062: //46271/55C5A9C7B288/CCAPI/ccIFCallSetupRequestPrivate:
   SPI Call Setup Request Is Success; Interface Type=1, FlowMode=1
101925: .Nov 27 17:33:05.062: //46271/55C5A9C7B288/CCAPI/ccCallSetContext:
   Context=0x45C3608C
101926: .Nov 27 17:33:05.062: //46270/55C5A9C7B288/CCAPI/ccSaveDialpeerTag:
   Outgoing Dial-peer=111
101927: .Nov 27 17:33:05.074: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 2.2.2.2:5060;branch=z9hG4bK05Bbcbd728f10b75fab
From: "KILLEN,SHANE" <sip:2055551234@2.2.2.2;pstn-params=9084818088;cpc=ordinary>;tag=gK054ac3ea
To: <sip:2054445678@10.10.10.10>
Date: Tue, 27 Nov 2012 17:33:05 GMT
Call-ID: 990183475_22697175@2.2.2.2
CSeq: 10426 INVITE
Allow-Events: telephone-event
Server: Cisco-SIPGateway/IOS-12.x
Content-Length: 0

101928: .Nov 27 17:33:05.082: //46271/55C5A9C7B288/CCAPI/cc_api_set_called_ccm_detected:
   CallInfo(called ccm detected=TRUE ccmVersion 3)
101929: .Nov 27 17:33:05.082: //46271/55C5A9C7B288/CCAPI/cc_api_call_proceeding:
   Interface=0x46F4AAA8, Progress Indication=NULL(0)
101930: .Nov 27 17:33:05.082: //46271/55C5A9C7B288/CCAPI/cc_api_call_disconnected:
   Cause Value=27, Interface=0x46F4AAA8, Call Id=46271
101931: .Nov 27 17:33:05.082: //46271/55C5A9C7B288/CCAPI/cc_api_call_disconnected:
   Call Entry(Responsed=TRUE, Cause Value=27, Retry Count=0)
101932: .Nov 27 17:33:05.086: //46270/xxxxxxxxxxxx/CCAPI/ccCallReleaseResources:
   release reserved xcoding resource.
101933: .Nov 27 17:33:05.086: //46271/55C5A9C7B288/CCAPI/ccCallSetAAA_Accounting:
   Accounting=0, Call Id=46271
101934: .Nov 27 17:33:05.086: //46271/55C5A9C7B288/CCAPI/ccCallDisconnect:
   Cause Value=27, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=27)
101935: .Nov 27 17:33:05.086: //46271/55C5A9C7B288/CCAPI/ccCallDisconnect:
   Cause Value=27, Call Entry(Responsed=TRUE, Cause Value=27)
101936: .Nov 27 17:33:05.086: //46271/55C5A9C7B288/CCAPI/cc_api_get_transfer_info:
   Transfer Number Is Null
101937: .Nov 27 17:33:05.086: %VOIPAAA-5-VOIP_CALL_HISTORY: CallLegType 2, ConnectionId 55C5A9C737EF11E2B288D61E695CAF39, SetupTime .17:33:05.066 UTC Tue Nov 27 2012, PeerAddress 2054445678, PeerSubAddress , DisconnectCause 1B  , DisconnectText destination out of order (27), ConnectTime .17:33:05.086 UTC Tue Nov 27 2012, DisconnectTime .17:33:05.086 UTC Tue Nov 27 2012, CallOrigin 1, ChargedUnits 0, InfoType 2, TransmitPackets 0, TransmitBytes 0, ReceivePackets 0, ReceiveBytes 0
101938: .Nov 27 17:33:05.090: //-1/xxxxxxxxxxxx/CCAPI/cc_build_feature_vsa:
  101939: .Nov 27 17:33:05.090: :Inside cc_build_feature_vsa
101940: .Nov 27 17:33:05.090: //-1/xxxxxxxxxxxx/CCAPI/cc_build_feature_vsa:
  101941: .Nov 27 17:33:05.090:  feature call basic
101942: .Nov 27 17:33:05.090: //-1/xxxxxxxxxxxx/CCAPI/cc_build_feature_vsa:
  101943: .Nov 27 17:33:05.090: cc_build_feature_vsa attr is fn:TWC,ft:11/27/2012 17:33:05.062,cgn:2055551234,cdn:2054445678,frs:0,fid:46020,fcid:55C5A9C737EF11E2B288D61E695CAF39,legID:B4BF
101944: .Nov 27 17:33:05.090: %VOIPAAA-5-VOIP_FEAT_HISTORY: FEAT_VSA=fn:TWC,ft:11/27/2012 17:33:05.062,cgn:2055551234,cdn:2054445678,frs:0,fid:46020,fcid:55C5A9C737EF11E2B288D61E695CAF39,legID:B4BF,bguid:55C5A9C737EF11E2B288D61E695CAF39
101945: .Nov 27 17:33:05.094: //46271/55C5A9C7B288/CCAPI/cc_api_call_disconnect_done:
   Disposition=0, Interface=0x46F4AAA8, Tag=0x0, Call Id=46271,
   Call Entry(Disconnect Cause=27, Voice Class Cause Code=0, Retry Count=0)
101946: .Nov 27 17:33:05.094: //46271/55C5A9C7B288/CCAPI/cc_api_call_disconnect_done:
   Call Disconnect Event Sent
101947: .Nov 27 17:33:05.094: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
  101948: .Nov 27 17:33:05.094: :cc_free_feature_vsa freeing 46A52B58
101949: .Nov 27 17:33:05.094: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
  101950: .Nov 27 17:33:05.094:  vsacount in free is 5
101951: .Nov 27 17:33:05.098: //-1/xxxxxxxxxxxx/CCAPI/ccMemPoolTDFreeHelper:
   data = 47BD4924
101952: .Nov 27 17:33:05.098: ccMemPoolTDFreeHelper:mem_mgr_mempool_free: mem_refcnt(46A266E0)=0 - mempool cleanup
101953: .Nov 27 17:33:05.098: //46270/55C5A9C7B288/CCAPI/ccCallDisconnect:
   Cause Value=27, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=0)
101954: .Nov 27 17:33:05.098: //46270/55C5A9C7B288/CCAPI/ccCallDisconnect:
   Cause Value=27, Call Entry(Responsed=TRUE, Cause Value=27)
101955: .Nov 27 17:33:05.102: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 404 Not Found
Via: SIP/2.0/UDP 2.2.2.2:5060;branch=z9hG4bK05Bbcbd728f10b75fab
From: "KILLEN,SHANE" <sip:2055551234@2.2.2.2;pstn-params=9084818088;cpc=ordinary>;tag=gK054ac3ea
To: <sip:2054445678@10.10.10.10>;tag=ECFD05A0-65
Date: Tue, 27 Nov 2012 17:33:05 GMT
Call-ID: 990183475_22697175@2.2.2.2
CSeq: 10426 INVITE
Allow-Events: telephone-event
Server: Cisco-SIPGateway/IOS-12.x
Reason: Q.850;cause=27
Content-Length: 0

101956: .Nov 27 17:33:05.154: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
ACK sip:2054445678@10.10.10.10:5060 SIP/2.0
Via: SIP/2.0/UDP 2.2.2.2:5060;branch=z9hG4bK05Bbcbd728f10b75fab
From: "KILLEN,SHANE" <sip:2055551234@2.2.2.2;pstn-params=9084818088;cpc=ordinary>;tag=gK054ac3ea
To: <sip:2054445678@10.10.10.10>;tag=ECFD05A0-65
Call-ID: 990183475_22697175@2.2.2.2
CSeq: 10426 ACK
Max-Forwards: 70
Content-Length: 0

101957: .Nov 27 17:33:05.154: %VOIPAAA-5-VOIP_CALL_HISTORY: CallLegType 2, ConnectionId 55C5A9C737EF11E2B288D61E695CAF39, SetupTime .17:33:05.044 UTC Tue Nov 27 2012, PeerAddress 2055551234, PeerSubAddress , DisconnectCause 1B  , DisconnectText destination out of order (27), ConnectTime .17:33:05.154 UTC Tue Nov 27 2012, DisconnectTime .17:33:05.154 UTC Tue Nov 27 2012, CallOrigin 2, ChargedUnits 0, InfoType 2, TransmitPackets 0, TransmitBytes 0, ReceivePackets 0, ReceiveBytes 0
101958: .Nov 27 17:33:05.158: //-1/xxxxxxxxxxxx/CCAPI/cc_build_feature_vsa:
  101959: .Nov 27 17:33:05.158: :Inside cc_build_feature_vsa
101960: .Nov 27 17:33:05.158: //-1/xxxxxxxxxxxx/CCAPI/cc_build_feature_vsa:
  101961: .Nov 27 17:33:05.158:  feature call basic
101962: .Nov 27 17:33:05.158: //-1/xxxxxxxxxxxx/CCAPI/cc_build_feature_vsa:
  101963: .Nov 27 17:33:05.158: cc_build_feature_vsa attr is fn:TWC,ft:11/27/2012 17:33:05.042,cgn:2055551234,cdn:2054445678,frs:0,fid:46019,fcid:55C5A9C737EF11E2B288D61E695CAF39,legID:B4BE
101964: .Nov 27 17:33:05.158: %VOIPAAA-5-VOIP_FEAT_HISTORY: FEAT_VSA=fn:TWC,ft:11/27/2012 17:33:05.042,cgn:2055551234,cdn:2054445678,frs:0,fid:46019,fcid:55C5A9C737EF11E2B288D61E695CAF39,legID:B4BE,bguid:55C5A9C737EF11E2B288D61E695CAF39
101965: .Nov 27 17:33:05.158: //46270/55C5A9C7B288/CCAPI/cc_api_call_disconnect_done:
   Disposition=0, Interface=0x471F0134, Tag=0x0, Call Id=46270,
   Call Entry(Disconnect Cause=27, Voice Class Cause Code=0, Retry Count=0)
101966: .Nov 27 17:33:05.158: //46270/55C5A9C7B288/CCAPI/cc_api_call_disconnect_done:
   Call Disconnect Event Sent
101967: .Nov 27 17:33:05.158: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
  101968: .Nov 27 17:33:05.158: :cc_free_feature_vsa freeing 46A53578
101969: .Nov 27 17:33:05.158: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
  101970: .Nov 27 17:33:05.158:  vsacount in free is 4
101971: .Nov 27 17:33:05.234: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
INVITE sip:2054445678@10.10.10.10:5060 SIP/2.0
Via: SIP/2.0/UDP 4.4.4.4:5060;branch=z9hG4bK04Bd7b9194d9fd0ad8e
From: "KILLEN,SHANE" <sip:2055551234@4.4.4.4;pstn-params=9084818088;cpc=ordinary>;tag=gK04172686
To: <sip:2054445678@10.10.10.10>
Call-ID: 263340_8103886@4.4.4.4
CSeq: 1991 INVITE
Max-Forwards: 66
Allow: INVITE,ACK,CANCEL,BYE,REGISTER,REFER,INFO,SUBSCRIBE,NOTIFY,PRACK,UPDATE,OPTIONS
Accept: application/sdp, application/isup, application/dtmf, application/dtmf-relay,  multipart/mixed
Contact: "KILLEN,SHANE" <sip:2055551234@4.4.4.4:5060>
Remote-Party-ID: "KILLEN,SHANE" <sip:2055551234@4.4.4.4:5060>;privacy=off
Supported: timer
Session-Expires: 1800
Min-SE: 90
Content-Length:  306
Content-Disposition: session; handling=required
Content-Type: application/sdp

v=0
o=Sonus_UAC 16277 17782 IN IP4 4.4.4.4
s=SIP Media Capabilities
c=IN IP4 64.158.162.80
t=0 0
m=audio 25842 RTP/AVP 0 18 8 101
a=rtpmap:0 PCMU/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendrecv
a=ptime:20

101972: .Nov 27 17:33:05.246: //46272/xxxxxxxxxxxx/CCAPI/cc_api_caps_ind:
   Call Entry Is Not Found
101973: .Nov 27 17:33:05.250: //-1/55E602D1B28D/CCAPI/cc_api_display_ie_subfields:
   cc_api_call_setup_ind_common:
   cisco-username=2055551234
   ----- ccCallInfo IE subfields -----
   cisco-ani=sip:2055551234@4.4.4.4;pstn-params=9084818088;cpc=ordinary
   cisco-anitype=0
   cisco-aniplan=0
   cisco-anipi=0
   cisco-anisi=0
   dest=sip:2054445678@10.10.10.10:5060
   cisco-desttype=0
   cisco-destplan=0
   cisco-rdie=FFFFFFFF
   cisco-rdn=
   cisco-rdntype=0
   cisco-rdnplan=0
   cisco-rdnpi=-1
   cisco-rdnsi=-1
   cisco-redirectreason=-1   fwd_final_type =0
   final_redirectNumber =
   hunt_group_timeout =0

101974: .Nov 27 17:33:05.250: //-1/55E602D1B28D/CCAPI/cc_api_call_setup_ind_common:
   Interface=0x471F0134, Call Info(
   Calling Number=sip:2055551234@4.4.4.4;pstn-params=9084818088;cpc=ordinary,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
   Called Number=sip:2054445678@10.10.10.10:5060(TON=Unknown, NPI=Unknown),
   Calling Translated=FALSE, Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE,
   Incoming Dial-peer=16, Progress Indication=NULL(0), Calling IE Present=TRUE,
   Source Trkgrp Route Label=, Target Trkgrp Route Label=, CLID Transparent=FALSE), Call Id=46272
101975: .Nov 27 17:33:05.250: //-1/55E602D1B28D/CCAPI/ccCheckClipClir:
   In: Calling Number=sip:2055551234@4.4.4.4;pstn-params=9084818088;cpc=ordinary(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
101976: .Nov 27 17:33:05.250: //-1/55E602D1B28D/CCAPI/ccCheckClipClir:
   Out: Calling Number=sip:2055551234@4.4.4.4;pstn-params=9084818088;cpc=ordinary(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
101977: .Nov 27 17:33:05.250: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
  101978: .Nov 27 17:33:05.250: :cc_get_feature_vsa malloc success
101979: .Nov 27 17:33:05.254: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
  101980: .Nov 27 17:33:05.254:  cc_get_feature_vsa count is 5
101981: .Nov 27 17:33:05.254: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
  101982: .Nov 27 17:33:05.254: :FEATURE_VSA attributes are: feature_name:0,feature_time:1185232256,feature_id:46021
101983: .Nov 27 17:33:05.254: //46272/55E602D1B28D/CCAPI/cc_api_call_setup_ind_common:
   Set Up Event Sent;
   Call Info(Calling Number=(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
   Called Number=(TON=Unknown, NPI=Unknown))
101984: .Nov 27 17:33:05.258: //46272/55E602D1B28D/CCAPI/cc_process_call_setup_ind:
   Event=0x4735E310
101985: .Nov 27 17:33:05.258: //46272/55E602D1B28D/CCAPI/ccCallSetContext:
   Context=0x45C3D44C
101986: .Nov 27 17:33:05.258: //46272/55E602D1B28D/CCAPI/cc_process_call_setup_ind:
   >>>>CCAPI handed cid 46272 with tag 16 to app "_ManagedAppProcess_Default"
101987: .Nov 27 17:33:05.262: //46272/55E602D1B28D/CCAPI/ccCallProceeding:
   Progress Indication=NULL(0)
101988: .Nov 27 17:33:05.262: //-1/xxxxxxxxxxxx/CCAPI/ccGetMemPoolFromContainer:
   mempool not found from usrContainer(47BBE100)
101989: .Nov 27 17:33:05.262: //-1/xxxxxxxxxxxx/CCAPI/ccCreateMemPoolInContainer:
   Mempool(47DD4E08) created in usrContainer(47BBE100)
101990: .Nov 27 17:33:05.266: //46272/55E602D1B28D/CCAPI/ccCallSetupRequest:
   Destination=, Calling IE Present=TRUE, Mode=0,
   Outgoing Dial-peer=111, Params=0x47D06F18, Progress Indication=NULL(0)
101991: .Nov 27 17:33:05.266: //46272/55E602D1B28D/CCAPI/ccCheckClipClir:
   In: Calling Number=sip:2055551234@4.4.4.4;pstn-params=9084818088;cpc=ordinary(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
101992: .Nov 27 17:33:05.266: //46272/55E602D1B28D/CCAPI/ccCheckClipClir:
   Out: Calling Number=sip:2055551234@4.4.4.4;pstn-params=9084818088;cpc=ordinary(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
101993: .Nov 27 17:33:05.266: //46272/55E602D1B28D/CCAPI/ccCallSetupRequest:
   Destination Pattern=20571669.., Called Number=2054445678, Digit Strip=FALSE
101994: .Nov 27 17:33:05.266: //46272/55E602D1B28D/CCAPI/ccCallSetupRequest:
   Calling Number=sip:2055551234@4.4.4.4;pstn-params=9084818088;cpc=ordinary(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
   Called Number=2054445678(TON=Unknown, NPI=Unknown),
   Redirect Number=, Display Info=KILLEN,SHANE
   Account Number=2055551234, Final Destination Flag=TRUE,
   Guid=55E602D1-37EF-11E2-B28D-D61E695CAF39, Outgoing Dial-peer=111
101995: .Nov 27 17:33:05.266: //46272/55E602D1B28D/CCAPI/cc_api_display_ie_subfields:
   ccCallSetupRequest:
   cisco-username=2055551234
   ----- ccCallInfo IE subfields -----
   cisco-ani=sip:2055551234@4.4.4.4;pstn-params=9084818088;cpc=ordinary
   cisco-anitype=0
   cisco-aniplan=0
   cisco-anipi=0
   cisco-anisi=0
   dest=2054445678
   cisco-desttype=0
   cisco-destplan=0
   cisco-rdie=FFFFFFFF
   cisco-rdn=
   cisco-rdntype=0
   cisco-rdnplan=0
   cisco-rdnpi=-1
   cisco-rdnsi=-1
   cisco-redirectreason=-1   fwd_final_type =0
   final_redirectNumber =
   hunt_group_timeout =0

101996: .Nov 27 17:33:05.270: //46272/55E602D1B28D/CCAPI/ccIFCallSetupRequestPrivate:
   Interface=0x46F4AAA8, Interface Type=1, Destination=, Mode=0x0,
   Call Params(Calling Number=sip:2055551234@4.4.4.4;pstn-params=9084818088;cpc=ordinary,(Calling Name=KILLEN,SHANE)(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
   Called Number=2054445678(TON=Unknown, NPI=Unknown), Calling Translated=FALSE,
   Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE, Outgoing Dial-peer=111, Call Count On=FALSE,
   Source Trkgrp Route Label=, Target Trkgrp Route Label=, tg_label_flag=0, Application Call Id=)
101997: .Nov 27 17:33:05.270: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
  101998: .Nov 27 17:33:05.270: :cc_get_feature_vsa malloc success
101999: .Nov 27 17:33:05.270: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
  102000: .Nov 27 17:33:05.270:  cc_get_feature_vsa count is 6
102001: .Nov 27 17:33:05.270: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
  102002: .Nov 27 17:33:05.270: :FEATURE_VSA attributes are: feature_name:0,feature_time:1185229664,feature_id:46022
102003: .Nov 27 17:33:05.270: //46273/55E602D1B28D/CCAPI/ccIFCallSetupRequestPrivate:
   SPI Call Setup Request Is Success; Interface Type=1, FlowMode=1
102004: .Nov 27 17:33:05.270: //46273/55E602D1B28D/CCAPI/ccCallSetContext:
   Context=0x47D06EC8
102005: .Nov 27 17:33:05.270: //46272/55E602D1B28D/CCAPI/ccSaveDialpeerTag:
   Outgoing Dial-peer=111
102006: .Nov 27 17:33:05.298: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 4.4.4.4:5060;branch=z9hG4bK04Bd7b9194d9fd0ad8e
From: "KILLEN,SHANE" <sip:2055551234@4.4.4.4;pstn-params=9084818088;cpc=ordinary>;tag=gK04172686
To: <sip:2054445678@10.10.10.10>
Date: Tue, 27 Nov 2012 17:33:05 GMT
Call-ID: 263340_8103886@4.4.4.4
CSeq: 1991 INVITE
Allow-Events: telephone-event
Server: Cisco-SIPGateway/IOS-12.x
Content-Length: 0

102007: .Nov 27 17:33:05.302: //46273/55E602D1B28D/CCAPI/cc_api_set_called_ccm_detected:
   CallInfo(called ccm detected=TRUE ccmVersion 3)
102008: .Nov 27 17:33:05.302: //46273/55E602D1B28D/CCAPI/cc_api_call_proceeding:
   Interface=0x46F4AAA8, Progress Indication=NULL(0)
102009: .Nov 27 17:33:05.302: //46273/55E602D1B28D/CCAPI/cc_api_call_disconnected:
   Cause Value=27, Interface=0x46F4AAA8, Call Id=46273
102010: .Nov 27 17:33:05.302: //46273/55E602D1B28D/CCAPI/cc_api_call_disconnected:
   Call Entry(Responsed=TRUE, Cause Value=27, Retry Count=0)
102011: .Nov 27 17:33:05.306: //46272/xxxxxxxxxxxx/CCAPI/ccCallReleaseResources:
   release reserved xcoding resource.
102012: .Nov 27 17:33:05.306: //46273/55E602D1B28D/CCAPI/ccCallSetAAA_Accounting:
   Accounting=0, Call Id=46273
102013: .Nov 27 17:33:05.310: //46273/55E602D1B28D/CCAPI/ccCallDisconnect:
   Cause Value=27, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=27)
102014: .Nov 27 17:33:05.310: //46273/55E602D1B28D/CCAPI/ccCallDisconnect:
   Cause Value=27, Call Entry(Responsed=TRUE, Cause Value=27)
102015: .Nov 27 17:33:05.310: //46273/55E602D1B28D/CCAPI/cc_api_get_transfer_info:
   Transfer Number Is Null
102016: .Nov 27 17:33:05.310: %VOIPAAA-5-VOIP_CALL_HISTORY: CallLegType 2, ConnectionId 55E602D137EF11E2B28DD61E695CAF39, SetupTime .17:33:05.280 UTC Tue Nov 27 2012, PeerAddress 2054445678, PeerSubAddress , DisconnectCause 1B  , DisconnectText destination out of order (27), ConnectTime .17:33:05.310 UTC Tue Nov 27 2012, DisconnectTime .17:33:05.310 UTC Tue Nov 27 2012, CallOrigin 1, ChargedUnits 0, InfoType 2, TransmitPackets 0, TransmitBytes 0, ReceivePackets 0, ReceiveBytes 0
102017: .Nov 27 17:33:05.314: //-1/xxxxxxxxxxxx/CCAPI/cc_build_feature_vsa:
  102018: .Nov 27 17:33:05.314: :Inside cc_build_feature_vsa
102019: .Nov 27 17:33:05.314: //-1/xxxxxxxxxxxx/CCAPI/cc_build_feature_vsa:
  102020: .Nov 27 17:33:05.314:  feature call basic
102021: .Nov 27 17:33:05.314: //-1/xxxxxxxxxxxx/CCAPI/cc_build_feature_vsa:
  102022: .Nov 27 17:33:05.314: cc_build_feature_vsa attr is fn:TWC,ft:11/27/2012 17:33:05.270,cgn:2055551234,cdn:2054445678,frs:0,fid:46022,fcid:55E602D137EF11E2B28DD61E695CAF39,legID:B4C1
102023: .Nov 27 17:33:05.314: %VOIPAAA-5-VOIP_FEAT_HISTORY: FEAT_VSA=fn:TWC,ft:11/27/2012 17:33:05.270,cgn:2055551234,cdn:2054445678,frs:0,fid:46022,fcid:55E602D137EF11E2B28DD61E695CAF39,legID:B4C1,bguid:55E602D137EF11E2B28DD61E695CAF39
102024: .Nov 27 17:33:05.314: //46273/55E602D1B28D/CCAPI/cc_api_call_disconnect_done:
   Disposition=0, Interface=0x46F4AAA8, Tag=0x0, Call Id=46273,
   Call Entry(Disconnect Cause=27, Voice Class Cause Code=0, Retry Count=0)
102025: .Nov 27 17:33:05.318: //46273/55E602D1B28D/CCAPI/cc_api_call_disconnect_done:
   Call Disconnect Event Sent
102026: .Nov 27 17:33:05.318: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
  102027: .Nov 27 17:33:05.318: :cc_free_feature_vsa freeing 46A52B58
102028: .Nov 27 17:33:05.318: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
 102029: .Nov 27 17:33:05.318:  vsacount in free is 5
102030: .Nov 27 17:33:05.322: //-1/xxxxxxxxxxxx/CCAPI/ccMemPoolTDFreeHelper:
   data = 47BCC080
102031: .Nov 27 17:33:05.322: ccMemPoolTDFreeHelper:mem_mgr_mempool_free: mem_refcnt(47DD4E08)=0 - mempool cleanup
102032: .Nov 27 17:33:05.322: //46272/55E602D1B28D/CCAPI/ccCallDisconnect:
   Cause Value=27, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=0)
102033: .Nov 27 17:33:05.322: //46272/55E602D1B28D/CCAPI/ccCallDisconnect:
   Cause Value=27, Call Entry(Responsed=TRUE, Cause Value=27)
102034: .Nov 27 17:33:05.326: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 404 Not Found
Via: SIP/2.0/UDP 4.4.4.4:5060;branch=z9hG4bK04Bd7b9194d9fd0ad8e
From: "KILLEN,SHANE" <sip:2055551234@4.4.4.4;pstn-params=9084818088;cpc=ordinary>;tag=gK04172686
To: <sip:2054445678@10.10.10.10>;tag=ECFD0680-22B6
Date: Tue, 27 Nov 2012 17:33:05 GMT
Call-ID: 263340_8103886@4.4.4.4
CSeq: 1991 INVITE
Allow-Events: telephone-event
Server: Cisco-SIPGateway/IOS-12.x
Reason: Q.850;cause=27
Content-Length: 0

102035: .Nov 27 17:33:05.710: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
ACK sip:2054445678@10.10.10.10:5060 SIP/2.0
Via: SIP/2.0/UDP 4.4.4.4:5060;branch=z9hG4bK04Bd7b9194d9fd0ad8e
From: "KILLEN,SHANE" <sip:2055551234@4.4.4.4;pstn-params=9084818088;cpc=ordinary>;tag=gK04172686
To: <sip:2054445678@10.10.10.10>;tag=ECFD0680-22B6
Call-ID: 263340_8103886@4.4.4.4
CSeq: 1991 ACK
Max-Forwards: 70
Content-Length: 0

Wednesday, November 21, 2012

ShoreTel 13 Re-Certification: Done.

I passed my two tests today for re-certifying on ShoreTel version 13. 

Monday, November 19, 2012

Cisco Debug: How Can You Tell If A Voice Call Is Being Call Forwarded?

How can you tell if a call is being call forwarded?  Well, you walk over to the phone and look for yourself it someone has set it that way.  However, if that is not an option, like if you are at a remote site and you are not getting ANY cooperation from the users, then you can use the 'debug isdn q931' command in y our UC500 or your CME.  See below and notice the three highlighted areas.  You know its call forwarded when you see the "redirecting number".  Interesting.

3741968: Nov 19 09:51:10.669: ISDN Se0/2/0:23 Q931: TX -> SETUP pd = 8  callref = 0x02C8
        Bearer Capability i = 0x8090A2
                Standard = CCITT
                Transfer Capability = Speech
                Transfer Mode = Circuit
                Transfer Rate = 64 kbit/s
        Channel ID i = 0xA9838E
                Exclusive, Channel 14
        Calling Party Number i = 0x80, '210'
                Plan:Unknown, Type:Unknown
        Called Party Number i = 0xA1, '2055552405'
                Plan:ISDN, Type:National
        Redirecting Number i = 0x00008F, '1007'
                Plan:Unknown, Type:Unknown
3741969: Nov 19 09:51:10.705: ISDN Se0/2/0:23 Q931: RX <- CALL_PROC pd = 8  callref = 0x82C8
        Channel ID i = 0xA9838E
                Exclusive, Channel 14
3741970: Nov 19 09:51:12.621: ISDN Se0/2/0:23 Q931: RX <- ALERTING pd = 8  callref = 0x82C8
        Progress Ind i = 0x8188 - In-band info or appropriate now available

Wednesday, November 14, 2012

Another ShoreTel Replaces Another Old Phone System

I just put in another ShoreTel phone system to replace another old PBX system.  "Another one bites the dust" appears to be the saying.  I took a picture of what Im replacing and Im putting in place a ShoreTel 13 system on a virtual server with one u in rack space of shoregear equipment.  Looks like we are not only getting a better phone system, but also saving a lot of room.

Thursday, November 8, 2012

Network Cabling: How To Extend When Its Just Shy Of Your Target

There is nothing like extending your cable when its just not long enough.  I found this when I looked up into the ceiling.  And No, I didnt do this! :)

Tuesday, November 6, 2012

Brocade: How To Detect A Loop In The Network

I see this sometimes when someone complains about poor network performance.  There is a loop in the network and its driving performance to the ground.  Finding it is sometimes a pain, and I wont cover that in this post.  But how can you know for sure if there is a loop?
FCX624 Switch#sho cpu-utilization
99 percent busy, from 15352245 sec ago
It's been more than 50 hours since last call, the CPU utilization
data collected may have wrapped around and result in high
utilization

1   sec avg:  1 percent busy
5   sec avg:  1 percent busy
60  sec avg:  1 percent busy
300 sec avg:  1 percent busy

How can you know there isnt a loop?
FCX624 Switch#sho cpu-utilization
1 percent busy, from 15 sec ago
1   sec avg:  1 percent busy
5   sec avg:  1 percent busy
60  sec avg:  1 percent busy
300 sec avg:  1 percent busy

Thursday, November 1, 2012

BackTrack 5 R3: Black Screen After Startx/Caps Lock Blinks/USB Thumb Drive Boot Problem

Well, I have to say up front, this took me a couple of hours to resolve.  It appears that this issue is quite common, but I found, literally no complete resolution to this issue anywhere on the Internet.  Here is what I tried to do:
I was trying to make a bootable USB drive with BackTrack 5 R3 on it.  Here is what I did to get that done:
1.  Get unetbootin and the ISO of backtrack.
2.  Run unetbootin and select the ISO of backtrack and the USB stick you want to use.
3.  Run the program and wait for it to finish.

This worked, except that it wouldnt boot after typing in 'startx".  It would just freeze up, black screen, and caps lock blinking steadily.  It wouldnt go any further.  From my research into this, it appears to be a video driver issue.  Im running a Dell Latitude E5410.  There appears to be fixes out there, but because Im running this on a USB drive, none of them were permanent fixes.  This is the fix that actually got me to realize that the my USB install was ok, and that this was a video driver issue (I found this in the BackTrack forums, posted by p0cTeam):
quote: insert DVD-live, in the grub press TAB to edit boot, you well see something like this file=/cdrom/preseed/ubuntu.see boot=casper initrd=/casper/initrd.gz, add xforcevesa noapic nosplash irqpoll -- after initrd.gz          end quote.

Well, that worked, ONCE.  There was another fix I found as well, and it appears to be similar in nature, although the syntax was different.  It consisted of editing the grub.cfg file.  The only problem was that I could not do a 'update-grub' after editing the grub file.  Which apparently fixed people's issue IF it was installed on the hard drive of the pc/laptop.  Mine wasnt, again, it was on the USB.  So for some reason, when I did the update-grub command, it complained to me and it never would write to the grub.cfg file.  Bummer.
Well, I found that someone on the Internet mentioned the sys.cfg file.  I looked for it in the linux directory, but I couldnt find it anywhere.  Another bummer.  But, what I did do was boot back into Windows and look at my USB drive and found a file called 'syslinux.cfg'.  I opened it up and I edited as follows:
--------
label unetbootindefault
menu label Default
kernel /ubnkern
append initrd=/ubninit file=/cdrom/preseed/custom.seed boot=casper text splash vga=791 xforcevesa noapic noapci nosplash irqpoll --

label ubnentry0
menu label BackTrack Text - Default Boot Text Mode
kernel /casper/vmlinuz
append initrd=/casper/initrd.gz file=/cdrom/preseed/custom.seed boot=casper  text splash vga=791 xforcevesa noapic noapci nosplash irqpol --


--------
Highlighted above is what I added.  Notice its the same as what p0cTeam said to add, except that it was in the syslinux.cfg file on the USB stick instead of in the grub file on the hard drive.
Ive tested this above and it works well (in my scenario).  I appears that there is about 3 variants to this, according to the install you do.  Again, mine was a USB, while most appears to address an install on the hard drive.  Im not sure how you would edit this on a CD.  I hope this helps you.
By the way, take a little time to get to know me better at my About Me page.  Thanks.