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

Fri Apr 17 11:32:52 CEST 2015

Hi,
please also check if you have set aliases (kamailio.cfg global
parameters) to the IP address in the R-URI.

--
Daniel Grotti
VoIP Engineer

Sipwise GmbH
Europaring F15 | 2345 Brunn am Gebirge, Austria | www.sipwise.com

On 04/16/2015 07:23 PM, Dmitry Sytchev wrote:
> 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 at 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 at 1.2.3.46>;tag=259196205.
> To: <sip:89211234567 at 1.2.3.46>;tag=as6bfd1fa1.
> Call-ID: 910089142 at 192.168.4.218.
> CSeq: 2 ACK.
> Contact: <sip:0099977 at 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 at 192.168.4.218:5062> =>
> [sip:0099977 at 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 at 1.2.3.46>;tag=259196205#015#012To:
> <sip:89215572714 at 1.2.3.46>;tag=as6bfd1fa1#015#012Call-ID:
> 910089142 at 192.168.4.218#015#012CSeq: 2 ACK#015#012Contact:
> <sip:0099977 at 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.
> 
> 
> 
> 
> 
> 
> 