X-Git-Url: https://code.citadel.org/?a=blobdiff_plain;f=citadel%2Fmodules%2Fsmtp%2Fserv_smtpeventclient.c;h=dbe2c297db94d940f03d74078ac3ef5cd0b97100;hb=eee9a1429dd032114946aad9e70fd8d84afbe918;hp=9114746685ec2b3d6d07b9962b45d87497c4e347;hpb=dc26af1104cd8f1a0fc65ed3e1d8504934dddeaa;p=citadel.git

diff --git a/citadel/modules/smtp/serv_smtpeventclient.c b/citadel/modules/smtp/serv_smtpeventclient.c
index 911474668..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;
@@ -106,7 +107,7 @@ void DeleteSmtpOutMsg(void *v)
 	FreeURL(&Msg->Relay);
 	FreeStrBuf(&Msg->msgtext);
 	FreeAsyncIOContents(&Msg->IO);
-///	memset (Msg, 0, sizeof(SmtpOutMsg)); /* just to be shure... */
+	memset (Msg, 0, sizeof(SmtpOutMsg)); /* just to be shure... */
 	free(Msg);
 }
 
@@ -117,10 +118,16 @@ 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);
 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)         *
@@ -128,33 +135,88 @@ 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)
+inline void FinalizeMessageSend_1(AsyncIO *IO)
 {
-	int IDestructQueItem;
-	int nRemain;
-	StrBuf *MsgData;
-	AsyncIO *IO = &Msg->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));
+
 
-	IDestructQueItem = DecreaseQReference(Msg->MyQItem);
+	Msg->IDestructQueItem = DecreaseQReference(Msg->MyQItem);
 
-	nRemain = CountActiveQueueEntries(Msg->MyQItem);
+	Msg->nRemain = CountActiveQueueEntries(Msg->MyQItem);
 
-	if ((nRemain > 0) || IDestructQueItem)
-		MsgData = SerializeQueueItem(Msg->MyQItem);
+	if (Msg->MyQEntry->Active && 
+	    CheckQEntryIsBounce(Msg->MyQEntry))
+	{
+		/* are we casue for a bounce mail? */
+		Msg->MyQItem->SendBounceMail |= (1<<Msg->MyQEntry->Status);
+	}
+
+	if ((Msg->nRemain > 0) || Msg->IDestructQueItem)
+		Msg->QMsgData = SerializeQueueItem(Msg->MyQItem);
 	else
-		MsgData = NULL;
+		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);
+}
 
-	if (IDestructQueItem)
-		smtpq_do_bounce(Msg->MyQItem,Msg->msgtext);
 
-	if (nRemain > 0)
+inline void FinalizeMessageSend_DB_2(AsyncIO *IO)
+{
+	SmtpOutMsg *Msg = IO->Data;
+
+	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)
 	{
 		struct CtdlMessage *msg;
 		msg = malloc(sizeof(struct CtdlMessage));
@@ -162,10 +224,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 {
@@ -173,12 +236,40 @@ void FinalizeMessageSend(SmtpOutMsg *Msg)
 				   &Msg->MyQItem->MessageID,
 				   1,
 				   "");
-		FreeStrBuf(&MsgData);
+		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 Done;
+	SmtpOutMsg *Msg = IO->Data;
+
+	Done = GetShutdownDeliveries(Msg->MyQItem);
+	if (!Done) 
+		return NextDBOperation(IO, FinalizeMessageSend_DB4);
+	else
+		return eAbort;
+}
+
+eNextState FinalizeMessageSend_DB(AsyncIO *IO)
+{
+	SmtpOutMsg *Msg = IO->Data;
+
 	RemoveContext(Msg->IO.CitContext);
-	if (IDestructQueItem)
+	if (Msg->IDestructQueItem)
 		RemoveQItem(Msg->MyQItem);
 	DeleteSmtpOutMsg(Msg);
+	return eAbort;
 }
 
 eNextState FailOneAttempt(AsyncIO *IO)
