Re: Intermittent calls dropping, returning fast busy - Page 2

Rick Morris · ‎10-29-2010

I am working an issue for Intermittent calls dropping, returning fast busy.

Here is the output of the RTMT log for the issue we see.

10/28/2010 15:37:51.546 CCM|Digit analysis: match(pi="2", fqcn="5133866428", cn="6428",plv="5", pss="BlockExploitPSTN_PT:BlockNothing:Phones_PT:System_PT:HQPSTN_PT",

TodFilteredPss="BlockExploitPSTN_PT:BlockNothing:Phones_PT:System_PT:HQPSTN_

PT",

dd="913606645773",dac="0")|<CLID::StandAloneCluster><NID::192.168.26.3><CT::

2,100,39,1.25832353><IP::192.168.26.56><DEV::SEP0016478B0C8D><LVL::State

Transition><MASK::0800>

10/28/2010 15:37:51.546 CCM|Digit analysis: analysis

results|<CLID::StandAloneCluster><NID::192.168.26.3><CT::2,100,39,1.2583

results|2353

><IP::192.168.26.56><DEV::SEP0016478B0C8D><LVL::State

Transition><MASK::0800>

10/28/2010 15:37:51.546 CCM||PretransformCallingPartyNumber=6428

|CallingPartyNumber=513

|DialingPartition=HQPSTN_PT

|DialingPattern=9.1[2-9]XX[2-9]XXXXXX

|FullyQualifiedCalledPartyNumber=913606645773

10/28/2010 15:37:52.014 CCM|StationD: (0000034) SEP0016478B0C8D ,

star_MediaExchangeAgenaOpenLogicalChannel packetSize=20, codec=4,

ci=40794829|<CLID::StandAloneCluster><NID::192.168.26.3><CT::2,100,16,129626

.2><IP::192.168.26.254><DEV::Port 26285><LVL::Detailed><MASK::0020>

10/28/2010 15:37:52.014 CCM|StationD: (0000034)

StopTone.|<CLID::StandAloneCluster><NID::192.168.26.3><CT::2,100,16,129626.2

><IP::192.168.26.254><DEV::Port 26285><LVL::State

>Transition><MASK::0020>

10/28/2010 15:37:52.014 CCM|StationD::star_StationOutputOpenReceiveChannel

myCi=40794829

keylen=0|<CLID::StandAloneCluster><NID::192.168.26.3><CT::2,100,16,129626.2>

<IP::192.168.26.254><DEV::Port 26285><LVL::Detailed><MASK::0800>

10/28/2010 15:37:52.014 CCM|StationD: (0000034) OpenReceiveChannel

conferenceID=40794829 passThruPartyID=34135337 millisecondPacketSize=20

compressionType=4(Media_Payload_G711Ulaw64k) RFC2833PayloadType=0 qualifierIn=? sourceIpAddr=IpAddr.type:0 ipAddr:0xc0a81a02000000000000000000000000(192.168.26.2). myIP: IpAddr.type:0

ipv4Addr:0xc0a81a38(192.168.26.56)

|<CLID::StandAloneCluster><NID::192.168.26.3><CT::2,100,16,129626.2><IP:

|:192

.168.26.254><DEV::Port 26285><LVL::Significant><MASK::0020>

10/28/2010 15:38:33.996 CCM|TranslateAndTransport(129626)::wait_SdlCloseInd

- ERROR: H245 signaling connection aborted!!!|

117380916| 2010/10/28 15:38:33.996| 002| SdlSig | TtFailure

| h245CloseSessionRequest_wait_for_LcseReleaseConfirm|

H245SessionManager(2,100,23,129626)| TranslateAndTransport(2,100,16,129626)|

(2,100,39,1).25832393-(SEP0016478B0C8D:192.168.26.56)| [R:NP - HP: 0, NP: 0,

LP: 0, VLP: 0, LZP: 0 DBP: 0]

10/28/2010 15:38:33.998 CCM|StationD: (0000034)

