[kamailio/kamailio] Kamailio not retrieving custom or default socket when sending timed REGISTER messages (#2262) - sr-dev

24 Mar 2020

### Description

When using Kamailio in a multi-homed configuration to register with another device using
the uac module, it does not retrieve the custom or default socket information for timed
registration attempts.  It does, however, use the custom/default socket data for the
initial registration.

#### Reproduction

The network is configured for two addresses: 10.9.9.121/24 and 10.9.7.121/24.

Two floating IP addresses are also assigned (via Pacemaker/Corosync): 10.9.9.120/24 and
10.9.7.120/24.  For testing, all addresses can be assigned permanently, so it is not
necessary to have Pacemaker/Corosync installed.

MySQL database has a user in the uacreg table with the socket column set to
udp:10.9.7.120:5060.

kamailio.cfg includes the following to enable sending of REGISTER messages:

mhomed = 1
listen=udp:10.9.9.120
listen=udp:10.9.7.120

#!define DBURL "mysql://kamailio:kamailiorw@10.9.9.101/kamailio"

modparam("rr", "append_fromtag", 1);
modparam("uac", "reg_db_url", DBURL);
modparam("uac", "reg_contact_addr", "10.9.7.120:5060");
modparam("uac", "reg_keep_callid", 1);
modparam("uac", "default_socket", "udp:10.9.7.120:5060");
modparam("uac", "reg_timer_interval", 30);

#### Log Messages

The initial REGISTER outputs the following log data.  The registration completes
successfully.

Mar 24 19:09:27 kam_test kamailio[8425]: DEBUG: uac [uac.c:407]: child_init(): run initial
uac registration routine
Mar 24 19:09:27 kam_test kamailio[8425]: DEBUG: uac [uac_reg.c:1172]: uac_reg_update():
using custom socket udp:10.9.7.120:5060 to send request
Mar 24 19:09:27 kam_test kamailio[8425]: DEBUG: <core> [core/socket_info.c:628]:
grep_sock_info(): checking if host==us: 10==10 && [10.9.7.120] == [10.9.9.120]
Mar 24 19:09:27 kam_test kamailio[8425]: DEBUG: <core> [core/socket_info.c:635]:
grep_sock_info(): checking if port 5060 (advertise 0) matches port 5060
Mar 24 19:09:27 kam_test kamailio[8425]: DEBUG: <core> [core/socket_info.c:628]:
grep_sock_info(): checking if host==us: 10==10 && [10.9.7.120] == [10.9.7.120]
Mar 24 19:09:27 kam_test kamailio[8425]: DEBUG: <core> [core/socket_info.c:635]:
grep_sock_info(): checking if port 5060 (advertise 0) matches port 5060
Mar 24 19:09:27 kam_test kamailio[8425]: DEBUG: tm [uac.c:435]: t_uac_prepare():
next_hop=<sip:10.9.7.102>
Mar 24 19:09:27 kam_test kamailio[8425]: DEBUG: tm [uac.c:158]: dlg2hash(): hashid 3846
Mar 24 19:09:27 kam_test kamailio[8425]: DEBUG: tm [uac.c:244]: t_run_local_req():
executing event_route[tm:local-request]
Mar 24 19:09:27 kam_test kamailio[8425]: DEBUG: <core>
[core/parser/msg_parser.c:610]: parse_msg(): SIP Request:
Mar 24 19:09:27 kam_test kamailio[8425]: DEBUG: <core>
[core/parser/msg_parser.c:612]: parse_msg():  method:  <REGISTER>
Mar 24 19:09:27 kam_test kamailio[8425]: DEBUG: <core>
[core/parser/msg_parser.c:614]: parse_msg():  uri:     <sip:10.9.7.102>
Mar 24 19:09:27 kam_test kamailio[8425]: DEBUG: <core>
[core/parser/msg_parser.c:616]: parse_msg():  version: <SIP/2.0>
Mar 24 19:09:27 kam_test kamailio[8425]: DEBUG: <core>
[core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> =
<z9hG4bK60f.6fd7c907000000000000000000000000.0>; state=16
Mar 24 19:09:27 kam_test kamailio[8425]: DEBUG: <core>
[core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
Mar 24 19:09:27 kam_test kamailio[8425]: DEBUG: <core>
[core/parser/msg_parser.c:498]: parse_headers(): Via found, flags=2
Mar 24 19:09:27 kam_test kamailio[8425]: DEBUG: <core>
[core/parser/msg_parser.c:500]: parse_headers(): this is the first via
Mar 24 19:09:27 kam_test kamailio[8425]: exec: *** cfgtrace:local_route=[tm:local-request]
c=[/usr/local/etc/kamailio/kamailio.cfg] l=229 a=26 n=xlog
Mar 24 19:09:27 kam_test kamailio[8425]: DEBUG: <script>: In
event_route(tm:local-request)
Mar 24 19:09:27 kam_test kamailio[8425]: DEBUG: tm [uac.c:664]:
send_prepared_request_impl(): uac: 0x7268e184  branch: 0  to 10.9.7.102:5060

When the timer expires, the following is logged.  Since the socket is not found, the
registration fails:

Mar 24 19:09:57 kam_test kamailio[8425]: DEBUG: tm [uac.c:435]: t_uac_prepare():
next_hop=<sip:10.9.7.102>
Mar 24 19:09:57 kam_test kamailio[8425]: ERROR: <core> [core/forward.c:181]:
get_out_socket(): no socket found
Mar 24 19:09:57 kam_test kamailio[8425]: ERROR: <core> [core/forward.c:183]:
get_out_socket(): no corresponding socket found for(udp:10.9.7.102:5060)
Mar 24 19:09:57 kam_test kamailio[8425]: ERROR: tm [ut.h:316]: uri2dst2(): no
corresponding socket found for "10.9.7.102" af 2 (udp:10.9.7.102:5060)
Mar 24 19:09:57 kam_test kamailio[8425]: ERROR: tm [uac.c:463]: t_uac_prepare(): no socket
found
Mar 24 19:09:57 kam_test kamailio[8425]: DEBUG: tm [h_table.c:132]: free_cell_helper():
freeing transaction 0x7268de10 from uac.c:604
Mar 24 19:09:57 kam_test kamailio[8425]: ERROR: uac [uac_reg.c:1196]: uac_reg_update():
failed to send request for [kamailioha]

### Additional Information

version: kamailio 5.3.2 (arm6/linux) 
flags: USE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS, USE_RAW_SOCKS, DISABLE_NAGLE, USE_MCAST,
DNS_IP_HACK, SHM_MMAP, PKG_MALLOC, Q_MALLOC, F_MALLOC, TLSF_MALLOC, DBG_SR_MEMORY,
USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR,
USE_DST_BLACKLIST, HAVE_RESOLV_RES, TLS_PTHREAD_MUTEX_SHARED
ADAPTIVE_WAIT_LOOPS 1024, MAX_RECV_BUFFER_SIZE 262144, MAX_URI_SIZE 1024, BUF_SIZE 65535,
DEFAULT PKG_SIZE 8MB
poll method support: poll, epoll_lt, epoll_et, sigio_rt, select.
id: unknown 
compiled on 17:22:05 Mar 18 2020 with gcc 8.3.0

* **Operating System**:

Linux kam_test 4.19.75-v7+ #1270 SMP Tue Sep 24 18:45:11 BST 2019 armv7l GNU/Linux

-- 
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/2262