[openssh-commits] [openssh] 02/03: upstream: revised log infrastructure for OpenSSH

git+noreply at mindrot.org git+noreply at mindrot.org
Sat Oct 17 00:43:27 AEDT 2020


This is an automated email from the git hooks/post-receive script.

djm pushed a commit to branch master
in repository openssh.

commit 752250caabda3dd24635503c4cd689b32a650794
Author: djm at openbsd.org <djm at openbsd.org>
Date:   Fri Oct 16 13:24:45 2020 +0000

    upstream: revised log infrastructure for OpenSSH
    
    log functions receive function, filename and line number of caller.
    We can use this to selectively enable logging via pattern-lists.
    
    ok markus@
    
    OpenBSD-Commit-ID: 51a472610cbe37834ce6ce4a3f0e0b1ccc95a349
---
 fatal.c        |   6 +-
 log.c          | 183 +++++++++++++++++++++++++++------------------------------
 log.h          |  59 +++++++++++++------
 monitor.c      |  15 +++--
 monitor_wrap.c |   8 ++-
 monitor_wrap.h |   5 +-
 ssh-keyscan.c  |   9 +--
 7 files changed, 153 insertions(+), 132 deletions(-)

diff --git a/fatal.c b/fatal.c
index 5e5aa3fe..3ecd510f 100644
--- a/fatal.c
+++ b/fatal.c
@@ -1,4 +1,4 @@
-/* $OpenBSD: fatal.c,v 1.7 2006/08/03 03:34:42 deraadt Exp $ */
+/* $OpenBSD: fatal.c,v 1.8 2020/10/16 13:24:45 djm Exp $ */
 /*
  * Copyright (c) 2002 Markus Friedl.  All rights reserved.
  *
@@ -34,12 +34,12 @@
 /* Fatal messages.  This function never returns. */
 
 void
-fatal(const char *fmt,...)
+sshfatal(const char *file, const char *func, int line, const char *fmt, ...)
 {
 	va_list args;
 
 	va_start(args, fmt);
-	do_log(SYSLOG_LEVEL_FATAL, fmt, args);
+	ssh_log(file, func, line, SYSLOG_LEVEL_FATAL, fmt, args);
 	va_end(args);
 	cleanup_exit(255);
 }
diff --git a/log.c b/log.c
index 6b1a7a31..159c306d 100644
--- a/log.c
+++ b/log.c
@@ -1,4 +1,4 @@
-/* $OpenBSD: log.c,v 1.52 2020/07/03 06:46:41 djm Exp $ */
+/* $OpenBSD: log.c,v 1.53 2020/10/16 13:24:45 djm Exp $ */
 /*
  * Author: Tatu Ylonen <ylo at cs.hut.fi>
  * Copyright (c) 1995 Tatu Ylonen <ylo at cs.hut.fi>, Espoo, Finland
@@ -51,6 +51,7 @@
 #endif
 
 #include "log.h"
+#include "match.h"
 
 static LogLevel log_level = SYSLOG_LEVEL_INFO;
 static int log_on_stderr = 1;
@@ -59,6 +60,8 @@ static int log_facility = LOG_AUTH;
 static char *argv0;
 static log_handler_fn *log_handler;
 static void *log_handler_ctx;
+static char **log_verbose;
+static size_t nlog_verbose;
 
 extern char *__progname;
 
@@ -157,96 +160,30 @@ log_level_name(LogLevel level)
 	return NULL;
 }
 
-/* Error messages that should be logged. */
-
-void
-error(const char *fmt,...)
-{
-	va_list args;
-
-	va_start(args, fmt);
-	do_log(SYSLOG_LEVEL_ERROR, fmt, args);
-	va_end(args);
-}
-
-void
-sigdie(const char *fmt,...)
-{
-#ifdef DO_LOG_SAFE_IN_SIGHAND
-	va_list args;
-
-	va_start(args, fmt);
-	do_log(SYSLOG_LEVEL_FATAL, fmt, args);
-	va_end(args);
-#endif
-	_exit(1);
-}
-
-void
-logdie(const char *fmt,...)
-{
-	va_list args;
-
-	va_start(args, fmt);
-	do_log(SYSLOG_LEVEL_INFO, fmt, args);
-	va_end(args);
-	cleanup_exit(255);
-}
-
-/* Log this message (information that usually should go to the log). */
-
-void
-logit(const char *fmt,...)
-{
-	va_list args;
-
-	va_start(args, fmt);
-	do_log(SYSLOG_LEVEL_INFO, fmt, args);
-	va_end(args);
-}
-
-/* More detailed messages (information that does not need to go to the log). */
-
-void
-verbose(const char *fmt,...)
-{
-	va_list args;
-
-	va_start(args, fmt);
-	do_log(SYSLOG_LEVEL_VERBOSE, fmt, args);
-	va_end(args);
-}
-
-/* Debugging messages that should not be logged during normal operation. */
-
-void
-debug(const char *fmt,...)
-{
-	va_list args;
-
-	va_start(args, fmt);
-	do_log(SYSLOG_LEVEL_DEBUG1, fmt, args);
-	va_end(args);
-}
-
 void
