More checks on header line length during reception
[exim.git] / src / src / deliver.c
index 9ab7402880d64f4f9c000e19fd73258603a3ae4a..664d00452ab2e7175c46ac1b09f19e982fb5dddc 100644 (file)
@@ -761,10 +761,9 @@ d_log_interface(gstring * g)
 if (LOGGING(incoming_interface) && LOGGING(outgoing_interface)
     && sending_ip_address)
   {
-  g = string_append(g, 2, US" I=[", sending_ip_address);
-  g = LOGGING(outgoing_port)
-    ? string_append(g, 2, US"]:", string_sprintf("%d", sending_port))
-    : string_catn(g, US"]", 1);
+  g = string_fmt_append(g, " I=[%s]", sending_ip_address);
+  if (LOGGING(outgoing_port))
+    g = string_fmt_append(g, "%d", sending_port);
   }
 return g;
 }
@@ -784,21 +783,21 @@ if (LOGGING(dnssec) && h->dnssec == DS_YES)
 g = string_append(g, 3, US" [", h->address, US"]");
 
 if (LOGGING(outgoing_port))
-  g = string_append(g, 2, US":", string_sprintf("%d", h->port));
+  g = string_fmt_append(g, ":%d", h->port);
 
 #ifdef SUPPORT_SOCKS
 if (LOGGING(proxy) && proxy_local_address)
   {
   g = string_append(g, 3, US" PRX=[", proxy_local_address, US"]");
   if (LOGGING(outgoing_port))
-    g = string_append(g, 2, US":", string_sprintf("%d", proxy_local_port));
+    g = string_fmt_append(g, ":%d", proxy_local_port);
   }
 #endif
 
 g = d_log_interface(g);
 
 if (testflag(addr, af_tcp_fastopen))
-  g = string_catn(g, US" TFO", 4);
+  g = string_catn(g, US" TFO*", testflag(addr, af_tcp_fastopen_data) ? 5 : 4);
 
 return g;
 }
@@ -877,20 +876,33 @@ const uschar * save_host = deliver_host;
 const uschar * save_address = deliver_host_address;
 const int      save_port =   deliver_host_port;
 
-if (!addr->transport)
-  return;
-
 router_name =    addr->router ? addr->router->name : NULL;
-transport_name = addr->transport->name;
 deliver_domain = addr->domain;
 deliver_localpart = addr->local_part;
 deliver_host =   addr->host_used ? addr->host_used->name : NULL;
 
-(void) event_raise(addr->transport->event_action, event,
-         addr->host_used
-          || Ustrcmp(addr->transport->driver_name, "smtp") == 0
-         || Ustrcmp(addr->transport->driver_name, "lmtp") == 0
-        ? addr->message : NULL);
+if (!addr->transport)
+  {
+  if (Ustrcmp(event, "msg:fail:delivery") == 0)
+    {
+     /* An address failed with no transport involved. This happens when
+     a filter was used which triggered a fail command (in such a case
+     a transport isn't needed).  Convert it to an internal fail event. */
+
+    (void) event_raise(event_action, US"msg:fail:internal", addr->message);
+    }
+  }
+else
+  {
+  transport_name = addr->transport->name;
+
+  (void) event_raise(addr->transport->event_action, event,
+           addr->host_used
+           || Ustrcmp(addr->transport->driver_name, "smtp") == 0
+           || Ustrcmp(addr->transport->driver_name, "lmtp") == 0
+           || Ustrcmp(addr->transport->driver_name, "autoreply") == 0
+          ? addr->message : NULL);
+  }
 
 deliver_host_port =    save_port;
 deliver_host_address = save_address;
@@ -1183,8 +1195,7 @@ if (addr->router)
 g = string_append(g, 2, US" T=", addr->transport->name);
 
 if (LOGGING(delivery_size))
-  g = string_append(g, 2, US" S=",
-    string_sprintf("%d", transport_count));
+  g = string_fmt_append(g, " S=%d", transport_count);
 
 /* Local delivery */
 
@@ -1234,8 +1245,15 @@ else
       }
     }
 
