ubuntu-kernel-tests

udpgso_bench.sh from net in ubuntu_kernel_selftests fails on Groovy/Hirsute/Impish

Bug #1926229 reported by Kelsey Steele on 2021-04-27

This bug affects 1 person

	Status	Importance	Assigned to
ubuntu-kernel-tests	Confirmed	Undecided	Unassigned
linux (Ubuntu)	Fix Released	Undecided	Unassigned
Focal	Confirmed	Undecided	Unassigned

Bug Description

Seeing on Groovy/linux 5.8.0-51.57 on host riccioli. Passed on host vought.

This passed last cycle, so may be a regression.

Tags:

Revision history for this message

Po-Hsu Lin (cypressyew) wrote on 2021-04-27:

make.log Edit (193.8 KiB, text/plain)

Download full text (6.2 KiB)

A manual test on riccioli didn't managed to reproduce this issue:

A manual test on riccioli didn't managed to reproduce this issue:

$ sudo ./udpgso_bench.sh 
ipv4
tcp
tcp tx:  10737 MB/s   182123 calls/s 182123 msg/s
tcp rx:  10748 MB/s   182189 calls/s
tcp tx:  10759 MB/s   182487 calls/s 182487 msg/s
tcp rx:  10771 MB/s   182608 calls/s
tcp tx:  10632 MB/s   180335 calls/s 180335 msg/s
tcp zerocopy
tcp tx:   7447 MB/s   126308 calls/s 126308 msg/s
tcp rx:   7454 MB/s   124602 calls/s
tcp tx:   7500 MB/s   127209 calls/s 127209 msg/s
tcp rx:   7502 MB/s   122880 calls/s
tcp tx:   8538 MB/s   144818 calls/s 144818 msg/s
udp
udp rx:   1007 MB/s   718031 calls/s
udp tx:   1010 MB/s   719586 calls/s  17133 msg/s
udp rx:    980 MB/s   698532 calls/s
udp tx:    979 MB/s   697746 calls/s  16613 msg/s
udp rx:    998 MB/s   711266 calls/s
udp tx:    997 MB/s   710514 calls/s  16917 msg/s
udp gso
udp rx:   2507 MB/s  1786348 calls/s
udp tx:   2519 MB/s    42736 calls/s  42736 msg/s
udp rx:   2489 MB/s  1773492 calls/s
udp tx:   2487 MB/s    42182 calls/s  42182 msg/s
udp rx:   2563 MB/s  1826286 calls/s
udp tx:   2557 MB/s    43385 calls/s  43385 msg/s
udp gso zerocopy
udp rx:   1862 MB/s  1326738 calls/s
udp tx:   1870 MB/s    31724 calls/s  31724 msg/s
udp rx:   1859 MB/s  1324960 calls/s
udp tx:   1857 MB/s    31509 calls/s  31509 msg/s
udp rx:   1852 MB/s  1319654 calls/s
udp tx:   1850 MB/s    31388 calls/s  31388 msg/s
udp gso timestamp
udp rx:   2460 MB/s  1752450 calls/s
udp tx:   2470 MB/s    41899 calls/s  41899 msg/s
udp rx:   2477 MB/s  1764504 calls/s
udp tx:   2474 MB/s    41970 calls/s  41970 msg/s
udp rx:   2490 MB/s  1773912 calls/s
udp tx:   2487 MB/s    42193 calls/s  42193 msg/s
udp gso zerocopy audit
udp rx:   1698 MB/s  1209890 calls/s
udp tx:   1708 MB/s    28974 calls/s  28974 msg/s
udp rx:   1771 MB/s  1262257 calls/s
udp tx:   1769 MB/s    30018 calls/s  30018 msg/s
udp rx:   1720 MB/s  1225487 calls/s
udp tx:   1718 MB/s    29151 calls/s  29151 msg/s
Summary over 3.000 seconds...
sum udp tx:   1773 MB/s      88143 calls (29381/s)      88143 msgs (29381/s)
Zerocopy acks:               88143
udp gso timestamp audit
udp rx:   2436 MB/s  1735314 calls/s
udp tx:   2446 MB/s    41492 calls/s  41492 msg/s
udp rx:   2474 MB/s  1762446 calls/s
udp tx:   2471 MB/s    41917 calls/s  41917 msg/s
udp rx:   2448 MB/s  1743966 calls/s
udp tx:   2444 MB/s    41455 calls/s  41455 msg/s
Summary over 3.000 seconds...
sum udp tx:   2512 MB/s     124864 calls (41621/s)     124864 msgs (41621/s)
Tx Timestamps:              124864 received                 0 errors
udp gso zerocopy timestamp audit
udp rx:   1630 MB/s  1161141 calls/s
udp tx:   1636 MB/s    27759 calls/s  27759 msg/s
udp rx:   1575 MB/s  1121959 calls/s
udp tx:   1573 MB/s    26685 calls/s  26685 msg/s
udp rx:   1571 MB/s  1119487 calls/s
udp tx:   1568 MB/s    26601 calls/s  26601 msg/s
Summary over 3.000 seconds...
sum udp tx:   1631 MB/s      81045 calls (27015/s)      81045 msgs (27015/s)
Tx Timestamps:               81045 received                 0 errors
Zerocopy acks:               81045
ipv6
tcp
tcp tx:   9236 MB/s   156655 calls/s 156655 msg/s
tcp rx:   9246 MB/s   156687 calls/s
tcp tx:   9857 MB/s   167192 calls/s 167192 msg/s
tcp rx:   9867 MB/s   167279 calls/s
tcp tx:   9618 MB/s   163129 calls/s 163129 msg/s
tcp zerocopy
tcp tx:   7886 MB/s   133763 calls/s 133763 msg/s
tcp rx:   7893 MB/s   109473 calls/s
tcp tx:   7948 MB/s   134820 calls/s 134820 msg/s
tcp rx:   7957 MB/s   111157 calls/s
tcp tx:   8289 MB/s   140597 calls/s 140597 msg/s
udp
udp rx:    932 MB/s   680171 calls/s
udp tx:    935 MB/s   682367 calls/s  15869 msg/s
udp rx:    939 MB/s   684939 calls/s
udp tx:    937 MB/s   683442 calls/s  15894 msg/s
udp rx:    943 MB/s   687784 calls/s
udp tx:    943 MB/s   687828 calls/s  15996 msg/s
udp gso
udp rx:   2570 MB/s  1874499 calls/s
udp tx:   2578 MB/s    43731 calls/s  43731 msg/s
udp rx:   2479 MB/s  1808214 calls/s
udp tx:   2476 MB/s    42006 calls/s  42006 msg/s
udp rx:   2466 MB/s  1798991 calls/s
udp tx:   2463 MB/s    41791 calls/s  41791 msg/s
udp gso zerocopy
udp rx:   1600 MB/s  1167590 calls/s
udp tx:   1605 MB/s    27237 calls/s  27237 msg/s
udp rx:   1566 MB/s  1142307 calls/s
udp tx:   1565 MB/s    26547 calls/s  26547 msg/s
udp rx:   1648 MB/s  1202208 calls/s
udp tx:   1646 MB/s    27929 calls/s  27929 msg/s
udp gso timestamp
udp rx:   2378 MB/s  1734569 calls/s
udp tx:   2390 MB/s    40550 calls/s  40550 msg/s
udp rx:   2386 MB/s  1740167 calls/s
udp tx:   2383 MB/s    40428 calls/s  40428 msg/s
udp rx:   2404 MB/s  1753411 calls/s
udp tx:   2401 MB/s    40735 calls/s  40735 msg/s
udp gso zerocopy audit
udp rx:   1579 MB/s  1152018 calls/s
udp tx:   1586 MB/s    26904 calls/s  26904 msg/s
udp rx:   1574 MB/s  1148512 calls/s
udp tx:   1572 MB/s    26678 calls/s  26678 msg/s
udp rx:   1671 MB/s  1218910 calls/s
udp tx:   1668 MB/s    28306 calls/s  28306 msg/s
Summary over 3.000 seconds...
sum udp tx:   1647 MB/s      81888 calls (27296/s)      81888 msgs (27296/s)
Zerocopy acks:               81888
udp gso timestamp audit
udp rx:   2457 MB/s  1792369 calls/s
udp tx:   2465 MB/s    41816 calls/s  41816 msg/s
udp rx:   2464 MB/s  1797099 calls/s
udp tx:   2461 MB/s    41749 calls/s  41749 msg/s
udp rx:   2393 MB/s  1745777 calls/s
udp tx:   2391 MB/s    40558 calls/s  40558 msg/s
Summary over 3.000 seconds...
sum udp tx:   2497 MB/s     124123 calls (41374/s)     124123 msgs (41374/s)
Tx Timestamps:              124123 received                 0 errors
udp gso zerocopy timestamp audit
udp rx:   1584 MB/s  1155782 calls/s
udp tx:   1589 MB/s    26964 calls/s  26964 msg/s
udp rx:   1574 MB/s  1147947 calls/s
udp tx:   1571 MB/s    26661 calls/s  26661 msg/s
udp rx:   1507 MB/s  1099533 calls/s
udp tx:   1506 MB/s    25550 calls/s  25550 msg/s
Summary over 3.000 seconds...
sum udp tx:   1593 MB/s      79175 calls (26391/s)      79175 msgs (26391/s)
Tx Timestamps:               79175 received                 0 errors
Zerocopy acks:               79175
udpgso_bench.sh: PASS=18 SKIP=0 FAIL=0
udpgso_bench.sh: PASS

