This enhancement adds options that facilitate load testing with additional TX CMSG options, and to optionally print results of various send CMSG operations.

These options are especially useful in isolating situations where error-queue messages are lost when combined with other CMSG operations (e.g. SO_ZEROCOPY).

New options:

-a - count all CMSG messages and match to sent messages -T - add TX CMSG that requests TX software timestamps -H - similar to -T except request TX hardware timestamps -P - call poll() before reading error queue -v - print detailed results

v2: Enhancements as per Willem de Bruijn willemb@google.com - Updated control and buffer parameters for recvmsg - poll() parameter cleanup - fail on bad audit results - remove TOS options - improved reporting

Signed-off-by: Fred Klassen fklassen@appneta.com --- tools/testing/selftests/net/udpgso_bench_tx.c | 324 ++++++++++++++++++++++++-- 1 file changed, 307 insertions(+), 17 deletions(-)

diff --git a/tools/testing/selftests/net/udpgso_bench_tx.c b/tools/testing/selftests/net/udpgso_bench_tx.c index 4074538b5df5..8506c7c2c354 100644 --- a/tools/testing/selftests/net/udpgso_bench_tx.c +++ b/tools/testing/selftests/net/udpgso_bench_tx.c @@ -5,6 +5,8 @@ #include <arpa/inet.h> #include <errno.h> #include <error.h> +#include <linux/errqueue.h> +#include <linux/net_tstamp.h> #include <netinet/if_ether.h> #include <netinet/in.h> #include <netinet/ip.h> @@ -19,6 +21,7 @@ #include <string.h> #include <sys/socket.h> #include <sys/time.h> +#include <sys/poll.h> #include <sys/types.h> #include <unistd.h>

@@ -34,6 +37,10 @@ #define SO_ZEROCOPY 60 #endif

+#ifndef SO_EE_ORIGIN_ZEROCOPY +#define SO_EE_ORIGIN_ZEROCOPY 5 +#endif + #ifndef MSG_ZEROCOPY #define MSG_ZEROCOPY 0x4000000 #endif @@ -48,12 +55,25 @@ static uint16_t cfg_mss; static int cfg_payload_len = (1472 * 42); static int cfg_port = 8000; static int cfg_runtime_ms = -1; +static bool cfg_poll; static bool cfg_segment; static bool cfg_sendmmsg; static bool cfg_tcp; +static uint32_t cfg_tx_ts = SOF_TIMESTAMPING_TX_SOFTWARE; +static bool cfg_tx_tstamp; +static bool cfg_audit; +static bool cfg_verbose; static bool cfg_zerocopy; static int cfg_msg_nr; static uint16_t cfg_gso_size; +static unsigned long total_num_msgs; +static unsigned long total_num_sends; +static unsigned long stat_tx_ts; +static unsigned long stat_tx_ts_errors; +static unsigned long tstart; +static unsigned long tend; +static unsigned long stat_zcopies; +static unsigned long stat_zcopy_errors;

static socklen_t cfg_alen; static struct sockaddr_storage cfg_dst_addr; @@ -110,23 +130,149 @@ static void setup_sockaddr(int domain, const char *str_addr, void *sockaddr) } }

