[BUG] Test ReuseAddr.ProtocolVersion fails

[yurivict]

218/218 Test #218: ReuseAddr.ProtocolVersion ...........................Subprocess aborted***Exception:   3.14 sec
Running main() from /disk-samsung/freebsd-ports/www/srt/work/.build/googletest/googletest-src/googletest/src/gtest_main.cc
Note: Google Test filter = ReuseAddr.ProtocolVersion
[==========] Running 1 test from 1 test case.
[----------] Global test environment set-up.
[----------] 1 test from ReuseAddr
[ RUN      ] ReuseAddr.ProtocolVersion
Bind to: :::5000
Connecting to: ::1:5000
Accepted from: ::1:15601
Client exit
Server exit
Bind to: 0.0.0.0:5000
Connecting to: 127.0.0.1:5000
srt_connect: Connection setup failure: connection timed out
/disk-samsung/freebsd-ports/www/srt/work/srt-1.5.0/test/test_reuseaddr.cpp:179: Failure
Expected: (connect_res) != (-1), actual: -1 vs -1
/disk-samsung/freebsd-ports/www/srt/work/srt-1.5.0/test/test_reuseaddr.cpp:267: Failure
Expected: (srt_epoll_wait(server_pollid, read, &rlen, write, &wlen, 3000, 0, 0, 0, 0)) != (SRT_ERROR), actual: -1 vs -1

Version: 1.5.0
clang-13
FreeBSD 13.1

[ethouris]

Do you run it maybe on the docker?

[yurivict]

No.

[ethouris]

Ok, so are you sure that on your machine you can send a UDP packet addressing 127.0.0.1:5000 while another application is trying to read from a socket bound to 0.0.0.0:5000?

[yurivict]

UDP should be allowed. I am running on a regular system.

[ethouris]

What I can see here is that this machine is able to establish a connection using UDP IPv6, but not UDP IPv4.

In particular: you can connect to ::1:5000 by having a socket bound to :::5000 (which is "in-addr any" for IPv6).

But there seems to be a problem to send a packet to 127.0.0.1:5000 with having a socket bound to 0.0.0.0:5000 (which also should use "in-addr any" for IPv4). That's why I'm asking if you can test on this machine first to send a UDP packet to the 127.0.0.1:5000 endpoint and whether it's properly received - just to rule out a possibility that the problem is in your system. Something like this:

// (sockaddr_any is in srtcore/netinet_any.h, CreateAddr in apps/apputil.hpp, defined in apps/apputil.cpp)

sockaddr_any local = CreateAddr("", 5000);
sockaddr_any remote = CreateAddr("127.0.0.1", 5000);

int sout = socket(AF_INET, SOCK_DGRAM, 0);
int sin = socket(AF_INET, SOCK_DGRAM, 0);

bind(sin, local.get(), local.size());

const char* text = "Example text";
sendto(sout, text, sizeof(text), 0, remote.get(), remote.size());

char output[101];
memset(output, 0, sizeof output);
sockaddr_any from(AF_INET);
int n = recvfrom(sin,output, 100, 0, from.get(), &sa.syslen());
cout << output << endl;

If everything is ok, then your program should print "Example text" immediately. If it hangs forever, there's a problem.

[yurivict]

This program:

#include "srtcore/netinet_any.h"
#include "apps/apputil.hpp"

using namespace std;
using namespace srt;


int main() {

// (sockaddr_any is in srtcore/netinet_any.h, CreateAddr in apps/apputil.hpp, defined in apps/apputil.cpp)

sockaddr_any local = CreateAddr("", 5000);
sockaddr_any remote = CreateAddr("127.0.0.1", 5000);

int sout = socket(AF_INET, SOCK_DGRAM, 0);
int sin = socket(AF_INET, SOCK_DGRAM, 0);

bind(sin, local.get(), local.size());

const char* text = "Example text";
sendto(sout, text, sizeof(text), 0, remote.get(), remote.size());

char output[101];
memset(output, 0, sizeof output);
sockaddr_any from(AF_INET);
int n = recvfrom(sin,output, 100, 0, from.get(), &sa.syslen());
cout << output << endl;


}

fails:

test.cpp:27:51: error: use of undeclared identifier 'sa'
int n = recvfrom(sin,output, 100, 0, from.get(), &sa.syslen());
                                                  ^

[ethouris]

Sorry, that sa should be from - the same thing as used in the previous parameter. Just copied it blindly from the example code, sorry.

[yurivict]

The testcase hangs both on my machine and on another machine in the FreeBSD network.

What would be an equivalent testcase based on installed srt, so that I would be able to create a testcase for someone in FreeBSD to look into?

For some reason the installed srt.h doesn't define the srt namespace.

[ethouris]

srt.h is a C header so it can't define anything for C++ (it actually does, but only some fragments that might refer to incorrect backward compatibility cases for C++).

I found one more error - the text variable should be const char text [], not const char* text - otherwise it takes the size 4 from the pointer and displays only first 4 characters. Still, on my machine (Windows/Cygwin actually, but same should be on Linux) it exits immediately and prints this text.

