Hi Wim,
Check this:
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*
Maybe is related rrs. Add it to your sipp scenarios.
<!-- By adding rrs="true" (Record Route Sets), the route sets --> <!-- are saved and used for following messages sent. Useful to test --> <!-- against stateful SIP proxies/B2BUAs. --> <recv rrs="true" request="INVITE" crlf="true">
Diego
2016-12-15 11:13 GMT-03:00 Wim Van Cauwenbergh wimvc73@gmail.com:
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@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 <02353%2068-7637> 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@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@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 <02353%2068-7637> 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@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@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 <02353%2068-7637> 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@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@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 <02353%2068-7637> 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@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@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 <02353%2068-7637> 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@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 <02353%2068-7637> 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 http://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@10.57.26.219 1-15698@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 http://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@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@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@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@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@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 <02353%2068-7637> 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@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 <02353%2068-7637> 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)
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