#1094138 udptunnel: flaky autopkgtest on s390x: UDPTunnel communication failed

#1094138#5
Date:
2025-01-24 22:04:03 UTC
From:
To:
Dear maintainer(s),

I looked at the results of the autopkgtest of your package. I noticed
that it regularly fails on s390x.

Because the unstable-to-testing migration software now blocks on
regressions in testing, flaky tests, i.e. tests that flip between
passing and failing without changes to the list of installed packages,
are causing people unrelated to your package to spend time on these
tests.

Don't hesitate to reach out if you need help and some more information
from our infrastructure.

Paul

https://ci.debian.net/packages/u/udptunnel/testing/s390x/56932819/

  20s autopkgtest [22:03:10]: test validation: [-----------------------
  23s udp        0      0 127.0.0.1:5500          0.0.0.0:*

  26s tcp        0      0 0.0.0.0:6491            0.0.0.0:*
  LISTEN
  29s udp        0      0 0.0.0.0:6661            0.0.0.0:*

  29s 1,7d0
  29s < THIS
  29s <  IS
  29s <   THE
  29s <    DATA
  29s <     SEND
  29s <      OVER
  29s <       UDPTunnel
  29s UDPTunnel communication failed
  29s ending
/tmp/autopkgtest-lxc.nxazm245/downtmp/build.f9v/src/debian/tests/validation
with status 1
  29s THIS
  29s  IS
  29s   THE
  29s    DATA
  29s     SEND
  29s      OVER
  29s       UDPTunnel
  29s /tmp/autopkgtest-lxc.nxazm245/downtmp/wrapper.sh: Killing leaked
background processes: 953 957 961
  29s     PID TTY      STAT   TIME COMMAND
  29s     953 ?        S      0:00 ncat -u -l 127.0.0.1 5500 -o
/tmp/autopkgtest-lxc.nxazm245/downtmp/autopkgtest_tmp/rx.data
  29s     957 ?        S      0:00 udptunnel -s 6491 127.0.0.1 5500
  29s     961 ?        S      0:00 udptunnel -c 127.0.0.1 6491 127.0.0.1
6661
  30s autopkgtest [22:03:20]: test validation: -----------------------]

#1094138#10
Date:
2025-02-19 01:34:31 UTC
From:
To:
Hi Paul!

I executed the test on a porterbox s390x, but the test ran with success.
If I run the test two times in sequence, it fails, but I think that in
ci.debian.net the test runs just once, right?

Also, I cannot run autopkgtest on schroot in the porterbox.


Best Regards,
mt

#1094138#15
Date:
2025-02-19 06:43:34 UTC
From:
To:
Hi,


We run multiple things in parallel and of course your test runs
regularly. I'm not sure what you mean with "the test runs just once".


Maybe this helps? https://salsa.debian.org/mbanck/dd-autopkgtest/

Paul

#1094138#20
Date:
2025-02-21 18:04:32 UTC
From:
To:
Hey,

On Wed, Feb 19, 2025 at 07:43:34AM +0100, Paul Gevers wrote:
[...]
$ AUTOPKGTEST_TMP=/tmp/udptunnel ./debian/tests/validation
$ AUTOPKGTEST_TMP=/tmp/udptunnel ./debian/tests/validation

Thanks, but not working.

According to [1], please, could you provide access to testbeds to me?

[1] https://lists.debian.org/debian-devel/2024/03/msg00034.html


Best Regards,
mt

#1094138#25
Date:
2025-02-22 19:16:08 UTC
From:
To:
Hi Marcos,


To align a time, it easiest to do that on IRC in #debci on oftc. Does
that work for you?

(Either I or terceiro needs to be on-line while you do this).

Paul

#1094138#30
Date:
2025-02-24 20:41:36 UTC
From:
To:
Hi there!

On Sat, Feb 22, 2025 at 08:16:08PM +0100, Paul Gevers wrote:
[...]

Thanks Paul, terceiro provided access to a testbed.

I confirmed the problem and I was able to find a solution.
Changing udp client from ncat (nmap pkg) to socat fixes the issue.
I ran the tests 100 times and every time it ran successfully.

In the past [1] something similar happened with ncat.
[1] https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=1039613


