[RFC] Extending the debugging system with per-class logfiles
Ralph Böhme
slow at samba.org
Mon Dec 10 15:26:27 UTC 2018
Hi folks!
I have a working WIP patchset that adds per-debug-class logfiles to our debug
subsystem, eg
log file = /var/log/samba/%m.log
log level = 1 full_audit:1@/var/log/samba/audit.log
The use case that triggered the work was having vfs_full_audit log to a
different file then "log file". This could also be achieved by changes to the
VFS module, but we saw the general usefulness of per-class logfiles, so I took
the stab.
I guess this could also be useful for the audit logging of AD DCs.
Fwiw, I'm extending the "log level" syntax to pass the optional per-class
logfile, not the "log file" option, because the option requires tokenizing the
option value which would break on any "log file" value that includes spaces (or
an '@').
Thoughts?
WIP patch attached in case you're curious. :)
-slow
--
Ralph Boehme, Samba Team https://samba.org/
Samba Developer, SerNet GmbH https://sernet.de/en/samba/
GPG-Fingerprint FAE2C6088A24252051C559E4AA1E9B7126399E46
-------------- next part --------------
From 0b143e99308fbd03b06f80b723c81dda8ac1e7bc Mon Sep 17 00:00:00 2001
From: Ralph Boehme <slow at samba.org>
Date: Mon, 10 Dec 2018 14:32:13 +0100
Subject: [PATCH 1/2] lib: debug: prepare for per-class logfile
---
lib/util/debug.c | 183 ++++++++++++++++++++++++++++++++++-------------
1 file changed, 132 insertions(+), 51 deletions(-)
diff --git a/lib/util/debug.c b/lib/util/debug.c
index b5f120bb3a4..a892e761a57 100644
--- a/lib/util/debug.c
+++ b/lib/util/debug.c
@@ -553,23 +553,44 @@ static const char *default_classname_table[] = {
[DBGC_DSDB_GROUP_AUDIT_JSON] = "dsdb_group_json_audit",
};
+struct debug_class {
+ /*
+ * The debug classname.
+ */
+ const char *class_name;
+
+ /*
+ * An optional class specific logfile, may be NULL in which case the
+ * "global" logfile is used.
+ */
+ const char *logfile;
+ int fd;
+
+ /*
+ * The debug loglevel of the class.
+ */
+ int loglevel;
+};
+
+
/*
* This is to allow reading of DEBUGLEVEL_CLASS before the debug
* system has been initialized.
*/
-static int debug_class_list_initial[ARRAY_SIZE(default_classname_table)];
+static struct debug_class
+debug_class_list_initial[ARRAY_SIZE(default_classname_table)];
static size_t debug_num_classes = 0;
-static int *DEBUGLEVEL_CLASS = debug_class_list_initial;
+static struct debug_class *DEBUGLEVEL_CLASS = debug_class_list_initial;
int debuglevel_get_class(size_t idx)
{
- return DEBUGLEVEL_CLASS[idx];
+ return DEBUGLEVEL_CLASS[idx].loglevel;
}
void debuglevel_set_class(size_t idx, int level)
{
- DEBUGLEVEL_CLASS[idx] = level;
+ DEBUGLEVEL_CLASS[idx].loglevel = level;
}
@@ -598,6 +619,7 @@ void debuglevel_set_class(size_t idx, int level)
static int debug_count = 0;
static int current_msg_level = 0;
+static int current_msg_class = 0;
static char format_bufr[FORMAT_BUFR_SIZE];
static size_t format_pos = 0;
static bool log_overflow = false;
@@ -629,7 +651,8 @@ void gfree_debugsyms(void)
if ( DEBUGLEVEL_CLASS != debug_class_list_initial ) {
TALLOC_FREE( DEBUGLEVEL_CLASS );
- DEBUGLEVEL_CLASS = discard_const_p(int, debug_class_list_initial);
+ DEBUGLEVEL_CLASS = discard_const_p(struct debug_class,
+ debug_class_list_initial);
}
debug_num_classes = 0;
@@ -654,7 +677,7 @@ char *debug_list_class_names_and_levels(void)
buf = talloc_asprintf_append(buf,
"%s:%d%s",
classname_table[i],
- DEBUGLEVEL_CLASS[i],
+ DEBUGLEVEL_CLASS[i].loglevel,
i == (debug_num_classes - 1) ? "\n" : " ");
if (buf == NULL) {
return NULL;
@@ -687,19 +710,21 @@ static int debug_lookup_classname_int(const char* classname)
int debug_add_class(const char *classname)
{
int ndx;
- int *new_class_list;
+ struct debug_class *new_class_list = NULL;
char **new_name_list;
int default_level;
- if (!classname)
+ if (classname == NULL) {
return -1;
+ }
/* check the init has yet been called */
debug_init();
ndx = debug_lookup_classname_int(classname);
- if (ndx >= 0)
+ if (ndx >= 0) {
return ndx;
+ }
ndx = debug_num_classes;
if (DEBUGLEVEL_CLASS == debug_class_list_initial) {
@@ -709,23 +734,32 @@ int debug_add_class(const char *classname)
new_class_list = DEBUGLEVEL_CLASS;
}
- default_level = DEBUGLEVEL_CLASS[DBGC_ALL];
+ default_level = DEBUGLEVEL_CLASS[DBGC_ALL].loglevel;
- new_class_list = talloc_realloc(NULL, new_class_list, int, ndx + 1);
- if (!new_class_list)
+ new_class_list = talloc_realloc(NULL,
+ new_class_list,
+ struct debug_class,
+ ndx + 1);
+ if (new_class_list == NULL) {
return -1;
+ }
+
DEBUGLEVEL_CLASS = new_class_list;
- DEBUGLEVEL_CLASS[ndx] = default_level;
+ ZERO_STRUCT(DEBUGLEVEL_CLASS[ndx]);
+ DEBUGLEVEL_CLASS[ndx].loglevel = default_level;
+ DEBUGLEVEL_CLASS[ndx].fd = -1;
new_name_list = talloc_realloc(NULL, classname_table, char *, ndx + 1);
- if (!new_name_list)
+ if (new_name_list == NULL) {
return -1;
+ }
classname_table = new_name_list;
classname_table[ndx] = talloc_strdup(classname_table, classname);
- if (! classname_table[ndx])
+ if (classname_table[ndx] == NULL) {
return -1;
+ }
debug_num_classes = ndx + 1;
@@ -766,7 +800,7 @@ static void debug_dump_status(int level)
const char *classname = classname_table[q];
DEBUGADD(level, (" %s: %d\n",
classname,
- DEBUGLEVEL_CLASS[q]));
+ DEBUGLEVEL_CLASS[q].loglevel));
}
}
@@ -792,7 +826,7 @@ static bool debug_parse_param(char *param)
return false;
}
- DEBUGLEVEL_CLASS[ndx] = atoi(class_level);
+ DEBUGLEVEL_CLASS[ndx].loglevel = atoi(class_level);
return true;
}
@@ -824,15 +858,15 @@ bool debug_parse_levels(const char *params_str)
* v.s. "all:10", this is the traditional way to set DEBUGLEVEL
*/
if (isdigit(tok[0])) {
- DEBUGLEVEL_CLASS[DBGC_ALL] = atoi(tok);
+ DEBUGLEVEL_CLASS[DBGC_ALL].loglevel = atoi(tok);
tok = strtok_r(NULL, LIST_SEP, &saveptr);
} else {
- DEBUGLEVEL_CLASS[DBGC_ALL] = 0;
+ DEBUGLEVEL_CLASS[DBGC_ALL].loglevel = 0;
}
/* Array is debug_num_classes long */
for (i = DBGC_ALL+1; i < debug_num_classes; i++) {
- DEBUGLEVEL_CLASS[i] = DEBUGLEVEL_CLASS[DBGC_ALL];
+ DEBUGLEVEL_CLASS[i].loglevel = DEBUGLEVEL_CLASS[DBGC_ALL].loglevel;
}
while (tok != NULL) {
@@ -1022,6 +1056,28 @@ static void debug_callback_log(const char *msg, int msg_level)
Fix from dgibson at linuxcare.com.
**************************************************************************/
+static int reopen_one_log(int *fd, const char *logfile)
+{
+ int new_fd;
+ int old_fd = -1;
+
+ new_fd = open(logfile, O_WRONLY|O_APPEND|O_CREAT, 0644);
+ if (new_fd == -1) {
+ log_overflow = true;
+ DBG_ERR("Unable to open new log file '%s': %s\n",
+ logfile, strerror(errno));
+ log_overflow = false;
+ return -1;
+ }
+
+ smb_set_close_on_exec(new_fd);
+ old_fd = *fd;
+ *fd = new_fd;
+ debug_close_fd(old_fd);
+
+ return new_fd;
+}
+
/**
reopen the log file (usually called because the log file name might have changed)
*/
@@ -1029,7 +1085,6 @@ bool reopen_logs_internal(void)
{
mode_t oldumask;
int new_fd = 0;
- int old_fd = 0;
bool ret = true;
if (state.reopening_logs) {
@@ -1066,18 +1121,9 @@ bool reopen_logs_internal(void)
state.reopening_logs = true;
- new_fd = open( state.debugf, O_WRONLY|O_APPEND|O_CREAT, 0644);
-
+ new_fd = reopen_one_log(&state.fd, state.debugf);
if (new_fd == -1) {
- log_overflow = true;
- DEBUG(0, ("Unable to open new log file '%s': %s\n", state.debugf, strerror(errno)));
- log_overflow = false;
ret = false;
- } else {
- smb_set_close_on_exec(new_fd);
- old_fd = state.fd;
- state.fd = new_fd;
- debug_close_fd(old_fd);
}
/* Fix from klausr at ITAP.Physik.Uni-Stuttgart.De
@@ -1144,10 +1190,58 @@ bool need_to_check_log_size( void )
Check to see if the log has grown to be too big.
**************************************************************************/
-void check_log_size( void )
+static void do_one_check_log_size(off_t maxlog, int fd, const char *logfile)
{
- int maxlog;
+ char name[strlen(logfile) + 5];
struct stat st;
+ int ret;
+ bool ok;
+
+ if (maxlog == 0) {
+ return;
+ }
+
+ ret = fstat(fd, &st);
+ if (ret != 0) {
+ return;
+ }
+ if (st.st_size < maxlog ) {
+ return;
+ }
+
+ (void)reopen_logs_internal();
+
+ if (fd <= 2) {
+ return;
+ }
+ ret = fstat(fd, &st);
+ if (ret != 0) {
+ return;
+ }
+ if (st.st_size < maxlog) {
+ return;
+ }
+
+ snprintf(name, sizeof(name), "%s.old", logfile);
+
+ (void)rename(logfile, name);
+
+ ok = reopen_logs_internal();
+ if (ok) {
+ return;
+ }
+ /* We failed to reopen a log - continue using the old name. */
+ (void)rename(name, logfile);
+}
+
+static void do_check_log_size(off_t maxlog)
+{
+ do_one_check_log_size(maxlog, state.fd, state.debugf);
+}
+
+void check_log_size( void )
+{
+ off_t maxlog;
/*
* We need to be root to check/change log-file, skip this and let the main
@@ -1177,23 +1271,7 @@ void check_log_size( void )
(void)reopen_logs_internal();
}
- if (maxlog && (fstat(state.fd, &st) == 0
- && st.st_size > maxlog )) {
- (void)reopen_logs_internal();
- if (state.fd > 2 && (fstat(state.fd, &st) == 0
- && st.st_size > maxlog)) {
- char name[strlen(state.debugf) + 5];
-
- snprintf(name, sizeof(name), "%s.old", state.debugf);
-
- (void)rename(state.debugf, name);
-
- if (!reopen_logs_internal()) {
- /* We failed to reopen a log - continue using the old name. */
- (void)rename(name, state.debugf);
- }
- }
- }
+ do_check_log_size(maxlog);
/*
* Here's where we need to panic if state.fd == 0 or -1 (invalid values)
@@ -1380,6 +1458,9 @@ bool dbghdrclass(int level, int cls, const char *location, const char *func)
/* Set current_msg_level. */
current_msg_level = level;
+ /* Set current message class */
+ current_msg_class = cls;
+
/* Don't print a header if we're logging to stdout. */
if ( state.logtype != DEBUG_FILE ) {
return( true );
@@ -1403,7 +1484,7 @@ bool dbghdrclass(int level, int cls, const char *location, const char *func)
goto full;
}
- if (unlikely(DEBUGLEVEL_CLASS[ cls ] >= 10)) {
+ if (unlikely(DEBUGLEVEL_CLASS[cls].loglevel >= 10)) {
verbose = true;
}
--
2.17.2
From 55e228f7c838ef681444660be23ac3002e2c735f Mon Sep 17 00:00:00 2001
From: Ralph Boehme <slow at samba.org>
Date: Mon, 10 Dec 2018 15:59:56 +0100
Subject: [PATCH 2/2] lib: debug: add per class logfile support
This allows configs like
log file = /var/log/samba/%m.log
log level = 1 full_audit:1@/var/log/samba/audit.log
---
lib/util/debug.c | 183 ++++++++++++++++++++++++++++-------------------
1 file changed, 108 insertions(+), 75 deletions(-)
diff --git a/lib/util/debug.c b/lib/util/debug.c
index a892e761a57..583d98ceb34 100644
--- a/lib/util/debug.c
+++ b/lib/util/debug.c
@@ -103,6 +103,79 @@ static struct {
.fd = 2 /* stderr by default */
};
+struct debug_class {
+ /*
+ * The debug classname.
+ */
+ const char *class_name;
+
+ /*
+ * An optional class specific logfile, may be NULL in which case the
+ * "global" logfile is used.
+ */
+ const char *logfile;
+ int fd;
+
+ /*
+ * The debug loglevel of the class.
+ */
+ int loglevel;
+};
+
+static const char *default_classname_table[] = {
+ [DBGC_ALL] = "all",
+ [DBGC_TDB] = "tdb",
+ [DBGC_PRINTDRIVERS] = "printdrivers",
+ [DBGC_LANMAN] = "lanman",
+ [DBGC_SMB] = "smb",
+ [DBGC_RPC_PARSE] = "rpc_parse",
+ [DBGC_RPC_SRV] = "rpc_srv",
+ [DBGC_RPC_CLI] = "rpc_cli",
+ [DBGC_PASSDB] = "passdb",
+ [DBGC_SAM] = "sam",
+ [DBGC_AUTH] = "auth",
+ [DBGC_WINBIND] = "winbind",
+ [DBGC_VFS] = "vfs",
+ [DBGC_IDMAP] = "idmap",
+ [DBGC_QUOTA] = "quota",
+ [DBGC_ACLS] = "acls",
+ [DBGC_LOCKING] = "locking",
+ [DBGC_MSDFS] = "msdfs",
+ [DBGC_DMAPI] = "dmapi",
+ [DBGC_REGISTRY] = "registry",
+ [DBGC_SCAVENGER] = "scavenger",
+ [DBGC_DNS] = "dns",
+ [DBGC_LDB] = "ldb",
+ [DBGC_TEVENT] = "tevent",
+ [DBGC_AUTH_AUDIT] = "auth_audit",
+ [DBGC_AUTH_AUDIT_JSON] = "auth_json_audit",
+ [DBGC_KERBEROS] = "kerberos",
+ [DBGC_DRS_REPL] = "drs_repl",
+ [DBGC_SMB2] = "smb2",
+ [DBGC_SMB2_CREDITS] = "smb2_credits",
+ [DBGC_DSDB_AUDIT] = "dsdb_audit",
+ [DBGC_DSDB_AUDIT_JSON] = "dsdb_json_audit",
+ [DBGC_DSDB_PWD_AUDIT] = "dsdb_password_audit",
+ [DBGC_DSDB_PWD_AUDIT_JSON] = "dsdb_password_json_audit",
+ [DBGC_DSDB_TXN_AUDIT] = "dsdb_transaction_audit",
+ [DBGC_DSDB_TXN_AUDIT_JSON] = "dsdb_transaction_json_audit",
+ [DBGC_DSDB_GROUP_AUDIT] = "dsdb_group_audit",
+ [DBGC_DSDB_GROUP_AUDIT_JSON] = "dsdb_group_json_audit",
+};
+
+/*
+ * This is to allow reading of DEBUGLEVEL_CLASS before the debug
+ * system has been initialized.
+ */
+static struct debug_class
+debug_class_list_initial[ARRAY_SIZE(default_classname_table)];
+
+static size_t debug_num_classes = 0;
+static struct debug_class *DEBUGLEVEL_CLASS = debug_class_list_initial;
+
+static int current_msg_level = 0;
+static int current_msg_class = 0;
+
#if defined(WITH_SYSLOG) || defined(HAVE_LIBSYSTEMD_JOURNAL) || defined(HAVE_LIBSYSTEMD)
static int debug_level_to_priority(int level)
{
@@ -141,10 +214,15 @@ static void debug_file_log(int msg_level,
const char *msg, const char *msg_no_nl)
{
ssize_t ret;
+ int fd = state.fd;
+
+ if (DEBUGLEVEL_CLASS[current_msg_class].fd != -1) {
+ fd = DEBUGLEVEL_CLASS[current_msg_class].fd;
+ }
check_log_size();
do {
- ret = write(state.fd, msg, strlen(msg));
+ ret = write(fd, msg, strlen(msg));
} while (ret == -1 && errno == EINTR);
}
@@ -512,77 +590,6 @@ static void debug_backends_log(const char *msg, int msg_level)
*/
bool override_logfile;
-static const char *default_classname_table[] = {
- [DBGC_ALL] = "all",
- [DBGC_TDB] = "tdb",
- [DBGC_PRINTDRIVERS] = "printdrivers",
- [DBGC_LANMAN] = "lanman",
- [DBGC_SMB] = "smb",
- [DBGC_RPC_PARSE] = "rpc_parse",
- [DBGC_RPC_SRV] = "rpc_srv",
- [DBGC_RPC_CLI] = "rpc_cli",
- [DBGC_PASSDB] = "passdb",
- [DBGC_SAM] = "sam",
- [DBGC_AUTH] = "auth",
- [DBGC_WINBIND] = "winbind",
- [DBGC_VFS] = "vfs",
- [DBGC_IDMAP] = "idmap",
- [DBGC_QUOTA] = "quota",
- [DBGC_ACLS] = "acls",
- [DBGC_LOCKING] = "locking",
- [DBGC_MSDFS] = "msdfs",
- [DBGC_DMAPI] = "dmapi",
- [DBGC_REGISTRY] = "registry",
- [DBGC_SCAVENGER] = "scavenger",
- [DBGC_DNS] = "dns",
- [DBGC_LDB] = "ldb",
- [DBGC_TEVENT] = "tevent",
- [DBGC_AUTH_AUDIT] = "auth_audit",
- [DBGC_AUTH_AUDIT_JSON] = "auth_json_audit",
- [DBGC_KERBEROS] = "kerberos",
- [DBGC_DRS_REPL] = "drs_repl",
- [DBGC_SMB2] = "smb2",
- [DBGC_SMB2_CREDITS] = "smb2_credits",
- [DBGC_DSDB_AUDIT] = "dsdb_audit",
- [DBGC_DSDB_AUDIT_JSON] = "dsdb_json_audit",
- [DBGC_DSDB_PWD_AUDIT] = "dsdb_password_audit",
- [DBGC_DSDB_PWD_AUDIT_JSON] = "dsdb_password_json_audit",
- [DBGC_DSDB_TXN_AUDIT] = "dsdb_transaction_audit",
- [DBGC_DSDB_TXN_AUDIT_JSON] = "dsdb_transaction_json_audit",
- [DBGC_DSDB_GROUP_AUDIT] = "dsdb_group_audit",
- [DBGC_DSDB_GROUP_AUDIT_JSON] = "dsdb_group_json_audit",
-};
-
-struct debug_class {
- /*
- * The debug classname.
- */
- const char *class_name;
-
- /*
- * An optional class specific logfile, may be NULL in which case the
- * "global" logfile is used.
- */
- const char *logfile;
- int fd;
-
- /*
- * The debug loglevel of the class.
- */
- int loglevel;
-};
-
-
-/*
- * This is to allow reading of DEBUGLEVEL_CLASS before the debug
- * system has been initialized.
- */
-static struct debug_class
-debug_class_list_initial[ARRAY_SIZE(default_classname_table)];
-
-static size_t debug_num_classes = 0;
-static struct debug_class *DEBUGLEVEL_CLASS = debug_class_list_initial;
-
int debuglevel_get_class(size_t idx)
{
return DEBUGLEVEL_CLASS[idx].loglevel;
@@ -618,8 +625,6 @@ void debuglevel_set_class(size_t idx, int level)
*/
static int debug_count = 0;
-static int current_msg_level = 0;
-static int current_msg_class = 0;
static char format_bufr[FORMAT_BUFR_SIZE];
static size_t format_pos = 0;
static bool log_overflow = false;
@@ -807,6 +812,7 @@ static void debug_dump_status(int level)
static bool debug_parse_param(char *param)
{
char *class_name;
+ char *class_file = NULL;
char *class_level;
char *saveptr = NULL;
int ndx;
@@ -816,11 +822,13 @@ static bool debug_parse_param(char *param)
return false;
}
- class_level = strtok_r(NULL, "\0", &saveptr);
+ class_level = strtok_r(NULL, "@\0", &saveptr);
if (class_level == NULL) {
return false;
}
+ class_file = strtok_r(NULL, "\0", &saveptr);
+
ndx = debug_lookup_classname(class_name);
if (ndx == -1) {
return false;
@@ -828,6 +836,12 @@ static bool debug_parse_param(char *param)
DEBUGLEVEL_CLASS[ndx].loglevel = atoi(class_level);
+ if (class_file != NULL) {
+ DEBUGLEVEL_CLASS[ndx].logfile = talloc_strdup(NULL, class_file);
+ if (DEBUGLEVEL_CLASS[ndx].logfile == NULL) {
+ return false;
+ }
+ }
return true;
}
@@ -1086,6 +1100,7 @@ bool reopen_logs_internal(void)
mode_t oldumask;
int new_fd = 0;
bool ret = true;
+ int i;
if (state.reopening_logs) {
return true;
@@ -1126,6 +1141,24 @@ bool reopen_logs_internal(void)
ret = false;
}
+ for (i = 0; i < debug_num_classes; i++) {
+ int fd;
+
+ if (DEBUGLEVEL_CLASS[i].logfile == NULL) {
+ debug_close_fd(DEBUGLEVEL_CLASS[i].fd);
+ DEBUGLEVEL_CLASS[i].fd = -1;
+ continue;
+ }
+
+ fd = reopen_one_log(&DEBUGLEVEL_CLASS[i].fd,
+ DEBUGLEVEL_CLASS[i].logfile);
+ if (fd == -1) {
+ DBG_ERR("Reopen log [%s] class [%s] failed\n",
+ DEBUGLEVEL_CLASS[i].logfile,
+ DEBUGLEVEL_CLASS[i].class_name);
+ }
+ }
+
/* Fix from klausr at ITAP.Physik.Uni-Stuttgart.De
* to fix problem where smbd's that generate less
* than 100 messages keep growing the log.
--
2.17.2
More information about the samba-technical
mailing list