SMTP-Client: shut down in one chunk
[citadel.git] / citadel / modules / smtp / serv_smtpeventclient.c
index c8da5590e63b62841f30a3cfccf81331957679bc..0d3428fea894f5ed529b75e2b50254875ad2064d 100644 (file)
 #include "smtpqueue.h"
 #include "smtp_clienthandlers.h"
 
+int SMTPClientDebugEnabled = 0;
 const unsigned short DefaultMXPort = 25;
 void DeleteSmtpOutMsg(void *v)
 {
        SmtpOutMsg *Msg = v;
        AsyncIO *IO = &Msg->IO;
-       EV_syslog(LOG_DEBUG, "SMTP: %s Aborting\n", __FUNCTION__);
+       EVS_syslog(LOG_DEBUG, "%s Exit\n", __FUNCTION__);
 
        /* these are kept in our own space and free'd below */
        Msg->IO.ConnectMe = NULL;
@@ -122,11 +123,6 @@ eReadState SMTP_C_ReadServerStatus(AsyncIO *IO);
 
 eNextState mx_connect_ip(AsyncIO *IO);
 eNextState get_one_mx_host_ip(AsyncIO *IO);
-eNextState FinalizeMessageSendDB(AsyncIO *IO);
-eNextState FinalizeMessageSend_DB1(AsyncIO *IO);
-eNextState FinalizeMessageSend_DB2(AsyncIO *IO);
-eNextState FinalizeMessageSend_DB3(AsyncIO *IO);
-eNextState FinalizeMessageSend_DB4(AsyncIO *IO);
 
 /******************************************************************************
  * So, we're finished with sending (regardless of success or failure)         *
@@ -134,9 +130,28 @@ eNextState FinalizeMessageSend_DB4(AsyncIO *IO);
  * we need to free the memory and send bounce messages (on terminal failure)  *
  * else we just free our SMTP-Message struct.                                 *
  ******************************************************************************/
-inline void FinalizeMessageSend_1(AsyncIO *IO)
+eNextState FinalizeMessageSend_DB(AsyncIO *IO)
 {
+       const char *Status;
        SmtpOutMsg *Msg = IO->Data;
+       
+       if (Msg->MyQEntry->Status == 2) 
+               Status = "Delivery successful.";
+       else if (Msg->MyQEntry->Status == 5) 
+               Status = "Delivery failed permanently; giving up.";
+       else
+               Status = "Delivery failed temporarily; will retry later.";
+                       
+       EVS_syslog(LOG_INFO,
+                  "%s Time[%fs] Recipient <%s> @ <%s> (%s) Status message: %s\n",
+                  Status,
+                  Msg->IO.Now - Msg->IO.StartIO,
+                  Msg->user,
+                  Msg->node,
+                  Msg->name,
+                  ChrPtr(Msg->MyQEntry->StatusMessage));
+
+
        Msg->IDestructQueItem = DecreaseQReference(Msg->MyQItem);
 
        Msg->nRemain = CountActiveQueueEntries(Msg->MyQItem);
@@ -152,49 +167,17 @@ inline void FinalizeMessageSend_1(AsyncIO *IO)
                Msg->QMsgData = SerializeQueueItem(Msg->MyQItem);
        else
                Msg->QMsgData = NULL;
-}
-eNextState FinalizeMessageSend(SmtpOutMsg *Msg)
-{
-       return QueueDBOperation(&Msg->IO, FinalizeMessageSend_DB1);
-}
-
-inline void FinalizeMessageSend_DB_1(AsyncIO *IO)
-{
-       SmtpOutMsg *Msg = IO->Data;
 
        /*
         * Uncompleted delivery instructions remain, so delete the old
         * instructions and replace with the updated ones.
         */
-       EVS_syslog(LOG_DEBUG, "SMTPQD: %ld", Msg->MyQItem->QueMsgID);
+       EVS_syslog(LOG_DEBUG, "%ld", Msg->MyQItem->QueMsgID);
        CtdlDeleteMessages(SMTP_SPOOLOUT_ROOM, &Msg->MyQItem->QueMsgID, 1, "");
-}
-eNextState FinalizeMessageSend_DB1(AsyncIO *IO)
-{
-       FinalizeMessageSend_1(IO);
-       FinalizeMessageSend_DB_1(IO);
-       return NextDBOperation(IO, FinalizeMessageSend_DB2);
-}
-
-
-inline void FinalizeMessageSend_DB_2(AsyncIO *IO)
-{
-       SmtpOutMsg *Msg = IO->Data;
+       Msg->MyQItem->QueMsgID = -1;
 
        if (Msg->IDestructQueItem)
                smtpq_do_bounce(Msg->MyQItem, Msg->msgtext);
-}
-eNextState FinalizeMessageSend_DB2(AsyncIO *IO)
-{
-       FinalizeMessageSend_DB_2(IO);
-
-       return NextDBOperation(IO, FinalizeMessageSend_DB3);
-}
-
-
-inline void FinalizeMessageSend_DB_3(AsyncIO *IO)
-{
-       SmtpOutMsg *Msg = IO->Data;
 
        if (Msg->nRemain > 0)
        {
@@ -208,7 +191,7 @@ inline void FinalizeMessageSend_DB_3(AsyncIO *IO)
                msg->cm_fields['U'] = strdup("QMSG");
                Msg->MyQItem->QueMsgID =
                        CtdlSubmitMsg(msg, NULL, SMTP_SPOOLOUT_ROOM, QP_EADDR);
-               EVS_syslog(LOG_DEBUG, "SMTPQ: %ld", Msg->MyQItem->QueMsgID);
+               EVS_syslog(LOG_DEBUG, "%ld", Msg->MyQItem->QueMsgID);
                CtdlFreeMessage(msg);
        }
        else {
@@ -218,39 +201,24 @@ inline void FinalizeMessageSend_DB_3(AsyncIO *IO)
                                   "");
                FreeStrBuf(&Msg->QMsgData);
        }
-       DecreaseShutdownDeliveries(Msg->MyQItem);
-}
-eNextState FinalizeMessageSend_DB3(AsyncIO *IO)
-{
-       SmtpOutMsg *Msg = IO->Data;
-       FinalizeMessageSend_DB_3(IO);
-       if (!Msg->IDestructQueItem)
-               return eAbort;
-       return NextDBOperation(IO, FinalizeMessageSend_DB4);
-}
-
-eNextState FinalizeMessageSend_DB4(AsyncIO *IO)
-{
-       int n;
-       SmtpOutMsg *Msg = IO->Data;
 
-       n = GetShutdownDeliveries(Msg->MyQItem);
-       if (n > 0) 
-               return NextDBOperation(IO, FinalizeMessageSend_DB4);
-       else
-               return eAbort;
+       RemoveContext(Msg->IO.CitContext);
+       if (Msg->IDestructQueItem)
+               RemoveQItem(Msg->MyQItem);
+       return eAbort;
 }
 
