Logging: created Message-IDs. Selectors for created and all IDs. Bugs 219, 1840, 2339

10 files changed, 148 insertions, 18 deletions

diff --git a/doc/doc-docbook/spec.xfpt b/doc/doc-docbook/spec.xfpt
index 415c72712..0632ba26b 100644
--- a/doc/doc-docbook/spec.xfpt
+++ b/doc/doc-docbook/spec.xfpt
@@ -37001,7 +37001,7 @@ the following table:
 &`F   `&        sender address (on delivery lines)
 &`H   `&        host name and IP address
 &`I   `&        local interface used
-&`id  `&        message id for incoming message
+&`id  `&        message id (from header) for incoming message
 &`K   `&        CHUNKING extension used
 &`L   `&        on &`<=`& and &`=>`& lines: PIPELINING extension used
 &`M8S `&        8BITMIME status for incoming message
@@ -37108,6 +37108,8 @@ selection marked by asterisks:
 &` incoming_port              `&  remote port on <= lines
 &`*lost_incoming_connection   `&  as it says (includes timeouts)
 &` millisec                   `&  millisecond timestamps and RT,QT,DT,D times
+&`*msg_id                     `&  on <= lines, Message-ID: header value
+&` msg_id_created             `&  on <= lines, Message-ID: header value when one had to be added
 &` outgoing_interface         `&  local interface on => lines
 &` outgoing_port              `&  add remote port to => lines
 &`*queue_run                  `&  start and end queue runs
@@ -37291,6 +37293,16 @@ connection is unexpectedly dropped.
 &%millisec%&: Timestamps have a period and three decimal places of finer granularity
 appended to the seconds value.
 .next
+.new
+.cindex "log" "message id"
+&%msg_id%&: The value of the Message-ID: header.
+.next
+&%msg_id_created%&: The value of the Message-ID: header, when one had to be created.
+This will be either because the message is a bounce, or was submitted locally
+(submission mode) without one.
+The field identifier will have an asterix appended: &"id*="&.
+.wen
+.next
 .cindex "log" "outgoing interface"
 .cindex "log" "local interface"
 .cindex "log" "local address and port"
diff --git a/doc/doc-txt/NewStuff b/doc/doc-txt/NewStuff
index ad238f4c7..973a66937 100644
--- a/doc/doc-txt/NewStuff
+++ b/doc/doc-txt/NewStuff
@@ -16,6 +16,9 @@ Version 4.93
  3. Variables $tls_in_cipher_std, $tls_out_cipher_std giving the RFC names
     for ciphersuites.
 
+ 4. Log_selectors "msg_id" (on by default) and "msg_id_created".
+
+
 Version 4.92
 --------------
 
diff --git a/src/src/functions.h b/src/src/functions.h
index c7acc2f52..27981db10 100644
--- a/src/src/functions.h
+++ b/src/src/functions.h
@@ -241,6 +241,7 @@ extern uschar * fn_hdrs_added(void);
 extern void    gstring_reset_unused(gstring *);
 
 extern void    header_add(int, const char *, ...);
+extern header_line *header_add_at_position_internal(BOOL, uschar *, BOOL, int, const char *, ...);
 extern int     header_checkname(header_line *, BOOL);
 extern BOOL    header_match(uschar *, BOOL, BOOL, string_item *, int, ...);
 extern int     host_address_extract_port(uschar *);
