SMTP-Client: first add backups, then Relays, since we want Relays to be attempted...
[citadel.git] / citadel / modules / smtp / serv_smtpqueue.c
index 4704d31ce75ef7267d833e97b2e5561c3c7712f9..0fa65bea2000901c0098d814f5fcabbc9f0cb481 100644 (file)
@@ -86,6 +86,7 @@
 #include "ctdl_module.h"
 
 #include "smtpqueue.h"
+#include "smtp_clienthandlers.h"
 #include "event_client.h"
 
 
@@ -93,6 +94,7 @@ struct CitContext smtp_queue_CC;
 pthread_mutex_t ActiveQItemsLock;
 HashList *ActiveQItems  = NULL;
 HashList *QItemHandlers = NULL;
+const unsigned short DefaultMXPort = 25;
 int max_sessions_for_outbound_smtp = 500; /* how many sessions might be active till we stop adding more smtp jobs */
 int ndelay_count = 50; /* every n queued messages we will sleep... */
 int delay_msec = 5000; /* this many seconds. */
@@ -141,6 +143,22 @@ int DecreaseQReference(OneQueItem *MyQItem)
        return IDestructQueItem;
 }
 
+void DecreaseShutdownDeliveries(OneQueItem *MyQItem)
+{
+       pthread_mutex_lock(&ActiveQItemsLock);
+       MyQItem->NotYetShutdownDeliveries--;
+       pthread_mutex_unlock(&ActiveQItemsLock);
+}
+
+int GetShutdownDeliveries(OneQueItem *MyQItem)
+{
+       int DestructNow;
+
+       pthread_mutex_lock(&ActiveQItemsLock);
+       DestructNow = MyQItem->ActiveDeliveries == 0;
+       pthread_mutex_unlock(&ActiveQItemsLock);
+       return DestructNow;
+}
 void RemoveQItem(OneQueItem *MyQItem)
 {
        long len;
@@ -154,13 +172,13 @@ void RemoveQItem(OneQueItem *MyQItem)
                DeleteEntryFromHash(ActiveQItems, It);
        else
        {
-               syslog(LOG_WARNING,
-                      "SMTP cleanup: unable to find QItem with ID[%ld]",
-                      MyQItem->MessageID);
+               SMTPC_syslog(LOG_WARNING,
+                            "unable to find QItem with ID[%ld]",
+                            MyQItem->MessageID);
                while (GetNextHashPos(ActiveQItems, It, &len, &Key, &VData))
-                       syslog(LOG_WARNING,
-                              "SMTP cleanup: have_: ID[%ld]",
-                              ((OneQueItem *)VData)->MessageID);
+                       SMTPC_syslog(LOG_WARNING,
+                                    "have_: ID[%ld]",
+                                    ((OneQueItem *)VData)->MessageID);
        }
        pthread_mutex_unlock(&ActiveQItemsLock);
        DeleteHashPos(&It);
@@ -171,7 +189,7 @@ void FreeMailQEntry(void *qv)
 {
        MailQEntry *Q = qv;
 /*
-       syslog(LOG_DEBUG, "---------------%s--------------", __FUNCTION__);
+       SMTPC_syslog(LOG_DEBUG, "---------------%s--------------", __FUNCTION__);
        cit_backtrace();
 */
        FreeStrBuf(&Q->Recipient);
@@ -183,7 +201,7 @@ void FreeMailQEntry(void *qv)
 void FreeQueItem(OneQueItem **Item)
 {
 /*
-       syslog(LOG_DEBUG, "---------------%s--------------", __FUNCTION__);
+       SMTPC_syslog(LOG_DEBUG, "---------------%s--------------", __FUNCTION__);
        cit_backtrace();
 */
        DeleteHash(&(*Item)->MailQEntries);
@@ -350,7 +368,7 @@ StrBuf *SerializeQueueItem(OneQueItem *MyQItem)
 
        StrBufAppendBufPlain(QMessage, HKEY("\nattempted|"), 0);
        StrBufAppendPrintf(QMessage, "%ld",
-                          ctdl_ev_now() + MyQItem->Retry);
+                          time(NULL) /*ctdl_ev_now()*/ + MyQItem->Retry);
 
        It = GetNewHashPos(MyQItem->MailQEntries, 0);
        while (GetNextHashPos(MyQItem->MailQEntries, It, &len, &Key, &vQE))
@@ -380,7 +398,8 @@ void NewMailQEntry(OneQueItem *Item)
 
        if (Item->MailQEntries == NULL)
                Item->MailQEntries = NewHash(1, Flathash);
-       Item->Current->StatusMessage = NewStrBuf();
+       /* alocate big buffer so we won't get problems reallocating later. */
+       Item->Current->StatusMessage = NewStrBufPlain(NULL, SIZ);
        Item->Current->n = GetCount(Item->MailQEntries);
        Put(Item->MailQEntries,
            IKEY(Item->Current->n),
@@ -469,11 +488,11 @@ StrBuf *smtp_load_msg(OneQueItem *MyQItem, int n)
        CCC->redirect_buffer = NULL;
        if ((StrLength(SendMsg) > 0) &&
            ChrPtr(SendMsg)[StrLength(SendMsg) - 1] != '\n') {
-               syslog(LOG_WARNING,
-                      "SMTP client[%d]: Possible problem: message did not "
-                      "correctly terminate. (expecting 0x10, got 0x%02x)\n",
-                      MsgCount, //yes uncool, but best choice here...
-                      ChrPtr(SendMsg)[StrLength(SendMsg) - 1] );
+               SMTPC_syslog(LOG_WARNING,
+                            "[%d] Possible problem: message did not "
+                            "correctly terminate. (expecting 0x10, got 0x%02x)\n",
+                            MsgCount, //yes uncool, but best choice here...
+                            ChrPtr(SendMsg)[StrLength(SendMsg) - 1] );
                StrBufAppendBufPlain(SendMsg, HKEY("\r\n"), 0);
        }
        return SendMsg;
@@ -507,12 +526,12 @@ void smtpq_do_bounce(OneQueItem *MyQItem, StrBuf *OMsgTxt)
        int num_bounces = 0;
        int give_up = 0;
 
-       syslog(LOG_DEBUG, "smtp_do_bounce() called\n");
+       SMTPCM_syslog(LOG_DEBUG, "smtp_do_bounce() called\n");
 
        if (MyQItem->SendBounceMail == 0)
                return;
 
-       now = ev_time();
+       now = time (NULL); //ev_time();
 
        if ( (now - MyQItem->Submitted) > SMTP_GIVE_UP ) {
                give_up = 1;
@@ -546,7 +565,7 @@ void smtpq_do_bounce(OneQueItem *MyQItem, StrBuf *OMsgTxt)
        DeleteHashPos(&It);
 
        /* Deliver the bounce if there's anything worth mentioning */
-       syslog(LOG_DEBUG, "num_bounces = %d\n", num_bounces);
+       SMTPC_syslog(LOG_DEBUG, "num_bounces = %d\n", num_bounces);
 
        if (num_bounces == 0) {
                FreeStrBuf(&Msg);
@@ -568,7 +587,7 @@ void smtpq_do_bounce(OneQueItem *MyQItem, StrBuf *OMsgTxt)
                StrLength(OMsgTxt)); /* the original message */
        if (BounceMB == NULL) {
                FreeStrBuf(&boundary);
-               syslog(LOG_ERR, "Failed to alloc() bounce message.\n");
+               SMTPCM_syslog(LOG_ERR, "Failed to alloc() bounce message.\n");
 
                return;
        }
@@ -577,7 +596,7 @@ void smtpq_do_bounce(OneQueItem *MyQItem, StrBuf *OMsgTxt)
        if (bmsg == NULL) {
                FreeStrBuf(&boundary);
                FreeStrBuf(&BounceMB);
-               syslog(LOG_ERR, "Failed to alloc() bounce message.\n");
+               SMTPCM_syslog(LOG_ERR, "Failed to alloc() bounce message.\n");
 
                return;
        }
@@ -630,7 +649,7 @@ void smtpq_do_bounce(OneQueItem *MyQItem, StrBuf *OMsgTxt)
        }
 
        /* Attach the original message */
-       StrBufAppendBufPlain(BounceMB, HKEY("--"), 0);
+       StrBufAppendBufPlain(BounceMB, HKEY("\r\n--"), 0);
        StrBufAppendBuf(BounceMB, boundary, 0);
        StrBufAppendBufPlain(BounceMB, HKEY("\r\n"), 0);
        StrBufAppendBufPlain(BounceMB,
@@ -658,11 +677,13 @@ void smtpq_do_bounce(OneQueItem *MyQItem, StrBuf *OMsgTxt)
        bmsg->cm_fields['M'] = SmashStrBuf(&BounceMB);
 
        /* First try the user who sent the message */
-       if (StrLength(MyQItem->BounceTo) == 0)
-               syslog(LOG_ERR, "No bounce address specified\n");
-       else
-               syslog(LOG_DEBUG, "bounce to user? <%s>\n",
+       if (StrLength(MyQItem->BounceTo) == 0) {
+               SMTPCM_syslog(LOG_ERR, "No bounce address specified\n");
+       }
+       else {
+               SMTPC_syslog(LOG_DEBUG, "bounce to user? <%s>\n",
                       ChrPtr(MyQItem->BounceTo));
+       }
 
        /* Can we deliver the bounce to the original sender? */
        valid = validate_recipients(ChrPtr(MyQItem->BounceTo), NULL, 0);
@@ -680,7 +701,7 @@ void smtpq_do_bounce(OneQueItem *MyQItem, StrBuf *OMsgTxt)
        free_recipients(valid);
        FreeStrBuf(&boundary);
        CtdlFreeMessage(bmsg);
-       syslog(LOG_DEBUG, "Done processing bounces\n");
+       SMTPCM_syslog(LOG_DEBUG, "Done processing bounces\n");
 }
 
 /*
@@ -689,6 +710,7 @@ void smtpq_do_bounce(OneQueItem *MyQItem, StrBuf *OMsgTxt)
  * Called by smtp_do_queue() to handle an individual message.
  */
 void smtp_do_procmsg(long msgnum, void *userdata) {
+       time_t now;
        int mynumsessions = num_sessions;
        struct CtdlMessage *msg = NULL;
        char *instr = NULL;
@@ -705,18 +727,18 @@ void smtp_do_procmsg(long msgnum, void *userdata) {
        StrBuf *Msg =NULL;
 
        if (mynumsessions > max_sessions_for_outbound_smtp) {
-               syslog(LOG_DEBUG,
-                      "SMTP Queue: skipping because of num jobs %d > %d max_sessions_for_outbound_smtp",
-                      mynumsessions,
-                      max_sessions_for_outbound_smtp);
+               SMTPC_syslog(LOG_DEBUG,
+                            "skipping because of num jobs %d > %d max_sessions_for_outbound_smtp",
+                            mynumsessions,
+                            max_sessions_for_outbound_smtp);
        }
 
-       syslog(LOG_DEBUG, "SMTP Queue: smtp_do_procmsg(%ld)\n", msgnum);
+       SMTPC_syslog(LOG_DEBUG, "smtp_do_procmsg(%ld)\n", msgnum);
        ///strcpy(envelope_from, "");
 
        msg = CtdlFetchMessage(msgnum, 1);
        if (msg == NULL) {
-               syslog(LOG_ERR, "SMTP Queue: tried %ld but no such message!\n",
+               SMTPC_syslog(LOG_ERR, "tried %ld but no such message!\n",
                       msgnum);
                return;
        }
@@ -737,20 +759,23 @@ void smtp_do_procmsg(long msgnum, void *userdata) {
        FreeStrBuf(&PlainQItem);
 
        if (MyQItem == NULL) {
-               syslog(LOG_ERR,
-                      "SMTP Queue: Msg No %ld: already in progress!\n",
-                      msgnum);
+               SMTPC_syslog(LOG_ERR,
+                            "Msg No %ld: already in progress!\n",
+                            msgnum);
                return; /* s.b. else is already processing... */
        }
 
        /*
         * Postpone delivery if we've already tried recently.
         */
+       now = time(NULL);
        if ((MyQItem->ReattemptWhen != 0) && 
-           (time(NULL) < MyQItem->ReattemptWhen) &&
+           (now < MyQItem->ReattemptWhen) &&
            (run_queue_now == 0))
        {
-               syslog(LOG_DEBUG, "SMTP client: Retry time not yet reached.\n");
+               SMTPC_syslog(LOG_DEBUG, 
+                            "Retry time not yet reached. %ld seconds left.",
+                            MyQItem->ReattemptWhen - now);
 
                It = GetNewHashPos(MyQItem->MailQEntries, 0);
                pthread_mutex_lock(&ActiveQItemsLock);
@@ -772,7 +797,7 @@ void smtp_do_procmsg(long msgnum, void *userdata) {
         * Bail out if there's no actual message associated with this
         */
        if (MyQItem->MessageID < 0L) {
-               syslog(LOG_ERR, "SMTP Queue: no 'msgid' directive found!\n");
+               SMTPCM_syslog(LOG_ERR, "no 'msgid' directive found!\n");
                It = GetNewHashPos(MyQItem->MailQEntries, 0);
                pthread_mutex_lock(&ActiveQItemsLock);
                {
@@ -792,7 +817,7 @@ void smtp_do_procmsg(long msgnum, void *userdata) {
        {
                char mxbuf[SIZ];
                ParsedURL **Url = &MyQItem->URL;
-               nRelays = get_hosts(mxbuf, "smarthost");
+               nRelays = get_hosts(mxbuf, "fallbackhost");
                if (nRelays > 0) {
                        StrBuf *All;
                        StrBuf *One;
@@ -805,21 +830,20 @@ void smtp_do_procmsg(long msgnum, void *userdata) {
                                !IsEmptyStr(Pos)))
                        {
                                StrBufExtract_NextToken(One, All, &Pos, '|');
-                               if (!ParseURL(Url, One, 25))
-                                       syslog(LOG_DEBUG,
-                                              "Failed to parse: %s\n",
-                                              ChrPtr(One));
+                               if (!ParseURL(Url, One, DefaultMXPort)) {
+                                       SMTPC_syslog(LOG_DEBUG,
+                                                    "Failed to parse: %s\n",
+                                                    ChrPtr(One));
+                               }
                                else {
-                                       ///if (!Url->IsIP)) // todo dupe me fork ipv6
-                                       Url = &(*Url)->Next;
+                                       (*Url)->IsRelay = 1;
+                                       MyQItem->HaveRelay = 1;
                                }
                        }
                        FreeStrBuf(&All);
                        FreeStrBuf(&One);
                }
-
-               Url = &MyQItem->FallBackHost;
-               nRelays = get_hosts(mxbuf, "fallbackhost");
+               nRelays = get_hosts(mxbuf, "smarthost");
                if (nRelays > 0) {
                        StrBuf *All;
                        StrBuf *One;
@@ -832,28 +856,34 @@ void smtp_do_procmsg(long msgnum, void *userdata) {
                                !IsEmptyStr(Pos)))
                        {
                                StrBufExtract_NextToken(One, All, &Pos, '|');
-                               if (!ParseURL(Url, One, 25))
-                                       syslog(LOG_DEBUG,
-                                              "Failed to parse: %s\n",
-                                              ChrPtr(One));
-                               else
-                                       Url = &(*Url)->Next;
+                               if (!ParseURL(Url, One, DefaultMXPort)) {
+                                       SMTPC_syslog(LOG_DEBUG,
+                                                    "Failed to parse: %s\n",
+                                                    ChrPtr(One));
+                               }
+                               else {
+                                       ///if (!Url->IsIP)) // todo dupe me fork ipv6
+                                       (*Url)->IsRelay = 1;
+                                       MyQItem->HaveRelay = 1;
+                               }
                        }
                        FreeStrBuf(&All);
                        FreeStrBuf(&One);
                }
+
        }
 
        It = GetNewHashPos(MyQItem->MailQEntries, 0);
        while (GetNextHashPos(MyQItem->MailQEntries, It, &len, &Key, &vQE))
        {
                MailQEntry *ThisItem = vQE;
-               syslog(LOG_DEBUG, "SMTP Queue: Task: <%s> %d\n",
-                      ChrPtr(ThisItem->Recipient),
-                      ThisItem->Active);
+               SMTPC_syslog(LOG_DEBUG, "SMTP Queue: Task: <%s> %d\n",
+                            ChrPtr(ThisItem->Recipient),
+                            ThisItem->Active);
        }
        DeleteHashPos(&It);
 
+       MyQItem->NotYetShutdownDeliveries = 
        MyQItem->ActiveDeliveries = CountActiveQueueEntries(MyQItem);
 
        /* failsafe against overload: 
@@ -866,11 +896,11 @@ void smtp_do_procmsg(long msgnum, void *userdata) {
            (((MyQItem->ActiveDeliveries * 2)  < max_sessions_for_outbound_smtp)))
        {
                /* abort delivery for another time. */
-               syslog(LOG_DEBUG,
-                      "SMTP Queue: skipping because of num jobs %d + %ld > %d max_sessions_for_outbound_smtp",
-                      mynumsessions,
-                      MyQItem->ActiveDeliveries,
-                      max_sessions_for_outbound_smtp);
+               SMTPC_syslog(LOG_DEBUG,
+                            "SMTP Queue: skipping because of num jobs %d + %ld > %d max_sessions_for_outbound_smtp",
+                            mynumsessions,
+                            MyQItem->ActiveDeliveries,
+                            max_sessions_for_outbound_smtp);
 
                FreeQueItem(&MyQItem);
 
@@ -902,11 +932,12 @@ void smtp_do_procmsg(long msgnum, void *userdata) {
 
                                if (i > 1) n = MsgCount++;
                                syslog(LOG_DEBUG,
-                                      "SMTPQ: Trying <%ld> <%s> %d / %d \n",
+                                      "SMTPC: Trying <%ld> <%s> %d / %d \n",
                                       MyQItem->MessageID,
                                       ChrPtr(ThisItem->Recipient),
                                       i,
                                       m);
+                               (*((int*) userdata)) ++;
                                smtp_try_one_queue_entry(MyQItem,
                                                         ThisItem,
                                                         Msg,
@@ -938,19 +969,18 @@ void smtp_do_procmsg(long msgnum, void *userdata) {
                                const char* Key;
                                void *VData;
 
-                               syslog(LOG_WARNING,
-                                      "SMTP cleanup: unable to find "
-                                      "QItem with ID[%ld]",
-                                      MyQItem->MessageID);
+                               SMTPC_syslog(LOG_WARNING,
+                                            "unable to find QItem with ID[%ld]",
+                                            MyQItem->MessageID);
                                while (GetNextHashPos(ActiveQItems,
                                                      It,
                                                      &len,
                                                      &Key,
                                                      &VData))
                                {
-                                       syslog(LOG_WARNING,
-                                              "SMTP cleanup: have: ID[%ld]",
-                                             ((OneQueItem *)VData)->MessageID);
+                                       SMTPC_syslog(LOG_WARNING,
+                                                    "have: ID[%ld]",
+                                                    ((OneQueItem *)VData)->MessageID);
                                }
                        }
 
@@ -976,18 +1006,14 @@ void smtp_do_procmsg(long msgnum, void *userdata) {
  * Run through the queue sending out messages.
  */
 void smtp_do_queue(void) {
-       static int is_running = 0;
        int num_processed = 0;
-
-       if (is_running)
-               return; /* Concurrency check - only one can run */
-       is_running = 1;
+       int num_activated = 0;
 
        pthread_setspecific(MyConKey, (void *)&smtp_queue_CC);
-       syslog(LOG_INFO, "SMTP client: processing outbound queue");
+       SMTPCM_syslog(LOG_INFO, "processing outbound queue");
 
        if (CtdlGetRoom(&CC->room, SMTP_SPOOLOUT_ROOM) != 0) {
-               syslog(LOG_ERR, "Cannot find room <%s>", SMTP_SPOOLOUT_ROOM);
+               SMTPC_syslog(LOG_ERR, "Cannot find room <%s>", SMTP_SPOOLOUT_ROOM);
        }
        else {
                num_processed = CtdlForEachMessage(MSGS_ALL,
@@ -996,14 +1022,12 @@ void smtp_do_queue(void) {
                                                   SPOOLMIME,
                                                   NULL,
                                                   smtp_do_procmsg,
-                                                  NULL);
+                                                  &num_activated);
        }
-       syslog(LOG_INFO,
-              "SMTP client: queue run completed; %d messages processed",
-              num_processed);
+       SMTPC_syslog(LOG_INFO,
+                    "queue run completed; %d messages processed %d activated",
+                    num_processed, num_activated);
 
-       run_queue_now = 0;
-       is_running = 0;
 }
 
 
@@ -1115,7 +1139,7 @@ CTDL_MODULE_INIT(smtp_queu)
                CtdlRegisterEVCleanupHook(smtp_evq_cleanup);
 
                CtdlRegisterProtoHook(cmd_smtp, "SMTP", "SMTP utility commands");
-               CtdlRegisterSessionHook(smtp_do_queue, EVT_TIMER);
+               CtdlRegisterSessionHook(smtp_do_queue, EVT_TIMER, PRIO_SEND + 10);
        }
 
        /* return our Subversion id for the Log */