Cleanups and improvements:

* Log more events (especially client session) and use a better scheme
  for that: each messages is prefixed with a token to easily identify
  its class:
    - info/warn/debug: general server messages
    - smtp-in: smtp client connections
    - relay: status update for relayed messages
    - delivery: status update for local deliveries

* Implement "smtpctl monitor" to display updates of selected internal
  counters.

* When reloading the on-disk queue at startup do not commit a message
  if no envelope was submitted for that message.

* Remove unused stuff in the config parser.

ok gilles@

32 files changed, 516 insertions, 325 deletions

diff --git a/usr.sbin/smtpd/aliases.c b/usr.sbin/smtpd/aliases.c
index 5c7d8420ad2..4827c8d34d3 100644
--- a/usr.sbin/smtpd/aliases.c
+++ b/usr.sbin/smtpd/aliases.c
@@ -1,4 +1,4 @@
-/*	$OpenBSD: aliases.c,v 1.57 2012/10/13 08:01:47 eric Exp $	*/
+/*	$OpenBSD: aliases.c,v 1.58 2012/11/12 14:58:53 eric Exp $	*/
 
 /*
  * Copyright (c) 2008 Gilles Chehade <gilles@openbsd.org>
@@ -68,7 +68,7 @@ aliases_get(objid_t mapid, struct expand *expand, const char *username)
 	expand_free(&map_alias->expand);
 	free(map_alias);
 
-	log_debug("aliases_get: returned %zd aliases", nbaliases);
+	log_debug("debug: aliases_get: returned %zd aliases", nbaliases);
 	return nbaliases;
 }
 
@@ -110,7 +110,7 @@ aliases_virtual_get(objid_t mapid, struct expand *expand,
 
 	expand_free(&map_virtual->expand);
 	free(map_virtual);
-	log_debug("aliases_virtual_get: '%s' resolved to %d nodes", pbuf, nbaliases);
+	log_debug("debug: aliases_virtual_get: '%s' resolved to %d nodes", pbuf, nbaliases);
 
 	return nbaliases;
 }
@@ -127,7 +127,7 @@ aliases_vdomain_exists(objid_t mapid, const char *hostname)
 		return (errno ? -1 : 0);
 
 	/* XXX - for now the map API always allocate */
-	log_debug("aliases_vdomain_exist: '%s' exists", hostname);
+	log_debug("debug: aliases_vdomain_exist: '%s' exists", hostname);
 	expand_free(&map_virtual->expand);
 	free(map_virtual);
 
@@ -146,7 +146,7 @@ aliases_expand_include(struct expand *expand, const char *filename)
 
 	fp = fopen(filename, "r");
 	if (fp == NULL) {
-		log_warn("failed to open include file \"%s\".", filename);
+		log_warn("warn: failed to open include file \"%s\".", filename);
 		return 0;
 	}
 
@@ -157,11 +157,11 @@ aliases_expand_include(struct expand *expand, const char *filename)
 		}
 
 		if (! alias_parse(&xn, line)) {
-			log_warnx("could not parse include entry \"%s\".", line);
+			log_warnx("warn: could not parse include entry \"%s\".", line);
 		}
 
 		if (xn.type == EXPAND_INCLUDE)
-			log_warnx("nested inclusion is not supported.");
+			log_warnx("warn: nested inclusion is not supported.");
 		else
 			expand_insert(expand, &xn);
 
diff --git a/usr.sbin/smtpd/bounce.c b/usr.sbin/smtpd/bounce.c
index 712de82a868..e2f09e6163e 100644
--- a/usr.sbin/smtpd/bounce.c
+++ b/usr.sbin/smtpd/bounce.c
@@ -1,4 +1,4 @@
-/*	$OpenBSD: bounce.c,v 1.51 2012/10/07 15:46:38 chl Exp $	*/
+/*	$OpenBSD: bounce.c,v 1.52 2012/11/12 14:58:53 eric Exp $	*/
 
 /*
  * Copyright (c) 2009 Gilles Chehade <gilles@openbsd.org>
@@ -111,7 +111,7 @@ bounce_add(uint64_t evpid)
 		bounce->msgid = evpid_to_msgid(evpid);
 		tree_xset(&bounces_by_msgid, bounce->msgid, bounce);
 
-		log_debug("bounce: %p: new bounce for msg:%08" PRIx32,
+		log_debug("debug: bounce: %p: new bounce for msg:%08" PRIx32,
 		    bounce, bounce->msgid);
 
 		TAILQ_INIT(&bounce->envelopes);
@@ -121,7 +121,7 @@ bounce_add(uint64_t evpid)
 		evtimer_add(&bounce->evt, &tv);
 	}
 
-	log_debug("bounce: %p: adding evp:%16" PRIx64, bounce, evp->id);
+	log_debug("debug: bounce: %p: adding evp:%16" PRIx64, bounce, evp->id);
 
 	TAILQ_INSERT_TAIL(&bounce->envelopes, evp, entry);
 	bounce->count += 1;
@@ -158,7 +158,7 @@ bounce_run(uint64_t id, int fd)
 	}
 
 	if ((bounce->msgfp = fdopen(msgfd, "r")) == NULL) {
-		log_warn("bounce_run: fdopen");
+		log_warn("warn: bounce_run: fdopen");
 		bounce_status(bounce, "error %i in fdopen", errno);
 		bounce_free(bounce);
 		close(msgfd);
@@ -203,20 +203,20 @@ bounce_drain()
 	while ((bounce = TAILQ_FIRST(&runnable))) {
 
 		if (running >= BOUNCE_MAXRUN) {
-			log_debug("bounce: max session reached");
+			log_debug("debug: bounce: max session reached");
 			return;
 		}
 
 		TAILQ_REMOVE(&runnable, bounce, entry);
 		if (TAILQ_FIRST(&bounce->envelopes) == NULL) {
-			log_debug("bounce: %p: no envelopes", bounce);
+			log_debug("debug: bounce: %p: no envelopes", bounce);
 			bounce_free(bounce);
 			continue;
 		}
 
 		tree_xset(&bounces_by_uid, bounce->id, bounce);
 
-		log_debug("bounce: %p: requesting enqueue socket with id 0x%016" PRIx64,
+		log_debug("debug: bounce: %p: requesting enqueue socket with id 0x%016" PRIx64,
 		    bounce, bounce->id);
 
 		imsg_compose_event(env->sc_ievs[PROC_SMTP], IMSG_SMTP_ENQUEUE,
@@ -408,7 +408,7 @@ bounce_free(struct bounce *bounce)
 {
 	struct envelope	*evp;
 
-	log_debug("bounce: %p: deleting session", bounce);
+	log_debug("debug: bounce: %p: deleting session", bounce);
 
 	/* if the envelopes where not sent, it is still in the tree */
 	tree_pop(&bounces_by_msgid, bounce->msgid);
diff --git a/usr.sbin/smtpd/control.c b/usr.sbin/smtpd/control.c
index ad85a35c6aa..e1eb8a925a9 100644
--- a/usr.sbin/smtpd/control.c
+++ b/usr.sbin/smtpd/control.c
@@ -1,4 +1,4 @@
-/*	$OpenBSD: control.c,v 1.77 2012/10/15 18:32:25 eric Exp $	*/
+/*	$OpenBSD: control.c,v 1.78 2012/11/12 14:58:53 eric Exp $	*/
 
 /*
  * Copyright (c) 2012 Gilles Chehade <gilles@openbsd.org>
@@ -36,6 +36,7 @@
 #include <stdio.h>
 #include <stdlib.h>
 #include <string.h>
+#include <time.h>
 #include <unistd.h>
 
 #include "smtpd.h"
@@ -64,11 +65,15 @@ static void control_close(struct ctl_conn *);
 static void control_sig_handler(int, short, void *);
 static void control_dispatch_ext(int, short, void *);
 
+static void control_digest_update(const char *, size_t, int);
+
 static struct stat_backend *stat_backend = NULL;
 extern const char *backend_stat;
 
 static TAILQ_HEAD(, ctl_conn)	ctl_conns;
 
+static struct stat_digest	digest;
+
 #define	CONTROL_FD_RESERVE	5
 
 static void
@@ -96,12 +101,14 @@ control_imsg(struct imsgev *iev, struct imsg *imsg)
 		key = (char*)imsg->data + sizeof (val);
 		if (stat_backend)
 			stat_backend->increment(key, val.u.counter);
+		control_digest_update(key, val.u.counter, 1);
 		return;
 	case IMSG_STAT_DECREMENT:
 		memmove(&val, imsg->data, sizeof (val));
 		key = (char*)imsg->data + sizeof (val);
 		if (stat_backend)
 			stat_backend->decrement(key, val.u.counter);
+		control_digest_update(key, val.u.counter, 0);
 		return;
 	case IMSG_STAT_SET:
 		memmove(&val, imsg->data, sizeof (val));
@@ -221,6 +228,9 @@ control(void)
 
 	TAILQ_INIT(&ctl_conns);
 
+	bzero(&digest, sizeof digest);
+	digest.startup = time(NULL);
+
 	config_pipes(peers, nitems(peers));
 	config_peers(peers, nitems(peers));
 	control_listen();
@@ -235,7 +245,7 @@ control(void)
 static void
 control_shutdown(void)
 {
-	log_info("control process exiting");
+	log_info("info: control process exiting");
 	unlink(SMTPD_SOCKET);
 	_exit(0);
 }
@@ -287,7 +297,7 @@ control_accept(int listenfd, short event, void *arg)
 	return;
 
 pause:
-	log_warnx("ctl client limit hit, disabling new connections");
+	log_warnx("warn: ctl client limit hit, disabling new connections");
 	event_del(&control_state.ev);
 }
 
@@ -318,11 +328,54 @@ control_close(struct ctl_conn *c)
 		return;
 
 	if (!event_pending(&control_state.ev, EV_READ, NULL)) {
-		log_warnx("re-enabling ctl connections");
+		log_warnx("warn: re-enabling ctl connections");
 		event_add(&control_state.ev, NULL);
 	}
 }
 
+static void
+control_digest_update(const char *key, size_t value, int incr)
+{
+	size_t	*p;
+
+	p = NULL;
+
+	if (!strcmp(key, "smtp.session")) {
+		if (incr)
+			p = &digest.clt_connect;
+		else
+			digest.clt_disconnect += value;
+	}
+	else if (!strcmp(key, "scheduler.envelope")) {
+		if (incr)
+			p = &digest.evp_enqueued;
+		else
+			digest.evp_dequeued += value;
+	}
+	else if  (!strcmp(key, "scheduler.envelope.expired"))
+		p = &digest.evp_expired;
+	else if  (!strcmp(key, "scheduler.envelope.removed"))
+		p = &digest.evp_removed;
+	else if  (!strcmp(key, "scheduler.delivery.ok"))
+		p = &digest.dlv_ok;
+	else if  (!strcmp(key, "scheduler.delivery.permfail"))
+		p = &digest.dlv_permfail;
+	else if  (!strcmp(key, "scheduler.delivery.tempfail"))
+		p = &digest.dlv_tempfail;
+	else if  (!strcmp(key, "scheduler.delivery.loop"))
+		p = &digest.dlv_loop;
+
+	else if  (!strcmp(key, "queue.bounce"))
+		p = &digest.evp_bounce;
+
+	if (p) {
+		if (incr)
+			*p = *p + value;
+		else
+			*p = *p - value;
+	}
+}
+
 /* ARGSUSED */
 static void
 control_dispatch_ext(int fd, short event, void *arg)
@@ -342,7 +395,7 @@ control_dispatch_ext(int fd, short event, void *arg)
 		fatal("getpeereid");
 
 	if ((c = control_connbyfd(fd)) == NULL) {
-		log_warn("control_dispatch_ext: fd %d: not found", fd);
+		log_warn("warn: control_dispatch_ext: fd %d: not found", fd);
 		return;
 	}
 
@@ -387,6 +440,14 @@ control_dispatch_ext(int fd, short event, void *arg)
 			imsg_compose_event(&c->iev, IMSG_STATS, 0, 0, -1, NULL, 0);
 			break;
 
+		case IMSG_DIGEST:
+			if (euid)
+				goto badcred;
+			digest.timestamp = time(NULL);
+			imsg_compose_event(&c->iev, IMSG_DIGEST, 0, 0, -1,
+			    &digest, sizeof digest);
+			break;
+
 		case IMSG_STATS_GET:
 			if (euid)
 				goto badcred;
@@ -403,7 +464,7 @@ control_dispatch_ext(int fd, short event, void *arg)
 
 		case IMSG_CTL_SHUTDOWN:
 			/* NEEDS_FIX */
-			log_debug("received shutdown request");
+			log_debug("debug: received shutdown request");
 
 			if (euid)
 				goto badcred;
@@ -443,7 +504,7 @@ control_dispatch_ext(int fd, short event, void *arg)
 					NULL, 0);
 				break;
 			}
-			log_info("mda paused");
+			log_info("info: mda paused");
 			env->sc_flags |= SMTPD_MDA_PAUSED;
 			imsg_compose_event(env->sc_ievs[PROC_QUEUE],
 			    IMSG_QUEUE_PAUSE_MDA, 0, 0, -1, NULL, 0);
@@ -459,7 +520,7 @@ control_dispatch_ext(int fd, short event, void *arg)
 					NULL, 0);
 				break;
 			}
-			log_info("mta paused");
+			log_info("info: mta paused");
 			env->sc_flags |= SMTPD_MTA_PAUSED;
 			imsg_compose_event(env->sc_ievs[PROC_QUEUE],
 			    IMSG_QUEUE_PAUSE_MTA, 0, 0, -1, NULL, 0);
@@ -475,7 +536,7 @@ control_dispatch_ext(int fd, short event, void *arg)
 					NULL, 0);
 				break;
 			}
-			log_info("smtp paused");
+			log_info("info: smtp paused");
 			env->sc_flags |= SMTPD_SMTP_PAUSED;
 			imsg_compose_event(env->sc_ievs[PROC_SMTP], IMSG_SMTP_PAUSE,			
 			    0, 0, -1, NULL, 0);
@@ -491,7 +552,7 @@ control_dispatch_ext(int fd, short event, void *arg)
 					NULL, 0);
 				break;
 			}
-			log_info("mda resumed");
+			log_info("info: mda resumed");
 			env->sc_flags &= ~SMTPD_MDA_PAUSED;
 			imsg_compose_event(env->sc_ievs[PROC_QUEUE],
 			    IMSG_QUEUE_RESUME_MDA, 0, 0, -1, NULL, 0);
@@ -507,7 +568,7 @@ control_dispatch_ext(int fd, short event, void *arg)
 					NULL, 0);
 				break;
 			}
-			log_info("mta resumed");
+			log_info("info: mta resumed");
 			env->sc_flags &= ~SMTPD_MTA_PAUSED;
 			imsg_compose_event(env->sc_ievs[PROC_QUEUE],
 			    IMSG_QUEUE_RESUME_MTA, 0, 0, -1, NULL, 0);
@@ -523,7 +584,7 @@ control_dispatch_ext(int fd, short event, void *arg)
 					NULL, 0);
 				break;
 			}
-			log_info("smtp resumed");
+			log_info("info: smtp resumed");
 			env->sc_flags &= ~SMTPD_SMTP_PAUSED;
 			imsg_compose_event(env->sc_ievs[PROC_SMTP], IMSG_SMTP_RESUME,
 			    0, 0, -1, NULL, 0);
@@ -566,7 +627,7 @@ control_dispatch_ext(int fd, short event, void *arg)
 			break;
 
 		default:
