diff --git a/configs/net_smtp.conf b/configs/net_smtp.conf index 605235e..88f0f46 100644 --- a/configs/net_smtp.conf +++ b/configs/net_smtp.conf @@ -48,6 +48,13 @@ addreceivedmsa=no ; Whether to include the sender's IP address in the Received notifyextfirstmsg=yes ; Whether to send an email to a user's external email address when his/her mailbox is first created. ; Default is yes. +; SMTP log file configuration. +; This log contains SMTP transaction info in a concise log for archival or debugging purposes. +; Nitty gritty low-level details are only present in the regular BBS debug messages. +[logging] +logfile=/var/log/lbbs/smtp.log ; SMTP logfile. If set, SMTP messages up to the SMTP log level will be logged to this file. +loglevel=5 ; Log level from 0 to 10 (maximum debug). Default is 5. + [authorized_relays] ; Define remote hosts that are allowed to relay outgoing mail using this server as a smart host. ; Configure each authorized relay as an IP/hostname/CIDR range and a list of domains or subdomains for which they are authorized to relay mail. ; If a connection matches multiple entries, the relay is allowed as long as it matches one of the entries. diff --git a/include/net_smtp.h b/include/net_smtp.h index 03a555c..859737c 100644 --- a/include/net_smtp.h +++ b/include/net_smtp.h @@ -24,6 +24,8 @@ struct smtp_session; +void __attribute__ ((format (gnu_printf, 3, 4))) bbs_smtp_log(int level, struct smtp_session *smtp, const char *fmt, ...); + /*! \brief Get the SMTP hostname of the local SMTP server, suitable for use in HELO/EHLO */ const char *smtp_hostname(void); diff --git a/modules/mod_mail_events.c b/modules/mod_mail_events.c index 394c2f9..cc026b4 100644 --- a/modules/mod_mail_events.c +++ b/modules/mod_mail_events.c @@ -210,6 +210,7 @@ static void mbox_event_callback(struct mailbox_event *event) pthread_mutex_lock(&loglock); log_cb(event); pthread_mutex_unlock(&loglock); + fflush(fp); /* Explicitly flush to disk so it immediately appears in the logfile. */ } static int load_config(void) diff --git a/modules/mod_smtp_delivery_external.c b/modules/mod_smtp_delivery_external.c index c90b58c..9122a22 100644 --- a/modules/mod_smtp_delivery_external.c +++ b/modules/mod_smtp_delivery_external.c @@ -38,6 +38,7 @@ #include "include/linkedlists.h" #include "include/oauth.h" #include "include/base64.h" +#include "include/cli.h" #include "include/mod_mail.h" #include "include/net_smtp.h" @@ -612,50 +613,46 @@ static void smtp_trigger_dsn(enum smtp_delivery_action action, struct smtp_tx_da } } -static int on_queue_file(const char *dir_name, const char *filename, void *obj) -{ +#define MAILQ_FILENAME_SIZE 516 + +struct mailq_file { FILE *fp; - char fullname[516], newname[sizeof(fullname) + 11]; - char from[1000], recipient[1000], todup[256]; - char *hostname; + unsigned long size; + size_t metalen; char *realfrom, *realto; char *user, *domain; char *retries; int newretries; - int res = -1; - unsigned long size; - size_t metalen; - char buf[256] = ""; - struct stringlist mxservers; struct tm created; - struct stat st; - struct smtp_tx_data tx; - - UNUSED(obj); - memset(&tx, 0, sizeof(tx)); + char fullname[MAILQ_FILENAME_SIZE]; + char from[1000], recipient[1000], todup[256]; +}; - snprintf(fullname, sizeof(fullname), "%s/%s", dir_name, filename); +static int mailq_file_load(struct mailq_file *restrict mqf, const char *dir_name, const char *filename) +{ + struct stat st; - fp = fopen(fullname, "r"); - if (!fp) { - bbs_error("Failed to open %s: %s\n", fullname, strerror(errno)); - return 0; + snprintf(mqf->fullname, sizeof(mqf->fullname), "%s/%s", dir_name, filename); + mqf->fp = fopen(mqf->fullname, "r"); + if (!mqf->fp) { + bbs_error("Failed to open %s: %s\n", mqf->fullname, strerror(errno)); + return -1; } - fseek(fp, 0L, SEEK_END); /* Go to EOF */ - size = (long unsigned) ftell(fp); - rewind(fp); /* Be kind, rewind */ + fseek(mqf->fp, 0L, SEEK_END); /* Go to EOF */ + mqf->size = (long unsigned) ftell(mqf->fp); + rewind(mqf->fp); /* Be kind, rewind */ - if (!fgets(from, sizeof(from), fp) || !fgets(recipient, sizeof(recipient), fp)) { - bbs_error("Failed to read metadata from %s\n", fullname); + if (!fgets(mqf->from, sizeof(mqf->from), mqf->fp) || !fgets(mqf->recipient, sizeof(mqf->recipient), mqf->fp)) { + bbs_error("Failed to read metadata from %s\n", mqf->fullname); goto cleanup; } - metalen = strlen(from) + strlen(recipient); /* This already includes the newlines */ + mqf->metalen = strlen(mqf->from) + strlen(mqf->recipient); /* This already includes the newlines */ - retries = strchr(fullname, '.'); - if (!retries++ || strlen_zero(retries)) { /* Shouldn't happen for mail queue files legitimately generated by this module, but somebody else might have dumped stuff in. */ - bbs_error("File name '%s' is non-compliant with our filename format\n", fullname); + mqf->retries = strchr(mqf->fullname, '.'); + if (!mqf->retries++ || strlen_zero(mqf->retries)) { /* Shouldn't happen for mail queue files legitimately generated by this module, but somebody else might have dumped stuff in. */ + bbs_error("File name '%s' is non-compliant with our filename format\n", mqf->fullname); goto cleanup; } @@ -669,49 +666,91 @@ static int on_queue_file(const char *dir_name, const char *filename, void *obj) * we'll only see LF . CR LF at the end, and delivery will thus fail. * Do not modify the mail queue files manually for debugging, unless you really know what you are doing, * and in particular are preserving the mixed line endings. */ - bbs_term_line(from); - bbs_term_line(recipient); + bbs_term_line(mqf->from); + bbs_term_line(mqf->recipient); - realfrom = strchr(from, '<'); - realto = strchr(recipient, '<'); + mqf->realfrom = strchr(mqf->from, '<'); + mqf->realto = strchr(mqf->recipient, '<'); - if (!realfrom) { - bbs_error("Mail queue file MAIL FROM missing <>: %s\n", fullname); + if (!mqf->realfrom) { + bbs_error("Mail queue file MAIL FROM missing <>: %s\n", mqf->fullname); goto cleanup; - } else if (!realto) { - bbs_error("Mail queue file RCPT TO missing <>: %s\n", fullname); + } else if (!mqf->realto) { + bbs_error("Mail queue file RCPT TO missing <>: %s\n", mqf->fullname); goto cleanup; } - realfrom++; /* Skip < */ - if (strlen_zero(realfrom)) { - bbs_error("Malformed MAIL FROM: %s\n", fullname); + mqf->realfrom++; /* Skip < */ + if (strlen_zero(mqf->realfrom)) { + bbs_error("Malformed MAIL FROM: %s\n", mqf->fullname); goto cleanup; } - bbs_strterm(realfrom, '>'); /* try_send will add <> for us, so strip it here to match */ + bbs_strterm(mqf->realfrom, '>'); /* try_send will add <> for us, so strip it here to match */ - if (bbs_str_count(realfrom, '<') || bbs_str_count(realfrom, '>') || bbs_str_count(realto, '<') != 1 || bbs_str_count(realto, '>') != 1) { - bbs_error("Sender or recipient address malformed %s -> %s\n", realfrom, realto); + if (bbs_str_count(mqf->realfrom, '<') || bbs_str_count(mqf->realfrom, '>') || bbs_str_count(mqf->realto, '<') != 1 || bbs_str_count(mqf->realto, '>') != 1) { + bbs_error("Sender or recipient address malformed %s -> %s\n", mqf->realfrom, mqf->realto); goto cleanup; } - bbs_debug(5, "Processing message from %s -> %s\n", realfrom, realto); - safe_strncpy(todup, realto, sizeof(todup)); - if (strlen_zero(realfrom) || bbs_parse_email_address(todup, NULL, &user, &domain)) { + safe_strncpy(mqf->todup, mqf->realto, sizeof(mqf->todup)); + if (strlen_zero(mqf->realfrom) || bbs_parse_email_address(mqf->todup, NULL, &mqf->user, &mqf->domain)) { bbs_error("Address parsing error\n"); goto cleanup; } - bbs_debug(2, "Retrying delivery of %s (%s -> %s)\n", fullname, realfrom, realto); - memset(&created, 0, sizeof(created)); - if (stat(fullname, &st)) { - bbs_error("stat(%s) failed: %s\n", fullname, strerror(errno)); + memset(&mqf->created, 0, sizeof(mqf->created)); + if (stat(mqf->fullname, &st)) { + bbs_error("stat(%s) failed: %s\n", mqf->fullname, strerror(errno)); } else { - localtime_r(&st.st_mtim.tv_sec, &created); + localtime_r(&st.st_mtim.tv_sec, &mqf->created); + } + + return 0; + +cleanup: + fclose(mqf->fp); + mqf->fp = NULL; + return -1; +} + +static int mailq_file_punt(struct mailq_file *mqf) +{ + char newname[MAILQ_FILENAME_SIZE + 11]; + char tmpbuf[256]; + + bbs_strncpy_until(tmpbuf, mqf->fullname, sizeof(tmpbuf), '.'); + /* Store retry information in the filename itself, so we don't have to modify the file, we can just rename it. Inspired by IMAP. */ + snprintf(newname, sizeof(newname), "%s.%d", tmpbuf, mqf->newretries); + if (rename(mqf->fullname, newname)) { + bbs_error("Failed to rename %s to %s\n", mqf->fullname, newname); + return -1; + } + return 0; +} + +static int on_queue_file(const char *dir_name, const char *filename, void *obj) +{ + int res = -1; + char *hostname; + char buf[256] = ""; + struct stringlist mxservers; + struct smtp_tx_data tx; + struct mailq_file mqf_stack, *mqf = &mqf_stack; + + UNUSED(obj); + + memset(&mqf_stack, 0, sizeof(mqf_stack)); + memset(&tx, 0, sizeof(tx)); + + if (mailq_file_load(&mqf_stack, dir_name, filename)) { + return 0; } + bbs_debug(5, "Processing message from %s -> %s\n", mqf->realfrom, mqf->realto); + bbs_debug(2, "Retrying delivery of %s (%s -> %s)\n", mqf->fullname, mqf->realfrom, mqf->realto); + memset(&mxservers, 0, sizeof(mxservers)); - res = lookup_mx_all(domain, &mxservers); + res = lookup_mx_all(mqf->domain, &mxservers); if (res == -2) { smtp_tx_data_reset(&tx); /* Do not set tx.hostname, since this message is from us, not the remote server */ @@ -720,68 +759,64 @@ static int on_queue_file(const char *dir_name, const char *filename, void *obj) if (res) { char a_ip[256]; /* Fall back to trying the A record */ - if (bbs_resolve_hostname(domain, a_ip, sizeof(a_ip))) { - bbs_warning("Recipient domain %s does not have any MX or A records\n", domain); + if (bbs_resolve_hostname(mqf->domain, a_ip, sizeof(a_ip))) { + bbs_warning("Recipient domain %s does not have any MX or A records\n", mqf->domain); /* Just treat as undeliverable at this point and return to sender (if no MX records now, probably won't be any the next time we try) */ /* Send a delivery failure response, then delete the file. */ - bbs_warning("Delivery of message %s from %s to %s has failed permanently (no MX records)\n", fullname, realfrom, realto); + bbs_warning("Delivery of message %s from %s to %s has failed permanently (no MX records)\n", mqf->fullname, mqf->realfrom, mqf->realto); /* There isn't any SMTP level error at this point yet, we have to make our own error message for the bounce message */ - snprintf(buf, sizeof(buf), "No MX record(s) located for hostname %s", domain); /* No status code */ + snprintf(buf, sizeof(buf), "No MX record(s) located for hostname %s", mqf->domain); /* No status code */ smtp_tx_data_reset(&tx); /* Do not set tx.hostname, since this message is from us, not the remote server */ - smtp_trigger_dsn(DELIVERY_FAILED, &tx, &created, realfrom, realto, buf, fileno(fp), metalen, size - metalen); - fclose(fp); - bbs_delete_file(fullname); + smtp_trigger_dsn(DELIVERY_FAILED, &tx, &mqf->created, mqf->realfrom, mqf->realto, buf, fileno(mqf->fp), mqf->metalen, mqf->size - mqf->metalen); + fclose(mqf->fp); + bbs_delete_file(mqf->fullname); return 0; } - bbs_warning("Recipient domain %s does not have any MX records, falling back to A record %s\n", domain, a_ip); + bbs_warning("Recipient domain %s does not have any MX records, falling back to A record %s\n", mqf->domain, a_ip); stringlist_push(&mxservers, a_ip); } /* Try all the MX servers in order, if necessary */ res = -1; /* Make condition true to start */ while (res < 0 && (hostname = stringlist_pop(&mxservers))) { - res = try_send(NULL, &tx, hostname, DEFAULT_SMTP_PORT, 0, NULL, NULL, realfrom, realto, NULL, NULL, 0, fileno(fp), (off_t) metalen, size - metalen, buf, sizeof(buf)); + res = try_send(NULL, &tx, hostname, DEFAULT_SMTP_PORT, 0, NULL, NULL, mqf->realfrom, mqf->realto, NULL, NULL, 0, fileno(mqf->fp), (off_t) mqf->metalen, mqf->size - mqf->metalen, buf, sizeof(buf)); free(hostname); } stringlist_empty(&mxservers); } - newretries = atoi(retries); /* This is actually current # of retries, not new # yet */ + mqf->newretries = atoi(mqf->retries); /* This is actually current # of retries, not new # yet */ if (!res) { /* Successful delivery. */ - bbs_debug(6, "Delivery successful after %d attempt%s, discarding queue file\n", newretries, ESS(newretries)); - smtp_trigger_dsn(DELIVERY_DELIVERED, &tx, &created, realfrom, realto, buf, fileno(fp), metalen, size - metalen); - fclose(fp); - bbs_delete_file(fullname); + bbs_debug(6, "Delivery successful after %d attempt%s, discarding queue file\n", mqf->newretries, ESS(mqf->newretries)); + bbs_smtp_log(4, NULL, "Delivery succeeded after queuing: %s -> %s\n", mqf->realfrom, mqf->realto); + smtp_trigger_dsn(DELIVERY_DELIVERED, &tx, &mqf->created, mqf->realfrom, mqf->realto, buf, fileno(mqf->fp), mqf->metalen, mqf->size - mqf->metalen); + fclose(mqf->fp); + bbs_delete_file(mqf->fullname); return 0; } - newretries++; /* Now it's the new number */ - bbs_debug(3, "Delivery of %s to %s has been attempted %d/%d times\n", fullname, realto, newretries, max_retries); - if (res == -2 || res > 0 || newretries >= (int) max_retries) { + mqf->newretries++; /* Now it's the new number */ + bbs_debug(3, "Delivery of %s to %s has been attempted %d/%d times\n", mqf->fullname, mqf->realto, mqf->newretries, max_retries); + if (res == -2 || res > 0 || mqf->newretries >= (int) max_retries) { /* Send a delivery failure response, then delete the file. */ - bbs_warning("Delivery of message %s from %s to %s has failed permanently after %d retries\n", fullname, realfrom, realto, newretries); + bbs_warning("Delivery of message %s from %s to %s has failed permanently after %d retries\n", mqf->fullname, mqf->realfrom, mqf->realto, mqf->newretries); + bbs_smtp_log(1, NULL, "Delivery failed permanently after queuing: %s -> %s\n", mqf->realfrom, mqf->realto); /* To the dead letter office we go */ /* XXX buf will only contain the last line of the SMTP transaction, since it was using the readline buffer * Thus, if we got a multiline error, only the last line is currently included in the non-delivery report */ - smtp_trigger_dsn(DELIVERY_FAILED, &tx, &created, realfrom, realto, buf, fileno(fp), metalen, size - metalen); - fclose(fp); - bbs_delete_file(fullname); + smtp_trigger_dsn(DELIVERY_FAILED, &tx, &mqf->created, mqf->realfrom, mqf->realto, buf, fileno(mqf->fp), mqf->metalen, mqf->size - mqf->metalen); + fclose(mqf->fp); + bbs_delete_file(mqf->fullname); return 0; } else { - char tmpbuf[256]; - bbs_strncpy_until(tmpbuf, fullname, sizeof(tmpbuf), '.'); - /* Store retry information in the filename itself, so we don't have to modify the file, we can just rename it. Inspired by IMAP. */ - snprintf(newname, sizeof(newname), "%s.%d", tmpbuf, newretries); - if (rename(fullname, newname)) { - bbs_error("Failed to rename %s to %s\n", fullname, newname); - } - smtp_trigger_dsn(DELIVERY_DELAYED, &tx, &created, realfrom, realto, buf, fileno(fp), metalen, size - metalen); + bbs_smtp_log(3, NULL, "Delivery delayed after queuing: %s -> %s\n", mqf->realfrom, mqf->realto); + mailq_file_punt(mqf); /* Try again later */ + smtp_trigger_dsn(DELIVERY_DELAYED, &tx, &mqf->created, mqf->realfrom, mqf->realto, buf, fileno(mqf->fp), mqf->metalen, mqf->size - mqf->metalen); } -cleanup: - fclose(fp); + fclose(mqf->fp); return 0; } @@ -817,6 +852,48 @@ static void *queue_handler(void *unused) return NULL; } +static int on_queue_file_cli_mailq(const char *dir_name, const char *filename, void *obj) +{ + struct bbs_cli_args *a = obj; + struct mailq_file mqf_stack, *mqf = &mqf_stack; + char arrival_date[64]; + + memset(&mqf_stack, 0, sizeof(mqf_stack)); + + if (mailq_file_load(&mqf_stack, dir_name, filename)) { + return 0; + } + + strftime(arrival_date, sizeof(arrival_date), "%a, %d %b %Y %H:%M:%S %z", &mqf->created); + + /* Ensure the format is synchronized with the heading in cli_mailq */ + bbs_dprintf(a->fdout, "%-25s %-30s %7d %-30s %s\n", arrival_date, filename, mqf->newretries, mqf->realfrom, mqf->realto); + return 0; +} + +static int cli_mailq(struct bbs_cli_args *a) +{ + bbs_dprintf(a->fdout, "%-25s %-30s %7s %-30s %s\n", "Orig Date", "Filename", "Retries", "Sender", "Recipient"); + pthread_mutex_lock(&queue_lock); + bbs_dir_traverse(queue_dir, on_queue_file_cli_mailq, a, -1); + pthread_mutex_unlock(&queue_lock); + return 0; +} + +static int cli_runq(struct bbs_cli_args *a) +{ + UNUSED(a); + pthread_mutex_lock(&queue_lock); + bbs_dir_traverse(queue_dir, on_queue_file, NULL, -1); + pthread_mutex_unlock(&queue_lock); + return 0; +} + +static struct bbs_cli_entry cli_commands_mailq[] = { + BBS_CLI_COMMAND(cli_mailq, "mailq", 1, "Show the current mail queue", NULL), + BBS_CLI_COMMAND(cli_runq, "runq", 1, "Retry delivery of all messages in the mail queue", NULL), +}; + /*! \note Enable a workaround for socket connects to mail servers failing if we try to send them synchronously. This effectively always enables sendasync=yes. */ #define BUGGY_SEND_IMMEDIATE @@ -1127,6 +1204,7 @@ static int load_module(void) pthread_mutex_destroy(&queue_lock); return -1; } + bbs_cli_register_multiple(cli_commands_mailq); return smtp_register_delivery_handler(&extdeliver, 90); /* Lowest priority */ } @@ -1134,6 +1212,7 @@ static int unload_module(void) { int res; res = smtp_unregister_delivery_agent(&extdeliver); + bbs_cli_unregister_multiple(cli_commands_mailq); bbs_pthread_cancel_kill(queue_thread); bbs_pthread_join(queue_thread, NULL); pthread_mutex_destroy(&queue_lock); diff --git a/nets/net_imap.c b/nets/net_imap.c index bdfea6f..6904539 100644 --- a/nets/net_imap.c +++ b/nets/net_imap.c @@ -139,6 +139,7 @@ #include "include/oauth.h" #include "include/base64.h" #include "include/range.h" +#include "include/cli.h" #include "include/mod_mail.h" @@ -240,6 +241,55 @@ static const char *preauth_username_match(const char *ipaddr) static RWLIST_HEAD_STATIC(sessions, imap_session); +static int cli_imap_sessions(struct bbs_cli_args *a) +{ + struct imap_session *imap; + + bbs_dprintf(a->fdout, "%4s %-25s %-25s %7s %s\n", "Node", "Current Mailbox", "Current Folder", "Proxied", "Client ID"); + RWLIST_RDLOCK(&sessions); + RWLIST_TRAVERSE(&sessions, imap, entry) { + char mbox_buf[32]; + const char *mbox_name = NULL; + if (imap->mbox) { + mbox_name = mailbox_name(imap->mbox); + if (!mbox_name) { + snprintf(mbox_buf, sizeof(mbox_buf), "%u", mailbox_id(imap->mbox)); + mbox_name = mbox_buf; + } + } + bbs_dprintf(a->fdout, "%4u %-25s %-25s %7s %s\n", + imap->node->id, S_IF(mbox_name), S_IF(imap->folder), imap->client ? "Yes" : "No", S_IF(imap->clientid)); + } + RWLIST_UNLOCK(&sessions); + return 0; +} + +static int cli_imap_clients(struct bbs_cli_args *a) +{ + struct imap_session *imap; + time_t now = time(NULL); + + bbs_dprintf(a->fdout, "%4s %-25s %6s %4s %9s\n", "Node", "Name", "Active", "Dead", "Idle"); + RWLIST_RDLOCK(&sessions); + RWLIST_TRAVERSE(&sessions, imap, entry) { + struct imap_client *client; + RWLIST_RDLOCK(&imap->clients); + RWLIST_TRAVERSE(&imap->clients, client, entry) { + time_t idle_elapsed = now - client->idlestarted; + bbs_dprintf(a->fdout, "%4u %-25s %6s %4s %4lu/%4d\n", + imap->node->id, client->name, BBS_YN(client->active), BBS_YN(client->dead), client->idling ? idle_elapsed : 0, client->maxidlesec); + } + RWLIST_UNLOCK(&imap->clients); + } + RWLIST_UNLOCK(&sessions); + return 0; +} + +static struct bbs_cli_entry cli_commands_imap[] = { + BBS_CLI_COMMAND(cli_imap_sessions, "imap sessions", 2, "List IMAP client sessions", NULL), + BBS_CLI_COMMAND(cli_imap_clients, "imap clients", 2, "List outbound IMAP client proxies", NULL), +}; + static inline void reset_saved_search(struct imap_session *imap) { free_if(imap->savedsearch); /* See comments about EXPUNGE in imap_expunge */ @@ -4812,6 +4862,7 @@ static int load_module(void) bbs_register_tests(tests); mailbox_register_watcher(imap_mbox_watcher); bbs_register_alerter(alertmsg, 90); + bbs_cli_register_multiple(cli_commands_imap); return 0; abort: @@ -4821,6 +4872,7 @@ static int load_module(void) static int unload_module(void) { + bbs_cli_unregister_multiple(cli_commands_imap); bbs_unregister_alerter(alertmsg); bbs_unregister_tests(tests); mailbox_unregister_watcher(imap_mbox_watcher); diff --git a/nets/net_smtp.c b/nets/net_smtp.c index 9d6f706..326d1a2 100644 --- a/nets/net_smtp.c +++ b/nets/net_smtp.c @@ -85,6 +85,10 @@ static int validatespf = 1; static int add_received_msa = 0; static int archivelists = 1; +static FILE *smtplogfp = NULL; +static unsigned int smtp_log_level = 5; +static pthread_mutex_t loglock = PTHREAD_MUTEX_INITIALIZER; + /*! \brief Max message size, in bytes */ static unsigned int max_message_size = 300000; @@ -100,6 +104,36 @@ static unsigned int max_message_size = 300000; /*! \brief Non-final SMTP response (subsequent responses with the same code follow) */ #define smtp_reply0_nostatus(smtp, code, fmt, ...) _smtp_reply(smtp, "%d-" fmt "\r\n", code, ## __VA_ARGS__) +void bbs_smtp_log(int level, struct smtp_session *smtp, const char *fmt, ...) +{ + va_list ap; + char datestr[20]; + time_t lognow; + struct tm logdate; + struct timeval now; + + if (!smtplogfp || (unsigned int) level > smtp_log_level) { /* This is static to this file, so we can't do this in a macro. */ + return; + } + +#pragma GCC diagnostic ignored "-Waggregate-return" + now = bbs_tvnow(); +#pragma GCC diagnostic pop + lognow = time(NULL); + localtime_r(&lognow, &logdate); + strftime(datestr, sizeof(datestr), "%Y-%m-%d %T", &logdate); + + pthread_mutex_lock(&loglock); + fprintf(smtplogfp, "[%s.%03d] %p: ", datestr, (int) now.tv_usec / 1000, smtp); + + va_start(ap, fmt); + vfprintf(smtplogfp, fmt, ap); + va_end(ap); + + pthread_mutex_unlock(&loglock); + fflush(smtplogfp); +} + /* * Wikipedia sums up the difference between MTAs/MSAs very nicely, if the difference is confusing: * @@ -1707,6 +1741,7 @@ static int expand_and_deliver(struct smtp_session *smtp, const char *filename, s } if (mres == 1) { /* Delivery or queuing to this recipient succeeded */ + bbs_smtp_log(4, smtp, "Delivery succeeded or queued: %s -> %s\n", smtp->from, recipient); succeeded++; } else if (res < 0) { /* Includes if the message has no handler */ /* Process any error message before unlocking the list. @@ -1714,6 +1749,7 @@ static int expand_and_deliver(struct smtp_session *smtp, const char *filename, s * just for one of the recipients (otherwise we might send multiple SMTP responses). * Instead, we have to send a bounce message. * If this is the only recipient, we can bounce at the SMTP level. */ + bbs_smtp_log(2, smtp, "Delivery failed: %s -> %s\n", smtp->from, recipient); if (total > 1) { char bouncemsg[512]; struct smtp_delivery_outcome *f; @@ -2074,6 +2110,7 @@ static int do_deliver(struct smtp_session *smtp, const char *filename, size_t da res = h->agent->relay(smtp, &mproc, srcfd, datalen, &smtp->recipients); bbs_module_unref(h->mod, 6); if (!res) { + bbs_smtp_log(4, smtp, "Outgoing message successfully relayed for submission: MAIL FROM %s\n", smtp->from); break; } } @@ -2085,6 +2122,7 @@ static int do_deliver(struct smtp_session *smtp, const char *filename, size_t da smtp_reply(smtp, 250, 2.6.0, "Message accepted for relay"); } else { /* XXX If we couldn't relay it immediately, don't queue it, just reject it */ + bbs_smtp_log(4, smtp, "Relay rejected: MAIL FROM %s\n", smtp->from); smtp_reply(smtp, 550, 5.7.0, "Mail relay rejected."); if (!s_strlen_zero(newfile)) { /* This is the one case where it's convenient to clean up, so we do so. @@ -2617,6 +2655,7 @@ static struct bbs_cli_entry cli_commands_smtp[] = { static int load_config(void) { + char smtp_log_file[256]; struct bbs_config *cfg; struct bbs_config_section *section = NULL; @@ -2668,6 +2707,14 @@ static int load_config(void) } } + if (!bbs_config_val_set_str(cfg, "logging", "logfile", smtp_log_file, sizeof(smtp_log_file))) { + smtplogfp = fopen(smtp_log_file, "a"); + if (!smtplogfp) { + bbs_error("Failed to open SMTP log file for appending: %s\n", smtp_log_file); + } + bbs_config_val_set_uint(cfg, "logging", "loglevel", &smtp_log_level); + } + return 0; } @@ -2735,6 +2782,9 @@ static int unload_module(void) if (!RWLIST_EMPTY(&filters)) { bbs_error("Filter(s) still registered at unload?\n"); } + if (smtplogfp) { + fclose(smtplogfp); + } return 0; }