From 049782c0de52a217f78116f82b3a1d69c0667458 Mon Sep 17 00:00:00 2001 From: Jeremy Harris Date: Tue, 1 Jan 2019 16:21:02 +0000 Subject: [PATCH] Logging: created Message-IDs. Selectors for created and all IDs. Bugs 219, 1840, 2339 --- doc/doc-docbook/spec.xfpt | 14 ++++++++++- doc/doc-txt/NewStuff | 3 +++ src/src/functions.h | 1 + src/src/globals.c | 3 +++ src/src/header.c | 30 +++++++++++++++++------- src/src/macros.h | 2 ++ src/src/receive.c | 32 +++++++++++++++++-------- test/confs/0619 | 26 +++++++++++++++++++++ test/log/0619 | 10 ++++++++ test/scripts/0000-Basic/0619 | 45 ++++++++++++++++++++++++++++++++++++ 10 files changed, 148 insertions(+), 18 deletions(-) create mode 100644 test/confs/0619 create mode 100644 test/log/0619 create mode 100644 test/scripts/0000-Basic/0619 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 -- 2.30.2