Voicemail to email randomly stopped working

[zp-mecanex]

Hello,

I have an NV7100 system and as of a couple of weeks ago, the voicemail to email feature stopped working. We have an onsite exchange server and none of the IP addresses or network settings were altered in any way.

[Anonymous]

Thanks for posting to ADTRAN Support Forums.

Log into the CLI and run following debug “debug voice verbose” and then call and try and leave voicemail.

Then copy all the debug and send it in reply.

Let me know what number you called from and who you called.

Thanks,

-Mark

[zp-mecanex]

Hi Mark,

I telnetted to the unit and attempted the command, however it is unrecognized.

[zp-mecanex]

I was about to do the debug voice verbose via the web console. Here are the results. I called from 8608169986 to 8608286531 ext 324

14:30:34.285 TM.T01 17 IsdnTmStateOutboundPreconnect->IsdnTmStateOutboundConnecting

14:30:34.285 TM.T01 17 IsdnTmStateOutboundConnecting::enter()

14:30:34.285 TA.T01 17 TAOutGoing           rcvd: connect from TM

14:30:34.286 TA.T01 17 State change      >> TAOutGoing->TAConnectWaitOut (TAS_Delivering)

14:30:34.286 SB.CALL 236 PreConnected         Called the connect routine

14:30:34.286 SB.CCM isResponseMappable:

14:30:34.286 SB.CCM  :  Call Struct 0x53e0410 :   Call-ID = 236

14:30:34.286 SB.CCM  :  Org Acct = 321    Dst Acct = T01

14:30:34.287 SB.CCM  :  Org Port ID = SipPhone 0/1.1   Dst Port ID = Isdn(Ds1Ds0Trunk) 2/1.17

14:30:34.287 SB.CCM  :  SDP Transaction = CallID: 236

14:30:34.287 SB.CCM  :  SDP Offer = 0x03cee610, (10.10.20.3:2232)

14:30:34.287 SB.CCM  :  SDP Answer = 0x03cef010, (127.0.0.3:10764)

14:30:34.287 SB.CCM  :  RTP Channel = 0/1.1

14:30:34.288 SB.CCM isResponseMappable: reversing call connection type to compensate for event originator direction

14:30:34.288 SB.CCM isResponseMappable: Call Connection Type is TDM_TO_RTP

14:30:34.288 SB.CCM isResponseMappable: Modifying SDP Answer

14:30:34.289 SB.CCM translateAnswer: offer  codec list: PCMU G729

14:30:34.289 SB.CCM                : answer codec list: PCMU G729

14:30:34.289 SB.CCM translateAnswer: CODEC transcoding is not required

14:30:34.290 SB.CCM translateAnswer: offer / answer DTMF signaling identical: DTMF transcoding not required

14:30:34.290 SB.CCM translateAnswer: success

14:30:34.291 SB.CALL 236 PreConnected         Connect sent from T01 to 321

14:30:34.291 SB.CALL 236 State change      >> PreConnected->Connecting

14:30:34.291 SA.321 Ca:0 Alerting             rcvd: connect from SB

14:30:34.291 SA.321 Ca:0 Alerting             State change      >> Alerting->ConnectPending (CAS_Connected)

14:30:34.292 SA.321 Ca:0 ConnectPending       sent: AcctPhoneMgr_cachg(CAS_Connected) to PM

14:30:34.292 PM.321 Ca:0 State change      >> SipPM_Pending->SipPM_Accepting

14:30:34.292 PM.321 Ca:0 SDP DPI call ID 236 : Media bin present.

14:30:34.293 PM.321 Ca:0 Processing new SDP entries.

14:30:34.293 PM.321 Ca:0 Checking for internal Media Gateway IP Address

14:30:34.293 PM.321 Ca:0 Using RTP Channel 0/1.1

14:30:34.293 PM.321 Ca:0 Inserting 10.10.20.1 into SDP for Media Gateway

14:30:34.294 PM.321 Ca:0 Adding RTP Media Gateway Entry: 127.0.0.3:10764 -> 10.10.20.1:10764

14:30:34.294 PM.321 Ca:0 Allocating anchor ports 10764 and 10765 for interface 10.10.20.1

14:30:34.297 PM.321 Ca:0 SipPM_Accepting      call-leg (P:0x5aa5b90 S:0x0) -> Accepted (Local Accepted)

14:30:34.297 PM.321 Ca:0 SipPM_Accepting      sent: 200 with SDP

14:30:34.315 PM.321 Ca:0 SipPM_Accepting      rcvd SIP call-leg request: ACK

14:30:34.315 PM.321 Ca:0 SipPM_Accepting      call-leg (P:0x5aa5b90 S:0x0) -> Connected (Remote Ack)

14:30:34.316 PM.321 Ca:0 SipPM_Accepting      rcvd: ACK

14:30:34.316 PM.321 Ca:0 SipPM_Accepting      No body in message when trying to get SDP

14:30:34.316 PM.321 Ca:0 SipPM_Accepting      info: unable to save SDP

14:30:34.316 PM.321 Ca:0 SipPM_Accepting      sent: SA->Connect

14:30:34.316 PM.321 Ca:0 State change      >> SipPM_Accepting->SipPM_Connected

14:30:34.317 PM.321 Ca:0 SipPM_Connected      call-leg-mod (P:0x5aa5b90 S:0x0) -> Modify Idle

14:30:34.317 PM.321 Ca:0 SipPM_Connected      Default: SipCallLegModifyStateChanged to Idle ignored

14:30:34.317 SA.321 Ca:0 ConnectPending       rcvd: AcctPhoneMgr_connect from PM

14:30:34.317 SA.321 Ca:0 ConnectPending       sent: connectResponse(pass) to SB

14:30:34.318 SA.321 Ca:0 ConnectPending       State change      >> ConnectPending->Connected (CAS_Connected)

14:30:34.318 SB.CALL 236 Connecting           Called the connectResponse routine

14:30:34.318 SB.CCM connect:

14:30:34.318 SB.CCM  :  Call Struct 0x53e0410 :   Call-ID = 236

14:30:34.318 SB.CCM  :  Org Acct = 321    Dst Acct = T01

14:30:34.319 SB.CCM  :  Org Port ID = SipPhone 0/1.1   Dst Port ID = Isdn(Ds1Ds0Trunk) 2/1.17

14:30:34.319 SB.CCM  :  SDP Transaction = CallID: 236

14:30:34.319 SB.CCM  :  SDP Offer = 0x03cee610, (10.10.20.3:2232)

14:30:34.319 SB.CCM  :  SDP Answer = 0x03cef010, (127.0.0.3:10764)

14:30:34.320 SB.CCM  :  RTP Channel = 0/1.1

14:30:34.320 MOH.APP printCSHoldStates, connect_: towOrig 0, towDest 0 origHold 0 destHold 0 isHold 0

14:30:34.320 SB.CCM connect: Call Connection Type is RTP_TO_TDM

14:30:34.320 SB.CCM SDP offer is 10.10.20.3:2232, SDP answer is 127.0.0.3:10764

14:30:34.321 SB.CCM connect: Connected RTP/TDM via MCM

14:30:34.322 SB.CCM setupRtpChannel, source 2, silence 0

14:30:34.322 SB.CCM setupRtpChannel: setup using media connection

14:30:34.322 SB.CCM Looking up source address for destination 10.10.20.3

14:30:34.322 SB.CCM setupRtpChannel: Source IP addr = 10.10.20.1, port = 10764

14:30:34.323 SB.CCM setupRtpChannel: Target IP addr = 10.10.20.3, port = 2232

14:30:34.323 SB.CCM setupRtpChannel: Undo of previous operation not required

14:30:34.323 SB.CCM getFinalCodec: PCMU

14:30:34.324 SB.CCM getFinalCodec: PCMU

14:30:34.324 SB.CCM setupRtpChannel: Configuring RTP Channel 0/1.1 to Src 10.10.20.1:10764 Trg 10.10.20.3:2232 via PCMU Rx PCMU G729

14:30:34.324 SB.CCM setupRtpChannel: fpp=2 echo=on dtmf=101/101 dscp=46 vad=off isOffer no

14:30:34.324 SB.CCM setupRtpChannel: No changes needed to RTP Channel

14:30:34.325 SB.CCM firewallConnectCall: Set up firewall from media connections

14:30:34.325 SB.CCM sdpFirewall: invoked with offer - 10.10.20.1:10764, answer - 10.10.20.3:2232

14:30:34.325 SB.CCM sdpFirewall: IPv4 firewall is not enabled, no action taken

14:30:34.326 SB.CCM connect: TDM streams: port(SipPhone 0/1.1) to port(Isdn(Ds1Ds0Trunk) 2/1.17)

14:30:34.326 SB.CALL 236 Connecting           ConnectResponse sent from 321 to T01

14:30:34.326 TA.T01 17 TAConnectWaitOut     connectResponse event accepted

14:30:34.326 TA.T01 17 State change      >> TAConnectWaitOut->TAConnected (TAS_Connected)

14:30:34.327 TM.T01 17 IsdnTmStateOutboundConnecting->IsdnTmStateOutboundConnected

14:30:34.327 TM.T01 17 IsdnTmStateOutboundConnected::enter()

14:30:34.327 TM.T01 17 sent: finalizeConnect to TA

14:30:34.327 TA.T01 17 TAConnected          rcvd: finalizeConnect from TM

14:30:34.328 TA.T01 17 TAConnected          forwarding finalizeConnect from TM

14:30:34.328 TA.T01 17 TAConnected          sent finalizeConnect to SB

14:30:34.328 SB.CALL 236 Connecting           Called the finalizeConnect routine

14:30:34.328 SB.CCM finalizeConnect: connection already finalized(3)

14:30:34.328 SB.CALL 236 State change      >> Connecting->Connected

14:31:34.344 PM.321 Ca:0 Sending Keep-alive: INFO

14:31:34.347 PM.321 Ca:0 call-leg transaction -> Request Sent

14:31:34.363 PM.321 Ca:0 SipPM_Connected      rcvd SIP call-leg response: 200 OK

14:31:34.364 PM.321 Ca:0 call-leg transaction -> Final Response Rcvd

14:31:34.364 PM.321 Ca:0 SipPM_Connected      Received keep-alive response: 200

14:31:34.364 PM.321 Ca:0 call-leg transaction -> Terminated

14:31:39.212 TM.T01 23 en bloc sending call rec'd

14:31:39.212 TM.T01 23 IsdnTmStateIdle->IsdnTmStateInboundAccept

14:31:39.212 TM.T01 23 IsdnTmStateInboundAccept::enter() send call to acct

14:31:39.213 TA.T01 23 TAIdle               rcvd: inboundCall from TM

14:31:39.213 TA.T01 23 State change      >> TAIdle->TAInboundCall (TAS_Calling)

14:31:39.213 TA.T01 23 Failed - DID translation: no match for 8608286531, using 8608286531

14:31:39.213 TA.T01 23 TAIdle               sent: call to SB

14:31:39.214 TM.T01 23 tachg_TAInboundCall do nothing

14:31:39.214 SB.CALL 237 Idle                 Called the call routine with 8608286531

14:31:39 SB.TGMgr TrunkGroup ISDN/PRI rejects number 8608286531 based on template 8608286531

14:31:39.214 SB.CALL 237 Idle                 No LOCAL station matched dialed number (8608286531)

14:31:39.215 SB.CALL 237 Idle                 No TRUNK accepted dialed number (8608286531)

14:31:39.215 SB.CALL 237 Idle                 Translating alias: 8608286531 to 100

14:31:39.215 SB.CCM isMappable:

14:31:39.215 SB.CCM  :  Call Struct 0x43f3c10 :   Call-ID = 237

14:31:39.215 SB.CCM  :  Org Acct = T01    Dst Acct = 100

14:31:39.216 SB.CCM  :  Org Port ID = Isdn(Ds1Ds0Trunk) 2/1.1   Dst Port ID = unknown 0/0

14:31:39.216 SB.CCM isMappable: Call Connection Type is TDM_TO_TDM

14:31:39.216 SB.CALL 237 Idle                 Call sent from T01 to 100 (100)

14:31:39.216 SB.CALL 237 State change      >> Idle->Delivering

14:31:39.217 TA.T01 23 TAInboundCall        CallResp event accepted

14:31:39.217 TA.T01 23 State change      >> TAInboundCall->TAConnectWaitIn (TAS_Calling)

14:31:39.217 SA.100 rcvd: deliver from SB

14:31:39.217 SA.100 num-rings disabled: process call coverage

14:31:39.218 SA.100 sent: ClearCall to SB

14:31:39.218 SB.CALL 237 Delivering           Called the clearCall routine

14:31:39.218 SB.CALL 237 Delivering           Call Cleared on call from 100 to T01

14:31:39.218 SB.CALL 237 State change      >> Delivering->Clearing

14:31:39.218 TA.T01 23 TAConnectWaitIn      ClearCall event accepted

14:31:39.219 TA.T01 23 TAConnectWaitIn      Processing a forward from call coverage

14:31:39.219 TA.T01 23 TAConnectWaitIn      sent: call to SB

14:31:39.219 TA.T01 23 State change      >> TAConnectWaitIn->TAInboundCall (TAS_Calling)

14:31:39.219 SB.CALL 237 Clearing             Called the clearResponse routine

14:31:39.220 SB.CALL 237 State change      >> Clearing->CallIdlePending

14:31:39.220 SB.CCM release:

14:31:39.220 SB.CCM  :  Call Struct 0x43f3c10 :   Call-ID = 237

14:31:39.220 SB.CCM  :  Org Acct = T01    Dst Acct = 100

14:31:39.221 SB.CCM  :  Org Port ID = Isdn(Ds1Ds0Trunk) 2/1.1   Dst Port ID = VirtualPhone 0/0

14:31:39.221 SB.CCM release: Call Connection Type is TDM_TO_TDM

14:31:39.221 SB.CALL 237 CallIdlePending      ClearResponse sent from T01 to 100

14:31:39.221 SB.CALL 238 Idle                 Called the call routine with 820

14:31:39.221 SB.CCM isMappable:

14:31:39.221 SB.CCM  :  Call Struct 0x3f40410 :   Call-ID = 238

14:31:39.222 SB.CCM  :  Org Acct = T01    Dst Acct = AutoAttendantAcct

14:31:39.222 SB.CCM  :  Org Port ID = Isdn(Ds1Ds0Trunk) 2/1.1   Dst Port ID = unknown 0/0

14:31:39.222 SB.CCM isMappable: Call Connection Type is TDM_TO_RTP

14:31:39.223 SB.CCM isMappable: Reserving RTP Channel 0/1.2

14:31:39.223 SB.CCM isMappable: Creating SDP Offer

14:31:39.224 SB.CCM updateOfferWithEndpointConfig: DTMF(NTE 101), VAD(off), ptime(0)

14:31:39.225 SB.CCM translateOffer: offer codec list: PCMU G729

14:31:39.225 SB.CCM translateOffer: revised offer codec list: PCMU G729

14:31:39.226 SB.CCM translateOffer: codec list after answerer: G729

14:31:39.226 SB.CCM translateOffer: codec list after transcode add: G729

14:31:39.227 SB.CCM translateOffer: compatible DTMF signaling: answerer restriction(NTE 101), offer(NTE 101): DTMF transcoding unnecessary, using offer

14:31:39.227 SB.CCM translateOffer: success

14:31:39.228 SB.CALL 238 Idle                 Call sent from T01 to AutoAttendantAcct (820)

14:31:39.228 SB.CALL 238 State change      >> Idle->Delivering

14:31:39.228 SA.100 ERROR! clearResponse ignored

14:31:39.229 RTP.MANAGER t1 2/1.1 - empty - RTP: Request resource

14:31:39.229 RTP.MANAGER t1 2/1.1 - Dsp 0/1.2 - RTP: DSP channel allocated for the resource

14:31:39.229 RTP.PROVIDER t1 2/1.1 - Dsp 0/1.2 - RTP: providing already allocated RTP channel

14:31:39.230 TA.T01 23 TAInboundCall        CallResp event accepted

14:31:39.230 TA.T01 23 State change      >> TAInboundCall->TAConnectWaitIn (TAS_Calling)

14:31:39.230 AUTOATTENDANT.CA:0 Idle - updateSdpInActiveCallStruct: Creating SDP Answer based on SDP Offer

14:31:39.232 AUTOATTENDANT.CA:0 Idle - State Change: Idle to DigitGathering

14:31:39.232 SB.CALL 238 Delivering           Called the connect routine

14:31:39.233 SB.CCM isResponseMappable:

14:31:39.233 SB.CCM  :  Call Struct 0x3f40410 :   Call-ID = 238

14:31:39.233 SB.CCM  :  Org Acct = T01    Dst Acct = AutoAttendantAcct

14:31:39.233 SB.CCM  :  Org Port ID = Isdn(Ds1Ds0Trunk) 2/1.1   Dst Port ID = InternalRtpApp 0/0

14:31:39.233 SB.CCM  :  SDP Transaction = CallID: 238

14:31:39.234 SB.CCM  :  SDP Offer = 0x03cc2610, (127.0.0.3:10766)

14:31:39.234 SB.CCM  :  SDP Answer = 0x03e93210, (127.0.0.1:10768)

14:31:39.234 SB.CCM  :  RTP Channel = 0/1.2

14:31:39.234 SB.CCM isResponseMappable: reversing call connection type to compensate for event originator direction

14:31:39.234 SB.CCM isResponseMappable: Call Connection Type is RTP_TO_TDM

14:31:39.235 SB.CCM isResponseMappable: Modifying SDP Answer

14:31:39.235 SB.CCM translateAnswer: offer  codec list: PCMU G729

14:31:39.235 SB.CCM                : answer codec list: G729

14:31:39.236 SB.CCM translateAnswer: CODEC transcoding is not required

14:31:39.236 SB.CCM translateAnswer: offer / answer DTMF signaling identical: DTMF transcoding not required

14:31:39.237 SB.CCM translateAnswer: success

14:31:39.238 SB.CALL 238 Delivering           Connect sent from AutoAttendantAcct to T01

14:31:39.238 SB.CALL 238 State change      >> Delivering->Connecting

14:31:39.238 TA.T01 23 TAConnectWaitIn      connect event accepted

14:31:39.238 TA.T01 23 State change      >> TAConnectWaitIn->TAConnectPending (TAS_Connected)

14:31:39.238 TM.T01 23 IsdnTmStateInboundAccept->IsdnTmStateInboundConnecting

14:31:39.239 TM.T01 23 IsdnTmStateInboundConnecting::enter()

14:31:39.239 TM.T01 23 IsdnTmStateInboundConnecting->IsdnTmStateInboundConnected

14:31:39.239 TM.T01 23 IsdnTmStateInboundConnected::enter()

14:31:39.239 TA.T01 23 TAConnectPending     rcvd: connect from TM

14:31:39.240 TA.T01 23 State change      >> TAConnectPending->TAConnected (TAS_Connected)

14:31:39.240 SB.CALL 238 Connecting           Called the connectResponse routine

14:31:39.240 SB.CCM connect:

14:31:39.240 SB.CCM  :  Call Struct 0x3f40410 :   Call-ID = 238

14:31:39.240 SB.CCM  :  Org Acct = T01    Dst Acct = AutoAttendantAcct

14:31:39.241 SB.CCM  :  Org Port ID = Isdn(Ds1Ds0Trunk) 2/1.1   Dst Port ID = InternalRtpApp 0/0

14:31:39.241 SB.CCM  :  SDP Transaction = CallID: 238

14:31:39.241 SB.CCM  :  SDP Offer = 0x03cc2610, (127.0.0.3:10766)

14:31:39.241 SB.CCM  :  SDP Answer = 0x03e93210, (127.0.0.1:10768)

14:31:39.241 SB.CCM  :  RTP Channel = 0/1.2

14:31:39.242 MOH.APP printCSHoldStates, connect_: towOrig 0, towDest 0 origHold 0 destHold 0 isHold 0

14:31:39.242 SB.CCM connect: Call Connection Type is TDM_TO_RTP