-  if (LOGGING(pipelining) && testflag(addr, af_pipelining))
-    g = string_catn(g, US" L", 2);
+  if (LOGGING(pipelining))
+    {
+    if (testflag(addr, af_pipelining))
+      g = string_catn(g, US" L", 2);
+#ifdef EXPERIMENTAL_PIPE_CONNECT
+    if (testflag(addr, af_early_pipe))
+      g = string_catn(g, US"*", 1);
+#endif
+    }
 
 #ifndef DISABLE_PRDR
   if (testflag(addr, af_prdr_used))
@@ -1325,13 +1343,12 @@ if (driver_name)
   {
   if (driver_kind[1] == 't' && addr->router)
     g = string_append(g, 2, US" R=", addr->router->name);
-  g = string_cat(g, string_sprintf(" %c=%s", toupper(driver_kind[1]), driver_name));
+  g = string_fmt_append(g, " %c=%s", toupper(driver_kind[1]), driver_name);
   }
 else if (driver_kind)
   g = string_append(g, 2, US" ", driver_kind);
 
-/*XXX need an s+s+p sprintf */
-g = string_cat(g, string_sprintf(" defer (%d)", addr->basic_errno));
+g = string_fmt_append(g, " defer (%d)", addr->basic_errno);
 
 if (addr->basic_errno > 0)
   g = string_append(g, 2, US": ",
@@ -1345,8 +1362,7 @@ if (addr->host_used)
   if (LOGGING(outgoing_port))
     {
     int port = addr->host_used->port;
-    g = string_append(g, 2,
-         US":", port == PORT_NONE ? US"25" : string_sprintf("%d", port));
+    g = string_fmt_append(g, ":%d", port == PORT_NONE ? 25 : port);
     }
   }
 
@@ -1383,6 +1399,16 @@ failure_log(address_item * addr, uschar * driver_kind, uschar * now)
 void * reset_point;
 gstring * g = reset_point = string_get(256);
 
+#ifndef DISABLE_EVENT
+/* Message failures for which we will send a DSN get their event raised
+later so avoid doing it here. */
+
+if (  !addr->prop.ignore_error
+   && !(addr->dsn_flags & (rf_dsnflags & ~rf_notify_failure))
+   )
+  msg_event_raise(US"msg:fail:delivery", addr);
+#endif
+
 /* Build up the log line for the message and main logs */
 
 /* Create the address string for logging. Must not do this earlier, because
@@ -1431,10 +1457,6 @@ else
 
 log_write(0, LOG_MAIN, "** %s", g->s);
 
-#ifndef DISABLE_EVENT
-msg_event_raise(US"msg:fail:delivery", addr);
-#endif
-
 store_reset(reset_point);
 return;
 }
@@ -1766,13 +1788,12 @@ addr->basic_errno = code;
 if (format)
   {
   va_list ap;
-  uschar buffer[512];
+  gstring * g;
+
   va_start(ap, format);
-  if (!string_vformat(buffer, sizeof(buffer), CS format, ap))
-    log_write(0, LOG_MAIN|LOG_PANIC_DIE,
-      "common_error expansion was longer than " SIZE_T_FMT, sizeof(buffer));
+  g = string_vformat(NULL, TRUE, CS format, ap);
   va_end(ap);
-  addr->message = string_copy(buffer);
+  addr->message = string_from_gstring(g);
   }
 
 for (addr2 = addr->next; addr2; addr2 = addr2->next)
@@ -3296,8 +3317,8 @@ small items (less than PIPE_BUF, which seems to be at least 512 in any Unix and
 often bigger) so even if we are reading while the subprocess is still going, we
 should never have only a partial item in the buffer.
 
-hs12: This assumption is not true anymore, since we got quit large items (certificate
-information and such)
+hs12: This assumption is not true anymore, since we get quite large items (certificate
+information and such).
 
 Argument:
   poffset     the offset of the parlist item
@@ -3557,6 +3578,9 @@ while (!done)
     case 'L':
       switch (*subid)
        {
+#ifdef EXPERIMENTAL_PIPE_CONNECT
+       case 2: setflag(addr, af_early_pipe);   /*FALLTHROUGH*/
+#endif
        case 1: setflag(addr, af_pipelining); break;
        }
       break;
