[kamailio/kamailio] Dispatcher destination attribute "socket" does not always work (#1161) - sr-dev

21 Jun 2017

### Description

Dispatcher destination attribute "socket", is not always respected.
Syslog throws:
```
ERROR: <core> [core/socket_info.c:2067]: parse_protohostport(): bad port number in
udp:10.2.10.49:5064
```

### Troubleshooting

#### Reproduction

relevant (I think) kamailio.cfg:
```
listen=udp:127.0.0.1:5060        
listen=udp:10.2.10.49:5060
listen=udp:10.2.10.49:5064
listen=udp:10.2.10.49:5065
listen=udp:10.2.10.49:5066
auto_bind_ipv6=0
auto_aliases=0

modparam("dispatcher", "list_file",
"/opt/kamailio/dispatcher.list")
modparam("dispatcher", "flags", 2)
modparam("dispatcher", "dst_avp", "$avp(ds_dst)")
modparam("dispatcher", "grp_avp", "$avp(ds_grp)")
modparam("dispatcher", "cnt_avp", "$avp(ds_cnt)")
modparam("dispatcher", "dstid_avp", "$avp(ds_dstid)")
modparam("dispatcher", "ds_hash_size", 9)
modparam("dispatcher", "setid_pvname", "$var(ds_setid)")
modparam("dispatcher", "attrs_avp", "$avp(ds_attrs_dst)")
modparam("dispatcher", "attrs_pvname",
"$avp(ds_attrs_from)")
modparam("dispatcher", "sock_avp", "$avp(ds_socket)")
modparam("dispatcher", "ds_default_socket",
"udp:10.2.10.49:5066")
modparam("dispatcher", "ds_ping_method", "OPTIONS")
modparam("dispatcher", "ds_ping_interval", 10)
modparam("dispatcher", "ds_probing_mode", 3)
```

dispatcher.list:
```
3 sip:127.0.0.1:1234;transport=udp 8 0 duid=abc;socket=udp:10.2.10.49:5064;pipe=p10
3 sip:127.0.0.1:1235;transport=udp 8 0 duid=abc;pipe=p10;socket=udp:10.2.10.49:5065
3 sip:127.0.0.1:1236;transport=udp 8 0 duid=abc;pipe=p10
```

Above kamailio.cfg and dispatcher.list demonstrates issue when probing (OPTIONS poll).
I did not test actual request dispatching yet.

#### Log Messages

```
20:26:37 freebsd11 kamailio[31694]: DEBUG: dispatcher [dispatch.c:2660]: ds_ping_set():
probing set #3, URI sip:127.0.0.1:1236;transport=udp
20:26:37 freebsd11 kamailio[31694]: DEBUG: dispatcher [dispatch.c:2674]: ds_ping_set():
>>>--- here2 - using default socket ---<<<
20:26:37 freebsd11 kamailio[31694]: DEBUG: tm [uac.c:988]: request(): request
20:26:37 freebsd11 kamailio[31694]: DEBUG: tm [uac.c:1027]: request():
uac_r->ssock==udp:10.2.10.49:5066
20:26:37 freebsd11 kamailio[31694]: DEBUG: <core> [core/socket_info.c:2077]:
lookup_local_socket(): lookup_local_socket() phostp==udp:10.2.10.49:5066
20:26:37 freebsd11 kamailio[31694]: DEBUG: <core> [core/socket_info.c:1978]:
parse_protohostport(): parse_protohostport ins==udp:10.2.10.49:5066
20:26:37 freebsd11 kamailio[31694]: DEBUG: <core> [core/socket_info.c:2082]:
lookup_local_socket(): lookup_local_socket() grep_sock_info()
20:26:37 freebsd11 kamailio[31694]: DEBUG: <core> [core/socket_info.c:564]:
grep_sock_info(): checking if host==us: 10==9 && [10.2.10.49] == [127.0.0.1]
20:26:37 freebsd11 kamailio[31694]: DEBUG: <core> [core/socket_info.c:567]:
grep_sock_info(): checking if port 5060 (advertise 0) matches port 5066
20:26:37 freebsd11 kamailio[31694]: DEBUG: <core> [core/socket_info.c:564]:
grep_sock_info(): checking if host==us: 10==10 && [10.2.10.49] == [10.2.10.49]
20:26:37 freebsd11 kamailio[31694]: DEBUG: <core> [core/socket_info.c:567]:
grep_sock_info(): checking if port 5060 (advertise 0) matches port 5066
20:26:37 freebsd11 kamailio[31694]: DEBUG: <core> [core/socket_info.c:564]:
grep_sock_info(): checking if host==us: 10==10 && [10.2.10.49] == [10.2.10.49]
20:26:37 freebsd11 kamailio[31694]: DEBUG: <core> [core/socket_info.c:567]:
grep_sock_info(): checking if port 5064 (advertise 0) matches port 5066
20:26:37 freebsd11 kamailio[31694]: DEBUG: <core> [core/socket_info.c:564]:
grep_sock_info(): checking if host==us: 10==10 && [10.2.10.49] == [10.2.10.49]
20:26:37 freebsd11 kamailio[31694]: DEBUG: <core> [core/socket_info.c:567]:
grep_sock_info(): checking if port 5065 (advertise 0) matches port 5066
20:26:37 freebsd11 kamailio[31694]: DEBUG: <core> [core/socket_info.c:564]:
grep_sock_info(): checking if host==us: 10==10 && [10.2.10.49] == [10.2.10.49]
20:26:37 freebsd11 kamailio[31694]: DEBUG: <core> [core/socket_info.c:567]:
grep_sock_info(): checking if port 5066 (advertise 0) matches port 5066
20:26:37 freebsd11 kamailio[31694]: DEBUG: tm [uac.c:427]: t_uac_prepare():
next_hop=<sip:127.0.0.1:1236;transport=udp>
20:26:37 freebsd11 kamailio[31694]: DEBUG: tm [uac.c:152]: dlg2hash(): hashid 37205
20:26:37 freebsd11 kamailio[31694]: DEBUG: tm [uac.c:640]: send_prepared_request_impl():
uac: 0x802572e98  branch: 0  to 127.0.0.1:1236
20:26:37 freebsd11 kamailio[31694]: DEBUG: tm [./../../core/onsend.h:69]: run_onsend():
required parameters are not available - ignoring
20:26:37 freebsd11 kamailio[31694]: DEBUG: dispatcher [dispatch.c:2660]: ds_ping_set():
probing set #3, URI sip:127.0.0.1:1235;transport=udp
20:26:37 freebsd11 kamailio[31694]: DEBUG: dispatcher [dispatch.c:2670]: ds_ping_set():
>>>--- here1 - using destination specific socket ---<<<
20:26:37 freebsd11 kamailio[31694]: DEBUG: tm [uac.c:988]: request(): request
20:26:37 freebsd11 kamailio[31694]: DEBUG: tm [uac.c:1027]: request():
uac_r->ssock==udp:10.2.10.49:5065
20:26:37 freebsd11 kamailio[31694]: DEBUG: <core> [core/socket_info.c:2077]:
lookup_local_socket(): lookup_local_socket() phostp==udp:10.2.10.49:5065
20:26:37 freebsd11 kamailio[31694]: DEBUG: <core> [core/socket_info.c:1978]:
parse_protohostport(): parse_protohostport ins==udp:10.2.10.49:5065
20:26:37 freebsd11 kamailio[31694]: DEBUG: <core> [core/socket_info.c:2082]:
lookup_local_socket(): lookup_local_socket() grep_sock_info()
20:26:37 freebsd11 kamailio[31694]: DEBUG: <core> [core/socket_info.c:564]:
grep_sock_info(): checking if host==us: 10==9 && [10.2.10.49] == [127.0.0.1]
20:26:37 freebsd11 kamailio[31694]: DEBUG: <core> [core/socket_info.c:567]:
grep_sock_info(): checking if port 5060 (advertise 0) matches port 5065
20:26:37 freebsd11 kamailio[31694]: DEBUG: <core> [core/socket_info.c:564]:
grep_sock_info(): checking if host==us: 10==10 && [10.2.10.49] == [10.2.10.49]
20:26:37 freebsd11 kamailio[31694]: DEBUG: <core> [core/socket_info.c:567]:
grep_sock_info(): checking if port 5060 (advertise 0) matches port 5065
20:26:37 freebsd11 kamailio[31694]: DEBUG: <core> [core/socket_info.c:564]:
grep_sock_info(): checking if host==us: 10==10 && [10.2.10.49] == [10.2.10.49]
20:26:37 freebsd11 kamailio[31694]: DEBUG: <core> [core/socket_info.c:567]:
grep_sock_info(): checking if port 5064 (advertise 0) matches port 5065
20:26:37 freebsd11 kamailio[31694]: DEBUG: <core> [core/socket_info.c:564]:
grep_sock_info(): checking if host==us: 10==10 && [10.2.10.49] == [10.2.10.49]
20:26:37 freebsd11 kamailio[31694]: DEBUG: <core> [core/socket_info.c:567]:
grep_sock_info(): checking if port 5065 (advertise 0) matches port 5065
20:26:37 freebsd11 kamailio[31694]: DEBUG: tm [uac.c:427]: t_uac_prepare():
next_hop=<sip:127.0.0.1:1235;transport=udp>
20:26:37 freebsd11 kamailio[31694]: DEBUG: tm [uac.c:152]: dlg2hash(): hashid 37202
20:26:37 freebsd11 kamailio[31694]: DEBUG: tm [uac.c:640]: send_prepared_request_impl():
uac: 0x802572148  branch: 0  to 127.0.0.1:1235
20:26:37 freebsd11 kamailio[31694]: DEBUG: tm [./../../core/onsend.h:69]: run_onsend():
required parameters are not available - ignoring
20:26:37 freebsd11 kamailio[31694]: DEBUG: dispatcher [dispatch.c:2660]: ds_ping_set():
probing set #3, URI sip:127.0.0.1:1234;transport=udp
20:26:37 freebsd11 kamailio[31694]: DEBUG: dispatcher [dispatch.c:2670]: ds_ping_set():
>>>--- here1 - using destination specific socket ---<<<
20:26:37 freebsd11 kamailio[31694]: DEBUG: tm [uac.c:988]: request(): request
20:26:37 freebsd11 kamailio[31694]: DEBUG: tm [uac.c:1027]: request():
uac_r->ssock==udp:10.2.10.49:5064
20:26:37 freebsd11 kamailio[31694]: DEBUG: <core> [core/socket_info.c:2077]:
lookup_local_socket(): lookup_local_socket() phostp==udp:10.2.10.49:5064
20:26:37 freebsd11 kamailio[31694]: DEBUG: <core> [core/socket_info.c:1978]:
parse_protohostport(): parse_protohostport ins==udp:10.2.10.49:5064
20:26:37 freebsd11 kamailio[31694]: DEBUG: <core> [core/socket_info.c:2020]:
parse_protohostport(): B *tmp==;
20:26:37 freebsd11 kamailio[31694]: DEBUG: <core> [core/socket_info.c:2024]:
parse_protohostport(): Y looks like strtol() ran too far
20:26:37 freebsd11 kamailio[31694]: DEBUG: <core> [core/socket_info.c:2026]:
parse_protohostport(): ins->len  : 19
20:26:37 freebsd11 kamailio[31694]: DEBUG: <core> [core/socket_info.c:2027]:
parse_protohostport(): ins->s    : 0x80255fe88
20:26:37 freebsd11 kamailio[31694]: DEBUG: <core> [core/socket_info.c:2028]:
parse_protohostport(): first     : 0x80255fe8b
20:26:37 freebsd11 kamailio[31694]: DEBUG: <core> [core/socket_info.c:2029]:
parse_protohostport(): first+1   : 0x80255fe8c
20:26:37 freebsd11 kamailio[31694]: DEBUG: <core> [core/socket_info.c:2030]:
parse_protohostport(): second    : 0x80255fe96
20:26:37 freebsd11 kamailio[31694]: DEBUG: <core> [core/socket_info.c:2031]:
parse_protohostport(): second+1  : 0x80255fe97
20:26:37 freebsd11 kamailio[31694]: DEBUG: <core> [core/socket_info.c:2032]:
parse_protohostport(): ins s+len : 0x80255fe9b
20:26:37 freebsd11 kamailio[31694]: DEBUG: <core> [core/socket_info.c:2033]:
parse_protohostport(): tmp       : 0x80255fe9b
20:26:37 freebsd11 kamailio[31694]: ERROR: <core> [core/socket_info.c:2067]:
parse_protohostport(): bad port number in udp:10.2.10.49:5064
20:26:37 freebsd11 kamailio[31694]: DEBUG: <core> [core/socket_info.c:2079]:
lookup_local_socket(): lookup_local_socket() return NULL
20:26:37 freebsd11 kamailio[31694]: DEBUG: tm [uac.c:427]: t_uac_prepare():
next_hop=<sip:127.0.0.1:1234;transport=udp>
20:26:37 freebsd11 kamailio[31694]: DEBUG: tm [uac.c:152]: dlg2hash(): hashid 37203
20:26:37 freebsd11 kamailio[31694]: DEBUG: tm [uac.c:640]: send_prepared_request_impl():
uac: 0x8025713f8  branch: 0  to 127.0.0.1:1234
20:26:37 freebsd11 kamailio[31694]: DEBUG: tm [./../../core/onsend.h:69]: run_onsend():
required parameters are not available - ignoring
```

NOTE: above output contains additional debug statements, see below and
77394f06e8349de7565adcc58946da07ee0cf7d7.

#### SIP Traffic

```
$ doas tcpdump -i lo0 -s 0 -n port 5060 or port 5064 or port 5065 or port 5066
tcpdump: verbose output suppressed, use -v or -vv for full protocol decode
listening on lo0, link-type NULL (BSD loopback), capture size 262144 bytes
.
.
.
20:26:37.465870 IP 10.2.10.49.5066 > 127.0.0.1.1236: UDP, length 374
20:26:37.465885 IP 10.2.10.49.5065 > 127.0.0.1.1235: UDP, length 374
20:26:37.465894 IP 10.2.10.49.5060 > 127.0.0.1.1234: SIP: OPTIONS
sip:127.0.0.1:1234;transport=udp SIP/2.0
20:26:37.968876 IP 10.2.10.49.5066 > 127.0.0.1.1236: UDP, length 374
20:26:37.969043 IP 10.2.10.49.5065 > 127.0.0.1.1235: UDP, length 374
20:26:37.969216 IP 10.2.10.49.5060 > 127.0.0.1.1234: SIP: OPTIONS
sip:127.0.0.1:1234;transport=udp SIP/2.0
.
.
.
```

Summary of sent packets:
src port 5066 == listener socket + dispatcher default socket
src port 5065 == listener socket + explicitly set to destination 127.0.0.1:1235
src port 5060 == listener socket, not mentioned in dispatcher config
Probe packets to destination 127.0.0.1:1234 are sent with src port 5060, expected 5064.

### Possible Solutions

Looks like ```strtol(second+1, &tmp, 10)``` in ```core/socket_info.c``` runs too far
because it expects null terminated string but is passed ```char*``` of Kamailio ```str```
struct instead.
Commit 77394f06e8349de7565adcc58946da07ee0cf7d7 tries to highlights this.

### Additional Information

Found initially in stable 5.0.2 with new configuration.
Replicated in master (20a961624bbe164d9120b7c9ac60df8ff1daaae4).

```
version: kamailio 5.1.0-dev4 (x86_64/freebsd)
flags: STATS: Off, USE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS, DISABLE_NAGLE, USE_MCAST,
DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC, Q_MALLOC, F_MALLOC, TLSF_MALLOC,
DBG_SR_MEMORY, FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR,
USE_DST_BLACKLIST, HAVE_RESOLV_RES
ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, MAX_URI_SIZE 1024,
BUF_SIZE 65535, DEFAULT PKG_SIZE 8MB
poll method support: poll, select, kqueue.
id: unknown
compiled on 19:21:12 Jun 21 2017 with clang39 3.9
```

* **Operating System**:

FreeBSD 11

```
$ uname -a
FreeBSD freebsd11 11.0-RELEASE-p9 FreeBSD 11.0-RELEASE-p9 #0: Tue Apr 11 08:48:40 UTC 2017
    root@amd64-builder.daemonology.net:/usr/obj/usr/src/sys/GENERIC  amd64
```

-- 
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/1161