diff --git a/src/src/globals.c b/src/src/globals.c
index df71025a3..94fab000d 100644
--- a/src/src/globals.c
+++ b/src/src/globals.c
@@ -1033,6 +1033,7 @@ int     log_default[]          = { /* for initializing log_selector */
   Li_host_lookup_failed,
   Li_lost_incoming_connection,
   Li_outgoing_interface, /* see d_log_interface in deliver.c */
+  Li_msg_id,
   Li_queue_run,
   Li_rejected_header,
   Li_retry_defer,
@@ -1075,6 +1076,8 @@ bit_table log_options[]        = { /* must be in alphabetical order */
   BIT_TABLE(L, incoming_port),
   BIT_TABLE(L, lost_incoming_connection),
   BIT_TABLE(L, millisec),
+  BIT_TABLE(L, msg_id),
+  BIT_TABLE(L, msg_id_created),
   BIT_TABLE(L, outgoing_interface),
   BIT_TABLE(L, outgoing_port),
   BIT_TABLE(L, pid),
diff --git a/src/src/header.c b/src/src/header.c
index dd82b2b69..19dbcc15d 100644
--- a/src/src/header.c
+++ b/src/src/header.c
@@ -86,10 +86,10 @@ Arguments:
   format    sprintf format
   ap        va_list value for format arguments
 
-Returns:    nothing
+Returns:    pointer to header struct (last one, if multiple added)
 */
 
-static void
+static header_line *
 header_add_backend(BOOL after, uschar *name, BOOL topnot, int type,
   const char *format, va_list ap)
 {
@@ -100,7 +100,7 @@ uschar *p, *q;
 uschar buffer[HEADER_ADD_BUFFER_SIZE];
 gstring gs = { .size = HEADER_ADD_BUFFER_SIZE, .ptr = 0, .s = buffer };
 
-if (!header_last) return;
+if (!header_last) return NULL;
 
 if (!string_vformat(&gs, FALSE, format, ap))
   log_write(0, LOG_MAIN|LOG_PANIC_DIE, "string too long in header_add: "
@@ -189,6 +189,7 @@ for (p = q = buffer; *p != 0; )
   if (!h) header_last = new;
   p = q;
   }
+return new;
 }
 
 
@@ -206,20 +207,33 @@ Arguments:
   format    sprintf format
   ...       format arguments
 
-Returns:    nothing
+Returns:    pointer to header struct added
 */
 
-void
-header_add_at_position(BOOL after, uschar *name, BOOL topnot, int type,
+header_line *
+header_add_at_position_internal(BOOL after, uschar *name, BOOL topnot, int type,
   const char *format, ...)
 {
+header_line * h;
 va_list ap;
 va_start(ap, format);
-header_add_backend(after, name, topnot, type, format, ap);
+h = header_add_backend(after, name, topnot, type, format, ap);
 va_end(ap);
+return h;
 }
 
 
+/* Documented external i/f for local_scan */
+void
+header_add_at_position(BOOL after, uschar *name, BOOL topnot, int type,
+  const char *format, ...)
+{
+header_line * h;
+va_list ap;
+va_start(ap, format);
+(void) header_add_backend(after, name, topnot, type, format, ap);
+va_end(ap);
+}
 
 /*************************************************
 *            Add new header on end of chain      *
@@ -240,7 +254,7 @@ header_add(int type, const char *format, ...)
 {
 va_list ap;
 va_start(ap, format);
-header_add_backend(TRUE, NULL, FALSE, type, format, ap);
+(void) header_add_backend(TRUE, NULL, FALSE, type, format, ap);
 va_end(ap);
 }
 
diff --git a/src/src/macros.h b/src/src/macros.h
index 0c54f969c..759955019 100644
--- a/src/src/macros.h
+++ b/src/src/macros.h
@@ -472,6 +472,8 @@ enum {
   Li_incoming_interface,
   Li_incoming_port,
   Li_millisec,
+  Li_msg_id,
+  Li_msg_id_created,
   Li_outgoing_interface,
   Li_outgoing_port,
   Li_pid,
diff --git a/src/src/receive.c b/src/src/receive.c
index c851d4bd9..0cb38626a 100644
--- a/src/src/receive.c
+++ b/src/src/receive.c
@@ -1673,6 +1673,7 @@ header_line *from_header = NULL;
 header_line *subject_header = NULL;
 header_line *msgid_header = NULL;
 header_line *received_header;
+BOOL msgid_header_newly_created = FALSE;
 
 #ifdef EXPERIMENTAL_DMARC
 int dmarc_up = 0;
@@ -2673,6 +2674,7 @@ if (  !msgid_header
   {
   uschar *id_text = US"";
   uschar *id_domain = primary_hostname;
+  header_line * h;
 
   /* Permit only letters, digits, dots, and hyphens in the domain */
 
@@ -2714,13 +2716,21 @@ if (  !msgid_header
       }
     }
 
-  /* Add the header line
-   * Resent-* headers are prepended, per RFC 5322 3.6.6.  Non-Resent-* are
-   * appended, to preserve classical expectations of header ordering. */
+  /* Add the header line.
+  Resent-* headers are prepended, per RFC 5322 3.6.6.  Non-Resent-* are
+  appended, to preserve classical expectations of header ordering. */
 
-  header_add_at_position(!resents_exist, NULL, FALSE, htype_id,
+  h = header_add_at_position_internal(!resents_exist, NULL, FALSE, htype_id,
     "%sMessage-Id: <%s%s%s@%s>\n", resent_prefix, message_id_external,
-    (*id_text == 0)? "" : ".", id_text, id_domain);
+    *id_text == 0 ? "" : ".", id_text, id_domain);
+
+  /* Arrange for newly-created Message-Id to be logged */
+
+  if (!resents_exist)
+    {
+    msgid_header_newly_created = TRUE;
+    msgid_header = h;
+    }
   }
 
 /* If we are to log recipients, keep a copy of the raw ones before any possible
@@ -4010,16 +4020,20 @@ any characters except " \ and CR and so in particular it can contain NL!
 Therefore, make sure we use a printing-characters only version for the log.
 Also, allow for domain literals in the message id. */
 
-if (msgid_header)
+if (  LOGGING(msg_id) && msgid_header
+   && (LOGGING(msg_id_created) || !msgid_header_newly_created)
+   )
   {
-  uschar *old_id;
+  uschar * old_id;
   BOOL save_allow_domain_literals = allow_domain_literals;
   allow_domain_literals = TRUE;
   old_id = parse_extract_address(Ustrchr(msgid_header->text, ':') + 1,
     &errmsg, &start, &end, &domain, FALSE);
   allow_domain_literals = save_allow_domain_literals;
-  if (old_id != NULL)
-    g = string_append(g, 2, US" id=", string_printing(old_id));
+  if (old_id)
+    g = string_append(g, 2,
+      msgid_header_newly_created ? US" id*=" : US" id=",
+      string_printing(old_id));
   }
 
 /* If subject logging is turned on, create suitable printing-character
diff --git a/test/confs/0619 b/test/confs/0619
new file mode 100644
index 000000000..dc23661ac
--- /dev/null
+++ b/test/confs/0619
@@ -0,0 +1,26 @@
+# Exim test configuration 0619
+
+LOG_SELECTOR=
+
+keep_environment = PATH
+exim_path = EXIM_PATH
+spool_directory = DIR/spool
+
+log_file_path = DIR/spool/log/%slog
+
+gecos_pattern = ""
+gecos_name = CALLER_NAME
+chunking_advertise_hosts =
+tls_advertise_hosts =
+
+primary_hostname = myhost.test.ex
+queue_only
+
+# ----- Main settings -----
+
+log_selector = LOG_SELECTOR
+
+acl_not_smtp = accept
+
+
+# End
diff --git a/test/log/0619 b/test/log/0619
new file mode 100644
index 000000000..36354ac56
--- /dev/null
+++ b/test/log/0619
@@ -0,0 +1,10 @@
+1999-03-02 09:44:33 10HmaX-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss id=original1235@example.com for a@test.ex
+1999-03-02 09:44:33 10HmaY-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss for b@test.ex
+1999-03-02 09:44:33 10HmaZ-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss id*=E10HmaZ-0005vi-00@myhost.test.ex for c@test.ex
+1999-03-02 09:44:33 10HmbA-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss id=original1235@example.com for d@test.ex
+1999-03-02 09:44:33 10HmaX-0005vi-00 ** a@test.ex: Unrouteable address
+1999-03-02 09:44:33 10HmbB-0005vi-00 <= <> R=10HmaX-0005vi-00 U=EXIMUSER P=local S=sss for CALLER@myhost.test.ex
+1999-03-02 09:44:33 10HmaX-0005vi-00 Completed
+1999-03-02 09:44:33 10HmaY-0005vi-00 ** b@test.ex: Unrouteable address
+1999-03-02 09:44:33 10HmbC-0005vi-00 <= <> R=10HmaY-0005vi-00 U=EXIMUSER P=local S=sss id*=E10HmbC-0005vi-00@myhost.test.ex for CALLER@myhost.test.ex
+1999-03-02 09:44:33 10HmaY-0005vi-00 Completed
diff --git a/test/scripts/0000-Basic/0619 b/test/scripts/0000-Basic/0619
new file mode 100644
index 000000000..196b9dc0c
--- /dev/null
+++ b/test/scripts/0000-Basic/0619
@@ -0,0 +1,45 @@
+# log_selector msg_id and msg_id_created
+#
+# msg_id is on by default; check baseline
+exim -DLOG_SELECTOR=+received_recipients -t
+From: CALLER@test.ex
+To: a@test.ex
+Message-ID: original1235@example.com
+
+body
+****
+#
+# msg_id is on by default; check it can be disabled
+exim -DLOG_SELECTOR=+received_recipients-msg_id -t
+From: CALLER@test.ex
+To: b@test.ex
+Message-ID: original1235@example.com
+
+body
+****
+#
+# check msg_id_created shows invented ones
+exim -DLOG_SELECTOR=+received_recipients+msg_id_created -t
+From: CALLER@test.ex
+To: c@test.ex
+
+body
+****
+#
+# check msg_id_created ignores non-invented ones
+exim -DLOG_SELECTOR=+received_recipients+msg_id_created -t
+From: CALLER@test.ex
+To: d@test.ex
+Message-ID: original1235@example.com
+
+body
+****
+#
+# check that bounces don't log created, by default
+exim -DLOG_SELECTOR=+received_recipients -M $msg1
+****
+# and check they do with msg_id_created
+exim -DLOG_SELECTOR=+received_recipients+msg_id_created -M $msg1
+****
+#
+no_msglog_check