diff --git a/changes/enhancement1668 b/changes/enhancement1668 new file mode 100644 index 0000000000..0d9f88fa06 --- /dev/null +++ b/changes/enhancement1668 @@ -0,0 +1,4 @@ + o Minor features: + - Make logging resolution configurable and change default from 1 + millisecond to 1 second. Implements enhancement 1668. + diff --git a/doc/spec/control-spec.txt b/doc/spec/control-spec.txt index 1864666047..2bbcfaec4c 100644 --- a/doc/spec/control-spec.txt +++ b/doc/spec/control-spec.txt @@ -525,9 +525,9 @@ of the form: OptionName SP OptionType [ SP Documentation ] CRLF OptionName = Keyword - OptionType = "Integer" / "TimeInterval" / "DataSize" / "Float" / - "Boolean" / "Time" / "CommaList" / "Dependant" / "Virtual" / - "String" / "LineList" + OptionType = "Integer" / "TimeInterval" / "TimeMsecInterval" / + "DataSize" / "Float" / "Boolean" / "Time" / "CommaList" / + "Dependant" / "Virtual" / "String" / "LineList" Documentation = Text "info/names" diff --git a/doc/tor.1.txt b/doc/tor.1.txt index 42eed6e3dd..5d6a959bea 100644 --- a/doc/tor.1.txt +++ b/doc/tor.1.txt @@ -343,6 +343,10 @@ Other options can be specified either on the command-line (--option on Windows; instead you should use the --service command-line option. (Default: 0) +**LogTimeGranularity** __NUM__:: + Set the resolution of timestamps in Tor's logs to NUM milliseconds. + NUM must be positive and either a divisor or a multiple of 1 second. + (Default: 1 second) **SafeLogging** **0**|**1**|**relay**:: Tor can scrub potentially sensitive strings from log messages (e.g. diff --git a/src/common/log.c b/src/common/log.c index b639e7a781..e507275830 100644 --- a/src/common/log.c +++ b/src/common/log.c @@ -131,6 +131,17 @@ log_set_application_name(const char *name) appname = name ? tor_strdup(name) : NULL; } +/** Log time granularity in milliseconds. */ +static int log_time_granularity = 1; + +/** Define log time granularity for all logs to be granularity_msec + * milliseconds. */ +void +set_log_time_granularity(int granularity_msec) +{ + log_time_granularity = granularity_msec; +} + /** Helper: Write the standard prefix for log lines to a * buf_len character buffer in buf. */ @@ -141,14 +152,22 @@ _log_prefix(char *buf, size_t buf_len, int severity) struct timeval now; struct tm tm; size_t n; - int r; + int r, ms; tor_gettimeofday(&now); t = (time_t)now.tv_sec; + ms = (int)now.tv_usec / 1000; + if (log_time_granularity >= 1000) { + t -= t % (log_time_granularity / 1000); + ms = 0; + } else { + ms -= ((int)now.tv_usec / 1000) % log_time_granularity; + } n = strftime(buf, buf_len, "%b %d %H:%M:%S", tor_localtime_r(&t, &tm)); - r = tor_snprintf(buf+n, buf_len-n, ".%.3i [%s] ", - (int)now.tv_usec / 1000, sev_to_string(severity)); + r = tor_snprintf(buf+n, buf_len-n, ".%.3i [%s] ", ms, + sev_to_string(severity)); + if (r<0) return buf_len-1; else diff --git a/src/common/torlog.h b/src/common/torlog.h index 21219569e3..d119993e87 100644 --- a/src/common/torlog.h +++ b/src/common/torlog.h @@ -138,6 +138,7 @@ void mark_logs_temp(void); void change_callback_log_severity(int loglevelMin, int loglevelMax, log_callback cb); void log_set_application_name(const char *name); +void set_log_time_granularity(int granularity_msec); /* Outputs a message to stdout */ void tor_log(int severity, log_domain_mask_t domain, const char *format, ...) diff --git a/src/or/config.c b/src/or/config.c index 4f7077153d..1112478946 100644 --- a/src/or/config.c +++ b/src/or/config.c @@ -44,6 +44,8 @@ typedef enum config_type_t { CONFIG_TYPE_FILENAME, /**< A filename: some prefixes get expanded. */ CONFIG_TYPE_UINT, /**< A non-negative integer less than MAX_INT */ CONFIG_TYPE_INTERVAL, /**< A number of seconds, with optional units*/ + CONFIG_TYPE_MSEC_INTERVAL,/**< A number of milliseconds, with optional + * units */ CONFIG_TYPE_MEMUNIT, /**< A number of bytes, with optional units*/ CONFIG_TYPE_DOUBLE, /**< A floating-point value */ CONFIG_TYPE_BOOL, /**< A boolean value, expressed as 0 or 1. */ @@ -291,6 +293,7 @@ static config_var_t _option_vars[] = { OBSOLETE("LinkPadding"), OBSOLETE("LogLevel"), OBSOLETE("LogFile"), + V(LogTimeGranularity, MSEC_INTERVAL, "1 second"), V(LongLivedPorts, CSV, "21,22,706,1863,5050,5190,5222,5223,6667,6697,8300"), VAR("MapAddress", LINELIST, AddressMap, NULL), @@ -556,6 +559,7 @@ static int is_listening_on_low_port(uint16_t port_option, const config_line_t *listen_options); static uint64_t config_parse_memunit(const char *s, int *ok); +static int config_parse_msec_interval(const char *s, int *ok); static int config_parse_interval(const char *s, int *ok); static void init_libevent(const or_options_t *options); static int opt_streq(const char *s1, const char *s2); @@ -1716,6 +1720,18 @@ config_assign_value(config_format_t *fmt, or_options_t *options, break; } + case CONFIG_TYPE_MSEC_INTERVAL: { + i = config_parse_msec_interval(c->value, &ok); + if (!ok) { + tor_asprintf(msg, + "Msec interval '%s %s' is malformed or out of bounds.", + c->key, c->value); + return -1; + } + *(int *)lvalue = i; + break; + } + case CONFIG_TYPE_MEMUNIT: { uint64_t u64 = config_parse_memunit(c->value, &ok); if (!ok) { @@ -2003,6 +2019,7 @@ get_assigned_option(config_format_t *fmt, void *options, escape_val = 0; /* Can't need escape. */ break; case CONFIG_TYPE_INTERVAL: + case CONFIG_TYPE_MSEC_INTERVAL: case CONFIG_TYPE_UINT: /* This means every or_options_t uint or bool element * needs to be an int. Not, say, a uint16_t or char. */ @@ -2230,6 +2247,7 @@ option_clear(config_format_t *fmt, or_options_t *options, config_var_t *var) *(time_t*)lvalue = 0; break; case CONFIG_TYPE_INTERVAL: + case CONFIG_TYPE_MSEC_INTERVAL: case CONFIG_TYPE_UINT: case CONFIG_TYPE_BOOL: *(int*)lvalue = 0; @@ -4324,6 +4342,17 @@ options_init_logs(or_options_t *options, int validate_only) options->RunAsDaemon; #endif + if (options->LogTimeGranularity > 0 && + (1000 % options->LogTimeGranularity == 0 || + options->LogTimeGranularity % 1000 == 0)) { + set_log_time_granularity(options->LogTimeGranularity); + } else { + log_warn(LD_CONFIG, "Log time granularity '%d' has to be positive " + "and either a divisor or a multiple of 1 second.", + options->LogTimeGranularity); + return -1; + } + ok = 1; elts = smartlist_create(); @@ -4812,6 +4841,26 @@ static struct unit_table_t time_units[] = { { NULL, 0 }, }; +/** Table to map the names of time units to the number of milliseconds + * they contain. */ +static struct unit_table_t time_msec_units[] = { + { "", 1 }, + { "msec", 1 }, + { "millisecond", 1 }, + { "milliseconds", 1 }, + { "second", 1000 }, + { "seconds", 1000 }, + { "minute", 60*1000 }, + { "minutes", 60*1000 }, + { "hour", 60*60*1000 }, + { "hours", 60*60*1000 }, + { "day", 24*60*60*1000 }, + { "days", 24*60*60*1000 }, + { "week", 7*24*60*60*1000 }, + { "weeks", 7*24*60*60*1000 }, + { NULL, 0 }, +}; + /** Parse a string val containing a number, zero or more * spaces, and an optional unit string. If the unit appears in the * table u, then multiply the number by the unit multiplier. @@ -4875,6 +4924,25 @@ config_parse_memunit(const char *s, int *ok) return u; } +/** Parse a string in the format "number unit", where unit is a unit of + * time in milliseconds. On success, set *ok to true and return + * the number of milliseconds in the provided interval. Otherwise, set + * *ok to 0 and return -1. */ +static int +config_parse_msec_interval(const char *s, int *ok) +{ + uint64_t r; + r = config_parse_units(s, time_msec_units, ok); + if (!ok) + return -1; + if (r > INT_MAX) { + log_warn(LD_CONFIG, "Msec interval '%s' is too long", s); + *ok = 0; + return -1; + } + return (int)r; +} + /** Parse a string in the format "number unit", where unit is a unit of time. * On success, set *ok to true and return the number of seconds in * the provided interval. Otherwise, set *ok to 0 and return -1. @@ -5264,6 +5332,7 @@ getinfo_helper_config(control_connection_t *conn, case CONFIG_TYPE_FILENAME: type = "Filename"; break; case CONFIG_TYPE_UINT: type = "Integer"; break; case CONFIG_TYPE_INTERVAL: type = "TimeInterval"; break; + case CONFIG_TYPE_MSEC_INTERVAL: type = "TimeMsecInterval"; break; case CONFIG_TYPE_MEMUNIT: type = "DataSize"; break; case CONFIG_TYPE_DOUBLE: type = "Float"; break; case CONFIG_TYPE_BOOL: type = "Boolean"; break; diff --git a/src/or/or.h b/src/or/or.h index 673a3920cf..01365381fc 100644 --- a/src/or/or.h +++ b/src/or/or.h @@ -2409,6 +2409,7 @@ typedef struct { config_line_t *Logs; /**< New-style list of configuration lines * for logs */ + int LogTimeGranularity; /**< Log resolution in milliseconds. */ char *DebugLogFile; /**< Where to send verbose log messages. */ char *DataDirectory; /**< OR only: where to store long-term data. */