the same message ID. Found by Victor. Files: global/mail_stream.c,
global/mail_queue.c.
+20051109
+
+ qshape.pl updated for extra microsecond time field in Postfix
+ queue files.
+
+ Cleanup: removed obsolete code that handles rejected/dropped
+ connections before the HELO handshake. File: smtp/smtp_connect.c.
+
+ Bugfix: XCLIENT broke when reverse hostname support was added.
+ Fix by Tomoyuki Sakurai. File: smtpd/smtpd.c.
+
Open problems:
"postsuper -r" no longer resets the message arrival time,
Is it safe to cache a connection after it has been used
for more than some number of address verification probes?
- The code in smtp_connect() that catches server reject and
- disconnect errors has become redundant. Connections that
- fail before MAIL FROM no longer count towards the MX session
- count limit per delivery attempt.
-
Access map actions such as FILTER and REDIRECT don't work
in smtpd_end_of_data_restrictions (or anything else that
generates additional queue file records after the message
/etc/postfix/master.cf:
:10026 inet n - n - - smtpd
- -o receive_override_options=nso_address_mapping
+ -o receive_override_options=no_address_mappings
Note: do not specify whitespace around the "=" here.
Incompatibility with snapshot 20051105
======================================
+qshape needs to be updated. See the file qshape-microsecond-patch.
+
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:
Incompatibility with snapshot 20051103
======================================
+pflogsumm needs to be updated. See the pflogsumm-conn-delays-dsn-patch
+file.
+
The queue manager protocol has changed. You need to "postfix reload"
after "make upgrade".
====================================
This release makes a beginning with a series of new attributes in
-Postfix logfile records.
+Postfix logfile records.
- Better insight into the nature of performance bottle necks, with
detailed logging of delays in various stages of message delivery.
$dlen = $1 if ($d =~ /^\s*(\d+)\s+\d+\s+\d+/);
($r, $l, $d) = rec_get($h);
return unless (defined $r && $r eq "T");
- $t = $d;
+ ($t) = split(/\s+/, $d);
} elsif ($r eq "S" || $r eq "F") {
# For embryonic queue files in the "maildrop" directory the first
# record is either a REC_TYPE_FULL (F) followed by REC_TYPE_FROM
<pre>
/etc/postfix/master.cf:
:10026 inet n - n - - smtpd
- -o <a href="postconf.5.html#receive_override_options">receive_override_options</a>=nso_address_mapping
+ -o <a href="postconf.5.html#receive_override_options">receive_override_options</a>=<a href="postconf.5.html#no_address_mappings">no_address_mappings</a>
</pre>
</blockquote>
<pre>
/etc/postfix/master.cf:
:10026 inet n - n - - smtpd
- -o receive_override_options=nso_address_mapping
+ -o receive_override_options=no_address_mappings
</pre>
</blockquote>
--- /dev/null
+This patch adds support for microsecond time information in Postfix
+queue files.
+
+*** /var/tmp/postfix-2.3-20051103/auxiliary/qshape/qshape.pl Fri Feb 4 19:41:14 2005
+--- auxiliary/qshape/qshape.pl Wed Nov 9 08:43:40 2005
+***************
+*** 204,210 ****
+ $dlen = $1 if ($d =~ /^\s*(\d+)\s+\d+\s+\d+/);
+ ($r, $l, $d) = rec_get($h);
+ return unless (defined $r && $r eq "T");
+! $t = $d;
+ } elsif ($r eq "S" || $r eq "F") {
+ # For embryonic queue files in the "maildrop" directory the first
+ # record is either a REC_TYPE_FULL (F) followed by REC_TYPE_FROM
+--- 204,210 ----
+ $dlen = $1 if ($d =~ /^\s*(\d+)\s+\d+\s+\d+/);
+ ($r, $l, $d) = rec_get($h);
+ return unless (defined $r && $r eq "T");
+! ($t) = split(/\s+/, $d);
+ } elsif ($r eq "S" || $r eq "F") {
+ # For embryonic queue files in the "maildrop" directory the first
+ # record is either a REC_TYPE_FULL (F) followed by REC_TYPE_FROM
* XXX An arbitrary amount of time may pass between the start of the mail
* transaction and the creation of a queue file. Since we guarantee queue
* ID uniqueness only within a second, we must ensure that the time in
- * the message ID matches the queue ID creation time, if we use the queue
- * ID in the message ID.
+ * the message ID matches the queue ID creation time, as long as we use
+ * the queue ID in the message ID.
*/
if ((state->headers_seen & (1 << (state->resent[0] ?
HDR_RESENT_MESSAGE_ID : HDR_MESSAGE_ID))) == 0) {
const char *status)
{
static VSTRING *buf;
- DELTA_TIME delay;
+ DELTA_TIME delay; /* end-to-end delay */
DELTA_TIME pdelay; /* time before queue manager */
DELTA_TIME adelay; /* queue manager latency */
DELTA_TIME sdelay; /* connection set-up latency */
/*
* Alas, we need an intermediate buffer for the pre-formatted result.
- * There are several optional fields, and we want to tweak some
- * formatting depending on delay values.
+ * There are several optional fields, and the delay fields are formatted
+ * in a manner that is not supported by vstring_sprintf().
*/
if (buf == 0)
buf = vstring_alloc(100);
DELTA(sdelay, stats->conn_setup_done, stats->agent_handoff);
DELTA(xdelay, now, stats->conn_setup_done);
} else {
- /* Non-network delivery agent. */
+ /* No network client. */
DELTA(xdelay, now, stats->agent_handoff);
}
} else {
/*
* Round off large time values to an integral number of seconds, and
- * display small numbers with only two digits as long as we stay above
- * the time resolution.
+ * display small numbers with only two significant digits, as long as
+ * they do not exceed the time resolution.
*/
+#define SIG_DIGS 2
#define PRETTY_FORMAT(b, text, x) \
do { \
vstring_strcat((b), text); \
- format_tv((b), (x).dt_sec, (x).dt_usec, 2, var_delay_max_res); \
+ format_tv((b), (x).dt_sec, (x).dt_usec, SIG_DIGS, var_delay_max_res); \
} while (0)
PRETTY_FORMAT(buf, ", delay=", delay);
#define XCLIENT_CMD "XCLIENT" /* XCLIENT command */
#define XCLIENT_NAME "NAME" /* client name */
#define XCLIENT_REVERSE_NAME "REVERSE_NAME" /* reverse client name */
+#ifdef FORWARD_CLIENT_NAME
#define XCLIENT_FORWARD_NAME "FORWARD_NAME" /* forward client name */
+#endif
#define XCLIENT_ADDR "ADDR" /* client address */
#define XCLIENT_PROTO "PROTO" /* client protocol */
#define XCLIENT_HELO "HELO" /* client helo */
* Patches change both the patchlevel and the release date. Snapshots have no
* patchlevel; they change the release date only.
*/
-#define MAIL_RELEASE_DATE "20051108"
+#define MAIL_RELEASE_DATE "20051109"
#define MAIL_VERSION_NUMBER "2.3"
#ifdef SNAPSHOT
return (0);
}
+ /*
+ * Following code is obsolete now that the SMTP client will connect to
+ * alternate hosts when a session fails before "MAIL FROM".
+ */
+#if 1
+ stream = vstream_fdopen(sock, O_RDWR);
+#else
+
/*
* Skip this host if it takes no action within some time limit. XXX Some
* MTAs use 426 to indicate a timeout error.
return (0);
}
vstream_ungetc(stream, ch);
+#endif
/*
* Bundle up what we have into a nice SMTP_SESSION object.
ENQUEUE_FIX_REPLY(state, reply_buf, XCLIENT_CMD
" " XCLIENT_NAME " " XCLIENT_ADDR
" " XCLIENT_PROTO " " XCLIENT_HELO
- " " XCLIENT_REVERSE_NAME
- " " XCLIENT_FORWARD_NAME);
+ " " XCLIENT_REVERSE_NAME);
if ((discard_mask & EHLO_MASK_XFORWARD) == 0)
if (xforward_allowed)
ENQUEUE_FIX_REPLY(state, reply_buf, XFORWARD_CMD
if (name_status == SMTPD_PEER_CODE_OK) {
UPDATE_STR(state->reverse_name, attr_value);
state->reverse_name_status = name_status;
-#ifdef FORWARD_CLIENT_NAME
- UPDATE_STR(state->forward_name, attr_value);
- state->forward_name_status = name_status;
-#endif
}
}
* REVERSE_NAME=substitute SMTP client reverse hostname. Also updates
* the client reverse hostname lookup status code.
*/
- if (STREQ(attr_name, XCLIENT_REVERSE_NAME)) {
+ else if (STREQ(attr_name, XCLIENT_REVERSE_NAME)) {
name_status = name_code(peer_codes, NAME_CODE_FLAG_NONE, attr_value);
if (name_status != SMTPD_PEER_CODE_OK) {
attr_value = CLIENT_NAME_UNKNOWN;
UPDATE_STR(state->reverse_name, attr_value);
}
- /*
- * FORWARD_NAME=substitute SMTP client forward hostname. Also updates
- * the client forward hostname lookup status code.
- */
-#ifdef FORWARD_CLIENT_NAME
- if (STREQ(attr_name, XCLIENT_FORWARD_NAME)) {
- name_status = name_code(peer_codes, NAME_CODE_FLAG_NONE, attr_value);
- if (name_status != SMTPD_PEER_CODE_OK) {
- attr_value = CLIENT_NAME_UNKNOWN;
- } else {
- if (!valid_hostname(attr_value, DONT_GRIPE)) {
- state->error_mask |= MAIL_ERROR_PROTOCOL;
- smtpd_chat_reply(state, "501 5.5.4 Bad %s syntax: %s",
- XCLIENT_FORWARD_NAME, attr_value);
- return (-1);
- }
- }
- state->forward_name_status = name_status;
- UPDATE_STR(state->forward_name, attr_value);
- }
-#endif
-
/*
* ADDR=substitute SMTP client network address.
*/
struct timeval arrival_time; /* start of MAIL FROM transaction */
char *name; /* verified client hostname */
char *reverse_name; /* unverified client hostname */
-#ifdef FORWARD_CLIENT_NAME
- char *forward_name; /* unverified client hostname */
-#endif
char *addr; /* client host address string */
char *namaddr; /* combined name and address */
char *rfc_addr; /* address for RFC 2821 */
struct sockaddr_storage sockaddr; /* binary client endpoint */
int name_status; /* 2=ok, 4=soft, 5=hard */
int reverse_name_status; /* 2=ok, 4=soft, 5=hard */
-#ifdef FORWARD_CLIENT_NAME
- int forward_name_status; /* 2=ok, 4=soft, 5=hard */
-#endif
int error_count; /* reset after DOT */
int error_mask; /* client errors */
int notify_mask; /* what to report to postmaster */
return (SMTPD_CHECK_DUNNO);
}
-#ifdef FORWARD_CLIENT_NAME
-
-/* reject_unknown_forward_name - fail if reverse client hostname is unknown */
-
-static int reject_unknown_forward_name(SMTPD_STATE *state)
-{
- char *myname = "reject_unknown_forward_name";
-
- if (msg_verbose)
- msg_info("%s: %s", myname, state->forward_name);
-
- if (state->forward_name_status != SMTPD_PEER_CODE_OK)
- return (smtpd_check_reject(state, MAIL_ERROR_POLICY,
- state->forward_name_status == SMTPD_PEER_CODE_PERM ?
- var_unk_client_code : 450, "4.7.1",
- "Client host rejected: cannot find your forward hostname, [%s]",
- state->addr));
- return (SMTPD_CHECK_DUNNO);
-}
-
-#endif
-
/* reject_unknown_client - fail if client hostname is unknown */
static int reject_unknown_client(SMTPD_STATE *state)
return (state->name);
} else if (STREQ(name, MAIL_ATTR_REVERSE_CLIENT_NAME)) {
return (state->reverse_name);
-#ifdef FORWARD_CLIENT_NAME
- } else if (STREQ(name, MAIL_ATTR_FORWARD_CLIENT_NAME)) {
- return (state->forward_name);
-#endif
} else if (STREQ(name, MAIL_ATTR_HELO_NAME)) {
return (state->helo_name ? state->helo_name : "");
} else if (STREQN(name, MAIL_ATTR_SENDER, CONST_LEN(MAIL_ATTR_SENDER))) {
ATTR_TYPE_STR, MAIL_ATTR_CLIENT_NAME, state->name,
ATTR_TYPE_STR, MAIL_ATTR_REVERSE_CLIENT_NAME,
state->reverse_name,
-#ifdef FORWARD_CLIENT_NAME
- ATTR_TYPE_STR, MAIL_ATTR_FORWARD_CLIENT_NAME,
- state->forward_name,
-#endif
ATTR_TYPE_STR, MAIL_ATTR_HELO_NAME,
state->helo_name ? state->helo_name : "",
ATTR_TYPE_STR, MAIL_ATTR_SENDER,
status = reject_unknown_client(state);
} else if (strcasecmp(name, REJECT_UNKNOWN_REVERSE_HOSTNAME) == 0) {
status = reject_unknown_reverse_name(state);
-#ifdef FORWARD_CLIENT_NAME
- } else if (strcasecmp(name, REJECT_UNKNOWN_FORWARD_HOSTNAME) == 0) {
- status = reject_unknown_forward_name(state);
-#endif
} else if (strcasecmp(name, PERMIT_INET_INTERFACES) == 0) {
status = permit_inet_interfaces(state);
} else if (strcasecmp(name, PERMIT_MYNETWORKS) == 0) {
state.where = "CONNECT";
UPDATE_STRING(state.name, args->argv[1]);
UPDATE_STRING(state.reverse_name, args->argv[1]);
-#ifdef FORWARD_CLIENT_NAME
- UPDATE_STRING(state.forward_name, args->argv[1]);
-#endif
UPDATE_STRING(state.addr, args->argv[2]);
if (args->argc == 4)
state.name_status =
state.reverse_name_status =
-#ifdef FORWARD_CLIENT_NAME
- state.forward_name_status =
-#endif
atoi(args->argv[3]);
else
state.name_status =
state.reverse_name_status =
-#ifdef FORWARD_CLIENT_NAME
- state.forward_name_status =
-#endif
SMTPD_PEER_CODE_OK;
if (state.namaddr)
myfree(state.namaddr);
if (errno == ECONNRESET || errno == ECONNABORTED) {
state->name = mystrdup(CLIENT_NAME_UNKNOWN);
state->reverse_name = mystrdup(CLIENT_NAME_UNKNOWN);
-#ifdef FORWARD_CLIENT_NAME
- state->forward_name = mystrdup(CLIENT_NAME_UNKNOWN);
-#endif
state->addr = mystrdup(CLIENT_ADDR_UNKNOWN);
state->rfc_addr = mystrdup(CLIENT_ADDR_UNKNOWN);
state->name_status = SMTPD_PEER_CODE_PERM;
state->reverse_name_status = SMTPD_PEER_CODE_PERM;
-#ifdef FORWARD_CLIENT_NAME
- state->forward_name_status = SMTPD_PEER_CODE_PERM;
-#endif
}
/*
if (var_smtpd_peername_lookup == 0) {
state->name = mystrdup(CLIENT_NAME_UNKNOWN);
state->reverse_name = mystrdup(CLIENT_NAME_UNKNOWN);
-#ifdef FORWARD_CLIENT_NAME
- state->forward_name = mystrdup(CLIENT_NAME_UNKNOWN);
-#endif
state->name_status = SMTPD_PEER_CODE_PERM;
state->reverse_name_status = SMTPD_PEER_CODE_PERM;
-#ifdef FORWARD_CLIENT_NAME
- state->forward_name_status = SMTPD_PEER_CODE_PERM;
-#endif
} else if ((aierr = sockaddr_to_hostname(sa, sa_len, &client_name,
(MAI_SERVNAME_STR *) 0, 0)) != 0) {
state->name = mystrdup(CLIENT_NAME_UNKNOWN);
state->reverse_name = mystrdup(CLIENT_NAME_UNKNOWN);
-#ifdef FORWARD_CLIENT_NAME
- state->forward_name = mystrdup(CLIENT_NAME_UNKNOWN);
-#endif
state->name_status = (TEMP_AI_ERROR(aierr) ?
SMTPD_PEER_CODE_TEMP : SMTPD_PEER_CODE_PERM);
state->reverse_name_status = (TEMP_AI_ERROR(aierr) ?
SMTPD_PEER_CODE_TEMP : SMTPD_PEER_CODE_PERM);
-#ifdef FORWARD_CLIENT_NAME
- state->forward_name_status = (TEMP_AI_ERROR(aierr) ?
- SMTPD_PEER_CODE_TEMP : SMTPD_PEER_CODE_PERM);
-#endif
} else {
struct addrinfo *res0;
struct addrinfo *res;
if (aierr) {
msg_warn("%s: hostname %s verification failed: %s",
state->addr, state->name, MAI_STRERROR(aierr));
-#ifdef FORWARD_CLIENT_NAME
- state->forward_name = mystrdup(CLIENT_NAME_UNKNOWN);
- state->forward_name_status = (TEMP_AI_ERROR(aierr) ?
- SMTPD_PEER_CODE_TEMP : SMTPD_PEER_CODE_PERM);
-#endif
REJECT_PEER_NAME(state, (TEMP_AI_ERROR(aierr) ?
SMTPD_PEER_CODE_TEMP : SMTPD_PEER_CODE_PERM));
} else {
-#ifdef FORWARD_CLIENT_NAME
- if (res0) {
- state->forward_name = mystrdup(res0->ai_canonname);
- state->forward_name_status = SMTPD_PEER_CODE_OK;
- } else {
- state->forward_name = mystrdup(CLIENT_NAME_UNKNOWN);
- state->forward_name_status = SMTPD_PEER_CODE_PERM;
- }
-#endif
for (res = res0; /* void */ ; res = res->ai_next) {
if (res == 0) {
msg_warn("%s: address not listed for hostname %s",
else {
state->name = mystrdup("localhost");
state->reverse_name = mystrdup("localhost");
-#ifdef FORWARD_CLIENT_NAME
- state->forward_name = mystrdup("localhost");
-#endif
state->addr = mystrdup("127.0.0.1"); /* XXX bogus. */
state->rfc_addr = mystrdup("127.0.0.1");/* XXX bogus. */
state->name_status = SMTPD_PEER_CODE_OK;
state->reverse_name_status = SMTPD_PEER_CODE_OK;
-#ifdef FORWARD_CLIENT_NAME
- state->forward_name_status = SMTPD_PEER_CODE_OK;
-#endif
}
/*
{
myfree(state->name);
myfree(state->reverse_name);
-#ifdef FORWARD_CLIENT_NAME
- myfree(state->forward_name);
-#endif
myfree(state->addr);
myfree(state->namaddr);
myfree(state->rfc_addr);
/* NAME
/* format_tv 3
/* SUMMARY
-/* format time value with limited precision
+/* format time value with sane precision
/* SYNOPSIS
/* #include <format_tv.h>
/*
-/* VSTRING *format_tv(buffer, sec, usec, width, max_pos)
+/* VSTRING *format_tv(buffer, sec, usec, sig_dig, max_dig)
/* VSTRING *buffer;
/* int sec;
/* int usec;
-/* int width;
-/* int max_pos;
+/* int sig_dig;
+/* int max_dig;
/* DESCRIPTION
-/* format_tv() formats the specified time while suppressing
-/* irrelevant digits in the output. Large numbers are always
-/* rounded up to an integral number of seconds. Small numbers
-/* are produced with a limited number of digits, provided that
-/* those digits don't exceed the limit on the number of positions
-/* after the decimal point. Trailing zeros are always omitted
-/* from the output.
+/* format_tv() formats the specified time as a floating-point
+/* number while suppressing irrelevant digits in the output.
+/* Large numbers are always rounded up to an integral number
+/* of seconds. Small numbers are produced with a limited number
+/* of significant digits, provided that the result does not
+/* exceed the limit on the total number of digits after the
+/* decimal point. Trailing zeros are always omitted from the
+/* output.
/*
/* Arguments:
/* .IP buffer
-/* Buffer to which the result is appended.
+/* The buffer to which the result is appended.
/* .IP sec
/* The seconds portion of the time value.
/* .IP usec
/* The microseconds portion of the time value.
-/* .IP width
-/* The maximal number of digits to produce when formatting
-/* small numbers. Trailing nulls are always omitted. Specify
+/* .IP sig_dig
+/* The maximal number of significant digits when formatting
+/* small numbers. Leading nulls don't count as significant,
+/* and trailing nulls are not included in the output. Specify
/* a number in the range 1..6.
-/* .IP max_pos
-/* The maximal number of positions after the decimal point.
+/* .IP max_dig
+/* The maximal number of all digits after the decimal point.
/* Specify a number in the range 0..6.
/* LICENSE
-/* .ad
-/* .fi
-/* The Secure Mailer license must be distributed with this software.
+/* .ad
+/* fi
+/* The Secure Mailer license must be distributed with this
+/* software.
/* AUTHOR(S)
/* Wietse Venema
/* IBM T.J. Watson Research
/* format_tv - print time with limited precision */
-VSTRING *format_tv(VSTRING *buf, int sec, int usec, int width, int max)
+VSTRING *format_tv(VSTRING *buf, int sec, int usec,
+ int sig_dig, int max_dig)
{
static int pow10[] = {1, 10, 100, 1000, 10000, 100000, 1000000};
int n;
/*
* Sanity check.
*/
- if (max < 0 || max > 6)
- msg_panic("format_tv: bad max decimal count %d", max);
+ if (max_dig < 0 || max_dig > 6)
+ msg_panic("format_tv: bad maximum decimal count %d", max_dig);
if (sec < 0 || usec < 0 || usec > MILLION)
msg_panic("format_tv: bad time %ds %dus", sec, usec);
- if (width < 1 || width > 6)
- msg_panic("format_tv: bad width %d", width);
- ures = MILLION / pow10[max];
- wid = pow10[width];
+ if (sig_dig < 1 || sig_dig > 6)
+ msg_panic("format_tv: bad significant decimal count %d", sig_dig);
+ ures = MILLION / pow10[max_dig];
+ wid = pow10[sig_dig];
/*
* Adjust the resolution to suppress irrelevant digits.
double tval;
int sec;
int usec;
- int width;
- int max_pos;
+ int sig_dig;
+ int max_dig;
while (vstring_get_nonl(in, VSTREAM_IN) > 0) {
vstream_printf(">> %s\n", vstring_str(in));
if (vstring_str(in)[0] == 0 || vstring_str(in)[0] == '#')
continue;
- if (sscanf(vstring_str(in), "%lf %d %d", &tval, &width, &max_pos) != 3)
+ if (sscanf(vstring_str(in), "%lf %d %d", &tval, &sig_dig, &max_dig) != 3)
msg_fatal("bad input: %s", vstring_str(in));
sec = (int) tval; /* raw seconds */
usec = (tval - sec) * MILLION; /* raw microseconds */
VSTRING_RESET(out);
- format_tv(out, sec, usec, width, max_pos);
+ format_tv(out, sec, usec, sig_dig, max_dig);
vstream_printf("%s\n", vstring_str(out));
vstream_fflush(VSTREAM_OUT);
}