From 4bc16ab818795e5d4eccc52d65bd7613376ffbe3 Mon Sep 17 00:00:00 2001 From: Jeremy Harris Date: Wed, 31 Jul 2024 08:41:34 +0100 Subject: [PATCH 1/1] Add $connection_id variable --- doc/doc-docbook/spec.xfpt | 7 ++++++- doc/doc-txt/NewStuff | 2 ++ src/src/daemon.c | 4 ++-- src/src/exim.c | 4 ++-- src/src/expand.c | 1 + src/src/functions.h | 14 ++++++++++++++ src/src/globals.c | 2 +- src/src/globals.h | 2 +- src/src/host.c | 2 +- src/src/receive.c | 2 +- src/src/smtp_in.c | 2 +- test/confs/0002 | 2 +- test/runtest | 4 ++++ test/scripts/0000-Basic/0002 | 2 +- test/stderr/0002 | 9 +++++++++ 15 files changed, 47 insertions(+), 12 deletions(-) diff --git a/doc/doc-docbook/spec.xfpt b/doc/doc-docbook/spec.xfpt index 8ab15d86b..aaa4a270f 100644 --- a/doc/doc-docbook/spec.xfpt +++ b/doc/doc-docbook/spec.xfpt @@ -12611,6 +12611,11 @@ contain the trailing slash. If &$config_file$& does not contain a slash, .vindex "&$config_file$&" The name of the main configuration file Exim is using. +.vitem &$connection_id$& +.vindex "&$connection_id$&" +.cindex connection "identifier logging" +An identifier for the accepted connection, for use in custom logging. + .vitem &$dkim_verify_status$& Results of DKIM verification. For details see section &<>&. @@ -39368,7 +39373,7 @@ only way to log such cases is to interpose a script such as &_util/logargs.sh_& between the caller and Exim. .next .cindex log "connection identifier" -.cindec connection "indentifier logging" +.cindex connection "identifier logging" &%connection_id%&: An identifier for the accepted connection is added to connection start and end lines and to message accept lines. The identifier is tagged by Ci=. diff --git a/doc/doc-txt/NewStuff b/doc/doc-txt/NewStuff index 012d71d68..d48f2252e 100644 --- a/doc/doc-txt/NewStuff +++ b/doc/doc-txt/NewStuff @@ -10,6 +10,8 @@ Version 4.98 ------------ 1. A sieve_inbox option for redirect routers + 2. A "connection_id" variable + Version 4.98 ------------ 1. The dkim_status ACL condition may now be used in data ACLs diff --git a/src/src/daemon.c b/src/src/daemon.c index 823c91937..4088cb532 100644 --- a/src/src/daemon.c +++ b/src/src/daemon.c @@ -383,7 +383,7 @@ if (pid == 0) #endif smtp_accept_count++; /* So that it includes this process */ - connection_id = getpid(); + set_connection_id(); /* Log the connection if requested. In order to minimize the cost (because this is going to happen for every @@ -405,7 +405,7 @@ if (pid == 0) save_log_selector &= ~L_smtp_connection; else if (LOGGING(connection_id)) log_write(L_smtp_connection, LOG_MAIN, "SMTP connection from %Y " - "Ci=%lu (TCP/IP connection count = %d)", + "Ci=%s (TCP/IP connection count = %d)", whofrom, connection_id, smtp_accept_count); else log_write(L_smtp_connection, LOG_MAIN, "SMTP connection from %Y " diff --git a/src/src/exim.c b/src/src/exim.c index cca02de5e..0d0396e3e 100644 --- a/src/src/exim.c +++ b/src/src/exim.c @@ -5475,7 +5475,7 @@ if (host_checking) "**** This is not for real!\n\n", sender_host_address); - connection_id = getpid(); + set_connection_id(); memset(sender_host_cache, 0, sizeof(sender_host_cache)); if (verify_check_host(&hosts_connection_nolog) == OK) { @@ -5664,7 +5664,7 @@ because a log line has already been written for all its failure exists (usually "connection refused: ") and writing another one is unnecessary clutter. */ -connection_id = getpid(); +set_connection_id(); if (smtp_input) { smtp_in = stdin; diff --git a/src/src/expand.c b/src/src/expand.c index b50639e4b..4135574d6 100644 --- a/src/src/expand.c +++ b/src/src/expand.c @@ -532,6 +532,7 @@ static var_entry var_table[] = { { "compile_number", vtype_stringptr, &version_cnumber }, { "config_dir", vtype_stringptr, &config_main_directory }, { "config_file", vtype_stringptr, &config_main_filename }, + { "connection_id", vtype_stringptr, &connection_id }, { "csa_status", vtype_stringptr, &csa_status }, #ifdef EXPERIMENTAL_DCC { "dcc_header", vtype_stringptr, &dcc_header }, diff --git a/src/src/functions.h b/src/src/functions.h index 079e94f5e..5d20bb2fc 100644 --- a/src/src/functions.h +++ b/src/src/functions.h @@ -1352,6 +1352,20 @@ return NULL; /******************************************************************************/ # if !defined(COMPILE_UTILITY) + +/* We use the PID of the head process for a connection-id. Note that +this is only for tracking a received connection and what it directly +causes; there is no inttent to describe transport-initiated TCP connections. +The value is intented to be a cookie usable for logging, and we might change +the generator for it at any time. */ + +static inline void +set_connection_id(void) +{ +connection_id = string_sprintf("%lu", (u_long)getpid()); +} + + /* Process manipulation */ static inline pid_t diff --git a/src/src/globals.c b/src/src/globals.c index a4b142bc0..02349497f 100644 --- a/src/src/globals.c +++ b/src/src/globals.c @@ -739,7 +739,7 @@ uid_t config_uid = CONFIGURE_OWNER; uid_t config_uid = 0; #endif -uint64_t connection_id = 0L; +const uschar *connection_id = NULL; int connection_max_messages= -1; unsigned continue_flags = 0; #ifndef DISABLE_ESMTP_LIMITS diff --git a/src/src/globals.h b/src/src/globals.h index 05c39109e..65eb4e4a5 100644 --- a/src/src/globals.h +++ b/src/src/globals.h @@ -435,7 +435,7 @@ extern gstring *client_cmd_log; /* debug log of client cmds & responses * extern int clmacro_count; /* Number of command line macros */ extern uschar *clmacros[]; /* Copy of them, for re-exec */ extern BOOL commandline_checks_require_admin; /* belt and braces for insecure setups */ -extern uint64_t connection_id; /* connection number */ +extern const uschar *connection_id; /* connection cookie for log */ extern int connection_max_messages;/* Max down one SMTP connection */ extern FILE *config_file; /* Configuration file */ extern const uschar *config_filename; /* Configuration file name */ diff --git a/src/src/host.c b/src/src/host.c index 597971814..182e5068b 100644 --- a/src/src/host.c +++ b/src/src/host.c @@ -629,7 +629,7 @@ else g = string_fmt_append(g, " U=%s", sender_ident); } if (LOGGING(connection_id)) - g = string_fmt_append(g, " Ci=%lu", connection_id); + g = string_fmt_append(g, " Ci=%s", connection_id); gstring_release_unused(g); return string_from_gstring(g); } diff --git a/src/src/receive.c b/src/src/receive.c index cc64f44f4..1ee02c5b7 100644 --- a/src/src/receive.c +++ b/src/src/receive.c @@ -1395,7 +1395,7 @@ if (f.tcp_in_fastopen && !f.tcp_in_fastopen_logged) if (sender_ident) g = string_append(g, 2, US" U=", sender_ident); if (LOGGING(connection_id)) - g = string_fmt_append(g, " Ci=%lu", connection_id); + g = string_fmt_append(g, " Ci=%s", connection_id); if (received_protocol) g = string_append(g, 2, US" P=", received_protocol); if (LOGGING(pipelining) && f.smtp_in_pipelining_advertised) diff --git a/src/src/smtp_in.c b/src/src/smtp_in.c index eadad682b..150d65a2d 100644 --- a/src/src/smtp_in.c +++ b/src/src/smtp_in.c @@ -1355,7 +1355,7 @@ const uschar * hostname = sender_fullhost gstring * g = string_catn(NULL, US"SMTP connection", 15); if (LOGGING(connection_id)) - g = string_fmt_append(g, " Ci=%lu", connection_id); + g = string_fmt_append(g, " Ci=%s", connection_id); g = string_catn(g, US" from ", 6); if (host_checking) diff --git a/test/confs/0002 b/test/confs/0002 index 7e565805b..7e346d54d 100644 --- a/test/confs/0002 +++ b/test/confs/0002 @@ -39,7 +39,7 @@ LENCHECK begin acl connect0: - accept + accept logwrite = connection_id: $connection_id connect1: deny hosts = <\n partial-lsearch;DIR/aux-fixed/0002.lsearch \n 1.2.3.4 diff --git a/test/runtest b/test/runtest index 3b936de3d..d3cea20a8 100755 --- a/test/runtest +++ b/test/runtest @@ -1205,6 +1205,9 @@ RESET_AFTER_EXTRA_LINE_READ: # Lines with a leading pid. Only handle >= 4-digit PIDs to avoid converting SMTP respose codes s/^\s*(\d{4,})\s(?!(?:previous message|in\s|bytes remain in|SMTP accept process running))/new_value($1, "p%s", \$next_pid) . ' '/e; + # Connection IDs + s/connection_id: \K(\d+)$/new_value($1, "conn%s", \$next_conn)/e; + # Debugging lines for Exim terminations and process-generation next if /(?:postfork: | fork(?:ing|ed) for )/; @@ -4608,6 +4611,7 @@ foreach $test (@test_list) $next_msgid = "aX"; $next_pid = 1234; $next_port = 1111; + $next_conn = 1111; $message_skip = 0; $msglog_skip = 0; $munge_skip = 0; diff --git a/test/scripts/0000-Basic/0002 b/test/scripts/0000-Basic/0002 index a90e7ee9c..0ed3e0dff 100644 --- a/test/scripts/0000-Basic/0002 +++ b/test/scripts/0000-Basic/0002 @@ -1090,7 +1090,7 @@ exim -d -bh V4NET.0.0.1 **** exim -d -bh V4NET.0.0.2 **** -# Test $reply_address +# Test $reply_address, $connection_id exim -bh V4NET.0.0.0 helo test mail from:<> diff --git a/test/stderr/0002 b/test/stderr/0002 index 0632de146..a2c0cc657 100644 --- a/test/stderr/0002 +++ b/test/stderr/0002 @@ -655,6 +655,9 @@ search_tidyup called >>> host in helo_accept_junk_hosts? no (option unset) >>> using ACL "connect0" >>> processing "accept" (TESTSUITE/test-config 42) +>>> check logwrite = connection_id: $connection_id +>>> = connection_id: conn1111 +LOG: connection_id: conn1111 >>> accept: condition test succeeded in ACL "connect0" >>> end of ACL "connect0": ACCEPT >>> test in helo_lookup_domains? @@ -745,6 +748,9 @@ LOG: 10HmbB-000000005vi-0000 H=(test) [V4NET.0.0.0] F=<> rejected after DATA: re >>> host in helo_accept_junk_hosts? no (option unset) >>> using ACL "connect0" >>> processing "accept" (TESTSUITE/test-config 42) +>>> check logwrite = connection_id: $connection_id +>>> = connection_id: conn1112 +LOG: connection_id: conn1112 >>> accept: condition test succeeded in ACL "connect0" >>> end of ACL "connect0": ACCEPT >>> test in helo_lookup_domains? @@ -776,6 +782,9 @@ LOG: 10HmbC-000000005vi-0000 H=(test) [V4NET.0.0.0] F=<> rejected after DATA: re >>> host in helo_accept_junk_hosts? no (option unset) >>> using ACL "connect0" >>> processing "accept" (TESTSUITE/test-config 42) +>>> check logwrite = connection_id: $connection_id +>>> = connection_id: conn1113 +LOG: connection_id: conn1113 >>> accept: condition test succeeded in ACL "connect0" >>> end of ACL "connect0": ACCEPT >>> test in helo_lookup_domains? -- 2.30.2