From 90d776cb18395ed804f0ab4fd13ef571fc0ad827 Mon Sep 17 00:00:00 2001 From: Ralph Boehme Date: Wed, 20 Mar 2024 14:28:43 +0100 Subject: [PATCH] smbd: add option "smbd:debug events" for tevent handling duration threshold warnings Can be used to enable printing an error message if tevent event handlers ran longer then three seconds. Also logs a message with a loglevel of 3 if there were no events at hall. Enabled by default with 'log level = 10' or 'smbd profiling level = on'... BUG: https://bugzilla.samba.org/show_bug.cgi?id=15624 Pair-Programmed-With: Stefan Metzmacher Signed-off-by: Ralph Boehme Signed-off-by: Stefan Metzmacher Reviewed-by: Guenther Deschner --- source3/smbd/smb2_process.c | 64 +++++++++++++++++++++++++++++++++++++ 1 file changed, 64 insertions(+) diff --git a/source3/smbd/smb2_process.c b/source3/smbd/smb2_process.c index ea2d4221d56..a4a0e8265ad 100644 --- a/source3/smbd/smb2_process.c +++ b/source3/smbd/smb2_process.c @@ -1739,8 +1739,36 @@ struct smbd_tevent_trace_state { struct tevent_context *ev; TALLOC_CTX *frame; SMBPROFILE_BASIC_ASYNC_STATE(profile_idle); + struct timeval before_wait_tv; + struct timeval after_wait_tv; }; +static inline void smbd_tevent_trace_callback_before_wait( + struct smbd_tevent_trace_state *state) +{ + struct timeval now = timeval_current(); + struct timeval diff; + + diff = tevent_timeval_until(&state->after_wait_tv, &now); + if (diff.tv_sec > 3) { + DBG_ERR("Handling event took %ld seconds!\n", (long)diff.tv_sec); + } + state->before_wait_tv = now; +} + +static inline void smbd_tevent_trace_callback_after_wait( + struct smbd_tevent_trace_state *state) +{ + struct timeval now = timeval_current(); + struct timeval diff; + + diff = tevent_timeval_until(&state->before_wait_tv, &now); + if (diff.tv_sec > 30) { + DBG_NOTICE("No event for %ld seconds!\n", (long)diff.tv_sec); + } + state->after_wait_tv = now; +} + static inline void smbd_tevent_trace_callback_before_loop_once( struct smbd_tevent_trace_state *state) { @@ -1776,6 +1804,30 @@ static void smbd_tevent_trace_callback(enum tevent_trace_point point, errno = 0; } +static void smbd_tevent_trace_callback_debug(enum tevent_trace_point point, + void *private_data) +{ + struct smbd_tevent_trace_state *state = + (struct smbd_tevent_trace_state *)private_data; + + switch (point) { + case TEVENT_TRACE_BEFORE_WAIT: + smbd_tevent_trace_callback_before_wait(state); + break; + case TEVENT_TRACE_AFTER_WAIT: + smbd_tevent_trace_callback_after_wait(state); + break; + case TEVENT_TRACE_BEFORE_LOOP_ONCE: + smbd_tevent_trace_callback_before_loop_once(state); + break; + case TEVENT_TRACE_AFTER_LOOP_ONCE: + smbd_tevent_trace_callback_after_loop_once(state); + break; + } + + errno = 0; +} + static void smbd_tevent_trace_callback_profile(enum tevent_trace_point point, void *private_data) { @@ -1784,6 +1836,7 @@ static void smbd_tevent_trace_callback_profile(enum tevent_trace_point point, switch (point) { case TEVENT_TRACE_BEFORE_WAIT: + smbd_tevent_trace_callback_before_wait(state); if (!smbprofile_dump_pending()) { /* * If there's no dump pending @@ -1796,6 +1849,7 @@ static void smbd_tevent_trace_callback_profile(enum tevent_trace_point point, SMBPROFILE_BASIC_ASYNC_START(idle, profile_p, state->profile_idle); break; case TEVENT_TRACE_AFTER_WAIT: + smbd_tevent_trace_callback_after_wait(state); SMBPROFILE_BASIC_ASYNC_END(state->profile_idle); if (!smbprofile_dump_pending()) { /* @@ -1843,7 +1897,13 @@ void smbd_process(struct tevent_context *ev_ctx, struct smbd_tevent_trace_state trace_state = { .ev = ev_ctx, .frame = talloc_stackframe(), + .before_wait_tv = tv, + .after_wait_tv = tv, }; + bool debug = lp_parm_bool(GLOBAL_SECTION_SNUM, + "smbd", + "debug events", + CHECK_DEBUGLVL(DBGLVL_DEBUG)); NTTIME now = timeval_to_nttime(&tv); char *chroot_dir = NULL; int rc; @@ -2090,6 +2150,10 @@ void smbd_process(struct tevent_context *ev_ctx, tevent_set_trace_callback(ev_ctx, smbd_tevent_trace_callback_profile, &trace_state); + } else if (debug) { + tevent_set_trace_callback(ev_ctx, + smbd_tevent_trace_callback_debug, + &trace_state); } else { tevent_set_trace_callback(ev_ctx, smbd_tevent_trace_callback,