This patch adds logging to standard error for qmail-smtpd. It logs
all interactions likely to be of interest. It is based on some
code John Levine was using, alas the original author is unknown.
The error logging from that code has been enhanced and extended with
assistance from John; some code has been separated out into separate
files (stderrbits.c, .h) for use in other qmail components and add-ons.

I expect to publish any updates to this patch at,
    http://free.acrconsulting.co.uk/
where you will also find some documentation for this patch.

                Andrew Richards, 16th October 2008.

diff -N -u netqmail-1.06/Makefile netqmail-1.06.errmsgs/Makefile
--- netqmail-1.06/Makefile	2007-11-30 20:22:54.000000000 +0000
+++ netqmail-1.06.errmsgs/Makefile	2008-10-14 16:21:10.000000000 +0100
@@ -1535,12 +1535,14 @@
 load qmail-smtpd.o rcpthosts.o commands.o timeoutread.o \
 timeoutwrite.o ip.o ipme.o ipalloc.o control.o constmap.o received.o \
 date822fmt.o now.o qmail.o cdb.a fd.a wait.a datetime.a getln.a \
-open.a sig.a case.a env.a stralloc.a alloc.a substdio.a error.a str.a \
+open.a sig.a case.a env.a stralloc.a stderrbits.o \
+alloc.a substdio.a error.a str.a \
 fs.a auto_qmail.o socket.lib
 	./load qmail-smtpd rcpthosts.o commands.o timeoutread.o \
 	timeoutwrite.o ip.o ipme.o ipalloc.o control.o constmap.o \
 	received.o date822fmt.o now.o qmail.o cdb.a fd.a wait.a \
 	datetime.a getln.a open.a sig.a case.a env.a stralloc.a \
+	stderrbits.o \
 	alloc.a substdio.a error.a str.a fs.a auto_qmail.o  `cat \
 	socket.lib`
 
@@ -1911,6 +1913,10 @@
 scan.h fmt.h
 	./compile splogger.c
 
+stderrbits.o: \
+compile stderrbits.c stderrbits.h stralloc.h gen_alloc.h fmt.h
+	./compile stderrbits.c
+
 str.a: \
 makelib str_len.o str_diff.o str_diffn.o str_cpy.o str_chr.o \
 str_rchr.o str_start.o byte_chr.o byte_rchr.o byte_diff.o byte_copy.o \
diff -N -u netqmail-1.06/qmail-smtpd.c netqmail-1.06.errmsgs/qmail-smtpd.c
--- netqmail-1.06/qmail-smtpd.c	2007-11-30 20:22:54.000000000 +0000
+++ netqmail-1.06.errmsgs/qmail-smtpd.c	2008-10-15 10:55:42.000000000 +0100
@@ -23,16 +23,35 @@
 #include "timeoutread.h"
 #include "timeoutwrite.h"
 #include "commands.h"
+#include "stderrbits.h"
 
+#define enew()	{ eout("qmail-smtpd("); epid(); eout3(") from ",remoteip,": "); }
+/* Or if you prefer shorter log messages (deduce IP from tcpserver PID entry), */
+/*              { eout("qmail-smtpd("); epid(); eout("): "); } */
 #define MAXHOPS 100
 unsigned int databytes = 0;
 int timeout = 1200;
 
+char *remoteip="(not yet set)";
+char *remotehost;
+char *remoteinfo;
+char *local;
+char *relayclient;
+
+stralloc mailfrom = {0};
+stralloc rcptto = {0};
+int rcptcount;
+stralloc addr = {0}; /* will be 0-terminated, if addrparse returns 1 */
+
 int safewrite(fd,buf,len) int fd; char *buf; int len;
 {
   int r;
   r = timeoutwrite(timeout,fd,buf,len);
-  if (r <= 0) _exit(1);
+  if (r <= 0)
+  {
+    enew(); eout("Write error (disconnect?), quitting.\n"); eflush();
+    _exit(1);
+  }
   return r;
 }
 
@@ -42,22 +61,79 @@
 void flush() { substdio_flush(&ssout); }
 void out(s) char *s; { substdio_puts(&ssout,s); }
 
-void die_read() { _exit(1); }
-void die_alarm() { out("451 timeout (#4.4.2)\r\n"); flush(); _exit(1); }
-void die_nomem() { out("421 out of memory (#4.3.0)\r\n"); flush(); _exit(1); }
-void die_control() { out("421 unable to read controls (#4.3.0)\r\n"); flush(); _exit(1); }
-void die_ipme() { out("421 unable to figure out my IP addresses (#4.3.0)\r\n"); flush(); _exit(1); }
-void straynewline() { out("451 See http://pobox.com/~djb/docs/smtplf.html.\r\n"); flush(); _exit(1); }
+void die_read()
+{
+  enew(); eout("Read error (disconnect?), quitting.\n"); eflush(); _exit(1);
+}
+void die_alarm()
+{
+  enew(); eout("Connection timed out, quitting.\n"); eflush();
+  out("451 timeout (#4.4.2)\r\n"); flush(); _exit(1);
+}
+void die_nomem()
+{
+  enew(); eout("Out of memory, quitting.\n"); eflush();
+  out("421 out of memory (#4.3.0)\r\n"); flush(); _exit(1);
+}
+void die_control()
+{
+  enew(); eout("Unable to read controls, quitting.\n"); eflush();
+  out("421 unable to read controls (#4.3.0)\r\n"); flush(); _exit(1);
+}
+void die_ipme()
+{
+  enew(); eout("Unable to figure out my IP addresses, quitting.\n"); eflush();
+  out("421 unable to figure out my IP addresses (#4.3.0)\r\n"); flush(); _exit(1);
+}
+void straynewline()
+{
+  enew(); eout("Stray newline, quitting.\n"); eflush();
+  out("451 See http://pobox.com/~djb/docs/smtplf.html.\r\n"); flush(); _exit(1);
+}
 