$ uname -a
Linux riccioli 5.8.0-51-generic #57-Ubuntu SMP Wed Apr 14 16:02:45 UTC 2021 x86_64 x86_64 x86_64 GNU/Linux

And it has passed with the net test run (please find attachment for the test log) with:
sudo make run_tests TARGETS=net

A glitch maybe?

Changed in ubuntu-kernel-tests:
status:	New → Incomplete

Revision history for this message

Po-Hsu Lin (cypressyew) wrote on 2021-04-27:

autotest.log Edit (383.6 KiB, text/plain)

Ran with autotest frame work, still unable to reproduce this issue.

Revision history for this message

Kelsey Steele (kelsey-steele) wrote on 2021-07-21:

Download full text (3.4 KiB)

Failing on Hirsute with connection refused:

16:08:04 DEBUG| [stdout] # udp
16:08:04 DEBUG| [stdout] # ./udpgso_bench_tx: write: Connection refused
16:08:04 DEBUG| [stdout] # udp gso
16:08:04 DEBUG| [stdout] # ./udpgso_bench_tx: sendmsg: Connection refused
16:08:04 DEBUG| [stdout] # udp gso zerocopy
16:08:05 DEBUG| [stdout] # udp rx: 1439 MB/s 1049992 calls/s
16:08:05 DEBUG| [stdout] # udp tx: 1848 MB/s 31355 calls/s 31355 msg/s
16:08:06 DEBUG| [stdout] # udp rx: 1795 MB/s 1309319 calls/s
16:08:06 DEBUG| [stdout] # udp tx: 1793 MB/s 30427 calls/s 30427 msg/s
16:08:07 DEBUG| [stdout] # udp tx: 1798 MB/s 30510 calls/s 30510 msg/s
16:08:07 DEBUG| [stdout] # udp gso timestamp
16:08:08 DEBUG| [stdout] # udp rx: 1696 MB/s 1236924 calls/s
16:08:08 DEBUG| [stdout] # udp tx: 1828 MB/s 31014 calls/s 31014 msg/s
16:08:09 DEBUG| [stdout] # udp tx: 2127 MB/s 36091 calls/s 36091 msg/s
16:08:09 DEBUG| [stdout] # udp rx: 543 MB/s 395969 calls/s
16:08:10 DEBUG| [stdout] # udp tx: 2135 MB/s 36220 calls/s 36220 msg/s
16:08:10 DEBUG| [stdout] # udp gso zerocopy audit
16:08:11 DEBUG| [stdout] # udp rx: 705 MB/s 514380 calls/s
16:08:11 DEBUG| [stdout] # udp tx: 1956 MB/s 33179 calls/s 33179 msg/s
16:08:12 DEBUG| [stdout] # udp rx: 600 MB/s 438206 calls/s
16:08:12 DEBUG| [stdout] # udp tx: 1971 MB/s 33442 calls/s 33442 msg/s
16:08:13 DEBUG| [stdout] # udp tx: 1967 MB/s 33366 calls/s 33366 msg/s
16:08:13 DEBUG| [stdout] # Summary over 3.000 seconds...
16:08:13 DEBUG| [stdout] # sum udp tx: 2012 MB/s 99987 calls (33329/s) 99987 msgs (33329/s)
16:08:13 DEBUG| [stdout] # Zerocopy acks: 99987
16:08:13 DEBUG| [stdout] # udp rx: 668 MB/s 487594 calls/s
16:08:13 DEBUG| [stdout] # udp gso timestamp audit
16:08:14 DEBUG| [stdout] # udp tx: 1923 MB/s 32629 calls/s 32629 msg/s
16:08:14 DEBUG| [stdout] # udp rx: 1464 MB/s 1068101 calls/s
16:08:15 DEBUG| [stdout] # udp tx: 2127 MB/s 36086 calls/s 36086 msg/s
16:08:15 DEBUG| [stdout] # udp rx: 528 MB/s 385353 calls/s
16:08:16 DEBUG| [stdout] # udp tx: 2109 MB/s 35783 calls/s 35783 msg/s
16:08:17 DEBUG| [stdout] # Summary over 3.000 seconds...
16:08:17 DEBUG| [stdout] # sum udp tx: 2103 MB/s 104498 calls (34832/s) 104498 msgs (34832/s)
16:08:17 DEBUG| [stdout] # Tx Timestamps: 104498 received 0 errors
16:08:17 DEBUG| [stdout] # udp gso zerocopy timestamp audit
16:08:18 DEBUG| [stdout] # udp rx: 1646 MB/s 1200968 calls/s
16:08:18 DEBUG| [stdout] # udp tx: 1649 MB/s 27970 calls/s 27970 msg/s
16:08:19 DEBUG| [stdout] # udp rx: 1556 MB/s 1134898 calls/s
16:08:19 DEBUG| [stdout] # udp tx: 1558 MB/s 26438 calls/s 26438 msg/s
16:08:20 DEBUG| [stdout] # udp rx: 1060 MB/s 773195 calls/s
16:08:20 DEBUG| [stdout] # Summary over 3.000 seconds...
16:08:20 DEBUG| [stdout] # sum udp tx: 1629 MB/s 80976 calls (26992/s) 80976 msgs (26992/s)
16:08:20 DEBUG| [stdout] # Tx Timestamps: 80976 received 0 errors
16:08:20 DEBUG| [stdout] # Zerocopy acks: 80976
16:08:20 DEBUG| [stdout] # udpgso_bench.sh: PAS...

