16 Apr
2015
16 Apr
'15
8:23 p.m.
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.
--
Best regards,
Dmitry Sytchev,
IT Engineer
17 Apr
17 Apr
12:19 p.m.
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(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.
12:32 p.m.
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(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.
1:13 p.m.
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(a)sipwise.com>om>:
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:
--
Best regards,
Dmitry Sytchev,
IT Engineer
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.
_______________________________________________
SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list
sr-users(a)lists.sip-router.org
http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
4:52 p.m.
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!
3513
days inactive
3514
days old
4 comments
2 participants
participants (2)
-
Daniel Grotti -
Dmitry Sytchev