15 Dec
2016
15 Dec
'16
3:13 p.m.
Hi, I have setup kamailio with the dispatcher module and have a problem
with the ACK in response to 200OK not being forwarded by kamailio:
Scenario is very simple:
sipp(.219) --> kamailio (.220) --> sipp(.239)
SIP trace:
root@DNS-enum-8Gb-3:/var/log# ngrep -W byline -d eth0 port 5060
interface: eth0 (10.57.26.0/255.255.255.0)
filter: (ip or ip6) and ( port 5060 )
#
U 10.57.26.219:5060 -> 10.57.26.220:5060
INVITE sip:service@10.57.26.220:5060 SIP/2.0.
Via: SIP/2.0/UDP 10.57.26.219:5060;branch=z9hG4bK-15698-1-0.
From: sipp <sip:sipp@10.57.26.219:5060>;tag=15698SIPpTag021.
To: sut <sip:service@10.57.26.220:5060>.
Call-ID: 1-15698(a)10.57.26.219.
CSeq: 1 INVITE.
Contact: sip:sipp@10.57.26.219:5060.
Max-Forwards: 70.
Subject: Performance Test.
Content-Type: application/sdp.
Content-Length: 135.
.
v=0.
o=user1 53655765 2353687637 IN IP4 10.57.26.219.
s=-.
c=IN IP4 10.57.26.219.
t=0 0.
m=audio 6000 RTP/AVP 0.
a=rtpmap:0 PCMU/8000.
#
U 10.57.26.220:5060 -> 10.57.26.219:5060
SIP/2.0 100 trying -- your call is important to us.
Via: SIP/2.0/UDP 10.57.26.219:5060;branch=z9hG4bK-15698-1-0.
From: sipp <sip:sipp@10.57.26.219:5060>;tag=15698SIPpTag021.
To: sut <sip:service@10.57.26.220:5060>.
Call-ID: 1-15698(a)10.57.26.219.
CSeq: 1 INVITE.
Server: kamailio (4.2.0 (x86_64/linux)).
Content-Length: 0.
.
#
U 10.57.26.220:5060 -> 10.57.26.239:5060
INVITE sip:service@10.57.26.220:5060 SIP/2.0.
Record-Route: <sip:10.57.26.220;lr>.
Via: SIP/2.0/UDP
10.57.26.220;branch=z9hG4bKf92d.33550a94aa52aef3978cb507902d8aaa.0.
Via: SIP/2.0/UDP 10.57.26.219:5060;branch=z9hG4bK-15698-1-0.
From: sipp <sip:sipp@10.57.26.219:5060>;tag=15698SIPpTag021.
To: sut <sip:service@10.57.26.220:5060>.
Call-ID: 1-15698(a)10.57.26.219.
CSeq: 1 INVITE.
Contact: sip:sipp@10.57.26.219:5060.
Max-Forwards: 69.
Subject: Performance Test.
Content-Type: application/sdp.
Content-Length: 135.
.
v=0.
o=user1 53655765 2353687637 IN IP4 10.57.26.219.
s=-.
c=IN IP4 10.57.26.219.
t=0 0.
m=audio 6000 RTP/AVP 0.
a=rtpmap:0 PCMU/8000.
#
U 10.57.26.239:5060 -> 10.57.26.220:5060
SIP/2.0 180 Ringing.
Via: SIP/2.0/UDP
10.57.26.220;branch=z9hG4bKf92d.33550a94aa52aef3978cb507902d8aaa.0,
SIP/2.0/UDP 10.57.26.219:5060;branch=z9hG4bK-15698-1-0.
From: sipp <sip:sipp@10.57.26.219:5060>;tag=15698SIPpTag021.
To: sut <sip:service@10.57.26.220:5060>;tag=14783SIPpTag018.
Call-ID: 1-15698(a)10.57.26.219.
CSeq: 1 INVITE.
Contact: <sip:10.57.26.239:5060;transport=UDP>.
Content-Length: 0.
.
#
U 10.57.26.239:5060 -> 10.57.26.220:5060
SIP/2.0 200 OK.
Via: SIP/2.0/UDP
10.57.26.220;branch=z9hG4bKf92d.33550a94aa52aef3978cb507902d8aaa.0,
SIP/2.0/UDP 10.57.26.219:5060;branch=z9hG4bK-15698-1-0.
From: sipp <sip:sipp@10.57.26.219:5060>;tag=15698SIPpTag021.
To: sut <sip:service@10.57.26.220:5060>;tag=14783SIPpTag018.
Call-ID: 1-15698(a)10.57.26.219.
CSeq: 1 INVITE.
Contact: <sip:10.57.26.239:5060;transport=UDP>.
Content-Type: application/sdp.
Content-Length: 135.
.
v=0.
o=user1 53655765 2353687637 IN IP4 10.57.26.239.
s=-.
c=IN IP4 10.57.26.239.
t=0 0.
m=audio 6000 RTP/AVP 0.
a=rtpmap:0 PCMU/8000.
#
U 10.57.26.220:5060 -> 10.57.26.219:5060
SIP/2.0 180 Ringing.
Via: SIP/2.0/UDP 10.57.26.219:5060;branch=z9hG4bK-15698-1-0.
From: sipp <sip:sipp@10.57.26.219:5060>;tag=15698SIPpTag021.
To: sut <sip:service@10.57.26.220:5060>;tag=14783SIPpTag018.
Call-ID: 1-15698(a)10.57.26.219.
CSeq: 1 INVITE.
Contact: <sip:10.57.26.239:5060;transport=UDP>.
Content-Length: 0.
.
#
U 10.57.26.220:5060 -> 10.57.26.219:5060
SIP/2.0 200 OK.
Via: SIP/2.0/UDP 10.57.26.219:5060;branch=z9hG4bK-15698-1-0.
From: sipp <sip:sipp@10.57.26.219:5060>;tag=15698SIPpTag021.
To: sut <sip:service@10.57.26.220:5060>;tag=14783SIPpTag018.
Call-ID: 1-15698(a)10.57.26.219.
CSeq: 1 INVITE.
Contact: <sip:10.57.26.239:5060;transport=UDP>.
Content-Type: application/sdp.
Content-Length: 135.
.
v=0.
o=user1 53655765 2353687637 IN IP4 10.57.26.239.
s=-.
c=IN IP4 10.57.26.239.
t=0 0.
m=audio 6000 RTP/AVP 0.
a=rtpmap:0 PCMU/8000.
#
U 10.57.26.219:5060 -> 10.57.26.220:5060
ACK sip:10.57.26.239:5060;transport=UDP SIP/2.0.
Via: SIP/2.0/UDP 10.57.26.219:5060;branch=z9hG4bK-15698-1-5.
From: sipp <sip:sipp@10.57.26.219:5060>;tag=15698SIPpTag021.
To: sut <sip:service@10.57.26.220:5060>;tag=14783SIPpTag018.
Call-ID: 1-15698(a)10.57.26.219.
CSeq: 1 ACK.
Contact: sip:sipp@10.57.26.219:5060.
Max-Forwards: 70.
Subject: Performance Test.
XContactinOK: <sip:10.57.26.239:5060;transport=UDP>.
Content-Length: 0.
.
#
U 10.57.26.239:5060 -> 10.57.26.220:5060
SIP/2.0 200 OK.
Via: SIP/2.0/UDP
10.57.26.220;branch=z9hG4bKf92d.33550a94aa52aef3978cb507902d8aaa.0,
SIP/2.0/UDP 10.57.26.219:5060;branch=z9hG4bK-15698-1-0.
From: sipp <sip:sipp@10.57.26.219:5060>;tag=15698SIPpTag021.
To: sut <sip:service@10.57.26.220:5060>;tag=14783SIPpTag018.
Call-ID: 1-15698(a)10.57.26.219.
CSeq: 1 INVITE.
Contact: <sip:10.57.26.239:5060;transport=UDP>.
Content-Type: application/sdp.
Content-Length: 135.
.
v=0.
o=user1 53655765 2353687637 IN IP4 10.57.26.239.
s=-.
c=IN IP4 10.57.26.239.
t=0 0.
m=audio 6000 RTP/AVP 0.
a=rtpmap:0 PCMU/8000.
#
U 10.57.26.220:5060 -> 10.57.26.219:5060
SIP/2.0 200 OK.
Via: SIP/2.0/UDP 10.57.26.219:5060;branch=z9hG4bK-15698-1-0.
From: sipp <sip:sipp@10.57.26.219:5060>;tag=15698SIPpTag021.
To: sut <sip:service@10.57.26.220:5060>;tag=14783SIPpTag018.
Call-ID: 1-15698(a)10.57.26.219.
CSeq: 1 INVITE.
Contact: <sip:10.57.26.239:5060;transport=UDP>.
Content-Type: application/sdp.
Content-Length: 135.
.
v=0.
o=user1 53655765 2353687637 IN IP4 10.57.26.239.
s=-.
c=IN IP4 10.57.26.239.
t=0 0.
m=audio 6000 RTP/AVP 0.
a=rtpmap:0 PCMU/8000.
#
*U 10.57.26.219:5060 <http://10.57.26.219:5060> -> 10.57.26.220:5060
<http://10.57.26.220:5060>*
*ACK sip:10.57.26.239:5060;transport=UDP SIP/2.0.*
*Via: SIP/2.0/UDP 10.57.26.219:5060;branch=z9hG4bK-15698-1-5.*
*From: sipp <sip:sipp@10.57.26.219:5060
<http://sip:sipp@10.57.26.219:5060>>;tag=15698SIPpTag021.*
*To: sut <sip:service@10.57.26.220:5060
<http://sip:service@10.57.26.220:5060>>;tag=14783SIPpTag018.*
*Call-ID: 1-15698(a)10.57.26.219 <1-15698(a)10.57.26.219>.*
*CSeq: 1 ACK.*
*Contact: sip:sipp@10.57.26.219:5060 <http://sip:sipp@10.57.26.219:5060>.*
*Max-Forwards: 70.*
*Subject: Performance Test.*
*XContactinOK: <sip:10.57.26.239:5060;transport=UDP>.*
*Content-Length: 0.*
.
#
U 10.57.26.219:5060 -> 10.57.26.220:5060
BYE sip:10.57.26.239:5060;transport=UDP SIP/2.0.
Via: SIP/2.0/UDP 10.57.26.219:5060;branch=z9hG4bK-15698-1-7.
From: sipp <sip:sipp@10.57.26.219:5060>;tag=15698SIPpTag021.
To: sut <sip:service@10.57.26.220:5060>;tag=14783SIPpTag018.
Call-ID: 1-15698(a)10.57.26.219.
CSeq: 2 BYE.
Contact: sip:sipp@10.57.26.219:5060.
Max-Forwards: 70.
Subject: Performance Test.
Content-Length: 0.
.
#
U 10.57.26.220:5060 -> 10.57.26.219:5060
SIP/2.0 404 Not here.
Via: SIP/2.0/UDP 10.57.26.219:5060;branch=z9hG4bK-15698-1-7.
From: sipp <sip:sipp@10.57.26.219:5060>;tag=15698SIPpTag021.
To: sut <sip:service@10.57.26.220:5060>;tag=14783SIPpTag018.
Call-ID: 1-15698(a)10.57.26.219.
CSeq: 2 BYE.
Server: kamailio (4.2.0 (x86_64/linux)).
Content-Length: 0.
.
#
U 10.57.26.219:5060 -> 10.57.26.220:5060
BYE sip:service@10.57.26.220:5060 SIP/2.0.
Via: SIP/2.0/UDP 10.57.26.219:5060;branch=z9hG4bK-15698-1--1.
From: sipp <sip:sipp@10.57.26.219:5060>;tag=15698SIPpTag021.
To: sut <sip:service@10.57.26.220:5060>;tag=14783SIPpTag018.
Call-ID: 1-15698(a)10.57.26.219.
CSeq: 3 BYE.
Max-Forwards: 70.
Contact: <sip:sipp@10.57.26.219:5060;transport=UDP>.
Content-Length: 0.
.
#
U 10.57.26.220:5060 -> 10.57.26.219:5060
SIP/2.0 404 Not here.
Via: SIP/2.0/UDP 10.57.26.219:5060;branch=z9hG4bK-15698-1--1.
From: sipp <sip:sipp@10.57.26.219:5060>;tag=15698SIPpTag021.
To: sut <sip:service@10.57.26.220:5060>;tag=14783SIPpTag018.
Call-ID: 1-15698(a)10.57.26.219.
CSeq: 3 BYE.
Server: kamailio (4.2.0 (x86_64/linux)).
Content-Length: 0.
.
#
U 10.57.26.239:5060 -> 10.57.26.220:5060
SIP/2.0 200 OK.
Via: SIP/2.0/UDP
10.57.26.220;branch=z9hG4bKf92d.33550a94aa52aef3978cb507902d8aaa.0,
SIP/2.0/UDP 10.57.26.219:5060;branch=z9hG4bK-15698-1-0.
From: sipp <sip:sipp@10.57.26.219:5060>;tag=15698SIPpTag021.
To: sut <sip:service@10.57.26.220:5060>;tag=14783SIPpTag018.
Call-ID: 1-15698(a)10.57.26.219.
CSeq: 1 INVITE.
Contact: <sip:10.57.26.239:5060;transport=UDP>.
Content-Type: application/sdp.
Content-Length: 135.
.
v=0.
o=user1 53655765 2353687637 IN IP4 10.57.26.239.
s=-.
c=IN IP4 10.57.26.239.
t=0 0.
m=audio 6000 RTP/AVP 0.
a=rtpmap:0 PCMU/8000.
#
U 10.57.26.220:5060 -> 10.57.26.219:5060
SIP/2.0 200 OK.
Via: SIP/2.0/UDP 10.57.26.219:5060;branch=z9hG4bK-15698-1-0.
From: sipp <sip:sipp@10.57.26.219:5060>;tag=15698SIPpTag021.
To: sut <sip:service@10.57.26.220:5060>;tag=14783SIPpTag018.
Call-ID: 1-15698(a)10.57.26.219.
CSeq: 1 INVITE.
Contact: <sip:10.57.26.239:5060;transport=UDP>.
Content-Type: application/sdp.
Content-Length: 135.
.
v=0.
o=user1 53655765 2353687637 IN IP4 10.57.26.239.
s=-.
c=IN IP4 10.57.26.239.
t=0 0.
m=audio 6000 RTP/AVP 0.
a=rtpmap:0 PCMU/8000.
*kamailio.conf:*
# ----- mi_fifo params -----
modparam("mi_fifo", "fifo_name",
"/var/run/kamailio/kamailio_fifo")
modparam("ctl", "binrpc",
"unix:/var/run/kamailio/kamailio_ctl")
# ----- rr params -----
# add value to ;lr param to cope with most of the UAs
modparam("rr", "enable_full_lr", 0)
# do not append from tag to the RR (no need for this script)
modparam("rr", "append_fromtag", 0)
# ----- acc params -----
modparam("acc", "log_flag", 1)
modparam("acc", "failed_transaction_flag", 3)
modparam("acc", "log_extra",
"src_user=$fU;src_domain=$fd;dst_ouser=$tU;dst_user=$rU;dst_domain=$rd;src_ip=$si")
# ----- tm params -----
modparam("tm", "fr_timer", 2000)
modparam("tm", "fr_inv_timer", 40000)
# ----- dispatcher params -----
#modparam("dispatcher", "db_url",
# "mysql://openser:openserro@localhost/openser")
modparam("dispatcher", "list_file",
"/etc/kamailio/dispatcher.list")
modparam("dispatcher", "table_name", "dispatcher")
modparam("dispatcher", "flags", 2)
modparam("dispatcher", "dst_avp", "$avp(AVP_DST)")
modparam("dispatcher", "grp_avp", "$avp(AVP_GRP)")
modparam("dispatcher", "cnt_avp", "$avp(AVP_CNT)")
####### Routing Logic ########
# main request routing logic
route {
# per request initial checks
route(REQINIT);
# handle requests within SIP dialogs
route(WITHINDLG);
### only initial requests (no To tag)
# CANCEL processing
if (is_method("CANCEL"))
{
if (t_check_trans())
t_relay();
exit;
}
t_check_trans();
# record routing for dialog forming requests (in case they are routed)
# - remove preloaded route headers
remove_hf("Route");
if (is_method("INVITE|SUBSCRIBE"))
record_route();
# account only INVITEs
if (is_method("INVITE"))
{
setflag(1); # do accounting
}
# handle presence related requests
route(PRESENCE);
# handle registrations
route(REGISTRAR);
if ($rU==$null)
{
# request with no Username in RURI
sl_send_reply("484","Address Incomplete");
exit;
}
# dispatch destinations
route(DISPATCH);
route(RELAY);
}
route[RELAY] {
if (!t_relay()) {
sl_reply_error();
}
exit;
}
# Per SIP request initial checks
route[REQINIT] {
if (!mf_process_maxfwd_header("15")) {
sl_send_reply("483","Too Many Hops");
exit;
}
# 1= only check the header RURI, 1126 checks some other general stuff
if(!sanity_check("1126", "1"))
{
xlog("Malformed SIP message from $si:$sp\n");
exit;
}
}
# Handle requests within SIP dialogs
route[WITHINDLG] {
if (has_totag()) {
# sequential request withing a dialog should
# take the path determined by record-routing
xlog("#######WITHINDLG:hastotag $si:$sp\n");
if (loose_route()) {
xlog("#######WITHINDLG:looseroute $si:$sp\n");
if (is_method("BYE")) {
setflag(1); # do accounting ...
setflag(3); # ... even if the transaction fails
}
route(RELAY);
} else {
if (is_method("SUBSCRIBE") && uri == myself) {
# in-dialog subscribe requests
route(PRESENCE);
exit;
}
if ( is_method("ACK") ) {
if ( t_check_trans() ) {
xlog("#######WITHINDLG:ACK transaction found $si:$sp\n");
# non loose-route, but stateful ACK;
# must be ACK after a 487 or e.g. 404 from upstream server
t_relay();
exit;
} else {
# ACK without matching transaction ... ignore and discard.
xlog("#######WITHINDLG:ACK no transaction found so discard $si:$sp\n");
exit;
}
}
sl_send_reply("404","Not here");
}
exit;
}
}
Debug:
Dec 15 15:12:02 DNS-enum-8Gb-3 kamailio[6864]: 1(6883) DEBUG: <core>
[parser/msg_parser.c:623]: parse_msg(): SIP Request:
Dec 15 15:12:02 DNS-enum-8Gb-3 kamailio[6864]: 1(6883) DEBUG: <core>
[parser/msg_parser.c:625]: parse_msg(): method: <ACK>
Dec 15 15:12:02 DNS-enum-8Gb-3 kamailio[6864]: 1(6883) DEBUG: <core>
[parser/msg_parser.c:627]: parse_msg(): uri: <sip:10.57.26.239:5060
;transport=UDP>
Dec 15 15:12:02 DNS-enum-8Gb-3 kamailio[6864]: 1(6883) DEBUG: <core>
[parser/msg_parser.c:629]: parse_msg(): version: <SIP/2.0>
Dec 15 15:12:02 DNS-enum-8Gb-3 kamailio[6864]: 1(6883) DEBUG: <core>
[parser/parse_via.c:1284]: parse_via_param(): Found param type 232,
<branch> = <z9hG4bK-15698-1-5>; state=16
Dec 15 15:12:02 DNS-enum-8Gb-3 kamailio[6864]: 1(6883) DEBUG: <core>
[parser/parse_via.c:2672]: parse_via(): end of header reached, state=5
Dec 15 15:12:02 DNS-enum-8Gb-3 kamailio[6864]: 1(6883) DEBUG: <core>
[parser/msg_parser.c:513]: parse_headers(): parse_headers: Via found,
flags=2
Dec 15 15:12:02 DNS-enum-8Gb-3 kamailio[6864]: 1(6883) DEBUG: <core>
[parser/msg_parser.c:515]: parse_headers(): parse_headers: this is the
first via
Dec 15 15:12:02 DNS-enum-8Gb-3 kamailio[6864]: 1(6883) DEBUG: <core>
[receive.c:154]: receive_msg(): After parse_msg...
Dec 15 15:12:02 DNS-enum-8Gb-3 kamailio[6864]: 1(6883) DEBUG: <core>
[receive.c:197]: receive_msg(): preparing to run routing scripts...
Dec 15 15:12:02 DNS-enum-8Gb-3 kamailio[6864]: 1(6883) DEBUG: sl
[sl_funcs.c:412]: sl_filter_ACK(): DEBUG : sl_filter_ACK: to late to be a
local ACK!
Dec 15 15:12:02 DNS-enum-8Gb-3 kamailio[6864]: 1(6883) DEBUG: <core>
[parser/parse_addr_spec.c:176]: parse_to_param(): DEBUG: add_param:
tag=14783SIPpTag018
Dec 15 15:12:02 DNS-enum-8Gb-3 kamailio[6864]: 1(6883) DEBUG: <core>
[parser/parse_addr_spec.c:898]: parse_addr_spec(): end of header reached,
state=29
Dec 15 15:12:02 DNS-enum-8Gb-3 kamailio[6864]: 1(6883) DEBUG: <core>
[parser/msg_parser.c:190]: get_hdr_field(): DEBUG: get_hdr_field: <To>
[57]; uri=[sip:service@10.57.26.220:5060]
Dec 15 15:12:02 DNS-enum-8Gb-3 kamailio[6864]: 1(6883) DEBUG: <core>
[parser/msg_parser.c:192]: get_hdr_field(): DEBUG: to body [sut <
sip:service@10.57.26.220:5060>]
Dec 15 15:12:02 DNS-enum-8Gb-3 kamailio[6864]: 1(6883) DEBUG: <core>
[parser/msg_parser.c:170]: get_hdr_field(): get_hdr_field: cseq <CSeq>: <1>
<ACK>
Dec 15 15:12:02 DNS-enum-8Gb-3 kamailio[6864]: 1(6883) DEBUG: maxfwd
[mf_funcs.c:85]: is_maxfwd_present(): value = 70
Dec 15 15:12:02 DNS-enum-8Gb-3 kamailio[6864]: 1(6883) DEBUG: sanity
[mod_sanity.c:255]: w_sanity_check(): sanity checks result: 1
Dec 15 15:12:02 DNS-enum-8Gb-3 kamailio[6864]: 1(6883) DEBUG: siputils
[checks.c:106]: has_totag(): totag found
Dec 15 15:12:02 DNS-enum-8Gb-3 kamailio[6864]: 1(6883) ERROR: <script>:
#######WITHINDLG:hastotag 10.57.26.219:5060
Dec 15 15:12:02 DNS-enum-8Gb-3 kamailio[6864]: 1(6883) DEBUG: <core>
[parser/msg_parser.c:204]: get_hdr_field(): DEBUG: get_hdr_body :
content_length=0
Dec 15 15:12:02 DNS-enum-8Gb-3 kamailio[6864]: 1(6883) DEBUG: <core>
[parser/msg_parser.c:106]: get_hdr_field(): found end of header
Dec 15 15:12:02 DNS-enum-8Gb-3 kamailio[6864]: 1(6883) DEBUG: rr
[loose.c:113]: find_first_route(): No Route headers found
Dec 15 15:12:02 DNS-enum-8Gb-3 kamailio[6864]: 1(6883) DEBUG: rr
[loose.c:929]: loose_route(): There is no Route HF
Dec 15 15:12:02 DNS-enum-8Gb-3 kamailio[6864]: 1(6883) DEBUG: tm
[t_lookup.c:1072]: t_check_msg(): DEBUG: t_check_msg: msg id=9 global id=8
T start=(nil)
Dec 15 15:12:02 DNS-enum-8Gb-3 kamailio[6864]: 1(6883) DEBUG: tm
[t_lookup.c:527]: t_lookup_request(): t_lookup_request: start searching:
hash=53919, isACK=1
Dec 15 15:12:02 DNS-enum-8Gb-3 kamailio[6864]: 1(6883) DEBUG: tm
[t_lookup.c:485]: matching_3261(): DEBUG: RFC3261 transaction matching
failed
Dec 15 15:12:02 DNS-enum-8Gb-3 kamailio[6864]: 1(6883) DEBUG: tm
[t_lookup.c:709]: t_lookup_request(): DEBUG: t_lookup_request: no
transaction found
Dec 15 15:12:02 DNS-enum-8Gb-3 kamailio[6864]: 1(6883) DEBUG: tm
[t_lookup.c:1141]: t_check_msg(): DEBUG: t_check_msg: msg id=9 global id=9
T end=(nil)
Dec 15 15:12:02 DNS-enum-8Gb-3 kamailio[6864]: 1(6883) ERROR: <script>:
#######WITHINDLG:ACK no transaction found so discard 10.57.26.219:5060
Dec 15 15:12:02 DNS-enum-8Gb-3 kamailio[6864]: 1(6883) DEBUG: <core>
[usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying
list (nil)