14:31:39.242 SB.CCM SDP offer is 127.0.0.3:10766, SDP answer is 127.0.0.1:10768

14:31:39.243 SB.CCM connect: Connected RTP/TDM via MCM

14:31:39.243 SB.CCM handleMediaConnectionRtpChannel: No RTP channel to set up

14:31:39.244 SB.CCM setupRtpChannel, source 2, silence 0

14:31:39.244 SB.CCM setupRtpChannel: setup using media connection

14:31:39.244 SB.CCM Looking up source address for destination 127.0.0.1

14:31:39.244 SB.CCM setupRtpChannel: Source IP addr = 127.0.0.1, port = 10766

14:31:39.245 SB.CCM setupRtpChannel: Target IP addr = 127.0.0.1, port = 10768

14:31:39.245 SB.CCM setupRtpChannel: Undo of previous operation not required

14:31:39.245 SB.CCM getFinalCodec: G729

14:31:39.245 SB.CCM getFinalCodec: G729

14:31:39.246 SB.CCM setupRtpChannel: Configuring RTP Channel 0/1.2 to Src 127.0.0.1:10766 Trg 127.0.0.1:10768 via G729 Rx G729

14:31:39.246 SB.CCM setupRtpChannel: fpp=2 echo=on dtmf=101/101 dscp=46 vad=off isOffer yes

14:31:39.246 SB.CCM setupRtpChannel: Starting RTP Channel

14:31:39.247 RTP.CHANNEL Channel 0/1.2 session statistics cleared.

14:31:39.247 RTP.CHANNEL Channel 0/1.2 started successfully.

14:31:39.247 SB.CCM firewallConnectCall: Set up firewall from media connections

14:31:39.247 SB.CCM sdpFirewall: invoked with offer - [::]:10768, answer - 127.0.0.1:10768

14:31:39.248 SB.CCM sdpFirewall: 'any' address detected, no action taken

14:31:39.248 SB.CCM sdpFirewall: invoked with offer - [::]:10766, answer - 127.0.0.1:10766

14:31:39.248 SB.CCM sdpFirewall: 'any' address detected, no action taken

14:31:39.249 SB.CCM connect: TDM streams: port(Isdn(Ds1Ds0Trunk) 2/1.1) to port(InternalRtpApp 0/1.2)

14:31:39.249 SB.CALL 238 Connecting           ConnectResponse sent from T01 to AutoAttendantAcct

14:31:39.250 RTP.CHANNEL t1 2/1.1 - Dsp 0/1.2 - RTP: starting

14:31:39.250 AUTOATTENDANT.CA:0 DigitGathering - rcvd: connectResponse from SB

14:31:39.250 AUTOATTENDANT.820 Ca:0 activate: New session initiated.

14:31:39.250 SB.CALL 238 Connecting           Called the finalizeConnect routine

14:31:39.251 SB.CCM finalizeConnect: connection already finalized(2)

14:31:39.251 SB.CALL 238 Connecting           ForceDoubleReinviteEvent sent

14:31:39.251 SB.CALL 238 State change      >> Connecting->Connected

14:31:39.251 SB.CALL 238 Connected            Forced double reInvite process beginning.

14:31:39.251 SB.CALL 238 Connected            Org/Dst mode is 1/1, reInvite without SDP sent to T01 (org)

14:31:39.251 SB.CALL 238 State change      >> Connected->ForcedReInviteOrg

14:31:39.252 TA.T01 23 TAConnected          reInvite event accepted

14:31:39.252 TA.T01 23 State change      >> TAConnected->TAReInvited (TAS_ReInvited)

14:31:39.252 TM.T01 0 IsdnTrunkManager: updated appearance SHF from call struct (19->1)

14:31:39.252 TM.T01 0 Processed ReInvite Event

14:31:39.252 TA.T01 23 TAReInvited          rcvd: reInviteResponse from TM

14:31:39.253 TA.T01 23 TAReInvited          rcvd: reConnect from TM

14:31:39.253 SB.CALL 238 ForcedReInviteOrg    Called the reInviteResponse routine

14:31:39.253 SB.CALL 238 ForcedReInviteOrg    Called the reconnect routine

14:31:39.253 SB.CCM isMappable:

14:31:39.253 SB.CCM  :  Call Struct 0x3f40410 :   Call-ID = 238

14:31:39.254 SB.CCM  :  Org Acct = T01    Dst Acct = AutoAttendantAcct

14:31:39.254 SB.CCM  :  Org Port ID = Isdn(Ds1Ds0Trunk) 2/1.1   Dst Port ID = InternalRtpApp 0/1.2

14:31:39.254 SB.CCM  :  RTP Channel = 0/1.2

14:31:39.254 SB.CCM isMappable: Call Connection Type is TDM_TO_RTP

14:31:39.254 SB.CCM isMappable: Creating SDP Offer

14:31:39.255 SB.CCM updateOfferWithEndpointConfig: DTMF(NTE 101), VAD(off), ptime(0)

14:31:39.256 SB.CCM translateOffer: offer codec list: PCMU G729

14:31:39.257 SB.CCM translateOffer: revised offer codec list: PCMU G729

14:31:39.257 SB.CCM translateOffer: codec list after answerer: G729

14:31:39.258 SB.CCM translateOffer: codec list after transcode add: G729

14:31:39.259 SB.CCM translateOffer: compatible DTMF signaling: answerer restriction(NTE 101), offer(NTE 101): DTMF transcoding unnecessary, using offer

14:31:39.259 SB.CCM translateOffer: success

14:31:39.260 SB.CALL 238 ForcedReInviteOrg    reInvite with SDP sent to AutoAttendantAcct

14:31:39.260 SB.CALL 238 State change      >> ForcedReInviteOrg->ForcedReInviteDst

14:31:39.260 AUTOATTENDANT.CA:0 DigitGathering - rcvd: reInvite from SB

14:31:39.260 AUTOATTENDANT.CA:0 DigitGathering - updateSdpInActiveCallStruct: Creating SDP Answer based on SDP Offer

14:31:39.262 SB.CALL 238 ForcedReInviteDst    Called the reInviteResponse routine

14:31:39.262 SB.CALL 238 ForcedReInviteDst    Called the reconnect routine

14:31:39.262 SB.CCM disconnect:

14:31:39.262 SB.CCM  :  Call Struct 0x3f40410 :   Call-ID = 238

14:31:39.262 SB.CCM  :  Org Acct = T01    Dst Acct = AutoAttendantAcct

14:31:39.262 SB.CCM  :  Org Port ID = Isdn(Ds1Ds0Trunk) 2/1.1   Dst Port ID = InternalRtpApp 0/1.2

14:31:39.263 SB.CCM  :  SDP Transaction = CallID: 238

14:31:39.263 SB.CCM  :  SDP Offer = 0x03cee510, (127.0.0.3:10766)

14:31:39.263 SB.CCM  :  SDP Answer = 0x03cc2010, (127.0.0.1:10768)

14:31:39.263 SB.CCM  :  RTP Channel = 0/1.2

14:31:39.263 MOH.APP printCSHoldStates, disconnect: towOrig 0, towDest 0 origHold 0 destHold 0 isHold 0

14:31:39.264 SB.CCM disconnect: Call Connection Type is TDM_TO_RTP

14:31:39.264 SB.CCM disconnect, music on hold

14:31:39.264 SB.CCM disconnect: Stopping RTP Channel 0/1.2

14:31:39.264 RTP.CHANNEL Channel 0/1.2 stopped successfully.

14:31:39.264 SB.CCM disconnect: Disconnecting TDM streams

14:31:39.265 SB.CCM isResponseMappable:

14:31:39.265 SB.CCM  :  Call Struct 0x3f40410 :   Call-ID = 238

14:31:39.265 SB.CCM  :  Org Acct = T01    Dst Acct = AutoAttendantAcct

14:31:39.265 SB.CCM  :  Org Port ID = Isdn(Ds1Ds0Trunk) 2/1.1   Dst Port ID = InternalRtpApp 0/1.2

14:31:39.265 SB.CCM  :  SDP Transaction = CallID: 238

14:31:39.266 SB.CCM  :  SDP Offer = 0x03cee510, (127.0.0.3:10766)

14:31:39.266 SB.CCM  :  SDP Answer = 0x03cc2010, (127.0.0.1:10768)

14:31:39.266 SB.CCM  :  RTP Channel = 0/1.2

14:31:39.266 SB.CCM isResponseMappable: reversing call connection type to compensate for event originator direction

14:31:39.267 SB.CCM isResponseMappable: Call Connection Type is RTP_TO_TDM

14:31:39.267 SB.CCM isResponseMappable: Modifying SDP Answer

14:31:39.268 SB.CCM translateAnswer: offer  codec list: PCMU G729

14:31:39.268 SB.CCM                : answer codec list: G729

14:31:39.269 SB.CCM translateAnswer: CODEC transcoding is not required

14:31:39.269 SB.CCM translateAnswer: offer / answer DTMF signaling identical: DTMF transcoding not required

14:31:39.269 SB.CCM translateAnswer: success

14:31:39.270 SB.CALL 238 ForcedReInviteDst    isResponseMappable passed, reconnecting both accounts

14:31:39.270 RTP.CHANNEL t1 2/1.1 - Dsp 0/1.2 - RTP: stopping

14:31:39.270 TA.T01 23 TAReInvited          reconnectResponse event accepted

14:31:39.271 TA.T01 23 State change      >> TAReInvited->TAConnected (TAS_Connected)

14:31:39.271 TM.T01 0 received reConnectResponse event

14:31:39.271 AUTOATTENDANT.CA:0 DigitGathering - rcvd: reconnectResponse from SB

14:31:39.272 TA.T01 23 TAConnected          rcvd: finalizeConnect from TM

14:31:39.272 TA.T01 23 TAConnected          forwarding finalizeConnect from TM

14:31:39.272 TA.T01 23 TAConnected          sent finalizeConnect to SB

14:31:39.272 SB.CALL 238 ForcedReInviteDst    Called the finalizeConnect routine

14:31:39.272 SB.CALL 238 ForcedReInviteDst    Called the finalizeConnect routine

14:31:39.273 SB.CCM connect:

14:31:39.273 SB.CCM  :  Call Struct 0x3f40410 :   Call-ID = 238

14:31:39.273 SB.CCM  :  Org Acct = T01    Dst Acct = AutoAttendantAcct

14:31:39.273 SB.CCM  :  Org Port ID = Isdn(Ds1Ds0Trunk) 2/1.1   Dst Port ID = InternalRtpApp 0/1.2

14:31:39.273 SB.CCM  :  SDP Transaction = CallID: 238

14:31:39.274 SB.CCM  :  SDP Offer = 0x03cee510, (127.0.0.3:10766)

14:31:39.274 SB.CCM  :  SDP Answer = 0x03cc2010, (127.0.0.1:10768)

14:31:39.274 SB.CCM  :  RTP Channel = 0/1.2

14:31:39.274 MOH.APP printCSHoldStates, connect_: towOrig 0, towDest 0 origHold 0 destHold 0 isHold 0

14:31:39.274 SB.CCM connect: Call Connection Type is TDM_TO_RTP

14:31:39.275 SB.CCM SDP offer is 127.0.0.3:10766, SDP answer is 127.0.0.1:10768

14:31:39.276 SB.CCM connect: Connected RTP/TDM via MCM

14:31:39.276 SB.CCM handleMediaConnectionRtpChannel: No RTP channel to set up

14:31:39.277 SB.CCM setupRtpChannel, source 2, silence 0

14:31:39.277 SB.CCM setupRtpChannel: setup using media connection

14:31:39.277 SB.CCM Looking up source address for destination 127.0.0.1

14:31:39.277 SB.CCM setupRtpChannel: Source IP addr = 127.0.0.1, port = 10766

14:31:39.278 SB.CCM setupRtpChannel: Target IP addr = 127.0.0.1, port = 10768

14:31:39.278 SB.CCM setupRtpChannel: Undo of previous operation not required

14:31:39.278 SB.CCM setupRtpChannel: *** Internal address used for RTP channel!!! ***

14:31:39.278 SB.CCM getFinalCodec: G729

14:31:39.279 SB.CCM getFinalCodec: G729

14:31:39.279 SB.CCM setupRtpChannel: Configuring RTP Channel 0/1.2 to Src 127.0.0.1:10766 Trg 127.0.0.1:10768 via G729 Rx G729

14:31:39.279 SB.CCM setupRtpChannel: fpp=2 echo=on dtmf=101/101 dscp=46 vad=off isOffer yes

14:31:39.279 SB.CCM setupRtpChannel: Starting RTP Channel

14:31:39.280 RTP.CHANNEL Channel 0/1.2 session statistics cleared.

14:31:39.280 RTP.CHANNEL Channel 0/1.2 started successfully.

14:31:39.280 SB.CCM firewallConnectCall: Set up firewall from media connections

14:31:39.280 SB.CCM sdpFirewall: invoked with offer - [::]:10768, answer - 127.0.0.1:10768

14:31:39.281 SB.CCM sdpFirewall: 'any' address detected, no action taken

14:31:39.281 SB.CCM sdpFirewall: invoked with offer - [::]:10766, answer - 127.0.0.1:10766

14:31:39.281 SB.CCM sdpFirewall: 'any' address detected, no action taken

14:31:39.281 SB.CCM connect: TDM streams: port(Isdn(Ds1Ds0Trunk) 2/1.1) to port(InternalRtpApp 0/1.2)

14:31:39.282 SB.CCM finalizeConnect: connection already finalized(6)

14:31:39.282 SB.CALL 238 State change      >> ForcedReInviteDst->Connected

14:31:39.282 RTP.CHANNEL t1 2/1.1 - Dsp 0/1.2 - RTP: starting

14:31:39 VXMLInterpreter vxml. Ca:0 # Platform Event: activate

14:31:39 VXMLInterpreter vxml. Ca:0 # Set 'SystemLanguage' to '0'

14:31:39 VXMLInterpreter vxml. Ca:0 # Set 'SystemDefaultPrompts' to 'CFLASH:/SystemDefaultPrompts'

14:31:39 VXMLInterpreter vxml. Ca:0 # Set 'RootForXML' to 'CFLASH:/AA/'

14:31:39 VXMLInterpreter vxml. Ca:0 # Set 'RootForWAV' to 'CFLASH:/AA/Prompts/'

14:31:39 VXMLInterpreter vxml. Ca:0 # Set 'operator' to '0'

14:31:39 VXMLInterpreter vxml. Ca:0 # Set 'internalError' to 'tel:@operator@'

14:31:39 VXMLInterpreter vxml. Ca:0 # Set 'collect' to ''

14:31:39 VXMLInterpreter vxml. Ca:0 # Set 'disconnect' to 'disconnect:'

14:31:39 VXMLInterpreter vxml. Ca:0 # Set 'repeat' to 'previous.0'

14:31:39 VXMLInterpreter vxml. Ca:0 # Set 'CallerName' to 'UNKNOWN'

14:31:39 VXMLInterpreter vxml. Ca:0 # Set 'CallerNumber' to 'UNKNOWN'

14:31:39 VXMLInterpreter vxml. Ca:0 # Set 'CalleeName' to 'UNKNOWN'

14:31:39 VXMLInterpreter vxml. Ca:0 # Set 'CalleeNumber' to 'UNKNOWN'

14:31:39 VXMLInterpreter vxml. Ca:0 # Set 'CallerNumber' to '718608169986'

14:31:39 VXMLInterpreter vxml. Ca:0 # Set 'CalleeName' to 'AutoAttendantAccount'

14:31:39 VXMLInterpreter vxml. Ca:0 # Set 'CalleeNumber' to '820'

14:31:39 VXMLInterpreter vxml.820 Ca:0 # Set 'CalledOriginalNumber' to '820'

14:31:39 VXMLInterpreter vxml.820 Ca:0 # Set 'FullOptions' to 'Yes'

14:31:39 VXMLInterpreter vxml.820 Ca:0   CallerName:UNKNOWN CallerNumber:718608169986 CalleeName:AutoAttendantAccount CalleeNumber:820 CalledOriginalNumber:820

14:31:39 VXMLInterpreter vxml.820 Ca:0 # Set 'RootDocument' to 'defaultAA.xml'

14:31:39 VXMLInterpreter vxml.820 Ca:0 Process Action: 'defaultAA.xml' (defaultAA.xml)

14:31:39 VXMLInterpreter vxml.820 Ca:0   Loaded XML from 'CFLASH:/AA/defaultAA.xml'

14:31:39 VXMLInterpreter vxml.820 Ca:0 # Set 'LoopCount.DefaultAA' to '1'

14:31:39 VXMLInterpreter vxml.820 Ca:0 Entering state: '<menu id='DefaultAA'>'

14:31:39 VXMLInterpreter vxml.820 Ca:0 # Entering File: 'CFLASH:/AA/defaultAA.xml' Offset: 1625'

14:31:39 VXMLInterpreter vxml.820 Ca:0 # Set 'operator' to '0'

14:31:39 VXMLInterpreter vxml.820 Ca:0 # Set 'collect' to ''

14:31:39 VXMLInterpreter vxml.820 Ca:0 # Started prompt 'CFLASH:/AA/Prompts/DayAA.wav'

2016.08.10 14:31:40 SMDR 237        08/10/2016 14:31:40 00:00 00:00:00 0:00:00:00 0    E T01 02/01                 718608169986    00/00 Main Incoming   100             N 8608286531      N  v2

14:31:43.198 RTP.DTMF-2833 E = 1, R = X, Duration = 2240, Volume = 4, Event = 3

14:31:43 VXMLInterpreter vxml.820 Ca:0 # Platform Event: dtmf '3'

14:31:43 VXMLInterpreter vxml.820 Ca:0 Stopping current prompt.

14:31:43 VXMLInterpreter vxml.820 Ca:0 ProcessingLogic.dtmf input '3' matched ''

14:31:43 VXMLInterpreter vxml.820 Ca:0 # Set 'collect' to '3'

14:31:43 VXMLInterpreter vxml.820 Ca:0 Leaving state: '<menu id='DefaultAA'>'

14:31:43 VXMLInterpreter vxml.820 Ca:0 Entering state: '<choice>'

14:31:43 VXMLInterpreter vxml.820 Ca:0 # Entering File: 'CFLASH:/AA/defaultAA.xml' Offset: 1336'

14:31:43 VXMLInterpreter vxml.820 Ca:0 Starting timer for 10 mseconds.

14:31:43.208 RTP.DTMF-2833 E = 1, R = X, Duration = 2240, Volume = 4, Event = 3

