X-Git-Url: https://vcs.fsf.org/?p=exim.git;a=blobdiff_plain;f=src%2Fsrc%2Fdeliver.c;h=1748c798511ffad9fb929b41cd6091f6efb8ef89;hp=59fbeeaf9a18bc69694c1996a3e0970d114cac58;hb=4b01271fa595a08e68ba8c58d6404e83623aa9c8;hpb=2944124ccb62cbf64e44bc8e0894fb30307514da diff --git a/src/src/deliver.c b/src/src/deliver.c index 59fbeeaf9..1748c7985 100644 --- a/src/src/deliver.c +++ b/src/src/deliver.c @@ -220,7 +220,9 @@ if (!addr->next) deliver_localpart = addr->local_part; deliver_localpart_prefix = addr->prefix; + deliver_localpart_prefix_v = addr->prefix_v; deliver_localpart_suffix = addr->suffix; + deliver_localpart_suffix_v = addr->suffix_v; for (addr_orig = addr; addr_orig->parent; addr_orig = addr_orig->parent) ; deliver_domain_orig = addr_orig->domain; @@ -260,7 +262,9 @@ if (!addr->next) else if (deliver_localpart[0] == '|') address_pipe = addr->local_part; deliver_localpart = addr->parent->local_part; deliver_localpart_prefix = addr->parent->prefix; + deliver_localpart_prefix_v = addr->parent->prefix_v; deliver_localpart_suffix = addr->parent->suffix; + deliver_localpart_suffix_v = addr->parent->suffix_v; } } @@ -328,6 +332,10 @@ Returns: a file descriptor, or -1 (with errno set) static int open_msglog_file(uschar *filename, int mode, uschar **error) { +if (Ustrstr(filename, US"/../")) + log_write(0, LOG_MAIN|LOG_PANIC, + "Attempt to open msglog file path with upward-traversal: '%s'\n", filename); + for (int i = 2; i > 0; i--) { int fd = Uopen(filename, @@ -425,7 +433,7 @@ for (address_item * addr2 = addr->next; addr2; addr2 = addr2->next) addr2->transport_return = addr->transport_return; addr2->basic_errno = addr->basic_errno; addr2->more_errno = addr->more_errno; - addr2->delivery_usec = addr->delivery_usec; + addr2->delivery_time = addr->delivery_time; addr2->special_action = addr->special_action; addr2->message = addr->message; addr2->user_message = addr->user_message; @@ -1088,42 +1096,6 @@ return g; -void -timesince(struct timeval * diff, struct timeval * then) -{ -gettimeofday(diff, NULL); -diff->tv_sec -= then->tv_sec; -if ((diff->tv_usec -= then->tv_usec) < 0) - { - diff->tv_sec--; - diff->tv_usec += 1000*1000; - } -} - - - -uschar * -string_timediff(struct timeval * diff) -{ -static uschar buf[sizeof("0.000s")]; - -if (diff->tv_sec >= 5 || !LOGGING(millisec)) - return readconf_printtime((int)diff->tv_sec); - -sprintf(CS buf, "%u.%03us", (uint)diff->tv_sec, (uint)diff->tv_usec/1000); -return buf; -} - - -uschar * -string_timesince(struct timeval * then) -{ -struct timeval diff; - -timesince(&diff, then); -return string_timediff(&diff); -} - /******************************************************************************/ @@ -1253,7 +1225,7 @@ else { if (testflag(addr, af_pipelining)) g = string_catn(g, US" L", 2); -#ifdef SUPPORT_PIPE_CONNECT +#ifndef DISABLE_PIPE_CONNECT if (testflag(addr, af_early_pipe)) g = string_catn(g, US"*", 1); #endif @@ -1296,10 +1268,7 @@ if (LOGGING(queue_time)) string_timesince(&received_time)); if (LOGGING(deliver_time)) - { - struct timeval diff = {.tv_sec = addr->more_errno, .tv_usec = addr->delivery_usec}; - g = string_append(g, 2, US" DT=", string_timediff(&diff)); - } + g = string_append(g, 2, US" DT=", string_timediff(&addr->delivery_time)); /* string_cat() always leaves room for the terminator. Release the store we used to build the line after writing it. */ @@ -1367,6 +1336,9 @@ if (addr->host_used) } } +if (LOGGING(deliver_time)) + g = string_append(g, 2, US" DT=", string_timediff(&addr->delivery_time)); + if (addr->message) g = string_append(g, 2, US": ", addr->message); @@ -1446,6 +1418,9 @@ if (addr->basic_errno > 0) if (addr->message) g = string_append(g, 2, US": ", addr->message); +if (LOGGING(deliver_time)) + g = string_append(g, 2, US" DT=", string_timediff(&addr->delivery_time)); + (void) string_from_gstring(g); /* Do the logging. For the message log, "routing failed" for those cases, @@ -1642,6 +1617,7 @@ if (result == OK) tls_out.peercert = addr->peercert; addr->peercert = NULL; + tls_out.ver = addr->tlsver; tls_out.cipher = addr->cipher; tls_out.peerdn = addr->peerdn; tls_out.ocsp = addr->ocsp; @@ -1655,6 +1631,7 @@ if (result == OK) #ifndef DISABLE_TLS tls_free_cert(&tls_out.ourcert); tls_free_cert(&tls_out.peercert); + tls_out.ver = NULL; tls_out.cipher = NULL; tls_out.peerdn = NULL; tls_out.ocsp = OCSP_NOT_REQ; @@ -2291,7 +2268,7 @@ a clean slate and doesn't interfere with the parent process. */ search_tidyup(); -if ((pid = fork()) == 0) +if ((pid = exim_fork(US"delivery-local")) == 0) { BOOL replicate = TRUE; @@ -2437,7 +2414,7 @@ if ((pid = fork()) == 0) || (ret = write(pfd[pipe_write], &addr2->flags, sizeof(addr2->flags))) != sizeof(addr2->flags) || (ret = write(pfd[pipe_write], &addr2->basic_errno, sizeof(int))) != sizeof(int) || (ret = write(pfd[pipe_write], &addr2->more_errno, sizeof(int))) != sizeof(int) - || (ret = write(pfd[pipe_write], &addr2->delivery_usec, sizeof(int))) != sizeof(int) + || (ret = write(pfd[pipe_write], &addr2->delivery_time, sizeof(struct timeval))) != sizeof(struct timeval) || (ret = write(pfd[pipe_write], &addr2->special_action, sizeof(int))) != sizeof(int) || (ret = write(pfd[pipe_write], &addr2->transport, sizeof(transport_instance *))) != sizeof(transport_instance *) @@ -2505,7 +2482,7 @@ for (addr2 = addr; addr2; addr2 = addr2->next) len = read(pfd[pipe_read], &addr2->flags, sizeof(addr2->flags)); len = read(pfd[pipe_read], &addr2->basic_errno, sizeof(int)); len = read(pfd[pipe_read], &addr2->more_errno, sizeof(int)); - len = read(pfd[pipe_read], &addr2->delivery_usec, sizeof(int)); + len = read(pfd[pipe_read], &addr2->delivery_time, sizeof(struct timeval)); len = read(pfd[pipe_read], &addr2->special_action, sizeof(int)); len = read(pfd[pipe_read], &addr2->transport, sizeof(transport_instance *)); @@ -2575,7 +2552,7 @@ if (!shadowing) /* In the test harness, wait just a bit to let the subprocess finish off any debug output etc first. */ - if (f.running_in_test_harness) millisleep(300); + testharness_pause_ms(300); DEBUG(D_deliver) debug_printf("journalling %s", big_buffer); len = Ustrlen(big_buffer); @@ -2638,7 +2615,7 @@ if (addr->special_action == SPECIAL_WARN && addr->transport->warn_message) "message for %s transport): %s", addr->transport->warn_message, addr->transport->name, expand_string_message); - else if ((pid = child_open_exim(&fd)) > 0) + else if ((pid = child_open_exim(&fd, US"tpt-warning-message")) > 0) { FILE *f = fdopen(fd, "wb"); if (errors_reply_to && !contains_header(US"Reply-To", warn_message)) @@ -3159,11 +3136,7 @@ while (addr_local) /* Done with this address */ - if (result == OK) - { - addr2->more_errno = deliver_time.tv_sec; - addr2->delivery_usec = deliver_time.tv_usec; - } + addr2->delivery_time = deliver_time; post_process_one(addr2, result, logflags, EXIM_DTYPE_TRANSPORT, logchar); /* If a pipe delivery generated text to be sent back, the result may be @@ -3512,11 +3485,13 @@ while (!done) switch (*subid) { case '1': - addr->cipher = NULL; - addr->peerdn = NULL; + addr->tlsver = addr->cipher = addr->peerdn = NULL; if (*ptr) + { addr->cipher = string_copy(ptr); + addr->tlsver = string_copyn(ptr, Ustrchr(ptr, ':') - ptr); + } while (*ptr++); if (*ptr) addr->peerdn = string_copy(ptr); @@ -3565,7 +3540,7 @@ while (!done) case 'L': switch (*subid) { -#ifdef SUPPORT_PIPE_CONNECT +#ifndef DISABLE_PIPE_CONNECT case 2: setflag(addr, af_early_pipe); /*FALLTHROUGH*/ #endif case 1: setflag(addr, af_pipelining); break; @@ -3635,8 +3610,8 @@ while (!done) ptr += sizeof(addr->basic_errno); memcpy(&addr->more_errno, ptr, sizeof(addr->more_errno)); ptr += sizeof(addr->more_errno); - memcpy(&addr->delivery_usec, ptr, sizeof(addr->delivery_usec)); - ptr += sizeof(addr->delivery_usec); + memcpy(&addr->delivery_time, ptr, sizeof(addr->delivery_time)); + ptr += sizeof(addr->delivery_time); memcpy(&addr->flags, ptr, sizeof(addr->flags)); ptr += sizeof(addr->flags); addr->message = *ptr ? string_copy(ptr) : NULL; @@ -4671,7 +4646,7 @@ all pipes, so I do not see a reason to use non-blocking IO here search_tidyup(); - if ((pid = fork()) == 0) + if ((pid = exim_fork(US"transport")) == 0) { int fd = pfd[pipe_write]; host_item *h; @@ -4685,10 +4660,7 @@ all pipes, so I do not see a reason to use non-blocking IO here /* Show pids on debug output if parallelism possible */ if (parmax > 1 && (parcount > 0 || addr_remote)) - { DEBUG(D_any|D_v) debug_selector |= D_pid; - DEBUG(D_deliver) debug_printf("Remote delivery process started\n"); - } /* Reset the random number generator, so different processes don't all have the same sequence. In the test harness we want different, but @@ -4872,7 +4844,7 @@ all pipes, so I do not see a reason to use non-blocking IO here #endif if (testflag(addr, af_pipelining)) -#ifdef SUPPORT_PIPE_CONNECT +#ifndef DISABLE_PIPE_CONNECT if (testflag(addr, af_early_pipe)) rmt_dlv_checked_write(fd, 'L', '2', NULL, 0); else @@ -4952,8 +4924,8 @@ all pipes, so I do not see a reason to use non-blocking IO here ptr += sizeof(addr->basic_errno); memcpy(ptr, &addr->more_errno, sizeof(addr->more_errno)); ptr += sizeof(addr->more_errno); - memcpy(ptr, &addr->delivery_usec, sizeof(addr->delivery_usec)); - ptr += sizeof(addr->delivery_usec); + memcpy(ptr, &addr->delivery_time, sizeof(addr->delivery_time)); + ptr += sizeof(addr->delivery_time); memcpy(ptr, &addr->flags, sizeof(addr->flags)); ptr += sizeof(addr->flags); @@ -5056,9 +5028,10 @@ all pipes, so I do not see a reason to use non-blocking IO here /* Otherwise, if we are running in the test harness, wait a bit, to let the newly created process get going before we create another process. This should - ensure repeatability in the tests. We only need to wait a tad. */ + ensure repeatability in the tests. Wait long enough for most cases to complete + the transport. */ - else if (f.running_in_test_harness) millisleep(500); + else testharness_pause_ms(600); continue; @@ -5505,6 +5478,26 @@ fprintf(f, "Action: %s\n" } + +/* When running in the test harness, there's an option that allows us to +fudge this time so as to get repeatability of the tests. Take the first +time off the list. In queue runs, the list pointer gets updated in the +calling process. */ + +int +test_harness_fudged_queue_time(int actual_time) +{ +int qt; +if ( f.running_in_test_harness && *fudged_queue_times + && (qt = readconf_readtime(fudged_queue_times, '/', FALSE)) >= 0) + { + DEBUG(D_deliver) debug_printf("fudged queue_times = %s\n", + fudged_queue_times); + return qt; + } +return actual_time; +} + /************************************************* * Deliver one message * *************************************************/ @@ -5556,8 +5549,13 @@ int process_recipients = RECIP_ACCEPT; open_db dbblock; open_db *dbm_file; extern int acl_where; +uschar *info; -uschar *info = queue_run_pid == (pid_t)0 +#ifdef MEASURE_TIMING +report_time_since(×tamp_startup, US"delivery start"); /* testcase 0022, 2100 */ +#endif + +info = queue_run_pid == (pid_t)0 ? string_sprintf("delivering %s", id) : string_sprintf("delivering %s (queue run pid %d)", id, queue_run_pid); @@ -6190,7 +6188,8 @@ if (process_recipients != RECIP_IGNORE) new->onetime_parent = recipients_list[r->pno].address; /* If DSN support is enabled, set the dsn flags and the original receipt - to be passed on to other DSN enabled MTAs */ + to be passed on to other DSN enabled MTAs */ + new->dsn_flags = r->dsn_flags & rf_dsnflags; new->dsn_orcpt = r->orcpt; DEBUG(D_deliver) debug_printf("DSN: set orcpt: %s flags: 0x%x\n", @@ -7173,7 +7172,7 @@ if (addr_remote) /* Precompile some regex that are used to recognize parameters in response to an EHLO command, if they aren't already compiled. */ - deliver_init(); + smtp_deliver_init(); /* Now sort the addresses if required, and do the deliveries. The yield of do_remote_deliveries is FALSE when mua_wrapper is set and all addresses @@ -7310,10 +7309,9 @@ for (address_item * a = addr_succeed; a; a = a->next) ); /* send report if next hop not DSN aware or a router flagged "last DSN hop" - and a report was requested */ - if ( ( a->dsn_aware != dsn_support_yes - || a->dsn_flags & rf_dsnlasthop - ) + and a report was requested */ + + if ( (a->dsn_aware != dsn_support_yes || a->dsn_flags & rf_dsnlasthop) && a->dsn_flags & rf_notify_success ) { @@ -7333,14 +7331,14 @@ if (addr_senddsn) int fd; /* create exim process to send message */ - pid = child_open_exim(&fd); + pid = child_open_exim(&fd, US"DSN"); DEBUG(D_deliver) debug_printf("DSN: child_open_exim returns: %d\n", pid); if (pid < 0) /* Creation of child failed */ { log_write(0, LOG_MAIN|LOG_PANIC_DIE, "Process %d (parent %d) failed to " - "create child process to send failure message: %s", getpid(), + "create child process to send success-dsn message: %s", getpid(), getppid(), strerror(errno)); DEBUG(D_deliver) debug_printf("DSN: child_open_exim failed\n"); @@ -7353,7 +7351,7 @@ if (addr_senddsn) transport_ctx tctx = {{0}}; DEBUG(D_deliver) - debug_printf("sending error message to: %s\n", sender_address); + debug_printf("sending success-dsn to: %s\n", sender_address); /* build unique id for MIME boundary */ bound = string_sprintf(TIME_T_FMT "-eximdsn-%d", time(NULL), rand()); @@ -7365,8 +7363,11 @@ if (addr_senddsn) moan_write_from(f); fprintf(f, "Auto-Submitted: auto-generated\n" "To: %s\n" - "Subject: Delivery Status Notification\n" - "Content-Type: multipart/report; report-type=delivery-status; boundary=%s\n" + "Subject: Delivery Status Notification\n", + sender_address); + moan_write_references(f, NULL); + fprintf(f, "Content-Type: multipart/report;" + " report-type=delivery-status; boundary=%s\n" "MIME-Version: 1.0\n\n" "--%s\n" @@ -7374,7 +7375,7 @@ if (addr_senddsn) "This message was created automatically by mail delivery software.\n" " ----- The following addresses had successful delivery notifications -----\n", - sender_address, bound, bound); + bound, bound); for (address_item * a = addr_senddsn; a; a = a->next) fprintf(f, "<%s> (relayed %s)\n\n", @@ -7531,7 +7532,7 @@ while (addr_failed) /* Make a subprocess to send a message */ - if ((pid = child_open_exim(&fd)) < 0) + if ((pid = child_open_exim(&fd, US"bounce-message")) < 0) log_write(0, LOG_MAIN|LOG_PANIC_DIE, "Process %d (parent %d) failed to " "create child process to send failure message: %s", getpid(), getppid(), strerror(errno)); @@ -7603,6 +7604,7 @@ while (addr_failed) fprintf(fp, "Auto-Submitted: auto-replied\n"); moan_write_from(fp); fprintf(fp, "To: %s\n", bounce_recipient); + moan_write_references(fp, NULL); /* generate boundary string and output MIME-Headers */ bound = string_sprintf(TIME_T_FMT "-eximdsn-%d", time(NULL), rand()); @@ -7911,10 +7913,6 @@ wording. */ (void)fclose(fp); rc = child_close(pid, 0); /* Waits for child to close, no timeout */ - /* In the test harness, let the child do it's thing first. */ - - if (f.running_in_test_harness) millisleep(500); - /* If the process failed, there was some disaster in setting up the error message. Unless the message is very old, ensure that addr_defer is non-null, which will have the effect of leaving the message on the @@ -8153,21 +8151,7 @@ else if (addr_defer != (address_item *)(+1)) int show_time; int queue_time = time(NULL) - received_time.tv_sec; - /* When running in the test harness, there's an option that allows us to - fudge this time so as to get repeatability of the tests. Take the first - time off the list. In queue runs, the list pointer gets updated in the - calling process. */ - - if (f.running_in_test_harness && fudged_queue_times[0] != 0) - { - int qt = readconf_readtime(fudged_queue_times, '/', FALSE); - if (qt >= 0) - { - DEBUG(D_deliver) debug_printf("fudged queue_times = %s\n", - fudged_queue_times); - queue_time = qt; - } - } + queue_time = test_harness_fudged_queue_time(queue_time); /* See how many warnings we should have sent by now */ @@ -8188,7 +8172,8 @@ else if (addr_defer != (address_item *)(+1)) DEBUG(D_deliver) { - debug_printf("time on queue = %s id %s addr %s\n", readconf_printtime(queue_time), message_id, addr_defer->address); + debug_printf("time on queue = %s id %s addr %s\n", + readconf_printtime(queue_time), message_id, addr_defer->address); debug_printf("warning counts: required %d done %d\n", count, warning_count); } @@ -8201,7 +8186,7 @@ else if (addr_defer != (address_item *)(+1)) { header_line *h; int fd; - pid_t pid = child_open_exim(&fd); + pid_t pid = child_open_exim(&fd, US"delay-warning-message"); if (pid > 0) { @@ -8226,6 +8211,7 @@ else if (addr_defer != (address_item *)(+1)) fprintf(f, "Auto-Submitted: auto-replied\n"); moan_write_from(f); fprintf(f, "To: %s\n", recipients); + moan_write_references(f, NULL); /* generated boundary string and output MIME-Headers */ bound = string_sprintf(TIME_T_FMT "-eximdsn-%d", time(NULL), rand()); @@ -8487,6 +8473,9 @@ to try delivery. */ (void)close(deliver_datafile); deliver_datafile = -1; DEBUG(D_deliver) debug_printf("end delivery of %s\n", id); +#ifdef MEASURE_TIMING +report_time_since(×tamp_startup, US"delivery end"); /* testcase 0005 */ +#endif /* It is unlikely that there will be any cached resources, since they are released after routing, and in the delivery subprocesses. However, it's @@ -8502,52 +8491,13 @@ return final_yield; void -deliver_init(void) +tcp_init(void) { #ifdef EXIM_TFO_PROBE tfo_probe(); #else f.tcp_fastopen_ok = TRUE; #endif - - -if (!regex_PIPELINING) regex_PIPELINING = - regex_must_compile(US"\\n250[\\s\\-]PIPELINING(\\s|\\n|$)", FALSE, TRUE); - -if (!regex_SIZE) regex_SIZE = - regex_must_compile(US"\\n250[\\s\\-]SIZE(\\s|\\n|$)", FALSE, TRUE); - -if (!regex_AUTH) regex_AUTH = - regex_must_compile(AUTHS_REGEX, FALSE, TRUE); - -#ifndef DISABLE_TLS -if (!regex_STARTTLS) regex_STARTTLS = - regex_must_compile(US"\\n250[\\s\\-]STARTTLS(\\s|\\n|$)", FALSE, TRUE); -#endif - -if (!regex_CHUNKING) regex_CHUNKING = - regex_must_compile(US"\\n250[\\s\\-]CHUNKING(\\s|\\n|$)", FALSE, TRUE); - -#ifndef DISABLE_PRDR -if (!regex_PRDR) regex_PRDR = - regex_must_compile(US"\\n250[\\s\\-]PRDR(\\s|\\n|$)", FALSE, TRUE); -#endif - -#ifdef SUPPORT_I18N -if (!regex_UTF8) regex_UTF8 = - regex_must_compile(US"\\n250[\\s\\-]SMTPUTF8(\\s|\\n|$)", FALSE, TRUE); -#endif - -if (!regex_DSN) regex_DSN = - regex_must_compile(US"\\n250[\\s\\-]DSN(\\s|\\n|$)", FALSE, TRUE); - -if (!regex_IGNOREQUOTA) regex_IGNOREQUOTA = - regex_must_compile(US"\\n250[\\s\\-]IGNOREQUOTA(\\s|\\n|$)", FALSE, TRUE); - -#ifdef SUPPORT_PIPE_CONNECT -if (!regex_EARLY_PIPE) regex_EARLY_PIPE = - regex_must_compile(US"\\n250[\\s\\-]" EARLY_PIPE_FEATURE_NAME "(\\s|\\n|$)", FALSE, TRUE); -#endif } @@ -8624,18 +8574,17 @@ if (cutthrough.cctx.sock >= 0 && cutthrough.callout_hold_only) goto fail; where = US"fork"; - if ((pid = fork()) < 0) + testharness_pause_ms(150); + if ((pid = exim_fork(US"tls-proxy-interproc")) < 0) goto fail; - else if (pid == 0) /* child: fork again to totally disconnect */ + if (pid == 0) /* child: will fork again to totally disconnect */ { - if (f.running_in_test_harness) millisleep(100); /* let parent debug out */ - /* does not return */ smtp_proxy_tls(cutthrough.cctx.tls_ctx, big_buffer, big_buffer_size, pfd, 5*60); + /* does not return */ } - DEBUG(D_transport) debug_printf("proxy-proc inter-pid %d\n", pid); close(pfd[0]); waitpid(pid, NULL, 0); (void) close(channel_fd); /* release the client socket */