OSSP CVS Repository

ossp - Difference in ossp-pkg/lmtp2nntp/lmtp2nntp.c versions 1.45 and 1.46
Not logged in
[Honeypot]  [Browse]  [Home]  [Login]  [Reports
[Search]  [Ticket]  [Timeline
  [History

ossp-pkg/lmtp2nntp/lmtp2nntp.c 1.45 -> 1.46

--- lmtp2nntp.c  2001/09/10 06:50:56     1.45
+++ lmtp2nntp.c  2001/09/10 06:54:06     1.46
@@ -72,15 +72,15 @@
 #define STDSTRLEN 128
 #define MAXNEWSSERVICES 16
 
-extern void lmtp_debug_dumplmtp(lmtp_t *lmtp);
+//FIXME extern void lmtp_debug_dumplmtp(lmtp_t *lmtp);
 
-static lmtp_rc_t lmtp_cb_lhlo   (lmtp_t *lmtp, lmtp_io_t *io, lmtp_req_t *req, void *ctx);
-static lmtp_rc_t lmtp_cb_mail   (lmtp_t *lmtp, lmtp_io_t *io, lmtp_req_t *req, void *ctx);
-static lmtp_rc_t lmtp_cb_rcpt   (lmtp_t *lmtp, lmtp_io_t *io, lmtp_req_t *req, void *ctx);
-static lmtp_rc_t lmtp_cb_data   (lmtp_t *lmtp, lmtp_io_t *io, lmtp_req_t *req, void *ctx);
-static lmtp_rc_t lmtp_cb_noop   (lmtp_t *lmtp, lmtp_io_t *io, lmtp_req_t *req, void *ctx);
-static lmtp_rc_t lmtp_cb_rset   (lmtp_t *lmtp, lmtp_io_t *io, lmtp_req_t *req, void *ctx);
-static lmtp_rc_t lmtp_cb_quit   (lmtp_t *lmtp, lmtp_io_t *io, lmtp_req_t *req, void *ctx);
+static lmtp_rc_t lmtp_cb_lhlo(lmtp_t *lmtp, lmtp_io_t *io, lmtp_req_t *req, void *ctx);
+static lmtp_rc_t lmtp_cb_mail(lmtp_t *lmtp, lmtp_io_t *io, lmtp_req_t *req, void *ctx);
+static lmtp_rc_t lmtp_cb_rcpt(lmtp_t *lmtp, lmtp_io_t *io, lmtp_req_t *req, void *ctx);
+static lmtp_rc_t lmtp_cb_data(lmtp_t *lmtp, lmtp_io_t *io, lmtp_req_t *req, void *ctx);
+static lmtp_rc_t lmtp_cb_noop(lmtp_t *lmtp, lmtp_io_t *io, lmtp_req_t *req, void *ctx);
+static lmtp_rc_t lmtp_cb_rset(lmtp_t *lmtp, lmtp_io_t *io, lmtp_req_t *req, void *ctx);
+static lmtp_rc_t lmtp_cb_quit(lmtp_t *lmtp, lmtp_io_t *io, lmtp_req_t *req, void *ctx);
 
 static int helo_rfc0821domain(char *msg, char **domain);
 static int helo_rfc1035domain(char *msg, char **domain);
@@ -611,9 +611,10 @@
     lmtp_loop(lmtp);
 
     /* graceful shutdown */
-    log0(ctx, INFO, "%P: graceful shutdown, no more logging until exit");
     lmtp_gfs_quit(ctx);
     lmtp_gfs_lhlo(ctx);
+    log0(ctx, INFO, "%P: graceful shutdown, no more logging until exit");
+    l2_stream_destroy(ctx->l2);
     lmtp_destroy(lmtp);
     if (ctx->option_logfile != NULL)
         free(ctx->option_logfile);
@@ -624,7 +625,6 @@
     if (ctx != NULL)
         free(ctx);
     str_parse(NULL, NULL);
-    l2_stream_destroy(ctx->l2);
 
     return 0;
 }
@@ -722,14 +722,14 @@
      *  HELO <SP> <domain> <CRLF>
      */
     lmtp2nntp_t *ctx = (lmtp2nntp_t *)_ctx;
-    lmtp_res_t res;
-    nntp_rc_t rc;
-    char str[STDSTRLEN];
-    int bOk;
-    int i;
-    nntp_io_t nntp_io;
+    nntp_rc_t    rc;
+    lmtp_res_t   res;
+    char         str[STDSTRLEN];
+    int          bOk;
+    int          i;
+    nntp_io_t    nntp_io;
 
-    log0(ctx, INFO, "lmtp_cb_lhlo");
+    log1(ctx, INFO, "lmtp_cb_lhlo < %s", req->msg);
 
     nntp_io.ctx    = ctx;
     nntp_io.select = NULL;
@@ -740,66 +740,72 @@
      *  RFC1893 2. Status Codes                         5.X.X   Permanent Failure
      *  RFC1893 3.5 Network and Routing Status          X.0.0   Other undefined Status
      */
+    log0(ctx, TRACE, "checking for Duplicate LHLO");
     if (ctx->session.lhlo_seen) {
         res.statuscode = "503";
         res.dsncode    = "5.0.0";
         res.statusmsg  = "Duplicate LHLO.";
-        lmtp_response(lmtp, &res);
-        return LMTP_OK;
+        CU(LMTP_OK);
     }
 
     /*  RFC0821 4.2.1. REPLY CODES BY FUNCTION GROUPS   501 Syntax error in parameters or arguments
      *  RFC1893 2. Status Codes                         5.X.X   Permanent Failure
      *  RFC1893 3.5 Network and Routing Status          X.0.0   Other undefined Status
      */
+    log0(ctx, TRACE, "checking lhlo_domain to match either RFC0821 or RFC1035 syntax");
     if (! (   helo_rfc0821domain(req->msg, &ctx->session.lhlo_domain) > 0
            || helo_rfc1035domain(req->msg, &ctx->session.lhlo_domain) > 0)) {
         res.statuscode = "501";
         res.dsncode    = "5.0.0";
         res.statusmsg  = "Please identify yourself. Domain must match RFC0821/RFC1035.";
-        lmtp_response(lmtp, &res);
-        return LMTP_OK;
+        CU(LMTP_OK);
     }
 
     /*  RFC0821 4.2.1. REPLY CODES BY FUNCTION GROUPS   451 Requested action aborted: local error in processing
      *  RFC1893 2. Status Codes                         4.X.X   Persistent Transient Failure
      *  RFC1893 3.5 Network and Routing Status          X.3.5   System incorrectly configured
      */
+    log0(ctx, TRACE, "check if at least one NNTP service was successfully configured");
     if (ctx->nsc == 0) {
         res.statuscode = "451";
         res.dsncode    = "4.3.5";
         res.statusmsg  = "No valid NNTP services configured.";
-        lmtp_response(lmtp, &res);
-        return LMTP_OK;
+        CU(LMTP_OK);
     }
 
+    log0(ctx, TRACE, "try to establish a session to any configured NNTP services");
     i = 0;
     do {
+        log1(ctx, DEBUG, "trying ns[%d]", i);
         bOk = TRUE;
+        log2(ctx, TRACE, "try %s:%s", ctx->ns[i].h, ctx->ns[i].p);
+
         if (bOk && (ctx->saBind != NULL)) {
-            log0(ctx, DEBUG, "bind");
+            log2(ctx, DEBUG, "bind local socket to %s:%s", ctx->cpBindh, ctx->cpBindp);
             if (bind(ctx->ns[i].s, ctx->saBind->sa_buf, ctx->saBind->sa_len) < 0) {
                 bOk = FALSE;
                 log0(ctx, ERROR, "bind=%m");
             }
         }
+
         if (bOk) {
             if(ctx->option_waittime > 0) {
-                log0(ctx, DEBUG, "connect_nonb");
+                log1(ctx, DEBUG, "connect_nonb with waittime=%d", ctx->option_waittime);
                 if (connect_nonb(ctx->ns[i].s, ctx->ns[i].sa->sa_buf, ctx->ns[i].sa->sa_len, 
                              ctx->option_waittime) < 0) {
                     bOk = FALSE;
-                    log0(ctx, ERROR, "connect_nonb=%m");
+                    log0(ctx, WARNING, "connect_nonb=%m");
                 }
             }
             else {
                 log0(ctx, DEBUG, "connect");
                 if (connect(ctx->ns[i].s, ctx->ns[i].sa->sa_buf, ctx->ns[i].sa->sa_len) < 0) {
                     bOk = FALSE;
-                    log0(ctx, ERROR, "connect=%m");
+                    log0(ctx, WARNING, "connect=%m");
                 }
             }
         }
+
         if (bOk) {
             log0(ctx, DEBUG, "nntp_create");
             if ((ctx->ns[i].nntp = nntp_create(ctx->ns[i].s, ctx->ns[i].s, 
@@ -809,10 +815,12 @@
                 log0(ctx, ERROR, "nntp_create failed");
             }
         }
+
         if (bOk && ctx->option_waittime >= 0) {
-            log1(ctx, DEBUG, "nntp_timeout(%d)", ctx->option_waittime);
+            log1(ctx, DEBUG, "nntp_timeout with %d", ctx->option_waittime);
             nntp_timeout(ctx->ns[i].nntp, ctx->option_waittime);
         }
+
         if (bOk) {
             log0(ctx, DEBUG, "nntp_init");
             if ((rc = nntp_init(ctx->ns[i].nntp)) != NNTP_OK) {
@@ -820,12 +828,14 @@
                 log2(ctx, ERROR, "nntp_init=(%m) %s", rc, nntp_error(rc));
             }
         }
+
         if (bOk) {
-            log0(ctx, INFO, "nntp connection successfully established");
+            log2(ctx, INFO, "NNTP session to %s:%s successfully established", ctx->ns[i].h, ctx->ns[i].p);
             i++;
         }
         else {
-            log0(ctx, INFO, "nntp connection establishment failed");
+            log2(ctx, WARNING, "NNTP session establishment to %s:%s failed", ctx->ns[i].h, ctx->ns[i].p);
+            log1(ctx, DEBUG, "removing ns[%d] from list", i);
             if (i < --ctx->nsc) {
                 memcpy(&ctx->ns[i], &ctx->ns[i+1], (ctx->nsc - i ) * sizeof(struct ns));
             }
@@ -836,12 +846,13 @@
      *  RFC1893 2. Status Codes                         4.X.X   Persistent Transient Failure
      *  RFC1893 3.5 Network and Routing Status          X.4.1   No answer from host
      */
+    log0(ctx, DEBUG, "check if at least one NNTP session successfully established");
     if (ctx->nsc == 0) {
+        log0(ctx, ERROR, "no NNTP session established");
         res.statuscode = "421";
         res.dsncode    = "4.4.1";
-        res.statusmsg  = "All attempts connecting to NNTP services failed.";
-        lmtp_response(lmtp, &res);
-        return LMTP_OK;
+        res.statusmsg  = "No NNTP session established.";
+        CU(LMTP_OK);
     }
         
     ctx->session.lhlo_seen = TRUE;
@@ -853,21 +864,26 @@
                "ENHANCEDSTATUSCODES\n"               /* RFC2034 */
                "DSN\n"                               /* RFC1894 */
                "PIPELINING\n"                        /* RFC1854 */
-               "8BITMIME",                           /* RFC1652 */
+               "8BITMIME\n"                          /* RFC1652 */
+               "ENVID",                              /* FIXME */
                ctx->uname.nodename,
                ctx->session.lhlo_domain);
     res.statuscode = "250";
     res.dsncode    = NULL; /* DSN not used for greeting */
     res.statusmsg  = str;
+    CU(LMTP_OK);
+
+    CUS:
     lmtp_response(lmtp, &res);
-    return LMTP_OK;
+    return rc;
 }
 
 static void lmtp_gfs_lhlo(lmtp2nntp_t *ctx)
 {
-    /* graceful shutdown */
     int i;
 
+    log0(ctx, INFO, "lmtp_gfs_lhlo - graceful shutdown");
+
     for (i = 0; i < ctx->nsc; i++) {
         if (ctx->ns[i].nntp != NULL)
             nntp_destroy(ctx->ns[i].nntp);
@@ -1009,44 +1025,45 @@
 static lmtp_rc_t lmtp_cb_mail(lmtp_t *lmtp, lmtp_io_t *io, lmtp_req_t *req, void *_ctx)
 {
     lmtp2nntp_t *ctx = (lmtp2nntp_t *)_ctx;
-    lmtp_res_t res;
+    lmtp_rc_t    rc;
+    lmtp_res_t   res;
 
-    log0(ctx, INFO, "lmtp_cb_mail");
+    log1(ctx, INFO, "lmtp_cb_mail < %s", req->msg);
 
     /*  RFC0821 4.2.1. REPLY CODES BY FUNCTION GROUPS   553 Requested action not taken: mailbox name not allowed
      *  RFC1893 2. Status Codes                         5.X.X   Permanent Failure
      *  RFC1893 3.5 Network and Routing Status          X.1.8   Bad sender's system address
      */
+    log0(ctx, TRACE, "checking for previous LHLO");
     if (!ctx->session.lhlo_seen) {
         res.statuscode = "553";
         res.dsncode    = "5.1.8";
         res.statusmsg  = "friendly people say LHLO to open a transmission channel.";
-        lmtp_response(lmtp, &res);
-        return LMTP_OK;
+        CU(LMTP_OK);
     }
 
     /*  RFC0821 4.2.1. REPLY CODES BY FUNCTION GROUPS   503 Bad sequence of commands
      *  RFC1893 2. Status Codes                         5.X.X   Permanent Failure
      *  RFC1893 3.5 Network and Routing Status          X.5.0   Other or undefined protocol status
      */
+    log0(ctx, TRACE, "checking for previous MAIL");
     if (ctx->msg != NULL) {
         res.statuscode = "503";
         res.dsncode    = "5.5.0";
         res.statusmsg  = "Sender already specified.";
-        lmtp_response(lmtp, &res);
-        return LMTP_OK;
+        CU(LMTP_OK);
     }
 
     /*  RFC0821 4.2.1. REPLY CODES BY FUNCTION GROUPS   452 Requested action not taken: insufficient system storage
      *  RFC1893 2. Status Codes                         4.X.X   Persistent Transient Failure
      *  RFC1893 3.5 Network and Routing Status          X.3.1   Mail system full 
      */
+    log0(ctx, TRACE, "msg_create");
     if ((ctx->msg = msg_create()) == NULL) {
         res.statuscode = "452";
         res.dsncode    = "4.3.1";
         res.statusmsg  = "Internal error - memory.";
-        lmtp_response(lmtp, &res);
-        return LMTP_ERR_MEM;
+        CU(LMTP_ERR_MEM);
     }
 
     /*  RFC1652 2. Framework for the 8bit MIME Transport Extension
@@ -1066,44 +1083,38 @@
      *  RFC1893 2. Status Codes                         5.X.X   Permanent Failure
      *  RFC1893 3.5 Network and Routing Status          X.1.7   Bad sender's mailbox address syntax
      */
+    log0(ctx, TRACE, "checking if sender address is a domain name");
     if (str_parse(req->msg, "m/^MAIL From:\\s*<(?:.+@.+)>/i") <= 0) {
         res.statuscode = "553";
         res.dsncode    = "5.1.7";
         res.statusmsg  = "Domain name required for sender address.";
-        lmtp_response(lmtp, &res);
-        msg_destroy(ctx->msg);
-        ctx->msg = NULL;
-        return LMTP_OK;
+        CU(LMTP_OK);
     }
     /*  RFC0821 4.2.1. REPLY CODES BY FUNCTION GROUPS   501 Syntax error in parameters or arguments
      *  RFC1893 2. Status Codes                         5.X.X   Permanent Failure
      *  RFC1893 3.5 Network and Routing Status          X.5.4   Invalid command arguments
      */
+    log0(ctx, TRACE, "checking BODY keyword");
     if (str_parse(req->msg, "m/^MAIL From:\\s*<(.+@.+)>"
                             "(?:\\s+BODY=(?:7BIT|8BITMIME)\\s*)?$/i", 
                             &ctx->msg->mail_from) <= 0) {
         res.statuscode = "501";
         res.dsncode    = "5.5.4";
         res.statusmsg  = "Unknown parameter for keyword BODY.";
-        lmtp_response(lmtp, &res);
-        msg_destroy(ctx->msg);
-        ctx->msg = NULL;
-        return LMTP_OK;
+        CU(LMTP_OK);
     }
     
     /*  RFC0821 4.2.1. REPLY CODES BY FUNCTION GROUPS   550 Requested action not taken: mailbox unavailable
      *  RFC1893 2. Status Codes                         5.X.X   Permanent Failure
      *  RFC1893 3.5 Network and Routing Status          X.7.1   Delivery not authorized, message refused
      */
+    log0(ctx, TRACE, "checking if sender is allowed");
     if ((ctx->option_mailfrom != NULL) &&
         (str_parse(ctx->msg->mail_from, ctx->option_mailfrom) <= 0)) {
         res.statuscode = "550";
         res.dsncode    = "5.7.1";
         res.statusmsg  = "Delivery not authorized, message refused.";
-        lmtp_response(lmtp, &res);
-        msg_destroy(ctx->msg);
-        ctx->msg = NULL;
-        return LMTP_OK;
+        CU(LMTP_OK);
     }
 
     /*  RFC0821 4.2.1. REPLY CODES BY FUNCTION GROUPS   250 Requested mail action okay, completed
@@ -1115,51 +1126,60 @@
     res.statusmsg  = "Sender ok.";
     lmtp_response(lmtp, &res);
     return LMTP_OK;
+
+    CUS:
+    lmtp_response(lmtp, &res);
+    if (ctx->msg != NULL) {
+        msg_destroy(ctx->msg);
+        ctx->msg = NULL;
+    }
+    return rc;
 }
 
 static lmtp_rc_t lmtp_cb_rcpt(lmtp_t *lmtp, lmtp_io_t *io, lmtp_req_t *req, void *_ctx)
 {
-    lmtp_res_t res;
+    lmtp_res_t   res;
+    lmtp_rc_t    rc;
     lmtp2nntp_t *ctx = (lmtp2nntp_t *)_ctx;
-    char *cp;
-    char *group;
+    char        *cp;
+    char        *group;
 
-    log0(ctx, INFO, "lmtp_cb_rcpt");
+    log1(ctx, INFO, "lmtp_cb_rcpt < %s", req->msg);
 
     /*  RFC0821 4.2.1. REPLY CODES BY FUNCTION GROUPS   503 Bad sequence of commands
      *  RFC1893 2. Status Codes                         5.X.X   Permanent Failure
      *  RFC1893 3.5 Network and Routing Status          X.5.0   Other or undefined protocol status
      */
+    log0(ctx, TRACE, "checking for previous MAIL");
     if ((ctx->msg == NULL) || (ctx->msg->mail_from == NULL)) {
         res.statuscode = "503";
         res.dsncode    = "5.5.0";
         res.statusmsg  = "specify sender with MAIL first.";
-        lmtp_response(lmtp, &res);
-        return LMTP_OK;
+        CU(LMTP_OK);
     }
 
     /*  RFC0821 4.2.1. REPLY CODES BY FUNCTION GROUPS   501 Syntax error in parameters or arguments
      *  RFC1893 2. Status Codes                         5.X.X   Permanent Failure
      *  RFC1893 3.5 Network and Routing Status          X.5.2   Syntax error
      */
+    log0(ctx, TRACE, "checking parameter syntax");
     if (str_parse(req->msg, "m/^RCPT To:\\s*(.+)$/i", &cp) <= 0) {
         res.statuscode = "501";
         res.dsncode    = "5.5.2";
         res.statusmsg  = "Syntax error in parameters.";
-        lmtp_response(lmtp, &res);
-        return LMTP_OK;
+        CU(LMTP_OK);
     }
     
     /*  RFC0821 4.2.1. REPLY CODES BY FUNCTION GROUPS   550 Requested action not taken: mailbox unavailable
      *  RFC1893 2. Status Codes                         5.X.X   Permanent Failure
      *  RFC1893 3.5 Network and Routing Status          X.1.1   Bad destination mailbox address
      */
+    log0(ctx, TRACE, "checking for empty parameter");
     if ((cp == NULL) || (strlen(cp) == 0)) {
         res.statuscode = "550";
         res.dsncode    = "5.1.1";
-        res.statusmsg  = "nul Recipient/ Group.";
-        lmtp_response(lmtp, &res);
-        return LMTP_OK;
+        res.statusmsg  = "empty Recipient/ Group.";
+        CU(LMTP_OK);
     }
 
     /* in GROUPMODE = ARG|HEADER recipient must be acknowledged and stored to
@@ -1172,23 +1192,26 @@
      *  RFC1893 3.5 Network and Routing Status          X.1.1   Bad destination mailbox address
      *                                                  X.7.2   Mailing list expansion prohibited
      */
+    log1(ctx, DEBUG, "ctx->option_groupmode=%d", ctx->option_groupmode);
     if (ctx->option_groupmode == GROUPMODE_ENVELOPE) {
+        log0(ctx, TRACE, "groupmode=envelope; transform recipient into group");
         if (str_parse(cp, "m/^<(.+)?@[^@]+>$/i", &group) <= 0) {
             res.statuscode = "550";
             res.dsncode    = "5.1.1";
             res.statusmsg  = "Recipient did not transform into group.";
-            lmtp_response(lmtp, &res);
-            return LMTP_OK;
+            CU(LMTP_OK);
         }
+        log1(ctx, TRACE, "groupmode=envelope; match group %s", group);
         if (!groupmatch(ctx->azGroupargs, ctx->asGroupargs, group)) {
             res.statuscode = "550";
             res.dsncode    = "5.7.2";
             res.statusmsg  = "unmatched Group.";
-            lmtp_response(lmtp, &res);
-            return LMTP_OK;
+            CU(LMTP_OK);
         }
+        log1(ctx, TRACE, "memorize group %s", group);
         argz_add(&ctx->msg->azEnvgroups, &ctx->msg->asEnvgroups, group);
     }
+    log1(ctx, TRACE, "memorize recipient %s", cp);
     argz_add(&ctx->msg->azRcpt, &ctx->msg->asRcpt, cp);
 
     /*  RFC0821 4.2.1. REPLY CODES BY FUNCTION GROUPS   250 Requested mail action okay, completed
@@ -1198,8 +1221,11 @@
     res.statuscode = "250";
     res.dsncode    = "2.1.5";
     res.statusmsg  = ctx->option_groupmode == GROUPMODE_ENVELOPE ? "Group accepted." : "Recipient accepted.";
+    CU(LMTP_OK);
+
+    CUS:
     lmtp_response(lmtp, &res);
-    return LMTP_OK;
+    return rc;
 }
 
 int groupmatch(char *azPattern, size_t asPattern, char *cpGroup)
@@ -1218,23 +1244,24 @@
 
 static lmtp_rc_t lmtp_cb_data(lmtp_t *lmtp, lmtp_io_t *io, lmtp_req_t *req, void *_ctx)
 {
-    lmtp_res_t res;
-    lmtp_rc_t rc = LMTP_OK;
     lmtp2nntp_t *ctx = (lmtp2nntp_t *)_ctx;
-    char   *azErr;
-    size_t  asErr;
-    char errorstring[STDSTRLEN];
-    char *rcpt;
-    int i;
-    int bSuccess;
-    char *cp;
+    lmtp_rc_t    rc = LMTP_OK;
+    lmtp_res_t   res;
+    char        *azErr;
+    size_t       asErr;
+    char         errorstring[STDSTRLEN];
+    char        *rcpt;
+    int          i;
+    int          bSuccess;
+    char        *cp;
 
-    log0(ctx, INFO, "lmtp_cb_data");
+    log1(ctx, INFO, "lmtp_cb_data < %s", req->msg);
 
     /*  RFC0821 4.2.1. REPLY CODES BY FUNCTION GROUPS   503 Bad sequence of commands
      *  RFC1893 2. Status Codes                         5.X.X   Permanent Failure
      *  RFC1893 3.5 Network and Routing Status          X.5.0   Other or undefined protocol status
      */
+    log0(ctx, TRACE, "checking for previous RCPT");
     if ((ctx->msg == NULL) || (argz_count(ctx->msg->azRcpt, ctx->msg->asRcpt) == 0)) {
         res.statuscode = "503";
         res.dsncode    = "5.5.0";
@@ -1245,18 +1272,20 @@
 
     /*  RFC0821 4.2.1. REPLY CODES BY FUNCTION GROUPS   354 Start mail input; end with <CRLF>.<CRLF>
      */
+    log0(ctx, TRACE, "tell remote to send message now");
     res.statuscode = "354";
     res.dsncode    = NULL; /* DSN not used for data */
     res.statusmsg  = "Enter mail, end with \".\" on a line by itself";
     lmtp_response(lmtp, &res);
 
+    log1(ctx, TRACE, "lmtp_readmsg, maximum size to accept = %d", ctx->option_maxmessagesize);
     rc = lmtp_readmsg(lmtp, &ctx->msg->cpMsg, ctx->option_maxmessagesize);
 
     /*  RFC0821 4.2.1. REPLY CODES BY FUNCTION GROUPS   552 Requested mail action aborted: exceeded storage allocation
      *  RFC1893 2. Status Codes                         5.X.X   Permanent Failure
      *  RFC1893 3.5 Network and Routing Status          X.2.3   Message length exceeds administrative limit.
-
      */
+    log0(ctx, TRACE, "checking for excessive message size");
     if (rc == LMTP_ERR_OVERFLOW) {
         str_format(errorstring, sizeof(errorstring), "Message length exceeds administrative limit. %s", lmtp_error(rc));
         res.statuscode = "552";
@@ -1273,6 +1302,7 @@
      *  RFC1893 2. Status Codes                         4.X.X   Persistent Transient Failure
      *  RFC1893 3.5 Network and Routing Status          X.3.2   System not accepting network messages
      */
+    log0(ctx, TRACE, "checking for system error");
     if (rc == LMTP_ERR_SYSTEM) {
         str_format(errorstring, sizeof(errorstring), "System error reading message: %s", strerror(errno));
         res.statuscode = "451";
@@ -1289,6 +1319,7 @@
      *  RFC1893 2. Status Codes                         4.X.X   Persistent Transient Failure
      *  RFC1893 3.5 Network and Routing Status          X.3.2   System not accepting network messages
      */
+    log0(ctx, TRACE, "checking for other error");
     if(rc != LMTP_OK) {
         str_format(errorstring, sizeof(errorstring), "Unknown error reading message: %s", lmtp_error(rc));
         res.statuscode = "451";
@@ -1305,6 +1336,7 @@
      *  RFC1893 2. Status Codes                         5.X.X   Permanent Failure
      *  RFC1893 3.5 Network and Routing Status          X.6.5   Conversion Failed
      */
+    log0(ctx, TRACE, "split message");
     if ((rc = msg_split(ctx->msg)) != MSG_OK) {
         str_format(errorstring, sizeof(errorstring), "Error splitting message: %s", msg_error(rc));
         res.statuscode = "554";
@@ -1385,6 +1417,7 @@
      *  RFC1893 2. Status Codes                         5.X.X   Permanent Failure
      *  RFC1893 3.5 Network and Routing Status          X.6.5   Conversion Failed
      */
+    log0(ctx, TRACE, "join message");
     if ((rc = msg_join(ctx->msg)) != MSG_OK) {
         str_format(errorstring, sizeof(errorstring), "Error joining message: %s", msg_error(rc));
         res.statuscode = "554";
@@ -1397,6 +1430,7 @@
         return LMTP_OK;
     }
 
+    log0(ctx, TRACE, "deliver message");
     bSuccess = NNTP_EOF; /* assume a hard error for the worst case */
     for (i = 0; i < ctx->nsc; i++) {
         switch (ctx->option_deliverymode) {
@@ -1494,7 +1528,7 @@
     lmtp_res_t res;
     lmtp_rc_t rc = LMTP_OK;
 
-    log0(ctx, INFO, "lmtp_cb_noop");
+    log1(ctx, INFO, "lmtp_cb_noop < %s", req->msg);
 
     /*  RFC0821 4.2.1. REPLY CODES BY FUNCTION GROUPS   250 Requested mail action okay, completed
      *  RFC1893 2. Status Codes                         2.X.X   Success
@@ -1513,7 +1547,7 @@
     lmtp_res_t res;
     lmtp_rc_t rc = LMTP_OK;
 
-    log0(ctx, INFO, "lmtp_cb_rset");
+    log1(ctx, INFO, "lmtp_cb_rset < %s", req->msg);
 
     lmtp_gfs_rset(ctx);
 
@@ -1530,7 +1564,8 @@
 
 static void lmtp_gfs_rset(lmtp2nntp_t *ctx)
 {
-    /* graceful shutdown */
+    log0(ctx, INFO, "lmtp_gfs_rset - graceful shutdown");
+
     if (ctx->msg != NULL) {
         msg_destroy(ctx->msg);
         ctx->msg = NULL;
@@ -1543,7 +1578,7 @@
     lmtp_res_t res;
     lmtp_rc_t rc = LMTP_EOF;
 
-    log0(ctx, INFO, "lmtp_cb_quit");
+    log1(ctx, INFO, "lmtp_cb_quit < %s", req->msg);
 
     lmtp_gfs_quit(ctx);
 
@@ -1560,7 +1595,8 @@
 
 static void lmtp_gfs_quit(lmtp2nntp_t *ctx)
 {
-    /* graceful shutdown */
+    log0(ctx, INFO, "lmtp_gfs_quit - graceful shutdown");
+
     lmtp_gfs_rset(ctx);
     resetsession(&ctx->session);
 }

CVSTrac 2.0.1