s4:torture/smb2: provide verbose output when we're waiting for potential lease/oplock...

It makes it easier to follow manual tests.

BUG: https://bugzilla.samba.org/show_bug.cgi?id=14449

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

diff --git a/source4/torture/smb2/lease_break_handler.c b/source4/torture/smb2/lease_break_handler.c
index d741127f3d591b70a6004f32ffec783bb30c7936..6c865dc20b1cfc696a56a94cbf8555f484bf2e0c 100644 (file)
--- 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, &timesup);
        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 d55a83964cd0ce200ebc7f3cd0077095939fd69d..c17d32a7344f0905353918744950649885dba0b0 100644 (file)
--- 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, &timesup);
        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