On slow machines the SND timestamp sometimes doesn't arrive before we quit. The test only waits as long as the packet delay, so it's easy for a race condition to happen.
Double the wait but do a bit of polling, once the SND timestamp arrives there's no point to wait any longer.
This fixes the "TXTIME abs" failures on debug kernels, like:
Case ICMPv4 - TXTIME abs returned '', expected 'OK'
Signed-off-by: Jakub Kicinski kuba@kernel.org --- CC: shuah@kernel.org CC: linux-kselftest@vger.kernel.org --- tools/testing/selftests/net/cmsg_sender.c | 20 +++++++++++++++----- 1 file changed, 15 insertions(+), 5 deletions(-)
diff --git a/tools/testing/selftests/net/cmsg_sender.c b/tools/testing/selftests/net/cmsg_sender.c index c79e65581dc3..f25268504937 100644 --- a/tools/testing/selftests/net/cmsg_sender.c +++ b/tools/testing/selftests/net/cmsg_sender.c @@ -333,16 +333,17 @@ static const char *cs_ts_info2str(unsigned int info) return "unknown"; }
-static void +static unsigned long cs_read_cmsg(int fd, struct msghdr *msg, char *cbuf, size_t cbuf_sz) { struct sock_extended_err *see; struct scm_timestamping *ts; + unsigned int ts_seen = 0; struct cmsghdr *cmsg; int i, err;
if (!opt.ts.ena) - return; + return 0; msg->msg_control = cbuf; msg->msg_controllen = cbuf_sz;
@@ -396,8 +397,11 @@ cs_read_cmsg(int fd, struct msghdr *msg, char *cbuf, size_t cbuf_sz) printf(" %5s ts%d %lluus\n", cs_ts_info2str(see->ee_info), i, rel_time); + ts_seen |= 1 << see->ee_info; } } + + return ts_seen; }
static void ca_set_sockopts(int fd) @@ -509,10 +513,16 @@ int main(int argc, char *argv[]) err = ERN_SUCCESS;
if (opt.ts.ena) { - /* Make sure all timestamps have time to loop back */ - usleep(opt.txtime.delay); + unsigned long seen; + int i;
- cs_read_cmsg(fd, &msg, cbuf, sizeof(cbuf)); + /* Make sure all timestamps have time to loop back */ + for (i = 0; i < 40; i++) { + seen = cs_read_cmsg(fd, &msg, cbuf, sizeof(cbuf)); + if (seen & (1 << SCM_TSTAMP_SND)) + break; + usleep(opt.txtime.delay / 20); + } }
err_out:
Slow machines can delay scheduling of the packets for milliseconds. Increase the delay to 8ms if KSFT_MACHINE_SLOW. Try to limit the variability by moving setsockopts earlier (before we read time).
This fixes the "TXTIME rel" failures on debug kernels, like:
Case ICMPv4 - TXTIME rel returned '', expected 'OK'
Signed-off-by: Jakub Kicinski kuba@kernel.org --- CC: shuah@kernel.org CC: linux-kselftest@vger.kernel.org --- tools/testing/selftests/net/cmsg_sender.c | 32 +++++++++++++---------- tools/testing/selftests/net/cmsg_time.sh | 7 +++-- 2 files changed, 23 insertions(+), 16 deletions(-)
diff --git a/tools/testing/selftests/net/cmsg_sender.c b/tools/testing/selftests/net/cmsg_sender.c index f25268504937..b2df05ef71cb 100644 --- a/tools/testing/selftests/net/cmsg_sender.c +++ b/tools/testing/selftests/net/cmsg_sender.c @@ -260,15 +260,8 @@ cs_write_cmsg(int fd, struct msghdr *msg, char *cbuf, size_t cbuf_sz) SOL_IPV6, IPV6_HOPLIMIT, &opt.v6.hlimit);
if (opt.txtime.ena) { - struct sock_txtime so_txtime = { - .clockid = CLOCK_MONOTONIC, - }; __u64 txtime;
- if (setsockopt(fd, SOL_SOCKET, SO_TXTIME, - &so_txtime, sizeof(so_txtime))) - error(ERN_SOCKOPT, errno, "setsockopt TXTIME"); - txtime = time_start_mono.tv_sec * (1000ULL * 1000 * 1000) + time_start_mono.tv_nsec + opt.txtime.delay * 1000; @@ -284,13 +277,6 @@ cs_write_cmsg(int fd, struct msghdr *msg, char *cbuf, size_t cbuf_sz) memcpy(CMSG_DATA(cmsg), &txtime, sizeof(txtime)); } if (opt.ts.ena) { - __u32 val = SOF_TIMESTAMPING_SOFTWARE | - SOF_TIMESTAMPING_OPT_TSONLY; - - if (setsockopt(fd, SOL_SOCKET, SO_TIMESTAMPING, - &val, sizeof(val))) - error(ERN_SOCKOPT, errno, "setsockopt TIMESTAMPING"); - cmsg = (struct cmsghdr *)(cbuf + cmsg_len); cmsg_len += CMSG_SPACE(sizeof(__u32)); if (cbuf_sz < cmsg_len) @@ -426,6 +412,24 @@ static void ca_set_sockopts(int fd) setsockopt(fd, SOL_SOCKET, SO_PRIORITY, &opt.sockopt.priority, sizeof(opt.sockopt.priority))) error(ERN_SOCKOPT, errno, "setsockopt SO_PRIORITY"); + + if (opt.txtime.ena) { + struct sock_txtime so_txtime = { + .clockid = CLOCK_MONOTONIC, + }; + + if (setsockopt(fd, SOL_SOCKET, SO_TXTIME, + &so_txtime, sizeof(so_txtime))) + error(ERN_SOCKOPT, errno, "setsockopt TXTIME"); + } + if (opt.ts.ena) { + __u32 val = SOF_TIMESTAMPING_SOFTWARE | + SOF_TIMESTAMPING_OPT_TSONLY; + + if (setsockopt(fd, SOL_SOCKET, SO_TIMESTAMPING, + &val, sizeof(val))) + error(ERN_SOCKOPT, errno, "setsockopt TIMESTAMPING"); + } }
int main(int argc, char *argv[]) diff --git a/tools/testing/selftests/net/cmsg_time.sh b/tools/testing/selftests/net/cmsg_time.sh index af85267ad1e3..1d7e756644bc 100755 --- a/tools/testing/selftests/net/cmsg_time.sh +++ b/tools/testing/selftests/net/cmsg_time.sh @@ -66,10 +66,13 @@ for i in "-4 $TGT4" "-6 $TGT6"; do awk '/SND/ { if ($3 > 1000) print "OK"; }') check_result $? "$ts" "OK" "$prot - TXTIME abs"
- ts=$(ip netns exec $NS ./cmsg_sender -p $p $i 1234 -t -d 1000 | + [ "$KSFT_MACHINE_SLOW" = yes ] && delay=8000 || delay=1000 + + ts=$(ip netns exec $NS ./cmsg_sender -p $p $i 1234 -t -d $delay | awk '/SND/ {snd=$3} /SCHED/ {sch=$3} - END { if (snd - sch > 500) print "OK"; }') + END { if (snd - sch > '$((delay/2))') print "OK"; + else print snd, "-", sch, "<", '$((delay/2))'; }') check_result $? "$ts" "OK" "$prot - TXTIME rel" done done
Jakub Kicinski wrote:
Slow machines can delay scheduling of the packets for milliseconds. Increase the delay to 8ms if KSFT_MACHINE_SLOW. Try to limit the variability by moving setsockopts earlier (before we read time).
This fixes the "TXTIME rel" failures on debug kernels, like:
Case ICMPv4 - TXTIME rel returned '', expected 'OK'
Signed-off-by: Jakub Kicinski kuba@kernel.org
Reviewed-by: Willem de Bruijn willemb@google.com
Jakub Kicinski wrote:
On slow machines the SND timestamp sometimes doesn't arrive before we quit. The test only waits as long as the packet delay, so it's easy for a race condition to happen.
Double the wait but do a bit of polling, once the SND timestamp arrives there's no point to wait any longer.
This fixes the "TXTIME abs" failures on debug kernels, like:
Case ICMPv4 - TXTIME abs returned '', expected 'OK'
Signed-off-by: Jakub Kicinski kuba@kernel.org
Reviewed-by: Willem de Bruijn willemb@google.com
diff --git a/tools/testing/selftests/net/cmsg_sender.c b/tools/testing/selftests/net/cmsg_sender.c index c79e65581dc3..f25268504937 100644 --- a/tools/testing/selftests/net/cmsg_sender.c +++ b/tools/testing/selftests/net/cmsg_sender.c @@ -333,16 +333,17 @@ static const char *cs_ts_info2str(unsigned int info) return "unknown"; } -static void +static unsigned long cs_read_cmsg(int fd, struct msghdr *msg, char *cbuf, size_t cbuf_sz) { struct sock_extended_err *see; struct scm_timestamping *ts;
- unsigned int ts_seen = 0;
nit: mixing unsigned long and unsigned int
Hello:
This series was applied to netdev/net-next.git (main) by Jakub Kicinski kuba@kernel.org:
On Thu, 9 May 2024 17:57:04 -0700 you wrote:
On slow machines the SND timestamp sometimes doesn't arrive before we quit. The test only waits as long as the packet delay, so it's easy for a race condition to happen.
Double the wait but do a bit of polling, once the SND timestamp arrives there's no point to wait any longer.
[...]
Here is the summary with links: - [net-next,1/2] selftests: net: fix timestamp not arriving in cmsg_time.sh https://git.kernel.org/netdev/net-next/c/2d3b8dfd82d7 - [net-next,2/2] selftests: net: increase the delay for relative cmsg_time.sh test https://git.kernel.org/netdev/net-next/c/b9d5f5711dd8
You are awesome, thank you!
linux-kselftest-mirror@lists.linaro.org
-
Jakub Kicinski -
patchwork-bot+netdevbpf＠kernel.org -
Willem de Bruijn