From 2c84bd4d083bc41aabf1d05f464cd601801d383d Mon Sep 17 00:00:00 2001 From: "Todd C. Miller" Date: Thu, 5 Apr 2012 12:37:15 -0400 Subject: [PATCH] Log warning() at SUDO_DEBUG_WARN not SUDO_DEBUG_ERROR. Log the function, file and line number in the debug log for warning() and error(). --- common/sudo_debug.c | 249 ++++++++++++++++++++++++++--------------- include/error.h | 24 ++-- include/sudo_debug.h | 7 +- plugins/sudoers/toke.c | 4 +- plugins/sudoers/toke.h | 5 - plugins/sudoers/toke.l | 4 +- 6 files changed, 181 insertions(+), 112 deletions(-) diff --git a/common/sudo_debug.c b/common/sudo_debug.c index 2b2a12355..c73d3d298 100644 --- a/common/sudo_debug.c +++ b/common/sudo_debug.c @@ -181,37 +181,37 @@ void sudo_debug_enter(const char *func, const char *file, int line, int subsys) { - sudo_debug_printf2(subsys | SUDO_DEBUG_TRACE, "-> %s @ %s:%d", func, - file, line); + sudo_debug_printf2(NULL, NULL, 0, subsys | SUDO_DEBUG_TRACE, + "-> %s @ %s:%d", func, file, line); } void sudo_debug_exit(const char *func, const char *file, int line, int subsys) { - sudo_debug_printf2(subsys | SUDO_DEBUG_TRACE, "<- %s @ %s:%d", func, - file, line); + sudo_debug_printf2(NULL, NULL, 0, subsys | SUDO_DEBUG_TRACE, + "<- %s @ %s:%d", func, file, line); } void sudo_debug_exit_int(const char *func, const char *file, int line, int subsys, int rval) { - sudo_debug_printf2(subsys | SUDO_DEBUG_TRACE, "<- %s @ %s:%d := %d", func, - file, line, rval); + sudo_debug_printf2(NULL, NULL, 0, subsys | SUDO_DEBUG_TRACE, + "<- %s @ %s:%d := %d", func, file, line, rval); } void sudo_debug_exit_long(const char *func, const char *file, int line, int subsys, long rval) { - sudo_debug_printf2(subsys | SUDO_DEBUG_TRACE, "<- %s @ %s:%d := %ld", func, - file, line, rval); + sudo_debug_printf2(NULL, NULL, 0, subsys | SUDO_DEBUG_TRACE, + "<- %s @ %s:%d := %ld", func, file, line, rval); } void sudo_debug_exit_size_t(const char *func, const char *file, int line, int subsys, size_t rval) { /* XXX - should use %zu but our snprintf.c doesn't support it */ - sudo_debug_printf2(subsys | SUDO_DEBUG_TRACE, "<- %s @ %s:%d := %lu", func, - file, line, (unsigned long)rval); + sudo_debug_printf2(NULL, NULL, 0, subsys | SUDO_DEBUG_TRACE, + "<- %s @ %s:%d := %lu", func, file, line, (unsigned long)rval); } /* We use int, not bool, here for functions that return -1 on error. */ @@ -219,19 +219,19 @@ void sudo_debug_exit_bool(const char *func, const char *file, int line, int subsys, int rval) { if (rval == true || rval == false) { - sudo_debug_printf2(subsys | SUDO_DEBUG_TRACE, "<- %s @ %s:%d := %s", - func, file, line, rval ? "true" : "false"); + sudo_debug_printf2(NULL, NULL, 0, subsys | SUDO_DEBUG_TRACE, + "<- %s @ %s:%d := %s", func, file, line, rval ? "true" : "false"); } else { - sudo_debug_printf2(subsys | SUDO_DEBUG_TRACE, "<- %s @ %s:%d := %d", - func, file, line, rval); + sudo_debug_printf2(NULL, NULL, 0, subsys | SUDO_DEBUG_TRACE, + "<- %s @ %s:%d := %d", func, file, line, rval); } } void sudo_debug_exit_str(const char *func, const char *file, int line, int subsys, const char *rval) { - sudo_debug_printf2(subsys | SUDO_DEBUG_TRACE, "<- %s @ %s:%d := %s", func, - file, line, rval ? rval : "(null)"); + sudo_debug_printf2(NULL, NULL, 0, subsys | SUDO_DEBUG_TRACE, + "<- %s @ %s:%d := %s", func, file, line, rval ? rval : "(null)"); } void sudo_debug_exit_str_masked(const char *func, const char *file, int line, @@ -240,104 +240,169 @@ void sudo_debug_exit_str_masked(const char *func, const char *file, int line, static const char stars[] = "********************************************************************************"; int len = rval ? strlen(rval) : sizeof("(null)") - 1; - sudo_debug_printf2(subsys | SUDO_DEBUG_TRACE, "<- %s @ %s:%d := %.*s", func, - file, line, len, rval ? stars : "(null)"); + sudo_debug_printf2(NULL, NULL, 0, subsys | SUDO_DEBUG_TRACE, + "<- %s @ %s:%d := %.*s", func, file, line, len, rval ? stars : "(null)"); } void sudo_debug_exit_ptr(const char *func, const char *file, int line, int subsys, const void *rval) { - sudo_debug_printf2(subsys | SUDO_DEBUG_TRACE, "<- %s @ %s:%d := %p", func, - file, line, rval); + sudo_debug_printf2(NULL, NULL, 0, subsys | SUDO_DEBUG_TRACE, + "<- %s @ %s:%d := %p", func, file, line, rval); } -void -sudo_debug_write(const char *str, int len, int errno_val) +static void +sudo_debug_write_conv(const char *func, const char *file, int lineno, + const char *str, int len, int errno_val) { - char *timestr; + struct sudo_conv_message msg; + struct sudo_conv_reply repl; + char *buf = NULL; + + /* Call conversation function */ + if (sudo_conv != NULL) { + /* Remove the newline at the end if appending extra info. */ + if (str[len - 1] == '\n') + len--; + + if (func != NULL && file != NULL && lineno != 0) { + if (errno_val) { + easprintf(&buf, "%.*s: %s @ %s() %s:%d", len, str, + strerror(errno_val), func, file, lineno); + } else { + easprintf(&buf, "%.*s @ %s() %s:%d", len, str, + func, file, lineno); + } + str = buf; + } else if (errno_val) { + easprintf(&buf, "%.*s: %s", len, str, strerror(errno_val)); + str = buf; + } + memset(&msg, 0, sizeof(msg)); + memset(&repl, 0, sizeof(repl)); + msg.msg_type = SUDO_CONV_DEBUG_MSG; + msg.msg = str; + sudo_conv(1, &msg, &repl); + if (buf != NULL) + efree(buf); + } +} + +static void +sudo_debug_write_file(const char *func, const char *file, int lineno, + const char *str, int len, int errno_val) +{ + char *timestr, numbuf[(((sizeof(int) * 8) + 2) / 3) + 2]; time_t now; - struct iovec iov[7]; + struct iovec iov[12]; int iovcnt = 4; bool need_newline = false; + /* Prepend program name with trailing space. */ + iov[1].iov_base = (char *)getprogname(); + iov[1].iov_len = strlen(iov[1].iov_base); + iov[2].iov_base = " "; + iov[2].iov_len = 1; + + /* Add string along with newline if it doesn't have one. */ + iov[3].iov_base = (char *)str; + iov[3].iov_len = len; + if (str[len - 1] != '\n') + need_newline = true; + + /* Append error string if errno is specified. */ + if (errno_val) { + iov[iovcnt].iov_base = ": "; + iov[iovcnt].iov_len = 2; + iovcnt++; + iov[iovcnt].iov_base = strerror(errno_val); + iov[iovcnt].iov_len = strlen(iov[iovcnt].iov_base); + iovcnt++; + + /* Move newline to the end. */ + if (!need_newline) { + need_newline = true; + iov[3].iov_len--; + } + } + + /* If function, file and lineno are specified, append them. */ + if (func != NULL && file != NULL && lineno != 0) { + iov[iovcnt].iov_base = " @ "; + iov[iovcnt].iov_len = 3; + iovcnt++; + + iov[iovcnt].iov_base = (char *)func; + iov[iovcnt].iov_len = strlen(func); + iovcnt++; + + iov[iovcnt].iov_base = "() "; + iov[iovcnt].iov_len = 3; + iovcnt++; + + iov[iovcnt].iov_base = (char *)file; + iov[iovcnt].iov_len = strlen(file); + iovcnt++; + + (void)snprintf(numbuf, sizeof(numbuf), ":%d", lineno); + iov[iovcnt].iov_base = numbuf; + iov[iovcnt].iov_len = strlen(numbuf); + iovcnt++; + + /* Move newline to the end. */ + if (!need_newline) { + need_newline = true; + iov[3].iov_len--; + } + } + + /* Append newline as needed. */ + if (need_newline) { + /* force newline */ + iov[iovcnt].iov_base = "\n"; + iov[iovcnt].iov_len = 1; + iovcnt++; + } + + /* Do timestamp last due to ctime's static buffer. */ + now = time(NULL); + timestr = ctime(&now) + 4; + timestr[15] = ' '; /* replace year with a space */ + timestr[16] = '\0'; + iov[0].iov_base = timestr; + iov[0].iov_len = 16; + + /* Write message in a single syscall */ + ignore_result(writev(sudo_debug_fd, iov, iovcnt)); +} + +void +sudo_debug_write2(const char *func, const char *file, int lineno, + const char *str, int len, int errno_val) +{ if (len <= 0) return; switch (sudo_debug_mode) { case SUDO_DEBUG_MODE_CONV: - /* Call conversation function */ - if (sudo_conv != NULL) { - struct sudo_conv_message msg[3]; - struct sudo_conv_reply repl[3]; - int msgcnt = 1; - - memset(msg, 0, sizeof(msg)); - memset(repl, 0, sizeof(repl)); - msg[0].msg_type = SUDO_CONV_DEBUG_MSG; - msg[0].msg = str; - if (errno_val) { - msgcnt = 3; - msg[1].msg_type = SUDO_CONV_DEBUG_MSG; - msg[1].msg = ": "; - msg[2].msg_type = SUDO_CONV_DEBUG_MSG; - msg[2].msg = strerror(errno_val); - } - sudo_conv(msgcnt, msg, repl); - } + sudo_debug_write_conv(func, file, lineno, str, len, errno_val); break; case SUDO_DEBUG_MODE_FILE: - /* Prepend program name with trailing space. */ - iov[1].iov_base = (char *)getprogname(); - iov[1].iov_len = strlen(iov[1].iov_base); - iov[2].iov_base = " "; - iov[2].iov_len = 1; - - /* Add string along with newline if it doesn't have one. */ - iov[3].iov_base = (char *)str; - iov[3].iov_len = len; - if (str[len - 1] != '\n') - need_newline = true; - - /* Append error string if errno is specified. */ - if (errno_val) { - iov[iovcnt].iov_base = ": "; - iov[iovcnt].iov_len = 2; - iovcnt++; - iov[iovcnt].iov_base = strerror(errno_val); - iov[iovcnt].iov_len = strlen(iov[iovcnt].iov_base); - iovcnt++; - - /* Move newline to the end. */ - if (!need_newline) { - need_newline = true; - iov[3].iov_len--; - } - } - - /* Append newline as needed. */ - if (need_newline) { - /* force newline */ - iov[iovcnt].iov_base = "\n"; - iov[iovcnt].iov_len = 1; - iovcnt++; - } - - /* Do timestamp last due to ctime's static buffer. */ - now = time(NULL); - timestr = ctime(&now) + 4; - timestr[15] = ' '; /* replace year with a space */ - timestr[16] = '\0'; - iov[0].iov_base = timestr; - iov[0].iov_len = 16; - - /* Write message in a single syscall */ - ignore_result(writev(sudo_debug_fd, iov, iovcnt)); + sudo_debug_write_file(func, file, lineno, str, len, errno_val); break; } } +/* XXX - turn into a macro */ void -sudo_debug_printf2(int level, const char *fmt, ...) +sudo_debug_write(const char *str, int len, int errno_val) +{ + sudo_debug_write2(NULL, NULL, 0, str, len, errno_val); +} + +void +sudo_debug_printf2(const char *func, const char *file, int lineno, int level, + const char *fmt, ...) { int buflen, pri, subsys, saved_errno = errno; va_list ap; @@ -357,9 +422,9 @@ sudo_debug_printf2(int level, const char *fmt, ...) va_end(ap); if (buflen != -1) { if (ISSET(level, SUDO_DEBUG_ERRNO)) - sudo_debug_write(buf, buflen, saved_errno); + sudo_debug_write2(func, file, lineno, buf, buflen, saved_errno); else - sudo_debug_write(buf, buflen, 0); + sudo_debug_write2(func, file, lineno, buf, buflen, 0); free(buf); } } diff --git a/include/error.h b/include/error.h index 17cc0697c..2c1cf636c 100644 --- a/include/error.h +++ b/include/error.h @@ -38,36 +38,44 @@ #else /* SUDO_ERROR_WRAP */ # if defined(__GNUC__) && __GNUC__ == 2 # define error(rval, fmt...) do { \ - sudo_debug_printf2(SUDO_DEBUG_ERROR|SUDO_DEBUG_ERRNO|sudo_debug_subsys, (fmt));\ + sudo_debug_printf2(__func__, __FILE__, __LINE__, \ + SUDO_DEBUG_ERROR|SUDO_DEBUG_ERRNO|sudo_debug_subsys, (fmt)); \ error2((rval), (fmt)); \ } while (0) # define errorx(rval, fmt...) do { \ - sudo_debug_printf2(SUDO_DEBUG_ERROR|sudo_debug_subsys, (fmt)); \ + sudo_debug_printf2(__func__, __FILE__, __LINE__, \ + SUDO_DEBUG_ERROR|sudo_debug_subsys, (fmt)); \ errorx2((rval), (fmt)); \ } while (0) # define warning(fmt...) do { \ - sudo_debug_printf2(SUDO_DEBUG_ERROR|SUDO_DEBUG_ERRNO|sudo_debug_subsys, (fmt));\ + sudo_debug_printf2(__func__, __FILE__, __LINE__, \ + SUDO_DEBUG_ERROR|SUDO_DEBUG_ERRNO|sudo_debug_subsys, (fmt)); \ warning2((fmt)); \ } while (0) # define warningx(fmt...) do { \ - sudo_debug_printf2(SUDO_DEBUG_ERROR|sudo_debug_subsys, (fmt)); \ + sudo_debug_printf2(__func__, __FILE__, __LINE__, \ + SUDO_DEBUG_ERROR|sudo_debug_subsys, (fmt)); \ warningx2((fmt)); \ } while (0) # else # define error(rval, ...) do { \ - sudo_debug_printf2(SUDO_DEBUG_ERROR|SUDO_DEBUG_ERRNO|sudo_debug_subsys, __VA_ARGS__);\ + sudo_debug_printf2(__func__, __FILE__, __LINE__, \ + SUDO_DEBUG_ERROR|SUDO_DEBUG_ERRNO|sudo_debug_subsys, __VA_ARGS__); \ error2((rval), __VA_ARGS__); \ } while (0) # define errorx(rval, ...) do { \ - sudo_debug_printf2(SUDO_DEBUG_ERROR|sudo_debug_subsys, __VA_ARGS__); \ + sudo_debug_printf2(__func__, __FILE__, __LINE__, \ + SUDO_DEBUG_ERROR|sudo_debug_subsys, __VA_ARGS__); \ errorx2((rval), __VA_ARGS__); \ } while (0) # define warning(...) do { \ - sudo_debug_printf2(SUDO_DEBUG_ERROR|SUDO_DEBUG_ERRNO|sudo_debug_subsys, __VA_ARGS__);\ + sudo_debug_printf2(__func__, __FILE__, __LINE__, \ + SUDO_DEBUG_WARN|SUDO_DEBUG_ERRNO|sudo_debug_subsys, __VA_ARGS__); \ warning2(__VA_ARGS__); \ } while (0) # define warningx(...) do { \ - sudo_debug_printf2(SUDO_DEBUG_ERROR|sudo_debug_subsys, __VA_ARGS__); \ + sudo_debug_printf2(__func__, __FILE__, __LINE__, \ + SUDO_DEBUG_WARN|sudo_debug_subsys, __VA_ARGS__); \ warningx2(__VA_ARGS__); \ } while (0) # endif /* __GNUC__ == 2 */ diff --git a/include/sudo_debug.h b/include/sudo_debug.h index 41389c798..4facb9dc6 100644 --- a/include/sudo_debug.h +++ b/include/sudo_debug.h @@ -167,10 +167,10 @@ */ #if defined(__GNUC__) && __GNUC__ == 2 # define sudo_debug_printf(pri, fmt...) \ - sudo_debug_printf2((pri)|sudo_debug_subsys, (fmt)) + sudo_debug_printf2(NULL, NULL, 0, (pri)|sudo_debug_subsys, (fmt)) #else # define sudo_debug_printf(pri, ...) \ - sudo_debug_printf2((pri)|sudo_debug_subsys, __VA_ARGS__) + sudo_debug_printf2(NULL, NULL, 0, (pri)|sudo_debug_subsys, __VA_ARGS__) #endif #define sudo_debug_execve(pri, path, argv, envp) \ @@ -194,7 +194,8 @@ void sudo_debug_exit_str_masked(const char *func, const char *file, int line, in void sudo_debug_exit_ptr(const char *func, const char *file, int line, int subsys, const void *rval); int sudo_debug_fd_set(int fd); int sudo_debug_init(const char *debugfile, const char *settings); -void sudo_debug_printf2(int level, const char *format, ...) __printflike(2, 3); +void sudo_debug_printf2(const char *func, const char *file, int line, int level, const char *format, ...) __printflike(5, 6); void sudo_debug_write(const char *str, int len, int errno_val); +void sudo_debug_write2(const char *func, const char *file, int line, const char *str, int len, int errno_val); #endif /* _SUDO_DEBUG_H */ diff --git a/plugins/sudoers/toke.c b/plugins/sudoers/toke.c index b740aaf24..83125a30c 100644 --- a/plugins/sudoers/toke.c +++ b/plugins/sudoers/toke.c @@ -3725,8 +3725,8 @@ sudoers_trace_print(const char *msg) /* XXX - assumes a final newline */ if (strchr(msg, '\n') != NULL) { - sudo_debug_printf2(SUDO_DEBUG_PARSER|SUDO_DEBUG_DEBUG, "%s:%d %s", - sudoers, sudolineno, lbuf.buf); + sudo_debug_printf2(NULL, NULL, 0, SUDO_DEBUG_PARSER|SUDO_DEBUG_DEBUG, + "%s:%d %s", sudoers, sudolineno, lbuf.buf); lbuf.len = 0; } return 0; diff --git a/plugins/sudoers/toke.h b/plugins/sudoers/toke.h index aed6dc379..efcb4f4f2 100644 --- a/plugins/sudoers/toke.h +++ b/plugins/sudoers/toke.h @@ -33,11 +33,6 @@ extern int (*trace_print)(const char *msg); /* realloc() to size + COMMANDARGINC to make room for command args */ #define COMMANDARGINC 64 -/* - * XXX - want to use debug file for lexer tracing, e.g. - * sudo_debug_printf2(SUDO_DEBUG_PARSER|SUDO_DEBUG_DEBUG, "%s", msg); - * but need to add buffering so that it is line oriented. - */ #define LEXTRACE(msg) do { \ if (trace_print != NULL) \ (*trace_print)(msg); \ diff --git a/plugins/sudoers/toke.l b/plugins/sudoers/toke.l index 912d4d6bc..40981cd83 100644 --- a/plugins/sudoers/toke.l +++ b/plugins/sudoers/toke.l @@ -1016,8 +1016,8 @@ sudoers_trace_print(const char *msg) /* XXX - assumes a final newline */ if (strchr(msg, '\n') != NULL) { - sudo_debug_printf2(SUDO_DEBUG_PARSER|SUDO_DEBUG_DEBUG, "%s:%d %s", - sudoers, sudolineno, lbuf.buf); + sudo_debug_printf2(NULL, NULL, 0, SUDO_DEBUG_PARSER|SUDO_DEBUG_DEBUG, + "%s:%d %s", sudoers, sudolineno, lbuf.buf); lbuf.len = 0; } return 0;