-			log_debug("control_dispatch_ext: "
+			log_debug("debug: control_dispatch_ext: "
 			    "error handling %s imsg",
 			    imsg_to_str(imsg.hdr.type));
 			break;
diff --git a/usr.sbin/smtpd/dns.c b/usr.sbin/smtpd/dns.c
index 3d00e4ee223..c3dad9f77a3 100644
--- a/usr.sbin/smtpd/dns.c
+++ b/usr.sbin/smtpd/dns.c
@@ -1,4 +1,4 @@
-/*	$OpenBSD: dns.c,v 1.60 2012/10/08 08:46:24 eric Exp $	*/
+/*	$OpenBSD: dns.c,v 1.61 2012/11/12 14:58:53 eric Exp $	*/
 
 /*
  * Copyright (c) 2008 Gilles Chehade <gilles@openbsd.org>
@@ -128,10 +128,10 @@ dns_async(struct imsgev *asker, int type, struct dns *query)
 
 	switch (type) {
 	case IMSG_DNS_HOST:
-		log_debug("dns: lookup host \"%s\"", query->host);
+		log_debug("debug: dns: lookup host \"%s\"", query->host);
 		if (sockaddr_from_str((struct sockaddr*)&query->ss, PF_UNSPEC,
 		    query->host) == 0) {
-			log_debug("dns:  \"%s\" is an IP address", query->host);
+			log_debug("debug: dns:  \"%s\" is an IP address", query->host);
 			query->error = DNS_OK;
 			dns_reply(query, IMSG_DNS_HOST);
 			dns_reply(query, IMSG_DNS_HOST_END);
@@ -149,23 +149,23 @@ dns_async(struct imsgev *asker, int type, struct dns *query)
 		    s->query.host, sizeof(s->query.host), NULL, 0, 0, NULL);
 		stat_increment("lka.session.cname", 1);
 		if (s->as == NULL) {
-			log_debug("dns_async: asr_query_cname error");
+			log_debug("debug: dns_async: asr_query_cname error");
 			break;
 		}
 		dns_asr_dispatch_cname(s);
 		return;
 	case IMSG_DNS_MX:
-		log_debug("dns: lookup mx \"%s\"", query->host);
+		log_debug("debug: dns: lookup mx \"%s\"", query->host);
 		s->as = res_query_async(query->host, C_IN, T_MX, NULL, 0, NULL);
 		stat_increment("lka.session.mx", 1);
 		if (s->as == NULL) {
-			log_debug("dns_async: asr_query_dns error");
+			log_debug("debug: dns_async: asr_query_dns error");
 			break;
 		}
 		dns_asr_dispatch_mx(s);
 		return;
 	default:
-		log_debug("dns_async: bad request");
+		log_debug("debug: dns_async: bad request");
 		break;
 	}
 
@@ -294,7 +294,7 @@ next:
 		if (mx == NULL || (s->preference != -1
 		    && s->preference <= mx->preference)) {
 			if (mx)
-				log_debug("dns: ignoring mx with lower preference");
+				log_debug("debug: dns: ignoring mx with lower preference");
 			if (s->mxfound)
 				query->error = DNS_OK;
 			dns_reply(query, IMSG_DNS_HOST_END);
@@ -302,7 +302,7 @@ next:
 			return;
 		}
 
-		log_debug("dns: resolving address for \"%s\"", mx->host);
+		log_debug("debug: dns: resolving address for \"%s\"", mx->host);
 
 		memset(&hints, 0, sizeof(hints));
 		hints.ai_family = PF_UNSPEC;
@@ -321,7 +321,7 @@ next:
 	if (ar.ar_gai_errno == 0) {
 		for (ai = ar.ar_addrinfo; ai; ai = ai->ai_next) {
 			memcpy(&query->ss, ai->ai_addr, ai->ai_addrlen);
-			log_debug("dns: got address %s", ss_to_text(&query->ss));
+			log_debug("debug: dns: got address %s", ss_to_text(&query->ss));
 			dns_reply(query, IMSG_DNS_HOST);
 			s->mxfound++;
 		}
@@ -393,7 +393,7 @@ dnssession_mx_insert(struct dnssession *s, const char *host, int preference)
 	mx->host = xstrdup(host, "dnssession_mx_insert");
 	mx->preference = preference;
 
-	log_debug("dns: found mx \"%s\" with preference %i", host, preference);
+	log_debug("debug: dns: found mx \"%s\" with preference %i", host, preference);
 
 	TAILQ_FOREACH(e, &s->mx, entry) {
 		if (mx->preference <= e->preference) {
@@ -407,7 +407,7 @@ dnssession_mx_insert(struct dnssession *s, const char *host, int preference)
 end:
 	if (s->preference == -1 && s->query.backup[0]
 	    && !strcasecmp(host, s->query.backup)) {
-		log_debug("dns: found our backup preference");
+		log_debug("debug: dns: found our backup preference");
 		s->preference = preference;
 	}
 }
diff --git a/usr.sbin/smtpd/enqueue.c b/usr.sbin/smtpd/enqueue.c
index c5aeb83ec6f..2254a74c208 100644
--- a/usr.sbin/smtpd/enqueue.c
+++ b/usr.sbin/smtpd/enqueue.c
@@ -1,4 +1,4 @@
-/*	$OpenBSD: enqueue.c,v 1.63 2012/09/27 20:34:15 chl Exp $	*/
+/*	$OpenBSD: enqueue.c,v 1.64 2012/11/12 14:58:53 eric Exp $	*/
 
 /*
  * Copyright (c) 2005 Henning Brauer <henning@bulabula.org>
@@ -406,13 +406,17 @@ send_line(FILE *fp, int v, char *fmt, ...)
 	int ret;
 	va_list ap;
 
-	if (v)
-		printf(">>> ");
 	va_start(ap, fmt);
 	ret = vfprintf(fp, fmt, ap);
-	if (v)
-		ret = vprintf(fmt, ap);
 	va_end(ap);
+
+	if (v) {
+		va_start(ap, fmt);
+		printf(">>> ");
+		ret = vprintf(fmt, ap);
+		va_end(ap);
+	}
+
 	return (ret);
 }
 
diff --git a/usr.sbin/smtpd/forward.c b/usr.sbin/smtpd/forward.c
index 247cb000859..ff1a5580f68 100644
--- a/usr.sbin/smtpd/forward.c
+++ b/usr.sbin/smtpd/forward.c
@@ -1,4 +1,4 @@
-/*	$OpenBSD: forward.c,v 1.31 2012/09/27 17:47:49 chl Exp $	*/
+/*	$OpenBSD: forward.c,v 1.32 2012/11/12 14:58:53 eric Exp $	*/
 
 /*
  * Copyright (c) 2008 Gilles Chehade <gilles@openbsd.org>
@@ -82,7 +82,7 @@ forwards_get(int fd, struct expand *expand)
 			cp = p;
 
 			if (! alias_parse(&xn, buf)) {
-				log_debug("bad entry in ~/.forward");
+				log_debug("debug: bad entry in ~/.forward");
 				continue;
 			}
 
diff --git a/usr.sbin/smtpd/ioev.c b/usr.sbin/smtpd/ioev.c
index 3f66fc6667b..4905c108444 100644
--- a/usr.sbin/smtpd/ioev.c
+++ b/usr.sbin/smtpd/ioev.c
@@ -1,4 +1,4 @@
-/*	$OpenBSD: ioev.c,v 1.7 2012/10/25 18:14:24 eric Exp $	*/
+/*	$OpenBSD: ioev.c,v 1.8 2012/11/12 14:58:53 eric Exp $	*/
 /*      
  * Copyright (c) 2012 Eric Faurot <eric@openbsd.org>
  *
@@ -543,7 +543,7 @@ io_dispatch(int fd, short ev, void *humppa)
 	if (ev & EV_WRITE && (w = io_queued(io))) {
 		if ((n = iobuf_write(io->iobuf, io->sock)) < 0) {
 			if (n == IOBUF_ERROR || n == IOBUF_WANT_WRITE)
-				log_warn("io_dispatch: iobuf_write");
+				log_warn("warn: io_dispatch: iobuf_write");
 			if (n == IOBUF_WANT_WRITE)  /* kqueue bug? */
 				goto read;
 			io_callback(io, n == IOBUF_CLOSED ?
@@ -558,7 +558,7 @@ io_dispatch(int fd, short ev, void *humppa)
 	if (ev & EV_READ) {
 		if ((n = iobuf_read(io->iobuf, io->sock)) < 0) {
 			if (n == IO_ERROR)
-				log_warn("io_dispatch: iobuf_read");
+				log_warn("warn: io_dispatch: iobuf_read");
 			io_callback(io, n == IOBUF_CLOSED ?
 			    IO_DISCONNECTED : IO_ERROR);
 			goto leave;
diff --git a/usr.sbin/smtpd/lka.c b/usr.sbin/smtpd/lka.c
index 0b260b8ef20..eb412c50992 100644
--- a/usr.sbin/smtpd/lka.c
+++ b/usr.sbin/smtpd/lka.c
@@ -1,4 +1,4 @@
-/*	$OpenBSD: lka.c,v 1.145 2012/10/14 11:58:23 gilles Exp $	*/
+/*	$OpenBSD: lka.c,v 1.146 2012/11/12 14:58:53 eric Exp $	*/
 
 /*
  * Copyright (c) 2008 Pierre-Yves Ritschard <pyr@openbsd.org>
@@ -107,7 +107,7 @@ lka_imsg(struct imsgev *iev, struct imsg *imsg)
 			secret = imsg->data;
 			map = map_findbyname(secret->mapname);
 			if (map == NULL) {
-				log_warn("lka: credentials map %s is missing",
+				log_warn("warn: lka: credentials map %s is missing",
 				    secret->mapname);
 				imsg_compose_event(iev, IMSG_LKA_SECRET, 0, 0,
 				    -1, secret, sizeof *secret);
@@ -115,15 +115,15 @@ lka_imsg(struct imsgev *iev, struct imsg *imsg)
 			}
 			map_credentials = map_lookup(map->m_id, secret->host,
 			    K_CREDENTIALS);
-			log_debug("lka: %s credentials lookup (%d)", secret->host,
+			log_debug("debug: lka: %s credentials lookup (%d)", secret->host,
 			    map_credentials != NULL);
 			secret->secret[0] = '\0';
 			if (map_credentials == NULL)
-				log_warnx("%s credentials not found",
+				log_warnx("warn: %s credentials not found",
 				    secret->host);
 			else if (lka_encode_credentials(secret->secret,
 				     sizeof secret->secret, map_credentials) == 0)
-				log_warnx("%s credentials parse fail",
+				log_warnx("warn: %s credentials parse fail",
 				    secret->host);
 			imsg_compose_event(iev, IMSG_LKA_SECRET, 0, 0, -1, secret,
 			    sizeof *secret);
@@ -211,7 +211,7 @@ lka_imsg(struct imsgev *iev, struct imsg *imsg)
 		case IMSG_LKA_UPDATE_MAP:
 			map = map_findbyname(imsg->data);
 			if (map == NULL) {
-				log_warnx("lka: no such map \"%s\"",
+				log_warnx("warn: lka: no such map \"%s\"",
 				    (char *)imsg->data);
 				return;
 			}
@@ -247,7 +247,7 @@ lka_sig_handler(int sig, short event, void *p)
 void
 lka_shutdown(void)
 {
-	log_info("lookup agent exiting");
+	log_info("info: lookup agent exiting");
 	_exit(0);
 }
 
diff --git a/usr.sbin/smtpd/lka_session.c b/usr.sbin/smtpd/lka_session.c
index 754aba5c9b6..9885c549625 100644
--- a/usr.sbin/smtpd/lka_session.c
+++ b/usr.sbin/smtpd/lka_session.c
@@ -1,4 +1,4 @@
-/*	$OpenBSD: lka_session.c,v 1.48 2012/10/16 11:10:38 eric Exp $	*/
+/*	$OpenBSD: lka_session.c,v 1.49 2012/11/12 14:58:53 eric Exp $	*/
 
 /*
  * Copyright (c) 2011 Gilles Chehade <gilles@openbsd.org>
@@ -113,12 +113,12 @@ lka_session_forward_reply(struct forward_req *fwreq, int fd)
 
 	if (fd == -1 && fwreq->status) {
 		/* no .forward, just deliver to local user */
-		log_debug("lka: no .forward for user %s, just deliver",
+		log_debug("debug: lka: no .forward for user %s, just deliver",
 		    fwreq->as_user);
 		lka_submit(lks, rule, xn);
 	}
 	else if (fd == -1) {
-		log_debug("lka: opening .forward failed for user %s",
+		log_debug("debug: lka: opening .forward failed for user %s",
 		    fwreq->as_user);
 		lks->ss.code = 530;
 		lks->flags |= F_ERROR;
@@ -159,7 +159,7 @@ lka_resume(struct lka_session *lks)
 
 	/* delivery list is empty, reject */
 	if (TAILQ_FIRST(&lks->deliverylist) == NULL) {
-		log_info("lka_done: expansion led to empty delivery list");
+		log_debug("debug: lka_done: expansion led to empty delivery list");
 		lks->flags |= F_ERROR;
 	}
     error:
@@ -200,7 +200,7 @@ lka_expand(struct lka_session *lks, struct rule *rule, struct expandnode *xn)
 	int			r;
 
 	if (xn->depth >= EXPAND_DEPTH) {
-		log_debug("lka_expand: node too deep.");
+		log_debug("debug: lka_expand: node too deep.");
 		lks->flags |= F_ERROR;
 		lks->ss.code = 530;
 		return;
@@ -213,7 +213,7 @@ lka_expand(struct lka_session *lks, struct rule *rule, struct expandnode *xn)
 		break;
 
 	case EXPAND_ADDRESS:
-		log_debug("lka_expand: expanding address: %s@%s [depth=%d]",
+		log_debug("debug: lka_expand: expanding address: %s@%s [depth=%d]",
 		    xn->u.mailaddr.user, xn->u.mailaddr.domain, xn->depth);
 
 		/* Pass the node through the ruleset */
@@ -246,7 +246,7 @@ lka_expand(struct lka_session *lks, struct rule *rule, struct expandnode *xn)
 			else if (r == 0) {
 				lks->flags |= F_ERROR;
 				lks->ss.code = 530;
-				log_debug("lka_expand: no aliases for virtual");
+				log_debug("debug: lka_expand: no aliases for virtual");
 			}
 		}
 		else {
@@ -261,10 +261,10 @@ lka_expand(struct lka_session *lks, struct rule *rule, struct expandnode *xn)
 		break;
 
 	case EXPAND_USERNAME:
-		log_debug("lka_expand: expanding username: %s [depth=%d]", xn->u.user, xn->depth);
+		log_debug("debug: lka_expand: expanding username: %s [depth=%d]", xn->u.user, xn->depth);
 
 		if (xn->sameuser) {
-			log_debug("lka_expand: same user, submitting");
+			log_debug("debug: lka_expand: same user, submitting");
 			lka_submit(lks, rule, xn);
 			break;
 		}
@@ -276,7 +276,7 @@ lka_expand(struct lka_session *lks, struct rule *rule, struct expandnode *xn)
 		if (rule->r_amap) {
 			r = aliases_get(rule->r_amap, &lks->expand, xn->u.user);
 			if (r == -1) {
-				log_debug("lka_expand: error in alias lookup");
+				log_debug("debug: lka_expand: error in alias lookup");
 				lks->flags |= F_ERROR;
 				lks->ss.code = 451;
 			}
@@ -286,7 +286,7 @@ lka_expand(struct lka_session *lks, struct rule *rule, struct expandnode *xn)
 
 		/* a username should not exceed the size of a system user */
 		if (strlen(xn->u.user) >= sizeof fwreq.as_user) {
-			log_debug("lka_expand: user-part too long to be a system user");
+			log_debug("debug: lka_expand: user-part too long to be a system user");
 			lks->flags |= F_ERROR;
 			lks->ss.code = 530;
 			break;
@@ -294,7 +294,7 @@ lka_expand(struct lka_session *lks, struct rule *rule, struct expandnode *xn)
 
 		pw = getpwnam(xn->u.user);
 		if (pw == NULL) {
-			log_debug("lka_expand: user-part does not match system user");
+			log_debug("debug: lka_expand: user-part does not match system user");
 			lks->flags |= F_ERROR;
 			lks->ss.code = 530;
 			break;
@@ -311,12 +311,12 @@ lka_expand(struct lka_session *lks, struct rule *rule, struct expandnode *xn)
 		break;
 
 	case EXPAND_FILENAME:
-		log_debug("lka_expand: expanding filename: %s [depth=%d]", xn->u.buffer, xn->depth);
+		log_debug("debug: lka_expand: expanding filename: %s [depth=%d]", xn->u.buffer, xn->depth);
 		lka_submit(lks, rule, xn);
 		break;
 
 	case EXPAND_FILTER:
-		log_debug("lka_expand: expanding filter: %s [depth=%d]", xn->u.buffer, xn->depth);
+		log_debug("debug: lka_expand: expanding filter: %s [depth=%d]", xn->u.buffer, xn->depth);
 		lka_submit(lks, rule, xn);
 		break;
 	}
@@ -328,7 +328,7 @@ lka_find_ancestor(struct expandnode *xn, enum expand_type type)
 	while(xn && (xn->type != type))
 		xn = xn->parent;
 	if (xn == NULL) {
-		log_warnx("lka_find_ancestor: no ancestors of type %i", type);
+		log_warnx("warn: lka_find_ancestor: no ancestors of type %i", type);
 		fatalx(NULL);
 	}
 	return (xn);
@@ -407,7 +407,7 @@ lka_submit(struct lka_session *lks, struct rule *rule, struct expandnode *xn)
 					sizeof(ep->agent.mda.buffer), ep)) {
 			lks->flags |= F_ERROR;
 			lks->ss.code = 451;
-			log_warnx("format string result too long while "
+			log_warnx("warn: format string result too long while "
 			    " expanding for user %s", ep->agent.mda.user);
 			free(ep);
 			return;
diff --git a/usr.sbin/smtpd/map.c b/usr.sbin/smtpd/map.c
index 5eb39173e16..2adbe2e55c8 100644
--- a/usr.sbin/smtpd/map.c
+++ b/usr.sbin/smtpd/map.c
@@ -1,4 +1,4 @@
-/*	$OpenBSD: map.c,v 1.34 2012/10/14 11:58:23 gilles Exp $	*/
+/*	$OpenBSD: map.c,v 1.35 2012/11/12 14:58:53 eric Exp $	*/
 
 /*
  * Copyright (c) 2008 Gilles Chehade <gilles@openbsd.org>
@@ -102,7 +102,7 @@ map_lookup(objid_t mapid, const char *key, enum map_kind kind)
 	backend = map_backend_lookup(map->m_src);
 	hdl = backend->open(map);
 	if (hdl == NULL) {
-		log_warn("map_lookup: can't open %s", map->m_config);
+		log_warn("warn: map_lookup: can't open %s", map->m_config);
 		if (errno == 0)
 			errno = ENOTSUP;
 		return NULL;
@@ -133,7 +133,7 @@ map_compare(objid_t mapid, const char *key, enum map_kind kind,
 	backend = map_backend_lookup(map->m_src);
 	hdl = backend->open(map);
 	if (hdl == NULL) {
-		log_warn("map_compare: can't open %s", map->m_config);
+		log_warn("warn: map_compare: can't open %s", map->m_config);
 		if (errno == 0)
 			errno = ENOTSUP;
 		return 0;
@@ -203,14 +203,14 @@ map_add(struct map *m, const char *key, const char * val)
 		errx(1, "map_add: cannot add to map");
 
 	me = xcalloc(1, sizeof(*me), "map_add");
-	n = strlcpy(me->me_key.med_string, key, sizeof(me->me_key.med_string));
-	if (n >= sizeof(me->me_key.med_string))
+	n = strlcpy(me->me_key, key, sizeof(me->me_key));
+	if (n >= sizeof(me->me_key))
 		errx(1, "map_add: key too long");
 
 	if (val) {
-		n = strlcpy(me->me_val.med_string, val,
-		    sizeof(me->me_val.med_string));
-		if (n >= sizeof(me->me_val.med_string))
+		n = strlcpy(me->me_val, val,
+		    sizeof(me->me_val));
+		if (n >= sizeof(me->me_val))
 			errx(1, "map_add: value too long");
 	}
 
@@ -226,7 +226,7 @@ map_delete(struct map *m, const char *key)
 		errx(1, "map_add: cannot delete from map");
 
 	TAILQ_FOREACH(me, &m->m_contents, me_entry) {
-		if (strcmp(me->me_key.med_string, key) == 0)
+		if (strcmp(me->me_key, key) == 0)
 			break;
 	}
 	if (me == NULL)
diff --git a/usr.sbin/smtpd/map_db.c b/usr.sbin/smtpd/map_db.c
index 4e33ac6c149..afbd2e1cd1c 100644
--- a/usr.sbin/smtpd/map_db.c
+++ b/usr.sbin/smtpd/map_db.c
@@ -1,4 +1,4 @@
-/*	$OpenBSD: map_db.c,v 1.11 2012/10/14 11:58:23 gilles Exp $	*/
+/*	$OpenBSD: map_db.c,v 1.12 2012/11/12 14:58:53 eric Exp $	*/
 
 /*
  * Copyright (c) 2011 Gilles Chehade <gilles@openbsd.org>
@@ -125,7 +125,7 @@ map_db_compare(void *hdl, const char *key, enum map_kind kind,
 	for (r = db->seq(db, &dbk, &dbd, R_FIRST); !r;
 	     r = db->seq(db, &dbk, &dbd, R_NEXT)) {
 		buf = xmemdup(dbk.data, dbk.size + 1, "map_db_compare");
-		log_debug("key: %s, buf: %s", key, buf);
+		log_debug("debug: key: %s, buf: %s", key, buf);
 		if (func(key, buf))
 			ret = 1;
 		free(buf);
diff --git a/usr.sbin/smtpd/map_file.c b/usr.sbin/smtpd/map_file.c
index 8d9e612fcad..47977dcf523 100644
--- a/usr.sbin/smtpd/map_file.c
+++ b/usr.sbin/smtpd/map_file.c
@@ -1,4 +1,4 @@
-/*	$OpenBSD: map_file.c,v 1.1 2012/10/14 11:58:23 gilles Exp $	*/
+/*	$OpenBSD: map_file.c,v 1.2 2012/11/12 14:58:53 eric Exp $	*/
 
 /*
  * Copyright (c) 2012 Gilles Chehade <gilles@openbsd.org>
@@ -112,7 +112,7 @@ map_file_open(struct map *map)
 
 	map->m_handle = mp;
 
-	log_info("map_file_open: initialized map \"%s\" from %s",
+	log_debug("debug: map_file_open: initialized map \"%s\" from %s",
 	    map->m_name, map->m_config);
 
 	return mp;
@@ -135,8 +135,8 @@ map_file_update(struct map *map)
 
 	fp = fopen(map->m_config, "r");
 	if (fp == NULL) {
-		log_info("map_file_update: could not update map \"%s\" from %s: %s",
-		    map->m_name, map->m_config, strerror(errno));
+		log_warn("warn: Could not update map \"%s\" from %s",
+		    map->m_name, map->m_config);
 		return;
 	}
 
@@ -150,8 +150,7 @@ map_file_update(struct map *map)
 	}
 
 	map->m_handle = mp;
-	log_info("map_file_update: updated map \"%s\" from %s",
-	    map->m_name, map->m_config);
+	log_info("info: Updated map \"%s\" from %s", map->m_name, map->m_config);
 }
 
 static void
diff --git a/usr.sbin/smtpd/map_static.c b/usr.sbin/smtpd/map_static.c
index c66da1025b1..9f998243fec 100644
--- a/usr.sbin/smtpd/map_static.c
+++ b/usr.sbin/smtpd/map_static.c
@@ -1,4 +1,4 @@
-/*	$OpenBSD: map_static.c,v 1.8 2012/10/14 11:58:23 gilles Exp $	*/
+/*	$OpenBSD: map_static.c,v 1.9 2012/11/12 14:58:53 eric Exp $	*/
 
 /*
  * Copyright (c) 2012 Gilles Chehade <gilles@openbsd.org>
@@ -78,10 +78,10 @@ map_static_lookup(void *hdl, const char *key, enum map_kind kind)
 
 	line = NULL;
 	TAILQ_FOREACH(me, &m->m_contents, me_entry) {
-		if (strcmp(key, me->me_key.med_string) == 0) {
-			if (me->me_val.med_string == NULL)
+		if (strcmp(key, me->me_key) == 0) {
+			if (me->me_val == NULL)
 				return NULL;
-			line = strdup(me->me_val.med_string);
+			line = strdup(me->me_val);
 			break;
 		}
 	}
@@ -126,7 +126,7 @@ map_static_compare(void *hdl, const char *key, enum map_kind kind,
 	int		 ret = 0;
 
 	TAILQ_FOREACH(me, &m->m_contents, me_entry) {
-		if (! func(key, me->me_key.med_string))
+		if (! func(key, me->me_key))
 			continue;
 		ret = 1;
 		break;
diff --git a/usr.sbin/smtpd/mda.c b/usr.sbin/smtpd/mda.c
index e7a1ffe03a3..95c4a812481 100644
--- a/usr.sbin/smtpd/mda.c
+++ b/usr.sbin/smtpd/mda.c
@@ -1,4 +1,4 @@
-/*	$OpenBSD: mda.c,v 1.83 2012/11/02 16:02:33 eric Exp $	*/
+/*	$OpenBSD: mda.c,v 1.84 2012/11/12 14:58:53 eric Exp $	*/
 
 /*
  * Copyright (c) 2008 Gilles Chehade <gilles@openbsd.org>
@@ -107,7 +107,7 @@ mda_imsg(struct imsgev *iev, struct imsg *imsg)
 			ep = xmemdup(imsg->data, sizeof *ep, "mda_imsg");
 
 			if (evpcount >= MDA_MAXEVP) {
-				log_debug("mda: too many envelopes");
+				log_debug("debug: mda: too many envelopes");
 				envelope_set_errormsg(ep,
 				    "Global envelope limit reached");
 				imsg_compose_event(env->sc_ievs[PROC_QUEUE],
@@ -122,7 +122,7 @@ mda_imsg(struct imsgev *iev, struct imsg *imsg)
 				if (!strcmp(name, u->name))
 					break;
 			if (u && u->evpcount >= MDA_MAXEVPUSER) {
-				log_debug("mda: too many envelopes for \"%s\"",
+				log_debug("debug: mda: too many envelopes for \"%s\"",
 				    u->name);
 				envelope_set_errormsg(ep,
 				    "User envelope limit reached");
@@ -139,7 +139,7 @@ mda_imsg(struct imsgev *iev, struct imsg *imsg)
 				TAILQ_INSERT_TAIL(&users, u, entry);
 			}
 			if (u->runnable == 0 && u->running < MDA_MAXSESSUSER) {
-				log_debug("mda: \"%s\" immediatly runnable",
+				log_debug("debug: mda: \"%s\" immediatly runnable",
 				    u->name);
 				TAILQ_INSERT_TAIL(&runnable, u, entry_runnable);
 				u->runnable = 1;
@@ -158,7 +158,7 @@ mda_imsg(struct imsgev *iev, struct imsg *imsg)
 			s = tree_xget(&sessions, id);
 
 			if (imsg->fd == -1) {
-				log_debug("mda: cannot get message fd");
+				log_debug("debug: mda: cannot get message fd");
 				envelope_set_errormsg(s->evp,
 				    "Cannot get message fd");
 				mda_done(s, IMSG_QUEUE_DELIVERY_TEMPFAIL);
@@ -166,7 +166,7 @@ mda_imsg(struct imsgev *iev, struct imsg *imsg)
 			}
 
 			if ((s->datafp = fdopen(imsg->fd, "r")) == NULL) {
-				log_warn("mda: fdopen");
+				log_warn("warn: mda: fdopen");
 				envelope_set_errormsg(s->evp, "fdopen failed");
 				mda_done(s, IMSG_QUEUE_DELIVERY_TEMPFAIL);
 				return;
@@ -174,7 +174,7 @@ mda_imsg(struct imsgev *iev, struct imsg *imsg)
 
 			/* check delivery loop */
 			if (mda_check_loop(s->datafp, s->evp)) {
-				log_debug("mda: loop detected");
+				log_debug("debug: mda: loop detected");
 				envelope_set_errormsg(s->evp, "Loop detected");
 				mda_done(s, IMSG_QUEUE_DELIVERY_LOOP);
 				return;
@@ -194,7 +194,7 @@ mda_imsg(struct imsgev *iev, struct imsg *imsg)
 				    s->evp->rcpt.user,
 				    s->evp->rcpt.domain);
 			if (n == -1) {
-				log_warn("mda: fail to write delivery info");
+				log_warn("warn: mda: fail to write delivery info");
 				envelope_set_errormsg(s->evp, "Out of memory");
 				mda_done(s, IMSG_QUEUE_DELIVERY_TEMPFAIL);
 				return;
@@ -256,7 +256,7 @@ mda_imsg(struct imsgev *iev, struct imsg *imsg)
 		case IMSG_PARENT_FORK_MDA:
 			s = tree_xget(&sessions, imsg->hdr.peerid);
 			if (imsg->fd == -1) {
-				log_warn("mda: fail to retreive mda fd");
+				log_warn("warn: mda: fail to retreive mda fd");
 				envelope_set_errormsg(s->evp,
 				    "Cannot get mda fd");
 				mda_done(s, IMSG_QUEUE_DELIVERY_TEMPFAIL);
@@ -297,7 +297,8 @@ mda_imsg(struct imsgev *iev, struct imsg *imsg)
 				envelope_set_errormsg(s->evp, "%s", error);
 				snprintf(stat, sizeof stat, "Error (%s)", error);
 			}
-			log_envelope(s->evp, NULL, error ? stat : "Delivered");
+			log_envelope(s->evp, NULL, error ? "TempFail" : "Ok",
+				     error ? stat : "Delivered");
 			mda_done(s, msg);
 			return;
 
@@ -326,7 +327,7 @@ mda_sig_handler(int sig, short event, void *p)
 static void
 mda_shutdown(void)
 {
-	log_info("mail delivery agent exiting");
+	log_info("info: mail delivery agent exiting");
 	_exit(0);
 }
 
@@ -429,7 +430,7 @@ mda_io(struct io *io, int evt)
 		}
 
 		if (ferror(s->datafp)) {
-			log_debug("mda_io: %p: ferror", s);
+			log_debug("debug: mda_io: %p: ferror", s);
 			snprintf(buf, sizeof buf, "Error reading body");
 			imsg_compose_event(env->sc_ievs[PROC_PARENT],
 			    IMSG_PARENT_KILL_MDA, s->id, 0, -1,
@@ -445,22 +446,22 @@ mda_io(struct io *io, int evt)
 		return;
 
 	case IO_TIMEOUT:
-		log_debug("mda_io: timeout");
+		log_debug("debug: mda_io: timeout");
 		io_pause(io, IO_PAUSE_OUT);
 		return;
 
 	case IO_ERROR:
-		log_debug("mda_io: io error: %s", strerror(errno));
+		log_debug("debug: mda_io: io error: %s", strerror(errno));
 		io_pause(io, IO_PAUSE_OUT);
 		return;
 
 	case IO_DISCONNECTED:
-		log_debug("mda_io: disconnected");
+		log_debug("debug: mda_io: disconnected");
 		io_pause(io, IO_PAUSE_OUT);
 		return;
 
 	default:
-		log_debug("mda_io: unexpected io event: %i", evt);
+		log_debug("debug: mda_io: unexpected io event: %i", evt);
 		io_pause(io, IO_PAUSE_OUT);
 		return;
 	}
@@ -521,13 +522,13 @@ mda_getlastline(int fd, char *dst, size_t dstsz)
 	size_t	 len;
 
 	if (lseek(fd, 0, SEEK_SET) < 0) {
-		log_warn("mda: lseek");
+		log_warn("warn: mda: lseek");
 		close(fd);
 		return (-1);
 	}
 	fp = fdopen(fd, "r");
 	if (fp == NULL) {
-		log_warn("mda: fdopen");
+		log_warn("warn: mda: fdopen");
 		close(fd);
 		return (-1);
 	}
@@ -561,11 +562,11 @@ mda_drain(void)
 	while ((user = (TAILQ_FIRST(&runnable)))) {
 
 		if (running >= MDA_MAXSESS) {
-			log_debug("mda: maximum number of session reached");
+			log_debug("debug: mda: maximum number of session reached");
 			return;
 		}
 
-		log_debug("mda: new session for user \"%s\"", user->name);
+		log_debug("debug: mda: new session for user \"%s\"", user->name);
 
 		s = xcalloc(1, sizeof *s, "mda_drain");
 		s->user = user;
@@ -601,7 +602,7 @@ mda_drain(void)
 		    user->running < MDA_MAXSESSUSER) {
 			TAILQ_INSERT_TAIL(&runnable, user, entry_runnable);
 			user->runnable = 1;
-			log_debug("mda: user \"%s\" still runnable", user->name);
+			log_debug("debug: mda: user \"%s\" still runnable", user->name);
 		}
 	}
 }
@@ -620,13 +621,13 @@ mda_done(struct mda_session *s, int msg)
 	stat_decrement("mda.running", 1);
 
 	if (TAILQ_FIRST(&s->user->envelopes) == NULL && s->user->running == 0) {
-		log_debug("mda: all done for user \"%s\"", s->user->name);
+		log_debug("debug: mda: all done for user \"%s\"", s->user->name);
 		TAILQ_REMOVE(&users, s->user, entry);
 		free(s->user);
 	} else if (s->user->runnable == 0 &&
 		   TAILQ_FIRST(&s->user->envelopes) &&
 		    s->user->running < MDA_MAXSESSUSER) {
-			log_debug("mda: user \"%s\" becomes runnable",
+			log_debug("debug: mda: user \"%s\" becomes runnable",
 			    s->user->name);
 			TAILQ_INSERT_TAIL(&runnable, s->user, entry_runnable);
 			s->user->runnable = 1;
diff --git a/usr.sbin/smtpd/mfa.c b/usr.sbin/smtpd/mfa.c
index 261ccca0996..921d75052c3 100644
--- a/usr.sbin/smtpd/mfa.c
+++ b/usr.sbin/smtpd/mfa.c
@@ -1,4 +1,4 @@
-/*	$OpenBSD: mfa.c,v 1.72 2012/10/25 14:06:08 eric Exp $	*/
+/*	$OpenBSD: mfa.c,v 1.73 2012/11/12 14:58:53 eric Exp $	*/
 
 /*
  * Copyright (c) 2008 Gilles Chehade <gilles@openbsd.org>
@@ -121,7 +121,7 @@ mfa_imsg(struct imsgev *iev, struct imsg *imsg)
 
 		case IMSG_CONF_END:
 			TAILQ_FOREACH(filter, env->sc_filters, f_entry) {
-				log_info("forking filter: %s", filter->name);
+				log_info("info: Forking filter: %s", filter->name);
 				if (! mfa_fork_filter(filter))
 					fatalx("could not fork filter");
 			}
@@ -168,7 +168,7 @@ mfa_shutdown(void)
 		pid = waitpid(WAIT_MYPGRP, NULL, 0);
 	} while (pid != -1 || (pid == -1 && errno == EINTR));
 
-	log_info("mail filter exiting");
+	log_info("info: mail filter exiting");
 	_exit(0);
 }
 
diff --git a/usr.sbin/smtpd/mta.c b/usr.sbin/smtpd/mta.c
index 20f90bccec1..4e414c072c7 100644
--- a/usr.sbin/smtpd/mta.c
+++ b/usr.sbin/smtpd/mta.c
@@ -1,4 +1,4 @@
-/*	$OpenBSD: mta.c,v 1.147 2012/10/11 21:52:59 gilles Exp $	*/
+/*	$OpenBSD: mta.c,v 1.148 2012/11/12 14:58:53 eric Exp $	*/
 
 /*
  * Copyright (c) 2008 Pierre-Yves Ritschard <pyr@openbsd.org>
@@ -119,7 +119,7 @@ mta_imsg(struct imsgev *iev, struct imsg *imsg)
 			/* XXX honour route->maxrcpt */
 			TAILQ_INSERT_TAIL(&task->envelopes, e, entry);
 			stat_increment("mta.envelope", 1);
-			log_debug("mta: received evp:%016" PRIx64 " for <%s@%s>",
+			log_debug("debug: mta: received evp:%016" PRIx64 " for <%s@%s>",
 			    e->id, e->dest.user, e->dest.domain);
 			return;
 
@@ -209,7 +209,7 @@ mta_sig_handler(int sig, short event, void *p)
 static void
 mta_shutdown(void)
 {
-	log_info("mail transfer agent exiting");
+	log_info("info: mail transfer agent exiting");
 	_exit(0);
 }
 
@@ -305,6 +305,22 @@ mta_response_delivery(const char *r)
 }
 
 const char *
+mta_response_prefix(const char *r)
+{
+	switch (r[0]) {
+	case '2':
+		return "Ok";
+	case '5':
+	case '6':
+		if (r[1] == '4' && r[2] == '6')
+			return "Loop";
+		return "PermFail";
+	default:
+		return "TempFail";
+	}
+}
+
+const char *
 mta_response_text(const char *r)
 {
 	return (r + 4);
@@ -315,13 +331,13 @@ mta_route_error(struct mta_route *route, const char *error)
 {
 	route->nfail += 1;
 	strlcpy(route->errorline, error, sizeof route->errorline);
-	log_warnx("mta: %s error: %s", mta_route_to_text(route), error);
+	log_warnx("warn: mta: %s error: %s", mta_route_to_text(route), error);
 }
 
 void
 mta_route_ok(struct mta_route *route)
 {
-	log_debug("mta: %s ready", mta_route_to_text(route));
+	log_debug("debug: mta: %s ready", mta_route_to_text(route));
 	route->nfail = 0;
 }
 
@@ -465,7 +481,7 @@ mta_route_drain(struct mta_route *route)
 	struct mta_task		*task;
 	struct envelope		*e;
 
-	log_debug("mta: draining %s (tasks=%i, refs=%i, sessions=%i)",
+	log_debug("debug: mta: draining %s (tasks=%i, refs=%i, sessions=%i)",
 	    mta_route_to_text(route),
 	    route->ntask, route->refcount, route->nsession);
 
@@ -476,7 +492,7 @@ mta_route_drain(struct mta_route *route)
 	}
 
 	if (route->ntask == 0) {
-		log_debug("mta: no task for %s", mta_route_to_text(route));
+		log_debug("debug: mta: no task for %s", mta_route_to_text(route));
 		return;
 	}
 
@@ -484,7 +500,7 @@ mta_route_drain(struct mta_route *route)
 		/* Three connection errors in a row: consider that the route
 		 * has a problem.
 		 */
-		log_debug("mta: too many failures on %s",
+		log_debug("debug: mta: too many failures on %s",
 		    mta_route_to_text(route));
 
 		while ((task = TAILQ_FIRST(&route->tasks))) {
@@ -504,7 +520,7 @@ mta_route_drain(struct mta_route *route)
 	while (route->nsession < route->ntask) {
 		/* if we have reached the max number of session, wait */
 		if (route->nsession >= route->maxconn) {
-			log_debug("mta: max conn reached for %s",
+			log_debug("debug: mta: max conn reached for %s",
 			    mta_route_to_text(route));
 			return;
 		}
@@ -516,13 +532,13 @@ mta_route_drain(struct mta_route *route)
 static void
 mta_envelope_done(struct mta_task *task, struct envelope *e, const char *status)
 {
-	char	relay[MAX_LINE_SIZE];
+	char	 relay[MAX_LINE_SIZE];
 
 	envelope_set_errormsg(e, "%s", status);
 
 	snprintf(relay, sizeof relay, "relay=%s, ", task->route->hostname);
-	log_envelope(e, relay, e->errorline);
 
+	log_envelope(e, relay, mta_response_prefix(e->errorline), e->errorline);
 	imsg_compose_event(env->sc_ievs[PROC_QUEUE],
 	    mta_response_delivery(e->errorline), 0, 0, -1, e, sizeof(*e));
 	TAILQ_REMOVE(&task->envelopes, e, entry);
diff --git a/usr.sbin/smtpd/mta_session.c b/usr.sbin/smtpd/mta_session.c
index 832a4a9a37c..9ad17e642af 100644
--- a/usr.sbin/smtpd/mta_session.c
+++ b/usr.sbin/smtpd/mta_session.c
@@ -1,4 +1,4 @@
-/*	$OpenBSD: mta_session.c,v 1.25 2012/11/06 09:25:37 eric Exp $	*/
+/*	$OpenBSD: mta_session.c,v 1.26 2012/11/12 14:58:53 eric Exp $	*/
 
 /*
  * Copyright (c) 2008 Pierre-Yves Ritschard <pyr@openbsd.org>
@@ -151,7 +151,7 @@ mta_session(struct mta_route *route)
 			session->flags |= MTA_ALLOW_PLAIN;
 	}
 
-	log_debug("mta: %p: spawned for %s", session, mta_route_to_text(route));
+	log_debug("debug: mta: %p: spawned for %s", session, mta_route_to_text(route));
 	stat_increment("mta.session", 1);
 	mta_enter_state(session, MTA_INIT);
 }
@@ -179,7 +179,7 @@ mta_session_imsg(struct imsgev *iev, struct imsg *imsg)
 			fatal("mta: fdopen");
 
 		if (mta_check_loop(s->datafp)) {
-			log_debug("mta: loop detected");
+			log_debug("debug: mta: loop detected");
 			fclose(s->datafp);
 			s->datafp = NULL;
 			mta_status(s, 0, "646 Loop detected");
@@ -240,12 +240,12 @@ mta_session_imsg(struct imsgev *iev, struct imsg *imsg)
 			strlcpy(host->fqdn, "<unknown>", sizeof host->fqdn);
 		else
 			strlcpy(host->fqdn, dns->host, sizeof host->fqdn);
-		log_debug("mta: %p: connected to %s", s, host->fqdn);
+		log_debug("debug: mta: %p: connected to %s", s, host->fqdn);
 
 		/* check if we need to start tls now... */
 		if (((s->flags & MTA_FORCE_ANYSSL) && host->used == 1) ||
 		    (s->flags & MTA_FORCE_SMTPS)) {
-			log_debug("mta: %p: trying smtps (ssl=%p)...", s, s->ssl);
+			log_debug("debug: mta: %p: trying smtps (ssl=%p)...", s, s->ssl);
 			if ((ptr = ssl_mta_init(s->ssl)) == NULL)
 				fatalx("mta: ssl_mta_init");
 			io_start_tls(&s->io, ptr);
@@ -344,7 +344,7 @@ mta_enter_state(struct mta_session *s, int newstate)
 			}
 			host->used++;
 
-			log_debug("mta: %p: connecting to %s...", s,
+			log_debug("debug: mta: %p: connecting to %s...", s,
 				ss_to_text(&host->sa));
 			sa = (struct sockaddr *)&host->sa;
 
@@ -361,7 +361,7 @@ mta_enter_state(struct mta_session *s, int newstate)
 			io_init(&s->io, -1, s, mta_io, &s->iobuf);
 			io_set_timeout(&s->io, 10000);
 			if (io_connect(&s->io, sa, NULL) == -1) {
-				log_debug("mta: %p: connection failed: %s", s,
+				log_debug("debug: mta: %p: connection failed: %s", s,
 				    strerror(errno));
 				iobuf_clear(&s->iobuf);
 				/*
@@ -384,7 +384,7 @@ mta_enter_state(struct mta_session *s, int newstate)
 		/*
 		 * Kill the mta session.
 		 */
-		log_debug("mta: %p: session done", s);
+		log_debug("debug: mta: %p: session done", s);
 		io_clear(&s->io);
 		iobuf_clear(&s->iobuf);
 		if (s->task)
@@ -432,7 +432,7 @@ mta_enter_state(struct mta_session *s, int newstate)
 		if (s->secret && s->flags & MTA_TLS)
 			mta_send(s, "AUTH PLAIN %s", s->secret);
 		else if (s->secret) {
-			log_debug("mta: %p: not using AUTH on non-TLS session",
+			log_debug("debug: mta: %p: not using AUTH on non-TLS session",
 			    s);
 			mta_enter_state(s, MTA_CONNECT);
 		} else {
@@ -447,11 +447,11 @@ mta_enter_state(struct mta_session *s, int newstate)
 			mta_route_ok(s->route);
 		}
 		if (s->msgcount >= s->route->maxmail) {
-			log_debug("mta: %p: cannot send more message to %s", s,
+			log_debug("debug: mta: %p: cannot send more message to %s", s,
 			    mta_route_to_text(s->route));
 			mta_enter_state(s, MTA_SMTP_QUIT);
 		} else if ((s->task = TAILQ_FIRST(&s->route->tasks))) {
-			log_debug("mta: %p: handling next task for %s", s,
+			log_debug("debug: mta: %p: handling next task for %s", s,
 			    mta_route_to_text(s->route));
 			TAILQ_REMOVE(&s->route->tasks, s->task, entry);
 			s->route->ntask -= 1;
@@ -460,7 +460,7 @@ mta_enter_state(struct mta_session *s, int newstate)
 			stat_increment("mta.task.running", 1);
 			mta_enter_state(s, MTA_DATA);
 		} else {
-			log_debug("mta: %p: no pending task for %s", s,
+			log_debug("debug: mta: %p: no pending task for %s", s,
 			    mta_route_to_text(s->route));
 			/* XXX stay open for a while? */
 			mta_enter_state(s, MTA_SMTP_QUIT);
@@ -711,7 +711,7 @@ mta_io(struct io *io, int evt)
     		iobuf_normalize(&s->iobuf);
 
 		if (iobuf_len(&s->iobuf)) {
-			log_debug("mta: remaining data in input buffer");
+			log_debug("debug: mta: remaining data in input buffer");
 			mta_status(s, 1, "150 Remote sent too much data");
 			mta_enter_state(s, MTA_DONE);
 		}
@@ -726,7 +726,7 @@ mta_io(struct io *io, int evt)
 		break;
 
 	case IO_TIMEOUT:
-		log_debug("mta: %p: connection timeout", s);
+		log_debug("debug: mta: %p: connection timeout", s);
 		if (!s->ready) {
 			mta_enter_state(s, MTA_CONNECT);
 			break;
@@ -736,7 +736,7 @@ mta_io(struct io *io, int evt)
 		break;
 
 	case IO_ERROR:
-		log_debug("mta: %p: IO error: %s", s, strerror(errno));
+		log_debug("debug: mta: %p: IO error: %s", s, strerror(errno));
 		if (!s->ready) {
 			mta_enter_state(s, MTA_CONNECT);
 			break;
@@ -746,7 +746,7 @@ mta_io(struct io *io, int evt)
 		break;
 
 	case IO_DISCONNECTED:
-		log_debug("mta: %p: disconnected in state %s", s, mta_strstate(s->state));
+		log_debug("debug: mta: %p: disconnected in state %s", s, mta_strstate(s->state));
 		if (!s->ready) {
 			mta_enter_state(s, MTA_CONNECT);
 			break;
@@ -851,7 +851,8 @@ mta_envelope_done(struct mta_task *task, struct envelope *e, const char *status)
 	snprintf(stat, sizeof stat, "%s (%s)",
 	    mta_response_status(e->errorline),
 	    mta_response_text(e->errorline));
-	log_envelope(e, relay, stat);
+
+	log_envelope(e, relay, mta_response_prefix(e->errorline), stat);
 
 	imsg_compose_event(env->sc_ievs[PROC_QUEUE],
 	    mta_response_delivery(e->errorline), 0, 0, -1, e, sizeof(*e));
diff --git a/usr.sbin/smtpd/parse.y b/usr.sbin/smtpd/parse.y
index 8f8a194b233..017eb61e382 100644
--- a/usr.sbin/smtpd/parse.y
+++ b/usr.sbin/smtpd/parse.y
@@ -1,4 +1,4 @@
-/*	$OpenBSD: parse.y,v 1.109 2012/10/14 11:58:23 gilles Exp $	*/
+/*	$OpenBSD: parse.y,v 1.110 2012/11/12 14:58:53 eric Exp $	*/
 
 /*
  * Copyright (c) 2008 Gilles Chehade <gilles@openbsd.org>
@@ -119,12 +119,12 @@ typedef struct {
 
 %}
 
-%token	AS QUEUE COMPRESSION CIPHER INTERVAL SIZE LISTEN ON ANY PORT EXPIRE
-%token	MAP HASH LIST SINGLE SSL SMTPS CERTIFICATE ENCRYPTION
+%token	AS QUEUE COMPRESSION SIZE LISTEN ON ANY PORT EXPIRE
+%token	MAP HASH LIST SINGLE SSL SMTPS CERTIFICATE
 %token	DB LDAP FILE DOMAIN SOURCE
 %token  RELAY BACKUP VIA DELIVER TO MAILDIR MBOX HOSTNAME
 %token	ACCEPT REJECT INCLUDE ERROR MDA FROM FOR
-%token	ARROW AUTH TLS LOCAL VIRTUAL TAG ALIAS FILTER KEY DIGEST
+%token	ARROW AUTH TLS LOCAL VIRTUAL TAG ALIAS FILTER KEY
 %token	AUTH_OPTIONAL TLS_REQUIRE
 %token	<v.string>	STRING
 %token  <v.number>	NUMBER
@@ -313,14 +313,11 @@ compression	: COMPRESSION STRING {
 		| /* empty */	{ $$ = NULL; }
 		;
 
-main		: QUEUE INTERVAL interval	{
-			conf->sc_qintval = $3;
-		}
-		| QUEUE compression {
+main		: QUEUE compression {
 			if ($2) {
 				conf->sc_queue_flags |= QUEUE_COMPRESS;
 				conf->sc_queue_compress_algo = strdup($2);
-				log_debug("queue compress using %s",
+				log_debug("debug: queue compress using %s",
 				    conf->sc_queue_compress_algo);
 			}
 			if ($2 == NULL) {
@@ -943,13 +940,10 @@ lookup(char *s)
 		{ "auth-optional",     	AUTH_OPTIONAL },
 		{ "backup",		BACKUP },
 		{ "certificate",	CERTIFICATE },
-		{ "cipher",		CIPHER },
 		{ "compression",       	COMPRESSION },
 		{ "db",			DB },
 		{ "deliver",		DELIVER },
-		{ "digest",		DIGEST },
 		{ "domain",		DOMAIN },
-		{ "encryption",		ENCRYPTION },
 		{ "expire",		EXPIRE },
 		{ "file",		FILE },
 		{ "filter",		FILTER },
@@ -958,7 +952,6 @@ lookup(char *s)
 		{ "hash",		HASH },
 		{ "hostname",		HOSTNAME },
 		{ "include",		INCLUDE },
-		{ "interval",		INTERVAL },
 		{ "key",		KEY },
 		{ "ldap",		LDAP },
 		{ "list",		LIST },
@@ -1248,15 +1241,15 @@ check_file_secrecy(int fd, const char *fname)
 	struct stat	st;
 
 	if (fstat(fd, &st)) {
-		log_warn("cannot stat %s", fname);
+		log_warn("warn: cannot stat %s", fname);
 		return (-1);
 	}
 	if (st.st_uid != 0 && st.st_uid != getuid()) {
-		log_warnx("%s: owner not root or current user", fname);
+		log_warnx("warn: %s: owner not root or current user", fname);
 		return (-1);
 	}
 	if (st.st_mode & (S_IRWXG | S_IRWXO)) {
-		log_warnx("%s: group/world readable/writeable", fname);
+		log_warnx("warn: %s: group/world readable/writeable", fname);
 		return (-1);
 	}
 	return (0);
@@ -1268,16 +1261,16 @@ pushfile(const char *name, int secret)
 	struct file	*nfile;
 
 	if ((nfile = calloc(1, sizeof(struct file))) == NULL) {
-		log_warn("malloc");
+		log_warn("warn: malloc");
 		return (NULL);
 	}
 	if ((nfile->name = strdup(name)) == NULL) {
-		log_warn("malloc");
+		log_warn("warn: malloc");
 		free(nfile);
 		return (NULL);
 	}
 	if ((nfile->stream = fopen(nfile->name, "r")) == NULL) {
-		log_warn("%s", nfile->name);
+		log_warn("warn: %s", nfile->name);
 		free(nfile->name);
 		free(nfile);
 		return (NULL);
@@ -1330,7 +1323,7 @@ parse_config(struct smtpd *x_conf, const char *filename, int opts)
 	    conf->sc_listeners == NULL	||
 	    conf->sc_ssl == NULL	||
 	    conf->sc_filters == NULL) {
-		log_warn("cannot allocate memory");
+		log_warn("warn: cannot allocate memory");
 		free(conf->sc_maps);
 		free(conf->sc_rules);
 		free(conf->sc_listeners);
@@ -1352,8 +1345,6 @@ parse_config(struct smtpd *x_conf, const char *filename, int opts)
 	SPLAY_INIT(&conf->sc_sessions);
 
 	conf->sc_qexpire = SMTPD_QUEUE_EXPIRY;
-	conf->sc_qintval.tv_sec = SMTPD_QUEUE_INTERVAL;
-	conf->sc_qintval.tv_usec = 0;
 	conf->sc_opts = opts;
 
 	if ((file = pushfile(filename, 0)) == NULL) {
@@ -1391,14 +1382,14 @@ parse_config(struct smtpd *x_conf, const char *filename, int opts)
 	}
 
 	if (TAILQ_EMPTY(conf->sc_rules)) {
-		log_warnx("no rules, nothing to do");
+		log_warnx("warn: no rules, nothing to do");
 		errors++;
 	}
 
 	if (strlen(conf->sc_hostname) == 0)
 		if (gethostname(conf->sc_hostname,
 		    sizeof(conf->sc_hostname)) == -1) {
-			log_warn("could not determine host name");
+			log_warn("warn: could not determine host name");
 			bzero(conf->sc_hostname, sizeof(conf->sc_hostname));
 			errors++;
 		}
@@ -1544,7 +1535,7 @@ host_dns(const char *s, const char *tag, const char *cert,
 	if (error == EAI_AGAIN || error == EAI_NODATA || error == EAI_NONAME)
 		return (0);
 	if (error) {
-		log_warnx("host_dns: could not parse \"%s\": %s", s,
+		log_warnx("warn: host_dns: could not parse \"%s\": %s", s,
 		    gai_strerror(error));
 		return (-1);
 	}
@@ -1583,7 +1574,7 @@ host_dns(const char *s, const char *tag, const char *cert,
 		cnt++;
 	}
 	if (cnt == max && res) {
-		log_warnx("host_dns: %s resolves to more than %d hosts",
+		log_warnx("warn: host_dns: %s resolves to more than %d hosts",
 		    s, max);
 	}
 	freeaddrinfo(res0);
diff --git a/usr.sbin/smtpd/queue.c b/usr.sbin/smtpd/queue.c
index bc6635827c6..239d31f4731 100644
--- a/usr.sbin/smtpd/queue.c
+++ b/usr.sbin/smtpd/queue.c
@@ -1,4 +1,4 @@
-/*	$OpenBSD: queue.c,v 1.140 2012/10/25 09:51:08 eric Exp $	*/
+/*	$OpenBSD: queue.c,v 1.141 2012/11/12 14:58:53 eric Exp $	*/
 
 /*
  * Copyright (c) 2008 Gilles Chehade <gilles@openbsd.org>
@@ -146,7 +146,8 @@ queue_imsg(struct imsgev *iev, struct imsg *imsg)
 			id = *(uint64_t*)(imsg->data);
 			if (queue_envelope_load(id, &evp) == 0)
 				errx(1, "cannot load evp:%016" PRIx64, id);
-			log_envelope(&evp, NULL, "Removed by administrator");
+			log_envelope(&evp, NULL, "Remove",
+			    "Removed by administrator");
 			queue_envelope_delete(&evp);
 			return;
 
@@ -156,7 +157,7 @@ queue_imsg(struct imsgev *iev, struct imsg *imsg)
 				errx(1, "cannot load evp:%016" PRIx64, id);
 			envelope_set_errormsg(&evp, "Envelope expired");
 			queue_bounce(&evp);
-			log_envelope(&evp, NULL, evp.errorline);
+			log_envelope(&evp, NULL, "Expire", evp.errorline);
 			queue_envelope_delete(&evp);
 			return;
 
@@ -290,19 +291,20 @@ queue_bounce(struct envelope *e)
 	b.expire = 3600 * 24 * 7;
 
 	if (e->type == D_BOUNCE) {
-		log_warnx("queue: double bounce!");
+		log_warnx("warn: queue: double bounce!");
 	} else if (e->sender.user[0] == '\0') {
-		log_warnx("queue: no return path!");
+		log_warnx("warn: queue: no return path!");
 	} else if (!queue_envelope_create(&b)) {
-		log_warnx("queue: cannot bounce!");
+		log_warnx("warn: queue: cannot bounce!");
 	} else {
-		log_debug("queue: bouncing evp:%016" PRIx64
+		log_debug("debug: queue: bouncing evp:%016" PRIx64
 		    " as evp:%016" PRIx64, e->id, b.id);
 		imsg_compose_event(env->sc_ievs[PROC_SCHEDULER],
 		    IMSG_QUEUE_SUBMIT_ENVELOPE, 0, 0, -1, &b, sizeof b);
 		msgid = evpid_to_msgid(b.id);
 		imsg_compose_event(env->sc_ievs[PROC_SCHEDULER],
 		    IMSG_QUEUE_COMMIT_MESSAGE, 0, 0, -1, &msgid, sizeof msgid);
+		stat_increment("queue.bounce", 1);
 	}
 }
 
@@ -322,7 +324,7 @@ queue_sig_handler(int sig, short event, void *p)
 static void
 queue_shutdown(void)
 {
-	log_info("queue handler exiting");
+	log_info("info: queue handler exiting");
 	_exit(0);
 }
 
@@ -404,41 +406,49 @@ static void
 queue_timeout(int fd, short event, void *p)
 {
 	static struct qwalk	*q = NULL;
-	static uint32_t		 last_msgid = 0;
+	static uint32_t		 msgid = 0;
+	static size_t		 evpcount = 0;
 	struct event		*ev = p;
 	struct envelope		 envelope;
 	struct timeval		 tv;
 	uint64_t		 evpid;
 
 	if (q == NULL) {
-		log_debug("queue: loading queue into scheduler");
+		log_debug("debug: queue: loading queue into scheduler");
 		q = qwalk_new(0);
 	}
 
 	while (qwalk(q, &evpid)) {
-		if (queue_envelope_load(evpid, &envelope))
+		if (! queue_envelope_load(evpid, &envelope))
+			log_warnx("warn: Failed to load envelope %016"PRIx64,
+			    evpid);
+		else {
 			imsg_compose_event(env->sc_ievs[PROC_SCHEDULER],
 			    IMSG_QUEUE_SUBMIT_ENVELOPE, 0, 0, -1, &envelope,
 			    sizeof envelope);
+			evpcount++;
+		}
 
-		if (last_msgid && evpid_to_msgid(evpid) != last_msgid)
+		if (msgid && evpid_to_msgid(evpid) != msgid && evpcount) {
 			imsg_compose_event(env->sc_ievs[PROC_SCHEDULER],
-			    IMSG_QUEUE_COMMIT_MESSAGE, 0, 0, -1, &last_msgid,
-			    sizeof last_msgid);
+			    IMSG_QUEUE_COMMIT_MESSAGE, 0, 0, -1, &msgid,
+			    sizeof msgid);
+			evpcount = 0;
+		}
 
-		last_msgid = evpid_to_msgid(evpid);
+		msgid = evpid_to_msgid(evpid);
 		tv.tv_sec = 0;
 		tv.tv_usec = 0;
 		evtimer_add(ev, &tv);	
 		return;
 	}
 
-	if (last_msgid) {
+	if (msgid && evpcount) {
 		imsg_compose_event(env->sc_ievs[PROC_SCHEDULER],
-		    IMSG_QUEUE_COMMIT_MESSAGE, 0, 0, -1, &last_msgid,
-		    sizeof last_msgid);
+		    IMSG_QUEUE_COMMIT_MESSAGE, 0, 0, -1, &msgid, sizeof msgid);
+		evpcount = 0;
 	}
 
-	log_debug("queue: done loading queue into scheduler");
+	log_debug("debug: queue: done loading queue into scheduler");
 	qwalk_close(q);
 }
diff --git a/usr.sbin/smtpd/queue_backend.c b/usr.sbin/smtpd/queue_backend.c
index 9de7e2ecd49..27cef8be6fb 100644
--- a/usr.sbin/smtpd/queue_backend.c
+++ b/usr.sbin/smtpd/queue_backend.c
@@ -1,4 +1,4 @@
-/*	$OpenBSD: queue_backend.c,v 1.39 2012/10/09 13:39:00 eric Exp $	*/
+/*	$OpenBSD: queue_backend.c,v 1.40 2012/11/12 14:58:53 eric Exp $	*/
 
 /*
  * Copyright (c) 2011 Gilles Chehade <gilles@openbsd.org>
@@ -287,7 +287,7 @@ queue_envelope_load(uint64_t evpid, struct envelope *ep)
 			ep->id = evpid;
 			return (1);
 		}
-		log_debug("invalid envelope %016" PRIx64 ": %s", ep->id, e);
+		log_debug("debug: invalid envelope %016" PRIx64 ": %s", ep->id, e);
 	}
 	return (0);
 }
diff --git a/usr.sbin/smtpd/queue_fsqueue.c b/usr.sbin/smtpd/queue_fsqueue.c
index 87b11046cbf..6bfb812e7ab 100644
--- a/usr.sbin/smtpd/queue_fsqueue.c
+++ b/usr.sbin/smtpd/queue_fsqueue.c
@@ -1,4 +1,4 @@
-/*	$OpenBSD: queue_fsqueue.c,v 1.54 2012/10/22 21:58:14 chl Exp $	*/
+/*	$OpenBSD: queue_fsqueue.c,v 1.55 2012/11/12 14:58:53 eric Exp $	*/
 
 /*
  * Copyright (c) 2011 Gilles Chehade <gilles@openbsd.org>
@@ -129,14 +129,14 @@ fsqueue_envelope_dump_atomic(char *dest, char *evpbuf, size_t evplen)
 
 	w = write(fd, evpbuf, evplen);
 	if (w == -1) {
-		log_warn("fsqueue_envelope_dump_atomic: write");
+		log_warn("warn: fsqueue_envelope_dump_atomic: write");
 		if (errno == ENOSPC)
 			goto tempfail;
 		fatal("fsqueue_envelope_dump_atomic: write");
 	}
 
 	if ((size_t) w != evplen) {
-		log_warnx("fsqueue_envelope_dump_atomic: partial write");
+		log_warnx("warn: fsqueue_envelope_dump_atomic: partial write");
 		goto tempfail;
 	}
 
@@ -145,7 +145,7 @@ fsqueue_envelope_dump_atomic(char *dest, char *evpbuf, size_t evplen)
 	close(fd);
 
 	if (rename(evpname, dest) == -1) {
-		log_warn("fsqueue_envelope_dump_atomic: rename");
+		log_warn("warn: fsqueue_envelope_dump_atomic: rename");
 		if (errno == ENOSPC)
 			goto tempfail;
 		fatal("fsqueue_envelope_dump_atomic: rename");
@@ -493,13 +493,13 @@ fsqueue_qwalk(void *hdl, uint64_t *evpid)
 		case FTS_D:
 			q->depth += 1;
 			if (q->depth == 2 && e->fts_namelen != 2) {
-				log_debug("fsqueue: bogus directory %s",
+				log_debug("debug: fsqueue: bogus directory %s",
 				    e->fts_path);
 				fts_set(q->fts, e, FTS_SKIP);
 				break;
 			}
 			if (q->depth == 3 && e->fts_namelen != 8) {
-				log_debug("fsqueue: bogus directory %s",
+				log_debug("debug: fsqueue: bogus directory %s",
 				    e->fts_path);
 				fts_set(q->fts, e, FTS_SKIP);
 				break;
@@ -528,7 +528,7 @@ fsqueue_qwalk(void *hdl, uint64_t *evpid)
 			tmp = NULL;
 			*evpid = strtoull(e->fts_name, &tmp, 16);
 			if (tmp && *tmp !=  '\0') {
-				log_debug("fsqueue: bogus file %s",
+				log_debug("debug: fsqueue: bogus file %s",
 				    e->fts_path);
 				break;
 			}
diff --git a/usr.sbin/smtpd/ruleset.c b/usr.sbin/smtpd/ruleset.c
index 259d021bfff..42399f93bb9 100644
--- a/usr.sbin/smtpd/ruleset.c
+++ b/usr.sbin/smtpd/ruleset.c
@@ -1,4 +1,4 @@
-/*	$OpenBSD: ruleset.c,v 1.25 2012/10/13 08:01:47 eric Exp $ */
+/*	$OpenBSD: ruleset.c,v 1.26 2012/11/12 14:58:53 eric Exp $ */
 
 /*
  * Copyright (c) 2009 Gilles Chehade <gilles@openbsd.org>
@@ -78,8 +78,7 @@ ruleset_match(const struct envelope *evp)
 
 			if (map->m_src == S_NONE) {
 				TAILQ_FOREACH(me, &map->m_contents, me_entry) {
-					if (hostname_match(maddr->domain,
-					    me->me_key.med_string))
+					if (hostname_match(maddr->domain, me->me_key))
 						return r;
 				}
 			}
@@ -143,12 +142,11 @@ ruleset_check_source(struct map *map, const struct sockaddr_storage *ss)
 	if (map->m_src == S_NONE) {
 		TAILQ_FOREACH(me, &map->m_contents, me_entry) {
 			if (ss->ss_family == AF_LOCAL) {
-				if (!strcmp(me->me_key.med_string, "local"))
+				if (!strcmp(me->me_key, "local"))
 					return 1;
 				continue;
 			}
-			if (ruleset_cmp_source(ss_to_text(ss),
-				me->me_key.med_string))
+			if (ruleset_cmp_source(ss_to_text(ss), me->me_key))
 				return 1;
 		}
 	}
diff --git a/usr.sbin/smtpd/scheduler.c b/usr.sbin/smtpd/scheduler.c
index feca49392a6..44f0f15eec1 100644
--- a/usr.sbin/smtpd/scheduler.c
+++ b/usr.sbin/smtpd/scheduler.c
@@ -1,4 +1,4 @@
-/*	$OpenBSD: scheduler.c,v 1.22 2012/11/02 14:46:43 eric Exp $	*/
+/*	$OpenBSD: scheduler.c,v 1.23 2012/11/12 14:58:53 eric Exp $	*/
 
 /*
  * Copyright (c) 2008 Gilles Chehade <gilles@openbsd.org>
@@ -172,11 +172,11 @@ scheduler_imsg(struct imsgev *iev, struct imsg *imsg)
 	case IMSG_SCHEDULER_SCHEDULE:
 		id = *(uint64_t *)(imsg->data);
 		if (id == 0)
-			log_debug("scheduler: scheduling all envelopes");
+			log_debug("debug: scheduler: scheduling all envelopes");
 		else if (id <= 0xffffffffL)
-			log_debug("scheduler: scheduling msg:%08" PRIx64, id);
+			log_debug("debug: scheduler: scheduling msg:%08" PRIx64, id);
 		else
-			log_debug("scheduler: scheduling evp:%016" PRIx64, id);
+			log_debug("debug: scheduler: scheduling evp:%016" PRIx64, id);
 		backend->schedule(id);
 		scheduler_reset_events();
 		return;
@@ -184,9 +184,9 @@ scheduler_imsg(struct imsgev *iev, struct imsg *imsg)
 	case IMSG_SCHEDULER_REMOVE:
 		id = *(uint64_t *)(imsg->data);
 		if (id <= 0xffffffffL)
-			log_debug("scheduler: removing msg:%08" PRIx64, id);
+			log_debug("debug: scheduler: removing msg:%08" PRIx64, id);
 		else
-			log_debug("scheduler: removing evp:%016" PRIx64, id);
+			log_debug("debug: scheduler: removing evp:%016" PRIx64, id);
 		backend->remove(id);
 		scheduler_reset_events();
 		return;
@@ -211,7 +211,7 @@ scheduler_sig_handler(int sig, short event, void *p)
 static void
 scheduler_shutdown(void)
 {
-	log_info("scheduler handler exiting");
+	log_info("info: scheduler handler exiting");
 	_exit(0);
 }
 
@@ -359,7 +359,7 @@ scheduler_process_remove(struct scheduler_batch *batch)
 
 	while ((e = batch->evpids)) {
 		batch->evpids = e->next;
-		log_debug("scheduler: evp:%016" PRIx64 " removed",
+		log_debug("debug: scheduler: evp:%016" PRIx64 " removed",
 		    e->id);
 		imsg_compose_event(env->sc_ievs[PROC_QUEUE], IMSG_QUEUE_REMOVE,
 		    0, 0, -1, &e->id, sizeof e->id);
@@ -377,7 +377,7 @@ scheduler_process_expire(struct scheduler_batch *batch)
 
 	while ((e = batch->evpids)) {
 		batch->evpids = e->next;
-		log_debug("scheduler: evp:%016" PRIx64 " expired",
+		log_debug("debug: scheduler: evp:%016" PRIx64 " expired",
 		    e->id);
 		imsg_compose_event(env->sc_ievs[PROC_QUEUE], IMSG_QUEUE_EXPIRE,
 		    0, 0, -1, &e->id, sizeof e->id);
@@ -395,7 +395,7 @@ scheduler_process_bounce(struct scheduler_batch *batch)
 
 	while ((e = batch->evpids)) {
 		batch->evpids = e->next;
-		log_debug("scheduler: evp:%016" PRIx64 " scheduled (bounce)",
+		log_debug("debug: scheduler: evp:%016" PRIx64 " scheduled (bounce)",
 		    e->id);
 		imsg_compose_event(env->sc_ievs[PROC_QUEUE], IMSG_SMTP_ENQUEUE,
 		    0, 0, -1, &e->id, sizeof e->id);
@@ -412,7 +412,7 @@ scheduler_process_mda(struct scheduler_batch *batch)
 
 	while ((e = batch->evpids)) {
 		batch->evpids = e->next;
-		log_debug("scheduler: evp:%016" PRIx64 " scheduled (mda)",
+		log_debug("debug: scheduler: evp:%016" PRIx64 " scheduled (mda)",
 		    e->id);
 		imsg_compose_event(env->sc_ievs[PROC_QUEUE], IMSG_MDA_SESS_NEW,
 		    0, 0, -1, &e->id, sizeof e->id);
@@ -432,7 +432,7 @@ scheduler_process_mta(struct scheduler_batch *batch)
 
 	while ((e = batch->evpids)) {
 		batch->evpids = e->next;
-		log_debug("scheduler: evp:%016" PRIx64 " scheduled (mta)",
+		log_debug("debug: scheduler: evp:%016" PRIx64 " scheduled (mta)",
 		    e->id);
 		imsg_compose_event(env->sc_ievs[PROC_QUEUE], IMSG_BATCH_APPEND,
 		    0, 0, -1, &e->id, sizeof e->id);
diff --git a/usr.sbin/smtpd/scheduler_ramqueue.c b/usr.sbin/smtpd/scheduler_ramqueue.c
index 1425e414fcf..055d2c8b4d2 100644
--- a/usr.sbin/smtpd/scheduler_ramqueue.c
+++ b/usr.sbin/smtpd/scheduler_ramqueue.c
@@ -1,4 +1,4 @@
-/*	$OpenBSD: scheduler_ramqueue.c,v 1.23 2012/11/02 14:46:43 eric Exp $	*/
+/*	$OpenBSD: scheduler_ramqueue.c,v 1.24 2012/11/12 14:58:53 eric Exp $	*/
 
 /*
  * Copyright (c) 2012 Gilles Chehade <gilles@openbsd.org>
@@ -612,16 +612,16 @@ rq_queue_dump(struct rq_queue *rq, const char * name)
 	void			*i, *j;
 	uint64_t		 id;
 
-	log_debug("/--- ramqueue: %s", name);
+	log_debug("debug: /--- ramqueue: %s", name);
 
 	i = NULL;
 	while((tree_iter(&rq->messages, &i, &id, (void*)&message))) {
-		log_debug("| msg:%08" PRIx32, message->msgid);
+		log_debug("debug: | msg:%08" PRIx32, message->msgid);
 		j = NULL;
 		while((tree_iter(&message->envelopes, &j, &id,
 		    (void*)&envelope)))
-			log_debug("|   %s",
+			log_debug("debug: |   %s",
 			    rq_envelope_to_text(envelope));
 	}
-	log_debug("\\---");
+	log_debug("debug: \\---");
 }
diff --git a/usr.sbin/smtpd/smtp.c b/usr.sbin/smtpd/smtp.c
index 461c5d89343..73067afcd74 100644
--- a/usr.sbin/smtpd/smtp.c
+++ b/usr.sbin/smtpd/smtp.c
@@ -1,4 +1,4 @@
-/*	$OpenBSD: smtp.c,v 1.120 2012/10/07 15:46:38 chl Exp $	*/
+/*	$OpenBSD: smtp.c,v 1.121 2012/11/12 14:58:53 eric Exp $	*/
 
 /*
  * Copyright (c) 2008 Gilles Chehade <gilles@openbsd.org>
@@ -259,13 +259,13 @@ smtp_imsg(struct imsgev *iev, struct imsg *imsg)
 			return;
 
 		case IMSG_SMTP_PAUSE:
-			log_debug("smtp: pausing listening sockets");
+			log_debug("debug: smtp: pausing listening sockets");
 			smtp_pause();
 			env->sc_flags |= SMTPD_SMTP_PAUSED;
 			return;
 
 		case IMSG_SMTP_RESUME:
-			log_debug("smtp: resuming listening sockets");
+			log_debug("debug: smtp: resuming listening sockets");
 			env->sc_flags &= ~SMTPD_SMTP_PAUSED;
 			smtp_resume();
 			return;
@@ -291,7 +291,7 @@ smtp_sig_handler(int sig, short event, void *p)
 static void
 smtp_shutdown(void)
 {
-	log_info("smtp server exiting");
+	log_info("info: smtp server exiting");
 	_exit(0);
 }
 
@@ -366,7 +366,7 @@ smtp_setup_events(void)
 	struct listener *l;
 
 	TAILQ_FOREACH(l, env->sc_listeners, entry) {
-		log_debug("smtp: listen on %s port %d flags 0x%01x"
+		log_debug("debug: smtp: listen on %s port %d flags 0x%01x"
 		    " cert \"%s\"", ss_to_text(&l->ss), ntohs(l->port),
 		    l->flags, l->ssl_cert_name);
 
@@ -381,7 +381,7 @@ smtp_setup_events(void)
 		ssl_setup(l);
 	}
 
-	log_debug("smtp: will accept at most %d clients",
+	log_debug("debug: smtp: will accept at most %d clients",
 	    (getdtablesize() - getdtablecount())/2 - SMTP_FD_RESERVE);
 }
 
@@ -463,14 +463,14 @@ smtp_accept(int fd, short event, void *p)
 	socklen_t		 len;
 
 	if ((s = smtp_new(l)) == NULL) {
-		log_warnx("smtp: client limit hit, disabling incoming connections");
+		log_warnx("warn: smtp: client limit hit, disabling incoming connections");
 		goto pause;
 	}
 
 	len = sizeof(s->s_ss);
 	if ((s->s_io.sock = accept(fd, (struct sockaddr *)&s->s_ss, &len)) == -1) {
 		if (errno == ENFILE || errno == EMFILE) {
-			log_warnx("smtp: fd exhaustion, disabling incoming connections");
+			log_warnx("warn: smtp: fd exhaustion, disabling incoming connections");
 			goto pause;
 		}
 		if (errno == EINTR || errno == ECONNABORTED)
@@ -495,7 +495,7 @@ smtp_new(struct listener *l)
 {
 	struct session	*s;
 
-	log_debug("smtp: new client on listener: %p", l);
+	log_debug("debug: smtp: new client on listener: %p", l);
 
 	if (env->sc_flags & SMTPD_SMTP_PAUSED)
 		fatalx("smtp_new: unexpected client");
@@ -537,7 +537,7 @@ smtp_destroy(struct session *session)
 		return;
 
 	if (env->sc_flags & SMTPD_SMTP_DISABLED) {
-		log_warnx("smtp: fd exaustion over, re-enabling incoming connections");
+		log_warnx("warn: smtp: fd exaustion over, re-enabling incoming connections");
 		env->sc_flags &= ~SMTPD_SMTP_DISABLED;
 		smtp_resume();
 	}
diff --git a/usr.sbin/smtpd/smtp_session.c b/usr.sbin/smtpd/smtp_session.c
index dbfb0535a03..39637ffc58c 100644
--- a/usr.sbin/smtpd/smtp_session.c
+++ b/usr.sbin/smtpd/smtp_session.c
@@ -1,4 +1,4 @@
-/*	$OpenBSD: smtp_session.c,v 1.174 2012/11/02 19:30:57 eric Exp $	*/
+/*	$OpenBSD: smtp_session.c,v 1.175 2012/11/12 14:58:53 eric Exp $	*/
 
 /*
  * Copyright (c) 2008 Gilles Chehade <gilles@openbsd.org>
@@ -28,12 +28,15 @@
 #include <netinet/in.h>
 
 #include <ctype.h>
+#include <errno.h>
 #include <event.h>
 #include <imsg.h>
+#include <inttypes.h>
 #include <resolv.h>
 #include <stdio.h>
 #include <stdlib.h>
 #include <unistd.h>
+#include <vis.h>
 
 #include <openssl/ssl.h>
 
@@ -309,12 +312,12 @@ session_rfc1652_mail_handler(struct session *s, char *args)
 		*body++ = '\0';
 
 		if (strncasecmp(body, "AUTH=", 5) == 0) {
-			log_debug("smtp: AUTH in MAIL FROM command, skipping");
+			log_debug("debug: smtp: AUTH in MAIL FROM command, skipping");
 			continue;		
 		}
 
 		if (strncasecmp(body, "BODY=", 5) == 0) {
-			log_debug("smtp: BODY in MAIL FROM command");
+			log_debug("debug: smtp: BODY in MAIL FROM command");
 
 			if (strncasecmp("body=7bit", body, 9) == 0) {
 				s->s_flags &= ~F_8BITMIME;
@@ -648,6 +651,8 @@ session_io(struct io *io, int evt)
 			io_set_write(&s->s_io);
 			session_respond(s, SMTPD_BANNER, env->sc_hostname);
 		}
+		log_info("smtp-in: Started TLS on session %016" PRIx64 ": %s",
+		    s->s_id, ssl_to_text(s->s_io.ssl));
 		s->kickcount = 0;
 		session_enter_state(s, S_GREETED);
 		break;
@@ -686,6 +691,7 @@ session_io(struct io *io, int evt)
 			return;
 		}
 
+		strlcpy(s->cmd, line, sizeof s->cmd);
 		session_line(s, line, len);
 		if (s->s_flags & F_KICK) {
 			session_destroy(s, "kick");
@@ -697,6 +703,8 @@ session_io(struct io *io, int evt)
 
 	case IO_LOWAT:
 		if (s->s_state == S_QUIT) {
+			log_info("smtp-in: Closing session %016" PRIx64,
+			    s->s_id);
 			session_destroy(s, "done");
 			break;
 		}
@@ -711,14 +719,20 @@ session_io(struct io *io, int evt)
 		break;
 
 	case IO_TIMEOUT:
+		log_info("smtp-in: Disconnecting session %016" PRIx64
+		    ": session timeout", s->s_id);
 		session_destroy(s, "timeout");
 		break;
 
 	case IO_DISCONNECTED:
+		log_info("smtp-in: Received disconnect from session %016" PRIx64,
+		    s->s_id);
 		session_destroy(s, "disconnected");
 		break;
 
 	case IO_ERROR:
+		log_info("smtp-in: Disconnecting session %016" PRIx64
+		    ": IO error: %s", s->s_id, strerror(errno));
 		session_destroy(s, "error");
 		break;
 
@@ -730,6 +744,7 @@ session_io(struct io *io, int evt)
 void
 session_pickup(struct session *s, struct submit_status *ss)
 {
+	char	 user[MAXLOGNAME];
 	void	*ssl;
 
 	s->s_flags &= ~F_WAITIMSG;
@@ -747,6 +762,10 @@ session_pickup(struct session *s, struct submit_status *ss)
 
 	case S_CONNECTED:
 		session_enter_state(s, S_INIT);
+		log_info("smtp-in: New session %016" PRIx64 " from host %s [%s]",
+		   s->s_id,
+		   s->s_hostname,
+		   ss_to_text(&s->s_ss));
 		s->s_msg.session_id = s->s_id;
 		s->s_msg.ss = s->s_ss;
 		session_imsg(s, PROC_MFA, IMSG_MFA_CONNECT, 0, 0, -1,
@@ -755,6 +774,8 @@ session_pickup(struct session *s, struct submit_status *ss)
 
 	case S_INIT:
 		if (ss->code != 250) {
+			log_info("smtp-in: Disconnecting session %016" PRIx64
+			    ": rejected by filter", s->s_id);
 			session_destroy(s, "rejected by filter");
 			return;
 		}
@@ -771,11 +792,17 @@ session_pickup(struct session *s, struct submit_status *ss)
 		break;
 
 	case S_AUTH_FINALIZE:
+		strnvis(user, s->s_auth.user, sizeof user, VIS_WHITE | VIS_SAFE);
 		if (s->s_flags & F_AUTHENTICATED) {
 			session_respond(s, "235 Authentication succeeded");
+			log_info("smtp-in: Accepted authentication for user %s "
+			    "on session %016" PRIx64, user, s->s_id);
 			s->kickcount = 0;
-		} else
+		} else {
+			log_info("smtp-in: Failed authentication for user %s "
+			    "on session %016" PRIx64, user, s->s_id);
 			session_respond(s, "535 Authentication failed");
+		}
 		session_enter_state(s, S_HELO);
 		break;
 
@@ -889,18 +916,16 @@ session_pickup(struct session *s, struct submit_status *ss)
 	case S_DONE:
 		session_respond(s, "250 2.0.0 %08x Message accepted for delivery",
 		    evpid_to_msgid(s->s_msg.id));
-		log_info("%08x: from=<%s%s%s>, size=%ld, nrcpts=%zu, proto=%s, "
-		    "relay=%s [%s]",
+		log_info("smtp-in: Accepted message %08x on session %016" PRIx64
+		    ": from=<%s%s%s>, size=%ld, nrcpts=%zu, proto=%s",
 		    evpid_to_msgid(s->s_msg.id),
+		    s->s_id,
 		    s->s_msg.sender.user,
 		    s->s_msg.sender.user[0] == '\0' ? "" : "@",
 		    s->s_msg.sender.domain,
 		    s->s_datalen,
 		    s->rcptcount,
-		    s->s_flags & F_EHLO ? "ESMTP" : "SMTP",
-		    s->s_hostname,
-		    ss_to_text(&s->s_ss));
-
+		    s->s_flags & F_EHLO ? "ESMTP" : "SMTP");
 		session_enter_state(s, S_HELO);
 		s->s_msg.id = 0;
 		s->mailcount++;
@@ -923,6 +948,8 @@ session_line(struct session *s, char *line, size_t len)
 	if (s->s_state != S_DATACONTENT) {
 		log_trace(TRACE_SMTP, "smtp: %p: <<< %s", s, line);
 		if (++s->kickcount >= SMTP_KICKTHRESHOLD) {
+			log_info("smtp-in: Disconnecting session %016" PRIx64
+			    ": session not moving forward", s->s_id);
 			s->s_flags |= F_KICK;
 			stat_increment("smtp.kick", 1);
 			return;
@@ -969,7 +996,7 @@ session_line(struct session *s, char *line, size_t len)
 		break;
 
 	default:
-		log_debug("session_read: %i", s->s_state);
+		log_debug("debug: session_read: %i", s->s_state);
 		fatalx("session_read: unexpected state");
 	}
 
@@ -1046,7 +1073,7 @@ session_destroy(struct session *s, const char * reason)
 {
 	uint32_t msgid;
 
-	log_debug("smtp: %p: deleting session: %s", s, reason);
+	log_debug("debug: smtp: %p: deleting session: %s", s, reason);
 
 	if (s->s_flags & F_ZOMBIE)
 		goto finalize;
@@ -1126,7 +1153,7 @@ session_respond(struct session *s, char *fmt, ...)
 {
 	va_list	 ap;
 	int	 n, delay;
-	char	 buf[SMTP_LINE_MAX];
+	char	 buf[SMTP_LINE_MAX], tmp[SMTP_LINE_MAX];
 
 	va_start(ap, fmt);
 	n = vsnprintf(buf, sizeof buf, fmt, ap);
@@ -1147,11 +1174,9 @@ session_respond(struct session *s, char *fmt, ...)
 	switch (buf[0]) {
 	case '5':
 	case '4':
-		log_info("%08x: from=<%s@%s>, relay=%s [%s], stat=LocalError (%.*s)",
-		    evpid_to_msgid(s->s_msg.id),
-		    s->s_msg.sender.user, s->s_msg.sender.domain,
-		    s->s_hostname, ss_to_text(&s->s_ss),
-		    n, buf);
+		strnvis(tmp, s->cmd, sizeof tmp, VIS_SAFE | VIS_CSTYLE);
+		log_info("smtp-in: Failed command on session %016" PRIx64
+		    ": \"%s\" => %.*s", s->s_id, tmp, n, buf);
 		break;
 	}
 
diff --git a/usr.sbin/smtpd/smtpctl.c b/usr.sbin/smtpd/smtpctl.c
index da5f871e06a..757024da491 100644
--- a/usr.sbin/smtpd/smtpctl.c
+++ b/usr.sbin/smtpd/smtpctl.c
@@ -1,4 +1,4 @@
-/*	$OpenBSD: smtpctl.c,v 1.94 2012/10/26 19:16:42 chl Exp $	*/
+/*	$OpenBSD: smtpctl.c,v 1.95 2012/11/12 14:58:53 eric Exp $	*/
 
 /*
  * Copyright (c) 2006 Pierre-Yves Ritschard <pyr@openbsd.org>
@@ -56,6 +56,7 @@ static void getflag(uint *, int, char *, char *, size_t);
 static void display(const char *);
 static void show_envelope(const char *);
 static void show_message(const char *);
+static void show_monitor(struct stat_digest *);
 
 int proctype;
 struct imsgbuf	*ibuf;
@@ -228,7 +229,8 @@ connected:
 		break;
 	}
 	case MONITOR:
-		/* XXX */
+    again:
+		imsg_compose(ibuf, IMSG_DIGEST, 0, 0, -1, NULL, 0);
 		break;
 	case LOG_VERBOSE:
 		verbose = 1;
@@ -280,7 +282,12 @@ connected:
 			case NONE:
 				break;
 			case UPDATE_MAP:
+				break;
 			case MONITOR:
+				show_monitor(imsg.data);
+				imsg_free(&imsg);
+				sleep(1);
+				goto again;
 				break;
 			default:
 				err(1, "unexpected reply (%d)", res->action);
@@ -351,7 +358,7 @@ again:
 
 			if (strcmp(kvp->key, "uptime") == 0) {
 				duration = time(NULL) - kvp->val.u.counter;
-				printf("uptime=%zd\n", duration); 
+				printf("uptime=%zd\n", (size_t)duration); 
 				printf("uptime.human=%s\n",
 				    duration_to_text(duration));
 			} else {
@@ -535,3 +542,52 @@ show_message(const char *s)
 
 	display(buf);
 }
+
+static void
+show_monitor(struct stat_digest *d)
+{
+	static int init = 0;
+	static size_t count = 0;
+	static struct stat_digest last;
+
+	if (init == 0) {
+		init = 1;
+		bzero(&last, sizeof last);
+	}
+
+	if (count % 25 == 0) {
+		if (count != 0)
+			printf("\n");
+		printf("--- client ---  "
+		    "-- envelope --   "
+		    "---- relay/delivery --- "
+		    "------- misc -------\n"
+		    "curr conn disc  "
+		    "curr  enq  deq   "
+		    "ok tmpfail prmfail loop "
+		    "expire remove bounce\n");
+	}
+	printf("%4zu %4zu %4zu  "
+	    "%4zu %4zu %4zu "
+	    "%4zu    %4zu    %4zu %4zu   "
+	    "%4zu   %4zu   %4zu\n",
+	    d->clt_connect - d->clt_disconnect,
+	    d->clt_connect - last.clt_connect,
+	    d->clt_disconnect - last.clt_disconnect,
+
+	    d->evp_enqueued - d->evp_dequeued,
+	    d->evp_enqueued - last.evp_enqueued,
+	    d->evp_dequeued - last.evp_dequeued,
+
+	    d->dlv_ok - last.dlv_ok,
+	    d->dlv_tempfail - last.dlv_tempfail,
+	    d->dlv_permfail - last.dlv_permfail,
+	    d->dlv_loop - last.dlv_loop,
+
+	    d->evp_expired - last.evp_expired,
+	    d->evp_removed - last.evp_removed,
+	    d->evp_bounce - last.evp_bounce);
+
+	last = *d;
+	count++;
+}
diff --git a/usr.sbin/smtpd/smtpd.c b/usr.sbin/smtpd/smtpd.c
index 545ce6c825d..ffb57be4e46 100644
--- a/usr.sbin/smtpd/smtpd.c
+++ b/usr.sbin/smtpd/smtpd.c
@@ -1,4 +1,4 @@
-/*	$OpenBSD: smtpd.c,v 1.180 2012/11/02 16:02:33 eric Exp $	*/
+/*	$OpenBSD: smtpd.c,v 1.181 2012/11/12 14:58:53 eric Exp $	*/
 
 /*
  * Copyright (c) 2008 Gilles Chehade <gilles@openbsd.org>
@@ -174,7 +174,7 @@ parent_imsg(struct imsgev *iev, struct imsg *imsg)
 				    c->cause == NULL)
 					break;
 			if (!n) {
-				log_debug("smptd: kill request: proc not found");
+				log_debug("debug: smptd: kill request: proc not found");
 				return;
 			}
 			len = imsg->hdr.len - sizeof imsg->hdr;
@@ -185,7 +185,7 @@ parent_imsg(struct imsgev *iev, struct imsg *imsg)
 				    "parent_imsg");
 				c->cause[len - 1] = '\0';
 			}
-			log_debug("smptd: kill requested for %u: %s",
+			log_debug("debug: smptd: kill requested for %u: %s",
 			    c->pid, c->cause);
 			kill(c->pid, SIGTERM);
 			return;
@@ -247,7 +247,7 @@ parent_shutdown(void)
 		pid = waitpid(WAIT_MYPGRP, NULL, 0);
 	} while (pid != -1 || (pid == -1 && errno == EINTR));
 
-	log_warnx("parent terminating");
+	log_warnx("warn: parent terminating");
 	exit(0);
 }
 
@@ -268,7 +268,7 @@ parent_send_config_listeners(void)
 	struct iovec		 iov[5];
 	int			 opt;
 
-	log_debug("parent_send_config: configuring smtp");
+	log_debug("debug: parent_send_config: configuring smtp");
 	imsg_compose_event(env->sc_ievs[PROC_SMTP], IMSG_CONF_START,
 	    0, 0, -1, NULL, 0);
 
@@ -314,7 +314,7 @@ parent_send_config_client_certs(void)
 	struct ssl		*s;
 	struct iovec		 iov[3];
 
-	log_debug("parent_send_config_client_certs: configuring smtp");
+	log_debug("debug: parent_send_config_client_certs: configuring smtp");
 	imsg_compose_event(env->sc_ievs[PROC_MTA], IMSG_CONF_START,
 	    0, 0, -1, NULL, 0);
 
@@ -346,7 +346,7 @@ parent_send_config_ruleset(int proc)
 	struct mapel		*mapel;
 	struct filter		*f;
 	
-	log_debug("parent_send_config_ruleset: reloading rules and maps");
+	log_debug("debug: parent_send_config_ruleset: reloading rules and maps");
 	imsg_compose_event(env->sc_ievs[proc], IMSG_CONF_START,
 	    0, 0, -1, NULL, 0);
 
@@ -422,7 +422,7 @@ parent_sig_handler(int sig, short event, void *p)
 			case CHILD_DAEMON:
 				die = 1;
 				if (fail)
-					log_warnx("lost child: %s %s",
+					log_warnx("warn: lost child: %s %s",
 					    child->title, cause);
 				break;
 
@@ -448,7 +448,7 @@ parent_sig_handler(int sig, short event, void *p)
 
 			case CHILD_ENQUEUE_OFFLINE:
 				if (fail)
-					log_warnx("smtpd: couldn't enqueue offline "
+					log_warnx("warn: smtpd: couldn't enqueue offline "
 					    "message %s; smtpctl %s", child->path, cause);
 				else
 					unlink(child->path);
@@ -516,7 +516,7 @@ main(int argc, char *argv[])
 			else if (strstr(optarg, "stat=") == optarg)
 				backend_stat = strchr(optarg, '=') + 1;
 			else
-				log_warnx("invalid backend specifier %s", optarg);
+				log_warnx("warn: invalid backend specifier %s", optarg);
 			break;
 		case 'd':
 			debug = 2;
@@ -524,7 +524,7 @@ main(int argc, char *argv[])
 			break;
 		case 'D':
 			if (cmdline_symset(optarg) < 0)
-				log_warnx("could not parse macro definition %s",
+				log_warnx("warn: could not parse macro definition %s",
 				    optarg);
 			break;
 		case 'n':
@@ -558,7 +558,7 @@ main(int argc, char *argv[])
 			else if (!strcmp(optarg, "all"))
 				verbose |= ~TRACE_VERBOSE;
 			else
-				log_warnx("unknown trace flag \"%s\"", optarg);
+				log_warnx("warn: unknown trace flag \"%s\"", optarg);
 			break;
 		case 'P':
 			if (!strcmp(optarg, "smtp"))
@@ -647,10 +647,10 @@ main(int argc, char *argv[])
 		if (daemon(0, 0) == -1)
 			err(1, "failed to daemonize");
 
-	log_debug("using \"%s\" queue backend", backend_queue);
-	log_debug("using \"%s\" scheduler backend", backend_scheduler);
-	log_debug("using \"%s\" stat backend", backend_stat);
-	log_info("startup%s", (debug > 1)?" [debug mode]":"");
+	log_debug("debug: using \"%s\" queue backend", backend_queue);
+	log_debug("debug: using \"%s\" scheduler backend", backend_scheduler);
+	log_debug("debug: using \"%s\" stat backend", backend_stat);
+	log_info("info: startup%s", (debug > 1)?" [debug mode]":"");
 
 	if (env->sc_hostname[0] == '\0')
 		errx(1, "machine does not have a hostname set");
@@ -814,12 +814,12 @@ purge_task(int fd, short ev, void *arg)
 				n++;
 			closedir(d);
 		} else
-			log_warn("purge_task: opendir");
+			log_warn("warn: purge_task: opendir");
 
 		if (n > 2) {
 			switch(purge_pid = fork()) {
 			case -1:
-				log_warn("purge_task: fork");
+				log_warn("warn: purge_task: fork");
 				break;
 			case 0:
 				if (chroot(PATH_SPOOL PATH_PURGE) == -1)
@@ -856,7 +856,7 @@ forkmda(struct imsgev *iev, uint32_t id,
 	pid_t		 pid;
 	int		 n, allout, pipefd[2];
 
-	log_debug("forkmda: to \"%s\" as %s", deliver->to, deliver->user);
+	log_debug("debug: forkmda: to \"%s\" as %s", deliver->to, deliver->user);
 
 	bzero(&u, sizeof (u));
 	ub = user_backend_lookup(USER_PWD);
@@ -971,7 +971,7 @@ offline_scan(int fd, short ev, void *arg)
 	int		 n = 0;
 
 	if (dir == NULL) {
-		log_debug("smtpd: scanning offline queue...");
+		log_debug("debug: smtpd: scanning offline queue...");
 		if ((dir = opendir(PATH_SPOOL PATH_OFFLINE)) == NULL)
 			errx(1, "smtpd: opendir");
 	}
@@ -981,7 +981,7 @@ offline_scan(int fd, short ev, void *arg)
 			continue;
 
 		if (offline_add(d->d_name)) {
-			log_warnx("smtpd: could not add offline message %s", d->d_name);
+			log_warnx("warn: smtpd: could not add offline message %s", d->d_name);
 			continue;
 		}
 
@@ -994,7 +994,7 @@ offline_scan(int fd, short ev, void *arg)
 		}
 	}
 
-	log_debug("smtpd: offline scanning done");
+	log_debug("debug: smtpd: offline scanning done");
 	closedir(dir);
 }
 
@@ -1008,19 +1008,19 @@ offline_enqueue(char *name)
 	struct passwd	*pw;
 
 	if (!bsnprintf(t, sizeof t, "%s/%s", PATH_SPOOL PATH_OFFLINE, name)) {
-		log_warnx("smtpd: path name too long");
+		log_warnx("warn: smtpd: path name too long");
 		return (-1);
 	}
 
 	if ((path = strdup(t)) == NULL) {
-		log_warn("smtpd: strdup");
+		log_warn("warn: smtpd: strdup");
 		return (-1);
 	}
 
-	log_debug("smtpd: enqueueing offline message %s", path);
+	log_debug("debug: smtpd: enqueueing offline message %s", path);
 
 	if ((pid = fork()) == -1) {
-		log_warn("smtpd: fork");
+		log_warn("warn: smtpd: fork");
 		free(path);
 		return (-1);
 	}
@@ -1034,25 +1034,25 @@ offline_enqueue(char *name)
 		bzero(&args, sizeof(args));
 
 		if (lstat(path, &sb) == -1) {
-			log_warn("smtpd: lstat: %s", path);
+			log_warn("warn: smtpd: lstat: %s", path);
 			_exit(1);
 		}
 
 		if (chflags(path, 0) == -1) {
-			log_warn("smtpd: chflags: %s", path);
+			log_warn("warn: smtpd: chflags: %s", path);
 			_exit(1);
 		}
 
 		pw = getpwuid(sb.st_uid);
 		if (pw == NULL) {
-			log_warnx("smtpd: getpwuid for uid %d failed",
+			log_warnx("warn: smtpd: getpwuid for uid %d failed",
 			    sb.st_uid);
 			_exit(1);
 		}
 		
 
 		if (! S_ISREG(sb.st_mode)) {
-			log_warnx("smtpd: file %s (uid %d) not regular",
+			log_warnx("warn: smtpd: file %s (uid %d) not regular",
 			    path, sb.st_uid);
 			_exit(1);
 		}
@@ -1159,12 +1159,12 @@ parent_forward_open(char *username)
 	if (fd == -1) {
 		if (errno == ENOENT)
 			return -2;
-		log_warn("smtpd: parent_forward_open: %s", pathname);
+		log_warn("warn: smtpd: parent_forward_open: %s", pathname);
 		return -1;
 	}
 
 	if (! secure_file(fd, pathname, u.directory, u.uid, 1)) {
-		log_warnx("smtpd: %s: unsecure file", pathname);
+		log_warnx("warn: smtpd: %s: unsecure file", pathname);
 		close(fd);
 		return -1;
 	}
@@ -1366,6 +1366,7 @@ imsg_to_str(int type)
 	CASE(IMSG_STAT_DECREMENT);
 	CASE(IMSG_STAT_SET);
 
+	CASE(IMSG_DIGEST);
 	CASE(IMSG_STATS);
   	CASE(IMSG_STATS_GET);
 	default:
diff --git a/usr.sbin/smtpd/smtpd.h b/usr.sbin/smtpd/smtpd.h
index 44f2fc9dc71..5c3b342bd9b 100644
--- a/usr.sbin/smtpd/smtpd.h
+++ b/usr.sbin/smtpd/smtpd.h
@@ -1,4 +1,4 @@
-/*	$OpenBSD: smtpd.h,v 1.394 2012/11/02 19:30:57 eric Exp $	*/
+/*	$OpenBSD: smtpd.h,v 1.395 2012/11/12 14:58:53 eric Exp $	*/
 
 /*
  * Copyright (c) 2008 Gilles Chehade <gilles@openbsd.org>
@@ -54,8 +54,6 @@
 
 #define	PATH_SMTPCTL		"/usr/sbin/smtpctl"
 
-#define	DIRHASH_BUCKETS		 4096
-
 #define PATH_SPOOL		"/var/spool/smtpd"
 #define PATH_OFFLINE		"/offline"
 #define PATH_PURGE		"/purge"
@@ -193,6 +191,7 @@ enum imsg_type {
 	IMSG_STAT_DECREMENT,
 	IMSG_STAT_SET,
 
+	IMSG_DIGEST,
 	IMSG_STATS,
 	IMSG_STATS_GET,
 };
@@ -248,25 +247,16 @@ enum map_kind {
 	K_NETADDR
 };	
 
-enum mapel_type {
-	ME_STRING,
-	ME_NET,
-	ME_NETMASK
-};
-
 struct mapel {
 	TAILQ_ENTRY(mapel)		 me_entry;
-	union mapel_data {
-		char			 med_string[MAX_LINE_SIZE];
-	}				 me_key;
-	union mapel_data		 me_val;
+	char				 me_key[MAX_LINE_SIZE];
+	char				 me_val[MAX_LINE_SIZE];
 };
 
 struct map {
 	TAILQ_ENTRY(map)		 m_entry;
 	char				 m_name[MAX_LINE_SIZE];
 	objid_t				 m_id;
-	enum mapel_type			 m_eltype;
 	enum map_src			 m_src;
 	char				 m_config[MAXPATHLEN];
 	TAILQ_HEAD(mapel_list, mapel)	 m_contents;
@@ -340,8 +330,8 @@ enum delivery_type {
 };
 
 enum delivery_status {
-	DS_PERMFAILURE	= 0x1,
-	DS_TEMPFAILURE	= 0x2,
+	DS_PERMFAILURE	= 1,
+	DS_TEMPFAILURE	= 2,
 };
 
 enum delivery_flags {
@@ -545,6 +535,8 @@ struct session {
 	struct timeval			 s_tv;
 	struct envelope			 s_msg;
 	short				 s_nresp[STATE_COUNT];
+
+	char				 cmd[SMTP_LINE_MAX];
 	size_t				 kickcount;
 	size_t				 mailcount;
 	size_t				 rcptcount;
@@ -577,7 +569,6 @@ struct smtpd {
 	uint32_t				 sc_queue_flags;
 #define QUEUE_COMPRESS				 0x00000001
 	char					*sc_queue_compress_algo;
-	struct timeval				 sc_qintval;
 	int					 sc_qexpire;
 	struct event				 sc_ev;
 	int					 *sc_pipes[PROC_COUNT]
@@ -901,6 +892,25 @@ struct stat_backend {
 	int	(*iter)(void **, char **, struct stat_value *);
 };
 
+struct stat_digest {
+	time_t			 startup;
+	time_t			 timestamp;
+
+	size_t			 clt_connect;
+	size_t			 clt_disconnect;
+
+	size_t			 evp_enqueued;
+	size_t			 evp_dequeued;
+
+	size_t			 evp_expired;
+	size_t			 evp_removed;
+	size_t			 evp_bounce;
+
+	size_t			 dlv_ok;
+	size_t			 dlv_permfail;
+	size_t			 dlv_tempfail;
+	size_t			 dlv_loop;
+};
 
 extern struct smtpd	*env;
 extern void (*imsg_callback)(struct imsgev *, struct imsg *);
@@ -1014,6 +1024,7 @@ void mfa_session(struct submit_status *, enum session_state);
 /* mta.c */
 pid_t mta(void);
 int mta_response_delivery(const char *);
+const char *mta_response_prefix(const char *);
 const char *mta_response_status(const char *);
 const char *mta_response_text(const char *);
 void mta_route_ok(struct mta_route *);
@@ -1105,6 +1116,7 @@ int ssl_load_certfile(const char *, uint8_t);
 void ssl_setup(struct listener *);
 void *ssl_smtp_init(void *);
 void *ssl_mta_init(struct ssl *);
+const char *ssl_to_text(void *);
 int ssl_cmp(struct ssl *, struct ssl *);
 SPLAY_PROTOTYPE(ssltree, ssl, ssl_nodes, ssl_cmp);
 
@@ -1189,7 +1201,8 @@ char *xstrdup(const char *, const char *);
 void *xmemdup(const void *, size_t, const char *);
 void iobuf_xinit(struct iobuf *, size_t, size_t, const char *);
 void iobuf_xfqueue(struct iobuf *, const char *, const char *, ...);
-void log_envelope(const struct envelope *, const char *, const char *);
+void log_envelope(const struct envelope *, const char *, const char *,
+    const char *);
 void session_socket_blockmode(int, enum blockmodes);
 void session_socket_no_linger(int);
 int session_socket_error(int);
diff --git a/usr.sbin/smtpd/ssl.c b/usr.sbin/smtpd/ssl.c
index 5201f95320f..3ecf57b47c3 100644
--- a/usr.sbin/smtpd/ssl.c
+++ b/usr.sbin/smtpd/ssl.c
@@ -1,4 +1,4 @@
-/*	$OpenBSD: ssl.c,v 1.49 2012/10/14 14:26:31 halex Exp $	*/
+/*	$OpenBSD: ssl.c,v 1.50 2012/11/12 14:58:53 eric Exp $	*/
 
 /*
  * Copyright (c) 2008 Pierre-Yves Ritschard <pyr@openbsd.org>
@@ -77,13 +77,13 @@ ssl_load_file(const char *name, off_t *len, mode_t perm)
 	if (fstat(fd, &st) != 0)
 		goto fail;
 	if (st.st_uid != 0) {
-		log_info("%s: not owned by uid 0", name);
+		log_warnx("warn:  %s: not owned by uid 0", name);
 		errno = EACCES;
 		goto fail;
 	}
 	if (st.st_mode & (S_IRWXU | S_IRWXG | S_IRWXO) & ~perm) {
 		strmode(perm, mode);
-		log_info("%s: insecure permissions: must be at most %s",
+		log_warnx("warn:  %s: insecure permissions: must be at most %s",
 		    name, &mode[1]);
 		errno = EACCES;
 		goto fail;
@@ -142,7 +142,7 @@ ssl_load_certfile(const char *name, uint8_t flags)
 
 	if (strlcpy(key.ssl_name, name, sizeof(key.ssl_name))
 	    >= sizeof(key.ssl_name)) {
-		log_warn("ssl_load_certfile: certificate name truncated");
+		log_warnx("warn:  ssl_load_certfile: certificate name truncated");
 		return -1;
 	}
 
@@ -182,7 +182,7 @@ ssl_load_certfile(const char *name, uint8_t flags)
 	if (s->ssl_ca == NULL) {
 		if (errno == EACCES)
 			goto err;
-		log_info("no CA found in %s", certfile);
+		log_warnx("warn:  no CA found in %s", certfile);
 	}
 
 	if (! bsnprintf(certfile, sizeof(certfile),
@@ -193,8 +193,8 @@ ssl_load_certfile(const char *name, uint8_t flags)
 	if (s->ssl_dhparams == NULL) {
 		if (errno == EACCES)
 			goto err;
-		log_info("no DH parameters found in %s", certfile);
-		log_info("using built-in DH parameters");
+		log_info("info: No DH parameters found in %s: "
+		    "using built-in parameters", certfile);
 	}
 
 	SPLAY_INSERT(ssltree, env->sc_ssl, s);
@@ -271,7 +271,7 @@ ssl_setup(struct listener *l)
 	ssl_set_ephemeral_key_exchange(l->ssl_ctx, dh);
 	DH_free(dh);
 
-	log_debug("ssl_setup: ssl setup finished for listener: %p", l);
+	log_debug("debug: ssl_setup: ssl setup finished for listener: %p", l);
 	return;
 
 err:
@@ -282,6 +282,18 @@ err:
 	return;
 }
 
+const char *
+ssl_to_text(void *ssl) {
+	static char buf[256];
+
+	snprintf(buf, sizeof buf, "version=%s, cipher=%s, bits=%i",
+	    SSL_get_cipher_version(ssl),
+	    SSL_get_cipher_name(ssl),
+	    SSL_get_cipher_bits(ssl, NULL));
+
+	return (buf);
+}
+
 void
 ssl_error(const char *where)
 {
@@ -293,7 +305,7 @@ ssl_error(const char *where)
 		return;
 	for (; (code = ERR_get_error()) != 0 ;) {
 		ERR_error_string_n(code, errbuf, sizeof(errbuf));
-		log_debug("SSL library error: %s: %s", where, errbuf);
+		log_debug("debug: SSL library error: %s: %s", where, errbuf);
 	}
 }
 
@@ -381,7 +393,7 @@ ssl_smtp_init(void *ssl_ctx)
 {
 	SSL *ssl;
 
-	log_debug("session_start_ssl: switching to SSL");
+	log_debug("debug: session_start_ssl: switching to SSL");
 
 	if ((ssl = SSL_new(ssl_ctx)) == NULL)
                 goto err;
diff --git a/usr.sbin/smtpd/stat_backend.c b/usr.sbin/smtpd/stat_backend.c
index 33bedda9982..4aaa5affd20 100644
--- a/usr.sbin/smtpd/stat_backend.c
+++ b/usr.sbin/smtpd/stat_backend.c
@@ -55,7 +55,7 @@ stat_increment(const char *name, size_t count)
 	s = buf + sizeof *value;
 	if ((len = strlcpy(s, name, STAT_KEY_SIZE)) >= STAT_KEY_SIZE) {
 		len = STAT_KEY_SIZE - 1;
-		log_warn("stat_increment: truncated key '%s', ignored", name);
+		log_warn("warn: stat_increment: truncated key '%s', ignored", name);
 	}
 
 	imsg_compose_event(env->sc_ievs[PROC_CONTROL],
@@ -74,7 +74,7 @@ stat_decrement(const char *name, size_t count)
 	s = buf + sizeof *value;
 	if ((len = strlcpy(s, name, STAT_KEY_SIZE)) >= STAT_KEY_SIZE) {
 		len = STAT_KEY_SIZE - 1;
-		log_warn("stat_increment: truncated key '%s', ignored", name);
+		log_warn("warn: stat_increment: truncated key '%s', ignored", name);
 	}
 
 	imsg_compose_event(env->sc_ievs[PROC_CONTROL],
@@ -91,7 +91,7 @@ stat_set(const char *name, const struct stat_value *value)
 	s = buf + sizeof *value;
 	if ((len = strlcpy(s, name, STAT_KEY_SIZE)) >= STAT_KEY_SIZE) {
 		len = STAT_KEY_SIZE - 1;
-		log_warn("stat_increment: truncated key '%s', ignored", name);
+		log_warn("warn: stat_increment: truncated key '%s', ignored", name);
 	}
 
 	imsg_compose_event(env->sc_ievs[PROC_CONTROL],
diff --git a/usr.sbin/smtpd/util.c b/usr.sbin/smtpd/util.c
index 5f00474ee21..820bbd4cf85 100644
--- a/usr.sbin/smtpd/util.c
+++ b/usr.sbin/smtpd/util.c
@@ -1,4 +1,4 @@
-/*	$OpenBSD: util.c,v 1.87 2012/10/10 19:39:11 gilles Exp $	*/
+/*	$OpenBSD: util.c,v 1.88 2012/11/12 14:58:53 eric Exp $	*/
 
 /*
  * Copyright (c) 2000,2001 Markus Friedl.  All rights reserved.
@@ -646,7 +646,7 @@ text_to_netaddr(struct netaddr *netaddr, const char *s)
 
 				/* XXX - until AF_INET6 support gets in base */
 				if (errno != EAFNOSUPPORT) {
-					log_warn("inet_net_pton");
+					log_warn("warn: inet_net_pton");
 					return 0;
 				}
 				bits = temp_inet_net_pton_ipv6(s,
@@ -654,7 +654,7 @@ text_to_netaddr(struct netaddr *netaddr, const char *s)
 				    sizeof(struct in6_addr));
 			}
 			if (bits == -1) {
-				log_warn("inet_net_pton");
+				log_warn("warn: inet_net_pton");
 				return 0;
 			}
 			ssin6.sin6_family = AF_INET6;
@@ -1055,7 +1055,8 @@ temp_inet_net_pton_ipv6(const char *src, void *dst, size_t size)
 }
 
 void
-log_envelope(const struct envelope *evp, const char *extra, const char *status)
+log_envelope(const struct envelope *evp, const char *extra, const char *prefix,
+    const char *status)
 {
 	char rcpt[MAX_LINE_SIZE];
 	char tmp[MAX_LINE_SIZE];
@@ -1086,7 +1087,9 @@ log_envelope(const struct envelope *evp, const char *extra, const char *status)
 	if (extra == NULL)
 		extra = "";
 
-	log_info("%016" PRIx64 ": from=<%s@%s>, to=<%s@%s>, %s%sdelay=%s, %sstat=%s",
+	log_info("%s: %s for %016" PRIx64 ": from=<%s@%s>, to=<%s@%s>, %s%sdelay=%s, %sstat=%s",
+	    evp->type == D_MDA ? "delivery" : "relay",
+	    prefix,
 	    evp->id, evp->sender.user, evp->sender.domain,
 	    evp->dest.user, evp->dest.domain,
 	    rcpt,