SIP calls dropped on Cisco CallManager

Symptom

SIP calls are dropped for no apparent reason when using Cisco Call Manager, and entries similar to the following are found in the log:

===== Call is connected and AlarmPoint is playing menu items ========
2009-09-14 13:11:22,746 [DeviceEngineWorker-SIP-2] DEBUG - - Play file: "Monday-1.vox"
2009-09-14 13:11:23,355 [DeviceEngineWorker-SIP-2] DEBUG - - Play file: "September.vox"
2009-09-14 13:11:24,214 [DeviceEngineWorker-SIP-2] DEBUG - - Play file: "Fourteenth.vox"
2009-09-14 13:11:25,027 [DeviceEngineWorker-SIP-2] DEBUG - - Play file: "AT-1.vox"
2009-09-14 13:11:25,605 [DeviceEngineWorker-SIP-2] DEBUG - - Play file: "Thirteen.vox"
2009-09-14 13:11:26,386 [DeviceEngineWorker-SIP-2] DEBUG - - Play file: "Ten.vox"
2009-09-14 13:11:26,980 [DeviceEngineWorker-SIP-2] DEBUG - - Failed to locate file "Hello World ". Spelling file name using TTS or characters.
2009-09-14 13:11:26,980 [DeviceEngineWorker-SIP-2] DEBUG - - Get TTS personality Microsoft Mary from engine settings
2009-09-14 13:11:30,308 [DeviceEngineWorker-SIP-2] DEBUG - - Play file: "1 ack, 2 clr, 3 ign, 9 rpt-1.vox"
2009-09-14 13:11:31,043 [SipRegistrationExpiredTimer_0] DEBUG - - SIP registration timeout. Register it again
2009-09-14 13:11:31,043 [SipRegistrationExpiredTimer_0] DEBUG - - The change state for registration is triggered. (sipAlarmPoint@localhost
:UPDATING_REGISTRATION)
2009-09-14 13:11:31,043 [SipRegistrationExpiredTimer_0] DEBUG - - The change state for registration is triggered. (sipAlarmPoint@localhost
:UNREGISTERING)
2009-09-14 13:11:31,043 [SipRegistrationExpiredTimer_0] DEBUG - - =>REGISTER sip:localhost;transport=udp SIP/2.0
Call-ID: 7fedff5b41d307ed3ec198a00d1aeebf@localhost

From: "AlarmPoint Systems" <sip:AlarmPoint@localhost
>;tag=8b72dad2
To: "AlarmPoint Systems" <sip:AlarmPoint@localhost
>
Via: SIP/2.0/UDP localhost:5060;branch=z9hG4bKd949b7de8ec53fd9c32eace498904d10;rport
Max-Forwards: 70
User-Agent: Alarmpoint SIP Client 1.0
Expires: 0
Contact: "Alarmpoint" <sip:AlarmPoint@localhost
:5060;transport=udp>;expires=0
CSeq: 511970 REGISTER
Content-Length: 0

2009-09-14 13:11:31,043 [EventScannerThread] DEBUG - - <=SIP/2.0 100 Trying
Date: Mon, 14 Sep 2009 17:11:30 GMT
From: "AlarmPoint Systems" <sip:AlarmPoint@localhost
>;tag=8b72dad2
To: "AlarmPoint Systems" <sip:AlarmPoint@localhost
>
Call-ID: 7fedff5b41d307ed3ec198a00d1aeebf@localhost

Via: SIP/2.0/UDP localhost:5060;branch=z9hG4bKd949b7de8ec53fd9c32eace498904d10;rport
CSeq: 511970 REGISTER
Content-Length: 0
2009-09-14 13:11:31,043 [EventScannerThread] DEBUG - - <=SIP/2.0 200 OK
Date: Mon, 14 Sep 2009 17:11:30 GMT
From: "AlarmPoint Systems" <sip:AlarmPoint@localhost
>;tag=8b72dad2
Supported: X-cisco-sis-2.0.0
To: "AlarmPoint Systems" <sip:AlarmPoint@localhost
>;tag=1072811692
Expires: 0
Call-ID: 7fedff5b41d307ed3ec198a00d1aeebf@localhost
Via: SIP/2.0/UDP localhost:5060;branch=z9hG4bKd949b7de8ec53fd9c32eace498904d10;rport
CSeq: 511970 REGISTER
Content-Length: 0
========== Registration expires so we try and register again ==========
2009-09-14 13:11:31,043 [EventScannerThread] DEBUG - - SIP registration expired
2009-09-14 13:11:31,043 [EventScannerThread] DEBUG - - The change state for registration is triggered. (sipAlarmPoint@localhost
:UNREGISTERED)
2009-09-14 13:11:31,043 [SipRegistrationExpiredTimer_0] DEBUG - - The change state for registration is triggered. (sipAlarmPoint@localhost
:REGISTERING)
2009-09-14 13:11:31,043 [SipRegistrationExpiredTimer_0] DEBUG - - =>REGISTER sip:localhost;transport=udp SIP/2.0
Call-ID: bd9576c56bb9dd821ca97d0d0cdd8700@localhost
CSeq: 511971 REGISTER
From: "AlarmPoint Systems" <sip:AlarmPoint@localhost
>;tag=5fdcdc1
To: "AlarmPoint Systems" <sip:AlarmPoint@localhost
>
Via: SIP/2.0/UDP localhost:5060;branch=z9hG4bKc66838ea8586a84d75d0c01d7cb3b0ae;rport
Max-Forwards: 70
User-Agent: Alarmpoint SIP Client 1.0
Expires: 120
Contact: "Alarmpoint" <sip:AlarmPoint@localhost
:5060;transport=udp>;expires=120
Content-Length: 0

