r15450: Change profiling data macros to use stack variables rather than

globals. This catches mismatched start/end calls and removes
the need for special nested profiling calls.
(This used to be commit ee750498812190edd3ec52ca3c750258f3b8a97a)

8 files changed, 122 insertions, 60 deletions

diff --git a/source3/include/includes.h b/source3/include/includes.h
index 0eb2ba83aa..3aec0f602a 100644
--- a/source3/include/includes.h
+++ b/source3/include/includes.h
@@ -943,8 +943,6 @@ extern int errno;
 
 #include "msdfs.h"
 
-#include "smbprofile.h"
-
 #include "rap.h"
 
 #include "md5.h"
@@ -1059,11 +1057,30 @@ struct smb_ldap_privates;
 
 #include "smb_ldap.h"
 
+/*
+ * Reasons for cache flush.
+ */
+
+enum flush_reason_enum {
+    SEEK_FLUSH,
+    READ_FLUSH,
+    WRITE_FLUSH,
+    READRAW_FLUSH,
+    OPLOCK_RELEASE_FLUSH,
+    CLOSE_FLUSH,
+    SYNC_FLUSH,
+    SIZECHANGE_FLUSH,
+    /* NUM_FLUSH_REASONS must remain the last value in the enumeration. */
+    NUM_FLUSH_REASONS};
+
 /***** automatically generated prototypes *****/
 #ifndef NO_PROTO_H
 #include "proto.h"
 #endif
 
+/* We need this after proto.h to reference GetTimeOfDay(). */
+#include "smbprofile.h"
+
 /* String routines */
 
 #include "srvstr.h"
diff --git a/source3/include/smbprofile.h b/source3/include/smbprofile.h
index f68a1e240f..dd171ac13e 100644
--- a/source3/include/smbprofile.h
+++ b/source3/include/smbprofile.h
@@ -21,14 +21,6 @@
 
 */
 
-/*
- * Reasons for cache flush.
- */
-
-#define NUM_FLUSH_REASONS 8 /* Keep this in sync with the enum below. */
-enum flush_reason_enum { SEEK_FLUSH, READ_FLUSH, WRITE_FLUSH, READRAW_FLUSH,
-			OPLOCK_RELEASE_FLUSH, CLOSE_FLUSH, SYNC_FLUSH, SIZECHANGE_FLUSH };
-
 /* this file defines the profile structure in the profile shared
    memory area */
 
@@ -417,6 +409,8 @@ extern struct timeval profile_endtime_nested;
 extern BOOL do_profile_flag;
 extern BOOL do_profile_times;
 
+#ifdef WITH_PROFILE
+
 /* these are helper macros - do not call them directly in the code
  * use the DO_PROFILE_* START_PROFILE and END_PROFILE ones
  * below which test for the profile flage first
@@ -424,61 +418,63 @@ extern BOOL do_profile_times;
 #define INC_PROFILE_COUNT(x) profile_p->x++
 #define DEC_PROFILE_COUNT(x) profile_p->x--
 #define ADD_PROFILE_COUNT(x,y) profile_p->x += (y)
-#define PROFILE_TIME \
-	((profile_endtime.tv_sec - profile_starttime.tv_sec) *1000000 + \
-	((int)profile_endtime.tv_usec - (int)profile_starttime.tv_usec))
-#define PROFILE_TIME_NESTED \
-	((profile_endtime_nested.tv_sec - profile_starttime_nested.tv_sec) *1000000 + \
-	((int)profile_endtime_nested.tv_usec - (int)profile_starttime_nested.tv_usec))
 
-#ifdef WITH_PROFILE
+static inline unsigned long long profile_timestamp(void)
+{
+	struct timeval tv;
+	GetTimeOfDay(&tv);
+	return (tv.tv_sec * 1000000) + tv.tv_usec;
+}
+
+/* end of helper macros */
+
 #define DO_PROFILE_INC(x) \
 	if (do_profile_flag) { \
 		INC_PROFILE_COUNT(x); \
 	}
+
 #define DO_PROFILE_DEC(x) \
 	if (do_profile_flag) { \
 		DEC_PROFILE_COUNT(x); \
 	}
+
 #define DO_PROFILE_DEC_INC(x,y) \
 	if (do_profile_flag) { \
 		DEC_PROFILE_COUNT(x); \
 		INC_PROFILE_COUNT(y); \
 	}
