summaryrefslogtreecommitdiffstats
path: root/src/global/log_adhoc.c
diff options
context:
space:
mode:
Diffstat (limited to '')
-rw-r--r--src/global/log_adhoc.c221
1 files changed, 221 insertions, 0 deletions
diff --git a/src/global/log_adhoc.c b/src/global/log_adhoc.c
new file mode 100644
index 0000000..e00e930
--- /dev/null
+++ b/src/global/log_adhoc.c
@@ -0,0 +1,221 @@
+/*++
+/* NAME
+/* log_adhoc 3
+/* SUMMARY
+/* ad-hoc delivery event logging
+/* SYNOPSIS
+/* #include <log_adhoc.h>
+/*
+/* void log_adhoc(id, stats, recipient, relay, dsn, status)
+/* const char *id;
+/* MSG_STATS *stats;
+/* RECIPIENT *recipient;
+/* const char *relay;
+/* DSN *dsn;
+/* const char *status;
+/* DESCRIPTION
+/* This module logs delivery events in an ad-hoc manner.
+/*
+/* log_adhoc() appends a record to the mail logfile
+/*
+/* Arguments:
+/* .IP queue
+/* The message queue name of the original message file.
+/* .IP id
+/* The queue id of the original message file.
+/* .IP stats
+/* Time stamps from different message delivery stages
+/* and session reuse count.
+/* .IP recipient
+/* Recipient information, see recipient_list(3). The address
+/* is formatted by the info_log_addr_form(3) routines.
+/* .IP relay
+/* Host we could (not) talk to.
+/* .IP status
+/* bounced, deferred, sent, and so on.
+/* .IP dsn
+/* Delivery status information. See dsn(3).
+/* BUGS
+/* Should be replaced by routines with an attribute-value based
+/* interface instead of an interface that uses a rigid argument list.
+/* LICENSE
+/* .ad
+/* .fi
+/* The Secure Mailer license must be distributed with this software.
+/* AUTHOR(S)
+/* Wietse Venema
+/* IBM T.J. Watson Research
+/* P.O. Box 704
+/* Yorktown Heights, NY 10598, USA
+/*
+/* Wietse Venema
+/* Google, Inc.
+/* 111 8th Avenue
+/* New York, NY 10011, USA
+/*--*/
+
+/* System library. */
+
+#include <sys_defs.h>
+#include <string.h>
+
+/* Utility library. */
+
+#include <msg.h>
+#include <vstring.h>
+#include <format_tv.h>
+#include <stringops.h>
+
+/* Global library. */
+
+#include <log_adhoc.h>
+#include <mail_params.h>
+#include <info_log_addr_form.h>
+
+ /*
+ * Don't use "struct timeval" for time differences; use explicit signed
+ * types instead. The code below relies on signed values to detect clocks
+ * jumping back.
+ */
+typedef struct {
+ long dt_sec; /* make sure it's signed */
+ long dt_usec; /* make sure it's signed */
+} DELTA_TIME;
+
+/* log_adhoc - ad-hoc logging */
+
+void log_adhoc(const char *id, MSG_STATS *stats, RECIPIENT *recipient,
+ const char *relay, DSN *dsn,
+ const char *status)
+{
+ static VSTRING *buf;
+ 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 */
+ DELTA_TIME xdelay; /* transmission latency */
+ struct timeval now;
+
+ /*
+ * Alas, we need an intermediate buffer for the pre-formatted result.
+ * 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);
+
+ /*
+ * First, critical information that identifies the nature of the
+ * transaction.
+ */
+ vstring_sprintf(buf, "%s: to=<%s>", id,
+ info_log_addr_form_recipient(recipient->address));
+ if (recipient->orig_addr && *recipient->orig_addr
+ && strcasecmp_utf8(recipient->address, recipient->orig_addr) != 0)
+ vstring_sprintf_append(buf, ", orig_to=<%s>",
+ info_log_addr_form_recipient(recipient->orig_addr));
+ vstring_sprintf_append(buf, ", relay=%s", relay);
+ if (stats->reuse_count > 0)
+ vstring_sprintf_append(buf, ", conn_use=%d", stats->reuse_count + 1);
+
+ /*
+ * Next, performance statistics.
+ *
+ * Use wall clock time to compute pdelay (before active queue latency) if
+ * there is no time stamp for active queue entry. This happens when mail
+ * is bounced by the cleanup server.
+ *
+ * Otherwise, use wall clock time to compute adelay (active queue latency)
+ * if there is no time stamp for hand-off to delivery agent. This happens
+ * when mail was deferred or bounced by the queue manager.
+ *
+ * Otherwise, use wall clock time to compute xdelay (message transfer
+ * latency) if there is no time stamp for delivery completion. In the
+ * case of multi-recipient deliveries the delivery agent may specify the
+ * delivery completion time, so that multiple recipient records show the
+ * same delay values.
+ *
+ * Don't compute the sdelay (connection setup latency) if there is no time
+ * stamp for connection setup completion.
+ *
+ * XXX Apparently, Solaris gettimeofday() can return out-of-range
+ * microsecond values.
+ */
+#define DELTA(x, y, z) \
+ do { \
+ (x).dt_sec = (y).tv_sec - (z).tv_sec; \
+ (x).dt_usec = (y).tv_usec - (z).tv_usec; \
+ while ((x).dt_usec < 0) { \
+ (x).dt_usec += 1000000; \
+ (x).dt_sec -= 1; \
+ } \
+ while ((x).dt_usec >= 1000000) { \
+ (x).dt_usec -= 1000000; \
+ (x).dt_sec += 1; \
+ } \
+ if ((x).dt_sec < 0) \
+ (x).dt_sec = (x).dt_usec = 0; \
+ } while (0)
+
+#define DELTA_ZERO(x) ((x).dt_sec = (x).dt_usec = 0)
+
+#define TIME_STAMPED(x) ((x).tv_sec > 0)
+
+ if (TIME_STAMPED(stats->deliver_done))
+ now = stats->deliver_done;
+ else
+ GETTIMEOFDAY(&now);
+
+ DELTA(delay, now, stats->incoming_arrival);
+ DELTA_ZERO(adelay);
+ DELTA_ZERO(sdelay);
+ DELTA_ZERO(xdelay);
+ if (TIME_STAMPED(stats->active_arrival)) {
+ DELTA(pdelay, stats->active_arrival, stats->incoming_arrival);
+ if (TIME_STAMPED(stats->agent_handoff)) {
+ DELTA(adelay, stats->agent_handoff, stats->active_arrival);
+ if (TIME_STAMPED(stats->conn_setup_done)) {
+ DELTA(sdelay, stats->conn_setup_done, stats->agent_handoff);
+ DELTA(xdelay, now, stats->conn_setup_done);
+ } else {
+ /* No network client. */
+ DELTA(xdelay, now, stats->agent_handoff);
+ }
+ } else {
+ /* No delivery agent. */
+ DELTA(adelay, now, stats->active_arrival);
+ }
+ } else {
+ /* No queue manager. */
+ DELTA(pdelay, now, stats->incoming_arrival);
+ }
+
+ /*
+ * Round off large time values to an integral number of seconds, and
+ * 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, SIG_DIGS, var_delay_max_res); \
+ } while (0)
+
+ PRETTY_FORMAT(buf, ", delay=", delay);
+ PRETTY_FORMAT(buf, ", delays=", pdelay);
+ PRETTY_FORMAT(buf, "/", adelay);
+ PRETTY_FORMAT(buf, "/", sdelay);
+ PRETTY_FORMAT(buf, "/", xdelay);
+
+ /*
+ * Finally, the delivery status.
+ */
+ vstring_sprintf_append(buf, ", dsn=%s, status=%s (%s)",
+ dsn->status, status, dsn->reason);
+
+ /*
+ * Ship it off.
+ */
+ msg_info("%s", vstring_str(buf));
+}