s3:smb2_server: use async smbprofile macros

This improves profiling and corrently counts the total and idle time for async
requests.

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

6 files changed, 97 insertions, 113 deletions

diff --git a/source3/include/smbprofile.h b/source3/include/smbprofile.h
index bae691b52b..c60f9d95d1 100644
--- a/source3/include/smbprofile.h
+++ b/source3/include/smbprofile.h
@@ -233,25 +233,25 @@
 	SMBPROFILE_STATS_SECTION_END \
 	\
 	SMBPROFILE_STATS_SECTION_START("SMB2 Calls") \
-	SMBPROFILE_STATS_BASIC(smb2_negprot) \
-	SMBPROFILE_STATS_BASIC(smb2_sesssetup) \
-	SMBPROFILE_STATS_BASIC(smb2_logoff) \
-	SMBPROFILE_STATS_BASIC(smb2_tcon) \
-	SMBPROFILE_STATS_BASIC(smb2_tdis) \
-	SMBPROFILE_STATS_BASIC(smb2_create) \
-	SMBPROFILE_STATS_BASIC(smb2_close) \
-	SMBPROFILE_STATS_BASIC(smb2_flush) \
-	SMBPROFILE_STATS_BASIC(smb2_read) \
-	SMBPROFILE_STATS_BASIC(smb2_write) \
-	SMBPROFILE_STATS_BASIC(smb2_lock) \
-	SMBPROFILE_STATS_BASIC(smb2_ioctl) \
-	SMBPROFILE_STATS_BASIC(smb2_cancel) \
-	SMBPROFILE_STATS_BASIC(smb2_keepalive) \
-	SMBPROFILE_STATS_BASIC(smb2_find) \
-	SMBPROFILE_STATS_BASIC(smb2_notify) \
-	SMBPROFILE_STATS_BASIC(smb2_getinfo) \
-	SMBPROFILE_STATS_BASIC(smb2_setinfo) \
-	SMBPROFILE_STATS_BASIC(smb2_break) \
+	SMBPROFILE_STATS_IOBYTES(smb2_negprot) \
+	SMBPROFILE_STATS_IOBYTES(smb2_sesssetup) \
+	SMBPROFILE_STATS_IOBYTES(smb2_logoff) \
+	SMBPROFILE_STATS_IOBYTES(smb2_tcon) \
+	SMBPROFILE_STATS_IOBYTES(smb2_tdis) \
+	SMBPROFILE_STATS_IOBYTES(smb2_create) \
+	SMBPROFILE_STATS_IOBYTES(smb2_close) \
+	SMBPROFILE_STATS_IOBYTES(smb2_flush) \
+	SMBPROFILE_STATS_IOBYTES(smb2_read) \
+	SMBPROFILE_STATS_IOBYTES(smb2_write) \
+	SMBPROFILE_STATS_IOBYTES(smb2_lock) \
+	SMBPROFILE_STATS_IOBYTES(smb2_ioctl) \
+	SMBPROFILE_STATS_IOBYTES(smb2_cancel) \
+	SMBPROFILE_STATS_IOBYTES(smb2_keepalive) \
+	SMBPROFILE_STATS_IOBYTES(smb2_find) \
+	SMBPROFILE_STATS_IOBYTES(smb2_notify) \
+	SMBPROFILE_STATS_IOBYTES(smb2_getinfo) \
+	SMBPROFILE_STATS_IOBYTES(smb2_setinfo) \
+	SMBPROFILE_STATS_IOBYTES(smb2_break) \
 	SMBPROFILE_STATS_SECTION_END \
 	\
 	SMBPROFILE_STATS_END
diff --git a/source3/smbd/globals.h b/source3/smbd/globals.h
index 36e7f0f806..c67c3c3e76 100644
--- a/source3/smbd/globals.h
+++ b/source3/smbd/globals.h
@@ -20,6 +20,7 @@
 
 #include "system/select.h"
 #include "librpc/gen_ndr/smbXsrv.h"
+#include "smbprofile.h"
 
 extern int aio_pending_size;
 extern int outstanding_aio_calls;
