Imported Upstream version 2.6.0p2
[debian/amanda] / common-src / debug.c
1 /*
2  * Amanda, The Advanced Maryland Automatic Network Disk Archiver
3  * Copyright (c) 1991-1998 University of Maryland at College Park
4  * All Rights Reserved.
5  *
6  * Permission to use, copy, modify, distribute, and sell this software and its
7  * documentation for any purpose is hereby granted without fee, provided that
8  * the above copyright notice appear in all copies and that both that
9  * copyright notice and this permission notice appear in supporting
10  * documentation, and that the name of U.M. not be used in advertising or
11  * publicity pertaining to distribution of the software without specific,
12  * written prior permission.  U.M. makes no representations about the
13  * suitability of this software for any purpose.  It is provided "as is"
14  * without express or implied warranty.
15  *
16  * U.M. DISCLAIMS ALL WARRANTIES WITH REGARD TO THIS SOFTWARE, INCLUDING ALL
17  * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS, IN NO EVENT SHALL U.M.
18  * BE LIABLE FOR ANY SPECIAL, INDIRECT OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES
19  * WHATSOEVER RESULTING FROM LOSS OF USE, DATA OR PROFITS, WHETHER IN AN ACTION
20  * OF CONTRACT, NEGLIGENCE OR OTHER TORTIOUS ACTION, ARISING OUT OF OR IN
21  * CONNECTION WITH THE USE OR PERFORMANCE OF THIS SOFTWARE.
22  *
23  * Author: James da Silva, Systems Design and Analysis Group
24  *                         Computer Science Department
25  *                         University of Maryland at College Park
26  */
27 /*
28  * $Id: debug.c,v 1.40 2006/07/26 11:49:32 martinea Exp $
29  *
30  * Logging support
31  */
32
33 #include "amanda.h"
34 #include "util.h"
35 #include "arglist.h"
36 #include "clock.h"
37 #include "timestamp.h"
38 #include "conffile.h"
39
40 #ifdef HAVE_GLIBC_BACKTRACE
41 #include <execinfo.h>
42 #endif
43
44 /* Minimum file descriptor on which to keep the debug file.  This is intended
45  * to keep the descriptor "out of the way" of other processing.  It's not clear
46  * that this is required any longer, but it doesn't hurt anything.
47  */
48 #define MIN_DB_FD                       10
49
50 /* information on the current debug file */
51 static int db_fd = 2;                   /* file descriptor (default stderr) */
52 static FILE *db_file = NULL;            /* stdio stream */
53 static char *db_name  = NULL;           /* unqualified filename */
54 static char *db_filename = NULL;        /* fully qualified pathname */
55
56 /* directory containing debug file, including trailing slash */
57 static char *dbgdir = NULL;
58
59 /* time debug log was opened (timestamp of the file) */
60 static time_t open_time;
61
62 /* pointer to logfile.c's 'logerror()', if we're linked
63  * with it */
64 static void (*logerror_fn)(char *) = NULL;
65
66 /* storage for global variables */
67 erroutput_type_t erroutput_type = ERR_INTERACTIVE;
68 int error_exit_status = 1;
69
70 /* static function prototypes */
71 static char *get_debug_name(time_t t, int n);
72 static void debug_setup_1(char *config, char *subdir);
73 static void debug_setup_2(char *s, int fd, char *annotation);
74 static char *msg_timestamp(void);
75
76 static void debug_logging_handler(const gchar *log_domain,
77         GLogLevelFlags log_level,
78         const gchar *message,
79         gpointer user_data);
80 static void debug_setup_logging(void);
81
82 /*
83  * Generate a debug file name.  The name is based on the program name,
84  * followed by a timestamp, an optional sequence number, and ".debug".
85  *
86  * @param t: timestamp
87  * @param n: sequence number between 1 and 1000; if zero, no sequence number
88  * is included.
89  */
90 static char *
91 get_debug_name(
92     time_t      t,
93     int         n)
94 {
95     char number[NUM_STR_SIZE];
96     char *ts;
97     char *result;
98
99     if(n < 0 || n > 1000) {
100         return NULL;
101     }
102     ts = get_timestamp_from_time(t);
103     if(n == 0) {
104         number[0] = '\0';
105     } else {
106         g_snprintf(number, SIZEOF(number), "%03d", n - 1);
107     }
108     result = vstralloc(get_pname(), ".", ts, number, ".debug", NULL);
109     amfree(ts);
110     return result;
111 }
112
113 /* A GLogFunc to handle g_log calls.  This function assumes that user_data
114  * is either NULL or a pointer to one of the debug_* configuration variables
115  * in conffile.c, indicating whether logging for this log domain is enabled.
116  *
117  * @param log_domain: the log domain, or NULL for general logging
118  * @param log_level: level, fatality, and recursion flags
119  * @param message: the message to log
120  * @param user_pointer: unused
121  */
122 static void
123 debug_logging_handler(const gchar *log_domain G_GNUC_UNUSED,
124             GLogLevelFlags log_level,
125             const gchar *message,
126             gpointer user_data G_GNUC_UNUSED)
127 {
128     char *maxlevel = NULL;
129
130     /* convert the highest level to a string and dbprintf it */
131     if (log_level & G_LOG_LEVEL_ERROR)
132         maxlevel = _("error (fatal): ");
133     else if (log_level & G_LOG_LEVEL_CRITICAL)
134         maxlevel = _("critical (fatal): ");
135     else if (log_level & G_LOG_LEVEL_WARNING)
136         maxlevel = _("warning: ");
137     else if (log_level & G_LOG_LEVEL_MESSAGE)
138         maxlevel = _("message: ");
139     else if (log_level & G_LOG_LEVEL_INFO)
140         maxlevel = _("info: ");
141     else
142         maxlevel = ""; /* no level displayed for debugging */
143
144     debug_printf("%s%s\n", maxlevel, message);
145
146     /* error and critical levels have special handling */
147     if (log_level & (G_LOG_LEVEL_ERROR|G_LOG_LEVEL_CRITICAL)) {
148         if (erroutput_type & ERR_AMANDALOG && logerror_fn != NULL)
149             (*logerror_fn)((char *)message); /* discard 'const' */
150
151         if (erroutput_type & ERR_SYSLOG) {
152 #ifdef LOG_AUTH
153             openlog(get_pname(), LOG_PID, LOG_AUTH);
154 #else
155             openlog(get_pname(), LOG_PID, 0);
156 #endif
157             syslog(LOG_NOTICE, "%s", message);
158             closelog();
159         }
160
161         if (erroutput_type & ERR_INTERACTIVE) {
162             g_fprintf(stderr, "%s: %s\n", get_pname(), message);
163             fflush(stderr);
164         }
165
166 #ifdef HAVE_GLIBC_BACKTRACE
167         /* try logging a traceback to the debug log */
168         if (db_fd != -1) {
169             void *stack[32];
170             int naddrs;
171             naddrs = backtrace(stack, sizeof(stack)/sizeof(*stack));
172             backtrace_symbols_fd(stack, naddrs, db_fd);
173         }
174 #endif
175
176         /* we're done */
177         if (log_level & G_LOG_LEVEL_CRITICAL)
178             exit(error_exit_status);
179         else
180             abort();
181         g_assert_not_reached();
182     }
183 }
184
185 /* Install our handler into the glib log handling system.
186  */
187 static void
188 debug_setup_logging(void)
189 {
190     /* g_error and g_critical should be fatal, although the log handler
191      * takes care of this anyway */
192     g_log_set_always_fatal(G_LOG_LEVEL_ERROR |  G_LOG_LEVEL_CRITICAL);
193
194     /* set up handler (g_log_set_default_handler is new in glib-2.6, and
195      * hence not useable here) */
196     g_log_set_handler(NULL, G_LOG_LEVEL_MASK | G_LOG_FLAG_FATAL | G_LOG_FLAG_RECURSION,
197                       debug_logging_handler, NULL);
198 }
199
200 /* Set the global dbgdir according to 'config' and 'subdir', and clean
201  * old debug files out of that directory
202  *
203  * The global open_time is set to the current time, and used to delete
204  * old files.
205  *
206  * @param config: configuration or NULL
207  * @param subdir: subdirectory (server, client, etc.) or NULL
208  */
209 static void
210 debug_setup_1(char *config, char *subdir)
211 {
212     char *pname;
213     size_t pname_len;
214     char *e = NULL;
215     char *s = NULL;
216     DIR *d;
217     struct dirent *entry;
218     int do_rename;
219     char *test_name;
220     size_t test_name_len;
221     size_t d_name_len;
222     struct stat sbuf;
223     char *dbfilename = NULL;
224     char *sane_config = NULL;
225     int i;
226
227     memset(&sbuf, 0, SIZEOF(sbuf));
228
229     pname = get_pname();
230     pname_len = strlen(pname);
231
232     /*
233      * Create the debug directory if it does not yet exist.
234      */
235     amfree(dbgdir);
236     if (config)
237         sane_config = sanitise_filename(config);
238     if (sane_config && subdir)
239         dbgdir = vstralloc(AMANDA_DBGDIR, "/", subdir, "/", sane_config,
240                            "/", NULL);
241     else if (sane_config)
242         dbgdir = vstralloc(AMANDA_DBGDIR, "/", sane_config, "/", NULL);
243     else if (subdir)
244         dbgdir = vstralloc(AMANDA_DBGDIR, "/", subdir, "/", NULL);
245     else
246         dbgdir = stralloc2(AMANDA_DBGDIR, "/");
247     if(mkpdir(dbgdir, 0700, get_client_uid(), get_client_gid()) == -1) {
248         error(_("create debug directory \"%s\": %s"),
249               dbgdir, strerror(errno));
250         /*NOTREACHED*/
251     }
252     amfree(sane_config);
253
254     /*
255      * Clean out old debug files.  We also rename files with old style
256      * names (XXX.debug or XXX.$PID.debug) into the new name format.
257      * We assume no system has 17 digit PID-s :-) and that there will
258      * not be a conflict between an old and new name.
259      */
260     if((d = opendir(dbgdir)) == NULL) {
261         error(_("open debug directory \"%s\": %s"),
262               dbgdir, strerror(errno));
263         /*NOTREACHED*/
264     }
265     time(&open_time);
266     test_name = get_debug_name(open_time - (AMANDA_DEBUG_DAYS * 24 * 60 * 60), 0);
267     test_name_len = strlen(test_name);
268     while((entry = readdir(d)) != NULL) {
269         if(is_dot_or_dotdot(entry->d_name)) {
270             continue;
271         }
272         d_name_len = strlen(entry->d_name);
273         if(strncmp(entry->d_name, pname, pname_len) != 0
274            || entry->d_name[pname_len] != '.'
275            || d_name_len < 6
276            || strcmp(entry->d_name + d_name_len - 6, ".debug") != 0) {
277             continue;                           /* not one of our debug files */
278         }
279         e = newvstralloc(e, dbgdir, entry->d_name, NULL);
280         if(d_name_len < test_name_len) {
281             /*
282              * Create a "pretend" name based on the last modification
283              * time.  This name will be used to decide if the real name
284              * should be removed.  If not, it will be used to rename the
285              * real name.
286              */
287             if(stat(e, &sbuf) != 0) {
288                 continue;                       /* ignore errors */
289             }
290             amfree(dbfilename);
291             dbfilename = get_debug_name((time_t)sbuf.st_mtime, 0);
292             do_rename = 1;
293         } else {
294             dbfilename = newstralloc(dbfilename, entry->d_name);
295             do_rename = 0;
296         }
297         if(strcmp(dbfilename, test_name) < 0) {
298             (void) unlink(e);                   /* get rid of old file */
299             continue;
300         }
301         if(do_rename) {
302             i = 0;
303             while(dbfilename != NULL
304                   && (s = newvstralloc(s, dbgdir, dbfilename, NULL)) != NULL
305                   && rename(e, s) != 0 && errno != ENOENT) {
306                 amfree(dbfilename);
307                 dbfilename = get_debug_name((time_t)sbuf.st_mtime, ++i);
308             }
309             if(dbfilename == NULL) {
310                 error(_("cannot rename old debug file \"%s\""), entry->d_name);
311                 /*NOTREACHED*/
312             }
313         }
314     }
315     amfree(dbfilename);
316     amfree(e);
317     amfree(s);
318     amfree(test_name);
319     closedir(d);
320 }
321
322 /* Given an already-opened debug file, set the file's ownership
323  * appropriately, move its file descriptor above MIN_DB_FD, and
324  * add an initial log entry to the file.
325  *
326  * This function records the file's identity in the globals
327  * db_filename, db_fd, and db_file.  It does *not* set db_name.
328  * db_file is not set if fd is -1
329  *
330  * This function uses the global 'open_time', which is set by
331  * debug_setup_1.
332  *
333  * @param s: the filename of the debug file; string should be malloc'd,
334  * and should *not* be freed by the caller.
335  * @param fd: the descriptor connected to the debug file, or -1 if
336  * no decriptor moving should take place.
337  * @param annotation: an extra string to include in the initial
338  * log entry.
339  */
340 static void
341 debug_setup_2(
342     char *      s,
343     int         fd,
344     char *      annotation)
345 {
346     int i;
347     int fd_close[MIN_DB_FD+1];
348
349     amfree(db_filename);
350     db_filename = s;
351     s = NULL;
352
353     /* If we're root, change the ownership of the debug files.  If we're not root,
354      * this would either be redundant or an error. */
355     if (geteuid() == 0) {
356         if (chown(db_filename, get_client_uid(), get_client_gid()) < 0) {
357             dbprintf(_("chown(%s, %d, %d) failed: %s"),
358                      db_filename, (int)get_client_uid(), (int)get_client_gid(), strerror(errno));
359         }
360     }
361     amfree(dbgdir);
362     /*
363      * Move the file descriptor up high so it stays out of the way
364      * of other processing, e.g. sendbackup.
365      */
366     if (fd >= 0) {
367         i = 0;
368         fd_close[i++] = fd;
369         while((db_fd = dup(fd)) < MIN_DB_FD) {
370             fd_close[i++] = db_fd;
371         }
372         while(--i >= 0) {
373             close(fd_close[i]);
374         }
375         db_file = fdopen(db_fd, "a");
376     }
377
378     if (annotation) {
379         /*
380          * Make the first debug log file entry.
381          */
382         debug_printf(_("pid %ld ruid %ld euid %ld: %s at %s"),
383                      (long)getpid(),
384                      (long)getuid(), (long)geteuid(),
385                      annotation,
386                      ctime(&open_time));
387     }
388 }
389
390 /* Get current GMT time and return a message timestamp.
391  * Used for g_printf calls to logs and such.  The return value
392  * is to a static buffer, so it should be used immediately.
393  *
394  * @returns: timestamp
395  */
396 static char *
397 msg_timestamp(void)
398 {
399     static char timestamp[128];
400     struct timeval tv;
401
402     gettimeofday(&tv, NULL);
403     g_snprintf(timestamp, SIZEOF(timestamp), "%lld.%06ld",
404                 (long long)tv.tv_sec, (long)tv.tv_usec);
405
406     return timestamp;
407 }
408
409 /*
410  * ---- public functions
411  */
412
413 void
414 set_logerror(void (*f)(char *))
415 {
416     logerror_fn = f;
417 }
418
419 void
420 debug_open(char *subdir)
421 {
422     int fd = -1;
423     int i;
424     char *s = NULL;
425     mode_t mask;
426
427     /* set up logging while we're here */
428     debug_setup_logging();
429
430     /* set 'dbgdir' and clean out old debug files */
431     debug_setup_1(NULL, subdir);
432
433     /*
434      * Create the new file with a unique sequence number.
435      */
436     mask = (mode_t)umask((mode_t)0037); /* Allow the group read bit through */
437
438     /* iteratate through sequence numbers until we find one that
439      * is not already in use */
440     for(i = 0; fd < 0; i++) {
441         amfree(db_name);
442         if ((db_name = get_debug_name(open_time, i)) == NULL) {
443             error(_("Cannot create debug file name in %d tries."), i);
444             /*NOTREACHED*/
445         }
446
447         if ((s = newvstralloc(s, dbgdir, db_name, NULL)) == NULL) {
448             error(_("Cannot allocate debug file name memory"));
449             /*NOTREACHED*/
450         }
451
452         if ((fd = open(s, O_WRONLY|O_CREAT|O_EXCL|O_APPEND, 0640)) < 0) {
453             if (errno != EEXIST) {
454                 error(_("Cannot create debug file \"%s\": %s"),
455                         s, strerror(errno));
456                 /*NOTREACHED*/
457             }
458             amfree(s);
459         }
460     }
461     (void)umask(mask); /* Restore mask */
462
463     /*
464      * Finish setup.
465      *
466      * Note: we release control of the string 's' points to.
467      */
468     debug_setup_2(s, fd, "start");
469 }
470
471 void
472 debug_reopen(
473     char *      dbfilename,
474     char *      annotation)
475 {
476     char *s = NULL;
477     int fd;
478
479     if (dbfilename == NULL) {
480         return;
481     }
482
483     /* set 'dbgdir' and clean out old debug files */
484     debug_setup_1(NULL, NULL);
485
486     /*
487      * Reopen the file.
488      */
489     if (*dbfilename == '/') {
490         s = stralloc(dbfilename);
491     } else {
492         s = newvstralloc(s, dbgdir, dbfilename, NULL);
493     }
494     if ((fd = open(s, O_RDWR|O_APPEND)) < 0) {
495         error(_("cannot reopen debug file %s"), dbfilename);
496         /*NOTREACHED*/
497     }
498
499     /*
500      * Finish setup.
501      *
502      * Note: we release control of the string 's' points to.
503      */
504     debug_setup_2(s, fd, annotation);
505 }
506
507 void
508 debug_rename(
509     char *config,
510     char *subdir)
511 {
512     int fd = -1;
513     int i;
514     char *s = NULL;
515     mode_t mask;
516
517     if (!db_filename)
518         return;
519
520     /* set 'dbgdir' and clean out old debug files */
521     debug_setup_1(config, subdir);
522
523     s = newvstralloc(s, dbgdir, db_name, NULL);
524
525     if (strcmp(db_filename, s) == 0) {
526         amfree(s);
527         return;
528     }
529
530     mask = (mode_t)umask((mode_t)0037);
531
532 #if defined(__CYGWIN__)
533     /*
534      * On cygwin, rename will not overwrite an existing file nor
535      * will it rename a file that is open for writing...
536      *
537      * Rename file directly.  Expect failure if file already exists
538      * or is open by another user.
539      */
540
541     i = 0;
542     while (rename(db_filename, s) < 0) {
543         if (errno != EEXIST) {
544             /*
545              * If the failure was not due to the target file name already
546              * existing then we have bigger issues at hand so we keep 
547              * the existing file.
548              */
549             dbprintf(_("Cannot rename \"%s\" to \"%s\": %s\n"),
550                      db_filename, s, strerror(errno));
551             s = newvstralloc(s, db_filename, NULL);
552             i = -1;
553             break;
554         }
555
556         /*
557          * Files already exists:
558          * Continue searching for a unique file name that will work.
559          */
560         amfree(db_name);
561         if ((db_name = get_debug_name(open_time, i++)) == NULL) {
562             dbprintf(_("Cannot create unique debug file name"));
563             break;
564         }
565         s = newvstralloc(s, dbgdir, db_name, NULL);
566     }
567     if (i >= 0) {
568         /*
569          * We need to close and reopen the original file handle to
570          * release control of the original debug file name.
571          */
572         if ((fd = open(s, O_WRONLY|O_APPEND, 0640)) >= 0) {
573             /*
574              * We can safely close the the original log file
575              * since we now have a new working handle.
576              */
577             db_fd = 2;
578             fclose(db_file);
579             db_file = NULL;
580         }
581     }
582 #else
583     /* check if a file with the same name already exists. */
584     if ((fd = open(s, O_WRONLY|O_CREAT|O_EXCL|O_APPEND, 0640)) < 0) {
585         for(i = 0; fd < 0; i++) {
586             amfree(db_name);
587             if ((db_name = get_debug_name(open_time, i)) == NULL) {
588                 dbprintf(_("Cannot create debug file"));
589                 break;
590             }
591
592             s = newvstralloc(s, dbgdir, db_name, NULL);
593             if ((fd = open(s, O_WRONLY|O_CREAT|O_EXCL|O_APPEND, 0640)) < 0) {
594                 if (errno != EEXIST) {
595                     dbprintf(_("Cannot create debug file: %s"),
596                               strerror(errno));
597                     break;
598                 }
599             }
600         }
601     }
602
603     if (fd >= 0) {
604         close(fd);
605         if (rename(db_filename, s) == -1) {
606             dbprintf(_("Cannot rename \"%s\" to \"%s\": %s\n"),
607                      db_filename, s, strerror(errno));
608         }
609         fd = -1;
610     }
611 #endif
612
613     (void)umask(mask); /* Restore mask */
614     /*
615      * Finish setup.
616      *
617      * Note: we release control of the string 's' points to.
618      */
619     debug_setup_2(s, fd, "rename");
620 }
621
622 void
623 debug_close(void)
624 {
625     time_t curtime;
626
627     time(&curtime);
628     debug_printf(_("pid %ld finish time %s"), (long)getpid(), ctime(&curtime));
629
630     if(db_file && fclose(db_file) == EOF) {
631         int save_errno = errno;
632
633         db_file = NULL;                         /* prevent recursion */
634         g_fprintf(stderr, _("close debug file: %s"), strerror(save_errno));
635         /*NOTREACHED*/
636     }
637     db_fd = 2;
638     db_file = NULL;
639     amfree(db_filename);
640     amfree(db_name);
641 }
642
643 /*
644  * Format and write a debug message to the process debug file.
645  */
646 printf_arglist_function(void debug_printf, const char *, format)
647 {
648     va_list argp;
649     int save_errno;
650
651     /*
652      * It is common in the code to call dbprintf to write out
653      * syserrno(errno) and then turn around and try to do something else
654      * with errno (e.g. g_printf() or log()), so we make sure errno goes
655      * back out with the same value it came in with.
656      */
657
658     save_errno = errno;
659
660     /* handle the default (stderr) if debug_open hasn't been called yet */
661     if(db_file == NULL && db_fd == 2) {
662         db_file = stderr;
663     }
664     if(db_file != NULL) {
665         if (db_file != stderr)
666             g_fprintf(db_file, "%s: %s: ", msg_timestamp(), get_pname());
667         else 
668             g_fprintf(db_file, "%s: ", get_pname());
669         arglist_start(argp, format);
670         g_vfprintf(db_file, format, argp);
671         arglist_end(argp);
672         fflush(db_file);
673     }
674     errno = save_errno;
675 }
676
677 int
678 debug_fd(void)
679 {
680     return db_fd;
681 }
682
683 FILE *
684 debug_fp(void)
685 {
686     return db_file;
687 }
688
689 char *
690 debug_fn(void)
691 {
692     return db_filename;
693 }
694
695 void
696 debug_dup_stderr_to_debug(void)
697 {
698     if(db_fd != -1 && db_fd != STDERR_FILENO)
699     {
700        if(dup2(db_fd, STDERR_FILENO) != STDERR_FILENO)
701        {
702            error(_("can't redirect stderr to the debug file"));
703            g_assert_not_reached();
704        }
705     }
706 }
707