@@ -3568,6 +3592,7 @@ while (!done)
     case 'T':
       setflag(addr, af_tcp_fastopen_conn);
       if (*subid > '0') setflag(addr, af_tcp_fastopen);
+      if (*subid > '1') setflag(addr, af_tcp_fastopen_data);
       break;
 
     case 'D':
@@ -4666,12 +4691,10 @@ all pipes, so I do not see a reason to use non-blocking IO here
 
   search_tidyup();
 
-
   if ((pid = fork()) == 0)
     {
     int fd = pfd[pipe_write];
     host_item *h;
-    DEBUG(D_deliver) debug_selector |= D_pid;  // hs12
 
     /* Setting this global in the subprocess means we need never clear it */
     transport_name = tp->name;
@@ -4867,6 +4890,11 @@ all pipes, so I do not see a reason to use non-blocking IO here
 #endif
 
       if (testflag(addr, af_pipelining))
+#ifdef EXPERIMENTAL_PIPE_CONNECT
+       if (testflag(addr, af_early_pipe))
+         rmt_dlv_checked_write(fd, 'L', '2', NULL, 0);
+       else
+#endif
          rmt_dlv_checked_write(fd, 'L', '1', NULL, 0);
 
       if (testflag(addr, af_chunking_used))
@@ -4874,7 +4902,9 @@ all pipes, so I do not see a reason to use non-blocking IO here
 
       if (testflag(addr, af_tcp_fastopen_conn))
        rmt_dlv_checked_write(fd, 'T',
-         testflag(addr, af_tcp_fastopen) ? '1' : '0', NULL, 0);
+         testflag(addr, af_tcp_fastopen) ? testflag(addr, af_tcp_fastopen_data)
+         ? '2' : '1' : '0',
+         NULL, 0);
 
       memcpy(big_buffer, &addr->dsn_aware, sizeof(addr->dsn_aware));
       rmt_dlv_checked_write(fd, 'D', '0', big_buffer, sizeof(addr->dsn_aware));
@@ -5348,7 +5378,7 @@ static void
 print_address_error(address_item *addr, FILE *f, uschar *t)
 {
 int count = Ustrlen(t);
-uschar *s = testflag(addr, af_pass_message)? addr->message : NULL;
+uschar *s = testflag(addr, af_pass_message) ? addr->message : NULL;
 
 if (!s && !(s = addr->user_message))
   return;
@@ -5569,7 +5599,8 @@ message size. This use of strcpy() is OK because the length id is checked when
 it is obtained from a command line (the -M or -q options), and otherwise it is
 known to be a valid message id. */
 
-Ustrcpy(message_id, id);
+if (id != message_id)
+  Ustrcpy(message_id, id);
 f.deliver_force = forced;
 return_count = 0;
 message_size = 0;
@@ -5854,9 +5885,7 @@ else if (system_filter && process_recipients != RECIP_FAIL_TIMEOUT)
     ugid.uid_set = ugid.gid_set = TRUE;
     }
   else
-    {
     ugid.uid_set = ugid.gid_set = FALSE;
-    }
 
   return_path = sender_address;
   f.enable_dollar_recipients = TRUE;   /* Permit $recipients in system filter */
@@ -6579,13 +6608,21 @@ while (addr_new)           /* Loop until all addresses dealt with */
       if (  domain_retry_record
          && now - domain_retry_record->time_stamp > retry_data_expire
         )
+       {
+       DEBUG(D_deliver|D_retry)
+         debug_printf("domain retry record present but expired\n");
         domain_retry_record = NULL;    /* Ignore if too old */
+       }
 
       address_retry_record = dbfn_read(dbm_file, addr->address_retry_key);
       if (  address_retry_record
          && now - address_retry_record->time_stamp > retry_data_expire
         )