StopTone.|<CLID::StandAloneCluster><NID::192.168.26.3><CT::2,100,39,1.258323

93><IP::192.168.26.56><DEV::SEP0016478B0C8D><LVL::State

Transition><MASK::0020>

10/28/2010 15:38:33.998 CCM|StationD: (0000034) StartTone

tone=37(ReorderTone),

direction=0.|<CLID::StandAloneCluster><NID::192.168.26.3><CT::2,100,39,1.258

32393><IP::192.168.26.56><DEV::SEP0016478B0C8D><LVL::State

Transition><MASK::0020>

10/28/2010 15:38:33.999 CCM|StationD: (0000034) SelectSoftKeys instance=1

reference=40794829 softKeySetIndex=8

validKeyMask=fffffffb.|<CLID::StandAloneCluster><NID::192.168.26.3><CT::2,10

0,39,1.25832393><IP::192.168.26.56><DEV::SEP0016478B0C8D><LVL::State

Transition><MASK::0020>

10/28/2010 15:38:33.999 CCM|StationD: (0000034) DEBUG-

star_DSetCallState(11) State of cdpc(265108) is

6.|<CLID::StandAloneCluster><NID::192.168.26.3><CT::2,100,39,1.25832393><IP:

:192.168.26.56><DEV::SEP0016478B0C8D><LVL::Detailed><MASK::0020>

You should investigate why the TCP session between the server and the gateway closed, and identify the failure on the network devices between them.

It took me some time to find out this because your CUCM version is not very specific with the messages from the logs, look at this bug to enhance the trace files

CSCsm26355

Symptom:

delayed or failed h323 call setup

Conditions:

CM sends TCP SYN to remote peer for h245 session but does not receive any response.

Workaround:

None.

Further Problem Description:

This is a request for additional debugging to make it clear when h.245 TCP session setup fails.

There are currently no intuitive SDI or alarm messages to indicate this failure. It usually requires SDL traces to identify failure to setup the TCP session.

After upgrade to fixed version the following errors appear in the CM SDI

traces:

h.245 tcp session setup failure:

TCP ERROR: H245ListenReq or H245ConnectReq failure, or received SdlCloseInd from H245Handler, Perform cleanup of H245 Session

established h.245 session experiences TCP keepalive timeout:

TranslateAndTransport(%d)::wait_SdlCloseInd - ERROR: H245 signaling connection aborted

established h.245 session receives unexpected TCP FIN or RST:

TranslateAndTransport(%d)::wait_SdlCloseInd - ERROR: H245 signaling connection aborted

My issue is where to look.

Here is the Topology:

CUCM 7.1 --- 2960 (Pub G0/18 Sub G0/15) --- Core 3750 (G2/0/1) --- Gateway 2851

I verified on all interfaces that there are no errors. Nothing in the logs to indicate any issues.

Any direction will be appreciated and will receive a rating.

Thanks,

Rick

asandborgh · ‎11-03-2010

Ah yes,

this is definitely a PRI - please do a debug isdn q931 instead of the debug VPM (as per my earlier post). It should give us the direction of the disconnect and the cause code which will help.

Thanks,

Art

Rick Morris · ‎11-03-2010

Thanks. Applied pri debug

Rick Morris · ‎11-03-2010

I have 3 dropped calls from the site.

I stopped the debug and searched through the log and do not see any of the numbers listed in the log that they say were dropped. How can I track down or debug those type of calls?

asandborgh · ‎11-04-2010

Hi Rick,

Assuming that the calls went off-site and that is the only path to the PSTN the calls should have been in the debug. I've never experienced a debug isdn q931 not catch a call out a PRI before....

The previous VPM debug that you had before indicated they were indeed going out that PRI - not sure what to make of it.

Art

asandborgh · ‎11-04-2010

Can you also run a show controller t1 0/1/0 so we can see if there are any errors or slips?

Art

Rick Morris · ‎11-04-2010

T1 0/1/0 is up.

