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.
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
Hi Mark,
I telnetted to the unit and attempted the command, however it is unrecognized.
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
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
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
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
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?
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
Mark,
The NV7100 uses the Outlook Anywhere feature for emailing?
I am not sure about Outlook Anywhere.
I know it works with Office365 using TLS
-Mark