======== Cisco says BYE for no apparent reason ============

2009-09-14 13:11:31,043 [EventScannerThread] DEBUG - - <=BYE sip:AlarmPoint@localhost
:5060 SIP/2.0
Reason: Q.850;cause=41
Date: Mon, 14 Sep 2009 17:11:04 GMT
From: "Bob Smith" <sip:AlarmPoint@localhost
>;tag=0b9d2f65-507b-4c1e-9c18-af53df588bfa-62905970
User-Agent: Cisco-CUCM6.1
To: "Alarmpoint" <sip:AlarmPoint@localhost
>;tag=f2953763
Call-ID: 93121c80-aae17926-2ed40-1a80d50a@localhost

Via: SIP/2.0/UDP localhost:5060;branch=z9hG4bK305b77596ba1
CSeq: 103 BYE
Max-Forwards: 70
Content-Length: 0

2009-09-14 13:11:31,043 [EventScannerThread] DEBUG - - Looking for participant with dialog: gov.nist.javax.sip.stack.SIPDialog@1e4b2c9
among 1 calls
2009-09-14 13:11:31,043 [EventScannerThread] DEBUG - - Found a participant: com.invoqsystems.apex.component.device.engine.phone.sip.service.call.SipParticipantImpl@19410c

2009-09-14 13:11:31,043 [EventScannerThread] INFO - - A tag was in this dialog already.
2009-09-14 13:11:31,043 [EventScannerThread] DEBUG - - =>SIP/2.0 200 OK
From: "Bob Smith" <sip:AlarmPoint@localhost>;tag=0b9d2f65-507b-4c1e-9c18-af53df588bfa-62905970
To: "Alarmpoint" <sip:AlarmPoint@localhost>;tag=f2953763
Call-ID: 93121c80-aae17926-2ed40-1a80d50a@localhost
Via: SIP/2.0/UDP localhost:5060;branch=z9hG4bK305b77596ba1
CSeq: 103 BYE
User-Agent: Alarmpoint SIP Client 1.0
Content-Length: 0

======= Call killed mid-call =============
2009-09-14 13:11:31,043 [EventScannerThread] DEBUG - - The state for participant "Bob Smith" <sip:AlarmPoint@localhost
> is changed: CONNECTED => DISCONNECTED
2009-09-14 13:11:31,043 [EventScannerThread] DEBUG - - The change state for participant is triggered. ("Bob Smith" <"Bob Smith" <sip:AlarmPoint@localhost
>>:DISCONNECTED)
2009-09-14 13:11:31,043 [RTPEventHandler] DEBUG - - Received RTP send stream event: javax.media.rtp.event.StreamClosedEvent[source = RTPManager
SSRCCache com.sun.media.rtp.SSRCCache@180838c

Dataport 0
Controlport 0
Address
RTPForwarder com.sun.media.rtp.util.PacketForwarder@3c9270

RTPDemux com.sun.media.rtp.RTPDemultiplexer@b232ae
]
2009-09-14 13:11:31,058 [EventScannerThread] DEBUG - - RTP the streams are stopped
2009-09-14 13:11:31,058 [EventScannerThread] DEBUG - - RTP close data socket: /localhost:1,025
2009-09-14 13:11:31,058 [alarmpoint_rtp_read_thread_116] ERROR - - RTP socket read error: socket closed
2009-09-14 13:11:31,058 [EventScannerThread] DEBUG - - RTP close control socket: /localhost:1,026
2009-09-14 13:11:31,058 [alarmpoint_rtcp_read_thread_117] ERROR - - RTP socket read error: socket closed
2009-09-14 13:11:31,058 [EventScannerThread] DEBUG - - All RTP resources allocated are released
2009-09-14 13:11:31,058 [EventScannerThread] DEBUG - - The state for call is changed: PROCESSING => ENDED
2009-09-14 13:11:31,058 [EventScannerThread] DEBUG - - The change state for call is triggered. (daff3192-f881-48d6-809e-cfb22d34c7b8:ENDED)

Potential Solution

The following steps may resolve this issue:

    1. Open the node/assets/resources/spring/integration/deSipContext.xml file in a text editor.
    2. Locate the following text:
<property name="sendCancellationRegistration">  
<value>true</value>  
</property> 

  1. Modify the text to the following:

<property name="sendCancellationRegistration">  
<value>false</value>  
</property>

 

xMatters Reference

SUP-3198, DOC-1938, JDN-1297

Originally created by Don Clark

Have more questions? Submit a request

0 Comments

Please sign in to leave a comment.
Powered by Zendesk