X-Git-Url: https://code.citadel.org/?a=blobdiff_plain;f=citadel%2Fmodules%2Fsmtp%2Fserv_smtpeventclient.c;h=dbe2c297db94d940f03d74078ac3ef5cd0b97100;hb=eee9a1429dd032114946aad9e70fd8d84afbe918;hp=e5c1cee00931f84c887addfcbdb51002b8eab444;hpb=99f5a2324115920e21e153e77ef369dc053299c7;p=citadel.git diff --git a/citadel/modules/smtp/serv_smtpeventclient.c b/citadel/modules/smtp/serv_smtpeventclient.c index e5c1cee00..dbe2c297d 100644 --- a/citadel/modules/smtp/serv_smtpeventclient.c +++ b/citadel/modules/smtp/serv_smtpeventclient.c @@ -90,12 +90,13 @@ #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; @@ -126,6 +127,7 @@ 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) * @@ -135,7 +137,26 @@ eNextState FinalizeMessageSend_DB3(AsyncIO *IO); ******************************************************************************/ inline void FinalizeMessageSend_1(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); @@ -165,7 +186,7 @@ inline void FinalizeMessageSend_DB_1(AsyncIO *IO) * 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) @@ -207,7 +228,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 { @@ -217,11 +238,27 @@ 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); - return eAbort; + if (!Msg->IDestructQueItem) + return eAbort; + return NextDBOperation(IO, FinalizeMessageSend_DB4); +} + +eNextState FinalizeMessageSend_DB4(AsyncIO *IO) +{ + int Done; + SmtpOutMsg *Msg = IO->Data; + + Done = GetShutdownDeliveries(Msg->MyQItem); + if (!Done) + return NextDBOperation(IO, FinalizeMessageSend_DB4); + else + return eAbort; } eNextState FinalizeMessageSend_DB(AsyncIO *IO) @@ -253,16 +290,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); } @@ -295,9 +332,8 @@ 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); @@ -318,7 +354,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; @@ -337,6 +373,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) && @@ -371,10 +410,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) @@ -387,13 +435,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); @@ -425,7 +470,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)) @@ -503,7 +550,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, @@ -567,7 +614,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; @@ -581,10 +628,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); @@ -631,7 +678,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: @@ -670,7 +717,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; @@ -684,7 +731,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; @@ -701,12 +748,12 @@ 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__); + EVS_syslog(LOG_DEBUG, "%s\n", __FUNCTION__); return FinalizeMessageSend_DB(IO); } eNextState SMTP_C_Timeout(AsyncIO *IO) @@ -714,7 +761,7 @@ 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; @@ -726,7 +773,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); } @@ -734,12 +781,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; @@ -781,7 +828,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"; }