-debug2(const char *fmt,...)
+log_verbose_add(const char *s)
 {
-	va_list args;
+	char **tmp;
 
-	va_start(args, fmt);
-	do_log(SYSLOG_LEVEL_DEBUG2, fmt, args);
-	va_end(args);
+	/* Ignore failures here */
+	if ((tmp = recallocarray(log_verbose, nlog_verbose, nlog_verbose + 1,
+	    sizeof(*log_verbose))) != NULL) {
+		log_verbose = tmp;
+		if ((log_verbose[nlog_verbose] = strdup(s)) != NULL)
+			nlog_verbose++;
+	}
 }
 
 void
-debug3(const char *fmt,...)
+log_verbose_reset(void)
 {
-	va_list args;
+	size_t i;
 
-	va_start(args, fmt);
-	do_log(SYSLOG_LEVEL_DEBUG3, fmt, args);
-	va_end(args);
+	for (i = 0; i < nlog_verbose; i++)
+		free(log_verbose[i]);
+	free(log_verbose);
+	log_verbose = NULL;
+	nlog_verbose = 0;
 }
 
 /*
@@ -395,18 +332,9 @@ set_log_handler(log_handler_fn *handler, void *ctx)
 	log_handler_ctx = ctx;
 }
 
-void
-do_log2(LogLevel level, const char *fmt,...)
-{
-	va_list args;
-
-	va_start(args, fmt);
-	do_log(level, fmt, args);
-	va_end(args);
-}
-
-void
-do_log(LogLevel level, const char *fmt, va_list args)
+static void
+do_log(const char *file, const char *func, int line, LogLevel level,
+    int force, const char *fmt, va_list args)
 {
 #if defined(HAVE_OPENLOG_R) && defined(SYSLOG_DATA_INIT)
 	struct syslog_data sdata = SYSLOG_DATA_INIT;
@@ -418,7 +346,7 @@ do_log(LogLevel level, const char *fmt, va_list args)
 	int saved_errno = errno;
 	log_handler_fn *tmp_handler;
 
-	if (level > log_level)
+	if (!force && level > log_level)
 		return;
 
 	switch (level) {
@@ -467,7 +395,7 @@ do_log(LogLevel level, const char *fmt, va_list args)
 		/* Avoid recursion */
 		tmp_handler = log_handler;
 		log_handler = NULL;
-		tmp_handler(level, fmtbuf, log_handler_ctx);
+		tmp_handler(file, func, line, level, fmtbuf, log_handler_ctx);
 		log_handler = tmp_handler;
 	} else if (log_on_stderr) {
 		snprintf(msgbuf, sizeof msgbuf, "%.*s\r\n",
@@ -486,3 +414,64 @@ do_log(LogLevel level, const char *fmt, va_list args)
 	}
 	errno = saved_errno;
 }
