X-Git-Url: https://code.citadel.org/?a=blobdiff_plain;f=citadel%2Fmodules%2Fsmtp%2Fserv_smtpeventclient.c;h=dd4e3e2662b08a05a10784a4e36ee4a26dda378f;hb=63dc1de06b047b4be691541935e98845457c4c04;hp=90a36b23539f6582b823bd1ec4ce023b834b9562;hpb=f74fed30f3d655d3f229628b6b998240fa6494be;p=citadel.git diff --git a/citadel/modules/smtp/serv_smtpeventclient.c b/citadel/modules/smtp/serv_smtpeventclient.c index 90a36b235..dd4e3e266 100644 --- a/citadel/modules/smtp/serv_smtpeventclient.c +++ b/citadel/modules/smtp/serv_smtpeventclient.c @@ -90,12 +90,34 @@ #include "smtpqueue.h" #include "smtp_clienthandlers.h" -const unsigned short DefaultMXPort = 25; +ConstStr SMTPStates[] = { + {HKEY("looking up mx - record")}, + {HKEY("evaluating what to do next")}, + {HKEY("looking up a - record")}, + {HKEY("looking up aaaa - record")}, + {HKEY("connecting remote")}, + {HKEY("smtp conversation ongoing")}, + {HKEY("smtp sending maildata")}, + {HKEY("smtp sending done")}, + {HKEY("smtp successfully finished")}, + {HKEY("failed one attempt")}, + {HKEY("failed temporarily")}, + {HKEY("failed permanently")} +}; + +void SetSMTPState(AsyncIO *IO, smtpstate State) +{ + CitContext* CCC = IO->CitContext; + if (CCC != NULL) + memcpy(CCC->cs_clientname, SMTPStates[State].Key, SMTPStates[State].len + 1); +} + +int SMTPClientDebugEnabled = 0; void DeleteSmtpOutMsg(void *v) { SmtpOutMsg *Msg = v; AsyncIO *IO = &Msg->IO; - EV_syslog(LOG_DEBUG, "SMTP: %s Aborting\n", __FUNCTION__); + EV_syslog(LOG_DEBUG, "%s Exit\n", __FUNCTION__); /* these are kept in our own space and free'd below */ Msg->IO.ConnectMe = NULL; @@ -117,6 +139,7 @@ eNextState SMTP_C_DispatchReadDone(AsyncIO *IO); eNextState SMTP_C_DispatchWriteDone(AsyncIO *IO); eNextState SMTP_C_DNSFail(AsyncIO *IO); eNextState SMTP_C_Terminate(AsyncIO *IO); +eNextState SMTP_C_TerminateDB(AsyncIO *IO); eReadState SMTP_C_ReadServerStatus(AsyncIO *IO); eNextState mx_connect_ip(AsyncIO *IO); @@ -128,40 +151,70 @@ eNextState get_one_mx_host_ip(AsyncIO *IO); * we need to free the memory and send bounce messages (on terminal failure) * * else we just free our SMTP-Message struct. * ******************************************************************************/ -void FinalizeMessageSend(SmtpOutMsg *Msg) +eNextState FinalizeMessageSend_DB(AsyncIO *IO) { - int IDestructQueItem; - int nRemain; - StrBuf *MsgData; - AsyncIO *IO = &Msg->IO; + const char *Status; + SmtpOutMsg *Msg = IO->Data; + StrBuf *StatusMessage; - IDestructQueItem = DecreaseQReference(Msg->MyQItem); + if (Msg->MyQEntry->AllStatusMessages != NULL) + StatusMessage = Msg->MyQEntry->AllStatusMessages; + else + StatusMessage = Msg->MyQEntry->StatusMessage; - nRemain = CountActiveQueueEntries(Msg->MyQItem); + + if (Msg->MyQEntry->Status == 2) { + SetSMTPState(IO, eSTMPfinished); + Status = "Delivery successful."; + } + else if (Msg->MyQEntry->Status == 5) { + SetSMTPState(IO, eSMTPFailTotal); + Status = "Delivery failed permanently; giving up."; + } + else { + SetSMTPState(IO, eSMTPFailTemporary); + 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(StatusMessage)); + + + Msg->IDestructQueItem = DecreaseQReference(Msg->MyQItem); + + Msg->nRemain = CountActiveQueueEntries(Msg->MyQItem, 0); if (Msg->MyQEntry->Active && + !Msg->MyQEntry->StillActive && CheckQEntryIsBounce(Msg->MyQEntry)) { /* are we casue for a bounce mail? */ Msg->MyQItem->SendBounceMail |= (1<MyQEntry->Status); } - if ((nRemain > 0) || IDestructQueItem) - MsgData = SerializeQueueItem(Msg->MyQItem); + if ((Msg->nRemain > 0) || Msg->IDestructQueItem) + Msg->QMsgData = SerializeQueueItem(Msg->MyQItem); else - MsgData = NULL; + Msg->QMsgData = NULL; /* * 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, ""); + Msg->MyQItem->QueMsgID = -1; - if (IDestructQueItem) - smtpq_do_bounce(Msg->MyQItem, Msg->msgtext); + if (Msg->IDestructQueItem) + smtpq_do_bounce(Msg->MyQItem, StatusMessage, Msg->msgtext, Msg->pCurrRelay); - if (nRemain > 0) + if (Msg->nRemain > 0) { struct CtdlMessage *msg; msg = malloc(sizeof(struct CtdlMessage)); @@ -169,11 +222,11 @@ void FinalizeMessageSend(SmtpOutMsg *Msg) msg->cm_magic = CTDLMESSAGE_MAGIC; msg->cm_anon_type = MES_NORMAL; msg->cm_format_type = FMT_RFC822; - msg->cm_fields['M'] = SmashStrBuf(&MsgData); + msg->cm_fields['M'] = SmashStrBuf(&Msg->QMsgData); 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 { @@ -181,18 +234,34 @@ void FinalizeMessageSend(SmtpOutMsg *Msg) &Msg->MyQItem->MessageID, 1, ""); - FreeStrBuf(&MsgData); + FreeStrBuf(&Msg->QMsgData); } + RemoveContext(Msg->IO.CitContext); - if (IDestructQueItem) + return eAbort; +} + +eNextState Terminate(AsyncIO *IO) +{ + SmtpOutMsg *Msg = IO->Data; + + 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) { SmtpOutMsg *Msg = IO->Data; + SetSMTPState(IO, eSTMPfailOne); if (Msg->MyQEntry->Status == 2) return eAbort; @@ -201,22 +270,37 @@ eNextState FailOneAttempt(AsyncIO *IO) * - connection timeout * - dns lookup failed */ - StopClientWatchers(IO); + StopClientWatchers(IO, 1); + + Msg->MyQEntry->nAttempt ++; + if (Msg->MyQEntry->AllStatusMessages == NULL) + Msg->MyQEntry->AllStatusMessages = NewStrBuf(); + + StrBufAppendPrintf(Msg->MyQEntry->AllStatusMessages, "%ld) ", Msg->MyQEntry->nAttempt); + StrBufAppendBuf(Msg->MyQEntry->AllStatusMessages, Msg->MyQEntry->StatusMessage, 0); + StrBufAppendBufPlain(Msg->MyQEntry->AllStatusMessages, HKEY("; "), 0); if (Msg->pCurrRelay != NULL) Msg->pCurrRelay = Msg->pCurrRelay->Next; + if ((Msg->pCurrRelay != NULL) && + !Msg->pCurrRelay->IsRelay && + Msg->MyQItem->HaveRelay) + { + EVS_syslog(LOG_DEBUG, "%s Aborting; last relay failed.\n", __FUNCTION__); + return eAbort; + } 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); } @@ -249,14 +333,13 @@ void SetConnectStatus(AsyncIO *IO) if (Msg->mx_host == NULL) Msg->mx_host = ""; - 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, @@ -271,8 +354,9 @@ void SetConnectStatus(AsyncIO *IO) eNextState mx_connect_ip(AsyncIO *IO) { SmtpOutMsg *Msg = IO->Data; + SetSMTPState(IO, eSTMPconnecting); - EVS_syslog(LOG_DEBUG, "SMTP: %s\n", __FUNCTION__); + EVS_syslog(LOG_DEBUG, "%s\n", __FUNCTION__); IO->ConnectMe = Msg->pCurrRelay; Msg->State = eConnectMX; @@ -290,7 +374,12 @@ eNextState get_one_mx_host_ip_done(AsyncIO *IO) SmtpOutMsg *Msg = IO->Data; struct hostent *hostent; + IO->ConnectMe = Msg->pCurrRelay; + 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) && @@ -304,7 +393,7 @@ eNextState get_one_mx_host_ip_done(AsyncIO *IO) Msg->pCurrRelay->Addr.sin6_family = hostent->h_addrtype; Msg->pCurrRelay->Addr.sin6_port = - htons(DefaultMXPort); + htons(Msg->IO.ConnectMe->Port); } else { struct sockaddr_in *addr; @@ -322,13 +411,23 @@ eNextState get_one_mx_host_ip_done(AsyncIO *IO) sizeof(uint32_t)); addr->sin_family = hostent->h_addrtype; - addr->sin_port = htons(DefaultMXPort); + addr->sin_port = htons(Msg->IO.ConnectMe->Port); } 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 { + SetSMTPState(IO, eSTMPfailOne); + 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) @@ -340,14 +439,12 @@ eNextState get_one_mx_host_ip(AsyncIO *IO) * - the direct hostname if there was no mx record * - one of the mx'es */ + SetSMTPState(IO, (Msg->pCurrRelay->IPv6)?eSTMPalookup:eSTMPaaaalookup); - 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); @@ -379,7 +476,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)) @@ -457,7 +556,9 @@ eNextState resolve_mx_records(AsyncIO *IO) { SmtpOutMsg * Msg = IO->Data; - EVS_syslog(LOG_DEBUG, "SMTP: %s\n", __FUNCTION__); + SetSMTPState(IO, eSTMPmxlookup); + + EVS_syslog(LOG_DEBUG, "%s\n", __FUNCTION__); /* start resolving MX records here. */ if (!QueueQuery(ns_t_mx, Msg->node, @@ -487,6 +588,8 @@ SmtpOutMsg *new_smtp_outmsg(OneQueItem *MyQItem, SmtpOutMsg * Msg; Msg = (SmtpOutMsg *) malloc(sizeof(SmtpOutMsg)); + if (Msg == NULL) + return NULL; memset(Msg, 0, sizeof(SmtpOutMsg)); Msg->n = MsgCount; @@ -502,6 +605,7 @@ SmtpOutMsg *new_smtp_outmsg(OneQueItem *MyQItem, SMTP_C_DispatchWriteDone, SMTP_C_DispatchReadDone, SMTP_C_Terminate, + SMTP_C_TerminateDB, SMTP_C_ConnFail, SMTP_C_Timeout, SMTP_C_Shutdown); @@ -520,33 +624,45 @@ 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 (Msg == NULL) { + SMTPC_syslog(LOG_DEBUG, "%s Failed to alocate message context.\n", __FUNCTION__); + if (KeepMsgText) + FreeStrBuf (&MsgText); + return; + } if (KeepMsgText) Msg->msgtext = MsgText; else Msg->msgtext = NewStrBufDup(MsgText); - if (smtp_resolve_recipients(Msg)) { - + if (smtp_resolve_recipients(Msg) && + (!MyQItem->HaveRelay || + (MyQItem->URL != NULL))) + { safestrncpy( ((CitContext *)Msg->IO.CitContext)->cs_host, Msg->node, 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); - if (Msg->pCurrRelay == NULL) + 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) { + SetSMTPState(&Msg->IO, eSTMPmxlookup); QueueEventContext(&Msg->IO, resolve_mx_records); + } else { /* oh... via relay host */ if (Msg->pCurrRelay->IsIP) { + SetSMTPState(&Msg->IO, eSTMPconnecting); QueueEventContext(&Msg->IO, mx_connect_ip); } else { + SetSMTPState(&Msg->IO, eSTMPalookup); /* uneducated admin has chosen to add DNS to the equation... */ QueueEventContext(&Msg->IO, @@ -555,14 +671,16 @@ void smtp_try_one_queue_entry(OneQueItem *MyQItem, } } else { + SetSMTPState(&Msg->IO, eSMTPFailTotal); /* No recipients? well fail then. */ - if ((Msg==NULL) || - (Msg->MyQEntry == NULL)) { + if (Msg->MyQEntry != NULL) { Msg->MyQEntry->Status = 5; - StrBufPlain(Msg->MyQEntry->StatusMessage, - HKEY("Invalid Recipient!")); + if (StrLength(Msg->MyQEntry->StatusMessage) == 0) + StrBufPlain(Msg->MyQEntry->StatusMessage, + HKEY("Invalid Recipient!")); } - FinalizeMessageSend(Msg); + FinalizeMessageSend_DB(&Msg->IO); + DeleteSmtpOutMsg(Msg); } } @@ -580,7 +698,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: @@ -619,7 +737,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; @@ -633,7 +751,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; @@ -650,17 +768,23 @@ eNextState SMTP_C_Terminate(AsyncIO *IO) { SmtpOutMsg *Msg = IO->Data; - EVS_syslog(LOG_DEBUG, "SMTP: %s\n", __FUNCTION__); - FinalizeMessageSend(Msg); - return eAbort; + EVS_syslog(LOG_DEBUG, "%s\n", __FUNCTION__); + return FinalizeMessageSend(Msg); +} +eNextState SMTP_C_TerminateDB(AsyncIO *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__); - StrBufPlain(IO->ErrMsg, CKEY(ReadErrors[Msg->State])); + EVS_syslog(LOG_DEBUG, "%s\n", __FUNCTION__); + StrBufPrintf(IO->ErrMsg, "Timeout: %s while talking to %s", + ReadErrors[Msg->State].Key, + Msg->mx_host); if (Msg->State > eRCPT) return eAbort; else @@ -671,27 +795,51 @@ eNextState SMTP_C_ConnFail(AsyncIO *IO) SmtpOutMsg *Msg = IO->Data; Msg->MyQEntry->Status = 4; - EVS_syslog(LOG_DEBUG, "SMTP: %s\n", __FUNCTION__); - StrBufPlain(IO->ErrMsg, CKEY(ReadErrors[Msg->State])); + EVS_syslog(LOG_DEBUG, "%s\n", __FUNCTION__); + StrBufPrintf(IO->ErrMsg, "Connection failure: %s while talking to %s", + ReadErrors[Msg->State].Key, + Msg->mx_host); + return FailOneAttempt(IO); } 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; + switch (IO->NextState) { + case eSendDNSQuery: + case eReadDNSReply: + + /* todo: abort c-ares */ + case eConnect: + case eSendReply: + case eSendMore: + case eSendFile: + case eReadMessage: + case eReadMore: + case eReadPayload: + case eReadFile: + StopClientWatchers(IO, 1); + break; + case eDBQuery: + + break; + case eTerminateConnection: + case eAbort: + break; + } Msg->MyQEntry->Status = 3; StrBufPlain(Msg->MyQEntry->StatusMessage, HKEY("server shutdown during message submit.")); - FinalizeMessageSend(Msg); - return eAbort; + return FinalizeMessageSend(Msg); } @@ -727,7 +875,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"; }