[cisco-voip] Voice mail question

Thu Nov 14 15:56:54 EST 2013

Here is what I think is the right SDI trace but in all honest I am not sure what I am looking for.  Call from 5878779777 (external call) to 3612 (local on the Call Manager)
Call is not answered and is transferred to the vm pilot over to the exchange server.   But it appears the exchange server sends back a 403 Forbidden but I am not sure why.

192.192.192.8 is the Call Manager and
192.192.192.12 is the exchange server.
IP's were changed to protect the innocent.  :)

1801 is our VM pilot.

Thanks

Terry

Date: Thu, 14 Nov 2013 19:55:43 GMT
Allow: INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, PUBLISH
From: <sip:5878779777 at 192.192.192.8>;tag=18666ade-2e36-4e6e-8483-8387cc4df15b-18050822
Allow-Events: presence, kpml
Supported: timer,replaces
Min-SE: 1800
Diversion: "B. MARSH" <sip:3612 at 192.192.192.8>;reason=no-answer;privacy=off;screen=yes
Remote-Party-ID: <sip:5878779777 at 192.192.192.8>;party=calling;screen=yes;privacy=off
Content-Length: 212
User-Agent: Cisco-CUCM6.1
To: <sip:1801 at 192.192.192.12>
Contact: <sip:5878779777 at 192.192.192.8:5060;transport=tcp>
Expires: 180
Content-Type: application/sdp
Call-ID: bd528f00-28512abf-1e6-8c910ac at 192.192.192.8<mailto:bd528f00-28512abf-1e6-8c910ac at 172.16.201.8>
Via: SIP/2.0/TCP 192.192.192.8:5060;branch=z9hG4bK3c87de972e1
CSeq: 101 INVITE
Session-Expires: 1800
Max-Forwards: 70
v=0
o=CiscoSystemsCCM-SIP 2000 1 IN IP4 192.192.192.8
s=SIP Call
c=IN IP4 172.16.201.9
t=0 0
m=audio 26166 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=ptime:20
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,65,1.359142><IP::172.16.201.9><DEV::MTP_9><LVL::State Transition><MASK::20000>
11/14/2013 12:55:43.728 CCM|//SIP/Stack/States/0xbe4f73c8/0xbe4f73c8 : State change from (STATE_IDLE, SUBSTATE_NONE) to (STATE_SENT_INVITE, SUBSTATE_NONE)|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,65,1.359142><IP::172.16.201.9><DEV::MTP_9><LVL::State Transition><MASK::40000>
11/14/2013 12:55:43.729 CCM|//SIP/SIPTcp(1,81,1)/wait_SdlReadRsp: SdlRead bufferLen=289|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1979><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::20000>
11/14/2013 12:55:43.729 CCM|//SIP/SIPTcp/wait_SdlReadRsp: Incoming SIP TCP message from 192.192.192.12 on port 5060 index 25 with 289 bytes:
SIP/2.0 100 Trying
FROM: <sip:5878779777 at 192.192.192.8>;tag=18666ade-2e36-4e6e-8483-8387cc4df15b-18050822
TO: <sip:1801 at 192.192.192.12>
CSEQ: 101 INVITE
CALL-ID: bd528f00-28512abf-1e6-8c910ac at 192.192.192.8<mailto:bd528f00-28512abf-1e6-8c910ac at 172.16.201.8>
VIA: SIP/2.0/TCP 192.192.192.8:5060;branch=z9hG4bK3c87de972e1
CONTENT-LENGTH: 0
|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1979><IP::192.192.192.12><DEV::><LVL::State Transition><MASK::20000>
11/14/2013 12:55:43.729 CCM|//SIP/SIPTcp(1,81,1)/wait_SdlReadRsp: SignalCounter = 1977|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1979><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::20000>
11/14/2013 12:55:43.729 CCM|//SIP/Stack/Info/0x0/ccsip_spi_get_msg_type returned: 2 for event 1|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1979><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.729 CCM|//SIP/Stack/Transport/0x0/context=0xbe600f30|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1979><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.729 CCM|//SIP/Stack/Transport/0x0/gConnTab=0xbe600f30, addr=201923756, port=5060, connid=25, transport=TCP|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1979><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.729 CCM|//SIP/Stack/Info/0x0/Checking Invite Dialog|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1979><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.729 CCM|//SIP/SIPHandler(1,84,1)/ccbId=0/scbId=0/sip_stop_timer: type=SIP_TIMER_TRYING value=500 retries=6|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1979><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::20000>
11/14/2013 12:55:43.729 CCM|//SIP/Stack/States/0xbe4f73c8/0xbe4f73c8 : State change from (STATE_SENT_INVITE, SUBSTATE_NONE) to (STATE_RECD_PROCEEDING, SUBSTATE_PROCEEDING_PROCEEDING)|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1979><IP::192.192.192.12><DEV::><LVL::State Transition><MASK::40000>
11/14/2013 12:55:43.729 CCM|//SIP/SIPHandler(1,84,1)/ccbId=0/scbId=0/sip_stop_timer: type=SIP_TIMER_EXPIRES value=180000 retries=0|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1979><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::20000>
11/14/2013 12:55:43.730 CCM|//SIP/SIPHandler(1,84,1)/ccbId=0/scbId=0/sip_start_timer: type=SIP_TIMER_EXPIRES value=180000 retries=0|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1979><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::20000>
11/14/2013 12:55:43.767 CCM|//SIP/SIPTcp(1,81,1)/wait_SdlReadRsp: SdlRead bufferLen=476|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1980><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::20000>
11/14/2013 12:55:43.767 CCM|//SIP/SIPTcp/wait_SdlReadRsp: Incoming SIP TCP message from 192.192.192.12 on port 5060 index 25 with 476 bytes:
SIP/2.0 302 Moved Temporarily
FROM: <sip:5878779777 at 192.192.192.8>;tag=18666ade-2e36-4e6e-8483-8387cc4df15b-18050822
TO: <sip:1801 at 192.192.192.12>;tag=7d744e5c5b
CSEQ: 101 INVITE
CALL-ID: bd528f00-28512abf-1e6-8c910ac at 192.192.192.8<mailto:bd528f00-28512abf-1e6-8c910ac at 172.16.201.8>
VIA: SIP/2.0/TCP 192.192.192.8:5060;branch=z9hG4bK3c87de972e1
CONTACT: <sip:1801 at 192.192.192.12:5065;transport=TCP>
CONTENT-LENGTH: 0
SERVER: RTCC/3.0.0.0
Diversion: "B. MARSH" <sip:3612 at 192.192.192.8>;reason=no-answer;privacy=off;screen=yes
|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1980><IP::192.192.192.12><DEV::><LVL::State Transition><MASK::20000>
11/14/2013 12:55:43.767 CCM|//SIP/SIPTcp(1,81,1)/wait_SdlReadRsp: SignalCounter = 1978|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1980><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::20000>
11/14/2013 12:55:43.767 CCM|//SIP/Stack/Info/0x0/ccsip_spi_get_msg_type returned: 2 for event 1|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1980><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.767 CCM|//SIP/Stack/Transport/0x0/context=0xbe600f30|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1980><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.767 CCM|//SIP/Stack/Transport/0x0/gConnTab=0xbe600f30, addr=201923756, port=5060, connid=25, transport=TCP|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1980><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.768 CCM|//SIP/Stack/Info/0x0/Checking Invite Dialog|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1980><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.768 CCM|//SIP/SIPHandler(1,84,1)/ccbId=0/scbId=0/sip_stop_timer: type=SIP_TIMER_EXPIRES value=180000 retries=0|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1980><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::20000>
11/14/2013 12:55:43.768 CCM|//SIP/Stack/Transport/0xbe4f73c8/Sending ACK to the transport layer|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1980><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.768 CCM|//SIP/Stack/Transport/0xbe4f73c8/msg=0xba247788, addr=201923756, port=5060, sentBy_port=5060, is_req=0, transport=2, switch=0, callBack=(nil)|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1980><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.768 CCM|//SIP/Stack/Transport/0xbe4f73c8/Proceedable for sending msg immediately|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1980><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.768 CCM|//SIP/Stack/Transport/0xbe4f73c8/switch transport is 0|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1980><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.768 CCM|//SIP/Stack/Transport/0xbe4f73c8/Trying to send resp=0xba247788 to default port=5060|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1980><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.768 CCM|//SIP/Stack/Transport/0xbe4f73c8/Connection obtained...sending msg=0xba247788|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1980><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.768 CCM|//SIP/Stack/Transport/0x0/Posting send for msg=0xba247788, addr=201923756, port=5060, connId=25 for TCP|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1980><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.768 CCM|//SIP/Stack/States/0xbe4f73c8/0xbe4f73c8 : State change from (STATE_RECD_PROCEEDING, SUBSTATE_PROCEEDING_PROCEEDING) to (SIP_STATE_REDIRECT_PENDING, SUBSTATE_NONE)|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1980><IP::192.192.192.12><DEV::><LVL::State Transition><MASK::40000>
11/14/2013 12:55:43.768 CCM|//SIP/SIPHandler(1,84,1)/ccbId=0/scbId=0/sip_stop_timer: type=SIP_TIMER_REDIRECT_PENDING value=36000 retries=0|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1980><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::20000>
11/14/2013 12:55:43.768 CCM|//SIP/SIPHandler(1,84,1)/ccbId=0/scbId=0/sip_start_timer: type=SIP_TIMER_REDIRECT_PENDING value=36000 retries=0|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1980><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::20000>
11/14/2013 12:55:43.768 CCM|//SIP/SIPTcp(1,81,1)/wait_SdlSPISignal: received a spi signal ...|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1980><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::20000>
11/14/2013 12:55:43.768 CCM|//SIP/Stack/Error/0x0/Bad holder type encountered : 1|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,84,1.1><IP::><DEV::><LVL::Error><MASK::40000>
11/14/2013 12:55:43.768 CCM|//SIP/SIPTcp/wait_SdlSPISignal: Outgoing SIP TCP message to 192.192.192.12 on port 5060 index 25
ACK sip:1801 at 192.192.192.12:5060 SIP/2.0
Date: Thu, 14 Nov 2013 19:55:43 GMT
From: <sip:5878779777 at 192.192.192.8>;tag=18666ade-2e36-4e6e-8483-8387cc4df15b-18050822
Allow-Events: presence, kpml
Content-Length: 0
To: <sip:1801 at 192.192.192.12>;tag=7d744e5c5b
Call-ID: bd528f00-28512abf-1e6-8c910ac at 192.192.192.8<mailto:bd528f00-28512abf-1e6-8c910ac at 172.16.201.8>
Via: SIP/2.0/TCP 192.192.192.8:5060;branch=z9hG4bK3c87de972e1
CSeq: 101 ACK
Max-Forwards: 70
|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1980><IP::192.192.192.12><DEV::><LVL::State Transition><MASK::20000>
11/14/2013 12:55:43.768 CCM|//SIP/Stack/Info/0x0/ccsip_spi_get_msg_type returned: 3 for event 32|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1980><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.768 CCM|//SIP/SIPHandler(1,84,1)/ccbId=0/scbId=0/sip_stop_timer: type=SIP_TIMER_REDIRECT_PENDING value=36000 retries=0|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1980><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::20000>
11/14/2013 12:55:43.768 CCM|//SIP/Stack/Info/0xbe4f73c8/Redirecting call from sip:1801 at 192.192.192.12:5060|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1980><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.768 CCM|//SIP/Stack/Info/0xbe4f73c8/Redirecting call to sip:1801 at 192.192.192.12:5065;transport=TCP|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1980><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.768 CCM|//SIP/Stack/States/0xbe4f73c8/0xbe4f73c8 : State change from (SIP_STATE_REDIRECT_PENDING, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE)|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1980><IP::192.192.192.12><DEV::><LVL::State Transition><MASK::40000>
11/14/2013 12:55:43.768 CCM|//SIP/Stack/Transport/0x0/Dialog Transaction Address 201923756,Port 5065, Transport 2, SentBy Port 5065|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1980><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.768 CCM|//SIP/Stack/Event/0xbe4f73c8/Received Octet3A=0x81 -> Setting ;screen=yes ;privacy=off|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1980><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.769 CCM|//SIP/Stack/Info/0xbe4f73c8/Guid value not set - not adding header.|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1980><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.769 CCM|//SIP/Stack/Info/0xbe4f73c8/Associated container=0xbaf0c580 to Invite|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1980><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.769 CCM|//SIP/Stack/Transport/0xbe4f73c8/Sending Invite to the transport layer|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1980><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.769 CCM|//SIP/Stack/Transport/0xbe4f73c8/msg=0xba247788, addr=201923756, port=5065, sentBy_port=0, is_req=1, transport=2, switch=0, callBack=0x9d3a648|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1980><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.769 CCM|//SIP/Stack/Transport/0xbe4f73c8/Proceedable for sending msg immediately|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1980><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.769 CCM|//SIP/Stack/Transport/0xbe4f73c8/switch transport is 0|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1980><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.769 CCM|//SIP/Stack/Transport/0xbe4f73c8/Set to send the msg=0xba247788|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1980><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.769 CCM|//SIP/Stack/Transport/0x0/Posting send for msg=0xba247788, addr=201923756, port=5065, connId=26 for TCP|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1980><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.769 CCM|//SIP/Stack/Info/0xbe4f73c8/Sent Invite in state STATE_IDLE|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1980><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.769 CCM|//SIP/SIPTcp(1,81,1)/wait_SdlSPISignal: received a spi signal ...|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1980><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::20000>
11/14/2013 12:55:43.769 CCM|//SIP/Stack/Info/0x0/Transaction active. Facilities will be queued.|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1980><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.769 CCM|//SIP/SIPHandler(1,84,1)/ccbId=0/scbId=0/sip_stop_timer: type=SIP_TIMER_TRYING value=500 retries=6|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1980><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::20000>
11/14/2013 12:55:43.769 CCM|//SIP/SIPHandler(1,84,1)/ccbId=0/scbId=0/sip_start_timer: type=SIP_TIMER_TRYING value=500 retries=6|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1980><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::20000>
11/14/2013 12:55:43.769 CCM|//SIP/Stack/Error/0x0/Bad holder type encountered : 1|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,84,1.1><IP::><DEV::><LVL::Error><MASK::40000>
11/14/2013 12:55:43.769 CCM|//SIP/SIPTcp/wait_SdlSPISignal: Outgoing SIP TCP message to 192.192.192.12 on port 5065 index 26
INVITE sip:1801 at 192.192.192.12:5065;transport=TCP SIP/2.0
Date: Thu, 14 Nov 2013 19:55:43 GMT
Allow: INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, PUBLISH
From: <sip:5878779777 at 192.192.192.8>;tag=18666ade-2e36-4e6e-8483-8387cc4df15b-18050822
Allow-Events: presence, kpml
Supported: timer,replaces
Min-SE: 1800
Diversion: "B. MARSH"<sip:3612 at 192.192.192.8>;privacy=off;reason=no-answer;screen=yes
Diversion: "B. MARSH" <sip:3612 at 192.192.192.8>;reason=no-answer;privacy=off;screen=yes
Remote-Party-ID: <sip:5878779777 at 192.192.192.8>;party=calling;screen=yes;privacy=off
Content-Length: 212
User-Agent: Cisco-CUCM6.1
To: <sip:1801 at 192.192.192.12>
Contact: <sip:5878779777 at 192.192.192.8:5060;transport=tcp>
Expires: 180
Content-Type: application/sdp
Call-ID: bd528f00-28512abf-1e6-8c910ac at 192.192.192.8<mailto:bd528f00-28512abf-1e6-8c910ac at 172.16.201.8>
Via: SIP/2.0/TCP 192.192.192.8:5060;branch=z9hG4bK3c95ee4d2dc
CSeq: 102 INVITE
Session-Expires: 1800
Max-Forwards: 70
v=0
o=CiscoSystemsCCM-SIP 2000 1 IN IP4 192.192.192.8
s=SIP Call
c=IN IP4 172.16.201.9
t=0 0
m=audio 26166 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=ptime:20
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1980><IP::192.192.192.12><DEV::><LVL::State Transition><MASK::20000>
11/14/2013 12:55:43.769 CCM|//SIP/Stack/States/0xbe4f73c8/0xbe4f73c8 : State change from (STATE_IDLE, SUBSTATE_NONE) to (STATE_SENT_INVITE, SUBSTATE_NONE)|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1980><IP::192.192.192.12><DEV::><LVL::State Transition><MASK::40000>
11/14/2013 12:55:43.770 CCM|//SIP/SIPTcp(1,81,1)/wait_SdlReadRsp: SdlRead bufferLen=289|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1981><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::20000>
11/14/2013 12:55:43.770 CCM|//SIP/SIPTcp/wait_SdlReadRsp: Incoming SIP TCP message from 192.192.192.12 on port 5065 index 26 with 289 bytes:
SIP/2.0 100 Trying
FROM: <sip:5878779777 at 192.192.192.8>;tag=18666ade-2e36-4e6e-8483-8387cc4df15b-18050822
TO: <sip:1801 at 192.192.192.12>
CSEQ: 102 INVITE
CALL-ID: bd528f00-28512abf-1e6-8c910ac at 192.192.192.8<mailto:bd528f00-28512abf-1e6-8c910ac at 172.16.201.8>
VIA: SIP/2.0/TCP 192.192.192.8:5060;branch=z9hG4bK3c95ee4d2dc
CONTENT-LENGTH: 0
|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1981><IP::192.192.192.12><DEV::><LVL::State Transition><MASK::20000>
11/14/2013 12:55:43.770 CCM|//SIP/SIPTcp(1,81,1)/wait_SdlReadRsp: SignalCounter = 1979|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1981><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::20000>
11/14/2013 12:55:43.770 CCM|//SIP/Stack/Info/0x0/ccsip_spi_get_msg_type returned: 2 for event 1|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1981><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.770 CCM|//SIP/Stack/Transport/0x0/context=0xbe600f30|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1981><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.770 CCM|//SIP/Stack/Transport/0x0/gConnTab=0xbe600f30, addr=201923756, port=5065, connid=26, transport=TCP|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1981><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.770 CCM|//SIP/Stack/Info/0x0/Checking Invite Dialog|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1981><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.770 CCM|//SIP/SIPHandler(1,84,1)/ccbId=0/scbId=0/sip_stop_timer: type=SIP_TIMER_TRYING value=500 retries=6|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1981><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::20000>
11/14/2013 12:55:43.770 CCM|//SIP/Stack/States/0xbe4f73c8/0xbe4f73c8 : State change from (STATE_SENT_INVITE, SUBSTATE_NONE) to (STATE_RECD_PROCEEDING, SUBSTATE_PROCEEDING_PROCEEDING)|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1981><IP::192.192.192.12><DEV::><LVL::State Transition><MASK::40000>
11/14/2013 12:55:43.770 CCM|//SIP/SIPHandler(1,84,1)/ccbId=0/scbId=0/sip_stop_timer: type=SIP_TIMER_EXPIRES value=180000 retries=0|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1981><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::20000>
11/14/2013 12:55:43.770 CCM|//SIP/SIPHandler(1,84,1)/ccbId=0/scbId=0/sip_start_timer: type=SIP_TIMER_EXPIRES value=180000 retries=0|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1981><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::20000>
11/14/2013 12:55:43.807 CCM|//SIP/SIPTcp(1,81,1)/wait_SdlReadRsp: SdlRead bufferLen=329|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1982><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::20000>
11/14/2013 12:55:43.807 CCM|//SIP/SIPTcp/wait_SdlReadRsp: Incoming SIP TCP message from 192.192.192.12 on port 5065 index 26 with 329 bytes:
SIP/2.0 403 Forbidden
FROM: <sip:5878779777 at 192.192.192.8>;tag=18666ade-2e36-4e6e-8483-8387cc4df15b-18050822
TO: <sip:1801 at 192.192.192.12>;tag=5983675ac8
CSEQ: 102 INVITE
CALL-ID: bd528f00-28512abf-1e6-8c910ac at 192.192.192.8<mailto:bd528f00-28512abf-1e6-8c910ac at 172.16.201.8>
VIA: SIP/2.0/TCP 192.192.192.8:5060;branch=z9hG4bK3c95ee4d2dc
CONTENT-LENGTH: 0
SERVER: RTCC/3.0.0.0
|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1982><IP::192.192.192.12><DEV::><LVL::State Transition><MASK::20000>
11/14/2013 12:55:43.807 CCM|//SIP/SIPTcp(1,81,1)/wait_SdlReadRsp: SignalCounter = 1980|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1982><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::20000>
11/14/2013 12:55:43.807 CCM|//SIP/Stack/Info/0x0/ccsip_spi_get_msg_type returned: 2 for event 1|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1982><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.807 CCM|//SIP/Stack/Transport/0x0/context=0xbe600f30|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1982><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.807 CCM|//SIP/Stack/Transport/0x0/gConnTab=0xbe600f30, addr=201923756, port=5065, connid=26, transport=TCP|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1982><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.807 CCM|//SIP/Stack/Info/0x0/Checking Invite Dialog|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1982><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.808 CCM|//SIP/SIPHandler(1,84,1)/ccbId=0/scbId=0/sip_stop_timer: type=SIP_TIMER_EXPIRES value=180000 retries=0|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1982><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::20000>
11/14/2013 12:55:43.808 CCM|//SIP/Stack/Info/0x0/No GTD found in inbound container|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1982><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.808 CCM|//SIP/Stack/Transport/0xbe4f73c8/Sending ACK to the transport layer|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1982><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.808 CCM|//SIP/Stack/Transport/0xbe4f73c8/msg=0xba247788, addr=201923756, port=5065, sentBy_port=5065, is_req=0, transport=2, switch=0, callBack=(nil)|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1982><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.808 CCM|//SIP/Stack/Transport/0xbe4f73c8/Proceedable for sending msg immediately|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1982><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.808 CCM|//SIP/Stack/Transport/0xbe4f73c8/switch transport is 0|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1982><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.808 CCM|//SIP/Stack/Transport/0xbe4f73c8/Trying to send resp=0xba247788 to default port=5065|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1982><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.808 CCM|//SIP/Stack/Transport/0xbe4f73c8/Connection obtained...sending msg=0xba247788|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1982><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.808 CCM|//SIP/Stack/Transport/0x0/Posting send for msg=0xba247788, addr=201923756, port=5065, connId=26 for TCP|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1982><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.808 CCM|//SIP/Stack/Info/0xbe4f73c8/Received a 4/5/6xx message with StatusCode: 403|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1982><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.808 CCM|//SIP/SIPTcp(1,81,1)/wait_SdlSPISignal: received a spi signal ...|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1982><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::20000>
11/14/2013 12:55:43.808 CCM|//SIP/Stack/Error/0xbe4f73c8/next_choice == 1|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1982><IP::192.192.192.12><DEV::><LVL::Error><MASK::40000>
11/14/2013 12:55:43.808 CCM|//SIP/Stack/Info/0xbe4f73c8/Initiate call disconnect(57) for outgoing call|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,81,1.1982><IP::192.192.192.12><DEV::><LVL::Detailed><MASK::40000>
11/14/2013 12:55:43.808 CCM|//SIP/Stack/Error/0x0/Bad holder type encountered : 1|<CLID::CCM1-Cluster><NID::192.192.192.8><CT::1,100,84,1.1><IP::><DEV::><LVL::Error><MASK::40000>
11/14/2013 12:55:43.808 CCM|//SIP/SIPTcp/wait_SdlSPISignal: Outgoing SIP TCP message to 192.192.192.12 on port 5065 index 26
ACK sip:1801 at 192.192.192.12:5065;transport=TCP SIP/2.0
Date: Thu, 14 Nov 2013 19:55:43 GMT
From: <sip:5878779777 at 192.192.192.8>;tag=18666ade-2e36-4e6e-8483-8387cc4df15b-18050822
Allow-Events: presence, kpml
Content-Length: 0
To: <sip:1801 at 192.192.192.12>;tag=5983675ac8
Call-ID: bd528f00-28512abf-1e6-8c910ac at 192.192.192.8<mailto:bd528f00-28512abf-1e6-8c910ac at 172.16.201.8>
Via: SIP/2.0/TCP 192.192.192.8:5060;branch=z9hG4bK3c95ee4d2dc
CSeq: 102 ACK
Max-Forwards: 70

