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@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@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.
Hi, is your Yealink SIP-T46G setting the right RURI in the ACK ? What is the 200OK sent to the yealink ?
ACK RURI should be set to the Contact field in the 200 OK and Route header must be set to the Record-Route headers value in the 200 OK, in the reverse order.
Do you have the complete call flow ?
-- 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@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@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@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.
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@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@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@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.
Hi Daniel!
I've tried Yealink and Cisco SPA-303 They send very similar ACKs, the problem seems to be not in their SIP stacks. Original ACK URI is correct uri from 200 OK contact. Route: header is set to correct value from Record-Route from 200 OK. Maybe my NAT handling code makes something wrong with original ACK...
There is kinda unusual IP setup on machine - there is quagga daemon, there are many public IPs and one of machine's public IP addresses is set as /32 on loopback to be announced with BGP. But routing is correct, so I don't think there are issues with this. mhomed = 1 in kamailo config.
I'll get full SIP dumps and post it there.
Thanks!
2015-04-17 12:32 GMT+03:00 Daniel Grotti dgrotti@sipwise.com:
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@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@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@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.
SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users@lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
I've found the cause of the problem - I added my backend domain to domains table to lookup some attrs of destination hosts. I forgot that Kamailio will interpret them local. So requests to backend with correct ip in rURI were intepreted as directed to proxy and processed this way.
Thanks for your help, Daniel!