If it doesn't work on your machine, you have something wrong in the firewall settings, or some weird network settings. Binding to address 0.0.0.0 should bind on "any interface", including localhost.

I made it using some utils from this library, but you can translate this example to something that is only system-header dependent:

• Replace sockaddr_any with sockaddr_in (include <netinet/in.h>) and remember to cast to sockaddr* when passing to a function, taking the size of it properly etc.
• replace CreateAddr with inet_pton (include <arpa/inet.h>), which works the same way if you specify the name by the IPv4 address spec

I also suspect you may try to do the same kind of test on TCP - just set up some service on a given port (without address to bind, or with address 0) and try to connect to this via telnet using 127.0.0.1:PORT endpoint.

[yurivict]

I rewrote the example in low-level API and it works fine on FreeBSD:

#include <netinet/in.h>
#include <arpa/inet.h>
#include <sys/socket.h>
#include <stdio.h>
#include <string.h>

#define PORT 15000

int main() {
        int res;

        // addrs
        sockaddr_in local, remote;

        ::memset(&local, 0, sizeof(local));
        local.sin_family = AF_INET;
        local.sin_port = htons(PORT);
        local.sin_addr.s_addr = inet_addr("0.0.0.0");

        ::memset(&remote, 0, sizeof(remote));
        remote.sin_family = AF_INET;
        remote.sin_port = htons(PORT);
        remote.sin_addr.s_addr = inet_addr("127.0.0.1");

        // sockets
        int sout = socket(AF_INET, SOCK_DGRAM, 0);
        int sin = socket(AF_INET, SOCK_DGRAM, 0);
        printf("sockets: sout=%d sin=%d\n", sout, sin);

        // bind
        if (bind(sin, (sockaddr*)&local, sizeof(local)) == -1) {
                perror("bind()");
                return 1;
        }

        // send
        const char* text = "Example text";
        if ((res = sendto(sout, text, strlen(text), 0, (sockaddr*)&remote, sizeof(remote))) != strlen(text)) {
                if (res >= 0)
                        printf("short write: %d of %zu\n", res, strlen(text));
                else
                        perror("sendto()");
                return 1;
        }

        // recv
        char output[101];
        memset(output, 0, sizeof output);
        sockaddr_in from;
        socklen_t len = 0;
        int n = recvfrom(sin, output, 100, 0, (sockaddr*)&from, &len);
        printf("received: %s\n", output);
}

There's something wrong in the srt code or in the test code that causes this test to fail.

[ethouris]

Ok, so let's take a look inside then. Please add in this test's function, after the line containing srt_startup() the following:

  srt_setloglevel(LOG_DEBUG);

Then run only this one test and send back the logs. Please recompile clean and use options: --enable-debug --enable-unittests --enable-heavy-logging. Here is the key part that you should see in the logs (especially this line with INCOMING PACKET):

Connecting to: 127.0.0.1:5000
20:10:09.913716/test-srt D:SRT.cn: clearData: PAYLOAD SIZE: 1456
20:10:09.913749/test-srt D:SRT.sm: bind: muxer @236459340 found, but for port 49891 (requested port: 0)
20:10:09.913773/test-srt D:SRT.sm: bind: muxer @236459341 found, but for port 5000 (requested port: 0)
20:10:09.913827/test-srt D:SRT.km: CHANNEL: Bound to local address: 0.0.0.0:0
20:10:09.914085/test-srt D:SRT.sm: bind: creating new multiplexer for port 38526
20:10:09.914113/test-srt D:SRT.ac: @236459337:startConnect: -> 127.0.0.1:5000 (SYNCHRONOUS)...
20:10:09.914146/test-srt D:SRT.cn: registerConnector: adding @236459337 addr=127.0.0.1:5000 TTL=10:31:39.446883 [STDY]
20:10:09.914184/test-srt D:SRT.cn: RID: adding socket @236459337 for address: 127.0.0.1:5000 expires: 10:31:39.446883 [STDY] (total connectors: 1)
20:10:09.914224/test-srt D:SRT.ac: startConnect: ISN generated = 762703782
20:10:09.914254/test-srt D:SRT.cn: @236459337:CUDT::startConnect: REQ-TIME set HIGH (TimeStamp: 512). SENDING HS: version=4 type=0x2 ISN=762703782 MSS=1500 FLW=8192 reqtype=induction srcID=236459337 cookie=0 srcIP=127.0.0.1.0.0.0.0.0.0.0.0.0.0.0.0.
20:10:09.914294/test-srt D:SRT.ks: CChannel::sendto: SENDING NOW DST=127.0.0.1:5000 target=@0 size=48 pkt.ts=512 TARGET=@0 CONTROL: size=48 type=handshake HS: version=4 type=0x2 ISN=762703782 MSS=1500 FLW=8192 reqtype=induction srcID=236459337 cookie=0 srcIP=127.0.0.1.0.0.0.0.0.0.0.0.0.0.0.0.
20:10:09.914420/test-srt D:SRT.cn: startConnect: LOOP: too early to send - 0 < 250ms
20:10:09.914427/SRT:RcvQ:w1 D:SRT.qr: INCOMING PACKET: FROM=::ffff:127.0.0.1:38526 BOUND=:::5000 TARGET=@0 CONTROL: size=48 type=handshake HS: version=4 type=0x2 ISN=762703782 MSS=1500 FLW=8192 reqtype=induction srcID=236459337 cookie=0 srcIP=127.0.0.1.0.0.0.0.0.0.0.0.0.0.0.0.
20:10:09.914498/SRT:RcvQ:w1 D:SRT.cn: Got sockID=0 from ::ffff:127.0.0.1:38526 - trying to resolve it as a connection request...
20:10:09.914534/SRT:RcvQ:w1.N:SRT.cn: PASSING request from: ::ffff:127.0.0.1:38526 to agent:236459338
20:10:09.914565/SRT:RcvQ:w1 D:SRT.cn: processConnectRequest: received a connection request