14:31:43 VXMLInterpreter vxml.820 Ca:0 Process Action: '#digitcollect01' (#digitcollect01)

14:31:43 VXMLInterpreter vxml.820 Ca:0 Leaving state: '<choice>'

14:31:43 VXMLInterpreter vxml.820 Ca:0 # Set 'LoopCount.digitcollect01' to '1'

14:31:43 VXMLInterpreter vxml.820 Ca:0 Entering state: '<digitcollect id='digitcollect01'>'

14:31:43 VXMLInterpreter vxml.820 Ca:0 # Entering File: 'CFLASH:/AA/defaultAA.xml' Offset: 746'

14:31:43 VXMLInterpreter vxml.820 Ca:0 # Set 'collect' to ''

14:31:43 VXMLInterpreter vxml.820 Ca:0 # Set 'collect' to '3'

14:31:43 VXMLInterpreter vxml.820 Ca:0 Starting timer for 5000 mseconds.

14:31:43.218 RTP.DTMF-2833 E = 1, R = X, Duration = 2240, Volume = 4, Event = 3

14:31:43.588 RTP.DTMF-2833 E = 1, R = X, Duration = 2240, Volume = 4, Event = 2

14:31:43 VXMLInterpreter vxml.820 Ca:0 # Platform Event: dtmf '2'

14:31:43 VXMLInterpreter vxml.820 Ca:0 Stopping current timer.

14:31:43 VXMLInterpreter vxml.820 Ca:0 # Set 'collect' to '32'

14:31:43 VXMLInterpreter vxml.820 Ca:0 Starting timer for 5000 mseconds.

14:31:43 VXMLInterpreter vxml.820 Ca:0 ProcessingLogic.dtmf '32' no match yet ...

14:31:43.597 RTP.DTMF-2833 E = 1, R = X, Duration = 2240, Volume = 4, Event = 2

14:31:43.607 RTP.DTMF-2833 E = 1, R = X, Duration = 2240, Volume = 4, Event = 2

14:31:43.938 RTP.DTMF-2833 E = 1, R = X, Duration = 2160, Volume = 4, Event = 4

14:31:43 VXMLInterpreter vxml.820 Ca:0 # Platform Event: dtmf '4'

14:31:43 VXMLInterpreter vxml.820 Ca:0 Stopping current timer.

14:31:43 VXMLInterpreter vxml.820 Ca:0 ProcessingLogic.dtmf input '324' matched ''

14:31:43 VXMLInterpreter vxml.820 Ca:0 # Set 'collect' to '324'

14:31:43 VXMLInterpreter vxml.820 Ca:0 Leaving state: '<digitcollect id='digitcollect01'>'

14:31:43 VXMLInterpreter vxml.820 Ca:0 Entering state: '<choice>'

14:31:43 VXMLInterpreter vxml.820 Ca:0 # Entering File: 'CFLASH:/AA/defaultAA.xml' Offset: 680'

14:31:43 VXMLInterpreter vxml.820 Ca:0 Starting timer for 10 mseconds.

14:31:43.947 RTP.DTMF-2833 E = 1, R = X, Duration = 2160, Volume = 4, Event = 4

14:31:43 VXMLInterpreter vxml.820 Ca:0 Process Action: '#transfer01' (#transfer01)

14:31:43 VXMLInterpreter vxml.820 Ca:0 Leaving state: '<choice>'

14:31:43 VXMLInterpreter vxml.820 Ca:0 # Set 'LoopCount.transfer01' to '1'

14:31:43 VXMLInterpreter vxml.820 Ca:0 Entering state: '<transfer id='transfer01'>'

14:31:43 VXMLInterpreter vxml.820 Ca:0 # Entering File: 'CFLASH:/AA/defaultAA.xml' Offset: 873'

14:31:43 VXMLInterpreter vxml.820 Ca:0 Starting timer for 10 mseconds.

14:31:43.957 RTP.DTMF-2833 E = 1, R = X, Duration = 2160, Volume = 4, Event = 4

14:31:43 VXMLInterpreter vxml.820 Ca:0 Process Action: 'tel:324' (tel:@collect@)

14:31:43 VXMLInterpreter vxml.820 Ca:0   Transferring call to 'tel:324'

14:31:43.963 AUTOATTENDANT. Ca:0 transferCall: attempting transfer

14:31:43.963 AUTOATTENDANT.CA:0 DigitGathering - State Change: DigitGathering to Referring

14:31:43.963 SB.CALL 238 Connected            refer(324) from AutoAttendantAcct to T01

14:31:43.963 TA.T01 23 TAConnected          refer event accepted

14:31:43.964 TA.T01 23 TAConnected          referred to 324, making new call

14:31:43.964 TA.T01 23 TAConnected          sent: call to SB

14:31:43.965 TA.T01 23 State change      >> TAConnected->TAInboundCall (TAS_Calling)

14:31:43.965 SB.CALL 238 Connected            referResponse(true) from T01 to AutoAttendantAcct

14:31:43.965 SB.CALL 239 Idle                 Called the call routine with 324

14:31:43.965 SB.CCM isMappable:

14:31:43.965 SB.CCM  :  Call Struct 0x43f3c10 :   Call-ID = 239

14:31:43.966 SB.CCM  :  Org Acct = T01    Dst Acct = 324

14:31:43.966 SB.CCM  :  Org Port ID = Isdn(Ds1Ds0Trunk) 2/1.1   Dst Port ID = unknown 0/0

14:31:43.966 SB.CCM isMappable: Call Connection Type is TDM_TO_RTP

14:31:43.966 SB.CCM isMappable: Reserving RTP Channel 0/1.3

14:31:43.966 SB.CCM isMappable: Creating SDP Offer

14:31:43.968 SB.CCM updateOfferWithEndpointConfig: DTMF(NTE 101), VAD(off), ptime(0)

14:31:43.969 SB.CCM translateOffer: offer codec list: PCMU G729

14:31:43.969 SB.CCM translateOffer: revised offer codec list: PCMU G729

14:31:43.970 SB.CCM translateOffer: codec list after answerer: PCMU G729

14:31:43.971 SB.CCM translateOffer: DTMF signaling: answerer has no restrictions configured, passing offer(NTE 101) through

14:31:43.971 SB.CCM translateOffer: success

14:31:43.972 SB.CALL 239 Idle                 Call sent from T01 to 324 (324)

14:31:43.972 SB.CALL 239 State change      >> Idle->Delivering

14:31:43.972 AUTOATTENDANT.CA:0 Referring - rcvd: referResponse from SB

14:31:43.972 RTP.MANAGER t1 2/1.1 - empty - RTP: Request resource

14:31:43.972 RTP.MANAGER t1 2/1.1 - Dsp 0/1.3 - RTP: DSP channel allocated for the resource

14:31:43.973 RTP.PROVIDER t1 2/1.1 - Dsp 0/1.3 - RTP: providing already allocated RTP channel

14:31:43.973 TA.T01 23 TAInboundCall        CallResp event accepted

14:31:43.973 TA.T01 23 State change      >> TAInboundCall->TAConnectWaitIn (TAS_Calling)

14:31:43.973 SA.324 rcvd: deliver from SB

14:31:43.973 SA.324 Ca:0 Idle                 sent: deliverResponse(accept) to SB

14:31:43.974 SA.324 Ca:0 Idle                 Set my destination sessionCookie to my call Appearance

14:31:43.974 SA.324 Ca:0 Idle                 State change      >> Idle->Ringing (CAS_Ringing)

14:31:43.983 SA.324 Ca:0 Ringing              sent: AcctPhoneMgr_cachg(CAS_Ringing) to PM

14:31:43.983 PM.324 Ca:0 SipPM_Idle           rcvd: CAS_Ringing

14:31:43.983 PM.324 Ca:0 State change      >> SipPM_Idle->SipPM_Ringing

14:31:43.984 PM.324 Ca:0 Looking up source address for destination 10.10.20.84

14:31:43.984 PM.324 Ca:0 call-leg (0x5aa5dc0) -> src: 10.10.20.1 : 5060  dst: 10.10.20.84 : 5060

14:31:43.985 PM.324 Ca:0 SDP DPI call ID 239 : No media bin.

14:31:43.985 PM.324 Ca:0 Processing new SDP entries.

14:31:43.985 PM.324 Ca:0 Checking for internal Media Gateway IP Address

14:31:43.985 PM.324 Ca:0 Using RTP Channel 0/1.3

14:31:43.986 PM.324 Ca:0 Inserting 10.10.20.1 into SDP for Media Gateway

14:31:43.986 PM.324 Ca:0 Adding RTP Media Gateway Entry: 127.0.0.3:10770 -> 10.10.20.1:10770

14:31:43.986 PM.324 Ca:0 Allocating anchor ports 10770 and 10771 for interface 10.10.20.1

14:31:43.989 PM.324 Ca:0 SipPM_Ringing        call-leg (P:0x5aa5dc0 S:0x0) -> Inviting (Local Inviting)

14:31:43.990 PM.324 Ca:0 SipPM_Ringing        Default: CallLegStateChanged to Inviting ignored

14:31:43.990 PM.324 Ca:0 SipPM_Ringing        sent: INVITE

14:31:43.990 SB.CALL 239 Delivering           Called the deliverResponse routine from Delivering

14:31:43.990 SB.CALL 239 Delivering           DeliverResponse(accept) sent from 324 to T01

14:31:43.991 TA.T01 23 TAConnectWaitIn      deliverResponse event accepted

14:31:43.991 TA.T01 23 TAConnectWaitIn      ERROR! deliverResponse ignored

14:31:44.018 PM.324 Ca:0 SipPM_Ringing        rcvd SIP call-leg response: 100 Trying

14:31:44.018 PM.324 Ca:0 SipPM_Ringing        call-leg (P:0x5aa5dc0 S:0x0) -> Proceeding (Remote Provisional Response)

14:31:44.104 PM.324 Ca:0 SipPM_Ringing        rcvd SIP call-leg response: 180 Ringing

14:31:44.105 PM.324 Ca:0 SipPM_Ringing        sent: SA->Alert

14:31:44.105 PM.324 Ca:0 call-leg prack -> Rel Prov Response Rcvd / Undefined : -1

14:31:44.105 PM.324 Ca:0 100rel prov resp rcvd, sent PRACK

14:31:44.107 PM.324 Ca:0 call-leg prack -> Prack Sent / Undefined : -1

14:31:44.107 SA.324 Ca:0 Ringing              rcvd: AcctPhoneMgr_alert from PM

14:31:44.107 SA.324 Ca:0 Ringing              sent: deliverResponse(alert) to SB

14:31:44.108 SB.CALL 239 Delivering           Called the deliverResponse routine from Delivering

14:31:44.108 SB.CALL 239 Delivering           Alert sent from 324 to T01

14:31:44.108 SB.CALL 239 State change      >> Delivering->Alerting

14:31:44.108 TA.T01 23 TAConnectWaitIn      alert event accepted

14:31:44.108 TA.T01 23 sending to SB: Notify(180)

14:31:44.109 TM.T01 23 IsdnTmStateInboundConnected->IsdnTmStateInboundConnectedAlerting

14:31:44.109 TM.T01 23 IsdnTmStateInboundConnectedAlerting::enter()

14:31:44.109 SB.CALL 238 Connected            notify(180) sent from T01 to AutoAttendantAcct, MOH orig = false, MOH dest = false

14:31:44.110 TONESERVICES.EVENTS t1 2/1.1 - empty - Ringback Generation: Request resource

14:31:44.110 TONESERVICES.EVENTS t1 2/1.1 - Dsp 0/1.2 - Ringback Generation: DSP channel allocated for the resource

14:31:44.110 TONESERVICES.EVENTS t1 2/1.1 - Dsp 0/1.2 - Ringback Generation: constructed

14:31:44.111 TONESERVICES.EVENTS t1 2/1.1 - Dsp 0/1.2 - Ringback Generation: starting

14:31:44.111 TONESERVICES.EVENTS t1 2/1.1 - Dsp 0/1.2 - Ringback Generation: TDM map

14:31:44.111 AUTOATTENDANT.CA:0 Referring - rcvd: notify from SB

14:31:44.111 AUTOATTENDANT.CA:0 Referring - State Change: Referring to ClearingSB

14:31:44.111 SB.CALL 238 Connected            notifyResponse(true) from AutoAttendantAcct to T01

14:31:44.112 SB.CALL 238 Connected            Called the clearCall routine

14:31:44.112 SB.CALL 238 Connected            ClearCall sent from AutoAttendantAcct to T01

14:31:44.112 SB.CALL 238 State change      >> Connected->Clearing

14:31:44.112 TA.T01 23 TAConnectWaitIn      notifyResponse event accepted for referred CS

14:31:44.112 TA.T01 23 TAConnectWaitIn      ClearCall event accepted for referred CS

14:31:44.113 SB.CALL 238 Clearing             Called the clearResponse routine

14:31:44.113 SB.CALL 238 State change      >> Clearing->CallIdlePending

14:31:44.113 SB.CCM release:

14:31:44.113 SB.CCM  :  Call Struct 0x3f40410 :   Call-ID = 238

14:31:44.113 SB.CCM  :  Org Acct = T01    Dst Acct = AutoAttendantAcct

14:31:44.114 SB.CCM  :  Org Port ID = Isdn(Ds1Ds0Trunk) 2/1.1   Dst Port ID = InternalRtpApp 0/1.2

14:31:44.114 SB.CCM  :  RTP Channel = 0/1.2

14:31:44.114 SB.CCM release: Call Connection Type is TDM_TO_RTP

14:31:44.114 SB.CCM release: Releasing RTP Channel 0/1.2

14:31:44.115 RTP.CHANNEL Channel 0/1.2 stopped successfully.

14:31:44.115 RTP.CHANNEL Channel 0/1.2 released successfully.

14:31:44.115 SB.CALL 238 CallIdlePending      ClearResponse sent from T01 to AutoAttendantAcct

14:31:44.115 AUTOATTENDANT.CA:0 ClearingSB - rcvd: clearResponse from SB

14:31:44.115 AUTOATTENDANT.CA:0 ClearingSB - State Change: ClearingSB to Idle

14:31:44.116 RTP.CHANNEL t1 2/1.1 - Dsp 0/1.2 - RTP: releasing RTP resource

14:31:44.116 RTP.CHANNEL t1 2/1.1 - Dsp 0/1.2 - RTP: releasing

14:31:44.116 RTP.CHANNEL t1 2/1.1 - Dsp 0/1.2 - RTP: stopping

14:31:44 VXMLInterpreter vxml.820 Ca:0 # Platform Event: deactivate

14:31:44 VXMLInterpreter vxml.820 Ca:0 Leaving state: '<transfer id='transfer01'>'

14:31:44.129 PM.324 Ca:0 SipPM_Ringing        rcvd SIP call-leg response: 200 OK

14:31:44.130 PM.324 Ca:0 call-leg prack -> Prack Final Response Rcvd / Undefined : 200

2016.08.10 14:31:45 SMDR 237        08/10/2016 14:31:39 00:00 00:00:00 0:00:00:06 0    E T01 02/01                 718608169986    00/01 AutoAttendantAc 820             N 8608286531      F  v2

14:31:59.032 PM.321 Ca:0 SipPM_Connected      rcvd SIP call-leg request: BYE

14:31:59.033 PM.321 Ca:0 SipPM_Connected      call-leg (P:0x5aa5b90 S:0x0) -> Disconnected (Remote Disconnected)

14:31:59.033 PM.321 Ca:0 SipPM_Connected      rcvd: BYE

14:31:59.033 PM.321 Ca:0 State change      >> SipPM_Connected->SipPM_Closing

14:31:59.033 PM.321 Ca:0 SipPM_Closing        sent: SA->Appearance Off

14:31:59.035 PM.321 UISM                      call-leg (0x5aa5b90) -> Terminated

14:31:59.035 SA.321 Ca:0 Connected            rcvd: AcctPhoneMgr_appearance(OFF) from PM

14:31:59.035 SA.321 Ca:0 Connected            sent: clearCall to SB

14:31:59.035 SA.321 Ca:0 Connected            State change      >> Connected->Clearing (CAS_Active)

14:31:59.036 SB.CALL 236 Connected            Called the clearCall routine

14:31:59.036 SB.CALL 236 Connected            ClearCall sent from 321 to T01

14:31:59.036 SB.CALL 236 State change      >> Connected->Clearing

14:31:59.036 TA.T01 17 TAConnected          ClearCall event accepted

14:31:59.036 TA.T01 17 State change      >> TAConnected->TAClearingComplete (TAS_Clearing)

14:31:59.037 TM.T01 17 IsdnTmStateOutboundConnected->IsdnTmStateUserClearing

14:31:59.037 TM.T01 17 IsdnTmStateUserClearing::enter()

14:31:59.038 SB.CALL 236 Clearing             Called the clearResponse routine

14:31:59.038 SB.CALL 236 State change      >> Clearing->CallIdlePending

14:31:59.038 SB.CCM disconnect:

14:31:59.039 SB.CCM  :  Call Struct 0x53e0410 :   Call-ID = 236

14:31:59.039 SB.CCM  :  Org Acct = 321    Dst Acct = T01

14:31:59.039 SB.CCM  :  Org Port ID = SipPhone 0/1.1   Dst Port ID = Isdn(Ds1Ds0Trunk) 2/1.17

14:31:59.039 SB.CCM  :  RTP Channel = 0/1.1

14:31:59.040 MOH.APP printCSHoldStates, disconnect: towOrig 0, towDest 0 origHold 0 destHold 0 isHold 0

14:31:59.040 SB.CCM disconnect: Call Connection Type is RTP_TO_TDM

14:31:59.040 SB.CCM disconnect, music on hold

14:31:59.040 SB.CCM disconnect: Stopping RTP Channel 0/1.1

14:31:59.040 RTP.CHANNEL Channel 0/1.1 stopped successfully.

14:31:59.041 SB.CCM disconnect: Disconnecting TDM streams

14:31:59.041 SB.CCM release:

14:31:59.041 SB.CCM  :  Call Struct 0x53e0410 :   Call-ID = 236

14:31:59.041 SB.CCM  :  Org Acct = 321    Dst Acct = T01

14:31:59.041 SB.CCM  :  Org Port ID = SipPhone 0/1.1   Dst Port ID = Isdn(Ds1Ds0Trunk) 2/1.17

14:31:59.041 SB.CCM  :  RTP Channel = 0/1.1

14:31:59.042 SB.CCM release: Call Connection Type is RTP_TO_TDM

14:31:59.042 SB.CCM release: Releasing RTP Channel 0/1.1

14:31:59.042 RTP.CHANNEL Channel 0/1.1 released successfully.

14:31:59.042 SB.CALL 236 CallIdlePending      ClearResponse sent from T01 to 321

14:31:59.043 TONESERVICES.EVENTS t1 2/1.17 - empty - FastBusy Generation: Request resource

14:31:59.043 TONESERVICES.EVENTS t1 2/1.17 - Dsp 0/1.1 - FastBusy Generation: DSP channel allocated for the resource

14:31:59.043 TONESERVICES.EVENTS t1 2/1.17 - Dsp 0/1.1 - FastBusy Generation: constructed

14:31:59.043 TONESERVICES.EVENTS t1 2/1.17 - Dsp 0/1.1 - FastBusy Generation: starting

14:31:59.044 TONESERVICES.EVENTS t1 2/1.17 - Dsp 0/1.1 - FastBusy Generation: TDM map

14:31:59.044 SA.321 Ca:0 Clearing             rcvd: clearResponse from SB

14:31:59.044 SA.321 Ca:0 Clearing             State change      >> Clearing->Idle (CAS_Idle)

14:31:59.053 TM.T01 17 IsdnTmStateUserClearing->IsdnTmStateIdling

14:31:59.053 TM.T01 17 IsdnTmStateIdling::enter()

14:31:59.053 TM.T01 17 IsdnTmStateIdling - send appearance off

14:31:59.053 TM.T01 17 IsdnTmStateIdling->IsdnTmStateIdle

14:31:59.054 TM.T01 17 IsdnAppearanceChannel::releaseChannel

14:31:59.054 TM.T01 17 IsdnTmStateIdle::enter()

14:31:59.054 SA.321 Ca:0 Idle                 sent: AcctPhoneMgr_cachg(CAS_Idle) to PM

14:31:59.055 PM.321 Ca:0 State change      >> SipPM_Closing->SipPM_Terminated

14:31:59.055 PM.321 Ca:0 State change      >> SipPM_Terminated->SipPM_Idle

14:31:59.055 RTP.CHANNEL t1 2/1.17 - Dsp 0/1.1 - RTP: stopping

14:31:59.056 RTP.CHANNEL t1 2/1.17 - Dsp 0/1.1 - RTP: releasing RTP resource

14:31:59.056 RTP.CHANNEL t1 2/1.17 - Dsp 0/1.1 - RTP: releasing

14:31:59.056 TONESERVICES.EVENTS t1 2/1.17 - Dsp 0/1.1 - FastBusy Generation: stopping

14:31:59.057 TONESERVICES.EVENTS t1 2/1.17 - Dsp 0/1.1 - FastBusy Generation: TDM unmap

14:31:59.057 RTP.CHANNEL t1 2/1.17 - Dsp 0/1.1 - FastBusy Generation: releasing RTP resource

14:31:59.057 TONESERVICES.EVENTS t1 2/1.17 - Dsp 0/1.1 - FastBusy Generation: release

14:31:59.057 TA.T01 17 TAClearingComplete   rcvd: appearance off from TM

14:31:59.057 TA.T01 17 TAClearingComplete   Clear Local Variables

14:31:59.058 TA.T01 17 State change      >> TAClearingComplete->TAIdle (TAS_Idle)

2016.08.10 14:32:00 SMDR 236        08/10/2016 14:30:22 00:12 00:00:00 0:00:01:38 0    I N/A 00/01 Warehouse       321             02/01 T01             78603560174     Y 78603560174     N  v2

14:32:08.000 PM.324 Ca:0 State change      >> SipPM_Ringing->SipPM_NoAnswer

14:32:08.000 PM.324 Ca:0 SipPM_NoAnswer       sent: SA->NoAnswer

14:32:08.000 SA.324 Ca:0 Ringing              rcvd: AcctPhoneMgr_noAnswer from PM

14:32:08.001 SA.324 sent: ClearCall to SB

14:32:08.001 SA.324 Ca:0 Ringing              State change      >> Ringing->Clearing (CAS_Ringing)

14:32:08.001 SB.CALL 239 Alerting             Called the clearCall routine

14:32:08.001 SB.CALL 239 State change      >> Alerting->Clearing

14:32:08.002 SB.CALL 239 Clearing             ClearCall sent from 324 to T01

14:32:08.002 TA.T01 23 TAConnectWaitIn      ClearCall event accepted

14:32:08.002 TA.T01 23 TAConnectWaitIn      Processing a forward from call coverage

14:32:08.002 TA.T01 23 TAConnectWaitIn      sent: call to SB

14:32:08.003 TA.T01 23 State change      >> TAConnectWaitIn->TAInboundCall (TAS_Alerting)

14:32:08.003 SB.CALL 239 Clearing             Called the clearResponse routine

14:32:08.003 SB.CALL 239 State change      >> Clearing->CallIdlePending

14:32:08.003 SB.CCM release:

14:32:08.003 SB.CCM  :  Call Struct 0x43f3c10 :   Call-ID = 239

14:32:08.004 SB.CCM  :  Org Acct = T01    Dst Acct = 324

14:32:08.004 SB.CCM  :  Org Port ID = Isdn(Ds1Ds0Trunk) 2/1.1   Dst Port ID = SipPhone 0/0

14:32:08.004 SB.CCM  :  SDP Transaction = CallID: 239

14:32:08.004 SB.CCM  :  SDP Offer = 0x03cc2610, (127.0.0.3:10770)

14:32:08.004 SB.CCM  :  RTP Channel = 0/1.3

14:32:08.005 SB.CCM release: Call Connection Type is TDM_TO_RTP

14:32:08.005 SB.CCM release: Releasing RTP Channel 0/1.3

14:32:08.005 RTP.CHANNEL Channel 0/1.3 released successfully.

14:32:08.005 SB.CALL 239 CallIdlePending      ClearResponse sent from T01 to 324

14:32:08.006 SB.CALL 240 Idle                 Called the call routine with 850

14:32:08.006 SB.CCM isMappable:

14:32:08.006 SB.CCM  :  Call Struct 0x53e0410 :   Call-ID = 240

14:32:08.006 SB.CCM  :  Org Acct = T01    Dst Acct = 850

14:32:08.006 SB.CCM  :  Org Port ID = Isdn(Ds1Ds0Trunk) 2/1.1   Dst Port ID = unknown 0/0

14:32:08.007 SB.CCM isMappable: Call Connection Type is TDM_TO_RTP

14:32:08.007 SB.CCM isMappable: Reserving RTP Channel 0/1.2

14:32:08.007 SB.CCM isMappable: Creating SDP Offer

14:32:08.008 SB.CCM updateOfferWithEndpointConfig: DTMF(NTE 101), VAD(off), ptime(0)

14:32:08.009 SB.CCM translateOffer: offer codec list: PCMU G729

14:32:08.010 SB.CCM translateOffer: revised offer codec list: PCMU G729

14:32:08.010 SB.CCM translateOffer: codec list after answerer: G729

14:32:08.011 SB.CCM translateOffer: codec list after transcode add: G729

14:32:08.011 SB.CCM translateOffer: compatible DTMF signaling: answerer restriction(NTE 101), offer(NTE 101): DTMF transcoding unnecessary, using offer

14:32:08.011 SB.CCM translateOffer: success

14:32:08.012 SB.CALL 240 Idle                 Call sent from T01 to 850 (850)

14:32:08.012 SB.CALL 240 State change      >> Idle->Delivering

14:32:08.013 SA.324 Ca:0 Clearing             rcvd: clearResponse from SB

14:32:08.013 SA.324 Ca:0 Clearing             State change      >> Clearing->Idle (CAS_Idle)

14:32:08.021 SA.324 Ca:0 Idle                 sent: AcctPhoneMgr_cachg(CAS_Idle) to PM

14:32:08.021 PM.324 Ca:0 State change      >> SipPM_NoAnswer->FarEnd

14:32:08.024 PM.324 Ca:0 FarEnd               call-leg (P:0x5aa5dc0 S:0x0) -> Cancelling (Local Cancelling)

14:32:08.024 PM.324 Ca:0 FarEnd               ERROR! Unexpected CallLegStateChanged to Cancelling.

14:32:08.025 PM.324 Ca:0 FarEnd               sent: CANCEL message.

14:32:08.025 RTP.CHANNEL t1 2/1.1 - Dsp 0/1.3 - RTP: releasing RTP resource

14:32:08.025 RTP.CHANNEL t1 2/1.1 - Dsp 0/1.3 - RTP: releasing

14:32:08.026 RTP.MANAGER t1 2/1.1 - empty - RTP: Request resource

14:32:08.026 RTP.MANAGER t1 2/1.1 - Dsp 0/1.2 - RTP: DSP channel allocated for the resource

14:32:08.026 RTP.PROVIDER t1 2/1.1 - Dsp 0/1.2 - RTP: providing already allocated RTP channel

14:32:08.026 TA.T01 23 TAInboundCall        CallResp event accepted

14:32:08.027 TA.T01 23 State change      >> TAInboundCall->TAConnectWaitIn (TAS_Alerting)

14:32:08.027 VOICEMAIL.CA:0 Idle - updateSdpInActiveCallStruct: Creating SDP Answer based on SDP Offer

14:32:08.029 VOICEMAIL.CA:0 Idle - State Change: Idle to DigitGathering

14:32:08.029 SB.CALL 240 Delivering           Called the connect routine

14:32:08.029 SB.CCM isResponseMappable:

14:32:08.030 SB.CCM  :  Call Struct 0x53e0410 :   Call-ID = 240

14:32:08.030 SB.CCM  :  Org Acct = T01    Dst Acct = 850

14:32:08.030 SB.CCM  :  Org Port ID = Isdn(Ds1Ds0Trunk) 2/1.1   Dst Port ID = InternalRtpApp 0/0

14:32:08.030 SB.CCM  :  SDP Transaction = CallID: 240

14:32:08.031 SB.CCM  :  SDP Offer = 0x03cc2510, (127.0.0.3:10772)

14:32:08.031 SB.CCM  :  SDP Answer = 0x03cc5410, (127.0.0.1:10774)

14:32:08.031 SB.CCM  :  RTP Channel = 0/1.2

14:32:08.031 SB.CCM isResponseMappable: reversing call connection type to compensate for event originator direction

14:32:08.031 SB.CCM isResponseMappable: Call Connection Type is RTP_TO_TDM

14:32:08.031 SB.CCM isResponseMappable: Modifying SDP Answer

14:32:08.032 SB.CCM translateAnswer: offer  codec list: PCMU G729

14:32:08.032 SB.CCM                : answer codec list: G729

14:32:08.033 SB.CCM translateAnswer: CODEC transcoding is not required

14:32:08.033 SB.CCM translateAnswer: offer / answer DTMF signaling identical: DTMF transcoding not required

14:32:08.033 SB.CCM translateAnswer: success

14:32:08.034 SB.CALL 240 Delivering           Connect sent from 850 to T01

14:32:08.034 SB.CALL 240 State change      >> Delivering->Connecting

14:32:08.034 TA.T01 23 TAConnectWaitIn      connect event accepted

14:32:08.035 TA.T01 23 State change      >> TAConnectWaitIn->TAConnectPending (TAS_Connected)

14:32:08.035 TM.T01 23 IsdnTmStateInboundConnectedAlerting - rcvd tachgConnect

14:32:08.035 TM.T01 23 IsdnTmStateInboundConnectedAlerting->IsdnTmStateInboundConnected

14:32:08.036 TM.T01 23 IsdnTmStateInboundConnected::enter()

14:32:08.036 TONESERVICES.EVENTS t1 2/1.1 - Dsp 0/1.2 - Ringback Generation: stopping

14:32:08.036 TONESERVICES.EVENTS t1 2/1.1 - Dsp 0/1.2 - Ringback Generation: TDM unmap

14:32:08.037 RTP.CHANNEL t1 2/1.1 - Dsp 0/1.2 - Ringback Generation: releasing RTP resource

14:32:08.037 TONESERVICES.EVENTS t1 2/1.1 - Dsp 0/1.2 - Ringback Generation: release

14:32:08.037 TA.T01 23 TAConnectPending     rcvd: connect from TM

14:32:08.037 TA.T01 23 State change      >> TAConnectPending->TAConnected (TAS_Connected)

14:32:08.037 SB.CALL 240 Connecting           Called the connectResponse routine

14:32:08.038 SB.CCM connect:

14:32:08.038 SB.CCM  :  Call Struct 0x53e0410 :   Call-ID = 240

14:32:08.038 SB.CCM  :  Org Acct = T01    Dst Acct = 850

14:32:08.038 SB.CCM  :  Org Port ID = Isdn(Ds1Ds0Trunk) 2/1.1   Dst Port ID = InternalRtpApp 0/0

14:32:08.038 SB.CCM  :  SDP Transaction = CallID: 240

14:32:08.039 SB.CCM  :  SDP Offer = 0x03cc2510, (127.0.0.3:10772)

14:32:08.039 SB.CCM  :  SDP Answer = 0x03cc5410, (127.0.0.1:10774)

14:32:08.039 SB.CCM  :  RTP Channel = 0/1.2

14:32:08.039 MOH.APP printCSHoldStates, connect_: towOrig 0, towDest 0 origHold 0 destHold 0 isHold 0

14:32:08.039 SB.CCM connect: Call Connection Type is TDM_TO_RTP

14:32:08.040 SB.CCM SDP offer is 127.0.0.3:10772, SDP answer is 127.0.0.1:10774

14:32:08.041 SB.CCM connect: Connected RTP/TDM via MCM

14:32:08.041 SB.CCM handleMediaConnectionRtpChannel: No RTP channel to set up

14:32:08.041 SB.CCM setupRtpChannel, source 2, silence 0

14:32:08.042 SB.CCM setupRtpChannel: setup using media connection

14:32:08.042 SB.CCM Looking up source address for destination 127.0.0.1

14:32:08.042 SB.CCM setupRtpChannel: Source IP addr = 127.0.0.1, port = 10772

14:32:08.042 SB.CCM setupRtpChannel: Target IP addr = 127.0.0.1, port = 10774

14:32:08.042 SB.CCM setupRtpChannel: Undo of previous operation not required

14:32:08.044 PM.324 Ca:0 FarEnd               rcvd SIP call-leg response: 200 OK

14:32:08.045 SB.CCM getFinalCodec: G729

14:32:08.045 SB.CCM getFinalCodec: G729

14:32:08.046 SB.CCM setupRtpChannel: Configuring RTP Channel 0/1.2 to Src 127.0.0.1:10772 Trg 127.0.0.1:10774 via G729 Rx G729

14:32:08.046 SB.CCM setupRtpChannel: fpp=2 echo=on dtmf=101/101 dscp=46 vad=off isOffer yes

14:32:08.046 SB.CCM setupRtpChannel: Starting RTP Channel

14:32:08.046 RTP.CHANNEL Channel 0/1.2 session statistics cleared.

14:32:08.047 RTP.CHANNEL Channel 0/1.2 started successfully.

14:32:08.047 SB.CCM firewallConnectCall: Set up firewall from media connections

14:32:08.047 SB.CCM sdpFirewall: invoked with offer - [::]:10774, answer - 127.0.0.1:10774

14:32:08.047 SB.CCM sdpFirewall: 'any' address detected, no action taken

14:32:08.047 SB.CCM sdpFirewall: invoked with offer - [::]:10772, answer - 127.0.0.1:10772

14:32:08.048 SB.CCM sdpFirewall: 'any' address detected, no action taken

14:32:08.048 SB.CCM connect: TDM streams: port(Isdn(Ds1Ds0Trunk) 2/1.1) to port(InternalRtpApp 0/1.2)

14:32:08.048 SB.CALL 240 Connecting           ConnectResponse sent from T01 to 850

14:32:08.049 RTP.CHANNEL t1 2/1.1 - Dsp 0/1.2 - RTP: starting

14:32:08.049 VOICEMAIL.CA:0 DigitGathering - rcvd: connectResponse from SB

14:32:08 VXMLInterpreter vxml. Ca:0 # Set 'VMMaxLoginAttempts' to '3'

14:32:08 VXMLInterpreter vxml. Ca:0 # Set 'VMAction' to 'Leaving'

14:32:08 VXMLInterpreter vxml. Ca:0 # Set 'VMTargetBox' to '324'

14:32:08.050 VOICEMAIL.324 Ca:0 activate: New session initiated.

14:32:08 VXMLInterpreter vxml. Ca:0 # Set 'SystemLanguage' to '0'

14:32:08 VXMLInterpreter vxml. Ca:0 # Set 'SystemDefaultPrompts' to 'CFLASH:/SystemDefaultPrompts'

14:32:08.050 SB.CALL 240 Connecting           Called the finalizeConnect routine

14:32:08.050 SB.CCM finalizeConnect: connection already finalized(2)

14:32:08.050 SB.CALL 240 Connecting           ForceDoubleReinviteEvent sent

14:32:08.051 SB.CALL 240 State change      >> Connecting->Connected

14:32:08.051 SB.CALL 240 Connected            Forced double reInvite process beginning.

14:32:08.051 SB.CALL 240 Connected            Org/Dst mode is 1/1, reInvite without SDP sent to T01 (org)

14:32:08.051 SB.CALL 240 State change      >> Connected->ForcedReInviteOrg

14:32:08.051 TA.T01 23 TAConnected          reInvite event accepted

14:32:08.052 TA.T01 23 State change      >> TAConnected->TAReInvited (TAS_ReInvited)

14:32:08.052 TM.T01 0 Processed ReInvite Event

14:32:08.052 TA.T01 23 TAReInvited          rcvd: reInviteResponse from TM

14:32:08.052 TA.T01 23 TAReInvited          rcvd: reConnect from TM

14:32:08.053 SB.CALL 240 ForcedReInviteOrg    Called the reInviteResponse routine

14:32:08.053 SB.CALL 240 ForcedReInviteOrg    Called the reconnect routine

14:32:08.053 SB.CCM isMappable:

14:32:08.053 SB.CCM  :  Call Struct 0x53e0410 :   Call-ID = 240

14:32:08.053 SB.CCM  :  Org Acct = T01    Dst Acct = 850

14:32:08.054 SB.CCM  :  Org Port ID = Isdn(Ds1Ds0Trunk) 2/1.1   Dst Port ID = InternalRtpApp 0/1.2

14:32:08.054 SB.CCM  :  RTP Channel = 0/1.2

14:32:08.054 SB.CCM isMappable: Call Connection Type is TDM_TO_RTP

14:32:08.054 SB.CCM isMappable: Creating SDP Offer

14:32:08.056 PM.324 Ca:0 FarEnd               rcvd SIP call-leg response: 487 Request Cancelled

14:32:08.058 PM.324 Ca:0 FarEnd               call-leg (P:0x5aa5dc0 S:0x0) -> Disconnected (Local Cancelling)

14:32:08.058 PM.324 Ca:0 State change      >> FarEnd->SipPM_Terminated

14:32:08.058 PM.324 Ca:0 State change      >> SipPM_Terminated->SipPM_Idle

14:32:08.060 SB.CCM updateOfferWithEndpointConfig: DTMF(NTE 101), VAD(off), ptime(0)

14:32:08.060 SB.CCM translateOffer: offer codec list: PCMU G729

14:32:08.061 SB.CCM translateOffer: revised offer codec list: PCMU G729

14:32:08.061 SB.CCM translateOffer: codec list after answerer: G729

14:32:08.062 SB.CCM translateOffer: codec list after transcode add: G729

14:32:08.062 SB.CCM translateOffer: compatible DTMF signaling: answerer restriction(NTE 101), offer(NTE 101): DTMF transcoding unnecessary, using offer

14:32:08.063 SB.CCM translateOffer: success

14:32:08.063 SB.CALL 240 ForcedReInviteOrg    reInvite with SDP sent to 850

14:32:08.063 SB.CALL 240 State change      >> ForcedReInviteOrg->ForcedReInviteDst

14:32:08.064 VOICEMAIL.CA:0 DigitGathering - rcvd: reInvite from SB

14:32:08.064 VOICEMAIL.CA:0 DigitGathering - updateSdpInActiveCallStruct: Creating SDP Answer based on SDP Offer

14:32:08.065 SB.CALL 240 ForcedReInviteDst    Called the reInviteResponse routine

14:32:08.065 SB.CALL 240 ForcedReInviteDst    Called the reconnect routine

14:32:08.066 SB.CCM disconnect:

14:32:08.066 SB.CCM  :  Call Struct 0x53e0410 :   Call-ID = 240

14:32:08.066 SB.CCM  :  Org Acct = T01    Dst Acct = 850

14:32:08.066 SB.CCM  :  Org Port ID = Isdn(Ds1Ds0Trunk) 2/1.1   Dst Port ID = InternalRtpApp 0/1.2

14:32:08.066 SB.CCM  :  SDP Transaction = CallID: 240

14:32:08.067 SB.CCM  :  SDP Offer = 0x03cc4010, (127.0.0.3:10772)

14:32:08.067 SB.CCM  :  SDP Answer = 0x03cee810, (127.0.0.1:10774)

14:32:08.067 SB.CCM  :  RTP Channel = 0/1.2

14:32:08.067 MOH.APP printCSHoldStates, disconnect: towOrig 0, towDest 0 origHold 0 destHold 0 isHold 0

14:32:08.067 SB.CCM disconnect: Call Connection Type is TDM_TO_RTP

14:32:08.068 SB.CCM disconnect, music on hold

14:32:08.068 SB.CCM disconnect: Stopping RTP Channel 0/1.2

14:32:08.068 RTP.CHANNEL Channel 0/1.2 stopped successfully.

14:32:08.069 SB.CCM disconnect: Disconnecting TDM streams

14:32:08.069 SB.CCM isResponseMappable:

14:32:08.069 SB.CCM  :  Call Struct 0x53e0410 :   Call-ID = 240

14:32:08.069 SB.CCM  :  Org Acct = T01    Dst Acct = 850

14:32:08.069 SB.CCM  :  Org Port ID = Isdn(Ds1Ds0Trunk) 2/1.1   Dst Port ID = InternalRtpApp 0/1.2

14:32:08.070 SB.CCM  :  SDP Transaction = CallID: 240

14:32:08.070 SB.CCM  :  SDP Offer = 0x03cc4010, (127.0.0.3:10772)

14:32:08.070 SB.CCM  :  SDP Answer = 0x03cee810, (127.0.0.1:10774)

14:32:08.070 SB.CCM  :  RTP Channel = 0/1.2

14:32:08.070 SB.CCM isResponseMappable: reversing call connection type to compensate for event originator direction

14:32:08.071 SB.CCM isResponseMappable: Call Connection Type is RTP_TO_TDM

14:32:08.071 SB.CCM isResponseMappable: Modifying SDP Answer

14:32:08.071 SB.CCM translateAnswer: offer  codec list: PCMU G729

14:32:08.072 SB.CCM                : answer codec list: G729

14:32:08.072 SB.CCM translateAnswer: CODEC transcoding is not required

14:32:08.072 SB.CCM translateAnswer: offer / answer DTMF signaling identical: DTMF transcoding not required

14:32:08.073 SB.CCM translateAnswer: success

14:32:08.073 SB.CALL 240 ForcedReInviteDst    isResponseMappable passed, reconnecting both accounts

14:32:08.073 RTP.CHANNEL t1 2/1.1 - Dsp 0/1.2 - RTP: stopping

14:32:08.074 TA.T01 23 TAReInvited          reconnectResponse event accepted

14:32:08.074 TA.T01 23 State change      >> TAReInvited->TAConnected (TAS_Connected)

14:32:08.074 TM.T01 0 received reConnectResponse event

14:32:08.074 VOICEMAIL.CA:0 DigitGathering - rcvd: reconnectResponse from SB

14:32:08.075 TA.T01 23 TAConnected          rcvd: finalizeConnect from TM

14:32:08.075 TA.T01 23 TAConnected          forwarding finalizeConnect from TM

14:32:08.075 TA.T01 23 TAConnected          sent finalizeConnect to SB

14:32:08.075 SB.CALL 240 ForcedReInviteDst    Called the finalizeConnect routine

14:32:08.076 SB.CALL 240 ForcedReInviteDst    Called the finalizeConnect routine

14:32:08.076 SB.CCM connect:

14:32:08.076 SB.CCM  :  Call Struct 0x53e0410 :   Call-ID = 240

14:32:08.076 SB.CCM  :  Org Acct = T01    Dst Acct = 850

14:32:08.076 SB.CCM  :  Org Port ID = Isdn(Ds1Ds0Trunk) 2/1.1   Dst Port ID = InternalRtpApp 0/1.2

14:32:08.077 SB.CCM  :  SDP Transaction = CallID: 240

14:32:08.077 SB.CCM  :  SDP Offer = 0x03cc4010, (127.0.0.3:10772)

14:32:08.077 SB.CCM  :  SDP Answer = 0x03cee810, (127.0.0.1:10774)

14:32:08.077 SB.CCM  :  RTP Channel = 0/1.2

14:32:08.078 MOH.APP printCSHoldStates, connect_: towOrig 0, towDest 0 origHold 0 destHold 0 isHold 0

14:32:08.078 SB.CCM connect: Call Connection Type is TDM_TO_RTP

14:32:08.078 SB.CCM SDP offer is 127.0.0.3:10772, SDP answer is 127.0.0.1:10774

14:32:08.079 SB.CCM connect: Connected RTP/TDM via MCM

14:32:08.079 SB.CCM handleMediaConnectionRtpChannel: No RTP channel to set up

14:32:08.080 SB.CCM setupRtpChannel, source 2, silence 0

14:32:08.080 SB.CCM setupRtpChannel: setup using media connection

14:32:08.080 SB.CCM Looking up source address for destination 127.0.0.1

14:32:08.080 SB.CCM setupRtpChannel: Source IP addr = 127.0.0.1, port = 10772

14:32:08.081 SB.CCM setupRtpChannel: Target IP addr = 127.0.0.1, port = 10774

14:32:08.081 SB.CCM setupRtpChannel: Undo of previous operation not required

14:32:08.081 SB.CCM setupRtpChannel: *** Internal address used for RTP channel!!! ***

14:32:08.081 SB.CCM getFinalCodec: G729

14:32:08.082 SB.CCM getFinalCodec: G729

14:32:08.082 SB.CCM setupRtpChannel: Configuring RTP Channel 0/1.2 to Src 127.0.0.1:10772 Trg 127.0.0.1:10774 via G729 Rx G729

14:32:08.082 SB.CCM setupRtpChannel: fpp=2 echo=on dtmf=101/101 dscp=46 vad=off isOffer yes

14:32:08.082 SB.CCM setupRtpChannel: Starting RTP Channel

14:32:08.083 RTP.CHANNEL Channel 0/1.2 session statistics cleared.

14:32:08.083 RTP.CHANNEL Channel 0/1.2 started successfully.

14:32:08.083 SB.CCM firewallConnectCall: Set up firewall from media connections

14:32:08.083 SB.CCM sdpFirewall: invoked with offer - [::]:10774, answer - 127.0.0.1:10774

14:32:08.083 SB.CCM sdpFirewall: 'any' address detected, no action taken

14:32:08.084 SB.CCM sdpFirewall: invoked with offer - [::]:10772, answer - 127.0.0.1:10772

14:32:08.084 SB.CCM sdpFirewall: 'any' address detected, no action taken

14:32:08.084 SB.CCM connect: TDM streams: port(Isdn(Ds1Ds0Trunk) 2/1.1) to port(InternalRtpApp 0/1.2)

14:32:08.085 SB.CCM finalizeConnect: connection already finalized(6)

14:32:08.085 SB.CALL 240 State change      >> ForcedReInviteDst->Connected

14:32:08.085 RTP.CHANNEL t1 2/1.1 - Dsp 0/1.2 - RTP: starting

14:32:08 VXMLInterpreter vxml. Ca:0 # Platform Event: activate

14:32:08 VXMLInterpreter vxml. Ca:0 # Set 'RootForXML' to 'CFLASH:/VoiceMail/'

14:32:08 VXMLInterpreter vxml. Ca:0 # Set 'RootForWAV' to 'CFLASH:/SystemDefaultPrompts/'

14:32:08 VXMLInterpreter vxml. Ca:0 # Set 'operator' to '0'

14:32:08 VXMLInterpreter vxml. Ca:0 # Set 'internalError' to 'tel:@operator@'

14:32:08 VXMLInterpreter vxml. Ca:0 # Set 'collect' to ''

14:32:08 VXMLInterpreter vxml. Ca:0 # Set 'disconnect' to 'disconnect:'

14:32:08 VXMLInterpreter vxml. Ca:0 # Set 'repeat' to 'previous.0'

14:32:08 VXMLInterpreter vxml. Ca:0 # Set 'CallerName' to 'UNKNOWN'

14:32:08 VXMLInterpreter vxml. Ca:0 # Set 'CallerNumber' to 'UNKNOWN'

14:32:08 VXMLInterpreter vxml. Ca:0 # Set 'CalleeName' to 'UNKNOWN'

14:32:08 VXMLInterpreter vxml. Ca:0 # Set 'CalleeNumber' to 'UNKNOWN'

14:32:08 VXMLInterpreter vxml. Ca:0 # Set 'CallerNumber' to '718608169986'

14:32:08 VXMLInterpreter vxml. Ca:0 # Set 'CalleeName' to 'VoiceMailAcct'

14:32:08 VXMLInterpreter vxml. Ca:0 # Set 'CalleeNumber' to '850'

14:32:08 VXMLInterpreter vxml.850 Ca:0 # Set 'CalledOriginalNumber' to '324'

14:32:08 VXMLInterpreter vxml.850 Ca:0 # Set 'FullOptions' to 'Yes'

14:32:08 VXMLInterpreter vxml.850 Ca:0   CallerName:UNKNOWN CallerNumber:718608169986 CalleeName:VoiceMailAcct CalleeNumber:850 CalledOriginalNumber:324

14:32:08 VXMLInterpreter vxml.850 Ca:0 # Set 'RootDocument' to '.vmRoot.xml'

14:32:08 VXMLInterpreter vxml.850 Ca:0 Process Action: '.vmRoot.xml' (.vmRoot.xml)

14:32:08 VXMLInterpreter vxml.850 Ca:0   Loaded XML from 'CFLASH:/VoiceMail/.vmRoot.xml'

14:32:08 VXMLInterpreter vxml.850 Ca:0 # Set 'LoopCount.CheckAction' to '1'

14:32:08 VXMLInterpreter vxml.850 Ca:0 Entering state: '<transfer id='CheckAction'>'

14:32:08 VXMLInterpreter vxml.850 Ca:0 # Entering File: 'CFLASH:/VoiceMail/.vmRoot.xml' Offset: 8531'

14:32:08 VXMLInterpreter vxml.850 Ca:0 # Set 'internalError' to '.vmRoot.xml#internalError'

14:32:08 VXMLInterpreter vxml.850 Ca:0 # Set 'action' to 'leaving'

14:32:08 VXMLInterpreter vxml.850 Ca:0 # Set 'mailboxNum' to '324'

14:32:08 VXMLInterpreter vxml.850 Ca:0 Calling external function '' = newVoicemailSession(@mailboxNum@,@action@,@CallerNumber@,@CallerName@)

14:32:08 VXMLInterpreter vxml.850 Ca:0 VSCO: New session started, requesting mailbox 324

14:32:08 VXMLInterpreter vxml.850 Ca:0 # External function 'newVoicemailSession' with args '324,leaving,718608169986,UNKNOWN' completed with '0'

VoiceMail.MailboxManager:  Sending Copy of Mailbox 324 to VSCO.

VoiceMail.MailboxManager:  getMailbox(): Getting Mailbox 324 for action Leaving

VoiceMail.MailboxManager:  getMailbox():  Found Mailbox 324 with a current status of Idle

VoiceMail.MailboxManager:  getMailbox()[324]:  Updating messages for deletion in copy of mailbox

VoiceMail.MailboxManager.Mailbox:  updateMessagesforDeletion():  Updating Quota and Ageing for mailbox

VoiceMail.MailboxManager:  getTotalNumMsgs():  The system has 119 total VM messages

VoiceMail.MailboxManager:  getMailbox():  Finished for mailbox 324 for action Leaving with a status of Leaving

14:32:08 VXMLInterpreter vxml.850 Ca:0 VSCO: Received mailbox  324

14:32:08 VXMLInterpreter vxml.850 Ca:0 # Set 'mailboxLoopCount' to '0'

14:32:08 VXMLInterpreter vxml.850 Ca:0 Starting timer for 10 mseconds.

14:32:08 VXMLInterpreter vxml.850 Ca:0 Process Action: '#ValidateMailbox' (#ValidateMailbox)

14:32:08 VXMLInterpreter vxml.850 Ca:0 Leaving state: '<transfer id='CheckAction'>'

14:32:08 VXMLInterpreter vxml.850 Ca:0 # Set 'LoopCount.ValidateMailbox' to '1'

14:32:08 VXMLInterpreter vxml.850 Ca:0 Entering state: '<transfer id='ValidateMailbox'>'

14:32:08 VXMLInterpreter vxml.850 Ca:0 # Entering File: 'CFLASH:/VoiceMail/.vmRoot.xml' Offset: 5071'

14:32:08 VXMLInterpreter vxml.324 Ca:0 Calling external function 'isValid' = isMailboxValid()

14:32:08 VXMLInterpreter vxml.324 Ca:0 # Set 'isValid' to 'true'

14:32:08 VXMLInterpreter vxml.324 Ca:0 # External function 'isMailboxValid' with args '' completed with '1'

14:32:08 VXMLInterpreter vxml.324 Ca:0 Calling external function 'isAvailable' = isMailboxAvailable()

14:32:08 VXMLInterpreter vxml.324 Ca:0 # Set 'isAvailable' to 'true'

14:32:08 VXMLInterpreter vxml.324 Ca:0 # External function 'isMailboxAvailable' with args '' completed with '1'

14:32:08 VXMLInterpreter vxml.324 Ca:0 Calling external function 'isBusy' = isMailboxBusy()

14:32:08 VXMLInterpreter vxml.324 Ca:0 # Set 'isBusy' to 'false'

14:32:08 VXMLInterpreter vxml.324 Ca:0 # External function 'isMailboxBusy' with args '' completed with '1'

14:32:08 VXMLInterpreter vxml.324 Ca:0 Starting timer for 10 mseconds.

14:32:08 VXMLInterpreter vxml.324 Ca:0 Process Action: '.vmLeaveMessage.xml' (.vmLeaveMessage.xml)

14:32:08 VXMLInterpreter vxml.324 Ca:0 Leaving state: '<transfer id='ValidateMailbox'>'

14:32:08 VXMLInterpreter vxml.324 Ca:0   Loaded XML from 'CFLASH:/VoiceMail/.vmLeaveMessage.xml'

14:32:08 VXMLInterpreter vxml.324 Ca:0 # Set 'LoopCount.checkMailbox' to '1'

14:32:08 VXMLInterpreter vxml.324 Ca:0 Entering state: '<transfer id='checkMailbox'>'

14:32:08 VXMLInterpreter vxml.324 Ca:0 # Entering File: 'CFLASH:/VoiceMail/.vmLeaveMessage.xml' Offset: 8932'

14:32:08 VXMLInterpreter vxml.324 Ca:0 Calling external function 'isFull' = isMailboxFull()

14:32:08 VXMLInterpreter vxml.324 Ca:0 # Set 'isFull' to 'false'

14:32:08 VXMLInterpreter vxml.324 Ca:0 # External function 'isMailboxFull' with args '' completed with '1'

14:32:08 VXMLInterpreter vxml.324 Ca:0 Starting timer for 10 mseconds.

14:32:08 VXMLInterpreter vxml.324 Ca:0 Process Action: '#leavingMessageMenu' (#leavingMessageMenu)

14:32:08 VXMLInterpreter vxml.324 Ca:0 Leaving state: '<transfer id='checkMailbox'>'

14:32:08 VXMLInterpreter vxml.324 Ca:0 # Set 'LoopCount.leavingMessageMenu' to '1'

14:32:08 VXMLInterpreter vxml.324 Ca:0 Entering state: '<menu id='leavingMessageMenu'>'

14:32:08 VXMLInterpreter vxml.324 Ca:0 # Entering File: 'CFLASH:/VoiceMail/.vmLeaveMessage.xml' Offset: 7340'

14:32:08 VXMLInterpreter vxml.324 Ca:0 Calling external function 'greeting' = getCurrentGreeting()

14:32:08 VXMLInterpreter vxml.324 Ca:0 # Set 'greeting' to 'CFLASH:/VoiceMail/324/standard.wav'

14:32:08 VXMLInterpreter vxml.324 Ca:0 # External function 'getCurrentGreeting' with args '' completed with '1'

14:32:08 VXMLInterpreter vxml.324 Ca:0 Calling external function 'newMessageName' = requestMessageName()

14:32:08 VXMLInterpreter vxml.324 Ca:0 VSCO: Requesting name for new vm message

14:32:08 VXMLInterpreter vxml.324 Ca:0 # External function 'requestMessageName' with args '' completed with '0'

VoiceMail.MailboxManager:  Sending New Message Filename of CFLASH:/VoiceMail/Messages/H10O32YBPK.wav to VSCO for Mailbox 324

14:32:08 VXMLInterpreter vxml.324 Ca:0 Calling external function 'messageTimeout' = getMaxMessageLength()

14:32:08 VXMLInterpreter vxml.324 Ca:0 # Set 'messageTimeout' to '120s'

14:32:08 VXMLInterpreter vxml.324 Ca:0 # External function 'getMaxMessageLength' with args '' completed with '1'

14:32:08 VXMLInterpreter vxml.324 Ca:0 Calling external function 'greetingType' = getCurrentGreetingType()

14:32:08 VXMLInterpreter vxml.324 Ca:0 # Set 'greetingType' to 'CFLASH:/SystemDefaultPrompts/R964.wav'

14:32:08 VXMLInterpreter vxml.324 Ca:0 # External function 'getCurrentGreetingType' with args '' completed with '1'

14:32:08 VXMLInterpreter vxml.324 Ca:0 # Set 'collect' to ''

14:32:08 VXMLInterpreter vxml.324 Ca:0 # Started prompt 'CFLASH:/VoiceMail/324/standard.wav'

14:32:08 VXMLInterpreter vxml.324 Ca:0 VSCO: New message name is  CFLASH:/VoiceMail/Messages/H10O32YBPK.wav

14:32:08 VXMLInterpreter vxml.324 Ca:0 # Set 'newMessageName' to 'CFLASH:/VoiceMail/Messages/H10O32YBPK.wav'2016.08.10 14:32:09 SMDR 237        08/10/2016 14:32:09 00:24 00:00:00 0:00:00:00 0    I T01 02/01                 718608169986    00/00 Zehen Pachori   324             N 324             F  v2

14:32:20 VXMLInterpreter vxml.324 Ca:0 # Platform Event: CFLASH:/VoiceMail/324/standard.wav audio complete

14:32:20 VXMLInterpreter vxml.324 Ca:0 ProcessingLogic. CFLASH:/VoiceMail/324/standard.wav audioComplete (OK)

14:32:20 VXMLInterpreter vxml.324 Ca:0 Starting timer for 1000 mseconds.

14:32:21 VXMLInterpreter vxml.324 Ca:0 # Platform Event: timer expired

14:32:21 VXMLInterpreter vxml.324 Ca:0 ProcessingLogic.timerExpired

14:32:21 VXMLInterpreter vxml.324 Ca:0 Starting timer for 10 mseconds.

14:32:21 VXMLInterpreter vxml.324 Ca:0 Leaving state: '<menu id='leavingMessageMenu'>'

14:32:21 VXMLInterpreter vxml.324 Ca:0 Entering state: '<noinput>'

14:32:21 VXMLInterpreter vxml.324 Ca:0 # Entering File: 'CFLASH:/VoiceMail/.vmLeaveMessage.xml' Offset: 6057'

14:32:21 VXMLInterpreter vxml.324 Ca:0 Starting timer for 10 mseconds.

14:32:21 VXMLInterpreter vxml.324 Ca:0 Process Action: '#recordMenu' (#recordMenu)

14:32:21 VXMLInterpreter vxml.324 Ca:0 Leaving state: '<noinput>'

14:32:21 VXMLInterpreter vxml.324 Ca:0 # Set 'LoopCount.recordMenu' to '1'

14:32:21 VXMLInterpreter vxml.324 Ca:0 Entering state: '<record id='recordMenu'>'

14:32:21 VXMLInterpreter vxml.324 Ca:0 # Entering File: 'CFLASH:/VoiceMail/.vmLeaveMessage.xml' Offset: 5721'

14:32:21 VXMLInterpreter vxml.324 Ca:0 Calling external function '' = recordingStarted(@newMessageName@)

14:32:21 VXMLInterpreter vxml.324 Ca:0 # External function 'recordingStarted' with args 'CFLASH:/VoiceMail/Messages/H10O32YBPK.wav' completed with '1'

14:32:21 VXMLInterpreter vxml.324 Ca:0 # Set 'collect' to ''

14:32:21 VXMLInterpreter vxml.324 Ca:0 # Started prompt 'CFLASH:/SystemDefaultPrompts/RS7_1.wav'

14:32:21 VXMLInterpreter vxml.324 Ca:0 # Platform Event: CFLASH:/SystemDefaultPrompts/RS7_1.wav audio complete

14:32:21 VXMLInterpreter vxml.324 Ca:0 ProcessingLogic. CFLASH:/SystemDefaultPrompts/RS7_1.wav audioComplete (OK)

14:32:21 VXMLInterpreter vxml.324 Ca:0 Starting timer for 120000 mseconds.

14:32:21 VXMLInterpreter vxml.324 Ca:0 Starting record to 'CFLASH:/VoiceMail/Messages/H10O32YBPK.wav'

14:32:28.530 TM.T01 23 IsdnTmStateInboundConnected->IsdnTmStateTrunkClearing

14:32:28.531 TM.T01 23 IsdnTmStateTrunkClearing::enter()

14:32:28.531 TA.T01 23 TAConnected          rcvd: clear from TM

14:32:28.531 TA.T01 23 State change      >> TAConnected->TATrunkClearing (TAS_Clearing)

14:32:28.531 SB.CALL 240 Connected            Called the clearCall routine

14:32:28.532 SB.CALL 240 Connected            ClearCall sent from T01 to 850

14:32:28.532 SB.CALL 240 State change      >> Connected->Clearing

14:32:28.532 VOICEMAIL.CA:0 DigitGathering - rcvd: clearCall from SB

14:32:28.536 VOICEMAIL.CA:0 DigitGathering - State Change: DigitGathering to Idle

14:32:28.537 SB.CALL 240 Clearing             Called the clearResponse routine

14:32:28.537 SB.CALL 240 State change      >> Clearing->CallIdlePending

14:32:28.538 SB.CCM disconnect:

14:32:28.538 SB.CCM  :  Call Struct 0x53e0410 :   Call-ID = 240

14:32:28.538 SB.CCM  :  Org Acct = T01    Dst Acct = 850

14:32:28.538 SB.CCM  :  Org Port ID = Isdn(Ds1Ds0Trunk) 2/1.1   Dst Port ID = InternalRtpApp 0/1.2

14:32:28.539 SB.CCM  :  RTP Channel = 0/1.2

14:32:28.539 MOH.APP printCSHoldStates, disconnect: towOrig 0, towDest 0 origHold 0 destHold 0 isHold 0

14:32:28.539 SB.CCM disconnect: Call Connection Type is TDM_TO_RTP

14:32:28.539 SB.CCM disconnect, music on hold

14:32:28.539 SB.CCM disconnect: Stopping RTP Channel 0/1.2

14:32:28.540 TM.T01 23 IsdnTmStateTrunkClearing->IsdnTmStateIdling

14:32:28.540 TM.T01 23 IsdnTmStateIdling::enter()

14:32:28.540 TM.T01 23 IsdnTmStateIdling - send appearance off

14:32:28.540 TM.T01 23 IsdnTmStateIdling->IsdnTmStateIdle

14:32:28.541 TM.T01 23 IsdnAppearanceChannel::releaseChannel

14:32:28.541 TM.T01 23 IsdnTmStateIdle::enter()

14:32:28.539 RTP.CHANNEL Channel 0/1.2 stopped successfully.

14:32:28.541 SB.CCM disconnect: Disconnecting TDM streams

14:32:28.541 SB.CCM release:

14:32:28.541 SB.CCM  :  Call Struct 0x53e0410 :   Call-ID = 240

14:32:28.542 SB.CCM  :  Org Acct = T01    Dst Acct = 850

14:32:28.542 SB.CCM  :  Org Port ID = Isdn(Ds1Ds0Trunk) 2/1.1   Dst Port ID = InternalRtpApp 0/1.2

14:32:28.542 SB.CCM  :  RTP Channel = 0/1.2

14:32:28.542 SB.CCM release: Call Connection Type is TDM_TO_RTP

14:32:28.542 SB.CCM release: Releasing RTP Channel 0/1.2

14:32:28.543 RTP.CHANNEL Channel 0/1.2 released successfully.

14:32:28.543 SB.CALL 240 CallIdlePending      ClearResponse sent from 850 to T01

14:32:28.543 TA.T01 23 TATrunkClearing      clearResponse event accepted

14:32:28.543 TA.T01 23 State change      >> TATrunkClearing->TAClearingComplete (TAS_Clearing)

14:32:28.544 RTP.CHANNEL t1 2/1.1 - Dsp 0/1.2 - RTP: stopping

14:32:28.544 TA.T01 23 TAClearingComplete   rcvd: appearance off from TM

14:32:28.544 TA.T01 23 TAClearingComplete   Clear Local Variables

14:32:28.544 TA.T01 23 State change      >> TAClearingComplete->TAIdle (TAS_Idle)

14:32:28.545 RTP.CHANNEL t1 2/1.1 - Dsp 0/1.2 - RTP: releasing RTP resource

14:32:28.545 RTP.CHANNEL t1 2/1.1 - Dsp 0/1.2 - RTP: releasing

14:32:28 VXMLInterpreter vxml.324 Ca:0 # Platform Event:  record complete (OK)

14:32:28 VXMLInterpreter vxml.324 Ca:0 # Platform Event: deactivate

VoiceMail.MailboxManager.Mailbox:  addNewMessage():  Adding new message CFLASH:/VoiceMail/Messages/H10O32YBPK.wav to mailbox

VoiceMail.MailboxManager.Mailbox:  addNewMessage():  Message CFLASH:/VoiceMail/Messages/H10O32YBPK.wav has been added to mailbox

14:32:28 VXMLInterpreter vxml.324 Ca:0 VSCO: Sent mailbox 324 for update.

14:32:28 VXMLInterpreter vxml.324 Ca:0 Leaving state: '<record id='recordMenu'>'

14:32:28 VXMLInterpreter vxml.324 Ca:0 Stopping current timer.

VoiceMail.MailboxManager:  Beginning Mailbox Merge process for Mailbox 324 with a current status of Leaving

VoiceMail.MailboxManager:  update_mailbox()[324]:  Message H10O32YBPK is new to this mailbox

VoiceMail.MailboxManager:  sendNotification()[324]:  Attempting to notify user of new VM CFLASH:/VoiceMail/Messages/H10O32YBPK.wav

VoiceMail.MailboxManager:  sendNotification()[324]:  Sending email notification to zpachori@mecanexusa.com for message CFLASH:/VoiceMail/Messages/H10O32YBPK.wav

VoiceMail.MailboxManager:  update_mailbox()[324]:  Message H10O32YBPK is marked as new

VoiceMail.MailboxManager:  update_mailbox()[324]:  Message H10O32YBPK needs files updated

VoiceMail.MailboxManager:  createDSCFile()[324]:  Sending event to write DSC file CFLASH:/VoiceMail/324/H10O32YBPK.dsc

VoiceMail.MailboxManager:  createHDRFile():  Sending event to write HDR file CFLASH:/VoiceMail/Messages/H10O32YBPK.hdr

VoiceMail.MailboxManager:  update_mailbox()[324]:  Updating greetings- Greeting is Standard Greeting

VoiceMail.MailboxManager:  update_mailbox()[324]:  Messages in this mailbox have been updated- now updating MWI status

VoiceMail.MailboxManager:  update_mailbox()[324]:  This mailbox status is now Idle

VoiceMail.MailboxManager:  Mailbox Merge for Mailbox 324 completed successfully.

VoiceMail.MailboxManager:  FileWriteEvent():  Creating new file CFLASH:/VoiceMail/324/H10O32YBPK.dsc

VoiceMail.MailboxManager:  2016.08.10 14:32:28 G729ToPCMConverting CFLASH:/VoiceMail/Messages/H10O32YBPK.wav

VoiceMail.MailboxManager:  FileWriteEvent():  Creating new file CFLASH:/VoiceMail/Messages/H10O32YBPK.hdr

VoiceMail.MailboxManager:  FileDeleteEvent():  Deleting file CFLASH:/VoiceMail/324/alternate.wav

2016.08.10 14:32:29 SMDR 237        08/10/2016 14:32:08 00:00 00:00:00 0:00:00:21 0    I T01 02/01                 718608169986    00/01 VoiceMailAcct   850             Y 324             F  v2

VoiceMail.MailboxManager:  2016.08.10 14:32:28 G729ToPCMConvert converted 718608169986_08102016_0232.wav but send failed

14:32:30.452 PM.324 Looking up source address for destination 10.10.20.84

14:32:31.997 PM.317 Looking up source address for destination 10.10.20.87

14:32:33.391 PM.345 Looking up source address for destination 10.10.20.88

14:32:33.495 PM.321 Looking up source address for destination 10.10.20.3

14:32:37.682 PM.400 Looking up source address for destination 10.10.20.23

[Anonymous]

If you’re in the CLI, make sure you are in enable mode by typing “enable” and then password and then the debug commands.

Ok,

We can see the 7100 VM attempting to send the vmail via this debug:

VoiceMail.MailboxManager: sendNotification()[324]: Sending email notification to zpachori@mecanexusa.com for message CFLASH:/VoiceMail/Messages/H10O32YBPK.wav

Now do a “debug system” and call and leave another voicemail. Run that along with “debug voice verbose” at the same time.

Post output.

Thanks,

-Mark

[zp-mecanex]

Hello, Thanks for your help Mark.

Again i called from 8608169986 to 8608286531 ext 324

08:06:30.522 SB.CCM  :  Org Acct = T01    Dst Acct = 346

08:06:30.522 SB.CCM  :  Org Port ID = Isdn(Ds1Ds0Trunk) 2/1.1   Dst Port ID = SipPhone 0/1.2

08:06:30.523 SB.CCM  :  RTP Channel = 0/1.2

08:06:30.523 SB.CCM release: Call Connection Type is TDM_TO_RTP

08:06:30.523 SB.CCM release: Releasing RTP Channel 0/1.2

08:06:30.523 RTP.CHANNEL Channel 0/1.2 released successfully.

08:06:30.524 SB.CALL 356 CallIdlePending      ClearResponse sent from 346 to T01

08:06:30.524 TA.T01 23 TATrunkClearing      clearResponse event accepted

08:06:30.524 TA.T01 23 State change      >> TATrunkClearing->TAClearingComplete (TAS_Clearing)

08:06:30.524 RTP.CHANNEL t1 2/1.1 - Dsp 0/1.2 - RTP: stopping

08:06:30.525 TA.T01 23 TAClearingComplete   rcvd: appearance off from TM

08:06:30.525 TA.T01 23 TAClearingComplete   Clear Local Variables

08:06:30.525 TA.T01 23 State change      >> TAClearingComplete->TAIdle (TAS_Idle)

08:06:30.525 RTP.CHANNEL t1 2/1.1 - Dsp 0/1.2 - RTP: releasing RTP resource

08:06:30.526 RTP.CHANNEL t1 2/1.1 - Dsp 0/1.2 - RTP: releasing

SMTP Not enough info to send.

2016.08.11 08:06:31 SMDR 354        08/11/2016 08:06:10 00:07 00:00:00 0:00:00:21 0    I T01 02/01                 718608342333    00/01 Luis Munoz      346             Y 346             F  v2

08:06:45.673 PM.324 Ca:0 State change      >> SipPM_Ringing->SipPM_NoAnswer

08:06:45.673 PM.324 Ca:0 SipPM_NoAnswer       sent: SA->NoAnswer

08:06:45.674 SA.324 Ca:0 Ringing              rcvd: AcctPhoneMgr_noAnswer from PM

08:06:45.674 SA.324 sent: ClearCall to SB

08:06:45.674 SA.324 Ca:0 Ringing              State change      >> Ringing->Clearing (CAS_Ringing)

08:06:45.674 SB.CALL 359 Alerting             Called the clearCall routine

08:06:45.674 SB.CALL 359 State change      >> Alerting->Clearing

08:06:45.675 SB.CALL 359 Clearing             ClearCall sent from 324 to T01

08:06:45.675 TA.T01 22 TAConnectWaitIn      ClearCall event accepted

08:06:45.675 TA.T01 22 TAConnectWaitIn      Processing a forward from call coverage

08:06:45.676 TA.T01 22 TAConnectWaitIn      sent: call to SB

08:06:45.676 TA.T01 22 State change      >> TAConnectWaitIn->TAInboundCall (TAS_Alerting)

08:06:45.676 SB.CALL 359 Clearing             Called the clearResponse routine

08:06:45.676 SB.CALL 359 State change      >> Clearing->CallIdlePending

08:06:45.676 SB.CCM release:

08:06:45.677 SB.CCM  :  Call Struct 0x4658410 :   Call-ID = 359

08:06:45.677 SB.CCM  :  Org Acct = T01    Dst Acct = 324

08:06:45.677 SB.CCM  :  Org Port ID = Isdn(Ds1Ds0Trunk) 2/1.2   Dst Port ID = SipPhone 0/0

08:06:45.677 SB.CCM  :  SDP Transaction = CallID: 359

08:06:45.677 SB.CCM  :  SDP Offer = 0x03cc3610, (127.0.0.3:11130)

08:06:45.678 SB.CCM  :  RTP Channel = 0/1.1

08:06:45.678 SB.CCM release: Call Connection Type is TDM_TO_RTP

08:06:45.678 SB.CCM release: Releasing RTP Channel 0/1.1

08:06:45.678 RTP.CHANNEL Channel 0/1.1 released successfully.

08:06:45.679 SB.CALL 359 CallIdlePending      ClearResponse sent from T01 to 324

08:06:45.679 SB.CALL 360 Idle                 Called the call routine with 850

08:06:45.679 SB.CCM isMappable:

08:06:45.679 SB.CCM  :  Call Struct 0x43f6010 :   Call-ID = 360

08:06:45.679 SB.CCM  :  Org Acct = T01    Dst Acct = 850

08:06:45.680 SB.CCM  :  Org Port ID = Isdn(Ds1Ds0Trunk) 2/1.2   Dst Port ID = unknown 0/0

08:06:45.680 SB.CCM isMappable: Call Connection Type is TDM_TO_RTP

08:06:45.680 SB.CCM isMappable: Reserving RTP Channel 0/1.1

08:06:45.680 SB.CCM isMappable: Creating SDP Offer

08:06:45.682 SB.CCM updateOfferWithEndpointConfig: DTMF(NTE 101), VAD(off), ptime(0)

08:06:45.683 SB.CCM translateOffer: offer codec list: PCMU G729

08:06:45.683 SB.CCM translateOffer: revised offer codec list: PCMU G729

08:06:45.684 SB.CCM translateOffer: codec list after answerer: G729

08:06:45.684 SB.CCM translateOffer: codec list after transcode add: G729

08:06:45.685 SB.CCM translateOffer: compatible DTMF signaling: answerer restriction(NTE 101), offer(NTE 101): DTMF transcoding unnecessary, using offer

08:06:45.685 SB.CCM translateOffer: success

08:06:45.686 SB.CALL 360 Idle                 Call sent from T01 to 850 (850)

08:06:45.686 SB.CALL 360 State change      >> Idle->Delivering

08:06:45.686 SA.324 Ca:0 Clearing             rcvd: clearResponse from SB

08:06:45.686 SA.324 Ca:0 Clearing             State change      >> Clearing->Idle (CAS_Idle)

08:06:45.695 SA.324 Ca:0 Idle                 sent: AcctPhoneMgr_cachg(CAS_Idle) to PM

08:06:45.695 PM.324 Ca:0 State change      >> SipPM_NoAnswer->FarEnd

08:06:45.698 PM.324 Ca:0 FarEnd               call-leg (P:0x5ab98c0 S:0x0) -> Cancelling (Local Cancelling)

08:06:45.698 PM.324 Ca:0 FarEnd               ERROR! Unexpected CallLegStateChanged to Cancelling.

08:06:45.698 PM.324 Ca:0 FarEnd               sent: CANCEL message.

08:06:45.699 RTP.CHANNEL t1 2/1.2 - Dsp 0/1.1 - RTP: releasing RTP resource

08:06:45.699 RTP.CHANNEL t1 2/1.2 - Dsp 0/1.1 - RTP: releasing

08:06:45.699 RTP.MANAGER t1 2/1.2 - empty - RTP: Request resource

08:06:45.700 RTP.MANAGER t1 2/1.2 - Dsp 0/1.1 - RTP: DSP channel allocated for the resource

08:06:45.700 RTP.PROVIDER t1 2/1.2 - Dsp 0/1.1 - RTP: providing already allocated RTP channel

08:06:45.700 TA.T01 22 TAInboundCall        CallResp event accepted

08:06:45.700 TA.T01 22 State change      >> TAInboundCall->TAConnectWaitIn (TAS_Alerting)

08:06:45.701 VOICEMAIL.CA:0 Idle - updateSdpInActiveCallStruct: Creating SDP Answer based on SDP Offer

08:06:45.703 VOICEMAIL.CA:0 Idle - State Change: Idle to DigitGathering

08:06:45.703 SB.CALL 360 Delivering           Called the connect routine

08:06:45.703 SB.CCM isResponseMappable:

08:06:45.703 SB.CCM  :  Call Struct 0x43f6010 :   Call-ID = 360

08:06:45.704 SB.CCM  :  Org Acct = T01    Dst Acct = 850

08:06:45.704 SB.CCM  :  Org Port ID = Isdn(Ds1Ds0Trunk) 2/1.2   Dst Port ID = InternalRtpApp 0/0

08:06:45.704 SB.CCM  :  SDP Transaction = CallID: 360

08:06:45.704 SB.CCM  :  SDP Offer = 0x03cc5b10, (127.0.0.3:11132)

08:06:45.705 SB.CCM  :  SDP Answer = 0x03cef110, (127.0.0.1:11134)

08:06:45.705 SB.CCM  :  RTP Channel = 0/1.1

08:06:45.705 SB.CCM isResponseMappable: reversing call connection type to compensate for event originator direction

08:06:45.705 SB.CCM isResponseMappable: Call Connection Type is RTP_TO_TDM

08:06:45.705 SB.CCM isResponseMappable: Modifying SDP Answer

08:06:45.706 SB.CCM translateAnswer: offer  codec list: PCMU G729

08:06:45.706 SB.CCM                : answer codec list: G729

08:06:45.707 SB.CCM translateAnswer: CODEC transcoding is not required

08:06:45.707 SB.CCM translateAnswer: offer / answer DTMF signaling identical: DTMF transcoding not required

08:06:45.707 SB.CCM translateAnswer: success

08:06:45.708 SB.CALL 360 Delivering           Connect sent from 850 to T01

08:06:45.708 SB.CALL 360 State change      >> Delivering->Connecting

08:06:45.708 TA.T01 22 TAConnectWaitIn      connect event accepted

08:06:45.709 TA.T01 22 State change      >> TAConnectWaitIn->TAConnectPending (TAS_Connected)

08:06:45.709 TM.T01 22 IsdnTmStateInboundConnectedAlerting - rcvd tachgConnect

08:06:45.709 TM.T01 22 IsdnTmStateInboundConnectedAlerting->IsdnTmStateInboundConnected

08:06:45.709 TM.T01 22 IsdnTmStateInboundConnected::enter()

08:06:45.710 TONESERVICES.EVENTS t1 2/1.2 - Dsp 0/1.1 - Ringback Generation: stopping

08:06:45.710 TONESERVICES.EVENTS t1 2/1.2 - Dsp 0/1.1 - Ringback Generation: TDM unmap

08:06:45.710 RTP.CHANNEL t1 2/1.2 - Dsp 0/1.1 - Ringback Generation: releasing RTP resource

08:06:45.711 TONESERVICES.EVENTS t1 2/1.2 - Dsp 0/1.1 - Ringback Generation: release

08:06:45.711 TA.T01 22 TAConnectPending     rcvd: connect from TM

08:06:45.711 TA.T01 22 State change      >> TAConnectPending->TAConnected (TAS_Connected)

08:06:45.711 SB.CALL 360 Connecting           Called the connectResponse routine

08:06:45.711 SB.CCM connect:

08:06:45.712 SB.CCM  :  Call Struct 0x43f6010 :   Call-ID = 360

08:06:45.712 SB.CCM  :  Org Acct = T01    Dst Acct = 850

08:06:45.712 SB.CCM  :  Org Port ID = Isdn(Ds1Ds0Trunk) 2/1.2   Dst Port ID = InternalRtpApp 0/0

08:06:45.712 SB.CCM  :  SDP Transaction = CallID: 360

08:06:45.712 SB.CCM  :  SDP Offer = 0x03cc5b10, (127.0.0.3:11132)

08:06:45.713 SB.CCM  :  SDP Answer = 0x03cef110, (127.0.0.1:11134)

08:06:45.713 SB.CCM  :  RTP Channel = 0/1.1

08:06:45.713 MOH.APP printCSHoldStates, connect_: towOrig 0, towDest 0 origHold 0 destHold 0 isHold 0

08:06:45.713 SB.CCM connect: Call Connection Type is TDM_TO_RTP

08:06:45.714 SB.CCM SDP offer is 127.0.0.3:11132, SDP answer is 127.0.0.1:11134

08:06:45.715 SB.CCM connect: Connected RTP/TDM via MCM

08:06:45.715 SB.CCM handleMediaConnectionRtpChannel: No RTP channel to set up

08:06:45.715 SB.CCM setupRtpChannel, source 2, silence 0

08:06:45.716 SB.CCM setupRtpChannel: setup using media connection

08:06:45.716 SB.CCM Looking up source address for destination 127.0.0.1

08:06:45.716 SB.CCM setupRtpChannel: Source IP addr = 127.0.0.1, port = 11132

08:06:45.716 SB.CCM setupRtpChannel: Target IP addr = 127.0.0.1, port = 11134

08:06:45.716 SB.CCM setupRtpChannel: Undo of previous operation not required

08:06:45.717 SB.CCM getFinalCodec: G729

08:06:45.717 SB.CCM getFinalCodec: G729

08:06:45.718 SB.CCM setupRtpChannel: Configuring RTP Channel 0/1.1 to Src 127.0.0.1:11132 Trg 127.0.0.1:11134 via G729 Rx G729

08:06:45.718 SB.CCM setupRtpChannel: fpp=2 echo=on dtmf=101/101 dscp=46 vad=off isOffer yes

08:06:45.718 SB.CCM setupRtpChannel: Starting RTP Channel

08:06:45.720 PM.324 Ca:0 FarEnd               rcvd SIP call-leg response: 200 OK

08:06:45.718 RTP.CHANNEL Channel 0/1.1 session statistics cleared.

08:06:45.721 RTP.CHANNEL Channel 0/1.1 started successfully.

08:06:45.721 SB.CCM firewallConnectCall: Set up firewall from media connections

08:06:45.721 SB.CCM sdpFirewall: invoked with offer - [::]:11134, answer - 127.0.0.1:11134

08:06:45.721 SB.CCM sdpFirewall: 'any' address detected, no action taken

08:06:45.722 SB.CCM sdpFirewall: invoked with offer - [::]:11132, answer - 127.0.0.1:11132

08:06:45.722 SB.CCM sdpFirewall: 'any' address detected, no action taken

08:06:45.722 SB.CCM connect: TDM streams: port(Isdn(Ds1Ds0Trunk) 2/1.2) to port(InternalRtpApp 0/1.1)

08:06:45.723 SB.CALL 360 Connecting           ConnectResponse sent from T01 to 850

08:06:45.723 RTP.CHANNEL t1 2/1.2 - Dsp 0/1.1 - RTP: starting

08:06:45.723 VOICEMAIL.CA:0 DigitGathering - rcvd: connectResponse from SB

08:06:45 VXMLInterpreter vxml. Ca:0 # Set 'VMMaxLoginAttempts' to '3'

08:06:45 VXMLInterpreter vxml. Ca:0 # Set 'VMAction' to 'Leaving'

08:06:45 VXMLInterpreter vxml. Ca:0 # Set 'VMTargetBox' to '324'

08:06:45.724 VOICEMAIL.324 Ca:0 activate: New session initiated.

08:06:45 VXMLInterpreter vxml. Ca:0 # Set 'SystemLanguage' to '0'

08:06:45 VXMLInterpreter vxml. Ca:0 # Set 'SystemDefaultPrompts' to 'CFLASH:/SystemDefaultPrompts'

08:06:45.725 SB.CALL 360 Connecting           Called the finalizeConnect routine

08:06:45.725 SB.CCM finalizeConnect: connection already finalized(2)

08:06:45.725 SB.CALL 360 Connecting           ForceDoubleReinviteEvent sent

08:06:45.725 SB.CALL 360 State change      >> Connecting->Connected

08:06:45.725 SB.CALL 360 Connected            Forced double reInvite process beginning.

08:06:45.725 SB.CALL 360 Connected            Org/Dst mode is 1/1, reInvite without SDP sent to T01 (org)

08:06:45.726 SB.CALL 360 State change      >> Connected->ForcedReInviteOrg

08:06:45.726 TA.T01 22 TAConnected          reInvite event accepted

08:06:45.726 TA.T01 22 State change      >> TAConnected->TAReInvited (TAS_ReInvited)

08:06:45.726 TM.T01 0 Processed ReInvite Event

08:06:45.726 TA.T01 22 TAReInvited          rcvd: reInviteResponse from TM

08:06:45.727 TA.T01 22 TAReInvited          rcvd: reConnect from TM

08:06:45.727 SB.CALL 360 ForcedReInviteOrg    Called the reInviteResponse routine

08:06:45.727 SB.CALL 360 ForcedReInviteOrg    Called the reconnect routine

08:06:45.727 SB.CCM isMappable:

08:06:45.728 SB.CCM  :  Call Struct 0x43f6010 :   Call-ID = 360

08:06:45.728 SB.CCM  :  Org Acct = T01    Dst Acct = 850

08:06:45.728 SB.CCM  :  Org Port ID = Isdn(Ds1Ds0Trunk) 2/1.2   Dst Port ID = InternalRtpApp 0/1.1

08:06:45.728 SB.CCM  :  RTP Channel = 0/1.1

08:06:45.728 SB.CCM isMappable: Call Connection Type is TDM_TO_RTP

08:06:45.729 SB.CCM isMappable: Creating SDP Offer

08:06:45.730 SB.CCM updateOfferWithEndpointConfig: DTMF(NTE 101), VAD(off), ptime(0)

08:06:45.730 SB.CCM translateOffer: offer codec list: PCMU G729

08:06:45.731 SB.CCM translateOffer: revised offer codec list: PCMU G729

08:06:45.732 SB.CCM translateOffer: codec list after answerer: G729

08:06:45.734 PM.324 Ca:0 FarEnd               rcvd SIP call-leg response: 487 Request Cancelled

08:06:45.735 PM.324 Ca:0 FarEnd               call-leg (P:0x5ab98c0 S:0x0) -> Disconnected (Local Cancelling)

08:06:45.736 PM.324 Ca:0 State change      >> FarEnd->SipPM_Terminated

08:06:45.736 PM.324 Ca:0 State change      >> SipPM_Terminated->SipPM_Idle

08:06:45.736 SB.CCM translateOffer: codec list after transcode add: G729

08:06:45.737 SB.CCM translateOffer: compatible DTMF signaling: answerer restriction(NTE 101), offer(NTE 101): DTMF transcoding unnecessary, using offer

08:06:45.737 SB.CCM translateOffer: success

08:06:45.738 SB.CALL 360 ForcedReInviteOrg    reInvite with SDP sent to 850

08:06:45.738 SB.CALL 360 State change      >> ForcedReInviteOrg->ForcedReInviteDst

08:06:45.738 VOICEMAIL.CA:0 DigitGathering - rcvd: reInvite from SB

08:06:45.739 VOICEMAIL.CA:0 DigitGathering - updateSdpInActiveCallStruct: Creating SDP Answer based on SDP Offer

08:06:45.740 SB.CALL 360 ForcedReInviteDst    Called the reInviteResponse routine

08:06:45.741 SB.CALL 360 ForcedReInviteDst    Called the reconnect routine

08:06:45.741 SB.CCM disconnect:

08:06:45.741 SB.CCM  :  Call Struct 0x43f6010 :   Call-ID = 360

08:06:45.741 SB.CCM  :  Org Acct = T01    Dst Acct = 850

08:06:45.741 SB.CCM  :  Org Port ID = Isdn(Ds1Ds0Trunk) 2/1.2   Dst Port ID = InternalRtpApp 0/1.1

08:06:45.742 SB.CCM  :  SDP Transaction = CallID: 360

08:06:45.742 SB.CCM  :  SDP Offer = 0x03cc4510, (127.0.0.3:11132)

08:06:45.742 SB.CCM  :  SDP Answer = 0x03cefe10, (127.0.0.1:11134)

08:06:45.742 SB.CCM  :  RTP Channel = 0/1.1

08:06:45.742 MOH.APP printCSHoldStates, disconnect: towOrig 0, towDest 0 origHold 0 destHold 0 isHold 0

08:06:45.743 SB.CCM disconnect: Call Connection Type is TDM_TO_RTP

08:06:45.743 SB.CCM disconnect, music on hold

08:06:45.743 SB.CCM disconnect: Stopping RTP Channel 0/1.1

08:06:45.743 RTP.CHANNEL Channel 0/1.1 stopped successfully.

08:06:45.743 SB.CCM disconnect: Disconnecting TDM streams

08:06:45.744 SB.CCM isResponseMappable:

08:06:45.744 SB.CCM  :  Call Struct 0x43f6010 :   Call-ID = 360

08:06:45.744 SB.CCM  :  Org Acct = T01    Dst Acct = 850

08:06:45.744 SB.CCM  :  Org Port ID = Isdn(Ds1Ds0Trunk) 2/1.2   Dst Port ID = InternalRtpApp 0/1.1

08:06:45.744 SB.CCM  :  SDP Transaction = CallID: 360

08:06:45.745 SB.CCM  :  SDP Offer = 0x03cc4510, (127.0.0.3:11132)

08:06:45.745 SB.CCM  :  SDP Answer = 0x03cefe10, (127.0.0.1:11134)

08:06:45.745 SB.CCM  :  RTP Channel = 0/1.1

08:06:45.745 SB.CCM isResponseMappable: reversing call connection type to compensate for event originator direction

08:06:45.745 SB.CCM isResponseMappable: Call Connection Type is RTP_TO_TDM

08:06:45.746 SB.CCM isResponseMappable: Modifying SDP Answer

08:06:45.746 SB.CCM translateAnswer: offer  codec list: PCMU G729

08:06:45.746 SB.CCM                : answer codec list: G729

08:06:45.747 SB.CCM translateAnswer: CODEC transcoding is not required

08:06:45.747 SB.CCM translateAnswer: offer / answer DTMF signaling identical: DTMF transcoding not required

08:06:45.747 SB.CCM translateAnswer: success

08:06:45.748 SB.CALL 360 ForcedReInviteDst    isResponseMappable passed, reconnecting both accounts

08:06:45.748 RTP.CHANNEL t1 2/1.2 - Dsp 0/1.1 - RTP: stopping

08:06:45 VXMLInterpreter vxml. Ca:0 # Platform Event: activate

08:06:45.749 TA.T01 22 TAReInvited          reconnectResponse event accepted

08:06:45.749 TA.T01 22 State change      >> TAReInvited->TAConnected (TAS_Connected)

08:06:45.750 TM.T01 0 received reConnectResponse event

08:06:45.750 VOICEMAIL.CA:0 DigitGathering - rcvd: reconnectResponse from SB

08:06:45.750 TA.T01 22 TAConnected          rcvd: finalizeConnect from TM

08:06:45.751 TA.T01 22 TAConnected          forwarding finalizeConnect from TM

08:06:45.751 TA.T01 22 TAConnected          sent finalizeConnect to SB

08:06:45.751 SB.CALL 360 ForcedReInviteDst    Called the finalizeConnect routine

08:06:45.751 SB.CALL 360 ForcedReInviteDst    Called the finalizeConnect routine

08:06:45.751 SB.CCM connect:

08:06:45.751 SB.CCM  :  Call Struct 0x43f6010 :   Call-ID = 360

08:06:45.752 SB.CCM  :  Org Acct = T01    Dst Acct = 850

08:06:45.752 SB.CCM  :  Org Port ID = Isdn(Ds1Ds0Trunk) 2/1.2   Dst Port ID = InternalRtpApp 0/1.1

08:06:45.752 SB.CCM  :  SDP Transaction = CallID: 360

08:06:45.752 SB.CCM  :  SDP Offer = 0x03cc4510, (127.0.0.3:11132)

08:06:45.753 SB.CCM  :  SDP Answer = 0x03cefe10, (127.0.0.1:11134)

08:06:45.753 SB.CCM  :  RTP Channel = 0/1.1

08:06:45.753 MOH.APP printCSHoldStates, connect_: towOrig 0, towDest 0 origHold 0 destHold 0 isHold 0

08:06:45.753 SB.CCM connect: Call Connection Type is TDM_TO_RTP

08:06:45.753 SB.CCM SDP offer is 127.0.0.3:11132, SDP answer is 127.0.0.1:11134

08:06:45.755 SB.CCM connect: Connected RTP/TDM via MCM

08:06:45.755 SB.CCM handleMediaConnectionRtpChannel: No RTP channel to set up

08:06:45.755 SB.CCM setupRtpChannel, source 2, silence 0

08:06:45.756 SB.CCM setupRtpChannel: setup using media connection

08:06:45.756 SB.CCM Looking up source address for destination 127.0.0.1

08:06:45.756 SB.CCM setupRtpChannel: Source IP addr = 127.0.0.1, port = 11132

08:06:45.756 SB.CCM setupRtpChannel: Target IP addr = 127.0.0.1, port = 11134

08:06:45.756 SB.CCM setupRtpChannel: Undo of previous operation not required

08:06:45.757 SB.CCM setupRtpChannel: *** Internal address used for RTP channel!!! ***

08:06:45.757 SB.CCM getFinalCodec: G729

08:06:45.757 SB.CCM getFinalCodec: G729

08:06:45.758 SB.CCM setupRtpChannel: Configuring RTP Channel 0/1.1 to Src 127.0.0.1:11132 Trg 127.0.0.1:11134 via G729 Rx G729

08:06:45.758 SB.CCM setupRtpChannel: fpp=2 echo=on dtmf=101/101 dscp=46 vad=off isOffer yes

08:06:45.758 SB.CCM setupRtpChannel: Starting RTP Channel

08:06:45.758 RTP.CHANNEL Channel 0/1.1 session statistics cleared.

08:06:45.759 RTP.CHANNEL Channel 0/1.1 started successfully.

08:06:45.759 SB.CCM firewallConnectCall: Set up firewall from media connections

08:06:45.759 SB.CCM sdpFirewall: invoked with offer - [::]:11134, answer - 127.0.0.1:11134

08:06:45.759 SB.CCM sdpFirewall: 'any' address detected, no action taken

08:06:45.760 SB.CCM sdpFirewall: invoked with offer - [::]:11132, answer - 127.0.0.1:11132

08:06:45.760 SB.CCM sdpFirewall: 'any' address detected, no action taken

08:06:45.760 SB.CCM connect: TDM streams: port(Isdn(Ds1Ds0Trunk) 2/1.2) to port(InternalRtpApp 0/1.1)

08:06:45.760 SB.CCM finalizeConnect: connection already finalized(6)

08:06:45.761 SB.CALL 360 State change      >> ForcedReInviteDst->Connected

08:06:45.761 RTP.CHANNEL t1 2/1.2 - Dsp 0/1.1 - RTP: starting

08:06:45 VXMLInterpreter vxml. Ca:0 # Set 'RootForXML' to 'CFLASH:/VoiceMail/'

08:06:45 VXMLInterpreter vxml. Ca:0 # Set 'RootForWAV' to 'CFLASH:/SystemDefaultPrompts/'

08:06:45 VXMLInterpreter vxml. Ca:0 # Set 'operator' to '0'

08:06:45 VXMLInterpreter vxml. Ca:0 # Set 'internalError' to 'tel:@operator@'

08:06:45 VXMLInterpreter vxml. Ca:0 # Set 'collect' to ''

08:06:45 VXMLInterpreter vxml. Ca:0 # Set 'disconnect' to 'disconnect:'

08:06:45 VXMLInterpreter vxml. Ca:0 # Set 'repeat' to 'previous.0'

08:06:45 VXMLInterpreter vxml. Ca:0 # Set 'CallerName' to 'UNKNOWN'

08:06:45 VXMLInterpreter vxml. Ca:0 # Set 'CallerNumber' to 'UNKNOWN'

08:06:45 VXMLInterpreter vxml. Ca:0 # Set 'CalleeName' to 'UNKNOWN'

08:06:45 VXMLInterpreter vxml. Ca:0 # Set 'CalleeNumber' to 'UNKNOWN'

08:06:45 VXMLInterpreter vxml. Ca:0 # Set 'CallerNumber' to '718608169986'

08:06:45 VXMLInterpreter vxml. Ca:0 # Set 'CalleeName' to 'VoiceMailAcct'

08:06:45 VXMLInterpreter vxml. Ca:0 # Set 'CalleeNumber' to '850'

08:06:45 VXMLInterpreter vxml.850 Ca:0 # Set 'CalledOriginalNumber' to '324'

08:06:45 VXMLInterpreter vxml.850 Ca:0 # Set 'FullOptions' to 'Yes'

08:06:45 VXMLInterpreter vxml.850 Ca:0   CallerName:UNKNOWN CallerNumber:718608169986 CalleeName:VoiceMailAcct CalleeNumber:850 CalledOriginalNumber:324

08:06:45 VXMLInterpreter vxml.850 Ca:0 # Set 'RootDocument' to '.vmRoot.xml'

08:06:45 VXMLInterpreter vxml.850 Ca:0 Process Action: '.vmRoot.xml' (.vmRoot.xml)

08:06:45 VXMLInterpreter vxml.850 Ca:0   Loaded XML from 'CFLASH:/VoiceMail/.vmRoot.xml'

08:06:45 VXMLInterpreter vxml.850 Ca:0 # Set 'LoopCount.CheckAction' to '1'

08:06:45 VXMLInterpreter vxml.850 Ca:0 Entering state: '<transfer id='CheckAction'>'

08:06:45 VXMLInterpreter vxml.850 Ca:0 # Entering File: 'CFLASH:/VoiceMail/.vmRoot.xml' Offset: 8531'

08:06:45 VXMLInterpreter vxml.850 Ca:0 # Set 'internalError' to '.vmRoot.xml#internalError'

08:06:45 VXMLInterpreter vxml.850 Ca:0 # Set 'action' to 'leaving'

08:06:45 VXMLInterpreter vxml.850 Ca:0 # Set 'mailboxNum' to '324'

08:06:45 VXMLInterpreter vxml.850 Ca:0 Calling external function '' = newVoicemailSession(@mailboxNum@,@action@,@CallerNumber@,@CallerName@)

08:06:45 VXMLInterpreter vxml.850 Ca:0 VSCO: New session started, requesting mailbox 324

08:06:45 VXMLInterpreter vxml.850 Ca:0 # External function 'newVoicemailSession' with args '324,leaving,718608169986,UNKNOWN' completed with '0'

VoiceMail.MailboxManager:  Sending Copy of Mailbox 324 to VSCO.

VoiceMail.MailboxManager:  getMailbox(): Getting Mailbox 324 for action Leaving

VoiceMail.MailboxManager:  getMailbox():  Found Mailbox 324 with a current status of Idle

VoiceMail.MailboxManager:  getMailbox()[324]:  Updating messages for deletion in copy of mailbox

VoiceMail.MailboxManager.Mailbox:  updateMessagesforDeletion():  Updating Quota and Ageing for mailbox

VoiceMail.MailboxManager:  getTotalNumMsgs():  The system has 106 total VM messages

VoiceMail.MailboxManager:  getMailbox():  Finished for mailbox 324 for action Leaving with a status of Leaving

08:06:45 VXMLInterpreter vxml.850 Ca:0 VSCO: Received mailbox  324

08:06:45 VXMLInterpreter vxml.850 Ca:0 # Set 'mailboxLoopCount' to '0'

08:06:45 VXMLInterpreter vxml.850 Ca:0 Starting timer for 10 mseconds.

08:06:45 VXMLInterpreter vxml.850 Ca:0 Process Action: '#ValidateMailbox' (#ValidateMailbox)

08:06:45 VXMLInterpreter vxml.850 Ca:0 Leaving state: '<transfer id='CheckAction'>'

08:06:45 VXMLInterpreter vxml.850 Ca:0 # Set 'LoopCount.ValidateMailbox' to '1'

08:06:45 VXMLInterpreter vxml.850 Ca:0 Entering state: '<transfer id='ValidateMailbox'>'

08:06:45 VXMLInterpreter vxml.850 Ca:0 # Entering File: 'CFLASH:/VoiceMail/.vmRoot.xml' Offset: 5071'

08:06:45 VXMLInterpreter vxml.324 Ca:0 Calling external function 'isValid' = isMailboxValid()

08:06:45 VXMLInterpreter vxml.324 Ca:0 # Set 'isValid' to 'true'

08:06:45 VXMLInterpreter vxml.324 Ca:0 # External function 'isMailboxValid' with args '' completed with '1'

08:06:45 VXMLInterpreter vxml.324 Ca:0 Calling external function 'isAvailable' = isMailboxAvailable()

08:06:45 VXMLInterpreter vxml.324 Ca:0 # Set 'isAvailable' to 'true'

08:06:45 VXMLInterpreter vxml.324 Ca:0 # External function 'isMailboxAvailable' with args '' completed with '1'

08:06:45 VXMLInterpreter vxml.324 Ca:0 Calling external function 'isBusy' = isMailboxBusy()

08:06:45 VXMLInterpreter vxml.324 Ca:0 # Set 'isBusy' to 'false'

08:06:45 VXMLInterpreter vxml.324 Ca:0 # External function 'isMailboxBusy' with args '' completed with '1'

08:06:45 VXMLInterpreter vxml.324 Ca:0 Starting timer for 10 mseconds.

08:06:45 VXMLInterpreter vxml.324 Ca:0 Process Action: '.vmLeaveMessage.xml' (.vmLeaveMessage.xml)

08:06:45 VXMLInterpreter vxml.324 Ca:0 Leaving state: '<transfer id='ValidateMailbox'>'

08:06:45 VXMLInterpreter vxml.324 Ca:0   Loaded XML from 'CFLASH:/VoiceMail/.vmLeaveMessage.xml'

08:06:45 VXMLInterpreter vxml.324 Ca:0 # Set 'LoopCount.checkMailbox' to '1'

08:06:45 VXMLInterpreter vxml.324 Ca:0 Entering state: '<transfer id='checkMailbox'>'

08:06:45 VXMLInterpreter vxml.324 Ca:0 # Entering File: 'CFLASH:/VoiceMail/.vmLeaveMessage.xml' Offset: 8932'

08:06:45 VXMLInterpreter vxml.324 Ca:0 Calling external function 'isFull' = isMailboxFull()

08:06:45 VXMLInterpreter vxml.324 Ca:0 # Set 'isFull' to 'false'

08:06:45 VXMLInterpreter vxml.324 Ca:0 # External function 'isMailboxFull' with args '' completed with '1'

08:06:45 VXMLInterpreter vxml.324 Ca:0 Starting timer for 10 mseconds.

08:06:45 VXMLInterpreter vxml.324 Ca:0 Process Action: '#leavingMessageMenu' (#leavingMessageMenu)

08:06:45 VXMLInterpreter vxml.324 Ca:0 Leaving state: '<transfer id='checkMailbox'>'

08:06:45 VXMLInterpreter vxml.324 Ca:0 # Set 'LoopCount.leavingMessageMenu' to '1'

08:06:45 VXMLInterpreter vxml.324 Ca:0 Entering state: '<menu id='leavingMessageMenu'>'

08:06:45 VXMLInterpreter vxml.324 Ca:0 # Entering File: 'CFLASH:/VoiceMail/.vmLeaveMessage.xml' Offset: 7340'

08:06:45 VXMLInterpreter vxml.324 Ca:0 Calling external function 'greeting' = getCurrentGreeting()

08:06:45 VXMLInterpreter vxml.324 Ca:0 # Set 'greeting' to 'CFLASH:/VoiceMail/324/standard.wav'

08:06:45 VXMLInterpreter vxml.324 Ca:0 # External function 'getCurrentGreeting' with args '' completed with '1'

08:06:45 VXMLInterpreter vxml.324 Ca:0 Calling external function 'newMessageName' = requestMessageName()

08:06:45 VXMLInterpreter vxml.324 Ca:0 VSCO: Requesting name for new vm message

08:06:45 VXMLInterpreter vxml.324 Ca:0 # External function 'requestMessageName' with args '' completed with '0'

VoiceMail.MailboxManager:  Sending New Message Filename of CFLASH:/VoiceMail/Messages/H11I06QODQ.wav to VSCO for Mailbox 324

08:06:45 VXMLInterpreter vxml.324 Ca:0 Calling external function 'messageTimeout' = getMaxMessageLength()

08:06:45 VXMLInterpreter vxml.324 Ca:0 # Set 'messageTimeout' to '120s'

08:06:45 VXMLInterpreter vxml.324 Ca:0 # External function 'getMaxMessageLength' with args '' completed with '1'

08:06:45 VXMLInterpreter vxml.324 Ca:0 Calling external function 'greetingType' = getCurrentGreetingType()

08:06:45 VXMLInterpreter vxml.324 Ca:0 # Set 'greetingType' to 'CFLASH:/SystemDefaultPrompts/R964.wav'

08:06:45 VXMLInterpreter vxml.324 Ca:0 # External function 'getCurrentGreetingType' with args '' completed with '1'

08:06:45 VXMLInterpreter vxml.324 Ca:0 # Set 'collect' to ''

08:06:45 VXMLInterpreter vxml.324 Ca:0 # Started prompt 'CFLASH:/VoiceMail/324/standard.wav'

08:06:45 VXMLInterpreter vxml.324 Ca:0 VSCO: New message name is  CFLASH:/VoiceMail/Messages/H11I06QODQ.wav

08:06:45 VXMLInterpreter vxml.324 Ca:0 # Set 'newMessageName' to 'CFLASH:/VoiceMail/Messages/H11I06QODQ.wav'

SMTP Not enough info to send.

2016.08.11 08:06:46 SMDR 357        08/11/2016 08:06:46 00:24 00:00:00 0:00:00:00 0    I T01 02/01                 718608169986    00/00 Zehen Pachori   324             N 324             F  v2

08:06:57 VXMLInterpreter vxml.324 Ca:0 # Platform Event: CFLASH:/VoiceMail/324/standard.wav audio complete

08:06:57 VXMLInterpreter vxml.324 Ca:0 ProcessingLogic. CFLASH:/VoiceMail/324/standard.wav audioComplete (OK)

08:06:57 VXMLInterpreter vxml.324 Ca:0 Starting timer for 1000 mseconds.

08:06:58 VXMLInterpreter vxml.324 Ca:0 # Platform Event: timer expired

08:06:58 VXMLInterpreter vxml.324 Ca:0 ProcessingLogic.timerExpired

08:06:58 VXMLInterpreter vxml.324 Ca:0 Starting timer for 10 mseconds.

08:06:58 VXMLInterpreter vxml.324 Ca:0 Leaving state: '<menu id='leavingMessageMenu'>'

08:06:58 VXMLInterpreter vxml.324 Ca:0 Entering state: '<noinput>'

08:06:58 VXMLInterpreter vxml.324 Ca:0 # Entering File: 'CFLASH:/VoiceMail/.vmLeaveMessage.xml' Offset: 6057'

08:06:58 VXMLInterpreter vxml.324 Ca:0 Starting timer for 10 mseconds.

08:06:58 VXMLInterpreter vxml.324 Ca:0 Process Action: '#recordMenu' (#recordMenu)

08:06:58 VXMLInterpreter vxml.324 Ca:0 Leaving state: '<noinput>'

08:06:58 VXMLInterpreter vxml.324 Ca:0 # Set 'LoopCount.recordMenu' to '1'

08:06:58 VXMLInterpreter vxml.324 Ca:0 Entering state: '<record id='recordMenu'>'

08:06:58 VXMLInterpreter vxml.324 Ca:0 # Entering File: 'CFLASH:/VoiceMail/.vmLeaveMessage.xml' Offset: 5721'

08:06:58 VXMLInterpreter vxml.324 Ca:0 Calling external function '' = recordingStarted(@newMessageName@)

08:06:58 VXMLInterpreter vxml.324 Ca:0 # External function 'recordingStarted' with args 'CFLASH:/VoiceMail/Messages/H11I06QODQ.wav' completed with '1'

08:06:58 VXMLInterpreter vxml.324 Ca:0 # Set 'collect' to ''

08:06:58 VXMLInterpreter vxml.324 Ca:0 # Started prompt 'CFLASH:/SystemDefaultPrompts/RS7_1.wav'

08:06:59 VXMLInterpreter vxml.324 Ca:0 # Platform Event: CFLASH:/SystemDefaultPrompts/RS7_1.wav audio complete

08:06:59 VXMLInterpreter vxml.324 Ca:0 ProcessingLogic. CFLASH:/SystemDefaultPrompts/RS7_1.wav audioComplete (OK)

08:06:59 VXMLInterpreter vxml.324 Ca:0 Starting timer for 120000 mseconds.

08:06:59 VXMLInterpreter vxml.324 Ca:0 Starting record to 'CFLASH:/VoiceMail/Messages/H11I06QODQ.wav'

SMTP Not enough info to send.

2016.08.11 08:07:04 OPERATING_SYSTEM.SESSION User polycomftp login OK on portal FTP (10.10.20.51:25364)

SMTP Not enough info to send.

2016.08.11 08:07:05 OPERATING_SYSTEM.NETSERVICES FTP Client serviced

SMTP Not enough info to send.

2016.08.11 08:07:05 OPERATING_SYSTEM.SESSION User polycomftp logged out from portal FTP (10.10.20.51:25364) after 00:00:01

SMTP Not enough info to send.

2016.08.11 08:07:07 OPERATING_SYSTEM.EXCEPTION New HTTP error reports detected, Emailing...

SMTP Response: 220 MXU-Exchange.MecanexUSA.local Microsoft ESMTP MAIL Service ready at Thu, 11 Aug 2016 08:06:35 -0400

To SMTP server: EHLO [10.0.0.160]

To SMTP server: 19 bytes of data

SMTP Response: 250-MXU-Exchange.MecanexUSA.local Hello [10.0.0.160]

SMTP Response: 250-SIZE

SMTP Response: 250-PIPELINING

SMTP Response: 250-DSN

SMTP Response: 250-ENHANCEDSTATUSCODES

SMTP Response: 250-X-ANONYMOUSTLS

SMTP Response: 250-AUTH NTLM

SMTP Response: 250-X-EXPS GSSAPI NTLM

SMTP Response: 250-8BITMIME

SMTP Response: 250-BINARYMIME

SMTP Response: 250-CHUNKING

SMTP Response: 250-XEXCH50

SMTP Response: 250-XRDST

SMTP Response: 250 XSHADOW

Unsupported form of SMTP-AUTH: 250-auth ntlm

SMTP Not enough info to send.

2016.08.11 08:07:07 OPERATING_SYSTEM.SESSION User polycomftp login OK on portal FTP (10.10.20.84:43720)

08:07:07.639 TM.T01 22 IsdnTmStateInboundConnected->IsdnTmStateTrunkClearing

08:07:07.639 TM.T01 22 IsdnTmStateTrunkClearing::enter()

08:07:07.640 TA.T01 22 TAConnected          rcvd: clear from TM

08:07:07.640 TA.T01 22 State change      >> TAConnected->TATrunkClearing (TAS_Clearing)

08:07:07.641 SB.CALL 360 Connected            Called the clearCall routine

08:07:07.641 SB.CALL 360 Connected            ClearCall sent from T01 to 850

08:07:07.641 SB.CALL 360 State change      >> Connected->Clearing

08:07:07.641 VOICEMAIL.CA:0 DigitGathering - rcvd: clearCall from SB

08:07:07.645 VOICEMAIL.CA:0 DigitGathering - State Change: DigitGathering to Idle

08:07:07.645 SB.CALL 360 Clearing             Called the clearResponse routine

08:07:07.646 SB.CALL 360 State change      >> Clearing->CallIdlePending

08:07:07.646 SB.CCM disconnect:

08:07:07.646 SB.CCM  :  Call Struct 0x43f6010 :   Call-ID = 360

08:07:07.646 SB.CCM  :  Org Acct = T01    Dst Acct = 850

08:07:07.646 SB.CCM  :  Org Port ID = Isdn(Ds1Ds0Trunk) 2/1.2   Dst Port ID = InternalRtpApp 0/1.1

08:07:07.647 SB.CCM  :  RTP Channel = 0/1.1

08:07:07.647 MOH.APP printCSHoldStates, disconnect: towOrig 0, towDest 0 origHold 0 destHold 0 isHold 0

08:07:07.647 SB.CCM disconnect: Call Connection Type is TDM_TO_RTP

08:07:07.647 SB.CCM disconnect, music on hold

08:07:07.647 SB.CCM disconnect: Stopping RTP Channel 0/1.1

08:07:07.648 RTP.CHANNEL Channel 0/1.1 stopped successfully.

08:07:07.648 SB.CCM disconnect: Disconnecting TDM streams

08:07:07.648 TM.T01 22 IsdnTmStateTrunkClearing->IsdnTmStateIdling

08:07:07.648 TM.T01 22 IsdnTmStateIdling::enter()

08:07:07.649 TM.T01 22 IsdnTmStateIdling - send appearance off

08:07:07.649 TM.T01 22 IsdnTmStateIdling->IsdnTmStateIdle

08:07:07.649 TM.T01 22 IsdnAppearanceChannel::releaseChannel

08:07:07.649 TM.T01 22 IsdnTmStateIdle::enter()

08:07:07.649 SB.CCM release:

08:07:07.650 SB.CCM  :  Call Struct 0x43f6010 :   Call-ID = 360

08:07:07.650 SB.CCM  :  Org Acct = T01    Dst Acct = 850

08:07:07.650 SB.CCM  :  Org Port ID = Isdn(Ds1Ds0Trunk) 2/1.2   Dst Port ID = InternalRtpApp 0/1.1

08:07:07.650 SB.CCM  :  RTP Channel = 0/1.1

08:07:07.650 SB.CCM release: Call Connection Type is TDM_TO_RTP

08:07:07.651 SB.CCM release: Releasing RTP Channel 0/1.1

08:07:07.651 RTP.CHANNEL Channel 0/1.1 released successfully.

08:07:07.651 SB.CALL 360 CallIdlePending      ClearResponse sent from 850 to T01

08:07:07.652 TA.T01 22 TATrunkClearing      clearResponse event accepted

08:07:07.652 TA.T01 22 State change      >> TATrunkClearing->TAClearingComplete (TAS_Clearing)

08:07:07.652 RTP.CHANNEL t1 2/1.2 - Dsp 0/1.1 - RTP: stopping

08:07:07.652 TA.T01 22 TAClearingComplete   rcvd: appearance off from TM

08:07:07.653 TA.T01 22 TAClearingComplete   Clear Local Variables

08:07:07.653 TA.T01 22 State change      >> TAClearingComplete->TAIdle (TAS_Idle)

08:07:07.653 RTP.CHANNEL t1 2/1.2 - Dsp 0/1.1 - RTP: releasing RTP resource

08:07:07.653 RTP.CHANNEL t1 2/1.2 - Dsp 0/1.1 - RTP: releasing

08:07:07 VXMLInterpreter vxml.324 Ca:0 # Platform Event:  record complete (OK)

08:07:07 VXMLInterpreter vxml.324 Ca:0 # Platform Event: deactivate

VoiceMail.MailboxManager.Mailbox:  addNewMessage():  Adding new message CFLASH:/VoiceMail/Messages/H11I06QODQ.wav to mailbox

VoiceMail.MailboxManager.Mailbox:  addNewMessage():  Message CFLASH:/VoiceMail/Messages/H11I06QODQ.wav has been added to mailbox

08:07:07 VXMLInterpreter vxml.324 Ca:0 VSCO: Sent mailbox 324 for update.

08:07:07 VXMLInterpreter vxml.324 Ca:0 Leaving state: '<record id='recordMenu'>'

08:07:07 VXMLInterpreter vxml.324 Ca:0 Stopping current timer.

VoiceMail.MailboxManager:  Beginning Mailbox Merge process for Mailbox 324 with a current status of Leaving

VoiceMail.MailboxManager:  update_mailbox()[324]:  Message H11I06QODQ is new to this mailbox

VoiceMail.MailboxManager:  sendNotification()[324]:  Attempting to notify user of new VM CFLASH:/VoiceMail/Messages/H11I06QODQ.wav

VoiceMail.MailboxManager:  sendNotification()[324]:  Sending email notification to zpachori@mecanexusa.com for message CFLASH:/VoiceMail/Messages/H11I06QODQ.wav

VoiceMail.MailboxManager:  update_mailbox()[324]:  Message H11I06QODQ is marked as new

VoiceMail.MailboxManager:  update_mailbox()[324]:  Message H11I06QODQ needs files updated

VoiceMail.MailboxManager:  createDSCFile()[324]:  Sending event to write DSC file CFLASH:/VoiceMail/324/H11I06QODQ.dsc

VoiceMail.MailboxManager:  createHDRFile():  Sending event to write HDR file CFLASH:/VoiceMail/Messages/H11I06QODQ.hdr

VoiceMail.MailboxManager:  update_mailbox()[324]:  Updating greetings- Greeting is Standard Greeting

VoiceMail.MailboxManager:  update_mailbox()[324]:  Messages in this mailbox have been updated- now updating MWI status

VoiceMail.MailboxManager:  update_mailbox()[324]:  This mailbox status is now Idle

VoiceMail.MailboxManager:  Mailbox Merge for Mailbox 324 completed successfully.

VoiceMail.MailboxManager:  FileWriteEvent():  Creating new file CFLASH:/VoiceMail/324/H11I06QODQ.dsc

VoiceMail.MailboxManager:  2016.08.11 08:07:07 G729ToPCMConverting CFLASH:/VoiceMail/Messages/H11I06QODQ.wav

VoiceMail.MailboxManager:  FileWriteEvent():  Creating new file CFLASH:/VoiceMail/Messages/H11I06QODQ.hdr

VoiceMail.MailboxManager:  FileDeleteEvent():  Deleting file CFLASH:/VoiceMail/324/alternate.wav

SMTP Not enough info to send.

2016.08.11 08:07:08 SMDR 357        08/11/2016 08:06:45 00:00 00:00:00 0:00:00:23 0    I T01 02/01                 718608169986    00/01 VoiceMailAcct   850             Y 324             F  v2

SMTP Response: 220 MXU-Exchange.MecanexUSA.local Microsoft ESMTP MAIL Service ready at Thu, 11 Aug 2016 08:06:37 -0400

To SMTP server: EHLO [10.0.0.160]

To SMTP server: 19 bytes of data

SMTP Response: 250-MXU-Exchange.MecanexUSA.local Hello [10.0.0.160]

SMTP Response: 250-SIZE

SMTP Response: 250-PIPELINING

SMTP Response: 250-DSN

SMTP Response: 250-ENHANCEDSTATUSCODES

SMTP Response: 250-X-ANONYMOUSTLS

SMTP Response: 250-AUTH NTLM

SMTP Response: 250-X-EXPS GSSAPI NTLM

SMTP Response: 250-8BITMIME

SMTP Response: 250-BINARYMIME

SMTP Response: 250-CHUNKING

SMTP Response: 250-XEXCH50

SMTP Response: 250-XRDST

SMTP Response: 250 XSHADOW

Unsupported form of SMTP-AUTH: 250-auth ntlm

VoiceMail.MailboxManager:  2016.08.11 08:07:07 G729ToPCMConvert converted 718608169986_08112016_0807.wav but send failedSMTP Not enough info to send.

2016.08.11 08:07:09 OPERATING_SYSTEM.NETSERVICES FTP Client serviced

SMTP Not enough info to send.

2016.08.11 08:07:09 OPERATING_SYSTEM.SESSION User polycomftp logged out from portal FTP (10.10.20.84:43720) after 00:00:02

08:07:11.443 PM.324 Looking up source address for destination 10.10.20.84

08:07:32.660 PM.303 Looking up source address for destination 10.10.20.32

[Anonymous]

If you look at the very bottom of your debug you will see this:

Unsupported form of SMTP-AUTH: 250-auth ntlm

The 7100 only supports plain, login, or md5 authentication. It does not support NTLM authentication.

Something must have changed on your Exchange server to request NTLM authentication.

-Mark

[zp-mecanex]

Mark I know it may be outside of your expertise, but would you know how to disable the ntlm authentication on the exchange server 2010 for the nv7100?

[Anonymous]

Sorry but I don’t have experience with that.

You could start here:

https://technet.microsoft.com/en-us/library/bb124503(v=exchg.141).aspx

-Mark

[zp-mecanex]

Mark,

The NV7100 uses the Outlook Anywhere feature for emailing?

[Anonymous]

I am not sure about Outlook Anywhere.

I know it works with Office365 using TLS

-Mark