Failing on Hirsute with connection refused:

16:08:04 DEBUG| [stdout] # udp
16:08:04 DEBUG| [stdout] # ./udpgso_bench_tx: write: Connection refused
16:08:04 DEBUG| [stdout] # udp gso
16:08:04 DEBUG| [stdout] # ./udpgso_bench_tx: sendmsg: Connection refused
16:08:04 DEBUG| [stdout] # udp gso zerocopy
16:08:05 DEBUG| [stdout] # udp rx:   1439 MB/s  1049992 calls/s
16:08:05 DEBUG| [stdout] # udp tx:   1848 MB/s    31355 calls/s  31355 msg/s
16:08:06 DEBUG| [stdout] # udp rx:   1795 MB/s  1309319 calls/s
16:08:06 DEBUG| [stdout] # udp tx:   1793 MB/s    30427 calls/s  30427 msg/s
16:08:07 DEBUG| [stdout] # udp tx:   1798 MB/s    30510 calls/s  30510 msg/s
16:08:07 DEBUG| [stdout] # udp gso timestamp
16:08:08 DEBUG| [stdout] # udp rx:   1696 MB/s  1236924 calls/s
16:08:08 DEBUG| [stdout] # udp tx:   1828 MB/s    31014 calls/s  31014 msg/s
16:08:09 DEBUG| [stdout] # udp tx:   2127 MB/s    36091 calls/s  36091 msg/s
16:08:09 DEBUG| [stdout] # udp rx:    543 MB/s   395969 calls/s
16:08:10 DEBUG| [stdout] # udp tx:   2135 MB/s    36220 calls/s  36220 msg/s
16:08:10 DEBUG| [stdout] # udp gso zerocopy audit
16:08:11 DEBUG| [stdout] # udp rx:    705 MB/s   514380 calls/s
16:08:11 DEBUG| [stdout] # udp tx:   1956 MB/s    33179 calls/s  33179 msg/s
16:08:12 DEBUG| [stdout] # udp rx:    600 MB/s   438206 calls/s
16:08:12 DEBUG| [stdout] # udp tx:   1971 MB/s    33442 calls/s  33442 msg/s
16:08:13 DEBUG| [stdout] # udp tx:   1967 MB/s    33366 calls/s  33366 msg/s
16:08:13 DEBUG| [stdout] # Summary over 3.000 seconds...
16:08:13 DEBUG| [stdout] # sum udp tx:   2012 MB/s      99987 calls (33329/s)      99987 msgs (33329/s)
16:08:13 DEBUG| [stdout] # Zerocopy acks:               99987
16:08:13 DEBUG| [stdout] # udp rx:    668 MB/s   487594 calls/s
16:08:13 DEBUG| [stdout] # udp gso timestamp audit
16:08:14 DEBUG| [stdout] # udp tx:   1923 MB/s    32629 calls/s  32629 msg/s
16:08:14 DEBUG| [stdout] # udp rx:   1464 MB/s  1068101 calls/s
16:08:15 DEBUG| [stdout] # udp tx:   2127 MB/s    36086 calls/s  36086 msg/s
16:08:15 DEBUG| [stdout] # udp rx:    528 MB/s   385353 calls/s
16:08:16 DEBUG| [stdout] # udp tx:   2109 MB/s    35783 calls/s  35783 msg/s
16:08:17 DEBUG| [stdout] # Summary over 3.000 seconds...
16:08:17 DEBUG| [stdout] # sum udp tx:   2103 MB/s     104498 calls (34832/s)     104498 msgs (34832/s)
16:08:17 DEBUG| [stdout] # Tx Timestamps:              104498 received                 0 errors
16:08:17 DEBUG| [stdout] # udp gso zerocopy timestamp audit
16:08:18 DEBUG| [stdout] # udp rx:   1646 MB/s  1200968 calls/s
16:08:18 DEBUG| [stdout] # udp tx:   1649 MB/s    27970 calls/s  27970 msg/s
16:08:19 DEBUG| [stdout] # udp rx:   1556 MB/s  1134898 calls/s
16:08:19 DEBUG| [stdout] # udp tx:   1558 MB/s    26438 calls/s  26438 msg/s
16:08:20 DEBUG| [stdout] # udp rx:   1060 MB/s   773195 calls/s
16:08:20 DEBUG| [stdout] # Summary over 3.000 seconds...
16:08:20 DEBUG| [stdout] # sum udp tx:   1629 MB/s      80976 calls (26992/s)      80976 msgs (26992/s)
16:08:20 DEBUG| [stdout] # Tx Timestamps:               80976 received                 0 errors
16:08:20 DEBUG| [stdout] # Zerocopy acks:               80976
16:08:20 DEBUG| [stdout] # udpgso_bench.sh: PASS=16 SKIP=0 FAIL=2
16:08:20 DEBUG| [stdout] # udpgso_bench.sh: [0;31mFAIL[0m
16:08:20 DEBUG| [stdout] not ok 19 selftests: net: udpgso_bench.sh # exit=1
16:08:20 DEBUG| [stdout] # selftests: net: fib_rule_tests.sh
16:08:20 DEBUG| [stdout] # net.ipv4.ip_forward = 1
16:08:20 DEBUG| [stdout] #