Best regards,
mt

#1094138#35
Date:
2025-03-10 19:14:02 UTC
From:
To:
Hi there!

I ran the udptunnel test in a s390x testbed without udptunnel, I only used
ncat, and sometimes, it fails.

I write some scripts [1] to help with the ncat tests. I ran for 100 times
the script "test-ncat-udp-series.sh", resulting in 10k tests.
[1] https://people.debian.org/~talau/tmp/test-ncat-udp

10k tests (using "test-ncat-udp-series.sh") results in a porterbox s390x:
- Fail: Avg: 3.01%, StdDev: 2.15636

10k tests (using "test-ncat-udp-series.sh") results in a porterbox amd64:
- Fail: Avg: 0.12%, StdDev: 0.381576

After the tests, I decided to make tests changing ncat client to socat client,
scripts (test-ncat-udp_socat-client-series.sh, test-ncat-udp_socat-client.sh).
Below the results:

10k tests (using "test-ncat-udp_socat-client-series.sh") results in a
porterbox s390x:
- Fail: Avg: 0.0%, StdDev: 0

10k tests (using "test-ncat-udp_socat-client-series.sh") results in a
porterbox amd64:
- Fail: Avg: 0.0%, StdDev: 0

Analyzing the results, it can be seen that communication using ncat-client and
ncat-server presents failures. By changing ncat-client to socat, communications
no longer present failures. This indicates to me that ncat (in client mode) has
some bug.


Best Regards,
mt

#1094138#50
Date:
2025-03-23 23:03:09 UTC
From:
To:
Hi Marcos!

I cannot confirm you findings. In a VM on my local amd64 machine I see
or don't see failures depending on the number of virtual CPUs when
running either of your scripts. I also noticed that one cycle of test-
ncat-udp_socat-client-series.sh takes more time, about 150%, than a
cycle of test-ncat-udp-series.sh. That makes me assume that socat
mitigates the problem in certain environments by spending more time
internally.

The measure which solves the issue for me is to insert a short delay
after 'transmit_upd_data'. This seems reasonable as one should not
expect data can be sent, received and written to a file in almost no
time. Here's what I changed in both of your scripts:

