Improve ID handling in tests

The comments in `_send_email_and_get_id` are pretty self-explanatory.
The whole thing has become more robust while it is now capable of
capturing more log lines.

test/helper/common.bash

@@ -466,7 +466,7 @@ function _print_mail_log_for_id() {
   local MAIL_ID=${1:?Mail ID must be provided}
   local CONTAINER_NAME=$(__handle_container_name "${2:-}")
 
-  _run_in_container grep -F "${MAIL_ID}" /var/log/mail.log
+  _run_in_container grep -E "${MAIL_ID}" /var/log/mail.log
 }
 
 # A simple wrapper for netcat (`nc`). This is useful when sending

test/helper/sending.bash

@@ -89,19 +89,25 @@ function _send_email() {
 # Like `_send_email` with two major differences:
 #
 # 1. this function waits for the mail to be processed; there is no asynchronicity
-#    because filtering the logs in a synchronous way is easier and safer!
+#    because filtering the logs in a synchronous way is easier and safer;
-# 2. this function prints an ID one can later filter by to check logs
+# 2. this function takes the name of a variable and inserts ID(s) one can later
+#    filter by to check logs.
 #
 # No. 2 is especially useful in case you send more than one email in a single
 # test file and need to assert certain log entries for each mail individually.
 #
-# This function takes the same arguments as `_send_mail`.
+# The first argument has to be the name of the variable that the e-mail ID is stored
+# in. The rest of the arguments are the same as `_send_email`.
 #
 # ## Attention
 #
 # This function assumes `CONTAINER_NAME` to be properly set (to the container
 # name the command should be executed in)!
 #
+# Moreover, if `--data <DATA>` is specified, the additional header added implicitly
+# (with `--add-header`) may get lost, so pay attention to the data having the token
+# to place additonal headers into.
+#
 # ## Safety
 #
 # This functions assumes **no concurrent sending of emails to the same container**!
@@ -109,20 +115,48 @@ function _send_email() {
 # chosen. Sending more than one mail at any given point in time with this function
 # is UNDEFINED BEHAVIOR!
 function _send_email_and_get_id() {
-  [[ -v CONTAINER_NAME ]] || return 1
+  # Get the name of the variable that the ID is stored in
+  local ID_NAME="${1:?Mail ID must be set for _send_email_and_get_id}"
+  # Get a "reference" so wan manipulate the ID
+  local -n MAIL_ID=${ID_NAME}
+  # Export the variable so everyone has access
+  # `:?` is required, otherwise ShellCheck complains
+  export "${ID_NAME:?}"
+  shift 1
 
   _wait_for_empty_mail_queue_in_container
-  _send_email "${@}"
+  _send_email "${@}" --add-header "Message-Id: ${ID_NAME}"
   _wait_for_empty_mail_queue_in_container
 
-  local MAIL_ID
   # The unique ID Postfix (and other services) use may be different in length
   # on different systems (e.g. amd64 (11) vs aarch64 (10)). Hence, we use a
   # range to safely capture it.
-  MAIL_ID=$(_exec_in_container tac /var/log/mail.log              \
+  #
-    | grep -E -m 1 'postfix/smtpd.*: [A-Z0-9]+: client=localhost' \
+  # First, we define the regular expressions we need for capturing the IDs.
-    | grep -E -o '[A-Z0-9]{9,12}' || true)
+  local REGEX_ID_PART_ONE='[A-Z0-9]{9,12}'
+  local REGEX_ID_PART_TWO="$(date +'%Y%m%d')[0-9]+\\.[0-9]+"
+  # The first line Postfix logs looks something like this:
+  #
+  # Jan  4 16:09:19 mail postfix/cleanup[1188]: 07B29249A7: message-id=MAIL_ID_HEADER
+  #
+  # where 07B29249A7 is one of the IDs we are searching for and MAIL_ID_HEADER is the ID_NAME.
+  # Note that we are searching the log in reverse, which is important to get the correct ID.
+  MAIL_ID=$(_exec_in_container tac /var/log/mail.log \
+    | grep -F -m 1 "message-id=${ID_NAME}" \
+    | grep -E -o "${REGEX_ID_PART_ONE}")
+  # We additionally grep for another ID that Postfix (and later mechanisms like Sieve) use (additionally),
+  # and the line looks something like this:
+  #
+  # Jan  4 16:09:19 mail postfix/cleanup[1188]: 07B29249A7: message-id=<20240104160919.001289@mail.example.test>
+  #
+  # where 20240104160919 is the other ID we are searching for. Note that the date is encoded by this ID.
+  # We exploit the fact that MAIL_ID is already on the line, so we can search for it efficiently. Moreover,
+  # these lines appear close to each other (usually next to each other). When looking in reverse.
+  MAIL_ID+="|$(_exec_in_container grep -F "${MAIL_ID}: message-id=" /var/log/mail.log \
+    | grep -E -o "${REGEX_ID_PART_TWO}")"
 
+  # Last but not least, we perform plausibility checks on the IDs.
   assert_not_equal "${MAIL_ID}" ''
-  echo "${MAIL_ID}"
+  run echo "${MAIL_ID}"
+  assert_line --regexp "^${REGEX_ID_PART_ONE}|${REGEX_ID_PART_TWO}$"
 }

test/tests/parallel/set1/spam_virus/postscreen.bats

@@ -56,12 +56,10 @@ function teardown_file() {
 @test "should successfully pass postscreen and get postfix greeting message (respecting postscreen_greet_wait time)" {
   # Configure `send_email()` to send from the mail client container (CONTAINER2_NAME) via ENV override,
   # mail is sent to the DMS server container (CONTAINER1_NAME) via `--server` parameter:
-  # TODO: Use _send_email when proper resolution of domain names is possible:
+  # TODO: Use _send_email_and_get_id when proper resolution of domain names is possible:
   CONTAINER_NAME=${CONTAINER2_NAME} _send_email_unchecked --server "${CONTAINER1_IP}" --port 25 --data 'postscreen'
-
+  # CONTAINER_NAME=${CONTAINER2_NAME} _send_email_and_get_id MAIL_ID_POSTSCREEN --server "${CONTAINER1_IP}" --data 'postscreen'
-  # TODO: Prefer this approach when `_send_email_and_get_id()` can support separate client and server containers:
+  # _print_mail_log_for_id "${MAIL_ID_POSTSCREEN}"
-  # local MAIL_ID=$(_send_email_and_get_id --port 25 --data 'postscreen')
-  # _print_mail_log_for_id "${MAIL_ID}"
   # assert_output --partial "stored mail into mailbox 'INBOX'"
 
   _run_in_container cat /var/log/mail.log

test/tests/parallel/set1/spam_virus/rspamd_full.bats

@@ -43,16 +43,20 @@ function setup_file() {
   _wait_for_service postfix
   _wait_for_smtp_port_in_container
 
-  # We will send 3 emails: the first one should pass just fine; the second one should
+  # We will send 4 emails:
-  # be rejected due to spam; the third one should be rejected due to a virus.
+  # 1. The first one should pass just fine
-  export MAIL_ID1=$(_send_email_and_get_id --from 'rspamd-pass@example.test' --data 'rspamd/pass')
+  _send_email_and_get_id MAIL_ID_PASS
-  export MAIL_ID2=$(_send_email_and_get_id --from 'rspamd-spam@example.test' --data 'rspamd/spam')
+  # 2. The second one should be rejected due to spam (GTube pattern)
-  export MAIL_ID3=$(_send_email_and_get_id --from 'rspamd-virus@example.test' --data 'rspamd/virus')
+  _send_email_and_get_id MAIL_ID_SPAM --body 'XJS*C4JDBQADN1.NSBN3*2IDNEN*GTUBE-STANDARD-ANTI-UBE-TEST-EMAIL*C.34X'
-  export MAIL_ID4=$(_send_email_and_get_id --from 'rspamd-spam-header@example.test' --data 'rspamd/spam-header')
+  # 3. Te third one should be rejected due to a virus (ClamAV Eicar pattern)
+  # shellcheck disable=SC2016
+  _send_email_and_get_id MAIL_ID_VIRUS --body 'X5O!P%@AP[4\PZX54(P^)7CC)7}$EICAR-STANDARD-ANTIVIRUS-TEST-FILE!$H+H*'
+  # 4. The fourth one will receive an added header (GTube pattern)
+  _send_email_and_get_id MAIL_ID_HEADER --body 'YJS*C4JDBQADN1.NSBN3*2IDNEN*GTUBE-STANDARD-ANTI-UBE-TEST-EMAIL*C.34X'
 
-  for ID in MAIL_ID{1,2,3,4}; do
+  _run_in_container cat /var/log/mail.log
-    [[ -n ${!ID} ]] || { echo "${ID} is empty - aborting!" ; return 1 ; }
+  assert_success
-  done
+  refute_output --partial 'inet:localhost:11332: Connection refused'
 }
 
 function teardown_file() { _default_teardown ; }
@@ -104,7 +108,7 @@ function teardown_file() { _default_teardown ; }
 @test 'normal mail passes fine' {
   _service_log_should_contain_string 'rspamd' 'F \(no action\)'
 
-  _print_mail_log_for_id "${MAIL_ID1}"
+  _print_mail_log_for_id "${MAIL_ID_PASS}"
   assert_output --partial "stored mail into mailbox 'INBOX'"
 
   _count_files_in_directory_in_container /var/mail/localhost.localdomain/user1/new/ 1
@@ -114,7 +118,7 @@ function teardown_file() { _default_teardown ; }
   _service_log_should_contain_string 'rspamd' 'S \(reject\)'
   _service_log_should_contain_string 'rspamd' 'reject "Gtube pattern"'
 
-  _print_mail_log_for_id "${MAIL_ID2}"
+  _print_mail_log_for_id "${MAIL_ID_SPAM}"
   assert_output --partial 'milter-reject'
   assert_output --partial '5.7.1 Gtube pattern'
 
@@ -125,7 +129,7 @@ function teardown_file() { _default_teardown ; }
   _service_log_should_contain_string 'rspamd' 'T \(reject\)'
   _service_log_should_contain_string 'rspamd' 'reject "ClamAV FOUND VIRUS "Eicar-Signature"'
 
-  _print_mail_log_for_id "${MAIL_ID3}"
+  _print_mail_log_for_id "${MAIL_ID_VIRUS}"
   assert_output --partial 'milter-reject'
   assert_output --partial '5.7.1 ClamAV FOUND VIRUS "Eicar-Signature"'
   refute_output --partial "stored mail into mailbox 'INBOX'"
@@ -214,7 +218,7 @@ function teardown_file() { _default_teardown ; }
   _service_log_should_contain_string 'rspamd' 'S \(add header\)'
   _service_log_should_contain_string 'rspamd' 'add header "Gtube pattern"'
 
-  _print_mail_log_for_id "${MAIL_ID4}"
+  _print_mail_log_for_id "${MAIL_ID_HEADER}"
   assert_output --partial "fileinto action: stored mail into mailbox 'Junk'"
 
   _count_files_in_directory_in_container /var/mail/localhost.localdomain/user1/new/ 1