Re: [SR-Users] Kamailio relays ACK of 200 OK to itself

Hi all! I can't make my Kamailio to correctly relay stateful ACKs for 200 OK. It takes URI from Route: header and trying relay it to itself instead of sending it to host sent 200 OK. I don't understand why it can't match transaction and relay to correct host. Seems BYEs aren't relayed correctly either... 192.168.4.218 -> NAT 1.2.2.94 -> Kamailo (1.2.3.46, 1.2.2.219) -> 172.19.126.105 192.168.4.218 sends INVITE to 1.2.3.45 which relays it to 172.19.126.105. After 172.19.126.105 answers with 200 OK, it never gets ACK for it back. Instead, ACK relayed by proxy to 1.2.3.46 (one of proxy addresses). Example of original ACK: ACK sip:89211234567@172.19.126.105:5060 SIP/2.0. Via: SIP/2.0/UDP 192.168.4.218:5062;branch=z9hG4bK1161188624. Route: <sip:1.2.3.46;lr=on;ftag=259196205;nat=yes>. From: "0099977" <sip:0099977@1.2.3.46>;tag=259196205. To: <sip:89211234567@1.2.3.46>;tag=as6bfd1fa1. Call-ID: 910089142(a)192.168.4.218. CSeq: 2 ACK. Contact: <sip:0099977@192.168.4.218:5062>. Max-Forwards: 70. User-Agent: Yealink SIP-T46G 28.71.14.4. Content-Length: 0. It sees that host is not local: check_self: host != me I think the problem is somewhere in my NAT handling script code, but seems I'm stuck and can't get what am I doing wrong, so I'll greatly appreciate any help. Apr 16 19:21:33 kam-sbc-1-01 /usr/sbin/kamailio[9178]: DEBUG: <core> [parser/msg_parser.c:170]: get_hdr_field(): get_hdr_field: cseq <CSeq>: <2> <ACK> Apr 16 19:21:33 kam-sbc-1-01 /usr/sbin/kamailio[9178]: DEBUG: maxfwd [mf_funcs.c:85]: is_maxfwd_present(): value = 70 Apr 16 19:21:33 kam-sbc-1-01 /usr/sbin/kamailio[9178]: DEBUG: <core> [parser/msg_parser.c:204]: get_hdr_field(): DEBUG: get_hdr_body : content_length=0 Apr 16 19:21:33 kam-sbc-1-01 /usr/sbin/kamailio[9178]: DEBUG: <core> [parser/msg_parser.c:106]: get_hdr_field(): found end of header Apr 16 19:21:33 kam-sbc-1-01 /usr/sbin/kamailio[9178]: DEBUG: sanity [mod_sanity.c:255]: w_sanity_check(): sanity checks result: 1 Apr 16 19:21:33 kam-sbc-1-01 /usr/sbin/kamailio[9178]: INFO: <script>: Nat detected Apr 16 19:21:33 kam-sbc-1-01 /usr/sbin/kamailio[9178]: DEBUG: siputils [sipops.c:161]: w_is_first_hop(): no 2nd via found - first hop Apr 16 19:21:33 kam-sbc-1-01 /usr/sbin/kamailio[9178]: INFO: <script>: Set contact alias Apr 16 19:21:33 kam-sbc-1-01 /usr/sbin/kamailio[9178]: DEBUG: <core> [dset.c:774]: uri_add_rcv_alias(): encoded <sip:0099977@192.168.4.218:5062> => [sip:0099977@192.168.4.218:5062;alias =1.2.2.94~58542~1] Apr 16 19:21:33 kam-sbc-1-01 /usr/sbin/kamailio[9178]: DEBUG: siputils [checks.c:106]: has_totag(): totag found Apr 16 19:21:33 kam-sbc-1-01 /usr/sbin/kamailio[9178]: INFO: <script>: Request in dialog Apr 16 19:21:33 kam-sbc-1-01 /usr/sbin/kamailio[9178]: DEBUG: rr [loose.c:90]: is_preloaded(): is_preloaded: No Apr 16 19:21:33 kam-sbc-1-01 /usr/sbin/kamailio[9178]: DEBUG: <core> [socket_info.c:583]: grep_sock_info(): grep_sock_info - checking if host==us: 14==9 && [172.19.126.105] == [127.0.0. 1] Apr 16 19:21:33 kam-sbc-1-01 /usr/sbin/kamailio[9178]: DEBUG: <core> [socket_info.c:587]: grep_sock_info(): grep_sock_info - checking if port 5060 (advertise 0) matches port 5060 Apr 16 19:21:33 kam-sbc-1-01 /usr/sbin/kamailio[9178]: DEBUG: <core> [socket_info.c:583]: grep_sock_info(): grep_sock_info - checking if host==us: 14==12 && [172.19.126.105] == [1.2. 2.219] Apr 16 19:21:33 kam-sbc-1-01 /usr/sbin/kamailio[9178]: DEBUG: <core> [socket_info.c:587]: grep_sock_info(): grep_sock_info - checking if port 5060 (advertise 0) matches port 5060 Apr 16 19:21:33 kam-sbc-1-01 /usr/sbin/kamailio[9178]: DEBUG: <core> [socket_info.c:583]: grep_sock_info(): grep_sock_info - checking if host==us: 14==11 && [172.19.126.105] == [1.2. 3.46] Apr 16 19:21:33 kam-sbc-1-01 /usr/sbin/kamailio[9178]: DEBUG: <core> [socket_info.c:587]: grep_sock_info(): grep_sock_info - checking if port 5060 (advertise 0) matches port 5060 Apr 16 19:21:33 kam-sbc-1-01 /usr/sbin/kamailio[9178]: DEBUG: <core> [socket_info.c:583]: grep_sock_info(): grep_sock_info - checking if host==us: 14==9 && [172.19.126.105] == [127.0.0. 1] Apr 16 19:21:33 kam-sbc-1-01 /usr/sbin/kamailio[9178]: DEBUG: <core> [socket_info.c:587]: grep_sock_info(): grep_sock_info - checking if port 5060 (advertise 0) matches port 5060 Apr 16 19:21:33 kam-sbc-1-01 /usr/sbin/kamailio[9178]: DEBUG: <core> [socket_info.c:583]: grep_sock_info(): grep_sock_info - checking if host==us: 14==12 && [172.19.126.105] == [1.2. 2.219] Apr 16 19:21:33 kam-sbc-1-01 /usr/sbin/kamailio[9178]: DEBUG: <core> [socket_info.c:587]: grep_sock_info(): grep_sock_info - checking if port 5060 (advertise 0) matches port 5060 Apr 16 19:21:33 kam-sbc-1-01 /usr/sbin/kamailio[9178]: DEBUG: <core> [socket_info.c:583]: grep_sock_info(): grep_sock_info - checking if host==us: 14==11 && [172.19.126.105] == [1.2. 3.46] Apr 16 19:21:33 kam-sbc-1-01 /usr/sbin/kamailio[9178]: DEBUG: <core> [socket_info.c:587]: grep_sock_info(): grep_sock_info - checking if port 5060 (advertise 0) matches port 5060 Apr 16 19:21:33 kam-sbc-1-01 /usr/sbin/kamailio[9178]: DEBUG: <core> [forward.c:448]: check_self(): check_self: host != me Apr 16 19:21:33 kam-sbc-1-01 /usr/sbin/kamailio[9178]: DEBUG: rr [loose.c:674]: after_strict(): Next hop: 'sip:1.2.3.46;lr=on;ftag=259196205;nat=yes' is loose router Apr 16 19:21:33 kam-sbc-1-01 /usr/sbin/kamailio[9178]: DEBUG: rr [loose.c:724]: after_strict(): The last route URI: 'sip:1.2.3.46;lr=on;ftag=259196205;nat=yes' Apr 16 19:21:33 kam-sbc-1-01 /usr/sbin/kamailio[9178]: DEBUG: outbound [ob_mod.c:496]: use_outbound(): Analysing ACK for outbound markers Apr 16 19:21:33 kam-sbc-1-01 /usr/sbin/kamailio[9178]: DEBUG: <core> [socket_info.c:583]: grep_sock_info(): grep_sock_info - checking if host==us: 11==9 && [1.2.3.46] == [127.0.0.1] Apr 16 19:21:33 kam-sbc-1-01 /usr/sbin/kamailio[9178]: DEBUG: <core> [socket_info.c:587]: grep_sock_info(): grep_sock_info - checking if port 5060 (advertise 0) matches port 5060 Apr 16 19:21:33 kam-sbc-1-01 /usr/sbin/kamailio[9178]: DEBUG: <core> [socket_info.c:583]: grep_sock_info(): grep_sock_info - checking if host==us: 11==12 && [1.2.3.46] == [1.2.2.2 19] Apr 16 19:21:33 kam-sbc-1-01 /usr/sbin/kamailio[9178]: DEBUG: <core> [socket_info.c:587]: grep_sock_info(): grep_sock_info - checking if port 5060 (advertise 0) matches port 5060 Apr 16 19:21:33 kam-sbc-1-01 /usr/sbin/kamailio[9178]: DEBUG: <core> [socket_info.c:583]: grep_sock_info(): grep_sock_info - checking if host==us: 11==11 && [1.2.3.46] == [1.2.3.4 6] Apr 16 19:21:33 kam-sbc-1-01 /usr/sbin/kamailio[9178]: DEBUG: <core> [socket_info.c:587]: grep_sock_info(): grep_sock_info - checking if port 5060 (advertise 0) matches port 5060 Apr 16 19:21:33 kam-sbc-1-01 /usr/sbin/kamailio[9178]: DEBUG: outbound [ob_mod.c:466]: use_outbound_non_reg(): outbound not used Apr 16 19:21:33 kam-sbc-1-01 /usr/sbin/kamailio[9178]: DEBUG: siputils [checks.c:106]: has_totag(): totag found Apr 16 19:21:33 kam-sbc-1-01 /usr/sbin/kamailio[9178]: DEBUG: siputils [checks.c:106]: has_totag(): totag found Apr 16 19:21:33 kam-sbc-1-01 /usr/sbin/kamailio[9178]: NOTICE: <script>: REL: ACK sip:1.2.3.46;lr=on;ftag=259196205;nat=yes -> sip:1.2.3.46;lr=on;ftag=259196205;nat=yes Apr 16 19:21:33 kam-sbc-1-01 /usr/sbin/kamailio[9178]: DEBUG: tm [t_lookup.c:1373]: t_newtran(): DEBUG: t_newtran: msg id=59 , global msg id=58 , T on entrance=0xffffffff Apr 16 19:21:33 kam-sbc-1-01 /usr/sbin/kamailio[9178]: DEBUG: tm [t_lookup.c:527]: t_lookup_request(): t_lookup_request: start searching: hash=37956, isACK=1 Apr 16 19:21:33 kam-sbc-1-01 /usr/sbin/kamailio[9178]: DEBUG: tm [t_lookup.c:485]: matching_3261(): DEBUG: RFC3261 transaction matching failed Apr 16 19:21:33 kam-sbc-1-01 /usr/sbin/kamailio[9178]: DEBUG: tm [t_lookup.c:709]: t_lookup_request(): DEBUG: t_lookup_request: no transaction found Apr 16 19:21:33 kam-sbc-1-01 /usr/sbin/kamailio[9178]: DEBUG: tm [t_funcs.c:312]: t_relay_to(): SER: forwarding ACK statelessly Apr 16 19:21:33 kam-sbc-1-01 /usr/sbin/kamailio[9178]: DEBUG: <core> [md5utils.c:67]: MD5StringArray(): DEBUG: MD5 calculated: 2132d578ec20fa9b478ada51e9f2965f Apr 16 19:21:33 kam-sbc-1-01 /usr/sbin/kamailio[9178]: DEBUG: <core> [forward.c:211]: get_out_socket(): DEBUG: get_out_socket: socket determined: 0xf6e777ec Apr 16 19:21:33 kam-sbc-1-01 /usr/sbin/kamailio[9178]: DEBUG: <core> [msg_translator.c:206]: check_via_address(): check_via_address(1.2.2.94, 192.168.4.218, 0) Apr 16 19:21:33 kam-sbc-1-01 /usr/sbin/kamailio[9178]: DEBUG: <core> [forward.c:592]: forward_request(): Sending:#012ACK sip:1.2.3.46;lr=on;ftag=259196205;nat=yes SIP/2.0#015#012Record-Route: <sip:1.2.3.46;lr=on;ftag=259196205>#015#012Via: SIP/2.0/UDP 1.2.3.46;branch=z9hG4bK4449.2132d578ec20fa9b478ada51e9f2965f.0#015#012Via: SIP/2.0/UDP 192.168.4.218:5062;rport=58542;received=1.2.2.94;branch=z9hG4bK1161188624#015#012From: "0099977" <sip:0099977@1.2.3.46>;tag=259196205#015#012To: <sip:89215572714@1.2.3.46>;tag=as6bfd1fa1#015#012Call-ID: 910089142(a)192.168.4.218#015#012CSeq: 2 ACK#015#012Contact: <sip:0099977@192.168.4.218:5062;alias=1.2.2.94~58542~1>#015#012Max-Forwards: 69#015#012User-Agent: Yealink SIP-T46G 28.71.14.4#015#012Content-Length: 0#015#012#015#012.