<p>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.</p>
<p>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).</p>
<p>Due to github not supporting attachments to issues, the sample config and debug log are inline.... :(</p>
<p>DNS entry:</p>
<pre><code>$ 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.
</code></pre>
<p>Log snippet:</p>
<pre lang="syslog"><code>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@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
</code></pre>
<p>Sample config:</p>
<div class="highlight highlight-python"><pre><span class="pl-c">#------------------</span>
<span class="pl-c"># Flags</span>
<span class="pl-c">#------------------</span>
debug<span class="pl-k">=</span><span class="pl-c1">3</span>
memdbg<span class="pl-k">=</span><span class="pl-c1">5</span>
mem_summary<span class="pl-k">=</span><span class="pl-c1">5</span>
<span class="pl-c">#fork=no # This option should not be present to enable forking but disable daemonize, also -D commandline parameter is needed</span>
log_stderror<span class="pl-k">=</span>no
sip_warning<span class="pl-k">=</span>no
listen<span class="pl-k">=</span><span class="pl-c1">172.28</span>.<span class="pl-c1">4.128</span>
port<span class="pl-k">=</span><span class="pl-c1">6789</span>
children<span class="pl-k">=</span><span class="pl-c1">2</span>
shm_mem_size<span class="pl-k">=</span><span class="pl-c1">64</span>
log_name<span class="pl-k">=</span><span class="pl-s"><span class="pl-pds">"</span>UACFailover<span class="pl-pds">"</span></span>
check_via<span class="pl-k">=</span>no <span class="pl-c"># (cmd. line: -v)</span>
dns<span class="pl-k">=</span>no <span class="pl-c"># (cmd. line: -r)</span>
rev_dns<span class="pl-k">=</span>no <span class="pl-c"># (cmd. line: -R)</span>
dns_use_search_list<span class="pl-k">=</span>no
use_dns_failover<span class="pl-k">=</span>yes
dns_srv_lb<span class="pl-k">=</span>yes
disable_tcp<span class="pl-k">=</span>yes
mpath<span class="pl-k">=</span><span class="pl-s"><span class="pl-pds">"</span>/usr/lib/x86_64-linux-gnu/kamailio/modules/<span class="pl-pds">"</span></span>
loadmodule <span class="pl-s"><span class="pl-pds">"</span>pv.so<span class="pl-pds">"</span></span>
loadmodule <span class="pl-s"><span class="pl-pds">"</span>tm.so<span class="pl-pds">"</span></span>
loadmodule <span class="pl-s"><span class="pl-pds">"</span>tmx.so<span class="pl-pds">"</span></span>
loadmodule <span class="pl-s"><span class="pl-pds">"</span>sl.so<span class="pl-pds">"</span></span>
loadmodule <span class="pl-s"><span class="pl-pds">"</span>xlog.so<span class="pl-pds">"</span></span>
loadmodule <span class="pl-s"><span class="pl-pds">"</span>rr.so<span class="pl-pds">"</span></span>
loadmodule <span class="pl-s"><span class="pl-pds">"</span>uac.so<span class="pl-pds">"</span></span>
loadmodule <span class="pl-s"><span class="pl-pds">"</span>rtimer.so<span class="pl-pds">"</span></span>
<span class="pl-c"># -----------------------------------------------------------------</span>
<span class="pl-c"># Module settings</span>
<span class="pl-c"># -----------------------------------------------------------------</span>
modparam(<span class="pl-s"><span class="pl-pds">"</span>pv<span class="pl-pds">"</span></span>, <span class="pl-s"><span class="pl-pds">"</span>varset<span class="pl-pds">"</span></span>, <span class="pl-s"><span class="pl-pds">"</span>server=s:LOGNAME<span class="pl-pds">"</span></span>)
modparam(<span class="pl-s"><span class="pl-pds">"</span>tm<span class="pl-pds">"</span></span>, <span class="pl-s"><span class="pl-pds">"</span>auto_inv_100<span class="pl-pds">"</span></span>, <span class="pl-c1">0</span>)
<span class="pl-c"># Time until provisional response (eg "100 Trying") is received</span>
modparam(<span class="pl-s"><span class="pl-pds">"</span>tm<span class="pl-pds">"</span></span>, <span class="pl-s"><span class="pl-pds">"</span>fr_timer<span class="pl-pds">"</span></span>, <span class="pl-c1">2000</span>)
<span class="pl-c"># Time to await final response on INVITE per branch (eg per branch ring time)</span>
modparam(<span class="pl-s"><span class="pl-pds">"</span>tm<span class="pl-pds">"</span></span>, <span class="pl-s"><span class="pl-pds">"</span>fr_inv_timer<span class="pl-pds">"</span></span>, <span class="pl-c1">10000</span>)
<span class="pl-c"># Time to await final response on INVITE (eg ring time)</span>
modparam(<span class="pl-s"><span class="pl-pds">"</span>tm<span class="pl-pds">"</span></span>, <span class="pl-s"><span class="pl-pds">"</span>max_inv_lifetime<span class="pl-pds">"</span></span>, <span class="pl-c1">20000</span>)
modparam(<span class="pl-s"><span class="pl-pds">"</span>tm<span class="pl-pds">"</span></span>, <span class="pl-s"><span class="pl-pds">"</span>restart_fr_on_each_reply<span class="pl-pds">"</span></span>, <span class="pl-c1">0</span>)
modparam(<span class="pl-s"><span class="pl-pds">"</span>tm<span class="pl-pds">"</span></span>, <span class="pl-s"><span class="pl-pds">"</span>failure_reply_mode<span class="pl-pds">"</span></span>, <span class="pl-c1">3</span>)
modparam(<span class="pl-s"><span class="pl-pds">"</span>rtimer<span class="pl-pds">"</span></span>, <span class="pl-s"><span class="pl-pds">"</span>timer<span class="pl-pds">"</span></span>, <span class="pl-s"><span class="pl-pds">"</span>name=uac;interval=10;mode=1;<span class="pl-pds">"</span></span>)
modparam(<span class="pl-s"><span class="pl-pds">"</span>rtimer<span class="pl-pds">"</span></span>, <span class="pl-s"><span class="pl-pds">"</span>exec<span class="pl-pds">"</span></span>, <span class="pl-s"><span class="pl-pds">"</span>timer=uac;route=TIMER<span class="pl-pds">"</span></span>)
route {
xlog(<span class="pl-s"><span class="pl-pds">"</span>L_NOTICE<span class="pl-pds">"</span></span>, <span class="pl-s"><span class="pl-pds">"</span>[$pr:$si:$sp] [$cs $rm] Request. (cid: $ci <$fu> => <$ru> len: $ml)<span class="pl-pds">"</span></span>);
drop();
}
event_route[tm:local<span class="pl-k">-</span>request] {
xlog(<span class="pl-s"><span class="pl-pds">"</span>L_INFO<span class="pl-pds">"</span></span>, <span class="pl-s"><span class="pl-pds">"</span> [$pr:$si:$sp] [$cs $rm] Request (cid: $ci Branch: $T_branch_idx ToTag: $tt len:$ml) To <$ru> via <$du><span class="pl-pds">"</span></span>);
}
onreply_route {
xlog(<span class="pl-s"><span class="pl-pds">"</span>L_INFO<span class="pl-pds">"</span></span>, <span class="pl-s"><span class="pl-pds">"</span> [$pr:$si:$sp] [$cs $rm] Reply (cid: $ci Branch: $T_branch_idx Status: $rs $rr ToTag: $tt len:$ml)<span class="pl-pds">"</span></span>);
}
route[TIMER] {
<span class="pl-k">if</span> <span class="pl-k">not</span> $var(done) <span class="pl-k">==</span> <span class="pl-c1">1</span> {
$var(done) <span class="pl-k">=</span> <span class="pl-c1">1</span>;
$uac_req(method) <span class="pl-k">=</span> <span class="pl-s"><span class="pl-pds">"</span>OPTIONS<span class="pl-pds">"</span></span>;
$uac_req(ruri) <span class="pl-k">=</span> <span class="pl-s"><span class="pl-pds">"</span>sip:failover.test.speakup.nl<span class="pl-pds">"</span></span>;
$uac_req(furi) <span class="pl-k">=</span> <span class="pl-s"><span class="pl-pds">"</span>sip:from.example.com<span class="pl-pds">"</span></span>;
$uac_req(turi) <span class="pl-k">=</span> <span class="pl-s"><span class="pl-pds">"</span>sip:to.example.com<span class="pl-pds">"</span></span>;
xlog(<span class="pl-s"><span class="pl-pds">"</span>L_INFO<span class="pl-pds">"</span></span>, <span class="pl-s"><span class="pl-pds">"</span>Sending $uac_req(method) request to $uac_req(ruri)<span class="pl-pds">"</span></span>);
uac_req_send();
}
}</pre></div>
<p style="font-size:small;-webkit-text-size-adjust:none;color:#666;">—<br>Reply to this email directly or <a href="https://github.com/kamailio/kamailio/issues/210">view it on GitHub</a>.<img alt="" height="1" src="https://github.com/notifications/beacon/AF36ZV-nTgNeM2zZeQ8Hz3_-M7-PkiRbks5oTn-ZgaJpZM4FDIZI.gif" width="1" /></p>
<div itemscope itemtype="http://schema.org/EmailMessage">
<div itemprop="action" itemscope itemtype="http://schema.org/ViewAction">
<link itemprop="url" href="https://github.com/kamailio/kamailio/issues/210"></link>
<meta itemprop="name" content="View Issue"></meta>
</div>
<meta itemprop="description" content="View this Issue on GitHub"></meta>
</div>