$ diff -u3 orig/test-ncat-udp_socat-client.sh  test-ncat-udp_socat-client.sh
--- orig/test-ncat-udp_socat-client.sh	2025-03-10 14:06:55.000000000 +0000
+++ test-ncat-udp_socat-client.sh	2025-03-23 22:07:14.223161539 +0000
@@ -63,6 +63,7 @@

 test_communication() {
     transmit_udp_data
+    sleep 0.05

     if ! received_udp_data; then
         echo "ncat UDP communication failed"

$ diff -u3 orig/test-ncat-udp.sh  test-ncat-udp.sh
--- orig/test-ncat-udp.sh	2025-03-10 14:06:56.000000000 +0000
+++ test-ncat-udp.sh	2025-03-23 22:07:22.827289754 +0000
@@ -63,6 +63,7 @@

 test_communication() {
     transmit_udp_data
+    sleep 0.05

     if ! received_udp_data; then
         echo "ncat UDP communication failed"


With these changes applied transmission failures vanish in my setup. I
suggest you try this in your environment(s), potentially with an
increased delay.

Cheers,
Sven

#1094138#57
Date:
2025-03-24 20:00:20 UTC
From:
To:
Hey Sven!
[...]

I run the tests (test-ncat-udp-series.sh x 100) again using the extra sleep on
barriere and zelenka, and I got 0% of failures. Thanks!!


Best Regards,
mt

#1094138#62
Date:
2025-03-24 23:34:03 UTC
From:
To:
We believe that the bug you reported is fixed in the latest version of
udptunnel, which is due to be installed in the Debian FTP archive.

A summary of the changes between this version and the previous one is
attached.

Thank you for reporting the bug, which will now be closed.  If you
have further comments please address them to 1094138@bugs.debian.org,
and the maintainer will reopen the bug report if appropriate.

Debian distribution maintenance software
pp.
Marcos Talau <talau@debian.org> (supplier of updated udptunnel package)

(This message was generated automatically at their request; if you
believe that there is a problem with it please contact the archive
administrators by mailing ftpmaster@ftp-master.debian.org)
Format: 1.8
Date: Mon, 24 Mar 2025 18:52:07 -0300
Source: udptunnel
Architecture: source
Version: 1.1-12
Distribution: unstable
Urgency: medium
Maintainer: Marcos Talau <talau@debian.org>
Changed-By: Marcos Talau <talau@debian.org>
Closes: 1094138
Changes:
 udptunnel (1.1-12) unstable; urgency=medium
 .
   * debian/control: Bump Standards-Version to "4.7.2".
   * debian/copyright: Update packaging copyright years.
   * debian/tests/control: Add procps (for kill) to Depends.
   * debian/tests/validation:
     - Add clean function to run sequential tests.
     - Add extra time before checking if the transmission was successful.
       Thanks to Sven Geuer. Closes: #1094138.
     - Change sleep to while-sleep approach to detect if a port is open.
Checksums-Sha1:
 c12ce61a0ad558e689e104996d097544f639cdf0 1918 udptunnel_1.1-12.dsc
 27f583d569613b97de66ce5ffc7910d9af1e2da4 7292 udptunnel_1.1-12.debian.tar.xz
 45b04e4fd717b759c6120829a96a1b42fca5a35a 5564 udptunnel_1.1-12_source.buildinfo
Checksums-Sha256:
 a1027b15959f69e7b10ff2fee0a3fe6489befa63544831f3b0127bea463af7fe 1918 udptunnel_1.1-12.dsc
 167db40522e40d27bd6a70b9f7e2dfb5fb1ae7a84d92d9c3e50895583fd1e571 7292 udptunnel_1.1-12.debian.tar.xz
 106d232d7966006b5af9a95d9ffdb4d69dbe49a6622d02a72546875b8873a27c 5564 udptunnel_1.1-12_source.buildinfo
Files:
 5324b50b05ad26de6916530ad39769c6 1918 net optional udptunnel_1.1-12.dsc
 6fa151d5e81646fe5694b633d78bbe24 7292 net optional udptunnel_1.1-12.debian.tar.xz
 0e6d6d1f2a0c46a53a4710fc43bd60aa 5564 net optional udptunnel_1.1-12_source.buildinfo
-----BEGIN PGP SIGNATURE-----

iQIzBAEBCgAdFiEEtSLzkVnaB9053AsR9LqqgNsoukwFAmfh5wcACgkQ9LqqgNso
ukw4VhAAvAKz85R5bj96TFTSbWpVcwohfq36j2Q9GPyhYAS9KXr3I1sIcQ2X/fNi
/jDbIUz9l38H75yHgJd3k6/QMjfW8LIAm5GN0xgo+Y/xhlszv9rs7/FFbTSsvzdL
YbySLqqPw+mxJjOPs9fmmK/6xnX3Ddn+YQNw/4ywXZJjXrBcRDpkY+rxrLE24eHr
x7ZqNox7QyvRXn5180y7mdlzf6WjR+ucINpuLj2uMCq3gCXVn9Dtp8cChPFVLSQJ
Ey5wEDHnQoxjQKgdlrYc5qJDHtfmtOybbZ+U3HFIvqLmNsYqUAYQEtCxZyKz375M
5CJgTWq9GlWU+911NNzK0JS2LpvJYP8KjfN+U573YqdU50Ej7bZJg8XgXrHLmr/E
GkKfKS35b9ArZlNj8UK41h08kSaQAfYdaSc6RnpM43hWjQ3VxpI/MHZR6e0+PmeO
adkR4+Zfp5eovOlV2WFvLa358Ujy+kr66nUAwshM/eC/LBXARuCHXqx+Ja56tFID
a3qa7+ry3EFwxiHjA8ai+6uWKgAGPnBtkJwFfGFvYSQt0IktPhF35JCETs3eNTD3
u0uvvEV31UCAA1TS5881B9Ipb8k9tI/8Uu0T/VxSio8DLuDQagifbRr9ZEjgxQS2
MIs3ErG1tAU+3Z8nNhkKd5mJrJbd0OftTod3wJ2w3XkoYMjxu6c=
=0f5b
-----END PGP SIGNATURE-----