@@ -651,6 +652,8 @@ struct smbd_smb2_request {
 
 	struct timeval request_time;
 
+	SMBPROFILE_IOBYTES_ASYNC_STATE(profile);
+
 	/* fake smb1 request. */
 	struct smb_request *smb1req;
 	struct files_struct *compat_chain_fsp;
diff --git a/source3/smbd/smb2_create.c b/source3/smbd/smb2_create.c
index 48bc48674c..31dc3ac223 100644
--- a/source3/smbd/smb2_create.c
+++ b/source3/smbd/smb2_create.c
@@ -957,6 +957,7 @@ static struct tevent_req *smbd_smb2_create_send(TALLOC_CTX *mem_ctx,
 						     &info);
 			if (!NT_STATUS_IS_OK(status)) {
 				if (open_was_deferred(smb1req->xconn, smb1req->mid)) {
+					SMBPROFILE_IOBYTES_ASYNC_SET_IDLE(smb2req->profile);
 					return req;
 				}
 				tevent_req_nterror(req, status);
diff --git a/source3/smbd/smb2_lock.c b/source3/smbd/smb2_lock.c
index d712290fe6..c1607314ae 100644
--- a/source3/smbd/smb2_lock.c
+++ b/source3/smbd/smb2_lock.c
@@ -349,6 +349,7 @@ static struct tevent_req *smbd_smb2_lock_send(TALLOC_CTX *mem_ctx,
 
 	if (async) {
 		tevent_req_defer_callback(req, smb2req->sconn->ev_ctx);
+		SMBPROFILE_IOBYTES_ASYNC_SET_IDLE(smb2req->profile);
 		return req;
 	}
 
@@ -702,6 +703,8 @@ static void reprocess_blocked_smb2_lock(struct smbd_smb2_request *smb2req,
 	if (!smb2req->subreq) {
 		return;
 	}
+	SMBPROFILE_IOBYTES_ASYNC_SET_BUSY(smb2req->profile);
+
 	state = tevent_req_data(smb2req->subreq, struct smbd_smb2_lock_state);
 	if (!state) {
 		return;
@@ -778,6 +781,7 @@ static void reprocess_blocked_smb2_lock(struct smbd_smb2_request *smb2req,
 		fsp_str_dbg(fsp),
 		fsp_fnum_dbg(fsp)));
 
+	SMBPROFILE_IOBYTES_ASYNC_SET_IDLE(smb2req->profile);
         return;
 }
 
diff --git a/source3/smbd/smb2_notify.c b/source3/smbd/smb2_notify.c
index 7b92927864..573635b89d 100644
--- a/source3/smbd/smb2_notify.c
+++ b/source3/smbd/smb2_notify.c
@@ -321,6 +321,7 @@ static struct tevent_req *smbd_smb2_notify_send(TALLOC_CTX *mem_ctx,
 	/* allow this request to be canceled */
 	tevent_req_set_cancel_fn(req, smbd_smb2_notify_cancel);
 
+	SMBPROFILE_IOBYTES_ASYNC_SET_IDLE(state->smb2req->profile);
 	return req;
 }
 
@@ -337,6 +338,8 @@ static void smbd_smb2_notify_reply(struct smb_request *smbreq,
 		return;
 	}
 
+	SMBPROFILE_IOBYTES_ASYNC_SET_BUSY(state->smb2req->profile);
+
 	state->status = error_code;
 	if (!NT_STATUS_IS_OK(error_code)) {
 		/* nothing */
diff --git a/source3/smbd/smb2_server.c b/source3/smbd/smb2_server.c
index 689bfd7561..c801746c5c 100644
--- a/source3/smbd/smb2_server.c
+++ b/source3/smbd/smb2_server.c
@@ -2191,157 +2191,127 @@ NTSTATUS smbd_smb2_request_dispatch(struct smbd_smb2_request *req)
 		SMB_ASSERT(call->need_tcon);
 	}
 
+#define _INBYTES(_r) \
+	iov_buflen(SMBD_SMB2_IN_HDR_IOV(_r), SMBD_SMB2_NUM_IOV_PER_REQ-1)
+
 	switch (opcode) {
 	case SMB2_OP_NEGPROT:
-		{
-			START_PROFILE(smb2_negprot);
-			return_value = smbd_smb2_request_process_negprot(req);
-			END_PROFILE(smb2_negprot);
-		}
+		SMBPROFILE_IOBYTES_ASYNC_START(smb2_negprot, profile_p,
+					       req->profile, _INBYTES(req));
+		return_value = smbd_smb2_request_process_negprot(req);
 		break;
 
 	case SMB2_OP_SESSSETUP:
-		{
-			START_PROFILE(smb2_sesssetup);
-			return_value = smbd_smb2_request_process_sesssetup(req);
-			END_PROFILE(smb2_sesssetup);
-		}
+		SMBPROFILE_IOBYTES_ASYNC_START(smb2_sesssetup, profile_p,
+					       req->profile, _INBYTES(req));
+		return_value = smbd_smb2_request_process_sesssetup(req);
 		break;
 
 	case SMB2_OP_LOGOFF:
-		{
-			START_PROFILE(smb2_logoff);
-			return_value = smbd_smb2_request_process_logoff(req);
-			END_PROFILE(smb2_logoff);
-		}
+		SMBPROFILE_IOBYTES_ASYNC_START(smb2_logoff, profile_p,
+					       req->profile, _INBYTES(req));
+		return_value = smbd_smb2_request_process_logoff(req);
 		break;
 
 	case SMB2_OP_TCON:
-		{
-			START_PROFILE(smb2_tcon);
-			return_value = smbd_smb2_request_process_tcon(req);
-			END_PROFILE(smb2_tcon);
-		}
+		SMBPROFILE_IOBYTES_ASYNC_START(smb2_tcon, profile_p,
+					       req->profile, _INBYTES(req));
+		return_value = smbd_smb2_request_process_tcon(req);
 		break;
 
 	case SMB2_OP_TDIS:
-		{
-			START_PROFILE(smb2_tdis);
-			return_value = smbd_smb2_request_process_tdis(req);
-			END_PROFILE(smb2_tdis);
-		}
+		SMBPROFILE_IOBYTES_ASYNC_START(smb2_tdis, profile_p,
+					       req->profile, _INBYTES(req));
+		return_value = smbd_smb2_request_process_tdis(req);
 		break;
 
 	case SMB2_OP_CREATE:
-		{
-			START_PROFILE(smb2_create);
-			return_value = smbd_smb2_request_process_create(req);
-			END_PROFILE(smb2_create);
+		if (req->subreq == NULL) {
+			SMBPROFILE_IOBYTES_ASYNC_START(smb2_create, profile_p,
+						       req->profile, _INBYTES(req));
+		} else {
+			SMBPROFILE_IOBYTES_ASYNC_SET_BUSY(req->profile);
 		}
+		return_value = smbd_smb2_request_process_create(req);
 		break;
 
 	case SMB2_OP_CLOSE:
-		{
-			START_PROFILE(smb2_close);
-			return_value = smbd_smb2_request_process_close(req);
-			END_PROFILE(smb2_close);
-		}
+		SMBPROFILE_IOBYTES_ASYNC_START(smb2_close, profile_p,
+					       req->profile, _INBYTES(req));
+		return_value = smbd_smb2_request_process_close(req);
 		break;
 
 	case SMB2_OP_FLUSH:
-		{
-			START_PROFILE(smb2_flush);
-			return_value = smbd_smb2_request_process_flush(req);
-			END_PROFILE(smb2_flush);
-		}
+		SMBPROFILE_IOBYTES_ASYNC_START(smb2_flush, profile_p,
+					       req->profile, _INBYTES(req));
+		return_value = smbd_smb2_request_process_flush(req);
 		break;
 
 	case SMB2_OP_READ:
-		{
-			START_PROFILE(smb2_read);
-			return_value = smbd_smb2_request_process_read(req);
-			END_PROFILE(smb2_read);
-		}
+		SMBPROFILE_IOBYTES_ASYNC_START(smb2_read, profile_p,
+					       req->profile, _INBYTES(req));
+		return_value = smbd_smb2_request_process_read(req);
 		break;
 
 	case SMB2_OP_WRITE:
-		{
-			START_PROFILE(smb2_write);
-			return_value = smbd_smb2_request_process_write(req);
-			END_PROFILE(smb2_write);
-		}
+		SMBPROFILE_IOBYTES_ASYNC_START(smb2_write, profile_p,
+					       req->profile, _INBYTES(req));
+		return_value = smbd_smb2_request_process_write(req);
 		break;
 
 	case SMB2_OP_LOCK:
-		{
-			START_PROFILE(smb2_lock);
-			return_value = smbd_smb2_request_process_lock(req);
-			END_PROFILE(smb2_lock);
-		}
+		SMBPROFILE_IOBYTES_ASYNC_START(smb2_lock, profile_p,
+					       req->profile, _INBYTES(req));
+		return_value = smbd_smb2_request_process_lock(req);
 		break;
 
 	case SMB2_OP_IOCTL:
-		{
-			START_PROFILE(smb2_ioctl);
-			return_value = smbd_smb2_request_process_ioctl(req);
-			END_PROFILE(smb2_ioctl);
-		}
+		SMBPROFILE_IOBYTES_ASYNC_START(smb2_ioctl, profile_p,
+					       req->profile, _INBYTES(req));
+		return_value = smbd_smb2_request_process_ioctl(req);
 		break;
 
 	case SMB2_OP_CANCEL:
-		{
-			START_PROFILE(smb2_cancel);
-			return_value = smbd_smb2_request_process_cancel(req);
-			END_PROFILE(smb2_cancel);
-		}
+		SMBPROFILE_IOBYTES_ASYNC_START(smb2_cancel, profile_p,
+					       req->profile, _INBYTES(req));
+		return_value = smbd_smb2_request_process_cancel(req);
+		SMBPROFILE_IOBYTES_ASYNC_END(req->profile, 0);
 		break;
 
 	case SMB2_OP_KEEPALIVE:
-		{
-			START_PROFILE(smb2_keepalive);
-			return_value = smbd_smb2_request_process_keepalive(req);
-			END_PROFILE(smb2_keepalive);
-		}
+		SMBPROFILE_IOBYTES_ASYNC_START(smb2_keepalive, profile_p,
+					       req->profile, _INBYTES(req));
+		return_value = smbd_smb2_request_process_keepalive(req);
 		break;
 
 	case SMB2_OP_FIND:
-		{
-			START_PROFILE(smb2_find);
-			return_value = smbd_smb2_request_process_find(req);
-			END_PROFILE(smb2_find);
-		}
+		SMBPROFILE_IOBYTES_ASYNC_START(smb2_find, profile_p,
+					       req->profile, _INBYTES(req));
+		return_value = smbd_smb2_request_process_find(req);
 		break;
 
 	case SMB2_OP_NOTIFY:
-		{
-			START_PROFILE(smb2_notify);
-			return_value = smbd_smb2_request_process_notify(req);
-			END_PROFILE(smb2_notify);
-		}
+		SMBPROFILE_IOBYTES_ASYNC_START(smb2_notify, profile_p,
+					       req->profile, _INBYTES(req));
+		return_value = smbd_smb2_request_process_notify(req);
 		break;
 
 	case SMB2_OP_GETINFO:
-		{
-			START_PROFILE(smb2_getinfo);
-			return_value = smbd_smb2_request_process_getinfo(req);
-			END_PROFILE(smb2_getinfo);
-		}
+		SMBPROFILE_IOBYTES_ASYNC_START(smb2_getinfo, profile_p,
+					       req->profile, _INBYTES(req));
+		return_value = smbd_smb2_request_process_getinfo(req);
 		break;
 
 	case SMB2_OP_SETINFO:
-		{
-			START_PROFILE(smb2_setinfo);
-			return_value = smbd_smb2_request_process_setinfo(req);
-			END_PROFILE(smb2_setinfo);
-		}
+		SMBPROFILE_IOBYTES_ASYNC_START(smb2_setinfo, profile_p,
+					       req->profile, _INBYTES(req));
+		return_value = smbd_smb2_request_process_setinfo(req);
 		break;
 
 	case SMB2_OP_BREAK:
-		{
-			START_PROFILE(smb2_break);
-			return_value = smbd_smb2_request_process_break(req);
-			END_PROFILE(smb2_break);
-		}
+		SMBPROFILE_IOBYTES_ASYNC_START(smb2_break, profile_p,
+					       req->profile, _INBYTES(req));
+		return_value = smbd_smb2_request_process_break(req);
 		break;
 
 	default:
@@ -2440,6 +2410,9 @@ static NTSTATUS smbd_smb2_request_reply(struct smbd_smb2_request *req)
 		data_blob_clear_free(&req->last_key);
 	}
 
+	SMBPROFILE_IOBYTES_ASYNC_END(req->profile,
+		iov_buflen(outhdr, SMBD_SMB2_NUM_IOV_PER_REQ-1));
+
 	req->current_idx += SMBD_SMB2_NUM_IOV_PER_REQ;
 
 	if (req->current_idx < req->out.vector_count) {