-void err_bmf() { out("553 sorry, your envelope sender is in my badmailfrom list (#5.7.1)\r\n"); }
-void err_nogateway() { out("553 sorry, that domain isn't in my list of allowed rcpthosts (#5.7.1)\r\n"); }
+void err_bmf()
+{
+  enew(); eout("Sender address in badmailfrom.\n"); eflush();
+  out("553 sorry, your envelope sender is in my badmailfrom list (#5.7.1)\r\n");
+}
+void err_nogateway()
+{
+  enew(); eout3("Recipient domain not in rcpthosts: ",addr.s,".\n"); eflush();
+  out("553 sorry, that domain isn't in my list of allowed rcpthosts (#5.7.1)\r\n");
+}
 void err_unimpl(arg) char *arg; { out("502 unimplemented (#5.5.1)\r\n"); }
 void err_syntax() { out("555 syntax error (#5.5.4)\r\n"); }
-void err_wantmail() { out("503 MAIL first (#5.5.1)\r\n"); }
-void err_wantrcpt() { out("503 RCPT first (#5.5.1)\r\n"); }
+void err_wantmail()
+{
+  enew(); eout("Attempted RCPT or DATA before MAIL.\n"); eflush();
+  out("503 MAIL first (#5.5.1)\r\n");
+}
+void err_wantrcpt()
+{
+  enew(); eout("Attempted DATA before RCPT.\n"); eflush();
+  out("503 RCPT first (#5.5.1)\r\n");
+}
 void err_noop(arg) char *arg; { out("250 ok\r\n"); }
-void err_vrfy(arg) char *arg; { out("252 send some mail, i'll try my best\r\n"); }
-void err_qqt() { out("451 qqt failure (#4.3.0)\r\n"); }
+void err_vrfy(arg) char *arg;
+{
+  enew(); eout("VRFY requested.\n"); eflush();
+  out("252 send some mail, i'll try my best\r\n");
+}
+void err_qqt()
+{
+  enew(); eout("qqt failure.\n"); eflush();
+  out("451 qqt failure (#4.3.0)\r\n");
+}
+void err_hops()
+{
+  enew(); eout("Exceeded hop count.\n"); eflush();
+  out("554 too many hops, this message is looping (#5.4.6)\r\n");
+}
+void err_databytes()
+{
+  enew(); eout("Exceeded DATABYTES limit.\n"); eflush();
+  out("552 sorry, that message size exceeds my databytes limit (#5.3.4)\r\n");
+}
 
 
 stralloc greeting = {0};
@@ -73,15 +149,10 @@
 }
 void smtp_quit(arg) char *arg;
 {
+  enew(); eout("Remote end QUIT, quitting.\n"); eflush();
   smtp_greet("221 "); out("\r\n"); flush(); _exit(0);
 }
 
-char *remoteip;
-char *remotehost;
-char *remoteinfo;
-char *local;
-char *relayclient;
-
 stralloc helohost = {0};
 char *fakehelo; /* pointer into helohost, or 0 */
 
@@ -132,11 +203,10 @@
   remoteinfo = env_get("TCPREMOTEINFO");
   relayclient = env_get("RELAYCLIENT");
   dohelo(remotehost);
+  enew(); eout("New session.\n"); eflush();
 }
 
 
-stralloc addr = {0}; /* will be 0-terminated, if addrparse returns 1 */
-
 int addrparse(arg)
 char *arg;
 {
@@ -219,16 +289,16 @@
 
 int seenmail = 0;
 int flagbarf; /* defined if seenmail */
-stralloc mailfrom = {0};
-stralloc rcptto = {0};
 
 void smtp_helo(arg) char *arg;
 {
+  enew(); eout3("Received HELO ",arg,".\n"); eflush();
   smtp_greet("250 "); out("\r\n");
   seenmail = 0; dohelo(arg);
 }
 void smtp_ehlo(arg) char *arg;
 {
+  enew(); eout3("Received EHLO ",arg,".\n"); eflush();
   smtp_greet("250-"); out("\r\n250-PIPELINING\r\n250 8BITMIME\r\n");
   seenmail = 0; dohelo(arg);
 }
@@ -245,6 +315,8 @@
   if (!stralloc_copys(&rcptto,"")) die_nomem();
   if (!stralloc_copys(&mailfrom,addr.s)) die_nomem();
   if (!stralloc_0(&mailfrom)) die_nomem();
+  rcptcount = 0;
+  enew(); eout3("Envelope sender ",mailfrom.s,".\n"); eflush();
   out("250 ok\r\n");
 }
 void smtp_rcpt(arg) char *arg; {
@@ -261,6 +333,8 @@
   if (!stralloc_cats(&rcptto,"T")) die_nomem();
   if (!stralloc_cats(&rcptto,addr.s)) die_nomem();
   if (!stralloc_0(&rcptto)) die_nomem();
+  ++rcptcount;
+  enew(); eout3("Recipient ",addr.s,".\n"); eflush();
   out("250 ok\r\n");
 }
 
