[cisco-voip] DTMF failing intermitently

Tue Feb 19 13:59:39 EST 2019

You can't tell from just this snippet.  The disconnect happens higher up.
Are these pre-9.x traces as well?

Can you send full traces with SDLs off-list?

On Tue, Feb 19, 2019 at 1:15 PM Nilson Costa <nilsonlino at gmail.com> wrote:

> Customer weren´t able to specify the issue correctly, actually the issue
> is that some calls is reaching the agent extension but with no cutomer
> audio then checking the logs I found the followin
>
> 11:22:23.320 |Cdcc::isStaticTransactionApplicable
> |3,100,152,1.140880147^172.29.2.161^S1/DS1-0 at GVBL-03-03
> 11:22:23.320 |cdrWrite PER RR, orig = 0, lrn = 0, current =
> 0|3,100,152,1.140880147^172.29.2.161^S1/DS1-0 at GVBL-03-03
> 11:22:23.320 |processCCMFeatureData:
> operationIeIdd=0|3,100,152,1.140880147^172.29.2.161^S1/DS1-0 at GVBL-03-03
> 11:22:23.320 |ConnectionManager -
> wait_AuDisconnectRequest(52247993,52248126),disconnectType(1),
> IFHandling(0,0)|3,100,152,1.140880147^172.29.2.161^S1/DS1-0 at GVBL-03-03
> 11:22:23.320 |ConnectionManager - storeMediaInfo(52247993): EXISTING ENTRY
> DISCOVERED, size=2973|3,100,152,1.140880147^172.29.2.161^S1/DS1-0 at GVBL-03-03
> 11:22:23.320 |ConnectionManager - storeMediaInfo(52248126): EXISTING ENTRY
> DISCOVERED, size=2973|3,100,152,1.140880147^172.29.2.161^S1/DS1-0 at GVBL-03-03
> 11:22:23.320 |MGCPManager remove recent Incoming transId
> 201090657|3,100,152,1.140880087^192.168.183.133^*
> *11:22:23.320 |MatrixControl:connecting_ind_TConnect - ERROR.  Media
> Timeout|2,100,57,1.35961152^10.131.50.146^**
> 11:22:23.320 |MediaCoordinator -
> wait_AuDisconnectRequest,CI(52247993,52248126),IFCreated(1,1)|3,100,152,1.140880147^172.29.2.161^S1/DS1-0 at GVBL-03-03
> 11:22:23.320 |MediaCoordinator - wait_AuDisconnectRequest - sending
> disconnect to
> MediaManager(19314870)|3,100,152,1.140880147^172.29.2.161^S1/DS1-0 at GVBL-03-03
> 11:22:23.320 |cdrWrite PER RR, orig = 0, lrn = 0, current =
> 0|2,100,57,1.35961152^10.131.50.146^*
> 11:22:23.320 |MediaManager(19314870)::wait_AuDisconnectRequest,
> mCleanupPreallocatedMTP=0|3,100,152,1.140880147^172.29.2.161^S1/DS1-0 at GVBL-03-03
> 11:22:23.320 |MediaManager(19314870)::wait_AuDisconnectRequest, mrid(0,0)
> ci(5224799352248126) size(1),
> dt(1)|3,100,152,1.140880147^172.29.2.161^S1/DS1-0 at GVBL-03-03
> 11:22:23.320 |MediaManager(19314870)::wait_AuDisconnectRequest,
> StopSession,disconn MX(130,22759634) mrid (0 0),
> IFHandling(0,0)|3,100,152,1.140880147^172.29.2.161^S1/DS1-0 at GVBL-03-03
> 11:22:23.320
> |//SIP/SIPD(3,67,10)/ccbId=0/scbId=0/getKeyBasedOnCiAndBranch:
> AddressingElement branch is 0 and ci is 52247952  mapKey is
> 52247952|2,100,57,1.35961152^10.131.50.146^*
> 11:22:23.320 |//SIP/SIPD(3,67,10)/ccbId=0/scbId=0/getCdpcPid: found Cdpc
> Pid (3,100,68,926546) for mapKey
> 52247952|2,100,57,1.35961152^10.131.50.146^*
> 11:22:23.320 |MediaExchange(22759634)::wait_Disconnect,
> dt=1,stReason=0,IFHandling(0,0)|3,100,152,1.140880147^172.29.2.161^S1/DS1-0 at GVBL-03-03
> 11:22:23.320
> |EnvProcessCdr::wait_DbCdrReq|3,100,152,1.140880147^172.29.2.161^S1/DS1-0 at GVBL-03-03
> 11:22:23.320 |EnvProcessCdr::wait_DbCdrReq DETAILED Entries 10287372,
> Inserts 7883215,             ZeroCalls 2404157, StartRecords 0, Default
> 0|3,100,152,1.140880147^172.29.2.161^S1/DS1-0 at GVBL-03-03
> 11:22:23.320
> |EnvProcessCdr::formatCdrData|3,100,152,1.140880147^172.29.2.161^S1/DS1-0 at GVBL-03-03
> 11:22:23.321
> |//SIP/SIPCdpc(3,68,926546)/ci=52247952/ccbId=1869334/scbId=0/active_CcDisconnReq:
> ccDisconnReq.onBehalfOf=Media : ccDisconnReq.s.sv=2 : ccDisconnReq.c.cv=47
> |2,100,57,1.35961152^10.131.50.146^*
> 11:22:23.321
> |//SIP/SIPCdpc(3,68,926546)/ci=52247952/ccbId=1869334/scbId=0/appendReasonHdr:
> appendReasonHdr - Invalid Disconnect Cause(cause=47), No Reason Header
> Appended|2,100,57,1.35961152^10.131.50.146^*
> 11:22:23.321
> |//SIP/SIPCdpc(3,68,926546)/ci=52247952/ccbId=1869334/scbId=0/addTransparencyInfo:
> Transparency info is NULL.  Not attaching
> anything.|2,100,57,1.35961152^10.131.50.146^*
> 11:22:23.321 |MGCPInterface(5624152) - isGClearCall - return false,
> gClearSupported:0,
> mpeerxfermode:7|3,100,152,1.140880147^172.29.2.161^S1/DS1-0 at GVBL-03-03
> 11:22:23.321 |MGCPHandler send msg SUCCESSFULLY to: 192.168.183.133
> MDCX 115006632 S1/DS1-0/28 at GVBL-03-03 MGCP 0.1
> C: D0000000031d3db9000000F500003573
> I: 37D646A
> X: 1c
> M: recvonly
> R: D/[0-9ABCD*#]
> Q: process,loop
> |3,100,152,1.140880147^172.29.2.161^S1/DS1-0 at GVBL-03-03
> 11:22:23.321 |//SIP/SIPHandler/ccbId=0/scbId=0/sip_stop_timer:
> type=SIP_TIMER_DISCONNECT value=500
> retries=10|2,100,57,1.35961152^10.131.50.146^*
> 11:22:23.321 |//SIP/SIPHandler/ccbId=0/scbId=0/sip_start_timer:
> type=SIP_TIMER_DISCONNECT value=500
> retries=10|2,100,57,1.35961152^10.131.50.146^*
> 11:22:23.321 |//SIP/SIPUdp/wait_SdlSPISignal: Outgoing SIP UDP message to
> 192.168.27.103:[5060]:
> [9821892,NET]
> BYE sip:11984660028 at 192.168.27.103:5060 SIP/2.0
> Via: SIP/2.0/UDP 192.168.183.5:5060;branch=z9hG4bK173a4d3d3146d
> From: <sip:4005 at 192.168.27.103:5060
> >;tag=1869334~676f1309-fb09-46b1-b894-3b8a002cf33d-52247952
> To: sip:11984660028 at 192.168.183.4
> ;tag=B9449B1E-3DD5-40FC-8A68-AF29BB48EA02-115745
> Date: Mon, 18 Feb 2019 14:22:06 GMT
> Call-ID: 98EC6E50-4719-41D1-B895-C0D319E2BC34-81888 at 192.168.27.103
> User-Agent: Cisco-CUCM8.5
> Max-Forwards: 70
> CSeq: 103 BYE
> Reason: Q.850;cause=47
> Content-Length: 0
>
> Now what I understood is that *10.131.50.146 *is finishing the call due
> to media inactivity, is that correct?
>
> Em seg, 18 de fev de 2019 às 18:37, Nilson Costa <nilsonlino at gmail.com>
> escreveu:
>
>> Hello Tim,
>>
>> We have 2 CUCM involved on this negociation the first which control the
>> call from PSTN is 8.5 and the second that controls the extension is 11.5
>> We have a bunch of hardware MTP for the whole system
>> not using transcoders
>>
>>
>> Em sex, 15 de fev de 2019 16:53, Johnson, Tim <johns10t at cmich.edu
>> escreveu:
>>
>>> Interesting. I’ve started to see this just within the last couple
>>> months. I talked with TAC about it but they just said I need to use a
>>> transcoder to resolve it. It seems that there must be another way to go
>>> about resolving it.
>>>
>>>
>>>
>>> What version of CUCM are you using? Are you using software or hardware
>>> MTP? How about transcoders?
>>>
>>>
>>>
>>> We’re on 12.0.1.21900-7, software MTP, and no transcoder.
>>>
>>>
>>>
>>> *From:* cisco-voip <cisco-voip-bounces at puck.nether.net> *On Behalf Of *Nilson
>>> Costa
>>> *Sent:* Friday, February 15, 2019 1:44 PM
>>> *To:* cisco-voip at puck.nether.net
>>> *Subject:* [cisco-voip] DTMF failing intermitently
>>>
>>>
>>>
>>> Hello all,
>>>
>>>
>>>
>>>
>>>
>>> Does it error means a DTMF error due to MTP failure ?
>>>
>>> |!!ERROR!! -MediaManager-(404)::isMTPNeededForDTMFInjectionFromOOBTo2833
>>> DTMFMTPSide=0, MTPInsertReason=0
>>>
>>>
>>>
>>> Regards
>>>
>>>
>>>
>>> --
>>>
>>> Nilson Lino da Costa Junior
>>>
>>
>
> --
> Nilson Lino da Costa Junior
> _______________________________________________
> cisco-voip mailing list
> cisco-voip at puck.nether.net
> https://puck.nether.net/mailman/listinfo/cisco-voip
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://puck.nether.net/pipermail/cisco-voip/attachments/20190219/f77fc456/attachment.html>