clock_gettime_mono in the VFS.
Uri Simchoni
uri at samba.org
Mon Mar 28 07:28:52 UTC 2016
On 03/04/2016 10:52 PM, Ralph Boehme wrote:
> On Fri, Mar 04, 2016 at 11:28:15AM -0800, Jeremy Allison wrote:
>> On Fri, Mar 04, 2016 at 01:18:20PM -0500, Ira Cooper wrote:
>>> I'm sorry that I'm coming in late on this one. I've been a bit head down
>>> recently.
>>>
>>> On some platforms clock_gettime_mono has a real measurable cost, alas. I
>>> discovered this on Solaris/Illumos when I compiled in the timing code in
>>> the samba 3.6 profiling framework.
>>
>> Just to follow up, I was OK with this in the review as at least on x86-64-linux, the
>> gettime calls aren't even real system calls - just a memcpy. It's
>> different on ARM I know.
>>
<snip>
>
> yes.
>
> Not sure, but one way to do it could be to make it part of
> --with-profiling-data, which would mean it'd be disabled by
> default. That would do it for my use case.
>
<snip>
>
> -Ralph
>
As an ARM stake-holder, I'd like to pick this up. Please review and push
if happy.
Ira - thanks for bringing this up.
Uri.
-------------- next part --------------
From 02f49189e95850667466c7e9e23af25ed7621ba1 Mon Sep 17 00:00:00 2001
From: Uri Simchoni <uri at samba.org>
Date: Mon, 28 Mar 2016 10:08:58 +0300
Subject: [PATCH 1/7] lib/util: fix function comment
Signed-off-by: Uri Simchoni <uri at samba.org>
---
lib/util/time.c | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)
diff --git a/lib/util/time.c b/lib/util/time.c
index 3c709af..8c01627 100644
--- a/lib/util/time.c
+++ b/lib/util/time.c
@@ -477,7 +477,7 @@ _PUBLIC_ int64_t usec_time_diff(const struct timeval *tv1, const struct timeval
}
/**
- return (tp1 - tp2) in microseconds
+ return (tp1 - tp2) in nanoseconds
*/
_PUBLIC_ int64_t nsec_time_diff(const struct timespec *tp1, const struct timespec *tp2)
{
--
2.5.5
From efdac028972936f612bdb684ff788c3e804b3c98 Mon Sep 17 00:00:00 2001
From: Uri Simchoni <uri at samba.org>
Date: Mon, 28 Mar 2016 10:11:33 +0300
Subject: [PATCH 2/7] s3-profile: reduce dependencies of smbprofile.h
Signed-off-by: Uri Simchoni <uri at samba.org>
---
source3/include/smbprofile.h | 3 ++-
source3/profile/profile.c | 12 ++++++------
source3/profile/profile_dummy.c | 2 +-
source3/smbd/server.c | 4 +++-
4 files changed, 12 insertions(+), 9 deletions(-)
diff --git a/source3/include/smbprofile.h b/source3/include/smbprofile.h
index c771fd4..9d02563 100644
--- a/source3/include/smbprofile.h
+++ b/source3/include/smbprofile.h
@@ -618,8 +618,9 @@ static inline void smbprofile_cleanup(pid_t pid, pid_t dst)
#endif /* WITH_PROFILE */
/* The following definitions come from profile/profile.c */
+struct server_id;
-void set_profile_level(int level, struct server_id src);
+void set_profile_level(int level, const struct server_id *src);
struct messaging_context;
bool profile_setup(struct messaging_context *msg_ctx, bool rdonly);
diff --git a/source3/profile/profile.c b/source3/profile/profile.c
index 1464a42..833c9c4 100644
--- a/source3/profile/profile.c
+++ b/source3/profile/profile.c
@@ -39,7 +39,7 @@ struct smbprofile_global_state smbprofile_state;
/****************************************************************************
Set a profiling level.
****************************************************************************/
-void set_profile_level(int level, struct server_id src)
+void set_profile_level(int level, const struct server_id *src)
{
SMB_ASSERT(smbprofile_state.internal.db != NULL);
@@ -48,25 +48,25 @@ void set_profile_level(int level, struct server_id src)
smbprofile_state.config.do_count = false;
smbprofile_state.config.do_times = false;
DEBUG(1,("INFO: Profiling turned OFF from pid %d\n",
- (int)procid_to_pid(&src)));
+ (int)procid_to_pid(src)));
break;
case 1: /* turn on counter profiling only */
smbprofile_state.config.do_count = true;
smbprofile_state.config.do_times = false;
DEBUG(1,("INFO: Profiling counts turned ON from pid %d\n",
- (int)procid_to_pid(&src)));
+ (int)procid_to_pid(src)));
break;
case 2: /* turn on complete profiling */
smbprofile_state.config.do_count = true;
smbprofile_state.config.do_times = true;
DEBUG(1,("INFO: Full profiling turned ON from pid %d\n",
- (int)procid_to_pid(&src)));
+ (int)procid_to_pid(src)));
break;
case 3: /* reset profile values */
ZERO_STRUCT(profile_p->values);
tdb_wipe_all(smbprofile_state.internal.db->tdb);
DEBUG(1,("INFO: Profiling values cleared from pid %d\n",
- (int)procid_to_pid(&src)));
+ (int)procid_to_pid(src)));
break;
}
}
@@ -88,7 +88,7 @@ static void profile_message(struct messaging_context *msg_ctx,
}
memcpy(&level, data->data, sizeof(level));
- set_profile_level(level, src);
+ set_profile_level(level, &src);
}
/****************************************************************************
diff --git a/source3/profile/profile_dummy.c b/source3/profile/profile_dummy.c
index 1f820ec..7d34d20 100644
--- a/source3/profile/profile_dummy.c
+++ b/source3/profile/profile_dummy.c
@@ -25,7 +25,7 @@ bool profile_setup(struct messaging_context *msg_ctx, bool rdonly)
return true;
}
-void set_profile_level(int level, struct server_id src)
+void set_profile_level(int level, const struct server_id *src)
{
DEBUG(1,("INFO: Profiling support unavailable in this build.\n"));
}
diff --git a/source3/smbd/server.c b/source3/smbd/server.c
index d68615e..7e5b5d9 100644
--- a/source3/smbd/server.c
+++ b/source3/smbd/server.c
@@ -1192,6 +1192,7 @@ extern void build_options(bool screen);
int opt;
poptContext pc;
bool print_build_options = False;
+ struct server_id main_server_id = {0};
enum {
OPT_DAEMON = 1000,
OPT_INTERACTIVE,
@@ -1444,7 +1445,8 @@ extern void build_options(bool screen);
} else {
profiling_level = lp_smbd_profiling_level();
}
- set_profile_level(profiling_level, messaging_server_id(msg_ctx));
+ main_server_id = messaging_server_id(msg_ctx);
+ set_profile_level(profiling_level, &main_server_id);
if (!is_daemon && !is_a_socket(0)) {
if (!interactive) {
--
2.5.5
From 7dbb5e2a91583bf20aeffc8d3dc487bdd0a1b232 Mon Sep 17 00:00:00 2001
From: Uri Simchoni <uri at samba.org>
Date: Mon, 28 Mar 2016 10:13:50 +0300
Subject: [PATCH 3/7] s3-profile: add PROFILE_TIMESTAMP macro
This is a get-timestamp macro which works only when
profiling is enabled in the build. The underlying
clock_gettime_mono() function can be costly on some
architectures and we want to avoid it if it's not
necessary.
Signed-off-by: Uri Simchoni <uri at samba.org>
---
source3/include/smbprofile.h | 7 +++++++
1 file changed, 7 insertions(+)
diff --git a/source3/include/smbprofile.h b/source3/include/smbprofile.h
index 9d02563..c08f494 100644
--- a/source3/include/smbprofile.h
+++ b/source3/include/smbprofile.h
@@ -565,6 +565,8 @@ static inline uint64_t profile_timestamp(void)
#define END_PROFILE_BYTES(x) \
SMBPROFILE_BYTES_ASYNC_END(__profasync_##x)
+#define PROFILE_TIMESTAMP(x) clock_gettime_mono(x)
+
#else /* WITH_PROFILE */
#define SMBPROFILE_COUNT_INCREMENT(_name, _area, _v)
@@ -595,6 +597,11 @@ static inline uint64_t profile_timestamp(void)
#define END_PROFILE(x)
#define END_PROFILE_BYTES(x)
+#define PROFILE_TIMESTAMP(x) do { \
+ struct timespec t = {0}; \
+ *(x) = t; \
+} while(0)
+
static inline bool smbprofile_dump_pending(void)
{
return false;
--
2.5.5
From 97bf7bb46581dd57d40f8626d9037d9bcc85fbe1 Mon Sep 17 00:00:00 2001
From: Uri Simchoni <uri at samba.org>
Date: Mon, 28 Mar 2016 10:17:03 +0300
Subject: [PATCH 4/7] asys: call clock_gettime_mono() only on profile-enabled
build
Signed-off-by: Uri Simchoni <uri at samba.org>
---
source3/lib/asys/asys.c | 13 +++++++------
1 file changed, 7 insertions(+), 6 deletions(-)
diff --git a/source3/lib/asys/asys.c b/source3/lib/asys/asys.c
index 068b460..670be01 100644
--- a/source3/lib/asys/asys.c
+++ b/source3/lib/asys/asys.c
@@ -21,6 +21,7 @@
#include <errno.h>
#include "../pthreadpool/pthreadpool.h"
#include "lib/util/time.h"
+#include "smbprofile.h"
struct asys_pwrite_args {
int fildes;
@@ -192,9 +193,9 @@ static void asys_pwrite_do(void *private_data)
struct asys_job *job = (struct asys_job *)private_data;
struct asys_pwrite_args *args = &job->args.pwrite_args;
- clock_gettime_mono(&job->start_time);
+ PROFILE_TIMESTAMP(&job->start_time);
job->ret = pwrite(args->fildes, args->buf, args->nbyte, args->offset);
- clock_gettime_mono(&job->end_time);
+ PROFILE_TIMESTAMP(&job->end_time);
if (job->ret == -1) {
job->err = errno;
@@ -237,9 +238,9 @@ static void asys_pread_do(void *private_data)
struct asys_job *job = (struct asys_job *)private_data;
struct asys_pread_args *args = &job->args.pread_args;
- clock_gettime_mono(&job->start_time);
+ PROFILE_TIMESTAMP(&job->start_time);
job->ret = pread(args->fildes, args->buf, args->nbyte, args->offset);
- clock_gettime_mono(&job->end_time);
+ PROFILE_TIMESTAMP(&job->end_time);
if (job->ret == -1) {
job->err = errno;
@@ -278,9 +279,9 @@ static void asys_fsync_do(void *private_data)
struct asys_job *job = (struct asys_job *)private_data;
struct asys_fsync_args *args = &job->args.fsync_args;
- clock_gettime_mono(&job->start_time);
+ PROFILE_TIMESTAMP(&job->start_time);
job->ret = fsync(args->fildes);
- clock_gettime_mono(&job->end_time);
+ PROFILE_TIMESTAMP(&job->end_time);
if (job->ret == -1) {
job->err = errno;
--
2.5.5
From 60c9774b7fdf6e8429fb2240d794925840bcc2a1 Mon Sep 17 00:00:00 2001
From: Uri Simchoni <uri at samba.org>
Date: Mon, 28 Mar 2016 10:18:46 +0300
Subject: [PATCH 5/7] vfs_aio_linux: call clock_gettime_mono() only on
profile-enabled build
Signed-off-by: Uri Simchoni <uri at samba.org>
---
source3/modules/vfs_aio_linux.c | 9 +++++----
1 file changed, 5 insertions(+), 4 deletions(-)
diff --git a/source3/modules/vfs_aio_linux.c b/source3/modules/vfs_aio_linux.c
index caa3149..55ef1df 100644
--- a/source3/modules/vfs_aio_linux.c
+++ b/source3/modules/vfs_aio_linux.c
@@ -27,6 +27,7 @@
#include "lib/util/sys_rw.h"
#include <sys/eventfd.h>
#include <libaio.h>
+#include "smbprofile.h"
static int event_fd = -1;
static io_context_t io_ctx;
@@ -168,7 +169,7 @@ static struct tevent_req *aio_linux_pread_send(
piocb = &state->event_iocb;
- clock_gettime_mono(&state->start);
+ PROFILE_TIMESTAMP(&state->start);
ret = io_submit(io_ctx, 1, &piocb);
if (ret < 0) {
tevent_req_error(req, -ret);
@@ -205,7 +206,7 @@ static struct tevent_req *aio_linux_pwrite_send(
piocb = &state->event_iocb;
- clock_gettime_mono(&state->start);
+ PROFILE_TIMESTAMP(&state->start);
ret = io_submit(io_ctx, 1, &piocb);
if (ret < 0) {
tevent_req_error(req, -ret);
@@ -240,7 +241,7 @@ static struct tevent_req *aio_linux_fsync_send(
piocb = &state->event_iocb;
- clock_gettime_mono(&state->start);
+ PROFILE_TIMESTAMP(&state->start);
ret = io_submit(io_ctx, 1, &piocb);
if (ret < 0) {
tevent_req_error(req, -ret);
@@ -261,7 +262,7 @@ static void aio_linux_done(struct tevent_context *event_ctx,
DEBUG(10, ("aio_linux_done called with flags=%d\n",
(int)flags));
- clock_gettime_mono(&end);
+ PROFILE_TIMESTAMP(&end);
/* Read the number of events available. */
if (sys_read(event_fd, &num_events, sizeof(num_events)) !=
--
2.5.5
From 0c3a1c98d6dc3602e158f73c58be344d33a68a1e Mon Sep 17 00:00:00 2001
From: Uri Simchoni <uri at samba.org>
Date: Mon, 28 Mar 2016 10:19:49 +0300
Subject: [PATCH 6/7] vfs_aio_fork: call clock_gettime_mono() only on
profile-enabled build
Signed-off-by: Uri Simchoni <uri at samba.org>
---
source3/modules/vfs_aio_fork.c | 5 +++--
1 file changed, 3 insertions(+), 2 deletions(-)
diff --git a/source3/modules/vfs_aio_fork.c b/source3/modules/vfs_aio_fork.c
index a722102..e699fc5 100644
--- a/source3/modules/vfs_aio_fork.c
+++ b/source3/modules/vfs_aio_fork.c
@@ -29,6 +29,7 @@
#include "lib/util/sys_rw.h"
#include "lib/util/sys_rw_data.h"
#include "lib/msghdr.h"
+#include "smbprofile.h"
#if !defined(HAVE_STRUCT_MSGHDR_MSG_CONTROL) && !defined(HAVE_STRUCT_MSGHDR_MSG_ACCRIGHTS)
# error Can not pass file descriptors
@@ -343,7 +344,7 @@ static void aio_child_loop(int sockfd, struct mmap_area *map)
ZERO_STRUCT(ret_struct);
- clock_gettime_mono(&start);
+ PROFILE_TIMESTAMP(&start);
switch (cmd_struct.cmd) {
case READ_CMD:
@@ -370,7 +371,7 @@ static void aio_child_loop(int sockfd, struct mmap_area *map)
errno = EINVAL;
}
- clock_gettime_mono(&end);
+ PROFILE_TIMESTAMP(&end);
ret_struct.duration = nsec_time_diff(&end, &start);
DEBUG(10, ("aio_child_loop: syscall returned %d\n",
(int)ret_struct.size));
--
2.5.5
From 241a9c5d8a20c6512cef4d40b34dcccb2903596f Mon Sep 17 00:00:00 2001
From: Uri Simchoni <uri at samba.org>
Date: Mon, 28 Mar 2016 10:20:22 +0300
Subject: [PATCH 7/7] vfs_glusterfs: call clock_gettime_mono() only on
profile-enabled build
Signed-off-by: Uri Simchoni <uri at samba.org>
---
source3/modules/vfs_glusterfs.c | 9 +++++----
1 file changed, 5 insertions(+), 4 deletions(-)
diff --git a/source3/modules/vfs_glusterfs.c b/source3/modules/vfs_glusterfs.c
index e202672..5ffbee0 100644
--- a/source3/modules/vfs_glusterfs.c
+++ b/source3/modules/vfs_glusterfs.c
@@ -44,6 +44,7 @@
#include "lib/tevent/tevent_internal.h"
#include "smbd/globals.h"
#include "lib/util/sys_rw.h"
+#include "smbprofile.h"
#define DEFAULT_VOLFILE_SERVER "localhost"
@@ -527,7 +528,7 @@ static void aio_glusterfs_done(glfs_fd_t *fd, ssize_t ret, void *data)
state = (struct glusterfs_aio_state *)data;
- clock_gettime_mono(&end);
+ PROFILE_TIMESTAMP(&end);
if (ret < 0) {
state->ret = -1;
@@ -695,7 +696,7 @@ static struct tevent_req *vfs_gluster_pread_send(struct vfs_handle_struct
return tevent_req_post(req, ev);
}
- clock_gettime_mono(&state->start);
+ PROFILE_TIMESTAMP(&state->start);
ret = glfs_pread_async(*(glfs_fd_t **)VFS_FETCH_FSP_EXTENSION(handle,
fsp), data, n, offset, 0, aio_glusterfs_done,
state);
@@ -731,7 +732,7 @@ static struct tevent_req *vfs_gluster_pwrite_send(struct vfs_handle_struct
return tevent_req_post(req, ev);
}
- clock_gettime_mono(&state->start);
+ PROFILE_TIMESTAMP(&state->start);
ret = glfs_pwrite_async(*(glfs_fd_t **)VFS_FETCH_FSP_EXTENSION(handle,
fsp), data, n, offset, 0, aio_glusterfs_done,
state);
@@ -845,7 +846,7 @@ static struct tevent_req *vfs_gluster_fsync_send(struct vfs_handle_struct
return tevent_req_post(req, ev);
}
- clock_gettime_mono(&state->start);
+ PROFILE_TIMESTAMP(&state->start);
ret = glfs_fsync_async(*(glfs_fd_t **)VFS_FETCH_FSP_EXTENSION(handle,
fsp), aio_glusterfs_done, req);
if (ret < 0) {
--
2.5.5
More information about the samba-technical
mailing list