From: Brian Meade (brmeade) [mailto:brmeade at cisco.com]
Sent: November-14-13 11:03 AM
To: Terry Oakley; cisco-voip at puck.nether.net
Subject: RE: Voice mail question

Terry,

Is the voice gateway set up as H323 or SIP?

CallManager SDI traces set to Detailed will most likely show you the problem.  It may be as simple as allowing offnet-to-offnet transfers under Service Parameters or may be some sort of codec issue.

Brian

From: cisco-voip [mailto:cisco-voip-bounces at puck.nether.net] On Behalf Of Terry Oakley
Sent: Thursday, November 14, 2013 12:16 PM
To: cisco-voip at puck.nether.net<mailto:cisco-voip at puck.nether.net>
Subject: [cisco-voip] Voice mail question

Environment

CUCM 6.1 (Publisher and Subscriber)
VG2811 connected to two T1's
Voicemail hosted on a 2010 Exchange server.
SIP trunk to connect/route the caller to the Exchange Server.

Recent changes:
We have changed our DNS IP addresses and the issue appears to have changed since then.

Issue:

External callers do not get transferred to the voicemail server but rather get a 2UC1 message saying all circuits are busy.
Internal callers do get transferred to the voicemail server and can leave voice mail.

So I believe the SIP trunk in CUCM is working properly.
Staff can access the voice mail server from their sets and change/record greetings so I believe voicemail is functioning properly.
The issue appears to be that external callers are not forwarding to the proper route.
Doing a traceroute on the VG2811 to the IP address and DNS name of the Exchange server does show proper resolution.

What or where should I look to determine why external callers do not get transferred/routed to the voice mail system.   They are ringing phones but unanswered calls appear to be transferred back out to the PSTN.

Thanks

Terry

Terry Oakley
Telecommunication Coordinator, | Information Technology Services
100 College Blvd | Red Deer, AB T4N 5H5
Tel (403) 342-3521 | Terry.Oakley at rdc.ab.ca<mailto:Terry.Oakley at rdc.ab.ca>
[cid:image002.jpg at 01CEE141.6051CAE0]<http://www.rdc.ab.ca/>

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://puck.nether.net/pipermail/cisco-voip/attachments/20131114/b355f6ea/attachment.html>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: image001.gif
Type: image/gif
Size: 3386 bytes
Desc: image001.gif
URL: <https://puck.nether.net/pipermail/cisco-voip/attachments/20131114/b355f6ea/attachment.gif>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: image002.jpg
Type: image/jpeg
Size: 2017 bytes
Desc: image002.jpg
URL: <https://puck.nether.net/pipermail/cisco-voip/attachments/20131114/b355f6ea/attachment.jpg>