Skip to content

Conversation

@davidBar-On
Copy link
Contributor

@davidBar-On davidBar-On commented May 16, 2025

(Updated on May 25, 2025 to show example of the Verbose and debug messages)
Added information that may help understanding the source of receiving non-iperf3 connection requests to the iperf3 port:

  • Verbose message about receiving new test connection, showing IP and Port.
    For example (from the logs in the following discussion): New test connection accepted from 167.94.145.107, port 40362 (address family 2).
  • Debug messages (DEBUG_LEVEL_INFO) about the received cookie when its size is too short or when the Parameters JSON size is illegal.
    For example (from the logs in the following discussion): Cookie received=GET / HTTP/1.1\x0D\x0AHost: 141.14.27.109:5.

@paulmenzel
Copy link

Thank you for the patch. Unfortunately, the IPv4 address looks printed as an IPv6 address:

Sun May 18 00:24:06 2025 iperf 3.19
Sun May 18 00:24:06 2025 Sun May 18 00:24:06 2025 Linux platsch.molgen.mpg.de 5.15.131.mx64.457 #1 SMP Tue Sep 12 12:55:20 CEST 2023 x86_64
Sun May 18 00:24:06 2025 -----------------------------------------------------------
Sun May 18 00:24:06 2025 Server listening on 5201 (test #1)
Sun May 18 00:24:06 2025 -----------------------------------------------------------
Sun May 18 00:24:06 2025 State change: State set to 15-IPERF_START - waiting for a new test (from 0-Test reset)
Sun May 18 04:38:46 2025 New test connection accepted from ::3532:3031:0, port 41126
Sun May 18 04:38:46 2025 Cookie size received is too short - 0 bytes instead of 37
Sun May 18 04:38:46 2025 All threads stopped
Sun May 18 04:38:46 2025 iperf3: error - unable to receive cookie at server: Bad file descriptor

@davidBar-On
Copy link
Contributor Author

davidBar-On commented May 19, 2025

@paulmenzel

Unfortunately, the IPv4 address looks printed as an IPv6 address:

If you will get the other error type, parameters error, it may help, as the first 37 bytes of the message received will be printed.

In any case, note that hex 35323031are characters "5201" - the port number. That may suggest that the connection may be coming from a tool inside your network (the ipv6 addrr itself is not riutable). Maybe, as you suggested, this is an internal tool in you network that scans open ports.

@paulmenzel
Copy link

@paulmenzel

Unfortunately, the IPv4 address looks printed as an IPv6 address:

If you will get the other error type, parameters error, it may help, as the first 37 bytes of the message received will be printed.

How do I get that error type? I merged your changes, built iperf3 and ran it. What do I need to do?

@davidBar-On
Copy link
Contributor Author

How do I get that error type?

#1882 shoeed two issues. One is "unable to receive cookie" that is what you got here, and the other is "unable to receive parameters". If that issue will happen than in addition to the ip addr, the 37 bytes received as the cookie will also be printed, which may help to inderstand which tool is connecting.

@paulmenzel
Copy link

How do I get that error type?

#1882 shoeed two issues. One is "unable to receive cookie" that is what you got here, and the other is "unable to receive parameters". If that issue will happen than in addition to the ip addr, the 37 bytes received as the cookie will also be printed, which may help to understand which tool is connecting.

Sorry, I still do not fully understand. My excerpt contains:

Cookie size received is too short - 0 bytes instead of 37

So nothing seems to have been sent.

Now with having been running for a while, there is also:

Mon May 19 21:23:29 2025 iperf 3.19
Mon May 19 21:23:29 2025 Mon May 19 21:23:29 2025 Linux platsch.molgen.mpg.de 5.15.131.mx64.457 #1 SMP Tue Sep 12 12:55:20 CEST 2023 x86_64
Mon May 19 21:23:29 2025 -----------------------------------------------------------
Mon May 19 21:23:29 2025 Server listening on 5201 (test #29)
Mon May 19 21:23:29 2025 -----------------------------------------------------------
Mon May 19 21:23:29 2025 State change: State set to 15-IPERF_START - waiting for a new test (from 0-Test reset)
Mon May 19 21:23:30 2025 New test connection accepted from ::3532:3031:0, port 49546
Mon May 19 21:23:33 2025 State change: State set to 9-PARAM_EXCHANGE - Client to Server Parameters Exchange (from 15-IPERF_START - waiting for a new test)
warning: JSON data length overflow - 842019085 bytes JSON size is not allowed
Mon May 19 21:23:33 2025 Cookie received (only printable chars)=GET / HTTP/1.1
Host: 141.14.27.109:5
Mon May 19 21:23:33 2025 Cookie received (full in Hex)=Mon May 19 21:23:33 2025 47Mon May 19 21:23:33 2025 45Mon May 19 21:23:33 2025 54Mon May 19 21:23:33 2025 20Mon May 19 21:23:33 2025 2fMon May 19 21:23:33 2025 20Mon May 19 21:23:33 2025 48Mon May 19 21:23:33 2025 54Mon May 19 21:23:33 2025 54Mon May 19 21:23:33 2025 50Mon May 19 21:23:33 2025 2fMon May 19 21:23:33 2025 31Mon May 19 21:23:33 2025 2eMon May 19 21:23:33 2025 31Mon May 19 21:23:33 2025 0dMon May 19 21:23:33 2025 0aMon May 19 21:23:33 2025 48Mon May 19 21:23:33 2025 6fMon May 19 21:23:33 2025 73Mon May 19 21:23:33 2025 74Mon May 19 21:23:33 2025 3aMon May 19 21:23:33 2025 20Mon May 19 21:23:33 2025 31Mon May 19 21:23:33 2025 34Mon May 19 21:23:33 2025 31Mon May 19 21:23:33 2025 2eMon May 19 21:23:33 2025 31Mon May 19 21:23:33 2025 34Mon May 19 21:23:33 2025 2eMon May 19 21:23:33 2025 32Mon May 19 21:23:33 2025 37Mon May 19 21:23:33 2025 2eMon May 19 21:23:33 2025 31Mon May 19 21:23:33 2025 30Mon May 19 21:23:33 2025 39Mon May 19 21:23:33 2025 3aMon May 19 21:23:33 2025 35Mon May 19 21:23:33 2025
Mon May 19 21:23:33 2025 All threads stopped
Mon May 19 21:23:33 2025 iperf3: error - unable to receive parameters from client: Bad file descriptor

So, some server tries to talk HTTP.

@paulmenzel
Copy link

In any case, note that hex 35323031are characters "5201" - the port number. That may suggest that the connection may be coming from a tool inside your network (the ipv6 addr itself is not routable). Maybe, as you suggested, this is an internal tool in you network that scans open ports.

Sorry to bring this up again, but shouldn’t the logging be able to differentiate between IP address and port number, and log it accordingly?

@davidBar-On
Copy link
Contributor Author

So, some server tries to talk HTTP.

Yes, "GET / HTTP/1.1 Host: 141.14.27.109:5" was sent (I assume the full port is 5201). However it does not add information about the sending app. (There seem to be an issue with the hex print which I will try to fix next week).

shouldn’t the logging be able to differentiate between IP address and port number, and log it accordingly?

I was referring ro the IPv6 source addr "::3532:3031:0". Note the the "3532:3031" is the hex coding of the chars "5201", which probably means that this is a fake addr generated by internal network app (the addr is not routable to ouside network). Maybr IT can help to identify what is this app.

@paulmenzel
Copy link

Here you go:

$ sudo tcpdump -i net02 -n 'ip dst 141.14.27.109'
[…]
11:30:11.390227 IP 91.238.181.96.55415 > 141.14.27.109.5201: Flags [SEW], seq 1482687488, win 8192, options [mss 1460,nop,wscale 8,nop,nop,sackOK], length 0
11:30:11.415330 IP 91.238.181.96.55425 > 141.14.27.109.5201: Flags [SEW], seq 2583398043, win 8192, options [mss 1460,nop,wscale 8,nop,nop,sackOK], length 0
11:30:11.421239 IP 91.238.181.96.55415 > 141.14.27.109.5201: Flags [.], ack 3688641247, win 1026, length 0
11:30:11.421334 IP 91.238.181.96.55415 > 141.14.27.109.5201: Flags [F.], seq 0, ack 1, win 1026, length 0
11:30:11.437578 IP 91.238.181.96.55425 > 141.14.27.109.5201: Flags [.], ack 229824637, win 1026, length 0
11:30:11.437667 IP 91.238.181.96.55425 > 141.14.27.109.5201: Flags [P.], seq 0:42, ack 1, win 1026, length 42
11:30:11.452256 IP 91.238.181.96.55415 > 141.14.27.109.5201: Flags [.], ack 2, win 1026, length 0
11:30:11.460238 IP 91.238.181.96.55431 > 141.14.27.109.5201: Flags [SEW], seq 3198807911, win 8192, options [mss 1460,nop,wscale 8,nop,nop,sackOK], length 0
11:30:11.484262 IP 91.238.181.96.55431 > 141.14.27.109.5201: Flags [.], ack 3984853523, win 1026, length 0
11:30:11.484338 IP 91.238.181.96.55431 > 141.14.27.109.5201: Flags [P.], seq 0:42, ack 1, win 1026, length 42
[…]
Tue May 20 10:59:03 2025 iperf 3.19
Tue May 20 10:59:03 2025 Tue May 20 10:59:03 2025 Linux platsch.molgen.mpg.de 5.15.131.mx64.457 #1 SMP Tue Sep 12 12:55:20 CEST 2023 x86_64
Tue May 20 10:59:03 2025 -----------------------------------------------------------
Tue May 20 10:59:03 2025 Server listening on 5201 (test #33)
Tue May 20 10:59:03 2025 -----------------------------------------------------------
Tue May 20 10:59:03 2025 State change: State set to 15-IPERF_START - waiting for a new test (from 0-Test reset)
Tue May 20 11:30:11 2025 New test connection accepted from ::3532:3031:0, port 55415
Tue May 20 11:30:11 2025 Cookie size received is too short - 0 bytes instead of 37
Tue May 20 11:30:11 2025 All threads stopped
Tue May 20 11:30:11 2025 iperf3: error - unable to receive cookie at server: Bad file descriptor
Tue May 20 11:30:11 2025 iperf 3.19
Tue May 20 11:30:11 2025 Tue May 20 11:30:11 2025 Linux platsch.molgen.mpg.de 5.15.131.mx64.457 #1 SMP Tue Sep 12 12:55:20 CEST 2023 x86_64
Tue May 20 11:30:11 2025 -----------------------------------------------------------
Tue May 20 11:30:11 2025 Server listening on 5201 (test #34)
Tue May 20 11:30:11 2025 -----------------------------------------------------------
Tue May 20 11:30:11 2025 State change: State set to 15-IPERF_START - waiting for a new test (from 0-Test reset)
Tue May 20 11:30:11 2025 New test connection accepted from ::3532:3031:0, port 55431
Tue May 20 11:30:11 2025 State change: State set to 9-PARAM_EXCHANGE - Client to Server Parameters Exchange (from 15-IPERF_START - waiting for a new test)
warning: JSON data length overflow - 196608 bytes JSON size is not allowed
Tue May 20 11:30:11 2025 Cookie received (only printable chars)=
Tue May 20 11:30:11 2025 Cookie received (full in Hex)=Tue May 20 11:30:11 2025 03Tue May 20 11:30:11 2025
Tue May 20 11:30:11 2025 All threads stopped
Tue May 20 11:30:11 2025 iperf3: error - unable to receive parameters from client: Bad file descriptor
Tue May 20 11:30:11 2025 iperf 3.19
Tue May 20 11:30:11 2025 Tue May 20 11:30:11 2025 Linux platsch.molgen.mpg.de 5.15.131.mx64.457 #1 SMP Tue Sep 12 12:55:20 CEST 2023 x86_64
Tue May 20 11:30:11 2025 -----------------------------------------------------------
Tue May 20 11:30:11 2025 Server listening on 5201 (test #35)
Tue May 20 11:30:11 2025 -----------------------------------------------------------
Tue May 20 11:30:11 2025 State change: State set to 15-IPERF_START - waiting for a new test (from 0-Test reset)

PS: The tcpdump output shows also a lot of servers try to connect to port 80 and 443.

@davidBar-On
Copy link
Contributor Author

davidBar-On commented May 20, 2025

The tcpdump output is interesting as it shows IPv4 source adress 91.238.181.96. I will check if there is a bug in the IP addr print I added ....

In any case, searching this IP shows that is is provided by ISP "AS49434 FBW NETWORKS SAS".

I now suspect that the connections are from a web crawler. The first "0 length cookie" connection is from port scanning that looks for open ports but does not send any data. When a port is open then it reconnects and sends HTTP GET (this is when the params error happens).

PS: Port 80 (http) and port 443 (https) are the ports for connecting to web servers, so it may be that the tool (web crawler?) also try to find if there is aweb server active in the site and get its data.

@davidBar-On davidBar-On force-pushed the issue-1882-add-server-debug-information branch from 9e3b408 to 2cf3d30 Compare May 24, 2025 17:23
@davidBar-On
Copy link
Contributor Author

@paulmenzel, I have improved the verbose/debug messages, including the display of the source IP address. If you still receive these connection reports, can you try running using this version to see if the verbose and debug messages show the right information? The problem that IPv6 addr was displayed instead of IPv4 addr did not happen in my environment, so I am not sure if the issue is fixed now. (I assume this will not give additional information, but it will help to make sure this PR is correct.)

@paulmenzel
Copy link

Awesome. Thank you for your work. It seems to work now:

$ src/iperf3 --server --port 5201 --bind iperf3.molgen.mpg.de --timestamps -V -d
Sat May 24 22:41:30 2025 iperf 3.19+
Sat May 24 22:41:30 2025 Sat May 24 22:41:30 2025 Linux platsch.molgen.mpg.de 5.15.131.mx64.457 #1 SMP Tue Sep 12 12:55:20 CEST 2023 x86_64
Sat May 24 22:41:30 2025 -----------------------------------------------------------
Sat May 24 22:41:30 2025 Server listening on 5201 (test #1)
Sat May 24 22:41:30 2025 -----------------------------------------------------------
Sat May 24 22:41:30 2025 State change: State set to 15-IPERF_START - waiting for a new test (from 0-Test reset)
Sun May 25 00:03:33 2025 New test connection accepted from 194.165.16.161, port 55588 (address family 2)
Cookie size received is too short - 0 bytes instead of 37
Sun May 25 00:03:33 2025 All threads stopped
Sun May 25 00:03:33 2025 iperf3: error - unable to receive cookie at server: Bad file descriptor
Sun May 25 00:03:33 2025 iperf 3.19+
Sun May 25 00:03:33 2025 Sun May 25 00:03:33 2025 Linux platsch.molgen.mpg.de 5.15.131.mx64.457 #1 SMP Tue Sep 12 12:55:20 CEST 2023 x86_64
Sun May 25 00:03:33 2025 -----------------------------------------------------------
Sun May 25 00:03:33 2025 Server listening on 5201 (test #2)
Sun May 25 00:03:33 2025 -----------------------------------------------------------
Sun May 25 00:03:33 2025 State change: State set to 15-IPERF_START - waiting for a new test (from 0-Test reset)
Sun May 25 00:03:34 2025 New test connection accepted from 194.165.16.161, port 55708 (address family 2)
Sun May 25 00:03:34 2025 State change: State set to 9-PARAM_EXCHANGE - Client to Server Parameters Exchange (from 15-IPERF_START - waiting for a new test)
warning: JSON data length overflow - 196608 bytes JSON size is not allowed
Cookie received=\x03
Sun May 25 00:03:34 2025 All threads stopped
Sun May 25 00:03:34 2025 iperf3: error - unable to receive parameters from client: Bad file descriptor
Sun May 25 00:03:34 2025 iperf 3.19+
Sun May 25 00:03:34 2025 Sun May 25 00:03:34 2025 Linux platsch.molgen.mpg.de 5.15.131.mx64.457 #1 SMP Tue Sep 12 12:55:20 CEST 2023 x86_64
Sun May 25 00:03:34 2025 -----------------------------------------------------------
Sun May 25 00:03:34 2025 Server listening on 5201 (test #3)
Sun May 25 00:03:34 2025 -----------------------------------------------------------
Sun May 25 00:03:34 2025 State change: State set to 15-IPERF_START - waiting for a new test (from 0-Test reset)
Sun May 25 00:03:34 2025 New test connection accepted from 194.165.16.161, port 59531 (address family 2)
Sun May 25 00:03:34 2025 State change: State set to 9-PARAM_EXCHANGE - Client to Server Parameters Exchange (from 15-IPERF_START - waiting for a new test)
warning: JSON data length overflow - 196608 bytes JSON size is not allowed
Cookie received=\x03
Sun May 25 00:03:34 2025 All threads stopped
Sun May 25 00:03:34 2025 iperf3: error - unable to receive parameters from client: Bad file descriptor
Sun May 25 00:03:34 2025 iperf 3.19+
Sun May 25 00:03:34 2025 Sun May 25 00:03:34 2025 Linux platsch.molgen.mpg.de 5.15.131.mx64.457 #1 SMP Tue Sep 12 12:55:20 CEST 2023 x86_64
Sun May 25 00:03:34 2025 -----------------------------------------------------------
Sun May 25 00:03:34 2025 Server listening on 5201 (test #4)
Sun May 25 00:03:34 2025 -----------------------------------------------------------
Sun May 25 00:03:34 2025 State change: State set to 15-IPERF_START - waiting for a new test (from 0-Test reset)
Sun May 25 00:45:54 2025 New test connection accepted from 194.165.16.162, port 32368 (address family 2)
Cookie size received is too short - 0 bytes instead of 37
Sun May 25 00:45:54 2025 All threads stopped
Sun May 25 00:45:54 2025 iperf3: error - unable to receive cookie at server: Bad file descriptor
Sun May 25 00:45:54 2025 iperf 3.19+
Sun May 25 00:45:54 2025 Sun May 25 00:45:54 2025 Linux platsch.molgen.mpg.de 5.15.131.mx64.457 #1 SMP Tue Sep 12 12:55:20 CEST 2023 x86_64
Sun May 25 00:45:54 2025 -----------------------------------------------------------
Sun May 25 00:45:54 2025 Server listening on 5201 (test #5)
Sun May 25 00:45:54 2025 -----------------------------------------------------------
Sun May 25 00:45:54 2025 State change: State set to 15-IPERF_START - waiting for a new test (from 0-Test reset)
Sun May 25 00:45:55 2025 New test connection accepted from 194.165.16.162, port 32372 (address family 2)
Sun May 25 00:45:55 2025 State change: State set to 9-PARAM_EXCHANGE - Client to Server Parameters Exchange (from 15-IPERF_START - waiting for a new test)
warning: JSON data length overflow - 196608 bytes JSON size is not allowed
Cookie received=\x03
Sun May 25 00:45:55 2025 All threads stopped
Sun May 25 00:45:55 2025 iperf3: error - unable to receive parameters from client: Bad file descriptor
Sun May 25 00:45:55 2025 iperf 3.19+
Sun May 25 00:45:55 2025 Sun May 25 00:45:55 2025 Linux platsch.molgen.mpg.de 5.15.131.mx64.457 #1 SMP Tue Sep 12 12:55:20 CEST 2023 x86_64
Sun May 25 00:45:55 2025 -----------------------------------------------------------
Sun May 25 00:45:55 2025 Server listening on 5201 (test #6)
Sun May 25 00:45:55 2025 -----------------------------------------------------------
Sun May 25 00:45:55 2025 State change: State set to 15-IPERF_START - waiting for a new test (from 0-Test reset)
Sun May 25 00:45:55 2025 New test connection accepted from 194.165.16.162, port 34051 (address family 2)
Sun May 25 00:45:55 2025 State change: State set to 9-PARAM_EXCHANGE - Client to Server Parameters Exchange (from 15-IPERF_START - waiting for a new test)
warning: JSON data length overflow - 196608 bytes JSON size is not allowed
Cookie received=\x03
Sun May 25 00:45:55 2025 All threads stopped
Sun May 25 00:45:55 2025 iperf3: error - unable to receive parameters from client: Bad file descriptor
Sun May 25 00:45:55 2025 iperf 3.19+
Sun May 25 00:45:55 2025 Sun May 25 00:45:55 2025 Linux platsch.molgen.mpg.de 5.15.131.mx64.457 #1 SMP Tue Sep 12 12:55:20 CEST 2023 x86_64
Sun May 25 00:45:55 2025 -----------------------------------------------------------
Sun May 25 00:45:55 2025 Server listening on 5201 (test #7)
Sun May 25 00:45:55 2025 -----------------------------------------------------------
Sun May 25 00:45:55 2025 State change: State set to 15-IPERF_START - waiting for a new test (from 0-Test reset)
Sun May 25 03:43:09 2025 New test connection accepted from 167.94.145.107, port 40362 (address family 2)
Sun May 25 03:43:12 2025 All threads stopped
Sun May 25 03:43:12 2025 iperf3: error - unable to receive cookie at server: Bad file descriptor
Sun May 25 03:43:12 2025 iperf 3.19+
Sun May 25 03:43:12 2025 Sun May 25 03:43:12 2025 Linux platsch.molgen.mpg.de 5.15.131.mx64.457 #1 SMP Tue Sep 12 12:55:20 CEST 2023 x86_64
Sun May 25 03:43:12 2025 -----------------------------------------------------------
Sun May 25 03:43:12 2025 Server listening on 5201 (test #8)
Sun May 25 03:43:12 2025 -----------------------------------------------------------
Sun May 25 03:43:12 2025 State change: State set to 15-IPERF_START - waiting for a new test (from 0-Test reset)
Sun May 25 03:43:12 2025 New test connection accepted from 167.94.145.107, port 58700 (address family 2)
Sun May 25 03:43:15 2025 State change: State set to 9-PARAM_EXCHANGE - Client to Server Parameters Exchange (from 15-IPERF_START - waiting for a new test)
warning: JSON data length overflow - 842019085 bytes JSON size is not allowed
Cookie received=GET / HTTP/1.1\x0D\x0AHost: 141.14.27.109:5
Sun May 25 03:43:15 2025 All threads stopped
Sun May 25 03:43:15 2025 iperf3: error - unable to receive parameters from client: Bad file descriptor

No idea, what is different in our setup. For the record, that server is an IPv4 server only, and has IPv6 disabled/no IPv6 address.

@davidBar-On
Copy link
Contributor Author

davidBar-On commented May 25, 2025

Awesome. Thank you for your work. It seems to work now:

Great. Thanks for testing. Unfortunately, I still had one issue with printing the cookie which I fixed now (using strlen() instead of COOKIE_SIZE which caused to print only the first cookie byte in Cookie received=\x03. Can you test with the update to make sure this issue is fixed now?

No idea, what is different in our setup. For the record, that server is an IPv4 server only, and has IPv6 disabled/no IPv6 address.

I also don't understand, but but that may be because the server only supports IPv4. While in your server "address family 2" (AF_INET) is set, in my computer it is "address family 10" (AF_INET6), event for IPv4 addresses (but the IPv4 and IPv6 addresses are displayed correctly).

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants