Capture the actual SMTP response from the server, ugly hack using libcurl debug
[citadel.git] / citadel / modules / smtp / serv_smtpclient.c
index bfe665984698ee69922f2843b03779ad30924c28..6354461d3972b287889aa838f83d3dd79f498752 100644 (file)
@@ -112,7 +112,8 @@ int smtp_aftersave(struct CtdlMessage *msg, recptypes *recps)
                             "bounceto|%s\n",
                             msg->cm_fields[eVltMsgNum],
                             (long)time(NULL),
-                            recps->bounce_to);
+                            recps->bounce_to
+               );
 
                if (recps->envelope_from != NULL) {
                        StrBufAppendBufPlain(SpoolMsg, HKEY("envelope_from|"), 0);
@@ -164,7 +165,7 @@ static size_t upload_source(void *ptr, size_t size, size_t nmemb, void *userp)
        sendbytes = (size * nmemb);
 
        if (s->bytes_sent >= s->bytes_total) {
-               return(0);                                      // we are donez0r
+               return(0);                                      // no data remaining; we are done
        }
 
        if (sendbytes > (s->bytes_total - s->bytes_sent)) {
@@ -180,11 +181,31 @@ static size_t upload_source(void *ptr, size_t size, size_t nmemb, void *userp)
 }
 
 
+/*
+ * The libcurl API doesn't provide a way to capture the actual SMTP result message returned
+ * by the remote server.  This is an ugly way to extract it, by capturing debug data from
+ * the library and filtering on the lines we want.
+ */
+int ctdl_libcurl_smtp_debug_callback(CURL *handle, curl_infotype type, char *data, size_t size, void *userptr)
+{
+       if (type != CURLINFO_HEADER_IN) return 0;
+       if (!userptr) return 0;
+       char *debugbuf = (char *)userptr;
+
+       int len = strlen(debugbuf);
+       if (len + size > SIZ) return 0;
+
+       memcpy(&debugbuf[len], data, size);
+       debugbuf[len+size] = 0;
+       return 0;
+}
+
+
 /*
  * Attempt a delivery to one recipient.
  * Returns a three-digit SMTP status code.
  */
-int smtp_attempt_delivery(long msgid, char *recp, char *envelope_from)
+int smtp_attempt_delivery(long msgid, char *recp, char *envelope_from, char *response)
 {
        struct smtpmsgsrc s;
        char *fromaddr = NULL;
@@ -198,6 +219,7 @@ int smtp_attempt_delivery(long msgid, char *recp, char *envelope_from)
        char node[1024];
        char name[1024];
        char try_this_mx[256];
+       char smtp_url[512];
        int i;
 
        syslog(LOG_DEBUG, "smtpclient: smtp_attempt_delivery(%ld, %s)", msgid, recp);
@@ -222,6 +244,7 @@ int smtp_attempt_delivery(long msgid, char *recp, char *envelope_from)
 
                curl = curl_easy_init();
                if (curl) {
+                       response[0] = 0;
 
                        if (!IsEmptyStr(envelope_from)) {
                                curl_easy_setopt(curl, CURLOPT_MAIL_FROM, envelope_from);
@@ -236,21 +259,30 @@ int smtp_attempt_delivery(long msgid, char *recp, char *envelope_from)
                        curl_easy_setopt(curl, CURLOPT_READDATA, &s);
                        curl_easy_setopt(curl, CURLOPT_UPLOAD, 1);                                              // tell libcurl we are uploading
                        curl_easy_setopt(curl, CURLOPT_TIMEOUT, 20L);                                           // Time out after 20 seconds
+                       if (CtdlGetConfigInt("c_smtpclient_try_starttls") != 0) {
+                               curl_easy_setopt(curl, CURLOPT_USE_SSL, CURLUSESSL_TRY);                        // Attempt STARTTLS if offered
+                       }
                        curl_easy_setopt(curl, CURLOPT_SSL_VERIFYPEER, 0L);
                        curl_easy_setopt(curl, CURLOPT_SSL_VERIFYHOST, 0L);
-
-                       strcpy(try_this_mx, "smtp://");
-                       extract_token(&try_this_mx[7], mxes, i, '|', (sizeof try_this_mx - 7));
-                       if (
-                               (!strncasecmp(try_this_mx, HKEY("smtp://smtp://")))                             // This can happen if the administrator
-                               || (!strncasecmp(try_this_mx, HKEY("smtp://smtps://")))                         // puts a full smtp[s] URI as the smart-host
-                       ) {
-                               strcpy(try_this_mx, &try_this_mx[7]);
-                       }
-
-                       curl_easy_setopt(curl, CURLOPT_URL, try_this_mx);
-
-                       syslog(LOG_DEBUG, "smtpclient: trying %s", try_this_mx);                        // send the message
+                       // curl_easy_setopt(curl, CURLOPT_ERRORBUFFER, curl_error_buffer);
+                       curl_easy_setopt(curl, CURLOPT_DEBUGFUNCTION, ctdl_libcurl_smtp_debug_callback);
+                       curl_easy_setopt(curl, CURLOPT_DEBUGDATA, (void *)response);
+                       curl_easy_setopt(curl, CURLOPT_VERBOSE, 1L);
+
+                       // Construct an SMTP URL in the form of:
+                       //      smtp[s]://target_host/source_host
+                       // This looks weird but libcurl uses that last part to set our name for EHLO or HELO.
+                       // We check for "smtp://" and "smtps://" because the admin may have put those prefixes in a smart-host entry.
+                       // If there is no prefix we add "smtp://"
+                       extract_token(try_this_mx, mxes, i, '|', (sizeof try_this_mx - 7));
+                       snprintf(smtp_url, sizeof smtp_url,
+                               "%s%s/%s",
+                               (((!strncasecmp(try_this_mx, HKEY("smtp://"))) || (!strncasecmp(try_this_mx, HKEY("smtps://")))) ? "" : "smtp://"),
+                               try_this_mx,
+                               CtdlGetConfigStr("c_fqdn")
+                       );
+                       curl_easy_setopt(curl, CURLOPT_URL, smtp_url);
+                       syslog(LOG_DEBUG, "smtpclient: trying %s", smtp_url);                           // send the message
                        res = curl_easy_perform(curl);
                        curl_easy_getinfo(curl, CURLINFO_RESPONSE_CODE, &response_code);
                        syslog(LOG_DEBUG, "smtpclient: libcurl returned %d (%s) , SMTP response %ld",
@@ -265,6 +297,25 @@ int smtp_attempt_delivery(long msgid, char *recp, char *envelope_from)
                        recipients = NULL;                                                              // this gets reused; avoid double-free
                        curl_easy_cleanup(curl);
                        curl = NULL;                                                                    // this gets reused; avoid double-free
+
+                       /* Trim the error message buffer down to just the actual message */
+                       char response_code_str[4];
+                       snprintf(response_code_str, sizeof response_code_str, "%ld", response_code);
+                       char *respstart = strstr(response, response_code_str);
+                       if (respstart == NULL)
+                       {
+                               strcpy(response, smtpstatus(response_code));
+                       }
+                       else {
+                               strcpy(response, respstart);
+                               char *p;
+                               for (p=response; *p!=0; ++p)
+                               {
+                                       if (*p == '\n') *p = ' ';
+                                       if (*p == '\r') *p = ' ';
+                                       if (!isprint(*p)) *p = ' ';
+                               }
+                       }
                }
        }
 
@@ -287,12 +338,11 @@ void smtp_process_one_msg(long qmsgnum)
        int num_delayed = 0;
        long deletes[2];
        int delete_this_queue = 0;
-
-       syslog(LOG_DEBUG, "smtpclient: processing queue entry %ld", qmsgnum);
+       char server_response[SIZ];
 
        msg = CtdlFetchMessage(qmsgnum, 1, 1);
        if (msg == NULL) {
-               syslog(LOG_WARNING, "smtpclient: queue message %ld does not exist", qmsgnum);
+               syslog(LOG_WARNING, "smtpclient: %ld does not exist", qmsgnum);
                return;
        }
 
@@ -328,7 +378,7 @@ void smtp_process_one_msg(long qmsgnum)
                if (!strncasecmp(cfgline, HKEY("envelope_from|")))      envelope_from = strdup(&cfgline[14]);
        }
 
-       int should_try_now = 1;
+       int should_try_now = 0;
        if (attempted < submitted) {                            // If no attempts have been made yet, try now
                should_try_now = 1;
        }
@@ -344,7 +394,7 @@ void smtp_process_one_msg(long qmsgnum)
        }
 
        if (should_try_now) {
-               syslog(LOG_DEBUG, "smtpclient: attempting delivery now");
+               syslog(LOG_DEBUG, "smtpclient: %ld attempting delivery now", qmsgnum);
                StrBuf *NewInstr = NewStrBuf();
                StrBufAppendPrintf(NewInstr, "Content-type: "SPOOLMIME"\n\n");
                StrBufAppendPrintf(NewInstr, "msgid|%ld\n", msgid);
@@ -360,8 +410,8 @@ void smtp_process_one_msg(long qmsgnum)
                                if ((previous_result == 0) || (previous_result == 4)) {
                                        int new_result = 421;
                                        extract_token(recp, cfgline, 1, '|', sizeof recp);
-                                       new_result = smtp_attempt_delivery(msgid, recp, envelope_from);
-                                       syslog(LOG_DEBUG, "smtpclient: recp: <%s> , result: %d (%s)", recp, new_result, smtpstatus(new_result));
+                                       new_result = smtp_attempt_delivery(msgid, recp, envelope_from, server_response);
+                                       syslog(LOG_DEBUG, "smtpclient: recp: <%s> , result: %d (%s)", recp, new_result, server_response);
                                        if ((new_result / 100) == 2) {
                                                ++num_success;
                                        }
@@ -373,7 +423,7 @@ void smtp_process_one_msg(long qmsgnum)
                                                        ++num_delayed;
                                                }
                                                StrBufAppendPrintf(NewInstr, "remote|%s|%ld|%ld (%s)\n",
-                                                       recp, (new_result / 100) , new_result, smtpstatus(new_result)
+                                                       recp, (new_result / 100) , new_result, server_response
                                                );
                                        }
                                }
