Failures of TCP/UDP unit tests

[JohanBertrand]

F´ Version	6bb780d
Affected Component

---

Problem Description

Similar to https://github.com/nasa/fprime/issues/1290, https://github.com/nasa/fprime/issues/881

Maybe also related to https://github.com/nasa/fprime/issues/2244

I am not sure if it is having an impact outside of the UT.

The tests of Drv/TcpServer and Drv/TcpClient are often failing, about 25% of the time (excluding silent failures).

It comes from several different errors:

• [Fixed in #2739] For TcpServer and TcpClient, most of the time, an error comes from the Address already being in use (Port already in use ?), based on errno. Also happens on the Github CI: https://github.com/nasa/fprime/actions/runs/8839296509/job/24272334136

[ RUN      ] Nominal.BasicMessaging
TCP server startup error: Address already in use
Port: 48514
/home/fprime/Drv/TcpServer/test/ut/TcpServerTester.cpp:49: Failure
Expected equality of these values:
  serverStat
    Which is: -9
  SOCK_SUCCESS
    Which is: 0
[  FAILED  ] Nominal.BasicMessaging (0 ms)

[ RUN      ] Reconnect.ReceiveThreadReconnect
TCP server startup error:Address already in use
Port: 33260
/home/fprime/Drv/TcpClient/test/ut/TcpClientTester.cpp:44: Failure
Expected equality of these values:
  serverStat
    Which is: -9
  SOCK_SUCCESS
    Which is: 0
[  FAILED  ] Reconnect.ReceiveThreadReconnect (0 ms)

• [Fixed in #2739] Sometimes TcpServer UT fail and can not start:

[ RUN      ] Nominal.BasicReceiveThread
[WARNING] Failed to open port with status -9 and errno 98
[WARNING] Failed to open port with status -9 and errno 98
/home/fprime/Drv/TcpServer/test/ut/TcpServerTester.cpp:41: Failure
Value of: Drv::Test::wait_on_started(this->component.getSocketHandler(), true, SOCKET_RETRY_INTERVAL_MS/10 + 1)
  Actual: false
Expected: true
/home/fprime/Drv/TcpServer/test/ut/TcpServerTester.cpp:51: Failure
Value of: component.getSocketHandler().isStarted()
  Actual: false
Expected: true
[WARNING] Failed to open port with status -9 and errno 98
/home/fprime/Drv/TcpServer/test/ut/TcpServerTester.cpp:65: Failure
Value of: Drv::Test::wait_on_change(this->component.getSocketHandler(), true, SOCKET_RETRY_INTERVAL_MS/10 + 1)
  Actual: false
Expected: true
/home/fprime/Drv/TcpServer/test/ut/TcpServerTester.cpp:67: Failure
Value of: this->component.getSocketHandler().isOpened()
  Actual: false
Expected: true
/home/fprime/Drv/TcpServer/test/ut/TcpServerTester.cpp:70: Failure
Expected equality of these values:
  status2
    Which is: -4
  Drv::SOCK_SUCCESS
    Which is: 0
/home/fprime/build-fprime-automatic-native-ut/F-Prime/Drv/TcpServer/TcpServerGTestBase.cpp:87: Failure
Expected equality of these values:
  size
    Which is: 1
  this->fromPortHistorySize_ready
    Which is: 0

/home/fprime/Drv/TcpServer/test/ut/TcpServerTester.cpp:105
  Value:    Size of history for ready
  Expected: 1
  Actual:   0

[  FAILED  ] Nominal.BasicReceiveThread (3001 ms)
[----------] 2 tests from Nominal (3002 ms total)

• Sometimes, in TCP and UDP UT, the UT fail silently

TcpClient:
[ RUN      ] Reconnect.ReceiveThreadReconnect
Listening for single client at 127.0.0.1:57291
Connected to 127.0.0.1:57291 as a tcp client
Accepted client at 127.0.0.1:57291
Connected to 127.0.0.1:57291 as a tcp client
Accepted client at 127.0.0.1:57291
Connected to 127.0.0.1:57291 as a tcp client
Accepted client at 127.0.0.1:57291
Connected to 127.0.0.1:57291 as a tcp client
Accepted client at 127.0.0.1:57291
[WARNING] Failed to recv from port with status -8 and errno 9
Connected to 127.0.0.1:57291 as a tcp client
Accepted client at 127.0.0.1:57291
Connected to 127.0.0.1:57291 as a tcp client
Accepted client at 127.0.0.1:57291
Connected to 127.0.0.1:57291 as a tcp client
Accepted client at 127.0.0.1:57291
Connected to 127.0.0.1:57291 as a tcp client
Accepted client at 127.0.0.1:57291
Connected to 127.0.0.1:57291 as a tcp client
Accepted client at 127.0.0.1:57291
Connected to 127.0.0.1:57291 as a tcp client
Accepted client at 127.0.0.1:57291
[       OK ] Reconnect.ReceiveThreadReconnect (103 ms)

TcpServer:
[ RUN      ] Nominal.BasicReceiveThread
Listening for single client at 127.0.0.1:44010
Connected to 127.0.0.1:44010 as a tcp client
Accepted client at 127.0.0.1:44010
[WARNING] Failed to recv from port with status -8 and errno 0
[       OK ] Nominal.BasicReceiveThread (20 ms)

TcpServer:
[ RUN      ] Nominal.BasicReceiveThread
Listening for single client at 127.0.0.1:40343
Connected to 127.0.0.1:40343 as a tcp client
Accepted client at 127.0.0.1:40343
[WARNING] Failed to open port with status -14 and errno 0
[       OK ] Nominal.BasicReceiveThread (1021 ms)

TcpServer:
[ RUN      ] Reconnect.ReceiveThreadReconnect
Listening for single client at 127.0.0.1:63959
Connected to 127.0.0.1:63959 as a tcp client
Accepted client at 127.0.0.1:63959
[WARNING] Failed to recv from port with status -8 and errno 0
Connected to 127.0.0.1:63959 as a tcp client
Accepted client at 127.0.0.1:63959
[WARNING] Failed to recv from port with status -8 and errno 0
Connected to 127.0.0.1:63959 as a tcp client
Accepted client at 127.0.0.1:63959
[WARNING] Failed to recv from port with status -8 and errno 0
Connected to 127.0.0.1:63959 as a tcp client
Accepted client at 127.0.0.1:63959
[WARNING] Failed to recv from port with status -8 and errno 0
Connected to 127.0.0.1:63959 as a tcp client
Accepted client at 127.0.0.1:63959
[WARNING] Failed to recv from port with status -8 and errno 0
Connected to 127.0.0.1:63959 as a tcp client
Accepted client at 127.0.0.1:63959
[WARNING] Failed to recv from port with status -8 and errno 0
Connected to 127.0.0.1:63959 as a tcp client
Accepted client at 127.0.0.1:63959
[WARNING] Failed to recv from port with status -8 and errno 0
Connected to 127.0.0.1:63959 as a tcp client
Accepted client at 127.0.0.1:63959
[WARNING] Failed to recv from port with status -8 and errno 0
Connected to 127.0.0.1:63959 as a tcp client
Accepted client at 127.0.0.1:63959
[WARNING] Failed to recv from port with status -8 and errno 0
Connected to 127.0.0.1:63959 as a tcp client
Accepted client at 127.0.0.1:63959
[WARNING] Failed to recv from port with status -8 and errno 0
[       OK ] Reconnect.ReceiveThreadReconnect (113 ms)

Udp:
[ RUN      ] Reconnect.ReceiveThreadReconnect
Setup to send and receive udp to 127.0.0.1:60059
Setup to send and receive udp to 127.0.0.1:37290
Setup to send and receive udp to 127.0.0.1:60059
Setup to send and receive udp to 127.0.0.1:37290
Setup to send and receive udp to 127.0.0.1:60059
Setup to send and receive udp to 127.0.0.1:37290
Setup to send and receive udp to 127.0.0.1:60059
Setup to send and receive udp to 127.0.0.1:37290
[WARNING] Failed to recv from port with status -8 and errno 0
Setup to send and receive udp to 127.0.0.1:60059
Setup to send and receive udp to 127.0.0.1:37290
Setup to send and receive udp to 127.0.0.1:60059
Setup to send and receive udp to 127.0.0.1:37290
Setup to send and receive udp to 127.0.0.1:60059
Setup to send and receive udp to 127.0.0.1:37290
Setup to send and receive udp to 127.0.0.1:60059
Setup to send and receive udp to 127.0.0.1:37290
Setup to send and receive udp to 127.0.0.1:60059
Setup to send and receive udp to 127.0.0.1:37290
Setup to send and receive udp to 127.0.0.1:60059
Setup to send and receive udp to 127.0.0.1:37290
[       OK ] Reconnect.ReceiveThreadReconnect (103 ms)

Udp:
[ RUN      ] Reconnect.ReceiveThreadReconnect
Setup to send and receive udp to 127.0.0.1:24765
Setup to send and receive udp to 127.0.0.1:53978
Setup to send and receive udp to 127.0.0.1:24765
Setup to send and receive udp to 127.0.0.1:53978
Setup to send and receive udp to 127.0.0.1:24765
Setup to send and receive udp to 127.0.0.1:53978
Setup to send and receive udp to 127.0.0.1:24765
Setup to send and receive udp to 127.0.0.1:53978
[WARNING] Failed to recv from port with status -8 and errno 9
Setup to send and receive udp to 127.0.0.1:24765
Setup to send and receive udp to 127.0.0.1:53978
Setup to send and receive udp to 127.0.0.1:24765
Setup to send and receive udp to 127.0.0.1:53978
Setup to send and receive udp to 127.0.0.1:24765
Setup to send and receive udp to 127.0.0.1:53978
Setup to send and receive udp to 127.0.0.1:24765
Setup to send and receive udp to 127.0.0.1:53978
Setup to send and receive udp to 127.0.0.1:24765
Setup to send and receive udp to 127.0.0.1:53978
Setup to send and receive udp to 127.0.0.1:24765
Setup to send and receive udp to 127.0.0.1:53978
[       OK ] Reconnect.ReceiveThreadReconnect (102 ms)

Context / Environment

Execute fprime-util version-check and share the output.

Operating System: Linux
CPU Architecture: x86_64
Platform: Linux-5.10.102.1-microsoft-standard-WSL2-x86_64-with-glibc2.29
Python version: 3.8.10
CMake version: 3.28.1
Pip version: 20.0.2
Pip packages:
    fprime-tools==3.4.4
    fprime-gds==3.4.3
    fprime-fpp-*==2.1.0a9

Running fprime on ubuntu:20.04 docker image.

Same behavior identified on a ubuntu:22.04 docker image.

How to Reproduce

1. Go to fprime root
2. Execute fprime generate --ut
3. Execute fprime build --ut -j16
4. Save the following python script:

import subprocess
import shutil

FPRIME_PATH="/home/fprime"
LOG_PATH="/home/log_tcp_udp_error/"
ITERATIONS=100

calls = [
    FPRIME_PATH + "/build-fprime-automatic-native-ut/bin/Linux/Drv_TcpClient_ut_exe",
    FPRIME_PATH + "/build-fprime-automatic-native-ut/bin/Linux/Drv_TcpServer_ut_exe",
    FPRIME_PATH + "/build-fprime-automatic-native-ut/bin/Linux/Drv_Udp_ut_exe",
]

for call in calls:
    executable = call.split('/')[-1]
    print(executable)
    for ii in range(0, ITERATIONS):
        print(f"Test number {ii:04}")
        try:
            output = subprocess.check_output([call], cwd=FPRIME_PATH, stderr=subprocess.PIPE)
            string_output = output.decode()
            if "[WARNING] Failed" in string_output:
                print("Silent failure")
                f = open(LOG_PATH + f"silent_{executable}_{ii:04}.log", "x")
                f.write(string_output)
                f.close()
        except subprocess.CalledProcessError as grepexc:
            print("Error code:", grepexc.returncode)
            f = open(LOG_PATH + f"{executable}_{ii:04}.log", "x")
            f.write(grepexc.output.decode())
            f.close()

5. Tune the values FPRIME_PATH to the current fprime folder and LOG_PATH to an empty folder to save log of unit tests. ITERATIONS can also be changed to increase the amount of run of the unit tests
6. Execute the python script
7. Check the log in the LOG_PATH folder

Expected Behavior

No error should be generated. The unit tests should also fail on warning

[JohanBertrand]

https://github.com/nasa/fprime/pull/2739 fixed the non-silent errors. The silent warnings are still here