Completion of support for time stamps from different stages
of message delivery. The information is now logged as
- "delays=a/b/c/d" where a=time before queue manager, b=time
- in queue manager, c=connection setup including HELO and
- TLS, d=message transmission time. Unlike Victor's example
+ "delays=a/b/c/d" where a=time before queue manager; b=time
+ in queue manager; c=connection setup including DNS, HELO
+ and TLS; d=message transmission time. Unlike Victor's example
which used time differences, this implementation uses
absolute times. The decision of what numbers to subtract
actually depends on program history, so we want to do it
the new "delays=a/b/c/d" logging. Specify a power of 10
in the range from 1 to 100000. File: global/log_adhoc.c.
+20051105
+
+ All delay logging now has sub-second resolution. This means
+ updating all code that reads or updates the records that
+ specify when mail arrived, and ensuring that mail submitted
+ with older Postfix versions produces sensible results.
+ Files: global/post_mail.c, global/mail_timeofday.[hc],
+ global/log_adhoc.c, postdrop/postdrop.c, pickup/pickup.c,
+ cleanup/cleanup_envelope.c, cleanup/cleanup_message.c,
+ smtpd/smtpd.c, qmqpd/qmqpd.c, *qmgr/qmgr_message.c,
+ *qmgr/qmgr_active.c, local/forward.c.
+
Open problems:
+ "postsuper -r" no longer resets the message arrival time,
+ because pickup(8) no longer overrides queue file time stamp
+ information. This can be a problem when mail "on hold" is
+ released after a long time.
+
Is it safe to cache a connection after it has been used
for more than some number of address verification probes?
If you upgrade from Postfix 2.1 or earlier, read RELEASE_NOTES-2.2
before proceeding.
+Incompatibility with snapshot 20051105
+======================================
+
+All delay logging now has sub-second resolution, including the
+over-all "delay=nnn" logging.
+At this point the Postfix logging for a recipient looks like this:
+
+ Nov 3 16:04:31 myname postfix/smtp[30840]: 19B6B2900FE:
+ to=<wietse@test.example.com>, orig_to=<wietse@test>,
+ relay=mail.example.com[1.2.3.4], conn_use=2, delay=0.22,
+ delays=0.04/0.01/0.05/0.1, dsn=2.0.0, status=sent (250 2.0.0 Ok)
+
+
Incompatibility with snapshot 20051103
======================================
- Better insight into the nature of performance bottle necks, with
detailed logging of delays in various stages of message delivery.
Postfix logs additional delay information as "delays=a/b/c/d" where
-a=time before queue manager, b=time in queue manager, c=connection
-setup time including HELO and TLS, d=message transmission time.
+a=time before queue manager; b=time in queue manager; c=connection
+setup time including DNS, HELO and TLS; d=message transmission time.
- Logging of the connection reuse count when SMTP connections are
used for more than one message delivery. This information is needed
<li> b = time in queue manager
-<li> c = time in connection setup, including EHLO and TLS
+<li> c = time in connection setup, including DNS, EHLO and TLS
<li> d = time in message transfer
.IP \(bu
b = time in queue manager
.IP \(bu
-c = time in connection setup, including EHLO and TLS
+c = time in connection setup, including DNS, EHLO and TLS
.IP \(bu
d = time in message transfer
.PP
<li> b = time in queue manager
-<li> c = time in connection setup, including EHLO and TLS
+<li> c = time in connection setup, including DNS, EHLO and TLS
<li> d = time in message transfer
/* DESCRIPTION
/* .nf
+ /*
+ * System library.
+ */
+#include <sys/time.h>
+
/*
* Utility library.
*/
MAIL_STREAM *handle; /* mail stream handle */
char *queue_name; /* queue name */
char *queue_id; /* queue file basename */
- time_t time; /* posting time */
+ struct timeval arrival_time; /* arrival time */
char *fullname; /* envelope sender full name */
char *sender; /* envelope sender address */
char *recip; /* envelope recipient address */
* MSG_STATS compatibility.
*/
#define CLEANUP_MSG_STATS(stats, state) \
- MSG_STATS_INIT1(stats, incoming_arrival, state->time)
+ MSG_STATS_INIT1(stats, incoming_arrival, state->arrival_time)
/* LICENSE
/* .ad
#include <sys_defs.h>
#include <string.h>
#include <stdlib.h>
+#include <ctype.h>
#ifdef STRCASECMP_IN_STRINGS_H
#include <strings.h>
state->errs |= CLEANUP_STAT_BAD;
return;
}
- if (state->time == 0) {
+ if (state->arrival_time.tv_sec == 0) {
msg_warn("%s: message rejected: missing time envelope record",
state->queue_id);
state->errs |= CLEANUP_STAT_BAD;
if ((state->flags & CLEANUP_FLAG_WARN_SEEN) == 0
&& var_delay_warn_time > 0) {
cleanup_out_format(state, REC_TYPE_WARN, REC_TYPE_WARN_FORMAT,
- (long) state->time + var_delay_warn_time);
+ (long) state->arrival_time.tv_sec + var_delay_warn_time);
}
state->flags |= CLEANUP_FLAG_INRCPT;
}
return;
if (type == REC_TYPE_TIME) {
/* First instance wins. */
- if (state->time == 0) {
- state->time = atol(buf);
+ if (state->arrival_time.tv_sec == 0) {
+ state->arrival_time.tv_sec = atol(buf);
cleanup_out(state, type, buf, len);
+ while (ISDIGIT(*buf))
+ buf++;
+ state->arrival_time.tv_usec = atol(buf);
}
return;
}
char time_stamp[1024]; /* XXX locale dependent? */
struct tm *tp;
TOK822 *token;
+ time_t tv;
/*
* Add a missing (Resent-)Message-Id: header. The message ID gives the
*/
if ((state->headers_seen & (1 << (state->resent[0] ?
HDR_RESENT_MESSAGE_ID : HDR_MESSAGE_ID))) == 0) {
- tp = gmtime(&state->time);
+ tv = state->arrival_time.tv_sec;
+ tp = gmtime(&tv);
strftime(time_stamp, sizeof(time_stamp), "%Y%m%d%H%M%S", tp);
cleanup_out_format(state, REC_TYPE_NORM, "%sMessage-Id: <%s.%s@%s>",
state->resent, time_stamp, state->queue_id, var_myhostname);
if ((state->headers_seen & (1 << (state->resent[0] ?
HDR_RESENT_DATE : HDR_DATE))) == 0) {
cleanup_out_format(state, REC_TYPE_NORM, "%sDate: %s",
- state->resent, mail_date(state->time));
+ state->resent, mail_date(state->arrival_time.tv_sec));
}
/*
const char *myname = "cleanup_message_headerbody";
MIME_STATE_DETAIL *detail;
const char *cp;
- char *dst;
+ char *dst;
/*
* Reject unwanted characters.
state->handle = 0;
state->queue_name = 0;
state->queue_id = 0;
- state->time = 0;
+ state->arrival_time.tv_sec = state->arrival_time.tv_usec = 0;
state->fullname = 0;
state->sender = 0;
state->recip = 0;
deliver_request.o: mail_queue.h
deliver_request.o: msg_stats.h
deliver_request.o: recipient_list.h
-dict_ldap.o: ../../include/argv.h
-dict_ldap.o: ../../include/binhash.h
-dict_ldap.o: ../../include/dict.h
-dict_ldap.o: ../../include/match_list.h
-dict_ldap.o: ../../include/match_ops.h
-dict_ldap.o: ../../include/msg.h
-dict_ldap.o: ../../include/mymalloc.h
-dict_ldap.o: ../../include/stringops.h
dict_ldap.o: ../../include/sys_defs.h
-dict_ldap.o: ../../include/vbuf.h
-dict_ldap.o: ../../include/vstream.h
-dict_ldap.o: ../../include/vstring.h
-dict_ldap.o: cfg_parser.h
-dict_ldap.o: db_common.h
dict_ldap.o: dict_ldap.c
-dict_ldap.o: dict_ldap.h
-dict_ldap.o: string_list.h
-dict_mysql.o: ../../include/argv.h
-dict_mysql.o: ../../include/dict.h
-dict_mysql.o: ../../include/events.h
-dict_mysql.o: ../../include/find_inet.h
-dict_mysql.o: ../../include/match_list.h
-dict_mysql.o: ../../include/match_ops.h
-dict_mysql.o: ../../include/msg.h
-dict_mysql.o: ../../include/mymalloc.h
-dict_mysql.o: ../../include/myrand.h
-dict_mysql.o: ../../include/split_at.h
dict_mysql.o: ../../include/sys_defs.h
-dict_mysql.o: ../../include/vbuf.h
-dict_mysql.o: ../../include/vstream.h
-dict_mysql.o: ../../include/vstring.h
-dict_mysql.o: cfg_parser.h
-dict_mysql.o: db_common.h
dict_mysql.o: dict_mysql.c
-dict_mysql.o: dict_mysql.h
-dict_mysql.o: string_list.h
-dict_pgsql.o: ../../include/argv.h
-dict_pgsql.o: ../../include/dict.h
-dict_pgsql.o: ../../include/events.h
-dict_pgsql.o: ../../include/find_inet.h
-dict_pgsql.o: ../../include/match_list.h
-dict_pgsql.o: ../../include/match_ops.h
-dict_pgsql.o: ../../include/msg.h
-dict_pgsql.o: ../../include/mymalloc.h
-dict_pgsql.o: ../../include/myrand.h
-dict_pgsql.o: ../../include/split_at.h
dict_pgsql.o: ../../include/sys_defs.h
-dict_pgsql.o: ../../include/vbuf.h
-dict_pgsql.o: ../../include/vstream.h
-dict_pgsql.o: ../../include/vstring.h
-dict_pgsql.o: cfg_parser.h
-dict_pgsql.o: db_common.h
dict_pgsql.o: dict_pgsql.c
-dict_pgsql.o: dict_pgsql.h
-dict_pgsql.o: string_list.h
dict_proxy.o: ../../include/argv.h
dict_proxy.o: ../../include/attr.h
dict_proxy.o: ../../include/dict.h
const char *status)
{
static VSTRING *buf;
- int delay;
- int pdelay; /* time before queue manager */
+ struct timeval delay;
+ struct timeval pdelay; /* time before queue manager */
struct timeval adelay; /* queue manager latency */
struct timeval sdelay; /* connection set-up latency */
struct timeval xdelay; /* transmission latency */
now = stats->deliver_done;
else
GETTIMEOFDAY(&now);
- delay = now.tv_sec - stats->incoming_arrival;
+
+ DELTA(delay, now, stats->incoming_arrival);
adelay.tv_sec = adelay.tv_usec =
sdelay.tv_sec = sdelay.tv_usec =
xdelay.tv_sec = xdelay.tv_usec = 0;
if (stats->active_arrival.tv_sec) {
- pdelay = stats->active_arrival.tv_sec - stats->incoming_arrival;
+ DELTA(pdelay, stats->active_arrival, stats->incoming_arrival);
if (stats->agent_handoff.tv_sec) {
DELTA(adelay, stats->agent_handoff, stats->active_arrival);
if (stats->conn_setup_done.tv_sec) {
}
} else {
/* No queue manager. */
- pdelay = now.tv_sec - stats->incoming_arrival;
+ DELTA(pdelay, now, stats->incoming_arrival);
}
+
if (stats->reuse_count > 0)
vstring_sprintf_append(buf, ", conn_use=%d", stats->reuse_count + 1);
+ /*
+ * XXX Eliminate dependency on floating point. Wietse insists, however,
+ * that precision be limited to avoid logfile clutter. That is, numbers
+ * less than 100 must look as if they were formatted with %.2g, not as if
+ * they were formatted with %.2f.
+ */
#define MILLION 1000000
#define DMILLION ((double) MILLION)
-#define PRETTY_FORMAT(b, x) \
+#define PRETTY_FORMAT(b, slash, x) \
do { \
if ((x).tv_sec > 9 \
|| ((x).tv_sec == 0 && (x).tv_usec < var_delay_resolution)) { \
- vstring_sprintf_append((b), "/%ld", \
+ vstring_sprintf_append((b), slash "%ld", \
(long) (x).tv_sec + ((x).tv_usec > (MILLION / 2))); \
} else { \
- vstring_sprintf_append((b), "/%.2g", \
- (x).tv_sec + ((x).tv_usec / var_delay_resolution) \
- * (var_delay_resolution / DMILLION)); \
+ vstring_sprintf_append((b), slash "%.2g", (x).tv_sec \
+ + ((x).tv_usec - (x).tv_usec % var_delay_resolution) \
+ / DMILLION); \
} \
} while (0)
- vstring_sprintf_append(buf, ", delay=%d, delays=%d", delay, pdelay);
- PRETTY_FORMAT(buf, adelay);
- PRETTY_FORMAT(buf, sdelay);
- PRETTY_FORMAT(buf, xdelay);
+ vstring_sprintf_append(buf, ", delay=");
+ PRETTY_FORMAT(buf, "", delay);
+ vstring_sprintf_append(buf, ", delays=");
+ PRETTY_FORMAT(buf, "", pdelay);
+ PRETTY_FORMAT(buf, "/", adelay);
+ PRETTY_FORMAT(buf, "/", sdelay);
+ PRETTY_FORMAT(buf, "/", xdelay);
/*
* Finally, the delivery status.
* Patches change both the patchlevel and the release date. Snapshots have no
* patchlevel; they change the release date only.
*/
-#define MAIL_RELEASE_DATE "20051104"
+#define MAIL_RELEASE_DATE "20051105"
#define MAIL_VERSION_NUMBER "2.3"
#ifdef SNAPSHOT
* values.
*/
typedef struct {
- time_t incoming_arrival; /* incoming queue entry */
+ struct timeval incoming_arrival; /* incoming queue entry */
struct timeval active_arrival; /* active queue entry */
struct timeval agent_handoff; /* delivery agent hand-off */
struct timeval conn_setup_done; /* connection set-up done */
/* System library. */
#include <sys_defs.h>
-#include <time.h>
+#include <sys/time.h>
#include <stdlib.h> /* 44BSD stdarg.h uses abort() */
#include <stdarg.h>
#include <string.h>
int cleanup_flags, int trace_flags)
{
VSTRING *id = vstring_alloc(100);
- long now = time((time_t *) 0);
- const char *date = mail_date(now);
+ struct timeval now;
+ const char *date;
+
+ GETTIMEOFDAY(&now);
+ date = mail_date(now.tv_sec);
/*
* Negotiate with the cleanup service. Give up if we can't agree.
* Generate a minimal envelope section. The cleanup service will add a
* size record.
*/
- rec_fprintf(stream, REC_TYPE_TIME, "%ld", (long) now);
+ rec_fprintf(stream, REC_TYPE_TIME, "%ld %ld",
+ (long) now.tv_sec, (long) now.tv_usec);
rec_fprintf(stream, REC_TYPE_ATTR, "%s=%s",
MAIL_ATTR_ORIGIN, MAIL_ATTR_ORG_LOCAL);
rec_fprintf(stream, REC_TYPE_ATTR, "%s=%d",
/* System library. */
#include <sys_defs.h>
+#include <sys/time.h>
#include <unistd.h>
-#include <time.h>
/* Utility library. */
typedef struct FORWARD_INFO {
VSTREAM *cleanup; /* clean up service handle */
char *queue_id; /* forwarded message queue id */
- time_t posting_time; /* posting time */
+ struct timeval posting_time; /* posting time */
} FORWARD_INFO;
/* forward_init - prepare for forwarding */
info = (FORWARD_INFO *) mymalloc(sizeof(FORWARD_INFO));
info->cleanup = cleanup;
info->queue_id = mystrdup(STR(buffer));
- info->posting_time = time((time_t *) 0);
+ GETTIMEOFDAY(&info->posting_time);
#define FORWARD_CLEANUP_FLAGS (CLEANUP_FLAG_BOUNCE | CLEANUP_FLAG_MASK_INTERNAL)
* Send initial message envelope information. For bounces, set the
* designated sender: mailing list owner, posting user, whatever.
*/
- rec_fprintf(cleanup, REC_TYPE_TIME, "%ld", (long) info->posting_time);
+ rec_fprintf(cleanup, REC_TYPE_TIME, "%ld %ld",
+ (long) info->posting_time.tv_sec,
+ (long) info->posting_time.tv_usec);
rec_fputs(cleanup, REC_TYPE_FROM, sender);
/*
rec_fprintf(info->cleanup, REC_TYPE_NORM, "Received: by %s (%s)",
var_myhostname, var_mail_name);
rec_fprintf(info->cleanup, REC_TYPE_NORM, "\tid %s; %s",
- info->queue_id, mail_date(info->posting_time));
+ info->queue_id, mail_date(info->posting_time.tv_sec));
if (local_deliver_hdr_mask & DELIVER_HDR_FWD)
rec_fprintf(info->cleanup, REC_TYPE_NORM, "Delivered-To: %s",
lowercase(STR(buffer)));
forward_dt = 0;
return (status);
}
-
VSTREAM *fp; /* open queue file or null */
int refcount; /* queue entries */
int single_rcpt; /* send one rcpt at a time */
- long arrival_time; /* time when queued */
+ struct timeval arrival_time; /* time when queued */
struct timeval active_time; /* time of entry into active queue */
long warn_offset; /* warning bounce flag offset */
time_t warn_time; /* time next warning to be sent */
* daemon waits for the qmgr to accept the "new mail" trigger.
*/
if (message->flags) {
- if (event_time() >= message->arrival_time +
+ if (event_time() >= message->arrival_time.tv_sec +
(*message->sender ? var_max_queue_time : var_dsn_queue_time)) {
msg_info("%s: from=<%s>, status=expired, returned to sender",
message->queue_id, message->sender);
* queue scans is finite.
*/
if (message->flags) {
- if (message->arrival_time > 0) {
- delay = event_time() - message->arrival_time;
+ if (message->arrival_time.tv_sec > 0) {
+ delay = event_time() - message->arrival_time.tv_sec;
if (delay > var_max_backoff_time)
delay = var_max_backoff_time;
if (delay < var_min_backoff_time)
#include <errno.h>
#include <unistd.h>
#include <string.h>
+#include <ctype.h>
#ifdef STRCASECMP_IN_STRINGS_H
#include <strings.h>
message->fp = 0;
message->refcount = 0;
message->single_rcpt = 0;
- message->arrival_time = 0;
+ message->arrival_time.tv_sec = message->arrival_time.tv_usec = 0;
GETTIMEOFDAY(&message->active_time);
message->data_offset = 0;
message->queue_id = mystrdup(queue_id);
continue;
}
if (rec_type == REC_TYPE_TIME) {
- if (message->arrival_time == 0)
- message->arrival_time = atol(start);
+ if (message->arrival_time.tv_sec == 0)
+ message->arrival_time.tv_sec = atol(start);
+ while(ISDIGIT(*start))
+ start++;
+ message->arrival_time.tv_usec = atol(start);
continue;
}
if (rec_type == REC_TYPE_FILT) {
*/
if (rec_type <= 0) {
/* Already logged warning. */
- } else if (message->arrival_time == 0) {
+ } else if (message->arrival_time.tv_sec == 0) {
msg_warn("%s: message rejected: missing arrival time record",
message->queue_id);
} else if (message->sender == 0) {
{
int type;
int check_first = (*expected == REC_TYPE_CONTENT[0]);
+ int time_seen = 0;
/*
* Limit the input record size. All front-end programs should protect the
msg_info("%s: read %c %s", info->id, type, vstring_str(buf));
if (type == *expected)
break;
- if (type == REC_TYPE_FROM)
+ if (type == REC_TYPE_FROM) {
if (info->sender == 0)
info->sender = mystrdup(vstring_str(buf));
+ /* Compatibility with Postfix < 2.3. */
+ if (time_seen == 0)
+ rec_fprintf(cleanup, REC_TYPE_TIME, "%ld",
+ (long) info->st.st_mtime);
+ }
if (type == REC_TYPE_TIME)
- /* Use our own arrival time record instead. */
- continue;
+ time_seen = 1;
/*
* XXX Workaround: REC_TYPE_FILT (used in envelopes) == REC_TYPE_CONT
info->id, (int) (now - info->st.st_mtime) / DAY_SECONDS);
}
- /*
- * Make sure the message has a posting-time record.
- */
- rec_fprintf(cleanup, REC_TYPE_TIME, "%ld", (long) info->st.st_mtime);
-
/*
* Add content inspection transport.
*/
char *attr_value;
const char *errstr;
char *junk;
+ struct timeval start;
/*
* Be consistent with file permissions.
/* End of initializations. */
+ /*
+ * Don't trust the caller's time information.
+ */
+ GETTIMEOFDAY(&start);
+
/*
* Create queue file. mail_stream_file() never fails. Send the queue ID
* to the caller. Stash away a copy of the queue file name so we can
vstream_control(VSTREAM_IN, VSTREAM_CTL_PATH, "stdin", VSTREAM_CTL_END);
buf = vstring_alloc(100);
expected = segment_info;
+ /* Override time information from the untrusted caller. */
+ rec_fprintf(dst->stream, REC_TYPE_TIME, "%ld %ld",
+ (long) start.tv_sec, (long) start.tv_usec);
for (;;) {
rec_type = rec_get(VSTREAM_IN, buf, var_line_limit);
if (rec_type == REC_TYPE_EOF) { /* request cancelled */
msg_fatal("uid=%ld: unexpected record type: %d", (long) uid, rec_type);
if (rec_type == **expected)
expected++;
+ /* Override time information from the untrusted caller. */
+ if (rec_type == REC_TYPE_TIME)
+ continue;
if (rec_type == REC_TYPE_ATTR) {
if ((error_text = split_nameval(vstring_str(buf), &attr_name,
&attr_value)) != 0) {
VSTREAM *fp; /* open queue file or null */
int refcount; /* queue entries */
int single_rcpt; /* send one rcpt at a time */
- long arrival_time; /* time when queued */
+ struct timeval arrival_time; /* time when queued */
struct timeval active_time; /* time of entry into active queue */
time_t queued_time; /* sanitized time when moved to the
* active queue */
* daemon waits for the qmgr to accept the "new mail" trigger.
*/
if (message->flags) {
- if (event_time() >= message->arrival_time +
+ if (event_time() >= message->arrival_time.tv_sec +
(*message->sender ? var_max_queue_time : var_dsn_queue_time)) {
msg_info("%s: from=<%s>, status=expired, returned to sender",
message->queue_id, message->sender);
* queue scans is finite.
*/
if (message->flags) {
- if (message->arrival_time > 0) {
- delay = event_time() - message->arrival_time;
+ if (message->arrival_time.tv_sec > 0) {
+ delay = event_time() - message->arrival_time.tv_sec;
if (delay > var_max_backoff_time)
delay = var_max_backoff_time;
if (delay < var_min_backoff_time)
#include <errno.h>
#include <unistd.h>
#include <string.h>
+#include <ctype.h>
#ifdef STRCASECMP_IN_STRINGS_H
#include <strings.h>
message->fp = 0;
message->refcount = 0;
message->single_rcpt = 0;
- message->arrival_time = 0;
+ message->arrival_time.tv_sec = message->arrival_time.tv_usec = 0;
GETTIMEOFDAY(&message->active_time);
message->queued_time = sane_time();
message->data_offset = 0;
continue;
}
if (rec_type == REC_TYPE_TIME) {
- if (message->arrival_time == 0)
- message->arrival_time = atol(start);
+ if (message->arrival_time.tv_sec == 0)
+ message->arrival_time.tv_sec = atol(start);
+ while(ISDIGIT(*start))
+ start++;
+ message->arrival_time.tv_usec = atol(start);
continue;
}
if (rec_type == REC_TYPE_FILT) {
}
if (rec_type <= 0) {
/* Already logged warning. */
- } else if (message->arrival_time == 0) {
+ } else if (message->arrival_time.tv_sec == 0) {
msg_warn("%s: message rejected: missing arrival time record",
message->queue_id);
} else if (message->sender == 0) {
* bloody likely, but present for the sake of consistency with all other
* Postfix points of entrance).
*/
- rec_fprintf(state->cleanup, REC_TYPE_TIME, "%ld", (long) state->time);
+ rec_fprintf(state->cleanup, REC_TYPE_TIME, "%ld %ld",
+ (long) state->arrival_time.tv_sec,
+ (long) state->arrival_time.tv_usec);
if (*var_filter_xport)
rec_fprintf(state->cleanup, REC_TYPE_FILT, "%s", var_filter_xport);
}
state->protocol, state->queue_id);
quote_822_local(state->buf, state->recipient);
rec_fprintf(state->cleanup, REC_TYPE_NORM,
- "\tfor <%s>; %s", STR(state->buf), mail_date(state->time));
+ "\tfor <%s>; %s", STR(state->buf),
+ mail_date(state->arrival_time.tv_sec));
} else {
rec_fprintf(state->cleanup, REC_TYPE_NORM,
"\tby %s (%s) with %s",
var_myhostname, var_mail_name, state->protocol);
rec_fprintf(state->cleanup, REC_TYPE_NORM,
- "\tid %s; %s", state->queue_id, mail_date(state->time));
+ "\tid %s; %s", state->queue_id,
+ mail_date(state->arrival_time.tv_sec));
}
#ifdef RECEIVED_ENVELOPE_FROM
quote_822_local(state->buf, state->sender);
/*
* System library.
*/
-#include <time.h>
+#include <sys/time.h>
/*
* Utility library.
VSTREAM *client; /* client connection */
VSTRING *message; /* message buffer */
VSTRING *buf; /* line buffer */
- time_t time; /* start of session */
+ struct timeval arrival_time; /* start of session */
char *name; /* client name */
char *addr; /* client IP address */
char *namaddr; /* name[addr] */
state->client = stream;
state->message = vstring_alloc(1000);
state->buf = vstring_alloc(100);
- state->time = time((time_t *) 0);
+ GETTIMEOFDAY(&state->arrival_time);
qmqpd_peer_init(state);
state->queue_id = 0;
state->cleanup = 0;
} else if (prev_type == REC_TYPE_CONT) /* missing newline */
smtp_fputs("", 0, session->stream);
if ((session->features & SMTP_FEATURE_MAYBEPIX) != 0
- && request->msg_stats.incoming_arrival < vstream_ftime(session->stream)
- - var_smtp_pix_thresh) {
+ && request->msg_stats.incoming_arrival.tv_sec
+ < vstream_ftime(session->stream) - var_smtp_pix_thresh) {
msg_info("%s: enabling PIX <CRLF>.<CRLF> workaround for %s",
request->queue_id, session->namaddr);
smtp_flush(session->stream); /* hurts performance */
#include <stdio.h> /* remove() */
#include <unistd.h>
#include <stdlib.h>
-#include <time.h>
#include <errno.h>
#include <ctype.h>
#include <signal.h>
* attributes.
*/
if (SMTPD_STAND_ALONE(state) == 0) {
- rec_fprintf(state->cleanup, REC_TYPE_TIME, "%ld", (long) state->time);
+ rec_fprintf(state->cleanup, REC_TYPE_TIME, "%ld %ld",
+ (long) state->arrival_time.tv_sec,
+ (long) state->arrival_time.tv_usec);
if (*var_filter_xport)
rec_fprintf(state->cleanup, REC_TYPE_FILT, "%s", var_filter_xport);
rec_fprintf(state->cleanup, REC_TYPE_ATTR, "%s=%s",
/*
* No more early returns. The mail transaction is in progress.
*/
- state->time = time((time_t *) 0);
+ GETTIMEOFDAY(&state->arrival_time);
state->sender = mystrdup(STR(state->addr_buf));
- vstring_sprintf(state->instance, "%x.%lx.%x",
- var_pid, (unsigned long) state->time, state->seqno++);
+ vstring_sprintf(state->instance, "%x.%lx.%lx.%x",
+ var_pid, (unsigned long) state->arrival_time.tv_sec,
+ (unsigned long) state->arrival_time.tv_usec, state->seqno++);
if (verp_delims)
state->verp_delims = mystrdup(verp_delims);
if (dsn_envid)
state->protocol, state->queue_id);
quote_822_local(state->buffer, state->recipient);
out_fprintf(out_stream, REC_TYPE_NORM,
- "\tfor <%s>; %s", STR(state->buffer), mail_date(state->time));
+ "\tfor <%s>; %s", STR(state->buffer),
+ mail_date(state->arrival_time.tv_sec));
} else {
out_fprintf(out_stream, REC_TYPE_NORM,
state->cleanup ? "\tby %s (%s) with %s id %s;" :
var_myhostname, var_mail_name,
state->protocol, state->queue_id);
out_fprintf(out_stream, REC_TYPE_NORM,
- "\t%s", mail_date(state->time));
+ "\t%s", mail_date(state->arrival_time.tv_sec));
}
#ifdef RECEIVED_ENVELOPE_FROM
quote_822_local(state->buffer, state->sender);
/*
* System library.
*/
+#include <sys/time.h>
#include <unistd.h>
/*
VSTRING *buffer; /* SMTP client buffer */
VSTRING *addr_buf; /* internalized address buffer */
char *service; /* for event rate control */
- time_t time; /* start of MAIL FROM transaction */
+ struct timeval arrival_time; /* start of MAIL FROM transaction */
char *name; /* verified client hostname */
char *reverse_name; /* unverified client hostname */
#ifdef FORWARD_CLIENT_NAME