[kamailio/kamailio] Wrong Record-Route and Via header fields when TCP is used (#2033)

List overview All Threads
Download

newer

older

[kamailio/kamailio] DNS...

git:5.5:d69c0362: lost:...

leonid-xorcom

15 Aug 2019 15 Aug '19

4: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

Attachments:

attachment.html (text/html — 4.5 KB)

Show replies by date

Daniel-Constantin Mierla

15 Aug 15 Aug

4: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

leonid-xorcom

4: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

Daniel-Constantin Mierla

21 Aug 21 Aug

5: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

leonid-xorcom

10:15 a.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

Daniel-Constantin Mierla

11:49 a.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

leonid-xorcom

22 Aug 22 Aug

6:29 a.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

Daniel-Constantin Mierla

12 Nov 12 Nov

4: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

leonid-xorcom

13 Nov 13 Nov

12: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

leonid-xorcom

15 Nov 15 Nov

5: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@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@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@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@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@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@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@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@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@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@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@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@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@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@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@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@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-2019.zip)

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

Daniel-Constantin Mierla

11 Aug 11 Aug

5: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

Daniel-Constantin Mierla

5: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

leonid-xorcom

6:26 a.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

Christoph Rüdiger

3 May 3 May

7:48 a.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

1409

Age (days ago)

2036

Last active (days ago)

sr-dev@lists.kamailio.org

13 comments

3 participants

tags (0)

participants (3)

Christoph Rüdiger
Daniel-Constantin Mierla
leonid-xorcom