@@ -363,6 +437,9 @@
   accept_buf[fmt_ulong(accept_buf,qp)] = 0;
   out(accept_buf);
   out("\r\n");
+  enew(); eout2("Message accepted, qp ",accept_buf);
+  accept_buf[fmt_ulong(accept_buf,rcptcount)] = 0;
+  eout3(" (",accept_buf," recipients).\n"); eflush();
 }
 
 void smtp_data(arg) char *arg; {
@@ -387,11 +464,15 @@
  
   qqx = qmail_close(&qqt);
   if (!*qqx) { acceptmessage(qp); return; }
-  if (hops) { out("554 too many hops, this message is looping (#5.4.6)\r\n"); return; }
-  if (databytes) if (!bytestooverflow) { out("552 sorry, that message size exceeds my databytes limit (#5.3.4)\r\n"); return; }
+  if (hops) { err_hops(); return; }
+  if (databytes) if (!bytestooverflow) { err_databytes(); return; }
   if (*qqx == 'D') out("554 "); else out("451 ");
   out(qqx + 1);
   out("\r\n");
+  enew(); eout("Message rejected (");
+  if (*qqx == 'D') eout("554 "); else eout("451 ");
+  eout2(qqx + 1,").\n");
+  eflush();
 }
 
 struct commands smtpcommands[] = {
diff -N -u netqmail-1.06/stderrbits.c netqmail-1.06.errmsgs/stderrbits.c
--- netqmail-1.06/stderrbits.c	1970-01-01 01:00:00.000000000 +0100
+++ netqmail-1.06.errmsgs/stderrbits.c	2008-10-14 16:10:45.000000000 +0100
@@ -0,0 +1,18 @@
+#include "readwrite.h"
+#include "stderrbits.h"
+#include "substdio.h"
+#include "fmt.h"
+
+char sserrbuf[512];
+static substdio sserr = SUBSTDIO_FDBUF(write,2,sserrbuf,sizeof sserrbuf);
+
+static char pid_str[FMT_ULONG]="?PID?";
+
+void eout(s) char *s; {substdio_puts(&sserr,s);}
+void epid()
+{
+  if (*pid_str == '?') /* not yet set from getpid() */
+    pid_str[fmt_ulong(pid_str,getpid())] = 0;
+  eout(pid_str);
+}
+void eflush() { substdio_flush(&sserr); }
diff -N -u netqmail-1.06/stderrbits.h netqmail-1.06.errmsgs/stderrbits.h
--- netqmail-1.06/stderrbits.h	1970-01-01 01:00:00.000000000 +0100
+++ netqmail-1.06.errmsgs/stderrbits.h	2008-10-10 12:22:49.000000000 +0100
@@ -0,0 +1,11 @@
+extern void eout();
+extern void epid();
+#define eout2(s1,s2)				{ eout(s1); eout(s2); }
+#define eout3(s1,s2,s3)				{ eout(s1); eout2(s2,s3); }
+#define eout4(s1,s2,s3,s4)			{ eout2(s1,s2); eout2(s3,s4); }
+#define eout5(s1,s2,s3,s4,s5)			{ eout2(s1,s2); eout3(s3,s4,s5); }
+#define eout6(s1,s2,s3,s4,s5,s6)		{ eout3(s1,s2,s3); eout3(s4,s5,s6); }
+#define eout7(s1,s2,s3,s4,s5,s6,s7)		{ eout3(s1,s2,s3); eout4(s4,s5,s6,s7); }
+#define eout8(s1,s2,s3,s4,s5,s6,s7,s8)		{ eout4(s1,s2,s3,s4); eout4(s5,s6,s7,s8); }
+#define eout9(s1,s2,s3,s4,s5,s6,s7,s8,s9)	{ eout4(s1,s2,s3,s4); eout5(s5,s6,s7,s8,s9); }
+extern void eflush();
diff -N -u netqmail-1.06/TARGETS netqmail-1.06.errmsgs/TARGETS
--- netqmail-1.06/TARGETS	1998-06-15 11:53:16.000000000 +0100
+++ netqmail-1.06.errmsgs/TARGETS	2008-09-29 17:12:34.000000000 +0100
@@ -252,6 +252,7 @@
 qmail-qmtpd
 qmail-smtpd.o
 qmail-smtpd
+stderrbits.o
 sendmail.o
 sendmail
 tcp-env.o