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 <georged...@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@lists.kamailio.org https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users