+
+void
+sshlog(const char *file, const char *func, int line, int showfunc,
+    LogLevel level, const char *fmt, ...)
+{
+	va_list args;
+
+	va_start(args, fmt);
+	sshlogv(file, func, line, showfunc, level, fmt, args);
+	va_end(args);
+}
+
+void
+sshlogdie(const char *file, const char *func, int line, const char *fmt, ...)
+{
+	va_list args;
+
+	va_start(args, fmt);
+	sshlogv(file, func, line, 0, SYSLOG_LEVEL_INFO, fmt, args);
+	va_end(args);
+	cleanup_exit(255);
+}
+
+void
+sshsigdie(const char *file, const char *func, int line, const char *fmt, ...)
+{
+	va_list args;
+
+	va_start(args, fmt);
+	sshlogv(file, func, line, 0, SYSLOG_LEVEL_FATAL, fmt, args);
+	va_end(args);
+	_exit(1);
+}
+
+void
+sshlogv(const char *file, const char *func, int line, int showfunc,
+    LogLevel level, const char *fmt, va_list args)
+{
+	char tag[128], fmt2[MSGBUFSIZ + 128];
+	int forced = 0;
+	const char *cp;
+	size_t i;
+
+	snprintf(tag, sizeof(tag), "%.48s:%.48s():%d",
+	    (cp = strrchr(file, '/')) == NULL ? file : cp + 1, func, line);
+	for (i = 0; i < nlog_verbose; i++) {
+		if (match_pattern_list(tag, log_verbose[i], 0) == 1) {
+			forced = 1;
+			break;
+		}
+	}
+
+	if (log_handler == NULL && forced)
+		snprintf(fmt2, sizeof(fmt2), "%s: %s", tag, fmt);
+	else if (showfunc)
+		snprintf(fmt2, sizeof(fmt2), "%s: %s", func, fmt);
+	else
+		strlcpy(fmt2, fmt, sizeof(fmt2));
+
+	do_log(file, func, line, level, forced, fmt2, args);
+}
diff --git a/log.h b/log.h
index 78cda287..b1ab7c7e 100644
--- a/log.h
+++ b/log.h
@@ -1,4 +1,4 @@
-/* $OpenBSD: log.h,v 1.24 2019/09/06 04:53:27 djm Exp $ */
+/* $OpenBSD: log.h,v 1.25 2020/10/16 13:24:45 djm Exp $ */
 
 /*
  * Author: Tatu Ylonen <ylo at cs.hut.fi>
@@ -48,36 +48,57 @@ typedef enum {
 	SYSLOG_LEVEL_NOT_SET = -1
 }       LogLevel;
 
-typedef void (log_handler_fn)(LogLevel, const char *, void *);
+typedef void (log_handler_fn)(const char *, const char *, int, LogLevel,
+    const char *, void *);
 
 void     log_init(char *, LogLevel, SyslogFacility, int);
 LogLevel log_level_get(void);
 int      log_change_level(LogLevel);
 int      log_is_on_stderr(void);
 void     log_redirect_stderr_to(const char *);
+void	 log_verbose_add(const char *);
+void	 log_verbose_reset(void);
 
 SyslogFacility	log_facility_number(char *);
 const char * 	log_facility_name(SyslogFacility);
 LogLevel	log_level_number(char *);
 const char *	log_level_name(LogLevel);
 
-void     fatal(const char *, ...) __attribute__((noreturn))
-    __attribute__((format(printf, 1, 2)));
-void     error(const char *, ...) __attribute__((format(printf, 1, 2)));
-void     sigdie(const char *, ...)  __attribute__((noreturn))
-    __attribute__((format(printf, 1, 2)));
-void     logdie(const char *, ...) __attribute__((noreturn))
-    __attribute__((format(printf, 1, 2)));
-void     logit(const char *, ...) __attribute__((format(printf, 1, 2)));
-void     verbose(const char *, ...) __attribute__((format(printf, 1, 2)));
-void     debug(const char *, ...) __attribute__((format(printf, 1, 2)));
-void     debug2(const char *, ...) __attribute__((format(printf, 1, 2)));
-void     debug3(const char *, ...) __attribute__((format(printf, 1, 2)));
-
-
 void	 set_log_handler(log_handler_fn *, void *);
-void	 do_log2(LogLevel, const char *, ...)
-    __attribute__((format(printf, 2, 3)));
-void	 do_log(LogLevel, const char *, va_list);
 void	 cleanup_exit(int) __attribute__((noreturn));
+
+void	 sshlog(const char *, const char *, int, int,
+    LogLevel, const char *, ...) __attribute__((format(printf, 6, 7)));
+void	 sshlogv(const char *, const char *, int, int,
+    LogLevel, const char *, va_list);
+void	 sshsigdie(const char *, const char *, int, const char *, ...)
+    __attribute__((noreturn)) __attribute__((format(printf, 4, 5)));
+void	 sshlogdie(const char *, const char *, int, const char *, ...)
+    __attribute__((noreturn)) __attribute__((format(printf, 4, 5)));
+void	 sshfatal(const char *, const char *, int, const char *, ...)
+    __attribute__((noreturn)) __attribute__((format(printf, 4, 5)));
+
+#define ssh_nlog(level, ...)	sshlog(__FILE__, __func__, __LINE__, 0, level, __VA_ARGS__)
+#define ssh_debug3(...)		sshlog(__FILE__, __func__, __LINE__, 0, SYSLOG_LEVEL_DEBUG3, __VA_ARGS__)
+#define ssh_debug2(...)		sshlog(__FILE__, __func__, __LINE__, 0, SYSLOG_LEVEL_DEBUG2, __VA_ARGS__)
+#define ssh_debug(...)		sshlog(__FILE__, __func__, __LINE__, 0, SYSLOG_LEVEL_DEBUG1, __VA_ARGS__)
+#define ssh_verbose(...)	sshlog(__FILE__, __func__, __LINE__, 0, SYSLOG_LEVEL_VERBOSE, __VA_ARGS__)
+#define ssh_log(...)		sshlog(__FILE__, __func__, __LINE__, 0, SYSLOG_LEVEL_INFO, __VA_ARGS__)
+#define ssh_error(...)		sshlog(__FILE__, __func__, __LINE__, 0, SYSLOG_LEVEL_ERROR, __VA_ARGS__)
+#define ssh_fatal(...)		sshfatal(__FILE__, __func__, __LINE__, __VA_ARGS__)
+#define ssh_logdie(...)		sshlogdie(__FILE__, __func__, __LINE__, __VA_ARGS__)
+#define ssh_sigdie(...)		sshsigdie(__FILE__, __func__, __LINE__, __VA_ARGS__)
+
+#define debug	ssh_debug
+#define debug1	ssh_debug1
+#define debug2	ssh_debug2
+#define debug3	ssh_debug3
+#define error	ssh_error
+#define logit	ssh_log
+#define verbose	ssh_verbose
+#define fatal	ssh_fatal
+#define logdie	ssh_logdie
+#define sigdie	ssh_sigdie
+#define do_log2	ssh_nlog
+
 #endif
diff --git a/monitor.c b/monitor.c
index 4cf79dfc..9f22f068 100644
--- a/monitor.c
+++ b/monitor.c
@@ -1,4 +1,4 @@
-/* $OpenBSD: monitor.c,v 1.214 2020/08/27 01:07:09 djm Exp $ */
+/* $OpenBSD: monitor.c,v 1.215 2020/10/16 13:24:45 djm Exp $ */
 /*
  * Copyright 2002 Niels Provos <provos at citi.umich.edu>
  * Copyright 2002 Markus Friedl <markus at openbsd.org>
@@ -420,8 +420,8 @@ static int
 monitor_read_log(struct monitor *pmonitor)
 {
 	struct sshbuf *logmsg;
-	u_int len, level;
-	char *msg;
+	u_int len, level, line;
+	char *msg, *file, *func;
 	u_char *p;
 	int r;
 
@@ -452,7 +452,10 @@ monitor_read_log(struct monitor *pmonitor)
 		fatal("%s: reserve: %s", __func__, ssh_err(r));
 	if (atomicio(read, pmonitor->m_log_recvfd, p, len) != len)
 		fatal("%s: log fd read: %s", __func__, strerror(errno));
-	if ((r = sshbuf_get_u32(logmsg, &level)) != 0 ||
+	if ((r = sshbuf_get_cstring(logmsg, &file, NULL)) != 0 ||
+	    (r = sshbuf_get_cstring(logmsg, &func, NULL)) != 0 ||
+	    (r = sshbuf_get_u32(logmsg, &line)) != 0 ||
+	    (r = sshbuf_get_u32(logmsg, &level)) != 0 ||
 	    (r = sshbuf_get_cstring(logmsg, &msg, NULL)) != 0)
 		fatal("%s: decode: %s", __func__, ssh_err(r));
 
@@ -460,9 +463,11 @@ monitor_read_log(struct monitor *pmonitor)
 	if (log_level_name(level) == NULL)
 		fatal("%s: invalid log level %u (corrupted message?)",
 		    __func__, level);
-	do_log2(level, "%s [preauth]", msg);
+	sshlog(file, func, line, 0, level, "%s [preauth]", msg);
 
 	sshbuf_free(logmsg);
+	free(file);
+	free(func);
 	free(msg);
 
 	return 0;
diff --git a/monitor_wrap.c b/monitor_wrap.c
index 5e38d83e..c18ee181 100644
--- a/monitor_wrap.c
+++ b/monitor_wrap.c
@@ -1,4 +1,4 @@
-/* $OpenBSD: monitor_wrap.c,v 1.118 2020/08/27 01:06:18 djm Exp $ */
+/* $OpenBSD: monitor_wrap.c,v 1.119 2020/10/16 13:24:45 djm Exp $ */
 /*
  * Copyright 2002 Niels Provos <provos at citi.umich.edu>
  * Copyright 2002 Markus Friedl <markus at openbsd.org>
@@ -82,7 +82,8 @@ extern struct sshbuf *loginmsg;
 extern ServerOptions options;
 
 void
-mm_log_handler(LogLevel level, const char *msg, void *ctx)
+mm_log_handler(const char *file, const char *func, int line,
+    LogLevel level, const char *msg, void *ctx)
 {
 	struct sshbuf *log_msg;
 	struct monitor *mon = (struct monitor *)ctx;
@@ -96,6 +97,9 @@ mm_log_handler(LogLevel level, const char *msg, void *ctx)
 		fatal("%s: sshbuf_new failed", __func__);
 
 	if ((r = sshbuf_put_u32(log_msg, 0)) != 0 || /* length; filled below */
