Capture the actual SMTP response from the server, ugly hack using libcurl debug
[citadel.git] / citadel / modules / smtp / serv_smtpclient.c
1 /*
2  * Transmit outbound SMTP mail to the big wide world of the Internet
3  *
4  * This is the new, exciting, clever version that makes libcurl do all the work  :)
5  *
6  * Copyright (c) 1997-2017 by the citadel.org team
7  *
8  * This program is open source software; you can redistribute it and/or
9  * modify it under the terms of the GNU General Public License as published
10  * by the Free Software Foundation; either version 3 of the License, or
11  * (at your option) any later version.
12  *
13  * This program is distributed in the hope that it will be useful,
14  * but WITHOUT ANY WARRANTY; without even the implied warranty of
15  * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
16  * GNU General Public License for more details.
17  */
18
19 #include <stdlib.h>
20 #include <unistd.h>
21 #include <stdio.h>
22 #include <sysconfig.h>
23
24 #if TIME_WITH_SYS_TIME
25 # include <sys/time.h>
26 # include <time.h>
27 #else
28 # if HAVE_SYS_TIME_H
29 #  include <sys/time.h>
30 # else
31 #  include <time.h>
32 # endif
33 #endif
34
35 #include <ctype.h>
36 #include <string.h>
37 #include <errno.h>
38 #include <sys/types.h>
39 #include <sys/stat.h>
40 #include <libcitadel.h>
41 #include <curl/curl.h>
42 #include "citadel.h"
43 #include "server.h"
44 #include "citserver.h"
45 #include "support.h"
46 #include "config.h"
47 #include "ctdl_module.h"
48 #include "clientsocket.h"
49 #include "msgbase.h"
50 #include "domain.h"
51 #include "internet_addressing.h"
52 #include "citadel_dirs.h"
53 #include "modules/smtp/smtp_util.h"
54
55 struct smtpmsgsrc {             // Data passed in and out of libcurl for message upload
56         StrBuf *TheMessage;
57         int bytes_total;
58         int bytes_sent;
59 };
60
61 struct CitContext smtp_client_CC;
62 static int doing_smtpclient = 0;
63 long *smtpq = NULL;             // array of msgnums containing queue instructions
64 int smtpq_count = 0;            // number of queue messages in smtpq
65 int smtpq_alloc = 0;            // current allocation size for smtpq
66
67
68 /*
69  * Initialize the SMTP outbound queue
70  */
71 void smtp_init_spoolout(void) {
72         struct ctdlroom qrbuf;
73
74         /*
75          * Create the room.  This will silently fail if the room already
76          * exists, and that's perfectly ok, because we want it to exist.
77          */
78         CtdlCreateRoom(SMTP_SPOOLOUT_ROOM, 3, "", 0, 1, 0, VIEW_QUEUE);
79
80         /*
81          * Make sure it's set to be a "system room" so it doesn't show up
82          * in the <K>nown rooms list for administrators.
83          */
84         if (CtdlGetRoomLock(&qrbuf, SMTP_SPOOLOUT_ROOM) == 0) {
85                 qrbuf.QRflags2 |= QR2_SYSTEM;
86                 CtdlPutRoomLock(&qrbuf);
87         }
88 }
89
90
91 /* For internet mail, generate delivery instructions.
92  * Yes, this is recursive.  Deal with it.  Infinite recursion does
93  * not happen because the delivery instructions message does not
94  * contain a recipient.
95  */
96 int smtp_aftersave(struct CtdlMessage *msg, recptypes *recps)
97 {
98         if ((recps != NULL) && (recps->num_internet > 0)) {
99                 struct CtdlMessage *imsg = NULL;
100                 char recipient[SIZ];
101                 StrBuf *SpoolMsg = NewStrBuf();
102                 long nTokens;
103                 int i;
104
105                 syslog(LOG_DEBUG, "smtpclient: generating delivery instructions");
106
107                 StrBufPrintf(SpoolMsg,
108                              "Content-type: "SPOOLMIME"\n"
109                              "\n"
110                              "msgid|%s\n"
111                              "submitted|%ld\n"
112                              "bounceto|%s\n",
113                              msg->cm_fields[eVltMsgNum],
114                              (long)time(NULL),
115                              recps->bounce_to
116                 );
117
118                 if (recps->envelope_from != NULL) {
119                         StrBufAppendBufPlain(SpoolMsg, HKEY("envelope_from|"), 0);
120                         StrBufAppendBufPlain(SpoolMsg, recps->envelope_from, -1, 0);
121                         StrBufAppendBufPlain(SpoolMsg, HKEY("\n"), 0);
122                 }
123                 if (recps->sending_room != NULL) {
124                         StrBufAppendBufPlain(SpoolMsg, HKEY("source_room|"), 0);
125                         StrBufAppendBufPlain(SpoolMsg, recps->sending_room, -1, 0);
126                         StrBufAppendBufPlain(SpoolMsg, HKEY("\n"), 0);
127                 }
128
129                 nTokens = num_tokens(recps->recp_internet, '|');
130                 for (i = 0; i < nTokens; i++) {
131                         long len;
132                         len = extract_token(recipient, recps->recp_internet, i, '|', sizeof recipient);
133                         if (len > 0) {
134                                 StrBufAppendBufPlain(SpoolMsg, HKEY("remote|"), 0);
135                                 StrBufAppendBufPlain(SpoolMsg, recipient, len, 0);
136                                 StrBufAppendBufPlain(SpoolMsg, HKEY("|0||\n"), 0);
137                         }
138                 }
139
140                 imsg = malloc(sizeof(struct CtdlMessage));
141                 memset(imsg, 0, sizeof(struct CtdlMessage));
142                 imsg->cm_magic = CTDLMESSAGE_MAGIC;
143                 imsg->cm_anon_type = MES_NORMAL;
144                 imsg->cm_format_type = FMT_RFC822;
145                 CM_SetField(imsg, eMsgSubject, HKEY("QMSG"));
146                 CM_SetField(imsg, eAuthor, HKEY("Citadel"));
147                 CM_SetField(imsg, eJournal, HKEY("do not journal"));
148                 CM_SetAsFieldSB(imsg, eMesageText, &SpoolMsg);
149                 CtdlSubmitMsg(imsg, NULL, SMTP_SPOOLOUT_ROOM, QP_EADDR);
150                 CM_Free(imsg);
151         }
152         return 0;
153 }
154
155
156 /*
157  * Callback for smtp_attempt_delivery() to supply libcurl with upload data.
158  */
159 static size_t upload_source(void *ptr, size_t size, size_t nmemb, void *userp)
160 {
161         struct smtpmsgsrc *s = (struct smtpmsgsrc *) userp;
162         int sendbytes = 0;
163         const char *send_this = NULL;
164
165         sendbytes = (size * nmemb);
166
167         if (s->bytes_sent >= s->bytes_total) {
168                 return(0);                                      // no data remaining; we are done
169         }
170
171         if (sendbytes > (s->bytes_total - s->bytes_sent)) {
172                 sendbytes = s->bytes_total - s->bytes_sent;     // can't send more than we have
173         }
174
175         send_this = ChrPtr(s->TheMessage);
176         send_this += s->bytes_sent;                             // start where we last left off
177
178         memcpy(ptr, send_this, sendbytes);
179         s->bytes_sent += sendbytes;
180         return(sendbytes);                                      // return the number of bytes _actually_ copied
181 }
182
183
184 /*
185  * The libcurl API doesn't provide a way to capture the actual SMTP result message returned
186  * by the remote server.  This is an ugly way to extract it, by capturing debug data from
187  * the library and filtering on the lines we want.
188  */
189 int ctdl_libcurl_smtp_debug_callback(CURL *handle, curl_infotype type, char *data, size_t size, void *userptr)
190 {
191         if (type != CURLINFO_HEADER_IN) return 0;
192         if (!userptr) return 0;
193         char *debugbuf = (char *)userptr;
194
195         int len = strlen(debugbuf);
196         if (len + size > SIZ) return 0;
197
198         memcpy(&debugbuf[len], data, size);
199         debugbuf[len+size] = 0;
200         return 0;
201 }
202
203
204 /*
205  * Attempt a delivery to one recipient.
206  * Returns a three-digit SMTP status code.
207  */
208 int smtp_attempt_delivery(long msgid, char *recp, char *envelope_from, char *response)
209 {
210         struct smtpmsgsrc s;
211         char *fromaddr = NULL;
212         CURL *curl;
213         CURLcode res = CURLE_OK;
214         struct curl_slist *recipients = NULL;
215         long response_code = 421;
216         int num_mx = 0;
217         char mxes[SIZ];
218         char user[1024];
219         char node[1024];
220         char name[1024];
221         char try_this_mx[256];
222         char smtp_url[512];
223         int i;
224
225         syslog(LOG_DEBUG, "smtpclient: smtp_attempt_delivery(%ld, %s)", msgid, recp);
226
227         process_rfc822_addr(recp, user, node, name);            // split recipient address into username, hostname, displayname
228         num_mx = getmx(mxes, node);
229         if (num_mx < 1) {
230                 return(421);
231         }
232
233         CC->redirect_buffer = NewStrBufPlain(NULL, SIZ);
234         CtdlOutputMsg(msgid, MT_RFC822, HEADERS_ALL, 0, 1, NULL, 0, NULL, &fromaddr, NULL);
235         s.TheMessage = CC->redirect_buffer;
236         s.bytes_total =  StrLength(CC->redirect_buffer);
237         s.bytes_sent = 0;
238         CC->redirect_buffer = NULL;
239         response_code = 421;
240
241         for (i=0; ((i<num_mx)&&((response_code/100)==4)); ++i) {                                // keep trying MXes until one works or we run out
242                 response_code = 421;                                                            // default 421 makes non-protocol errors transient
243                 s.bytes_sent = 0;                                                               // rewind our buffer in case we try multiple MXes
244
245                 curl = curl_easy_init();
246                 if (curl) {
247                         response[0] = 0;
248
249                         if (!IsEmptyStr(envelope_from)) {
250                                 curl_easy_setopt(curl, CURLOPT_MAIL_FROM, envelope_from);
251                         }
252                         else {
253                                 curl_easy_setopt(curl, CURLOPT_MAIL_FROM, fromaddr);
254                         }
255         
256                         recipients = curl_slist_append(recipients, recp);
257                         curl_easy_setopt(curl, CURLOPT_MAIL_RCPT, recipients);
258                         curl_easy_setopt(curl, CURLOPT_READFUNCTION, upload_source);
259                         curl_easy_setopt(curl, CURLOPT_READDATA, &s);
260                         curl_easy_setopt(curl, CURLOPT_UPLOAD, 1);                                              // tell libcurl we are uploading
261                         curl_easy_setopt(curl, CURLOPT_TIMEOUT, 20L);                                           // Time out after 20 seconds
262                         if (CtdlGetConfigInt("c_smtpclient_try_starttls") != 0) {
263                                 curl_easy_setopt(curl, CURLOPT_USE_SSL, CURLUSESSL_TRY);                        // Attempt STARTTLS if offered
264                         }
265                         curl_easy_setopt(curl, CURLOPT_SSL_VERIFYPEER, 0L);
266                         curl_easy_setopt(curl, CURLOPT_SSL_VERIFYHOST, 0L);
267                         // curl_easy_setopt(curl, CURLOPT_ERRORBUFFER, curl_error_buffer);
268                         curl_easy_setopt(curl, CURLOPT_DEBUGFUNCTION, ctdl_libcurl_smtp_debug_callback);
269                         curl_easy_setopt(curl, CURLOPT_DEBUGDATA, (void *)response);
270                         curl_easy_setopt(curl, CURLOPT_VERBOSE, 1L);
271
272                         // Construct an SMTP URL in the form of:
273                         //      smtp[s]://target_host/source_host
274                         // This looks weird but libcurl uses that last part to set our name for EHLO or HELO.
275                         // We check for "smtp://" and "smtps://" because the admin may have put those prefixes in a smart-host entry.
276                         // If there is no prefix we add "smtp://"
277                         extract_token(try_this_mx, mxes, i, '|', (sizeof try_this_mx - 7));
278                         snprintf(smtp_url, sizeof smtp_url,
279                                 "%s%s/%s",
280                                 (((!strncasecmp(try_this_mx, HKEY("smtp://"))) || (!strncasecmp(try_this_mx, HKEY("smtps://")))) ? "" : "smtp://"),
281                                 try_this_mx,
282                                 CtdlGetConfigStr("c_fqdn")
283                         );
284                         curl_easy_setopt(curl, CURLOPT_URL, smtp_url);
285                         syslog(LOG_DEBUG, "smtpclient: trying %s", smtp_url);                           // send the message
286                         res = curl_easy_perform(curl);
287                         curl_easy_getinfo(curl, CURLINFO_RESPONSE_CODE, &response_code);
288                         syslog(LOG_DEBUG, "smtpclient: libcurl returned %d (%s) , SMTP response %ld",
289                                 res, curl_easy_strerror(res), response_code
290                         );
291
292                         if ((res != CURLE_OK) && (response_code == 0)) {                                // check for errors
293                                 response_code = 421;
294                         }
295
296                         curl_slist_free_all(recipients);
297                         recipients = NULL;                                                              // this gets reused; avoid double-free
298                         curl_easy_cleanup(curl);
299                         curl = NULL;                                                                    // this gets reused; avoid double-free
300
301                         /* Trim the error message buffer down to just the actual message */
302                         char response_code_str[4];
303                         snprintf(response_code_str, sizeof response_code_str, "%ld", response_code);
304                         char *respstart = strstr(response, response_code_str);
305                         if (respstart == NULL)
306                         {
307                                 strcpy(response, smtpstatus(response_code));
308                         }
309                         else {
310                                 strcpy(response, respstart);
311                                 char *p;
312                                 for (p=response; *p!=0; ++p)
313                                 {
314                                         if (*p == '\n') *p = ' ';
315                                         if (*p == '\r') *p = ' ';
316                                         if (!isprint(*p)) *p = ' ';
317                                 }
318                         }
319                 }
320         }
321
322         FreeStrBuf(&s.TheMessage);
323         if (fromaddr) free(fromaddr);
324         return((int)response_code);
325 }
326
327
328 /*
329  * Process one outbound message.
330  */
331 void smtp_process_one_msg(long qmsgnum)
332 {
333         struct CtdlMessage *msg = NULL;
334         char *instr = NULL;
335         int i;
336         int num_success = 0;
337         int num_fail = 0;
338         int num_delayed = 0;
339         long deletes[2];
340         int delete_this_queue = 0;
341         char server_response[SIZ];
342
343         msg = CtdlFetchMessage(qmsgnum, 1, 1);
344         if (msg == NULL) {
345                 syslog(LOG_WARNING, "smtpclient: %ld does not exist", qmsgnum);
346                 return;
347         }
348
349         instr = msg->cm_fields[eMesageText];
350         msg->cm_fields[eMesageText] = NULL;
351         CM_Free(msg);
352
353         // if the queue message has any CRLF's convert them to LF's
354         char *crlf = NULL;
355         while (crlf = strstr(instr, "\r\n"), crlf != NULL) {
356                 strcpy(crlf, crlf+1);
357         }
358
359         // Strip out the headers and we are now left with just the instructions.
360         char *soi = strstr(instr, "\n\n");
361         if (soi) {
362                 strcpy(instr, soi+2);
363         }
364
365         long msgid = 0;
366         time_t submitted = time(NULL);
367         time_t attempted = 0;
368         char *bounceto = NULL;
369         char *envelope_from = NULL;
370
371         char cfgline[SIZ];
372         for (i=0; i<num_tokens(instr, '\n'); ++i) {
373                 extract_token(cfgline, instr, i, '\n', sizeof cfgline);
374                 if (!strncasecmp(cfgline, HKEY("msgid|")))              msgid = atol(&cfgline[6]);
375                 if (!strncasecmp(cfgline, HKEY("submitted|")))          submitted = atol(&cfgline[10]);
376                 if (!strncasecmp(cfgline, HKEY("attempted|")))          attempted = atol(&cfgline[10]);
377                 if (!strncasecmp(cfgline, HKEY("bounceto|")))           bounceto = strdup(&cfgline[9]);
378                 if (!strncasecmp(cfgline, HKEY("envelope_from|")))      envelope_from = strdup(&cfgline[14]);
379         }
380
381         int should_try_now = 0;
382         if (attempted < submitted) {                            // If no attempts have been made yet, try now
383                 should_try_now = 1;
384         }
385         else if ((attempted - submitted) <= 14400) {
386                 if ((time(NULL) - attempted) > 1800) {          // First four hours, retry every 30 minutes
387                         should_try_now = 1;
388                 }
389         }
390         else {
391                 if ((time(NULL) - attempted) > 14400) {         // After that, retry once every 4 hours
392                         should_try_now = 1;
393                 }
394         }
395
396         if (should_try_now) {
397                 syslog(LOG_DEBUG, "smtpclient: %ld attempting delivery now", qmsgnum);
398                 StrBuf *NewInstr = NewStrBuf();
399                 StrBufAppendPrintf(NewInstr, "Content-type: "SPOOLMIME"\n\n");
400                 StrBufAppendPrintf(NewInstr, "msgid|%ld\n", msgid);
401                 StrBufAppendPrintf(NewInstr, "submitted|%ld\n", submitted);
402                 if (bounceto) StrBufAppendPrintf(NewInstr, "bounceto|%s\n", bounceto);
403                 if (envelope_from) StrBufAppendPrintf(NewInstr, "envelope_from|%s\n", envelope_from);
404
405                 for (i=0; i<num_tokens(instr, '\n'); ++i) {
406                         extract_token(cfgline, instr, i, '\n', sizeof cfgline);
407                         if (!strncasecmp(cfgline, HKEY("remote|"))) {
408                                 char recp[SIZ];
409                                 int previous_result = extract_int(cfgline, 2);
410                                 if ((previous_result == 0) || (previous_result == 4)) {
411                                         int new_result = 421;
412                                         extract_token(recp, cfgline, 1, '|', sizeof recp);
413                                         new_result = smtp_attempt_delivery(msgid, recp, envelope_from, server_response);
414                                         syslog(LOG_DEBUG, "smtpclient: recp: <%s> , result: %d (%s)", recp, new_result, server_response);
415                                         if ((new_result / 100) == 2) {
416                                                 ++num_success;
417                                         }
418                                         else {
419                                                 if ((new_result / 100) == 5) {
420                                                         ++num_fail;
421                                                 }
422                                                 else {
423                                                         ++num_delayed;
424                                                 }
425                                                 StrBufAppendPrintf(NewInstr, "remote|%s|%ld|%ld (%s)\n",
426                                                         recp, (new_result / 100) , new_result, server_response
427                                                 );
428                                         }
429                                 }
430                         }
431                 }
432
433                 StrBufAppendPrintf(NewInstr, "attempted|%ld\n", time(NULL));
434
435                 // All deliveries have now been attempted.  Now determine the disposition of this queue entry.
436
437                 time_t age = time(NULL) - submitted;
438                 syslog(LOG_DEBUG, "smtpclient: submission age: %ldd%ldh%ldm%lds", (age/86400) , ((age%86400)/3600) , ((age%3600)/60) , (age%60));
439                 syslog(LOG_DEBUG, "smtpclient: num_success=%d , num_fail=%d , num_delayed=%d", num_success, num_fail, num_delayed);
440
441                 // If there are permanent fails on this attempt, deliver a bounce to the user.
442                 // The 5XX fails will be recorded in the rewritten queue, but they will be removed before the next attempt.
443                 if (num_fail > 0) {
444                         smtp_do_bounce(ChrPtr(NewInstr), SDB_BOUNCE_FATALS);
445                 }
446
447                 // If all deliveries have either succeeded or failed, we are finished with this queue entry.
448                 //
449                 if (num_delayed == 0) {
450                         delete_this_queue = 1;
451                 }
452
453                 // If it's been more than five days, give up and tell the sender that delivery failed
454                 //
455                 else if ((time(NULL) - submitted) > SMTP_DELIVER_FAIL) {
456                         smtp_do_bounce(ChrPtr(NewInstr), SDB_BOUNCE_ALL);
457                         delete_this_queue = 1;
458                 }
459
460                 // If it's been more than four hours but less than five days, warn the sender that delivery is delayed
461                 //
462                 else if ( ((attempted - submitted) < SMTP_DELIVER_WARN) && ((time(NULL) - submitted) >= SMTP_DELIVER_WARN) ) {
463                         smtp_do_bounce(ChrPtr(NewInstr), SDB_WARN);
464                 }
465
466                 if (delete_this_queue) {
467                         syslog(LOG_DEBUG, "smtpclient: %ld deleting", qmsgnum);
468                         deletes[0] = qmsgnum;
469                         deletes[1] = msgid;
470                         CtdlDeleteMessages(SMTP_SPOOLOUT_ROOM, deletes, 2, "");
471                         FreeStrBuf(&NewInstr);                                          // We have to free NewInstr here, no longer needed
472                 }
473                 else {
474                         // replace the old queue entry with the new one
475                         syslog(LOG_DEBUG, "smtpclient: %ld rewriting", qmsgnum);
476                         msg = convert_internet_message_buf(&NewInstr);                  // This function will free NewInstr for us
477                         CtdlSubmitMsg(msg, NULL, SMTP_SPOOLOUT_ROOM, 0);
478                         CM_Free(msg);
479                         CtdlDeleteMessages(SMTP_SPOOLOUT_ROOM, &qmsgnum, 1, "");
480                 }
481         }
482         else {
483                 syslog(LOG_DEBUG, "smtpclient: %ld retry time not reached", qmsgnum);
484         }
485
486         if (bounceto != NULL)           free(bounceto);
487         if (envelope_from != NULL)      free(envelope_from);
488         free(instr);
489 }
490
491
492 /*
493  * Callback for smtp_do_queue()
494  */
495 void smtp_add_msg(long msgnum, void *userdata) {
496
497         if (smtpq == NULL) {
498                 smtpq_count = 0;
499                 smtpq_alloc = 100;
500                 smtpq = malloc(smtpq_alloc * sizeof(long));
501         }
502
503         if (smtpq_alloc >= smtpq_count) {
504                 smtpq_alloc += 100;
505                 smtpq = realloc(smtpq, (smtpq_alloc * sizeof(long)));
506         }
507
508         smtpq[smtpq_count++] = msgnum;
509 }
510
511
512 /*
513  * Run through the queue sending out messages.
514  */
515 void smtp_do_queue(void) {
516         int i = 0;
517
518         /*
519          * This is a simple concurrency check to make sure only one smtpclient
520          * run is done at a time.  We could do this with a mutex, but since we
521          * don't really require extremely fine granularity here, we'll do it
522          * with a static variable instead.
523          */
524         if (doing_smtpclient) return;
525         doing_smtpclient = 1;
526
527         syslog(LOG_DEBUG, "smtpclient: start queue run");
528         pthread_setspecific(MyConKey, (void *)&smtp_client_CC);
529
530         if (CtdlGetRoom(&CC->room, SMTP_SPOOLOUT_ROOM) != 0) {
531                 syslog(LOG_WARNING, "Cannot find room <%s>", SMTP_SPOOLOUT_ROOM);
532                 doing_smtpclient = 0;
533                 return;
534         }
535
536         // Put the queue in memory so we can close the db cursor
537         CtdlForEachMessage(MSGS_ALL, 0L, NULL, SPOOLMIME, NULL, smtp_add_msg, NULL);
538
539         // We are ready to run through the queue now.
540         for (i=0; i<smtpq_count; ++i) {
541                 smtp_process_one_msg(smtpq[i]);
542         }
543
544         smtpq_count = 0;                // don't free it, we will use this memory on the next run
545         doing_smtpclient = 0;
546         syslog(LOG_DEBUG, "smtpclient: end queue run");
547 }
548
549
550 /*
551  * Module entry point
552  */
553 CTDL_MODULE_INIT(smtpclient)
554 {
555         if (!threading)
556         {
557                 CtdlFillSystemContext(&smtp_client_CC, "SMTP_Send");
558                 CtdlRegisterMessageHook(smtp_aftersave, EVT_AFTERSAVE);
559                 CtdlRegisterSessionHook(smtp_do_queue, EVT_TIMER, PRIO_AGGR + 50);
560                 smtp_init_spoolout();
561         }
562
563         /* return our module id for the log */
564         return "smtpclient";
565 }