@@ -199,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);
 	}
@@ -241,9 +332,8 @@ 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);
@@ -264,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;
@@ -283,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) &&
@@ -317,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)
@@ -333,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);
@@ -371,7 +470,10 @@ 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))
 		pp = &(*pp)->Next;
@@ -379,7 +481,6 @@ eNextState smtp_resolve_mx_record_done(AsyncIO *IO)
 	if ((IO->DNS.Query->DNSStatus == ARES_SUCCESS) &&
 	    (IO->DNS.Query->VParsedDNSReply != NULL))
 	{ /* ok, we found mx records. */
-		Msg->IO.ErrMsg = Msg->MyQEntry->StatusMessage;
 
 		Msg->CurrMX
 			= Msg->AllMX
@@ -391,13 +492,29 @@ eNextState smtp_resolve_mx_record_done(AsyncIO *IO)
 
 				p = (ParsedURL*) malloc(sizeof(ParsedURL));
 				memset(p, 0, sizeof(ParsedURL));
+				p->Priority = Msg->CurrMX->priority;
 				p->IsIP = 0;
 				p->Port = DefaultMXPort;
 				p->IPv6 = i == 1;
 				p->Host = Msg->CurrMX->host;
-
-				*pp = p;
-				pp = &p->Next;
+				if (*pp == NULL)
+					*pp = p;
+				else {
+					ParsedURL *ppp = *pp;
+
+					while ((ppp->Next != NULL) &&
+					       (ppp->Next->Priority <= p->Priority))
+					       ppp = ppp->Next;
+					if ((ppp == *pp) &&
+					    (ppp->Priority > p->Priority)) {
+						p->Next = *pp;
+						*pp = p;
+					}
+					else {
+						p->Next = ppp->Next;
+						ppp->Next = p;
+					}
+				}
 			}
 			Msg->CurrMX    = Msg->CurrMX->next;
 		}
@@ -420,7 +537,11 @@ eNextState smtp_resolve_mx_record_done(AsyncIO *IO)
 		}
 		Msg->CXFlags   = Msg->CXFlags & F_DIRECT;
 	}
-	*pp = Msg->MyQItem->FallBackHost;
+	if (Msg->MyQItem->FallBackHost != NULL)
+	{
+		Msg->MyQItem->FallBackHost->Next = *pp;
+		*pp = Msg->MyQItem->FallBackHost;
+	}
 	Msg->pCurrRelay = Msg->Relay;
 	return get_one_mx_host_ip(IO);
 }
@@ -429,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,
@@ -474,10 +595,13 @@ 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);
 
+	Msg->IO.ErrMsg = Msg->MyQEntry->StatusMessage;
+
 	return Msg;
 }
 
@@ -490,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;
@@ -504,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);
@@ -532,7 +656,11 @@ void smtp_try_one_queue_entry(OneQueItem *MyQItem,
 			StrBufPlain(Msg->MyQEntry->StatusMessage,
 				    HKEY("Invalid Recipient!"));
 		}
-		FinalizeMessageSend(Msg);
+		FinalizeMessageSend_1(&Msg->IO);
+		FinalizeMessageSend_DB_1(&Msg->IO);
+		FinalizeMessageSend_DB_2(&Msg->IO);
+		FinalizeMessageSend_DB_3(&Msg->IO);
+		FinalizeMessageSend_DB(&Msg->IO);
 	}
 }
 
@@ -550,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:
@@ -589,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;
 
@@ -603,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;
 
@@ -620,16 +748,20 @@ 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 FinalizeMessageSend_DB(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;
@@ -641,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);
 }
@@ -649,19 +781,18 @@ 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;
 	StrBufPlain(Msg->MyQEntry->StatusMessage,
 		    HKEY("server shutdown during message submit."));
-	FinalizeMessageSend(Msg);
-	return eAbort;
+	return FinalizeMessageSend(Msg);
 }
 
 
@@ -697,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";
 }