s4:torture/smb2: add smb2.bench.echo

This test calls SMB2_Echo in a loop per connection.

For 4 connections with 2 parallel loops use this:

time smbtorture //127.0.0.1/m -Uroot%test smb2.bench.echo \
	--option="torture:timelimit=600" \
	--option="torture:nprocs=1" \
	--option="torture:qdepth=2"

Sometimes the bottleneck is the smbtorture process.
In order to bring the smbd process to 100% cpu, you can use
'--option="libsmb:client_guid=6112f7d3-9528-4a2a-8861-0ca129aae6c4"'
and run multiple instances of the test at the same time,
which both talk to the same smbd process.

This is a very useful test to show how many requests are possible
at the raw SMB2 layer.

Signed-off-by: Stefan Metzmacher <metze@samba.org>
Reviewed-by: Jeremy Allison <jra@samba.org>

Autobuild-User(master): Jeremy Allison <jra@samba.org>
Autobuild-Date(master): Thu Aug 11 19:23:37 UTC 2022 on sn-devel-184

1 files changed, 329 insertions, 0 deletions

diff --git a/source4/torture/smb2/create.c b/source4/torture/smb2/create.c
index c944fe45c64..9277488e9d7 100644
--- a/source4/torture/smb2/create.c
+++ b/source4/torture/smb2/create.c
@@ -22,6 +22,7 @@
 #include "includes.h"
 #include "libcli/smb2/smb2.h"
 #include "libcli/smb2/smb2_calls.h"
+#include "libcli/smb/smbXcli_base.h"
 #include "torture/torture.h"
 #include "torture/util.h"
 #include "torture/smb2/proto.h"
