a2f0e69465da6af7aa1bb779e38fa86197f654fc
[gpgme.git] / src / debug.c
1 /* debug.c - helpful output in desperate situations
2  * Copyright (C) 2000 Werner Koch (dd9jn)
3  * Copyright (C) 2001, 2002, 2003, 2004, 2005, 2007, 2009 g10 Code GmbH
4  *
5  * This file is part of GPGME.
6  *
7  * GPGME is free software; you can redistribute it and/or modify it
8  * under the terms of the GNU Lesser General Public License as
9  * published by the Free Software Foundation; either version 2.1 of
10  * the License, or (at your option) any later version.
11  *
12  * GPGME is distributed in the hope that it will be useful, but
13  * WITHOUT ANY WARRANTY; without even the implied warranty of
14  * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU
15  * Lesser General Public License for more details.
16  *
17  * You should have received a copy of the GNU Lesser General Public
18  * License along with this program; if not, see <https://gnu.org/licenses/>.
19  * SPDX-License-Identifier: LGPL-2.1-or-later
20  */
21
22 #if HAVE_CONFIG_H
23 #include <config.h>
24 #endif
25 #include <stdio.h>
26 #include <stdlib.h>
27 #include <string.h>
28 #include <stdarg.h>
29 #ifdef HAVE_UNISTD_H
30 # include <unistd.h>
31 #endif
32 #include <ctype.h>
33 #include <errno.h>
34 #include <time.h>
35 #ifndef HAVE_DOSISH_SYSTEM
36 # ifdef HAVE_SYS_TYPES_H
37 #  include <sys/types.h>
38 # endif
39 # ifdef HAVE_SYS_STAT_H
40 #  include <sys/stat.h>
41 # endif
42 # include <fcntl.h>
43 #endif
44 #include <assert.h>
45
46 #include "util.h"
47 #include "ath.h"
48 #include "sema.h"
49 #include "sys-util.h"
50 #include "debug.h"
51
52 \f
53 /* Lock to serialize initialization of the debug output subsystem and
54    output of actual debug messages.  */
55 DEFINE_STATIC_LOCK (debug_lock);
56
57 /* The amount of detail requested by the user, per environment
58    variable GPGME_DEBUG.  */
59 static int debug_level;
60
61 /* The output stream for the debug messages.  */
62 static FILE *errfp;
63
64 /* If not NULL, this malloced string is used instead of the
65    GPGME_DEBUG envvar.  It must have been set before the debug
66    subsystem has been initialized.  Using it later may or may not have
67    any effect.  */
68 static char *envvar_override;
69
70 \f
71 #ifdef HAVE_TLS
72 #define FRAME_NR
73 static __thread int frame_nr = 0;
74 #endif
75
76 void
77 _gpgme_debug_frame_begin (void)
78 {
79 #ifdef FRAME_NR
80   frame_nr++;
81 #endif
82 }
83
84 int _gpgme_debug_frame_end (void)
85 {
86 #ifdef FRAME_NR
87   frame_nr--;
88 #endif
89   return 0;
90 }
91
92
93 \f
94 /* Remove leading and trailing white spaces.  */
95 static char *
96 trim_spaces (char *str)
97 {
98   char *string, *p, *mark;
99
100   string = str;
101   /* Find first non space character.  */
102   for (p = string; *p && isspace (*(unsigned char *) p); p++)
103     ;
104   /* Move characters.  */
105   for (mark = NULL; (*string = *p); string++, p++)
106     if (isspace (*(unsigned char *) p))
107       {
108         if (!mark)
109           mark = string;
110       }
111     else
112       mark = NULL;
113   if (mark)
114     *mark = '\0';       /* Remove trailing spaces.  */
115
116   return str;
117 }
118
119
120 /* This is an internal function to set debug info.  The caller must
121    assure that this function is called only by one thread at a time.
122    The function may have no effect if called after the debug system
123    has been initialized.  Returns 0 on success.  */
124 int
125 _gpgme_debug_set_debug_envvar (const char *value)
126 {
127   free (envvar_override);
128   envvar_override = strdup (value);
129   return !envvar_override;
130 }
131
132
133 static void
134 debug_init (void)
135 {
136   static int initialized;
137
138   LOCK (debug_lock);
139   if (!initialized)
140     {
141       gpgme_error_t err;
142       char *e;
143       const char *s1, *s2;;
144
145       if (envvar_override)
146         {
147           e = strdup (envvar_override);
148           free (envvar_override);
149           envvar_override = NULL;
150         }
151       else
152         {
153           err = _gpgme_getenv ("GPGME_DEBUG", &e);
154           if (err)
155             {
156               UNLOCK (debug_lock);
157               return;
158             }
159         }
160
161       initialized = 1;
162       errfp = stderr;
163       if (e)
164         {
165           debug_level = atoi (e);
166           s1 = strchr (e, PATHSEP_C);
167           if (s1)
168             {
169 #ifndef HAVE_DOSISH_SYSTEM
170               if (getuid () == geteuid ()
171 #if defined(HAVE_GETGID) && defined(HAVE_GETEGID)
172                   && getgid () == getegid ()
173 #endif
174                   )
175                 {
176 #endif
177                   char *p;
178                   FILE *fp;
179
180                   s1++;
181                   if (!(s2 = strchr (s1, PATHSEP_C)))
182                     s2 = s1 + strlen (s1);
183                   p = malloc (s2 - s1 + 1);
184                   if (p)
185                     {
186                       memcpy (p, s1, s2 - s1);
187                       p[s2-s1] = 0;
188                       trim_spaces (p);
189                       fp = fopen (p,"a");
190                       if (fp)
191                         {
192                           setvbuf (fp, NULL, _IOLBF, 0);
193                           errfp = fp;
194                         }
195                       free (p);
196                     }
197 #ifndef HAVE_DOSISH_SYSTEM
198                 }
199 #endif
200             }
201           free (e);
202         }
203     }
204   UNLOCK (debug_lock);
205
206   if (debug_level > 0)
207     {
208       _gpgme_debug (DEBUG_INIT, "gpgme_debug: level=%d\n", debug_level);
209 #ifdef HAVE_W32_SYSTEM
210       {
211         const char *name = _gpgme_get_inst_dir ();
212         _gpgme_debug (DEBUG_INIT, "gpgme_debug: gpgme='%s'\n",
213                       name? name: "?");
214       }
215 #endif
216     }
217 }
218
219
220
221 /* This should be called as soon as the locks are initialized.  It is
222    required so that the assuan logging gets conncted to the gpgme log
223    stream as early as possible.  */
224 void
225 _gpgme_debug_subsystem_init (void)
226 {
227   debug_init ();
228 }
229
230
231
232 \f
233 /* Log the formatted string FORMAT at debug level LEVEL or higher.
234  *
235  * Returns: 0
236  *
237  * Note that we always return 0 because the old TRACE macro evaluated
238  * to 0 which issues a warning with newer gcc version about an unused
239  * values.  By using a return value of this function this can be
240  * avoided.  Fixme: It might be useful to check whether the return
241  * value from the TRACE macros are actually used somewhere.
242  */
243 int
244 _gpgme_debug (int level, const char *format, ...)
245 {
246   va_list arg_ptr;
247   int saved_errno;
248
249   saved_errno = errno;
250   if (debug_level < level)
251     return 0;
252
253   va_start (arg_ptr, format);
254   LOCK (debug_lock);
255   {
256     struct tm *tp;
257     time_t atime = time (NULL);
258
259     tp = localtime (&atime);
260     fprintf (errfp, "GPGME %04d-%02d-%02d %02d:%02d:%02d <0x%04llx>  ",
261              1900+tp->tm_year, tp->tm_mon+1, tp->tm_mday,
262              tp->tm_hour, tp->tm_min, tp->tm_sec,
263              (unsigned long long) ath_self ());
264   }
265 #ifdef FRAME_NR
266   {
267     int indent;
268
269     indent = frame_nr > 0? (2 * (frame_nr - 1)):0;
270     fprintf (errfp, "%*s", indent < 40? indent : 40, "");
271   }
272 #endif
273
274   vfprintf (errfp, format, arg_ptr);
275   va_end (arg_ptr);
276   if(format && *format && format[strlen (format) - 1] != '\n')
277     putc ('\n', errfp);
278   UNLOCK (debug_lock);
279   fflush (errfp);
280
281   gpg_err_set_errno (saved_errno);
282   return 0;
283 }
284
285 /* Log the formatted string FORMAT prefixed with additional info
286  * depending on MODE:
287  *
288  * -1 = Do not print any additional args.
289  *  0 = standalone (used by macro TRACE)
290  *  1 = enter a function (used by macro TRACE_BEG)
291  *  2 = debug a function (used by macro TRACE_LOG)
292  *  3 = leave a function (used by macro TRACE_SUC)
293  *
294  * Returns: 0
295  *
296  * Note that we always return 0 because the old TRACE macro evaluated
297  * to 0 which issues a warning with newer gcc version about an unused
298  * values.  By using a return value of this function this can be
299  * avoided.  Fixme: It might be useful to check whether the return
300  * value from the TRACE macros are actually used somewhere.
301  */
302 int
303 _gpgme_debugf (int level, int mode, const char *func, const char *tagname,
304                const char *tagvalue, const char *format, ...)
305 {
306   va_list arg_ptr;
307   int saved_errno;
308
309   saved_errno = errno;
310   if (debug_level < level)
311     return 0;
312
313   va_start (arg_ptr, format);
314   LOCK (debug_lock);
315   {
316     struct tm *tp;
317     time_t atime = time (NULL);
318
319     tp = localtime (&atime);
320     fprintf (errfp, "GPGME %04d-%02d-%02d %02d:%02d:%02d <0x%04llx>  ",
321              1900+tp->tm_year, tp->tm_mon+1, tp->tm_mday,
322              tp->tm_hour, tp->tm_min, tp->tm_sec,
323              (unsigned long long) ath_self ());
324   }
325 #ifdef FRAME_NR
326   {
327     int indent;
328
329     indent = frame_nr > 0? (2 * (frame_nr - 1)):0;
330     fprintf (errfp, "%*s", indent < 40? indent : 40, "");
331   }
332 #endif
333
334   switch (mode)
335     {
336     case -1:  /* Do nothing.  */
337       break;
338     case 0:
339       fprintf (errfp, "%s: call: %s=%p ", func, tagname, tagvalue);
340       break;
341     case 1:
342       fprintf (errfp, "%s: enter: %s=%p ", func, tagname, tagvalue);
343       break;
344     case 2:
345       fprintf (errfp, "%s: check: %s=%p ", func, tagname, tagvalue);
346       break;
347     case 3:
348       if (tagname)
349         fprintf (errfp, "%s: leave: %s=%p ", func, tagname, tagvalue);
350       else
351         fprintf (errfp, "%s: leave: ", func);
352       break;
353     default:
354       fprintf (errfp, "%s: m=%d: %s=%p ", func, mode, tagname, tagvalue);
355       break;
356     }
357
358   vfprintf (errfp, format, arg_ptr);
359   va_end (arg_ptr);
360   if(format && *format && format[strlen (format) - 1] != '\n')
361     putc ('\n', errfp);
362   UNLOCK (debug_lock);
363   fflush (errfp);
364
365   gpg_err_set_errno (saved_errno);
366   return 0;
367 }
368
369
370
371 /* Start a new debug line in *LINE, logged at level LEVEL or higher,
372    and starting with the formatted string FORMAT.  */
373 void
374 _gpgme_debug_begin (void **line, int level, const char *format, ...)
375 {
376   va_list arg_ptr;
377   int res;
378
379   if (debug_level < level)
380     {
381       /* Disable logging of this line.  */
382       *line = NULL;
383       return;
384     }
385
386   va_start (arg_ptr, format);
387   res = gpgrt_vasprintf ((char **) line, format, arg_ptr);
388   va_end (arg_ptr);
389   if (res < 0)
390     *line = NULL;
391 }
392
393
394 /* Add the formatted string FORMAT to the debug line *LINE.  */
395 void
396 _gpgme_debug_add (void **line, const char *format, ...)
397 {
398   va_list arg_ptr;
399   char *toadd;
400   char *result;
401   int res;
402
403   if (!*line)
404     return;
405
406   va_start (arg_ptr, format);
407   res = gpgrt_vasprintf (&toadd, format, arg_ptr);
408   va_end (arg_ptr);
409   if (res < 0)
410     {
411       gpgrt_free (*line);
412       *line = NULL;
413     }
414   res = gpgrt_asprintf (&result, "%s%s", *(char **) line, toadd);
415   gpgrt_free (toadd);
416   gpgrt_free (*line);
417   if (res < 0)
418     *line = NULL;
419   else
420     *line = result;
421 }
422
423
424 /* Finish construction of *LINE and send it to the debug output
425    stream.  */
426 void
427 _gpgme_debug_end (void **line)
428 {
429   if (!*line)
430     return;
431
432   /* The smallest possible level is 1, so force logging here by
433      using that.  */
434   _gpgme_debug (1, "%s", *line);
435   gpgrt_free (*line);
436   *line = NULL;
437 }
438
439
440 #define TOHEX(val) (((val) < 10) ? ((val) + '0') : ((val) - 10 + 'a'))
441
442 void
443 _gpgme_debug_buffer (int lvl, const char *const fmt,
444                      const char *const func, const char *const buffer,
445                      size_t len)
446 {
447   int idx = 0;
448   int j;
449
450   if (!_gpgme_debug_trace ())
451     return;
452
453   if (!buffer)
454     return;
455
456   while (idx < len)
457     {
458       char str[51];
459       char *strp = str;
460       char *strp2 = &str[34];
461
462       for (j = 0; j < 16; j++)
463         {
464           unsigned char val;
465           if (idx < len)
466             {
467               val = buffer[idx++];
468               *(strp++) = TOHEX (val >> 4);
469               *(strp++) = TOHEX (val % 16);
470               *(strp2++) = isprint (val) ? val : '.';
471             }
472           else
473             {
474               *(strp++) = ' ';
475               *(strp++) = ' ';
476             }
477           if (j == 7)
478             *(strp++) = ' ';
479         }
480       *(strp++) = ' ';
481       *(strp2) = '\0';
482
483       _gpgme_debug (lvl, fmt, func, str);
484     }
485 }