+
 #define DO_PROFILE_ADD(x,n) \
 	if (do_profile_flag) { \
 		ADD_PROFILE_COUNT(x,n); \
 	}
+
 #define START_PROFILE(x) \
+	unsigned long long __profstamp_##x = 0; \
 	if (do_profile_flag) { \
-		if (do_profile_times) \
-			GetTimeOfDay(&profile_starttime); \
-		INC_PROFILE_COUNT(x##_count); \
-	}
-#define START_PROFILE_NESTED(x) \
-	if (do_profile_flag) { \
-		if (do_profile_times) \
-			GetTimeOfDay(&profile_starttime_nested); \
+		__profstamp_##x = do_profile_times ? profile_timestamp() : 0;\
 		INC_PROFILE_COUNT(x##_count); \
-	}
+  	}
+
 #define START_PROFILE_BYTES(x,n) \
+	unsigned long long __profstamp_##x = 0; \
 	if (do_profile_flag) { \
-		if (do_profile_times) \
-			GetTimeOfDay(&profile_starttime); \
+		__profstamp_##x = do_profile_times ? profile_timestamp() : 0;\
 		INC_PROFILE_COUNT(x##_count); \
-		ADD_PROFILE_COUNT(x##_bytes,n); \
-	}
+		ADD_PROFILE_COUNT(x##_bytes, n); \
+  	}
+
 #define END_PROFILE(x) \
 	if (do_profile_times) { \
-		GetTimeOfDay(&profile_endtime); \
-		ADD_PROFILE_COUNT(x##_time,PROFILE_TIME); \
+		ADD_PROFILE_COUNT(x##_time, \
+		    profile_timestamp() - __profstamp_##x); \
 	}
-#define END_PROFILE_NESTED(x) \
-	if (do_profile_times) { \
-		GetTimeOfDay(&profile_endtime_nested); \
-		ADD_PROFILE_COUNT(x##_time,PROFILE_TIME_NESTED); \
-	}
-#else
+
+#define START_PROFILE_NESTED(x) START_PROFILE(x)
+#define END_PROFILE_NESTED(x) END_PROFILE(x)
+
+#else /* WITH_PROFILE */
+
 #define DO_PROFILE_INC(x)
 #define DO_PROFILE_DEC(x)
 #define DO_PROFILE_DEC_INC(x,y)
@@ -488,6 +484,7 @@ extern BOOL do_profile_times;
 #define START_PROFILE_BYTES(x,n)
 #define END_PROFILE(x)
 #define END_PROFILE_NESTED(x)
-#endif
+
+#endif /* WITH_PROFILE */
 
 #endif
diff --git a/source3/nmbd/nmbd_incomingdgrams.c b/source3/nmbd/nmbd_incomingdgrams.c
index 09eb7bfa86..880700c72c 100644
--- a/source3/nmbd/nmbd_incomingdgrams.c
+++ b/source3/nmbd/nmbd_incomingdgrams.c
@@ -797,7 +797,7 @@ void process_announce_request(struct subnet_record *subrec, struct packet_struct
 	work->needannounce = True;
 done:
 
-	END_PROFILE(lm_host_announce);
+	END_PROFILE(announce_request);
 }
 
 /*******************************************************************
@@ -838,5 +838,5 @@ void process_lm_announce_request(struct subnet_record *subrec, struct packet_str
 
 done:
 
-	END_PROFILE(lm_host_announce);
+	END_PROFILE(lm_announce_request);
 }
diff --git a/source3/profile/profile.c b/source3/profile/profile.c
index 838383b1af..db8a643042 100644
--- a/source3/profile/profile.c
+++ b/source3/profile/profile.c
@@ -36,11 +36,6 @@ struct profile_stats *profile_p;
 BOOL do_profile_flag = False;
 BOOL do_profile_times = False;
 
-struct timeval profile_starttime;
-struct timeval profile_endtime;
-struct timeval profile_starttime_nested;
-struct timeval profile_endtime_nested;
-
 /****************************************************************************
 receive a set profile level message
 ****************************************************************************/
diff --git a/source3/smbd/nttrans.c b/source3/smbd/nttrans.c
index 96e2c18bc0..3cdc4997b2 100644
--- a/source3/smbd/nttrans.c
+++ b/source3/smbd/nttrans.c
@@ -2719,6 +2719,7 @@ static int handle_nttrans(connection_struct *conn,
 	/* Now we must call the relevant NT_TRANS function */
 	switch(state->call) {
 		case NT_TRANSACT_CREATE:
+		{
 			START_PROFILE_NESTED(NT_transact_create);
 			outsize = call_nt_transact_create(conn, inbuf, outbuf,
 							  size, bufsize, 
@@ -2728,7 +2729,10 @@ static int handle_nttrans(connection_struct *conn,
 							  state->max_data_return);
 			END_PROFILE_NESTED(NT_transact_create);
 			break;
+		}
+
 		case NT_TRANSACT_IOCTL:
+		{
 			START_PROFILE_NESTED(NT_transact_ioctl);
 			outsize = call_nt_transact_ioctl(conn, inbuf, outbuf,
 							 size, bufsize, 
@@ -2737,7 +2741,10 @@ static int handle_nttrans(connection_struct *conn,
 							 &state->data, state->total_data, state->max_data_return);
 			END_PROFILE_NESTED(NT_transact_ioctl);
 			break;
+		}
+
 		case NT_TRANSACT_SET_SECURITY_DESC:
+		{
 			START_PROFILE_NESTED(NT_transact_set_security_desc);
 			outsize = call_nt_transact_set_security_desc(conn, inbuf, outbuf, 
 							 size, bufsize, 
@@ -2746,7 +2753,10 @@ static int handle_nttrans(connection_struct *conn,
 							 &state->data, state->total_data, state->max_data_return);
 			END_PROFILE_NESTED(NT_transact_set_security_desc);
 			break;
+		}
+
 		case NT_TRANSACT_NOTIFY_CHANGE:
+		{
 			START_PROFILE_NESTED(NT_transact_notify_change);
 			outsize = call_nt_transact_notify_change(conn, inbuf, outbuf, 
 							 size, bufsize, 
@@ -2755,7 +2765,10 @@ static int handle_nttrans(connection_struct *conn,
 							 &state->data, state->total_data, state->max_data_return);
 			END_PROFILE_NESTED(NT_transact_notify_change);
 			break;
+		}
+
 		case NT_TRANSACT_RENAME:
+		{
 			START_PROFILE_NESTED(NT_transact_rename);
 			outsize = call_nt_transact_rename(conn, inbuf, outbuf,
 							 size, bufsize, 
@@ -2764,8 +2777,10 @@ static int handle_nttrans(connection_struct *conn,
 							 &state->data, state->total_data, state->max_data_return);
 			END_PROFILE_NESTED(NT_transact_rename);
 			break;
+		}
 
 		case NT_TRANSACT_QUERY_SECURITY_DESC:
+		{
 			START_PROFILE_NESTED(NT_transact_query_security_desc);
 			outsize = call_nt_transact_query_security_desc(conn, inbuf, outbuf, 
 							 size, bufsize, 
@@ -2774,8 +2789,11 @@ static int handle_nttrans(connection_struct *conn,
 							 &state->data, state->total_data, state->max_data_return);
 			END_PROFILE_NESTED(NT_transact_query_security_desc);
 			break;
+		}
+
 #ifdef HAVE_SYS_QUOTAS
 		case NT_TRANSACT_GET_USER_QUOTA:
+		{
 			START_PROFILE_NESTED(NT_transact_get_user_quota);
 			outsize = call_nt_transact_get_user_quota(conn, inbuf, outbuf, 
 							 size, bufsize, 
@@ -2784,7 +2802,10 @@ static int handle_nttrans(connection_struct *conn,
 							 &state->data, state->total_data, state->max_data_return);
 			END_PROFILE_NESTED(NT_transact_get_user_quota);
 			break;
+		}
+
 		case NT_TRANSACT_SET_USER_QUOTA:
+		{
 			START_PROFILE_NESTED(NT_transact_set_user_quota);
 			outsize = call_nt_transact_set_user_quota(conn, inbuf, outbuf, 
 							 size, bufsize, 
@@ -2793,7 +2814,9 @@ static int handle_nttrans(connection_struct *conn,
 							 &state->data, state->total_data, state->max_data_return);
 			END_PROFILE_NESTED(NT_transact_set_user_quota);
 			break;					
+		}
 #endif /* HAVE_SYS_QUOTAS */
+
 		default:
 			/* Error in request */
 			DEBUG(0,("reply_nttrans: Unknown request %d in nttrans call\n",
@@ -2881,7 +2904,7 @@ int reply_nttrans(connection_struct *conn,
 			DEBUG(0,("reply_nttrans: data malloc fail for %u "
 				 "bytes !\n", state->total_data));
 			TALLOC_FREE(state);
-			END_PROFILE(SMBtrans);
+			END_PROFILE(SMBnttrans);
 			return(ERROR_DOS(ERRDOS,ERRnomem));
 		} 
 		if ((dsoff+dscnt < dsoff) || (dsoff+dscnt < dscnt))
@@ -2901,7 +2924,7 @@ int reply_nttrans(connection_struct *conn,
 				 "bytes !\n", state->total_param));
 			SAFE_FREE(state->data);
 			TALLOC_FREE(state);
-			END_PROFILE(SMBtrans);
+			END_PROFILE(SMBnttrans);
 			return(ERROR_DOS(ERRDOS,ERRnomem));
 		} 
 		if ((psoff+pscnt < psoff) || (psoff+pscnt < pscnt))
diff --git a/source3/smbd/reply.c b/source3/smbd/reply.c
index 0524078310..387ed4a47f 100644
--- a/source3/smbd/reply.c
+++ b/source3/smbd/reply.c
@@ -1085,12 +1085,13 @@ int reply_search(connection_struct *conn, char *inbuf,char *outbuf, int dum_size
 	BOOL mask_contains_wcard = False;
 	BOOL allow_long_path_components = (SVAL(inbuf,smb_flg2) & FLAGS2_LONG_PATH_COMPONENTS) ? True : False;
 
+	START_PROFILE(SMBsearch);
+
 	if (lp_posix_pathnames()) {
+		END_PROFILE(SMBsearch);
 		return reply_unknown(inbuf, outbuf);
 	}
 
-	START_PROFILE(SMBsearch);
-
 	*mask = *directory = *fname = 0;
 
 	/* If we were called as SMBffirst then we must expect close. */
@@ -1284,12 +1285,13 @@ int reply_fclose(connection_struct *conn, char *inbuf,char *outbuf, int dum_size
 	NTSTATUS err;
 	BOOL path_contains_wcard = False;
 
+	START_PROFILE(SMBfclose);
+
 	if (lp_posix_pathnames()) {
+		END_PROFILE(SMBfclose);
 		return reply_unknown(inbuf, outbuf);
 	}
 
-	START_PROFILE(SMBfclose);
-
 	outsize = set_message(outbuf,1,0,True);
 	p = smb_buf(inbuf) + 1;
 	p += srvstr_get_path_wcard(inbuf, path, p, sizeof(path), 0, STR_TERMINATE, &err, &path_contains_wcard);
@@ -1517,13 +1519,13 @@ int reply_open_and_X(connection_struct *conn, char *inbuf,char *outbuf,int lengt
 		fsp->initial_allocation_size = smb_roundup(fsp->conn, allocation_size);
 		if (vfs_allocate_file_space(fsp, fsp->initial_allocation_size) == -1) {
 			close_file(fsp,ERROR_CLOSE);
-			END_PROFILE(SMBntcreateX);
+			END_PROFILE(SMBopenX);
 			return ERROR_NT(NT_STATUS_DISK_FULL);
 		}
 		retval = vfs_set_filelen(fsp, (SMB_OFF_T)allocation_size);
 		if (retval < 0) {
 			close_file(fsp,ERROR_CLOSE);
-			END_PROFILE(SMBwrite);
+			END_PROFILE(SMBopenX);
 			return ERROR_NT(NT_STATUS_DISK_FULL);
 		}
 		size = get_allocation_size(conn,fsp,&sbuf);
@@ -2629,7 +2631,6 @@ int send_file_readX(connection_struct *conn, char *inbuf,char *outbuf,int length
 	nread = read_file(fsp,data,startpos,smb_maxcnt);
   
 	if (nread < 0) {
-		END_PROFILE(SMBreadX);
 		return(UNIXERROR(ERRDOS,ERRnoaccess));
 	}
 
diff --git a/source3/smbd/trans2.c b/source3/smbd/trans2.c
index 5d6de951ef..fc14772c57 100644
--- a/source3/smbd/trans2.c
+++ b/source3/smbd/trans2.c
@@ -5011,6 +5011,7 @@ int handle_trans2(connection_struct *conn,
 	/* Now we must call the relevant TRANS2 function */
 	switch(state->call)  {
 	case TRANSACT2_OPEN:
+	{
 		START_PROFILE_NESTED(Trans2_open);
 		outsize = call_trans2open(
 			conn, inbuf, outbuf, bufsize, 
@@ -5019,8 +5020,10 @@ int handle_trans2(connection_struct *conn,
 			state->max_data_return);
 		END_PROFILE_NESTED(Trans2_open);
 		break;
+	}
 
 	case TRANSACT2_FINDFIRST:
+	{
 		START_PROFILE_NESTED(Trans2_findfirst);
 		outsize = call_trans2findfirst(
 			conn, inbuf, outbuf, bufsize,
@@ -5029,8 +5032,10 @@ int handle_trans2(connection_struct *conn,
 			state->max_data_return);
 		END_PROFILE_NESTED(Trans2_findfirst);
 		break;
+	}
 
 	case TRANSACT2_FINDNEXT:
+	{
 		START_PROFILE_NESTED(Trans2_findnext);
 		outsize = call_trans2findnext(
 			conn, inbuf, outbuf, size, bufsize, 
@@ -5039,8 +5044,10 @@ int handle_trans2(connection_struct *conn,
 			state->max_data_return);
 		END_PROFILE_NESTED(Trans2_findnext);
 		break;
+	}
 
 	case TRANSACT2_QFSINFO:
+	{
 		START_PROFILE_NESTED(Trans2_qfsinfo);
 		outsize = call_trans2qfsinfo(
 			conn, inbuf, outbuf, size, bufsize,
@@ -5049,8 +5056,10 @@ int handle_trans2(connection_struct *conn,
 			state->max_data_return);
 		END_PROFILE_NESTED(Trans2_qfsinfo);
 	    break;
+	}
 
 	case TRANSACT2_SETFSINFO:
+	{
 		START_PROFILE_NESTED(Trans2_setfsinfo);
 		outsize = call_trans2setfsinfo(
 			conn, inbuf, outbuf, size, bufsize, 
@@ -5059,9 +5068,11 @@ int handle_trans2(connection_struct *conn,
 			state->max_data_return);
 		END_PROFILE_NESTED(Trans2_setfsinfo);
 		break;
+	}
 
 	case TRANSACT2_QPATHINFO:
 	case TRANSACT2_QFILEINFO:
+	{
 		START_PROFILE_NESTED(Trans2_qpathinfo);
 		outsize = call_trans2qfilepathinfo(
 			conn, inbuf, outbuf, size, bufsize, state->call,
@@ -5070,8 +5081,11 @@ int handle_trans2(connection_struct *conn,
 			state->max_data_return);
 		END_PROFILE_NESTED(Trans2_qpathinfo);
 		break;
+	}
+
 	case TRANSACT2_SETPATHINFO:
 	case TRANSACT2_SETFILEINFO:
+	{
 		START_PROFILE_NESTED(Trans2_setpathinfo);
 		outsize = call_trans2setfilepathinfo(
 			conn, inbuf, outbuf, size, bufsize, state->call,
@@ -5080,8 +5094,10 @@ int handle_trans2(connection_struct *conn,
 			state->max_data_return);
 		END_PROFILE_NESTED(Trans2_setpathinfo);
 		break;
+	}
 
 	case TRANSACT2_FINDNOTIFYFIRST:
+	{
 		START_PROFILE_NESTED(Trans2_findnotifyfirst);
 		outsize = call_trans2findnotifyfirst(
 			conn, inbuf, outbuf, size, bufsize, 
@@ -5090,8 +5106,10 @@ int handle_trans2(connection_struct *conn,
 			state->max_data_return);
 		END_PROFILE_NESTED(Trans2_findnotifyfirst);
 		break;
+	}
 
 	case TRANSACT2_FINDNOTIFYNEXT:
+	{
 		START_PROFILE_NESTED(Trans2_findnotifynext);
 		outsize = call_trans2findnotifynext(
 			conn, inbuf, outbuf, size, bufsize, 
@@ -5100,7 +5118,10 @@ int handle_trans2(connection_struct *conn,
 			state->max_data_return);
 		END_PROFILE_NESTED(Trans2_findnotifynext);
 		break;
+	}
+
 	case TRANSACT2_MKDIR:
+	{
 		START_PROFILE_NESTED(Trans2_mkdir);
 		outsize = call_trans2mkdir(
 			conn, inbuf, outbuf, size, bufsize,
@@ -5109,8 +5130,10 @@ int handle_trans2(connection_struct *conn,
 			state->max_data_return);
 		END_PROFILE_NESTED(Trans2_mkdir);
 		break;
+	}
 
 	case TRANSACT2_GET_DFS_REFERRAL:
+	{
 		START_PROFILE_NESTED(Trans2_get_dfs_referral);
 		outsize = call_trans2getdfsreferral(
 			conn, inbuf, outbuf, size, bufsize,
@@ -5119,7 +5142,10 @@ int handle_trans2(connection_struct *conn,
 			state->max_data_return);
 		END_PROFILE_NESTED(Trans2_get_dfs_referral);
 		break;
+	}
+
 	case TRANSACT2_IOCTL:
+	{
 		START_PROFILE_NESTED(Trans2_ioctl);
 		outsize = call_trans2ioctl(
 			conn, inbuf, outbuf, size, bufsize,
@@ -5128,11 +5154,14 @@ int handle_trans2(connection_struct *conn,
 			state->max_data_return);
 		END_PROFILE_NESTED(Trans2_ioctl);
 		break;
+	}
+
 	default:
 		/* Error in request */
 		DEBUG(2,("Unknown request %d in trans2 call\n", state->call));
 		outsize = ERROR_DOS(ERRSRV,ERRerror);
 	}
+
 	return outsize;
 }
 
@@ -5246,7 +5275,7 @@ int reply_trans2(connection_struct *conn, char *inbuf,char *outbuf,
 				 "bytes !\n", state->total_param));
 			SAFE_FREE(state->data);
 			TALLOC_FREE(state);
-			END_PROFILE(SMBtrans);
+			END_PROFILE(SMBtrans2);
 			return(ERROR_DOS(ERRDOS,ERRnomem));
 		} 
 		if ((psoff+pscnt < psoff) || (psoff+pscnt < pscnt))
@@ -5269,7 +5298,7 @@ int reply_trans2(connection_struct *conn, char *inbuf,char *outbuf,
 		SAFE_FREE(state->data);
 		SAFE_FREE(state->param);
 		TALLOC_FREE(state);
-		END_PROFILE(SMBtrans);
+		END_PROFILE(SMBtrans2);
 		return outsize;
 	}
 
@@ -5379,7 +5408,7 @@ int reply_transs2(connection_struct *conn,
 
 	if ((state->received_param < state->total_param) ||
 	    (state->received_data < state->total_data)) {
-		END_PROFILE(SMBtranss);
+		END_PROFILE(SMBtranss2);
 		return -1;
 	}
 
@@ -5396,7 +5425,7 @@ int reply_transs2(connection_struct *conn,
 	TALLOC_FREE(state);
 
 	if (outsize == 0) {
-		END_PROFILE(SMBtranss);
+		END_PROFILE(SMBtranss2);
 		return(ERROR_DOS(ERRSRV,ERRnosupport));
 	}
 	
diff --git a/source3/smbd/vfs-wrap.c b/source3/smbd/vfs-wrap.c
index 55bf146c20..ee251c17d8 100644
--- a/source3/smbd/vfs-wrap.c
+++ b/source3/smbd/vfs-wrap.c
@@ -549,7 +549,7 @@ int vfswrap_fchmod(vfs_handle_struct *handle, files_struct *fsp, int fd, mode_t
 	{
 		int saved_errno = errno; /* We might get ENOSYS */
 		if ((result = SMB_VFS_FCHMOD_ACL(fsp, fd, mode)) == 0) {
-			END_PROFILE(syscall_chmod);
+			END_PROFILE(syscall_fchmod);
 			return result;
 		}
 		/* Error - return the old errno. */