core: Fix duplication of close_notify_handler for gpgsm.
[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, -1, NULL, NULL, NULL,
209                     "gpgme_debug: level=%d\n", debug_level);
210 #ifdef HAVE_W32_SYSTEM
211       {
212         const char *name = _gpgme_get_inst_dir ();
213         _gpgme_debug (DEBUG_INIT, -1, NULL, NULL, NULL,
214                       "gpgme_debug: gpgme='%s'\n", name? name: "?");
215       }
216 #endif
217     }
218 }
219
220
221
222 /* This should be called as soon as the locks are initialized.  It is
223    required so that the assuan logging gets conncted to the gpgme log
224    stream as early as possible.  */
225 void
226 _gpgme_debug_subsystem_init (void)
227 {
228   debug_init ();
229 }
230
231
232
233 \f
234 /* Log the formatted string FORMAT prefixed with additional info
235  * depending on MODE:
236  *
237  * -1 = Do not print any additional args.
238  *  0 = standalone (used by macro TRACE)
239  *  1 = enter a function (used by macro TRACE_BEG)
240  *  2 = debug a function (used by macro TRACE_LOG)
241  *  3 = leave a function (used by macro TRACE_SUC)
242  *
243  * Returns: 0
244  *
245  * Note that we always return 0 because the old TRACE macro evaluated
246  * to 0 which issues a warning with newer gcc version about an unused
247  * values.  By using a return value of this function this can be
248  * avoided.  Fixme: It might be useful to check whether the return
249  * value from the TRACE macros are actually used somewhere.
250  */
251 int
252 _gpgme_debug (int level, int mode, const char *func, const char *tagname,
253               const char *tagvalue, const char *format, ...)
254 {
255   va_list arg_ptr;
256   int saved_errno;
257   int need_lf;
258   char *output;
259   int out_len;
260
261   if (debug_level < level)
262     return 0;
263
264   saved_errno = errno;
265   va_start (arg_ptr, format);
266   LOCK (debug_lock);
267   {
268     struct tm *tp;
269     time_t atime = time (NULL);
270
271     tp = localtime (&atime);
272     fprintf (errfp, "GPGME %04d-%02d-%02d %02d:%02d:%02d <0x%04llx>  ",
273              1900+tp->tm_year, tp->tm_mon+1, tp->tm_mday,
274              tp->tm_hour, tp->tm_min, tp->tm_sec,
275              (unsigned long long) ath_self ());
276   }
277 #ifdef FRAME_NR
278   {
279     int indent;
280
281     indent = frame_nr > 0? (2 * (frame_nr - 1)):0;
282     fprintf (errfp, "%*s", indent < 40? indent : 40, "");
283   }
284 #endif
285
286   need_lf = 0;
287   switch (mode)
288     {
289     case -1:  /* Do nothing.  */
290       break;
291     case 0:
292       fprintf (errfp, "%s: call: %s=%p ", func, tagname, tagvalue);
293       break;
294     case 1:
295       fprintf (errfp, "%s: enter: %s=%p ", func, tagname, tagvalue);
296       break;
297     case 2:
298       fprintf (errfp, "%s: check: %s=%p ", func, tagname, tagvalue);
299       break;
300     case 3:
301       if (tagname)
302         fprintf (errfp, "%s: leave: %s=%p ", func, tagname, tagvalue);
303       else
304         fprintf (errfp, "%s: leave: ", func);
305       break;
306     default:
307       fprintf (errfp, "%s: ?(mode=%d): %s=%p ", func, mode, tagname, tagvalue);
308       break;
309     }
310   need_lf = (mode != -1 && (!format || !*format));
311
312   out_len = gpgrt_vasprintf (&output, format, arg_ptr);
313   if (out_len >= 0)
314     {
315       fwrite (output, out_len, 1, errfp);
316       free (output);
317     }
318   va_end (arg_ptr);
319   if (need_lf || (format && *format && format[strlen (format) - 1] != '\n'))
320     putc ('\n', errfp);
321   UNLOCK (debug_lock);
322   fflush (errfp);
323
324   gpg_err_set_errno (saved_errno);
325   return 0;
326 }
327
328
329 /* Start a new debug line in *LINE, logged at level LEVEL or higher,
330    and starting with the formatted string FORMAT.  */
331 void
332 _gpgme_debug_begin (void **line, int level, const char *format, ...)
333 {
334   va_list arg_ptr;
335   int res;
336
337   if (debug_level < level)
338     {
339       /* Disable logging of this line.  */
340       *line = NULL;
341       return;
342     }
343
344   va_start (arg_ptr, format);
345   res = gpgrt_vasprintf ((char **) line, format, arg_ptr);
346   va_end (arg_ptr);
347   if (res < 0)
348     *line = NULL;
349 }
350
351
352 /* Add the formatted string FORMAT to the debug line *LINE.  */
353 void
354 _gpgme_debug_add (void **line, const char *format, ...)
355 {
356   va_list arg_ptr;
357   char *toadd;
358   char *result;
359   int res;
360
361   if (!*line)
362     return;
363
364   va_start (arg_ptr, format);
365   res = gpgrt_vasprintf (&toadd, format, arg_ptr);
366   va_end (arg_ptr);
367   if (res < 0)
368     {
369       gpgrt_free (*line);
370       *line = NULL;
371     }
372   res = gpgrt_asprintf (&result, "%s%s", *(char **) line, toadd);
373   gpgrt_free (toadd);
374   gpgrt_free (*line);
375   if (res < 0)
376     *line = NULL;
377   else
378     *line = result;
379 }
380
381
382 /* Finish construction of *LINE and send it to the debug output
383    stream.  */
384 void
385 _gpgme_debug_end (void **line)
386 {
387   if (!*line)
388     return;
389
390   /* The smallest possible level is 1, so force logging here by
391      using that.  */
392   _gpgme_debug (1, -1, NULL, NULL, NULL, "%s", (char*)*line);
393   gpgrt_free (*line);
394   *line = NULL;
395 }
396
397
398 #define TOHEX(val) (((val) < 10) ? ((val) + '0') : ((val) - 10 + 'a'))
399
400 void
401 _gpgme_debug_buffer (int lvl, const char *const fmt,
402                      const char *const func, const char *const buffer,
403                      size_t len)
404 {
405   int idx = 0;
406   int j;
407
408   if (!_gpgme_debug_trace ())
409     return;
410
411   if (!buffer)
412     return;
413
414   while (idx < len)
415     {
416       char str[51];
417       char *strp = str;
418       char *strp2 = &str[34];
419
420       for (j = 0; j < 16; j++)
421         {
422           unsigned char val;
423           if (idx < len)
424             {
425               val = buffer[idx++];
426               *(strp++) = TOHEX (val >> 4);
427               *(strp++) = TOHEX (val % 16);
428               *(strp2++) = isprint (val) ? val : '.';
429             }
430           else
431             {
432               *(strp++) = ' ';
433               *(strp++) = ' ';
434             }
435           if (j == 7)
436             *(strp++) = ' ';
437         }
438       *(strp++) = ' ';
439       *(strp2) = '\0';
440
441       _gpgme_debug (lvl, -1, NULL, NULL, NULL, fmt, func, str);
442     }
443 }