Applique type is Channelized T1

Cablelength is long gain36 0db

No alarms detected.

alarm-trigger is not set

Soaking time: 3, Clearance time: 10

AIS State:Clear LOS State:Clear LOF State:Clear

Version info Firmware: 20060711, FPGA: 13, spm_count = 0

Framing is ESF, Line Code is B8ZS, Clock Source is Line.

CRC Threshold is 320. Reported from firmware is 320.

Data in current interval (44 seconds elapsed):

0 Line Code Violations, 0 Path Code Violations

0 Slip Secs, 0 Fr Loss Secs, 0 Line Err Secs, 0 Degraded Mins

0 Errored Secs, 0 Bursty Err Secs, 0 Severely Err Secs, 0 Unavail Secs

Total Data (last 24 hours)

0 Line Code Violations, 0 Path Code Violations,

0 Slip Secs, 0 Fr Loss Secs, 0 Line Err Secs, 0 Degraded Mins,

0 Errored Secs, 0 Bursty Err Secs, 0 Severely Err Secs, 0 Unavail Secs

Ray Watkins · ‎10-29-2010

Do you have a firewall between the devices?

Rick Morris · ‎10-29-2010

No firewall in this topology

Ray Watkins · ‎10-29-2010

Can you post part of the config? I interested in the voice service voip section.

Rick Morris · ‎10-30-2010

Here is the config, and I am particularly curious about one of the sections:

See above comments about the timeout after 3 seconds:

isdn switch-type primary-ni
!
voice-card 0
no dspfarm
!
!
voice rtp send-recv
!
voice service pots
!
voice service voip
allow-connections h323 to h323
allow-connections h323 to sip
allow-connections sip to h323
allow-connections sip to sip
supplementary-service h450.12
fax protocol t38 ls-redundancy 5 hs-redundancy 2 fallback none
h323
sip
!
voice class codec 1
codec preference 1 g711ulaw
codec preference 2 g729r8
!
voice class h323 1
h225 timeout tcp establish 3
call start fast
call preserve
!
voice vad-time 25000
!
voice translation-rule 2
rule 1 // // type any unknown plan any unknown
!
voice translation-profile international
translate called 2
!
voice-port 0/1/0:23
!

dial-peer voice 8000 voip
description **** SIP TRUNK TO TWTC ****
destination-pattern .T
session protocol sipv2
session target ipv4:2xx.2xx.xx.xx:4060
dtmf-relay rtp-nte digit-drop
codec g711ulaw
fax protocol pass-through g711ulaw
ip qos dscp cs5 media
ip qos dscp cs5 signaling
no vad
!
dial-peer voice 3099 pots
destination-pattern 999T
port 0/1/0:23
!
!
gateway
timer receive-rtp 1200
!
telephony-service
max-conferences 8 gain -6
transfer-system full-consult
create cnf-files version-stamp Jan 01 2002 00:00:00
!

Ray Watkins · ‎10-31-2010

Ok. I just finished resolving an issue with a similiar issue and config. If this is not an IP 2 IP gateway then you need to remove the following statement unless you have another need for them.

allow-connections h323 to h323
allow-connections h323 to sip
allow-connections sip to h323
allow-connections sip to sip

Ray Watkins · ‎10-31-2010

One other thing. What's the processor on the gateway during times of dropped calls. I suspect you'll also notice burst of high call volume in the RTMT as well.

Ray Watkins · ‎11-04-2010

Is this configured as a H323 gateway in Callmanager? Can you post the entire config off the gateway? What is the call volume? How many calls are active at any given time?

Rick Morris · ‎11-09-2010

***RESOLVED***

the issue with this was found to be a config issue between the call manager and the gateway. The call manager was set for fast-start and the gateway was set for slow-start. We added more to the MTP resources and changed the gateway to reflect fast-start and the issue appears to be gone. Why now? There was a change, which the customer stated was not done, and there was a large increase in call volume.

Thanks all for your assistance