+       {
+       DEBUG(D_deliver|D_retry)
+         debug_printf("address retry record present but expired\n");
         address_retry_record = NULL;   /* Ignore if too old */
+       }
 
       if (!address_retry_record)
         {
@@ -6594,7 +6631,11 @@ while (addr_new)           /* Loop until all addresses dealt with */
         address_retry_record = dbfn_read(dbm_file, altkey);
         if (  address_retry_record
           && now - address_retry_record->time_stamp > retry_data_expire)
+         {
+         DEBUG(D_deliver|D_retry)
+           debug_printf("address<sender> retry record present but expired\n");
           address_retry_record = NULL;   /* Ignore if too old */
+         }
         }
       }
     else
@@ -6603,9 +6644,18 @@ while (addr_new)           /* Loop until all addresses dealt with */
     DEBUG(D_deliver|D_retry)
       {
       if (!domain_retry_record)
-        debug_printf("no domain retry record\n");
+       debug_printf("no   domain  retry record\n");
+      else
+       debug_printf("have domain  retry record; next_try = now%+d\n",
+                     f.running_in_test_harness ? 0 :
+                     (int)(domain_retry_record->next_try - now));
+
       if (!address_retry_record)
-        debug_printf("no address retry record\n");
+       debug_printf("no   address retry record\n");
+      else
+       debug_printf("have address retry record; next_try = now%+d\n",
+                     f.running_in_test_harness ? 0 :
+                     (int)(address_retry_record->next_try - now));
       }
 
     /* If we are sending a message down an existing SMTP connection, we must
@@ -6627,6 +6677,9 @@ while (addr_new)           /* Loop until all addresses dealt with */
       addr->message = US"reusing SMTP connection skips previous routing defer";
       addr->basic_errno = ERRNO_RRETRY;
       (void)post_process_one(addr, DEFER, LOG_MAIN, EXIM_DTYPE_ROUTER, 0);
+
+      addr->message = domain_retry_record->text;
+      setflag(addr, af_pass_message);
       }
 
     /* If we are in a queue run, defer routing unless there is no retry data or
@@ -6680,6 +6733,16 @@ while (addr_new)           /* Loop until all addresses dealt with */
       addr->message = US"retry time not reached";
       addr->basic_errno = ERRNO_RRETRY;
       (void)post_process_one(addr, DEFER, LOG_MAIN, EXIM_DTYPE_ROUTER, 0);