tags:

added: 5.11 hirsute sru-20210719

Kleber Sacilotto de Souza (kleber-souza) on 2021-09-08

summary:

- udpgso_bench from net in ubuntu_kernel_selftests fails on Groovy
+ udpgso_bench from net in ubuntu_kernel_selftests fails on Groovy/Hirsute

Revision history for this message

Kleber Sacilotto de Souza (kleber-souza) wrote on 2021-09-20: Re: udpgso_bench from net in ubuntu_kernel_selftests fails on Groovy/Hirsute

Also spotted with bionic/linux-hwe-5.4 5.4.0-85.95~18.04.1.

tags:

added: 5.4 sru-20210906

Revision history for this message

Krzysztof Kozlowski (krzk) wrote on 2021-11-30:

Found on 2021.11.08/bionic/linux-azure-5.4/5.4.0-1064.67~18.04.1

tags:

added: azure bionic hinted sru-20211108

Revision history for this message

Po-Hsu Lin (cypressyew) wrote on 2021-12-17:

This test seems to be a bit flaky on our RT matrix.

Changed in ubuntu-kernel-tests:
status:	Incomplete → Confirmed
tags:	added: sru-20211129

Revision history for this message

Kleber Sacilotto de Souza (kleber-souza) wrote on 2022-02-08: Re: udpgso_bench from net in ubuntu_kernel_selftests fails on Groovy/Hirsute/Impish

Found the same flakyness with impish/linux 5.13.0-30.33:

https://autopkgtest.ubuntu.com/results/autopkgtest-impish/impish/amd64/l/linux/20220207_204034_e45f6@/log.gz

Issue found only on ADT amd64, not found on other architectures or on RT. I also wasn't able to reproduce on another system.

summary:

- udpgso_bench from net in ubuntu_kernel_selftests fails on Groovy/Hirsute
+ udpgso_bench from net in ubuntu_kernel_selftests fails on
+ Groovy/Hirsute/Impish

Kleber Sacilotto de Souza (kleber-souza) on 2022-02-08

tags:

added: 5.13 sru-20220131

Kleber Sacilotto de Souza (kleber-souza) on 2022-09-13