2 * Amanda, The Advanced Maryland Automatic Network Disk Archiver
3 * Copyright (c) 1991-1998 University of Maryland at College Park
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.
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.
23 * Author: James da Silva, Systems Design and Analysis Group
24 * Computer Science Department
25 * University of Maryland at College Park
28 * $Id: debug.c,v 1.40 2006/07/26 11:49:32 martinea Exp $
37 #include "timestamp.h"
40 #ifdef HAVE_GLIBC_BACKTRACE
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.
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 */
56 /* directory containing debug file, including trailing slash */
57 static char *dbgdir = NULL;
59 /* time debug log was opened (timestamp of the file) */
60 static time_t open_time;
62 /* storage for global variables */
63 int error_exit_status = 1;
65 /* static function prototypes */
66 static char *get_debug_name(time_t t, int n);
67 static void debug_unlink_old(void);
68 static void debug_setup_1(char *config, char *subdir);
69 static void debug_setup_2(char *s, int fd, char *annotation);
70 static char *msg_timestamp(void);
71 static char *msg_thread(void);
73 static void debug_logging_handler(const gchar *log_domain,
74 GLogLevelFlags log_level,
77 static void debug_setup_logging(void);
79 /* By default, do not suppress tracebacks */
80 static gboolean do_suppress_error_traceback = FALSE;
82 /* configured amanda_log_handlers */
83 static GSList *amanda_log_handlers = NULL;
86 * Generate a debug file name. The name is based on the program name,
87 * followed by a timestamp, an optional sequence number, and ".debug".
90 * @param n: sequence number between 1 and 1000; if zero, no sequence number
98 char number[NUM_STR_SIZE];
102 if(n < 0 || n > 1000) {
105 ts = get_timestamp_from_time(t);
109 g_snprintf(number, SIZEOF(number), "%03d", n - 1);
111 result = vstralloc(get_pname(), ".", ts, number, ".debug", NULL);
116 /* Call this to suppress tracebacks on error() or g_critical(). This is used
117 * when a critical error is indicated in perl, and the traceback will not be
120 suppress_error_traceback(void)
122 do_suppress_error_traceback = 1;
125 /* A GLogFunc to handle g_log calls. This function assumes that user_data
126 * is either NULL or a pointer to one of the debug_* configuration variables
127 * in conffile.c, indicating whether logging for this log domain is enabled.
129 * @param log_domain: the log domain, or NULL for general logging
130 * @param log_level: level, fatality, and recursion flags
131 * @param message: the message to log
132 * @param user_pointer: unused
135 debug_logging_handler(const gchar *log_domain G_GNUC_UNUSED,
136 GLogLevelFlags log_level,
137 const gchar *message,
138 gpointer user_data G_GNUC_UNUSED)
140 GLogLevelFlags maxlevel;
141 char *levprefix = NULL;
142 pcontext_t context = get_pcontext();
144 /* glib allows a message to have multiple levels, so calculate the "worst"
146 if (log_level & G_LOG_LEVEL_ERROR) {
147 maxlevel = G_LOG_LEVEL_ERROR;
148 levprefix = _("error (fatal): ");
149 } else if (log_level & G_LOG_LEVEL_CRITICAL) {
150 maxlevel = G_LOG_LEVEL_CRITICAL;
151 levprefix = _("critical (fatal): ");
152 } else if (log_level & G_LOG_LEVEL_WARNING) {
153 maxlevel = G_LOG_LEVEL_WARNING;
154 levprefix = _("warning: ");
155 } else if (log_level & G_LOG_LEVEL_MESSAGE) {
156 maxlevel = G_LOG_LEVEL_MESSAGE;
157 levprefix = _("message: ");
158 } else if (log_level & G_LOG_LEVEL_INFO) {
159 maxlevel = G_LOG_LEVEL_INFO;
160 levprefix = _("info: ");
162 maxlevel = G_LOG_LEVEL_DEBUG;
163 levprefix = ""; /* no level displayed for debugging */
166 /* scriptutil context doesn't do any logging except for critical
167 * and error levels */
168 if (context != CONTEXT_SCRIPTUTIL) {
169 /* convert the highest level to a string and dbprintf it */
170 debug_printf("%s%s\n", levprefix, message);
173 if (amanda_log_handlers) {
174 GSList *iter = amanda_log_handlers;
176 amanda_log_handler_t *hdlr = (amanda_log_handler_t *)iter->data;
177 hdlr(maxlevel, message);
178 iter = g_slist_next(iter);
181 /* call the appropriate handlers, based on the context */
182 amanda_log_stderr(maxlevel, message);
183 if (context == CONTEXT_DAEMON)
184 amanda_log_syslog(maxlevel, message);
187 /* error and critical levels have special handling */
188 if (log_level & (G_LOG_LEVEL_ERROR|G_LOG_LEVEL_CRITICAL)) {
189 #ifdef HAVE_GLIBC_BACKTRACE
190 /* try logging a traceback to the debug log */
191 if (!do_suppress_error_traceback && db_fd != -1) {
194 naddrs = backtrace(stack, sizeof(stack)/sizeof(*stack));
195 backtrace_symbols_fd(stack, naddrs, db_fd);
200 if (log_level & G_LOG_LEVEL_CRITICAL)
201 exit(error_exit_status);
204 g_assert_not_reached();
208 /* Install our handler into the glib log handling system.
211 debug_setup_logging(void)
213 /* g_error and g_critical should be fatal, although the log handler
214 * takes care of this anyway */
215 g_log_set_always_fatal(G_LOG_LEVEL_ERROR | G_LOG_LEVEL_CRITICAL);
217 /* set up handler (g_log_set_default_handler is new in glib-2.6, and
218 * hence not useable here) */
219 g_log_set_handler(NULL, G_LOG_LEVEL_MASK | G_LOG_FLAG_FATAL | G_LOG_FLAG_RECURSION,
220 debug_logging_handler, NULL);
224 add_amanda_log_handler(amanda_log_handler_t *hdlr)
226 amanda_log_handlers = g_slist_append(amanda_log_handlers, (gpointer)hdlr);
230 amanda_log_syslog(GLogLevelFlags log_level, const gchar *message)
232 int priority = LOG_ERR;
234 case G_LOG_LEVEL_ERROR:
235 case G_LOG_LEVEL_CRITICAL:
239 case G_LOG_LEVEL_WARNING:
241 priority = LOG_WARNING;
250 openlog(get_pname(), LOG_PID, LOG_DAEMON);
252 openlog(get_pname(), LOG_PID, 0);
254 syslog(priority, "%s", message);
260 amanda_log_stderr(GLogLevelFlags log_level, const gchar *message)
263 case G_LOG_LEVEL_ERROR:
264 case G_LOG_LEVEL_CRITICAL:
265 g_fprintf(stderr, "%s: %s\n", get_pname(), message);
274 amanda_log_null(GLogLevelFlags log_level G_GNUC_UNUSED, const gchar *message G_GNUC_UNUSED)
278 /* Set the global dbgdir according to 'config' and 'subdir'
280 * The global open_time is set to the current time, and used to delete
283 * @param config: configuration or NULL
284 * @param subdir: subdirectory (server, client, etc.) or NULL
287 debug_setup_1(char *config, char *subdir)
289 char *sane_config = NULL;
292 * Create the debug directory if it does not yet exist.
296 sane_config = sanitise_filename(config);
297 if (sane_config && subdir)
298 dbgdir = vstralloc(AMANDA_DBGDIR, "/", subdir, "/", sane_config,
300 else if (sane_config)
301 dbgdir = vstralloc(AMANDA_DBGDIR, "/", sane_config, "/", NULL);
303 dbgdir = vstralloc(AMANDA_DBGDIR, "/", subdir, "/", NULL);
305 dbgdir = stralloc2(AMANDA_DBGDIR, "/");
306 if(mkpdir(dbgdir, 0700, get_client_uid(), get_client_gid()) == -1) {
307 error(_("create debug directory \"%s\": %s"),
308 dbgdir, strerror(errno));
317 * Clean out old debug files. We also rename files with old style
318 * names (XXX.debug or XXX.$PID.debug) into the new name format.
319 * We assume no system has 17 digit PID-s :-) and that there will
320 * not be a conflict between an old and new name.
323 debug_unlink_old(void)
329 struct dirent *entry;
332 size_t test_name_len;
334 char *dbfilename = NULL;
339 assert(dbgdir != NULL);
341 memset(&sbuf, 0, SIZEOF(sbuf));
344 pname_len = strlen(pname);
346 if((d = opendir(dbgdir)) == NULL) {
347 error(_("open debug directory \"%s\": %s"),
348 dbgdir, strerror(errno));
351 test_name = get_debug_name(open_time - (getconf_int(CNF_DEBUG_DAYS) * 24 * 60 * 60), 0);
352 test_name_len = strlen(test_name);
353 while((entry = readdir(d)) != NULL) {
354 if(is_dot_or_dotdot(entry->d_name)) {
357 d_name_len = strlen(entry->d_name);
358 if(strncmp(entry->d_name, pname, pname_len) != 0
359 || entry->d_name[pname_len] != '.'
361 || strcmp(entry->d_name + d_name_len - 6, ".debug") != 0) {
362 continue; /* not one of our debug files */
364 e = newvstralloc(e, dbgdir, entry->d_name, NULL);
365 if(d_name_len < test_name_len) {
367 * Create a "pretend" name based on the last modification
368 * time. This name will be used to decide if the real name
369 * should be removed. If not, it will be used to rename the
372 if(stat(e, &sbuf) != 0) {
373 continue; /* ignore errors */
376 dbfilename = get_debug_name((time_t)sbuf.st_mtime, 0);
379 dbfilename = newstralloc(dbfilename, entry->d_name);
382 if(strcmp(dbfilename, test_name) < 0) {
383 (void) unlink(e); /* get rid of old file */
388 while(dbfilename != NULL
389 && (s = newvstralloc(s, dbgdir, dbfilename, NULL)) != NULL
390 && rename(e, s) != 0 && errno != ENOENT) {
392 dbfilename = get_debug_name((time_t)sbuf.st_mtime, ++i);
394 if(dbfilename == NULL) {
395 error(_("cannot rename old debug file \"%s\""), entry->d_name);
407 /* Given an already-opened debug file, set the file's ownership
408 * appropriately, move its file descriptor above MIN_DB_FD, and
409 * add an initial log entry to the file.
411 * This function records the file's identity in the globals
412 * db_filename, db_fd, and db_file. It does *not* set db_name.
413 * db_file is not set if fd is -1
415 * This function uses the global 'open_time', which is set by
418 * @param s: the filename of the debug file; string should be malloc'd,
419 * and should *not* be freed by the caller.
420 * @param fd: the descriptor connected to the debug file, or -1 if
421 * no decriptor moving should take place.
422 * @param annotation: an extra string to include in the initial
432 int fd_close[MIN_DB_FD+1];
438 /* If we're root, change the ownership of the debug files. If we're not root,
439 * this would either be redundant or an error. */
440 if (geteuid() == 0) {
441 if (chown(db_filename, get_client_uid(), get_client_gid()) < 0) {
442 dbprintf(_("chown(%s, %d, %d) failed: %s"),
443 db_filename, (int)get_client_uid(), (int)get_client_gid(), strerror(errno));
448 * Move the file descriptor up high so it stays out of the way
449 * of other processing, e.g. sendbackup.
454 while((db_fd = dup(fd)) < MIN_DB_FD) {
455 fd_close[i++] = db_fd;
460 db_file = fdopen(db_fd, "a");
465 * Make the first debug log file entry.
467 debug_printf(_("pid %ld ruid %ld euid %ld version %s: %s at %s"),
469 (long)getuid(), (long)geteuid(),
476 /* Get current GMT time and return a message timestamp.
477 * Used for g_printf calls to logs and such. The return value
478 * is to a static buffer, so it should be used immediately.
480 * @returns: timestamp
485 static char timestamp[128];
490 ctime_r(&curtime, timestamp);
491 r = strchr(timestamp, '\n');
498 /* Get current GMT time and return a message timestamp.
499 * Used for g_printf calls to logs and such. The return value
500 * is to a static buffer, so it should be used immediately.
502 * @returns: timestamp
507 static char thread[128];
509 sprintf(thread, "thd-%p", g_thread_self());
515 * ---- public functions
521 debug_setup_logging();
523 /* the scriptutil context does not create a debug log, since such
524 * processes are invoked many times.
526 if (get_pcontext() != CONTEXT_SCRIPTUTIL) {
527 debug_open(get_ptype());
532 debug_open(char *subdir)
539 /* set up logging while we're here */
540 debug_setup_logging();
542 /* set 'dbgdir' and clean out old debug files */
543 debug_setup_1(NULL, subdir);
546 * Create the new file with a unique sequence number.
548 mask = (mode_t)umask((mode_t)0037); /* Allow the group read bit through */
550 /* iteratate through sequence numbers until we find one that
551 * is not already in use */
552 for(i = 0; fd < 0; i++) {
554 if ((db_name = get_debug_name(open_time, i)) == NULL) {
555 error(_("Cannot create debug file name in %d tries."), i);
559 if ((s = newvstralloc(s, dbgdir, db_name, NULL)) == NULL) {
560 error(_("Cannot allocate debug file name memory"));
564 if ((fd = open(s, O_WRONLY|O_CREAT|O_EXCL|O_APPEND, 0640)) < 0) {
565 if (errno != EEXIST) {
566 error(_("Cannot create debug file \"%s\": %s"),
573 (void)umask(mask); /* Restore mask */
578 * Note: we release control of the string 's' points to.
580 debug_setup_2(s, fd, "start");
591 if (dbfilename == NULL) {
595 /* set 'dbgdir' and clean out old debug files */
596 debug_setup_1(NULL, NULL);
601 if (*dbfilename == '/') {
602 s = stralloc(dbfilename);
604 s = newvstralloc(s, dbgdir, dbfilename, NULL);
606 if ((fd = open(s, O_RDWR|O_APPEND)) < 0) {
607 error(_("cannot reopen debug file %s"), dbfilename);
614 * Note: we release control of the string 's' points to.
616 debug_setup_2(s, fd, annotation);
632 if (get_pcontext() == CONTEXT_SCRIPTUTIL) {
636 /* Remove old log from source directory */
638 /* set 'dbgdir' and clean out old debug files */
639 debug_setup_1(config, subdir);
640 /* Remove old log from destination directory */
643 s = newvstralloc(s, dbgdir, db_name, NULL);
645 if (strcmp(db_filename, s) == 0) {
650 mask = (mode_t)umask((mode_t)0037);
652 #if defined(__CYGWIN__)
654 * On cygwin, rename will not overwrite an existing file nor
655 * will it rename a file that is open for writing...
657 * Rename file directly. Expect failure if file already exists
658 * or is open by another user.
662 while (rename(db_filename, s) < 0) {
663 if (errno != EEXIST) {
665 * If the failure was not due to the target file name already
666 * existing then we have bigger issues at hand so we keep
669 dbprintf(_("Cannot rename \"%s\" to \"%s\": %s\n"),
670 db_filename, s, strerror(errno));
671 s = newvstralloc(s, db_filename, NULL);
677 * Files already exists:
678 * Continue searching for a unique file name that will work.
681 if ((db_name = get_debug_name(open_time, i++)) == NULL) {
682 dbprintf(_("Cannot create unique debug file name"));
685 s = newvstralloc(s, dbgdir, db_name, NULL);
689 * We need to close and reopen the original file handle to
690 * release control of the original debug file name.
692 if ((fd = open(s, O_WRONLY|O_APPEND, 0640)) >= 0) {
694 * We can safely close the the original log file
695 * since we now have a new working handle.
703 /* check if a file with the same name already exists. */
704 if ((fd = open(s, O_WRONLY|O_CREAT|O_EXCL|O_APPEND, 0640)) < 0) {
705 for(i = 0; fd < 0; i++) {
707 if ((db_name = get_debug_name(open_time, i)) == NULL) {
708 dbprintf(_("Cannot create debug file"));
712 s = newvstralloc(s, dbgdir, db_name, NULL);
713 if ((fd = open(s, O_WRONLY|O_CREAT|O_EXCL|O_APPEND, 0640)) < 0) {
714 if (errno != EEXIST) {
715 dbprintf(_("Cannot create debug file: %s"),
725 if (rename(db_filename, s) == -1) {
726 dbprintf(_("Cannot rename \"%s\" to \"%s\": %s\n"),
727 db_filename, s, strerror(errno));
733 (void)umask(mask); /* Restore mask */
737 * Note: we release control of the string 's' points to.
739 debug_setup_2(s, fd, "rename");
747 if (get_pcontext() == CONTEXT_SCRIPTUTIL) {
754 debug_printf(_("pid %ld finish time %s"), (long)getpid(), ctime(&curtime));
756 if(db_file && fclose(db_file) == EOF) {
757 int save_errno = errno;
759 db_file = NULL; /* prevent recursion */
760 g_fprintf(stderr, _("close debug file: %s"), strerror(save_errno));
770 * Format and write a debug message to the process debug file.
772 printf_arglist_function(void debug_printf, const char *, format)
778 * It is common in the code to call dbprintf to write out
779 * syserrno(errno) and then turn around and try to do something else
780 * with errno (e.g. g_printf() or log()), so we make sure errno goes
781 * back out with the same value it came in with.
786 /* handle the default (stderr) if debug_open hasn't been called yet */
787 if(db_file == NULL && db_fd == 2) {
790 if(db_file != NULL) {
794 if (db_file != stderr)
795 prefix = g_strdup_printf("%s: %s: %s:", msg_timestamp(), msg_thread(), get_pname());
797 prefix = g_strdup_printf("%s:", get_pname());
798 arglist_start(argp, format);
799 text = g_strdup_vprintf(format, argp);
801 fprintf(db_file, "%s %s", prefix, text);
828 debug_dup_stderr_to_debug(void)
830 if(db_fd != -1 && db_fd != STDERR_FILENO)
832 if(dup2(db_fd, STDERR_FILENO) != STDERR_FILENO)
834 error(_("can't redirect stderr to the debug file: %d, %s"), db_fd, strerror(errno));
835 g_assert_not_reached();