[sr-dev] [kamailio] uac module (uac_req_send, register) doesn't do failover (#210)

Alex notifications at github.com
Mon Jun 15 10:08:57 CEST 2015


Requests send with uac module's functions like uac_req_send() and remote registrations use the TM module, but don't actually do (DNS) failover when a destination is unreachable or sends a 503.

In the tm's uac.c, t_uac_prepare() function, i can already see that the dns handle is stored in a throwaway variable instead of in the transaction, but fixing the issue isn't as simple as just storing it in the transaction (print_uac_request_from_buf() needs a uas in the transaction).

Due to github not supporting attachments to issues, the sample config and debug log are inline.... :(

DNS entry:
```
$ host -t SRV _sip._udp.failover.test.speakup.nl
_sip._udp.failover.test.speakup.nl has SRV record 10 0 1111 try1.test.speakup.nl.
_sip._udp.failover.test.speakup.nl has SRV record 100 0 2222 try2.test.speakup.nl.
```

Log snippet:
```syslog
Jun 15 10:00:03 rio UACFailover[18178]: INFO: <script>: Sending OPTIONS request to sip:failover.test.speakup.nl
Jun 15 10:00:03 rio UACFailover[18178]: DEBUG: tm [uac.c:249]: t_uac_prepare(): DEBUG:tm:t_uac: next_hop=<sip:failover.test.speakup.nl>
Jun 15 10:00:03 rio UACFailover[18178]: DEBUG: <core> [dns_cache.c:537]: _dns_hash_find(): (_sip._udp.failover.test.speakup.nl(34), 33), h=825
Jun 15 10:00:03 rio UACFailover[18178]: DEBUG: <core> [resolve.c:937]: get_record(): skipping 8 NS (p=0x9ea284, end=0x9ea3e9)
Jun 15 10:00:03 rio UACFailover[18178]: DEBUG: <core> [resolve.c:952]: get_record(): parsing 9 ARs (p=0x9ea335, end=0x9ea3e9)
Jun 15 10:00:03 rio UACFailover[18178]: DEBUG: <core> [dns_cache.c:1741]: dns_get_related(): (0x7f225233eb38 (_sip._udp.failover.test.speakup.nl, 33), 33, *0x7f2257baf2b8) (0)
Jun 15 10:00:03 rio UACFailover[18178]: DEBUG: <core> [dns_cache.c:840]: dns_cache_add_unsafe(): adding _sip._udp.failover.test.speakup.nl(34) 33 (flags=0) at 825
Jun 15 10:00:03 rio UACFailover[18178]: DEBUG: <core> [dns_cache.c:840]: dns_cache_add_unsafe(): adding try1.test.speakup.nl(20) 1 (flags=0) at 310
Jun 15 10:00:03 rio UACFailover[18178]: DEBUG: <core> [dns_cache.c:840]: dns_cache_add_unsafe(): adding try2.test.speakup.nl(20) 1 (flags=0) at 307
Jun 15 10:00:03 rio UACFailover[18178]: DEBUG: <core> [dns_cache.c:2336]: dns_srv_get_nxt_rr(): (0x7f225233eb38, 0, 0, 1597643831): selected 0/1 in grp. 0 (rand_w=0, rr=0x7f225233eba0 rd=0x7f225233ebb8 p=10 w=0 rsum=0)
Jun 15 10:00:03 rio UACFailover[18178]: DEBUG: <core> [dns_cache.c:537]: _dns_hash_find(): (try1.test.speakup.nl(20), 1), h=310
Jun 15 10:00:03 rio UACFailover[18178]: DEBUG: <core> [dns_cache.c:2926]: dns_a_resolve(): (try1.test.speakup.nl, 0) returning 0
Jun 15 10:00:03 rio UACFailover[18178]: DEBUG: <core> [dns_cache.c:3169]: dns_srv_resolve_ip(): ("_sip._udp.failover.test.speakup.nl", 0, 0), ret=0, ip=192.168.1.245
Jun 15 10:00:03 rio UACFailover[18178]: DEBUG: <core> [dns_cache.c:3260]: dns_srv_sip_resolve(): (failover.test.speakup.nl, 0, 0), srv0, ret=0
Jun 15 10:00:03 rio UACFailover[18178]: DEBUG: tm [uac.c:150]: dlg2hash(): DEBUG: dlg2hash: 54501
Jun 15 10:00:03 rio UACFailover[18178]: DEBUG: tm [uac.c:351]: t_uac_prepare(): executing event_route[tm:local-request]
Jun 15 10:00:03 rio UACFailover[18178]: DEBUG: <core> [parser/msg_parser.c:606]: parse_msg(): SIP Request:
Jun 15 10:00:03 rio UACFailover[18178]: DEBUG: <core> [parser/msg_parser.c:608]: parse_msg():  method:  <OPTIONS>
Jun 15 10:00:03 rio UACFailover[18178]: DEBUG: <core> [parser/msg_parser.c:610]: parse_msg():  uri:     <sip:failover.test.speakup.nl>
Jun 15 10:00:03 rio UACFailover[18178]: DEBUG: <core> [parser/msg_parser.c:612]: parse_msg():  version: <SIP/2.0>
Jun 15 10:00:03 rio UACFailover[18178]: DEBUG: <core> [parser/parse_via.c:1254]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK5e4d.47adbbf5000000000000000000000000.0>; state=16
Jun 15 10:00:03 rio UACFailover[18178]: DEBUG: <core> [parser/parse_via.c:2642]: parse_via(): end of header reached, state=5
Jun 15 10:00:03 rio UACFailover[18178]: DEBUG: <core> [parser/msg_parser.c:496]: parse_headers(): parse_headers: Via found, flags=2
Jun 15 10:00:03 rio UACFailover[18178]: DEBUG: <core> [parser/msg_parser.c:498]: parse_headers(): parse_headers: this is the first via
Jun 15 10:00:03 rio UACFailover[18178]: DEBUG: <core> [parser/parse_addr_spec.c:894]: parse_addr_spec(): end of header reached, state=10
Jun 15 10:00:03 rio UACFailover[18178]: DEBUG: <core> [parser/msg_parser.c:173]: get_hdr_field(): DEBUG: get_hdr_field: <To> [22]; uri=[sip:to.example.com]
Jun 15 10:00:03 rio UACFailover[18178]: [97B blob data]
Jun 15 10:00:03 rio UACFailover[18178]: DEBUG: <core> [parser/msg_parser.c:153]: get_hdr_field(): get_hdr_field: cseq <CSeq>: <10> <OPTIONS>
Jun 15 10:00:03 rio UACFailover[18178]: DEBUG: pv [pv_core.c:376]: pv_get_xto_attr(): no Tag parameter
Jun 15 10:00:03 rio UACFailover[18178]: INFO: <script>:   [udp:172.28.4.128:6789] [10 OPTIONS] Request (cid: 6cd531e47cc63e20-18178 at 172.28.4.128  Branch: -1  ToTag: <null>  len:382) To <sip:failover.test.speakup.nl> via <sip:failover.test.speakup.nl>
Jun 15 10:00:03 rio UACFailover[18178]: DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil)
Jun 15 10:00:03 rio UACFailover[18178]: DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil)
Jun 15 10:00:03 rio UACFailover[18178]: DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil)
Jun 15 10:00:03 rio UACFailover[18178]: DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil)
Jun 15 10:00:03 rio UACFailover[18178]: DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil)
Jun 15 10:00:03 rio UACFailover[18178]: DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil)
Jun 15 10:00:03 rio UACFailover[18178]: DEBUG: <core> [xavp.c:446]: xavp_destroy_list(): destroying xavp list (nil)


Jun 15 10:00:05 rio UACFailover[18176]: DEBUG: tm [t_reply.c:1230]: t_should_relay_response(): ->>>>>>>>> T_code=0, new_code=408
Jun 15 10:00:05 rio UACFailover[18176]: WARNING: tm [t_reply.c:957]: run_failure_handlers(): Warning: run_failure_handlers: no UAC support (1, 0)
Jun 15 10:00:05 rio UACFailover[18176]: DEBUG: tm [t_reply.c:2016]: local_reply(): DEBUG: local_reply: branch=0, save=0, winner=0
Jun 15 10:00:05 rio UACFailover[18176]: DEBUG: tm [t_reply.c:2053]: local_reply(): DEBUG: local transaction completed
```

Sample config:
```python
#------------------
# Flags
#------------------

debug=3
memdbg=5
mem_summary=5

#fork=no	# This option should not be present to enable forking but disable daemonize, also -D commandline parameter is needed
log_stderror=no
sip_warning=no

listen=172.28.4.128
port=6789
children=2
shm_mem_size=64

log_name="UACFailover"

check_via=no	# (cmd. line: -v)
dns=no          # (cmd. line: -r)
rev_dns=no      # (cmd. line: -R)
dns_use_search_list=no
use_dns_failover=yes
dns_srv_lb=yes
disable_tcp=yes

mpath="/usr/lib/x86_64-linux-gnu/kamailio/modules/"

loadmodule "pv.so"
loadmodule "tm.so"
loadmodule "tmx.so"
loadmodule "sl.so"
loadmodule "xlog.so"
loadmodule "rr.so"
loadmodule "uac.so"
loadmodule "rtimer.so"


# -----------------------------------------------------------------
# Module settings
# -----------------------------------------------------------------

modparam("pv", "varset", "server=s:LOGNAME")

modparam("tm", "auto_inv_100", 0)
# Time until provisional response (eg "100 Trying") is received
modparam("tm", "fr_timer", 2000)
# Time to await final response on INVITE per branch (eg per branch ring time)
modparam("tm", "fr_inv_timer", 10000)
# Time to await final response on INVITE (eg ring time)
modparam("tm", "max_inv_lifetime", 20000)
modparam("tm", "restart_fr_on_each_reply", 0)
modparam("tm", "failure_reply_mode", 3)

modparam("rtimer", "timer", "name=uac;interval=10;mode=1;")
modparam("rtimer", "exec", "timer=uac;route=TIMER")


route {
	xlog("L_NOTICE", "[$pr:$si:$sp] [$cs $rm] Request. (cid: $ci  <$fu> => <$ru>  len: $ml)");

	drop();
}


event_route[tm:local-request] {
	xlog("L_INFO", "  [$pr:$si:$sp] [$cs $rm] Request (cid: $ci  Branch: $T_branch_idx  ToTag: $tt  len:$ml) To <$ru> via <$du>");
}


onreply_route {
	xlog("L_INFO", "  [$pr:$si:$sp] [$cs $rm] Reply (cid: $ci  Branch: $T_branch_idx  Status: $rs $rr  ToTag: $tt  len:$ml)");
}


route[TIMER] {
	if not $var(done) == 1 {
		$var(done) = 1;
		$uac_req(method) = "OPTIONS";
		$uac_req(ruri) = "sip:failover.test.speakup.nl";
		$uac_req(furi) = "sip:from.example.com";
		$uac_req(turi) = "sip:to.example.com";
		xlog("L_INFO", "Sending $uac_req(method) request to $uac_req(ruri)");
		uac_req_send();
	}
}
```

---
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/210
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.sip-router.org/pipermail/sr-dev/attachments/20150615/30a4f07e/attachment.html>


More information about the sr-dev mailing list