diff --git a/src/debug.c b/src/debug.c index 0ddb1539..a861b416 100644 --- a/src/debug.c +++ b/src/debug.c @@ -1,424 +1,435 @@ /* debug.c - helpful output in desperate situations * Copyright (C) 2000 Werner Koch (dd9jn) * Copyright (C) 2001, 2002, 2003, 2004, 2005, 2007, 2009, 2019 g10 Code GmbH * * This file is part of GPGME. * * GPGME is free software; you can redistribute it and/or modify it * under the terms of the GNU Lesser General Public License as * published by the Free Software Foundation; either version 2.1 of * the License, or (at your option) any later version. * * GPGME is distributed in the hope that it will be useful, but * WITHOUT ANY WARRANTY; without even the implied warranty of * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU * Lesser General Public License for more details. * * You should have received a copy of the GNU Lesser General Public * License along with this program; if not, see . * SPDX-License-Identifier: LGPL-2.1-or-later */ #if HAVE_CONFIG_H #include #endif #include #include #include #include #ifdef HAVE_UNISTD_H # include #endif #include #include #include #ifndef HAVE_DOSISH_SYSTEM # ifdef HAVE_SYS_TYPES_H # include # endif # ifdef HAVE_SYS_STAT_H # include # endif # include #endif #include #include "util.h" #include "ath.h" #include "sema.h" #include "sys-util.h" #include "debug.h" /* The amount of detail requested by the user, per environment variable GPGME_DEBUG. */ static int debug_level; /* The output stream for the debug messages. */ static FILE *errfp; /* If not NULL, this malloced string is used instead of the GPGME_DEBUG envvar. It must have been set before the debug subsystem has been initialized. Using it later may or may not have any effect. */ static char *envvar_override; #ifdef HAVE_TLS #define FRAME_NR static __thread int frame_nr = 0; #endif void _gpgme_debug_frame_begin (void) { #ifdef FRAME_NR frame_nr++; #endif } int _gpgme_debug_frame_end (void) { #ifdef FRAME_NR frame_nr--; #endif return 0; } /* Remove leading and trailing white spaces. */ static char * trim_spaces (char *str) { char *string, *p, *mark; string = str; /* Find first non space character. */ for (p = string; *p && isspace (*(unsigned char *) p); p++) ; /* Move characters. */ for (mark = NULL; (*string = *p); string++, p++) if (isspace (*(unsigned char *) p)) { if (!mark) mark = string; } else mark = NULL; if (mark) *mark = '\0'; /* Remove trailing spaces. */ return str; } /* This is an internal function to set debug info. The caller must assure that this function is called only by one thread at a time. The function may have no effect if called after the debug system has been initialized. Returns 0 on success. */ int _gpgme_debug_set_debug_envvar (const char *value) { free (envvar_override); envvar_override = strdup (value); return !envvar_override; } static void debug_init (void) { static int initialized; if (!initialized) { gpgme_error_t err; char *e; const char *s1, *s2;; if (envvar_override) { e = strdup (envvar_override); free (envvar_override); envvar_override = NULL; } else { err = _gpgme_getenv ("GPGME_DEBUG", &e); if (err) return; } initialized = 1; errfp = stderr; if (e) { debug_level = atoi (e); s1 = strchr (e, PATHSEP_C); if (s1) { #ifndef HAVE_DOSISH_SYSTEM if (getuid () == geteuid () #if defined(HAVE_GETGID) && defined(HAVE_GETEGID) && getgid () == getegid () #endif ) { #endif char *p; FILE *fp; s1++; if (!(s2 = strchr (s1, PATHSEP_C))) s2 = s1 + strlen (s1); p = malloc (s2 - s1 + 1); if (p) { memcpy (p, s1, s2 - s1); p[s2-s1] = 0; trim_spaces (p); fp = fopen (p,"a"); if (fp) { setvbuf (fp, NULL, _IOLBF, 0); errfp = fp; } free (p); } #ifndef HAVE_DOSISH_SYSTEM } #endif } free (e); } } if (debug_level > 0) { _gpgme_debug (NULL, DEBUG_INIT, -1, NULL, NULL, NULL, "gpgme_debug: level=%d\n", debug_level); #ifdef HAVE_W32_SYSTEM { const char *name = _gpgme_get_inst_dir (); _gpgme_debug (NULL, DEBUG_INIT, -1, NULL, NULL, NULL, "gpgme_debug: gpgme='%s'\n", name? name: "?"); } #endif } } /* This should be called as soon as possible. It is required so that * the assuan logging gets connected to the gpgme log stream as early * as possible. */ void _gpgme_debug_subsystem_init (void) { debug_init (); } /* Log the formatted string FORMAT prefixed with additional info * depending on MODE: * * -1 = Do not print any additional args. * 0 = standalone (used by macro TRACE) * 1 = enter a function (used by macro TRACE_BEG) * 2 = debug a function (used by macro TRACE_LOG) * 3 = leave a function (used by macro TRACE_SUC) * * If LINE is not NULL the output will be stored in that variabale but * without a LF. _gpgme_debug_add can be used to add more and * _gpgme_debug_end to finally output it. * * Returns: 0 * * Note that we always return 0 because the old TRACE macro evaluated * to 0 which issues a warning with newer gcc version about an unused * values. By using a return value of this function this can be * avoided. Fixme: It might be useful to check whether the return * value from the TRACE macros are actually used somewhere. */ int _gpgme_debug (void **line, int level, int mode, const char *func, const char *tagname, const char *tagvalue, const char *format, ...) { va_list arg_ptr; int saved_errno; int need_lf; int indent; char *prefix, *stdinfo, *userinfo; const char *modestr; + int no_userinfo = 0; if (debug_level < level) return 0; #ifdef FRAME_NR indent = frame_nr > 0? (2 * (frame_nr - 1)):0; #else indent = 0; #endif saved_errno = errno; va_start (arg_ptr, format); { struct tm *tp; time_t atime = time (NULL); tp = localtime (&atime); prefix = gpgrt_bsprintf ("GPGME %04d%02d%02dT%02d%02d%02d %04llX %*s", 1900+tp->tm_year, tp->tm_mon+1, tp->tm_mday, tp->tm_hour, tp->tm_min, tp->tm_sec, (unsigned long long) ath_self (), indent < 40? indent : 40, ""); } switch (mode) { case -1: modestr = NULL; break; /* Do nothing. */ case 0: modestr = "call"; break; case 1: modestr = "enter"; break; case 2: modestr = "check"; break; case 3: modestr = "leave"; break; default: modestr = "mode?"; break; } if (!modestr) stdinfo = NULL; else if (tagname && strcmp (tagname, XSTRINGIFY (NULL))) stdinfo = gpgrt_bsprintf ("%s: %s: %s=%p ", func,modestr,tagname,tagvalue); else stdinfo = gpgrt_bsprintf ("%s: %s: ", func, modestr); - userinfo = gpgrt_vbsprintf (format, arg_ptr); + if (format && *format) + userinfo = gpgrt_vbsprintf (format, arg_ptr); + else + { + userinfo = NULL; + no_userinfo = 1; + } va_end (arg_ptr); if (mode != -1 && (!format || !*format)) need_lf = 1; else if (userinfo && *userinfo && userinfo[strlen (userinfo) - 1] != '\n') need_lf = 1; else need_lf = 0; if (line) *line = gpgrt_bsprintf ("%s%s%s", prefix? prefix : "GPGME out-of-core ", !modestr? "" : stdinfo? stdinfo : (!format || !*format)? "" :"out-of-core ", userinfo? userinfo : "out-of-core"); else { fprintf (errfp, "%s%s%s%s", prefix? prefix : "GPGME out-of-core ", !modestr? "" : stdinfo? stdinfo : (!format || !*format)? "" :"out-of-core ", - userinfo? userinfo : "out-of-core", + userinfo? userinfo : no_userinfo? "" : "out-of-core", need_lf? "\n":""); fflush (errfp); } gpgrt_free (userinfo); gpgrt_free (stdinfo); gpgrt_free (prefix); gpg_err_set_errno (saved_errno); return 0; } /* Add the formatted string FORMAT to the debug line *LINE. */ void _gpgme_debug_add (void **line, const char *format, ...) { va_list arg_ptr; char *toadd; char *result; int res; if (!*line) return; va_start (arg_ptr, format); res = gpgrt_vasprintf (&toadd, format, arg_ptr); va_end (arg_ptr); if (res < 0) { gpgrt_free (*line); *line = NULL; } res = gpgrt_asprintf (&result, "%s%s", *(char **) line, toadd); gpgrt_free (toadd); gpgrt_free (*line); if (res < 0) *line = NULL; else *line = result; } /* Finish construction of *LINE and send it to the debug output stream. */ void _gpgme_debug_end (void **line) { + const char *string; + if (!*line) return; + string = *line; - /* The smallest possible level is 1, so force logging here by - using that. */ - _gpgme_debug (NULL, 1, -1, NULL, NULL, NULL, "%s", (char*)*line); + fprintf (errfp, "%s%s", + string, + (*string && string[strlen (string)-1] != '\n')? "\n":""); + fflush (errfp); gpgrt_free (*line); *line = NULL; } #define TOHEX(val) (((val) < 10) ? ((val) + '0') : ((val) - 10 + 'a')) void _gpgme_debug_buffer (int lvl, const char *const fmt, const char *const func, const char *const buffer, size_t len) { int idx = 0; int j; if (!_gpgme_debug_trace ()) return; if (!buffer) return; while (idx < len) { char str[51]; char *strp = str; char *strp2 = &str[34]; for (j = 0; j < 16; j++) { unsigned char val; if (idx < len) { val = buffer[idx++]; *(strp++) = TOHEX (val >> 4); *(strp++) = TOHEX (val % 16); *(strp2++) = isprint (val) ? val : '.'; } else { *(strp++) = ' '; *(strp++) = ' '; } if (j == 7) *(strp++) = ' '; } *(strp++) = ' '; *(strp2) = '\0'; _gpgme_debug (NULL, lvl, -1, NULL, NULL, NULL, fmt, func, str); } } diff --git a/src/debug.h b/src/debug.h index 08d063c6..fa0bfc6c 100644 --- a/src/debug.h +++ b/src/debug.h @@ -1,223 +1,224 @@ /* debug.h - interface to debugging functions Copyright (C) 2002, 2004, 2005, 2007 g10 Code GmbH This file is part of GPGME. GPGME is free software; you can redistribute it and/or modify it under the terms of the GNU Lesser General Public License as published by the Free Software Foundation; either version 2.1 of the License, or (at your option) any later version. GPGME is distributed in the hope that it will be useful, but WITHOUT ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU Lesser General Public License for more details. You should have received a copy of the GNU Lesser General Public License along with this program; if not, write to the Free Software Foundation, Inc., 59 Temple Place - Suite 330, Boston, MA 02111-1307, USA. */ #ifndef DEBUG_H #define DEBUG_H #include #ifdef HAVE_STDINT_H #include #endif +#include #include "gpgme.h" /* Required for gpgme_error stuff. */ /* Indirect stringification, requires __STDC__ to work. */ #define STRINGIFY(v) #v #define XSTRINGIFY(v) STRINGIFY(v) /* * The debug levels. * * Note that TRACE_LOGBUFX uses the current debug level + 1. */ #define DEBUG_INIT 1 #define DEBUG_GLOBAL 2 #define DEBUG_CTX 3 #define DEBUG_ENGINE 4 #define DEBUG_DATA 5 #define DEBUG_ASSUAN 6 #define DEBUG_SYSIO 7 /* Remove path components from filenames (i.e. __FILE__) for cleaner logs. */ static inline const char *_gpgme_debug_srcname (const char *file) GPGME_GCC_A_PURE; static inline const char * _gpgme_debug_srcname (const char *file) { const char *s = strrchr (file, '/'); return s? s+1:file; } /* Initialization helper function; see debug.c. */ int _gpgme_debug_set_debug_envvar (const char *value); /* Called early to initialize the logging. */ void _gpgme_debug_subsystem_init (void); /* Log the formatted string FORMAT at debug level LEVEL or higher. */ int _gpgme_debug (void **line, int level, int mode, const char *func, const char *tagname, const char *tagvalue, const char *format, ...) GPGRT_ATTR_PRINTF(7,8); /* Add the formatted string FORMAT to the debug line *LINE. */ void _gpgme_debug_add (void **helper, const char *format, ...); /* Finish construction of *LINE and send it to the debug output stream. */ void _gpgme_debug_end (void **helper); void _gpgme_debug_buffer (int lvl, const char *const fmt, const char *const func, const char *const buffer, size_t len); void _gpgme_debug_frame_begin (void); int _gpgme_debug_frame_end (void); static inline gpgme_error_t _gpgme_trace_gpgme_error (gpgme_error_t err, const char *file, int line) { _gpgme_debug (NULL, DEBUG_ENGINE, -1, NULL, NULL, NULL, "%s:%d: returning error: %s\n", _gpgme_debug_srcname (file), line, gpgme_strerror (err)); return err; } /* Trace support. */ /* FIXME: For now. */ #define _gpgme_debug_trace() 1 #define _TRACE(lvl, name, tag) \ int _gpgme_trace_level = lvl; \ const char *const _gpgme_trace_func = name; \ const char *const _gpgme_trace_tagname = STRINGIFY (tag); \ void *_gpgme_trace_tag = (void *) (uintptr_t) tag; \ _gpgme_debug_frame_begin () /* Note: We can't protect this with a do-while block. */ #define TRACE_BEG(lvl, name, tag, ...) \ _TRACE (lvl, name, tag); \ _gpgme_debug (NULL, _gpgme_trace_level, 1, \ _gpgme_trace_func, _gpgme_trace_tagname, _gpgme_trace_tag, \ __VA_ARGS__) #define TRACE(lvl, name, tag, ...) do { \ _gpgme_debug_frame_begin (); \ _gpgme_debug (NULL, lvl, 0, name, STRINGIFY (tag), (void *)(uintptr_t)tag, \ __VA_ARGS__); \ _gpgme_debug_frame_end (); \ } while (0) /* Trace a gpg-error and return it. */ #define TRACE_ERR(err) \ _trace_err ((err), _gpgme_trace_level, _gpgme_trace_func, __LINE__) static inline gpg_error_t _trace_err (gpg_error_t err, int lvl, const char *func, int line) { if (!err) _gpgme_debug (NULL, lvl, 3, func, NULL, NULL, ""); else _gpgme_debug (NULL, lvl, -1, NULL, NULL, NULL, "%s:%d: error: %s <%s>\n", func, line, gpgme_strerror (err), gpgme_strsource (err)); _gpgme_debug_frame_end (); return err; } /* Trace a system call result and return it. */ #define TRACE_SYSRES(res) \ _trace_sysres ((res), _gpgme_trace_level, _gpgme_trace_func, __LINE__) static inline int _trace_sysres (int res, int lvl, const char *func, int line) { if (res >= 0) _gpgme_debug (NULL, lvl, 3, func, NULL, NULL, "result=%d", res); else _gpgme_debug (NULL, lvl, -1, NULL, NULL, NULL, "%s:%d: error: %s (%d)\n", - func, line, strerror (res), res); + func, line, strerror (errno), errno); _gpgme_debug_frame_end (); return res; } /* Trace a system call error and return it. */ #define TRACE_SYSERR(rc) \ _trace_syserr ((rc), _gpgme_trace_level, _gpgme_trace_func, __LINE__) static inline int _trace_syserr (int rc, int lvl, const char *func, int line) { if (!rc) _gpgme_debug (NULL, lvl, 3, func, NULL, NULL, "result=0"); else _gpgme_debug (NULL, lvl, -1, NULL, NULL, NULL, "%s:%d: error: %s (%d)\n", func, line, strerror (rc), rc); _gpgme_debug_frame_end (); return rc; } #define TRACE_SUC(...) do { \ _gpgme_debug (NULL, _gpgme_trace_level, 3, _gpgme_trace_func, NULL, NULL, \ __VA_ARGS__); \ _gpgme_debug_frame_end (); \ } while (0) #define TRACE_LOG(...) do { \ _gpgme_debug (NULL, _gpgme_trace_level, 2, \ _gpgme_trace_func, _gpgme_trace_tagname, _gpgme_trace_tag, \ __VA_ARGS__); \ } while (0) #define TRACE_LOGBUF(buf, len) do { \ _gpgme_debug_buffer (_gpgme_trace_level, "%s: check: %s", \ _gpgme_trace_func, buf, len); \ } while (0) #define TRACE_LOGBUFX(buf, len) do { \ _gpgme_debug_buffer (_gpgme_trace_level+1, "%s: check: %s", \ _gpgme_trace_func, buf, len); \ } while (0) #define TRACE_SEQ(hlp,...) do { \ _gpgme_debug (&(hlp), _gpgme_trace_level, 2, _gpgme_trace_func, \ _gpgme_trace_tagname, _gpgme_trace_tag, __VA_ARGS__); \ } while (0) #define TRACE_ADD0(hlp,fmt) \ _gpgme_debug_add (&(hlp), fmt) #define TRACE_ADD1(hlp,fmt,a) \ _gpgme_debug_add (&(hlp), fmt, (a)) #define TRACE_ADD2(hlp,fmt,a,b) \ _gpgme_debug_add (&(hlp), fmt, (a), (b)) #define TRACE_ADD3(hlp,fmt,a,b,c) \ _gpgme_debug_add (&(hlp), fmt, (a), (b), (c)) #define TRACE_END(hlp,fmt) \ _gpgme_debug_add (&(hlp), fmt); \ _gpgme_debug_end (&(hlp)) #define TRACE_ENABLED(hlp) (!!(hlp)) /* And finally a simple macro to trace the location of an error code. This macro is independent of the other trace macros and may be used without any preconditions. */ #define trace_gpg_error(e) \ _gpgme_trace_gpgme_error (gpg_error (e), __FILE__, __LINE__) #endif /* DEBUG_H */