search

igorb3st / sipservlets

sipservlets
1 stars 0 forks source link

Container doesn't send send ACK to 487 #190

Closed GoogleCodeExporter closed 8 years ago

GoogleCodeExporter commented 8 years ago 
When the container receives a 487 response after canceling an INVITE it does 
not generate an ACK for the 487 response.

Original issue reported on code.google.com by quintana...@gmail.com on 22 Jan 2013 at 9:13

GoogleCodeExporter commented 8 years ago 
Log entries for a test call. Using Tomcat and log level set to FINEST

2013-01-22 15:25:57,186 INFO  [CallDownOneShotResource] (http-8080-1) A call 
back for a call with ID CA430c63259abd45b292170109a15b002e is being sent to 
null the contents are enclosed below.
{"Resident":false,"ExternalID":"6675647064140959745","ResponderPhoneNumber":"954
9376176","QuestionNumber":0,"TypeOfResponse":900,"LibraryName":"HealthSense","Sc
riptName":"CallDownOneShot"}
2013-01-22 15:25:57,187 INFO  [CallDownOneShotResource] (http-8080-1) Starting 
a new call from +19524007201 To +19549376176. The application located @ 
http://10.0.6.73:8080/translator/scripts/call-down-one-shot/translator will be 
executed during this call.Finally, all callbacks will be made to 
http://10.0.6.73:8080/translator/scripts/call-down-one-shot/responder-call-clean
up
2013-01-22 15:25:57,455 INFO  [TranslatorResource] (http-8080-1) RCML Response 
for call with ID CA430c63259abd45b292170109a15b002e.
<Response><Gather numDigits="2" finishOnKey="1" 
action="input-accept?Attempts=1" timeout="30"><Say><![CDATA[<voice 
gender="male"><prosody rate="default">Pull Cord of Room 207 in room 2 0 7  is 
requesting assistance. Pull Cord of Room 207 in room 2 0 7  is requesting 
assistance. Pull Cord of Room 207 in room 2 0 7  is requesting assistance. 
</prosody></voice>]]></Say><Say><![CDATA[<voice gender="male"><prosody 
rate="default">Please enter your access code followed by the pound key. 
</prosody></voice>]]></Say></Gather><Redirect>translator?Attempts=1</Redirect></
Response>
2013-01-22 15:25:57,844 INFO  [SIPTransactionStack] (pool-4-thread-1) <message
from="10.0.6.73:5080" 
to="68.68.118.47:5060" 
time="1358889957838"
isSender="true" 
transactionId="z9hg4bk7e385d13-7774-46a4-9c74-36a412278334_57a5b08a_134175660328
12529" 
callId="46f1ad6e3ab61ac204d4011d80bb556b@10.0.6.73" 
firstLine="INVITE sip:+19549376176@68.68.118.47 SIP/2.0" 
>
<![CDATA[INVITE sip:+19549376176@68.68.118.47 SIP/2.0
Call-ID: 46f1ad6e3ab61ac204d4011d80bb556b@10.0.6.73
CSeq: 1 INVITE
From: 
<sip:+19524007201@68.68.118.47>;tag=14659765_57a5b08a_7e385d13-7774-46a4-9c74-36
a412278334
To: <sip:+19549376176@68.68.118.47>
Max-Forwards: 70
Contact: <sip:+19524007201@10.0.6.73:5080>
Route: <sip:68.68.118.47;lr>
Content-Type: application/sdp
Via: SIP/2.0/UDP 
10.0.6.73:5080;branch=z9hG4bK7e385d13-7774-46a4-9c74-36a412278334_57a5b08a_13417
566032812529
Content-Length: 248

v=0
o=- 1358889957540 1 IN IP4 10.0.6.73
s=Mobicents Media Server
c=IN IP4 10.0.6.73
t=0 0
m=audio 63666 RTP/AVP 97 8 0 101
a=rtpmap:97 l16/8000
a=rtpmap:8 pcma/8000
a=rtpmap:0 pcmu/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
]]>
</message>

2013-01-22 15:25:57,876 INFO  [SIPTransactionStack] 
(Mobicents-SIP-Servlets-UDPMessageChannelThread-0) <message
from="68.68.118.47:5060" 
to="10.0.6.73:5080" 
time="1358889957875"
isSender="false" 
transactionId="z9hg4bk7e385d13-7774-46a4-9c74-36a412278334_57a5b08a_134175660328
12529" 
callId="46f1ad6e3ab61ac204d4011d80bb556b@10.0.6.73" 
firstLine="SIP/2.0 100 Trying" 
>
<![CDATA[SIP/2.0 100 Trying
Via: SIP/2.0/UDP 
10.0.6.73:5080;branch=z9hG4bK7e385d13-7774-46a4-9c74-36a412278334_57a5b08a_13417
566032812529
From: 
<sip:+19524007201@68.68.118.47>;tag=14659765_57a5b08a_7e385d13-7774-46a4-9c74-36
a412278334
To: <sip:+19549376176@68.68.118.47>;tag=gK04812019
Call-ID: 46f1ad6e3ab61ac204d4011d80bb556b@10.0.6.73
CSeq: 1 INVITE
Content-Length: 0

]]>
</message>

2013-01-22 15:26:00,023 INFO  [ResourceResolverBean] (scheduler_Worker-8) 
Reading CONTEXT /translator
2013-01-22 15:26:00,024 INFO  [ResourceResolverBean] (scheduler_Worker-8) 
Reading CONTEXT 
2013-01-22 15:26:00,024 INFO  [ResourceResolverBean] (scheduler_Worker-8) 
Reading CONTEXT /manager
2013-01-22 15:26:00,025 INFO  [ResourceResolverBean] (scheduler_Worker-8) 
Reading CONTEXT /sip-servlets-management
2013-01-22 15:26:00,025 INFO  [ResourceResolverBean] (scheduler_Worker-8) 
Reading CONTEXT /docs
2013-01-22 15:26:00,025 INFO  [ResourceResolverBean] (scheduler_Worker-8) 
Reading CONTEXT /examples
2013-01-22 15:26:00,025 INFO  [ResourceResolverBean] (scheduler_Worker-8) 
Reading CONTEXT /host-manager
2013-01-22 15:26:00,025 INFO  [ResourceResolverBean] (scheduler_Worker-8) 
Reading CONTEXT /probe
2013-01-22 15:26:00,025 INFO  [ResourceResolverBean] (scheduler_Worker-8) 
Reading CONTEXT /click2call
2013-01-22 15:26:00,025 INFO  [ResourceResolverBean] (scheduler_Worker-8) 
Reading CONTEXT /mobicentsreply
2013-01-22 15:26:00,025 INFO  [ResourceResolverBean] (scheduler_Worker-8) 
Reading CONTEXT /restcomm
2013-01-22 15:26:00,026 INFO  [ResourceResolverBean] (scheduler_Worker-8) 
Reading GLOBAL resources
2013-01-22 15:26:00,039 INFO  [ResourceResolverBean] (scheduler_Worker-8) 
reading resource: 
Catalina:type=Resource,resourcetype=Global,class=org.apache.catalina.UserDatabas
e,name="UserDatabase"
2013-01-22 15:26:00,485 INFO  [SIPTransactionStack] 
(Mobicents-SIP-Servlets-UDPMessageChannelThread-1) <message
from="68.68.118.47:5060" 
to="10.0.6.73:5080" 
time="1358889960484"
isSender="false" 
transactionId="z9hg4bk7e385d13-7774-46a4-9c74-36a412278334_57a5b08a_134175660328
12529" 
callId="46f1ad6e3ab61ac204d4011d80bb556b@10.0.6.73" 
firstLine="SIP/2.0 183 Session Progress" 
>
<![CDATA[SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP 
10.0.6.73:5080;branch=z9hG4bK7e385d13-7774-46a4-9c74-36a412278334_57a5b08a_13417
566032812529
From: 
<sip:+19524007201@68.68.118.47>;tag=14659765_57a5b08a_7e385d13-7774-46a4-9c74-36
a412278334
To: <sip:+19549376176@68.68.118.47>;tag=gK04812019
Call-ID: 46f1ad6e3ab61ac204d4011d80bb556b@10.0.6.73
CSeq: 1 INVITE
Contact: <sip:+19549376176@68.68.118.47:5060>
Allow: INVITE,ACK,CANCEL,BYE,PRACK,UPDATE,OPTIONS,MESSAGE,PUBLISH
Content-Disposition: session;handling=required
Content-Type: application/sdp
Content-Length: 231

v=0
o=Sonus_UAC 8153 2713 IN IP4 68.68.118.47
s=SIP Media Capabilities
c=IN IP4 68.68.118.43
t=0 0
m=audio 28918 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendrecv
a=ptime:20
]]>
</message>

2013-01-22 15:26:00,508 INFO  [ResponderCallCleanupResource] (http-8080-3) 
Responder call with ID CA430c63259abd45b292170109a15b002e ended with the 
following status ringing.
2013-01-22 15:26:00,510 INFO  [ResponderCallCleanupResource] (http-8080-3) A 
call back for a call with ID CA430c63259abd45b292170109a15b002e is being sent 
to null the contents are enclosed below.
{"Resident":false,"ExternalID":"6675647064140959745","ResponderPhoneNumber":"954
9376176","QuestionNumber":0,"TypeOfResponse":901,"LibraryName":"HealthSense","Sc
riptName":"CallDownOneShot"}
2013-01-22 15:26:10,516 INFO  [SIPTransactionStack] (pool-4-thread-1) <message
from="10.0.6.73:5080" 
to="68.68.118.47:5060" 
time="1358889970515"
isSender="true" 
transactionId="z9hg4bk7e385d13-7774-46a4-9c74-36a412278334_57a5b08a_134175660328
12529:cancel" 
callId="46f1ad6e3ab61ac204d4011d80bb556b@10.0.6.73" 
firstLine="CANCEL sip:+19549376176@68.68.118.47 SIP/2.0" 
>
<![CDATA[CANCEL sip:+19549376176@68.68.118.47 SIP/2.0
Call-ID: 46f1ad6e3ab61ac204d4011d80bb556b@10.0.6.73
To: <sip:+19549376176@68.68.118.47>
CSeq: 1 CANCEL
From: 
<sip:+19524007201@68.68.118.47>;tag=14659765_57a5b08a_7e385d13-7774-46a4-9c74-36
a412278334
Via: SIP/2.0/UDP 
10.0.6.73:5080;branch=z9hG4bK7e385d13-7774-46a4-9c74-36a412278334_57a5b08a_13417
566032812529
Max-Forwards: 70
Route: <sip:68.68.118.47;lr>
Content-Length: 0

]]>
</message>

2013-01-22 15:26:10,520 INFO  [SipSessionImpl] (pool-4-thread-1) Invalidating 
the sip session 
(14659765_57a5b08a_7e385d13-7774-46a4-9c74-36a412278334:46f1ad6e3ab61ac204d4011d
80bb556b@10.0.6.73:7e385d13-7774-46a4-9c74-36a412278334:RestComm)
2013-01-22 15:26:10,542 INFO  [ResponderCallCleanupResource] (http-8080-4) 
Responder call with ID CA430c63259abd45b292170109a15b002e ended with the 
following status cancelled.
2013-01-22 15:26:10,544 INFO  [ResponderCallCleanupResource] (http-8080-4) A 
call back for a call with ID CA430c63259abd45b292170109a15b002e is being sent 
to null the contents are enclosed below.
{"Resident":false,"ExternalID":"6675647064140959745","ResponderPhoneNumber":"954
9376176","QuestionNumber":0,"TypeOfResponse":0,"LibraryName":"HealthSense","Scri
ptName":"CallDownOneShot"}
2013-01-22 15:26:10,549 INFO  [SIPTransactionStack] 
(Mobicents-SIP-Servlets-UDPMessageChannelThread-2) <message
from="68.68.118.47:5060" 
to="10.0.6.73:5080" 
time="1358889970549"
isSender="false" 
transactionId="z9hg4bk7e385d13-7774-46a4-9c74-36a412278334_57a5b08a_134175660328
12529:cancel" 
callId="46f1ad6e3ab61ac204d4011d80bb556b@10.0.6.73" 
firstLine="SIP/2.0 200 OK" 
>
<![CDATA[SIP/2.0 200 OK
Via: SIP/2.0/UDP 
10.0.6.73:5080;branch=z9hG4bK7e385d13-7774-46a4-9c74-36a412278334_57a5b08a_13417
566032812529
From: 
<sip:+19524007201@68.68.118.47>;tag=14659765_57a5b08a_7e385d13-7774-46a4-9c74-36
a412278334
To: <sip:+19549376176@68.68.118.47>;tag=gK04812019
Call-ID: 46f1ad6e3ab61ac204d4011d80bb556b@10.0.6.73
CSeq: 1 CANCEL
Content-Length: 0

]]>
</message>

2013-01-22 15:26:10,551 INFO  [SIPTransactionStack] 
(Mobicents-SIP-Servlets-UDPMessageChannelThread-2) <message
from="68.68.118.47:5060" 
to="10.0.6.73:5080" 
time="1358889970551"
isSender="false" 
transactionId="z9hg4bk7e385d13-7774-46a4-9c74-36a412278334_57a5b08a_134175660328
12529" 
callId="46f1ad6e3ab61ac204d4011d80bb556b@10.0.6.73" 
firstLine="SIP/2.0 487 Request Terminated" 
>
<![CDATA[SIP/2.0 487 Request Terminated
Via: SIP/2.0/UDP 
10.0.6.73:5080;branch=z9hG4bK7e385d13-7774-46a4-9c74-36a412278334_57a5b08a_13417
566032812529
From: 
<sip:+19524007201@68.68.118.47>;tag=14659765_57a5b08a_7e385d13-7774-46a4-9c74-36
a412278334
To: <sip:+19549376176@68.68.118.47>;tag=gK04812019
Call-ID: 46f1ad6e3ab61ac204d4011d80bb556b@10.0.6.73
CSeq: 1 INVITE
Content-Length: 0

]]>
</message>

2013-01-22 15:26:11,044 INFO  [SIPTransactionStack] 
(Mobicents-SIP-Servlets-UDPMessageChannelThread-4) <message
from="68.68.118.47:5060" 
to="10.0.6.73:5080" 
time="1358889971043"
isSender="false" 
transactionId="z9hg4bk7e385d13-7774-46a4-9c74-36a412278334_57a5b08a_134175660328
12529" 
callId="46f1ad6e3ab61ac204d4011d80bb556b@10.0.6.73" 
firstLine="SIP/2.0 487 Request Terminated" 
>
<![CDATA[SIP/2.0 487 Request Terminated
Via: SIP/2.0/UDP 
10.0.6.73:5080;branch=z9hG4bK7e385d13-7774-46a4-9c74-36a412278334_57a5b08a_13417
566032812529
From: 
<sip:+19524007201@68.68.118.47>;tag=14659765_57a5b08a_7e385d13-7774-46a4-9c74-36
a412278334
To: <sip:+19549376176@68.68.118.47>;tag=gK04812019
Call-ID: 46f1ad6e3ab61ac204d4011d80bb556b@10.0.6.73
CSeq: 1 INVITE
Content-Length: 0

]]>
</message>

2013-01-22 15:26:12,045 INFO  [SIPTransactionStack] 
(Mobicents-SIP-Servlets-UDPMessageChannelThread-5) <message
from="68.68.118.47:5060" 
to="10.0.6.73:5080" 
time="1358889972043"
isSender="false" 
transactionId="z9hg4bk7e385d13-7774-46a4-9c74-36a412278334_57a5b08a_134175660328
12529" 
callId="46f1ad6e3ab61ac204d4011d80bb556b@10.0.6.73" 
firstLine="SIP/2.0 487 Request Terminated" 
>
<![CDATA[SIP/2.0 487 Request Terminated
Via: SIP/2.0/UDP 
10.0.6.73:5080;branch=z9hG4bK7e385d13-7774-46a4-9c74-36a412278334_57a5b08a_13417
566032812529
From: 
<sip:+19524007201@68.68.118.47>;tag=14659765_57a5b08a_7e385d13-7774-46a4-9c74-36
a412278334
To: <sip:+19549376176@68.68.118.47>;tag=gK04812019
Call-ID: 46f1ad6e3ab61ac204d4011d80bb556b@10.0.6.73
CSeq: 1 INVITE
Content-Length: 0

]]>
</message>

2013-01-22 15:26:14,044 INFO  [SIPTransactionStack] 
(Mobicents-SIP-Servlets-UDPMessageChannelThread-6) <message
from="68.68.118.47:5060" 
to="10.0.6.73:5080" 
time="1358889974043"
isSender="false" 
transactionId="z9hg4bk7e385d13-7774-46a4-9c74-36a412278334_57a5b08a_134175660328
12529" 
callId="46f1ad6e3ab61ac204d4011d80bb556b@10.0.6.73" 
firstLine="SIP/2.0 487 Request Terminated" 
>
<![CDATA[SIP/2.0 487 Request Terminated
Via: SIP/2.0/UDP 
10.0.6.73:5080;branch=z9hG4bK7e385d13-7774-46a4-9c74-36a412278334_57a5b08a_13417
566032812529
From: 
<sip:+19524007201@68.68.118.47>;tag=14659765_57a5b08a_7e385d13-7774-46a4-9c74-36
a412278334
To: <sip:+19549376176@68.68.118.47>;tag=gK04812019
Call-ID: 46f1ad6e3ab61ac204d4011d80bb556b@10.0.6.73
CSeq: 1 INVITE
Content-Length: 0

]]>
</message>

2013-01-22 15:26:18,044 INFO  [SIPTransactionStack] 
(Mobicents-SIP-Servlets-UDPMessageChannelThread-7) <message
from="68.68.118.47:5060" 
to="10.0.6.73:5080" 
time="1358889978044"
isSender="false" 
transactionId="z9hg4bk7e385d13-7774-46a4-9c74-36a412278334_57a5b08a_134175660328
12529" 
callId="46f1ad6e3ab61ac204d4011d80bb556b@10.0.6.73" 
firstLine="SIP/2.0 487 Request Terminated" 
>
<![CDATA[SIP/2.0 487 Request Terminated
Via: SIP/2.0/UDP 
10.0.6.73:5080;branch=z9hG4bK7e385d13-7774-46a4-9c74-36a412278334_57a5b08a_13417
566032812529
From: 
<sip:+19524007201@68.68.118.47>;tag=14659765_57a5b08a_7e385d13-7774-46a4-9c74-36
a412278334
To: <sip:+19549376176@68.68.118.47>;tag=gK04812019
Call-ID: 46f1ad6e3ab61ac204d4011d80bb556b@10.0.6.73
CSeq: 1 INVITE
Content-Length: 0

]]>
</message>

2013-01-22 15:26:22,044 INFO  [SIPTransactionStack] 
(Mobicents-SIP-Servlets-UDPMessageChannelThread-8) <message
from="68.68.118.47:5060" 
to="10.0.6.73:5080" 
time="1358889982044"
isSender="false" 
transactionId="z9hg4bk7e385d13-7774-46a4-9c74-36a412278334_57a5b08a_134175660328
12529" 
callId="46f1ad6e3ab61ac204d4011d80bb556b@10.0.6.73" 
firstLine="SIP/2.0 487 Request Terminated" 
>
<![CDATA[SIP/2.0 487 Request Terminated
Via: SIP/2.0/UDP 
10.0.6.73:5080;branch=z9hG4bK7e385d13-7774-46a4-9c74-36a412278334_57a5b08a_13417
566032812529
From: 
<sip:+19524007201@68.68.118.47>;tag=14659765_57a5b08a_7e385d13-7774-46a4-9c74-36
a412278334
To: <sip:+19549376176@68.68.118.47>;tag=gK04812019
Call-ID: 46f1ad6e3ab61ac204d4011d80bb556b@10.0.6.73
CSeq: 1 INVITE
Content-Length: 0

]]>
</message>

2013-01-22 15:26:26,047 INFO  [SIPTransactionStack] 
(Mobicents-SIP-Servlets-UDPMessageChannelThread-9) <message
from="68.68.118.47:5060" 
to="10.0.6.73:5080" 
time="1358889986047"
isSender="false" 
transactionId="z9hg4bk7e385d13-7774-46a4-9c74-36a412278334_57a5b08a_134175660328
12529" 
callId="46f1ad6e3ab61ac204d4011d80bb556b@10.0.6.73" 
firstLine="SIP/2.0 487 Request Terminated" 
>
<![CDATA[SIP/2.0 487 Request Terminated
Via: SIP/2.0/UDP 
10.0.6.73:5080;branch=z9hG4bK7e385d13-7774-46a4-9c74-36a412278334_57a5b08a_13417
566032812529
From: 
<sip:+19524007201@68.68.118.47>;tag=14659765_57a5b08a_7e385d13-7774-46a4-9c74-36
a412278334
To: <sip:+19549376176@68.68.118.47>;tag=gK04812019
Call-ID: 46f1ad6e3ab61ac204d4011d80bb556b@10.0.6.73
CSeq: 1 INVITE
Content-Length: 0

]]>
</message>

2013-01-22 15:26:30,044 INFO  [SIPTransactionStack] 
(Mobicents-SIP-Servlets-UDPMessageChannelThread-10) <message
from="68.68.118.47:5060" 
to="10.0.6.73:5080" 
time="1358889990043"
isSender="false" 
transactionId="z9hg4bk7e385d13-7774-46a4-9c74-36a412278334_57a5b08a_134175660328
12529" 
callId="46f1ad6e3ab61ac204d4011d80bb556b@10.0.6.73" 
firstLine="SIP/2.0 487 Request Terminated" 
>
<![CDATA[SIP/2.0 487 Request Terminated
Via: SIP/2.0/UDP 
10.0.6.73:5080;branch=z9hG4bK7e385d13-7774-46a4-9c74-36a412278334_57a5b08a_13417
566032812529
From: 
<sip:+19524007201@68.68.118.47>;tag=14659765_57a5b08a_7e385d13-7774-46a4-9c74-36
a412278334
To: <sip:+19549376176@68.68.118.47>;tag=gK04812019
Call-ID: 46f1ad6e3ab61ac204d4011d80bb556b@10.0.6.73
CSeq: 1 INVITE
Content-Length: 0

]]>
</message>

Original comment by quintana...@gmail.com on 22 Jan 2013 at 9:27

GoogleCodeExporter commented 8 years ago

Original comment by jean.deruelle on 17 Dec 2014 at 9:16