-static void flush_zerocopy(int fd) +static void flush_cmsg(struct cmsghdr *cmsg) { - struct msghdr msg = {0}; /* flush */ + switch (cmsg->cmsg_level) { + case SOL_SOCKET: + if (cmsg->cmsg_type == SO_TIMESTAMPING) { + int i; + + i = (cfg_tx_ts == SOF_TIMESTAMPING_TX_HARDWARE) ? 2 : 0; + struct scm_timestamping *tss; + + tss = (struct scm_timestamping *)CMSG_DATA(cmsg); + if (tss->ts[i].tv_sec == 0) + stat_tx_ts_errors++; + } else { + error(1, 0, + "unknown SOL_SOCKET cmsg type=%u level=%u\n", + cmsg->cmsg_type, cmsg->cmsg_level); + } + break; + case SOL_IP: + case SOL_IPV6: + switch (cmsg->cmsg_type) { + case IP_RECVERR: + case IPV6_RECVERR: + { + struct sock_extended_err *err; + + err = (struct sock_extended_err *)CMSG_DATA(cmsg); + switch (err->ee_origin) { + case SO_EE_ORIGIN_TIMESTAMPING: + // Got a TX timestamp from error queue + stat_tx_ts++; + break; + case SO_EE_ORIGIN_ICMP: + case SO_EE_ORIGIN_ICMP6: + if (cfg_verbose) + fprintf(stderr, + "received ICMP error: type=%u, code=%u\n", + err->ee_type, err->ee_code); + break; + case SO_EE_ORIGIN_ZEROCOPY: + { + __u32 lo = err->ee_info; + __u32 hi = err->ee_data; + + if (hi == lo - 1) { + // TX was aborted + stat_zcopy_errors++; + if (cfg_verbose) + fprintf(stderr, + "Zerocopy TX aborted: lo=%u hi=%u\n", + lo, hi); + } else if (hi == lo) { + // single ID acknowledged + stat_zcopies++; + } else { + // range of IDs acknowledged + stat_zcopies += hi - lo + 1; + } + break; + } + case SO_EE_ORIGIN_LOCAL: + if (cfg_verbose) + fprintf(stderr, + "received packet with local origin: %u\n", + err->ee_origin); + break; + default: + error(0, 1, + "received packet with origin: %u", + err->ee_origin); + } + + break; + } + default: + error(0, 1, "unknown IP msg type=%u level=%u\n", + cmsg->cmsg_type, cmsg->cmsg_level); + break; + } + break; + default: + error(0, 1, "unknown cmsg type=%u level=%u\n", + cmsg->cmsg_type, cmsg->cmsg_level); + } +} + +static void flush_errqueue_recv(int fd) +{ + char control[CMSG_SPACE(sizeof(struct scm_timestamping)) + + CMSG_SPACE(sizeof(struct sock_extended_err)) + + CMSG_SPACE(sizeof(struct sockaddr_in6))] = {0}; + char buf[cfg_payload_len]; + struct msghdr msg = {0}; + struct cmsghdr *cmsg; + struct iovec entry; int ret;

+ /* add a buffer to the message to avoid MSG_TRUNC msg_flag */ + entry.iov_base = buf; + entry.iov_len = sizeof(buf); + msg.msg_iovlen = 1; + msg.msg_iov = &entry; + while (1) { + msg.msg_control = control; + msg.msg_controllen = sizeof(control); ret = recvmsg(fd, &msg, MSG_ERRQUEUE); if (ret == -1 && errno == EAGAIN) break; if (ret == -1) error(1, errno, "errqueue"); - if (msg.msg_flags != (MSG_ERRQUEUE | MSG_CTRUNC)) + if (msg.msg_flags != MSG_ERRQUEUE) error(1, 0, "errqueue: flags 0x%x\n", msg.msg_flags); + if (cfg_audit) { + for (cmsg = CMSG_FIRSTHDR(&msg); + cmsg; + cmsg = CMSG_NXTHDR(&msg, cmsg)) + flush_cmsg(cmsg); + } msg.msg_flags = 0; } }

+static void flush_errqueue(int fd, const bool do_poll) +{ + if (do_poll) { + struct pollfd fds = {0}; + int ret; + + fds.fd = fd; + ret = poll(&fds, 1, 500); + if (ret == 0) { + if (cfg_verbose) + fprintf(stderr, "poll timeout\n"); + } else if (ret < 0) { + error(1, errno, "poll"); + } + } + + flush_errqueue_recv(fd); +} + static int send_tcp(int fd, char *data) { int ret, done = 0, count = 0; @@ -168,16 +314,40 @@ static int send_udp(int fd, char *data) return count; }

+static void send_ts_cmsg(struct cmsghdr *cm) +{ + uint32_t *valp; + + cm->cmsg_level = SOL_SOCKET; + cm->cmsg_type = SO_TIMESTAMPING; + cm->cmsg_len = CMSG_LEN(sizeof(cfg_tx_ts)); + valp = (void *)CMSG_DATA(cm); + *valp = cfg_tx_ts; +} + static int send_udp_sendmmsg(int fd, char *data) { + char control[CMSG_SPACE(sizeof(cfg_tx_ts))] = {0}; const int max_nr_msg = ETH_MAX_MTU / ETH_DATA_LEN; struct mmsghdr mmsgs[max_nr_msg]; struct iovec iov[max_nr_msg]; unsigned int off = 0, left; + size_t msg_controllen = 0; int i = 0, ret;

memset(mmsgs, 0, sizeof(mmsgs));

+ if (cfg_tx_tstamp) { + struct msghdr msg = {0}; + struct cmsghdr *cmsg; + + msg.msg_control = control; + msg.msg_controllen = sizeof(control); + cmsg = CMSG_FIRSTHDR(&msg); + send_ts_cmsg(cmsg); + msg_controllen += CMSG_SPACE(sizeof(cfg_tx_ts)); + } + left = cfg_payload_len; while (left) { if (i == max_nr_msg) @@ -188,6 +358,12 @@ static int send_udp_sendmmsg(int fd, char *data)

mmsgs[i].msg_hdr.msg_iov = iov + i; mmsgs[i].msg_hdr.msg_iovlen = 1; + mmsgs[i].msg_hdr.msg_name = (void *)&cfg_dst_addr; + mmsgs[i].msg_hdr.msg_namelen = cfg_alen; + if (msg_controllen) { + mmsgs[i].msg_hdr.msg_control = control; + mmsgs[i].msg_hdr.msg_controllen = msg_controllen; + }

off += iov[i].iov_len; left -= iov[i].iov_len; @@ -214,9 +390,12 @@ static void send_udp_segment_cmsg(struct cmsghdr *cm)

static int send_udp_segment(int fd, char *data) { - char control[CMSG_SPACE(sizeof(cfg_gso_size))] = {0}; + char control[CMSG_SPACE(sizeof(cfg_gso_size)) + + CMSG_SPACE(sizeof(cfg_tx_ts))] = {0}; struct msghdr msg = {0}; struct iovec iov = {0}; + size_t msg_controllen; + struct cmsghdr *cmsg; int ret;

iov.iov_base = data; @@ -227,8 +406,16 @@ static int send_udp_segment(int fd, char *data)

msg.msg_control = control; msg.msg_controllen = sizeof(control); - send_udp_segment_cmsg(CMSG_FIRSTHDR(&msg)); + cmsg = CMSG_FIRSTHDR(&msg); + send_udp_segment_cmsg(cmsg); + msg_controllen = CMSG_SPACE(sizeof(cfg_mss)); + if (cfg_tx_tstamp) { + cmsg = CMSG_NXTHDR(&msg, cmsg); + send_ts_cmsg(cmsg); + msg_controllen += CMSG_SPACE(sizeof(cfg_tx_ts)); + }

+ msg.msg_controllen = msg_controllen; msg.msg_name = (void *)&cfg_dst_addr; msg.msg_namelen = cfg_alen;

@@ -236,15 +423,16 @@ static int send_udp_segment(int fd, char *data) if (ret == -1) error(1, errno, "sendmsg"); if (ret != iov.iov_len) - error(1, 0, "sendmsg: %u != %lu\n", ret, iov.iov_len); + error(1, 0, "sendmsg: %u != %lu", ret, iov.iov_len);

return 1; }

static void usage(const char *filepath) { - error(1, 0, "Usage: %s [-46cmtuz] [-C cpu] [-D dst ip] [-l secs] [-m messagenr] [-p port] [-s sendsize] [-S gsosize]", - filepath); + error(1, 0, + "Usage: %s [-46acmHPtTuvz] [-C cpu] [-D dst ip] [-l secs] [-M messagenr] [-p port] [-s sendsize] [-S gsosize]", + filepath); }

static void parse_opts(int argc, char **argv) @@ -252,7 +440,7 @@ static void parse_opts(int argc, char **argv) int max_len, hdrlen; int c;

- while ((c = getopt(argc, argv, "46cC:D:l:mM:p:s:S:tuz")) != -1) { + while ((c = getopt(argc, argv, "46acC:D:Hl:mM:p:s:PS:tTuvz")) != -1) { switch (c) { case '4': if (cfg_family != PF_UNSPEC) @@ -266,6 +454,9 @@ static void parse_opts(int argc, char **argv) cfg_family = PF_INET6; cfg_alen = sizeof(struct sockaddr_in6); break; + case 'a': + cfg_audit = true; + break; case 'c': cfg_cache_trash = true; break; @@ -287,6 +478,9 @@ static void parse_opts(int argc, char **argv) case 'p': cfg_port = strtoul(optarg, NULL, 0); break; + case 'P': + cfg_poll = true; + break; case 's': cfg_payload_len = strtoul(optarg, NULL, 0); break; @@ -294,12 +488,22 @@ static void parse_opts(int argc, char **argv) cfg_gso_size = strtoul(optarg, NULL, 0); cfg_segment = true; break; + case 'H': + cfg_tx_ts = SOF_TIMESTAMPING_TX_HARDWARE; + cfg_tx_tstamp = true; + break; case 't': cfg_tcp = true; break; + case 'T': + cfg_tx_tstamp = true; + break; case 'u': cfg_connected = false; break; + case 'v': + cfg_verbose = true; + break; case 'z': cfg_zerocopy = true; break; @@ -315,6 +519,8 @@ static void parse_opts(int argc, char **argv) error(1, 0, "connectionless tcp makes no sense"); if (cfg_segment && cfg_sendmmsg) error(1, 0, "cannot combine segment offload and sendmmsg"); + if (cfg_tx_tstamp && !(cfg_segment || cfg_sendmmsg)) + error(1, 0, "Options -T and -H require either -S or -m option");

if (cfg_family == PF_INET) hdrlen = sizeof(struct iphdr) + sizeof(struct udphdr); @@ -349,6 +555,79 @@ static void set_pmtu_discover(int fd, bool is_ipv4) error(1, errno, "setsockopt path mtu"); }

+static void set_tx_timestamping(int fd) +{ + int val = SOF_TIMESTAMPING_OPT_CMSG | SOF_TIMESTAMPING_OPT_ID; + + if (cfg_tx_ts == SOF_TIMESTAMPING_TX_SOFTWARE) + val |= SOF_TIMESTAMPING_SOFTWARE; + else + val |= SOF_TIMESTAMPING_RAW_HARDWARE; + + if (setsockopt(fd, SOL_SOCKET, SO_TIMESTAMPING, &val, sizeof(val))) + error(1, errno, "setsockopt tx timestamping"); +} + +static void print_audit_report(unsigned long num_msgs, unsigned long num_sends) +{ + unsigned long tdelta; + + tdelta = tend - tstart; + if (!tdelta) + return; + + fprintf(stderr, "Summary over %lu.%03lu seconds...\n", + tdelta / 1000, tdelta % 1000); + fprintf(stderr, + "sum %s tx: %6lu MB/s %10lu calls (%lu/s) %10lu msgs (%lu/s)\n", + cfg_tcp ? "tcp" : "udp", + ((num_msgs * cfg_payload_len) >> 10) / tdelta, + num_sends, num_sends * 1000 / tdelta, + num_msgs, num_msgs * 1000 / tdelta); + + if (cfg_tx_tstamp) { + if (stat_tx_ts_errors) + error(1, 0, + "Expected clean TX Timestamps: %9lu msgs received %6lu errors", + stat_tx_ts, stat_tx_ts_errors); + if (stat_tx_ts != num_sends) + error(1, 0, + "Unexpected number of TX Timestamps: %9lu expected %9lu received", + num_sends, stat_tx_ts); + fprintf(stderr, + "Tx Timestamps: %19lu received %17lu errors\n", + stat_tx_ts, stat_tx_ts_errors); + } + + if (cfg_zerocopy) { + if (stat_zcopy_errors) + error(1, 0, + "Expected clean Zerocopies: %9lu msgs received %6lu errors", + stat_zcopies, stat_zcopy_errors); + if (stat_zcopies != num_sends) + error(1, 0, + "Unexpected number of Zerocopy completions: %9lu expected %9lu received", + num_sends, stat_zcopies); + fprintf(stderr, + "Zerocopy acks: %19lu received %17lu errors\n", + stat_zcopies, stat_zcopy_errors); + } +} + +static void print_report(unsigned long num_msgs, unsigned long num_sends) +{ + fprintf(stderr, + "%s tx: %6lu MB/s %8lu calls/s %6lu msg/s\n", + cfg_tcp ? "tcp" : "udp", + (num_msgs * cfg_payload_len) >> 20, + num_sends, num_msgs); + + if (cfg_audit) { + total_num_msgs += num_msgs; + total_num_sends += num_sends; + } +} + int main(int argc, char **argv) { unsigned long num_msgs, num_sends; @@ -384,8 +663,13 @@ int main(int argc, char **argv) if (cfg_segment) set_pmtu_discover(fd, cfg_family == PF_INET);

+ if (cfg_tx_tstamp) + set_tx_timestamping(fd); + num_msgs = num_sends = 0; tnow = gettimeofday_ms(); + tstart = tnow; + tend = tnow; tstop = tnow + cfg_runtime_ms; treport = tnow + 1000;

@@ -400,19 +684,15 @@ int main(int argc, char **argv) else num_sends += send_udp(fd, buf[i]); num_msgs++; - if (cfg_zerocopy && ((num_msgs & 0xF) == 0)) - flush_zerocopy(fd); + if ((cfg_zerocopy && ((num_msgs & 0xF) == 0)) || cfg_tx_tstamp) + flush_errqueue(fd, cfg_poll);

if (cfg_msg_nr && num_msgs >= cfg_msg_nr) break;

tnow = gettimeofday_ms(); - if (tnow > treport) { - fprintf(stderr, - "%s tx: %6lu MB/s %8lu calls/s %6lu msg/s\n", - cfg_tcp ? "tcp" : "udp", - (num_msgs * cfg_payload_len) >> 20, - num_sends, num_msgs); + if (tnow >= treport) { + print_report(num_msgs, num_sends); num_msgs = num_sends = 0; treport = tnow + 1000; } @@ -423,8 +703,18 @@ int main(int argc, char **argv)

} while (!interrupted && (cfg_runtime_ms == -1 || tnow < tstop));

+ if (cfg_zerocopy || cfg_tx_tstamp) + flush_errqueue(fd, true); + if (close(fd)) error(1, errno, "close");

+ if (cfg_audit) { + tend = tnow; + total_num_msgs += num_msgs; + total_num_sends += num_sends; + print_audit_report(total_num_msgs, total_num_sends); + } + return 0; }

Audit tests count the total number of messages sent and compares with total number of CMSG received on error queue. Example:

udp gso zerocopy timestamp audit udp rx: 1599 MB/s 1166414 calls/s udp tx: 1615 MB/s 27395 calls/s 27395 msg/s udp rx: 1634 MB/s 1192261 calls/s udp tx: 1633 MB/s 27699 calls/s 27699 msg/s udp rx: 1633 MB/s 1191358 calls/s udp tx: 1631 MB/s 27678 calls/s 27678 msg/s Summary over 4.000 seconds... sum udp tx: 1665 MB/s 82772 calls (27590/s) 82772 msgs (27590/s) Tx Timestamps: 82772 received 0 errors Zerocopy acks: 82772 received 0 errors

Errors are thrown if CMSG count does not equal send count, example:

Summary over 4.000 seconds... sum tcp tx: 7451 MB/s 493706 calls (123426/s) 493706 msgs (123426/s) ./udpgso_bench_tx: Unexpected number of Zerocopy completions: 493706 expected 493704 received

Also reduce individual test time from 4 to 3 seconds so that overall test time does not increase significantly.

Signed-off-by: Fred Klassen fklassen@appneta.com --- tools/testing/selftests/net/udpgso_bench.sh | 18 +++++++++++++++++- 1 file changed, 17 insertions(+), 1 deletion(-)

diff --git a/tools/testing/selftests/net/udpgso_bench.sh b/tools/testing/selftests/net/udpgso_bench.sh index 5670a9ffd8eb..89c7de97b832 100755 --- a/tools/testing/selftests/net/udpgso_bench.sh +++ b/tools/testing/selftests/net/udpgso_bench.sh @@ -38,6 +38,18 @@ run_udp() {

echo "udp gso zerocopy" run_in_netns ${args} -S 0 -z + + echo "udp gso timestamp" + run_in_netns ${args} -S 0 -T + + echo "udp gso zerocopy audit" + run_in_netns ${args} -S 0 -z -a + + echo "udp gso timestamp audit" + run_in_netns ${args} -S 0 -T -a + + echo "udp gso zerocopy timestamp audit" + run_in_netns ${args} -S 0 -T -z -a }

run_tcp() { @@ -48,10 +60,14 @@ run_tcp() {

echo "tcp zerocopy" run_in_netns ${args} -t -z + + # excluding for now because test fails intermittently + #echo "tcp zerocopy audit" + #run_in_netns ${args} -t -z -P -a }

run_all() { - local -r core_args="-l 4" + local -r core_args="-l 3" local -r ipv4_args="${core_args} -4 -D 127.0.0.1" local -r ipv6_args="${core_args} -6 -D ::1"

Ensure that failure on any individual test results in an overall failure of the test script.

Signed-off-by: Fred Klassen fklassen@appneta.com --- tools/testing/selftests/net/udpgso_bench.sh | 33 +++++++++++++++++++++++++++++ 1 file changed, 33 insertions(+)

diff --git a/tools/testing/selftests/net/udpgso_bench.sh b/tools/testing/selftests/net/udpgso_bench.sh index 89c7de97b832..3a8543b14d3f 100755 --- a/tools/testing/selftests/net/udpgso_bench.sh +++ b/tools/testing/selftests/net/udpgso_bench.sh @@ -3,6 +3,10 @@ # # Run a series of udpgso benchmarks

+GREEN='\033[0;92m' +RED='\033[0;31m' +NC='\033[0m' # No Color + wake_children() { local -r jobs="$(jobs -p)"

@@ -29,59 +33,88 @@ run_in_netns() {

run_udp() { local -r args=$@ + local errors=0

echo "udp" run_in_netns ${args} + errors=$(( $errors + $? ))

echo "udp gso" run_in_netns ${args} -S 0 + errors=$(( $errors + $? ))

echo "udp gso zerocopy" run_in_netns ${args} -S 0 -z + errors=$(( $errors + $? ))

echo "udp gso timestamp" run_in_netns ${args} -S 0 -T + errors=$(( $errors + $? ))

echo "udp gso zerocopy audit" run_in_netns ${args} -S 0 -z -a + errors=$(( $errors + $? ))

echo "udp gso timestamp audit" run_in_netns ${args} -S 0 -T -a + errors=$(( $errors + $? ))

echo "udp gso zerocopy timestamp audit" run_in_netns ${args} -S 0 -T -z -a + errors=$(( $errors + $? )) + + return $errors }

run_tcp() { local -r args=$@ + local errors=0

echo "tcp" run_in_netns ${args} -t + errors=$(( $errors + $? ))

echo "tcp zerocopy" run_in_netns ${args} -t -z + errors=$(( $errors + $? ))

# excluding for now because test fails intermittently #echo "tcp zerocopy audit" #run_in_netns ${args} -t -z -P -a + #errors=$(( $errors + $? )) + + return $errors }

run_all() { local -r core_args="-l 3" local -r ipv4_args="${core_args} -4 -D 127.0.0.1" local -r ipv6_args="${core_args} -6 -D ::1" + local errors=0

echo "ipv4" run_tcp "${ipv4_args}" + errors=$(( $errors + $? )) run_udp "${ipv4_args}" + errors=$(( $errors + $? ))

echo "ipv6" run_tcp "${ipv4_args}" + errors=$(( $errors + $? )) run_udp "${ipv6_args}" + errors=$(( $errors + $? )) + + return $errors }

if [[ $# -eq 0 ]]; then run_all + if [ $? -ne 0 ]; then + echo -e "$(basename $0): ${RED}FAIL${NC}" + exit 1 + fi + + echo -e "$(basename $0): ${GREEN}PASS${NC}" elif [[ $1 == "__subprocess" ]]; then shift run_one $@