Wim,
Looks like your ACK is missing the Route header, since ACK is a new transaction kamailio needs to route it based on a preloaded route. When you receive the 200OK in sipp you should save the record route set and use it in the ACK with the "[routes]" statement.
Take a look at the SIPP docs and search for rrs="true". If you take a packet capture on the loopback interface of the kamailio server you will probably see that kamailio keeps looping the ACK until the Max-Forwards is exhausted.
Example:
<recv response="200" rtd="true" rrs="true">
</recv>
<send>
<![CDATA[
ACK [next_url] SIP/2.0
Via: SIP/2.0/[transport] [local_ip]:[local_port];branch=[branch]
From: sipp <sip:sipp@[field1]>;tag=[pid]SIPpTag00[call_number]
To: sut <sip:[service]@[field1]>[peer_tag_param]
Call-ID: [call_id]
CSeq: 2 ACK
[routes]
Contact: sip:[service]@[local_ip]:[local_port]
Max-Forwards: 70
Subject: Performance Test
Content-Length: 0
]]>
</send>
Regards,
Jan Hazenberg
Wim Van Cauwenbergh schreef op 2016-12-15 15:13:
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 5060interface: eth0 (10.57.26.0/255.255.255.0)filter: (ip or ip6) and ( port 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@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.#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@10.57.26.219.CSeq: 1 INVITE.Server: kamailio (4.2.0 (x86_64/linux)).Content-Length: 0..#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@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.#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@10.57.26.219.CSeq: 1 INVITE.Contact: <sip:10.57.26.239:5060;transport=UDP>.Content-Length: 0..#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@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.#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@10.57.26.219.CSeq: 1 INVITE.Contact: <sip:10.57.26.239:5060;transport=UDP>.Content-Length: 0..#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@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.#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@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..#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@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.#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@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.#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@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..#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@10.57.26.219.CSeq: 2 BYE.Contact: sip:sipp@10.57.26.219:5060.Max-Forwards: 70.Subject: Performance Test.Content-Length: 0..#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@10.57.26.219.CSeq: 2 BYE.Server: kamailio (4.2.0 (x86_64/linux)).Content-Length: 0..#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@10.57.26.219.CSeq: 3 BYE.Max-Forwards: 70.Contact: <sip:sipp@10.57.26.219:5060;transport=UDP>.Content-Length: 0..#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@10.57.26.219.CSeq: 3 BYE.Server: kamailio (4.2.0 (x86_64/linux)).Content-Length: 0..#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@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.#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@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 UAsmodparam("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 logicroute {# per request initial checksroute(REQINIT);# handle requests within SIP dialogsroute(WITHINDLG);### only initial requests (no To tag)# CANCEL processingif (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 headersremove_hf("Route");if (is_method("INVITE|SUBSCRIBE"))record_route();# account only INVITEsif (is_method("INVITE")){setflag(1); # do accounting}# handle presence related requestsroute(PRESENCE);# handle registrationsroute(REGISTRAR);if ($rU==$null){# request with no Username in RURIsl_send_reply("484","Address Incomplete");exit;}# dispatch destinationsroute(DISPATCH);route(RELAY);}route[RELAY] {if (!t_relay()) {sl_reply_error();}exit;}# Per SIP request initial checksroute[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 stuffif(!sanity_check("1126", "1")){xlog("Malformed SIP message from $si:$sp\n");exit;}}# Handle requests within SIP dialogsroute[WITHINDLG] {if (has_totag()) {# sequential request withing a dialog should# take the path determined by record-routingxlog("#######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 requestsroute(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 servert_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=16Dec 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=5Dec 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=2Dec 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 viaDec 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=14783SIPpTag018Dec 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=29Dec 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 = 70Dec 15 15:12:02 DNS-enum-8Gb-3 kamailio[6864]: 1(6883) DEBUG: sanity [mod_sanity.c:255]: w_sanity_check(): sanity checks result: 1Dec 15 15:12:02 DNS-enum-8Gb-3 kamailio[6864]: 1(6883) DEBUG: siputils [checks.c:106]: has_totag(): totag foundDec 15 15:12:02 DNS-enum-8Gb-3 kamailio[6864]: 1(6883) ERROR: <script>: #######WITHINDLG:hastotag 10.57.26.219:5060Dec 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=0Dec 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 headerDec 15 15:12:02 DNS-enum-8Gb-3 kamailio[6864]: 1(6883) DEBUG: rr [loose.c:113]: find_first_route(): No Route headers foundDec 15 15:12:02 DNS-enum-8Gb-3 kamailio[6864]: 1(6883) DEBUG: rr [loose.c:929]: loose_route(): There is no Route HFDec 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=1Dec 15 15:12:02 DNS-enum-8Gb-3 kamailio[6864]: 1(6883) DEBUG: tm [t_lookup.c:485]: matching_3261(): DEBUG: RFC3261 transaction matching failedDec 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 foundDec 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:5060Dec 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)
_______________________________________________ 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