<div dir="ltr"><div>A clarification:<br><br></div>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.<br></div><div class="gmail_extra"><br><div class="gmail_quote">On 23 August 2017 at 17:13, George Diamantopoulos <span dir="ltr"><<a href="mailto:georgediam@gmail.com" target="_blank">georgediam@gmail.com</a>></span> wrote:<br><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><div dir="ltr"><div><div><div><div><div><div><div><div>Hello all,<br><br></div>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.<br><br></div>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).<br><br></div>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?<br><br></div>Here's an example transaction of the failed kind (results in kamailio retransmitting the 487):</div><div><br></div><div>myself:5060 -> peer:5060<br>-------------------------<br>SIP/2.0 487 Request Terminated<br>Via: SIP/2.0/UDP peer:5060 <br>From: <sip:user@peer>;tag=<wbr>116B5368-24D8<br>To: <sip:tel@myself>;tag=<wbr>as655f6372 <br>Call-ID: 84DC69F2-873811E7-8A639B5A-<wbr>3D9194E8@peer<br>CSeq: 101 INVITE <br>Server: modCOM v2 SIP Server <br>Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE <br>Supported: replaces, timer <br>Content-Length: 0<br><br>peer:49590 -> myself:5060<br>-------------------------<br>ACK sip:tel@myself:5060 SIP/2.0<br>Via: SIP/2.0/UDP peer:5060<br>From: <sip:user@peer>;tag=<wbr>116B5368-24D8<br>To: <sip:tel@myself>;tag=<wbr>as655f6372<br>Date: Wed, 23 Aug 2017 12:50:47 GMT<br>Call-ID: 84DC69F2-873811E7-8A639B5A-<wbr>3D9194E8@peer<br>Max-Forwards: 10<br>Content-Length: 0<br>CSeq: 101 ACK<br><br></div>And here's another similar transaction which is successful (no retransmissions):<br><br>myself:5060 -> peer:5060<br>------------------------<br>SIP/2.0 487 Request Terminated<br>Via: SIP/2.0/UDP peer:5060;branch=<wbr>z9hG4bKjbmvq4009gthskk0a6s1.1<br>From: <sip:user@anonymous.invalid;<wbr>user=phone>;tag=599D7495-<wbr>9ACE9E3-0A324A05<br>To: <sip:tel@anonymous.invalid:<wbr>5060;user=phone>;tag=<wbr>as65375e5d<br>Call-ID: 599D7495-007A5832@fath3pcu238<br>CSeq: 1 INVITE<br>Server: modCOM v2 SIP Server<br>Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE<br>Supported: replaces, timer<br>Content-Length: 0<br><br><br>peer:5060 -> myself:5060<br>------------------------<br>ACK sip:tel@myself:5060;user=phone SIP/2.0<br>Via: SIP/2.0/UDP peer:5060;branch=<wbr>z9hG4bKjbmvq4009gthskk0a6s1.1<br>From: <sip:user@anonymous.invalid;<wbr>user=phone>;tag=599D7495-<wbr>9ACE9E3-0A324A05<br>To: <sip:tel@anonymous.invalid:<wbr>5060;user=phone>;tag=<wbr>as65375e5d<br><br>Call-ID: 599D7495-007A5832@fath3pcu238<br>Max-Forwards: 69<br>Content-Length: 0<br>CSeq: 1 ACK<br><br></div>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).<br></div><div><br></div><div>Now the relevant portion of the debug log is:</div><div><br></div><div>Aug 23 16:47:12 modcom-sbc-1 kamailio[9750]: {1 101 ACK 64AA4E6C-874011E7-9A729B5A-<wbr>3D9194E8@peer} 7(9760) exec: *** cfgtrace:request_route=[<wbr>WITHINDLG] c=[/etc/kamailio/kamailio.cfg] l=223 a=24 n=t_check_trans<br>Aug 23 16:47:12 modcom-sbc-1 kamailio[9750]: {1 101 ACK 64AA4E6C-874011E7-9A729B5A-<wbr>3D9194E8@peer} 7(9760) DEBUG: tm [t_lookup.c:1001]: t_check_msg(): msg id=104 global id=103 T start=(nil)<br>Aug 23 16:47:12 modcom-sbc-1 kamailio[9750]: {1 101 ACK 64AA4E6C-874011E7-9A729B5A-<wbr>3D9194E8@peer} 7(9760) DEBUG: tm [t_lookup.c:459]: t_lookup_request(): start searching: hash=54992, isACK=1<br>Aug 23 16:47:12 modcom-sbc-1 kamailio[9750]: {1 101 ACK 64AA4E6C-874011E7-9A729B5A-<wbr>3D9194E8@peer} 7(9760) DEBUG: tm [t_lookup.c:494]: t_lookup_request(): proceeding to pre-RFC3261 transaction matching<br>Aug 23 16:47:12 modcom-sbc-1 kamailio[9750]: {1 101 ACK 64AA4E6C-874011E7-9A729B5A-<wbr>3D9194E8@peer} 7(9760) DEBUG: tm [t_lookup.c:641]: t_lookup_request(): no transaction found<br>Aug 23 16:47:12 modcom-sbc-1 kamailio[9750]: {1 101 ACK 64AA4E6C-874011E7-9A729B5A-<wbr>3D9194E8@peer} 7(9760) DEBUG: tm [t_lookup.c:1070]: t_check_msg(): msg id=104 global id=104 T end=(nil)<br>Aug 23 16:47:12 modcom-sbc-1 kamailio[9750]: {1 101 ACK 64AA4E6C-874011E7-9A729B5A-<wbr>3D9194E8@peer} 7(9760) exec: *** cfgtrace:request_route=[<wbr>WITHINDLG] c=[/etc/kamailio/kamailio.cfg] l=231 a=2 n=exit<br></div><div><br></div>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.<br></div><div><div><br>Any input would be greatly appreciated, thanks!</div><span class="HOEnZb"><font color="#888888"><div>George<br></div></font></span></div></div>
</blockquote></div><br></div>