1 /* Copyright (c) 2001, Matej Pfajfar.
2 * Copyright (c) 2001-2004, Roger Dingledine.
3 * Copyright (c) 2004-2006, Roger Dingledine, Nick Mathewson.
4 * Copyright (c) 2007-2010, The Tor Project, Inc. */
5 /* See LICENSE for licensing information */
9 * \brief Functions to send messages to log files or the console.
18 #ifdef HAVE_SYS_TIME_H
27 #ifdef HAVE_SYS_TYPES_H
28 #include <sys/types.h>
37 #include "container.h"
39 #define TRUNCATED_STR "[...truncated]"
40 #define TRUNCATED_STR_LEN 14
42 /** Information for a single logfile; only used in log.c */
43 typedef struct logfile_t
{
44 struct logfile_t
*next
; /**< Next logfile_t in the linked list. */
45 char *filename
; /**< Filename to open. */
46 int fd
; /**< fd to receive log messages, or -1 for none. */
47 int seems_dead
; /**< Boolean: true if the stream seems to be kaput. */
48 int needs_close
; /**< Boolean: true if the stream gets closed on shutdown. */
49 int is_temporary
; /**< Boolean: close after initializing logging subsystem.*/
50 int is_syslog
; /**< Boolean: send messages to syslog. */
51 log_callback callback
; /**< If not NULL, send messages to this function. */
52 log_severity_list_t
*severities
; /**< Which severity of messages should we
53 * log for each log domain? */
56 static void log_free(logfile_t
*victim
);
58 /** Helper: map a log severity to descriptive string. */
59 static INLINE
const char *
60 sev_to_string(int severity
)
63 case LOG_DEBUG
: return "debug";
64 case LOG_INFO
: return "info";
65 case LOG_NOTICE
: return "notice";
66 case LOG_WARN
: return "warn";
67 case LOG_ERR
: return "err";
68 default: /* Call assert, not tor_assert, since tor_assert
69 * calls log on failure. */
70 assert(0); return "UNKNOWN";
74 /** Helper: decide whether to include the function name in the log message. */
76 should_log_function_name(log_domain_mask_t domain
, int severity
)
81 /* All debugging messages occur in interesting places. */
86 /* We care about places where bugs occur. */
87 return (domain
== LD_BUG
);
89 /* Call assert, not tor_assert, since tor_assert calls log on failure. */
94 /** A mutex to guard changes to logfiles and logging. */
95 static tor_mutex_t log_mutex
;
96 static int log_mutex_initialized
= 0;
98 /** Linked list of logfile_t. */
99 static logfile_t
*logfiles
= NULL
;
101 /** The number of open syslog log handlers that we have. When this reaches 0,
102 * we can close our connection to the syslog facility. */
103 static int syslog_count
= 0;
106 #define LOCK_LOGS() STMT_BEGIN \
107 tor_mutex_acquire(&log_mutex); \
109 #define UNLOCK_LOGS() STMT_BEGIN tor_mutex_release(&log_mutex); STMT_END
111 /** What's the lowest log level anybody cares about? Checking this lets us
112 * bail out early from log_debug if we aren't debugging. */
113 int _log_global_min_severity
= LOG_NOTICE
;
115 static void delete_log(logfile_t
*victim
);
116 static void close_log(logfile_t
*victim
);
118 /** Name of the application: used to generate the message we write at the
119 * start of each new log. */
120 static char *appname
= NULL
;
122 /** Set the "application name" for the logs to <b>name</b>: we'll use this
123 * name in the message we write when starting up, and at the start of each new
126 * Tor uses this string to write the version number to the log file. */
128 log_set_application_name(const char *name
)
131 appname
= name
? tor_strdup(name
) : NULL
;
134 /** Helper: Write the standard prefix for log lines to a
135 * <b>buf_len</b> character buffer in <b>buf</b>.
138 _log_prefix(char *buf
, size_t buf_len
, int severity
)
146 tor_gettimeofday(&now
);
147 t
= (time_t)now
.tv_sec
;
149 n
= strftime(buf
, buf_len
, "%b %d %H:%M:%S", tor_localtime_r(&t
, &tm
));
150 r
= tor_snprintf(buf
+n
, buf_len
-n
, ".%.3i [%s] ",
151 (int)now
.tv_usec
/ 1000, sev_to_string(severity
));
158 /** If lf refers to an actual file that we have just opened, and the file
159 * contains no data, log an "opening new logfile" message at the top.
161 * Return -1 if the log is broken and needs to be deleted, else return 0.
164 log_tor_version(logfile_t
*lf
, int reset
)
170 if (!lf
->needs_close
)
171 /* If it doesn't get closed, it isn't really a file. */
173 if (lf
->is_temporary
)
174 /* If it's temporary, it isn't really a file. */
177 is_new
= lf
->fd
>= 0 && tor_fd_getpos(lf
->fd
) == 0;
179 if (reset
&& !is_new
)
180 /* We are resetting, but we aren't at the start of the file; no
181 * need to log again. */
183 n
= _log_prefix(buf
, sizeof(buf
), LOG_NOTICE
);
185 tor_snprintf(buf
+n
, sizeof(buf
)-n
,
186 "%s opening %slog file.\n", appname
, is_new
?"new ":"");
188 tor_snprintf(buf
+n
, sizeof(buf
)-n
,
189 "Tor %s opening %slog file.\n", VERSION
, is_new
?"new ":"");
191 if (write_all(lf
->fd
, buf
, strlen(buf
), 0) < 0) /* error */
192 return -1; /* failed */
196 /** Helper: Format a log message into a fixed-sized buffer. (This is
197 * factored out of <b>logv</b> so that we never format a message more
198 * than once.) Return a pointer to the first character of the message
199 * portion of the formatted string.
202 format_msg(char *buf
, size_t buf_len
,
203 log_domain_mask_t domain
, int severity
, const char *funcname
,
204 const char *format
, va_list ap
, size_t *msg_len_out
)
210 assert(buf_len
>= 2); /* prevent integer underflow */
211 buf_len
-= 2; /* subtract 2 characters so we have room for \n\0 */
213 n
= _log_prefix(buf
, buf_len
, severity
);
214 end_of_prefix
= buf
+n
;
216 if (funcname
&& should_log_function_name(domain
, severity
)) {
217 r
= tor_snprintf(buf
+n
, buf_len
-n
, "%s(): ", funcname
);
224 if (domain
== LD_BUG
&& buf_len
-n
> 6) {
225 memcpy(buf
+n
, "Bug: ", 6);
229 r
= tor_vsnprintf(buf
+n
,buf_len
-n
,format
,ap
);
231 /* The message was too long; overwrite the end of the buffer with
232 * "[...truncated]" */
233 if (buf_len
>= TRUNCATED_STR_LEN
) {
234 size_t offset
= buf_len
-TRUNCATED_STR_LEN
;
235 /* We have an extra 2 characters after buf_len to hold the \n\0,
236 * so it's safe to add 1 to the size here. */
237 strlcpy(buf
+offset
, TRUNCATED_STR
, buf_len
-offset
+1);
239 /* Set 'n' to the end of the buffer, where we'll be writing \n\0.
240 * Since we already subtracted 2 from buf_len, this is safe.*/
248 return end_of_prefix
;
251 /** Helper: sends a message to the appropriate logfiles, at loglevel
252 * <b>severity</b>. If provided, <b>funcname</b> is prepended to the
253 * message. The actual message is derived as from tor_snprintf(format,ap).
256 logv(int severity
, log_domain_mask_t domain
, const char *funcname
,
257 const char *format
, va_list ap
)
263 char *end_of_prefix
=NULL
;
265 /* Call assert, not tor_assert, since tor_assert calls log on failure. */
267 /* check that severity is sane. Overrunning the masks array leads to
268 * interesting and hard to diagnose effects */
269 assert(severity
>= LOG_ERR
&& severity
<= LOG_DEBUG
);
273 if (! (lf
->severities
->masks
[SEVERITY_MASK_IDX(severity
)] & domain
)) {
277 if (! (lf
->fd
>= 0 || lf
->is_syslog
|| lf
->callback
)) {
281 if (lf
->seems_dead
) {
288 format_msg(buf
, sizeof(buf
), domain
, severity
, funcname
, format
, ap
,
294 char *m
= end_of_prefix
;
296 /* Some syslog implementations have limits on the length of what you can
297 * pass them, and some very old ones do not detect overflow so well.
298 * Regrettably, they call their maximum line length MAXLINE. */
300 #warn "MAXLINE is a very low number; it might not be from syslog.h after all"
302 if (msg_len
>= MAXLINE
)
303 m
= tor_strndup(end_of_prefix
, MAXLINE
-1);
305 syslog(severity
, "%s", m
);
307 if (m
!= end_of_prefix
) {
314 } else if (lf
->callback
) {
315 lf
->callback(severity
, domain
, end_of_prefix
);
319 if (write_all(lf
->fd
, buf
, msg_len
, 0) < 0) { /* error */
320 /* don't log the error! mark this log entry to be blown away, and
329 /** Output a message to the log. */
331 tor_log(int severity
, log_domain_mask_t domain
, const char *format
, ...)
334 if (severity
> _log_global_min_severity
)
337 logv(severity
, domain
, NULL
, format
, ap
);
341 /** Output a message to the log, prefixed with a function name <b>fn</b>. */
344 _log_fn(int severity
, log_domain_mask_t domain
, const char *fn
,
345 const char *format
, ...)
348 if (severity
> _log_global_min_severity
)
351 logv(severity
, domain
, fn
, format
, ap
);
355 const char *_log_fn_function_name
=NULL
;
357 _log_fn(int severity
, log_domain_mask_t domain
, const char *format
, ...)
360 if (severity
> _log_global_min_severity
)
363 logv(severity
, domain
, _log_fn_function_name
, format
, ap
);
365 _log_fn_function_name
= NULL
;
368 _log_debug(log_domain_mask_t domain
, const char *format
, ...)
371 /* For GCC we do this check in the macro. */
372 if (PREDICT_LIKELY(LOG_DEBUG
> _log_global_min_severity
))
375 logv(LOG_DEBUG
, domain
, _log_fn_function_name
, format
, ap
);
377 _log_fn_function_name
= NULL
;
380 _log_info(log_domain_mask_t domain
, const char *format
, ...)
383 if (LOG_INFO
> _log_global_min_severity
)
386 logv(LOG_INFO
, domain
, _log_fn_function_name
, format
, ap
);
388 _log_fn_function_name
= NULL
;
391 _log_notice(log_domain_mask_t domain
, const char *format
, ...)
394 if (LOG_NOTICE
> _log_global_min_severity
)
397 logv(LOG_NOTICE
, domain
, _log_fn_function_name
, format
, ap
);
399 _log_fn_function_name
= NULL
;
402 _log_warn(log_domain_mask_t domain
, const char *format
, ...)
405 if (LOG_WARN
> _log_global_min_severity
)
408 logv(LOG_WARN
, domain
, _log_fn_function_name
, format
, ap
);
410 _log_fn_function_name
= NULL
;
413 _log_err(log_domain_mask_t domain
, const char *format
, ...)
416 if (LOG_ERR
> _log_global_min_severity
)
419 logv(LOG_ERR
, domain
, _log_fn_function_name
, format
, ap
);
421 _log_fn_function_name
= NULL
;
425 /** Free all storage held by <b>victim</b>. */
427 log_free(logfile_t
*victim
)
431 tor_free(victim
->severities
);
432 tor_free(victim
->filename
);
436 /** Close all open log files, and free other static memory. */
440 logfile_t
*victim
, *next
;
453 /* We _could_ destroy the log mutex here, but that would screw up any logs
454 * that happened between here and the end of execution. */
457 /** Remove and free the log entry <b>victim</b> from the linked-list
458 * logfiles (it is probably present, but it might not be due to thread
459 * racing issues). After this function is called, the caller shouldn't
460 * refer to <b>victim</b> anymore.
462 * Long-term, we need to do something about races in the log subsystem
463 * in general. See bug 222 for more details.
466 delete_log(logfile_t
*victim
)
469 if (victim
== logfiles
)
470 logfiles
= victim
->next
;
472 for (tmpl
= logfiles
; tmpl
&& tmpl
->next
!= victim
; tmpl
=tmpl
->next
) ;
474 // tor_assert(tmpl->next == victim);
477 tmpl
->next
= victim
->next
;
482 /** Helper: release system resources (but not memory) held by a single
485 close_log(logfile_t
*victim
)
487 if (victim
->needs_close
&& victim
->fd
>= 0) {
490 } else if (victim
->is_syslog
) {
492 if (--syslog_count
== 0) {
493 /* There are no other syslogs; close the logging facility. */
500 /** Adjust a log severity configuration in <b>severity_out</b> to contain
501 * every domain between <b>loglevelMin</b> and <b>loglevelMax</b>, inclusive.
504 set_log_severity_config(int loglevelMin
, int loglevelMax
,
505 log_severity_list_t
*severity_out
)
508 tor_assert(loglevelMin
>= loglevelMax
);
509 tor_assert(loglevelMin
>= LOG_ERR
&& loglevelMin
<= LOG_DEBUG
);
510 tor_assert(loglevelMax
>= LOG_ERR
&& loglevelMax
<= LOG_DEBUG
);
511 memset(severity_out
, 0, sizeof(log_severity_list_t
));
512 for (i
= loglevelMin
; i
>= loglevelMax
; --i
) {
513 severity_out
->masks
[SEVERITY_MASK_IDX(i
)] = ~0u;
517 /** Add a log handler named <b>name</b> to send all messages in <b>severity</b>
518 * to <b>fd</b>. Copies <b>severity</b>. Helper: does no locking. */
520 add_stream_log_impl(const log_severity_list_t
*severity
,
521 const char *name
, int fd
)
524 lf
= tor_malloc_zero(sizeof(logfile_t
));
526 lf
->filename
= tor_strdup(name
);
527 lf
->severities
= tor_memdup(severity
, sizeof(log_severity_list_t
));
531 _log_global_min_severity
= get_min_log_level();
534 /** Add a log handler named <b>name</b> to send all messages in <b>severity</b>
535 * to <b>fd</b>. Steals a reference to <b>severity</b>; the caller must
536 * not use it after calling this function. */
538 add_stream_log(const log_severity_list_t
*severity
,
539 const char *name
, int fd
)
542 add_stream_log_impl(severity
, name
, fd
);
546 /** Initialize the global logging facility */
550 if (!log_mutex_initialized
) {
551 tor_mutex_init(&log_mutex
);
552 log_mutex_initialized
= 1;
556 /** Add a log handler to receive messages during startup (before the real
557 * logs are initialized).
560 add_temp_log(int min_severity
)
562 log_severity_list_t
*s
= tor_malloc_zero(sizeof(log_severity_list_t
));
563 set_log_severity_config(min_severity
, LOG_ERR
, s
);
565 add_stream_log_impl(s
, "<temp>", fileno(stdout
));
567 logfiles
->is_temporary
= 1;
572 * Add a log handler to send messages in <b>severity</b>
573 * to the function <b>cb</b>.
576 add_callback_log(const log_severity_list_t
*severity
, log_callback cb
)
579 lf
= tor_malloc_zero(sizeof(logfile_t
));
581 lf
->severities
= tor_memdup(severity
, sizeof(log_severity_list_t
));
582 lf
->filename
= tor_strdup("<callback>");
588 _log_global_min_severity
= get_min_log_level();
593 /** Adjust the configured severity of any logs whose callback function is
596 change_callback_log_severity(int loglevelMin
, int loglevelMax
,
600 log_severity_list_t severities
;
601 set_log_severity_config(loglevelMin
, loglevelMax
, &severities
);
603 for (lf
= logfiles
; lf
; lf
= lf
->next
) {
604 if (lf
->callback
== cb
) {
605 memcpy(lf
->severities
, &severities
, sizeof(severities
));
608 _log_global_min_severity
= get_min_log_level();
612 /** Close any log handlers added by add_temp_log() or marked by
613 * mark_logs_temp(). */
615 close_temp_logs(void)
620 for (p
= &logfiles
; *p
; ) {
621 if ((*p
)->is_temporary
) {
623 /* we use *p here to handle the edge case of the head of the list */
632 _log_global_min_severity
= get_min_log_level();
636 /** Make all currently temporary logs (set to be closed by close_temp_logs)
637 * live again, and close all non-temporary logs. */
639 rollback_log_changes(void)
643 for (lf
= logfiles
; lf
; lf
= lf
->next
)
644 lf
->is_temporary
= ! lf
->is_temporary
;
649 /** Configure all log handles to be closed by close_temp_logs(). */
655 for (lf
= logfiles
; lf
; lf
= lf
->next
)
656 lf
->is_temporary
= 1;
661 * Add a log handler to send messages to <b>filename</b>. If opening the
662 * logfile fails, -1 is returned and errno is set appropriately (by open(2)).
665 add_file_log(const log_severity_list_t
*severity
, const char *filename
)
670 fd
= open(filename
, O_WRONLY
|O_CREAT
|O_APPEND
, 0644);
673 if (tor_fd_seekend(fd
)<0)
677 add_stream_log_impl(severity
, filename
, fd
);
678 logfiles
->needs_close
= 1;
680 _log_global_min_severity
= get_min_log_level();
682 if (log_tor_version(lf
, 0) < 0) {
692 * Add a log handler to send messages to they system log facility.
695 add_syslog_log(const log_severity_list_t
*severity
)
698 if (syslog_count
++ == 0)
699 /* This is the first syslog. */
700 openlog("Tor", LOG_PID
| LOG_NDELAY
, LOGFACILITY
);
702 lf
= tor_malloc_zero(sizeof(logfile_t
));
704 lf
->severities
= tor_memdup(severity
, sizeof(log_severity_list_t
));
705 lf
->filename
= tor_strdup("<syslog>");
712 _log_global_min_severity
= get_min_log_level();
718 /** If <b>level</b> is a valid log severity, return the corresponding
719 * numeric value. Otherwise, return -1. */
721 parse_log_level(const char *level
)
723 if (!strcasecmp(level
, "err"))
725 if (!strcasecmp(level
, "warn"))
727 if (!strcasecmp(level
, "notice"))
729 if (!strcasecmp(level
, "info"))
731 if (!strcasecmp(level
, "debug"))
736 /** Return the string equivalent of a given log level. */
738 log_level_to_string(int level
)
740 return sev_to_string(level
);
743 /** NULL-terminated array of names for log domains such that domain_list[dom]
744 * is a description of <b>dom</b>. */
745 static const char *domain_list
[] = {
746 "GENERAL", "CRYPTO", "NET", "CONFIG", "FS", "PROTOCOL", "MM",
747 "HTTP", "APP", "CONTROL", "CIRC", "REND", "BUG", "DIR", "DIRSERV",
748 "OR", "EDGE", "ACCT", "HIST", "HANDSHAKE", NULL
751 /** Return a bitmask for the log domain for which <b>domain</b> is the name,
752 * or 0 if there is no such name. */
753 static log_domain_mask_t
754 parse_log_domain(const char *domain
)
757 for (i
=0; domain_list
[i
]; ++i
) {
758 if (!strcasecmp(domain
, domain_list
[i
]))
764 /** Translate a bitmask of log domains to a string, or NULL if the bitmask
767 domain_to_string(log_domain_mask_t domain
)
769 int bit
= tor_log2(domain
);
770 if ((bit
== 0 && domain
== 0) || bit
>= N_LOGGING_DOMAINS
)
772 return domain_list
[bit
];
776 /** Parse a log severity pattern in *<b>cfg_ptr</b>. Advance cfg_ptr after
777 * the end of the severityPattern. Set the value of <b>severity_out</b> to
778 * the parsed pattern. Return 0 on success, -1 on failure.
780 * The syntax for a SeverityPattern is:
782 * SeverityPattern = *(DomainSeverity SP)* DomainSeverity
783 * DomainSeverity = (DomainList SP)? SeverityRange
784 * SeverityRange = MinSeverity ("-" MaxSeverity )?
785 * DomainList = "[" (SP? DomainSpec SP? ",") SP? DomainSpec "]"
786 * DomainSpec = "*" | Domain | "~" Domain
788 * A missing MaxSeverity defaults to ERR. Severities and domains are
789 * case-insensitive. "~" indicates negation for a domain; negation happens
790 * last inside a DomainList. Only one SeverityRange without a DomainList is
794 parse_log_severity_config(const char **cfg_ptr
,
795 log_severity_list_t
*severity_out
)
797 const char *cfg
= *cfg_ptr
;
798 int got_anything
= 0;
799 int got_an_unqualified_range
= 0;
800 memset(severity_out
, 0, sizeof(*severity_out
));
802 cfg
= eat_whitespace(cfg
);
804 const char *dash
, *space
;
805 char *sev_lo
, *sev_hi
;
807 log_domain_mask_t domains
= ~0u;
812 smartlist_t
*domains_list
;
813 log_domain_mask_t neg_domains
= 0;
814 const char *closebracket
= strchr(cfg
, ']');
818 domains_str
= tor_strndup(cfg
+1, closebracket
-cfg
-1);
819 domains_list
= smartlist_create();
820 smartlist_split_string(domains_list
, domains_str
, ",", SPLIT_SKIP_SPACE
,
822 tor_free(domains_str
);
823 SMARTLIST_FOREACH(domains_list
, const char *, domain
,
825 if (!strcmp(domain
, "*")) {
830 if (*domain
== '~') {
834 d
= parse_log_domain(domain
);
836 log_warn(LD_CONFIG
, "No such logging domain as %s", domain
);
846 SMARTLIST_FOREACH(domains_list
, char *, d
, tor_free(d
));
847 smartlist_free(domains_list
);
850 domains
&= ~neg_domains
;
851 cfg
= eat_whitespace(closebracket
+1);
853 ++got_an_unqualified_range
;
855 if (!strcasecmpstart(cfg
, "file") ||
856 !strcasecmpstart(cfg
, "stderr") ||
857 !strcasecmpstart(cfg
, "stdout") ||
858 !strcasecmpstart(cfg
, "syslog")) {
861 if (got_an_unqualified_range
> 1)
864 space
= strchr(cfg
, ' ');
865 dash
= strchr(cfg
, '-');
867 space
= strchr(cfg
, '\0');
868 if (dash
&& dash
< space
) {
869 sev_lo
= tor_strndup(cfg
, dash
-cfg
);
870 sev_hi
= tor_strndup(dash
+1, space
-(dash
+1));
872 sev_lo
= tor_strndup(cfg
, space
-cfg
);
873 sev_hi
= tor_strdup("ERR");
875 low
= parse_log_level(sev_lo
);
876 high
= parse_log_level(sev_hi
);
885 for (i
=low
; i
>= high
; --i
)
886 severity_out
->masks
[SEVERITY_MASK_IDX(i
)] |= domains
;
888 cfg
= eat_whitespace(space
);
893 return got_anything
? 0 : -1;
896 /** Return the least severe log level that any current log is interested in. */
898 get_min_log_level(void)
903 for (lf
= logfiles
; lf
; lf
= lf
->next
) {
904 for (i
= LOG_DEBUG
; i
> min
; --i
)
905 if (lf
->severities
->masks
[SEVERITY_MASK_IDX(i
)])
911 /** Switch all logs to output at most verbose level. */
913 switch_logs_debug(void)
918 for (lf
= logfiles
; lf
; lf
=lf
->next
) {
919 for (i
= LOG_DEBUG
; i
>= LOG_ERR
; --i
)
920 lf
->severities
->masks
[SEVERITY_MASK_IDX(i
)] = ~0u;
922 _log_global_min_severity
= get_min_log_level();
928 dump_log_info(logfile_t
*lf
)
933 printf("=== log into \"%s\" (%s-%s) (%stemporary)\n", lf
->filename
,
934 sev_to_string(lf
->min_loglevel
),
935 sev_to_string(lf
->max_loglevel
),
936 lf
->is_temporary
?"":"not ");
937 } else if (lf
->is_syslog
) {
938 printf("=== syslog (%s-%s) (%stemporary)\n",
939 sev_to_string(lf
->min_loglevel
),
940 sev_to_string(lf
->max_loglevel
),
941 lf
->is_temporary
?"":"not ");
943 printf("=== log (%s-%s) (%stemporary)\n",
944 sev_to_string(lf
->min_loglevel
),
945 sev_to_string(lf
->max_loglevel
),
946 lf
->is_temporary
?"":"not ");
954 printf("==== BEGIN LOGS ====\n");
955 for (lf
= logfiles
; lf
; lf
= lf
->next
)
957 printf("==== END LOGS ====\n");