"Message too long" when running test

[taismi]

Hello

I'm trying to run tests atm in our LAN.

'sudo etherate -i enp0s25'
prints
'Delay test Tx error: Message tool long'
and
'Speed test Tx error: Message too long'

What can cause this? It does't matter if I define -f 1000 etc. We are using non managed switches.

[jwbensley]

Hi @taismi ,

Thanks for opening this issue!

Please can you provide the following outputs?

uname -a
cat /etc/redhat-release || lsb_release -a || cat /etc/issue
lspci | grep -i eth
ip link
etherate -v
etherate -l

[taismi]

user@R61:~$ uname -a
Linux R61 4.4.0-116-generic #140-Ubuntu SMP Mon Feb 12 21:23:04 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux

user@R61:~$ cat /etc/redhat-release || lsb_release -a || cat /etc/issue
cat: /etc/redhat-release: Tiedostoa tai hakemistoa ei ole
No LSB modules are available.
Distributor ID:	Ubuntu
Description:	Ubuntu 16.04.4 LTS
Release:	16.04
Codename:	xenial

user@R61:~$ lspci | grep -i eth
00:19.0 Ethernet controller: Intel Corporation 82566MM Gigabit Network Connection (rev 03)

user@R61:~$ ip link
1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN mode DEFAULT group default qlen 1
    link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
2: enp0s25: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UP mode DEFAULT group default qlen 1000
    link/ether 00:1f:e2:1a:f6:67 brd ff:ff:ff:ff:ff:ff
3: wls3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc mq state UP mode DORMANT group default qlen 1000
    link/ether 00:21:5c:75:df:b9 brd ff:ff:ff:ff:ff:ff

user@R61:~$ etherate -v
Oops! Missing 802.1p VLAN ID
Usage info: etherate -h|--h

user@R61:~$ sudo etherate -l
Device lo with address 00:00:00:00:00:00, has interface index 1
Device enp0s25 with address 00:1f:e2:1a:f6:67, has interface index 2
Device wls3 with address 00:21:5c:75:df:b9, has interface index 3

[jwbensley]

@taismi Thanks for the quick response!

Sorry but I made a mistake in my previous comment, can you please provide the output of this command: etherate -V

Note the uppercase "V", I put lowercase in my previous comment.

[taismi]

user@R61:~$ etherate -V
Etherate version 1.16 2018-01

[yskripachov]

Delay Tx error seems caused by an incorrectly ordered assignments in defaults.c/set_default_values.
Speed test Tx error still here somewhere in speed_tests.c/speed_test_full

