24 Oct
2014
24 Oct
'14
7:51 p.m.
Hello,
We are trying to use Kamailio 4.2 with RTPEngine 3.3 behind NAT.
Somehow SIP responses (200 OK) are not handled by Kamailio.
The following INVITE is send to the receiving end (WebRTC Client):
INVITE sip:evQzk4l62MdF3G7U6eudj@whtest3.24dial.com SIP/2.0
Record-Route: <sip:104.155.11.255:5060;nat=yes;lr=on>
Via: SIP/2.0/UDP 104.155.11.255:5060
;branch=z9hG4bK865.9db0c023bec2f314e89ae0f18b78d2f0.0
Via: SIP/2.0/UDP 10.240.215.73:5060
;rport=5060;received=146.148.113.245;branch=z9hG4bK644600e2
Max-Forwards: 69
From: "Anonymous" <sip:anonymous@anonymous.invalid>;tag=as68f0a26a
To: <sip:evQzk4l62MdF3G7U6eudj@whtest3.24dial.com>
Contact: <sip:anonymous@10.240.215.73:5060;alias=146.148.113.245~5060~1>
Call-ID: 368f6ec901a3552e3b37a70907634f4f@10.240.215.73:5060
CSeq: 102 INVITE
User-Agent: Asterisk PBX 12.5.0
Date: Fri, 24 Oct 2014 08:38:09 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO,
PUBLISH, MESSAGE
Supported: replaces, timer
Content-Type: application/sdp
Content-Length: 738
P-hint: outbound
.......
The client response looks like this:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 104.155.11.255:5060
;branch=z9hG4bK865.9db0c023bec2f314e89ae0f18b78d2f0.0;rport=5060;received=104.155.11.255
, SIP/2.0/UDP 10.240.215.73:5060
;rport=5060;received=146.148.113.245;branch=z9hG4bK644600e2
From: "Anonymous" <sip:anonymous@anonymous.invalid>;tag=as68f0a26a
To: <sip:evQzk4l62MdF3G7U6eudj@whtest3.24dial.com
;tag=E2VMB39U5NYHCXLZREFGQV2DAXPCZXNQ6J6P
Contact: <sip:evQzk4l62MdF3G7U6eudj@whtest3.24dial.com
;tag=E2VMB39U5NYHCXLZREFGQV2DAXPCZXNQ6J6P
Call-ID: 368f6ec901a3552e3b37a70907634f4f@10.240.215.73:5060
CSeq: 102 INVITE
Record-Route: <sip:104.155.11.255:5060;nat=yes;lr=on>
Content-Type: application/sdp
Content-Length: 938
.......
I have a xlog call as the first statement in kamailio routing script. I can
see the request, which get's handled correctly but the response does not
appear in kamailio log, though it arrives at the machine.
I am totally helpless, what might be wrong. If we use kamailio on a public
accessable machine everything works as expected.
Maybe anyone might have had similiar problems using kamailio behind NAT.
Kind regards,
Marko
24 Oct
24 Oct
10:32 p.m.
Le Fri, 24 Oct 2014 10:51:57 +0200,
Marko Seidenglanz <marko.seidenglanz(a)gmail.com> a écrit :
I have a xlog call as the first statement in kamailio
routing script.
I can see the request, which get's handled correctly but the response
does not appear in kamailio log, though it arrives at the machine.
Hi Marko,
the SIP replies don't fall into the same routing block as the requests.
You have to declare an explicit onreply_route to be able to catch
replies and do something with them, like logging for example. See
http://www.kamailio.org/wiki/cookbooks/4.2.x/core#onreply_route for
details.
Cheers,
--
Camille
25 Oct
25 Oct
12:53 a.m.
Hello Camille,
thank you for your fast response.
I have defined a reply route:
onreply_route[REPLY_FROM_WEBRTC] {
xlog("L_DEBUG",
"<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
SIP WEBRTC_REPLY: $si:$sp ------> $du ");
xlog("L_DEBUG", "WEBRTC
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
KAMAILIO");
if(status=~"[12][0-9][0-9]") {
rtpengine_manage("force trust-address replace-origin
replace-session-connection ICE=remove RTP/AVP");
route(NATMANAGE);
}
}
And the request get's handled here:
route[TO_WEBRTC] {
xlog("L_DEBUG", "KAMAILIO
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
WEBRTC");
rtpengine_manage("rtcp-mux-offer trust-address replace-origin
replace-session-connection ICE=force RTP/SAVPF");
t_on_reply("REPLY_FROM_WEBRTC");
}
I've also defined a naked reply handler:
onreply_route {
xlog("L_DEBUG",
"<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
SIP NAKED REPLY:
$si:$sp ------> $du ");
}
None of the handler get's called, when kamailio is behind NAT.
If I use it without NAT it works:
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: exec: ***
cfgtrace:request_route=[TO_WEBRTC] c=[/usr/local/etc/kamailio/routing.cfg]
l=83 a=25 n=t_on_reply
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: exec: ***
cfgtrace:request_route=[RELAY] c=[/usr/local/etc/kamailio/routing.cfg] l=72
a=16 n=if
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: exec: ***
cfgtrace:request_route=[RELAY] c=[/usr/local/etc/kamailio/routing.cfg] l=71
a=25 n=t_is_set
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: exec: ***
cfgtrace:request_route=[RELAY] c=[/usr/local/etc/kamailio/routing.cfg] l=71
a=25 n=t_on_failure
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: exec: ***
cfgtrace:request_route=[RELAY] c=[/usr/local/etc/kamailio/routing.cfg] l=77
a=16 n=if
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: exec: ***
cfgtrace:request_route=[RELAY] c=[/usr/local/etc/kamailio/routing.cfg] l=74
a=24 n=t_relay
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: DEBUG: tm
[t_lookup.c:1373]: t_newtran(): DEBUG: t_newtran: msg id=1 , global msg
id=1 , T on entrance=(nil)
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: DEBUG: tm
[t_lookup.c:527]: t_lookup_request(): t_lookup_request: start searching:
hash=17975, isACK=0
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: DEBUG: tm
[t_lookup.c:485]: matching_3261(): DEBUG: RFC3261 transaction matching
failed
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: DEBUG: tm
[t_lookup.c:709]: t_lookup_request(): DEBUG: t_lookup_request: no
transaction found
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: DEBUG: tm
[t_hooks.c:374]: run_reqin_callbacks_internal(): DBG: trans=0x7f05125345d8,
callback type 1, id 0 entered
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: DEBUG: <core>
[md5utils.c:67]: MD5StringArray(): DEBUG: MD5 calculated:
1192e2bc8b6a8390f99a4a7139cd344e
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: DEBUG: tm
[t_funcs.c:347]: t_relay_to(): SER: new INVITE
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: DEBUG: <core>
[msg_translator.c:205]: check_via_address():
check_via_address(146.148.113.245, 10.240.215.73, 0)
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: DEBUG: <core>
[mem/shm_mem.c:111]: _shm_resize(): WARNING:vqm_resize: resize(0) called
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: DEBUG: tm
[t_reply.c:728]: _reply_light(): DEBUG: reply sent out. buf=0x7f051a8ed250:
SIP/2.0 100 trying -..., shmem=0x7f0512536f90: SIP/2.0 100 trying -
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: DEBUG: tm
[t_reply.c:738]: _reply_light(): DEBUG: _reply_light: finished
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: DEBUG: <core>
[dns_cache.c:566]: _dns_hash_find(): dns_hash_find(_sip._
udp.whtest3.24dial.com(28), 33), h=536
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: DEBUG: <core>
[resolve.c:967]: get_record(): get_record: skipping 1 NS (p=0x9e5b1b,
end=0x9e5b4d)
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: DEBUG: <core>
[resolve.c:983]: get_record(): get_record: parsing 0 ARs (p=0x9e5b4d,
end=0x9e5b4d)
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: DEBUG: <core>
[dns_cache.c:1772]: dns_get_related(): dns_get_related(0x7f0512537778
(_sip._udp.whtest3.24dial.com, 5), 33, *0x7f051a8ec028) (0)
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: DEBUG: <core>
[dns_cache.c:1939]: dns_cache_do_request(): dns_cache_do_request: cname
detected: ghs.l.google.com (16)
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: DEBUG: <core>
[dns_cache.c:869]: dns_cache_add_unsafe(): dns_cache_add: adding _sip._
udp.whtest3.24dial.com(28) 5 (flags=0) at 536
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: DEBUG: <core>
[dns_cache.c:869]: dns_cache_add_unsafe(): dns_cache_add: adding
ghs.google.com(14) 5 (flags=0) at 66
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: DEBUG: <core>
[dns_cache.c:2003]: dns_cache_do_request(): dns_cache_do_request:
dns_get_entry(cname: ghs.l.google.com (16))
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: DEBUG: <core>
[dns_cache.c:566]: _dns_hash_find(): dns_hash_find(ghs.l.google.com(16),
33), h=702
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: DEBUG: <core>
[resolve.c:770]: get_record(): get_record: lookup(ghs.l.google.com, 33)
failed
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: DEBUG: <core>
[dns_cache.c:894]: dns_cache_mk_bad_entry(): dns_cache_mk_bad_entry(
ghs.l.google.com, 33, 60, 1)
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: DEBUG: <core>
[dns_cache.c:827]: dns_cache_add(): dns_cache_add: adding ghs.l.google.com(16)
33 (flags=1) at 702
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: DEBUG: <core>
[dns_cache.c:566]: _dns_hash_find(): dns_hash_find(whtest3.24dial.com(18),
1), h=452
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: DEBUG: <core>
[resolve.c:967]: get_record(): get_record: skipping 0 NS (p=0x9e5af4,
end=0x9e5af4)
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: DEBUG: <core>
[resolve.c:983]: get_record(): get_record: parsing 0 ARs (p=0x9e5af4,
end=0x9e5af4)
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: DEBUG: <core>
[dns_cache.c:1772]: dns_get_related(): dns_get_related(0x7f0512537978 (
whtest3.24dial.com, 1), 1, *(nil)) (0)
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: DEBUG: <core>
[dns_cache.c:869]: dns_cache_add_unsafe(): dns_cache_add: adding
whtest3.24dial.com(18) 1 (flags=0) at 452
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: DEBUG: <core>
[msg_translator.c:458]: clen_builder(): clen_builder: content-length: 740
(740)
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: DEBUG: <core>
[msg_translator.c:205]: check_via_address():
check_via_address(146.148.113.245, 10.240.215.73, 0)
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: DEBUG: tm
[t_funcs.c:394]: t_relay_to(): SER: new transaction fwd'ed
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: exec: ***
cfgtrace:request_route=[RELAY] c=[/usr/local/etc/kamailio/routing.cfg] l=77
a=2 n=exit
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: DEBUG: <core>
[usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying
list (nil)
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: DEBUG: <core>
[usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying
list (nil)
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: DEBUG: <core>
[usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying
list (nil)
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: DEBUG: <core>
[usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying
list (nil)
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: DEBUG: <core>
[usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying
list (nil)
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: DEBUG: <core>
[usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying
list (nil)
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: DEBUG: <core>
[xavp.c:448]: xavp_destroy_list(): destroying xavp list (nil)
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: DEBUG: <core>
[receive.c:298]: receive_msg(): receive_msg: cleaning up
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: DEBUG: <core>
[parser/sdp/sdp.c:793]: free_sdp(): _sdp = 0x7f051a908b00
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: DEBUG: <core>
[parser/sdp/sdp.c:795]: free_sdp(): sdp = 0x7f051a8f7fd8
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[765]: DEBUG: <core>
[parser/sdp/sdp.c:797]: free_sdp(): session = 0x7f051a8f8050
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[764]: DEBUG: <core>
[parser/msg_parser.c:633]: parse_msg(): SIP Reply (status):
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[764]: DEBUG: <core>
[parser/msg_parser.c:635]: parse_msg(): version: <SIP/2.0>
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[764]: DEBUG: <core>
[parser/msg_parser.c:637]: parse_msg(): status: <200>
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[764]: DEBUG: <core>
[parser/msg_parser.c:639]: parse_msg(): reason: <OK>
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[764]: DEBUG: <core>
[parser/parse_via.c:1284]: parse_via_param(): Found param type 232,
<branch> = <z9hG4bK7364.1192e2bc8b6a8390f99a4a7139cd344e.0>; state=6
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[764]: DEBUG: <core>
[parser/parse_via.c:1284]: parse_via_param(): Found param type 235, <rport>
= <5060>; state=6
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[764]: DEBUG: <core>
[parser/parse_via.c:1284]: parse_via_param(): Found param type 234,
<received> = <104.155.11.255>; state=16
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[764]: DEBUG: <core>
[parser/parse_via.c:2715]: parse_via(): parse_via: next_via
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[764]: DEBUG: <core>
[parser/parse_via.c:1284]: parse_via_param(): Found param type 235, <rport>
= <5060>; state=6
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[764]: DEBUG: <core>
[parser/parse_via.c:1284]: parse_via_param(): Found param type 234,
<received> = <146.148.113.245>; state=6
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[764]: DEBUG: <core>
[parser/parse_via.c:1284]: parse_via_param(): Found param type 232,
<branch> = <z9hG4bK22173743>; state=16
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[764]: DEBUG: <core>
[parser/parse_via.c:2672]: parse_via(): end of header reached, state=5
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[764]: DEBUG: <core>
[parser/msg_parser.c:513]: parse_headers(): parse_headers: Via found,
flags=2
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[764]: DEBUG: <core>
[parser/msg_parser.c:515]: parse_headers(): parse_headers: this is the
first via
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[764]: DEBUG: <core>
[receive.c:154]: receive_msg(): After parse_msg...
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[764]: exec: ***
cfgtrace:onreply_route=[MANAGE_BRANCH]
c=[/usr/local/etc/kamailio/routing.cfg] l=295 a=26 n=xlog
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[764]: DEBUG: pv
[pv_core.c:1133]: pv_get_dsturi(): no destination URI
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[764]: DEBUG: <script>:
<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
SIP NAKED REPLY:
104.155.12.183:5060 ------> <null>
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[764]: DEBUG: tm
[t_lookup.c:1072]: t_check_msg(): DEBUG: t_check_msg: msg id=1 global id=0
T start=0xffffffffffffffff
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[764]: DEBUG: <core>
[parser/parse_addr_spec.c:176]: parse_to_param(): DEBUG: add_param:
tag=NE99PKCCWL6TCJ6MP4FL9XKM5XS8PLHG28AL
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[764]: DEBUG: <core>
[parser/parse_addr_spec.c:898]: parse_addr_spec(): end of header reached,
state=29
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[764]: DEBUG: <core>
[parser/msg_parser.c:190]: get_hdr_field(): DEBUG: get_hdr_field: <To>
[89]; uri=[sip:eZFOBx3naIamgwXtSCUi3@whtest3.24dial.com]
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[764]: DEBUG: <core>
[parser/msg_parser.c:192]: get_hdr_field(): DEBUG: to body [<
sip:eZFOBx3naIamgwXtSCUi3@whtest3.24dial.com>]
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[764]: DEBUG: <core>
[parser/msg_parser.c:170]: get_hdr_field(): get_hdr_field: cseq <CSeq>:
<102> <INVITE>
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[764]: DEBUG: tm
[t_lookup.c:949]: t_reply_matching(): DEBUG: t_reply_matching: hash 17975
label 0 branch 0
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[764]: DEBUG: tm
[t_lookup.c:1004]: t_reply_matching(): DEBUG: t_reply_matching: reply
matched (T=0x7f05125345d8)!
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[764]: DEBUG: tm
[t_hooks.c:288]: run_trans_callbacks_internal(): DBG: trans=0x7f05125345d8,
callback type 2, id 0 entered
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[764]: DEBUG: acc
[acc_logic.c:644]: tmcb_func(): acc callback called for t(0x7f05125345d8)
event type 2, reply code 200
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[764]: DEBUG: tm
[t_lookup.c:1141]: t_check_msg(): DEBUG: t_check_msg: msg id=1 global id=1
T end=0x7f05125345d8
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[764]: DEBUG: tm
[t_reply.c:2210]: reply_received(): DEBUG: reply_received: org. status
uas=100, uac[0]=0 local=0 is_invite=1)
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[764]: exec: ***
cfgtrace:onreply_route=[REPLY_FROM_WEBRTC]
c=[/usr/local/etc/kamailio/routing.cfg] l=318 a=26 n=xlog
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[764]: DEBUG: pv
[pv_core.c:1133]: pv_get_dsturi(): no destination URI
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[764]: DEBUG: <script>:
<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
SIP WEBRTC_REPLY:
104.155.12.183:5060 ------> <null>
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[764]: exec: ***
cfgtrace:onreply_route=[REPLY_FROM_WEBRTC]
c=[/usr/local/etc/kamailio/routing.cfg] l=319 a=26 n=xlog
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[764]: DEBUG: <script>:
WEBRTC
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
KAMAILIO
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[764]: exec: ***
cfgtrace:onreply_route=[REPLY_FROM_WEBRTC]
c=[/usr/local/etc/kamailio/routing.cfg] l=325 a=16 n=if
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[764]: exec: ***
cfgtrace:onreply_route=[REPLY_FROM_WEBRTC]
c=[/usr/local/etc/kamailio/routing.cfg] l=322 a=25 n=rtpengine_manage
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[764]: DEBUG: <core>
[parser/msg_parser.c:204]: get_hdr_field(): DEBUG: get_hdr_body :
content_length=727
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[764]: DEBUG: <core>
[parser/msg_parser.c:106]: get_hdr_field(): found end of header
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[764]: DEBUG: <core>
[parser/sdp/sdp_helpr_funcs.c:505]: extract_mediaip(): located IP address
[127.0.0.1] in `o=' field
Oct 24 15:42:38 h2296799 /usr/local/sbin/kamailio[764]: DEBUG: <core>
[parser/sdp/sdp_helpr_funcs.c:505]: extract_mediaip(): located IP address
[84.180.121.192] in `c=' field
Behind NAT:
Oct 24 13:51:25 kamailio-test /usr/local/sbin/kamailio[23473]: DEBUG:
<script>: KAMAILIO
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
WEBRTC
Oct 24 13:51:25 kamailio-test /usr/local/sbin/kamailio[23473]: exec: ***
cfgtrace:request_route=[TO_WEBRTC] c=[/usr/local/etc/kamailio/routing.cfg]
l=82 a=25 n=rtpengine_manage
Oct 24 13:51:25 kamailio-test /usr/local/sbin/kamailio[23473]: DEBUG:
<core> [parser/sdp/sdp_helpr_funcs.c:505]: extract_mediaip(): located IP
address [10.240.215.73] in `o=' field
Oct 24 13:51:25 kamailio-test /usr/local/sbin/kamailio[23473]: DEBUG:
<core> [parser/sdp/sdp_helpr_funcs.c:505]: extract_mediaip(): located IP
address [10.240.215.73] in `c=' field
Oct 24 13:51:25 kamailio-test /usr/local/sbin/kamailio[23473]: DEBUG:
<core> [parser/sdp/sdp.c:574]: parse_sdp_session(): ignoring unknown type
in a= line: `a=maxptime:150#015#012a=sendrecv#015#012'
Oct 24 13:51:25 kamailio-test /usr/local/sbin/kamailio[23473]: DEBUG:
rtpengine [rtpengine_funcs.c:148]: check_content_type(): type
<application/sdp> found valid
Oct 24 13:51:25 kamailio-test /usr/local/sbin/kamailio[23473]: DEBUG:
rtpengine [rtpengine.c:1448]: rtpp_function_call(): proxy reply:
d3:sdp740:v=0#015#012o=root 2105198325 2105198325 IN IP4
104.155.11.255#015#012s=Asterisk PBX 12.5.0#015#012c=IN IP4
104.155.11.255#015#012t=0 0#015#012a=ice-lite#015#012m=audio 32252
RTP/SAVPF 3 0 8 101#015#012a=rtpmap:3 GSM/8000#015#012a=rtpmap:0
PCMU/8000#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:101
telephone-event/8000#015#012a=fmtp:101
0-16#015#012a=ptime:20#015#012a=maxptime:150#015#012a=sendrecv#015#012a=rtcp:32253#015#012a=rtcp-mux#015#012a=crypto:1
AES_CM_128_HMAC_SHA1_80
inline:RC/2fFtLO6fLVwOyaBqTK/5PowB/7LNGJOtNS0iD#015#012a=setup:actpass#015#012a=fingerprint:sha-1
D9:26:45:E1:D6:E7:01:A4:04:90:F2:15:AF:A3:AD:01:3C:39:9B:7D#015#012a=ice-ufrag:pP7ALOtu#015#012a=ice-pwd:wsreIk3fR2JTJPvtWGpCu21RP7ry#015#012a=candidate:krhMgLYHbAxWidfK
1 UDP 2130706431 104.155.11.255 32252 typ
host#015#012a=candidate:krhMgLYHbAxWidfK 2 UDP 2130706430 104.155.11.255
32253 typ host#015#0126:result2:oke
Oct 24 13:51:25 kamailio-test /usr/local/sbin/kamailio[23473]: exec: ***
cfgtrace:request_route=[TO_WEBRTC] c=[/usr/local/etc/kamailio/routing.cfg]
l=83 a=25 n=t_on_reply
Oct 24 13:51:25 kamailio-test /usr/local/sbin/kamailio[23473]: exec: ***
cfgtrace:request_route=[RELAY] c=[/usr/local/etc/kamailio/routing.cfg] l=72
a=16 n=if
Oct 24 13:51:25 kamailio-test /usr/local/sbin/kamailio[23473]: exec: ***
cfgtrace:request_route=[RELAY] c=[/usr/local/etc/kamailio/routing.cfg] l=71
a=25 n=t_is_set
Oct 24 13:51:25 kamailio-test /usr/local/sbin/kamailio[23473]: exec: ***
cfgtrace:request_route=[RELAY] c=[/usr/local/etc/kamailio/routing.cfg] l=71
a=25 n=t_on_failure
Oct 24 13:51:25 kamailio-test /usr/local/sbin/kamailio[23473]: exec: ***
cfgtrace:request_route=[RELAY] c=[/usr/local/etc/kamailio/routing.cfg] l=77
a=16 n=if
Oct 24 13:51:25 kamailio-test /usr/local/sbin/kamailio[23473]: exec: ***
cfgtrace:request_route=[RELAY] c=[/usr/local/etc/kamailio/routing.cfg] l=74
a=24 n=t_relay
Oct 24 13:51:25 kamailio-test /usr/local/sbin/kamailio[23473]: DEBUG: tm
[t_lookup.c:1373]: t_newtran(): DEBUG: t_newtran: msg id=1 , global msg
id=1 , T on entrance=(nil)
Oct 24 13:51:25 kamailio-test /usr/local/sbin/kamailio[23473]: DEBUG: tm
[t_lookup.c:527]: t_lookup_request(): t_lookup_request: start searching:
hash=27313, isACK=0
Oct 24 13:51:25 kamailio-test /usr/local/sbin/kamailio[23473]: DEBUG: tm
[t_lookup.c:485]: matching_3261(): DEBUG: RFC3261 transaction matching
failed
Oct 24 13:51:25 kamailio-test /usr/local/sbin/kamailio[23473]: DEBUG: tm
[t_lookup.c:709]: t_lookup_request(): DEBUG: t_lookup_request: no
transaction found
Oct 24 13:51:25 kamailio-test /usr/local/sbin/kamailio[23473]: DEBUG: tm
[t_hooks.c:374]: run_reqin_callbacks_internal(): DBG: trans=0x7f4eb02f8bf8,
callback type 1, id 0 entered
Oct 24 13:51:25 kamailio-test /usr/local/sbin/kamailio[23473]: DEBUG:
<core> [md5utils.c:67]: MD5StringArray(): DEBUG: MD5 calculated:
30d0d77f27566a4be6ae5a29b9556a1d
Oct 24 13:51:25 kamailio-test /usr/local/sbin/kamailio[23473]: DEBUG: tm
[t_funcs.c:347]: t_relay_to(): SER: new INVITE
Oct 24 13:51:25 kamailio-test /usr/local/sbin/kamailio[23473]: DEBUG:
<core> [msg_translator.c:205]: check_via_address():
check_via_address(146.148.113.245, 10.240.215.73, 0)
Oct 24 13:51:25 kamailio-test /usr/local/sbin/kamailio[23473]: DEBUG:
<core> [mem/shm_mem.c:111]: _shm_resize(): WARNING:vqm_resize: resize(0)
called
Oct 24 13:51:25 kamailio-test /usr/local/sbin/kamailio[23473]: DEBUG: tm
[t_reply.c:728]: _reply_light(): DEBUG: reply sent out. buf=0x7f4eb86b55e8:
SIP/2.0 100 trying -..., shmem=0x7f4eb02fb828: SIP/2.0 100 trying -
Oct 24 13:51:25 kamailio-test /usr/local/sbin/kamailio[23473]: DEBUG: tm
[t_reply.c:738]: _reply_light(): DEBUG: _reply_light: finished
Oct 24 13:51:25 kamailio-test /usr/local/sbin/kamailio[23473]: DEBUG:
<core> [dns_cache.c:566]: _dns_hash_find(): dns_hash_find(_sip._
udp.whtest3.24dial.com(28), 33), h=536
Oct 24 13:51:25 kamailio-test /usr/local/sbin/kamailio[23473]: DEBUG:
<core> [dns_cache.c:566]: _dns_hash_find(): dns_hash_find(ghs.google.com(14),
33), h=66
Oct 24 13:51:25 kamailio-test /usr/local/sbin/kamailio[23473]: DEBUG:
<core> [dns_cache.c:566]: _dns_hash_find(): dns_hash_find(ghs.l.google.com(16),
33), h=702
Oct 24 13:51:25 kamailio-test /usr/local/sbin/kamailio[23473]: DEBUG:
<core> [resolve.c:770]: get_record(): get_record: lookup(ghs.l.google.com,
33) failed
Oct 24 13:51:25 kamailio-test /usr/local/sbin/kamailio[23473]: DEBUG:
<core> [dns_cache.c:894]: dns_cache_mk_bad_entry(): dns_cache_mk_bad_entry(
ghs.l.google.com, 33, 60, 1)
Oct 24 13:51:25 kamailio-test /usr/local/sbin/kamailio[23473]: DEBUG:
<core> [dns_cache.c:827]: dns_cache_add(): dns_cache_add: adding
ghs.l.google.com(16) 33 (flags=1) at 702
Oct 24 13:51:25 kamailio-test /usr/local/sbin/kamailio[23473]: DEBUG:
<core> [dns_cache.c:566]: _dns_hash_find():
dns_hash_find(whtest3.24dial.com(18),
1), h=452
Oct 24 13:51:25 kamailio-test /usr/local/sbin/kamailio[23473]: DEBUG:
<core> [msg_translator.c:458]: clen_builder(): clen_builder:
content-length: 740 (740)
Oct 24 13:51:25 kamailio-test /usr/local/sbin/kamailio[23473]: DEBUG:
<core> [msg_translator.c:205]: check_via_address():
check_via_address(146.148.113.245, 10.240.215.73, 0)
Oct 24 13:51:25 kamailio-test /usr/local/sbin/kamailio[23473]: DEBUG: tm
[t_funcs.c:394]: t_relay_to(): SER: new transaction fwd'ed
Oct 24 13:51:25 kamailio-test /usr/local/sbin/kamailio[23473]: exec: ***
cfgtrace:request_route=[RELAY] c=[/usr/local/etc/kamailio/routing.cfg] l=77
a=2 n=exit
Oct 24 13:51:25 kamailio-test /usr/local/sbin/kamailio[23473]: DEBUG:
<core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list:
destroying list (nil)
Oct 24 13:51:25 kamailio-test /usr/local/sbin/kamailio[23473]: DEBUG:
<core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list:
destroying list (nil)
Oct 24 13:51:25 kamailio-test /usr/local/sbin/kamailio[23473]: DEBUG:
<core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list:
destroying list (nil)
Oct 24 13:51:25 kamailio-test /usr/local/sbin/kamailio[23473]: DEBUG:
<core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list:
destroying list (nil)
Oct 24 13:51:25 kamailio-test /usr/local/sbin/kamailio[23473]: DEBUG:
<core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list:
destroying list (nil)
Oct 24 13:51:25 kamailio-test /usr/local/sbin/kamailio[23473]: DEBUG:
<core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list:
destroying list (nil)
Oct 24 13:51:25 kamailio-test /usr/local/sbin/kamailio[23473]: DEBUG:
<core> [xavp.c:448]: xavp_destroy_list(): destroying xavp list (nil)
Oct 24 13:51:25 kamailio-test /usr/local/sbin/kamailio[23473]: DEBUG:
<core> [receive.c:298]: receive_msg(): receive_msg: cleaning up
Oct 24 13:51:25 kamailio-test /usr/local/sbin/kamailio[23473]: DEBUG:
<core> [parser/sdp/sdp.c:793]: free_sdp(): _sdp = 0x7f4eb86d01c0
Oct 24 13:51:25 kamailio-test /usr/local/sbin/kamailio[23473]: DEBUG:
<core> [parser/sdp/sdp.c:795]: free_sdp(): sdp = 0x7f4eb86c0370
Oct 24 13:51:25 kamailio-test /usr/local/sbin/kamailio[23473]: DEBUG:
<core> [parser/sdp/sdp.c:797]: free_sdp(): session = 0x7f4eb86c03e8
And nothing get's received.
2014-10-24 13:32 GMT+02:00 Camille Oudot <camille.oudot(a)orange.com>om>:
Le Fri, 24 Oct 2014 10:51:57 +0200,
Marko Seidenglanz <marko.seidenglanz(a)gmail.com> a écrit :
I have a xlog call as the first statement in
kamailio routing script.
I can see the request, which get's handled correctly but the response
does not appear in kamailio log, though it arrives at the machine.
Hi Marko,
the SIP replies don't fall into the same routing block as the requests.
You have to declare an explicit onreply_route to be able to catch
replies and do something with them, like logging for example. See
http://www.kamailio.org/wiki/cookbooks/4.2.x/core#onreply_route for
details.
Cheers,
--
Camille
2:13 a.m.
Hello,
The problem of kamailio not receiving the packet's is that packet size of
200 response seems to be too large. I removed the SDP from response and it
arrives.
Anyone had a similar problem and knows how it might get solved (accept
switching to TCP)
Kind regards,
Marko
2014-10-24 10:51 GMT+02:00 Marko Seidenglanz <marko.seidenglanz(a)gmail.com>om>:
Hello,
We are trying to use Kamailio 4.2 with RTPEngine 3.3 behind NAT.
Somehow SIP responses (200 OK) are not handled by Kamailio.
The following INVITE is send to the receiving end (WebRTC Client):
INVITE sip:evQzk4l62MdF3G7U6eudj@whtest3.24dial.com SIP/2.0
Record-Route: <sip:104.155.11.255:5060;nat=yes;lr=on>
Via: SIP/2.0/UDP 104.155.11.255:5060
;branch=z9hG4bK865.9db0c023bec2f314e89ae0f18b78d2f0.0
Via: SIP/2.0/UDP 10.240.215.73:5060
;rport=5060;received=146.148.113.245;branch=z9hG4bK644600e2
Max-Forwards: 69
From: "Anonymous" <sip:anonymous@anonymous.invalid>;tag=as68f0a26a
To: <sip:evQzk4l62MdF3G7U6eudj@whtest3.24dial.com>
Contact: <sip:anonymous@10.240.215.73:5060;alias=146.148.113.245~5060~1>
Call-ID: 368f6ec901a3552e3b37a70907634f4f@10.240.215.73:5060
CSeq: 102 INVITE
User-Agent: Asterisk PBX 12.5.0
Date: Fri, 24 Oct 2014 08:38:09 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO,
PUBLISH, MESSAGE
Supported: replaces, timer
Content-Type: application/sdp
Content-Length: 738
P-hint: outbound
.......
The client response looks like this:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 104.155.11.255:5060
;branch=z9hG4bK865.9db0c023bec2f314e89ae0f18b78d2f0.0;rport=5060;received=104.155.11.255
, SIP/2.0/UDP 10.240.215.73:5060
;rport=5060;received=146.148.113.245;branch=z9hG4bK644600e2
From: "Anonymous" <sip:anonymous@anonymous.invalid>;tag=as68f0a26a
To: <sip:evQzk4l62MdF3G7U6eudj@whtest3.24dial.com
;tag=E2VMB39U5NYHCXLZREFGQV2DAXPCZXNQ6J6P
Contact: <sip:evQzk4l62MdF3G7U6eudj@whtest3.24dial.com
;tag=E2VMB39U5NYHCXLZREFGQV2DAXPCZXNQ6J6P
Call-ID: 368f6ec901a3552e3b37a70907634f4f@10.240.215.73:5060
CSeq: 102 INVITE
Record-Route: <sip:104.155.11.255:5060;nat=yes;lr=on>
Content-Type: application/sdp
Content-Length: 938
.......
I have a xlog call as the first statement in kamailio routing script. I
can see the request, which get's handled correctly but the response does
not appear in kamailio log, though it arrives at the machine.
I am totally helpless, what might be wrong. If we use kamailio on a public
accessable machine everything works as expected.
Maybe anyone might have had similiar problems using kamailio behind NAT.
Kind regards,
Marko
3762
days inactive
3762
days old
3 comments
2 participants
participants (2)
-
Camille Oudot -
Marko Seidenglanz