From ae1c3a0d9ae00471cbbc8a7787f026b87e76aa45 Mon Sep 17 00:00:00 2001 From: Stefan Metzmacher Date: Wed, 17 Mar 2021 13:49:28 +0100 Subject: [PATCH] s4:torture/smb2: provide verbose output when we're waiting for potential lease/oplock breaks It makes it easier to follow manual tests. BUG: https://bugzilla.samba.org/show_bug.cgi?id=14449 Signed-off-by: Stefan Metzmacher Reviewed-by: Jeremy Allison --- source4/torture/smb2/lease_break_handler.c | 31 ++++++++++++++++++--- source4/torture/smb2/oplock_break_handler.c | 21 ++++++++++---- 2 files changed, 43 insertions(+), 9 deletions(-) diff --git a/source4/torture/smb2/lease_break_handler.c b/source4/torture/smb2/lease_break_handler.c index d741127f3d5..6c865dc20b1 100644 --- a/source4/torture/smb2/lease_break_handler.c +++ b/source4/torture/smb2/lease_break_handler.c @@ -50,15 +50,31 @@ bool torture_lease_handler(struct smb2_transport *transport, struct smb2_tree *tree = private_data; struct smb2_lease_break_ack io; struct smb2_request *req; + const char *action = NULL; + char *ls = smb2_util_lease_state_string(lease_break_info.tctx, + lb->new_lease_state); + + if (lb->break_flags & SMB2_NOTIFY_BREAK_LEASE_FLAG_ACK_REQUIRED) { + action = "acking"; + } else { + action = "received"; + } lease_break_info.lease_transport = transport; lease_break_info.lease_break = *lb; lease_break_info.count++; if (lease_break_info.lease_skip_ack) { + torture_comment(lease_break_info.tctx, + "transport[%p] Skip %s to %s in lease handler\n", + transport, action, ls); return true; } + torture_comment(lease_break_info.tctx, + "transport[%p] %s to %s in lease handler\n", + transport, action, ls); + if (lb->break_flags & SMB2_NOTIFY_BREAK_LEASE_FLAG_ACK_REQUIRED) { ZERO_STRUCT(io); io.in.lease.lease_key = lb->current_lease.lease_key; @@ -113,19 +129,26 @@ void torture_wait_for_lease_break(struct torture_context *tctx) te = tevent_add_timer(tctx->ev, tmp_ctx, ne, timeout_cb, ×up); if (te == NULL) { - torture_comment(tctx, "Failed to wait for an oplock break. " - "test results may not be accurate."); + torture_comment(tctx, "Failed to wait for an lease break. " + "test results may not be accurate.\n"); goto done; } + torture_comment(tctx, "Waiting for a potential lease break...\n"); while (!timesup && lease_break_info.count < old_count + 1) { if (tevent_loop_once(tctx->ev) != 0) { - torture_comment(tctx, "Failed to wait for an oplock " + torture_comment(tctx, "Failed to wait for a lease " "break. test results may not be " - "accurate."); + "accurate.\n"); goto done; } } + if (timesup) { + torture_comment(tctx, "... waiting for a lease break timed out\n"); + } else { + torture_comment(tctx, "Got %u lease breaks\n", + lease_break_info.count - old_count); + } done: /* We don't know if the timed event fired and was freed, we received diff --git a/source4/torture/smb2/oplock_break_handler.c b/source4/torture/smb2/oplock_break_handler.c index d55a83964cd..c17d32a7344 100644 --- a/source4/torture/smb2/oplock_break_handler.c +++ b/source4/torture/smb2/oplock_break_handler.c @@ -73,9 +73,6 @@ bool torture_oplock_ack_handler(struct smb2_transport *transport, name = "unknown"; break_info.failures++; } - torture_comment(break_info.tctx, - "transport[%p] Acking to %s [0x%02X] in oplock handler\n", - transport, name, level); break_info.br.in.file.handle = *handle; break_info.br.in.oplock_level = level; @@ -85,9 +82,16 @@ bool torture_oplock_ack_handler(struct smb2_transport *transport, SMB_ASSERT(tree->session->transport == transport); if (break_info.oplock_skip_ack) { + torture_comment(break_info.tctx, + "transport[%p] skip acking to %s [0x%02X] in oplock handler\n", + transport, name, level); return true; } + torture_comment(break_info.tctx, + "transport[%p] Acking to %s [0x%02X] in oplock handler\n", + transport, name, level); + req = smb2_break_send(tree, &break_info.br); req->async.fn = torture_oplock_ack_callback; req->async.private_data = NULL; @@ -135,18 +139,25 @@ void torture_wait_for_oplock_break(struct torture_context *tctx) te = tevent_add_timer(tctx->ev, tmp_ctx, ne, timeout_cb, ×up); if (te == NULL) { torture_comment(tctx, "Failed to wait for an oplock break. " - "test results may not be accurate."); + "test results may not be accurate.\n"); goto done; } + torture_comment(tctx, "Waiting for a potential oplock break...\n"); while (!timesup && break_info.count < old_count + 1) { if (tevent_loop_once(tctx->ev) != 0) { torture_comment(tctx, "Failed to wait for an oplock " "break. test results may not be " - "accurate."); + "accurate\n."); goto done; } } + if (timesup) { + torture_comment(tctx, "... waiting for an oplock break timed out\n"); + } else { + torture_comment(tctx, "Got %u oplock breaks\n", + break_info.count - old_count); + } done: /* We don't know if the timed event fired and was freed, we received -- 2.34.1