2 * Amanda, The Advanced Maryland Automatic Network Disk Archiver
3 * Copyright (c) 1991-1998 University of Maryland at College Park
4 * Copyright (c) 2007-2012 Zmanda, Inc. All Rights Reserved.
7 * Permission to use, copy, modify, distribute, and sell this software and its
8 * documentation for any purpose is hereby granted without fee, provided that
9 * the above copyright notice appear in all copies and that both that
10 * copyright notice and this permission notice appear in supporting
11 * documentation, and that the name of U.M. not be used in advertising or
12 * publicity pertaining to distribution of the software without specific,
13 * written prior permission. U.M. makes no representations about the
14 * suitability of this software for any purpose. It is provided "as is"
15 * without express or implied warranty.
17 * U.M. DISCLAIMS ALL WARRANTIES WITH REGARD TO THIS SOFTWARE, INCLUDING ALL
18 * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS, IN NO EVENT SHALL U.M.
19 * BE LIABLE FOR ANY SPECIAL, INDIRECT OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES
20 * WHATSOEVER RESULTING FROM LOSS OF USE, DATA OR PROFITS, WHETHER IN AN ACTION
21 * OF CONTRACT, NEGLIGENCE OR OTHER TORTIOUS ACTION, ARISING OUT OF OR IN
22 * CONNECTION WITH THE USE OR PERFORMANCE OF THIS SOFTWARE.
24 * Author: James da Silva, Systems Design and Analysis Group
25 * Computer Science Department
26 * University of Maryland at College Park
29 * $Id: debug.c,v 1.40 2006/07/26 11:49:32 martinea Exp $
38 #include "timestamp.h"
41 #ifdef HAVE_GLIBC_BACKTRACE
45 /* Minimum file descriptor on which to keep the debug file. This is intended
46 * to keep the descriptor "out of the way" of other processing. It's not clear
47 * that this is required any longer, but it doesn't hurt anything.
51 /* information on the current debug file */
52 static int db_fd = 2; /* file descriptor (default stderr) */
53 static FILE *db_file = NULL; /* stdio stream */
54 static char *db_name = NULL; /* unqualified filename */
55 static char *db_filename = NULL; /* fully qualified pathname */
57 /* directory containing debug file, including trailing slash */
58 static char *dbgdir = NULL;
60 /* time debug log was opened (timestamp of the file) */
61 static time_t open_time;
63 /* storage for global variables */
64 int error_exit_status = 1;
66 /* static function prototypes */
67 static char *get_debug_name(time_t t, int n);
68 static void debug_unlink_old(void);
69 static void debug_setup_1(char *config, char *subdir);
70 static void debug_setup_2(char *s, int fd, char *annotation);
71 static char *msg_timestamp(void);
72 static char *msg_thread(void);
74 static void debug_logging_handler(const gchar *log_domain,
75 GLogLevelFlags log_level,
78 static void debug_setup_logging(void);
80 /* By default, do not suppress tracebacks */
81 static gboolean do_suppress_error_traceback = FALSE;
83 /* configured amanda_log_handlers */
84 static GSList *amanda_log_handlers = NULL;
87 * Generate a debug file name. The name is based on the program name,
88 * followed by a timestamp, an optional sequence number, and ".debug".
91 * @param n: sequence number between 1 and 1000; if zero, no sequence number
99 char number[NUM_STR_SIZE];
103 if(n < 0 || n > 1000) {
106 ts = get_timestamp_from_time(t);
110 g_snprintf(number, SIZEOF(number), "%03d", n - 1);
112 result = vstralloc(get_pname(), ".", ts, number, ".debug", NULL);
117 /* Call this to suppress tracebacks on error() or g_critical(). This is used
118 * when a critical error is indicated in perl, and the traceback will not be
121 suppress_error_traceback(void)
123 do_suppress_error_traceback = 1;
126 /* A GLogFunc to handle g_log calls. This function assumes that user_data
127 * is either NULL or a pointer to one of the debug_* configuration variables
128 * in conffile.c, indicating whether logging for this log domain is enabled.
130 * @param log_domain: the log domain, or NULL for general logging
131 * @param log_level: level, fatality, and recursion flags
132 * @param message: the message to log
133 * @param user_pointer: unused
136 debug_logging_handler(const gchar *log_domain G_GNUC_UNUSED,
137 GLogLevelFlags log_level,
138 const gchar *message,
139 gpointer user_data G_GNUC_UNUSED)
141 GLogLevelFlags maxlevel;
142 char *levprefix = NULL;
143 pcontext_t context = get_pcontext();
145 /* glib allows a message to have multiple levels, so calculate the "worst"
147 if (log_level & G_LOG_LEVEL_ERROR) {
148 maxlevel = G_LOG_LEVEL_ERROR;
149 levprefix = _("error (fatal): ");
150 } else if (log_level & G_LOG_LEVEL_CRITICAL) {
151 maxlevel = G_LOG_LEVEL_CRITICAL;
152 levprefix = _("critical (fatal): ");
153 } else if (log_level & G_LOG_LEVEL_WARNING) {
154 maxlevel = G_LOG_LEVEL_WARNING;
155 levprefix = _("warning: ");
156 } else if (log_level & G_LOG_LEVEL_MESSAGE) {
157 maxlevel = G_LOG_LEVEL_MESSAGE;
158 levprefix = _("message: ");
159 } else if (log_level & G_LOG_LEVEL_INFO) {
160 maxlevel = G_LOG_LEVEL_INFO;
161 levprefix = _("info: ");
163 maxlevel = G_LOG_LEVEL_DEBUG;
164 levprefix = ""; /* no level displayed for debugging */
167 /* scriptutil context doesn't do any logging except for critical
168 * and error levels */
169 if (context != CONTEXT_SCRIPTUTIL) {
170 /* convert the highest level to a string and dbprintf it */
171 debug_printf("%s%s\n", levprefix, message);
174 if (amanda_log_handlers) {
175 GSList *iter = amanda_log_handlers;
177 amanda_log_handler_t *hdlr = (amanda_log_handler_t *)iter->data;
178 hdlr(maxlevel, message);
179 iter = g_slist_next(iter);
182 /* call the appropriate handlers, based on the context */
183 amanda_log_stderr(maxlevel, message);
184 if (context == CONTEXT_DAEMON)
185 amanda_log_syslog(maxlevel, message);
188 /* error and critical levels have special handling */
189 if (log_level & (G_LOG_LEVEL_ERROR|G_LOG_LEVEL_CRITICAL)) {
190 #ifdef HAVE_GLIBC_BACKTRACE
191 /* try logging a traceback to the debug log */
192 if (!do_suppress_error_traceback && db_fd != -1) {
195 naddrs = backtrace(stack, sizeof(stack)/sizeof(*stack));
196 backtrace_symbols_fd(stack, naddrs, db_fd);
201 if (log_level & G_LOG_LEVEL_CRITICAL)
202 exit(error_exit_status);
205 g_assert_not_reached();
209 /* Install our handler into the glib log handling system.
212 debug_setup_logging(void)
214 /* g_error and g_critical should be fatal, although the log handler
215 * takes care of this anyway */
216 g_log_set_always_fatal(G_LOG_LEVEL_ERROR | G_LOG_LEVEL_CRITICAL);
218 /* set up handler (g_log_set_default_handler is new in glib-2.6, and
219 * hence not useable here) */
220 g_log_set_handler(NULL, G_LOG_LEVEL_MASK | G_LOG_FLAG_FATAL | G_LOG_FLAG_RECURSION,
221 debug_logging_handler, NULL);
225 add_amanda_log_handler(amanda_log_handler_t *hdlr)
227 amanda_log_handlers = g_slist_append(amanda_log_handlers, (gpointer)hdlr);
231 amanda_log_syslog(GLogLevelFlags log_level, const gchar *message)
233 int priority = LOG_ERR;
235 case G_LOG_LEVEL_ERROR:
236 case G_LOG_LEVEL_CRITICAL:
240 case G_LOG_LEVEL_WARNING:
242 priority = LOG_WARNING;
251 openlog(get_pname(), LOG_PID, LOG_DAEMON);
253 openlog(get_pname(), LOG_PID, 0);
255 syslog(priority, "%s", message);
261 amanda_log_stderr(GLogLevelFlags log_level, const gchar *message)
264 case G_LOG_LEVEL_ERROR:
265 case G_LOG_LEVEL_CRITICAL:
266 g_fprintf(stderr, "%s: %s\n", get_pname(), message);
275 amanda_log_null(GLogLevelFlags log_level G_GNUC_UNUSED, const gchar *message G_GNUC_UNUSED)
279 /* Set the global dbgdir according to 'config' and 'subdir'
281 * The global open_time is set to the current time, and used to delete
284 * @param config: configuration or NULL
285 * @param subdir: subdirectory (server, client, etc.) or NULL
288 debug_setup_1(char *config, char *subdir)
290 char *sane_config = NULL;
293 * Create the debug directory if it does not yet exist.
297 sane_config = sanitise_filename(config);
298 if (sane_config && subdir)
299 dbgdir = vstralloc(AMANDA_DBGDIR, "/", subdir, "/", sane_config,
301 else if (sane_config)
302 dbgdir = vstralloc(AMANDA_DBGDIR, "/", sane_config, "/", NULL);
304 dbgdir = vstralloc(AMANDA_DBGDIR, "/", subdir, "/", NULL);
306 dbgdir = stralloc2(AMANDA_DBGDIR, "/");
307 if(mkpdir(dbgdir, 0700, get_client_uid(), get_client_gid()) == -1) {
308 error(_("create debug directory \"%s\": %s"),
309 dbgdir, strerror(errno));
318 * Clean out old debug files. We also rename files with old style
319 * names (XXX.debug or XXX.$PID.debug) into the new name format.
320 * We assume no system has 17 digit PID-s :-) and that there will
321 * not be a conflict between an old and new name.
324 debug_unlink_old(void)
330 struct dirent *entry;
333 size_t test_name_len;
335 char *dbfilename = NULL;
340 assert(dbgdir != NULL);
342 memset(&sbuf, 0, SIZEOF(sbuf));
345 pname_len = strlen(pname);
347 if((d = opendir(dbgdir)) == NULL) {
348 error(_("open debug directory \"%s\": %s"),
349 dbgdir, strerror(errno));
352 test_name = get_debug_name(open_time - (getconf_int(CNF_DEBUG_DAYS) * 24 * 60 * 60), 0);
353 test_name_len = strlen(test_name);
354 while((entry = readdir(d)) != NULL) {
355 if(is_dot_or_dotdot(entry->d_name)) {
358 d_name_len = strlen(entry->d_name);
359 if(strncmp(entry->d_name, pname, pname_len) != 0
360 || entry->d_name[pname_len] != '.'
362 || strcmp(entry->d_name + d_name_len - 6, ".debug") != 0) {
363 continue; /* not one of our debug files */
365 e = newvstralloc(e, dbgdir, entry->d_name, NULL);
366 if(d_name_len < test_name_len) {
368 * Create a "pretend" name based on the last modification
369 * time. This name will be used to decide if the real name
370 * should be removed. If not, it will be used to rename the
373 if(stat(e, &sbuf) != 0) {
374 continue; /* ignore errors */
377 dbfilename = get_debug_name((time_t)sbuf.st_mtime, 0);
380 dbfilename = newstralloc(dbfilename, entry->d_name);
383 if(strcmp(dbfilename, test_name) < 0) {
384 (void) unlink(e); /* get rid of old file */
389 while(dbfilename != NULL
390 && (s = newvstralloc(s, dbgdir, dbfilename, NULL)) != NULL
391 && rename(e, s) != 0 && errno != ENOENT) {
393 dbfilename = get_debug_name((time_t)sbuf.st_mtime, ++i);
395 if(dbfilename == NULL) {
396 error(_("cannot rename old debug file \"%s\""), entry->d_name);
408 /* Given an already-opened debug file, set the file's ownership
409 * appropriately, move its file descriptor above MIN_DB_FD, and
410 * add an initial log entry to the file.
412 * This function records the file's identity in the globals
413 * db_filename, db_fd, and db_file. It does *not* set db_name.
414 * db_file is not set if fd is -1
416 * This function uses the global 'open_time', which is set by
419 * @param s: the filename of the debug file; string should be malloc'd,
420 * and should *not* be freed by the caller.
421 * @param fd: the descriptor connected to the debug file, or -1 if
422 * no decriptor moving should take place.
423 * @param annotation: an extra string to include in the initial
433 int fd_close[MIN_DB_FD+1];
439 /* If we're root, change the ownership of the debug files. If we're not root,
440 * this would either be redundant or an error. */
441 if (geteuid() == 0) {
442 if (chown(db_filename, get_client_uid(), get_client_gid()) < 0) {
443 dbprintf(_("chown(%s, %d, %d) failed: %s"),
444 db_filename, (int)get_client_uid(), (int)get_client_gid(), strerror(errno));
449 * Move the file descriptor up high so it stays out of the way
450 * of other processing, e.g. sendbackup.
455 while((db_fd = dup(fd)) < MIN_DB_FD) {
456 fd_close[i++] = db_fd;
461 db_file = fdopen(db_fd, "a");
466 * Make the first debug log file entry.
468 debug_printf(_("pid %ld ruid %ld euid %ld version %s: %s at %s"),
470 (long)getuid(), (long)geteuid(),
477 /* Get current GMT time and return a message timestamp.
478 * Used for g_printf calls to logs and such. The return value
479 * is to a static buffer, so it should be used immediately.
481 * @returns: timestamp
486 static char timestamp[128];
491 ctime_r(&curtime, timestamp);
492 r = strchr(timestamp, '\n');
499 /* Get current GMT time and return a message timestamp.
500 * Used for g_printf calls to logs and such. The return value
501 * is to a static buffer, so it should be used immediately.
503 * @returns: timestamp
508 static char thread[128];
510 sprintf(thread, "thd-%p", g_thread_self());
516 * ---- public functions
522 debug_setup_logging();
524 /* the scriptutil context does not create a debug log, since such
525 * processes are invoked many times.
527 if (get_pcontext() != CONTEXT_SCRIPTUTIL) {
528 debug_open(get_ptype());
533 debug_open(char *subdir)
540 /* create AMANDA_TMPDIR */
541 make_amanda_tmpdir();
543 /* set up logging while we're here */
544 debug_setup_logging();
546 /* set 'dbgdir' and clean out old debug files */
547 debug_setup_1(NULL, subdir);
550 * Create the new file with a unique sequence number.
552 mask = (mode_t)umask((mode_t)0037); /* Allow the group read bit through */
554 /* iteratate through sequence numbers until we find one that
555 * is not already in use */
556 for(i = 0; fd < 0; i++) {
558 if ((db_name = get_debug_name(open_time, i)) == NULL) {
559 error(_("Cannot create debug file name in %d tries."), i);
563 if ((s = newvstralloc(s, dbgdir, db_name, NULL)) == NULL) {
564 error(_("Cannot allocate debug file name memory"));
568 if ((fd = open(s, O_WRONLY|O_CREAT|O_EXCL|O_APPEND, 0640)) < 0) {
569 if (errno != EEXIST) {
570 error(_("Cannot create debug file \"%s\": %s"),
577 (void)umask(mask); /* Restore mask */
582 * Note: we release control of the string 's' points to.
584 debug_setup_2(s, fd, "start");
595 if (dbfilename == NULL) {
599 /* set 'dbgdir' and clean out old debug files */
600 debug_setup_1(NULL, NULL);
605 if (*dbfilename == '/') {
606 s = stralloc(dbfilename);
608 s = newvstralloc(s, dbgdir, dbfilename, NULL);
610 if ((fd = open(s, O_RDWR|O_APPEND)) < 0) {
611 error(_("cannot reopen debug file %s"), dbfilename);
618 * Note: we release control of the string 's' points to.
620 debug_setup_2(s, fd, annotation);
636 if (get_pcontext() == CONTEXT_SCRIPTUTIL) {
640 /* Remove old log from source directory */
642 /* set 'dbgdir' and clean out old debug files */
643 debug_setup_1(config, subdir);
644 /* Remove old log from destination directory */
647 s = newvstralloc(s, dbgdir, db_name, NULL);
649 if (strcmp(db_filename, s) == 0) {
654 mask = (mode_t)umask((mode_t)0037);
656 #if defined(__CYGWIN__)
658 * On cygwin, rename will not overwrite an existing file nor
659 * will it rename a file that is open for writing...
661 * Rename file directly. Expect failure if file already exists
662 * or is open by another user.
666 while (rename(db_filename, s) < 0) {
667 if (errno != EEXIST) {
669 * If the failure was not due to the target file name already
670 * existing then we have bigger issues at hand so we keep
673 dbprintf(_("Cannot rename \"%s\" to \"%s\": %s\n"),
674 db_filename, s, strerror(errno));
675 s = newvstralloc(s, db_filename, NULL);
681 * Files already exists:
682 * Continue searching for a unique file name that will work.
685 if ((db_name = get_debug_name(open_time, i++)) == NULL) {
686 dbprintf(_("Cannot create unique debug file name"));
689 s = newvstralloc(s, dbgdir, db_name, NULL);
693 * We need to close and reopen the original file handle to
694 * release control of the original debug file name.
696 if ((fd = open(s, O_WRONLY|O_APPEND, 0640)) >= 0) {
698 * We can safely close the the original log file
699 * since we now have a new working handle.
707 /* check if a file with the same name already exists. */
708 if ((fd = open(s, O_WRONLY|O_CREAT|O_EXCL|O_APPEND, 0640)) < 0) {
709 for(i = 0; fd < 0; i++) {
711 if ((db_name = get_debug_name(open_time, i)) == NULL) {
712 dbprintf(_("Cannot create debug file"));
716 s = newvstralloc(s, dbgdir, db_name, NULL);
717 if ((fd = open(s, O_WRONLY|O_CREAT|O_EXCL|O_APPEND, 0640)) < 0) {
718 if (errno != EEXIST) {
719 dbprintf(_("Cannot create debug file: %s"),
729 if (rename(db_filename, s) == -1) {
730 dbprintf(_("Cannot rename \"%s\" to \"%s\": %s\n"),
731 db_filename, s, strerror(errno));
737 (void)umask(mask); /* Restore mask */
741 * Note: we release control of the string 's' points to.
743 debug_setup_2(s, fd, "rename");
751 if (get_pcontext() == CONTEXT_SCRIPTUTIL) {
758 debug_printf(_("pid %ld finish time %s"), (long)getpid(), ctime(&curtime));
760 if(db_file && fclose(db_file) == EOF) {
761 int save_errno = errno;
763 db_file = NULL; /* prevent recursion */
764 g_fprintf(stderr, _("close debug file: %s"), strerror(save_errno));
774 * Format and write a debug message to the process debug file.
776 printf_arglist_function(void debug_printf, const char *, format)
782 * It is common in the code to call dbprintf to write out
783 * syserrno(errno) and then turn around and try to do something else
784 * with errno (e.g. g_printf() or log()), so we make sure errno goes
785 * back out with the same value it came in with.
790 /* handle the default (stderr) if debug_open hasn't been called yet */
791 if(db_file == NULL && db_fd == 2) {
794 if(db_file != NULL) {
798 if (db_file != stderr)
799 prefix = g_strdup_printf("%s: %s: %s:", msg_timestamp(), msg_thread(), get_pname());
801 prefix = g_strdup_printf("%s:", get_pname());
802 arglist_start(argp, format);
803 text = g_strdup_vprintf(format, argp);
805 fprintf(db_file, "%s %s", prefix, text);
832 debug_dup_stderr_to_debug(void)
834 if(db_fd != -1 && db_fd != STDERR_FILENO)
836 if(dup2(db_fd, STDERR_FILENO) != STDERR_FILENO)
838 error(_("can't redirect stderr to the debug file: %d, %s"), db_fd, strerror(errno));
839 g_assert_not_reached();