summaryrefslogtreecommitdiff
diff options
context:
space:
mode:
Diffstat
-rw-r--r--doc/doc-docbook/spec.xfpt9
-rw-r--r--doc/doc-txt/NewStuff2
-rw-r--r--src/OS/Makefile-Base6
-rw-r--r--src/src/exigrep.src6
-rw-r--r--src/src/eximstats.src36
-rw-r--r--src/src/globals.c1
-rw-r--r--src/src/log.c54
-rw-r--r--src/src/macros.h1
-rw-r--r--src/src/tod.c254
-rw-r--r--test/log/05516
-rwxr-xr-xtest/runtest3
-rw-r--r--test/scripts/0000-Basic/05514
-rw-r--r--test/stdout/05516
13 files changed, 207 insertions, 181 deletions
diff --git a/doc/doc-docbook/spec.xfpt b/doc/doc-docbook/spec.xfpt
index 84540508f..a4b1926ec 100644
--- a/doc/doc-docbook/spec.xfpt
+++ b/doc/doc-docbook/spec.xfpt
@@ -36118,6 +36118,7 @@ selection marked by asterisks:
&` incoming_interface `& local interface on <= and => lines
&` incoming_port `& remote port on <= lines
&`*lost_incoming_connection `& as it says (includes timeouts)
+&` millisec `& millisecond timestamps
&` outgoing_interface `& local interface on => lines
&` outgoing_port `& add remote port to => lines
&`*queue_run `& start and end queue runs
@@ -36282,6 +36283,14 @@ important with the widening use of NAT (see RFC 2505).
&%lost_incoming_connection%&: A log line is written when an incoming SMTP
connection is unexpectedly dropped.
.next
+.new
+.cindex "log" "millisecond timestamps"
+.cindex millisecond logging
+.cindex timstamps "millisecond, in logs"
+&%millisec%&: Timestamps have a period and three decimal places of finer granularity
+appended to the seconds value.
+.wen
+.next
.cindex "log" "outgoing interface"
.cindex "log" "local interface"
.cindex "log" "local address and port"
diff --git a/doc/doc-txt/NewStuff b/doc/doc-txt/NewStuff
index f3050a950..ea757f059 100644
--- a/doc/doc-txt/NewStuff
+++ b/doc/doc-txt/NewStuff
@@ -44,6 +44,8 @@ Version 4.90
10. Variable $smtp_command_history returning a comma-sep list of recent
SMTP commands.
+11. Millisecond timetamps in logs, on log_selector "millisec".
+
Version 4.89
------------
diff --git a/src/OS/Makefile-Base b/src/OS/Makefile-Base
index 11f4dad0c..b4345e86f 100644
--- a/src/OS/Makefile-Base
+++ b/src/OS/Makefile-Base
@@ -487,7 +487,7 @@ OBJ_MONBIN = util-spool_in.o \
util-store.o \
util-string.o \
util-queue.o \
- tod.o \
+ util-tod.o \
tree.o \
$(MONBIN)
@@ -614,6 +614,10 @@ util-queue.o: $(HDRS) queue.c
@echo "$(CC) -DCOMPILE_UTILITY queue.c"
$(FE)$(CC) -c $(CFLAGS) $(INCLUDE) -DCOMPILE_UTILITY -o util-queue.o queue.c
+util-tod.o: $(HDRS) tod.c
+ @echo "$(CC) -DCOMPILE_UTILITY tod.c"
+ $(FE)$(CC) -c $(CFLAGS) $(INCLUDE) -DCOMPILE_UTILITY -o util-tod.o tod.c
+
util-os.o: $(HDRS) os.c
@echo "$(CC) -DCOMPILE_UTILITY os.c"
$(FE)$(CC) -c $(CFLAGS) $(INCLUDE) \
diff --git a/src/src/exigrep.src b/src/src/exigrep.src
index 851ca63bb..1899267be 100644
--- a/src/src/exigrep.src
+++ b/src/src/exigrep.src
@@ -45,7 +45,7 @@ use POSIX qw(mktime);
sub seconds {
my($year,$month,$day,$hour,$min,$sec,$tzs,$tzh,$tzm) =
- $_[0] =~ /^(\d{4})-(\d\d)-(\d\d)\s(\d\d):(\d\d):(\d\d)(?>\s([+-])(\d\d)(\d\d))?/o;
+ $_[0] =~ /^(\d{4})-(\d\d)-(\d\d)\s(\d\d):(\d\d):(\d\d)(?:.\d+)?(?>\s([+-])(\d\d)(\d\d))?/o;
my $seconds = mktime $sec, $min, $hour, $day, $month - 1, $year - 1900;
@@ -83,7 +83,7 @@ sub do_line {
if (!/^\d{4}-/o) { $_ =~ s/^.*? exim\b.*?: //o; }
return unless
- my($date,$id) = /^(\d{4}-\d\d-\d\d \d\d:\d\d:\d\d (?:[+-]\d{4} )?)(?:\[\d+\] )?(\w{6}\-\w{6}\-\w{2})?/o;
+ my($date,$id) = /^(\d{4}-\d\d-\d\d \d\d:\d\d:\d\d(?:\.\d+)? (?:[+-]\d{4} )?)(?:\[\d+\] )?(\w{6}\-\w{6}\-\w{2})?/o;
# Handle the case when the log line belongs to a specific message. We save
# lines for specific messages until the message is complete. Then either print
@@ -124,7 +124,7 @@ if (defined $id)
if (index($_, 'Completed') != -1 ||
index($_, 'SMTP data timeout') != -1 ||
(index($_, 'rejected') != -1 &&
- /^(\d{4}-\d\d-\d\d \d\d:\d\d:\d\d (?:[+-]\d{4} )?)(?:\[\d+\] )?\w{6}\-\w{6}\-\w{2} rejected/o))
+ /^(\d{4}-\d\d-\d\d \d\d:\d\d:\d\d(?:\.\d+)? (?:[+-]\d{4} )?)(?:\[\d+\] )?\w{6}\-\w{6}\-\w{2} rejected/o))
{
if ($queue_time != -1 &&
$saved{$id} =~ /^(\d{4}-\d\d-\d\d \d\d:\d\d:\d\d ([+-]\d{4} )?)/o)
diff --git a/src/src/eximstats.src b/src/src/eximstats.src
index a2113f106..727ee44b9 100644
--- a/src/src/eximstats.src
+++ b/src/src/eximstats.src
@@ -896,6 +896,7 @@ sub unformat_time {
# POSIX::mktime. We expect the timestamp to be of the form
# "$year-$mon-$day $hour:$min:$sec", with month going from 1 to 12,
# and the year to be absolute (we do the necessary conversions). The
+# seconds value can be followed by decimals, which we ignore. The
# timestamp may be followed with an offset from UTC like "+$hh$mm"; if the
# offset is not present, and we have not been told that the log is in UTC
# (with the -utc option), then we adjust the time by the current local
@@ -919,7 +920,7 @@ sub seconds {
# Is the timestamp the same as the last one?
return $last_time if ($last_timestamp eq $timestamp);
- return 0 unless ($timestamp =~ /^((\d{4})\-(\d\d)-(\d\d))\s(\d\d):(\d\d):(\d\d)( ([+-])(\d\d)(\d\d))?/o);
+ return 0 unless ($timestamp =~ /^((\d{4})\-(\d\d)-(\d\d))\s(\d\d):(\d\d):(\d\d)(?:\.\d+)?( ([+-])(\d\d)(\d\d))?/o);
unless ($last_date eq $1) {
$last_date = $1;
@@ -931,7 +932,7 @@ sub seconds {
my $time = $date_seconds + ($5 * 3600) + ($6 * 60) + $7;
# SC. Use caching. Also note we want seconds not minutes.
- #my($this_offset) = ($10 * 60 + $11) * ($9 . "1") if defined $8;
+ #my($this_offset) = ($10 * 60 + $12) * ($9 . "1") if defined $8;
if (defined $8 && ($8 ne $last_offset)) {
$last_offset = $8;
$offset_seconds = ($10 * 60 + $11) * 60;
@@ -939,7 +940,7 @@ sub seconds {
}
- if (defined $7) {
+ if (defined $8) {
#$time -= $this_offset;
$time -= $offset_seconds;
} elsif (defined $localtime_offset) {
@@ -1853,12 +1854,23 @@ sub generate_parser {
$length = length($_);
next if ($length < 38);
- next unless /^(\\d{4}\\-\\d\\d-\\d\\d\\s(\\d\\d):(\\d\\d):\\d\\d( [-+]\\d\\d\\d\\d)?)( \\[\\d+\\])?/o;
-
- ($tod,$m_hour,$m_min) = ($1,$2,$3);
+ next unless /^
+ (\\d{4}\\-\\d\\d-\\d\\d\\s # 1: YYYYMMDD HHMMSS
+ (\\d\\d) # 2: HH
+ :
+ (\\d\\d) # 3: MM
+ :\\d\\d
+ )
+ (\\.\\d+)? # 4: subseconds
+ (\s[-+]\\d\\d\\d\\d)? # 5: tz-offset
+ (\s\\[\\d+\\])? # 6: pid
+ /ox;
+
+ $tod = defined($5) ? $1 . $5 : $1;
+ ($m_hour,$m_min) = ($2,$3);
# PH - watch for GMT offsets in the timestamp.
- if (defined($4)) {
+ if (defined($5)) {
$extra = 6;
next if ($length < 44);
}
@@ -1866,9 +1878,15 @@ sub generate_parser {
$extra = 0;
}
+ # watch for subsecond precision
+ if (defined($4)) {
+ $extra += length($4);
+ next if ($length < 38 + $extra);
+ }
+
# PH - watch for PID added after the timestamp.
- if (defined($5)) {
- $extra += length($5);
+ if (defined($6)) {
+ $extra += length($6);
next if ($length < 38 + $extra);
}
diff --git a/src/src/globals.c b/src/src/globals.c
index bfb1c2166..8c35c6fe2 100644
--- a/src/src/globals.c
+++ b/src/src/globals.c
@@ -893,6 +893,7 @@ bit_table log_options[] = { /* must be in alphabetical order */
BIT_TABLE(L, incoming_interface),
BIT_TABLE(L, incoming_port),
BIT_TABLE(L, lost_incoming_connection),
+ BIT_TABLE(L, millisec),
BIT_TABLE(L, outgoing_interface),
BIT_TABLE(L, outgoing_port),
BIT_TABLE(L, pid),
diff --git a/src/src/log.c b/src/src/log.c
index 62ee629b0..d12989b6f 100644
--- a/src/src/log.c
+++ b/src/src/log.c
@@ -147,7 +147,7 @@ int linecount = 0;
if (running_in_test_harness) return;
-if (!syslog_timestamp) s += log_timezone? 26 : 20;
+if (!syslog_timestamp) s += log_timezone ? 26 : 20;
if (!syslog_pid && LOGGING(pid))
memmove(s + pid_position[0], s + pid_position[1], pid_position[1] - pid_position[0]);
@@ -223,10 +223,10 @@ Returns: The function does not return
static void
die(uschar *s1, uschar *s2)
{
-if (s1 != NULL)
+if (s1)
{
write_syslog(LOG_CRIT, s1);
- if (debug_file != NULL) debug_printf("%s\n", s1);
+ if (debug_file) debug_printf("%s\n", s1);
if (log_stderr != NULL && log_stderr != debug_file)
fprintf(log_stderr, "%s\n", s1);
}
@@ -272,7 +272,7 @@ if (fd < 0 && errno == ENOENT)
*lastslash = 0;
created = directory_make(NULL, name, LOG_DIRECTORY_MODE, FALSE);
DEBUG(D_any) debug_printf("%s log directory %s\n",
- created? "created" : "failed to create", name);
+ created ? "created" : "failed to create", name);
*lastslash = '/';
if (created) fd = Uopen(name,
#ifdef O_CLOEXEC
@@ -446,10 +446,8 @@ else if (string_datestamp_offset >= 0)
/* If the file name is too long, it is an unrecoverable disaster */
if (!ok)
- {
die(US"exim: log file path too long: aborting",
US"Logging failure; please try later");
- }
/* We now have the file name. Try to open an existing file. After a successful
open, arrange for automatic closure on exec(), and then return. */
@@ -559,10 +557,7 @@ if ((flags & (LOG_CONFIG_FOR & ~LOG_CONFIG)) != 0)
}
if ((flags & (LOG_CONFIG_IN & ~LOG_CONFIG)) != 0)
- {
- sprintf(CS ptr, " in line %d of %s", config_lineno, config_filename);
- while (*ptr) ptr++;
- }
+ ptr += sprintf(CS ptr, " in line %d of %s", config_lineno, config_filename);
Ustrcpy(ptr, ":\n ");
return ptr + 4;
@@ -736,7 +731,7 @@ Returns: nothing
void
log_write(unsigned int selector, int flags, const char *format, ...)
{
-uschar *ptr;
+uschar * ptr;
int length;
int paniclogfd;
ssize_t written_len;
@@ -903,22 +898,17 @@ if (!write_rejectlog) flags &= ~LOG_REJECT;
when called by a utility. */
ptr = log_buffer;
-sprintf(CS ptr, "%s ", tod_stamp(tod_log));
-while(*ptr) ptr++;
+ptr += sprintf(CS ptr, "%s ", tod_stamp(tod_log));
if (LOGGING(pid))
{
- sprintf(CS ptr, "[%d] ", (int)getpid());
if (!syslog_pid) pid_position[0] = ptr - log_buffer; /* remember begin … */
- while (*ptr) ptr++;
+ ptr += sprintf(CS ptr, "[%d] ", (int)getpid());
if (!syslog_pid) pid_position[1] = ptr - log_buffer; /* … and end+1 of the PID */
}
if (really_exim && message_id[0] != 0)
- {
- sprintf(CS ptr, "%s ", message_id);
- while(*ptr) ptr++;
- }
+ ptr += sprintf(CS ptr, "%s ", message_id);
if ((flags & LOG_CONFIG) != 0) ptr = log_config_info(ptr, flags);
@@ -933,10 +923,7 @@ this way because it kind of fits with LOG_RECIPIENTS. */
if ((flags & LOG_SENDER) != 0 &&
ptr < log_buffer + LOG_BUFFER_SIZE - 10 - Ustrlen(raw_sender))
- {
- sprintf(CS ptr, " from <%s>", raw_sender);
- while (*ptr) ptr++;
- }
+ ptr += sprintf(CS ptr, " from <%s>", raw_sender);
/* Add list of recipients to the message if required; the raw list,
before rewriting, was saved in raw_recipients. There may be none, if an ACL
@@ -946,19 +933,16 @@ if ((flags & LOG_RECIPIENTS) != 0 && ptr < log_buffer + LOG_BUFFER_SIZE - 6 &&
raw_recipients_count > 0)
{
int i;
- sprintf(CS ptr, " for");
- while (*ptr) ptr++;
+ ptr += sprintf(CS ptr, " for");
for (i = 0; i < raw_recipients_count; i++)
{
- uschar *s = raw_recipients[i];
+ uschar * s = raw_recipients[i];
if (log_buffer + LOG_BUFFER_SIZE - ptr < Ustrlen(s) + 3) break;
- sprintf(CS ptr, " %s", s);
- while (*ptr) ptr++;
+ ptr += sprintf(CS ptr, " %s", s);
}
}
-sprintf(CS ptr, "\n");
-while(*ptr) ptr++;
+ptr += sprintf(CS ptr, "\n");
length = ptr - log_buffer;
/* Handle loggable errors when running a utility, or when address testing.
@@ -1084,11 +1068,9 @@ if ((flags & LOG_REJECT) != 0)
/* A header with a NULL text is an unfilled in Received: header */
- for (h = header_list; h != NULL; h = h->next)
+ for (h = header_list; h; h = h->next) if (h->text)
{
- BOOL fitted;
- if (h->text == NULL) continue;
- fitted = string_format(ptr, LOG_BUFFER_SIZE - (ptr-log_buffer),
+ BOOL fitted = string_format(ptr, LOG_BUFFER_SIZE - (ptr-log_buffer),
"%c %s", h->type, h->text);
while(*ptr) ptr++;
if (!fitted) /* Buffer is full; truncate */
@@ -1118,7 +1100,7 @@ if ((flags & LOG_REJECT) != 0)
{
struct stat statbuf;
- if (rejectlog_datestamp != NULL)
+ if (rejectlog_datestamp)
{
uschar *nowstamp = tod_stamp(string_datestamp_type);
if (Ustrncmp (rejectlog_datestamp, nowstamp, Ustrlen(nowstamp)) != 0)
@@ -1175,9 +1157,7 @@ if ((flags & LOG_PANIC) != 0)
fprintf(log_stderr, "%s", CS log_buffer);
if ((logging_mode & LOG_MODE_SYSLOG) != 0)
- {
write_syslog(LOG_ALERT, log_buffer);
- }
/* If this panic logging was caused by a failure to open the main log,
the original log line is in panic_save_buffer. Make an attempt to write it. */
diff --git a/src/src/macros.h b/src/src/macros.h
index a8022adf6..937722494 100644
--- a/src/src/macros.h
+++ b/src/src/macros.h
@@ -467,6 +467,7 @@ enum {
Li_ident_timeout,
Li_incoming_interface,
Li_incoming_port,
+ Li_millisec,
Li_outgoing_interface,
Li_outgoing_port,
Li_pid,
diff --git a/src/src/tod.c b/src/src/tod.c
index 5f451ba96..dac8b27f3 100644
--- a/src/src/tod.c
+++ b/src/src/tod.c
@@ -13,7 +13,7 @@
/* #define TESTING_LOG_DATESTAMP */
-static uschar timebuf[sizeof("www, dd-mmm-yyyy hh:mm:ss +zzzz")];
+static uschar timebuf[sizeof("www, dd-mmm-yyyy hh:mm:ss.ddd +zzzz")];
/*************************************************
@@ -52,159 +52,169 @@ Returns: pointer to fixed buffer containing the timestamp
uschar *
tod_stamp(int type)
{
-time_t now;
-struct tm *t;
+struct timeval now;
+struct tm * t;
+int off = 0;
-if (type == tod_epoch_l)
- {
- struct timeval tv;
- gettimeofday(&tv, NULL);
- /* Unix epoch/usec format */
- (void) sprintf(CS timebuf, TIME_T_FMT "%06ld", tv.tv_sec, (long) tv.tv_usec );
- return timebuf;
- }
-
-now = time(NULL);
-
-/* Vary log type according to timezone requirement */
-
-if (type == tod_log) type = log_timezone? tod_log_zone : tod_log_bare;
+gettimeofday(&now, NULL);
/* Styles that don't need local time */
-else if (type == tod_epoch)
+switch(type)
{
- (void) sprintf(CS timebuf, TIME_T_FMT, now); /* Unix epoch format */
- return timebuf; /* NB the above will be wrong if time_t is FP */
+ case tod_epoch:
+ (void) sprintf(CS timebuf, TIME_T_FMT, now.tv_sec); /* Unix epoch format */
+ return timebuf; /* NB the above will be wrong if time_t is FP */
+
+ case tod_epoch_l:
+ /* Unix epoch/usec format */
+ (void) sprintf(CS timebuf, TIME_T_FMT "%06ld", now.tv_sec, (long) now.tv_usec );
+ return timebuf;
+
+ case tod_zulu:
+ t = gmtime(&now.tv_sec);
+ (void) sprintf(CS timebuf, "%04d%02d%02d%02d%02d%02dZ",
+ 1900 + t->tm_year, 1 + t->tm_mon, t->tm_mday, t->tm_hour, t->tm_min,
+ t->tm_sec);
+ return timebuf;
}
-else if (type == tod_zulu)
- {
- t = gmtime(&now);
- (void) sprintf(CS timebuf, "%04d%02d%02d%02d%02d%02dZ",
- 1900 + t->tm_year, 1 + t->tm_mon, t->tm_mday, t->tm_hour, t->tm_min,
- t->tm_sec);
- return timebuf;
- }
+/* Vary log type according to timezone requirement */
+
+if (type == tod_log) type = log_timezone ? tod_log_zone : tod_log_bare;
/* Convert to local time or UTC */
-t = timestamps_utc? gmtime(&now) : localtime(&now);
+t = timestamps_utc ? gmtime(&now.tv_sec) : localtime(&now.tv_sec);
switch(type)
{
case tod_log_bare: /* Format used in logging without timezone */
- (void) sprintf(CS timebuf, "%04d-%02d-%02d %02d:%02d:%02d",
- 1900 + t->tm_year, 1 + t->tm_mon, t->tm_mday,
- t->tm_hour, t->tm_min, t->tm_sec);
- break;
+ off = sprintf(CS timebuf, "%04d-%02d-%02d %02d:%02d:%02d",
+ 1900 + t->tm_year, 1 + t->tm_mon, t->tm_mday,
+ t->tm_hour, t->tm_min, t->tm_sec);
+ break;
- /* Format used as suffix of log file name when 'log_datestamp' is active. For
- testing purposes, it changes the file every second. */
+ /* Format used as suffix of log file name when 'log_datestamp' is active. For
+ testing purposes, it changes the file every second. */
- #ifdef TESTING_LOG_DATESTAMP
+#ifdef TESTING_LOG_DATESTAMP
case tod_log_datestamp_daily:
case tod_log_datestamp_monthly:
- (void) sprintf(CS timebuf, "%04d%02d%02d%02d%02d",
- 1900 + t->tm_year, 1 + t->tm_mon, t->tm_mday, t->tm_hour, t->tm_min);
- break;
+ off = sprintf(CS timebuf, "%04d%02d%02d%02d%02d",
+ 1900 + t->tm_year, 1 + t->tm_mon, t->tm_mday, t->tm_hour, t->tm_min);
+ break;
- #else
+#else
case tod_log_datestamp_daily:
- (void) sprintf(CS timebuf, "%04d%02d%02d",
- 1900 + t->tm_year, 1 + t->tm_mon, t->tm_mday);
- break;
+ off = sprintf(CS timebuf, "%04d%02d%02d",
+ 1900 + t->tm_year, 1 + t->tm_mon, t->tm_mday);
+ break;
case tod_log_datestamp_monthly:
- (void) sprintf(CS timebuf, "%04d%02d",
- 1900 + t->tm_year, 1 + t->tm_mon);
- break;
- #endif
+ off = sprintf(CS timebuf, "%04d%02d",
+ 1900 + t->tm_year, 1 + t->tm_mon);
+ break;
+#endif
- /* Format used in BSD inbox separator lines. Sort-of documented in RFC 976
- ("UUCP Mail Interchange Format Standard") but only by example, not by
- explicit definition. The examples show no timezone offsets, and some MUAs
- appear to be sensitive to this, so Exim has been changed to remove the
- timezone offsets that originally appeared. */
+ /* Format used in BSD inbox separator lines. Sort-of documented in RFC 976
+ ("UUCP Mail Interchange Format Standard") but only by example, not by
+ explicit definition. The examples show no timezone offsets, and some MUAs
+ appear to be sensitive to this, so Exim has been changed to remove the
+ timezone offsets that originally appeared. */
case tod_bsdin:
- {
- int len = Ustrftime(timebuf, sizeof(timebuf), "%a %b %d %H:%M:%S", t);
- Ustrftime(timebuf + len, sizeof(timebuf) - len, " %Y", t);
- }
- break;
-
- /* Other types require the GMT offset to be calculated, or just set up in the
- case of UTC timestamping. We need to take a copy of the local time first. */
-
- default:
- {
- int diff_hour, diff_min;
- struct tm local;
- memcpy(&local, t, sizeof(struct tm));
-
- if (timestamps_utc)
{
- diff_hour = diff_min = 0;
- }
- else
- {
- struct tm *gmt = gmtime(&now);
- diff_min = 60*(local.tm_hour - gmt->tm_hour) + local.tm_min - gmt->tm_min;
- if (local.tm_year != gmt->tm_year)
- diff_min += (local.tm_year > gmt->tm_year)? 1440 : -1440;
- else if (local.tm_yday != gmt->tm_yday)
- diff_min += (local.tm_yday > gmt->tm_yday)? 1440 : -1440;
- diff_hour = diff_min/60;
- diff_min = abs(diff_min - diff_hour*60);
+ int len = Ustrftime(timebuf, sizeof(timebuf), "%a %b %d %H:%M:%S", t);
+ Ustrftime(timebuf + len, sizeof(timebuf) - len, " %Y", t);
}
+ break;
+
+ /* Other types require the GMT offset to be calculated, or just set up in the
+ case of UTC timestamping. We need to take a copy of the local time first. */
- switch(type)
+ default:
{
- case tod_log_zone: /* Format used in logging with timezone */
- (void) sprintf(CS timebuf, "%04d-%02d-%02d %02d:%02d:%02d %+03d%02d",
- 1900 + local.tm_year, 1 + local.tm_mon, local.tm_mday,
- local.tm_hour, local.tm_min, local.tm_sec,
- diff_hour, diff_min);
- break;
-
- case tod_zone: /* Just the timezone offset */
- (void) sprintf(CS timebuf, "%+03d%02d", diff_hour, diff_min);
- break;
-
- /* tod_mbx: format used in MBX mailboxes - subtly different to tod_full */
-
- #ifdef SUPPORT_MBX
- case tod_mbx:
- {
- int len;
- (void) sprintf(CS timebuf, "%02d-", local.tm_mday);
- len = Ustrlen(timebuf);
- len += Ustrftime(timebuf + len, sizeof(timebuf) - len, "%b-%Y %H:%M:%S",
- &local);
- (void) sprintf(CS timebuf + len, " %+03d%02d", diff_hour, diff_min);
- }
- break;
- #endif
-
- /* tod_full: format used in Received: headers (use as default just in case
- called with a junk type value) */
-
- default:
- {
- int len = Ustrftime(timebuf, sizeof(timebuf), "%a, ", &local);
- (void) sprintf(CS timebuf + len, "%02d ", local.tm_mday);
- len += Ustrlen(timebuf + len);
- len += Ustrftime(timebuf + len, sizeof(timebuf) - len, "%b %Y %H:%M:%S",
- &local);
- (void) sprintf(CS timebuf + len, " %+03d%02d", diff_hour, diff_min);
- }
- break;
+ int diff_hour, diff_min;
+ struct tm local;
+ memcpy(&local, t, sizeof(struct tm));
+
+ if (timestamps_utc)
+ diff_hour = diff_min = 0;
+ else
+ {
+ struct tm * gmt = gmtime(&now.tv_sec);
+
+ diff_min = 60*(local.tm_hour - gmt->tm_hour) + local.tm_min - gmt->tm_min;
+ if (local.tm_year != gmt->tm_year)
+ diff_min += (local.tm_year > gmt->tm_year)? 1440 : -1440;
+ else if (local.tm_yday != gmt->tm_yday)
+ diff_min += (local.tm_yday > gmt->tm_yday)? 1440 : -1440;
+ diff_hour = diff_min/60;
+ diff_min = abs(diff_min - diff_hour*60);
+ }
+
+ switch(type)
+ {
+ case tod_log_zone: /* Format used in logging with timezone */
+#ifndef COMPILE_UTILITY
+ if (LOGGING(millisec))
+ (void) sprintf(CS timebuf,
+ "%04d-%02d-%02d %02d:%02d:%02d.%03d %+03d%02d",
+ 1900 + local.tm_year, 1 + local.tm_mon, local.tm_mday,
+ local.tm_hour, local.tm_min, local.tm_sec, now.tv_usec/1000,
+ diff_hour, diff_min);
+ else
+#endif
+ (void) sprintf(CS timebuf,
+ "%04d-%02d-%02d %02d:%02d:%02d %+03d%02d",
+ 1900 + local.tm_year, 1 + local.tm_mon, local.tm_mday,
+ local.tm_hour, local.tm_min, local.tm_sec,
+ diff_hour, diff_min);
+ break;
+
+ case tod_zone: /* Just the timezone offset */
+ (void) sprintf(CS timebuf, "%+03d%02d", diff_hour, diff_min);
+ break;
+
+ /* tod_mbx: format used in MBX mailboxes - subtly different to tod_full */
+
+ #ifdef SUPPORT_MBX
+ case tod_mbx:
+ {
+ int len;
+ (void) sprintf(CS timebuf, "%02d-", local.tm_mday);
+ len = Ustrlen(timebuf);
+ len += Ustrftime(timebuf + len, sizeof(timebuf) - len, "%b-%Y %H:%M:%S",
+ &local);
+ (void) sprintf(CS timebuf + len, " %+03d%02d", diff_hour, diff_min);
+ }
+ break;
+ #endif
+
+ /* tod_full: format used in Received: headers (use as default just in case
+ called with a junk type value) */
+
+ default:
+ {
+ int len = Ustrftime(timebuf, sizeof(timebuf), "%a, ", &local);
+ (void) sprintf(CS timebuf + len, "%02d ", local.tm_mday);
+ len += Ustrlen(timebuf + len);
+ len += Ustrftime(timebuf + len, sizeof(timebuf) - len, "%b %Y %H:%M:%S",
+ &local);
+ (void) sprintf(CS timebuf + len, " %+03d%02d", diff_hour, diff_min);
+ }
+ break;
+ }
}
- }
- break;
+ break;
}
+#ifndef COMPILE_UTILITY
+if (LOGGING(millisec) && off > 0)
+ (void) sprintf(CS timebuf + off, ".%03d", now.tv_usec/1000);
+#endif
+
return timebuf;
}
diff --git a/test/log/0551 b/test/log/0551
index 831e11a89..189bd380d 100644
--- a/test/log/0551
+++ b/test/log/0551
@@ -6,6 +6,6 @@
1999-03-02 09:44:33 [1237] 10HmaY-0005vi-00 => userx <userx@test.ex> R=r1 T=t1
1999-03-02 09:44:33 [1237] 10HmaY-0005vi-00 => userz <userz@test.ex> R=r1 T=t1
1999-03-02 09:44:33 [1237] 10HmaY-0005vi-00 Completed
-1999-03-02 09:44:33 10HmaZ-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss
-1999-03-02 09:44:33 10HmaZ-0005vi-00 => userx <userx@test.ex> R=r1 T=t1
-1999-03-02 09:44:33 10HmaZ-0005vi-00 Completed
+2017-07-30 18:51:05.712 10HmaZ-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss
+2017-07-30 18:51:05.712 10HmaZ-0005vi-00 => userx <userx@test.ex> R=r1 T=t1
+2017-07-30 18:51:05.712 10HmaZ-0005vi-00 Completed
diff --git a/test/runtest b/test/runtest
index 0e7e8ee0b..b7339f5d0 100755
--- a/test/runtest
+++ b/test/runtest
@@ -487,7 +487,8 @@ RESET_AFTER_EXTRA_LINE_READ:
/Tue, 2 Mar 1999 09:44:33 +0000/gx;
# Date/time in logs and in one instance of a filter test
- s/^\d{4}-\d\d-\d\d\s\d\d:\d\d:\d\d(\s[+-]\d\d\d\d)?/1999-03-02 09:44:33/gx;
+ s/^\d{4}-\d\d-\d\d\s\d\d:\d\d:\d\d(\s[+-]\d\d\d\d)?\s/1999-03-02 09:44:33 /gx;
+ s/^\d{4}-\d\d-\d\d\s\d\d:\d\d:\d\d\.\d{3}(\s[+-]\d\d\d\d)?\s/2017-07-30 18:51:05.712 /gx;
s/^Logwrite\s"\d{4}-\d\d-\d\d\s\d\d:\d\d:\d\d/Logwrite "1999-03-02 09:44:33/gx;
# Date/time in message separators
diff --git a/test/scripts/0000-Basic/0551 b/test/scripts/0000-Basic/0551
index d11064c00..b91f7e206 100644
--- a/test/scripts/0000-Basic/0551
+++ b/test/scripts/0000-Basic/0551
@@ -1,4 +1,4 @@
-# log_selector = +pid
+# log_selector = +pid , +millisec
#
exim -odi userx@test.ex usery@test.ex
Message 1
@@ -6,7 +6,7 @@ Message 1
exim -odi userx@test.ex userz@test.ex
Message 2
****
-exim -DLOG_SELECTOR= -odi userx@test.ex
+exim -DLOG_SELECTOR=+millisec -odi userx@test.ex
Message 3
****
exigrep userx
diff --git a/test/stdout/0551 b/test/stdout/0551
index 8af281557..9212d1410 100644
--- a/test/stdout/0551
+++ b/test/stdout/0551
@@ -8,9 +8,9 @@
1999-03-02 09:44:33 [1237] 10HmaY-0005vi-00 => userz <userz@test.ex> R=r1 T=t1
1999-03-02 09:44:33 [1237] 10HmaY-0005vi-00 Completed
-1999-03-02 09:44:33 10HmaZ-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss
-1999-03-02 09:44:33 10HmaZ-0005vi-00 => userx <userx@test.ex> R=r1 T=t1
-1999-03-02 09:44:33 10HmaZ-0005vi-00 Completed
+2017-07-30 18:51:05.712 10HmaZ-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss
+2017-07-30 18:51:05.712 10HmaZ-0005vi-00 => userx <userx@test.ex> R=r1 T=t1
+2017-07-30 18:51:05.712 10HmaZ-0005vi-00 Completed
exigrep exit code = 0
generated by cgit v1.2.3 (git 2.39.1) at 2024-12-28 14:07:26 +0000