[SCM] Samba Shared Repository - branch master updated
Volker Lendecke
vlendec at samba.org
Thu Oct 14 11:11:01 UTC 2021
The branch, master has been updated
via a9a3555b430 debug: Optimise construction of msg_no_nl
via 62fd771aea4 debug: Move msg_no_nl to state
via cb70eea0536 debug: Optimise early return when header string buffer is full
via c5061ebe214 debug: Optimise to avoid walking the header string
via ee17f5306c3 debug: Optimise construction of header_str_no_nl
via 8cdd20c70a1 debug: Rename variable for consistency
via 24dc8c5d2b8 debug: Push message length argument down to backend log functions
via 3085a7d317d debug: Add length argument to Debug1()
via 9f8be709c49 debug: Avoid debug header being separated from debug text
via 10f68148a97 debug: Factor out function copy_no_nl()
via 0e59375ac5b debug: Add a level of indirection to ring buffer logging
via fb29a8ebcd0 debug: Move header_str and hs_len to state
from 71cef2fa1dd docs: document new Spotlight Elasticsearch options
https://git.samba.org/?p=samba.git;a=shortlog;h=master
- Log -----------------------------------------------------------------
commit a9a3555b43075c46e2051e6c1ef80762a0a19120
Author: Martin Schwenke <martin at meltin.net>
Date: Thu Oct 14 11:08:38 2021 +1100
debug: Optimise construction of msg_no_nl
If it isn't used then it isn't copied.
Signed-off-by: Martin Schwenke <martin at meltin.net>
Reviewed-by: Volker Lendecke <vl at samba.org>
Autobuild-User(master): Volker Lendecke <vl at samba.org>
Autobuild-Date(master): Thu Oct 14 11:10:40 UTC 2021 on sn-devel-184
commit 62fd771aea4bfb9f3042c80207e9800b74a43f75
Author: Martin Schwenke <martin at meltin.net>
Date: Thu Oct 14 11:00:20 2021 +1100
debug: Move msg_no_nl to state
This enables an optimisation.
Signed-off-by: Martin Schwenke <martin at meltin.net>
Reviewed-by: Volker Lendecke <vl at samba.org>
commit cb70eea0536a33583cd57e8dd416bfc2e37fe9d2
Author: Martin Schwenke <martin at meltin.net>
Date: Wed Oct 13 20:40:34 2021 +1100
debug: Optimise early return when header string buffer is full
The existing check is for truncation, not whether the buffer is full.
However, if the buffer is full (i.e. hs_len == sizeof(header_str) - 1)
then there's no use trying subsequent snprintf() calls because there
will be one byte available that already contains the NUL-terminator.
A subsequent call will just do a no-op truncation.
Check for full buffer instead.
This might be confusing because it isn't the standard check that is
done after snprintf() calls. Is it worth it for a rare corner case?
Signed-off-by: Martin Schwenke <martin at meltin.net>
Reviewed-by: Volker Lendecke <vl at samba.org>
commit c5061ebe2146b6e8257205a4ad9ba69d1caa4c7d
Author: Martin Schwenke <martin at meltin.net>
Date: Wed Oct 13 12:06:13 2021 +1100
debug: Optimise to avoid walking the header string
strlcat() needs to walk to the end of its first argument. However,
but the length of state.header_str is already known, so optimise by
manually appending the extra characters if they will fit.
Signed-off-by: Martin Schwenke <martin at meltin.net>
Reviewed-by: Volker Lendecke <vl at samba.org>
commit ee17f5306c3db1b6d950a9ea7d1787cac96a6d9d
Author: Martin Schwenke <martin at meltin.net>
Date: Thu Sep 23 18:13:30 2021 +1000
debug: Optimise construction of header_str_no_nl
If it isn't used then it isn't copied.
Signed-off-by: Martin Schwenke <martin at meltin.net>
Reviewed-by: Volker Lendecke <vl at samba.org>
commit 8cdd20c70a17e6ee8e7ca41e4c38763f41d158b4
Author: Martin Schwenke <martin at meltin.net>
Date: Wed Oct 6 23:02:10 2021 +1100
debug: Rename variable for consistency
Signed-off-by: Martin Schwenke <martin at meltin.net>
Reviewed-by: Volker Lendecke <vl at samba.org>
commit 24dc8c5d2b809fefcb27abcb0aba7a1de5a55630
Author: Martin Schwenke <martin at meltin.net>
Date: Fri Dec 2 16:37:47 2016 +1100
debug: Push message length argument down to backend log functions
Optimise because length is now available.
Signed-off-by: Martin Schwenke <martin at meltin.net>
Reviewed-by: Volker Lendecke <vl at samba.org>
commit 3085a7d317dd4ce338a5265312c57ed389391786
Author: Martin Schwenke <martin at meltin.net>
Date: Fri Dec 2 16:29:56 2016 +1100
debug: Add length argument to Debug1()
This the first step in avoiding potentially repeated length
calculations in the backends. The length is known at call time for
most usual callers, so pass it down.
Signed-off-by: Martin Schwenke <martin at meltin.net>
Reviewed-by: Volker Lendecke <vl at samba.org>
commit 9f8be709c4951f2af8797f175555c6b861ea6fa4
Author: Martin Schwenke <martin at meltin.net>
Date: Sat Dec 3 12:27:47 2016 +1100
debug: Avoid debug header being separated from debug text
Currently the file backend can produce something like:
HEADER1 HEADER2 TEXT2
TEXT1
when different processes try to log at the same time.
Avoid this by writing the header and text at the same time using
writev(). This means that the header always has to be written by the
backend, so update all backends to do this.
The non-file backends should behave as before when they were invoked
separately to render the header. It might be possible to optimise
some of them (e.g. via sd_journal_sendv) but this requires more
investigation (e.g. sd_journal_sendv()'s handling of newlines) and is
beyond the scope of this change.
state.header_str_no_nl takes the place of msg_no_nl for the header,
since some of the backends need the no-newline version. It is handled
the same was as msg_no_nl: produce the no_nl version exactly once,
whether or not it is needed, since this is better than repeating it in
several backends.
Signed-off-by: Martin Schwenke <martin at meltin.net>
Reviewed-by: Volker Lendecke <vl at samba.org>
commit 10f68148a9716fd06ac58d0b69783a4fac30c2bc
Author: Martin Schwenke <martin at meltin.net>
Date: Wed Oct 6 22:49:06 2021 +1100
debug: Factor out function copy_no_nl()
Signed-off-by: Martin Schwenke <martin at meltin.net>
Reviewed-by: Volker Lendecke <vl at samba.org>
commit 0e59375ac5bc6e88f324b6d4d8b823ddc9d6f574
Author: Martin Schwenke <martin at meltin.net>
Date: Thu Sep 23 10:25:04 2021 +1000
debug: Add a level of indirection to ring buffer logging
Add an internal function to do the work and call it. It will be
called again in a subsequent commit.
Signed-off-by: Martin Schwenke <martin at meltin.net>
Reviewed-by: Volker Lendecke <vl at samba.org>
commit fb29a8ebcd076df9da51275adb45d90482f2e19f
Author: Martin Schwenke <martin at meltin.net>
Date: Wed Oct 13 11:42:14 2021 +1100
debug: Move header_str and hs_len to state
They'll need to be accessible by the backends.
Note that the snprintf() and strlcat() calls can result in
state.hs_len >= sizeof(state.header_str), so state.hs_len needs to be
sanitised before any potential use. Previously this wasn't necessary
because this value was on the stack, so it couldn't be used after
dbghdrclass() returned.
Signed-off-by: Martin Schwenke <martin at meltin.net>
Reviewed-by: Volker Lendecke <vl at samba.org>
-----------------------------------------------------------------------
Summary of changes:
lib/util/debug.c | 275 +++++++++++++++++++++++++++++++++++++++----------------
1 file changed, 197 insertions(+), 78 deletions(-)
Changeset truncated at 500 lines:
diff --git a/lib/util/debug.c b/lib/util/debug.c
index 4fd17679227..b0ac6ce40ea 100644
--- a/lib/util/debug.c
+++ b/lib/util/debug.c
@@ -95,6 +95,10 @@ static struct {
struct debug_settings settings;
debug_callback_fn callback;
void *callback_private;
+ char header_str[300];
+ char header_str_no_nl[300];
+ size_t hs_len;
+ char msg_no_nl[FORMAT_BUFR_SIZE];
} state = {
.settings = {
.timestamp_logs = true
@@ -201,14 +205,65 @@ static int debug_level_to_priority(int level)
}
#endif
+/* -------------------------------------------------------------------------- **
+ * Produce a version of the given buffer without any trailing newlines.
+ */
+#if defined(HAVE_LIBSYSTEMD_JOURNAL) || defined(HAVE_LIBSYSTEMD) || \
+ defined(HAVE_LTTNG_TRACEF) || defined(HAVE_GPFS)
+static void copy_no_nl(char *out,
+ size_t out_size,
+ const char *in,
+ size_t in_len)
+{
+ size_t len;
+ /*
+ * Some backends already add an extra newline, so also provide
+ * a buffer without the newline character.
+ */
+ len = MIN(in_len, out_size - 1);
+ if ((len > 0) && (in[len - 1] == '\n')) {
+ len--;
+ }
+
+ memcpy(out, in, len);
+ out[len] = '\0';
+}
+
+static void ensure_copy_no_nl(char *out,
+ size_t out_size,
+ const char *in,
+ size_t in_len)
+{
+ /*
+ * Assume out is a static buffer that is reused as a cache.
+ * If it isn't empty then this has already been done with the
+ * same input.
+ */
+ if (out[0] != '\0') {
+ return;
+ }
+
+ copy_no_nl(out, out_size, in, in_len);
+}
+#endif
+
/* -------------------------------------------------------------------------- **
* Debug backends. When logging to DEBUG_FILE, send the log entries to
* all active backends.
*/
-static void debug_file_log(int msg_level,
- const char *msg, const char *msg_no_nl)
+static void debug_file_log(int msg_level, const char *msg, size_t msg_len)
{
+ struct iovec iov[] = {
+ {
+ .iov_base = discard_const(state.header_str),
+ .iov_len = state.hs_len,
+ },
+ {
+ .iov_base = discard_const(msg),
+ .iov_len = msg_len,
+ },
+ };
ssize_t ret;
int fd;
@@ -221,7 +276,7 @@ static void debug_file_log(int msg_level,
}
do {
- ret = write(fd, msg, strlen(msg));
+ ret = writev(fd, iov, ARRAY_SIZE(iov));
} while (ret == -1 && errno == EINTR);
}
@@ -248,8 +303,7 @@ static void debug_syslog_reload(bool enabled, bool previously_enabled,
}
}
-static void debug_syslog_log(int msg_level,
- const char *msg, const char *msg_no_nl)
+static void debug_syslog_log(int msg_level, const char *msg, size_t msg_len)
{
int priority;
@@ -261,16 +315,34 @@ static void debug_syslog_log(int msg_level,
*/
priority |= SYSLOG_FACILITY;
+ if (state.hs_len > 0) {
+ syslog(priority, "%s", state.header_str);
+ }
syslog(priority, "%s", msg);
}
#endif /* WITH_SYSLOG */
#if defined(HAVE_LIBSYSTEMD_JOURNAL) || defined(HAVE_LIBSYSTEMD)
#include <systemd/sd-journal.h>
-static void debug_systemd_log(int msg_level,
- const char *msg, const char *msg_no_nl)
+static void debug_systemd_log(int msg_level, const char *msg, size_t msg_len)
{
- sd_journal_send("MESSAGE=%s", msg_no_nl,
+ if (state.hs_len > 0) {
+ ensure_copy_no_nl(state.header_str_no_nl,
+ sizeof(state.header_str_no_nl),
+ state.header_str,
+ state.hs_len);
+ sd_journal_send("MESSAGE=%s",
+ state.header_str_no_nl,
+ "PRIORITY=%d",
+ debug_level_to_priority(msg_level),
+ "LEVEL=%d",
+ msg_level,
+ NULL);
+ }
+ ensure_copy_no_nl(state.msg_no_nl,
+ sizeof(state.msg_no_nl),
+ msg, msg_len);
+ sd_journal_send("MESSAGE=%s", state.msg_no_nl,
"PRIORITY=%d", debug_level_to_priority(msg_level),
"LEVEL=%d", msg_level,
NULL);
@@ -279,10 +351,19 @@ static void debug_systemd_log(int msg_level,
#ifdef HAVE_LTTNG_TRACEF
#include <lttng/tracef.h>
-static void debug_lttng_log(int msg_level,
- const char *msg, const char *msg_no_nl)
+static void debug_lttng_log(int msg_level, const char *msg, size_t msg_len)
{
- tracef(msg_no_nl);
+ if (state.hs_len > 0) {
+ ensure_copy_no_nl(state.header_str_no_nl,
+ sizeof(state.header_str_no_nl),
+ state.header_str,
+ state.hs_len);
+ tracef(state.header_str_no_nl);
+ }
+ ensure_copy_no_nl(state.msg_no_nl,
+ sizeof(state.msg_no_nl),
+ msg, msg_len);
+ tracef(state.msg_no_nl);
}
#endif /* WITH_LTTNG_TRACEF */
@@ -311,10 +392,19 @@ static void debug_gpfs_reload(bool enabled, bool previously_enabled,
}
}
-static void debug_gpfs_log(int msg_level,
- const char *msg, const char *msg_no_nl)
+static void debug_gpfs_log(int msg_level, const char *msg, size_t msg_len)
{
- gpfswrap_add_trace(msg_level, msg_no_nl);
+ if (state.hs_len > 0) {
+ ensure_copy_no_nl(state.header_str_no_nl,
+ sizeof(state.header_str_no_nl),
+ state.header_str,
+ state.hs_len);
+ gpfswrap_add_trace(msg_level, state.header_str_no_nl);
+ }
+ ensure_copy_no_nl(state.msg_no_nl,
+ sizeof(state.msg_no_nl),
+ msg, msg_len);
+ gpfswrap_add_trace(msg_level, state.msg_no_nl);
}
#endif /* HAVE_GPFS */
@@ -366,11 +456,8 @@ static void debug_ringbuf_reload(bool enabled, bool previously_enabled,
}
}
-static void debug_ringbuf_log(int msg_level,
- const char *msg,
- const char *msg_no_nl)
+static void _debug_ringbuf_log(int msg_level, const char *msg, size_t msg_len)
{
- size_t msglen = strlen(msg);
size_t allowed_size;
if (debug_ringbuf == NULL) {
@@ -380,20 +467,28 @@ static void debug_ringbuf_log(int msg_level,
/* Ensure the buffer is always \0 terminated */
allowed_size = debug_ringbuf_size - 1;
- if (msglen > allowed_size) {
+ if (msg_len > allowed_size) {
return;
}
- if ((debug_ringbuf_ofs + msglen) < debug_ringbuf_ofs) {
+ if ((debug_ringbuf_ofs + msg_len) < debug_ringbuf_ofs) {
return;
}
- if ((debug_ringbuf_ofs + msglen) > allowed_size) {
+ if ((debug_ringbuf_ofs + msg_len) > allowed_size) {
debug_ringbuf_ofs = 0;
}
- memcpy(debug_ringbuf + debug_ringbuf_ofs, msg, msglen);
- debug_ringbuf_ofs += msglen;
+ memcpy(debug_ringbuf + debug_ringbuf_ofs, msg, msg_len);
+ debug_ringbuf_ofs += msg_len;
+}
+
+static void debug_ringbuf_log(int msg_level, const char *msg, size_t msg_len)
+{
+ if (state.hs_len > 0) {
+ _debug_ringbuf_log(msg_level, state.header_str, state.hs_len);
+ }
+ _debug_ringbuf_log(msg_level, msg, msg_len);
}
static struct debug_backend {
@@ -402,7 +497,9 @@ static struct debug_backend {
int new_log_level;
void (*reload)(bool enabled, bool prev_enabled,
const char *prog_name, char *option);
- void (*log)(int msg_level, const char *msg, const char *msg_no_nl);
+ void (*log)(int msg_level,
+ const char *msg,
+ size_t len);
char *option;
} debug_backends[] = {
{
@@ -558,29 +655,25 @@ static void debug_set_backends(const char *param)
}
}
-static void debug_backends_log(const char *msg, int msg_level)
+static void debug_backends_log(const char *msg, size_t msg_len, int msg_level)
{
- char msg_no_nl[FORMAT_BUFR_SIZE];
size_t i;
- size_t len;
/*
- * Some backends already add an extra newline, so also provide
- * a buffer without the newline character.
+ * Some backends already add an extra newline, so initialize a
+ * buffer without the newline character. It will be filled by
+ * the first backend that needs it.
*/
- len = MIN(strlen(msg), FORMAT_BUFR_SIZE - 1);
- if ((len > 0) && (msg[len - 1] == '\n')) {
- len--;
- }
-
- memcpy(msg_no_nl, msg, len);
- msg_no_nl[len] = '\0';
+ state.msg_no_nl[0] = '\0';
for (i = 0; i < ARRAY_SIZE(debug_backends); i++) {
if (msg_level <= debug_backends[i].log_level) {
- debug_backends[i].log(msg_level, msg, msg_no_nl);
+ debug_backends[i].log(msg_level, msg, msg_len);
}
}
+
+ /* Only log the header once */
+ state.hs_len = 0;
}
int debuglevel_get_class(size_t idx)
@@ -1056,9 +1149,8 @@ void debug_set_callback(void *private_ptr, debug_callback_fn fn)
}
}
-static void debug_callback_log(const char *msg, int msg_level)
+static void debug_callback_log(const char *msg, size_t msg_len, int msg_level)
{
- size_t msg_len = strlen(msg);
char msg_copy[msg_len];
if ((msg_len > 0) && (msg[msg_len-1] == '\n')) {
@@ -1396,10 +1488,10 @@ void check_log_size( void )
/*************************************************************************
Write an debug message on the debugfile.
- This is called by dbghdr() and format_debug_text().
+ This is called by format_debug_text().
************************************************************************/
-static void Debug1(const char *msg)
+static void Debug1(const char *msg, size_t msg_len)
{
int old_errno = errno;
@@ -1407,7 +1499,7 @@ static void Debug1(const char *msg)
switch(state.logtype) {
case DEBUG_CALLBACK:
- debug_callback_log(msg, current_msg_level);
+ debug_callback_log(msg, msg_len, current_msg_level);
break;
case DEBUG_STDOUT:
case DEBUG_STDERR:
@@ -1418,12 +1510,12 @@ static void Debug1(const char *msg)
do {
ret = write(dbgc_config[DBGC_ALL].fd,
msg,
- strlen(msg));
+ msg_len);
} while (ret == -1 && errno == EINTR);
}
break;
case DEBUG_FILE:
- debug_backends_log(msg, current_msg_level);
+ debug_backends_log(msg, msg_len, current_msg_level);
break;
};
@@ -1439,7 +1531,7 @@ static void Debug1(const char *msg)
static void bufr_print( void )
{
format_bufr[format_pos] = '\0';
- (void)Debug1(format_bufr);
+ (void)Debug1(format_bufr, format_pos);
format_pos = 0;
}
@@ -1485,8 +1577,9 @@ static void format_debug_text( const char *msg )
* continuation indicator.
*/
if (format_pos >= FORMAT_BUFR_SIZE - 1) {
+ const char cont[] = " +>\n";
bufr_print();
- (void)Debug1( " +>\n" );
+ (void)Debug1(cont , sizeof(cont) - 1);
}
}
@@ -1518,7 +1611,7 @@ bool dbgsetclass(int level, int cls)
}
/***************************************************************************
- Print a Debug Header.
+ Put a Debug Header into header_str.
Input: level - Debug level of the message (not the system-wide debug
level. )
@@ -1543,11 +1636,17 @@ bool dbghdrclass(int level, int cls, const char *location, const char *func)
/* Ensure we don't lose any real errno value. */
int old_errno = errno;
bool verbose = false;
- char header_str[300];
- size_t hs_len;
struct timeval tv;
struct timeval_buf tvbuf;
+ /*
+ * This might be overkill, but if another early return is
+ * added later then initialising these avoids potential
+ * problems
+ */
+ state.hs_len = 0;
+ state.header_str[0] = '\0';
+
if( format_pos ) {
/* This is a fudge. If there is stuff sitting in the format_bufr, then
* the *right* thing to do is to call
@@ -1580,9 +1679,12 @@ bool dbghdrclass(int level, int cls, const char *location, const char *func)
timeval_str_buf(&tv, false, state.settings.debug_hires_timestamp,
&tvbuf);
- hs_len = snprintf(header_str, sizeof(header_str), "[%s, %2d",
- tvbuf.buf, level);
- if (hs_len >= sizeof(header_str)) {
+ state.hs_len = snprintf(state.header_str,
+ sizeof(state.header_str),
+ "[%s, %2d",
+ tvbuf.buf,
+ level);
+ if (state.hs_len >= sizeof(state.header_str) - 1) {
goto full;
}
@@ -1591,54 +1693,71 @@ bool dbghdrclass(int level, int cls, const char *location, const char *func)
}
if (verbose || state.settings.debug_pid) {
- hs_len += snprintf(
- header_str + hs_len, sizeof(header_str) - hs_len,
- ", pid=%u", (unsigned int)getpid());
- if (hs_len >= sizeof(header_str)) {
+ state.hs_len += snprintf(state.header_str + state.hs_len,
+ sizeof(state.header_str) - state.hs_len,
+ ", pid=%u",
+ (unsigned int)getpid());
+ if (state.hs_len >= sizeof(state.header_str) - 1) {
goto full;
}
}
if (verbose || state.settings.debug_uid) {
- hs_len += snprintf(
- header_str + hs_len, sizeof(header_str) - hs_len,
- ", effective(%u, %u), real(%u, %u)",
- (unsigned int)geteuid(), (unsigned int)getegid(),
- (unsigned int)getuid(), (unsigned int)getgid());
- if (hs_len >= sizeof(header_str)) {
+ state.hs_len += snprintf(state.header_str + state.hs_len,
+ sizeof(state.header_str) - state.hs_len,
+ ", effective(%u, %u), real(%u, %u)",
+ (unsigned int)geteuid(),
+ (unsigned int)getegid(),
+ (unsigned int)getuid(),
+ (unsigned int)getgid());
+ if (state.hs_len >= sizeof(state.header_str) - 1) {
goto full;
}
}
if ((verbose || state.settings.debug_class)
&& (cls != DBGC_ALL)) {
- hs_len += snprintf(
- header_str + hs_len, sizeof(header_str) - hs_len,
- ", class=%s", classname_table[cls]);
- if (hs_len >= sizeof(header_str)) {
- goto full;
- }
+ state.hs_len += snprintf(state.header_str + state.hs_len,
+ sizeof(state.header_str) - state.hs_len,
+ ", class=%s",
+ classname_table[cls]);
}
- /*
- * No +=, see man man strlcat
- */
- hs_len = strlcat(header_str, "] ", sizeof(header_str));
- if (hs_len >= sizeof(header_str)) {
+ if (state.hs_len >= sizeof(state.header_str) - 1) {
goto full;
}
+ state.header_str[state.hs_len] = ']';
+ state.hs_len++;
+ if (state.hs_len < sizeof(state.header_str) - 1) {
+ state.header_str[state.hs_len] = ' ';
+ state.hs_len++;
+ }
+ state.header_str[state.hs_len] = '\0';
if (!state.settings.debug_prefix_timestamp) {
- hs_len += snprintf(
- header_str + hs_len, sizeof(header_str) - hs_len,
- "%s(%s)\n", location, func);
- if (hs_len >= sizeof(header_str)) {
+ state.hs_len += snprintf(state.header_str + state.hs_len,
+ sizeof(state.header_str) - state.hs_len,
+ "%s(%s)\n",
+ location,
+ func);
+ if (state.hs_len >= sizeof(state.header_str)) {
goto full;
}
}
full:
- (void)Debug1(header_str);
+ /*
+ * Above code never overflows state.header_str and always
+ * NUL-terminates correctly. However, state.hs_len can point
+ * past the end of the buffer to indicate that truncation
+ * occurred, so fix it if necessary, since state.hs_len is
+ * expected to be used after return.
+ */
+ if (state.hs_len >= sizeof(state.header_str)) {
+ state.hs_len = sizeof(state.header_str) - 1;
+ }
+
+ state.header_str_no_nl[0] = '\0';
errno = old_errno;
return( true );
--
Samba Shared Repository
More information about the samba-cvs
mailing list