[yurivict]

I've built using cmake with Debug build type and with HEAVY_LOGGING=ON but the log didn't become more detailed:

[ RUN      ] ReuseAddr.ProtocolVersion
Bind to: :::5000
Connecting to: ::1:5000
Accepted from: ::1:48567
Client exit
Server exit
Bind to: 0.0.0.0:5000
Connecting to: 127.0.0.1:5000
/disk-samsung/freebsd-ports/www/srt/work/srt-1.5.0/test/test_reuseaddr.cpp:267: Failure
Expected: (srt_epoll_wait(server_pollid, read, &rlen, write, &wlen, 3000, 0, 0, 0, 0)) != (SRT_ERROR), actual: -1 vs -1
<end of output>
Test time =   3.14 sec
----------------------------------------------------------
Test Failed.

[ethouris]

If you use cmake, then use options: -DENABLE_DEBUG=1 -DENABLE_HEAVY_LOGGING=1 -DENABLE_UNITTESTS=1. And remember to compile cleanly, incremental compiling may not always work.

[yurivict]

With all these flags set the log still lacks details.
See the complete build/test log here.

[ethouris]

Did you modify the test_reuseaddr.cpp file as instructed, that is added this call after the line containing srt_startup() call?

  srt_setloglevel(LOG_DEBUG);

[yurivict]

Here is log with details.

[ethouris]

Ok, I think I can guess where the problem can be. What's your default value of the IPV6_V6ONLY option on a newly created UDP socket?

I made another mistake when creating this example program. Local binding should not be for an empty string "", but for "::" (and in the "indepepdent" version you should use sockaddr_in6 type). That is, it should be bound as "inaddr-any IPv6". Only then will it replicate things happening on the UDP level in this SRT test.

If there really happens what I think it does, then please try modifying the serverSocket function, about line 226, you have two socket options already there. Add another one, to SRTO_IPV6ONLY to the value of no, and tell me if this helped.

As an explanation per IPV6_V6ONLY option we simply don't set its value in SRT and rely on what is default in the system. By setting this option (SRTO_IPV6ONLY) you request to set this option to a certain value.

[ethouris]

@maxsharabayko I think the procedure for binding check is wrong.

if (m.m_mcfg.iIpV6Only != -1 && m.m_mcfg.iIpV6Only != cfgSocket.iIpV6Only)

The problem is that this finds a nonexistent conflict between a multiplexer bound to an IPv4 any address and IPv6 any address while these sockets have different settings of SRTO_IPV6ONLY option.

[maxsharabayko]

In the ReuseAddr.ProtocolVersion unit test first IPv6 connection to host :: port 5000 is being checked (serverSocket("::", 5000, true);).
A listener is created, the connection is established, and a sample transmission is performed.
In your case, @yurivict, IPv6 check passes.

Then IPv4 connection is being checked. Listener SRT socket is bound to host 0.0.0.0 and port 5000 ( serverSocket("0.0.0.0", 5000, true);). From the heavy logs you have submitted, we see that the existing multiplexer created for IPv6 ANY is being reused.

Bind to: 0.0.0.0:5000
08:37:01.134689/T0x801212000 D:SRT.cn: clearData: PAYLOAD SIZE: 1456
08:37:01.134717/T0x801212000 D:SRT.sm: bind: muxer @960033269 found, but for port 26054 (requested port: 5000)
08:37:01.134751/T0x801212000 D:SRT.sm: bind: Found existing muxer @960033270 : :::5000 - check against 0.0.0.0:5000
08:37:01.134785/T0x801212000 D:SRT.sm: bind: wildcard address - multiplexer reusable
08:37:01.134807/T0x801212000 D:SRT.sm: bind: reusing multiplexer for port 5000

An IPv4 connection is attempted to be established to the listener bound to IPv6 ANY.
In a way, the test becomes similar to TestIPv6.v4_calls_v6. Related to #2007, #2390?

[maxsharabayko]

The ReuseAddr.ProtocolVersion test is crashing if the system default bindv6only is changed to 1.

sysctl -w net.ipv6.bindv6only=1