15 Aug
2019
15 Aug
'19
10:05 a.m.
### Description
Kamailio server has two legs that are connected to different networks.
I'm using Kamailio v.5.2.3 and the "enable_double_rr" is implicitly set to
"1".
The leg "A" IP address is 10.28.80.1
The leg "B" IP address is 192.168.9.103
The call is initiated from 10.28.80.47
According to the "rr" module documentation, function record_route()
should insert two "Record_Route" header fields when a request is
accepted on one leg is should go out via the second leg. This works as
expected in case of UDP protocol:
INVITE sip:2601@192.168.0.178:49162;transport=udp SIP/2.0
Record-Route: <sip:192.168.9.103;r2=on;lr;did=e2c.a191>
Record-Route: <sip:10.28.80.1;r2=on;lr;did=e2c.a191>
Via: SIP/2.0/UDP 192.168.9.103;branch=z9hG4bKcfa5.d64ecbd87d5315b5993c4ccf16f86537.0
Via: SIP/2.0/UDP 10.28.80.47:5060;rport=5060;branch=z9hG4bK3a9e9a4d
But when the TCP protocol is used AND "listen" parameters are defined:
listen=udp:10.28.80.1:5060
listen=tcp:10.28.80.1:5060
listen=udp:192.168.9.103:5060
listen=tcp:192.168.9.103:5060
then the outbound message looks like this:
INVITE sip:2601@192.168.0.178:48758;transport=tcp SIP/2.0
Record-Route: <sip:10.28.80.1;transport=tcp;lr;did=bcd.72f>
Via: SIP/2.0/TCP 10.28.80.1;branch=z9hG4bKb9ca.26ea08654c9dbc32bb0dc6e3b6f92d45.0;i=3
Via: SIP/2.0/TCP 10.28.80.47:5060;rport=33976;branch=z9hG4bK5291fab1
There are two problems there:
a) only one Record-Route with leg "A" is inserted
b) the added "Via" header field contains the leg "A" IP address
instead of expected leg "B" IP address (192.168.9.103). In the LAN trace, I see
that in reality the message was sent from leg "B".
IMPORTANT: The problem occurs only when the "listen" parameters are defined in
the Kamailio configuration. When the "listens" are not configured then
everything works correctly.
### Troubleshooting
#### Reproduction
#### Debugging Data
#### Log Messages
http://updates.xorcom.com/~xorcom/kam-tcp-problem.tar.gz
The archive contains the following files:
* syslog-bad.log and bad.cap - Kamailio log and tcpdump trace of a call when the problem
occurs
* syslog-good.log and good.cap - Kamailio log and tcpdump trace of a call when the problem
doesn't occur
#### SIP Traffic
### Possible Solutions
### Additional Information
kamailio -v
version: kamailio 5.2.3 (x86_64/linux)
flags: STATS: Off, USE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS, USE_RAW_SOCKS, DISABLE_NAGLE,
USE_MCAST, DNS_IP_HACK, SHM_MEM, 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
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 with gcc 7.3.0
***Operating System**:
Ubuntu 18.0.4
--
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/2033
15 Aug
15 Aug
10:12 a.m.
Now that I see the order of listen and what is in via/record-route -- can you change the
order of listen parameter to IP for leg B first and test to see the result? Like:
```
listen=tcp:192.168.9.103:5060
listen=tcp:10.28.80.1:5060
```
Like I said on the sr-users, my guess is that the OS finds an IP route from the local
A-leg IP towards B.
Is mhomed=1 (or yes) in your config? I don't recall if I asked on mailing list.
--
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/2033#issuecomment-521555816
10:46 a.m.
Bingo! It works correct once I reversed the 'listen' parameters order as you
suggested:
```
INVITE sip:2601@192.168.0.178:47566;transport=tcp SIP/2.0
Record-Route: <sip:192.168.9.103;transport=tcp;r2=on;lr;did=18b.c921>
Record-Route: <sip:10.28.80.1;transport=tcp;r2=on;lr;did=18b.c921>
Via: SIP/2.0/TCP 192.168.9.103;branch=z9hG4bK25a.491f2e3a37e082ce56aae708a46851e9.0;i=3
Via: SIP/2.0/TCP 10.28.80.47:5060;rport=49394;branch=z9hG4bK2cde1541
```
But, obviously, the same problem appears for calls in the opposite direction:
```
INVITE sip:2600@cust1.cpbxmt3.in.xorcom.com SIP/2.0
Record-Route: <sip:192.168.9.103;transport=tcp;lr;did=30f.9df1>
Via: SIP/2.0/TCP 192.168.9.103;branch=z9hG4bKb8cf.41e31318f7016a84b9f0615135a326b8.0;i=1
Via: SIP/2.0/TCP 192.168.0.178;received=192.168.0.178;rport=47566;branch=z9hG4bKikbzlczg
````
I have mhomed=1 in my configuration.
--
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/2033#issuecomment-521565159
21 Aug
21 Aug
11:29 a.m.
Can you try with latest master branch? There were couple of commits related to connection
match and maybe they help here as well. You have to set a new core parameter:
```
tcp_connection_match=1
```
--
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/2033#issuecomment-523377004
4:15 p.m.
I just tried the current master (commit: 4efe19f64d8).
I see that the request is not sent out by Kamailio at all.
tcpdump and syslog: http://updates.xorcom.com/~xorcom/tcp-4efe19f64d8.tar.gz
Ref. OPTIONS request (packet 67 in the tcpdump-4efe19f64d8.cap, line 2869 in
syslog-4efe19f64d8)
The expected path: Asterisk (10.28.80.47) ->
Kamailio(10.28.80.47)--Kamailio(192.168.9.103)->SIPPhone(192.168.0.178)
In reality, the message is accepted by Kamailio at 10.28.80.47 and not set out.
Like in v. 5.2, the messages are forwarded correctly if I remove the 'listen'
parameters.
Kamailio configuration:
```
tcp_connection_match=1
mhomed=1
listen=udp:10.28.80.1:5060
listen=udp:192.168.9.103:5060
listen=tcp:10.28.80.1:5060
listen=tcp:192.168.9.103:5060
```
IP configuration:
```
2: ens32: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc fq_codel state UP group
default qlen 1000
link/ether 00:0c:29:ad:af:e9 brd ff:ff:ff:ff:ff:ff
inet 192.168.9.103/20 brd 192.168.15.255 scope global dynamic ens32
3: lxdbr0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue state UP group
default qlen 1000
link/ether fe:16:11:59:92:19 brd ff:ff:ff:ff:ff:ff
inet 10.28.80.1/24 scope global lxdbr0
```
```
# ip r
default via 192.168.0.1 dev ens32 proto dhcp src 192.168.9.103 metric 100
10.28.80.0/24 dev lxdbr0 proto kernel scope link src 10.28.80.1
192.168.0.0/20 dev ens32 proto kernel scope link src 192.168.9.103
192.168.0.1 dev ens32 proto dhcp scope link src 192.168.9.103 metric 100
```
--
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/2033#issuecomment-523476197
5:49 p.m.
If you try with `tcp_connection_match=0`, does it work?
--
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/2033#issuecomment-523519983
22 Aug
22 Aug
12:29 p.m.
It also doesn't work.
So, it looks like that the presence of the 'listen' parameters only affects the
Kamailio behavior. According to the LAN traces, when the "listen" parameters are
NOT defined then Kamailio uses an "old" existing TCP connection.
For example:
```
Endpoint sends a REGISTER request:
EP(IP1:P1) -->Kamalio(IP2:5060), Kamalio(IP3:P2) -->Asterisk(IP4:5060)
Asterisk creates a new TCP connection and sends OPTIONS.
EP(IP1:P1) <--Kamailio(IP2:5060), Kamailio(IP3:5060) <--Asterisk(IP4:P3)
```
where P1, P2, and P3 are the dynamically allocated IP ports.
When the "listen" parameters are defined I see something like that:
```
REGISTER:
EP(IP1:P1) -->Kamalio(IP2:5060), Kamailio(IP3:P2) -->Asterisk(IP4:5060)
Asterisk creates a new TCP connection and sends OPTIONS. Kamailio
tries to create a new connection to EP(IP1:P1) and fails to do it because
P1 is a dynamically allocated port and nobody is listening on it.
EP(IP1:P1) X<--Kamalio(IP2:P4), Kamalio(IP3:5060) <--Asterisk(IP4:P3)
```
--
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/2033#issuecomment-523846489
12 Nov
12 Nov
10:36 p.m.
Back to this one, somehow it got on the side with busy end of summer and autumn ...
I tried to reproduce, but I couldn't get the same result. In my case it worked fine
with the current master branch. I made the following minimal config:
```
#!KAMAILIO
debug=3
children=4
mhomed=1
listen=tcp:192.168.56.1:5060
listen=tcp:127.0.0.1:5060
loadmodule "tm.so"
loadmodule "sl.so"
loadmodule "corex.so"
loadmodule "pv.so"
loadmodule "textops.so"
loadmodule "rr.so"
request_route {
if(is_method("INVITE")) {
record_route();
}
$du = "sip:192.168.56.1:5080;transport=tcp";
t_relay();
}
```
The INVITE was sent to 127.0.0.1:5060 and the outgoing one from kamailio had two
Record-Route headers:
```
INVITE sip:test@kamailio.org SIP/2.0
Record-Route:
<sip:192.168.56.1;transport=tcp;r2=on;lr;ftag=76ff7a07-c091-4192-84a0-d56e91fe104f>
Record-Route:
<sip:127.0.0.1;transport=tcp;r2=on;lr;ftag=76ff7a07-c091-4192-84a0-d56e91fe104f>
Via: SIP/2.0/TCP 192.168.56.1;branch=z9hG4bKac3f.6b055b9438495fd0fb5e6b08f07611d5.0;i=1
Via: SIP/2.0/UDP
192.168.178.8:5040;received=127.0.0.1;branch=z9hG4bKac3fd.jasefjsdfas;rport=54075
```
I also changed the order of listen parameters and the same result with two record-route
headers.
Can you test again with latest master and see if you get the same result like in the past?
If yes, are the two IP addresses assigned to different network interfaces/cards, or they
are assigned to the same network interface?
--
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/2033#issuecomment-553126580
13 Nov
13 Nov
6:58 a.m.
Thank you for following up.Regarding my server networking configuration. This is an LXD
server where Kamailio and rtpproxy are running on the host and several containers with
Asterisk. The Asterisks are running behind of lxdbr0 NAT. This is an example of server
configuration:
```
3: eno1: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc fq_codel state UP group
default qlen 1000
link/ether 0c:c4:7a:92:5c:f4 brd ff:ff:ff:ff:ff:ff
inet 192.168.0.31/20 brd 192.168.15.255 scope global eno1
valid_lft forever preferred_lft forever
4: lxdbr0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue state UP group
default qlen 1000
link/ether fe:5c:a5:12:c9:09 brd ff:ff:ff:ff:ff:ff
inet 10.159.65.1/24 scope global lxdbr0
valid_lft forever preferred_lft forever
inet6 fd42:b153:24b2:77aa::1/64 scope global
valid_lft forever preferred_lft forever
inet6 fe80::248c:4cff:fe69:8ca9/64 scope link
valid_lft forever preferred_lft forever
8: veth7JRSU0@if7: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue master
lxdbr0 state UP group default qlen 1000
link/ether fe:7e:6e:b6:39:3a brd ff:ff:ff:ff:ff:ff link-netnsid 1
inet6 fe80::fc7e:6eff:feb6:393a/64 scope link
valid_lft forever preferred_lft forever
```
So, sometimes I have to define 'listen' parameters. For example, when it is
necessary to configure the advertised address.
Anyway, in order to reproduce the problem I define something like this:
```
listen=udp:10.159.65.1:5060
listen=tcp:10.159.65.1:5060
listen=udp:192.168.0.31:5060
listen=tcp:192.168.0.31:5060
```
I'll check the latest branch during the next couple of days.
Thank you again.
Leonid
--
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/2033#issuecomment-553252588
15 Nov
15 Nov
11:29 a.m.
The situation with the latest master is worse than it is with 5.2.
My setup is:
```
listen=udp:10.28.80.1:5060
listen=udp:192.168.9.103:5060
listen=tcp:10.28.80.1:5060
listen=tcp:192.168.9.103:5060
```
192.168.0.185 (2600) sends UDP call to Kamalio (192.168.9.103:5060). Ref. packet 94 in the
tcp2.cap. Kamalio forwards the call via its udp:10.28.80.1:5060 to Asterisk
(10.28.80.47).
Asterisk initiates a new, this time TCP, call and sends INVITE to Kamailio
(tcp:10.28.80.1:5060). ref. packet 100 in tcp2.cap. This INVITE is not sent out from
Kamailio. I guess that the following Kamailio debug log excerpt is relevant:
```
Nov 15 11:25:23 cpbxmt3 kamailio[16720]: 25(16762) DEBUG: {1 102 INVITE
65d0b7876b68ef072f152fc210456690(a)cust1.cpbxmt3.in.xorcom.com} <core>
[core/msg_translator.c:161]: check_via_address(): (10.28.80.47, 10.28.80.47, 0)
Nov 15 11:25:23 cpbxmt3 kamailio[16720]: 25(16762) DEBUG: {1 102 INVITE
65d0b7876b68ef072f152fc210456690(a)cust1.cpbxmt3.in.xorcom.com} <core>
[core/tcp_main.c:2060]: tcp_send(): no open tcp connection found, opening new one
Nov 15 11:25:23 cpbxmt3 kamailio[16720]: 25(16762) DEBUG: {1 102 INVITE
65d0b7876b68ef072f152fc210456690(a)cust1.cpbxmt3.in.xorcom.com} <core>
[core/ip_addr.c:229]: print_ip(): tcpconn_new: new tcp connection: 192.168.0.178
Nov 15 11:25:23 cpbxmt3 kamailio[16720]: 25(16762) DEBUG: {1 102 INVITE
65d0b7876b68ef072f152fc210456690(a)cust1.cpbxmt3.in.xorcom.com} <core>
[core/tcp_main.c:1242]: tcpconn_new(): on port 35762, type 2
Nov 15 11:25:23 cpbxmt3 kamailio[16720]: 25(16762) DEBUG: {1 102 INVITE
65d0b7876b68ef072f152fc210456690(a)cust1.cpbxmt3.in.xorcom.com} <core>
[core/tcp_main.c:1561]: tcpconn_add(): hashes: 2694:1565:0, 5
Nov 15 11:25:23 cpbxmt3 kamailio[16720]: 25(16762) DEBUG: {1 102 INVITE
65d0b7876b68ef072f152fc210456690(a)cust1.cpbxmt3.in.xorcom.com} <core>
[core/tcp_main.c:2954]: tcpconn_1st_send(): pending write on new connection 0x7fa0dd7c9170
(-1/1093 bytes written) (err: 11 - Resource temporarily unavailable)
Nov 15 11:25:23 cpbxmt3 kamailio[16720]: 30(16769) DEBUG: <core>
[core/tcp_main.c:3858]: handle_ser_child(): read response= 7fa0dd7c9170, 5, fd 51 from 25
(16762)
Nov 15 11:25:23 cpbxmt3 kamailio[16720]: 30(16769) DEBUG: <core>
[core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0x55b9805f5360, 51, 2,
0x7fa0dd7c9170), fd_no=41
Nov 15 11:25:23 cpbxmt3 kamailio[16720]: 25(16762) DEBUG: {1 102 INVITE
65d0b7876b68ef072f152fc210456690(a)cust1.cpbxmt3.in.xorcom.com} tm [t_funcs.c:374]:
t_relay_to(): new transaction forwarded
Nov 15 11:25:23 cpbxmt3 kamailio[16720]: 25(16762) DEBUG: {1 102 INVITE
65d0b7876b68ef072f152fc210456690(a)cust1.cpbxmt3.in.xorcom.com} <core>
[core/receive.c:438]: receive_msg(): request-route executed in: 2156 usec
Nov 15 11:25:23 cpbxmt3 kamailio[16720]: 25(16762) DEBUG: {1 102 INVITE
65d0b7876b68ef072f152fc210456690(a)cust1.cpbxmt3.in.xorcom.com} dialog [dlg_hash.c:784]:
dlg_lookup(): ref dlg 0x7fa0dd7c5558 with 1 -> 2
Nov 15 11:25:23 cpbxmt3 kamailio[16720]: 25(16762) DEBUG: {1 102 INVITE
65d0b7876b68ef072f152fc210456690(a)cust1.cpbxmt3.in.xorcom.com} dialog [dlg_hash.c:786]:
dlg_lookup(): dialog id=8359 found on entry 2880
Nov 15 11:25:23 cpbxmt3 kamailio[16720]: 25(16762) DEBUG: {1 102 INVITE
65d0b7876b68ef072f152fc210456690(a)cust1.cpbxmt3.in.xorcom.com} dialog [dlg_hash.c:1029]:
dlg_unref_helper(): unref op on 0x7fa0dd7c5558 with 1 from dlg_hash.c:1047
Nov 15 11:25:23 cpbxmt3 kamailio[16720]: 25(16762) DEBUG: {1 102 INVITE
65d0b7876b68ef072f152fc210456690(a)cust1.cpbxmt3.in.xorcom.com} dialog [dlg_hash.c:1033]:
dlg_unref_helper(): unref dlg 0x7fa0dd7c5558 with 1 -> 1
Nov 15 11:25:23 cpbxmt3 kamailio[16720]: 25(16762) DEBUG: {1 102 INVITE
65d0b7876b68ef072f152fc210456690(a)cust1.cpbxmt3.in.xorcom.com} <core>
[core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Nov 15 11:25:23 cpbxmt3 kamailio[16720]: message repeated 5 times: [ 25(16762) DEBUG: {1
102 INVITE 65d0b7876b68ef072f152fc210456690(a)cust1.cpbxmt3.in.xorcom.com} <core>
[core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)]
Nov 15 11:25:23 cpbxmt3 kamailio[16720]: 25(16762) DEBUG: {1 102 INVITE
65d0b7876b68ef072f152fc210456690(a)cust1.cpbxmt3.in.xorcom.com} <core>
[core/xavp.c:517]: xavp_destroy_list(): destroying xavp list (nil)
Nov 15 11:25:23 cpbxmt3 kamailio[16720]: 25(16762) DEBUG: {1 102 INVITE
65d0b7876b68ef072f152fc210456690(a)cust1.cpbxmt3.in.xorcom.com} <core>
[core/receive.c:529]: receive_msg(): cleaning up
Nov 15 11:25:23 cpbxmt3 kamailio[16720]: 30(16769) DEBUG: <core>
[core/io_wait.h:599]: io_watch_del(): DBG: io_watch_del (0x55b9805f5360, 51, -1, 0x10)
fd_no=42 called
Nov 15 11:25:23 cpbxmt3 kamailio[16720]: 30(16769) ERROR: <core>
[core/tcp_main.c:4462]: handle_tcpconn_ev(): connect 192.168.0.178:35762 failed
```
The destination IP:port (192.168.0.178:35762) is actually source IP addres:port of 2601.
This is a softphone that was registered from this addr/port. The TCP connection was
existing when Kamailio tried to send there the INVITE.
I am attaching all of the configuration and log files.
When I run Kamailio 5.2.2 on the same server and with the same configuration then the call
is created but with the Record-Route problem.
[15-nov-2019.zip](https://github.com/kamailio/kamailio/files/3851031/15-nov-…
--
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/2033#issuecomment-554305345
11 Aug
11 Aug
11:56 a.m.
There were couple of enhancements done lately to listening sockets, among them the ability
to associate names, so one can enforce sending socket by name and record route will also
take that in cosideration.
If this issue is still not solved, then open a new item here with data collected from
Kamailio 5.4 or master branch.
--
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/2033#issuecomment-671850328
11:56 a.m.
Closed #2033.
--
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/2033#event-3642376652
12:26 p.m.
Yes, I have solved the problem by using $fs.
--
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/2033#issuecomment-671864731
3 May
3 May
1:48 p.m.
I'm having the exact same issue. May I ask how you solved the problem with $fs? I have
tried with force_send_socket() but haven't been able to resolve it.
--
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/2033#issuecomment-831208439
1088
days inactive
1715
days old
13 comments
3 participants
participants (3)
-
Christoph Rüdiger -
Daniel-Constantin Mierla
-
leonid-xorcom