@@ -400,21 +450,21 @@ void smtp_process_one_msg(long qmsgnum)
                        delete_this_queue = 1;
                }
 
-               // If it's been more than five days, give up and tell the sender we #failed
+               // If it's been more than five days, give up and tell the sender that delivery failed
                //
                else if ((time(NULL) - submitted) > SMTP_DELIVER_FAIL) {
                        smtp_do_bounce(ChrPtr(NewInstr), SDB_BOUNCE_ALL);
                        delete_this_queue = 1;
                }
 
-               // If it's been more than four hours but less than five days, warn the sender that I've Been Delayed
+               // If it's been more than four hours but less than five days, warn the sender that delivery is delayed
                //
                else if ( ((attempted - submitted) < SMTP_DELIVER_WARN) && ((time(NULL) - submitted) >= SMTP_DELIVER_WARN) ) {
                        smtp_do_bounce(ChrPtr(NewInstr), SDB_WARN);
                }
-       
+
                if (delete_this_queue) {
-                       syslog(LOG_DEBUG, "smtpclient: deleting this queue entry");
+                       syslog(LOG_DEBUG, "smtpclient: %ld deleting", qmsgnum);
                        deletes[0] = qmsgnum;
                        deletes[1] = msgid;
                        CtdlDeleteMessages(SMTP_SPOOLOUT_ROOM, deletes, 2, "");
@@ -422,7 +472,7 @@ void smtp_process_one_msg(long qmsgnum)
                }
                else {
                        // replace the old queue entry with the new one
-                       syslog(LOG_DEBUG, "smtpclient: rewriting this queue entry");
+                       syslog(LOG_DEBUG, "smtpclient: %ld rewriting", qmsgnum);
                        msg = convert_internet_message_buf(&NewInstr);                  // This function will free NewInstr for us
                        CtdlSubmitMsg(msg, NULL, SMTP_SPOOLOUT_ROOM, 0);
                        CM_Free(msg);
@@ -430,7 +480,7 @@ void smtp_process_one_msg(long qmsgnum)
                }
        }
        else {
-               syslog(LOG_DEBUG, "smtpclient: retry time not reached");
+               syslog(LOG_DEBUG, "smtpclient: %ld retry time not reached", qmsgnum);
        }
 
        if (bounceto != NULL)           free(bounceto);