+
+      /* For remote-retry errors (here and just above) that we've not yet
+      hit the rery time, use the error recorded in the retry database
+      as info in the warning message.  This lets us send a message even
+      when we're not failing on a fresh attempt.  We assume that this
+      info is not sensitive. */
+
+      addr->message = domain_retry_record
+       ? domain_retry_record->text : address_retry_record->text;
+      setflag(addr, af_pass_message);
       }
 
     /* The domain is OK for routing. Remember if retry data exists so it
@@ -7010,7 +7073,7 @@ if (  f.header_rewritten
   }
 
 
-/* If there are any deliveries to be and we do not already have the journal
+/* If there are any deliveries to do and we do not already have the journal
 file, create it. This is used to record successful deliveries as soon as
 possible after each delivery is known to be complete. A file opened with
 O_APPEND is used so that several processes can run simultaneously.
@@ -7287,7 +7350,7 @@ if (addr_senddsn)
     }
   else  /* Creation of child succeeded */
     {
-    FILE *f = fdopen(fd, "wb");
+    FILE * f = fdopen(fd, "wb");
     /* header only as required by RFC. only failure DSN needs to honor RET=FULL */
     uschar * bound;
     transport_ctx tctx = {{0}};
@@ -7368,8 +7431,10 @@ if (addr_senddsn)
 
     /* Write the original email out */
 
-    tctx.u.fd = fileno(f);
+    tctx.u.fd = fd;
     tctx.options = topt_add_return_path | topt_no_body;
+    /*XXX hmm, retval ignored.
+    Could error for any number of reasons, and they are not handled. */
     transport_write_message(&tctx, 0);
     fflush(f);
 
@@ -7445,6 +7510,9 @@ while (addr_failed)
     addr_failed = addr->next;
     if (addr->return_filename) Uunlink(addr->return_filename);
 
+#ifndef DISABLE_EVENT
+    msg_event_raise(US"msg:fail:delivery", addr);
+#endif
     log_write(0, LOG_MAIN, "%s%s%s%s: error ignored",
       addr->address,
       !addr->parent ? US"" : US" <",
@@ -7834,6 +7902,7 @@ wording. */
        tctx.options = topt;
        tb.add_headers = dsnnotifyhdr;
 
+       /*XXX no checking for failure!  buggy! */
        transport_write_message(&tctx, 0);
        }
       fflush(fp);
@@ -7975,6 +8044,8 @@ the parent's domain.
 If all the deferred addresses have an error number that indicates "retry time
 not reached", skip sending the warning message, because it won't contain the
 reason for the delay. It will get sent at the next real delivery attempt.
+  Exception: for retries caused by a remote peer we use the error message
+  store in the retry DB as the reason.
 However, if at least one address has tried, we'd better include all of them in
 the message.
 
@@ -7994,7 +8065,7 @@ else if (addr_defer != (address_item *)(+1))
   {
   address_item *addr;
   uschar *recipients = US"";
-  BOOL delivery_attempted = FALSE;
+  BOOL want_warning_msg = FALSE;
 
   deliver_domain = testflag(addr_defer, af_pfr)
     ? addr_defer->parent->domain : addr_defer->domain;
@@ -8003,7 +8074,7 @@ else if (addr_defer != (address_item *)(+1))
     {
     address_item *otaddr;
 
-    if (addr->basic_errno > ERRNO_RETRY_BASE) delivery_attempted = TRUE;
+    if (addr->basic_errno > ERRNO_WARN_BASE) want_warning_msg = TRUE;
 
     if (deliver_domain)
       {
@@ -8075,7 +8146,7 @@ else if (addr_defer != (address_item *)(+1))
   it also defers). */
 
   if (  !f.queue_2stage
-     && delivery_attempted
+     && want_warning_msg
      && (  !(addr_defer->dsn_flags & rf_dsnflags)
         || addr_defer->dsn_flags & rf_notify_delay
        )
@@ -8126,7 +8197,7 @@ else if (addr_defer != (address_item *)(+1))
 
     DEBUG(D_deliver)
       {
-      debug_printf("time on queue = %s\n", readconf_printtime(queue_time));
+      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);
       }
@@ -8300,6 +8371,7 @@ else if (addr_defer != (address_item *)(+1))
         return_path = sender_address;   /* In case not previously set */
 
         /* Write the original email out */
+       /*XXX no checking for failure!  buggy! */
         transport_write_message(&tctx, 0);
         fflush(f);
 
@@ -8463,8 +8535,7 @@ if (!regex_SIZE) regex_SIZE =
   regex_must_compile(US"\\n250[\\s\\-]SIZE(\\s|\\n|$)", FALSE, TRUE);
 
 if (!regex_AUTH) regex_AUTH =
-  regex_must_compile(US"\\n250[\\s\\-]AUTH\\s+([\\-\\w\\s]+)(?:\\n|$)",
-    FALSE, TRUE);
+  regex_must_compile(AUTHS_REGEX, FALSE, TRUE);
 
 #ifdef SUPPORT_TLS
 if (!regex_STARTTLS) regex_STARTTLS =
@@ -8494,6 +8565,11 @@ if (!regex_DSN) regex_DSN  =
 
 if (!regex_IGNOREQUOTA) regex_IGNOREQUOTA =
   regex_must_compile(US"\\n250[\\s\\-]IGNOREQUOTA(\\s|\\n|$)", FALSE, TRUE);
+
+#ifdef EXPERIMENTAL_PIPE_CONNECT
+if (!regex_EARLY_PIPE) regex_EARLY_PIPE =
+  regex_must_compile(US"\\n250[\\s\\-]" EARLY_PIPE_FEATURE_NAME "(\\s|\\n|$)", FALSE, TRUE);
+#endif
 }