@@ -127,6 +128,333 @@
 	}} while (0)
 
 /*
+   stress testing keepalive iops
+ */
+
+struct test_smb2_bench_echo_conn;
+struct test_smb2_bench_echo_loop;
+
+struct test_smb2_bench_echo_state {
+	struct torture_context *tctx;
+	size_t num_conns;
+	struct test_smb2_bench_echo_conn *conns;
+	size_t num_loops;
+	struct test_smb2_bench_echo_loop *loops;
+	struct timeval starttime;
+	int timecount;
+	int timelimit;
+	uint64_t num_finished;
+	double total_latency;
+	double min_latency;
+	double max_latency;
+	bool ok;
+	bool stop;
+};
+
+struct test_smb2_bench_echo_conn {
+	struct test_smb2_bench_echo_state *state;
+	int idx;
+	struct smb2_tree *tree;
+};
+
+struct test_smb2_bench_echo_loop {
+	struct test_smb2_bench_echo_state *state;
+	struct test_smb2_bench_echo_conn *conn;
+	int idx;
+	struct tevent_immediate *im;
+	struct tevent_req *req;
+	struct timeval starttime;
+	uint64_t num_started;
+	uint64_t num_finished;
+	double total_latency;
+	double min_latency;
+	double max_latency;
+	NTSTATUS error;
+};
+
+static void test_smb2_bench_echo_loop_do(
+	struct test_smb2_bench_echo_loop *loop);
+
+static void test_smb2_bench_echo_loop_start(struct tevent_context *ctx,
+						       struct tevent_immediate *im,
+						       void *private_data)
+{
+	struct test_smb2_bench_echo_loop *loop =
+		(struct test_smb2_bench_echo_loop *)
+		private_data;
+
+	test_smb2_bench_echo_loop_do(loop);
+}
+
+static void test_smb2_bench_echo_loop_done(struct tevent_req *req);
+
+static void test_smb2_bench_echo_loop_do(
+	struct test_smb2_bench_echo_loop *loop)
+{
+	struct test_smb2_bench_echo_state *state = loop->state;
+
+	loop->num_started += 1;
+	loop->starttime = timeval_current();
+	loop->req = smb2cli_echo_send(state->loops,
+				      state->tctx->ev,
+				      loop->conn->tree->session->transport->conn,
+				      1000);
+	torture_assert_goto(state->tctx, loop->req != NULL,
+			    state->ok, asserted, "smb2_create_send");
+
+	tevent_req_set_callback(loop->req,
+				test_smb2_bench_echo_loop_done,
+				loop);
+	return;
+asserted:
+	state->stop = true;
+}
+
+static void test_smb2_bench_echo_loop_done(struct tevent_req *req)
+{
+	struct test_smb2_bench_echo_loop *loop =
+		(struct test_smb2_bench_echo_loop *)
+		_tevent_req_callback_data(req);
+	struct test_smb2_bench_echo_state *state = loop->state;
+	double latency = timeval_elapsed(&loop->starttime);
+	TALLOC_CTX *frame = talloc_stackframe();
+
+	torture_assert_goto(state->tctx, loop->req == req,
+			    state->ok, asserted, __location__);
+	loop->error = smb2cli_echo_recv(req);
+	torture_assert_ntstatus_ok_goto(state->tctx, loop->error,
+					state->ok, asserted, __location__);
+	SMB_ASSERT(latency >= 0.000001);
+
+	if (loop->num_finished == 0) {
+		/* first round */
+		loop->min_latency = latency;
+		loop->max_latency = latency;
+	}
+
+	loop->num_finished += 1;
+	loop->total_latency += latency;
+
+	if (latency < loop->min_latency) {
+		loop->min_latency = latency;
+	}
+
+	if (latency > loop->max_latency) {
+		loop->max_latency = latency;
+	}
+
+	TALLOC_FREE(frame);
+	test_smb2_bench_echo_loop_do(loop);
+	return;
+asserted:
+	state->stop = true;
+	TALLOC_FREE(frame);
+}
+
+static void test_smb2_bench_echo_progress(struct tevent_context *ev,
+					  struct tevent_timer *te,
+					  struct timeval current_time,
+					  void *private_data)
+{
+	struct test_smb2_bench_echo_state *state =
+		(struct test_smb2_bench_echo_state *)private_data;
+	uint64_t num_echos = 0;
+	double total_echo_latency = 0;
+	double min_echo_latency = 0;
+	double max_echo_latency = 0;
+	double avs_echo_latency = 0;
+	size_t i;
+
+	state->timecount += 1;
+
+	for (i=0;i<state->num_loops;i++) {
+		struct test_smb2_bench_echo_loop *loop =
+			&state->loops[i];
+
+		num_echos += loop->num_finished;
+		total_echo_latency += loop->total_latency;
+		if (min_echo_latency == 0.0 && loop->min_latency != 0.0) {
+			min_echo_latency = loop->min_latency;
+		}
+		if (loop->min_latency < min_echo_latency) {
+			min_echo_latency = loop->min_latency;
+		}
+		if (max_echo_latency == 0.0) {
+			max_echo_latency = loop->max_latency;
+		}
+		if (loop->max_latency > max_echo_latency) {
+			max_echo_latency = loop->max_latency;
+		}
+		loop->num_finished = 0;
+		loop->total_latency = 0.0;
+	}
+
+	state->num_finished += num_echos;
+	state->total_latency += total_echo_latency;
+	if (state->min_latency == 0.0 && min_echo_latency != 0.0) {
+		state->min_latency = min_echo_latency;
+	}
+	if (min_echo_latency < state->min_latency) {
+		state->min_latency = min_echo_latency;
+	}
+	if (state->max_latency == 0.0) {
+		state->max_latency = max_echo_latency;
+	}
+	if (max_echo_latency > state->max_latency) {
+		state->max_latency = max_echo_latency;
+	}
+
+	if (state->timecount < state->timelimit) {
+		te = tevent_add_timer(state->tctx->ev,
+				      state,
+				      timeval_current_ofs(1, 0),
+				      test_smb2_bench_echo_progress,
+				      state);
+		torture_assert_goto(state->tctx, te != NULL,
+				    state->ok, asserted, "tevent_add_timer");
+
+		if (!torture_setting_bool(state->tctx, "progress", true)) {
+			return;
+		}
+
+		avs_echo_latency = total_echo_latency / num_echos;
+
+		torture_comment(state->tctx,
+				"%.2f second: "
+				"echo[num/s=%llu,avslat=%.6f,minlat=%.6f,maxlat=%.6f]      \r",
+				timeval_elapsed(&state->starttime),
+				(unsigned long long)num_echos,
+				avs_echo_latency,
+				min_echo_latency,
+				max_echo_latency);
+		return;
+	}
+
+	avs_echo_latency = state->total_latency / state->num_finished;
+	num_echos = state->num_finished / state->timelimit;
+
+	torture_comment(state->tctx,
+			"%.2f second: "
+			"echo[num/s=%llu,avslat=%.6f,minlat=%.6f,maxlat=%.6f]\n",
+			timeval_elapsed(&state->starttime),
+			(unsigned long long)num_echos,
+			avs_echo_latency,
+			state->min_latency,
+			state->max_latency);
+
+asserted:
+	state->stop = true;
+}
+
+static bool test_smb2_bench_echo(struct torture_context *tctx,
+			         struct smb2_tree *tree)
+{
+	struct test_smb2_bench_echo_state *state = NULL;
+	bool ret = true;
+	int torture_nprocs = torture_setting_int(tctx, "nprocs", 4);
+	int torture_qdepth = torture_setting_int(tctx, "qdepth", 1);
+	size_t i;
+	size_t li = 0;
+	int timelimit = torture_setting_int(tctx, "timelimit", 10);
+	struct tevent_timer *te = NULL;
+	uint32_t timeout_msec;
+
+	state = talloc_zero(tctx, struct test_smb2_bench_echo_state);
+	torture_assert(tctx, state != NULL, __location__);
+	state->tctx = tctx;
+	state->num_conns = torture_nprocs;
+	state->conns = talloc_zero_array(state,
+			struct test_smb2_bench_echo_conn,
+			state->num_conns);
+	torture_assert(tctx, state->conns != NULL, __location__);
+	state->num_loops = torture_nprocs * torture_qdepth;
+	state->loops = talloc_zero_array(state,
+			struct test_smb2_bench_echo_loop,
+			state->num_loops);
+	torture_assert(tctx, state->loops != NULL, __location__);
+	state->ok = true;
+	state->timelimit = MAX(timelimit, 1);
+
+	timeout_msec = tree->session->transport->options.request_timeout * 1000;
+
+	torture_comment(tctx, "Opening %zu connections\n", state->num_conns);
+
+	for (i=0;i<state->num_conns;i++) {
+		struct smb2_tree *ct = NULL;
+		DATA_BLOB out_input_buffer = data_blob_null;
+		DATA_BLOB out_output_buffer = data_blob_null;
+		size_t pcli;
+
+		state->conns[i].state = state;
+		state->conns[i].idx = i;
+
+		if (!torture_smb2_connection(tctx, &ct)) {
+			torture_comment(tctx, "Failed opening %zu/%zu connections\n", i, state->num_conns);
+			return false;
+		}
+		state->conns[i].tree = talloc_steal(state->conns, ct);
+
+		smb2cli_conn_set_max_credits(ct->session->transport->conn, 8192);
+		smb2cli_ioctl(ct->session->transport->conn,
+			      timeout_msec,
+			      ct->session->smbXcli,
+			      ct->smbXcli,
+			      UINT64_MAX, /* in_fid_persistent */
+			      UINT64_MAX, /* in_fid_volatile */
+			      UINT32_MAX,
+			      0, /* in_max_input_length */
+			      NULL, /* in_input_buffer */
+			      1, /* in_max_output_length */
+			      NULL, /* in_output_buffer */
+			      SMB2_IOCTL_FLAG_IS_FSCTL,
+			      ct,
+			      &out_input_buffer,
+			      &out_output_buffer);
+		torture_assert(tctx,
+		       smbXcli_conn_is_connected(ct->session->transport->conn),
+		       "smbXcli_conn_is_connected");
+
+		for (pcli = 0; pcli < torture_qdepth; pcli++) {
+			struct test_smb2_bench_echo_loop *loop = &state->loops[li];
+
+			loop->idx = li++;
+			loop->state = state;
+			loop->conn = &state->conns[i];
+			loop->im = tevent_create_immediate(state->loops);
+			torture_assert(tctx, loop->im != NULL, __location__);
+
+			tevent_schedule_immediate(loop->im,
+						  tctx->ev,
+						  test_smb2_bench_echo_loop_start,
+						  loop);
+		}
+	}
+
+	torture_comment(tctx, "Opened %zu connections with qdepth=%d => %zu loops\n",
+			state->num_conns, torture_qdepth, state->num_loops);
+
+	torture_comment(tctx, "Running for %d seconds\n", state->timelimit);
+
+	state->starttime = timeval_current();
+
+	te = tevent_add_timer(tctx->ev,
+			      state,
+			      timeval_current_ofs(1, 0),
+			      test_smb2_bench_echo_progress,
+			      state);
+	torture_assert(tctx, te != NULL, __location__);
+
+	while (!state->stop) {
+		int rc = tevent_loop_once(tctx->ev);
+		torture_assert_int_equal(tctx, rc, 0, "tevent_loop_once");
+	}
+
+	torture_comment(tctx, "%.2f seconds\n", timeval_elapsed(&state->starttime));
+	TALLOC_FREE(state);
+	return ret;
+}
+
+/*
   test some interesting combinations found by gentest
  */
 static bool test_create_gentest(struct torture_context *tctx, struct smb2_tree *tree)
@@ -3645,6 +3973,7 @@ struct torture_suite *torture_smb2_bench_init(TALLOC_CTX *ctx)
 
 	torture_suite_add_1smb2_test(suite, "oplock1", test_smb2_bench_oplock);
 	torture_suite_add_1smb2_test(suite, "path-contention-shared", test_smb2_bench_path_contention_shared);
+	torture_suite_add_1smb2_test(suite, "echo", test_smb2_bench_echo);
 
 	suite->description = talloc_strdup(suite, "SMB2-BENCH tests");