> diff --git a/defaults.c b/defaults.c
index 0eea55e..83e94d7 100644
--- a/defaults.c
+++ b/defaults.c
@@ -92,11 +92,11 @@ void set_default_values(struct app_params *app_params,
     frame_headers->src_mac[3]        = 0x00;
     frame_headers->src_mac[4]        = 0x00;
     frame_headers->src_mac[5]        = 0x01;
+    frame_headers->tlv_size          = sizeof(uint8_t) + sizeof(uint16_t) +
+                                       sizeof(uint32_t);
     frame_headers->sub_tlv_size      = frame_headers->tlv_size +
                                        sizeof(uint8_t) + sizeof(uint16_t) +
                                        sizeof(uint64_t);
-    frame_headers->tlv_size          = sizeof(uint8_t) + sizeof(uint16_t) +
-                                       sizeof(uint32_t);
     frame_headers->tx_buffer         = (uint8_t*)calloc(1, F_SIZE_MAX);
     frame_headers->vlan_dei          = 0;
     frame_headers->vlan_id           = VLAN_ID_DEF;
@@ -328,4 +328,4 @@ int16_t setup_socket_interface(struct frame_headers *frame_headers,

[yskripachov]

Speed test Tx error seems caused by SOCK_RAW -> SOCK_DGRAM in defaults.c/setup_socket. At least for deb9. It is possible to workaround with command line parameter -f (etherate -f 1460 for example).

Still have problems with Speed test Tx error : Resource temporarily unavailable.
The error has gone when ACK mode was selected with -a 10 100 but test results looks like completly invalid and counter-part etherate in RX mode finished ahead of time. Test results are:
Speed test complete
Test frames transmitted: 1
Test frames received: 0
Non test frames received: 135
In order ACK frames received: 0
Out of order ACK frames received early: 0
Out of order ACK frames received late: 0
Maximum speed during test: 0.01Mbps, 1Fps
Average speed during test: 0.00Mbps, 1Fps
Data transmitted during test: 0MBs
Ending test on Thu Mar 8 20:08:25 2018

PS: To run etherate in ACK mode this patch should be applied:

diff --git a/functions.c b/functions.c                                                                           
index a36ece5..faad4f4 100644                                                                                    
--- a/functions.c                                                                                                
+++ b/functions.c                                                                                                
@@ -2214,7 +2214,7 @@ void sync_settings(struct app_params *app_params,                                          
                 // TX has set ACK mode frame count                                                              
                 } else if (ntohs(*frame_headers->rx_sub_tlv_type) == TYPE_ACKCOUNT) {                           
                                                                                                                 
-                    test_params->f_ack_timeout = (uint32_t)ntohll(*frame_headers->rx_sub_tlv_value);            
+                    test_params->f_ack_count = (uint32_t)ntohll(*frame_headers->rx_sub_tlv_value);              
                     printf("ACK mode set to ACK every %" PRIu32 " frames\n", test_params->f_ack_count);         
                                                                                                                 
                 // TX has requested MTU sweep test

[jwbensley]

@yskripachov - Thanks for reporting the issue in set_default_values().

I've put this in it's own issue record here: #47

Also thanks for reporting the issue in sync_settings() relating to ACKs, that feature isn't finished yet. I have updated the existing record with the information you have provided: #28

In this issue record I will focus on the problem reported by @taismi.

[jwbensley]

@taismi

The fix for your issue is as follows:

https://github.com/jwbensley/Etherate/blob/master/defaults.c#L232

 test_interface->sock_fd = socket(AF_PACKET, SOCK_DGRAM, htons(ETH_P_ALL)); ///// Was SOCK_RAW

I was testing SOCK_DGRAM must have left that in the code when I made my last git push. SOCK_DGRAM expects a smaller packet size because the Kernel will build the Ether/IP/TCP/UDP headers for you. Etherate should use SOCK_RAW because it builds the frame including the Ethernet headers. This means that using SOCK_DGRAM the Kernel reports EMSGSIZE because it wants to build the headers onto the frame which is already 1500 bytes in size, and exceeds you 1500 byte link MTU. This is why -f 1460 works for you.

In addition to this each instance of sendto() that uses MSG_DONTWAIT isn't checking if the return code is EAGAIN, in this case we can ignore this error rather than ending the test:

https://github.com/jwbensley/Etherate/blob/master/speed_tests.c#L229
https://github.com/jwbensley/Etherate/blob/master/speed_tests.c#L376
https://github.com/jwbensley/Etherate/blob/master/speed_tests.c#L520
https://github.com/jwbensley/Etherate/blob/master/speed_tests.c#L679

I will fix this in the next version.

[jwbensley]

@taismi - Can you please test again with the latest version? I have put a short term fix in for you to check by removing the MSG_DONTWAIT flag from the sendto() syscalls.

[taismi]

Now etherate starts sending. Rx node says "Settings have been synchronised" and "Frame size is 1514 bytes" and "Calculating delay between hosts..." but the too long error is still there.

user@R61:~/Etherate$ sudo ./etherate
Running in TX mode
Using device enp0s25 with address 00:1f:e2:1a:f6:67, interface index 2
Entering promiscuous mode
Source MAC 00:00:5e:00:00:01
Destination MAC 00:00:5e:00:00:02
Sending gratuitous broadcasts...
Done.

Synchronising settings with RX host
Settings have been synchronised

Frame size is 1514 bytes
Calculating delay between hosts...
Delay test Tx error : Message too long
Starting test on Fri Mar  9 09:29:04 2018

Seconds		Mbps Tx		MBs Tx		FrmTx/s		Frames Tx
1		483.95		57		39956		39956
2		978.98		174		80827		120783
3		978.63		291		80798		201581
4		979.69		407		80886		282467
5		979.17		524		80843		363310
6		978.72		641		80806		444116
7		979.27		757		80851		524967
8		978.29		874		80770		605737
9		975.02		990		80500		686237
10		978.58		1107		80794		767031
11		979.46		1224		80867		847898
12		978.75		1340		80808		928706
13		978.72		1457		80806		1009512
14		978.96		1574		80826		1090338
15		977.74		1690		80725		1171063
16		979.59		1807		80878		1251941
17		979.01		1924		80830		1332771
18		979.33		2041		80856		1413627
19		979.51		2157		80871		1494498
20		977.79		2274		80729		1575227
21		972.05		2390		80255		1655482
22		979.73		2507		80889		1736371
23		979.40		2623		80862		1817233
24		978.89		2740		80820		1898053
25		979.23		2857		80848		1978901
Speed test Tx error : No buffer space available
Speed test complete
Test frames transmitted: 1997386
Test frames received: 0
Non test frames received: 5
In order ACK frames received: 0
Out of order ACK frames received early: 0
Out of order ACK frames received late: 0
Maximum speed during test: 979.73Mbps, 80889Fps
Average speed during test: 958.74Mbps, 80889Fps
Data transmitted during test: 2883MBs
Ending test on Fri Mar  9 09:29:29 2018

[jwbensley]

Hi @taismi

Please grab the latest copy again, I've also added the fix from @yskripachov I was very tired from work yesterday and forgot to add this in :)

[jwbensley]

@taismi I just found and fixed this issue; #48

I think things should be working now.

[jwbensley]

@taismi is the issue fixed for you now?

[jwbensley]

This is fixed in version 1.17 (2018-04).