The peer exposing the issue seems to be a pre-REF3261 implementation (no
branch parameter in Via header). Can you also show the invite sent by
the peer?
Cheers,
Daniel
On 23.08.17 16:17, George Diamantopoulos wrote:
A clarification:
The two exchanges-examples I included in the original message are not
from the same peer. The issue is reproducible every time with the
problematic peer (first example). I only included another exchange
from a different peer (so it should read peer2 where I censored IP
addressed) for comparison and to prove a point.
On 23 August 2017 at 17:13, George Diamantopoulos
<georgediam(a)gmail.com <mailto:georgediam@gmail.com>> wrote:
Hello all,
I'm having a weird issue with Kamailio failing to properly process
an ACK received to a 487 it sent, resulting in retransmissions of
the 487. I assume it's because it can't match the ACK to the
transaction, but I could be wrong.
I'm using a modified version of the default configuration, so ACKs
should be handled correctly. I haven't editted the WITHINDLG route
in any way that would affect this (or at least I think).
In addition, ACKs to 487 from other UAs are processed correctly,
and these transactions are handled by the same routes in kamailio
configuration as the problematic one, so I'm inclined to believe
it's UA-specific?
Here's an example transaction of the failed kind (results in
kamailio retransmitting the 487):
myself:5060 -> peer:5060
-------------------------
SIP/2.0 487 Request Terminated
Via: SIP/2.0/UDP peer:5060
From: <sip:user@peer>;tag=116B5368-24D8
To: <sip:tel@myself>;tag=as655f6372
Call-ID: 84DC69F2-873811E7-8A639B5A-3D9194E8@peer
CSeq: 101 INVITE
Server: modCOM v2 SIP Server
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE,
NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Content-Length: 0
peer:49590 -> myself:5060
-------------------------
ACK sip:tel@myself:5060 SIP/2.0
Via: SIP/2.0/UDP peer:5060
From: <sip:user@peer>;tag=116B5368-24D8
To: <sip:tel@myself>;tag=as655f6372
Date: Wed, 23 Aug 2017 12:50:47 GMT
Call-ID: 84DC69F2-873811E7-8A639B5A-3D9194E8@peer
Max-Forwards: 10
Content-Length: 0
CSeq: 101 ACK
And here's another similar transaction which is successful (no
retransmissions):
myself:5060 -> peer:5060
------------------------
SIP/2.0 487 Request Terminated
Via: SIP/2.0/UDP peer:5060;branch=z9hG4bKjbmvq4009gthskk0a6s1.1
From:
<sip:user@anonymous.invalid;user=phone>;tag=599D7495-9ACE9E3-0A324A05
To: <sip:tel@anonymous.invalid:5060;user=phone>;tag=as65375e5d
Call-ID: 599D7495-007A5832@fath3pcu238
CSeq: 1 INVITE
Server: modCOM v2 SIP Server
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE,
NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Content-Length: 0
peer:5060 -> myself:5060
------------------------
ACK sip:tel@myself:5060;user=phone SIP/2.0
Via: SIP/2.0/UDP peer:5060;branch=z9hG4bKjbmvq4009gthskk0a6s1.1
From:
<sip:user@anonymous.invalid;user=phone>;tag=599D7495-9ACE9E3-0A324A05
To: <sip:tel@anonymous.invalid:5060;user=phone>;tag=as65375e5d
Call-ID: 599D7495-007A5832@fath3pcu238
Max-Forwards: 69
Content-Length: 0
CSeq: 1 ACK
I can't pinpoint anything wrong with the first exchange, other
than the fact that for some reason, the "less than" (<) sign in
the from and to URIs is escaped as < in homer's GUI (which also
breaks CSS rendering in Firefox, I had to clear this code out).
However, these escaping characters are not visible with sngrep
when capturing traffic normally, and neither when doing a select
in homer's database directly, so I guess it's a rendering bug in
homer-ui and can be ignored (unless someone has reason to believe
otherwise).
Now the relevant portion of the debug log is:
Aug 23 16:47:12 modcom-sbc-1 kamailio[9750]: {1 101 ACK
64AA4E6C-874011E7-9A729B5A-3D9194E8@peer} 7(9760) exec: ***
cfgtrace:request_route=[WITHINDLG] c=[/etc/kamailio/kamailio.cfg]
l=223 a=24 n=t_check_trans
Aug 23 16:47:12 modcom-sbc-1 kamailio[9750]: {1 101 ACK
64AA4E6C-874011E7-9A729B5A-3D9194E8@peer} 7(9760) DEBUG: tm
[t_lookup.c:1001]: t_check_msg(): msg id=104 global id=103 T
start=(nil)
Aug 23 16:47:12 modcom-sbc-1 kamailio[9750]: {1 101 ACK
64AA4E6C-874011E7-9A729B5A-3D9194E8@peer} 7(9760) DEBUG: tm
[t_lookup.c:459]: t_lookup_request(): start searching: hash=54992,
isACK=1
Aug 23 16:47:12 modcom-sbc-1 kamailio[9750]: {1 101 ACK
64AA4E6C-874011E7-9A729B5A-3D9194E8@peer} 7(9760) DEBUG: tm
[t_lookup.c:494]: t_lookup_request(): proceeding to pre-RFC3261
transaction matching
Aug 23 16:47:12 modcom-sbc-1 kamailio[9750]: {1 101 ACK
64AA4E6C-874011E7-9A729B5A-3D9194E8@peer} 7(9760) DEBUG: tm
[t_lookup.c:641]: t_lookup_request(): no transaction found
Aug 23 16:47:12 modcom-sbc-1 kamailio[9750]: {1 101 ACK
64AA4E6C-874011E7-9A729B5A-3D9194E8@peer} 7(9760) DEBUG: tm
[t_lookup.c:1070]: t_check_msg(): msg id=104 global id=104 T end=(nil)
Aug 23 16:47:12 modcom-sbc-1 kamailio[9750]: {1 101 ACK
64AA4E6C-874011E7-9A729B5A-3D9194E8@peer} 7(9760) exec: ***
cfgtrace:request_route=[WITHINDLG] c=[/etc/kamailio/kamailio.cfg]
l=231 a=2 n=exit
It explicitly states that no transaction is found, after
initiating pre-RFC3261 (why?) transaction matching. However, even
pre-3261 matching should work, as the from and to headers as well
as call-id in request and repy are the same.
Any input would be greatly appreciated, thanks!
George
_______________________________________________
Kamailio (SER) - Users Mailing List
sr-users(a)lists.kamailio.org
https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users