+	    (r = sshbuf_put_cstring(log_msg, file)) != 0 ||
+	    (r = sshbuf_put_cstring(log_msg, func)) != 0 ||
+	    (r = sshbuf_put_u32(log_msg, (u_int)line)) != 0 ||
 	    (r = sshbuf_put_u32(log_msg, level)) != 0 ||
 	    (r = sshbuf_put_cstring(log_msg, msg)) != 0)
 		fatal("%s: buffer error: %s", __func__, ssh_err(r));
diff --git a/monitor_wrap.h b/monitor_wrap.h
index 0db38c20..8507f1c1 100644
--- a/monitor_wrap.h
+++ b/monitor_wrap.h
@@ -1,4 +1,4 @@
-/* $OpenBSD: monitor_wrap.h,v 1.45 2020/08/27 01:06:18 djm Exp $ */
+/* $OpenBSD: monitor_wrap.h,v 1.46 2020/10/16 13:24:45 djm Exp $ */
 
 /*
  * Copyright 2002 Niels Provos <provos at citi.umich.edu>
@@ -40,7 +40,8 @@ struct sshkey;
 struct sshauthopt;
 struct sshkey_sig_details;
 
-void mm_log_handler(LogLevel, const char *, void *);
+void mm_log_handler(const char *, const char *, int, LogLevel,
+    const char *, void *);
 int mm_is_monitor(void);
 #ifdef WITH_OPENSSL
 DH *mm_choose_dh(int, int, int);
diff --git a/ssh-keyscan.c b/ssh-keyscan.c
index ca190428..ac7bfcd1 100644
--- a/ssh-keyscan.c
+++ b/ssh-keyscan.c
@@ -1,4 +1,4 @@
-/* $OpenBSD: ssh-keyscan.c,v 1.132 2020/08/12 01:23:45 cheloha Exp $ */
+/* $OpenBSD: ssh-keyscan.c,v 1.133 2020/10/16 13:24:45 djm Exp $ */
 /*
  * Copyright 1995, 1996 by David Mazieres <dm at lcs.mit.edu>.
  *
@@ -635,14 +635,15 @@ do_host(char *host)
 }
 
 void
-fatal(const char *fmt,...)
+sshfatal(const char *file, const char *func, int line,
+    const char *fmt, ...)
 {
 	va_list args;
 
 	va_start(args, fmt);
-	do_log(SYSLOG_LEVEL_FATAL, fmt, args);
+	ssh_log(file, func, line, SYSLOG_LEVEL_FATAL, fmt, args);
 	va_end(args);
-	exit(255);
+	cleanup_exit(255);
 }
 
 static void

-- 
To stop receiving notification emails like this one, please contact
djm at mindrot.org.


More information about the openssh-commits mailing list