-eNextState FinalizeMessageSend_DB(AsyncIO *IO)
+eNextState Terminate(AsyncIO *IO)
 {
        SmtpOutMsg *Msg = IO->Data;
-
-       RemoveContext(Msg->IO.CitContext);
-       if (Msg->IDestructQueItem)
-               RemoveQItem(Msg->MyQItem);
        DeleteSmtpOutMsg(Msg);
        return eAbort;
 }
+eNextState FinalizeMessageSend(SmtpOutMsg *Msg)
+{
+       /* hand over to DB Queue */
+       return QueueDBOperation(&Msg->IO, FinalizeMessageSend_DB);
+}
 
 eNextState FailOneAttempt(AsyncIO *IO)
 {
@@ -270,16 +238,16 @@ eNextState FailOneAttempt(AsyncIO *IO)
                Msg->pCurrRelay = Msg->pCurrRelay->Next;
 
        if (Msg->pCurrRelay == NULL) {
-               EVS_syslog(LOG_DEBUG, "SMTP: %s Aborting\n", __FUNCTION__);
+               EVS_syslog(LOG_DEBUG, "%s Aborting\n", __FUNCTION__);
                return eAbort;
        }
        if (Msg->pCurrRelay->IsIP) {
-               EVS_syslog(LOG_DEBUG, "SMTP: %s connecting IP\n", __FUNCTION__);
+               EVS_syslog(LOG_DEBUG, "%s connecting IP\n", __FUNCTION__);
                return mx_connect_ip(IO);
        }
        else {
                EVS_syslog(LOG_DEBUG,
-                          "SMTP: %s resolving next MX Record\n",
+                          "%s resolving next MX Record\n",
                           __FUNCTION__);
                return get_one_mx_host_ip(IO);
        }
@@ -312,14 +280,13 @@ void SetConnectStatus(AsyncIO *IO)
        if (Msg->mx_host == NULL)
                Msg->mx_host = "<no MX-Record>";
 
-       EVS_syslog(LOG_DEBUG,
-                 "SMTP client[%ld]: connecting to %s [%s]:%d ...\n",
-                 Msg->n,
+       EVS_syslog(LOG_INFO,
+                 "connecting to %s [%s]:%d ...\n",
                  Msg->mx_host,
                  buf,
                  Msg->IO.ConnectMe->Port);
 
-       Msg->MyQEntry->Status = 5;
+       Msg->MyQEntry->Status = 4;
        StrBufPrintf(Msg->MyQEntry->StatusMessage,
                     "Timeout while connecting %s [%s]:%d ",
                     Msg->mx_host,
@@ -335,7 +302,7 @@ eNextState mx_connect_ip(AsyncIO *IO)
 {
        SmtpOutMsg *Msg = IO->Data;
 
-       EVS_syslog(LOG_DEBUG, "SMTP: %s\n", __FUNCTION__);
+       EVS_syslog(LOG_DEBUG, "%s\n", __FUNCTION__);
 
        IO->ConnectMe = Msg->pCurrRelay;
        Msg->State = eConnectMX;
@@ -354,6 +321,9 @@ eNextState get_one_mx_host_ip_done(AsyncIO *IO)
        struct hostent *hostent;
 
        QueryCbDone(IO);
+       EVS_syslog(LOG_DEBUG, "%s Time[%fs]\n",
+                  __FUNCTION__,
+                  IO->Now - IO->DNS.Start);
 
        hostent = Msg->HostLookup.VParsedDNSReply;
        if ((Msg->HostLookup.DNSStatus == ARES_SUCCESS) &&
@@ -388,10 +358,19 @@ eNextState get_one_mx_host_ip_done(AsyncIO *IO)
                        addr->sin_port   = htons(DefaultMXPort);
                }
                Msg->mx_host = Msg->pCurrRelay->Host;
+               if (Msg->HostLookup.VParsedDNSReply != NULL) {
+                       Msg->HostLookup.DNSReplyFree(Msg->HostLookup.VParsedDNSReply);
+                       Msg->HostLookup.VParsedDNSReply = NULL;
+               }
                return mx_connect_ip(IO);
        }
-       else
+       else {
+               if (Msg->HostLookup.VParsedDNSReply != NULL) {
+                       Msg->HostLookup.DNSReplyFree(Msg->HostLookup.VParsedDNSReply);
+                       Msg->HostLookup.VParsedDNSReply = NULL;
+               }
                return FailOneAttempt(IO);
+       }
 }
 
 eNextState get_one_mx_host_ip(AsyncIO *IO)
@@ -404,13 +383,10 @@ eNextState get_one_mx_host_ip(AsyncIO *IO)
         * - one of the mx'es
         */
 
-       InitC_ares_dns(IO);
-
-       EVS_syslog(LOG_DEBUG, "SMTP: %s\n", __FUNCTION__);
+       EVS_syslog(LOG_DEBUG, "%s\n", __FUNCTION__);
 
        EVS_syslog(LOG_DEBUG,
-                 "SMTP client[%ld]: looking up %s-Record %s : %d ...\n",
-                 Msg->n,
+                 "looking up %s-Record %s : %d ...\n",
                  (Msg->pCurrRelay->IPv6)? "aaaa": "a",
                  Msg->pCurrRelay->Host,
                  Msg->pCurrRelay->Port);
@@ -442,7 +418,9 @@ eNextState smtp_resolve_mx_record_done(AsyncIO *IO)
 
        QueryCbDone(IO);
 
-       EVS_syslog(LOG_DEBUG, "SMTP: %s\n", __FUNCTION__);
+       EVS_syslog(LOG_DEBUG, "%s Time[%fs]\n",
+                  __FUNCTION__,
+                  IO->Now - IO->DNS.Start);
 
        pp = &Msg->Relay;
        while ((pp != NULL) && (*pp != NULL) && ((*pp)->Next != NULL))
@@ -520,7 +498,7 @@ eNextState resolve_mx_records(AsyncIO *IO)
 {
        SmtpOutMsg * Msg = IO->Data;
 
-       EVS_syslog(LOG_DEBUG, "SMTP: %s\n", __FUNCTION__);
+       EVS_syslog(LOG_DEBUG, "%s\n", __FUNCTION__);
        /* start resolving MX records here. */
        if (!QueueQuery(ns_t_mx,
                        Msg->node,
@@ -584,7 +562,7 @@ void smtp_try_one_queue_entry(OneQueItem *MyQItem,
 {
        SmtpOutMsg *Msg;
 
-       syslog(LOG_DEBUG, "SMTP: %s\n", __FUNCTION__);
+       SMTPC_syslog(LOG_DEBUG, "%s\n", __FUNCTION__);
 
        Msg = new_smtp_outmsg(MyQItem, MyQEntry, MsgCount);
        if (KeepMsgText) Msg->msgtext = MsgText;
@@ -598,10 +576,10 @@ void smtp_try_one_queue_entry(OneQueItem *MyQItem,
                        sizeof(((CitContext *)
                                Msg->IO.CitContext)->cs_host));
 
-               syslog(LOG_DEBUG, "SMTP Starting: [%ld] <%s> CC <%d> \n",
-                      Msg->MyQItem->MessageID,
-                      ChrPtr(Msg->MyQEntry->Recipient),
-                      ((CitContext*)Msg->IO.CitContext)->cs_pid);
+               SMTPC_syslog(LOG_DEBUG, "Starting: [%ld] <%s> CC <%d> \n",
+                            Msg->MyQItem->MessageID,
+                            ChrPtr(Msg->MyQEntry->Recipient),
+                            ((CitContext*)Msg->IO.CitContext)->cs_pid);
                if (Msg->pCurrRelay == NULL)
                        QueueEventContext(&Msg->IO,
                                          resolve_mx_records);
@@ -626,11 +604,8 @@ void smtp_try_one_queue_entry(OneQueItem *MyQItem,
                        StrBufPlain(Msg->MyQEntry->StatusMessage,
                                    HKEY("Invalid Recipient!"));
                }
-               FinalizeMessageSend_1(&Msg->IO);
-               FinalizeMessageSend_DB_1(&Msg->IO);
-               FinalizeMessageSend_DB_2(&Msg->IO);
-               FinalizeMessageSend_DB_3(&Msg->IO);
                FinalizeMessageSend_DB(&Msg->IO);
+               DeleteSmtpOutMsg(&Msg->IO);
        }
 }
 
@@ -648,7 +623,7 @@ void SMTPSetTimeout(eNextState NextTCPState, SmtpOutMsg *Msg)
        double Timeout = 0.0;
        AsyncIO *IO = &Msg->IO;
 
-       EVS_syslog(LOG_DEBUG, "SMTP: %s\n", __FUNCTION__);
+       EVS_syslog(LOG_DEBUG, "%s\n", __FUNCTION__);
 
        switch (NextTCPState) {
        case eSendFile:
@@ -687,7 +662,7 @@ void SMTPSetTimeout(eNextState NextTCPState, SmtpOutMsg *Msg)
 }
 eNextState SMTP_C_DispatchReadDone(AsyncIO *IO)
 {
-       EVS_syslog(LOG_DEBUG, "SMTP: %s\n", __FUNCTION__);
+       EVS_syslog(LOG_DEBUG, "%s\n", __FUNCTION__);
        SmtpOutMsg *Msg = IO->Data;
        eNextState rc;
 
@@ -701,7 +676,7 @@ eNextState SMTP_C_DispatchReadDone(AsyncIO *IO)
 }
 eNextState SMTP_C_DispatchWriteDone(AsyncIO *IO)
 {
-       EVS_syslog(LOG_DEBUG, "SMTP: %s\n", __FUNCTION__);
+       EVS_syslog(LOG_DEBUG, "%s\n", __FUNCTION__);
        SmtpOutMsg *Msg = IO->Data;
        eNextState rc;
 
@@ -718,20 +693,20 @@ eNextState SMTP_C_Terminate(AsyncIO *IO)
 {
        SmtpOutMsg *Msg = IO->Data;
 
-       EVS_syslog(LOG_DEBUG, "SMTP: %s\n", __FUNCTION__);
+       EVS_syslog(LOG_DEBUG, "%s\n", __FUNCTION__);
        return FinalizeMessageSend(Msg);
 }
 eNextState SMTP_C_TerminateDB(AsyncIO *IO)
 {
-       EVS_syslog(LOG_DEBUG, "SMTP: %s\n", __FUNCTION__);
-       return FinalizeMessageSend_DB(IO);
+       EVS_syslog(LOG_DEBUG, "%s\n", __FUNCTION__);
+       return Terminate(IO);
 }
 eNextState SMTP_C_Timeout(AsyncIO *IO)
 {
        SmtpOutMsg *Msg = IO->Data;
 
        Msg->MyQEntry->Status = 4;
-       EVS_syslog(LOG_DEBUG, "SMTP: %s\n", __FUNCTION__);
+       EVS_syslog(LOG_DEBUG, "%s\n", __FUNCTION__);
        StrBufPlain(IO->ErrMsg, CKEY(ReadErrors[Msg->State]));
        if (Msg->State > eRCPT)
                return eAbort;
@@ -743,7 +718,7 @@ eNextState SMTP_C_ConnFail(AsyncIO *IO)
        SmtpOutMsg *Msg = IO->Data;
 
        Msg->MyQEntry->Status = 4;
-       EVS_syslog(LOG_DEBUG, "SMTP: %s\n", __FUNCTION__);
+       EVS_syslog(LOG_DEBUG, "%s\n", __FUNCTION__);
        StrBufPlain(IO->ErrMsg, CKEY(ReadErrors[Msg->State]));
        return FailOneAttempt(IO);
 }
@@ -751,12 +726,12 @@ eNextState SMTP_C_DNSFail(AsyncIO *IO)
 {
        SmtpOutMsg *Msg = IO->Data;
        Msg->MyQEntry->Status = 4;
-       EVS_syslog(LOG_DEBUG, "SMTP: %s\n", __FUNCTION__);
+       EVS_syslog(LOG_DEBUG, "%s\n", __FUNCTION__);
        return FailOneAttempt(IO);
 }
 eNextState SMTP_C_Shutdown(AsyncIO *IO)
 {
-       EVS_syslog(LOG_DEBUG, "SMTP: %s\n", __FUNCTION__);
+       EVS_syslog(LOG_DEBUG, "%s\n", __FUNCTION__);
        SmtpOutMsg *Msg = IO->Data;
 
        Msg->MyQEntry->Status = 3;
@@ -798,7 +773,14 @@ eReadState SMTP_C_ReadServerStatus(AsyncIO *IO)
        return Finished;
 }
 
+void LogDebugEnableSMTPClient(const int n)
+{
+       SMTPClientDebugEnabled = n;
+}
+
 CTDL_MODULE_INIT(smtp_eventclient)
 {
+       if (!threading)
+               CtdlRegisterDebugFlagHook(HKEY("smtpeventclient"), LogDebugEnableSMTPClient, &SMTPClientDebugEnabled);
        return "smtpeventclient";
 }