Line data Source code
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, write to the Free Software
19 : Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston,
20 : MA 02110-1301, USA. */
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 :
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 :
71 : #ifdef HAVE_TLS
72 : #define FRAME_NR
73 : static __thread int frame_nr = 0;
74 : #endif
75 :
76 : void
77 46172 : _gpgme_debug_frame_begin (void)
78 : {
79 : #ifdef FRAME_NR
80 46172 : frame_nr++;
81 : #endif
82 46172 : }
83 :
84 60751 : int _gpgme_debug_frame_end (void)
85 : {
86 : #ifdef FRAME_NR
87 60751 : frame_nr--;
88 : #endif
89 60751 : return 0;
90 : }
91 :
92 :
93 :
94 : /* Remove leading and trailing white spaces. */
95 : static char *
96 0 : trim_spaces (char *str)
97 : {
98 : char *string, *p, *mark;
99 :
100 0 : string = str;
101 : /* Find first non space character. */
102 0 : for (p = string; *p && isspace (*(unsigned char *) p); p++)
103 : ;
104 : /* Move characters. */
105 0 : for (mark = NULL; (*string = *p); string++, p++)
106 0 : if (isspace (*(unsigned char *) p))
107 : {
108 0 : if (!mark)
109 0 : mark = string;
110 : }
111 : else
112 0 : mark = NULL;
113 0 : if (mark)
114 0 : *mark = '\0'; /* Remove trailing spaces. */
115 :
116 0 : 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 0 : _gpgme_debug_set_debug_envvar (const char *value)
126 : {
127 0 : free (envvar_override);
128 0 : envvar_override = strdup (value);
129 0 : return !envvar_override;
130 : }
131 :
132 :
133 : static void
134 84 : debug_init (void)
135 : {
136 : static int initialized;
137 :
138 84 : LOCK (debug_lock);
139 84 : if (!initialized)
140 : {
141 : gpgme_error_t err;
142 : char *e;
143 : const char *s1, *s2;;
144 :
145 84 : if (envvar_override)
146 : {
147 0 : e = strdup (envvar_override);
148 0 : free (envvar_override);
149 0 : envvar_override = NULL;
150 : }
151 : else
152 : {
153 : #ifdef HAVE_W32CE_SYSTEM
154 : e = _gpgme_w32ce_get_debug_envvar ();
155 : #else /*!HAVE_W32CE_SYSTEM*/
156 84 : err = _gpgme_getenv ("GPGME_DEBUG", &e);
157 84 : if (err)
158 : {
159 0 : UNLOCK (debug_lock);
160 84 : return;
161 : }
162 : #endif /*!HAVE_W32CE_SYSTEM*/
163 : }
164 :
165 84 : initialized = 1;
166 84 : errfp = stderr;
167 84 : if (e)
168 : {
169 0 : debug_level = atoi (e);
170 0 : s1 = strchr (e, PATHSEP_C);
171 0 : if (s1)
172 : {
173 : #ifndef HAVE_DOSISH_SYSTEM
174 0 : if (getuid () == geteuid ()
175 : #if defined(HAVE_GETGID) && defined(HAVE_GETEGID)
176 0 : && getgid () == getegid ()
177 : #endif
178 : )
179 : {
180 : #endif
181 : char *p;
182 : FILE *fp;
183 :
184 0 : s1++;
185 0 : if (!(s2 = strchr (s1, PATHSEP_C)))
186 0 : s2 = s1 + strlen (s1);
187 0 : p = malloc (s2 - s1 + 1);
188 0 : if (p)
189 : {
190 0 : memcpy (p, s1, s2 - s1);
191 0 : p[s2-s1] = 0;
192 0 : trim_spaces (p);
193 0 : fp = fopen (p,"a");
194 0 : if (fp)
195 : {
196 0 : setvbuf (fp, NULL, _IOLBF, 0);
197 0 : errfp = fp;
198 : }
199 0 : free (p);
200 : }
201 : #ifndef HAVE_DOSISH_SYSTEM
202 : }
203 : #endif
204 : }
205 0 : free (e);
206 : }
207 : }
208 84 : UNLOCK (debug_lock);
209 :
210 84 : if (debug_level > 0)
211 : {
212 0 : _gpgme_debug (DEBUG_INIT, "gpgme_debug: level=%d\n", debug_level);
213 : #ifdef HAVE_W32_SYSTEM
214 : {
215 : const char *name = _gpgme_get_inst_dir ();
216 : _gpgme_debug (DEBUG_INIT, "gpgme_debug: gpgme='%s'\n",
217 : name? name: "?");
218 : }
219 : #endif
220 : }
221 : }
222 :
223 :
224 :
225 : /* This should be called as soon as the locks are intialized. It is
226 : required so that the assuan logging gets conncted to the gpgme log
227 : stream as early as possible. */
228 : void
229 84 : _gpgme_debug_subsystem_init (void)
230 : {
231 84 : debug_init ();
232 84 : }
233 :
234 :
235 :
236 :
237 : /* Log the formatted string FORMAT at debug level LEVEL or higher.
238 : *
239 : * Returns: 0
240 : *
241 : * Note that we always return 0 because the old TRACE macro evaluated
242 : * to 0 which issues a warning with newer gcc version about an unused
243 : * values. By using a return value of this function this can be
244 : * avoided. Fixme: It might be useful to check whether the return
245 : * value from the TRACE macros are actually used somewhere.
246 : */
247 : int
248 251381 : _gpgme_debug (int level, const char *format, ...)
249 : {
250 : va_list arg_ptr;
251 : int saved_errno;
252 :
253 251381 : saved_errno = errno;
254 242786 : if (debug_level < level)
255 242786 : return 0;
256 :
257 0 : va_start (arg_ptr, format);
258 0 : LOCK (debug_lock);
259 : {
260 : #ifdef HAVE_W32CE_SYSTEM
261 : SYSTEMTIME t;
262 :
263 : GetLocalTime (&t);
264 : fprintf (errfp, "GPGME %04d-%02d-%02d %02d:%02d:%02d <0x%04llx> ",
265 : t.wYear, t.wMonth, t.wDay,
266 : t.wHour, t.wMinute, t.wSecond,
267 : (unsigned long long) ath_self ());
268 : #else
269 : struct tm *tp;
270 0 : time_t atime = time (NULL);
271 :
272 0 : tp = localtime (&atime);
273 0 : fprintf (errfp, "GPGME %04d-%02d-%02d %02d:%02d:%02d <0x%04llx> ",
274 0 : 1900+tp->tm_year, tp->tm_mon+1, tp->tm_mday,
275 : tp->tm_hour, tp->tm_min, tp->tm_sec,
276 0 : (unsigned long long) ath_self ());
277 : #endif
278 : }
279 : #ifdef FRAME_NR
280 : {
281 : int indent;
282 :
283 0 : indent = frame_nr > 0? (2 * (frame_nr - 1)):0;
284 0 : fprintf (errfp, "%*s", indent < 40? indent : 40, "");
285 : }
286 : #endif
287 :
288 0 : vfprintf (errfp, format, arg_ptr);
289 0 : va_end (arg_ptr);
290 0 : if(format && *format && format[strlen (format) - 1] != '\n')
291 0 : putc ('\n', errfp);
292 0 : UNLOCK (debug_lock);
293 0 : fflush (errfp);
294 :
295 0 : gpg_err_set_errno (saved_errno);
296 0 : return 0;
297 : }
298 :
299 :
300 : /* Start a new debug line in *LINE, logged at level LEVEL or higher,
301 : and starting with the formatted string FORMAT. */
302 : void
303 22956 : _gpgme_debug_begin (void **line, int level, const char *format, ...)
304 : {
305 : va_list arg_ptr;
306 : int res;
307 :
308 22956 : if (debug_level < level)
309 : {
310 : /* Disable logging of this line. */
311 22956 : *line = NULL;
312 45912 : return;
313 : }
314 :
315 0 : va_start (arg_ptr, format);
316 0 : res = vasprintf ((char **) line, format, arg_ptr);
317 0 : va_end (arg_ptr);
318 0 : if (res < 0)
319 0 : *line = NULL;
320 : }
321 :
322 :
323 : /* Add the formatted string FORMAT to the debug line *LINE. */
324 : void
325 27742 : _gpgme_debug_add (void **line, const char *format, ...)
326 : {
327 : va_list arg_ptr;
328 : char *toadd;
329 : char *result;
330 : int res;
331 :
332 27742 : if (!*line)
333 55484 : return;
334 :
335 0 : va_start (arg_ptr, format);
336 0 : res = vasprintf (&toadd, format, arg_ptr);
337 0 : va_end (arg_ptr);
338 0 : if (res < 0)
339 : {
340 0 : free (*line);
341 0 : *line = NULL;
342 : }
343 0 : res = asprintf (&result, "%s%s", *(char **) line, toadd);
344 0 : free (toadd);
345 0 : free (*line);
346 0 : if (res < 0)
347 0 : *line = NULL;
348 : else
349 0 : *line = result;
350 : }
351 :
352 :
353 : /* Finish construction of *LINE and send it to the debug output
354 : stream. */
355 : void
356 11503 : _gpgme_debug_end (void **line)
357 : {
358 11503 : if (!*line)
359 23006 : return;
360 :
361 : /* The smallest possible level is 1, so force logging here by
362 : using that. */
363 0 : _gpgme_debug (1, "%s", *line);
364 0 : free (*line);
365 0 : *line = NULL;
366 : }
367 :
368 :
369 : #define TOHEX(val) (((val) < 10) ? ((val) + '0') : ((val) - 10 + 'a'))
370 :
371 : void
372 6711 : _gpgme_debug_buffer (int lvl, const char *const fmt,
373 : const char *const func, const char *const buffer,
374 : size_t len)
375 : {
376 6711 : int idx = 0;
377 : int j;
378 :
379 : if (!_gpgme_debug_trace ())
380 6721 : return;
381 :
382 203130 : while (idx < len)
383 : {
384 : char str[51];
385 189698 : char *strp = str;
386 189698 : char *strp2 = &str[34];
387 :
388 1987171 : for (j = 0; j < 16; j++)
389 : {
390 : unsigned char val;
391 1838855 : if (idx < len)
392 : {
393 1799600 : val = buffer[idx++];
394 1799600 : *(strp++) = TOHEX (val >> 4);
395 1799600 : *(strp++) = TOHEX (val % 16);
396 1799600 : *(strp2++) = isprint (val) ? val : '.';
397 : }
398 : else
399 : {
400 39255 : *(strp++) = ' ';
401 39255 : *(strp++) = ' ';
402 : }
403 1797473 : if (j == 7)
404 137940 : *(strp++) = ' ';
405 : }
406 148316 : *(strp++) = ' ';
407 148316 : *(strp2) = '\0';
408 :
409 148316 : _gpgme_debug (lvl, fmt, func, str);
410 : }
411 : }
|