From 6e1550b2be540da349b87cfc02c7cf35c4266965 Mon Sep 17 00:00:00 2001 From: georglauterbach <44545919+georglauterbach@users.noreply.github.com> Date: Thu, 4 Jan 2024 18:08:22 +0100 Subject: [PATCH] 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 | 2 +- test/helper/sending.bash | 54 +++++++++++++++---- .../parallel/set1/spam_virus/postscreen.bats | 8 ++- .../parallel/set1/spam_virus/rspamd_full.bats | 30 ++++++----- 4 files changed, 65 insertions(+), 29 deletions(-) diff --git a/test/helper/common.bash b/test/helper/common.bash index ab21ef60..aedb33ba 100644 --- a/test/helper/common.bash +++ b/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 diff --git a/test/helper/sending.bash b/test/helper/sending.bash index 1b69eb9c..90d2da71 100644 --- a/test/helper/sending.bash +++ b/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! -# 2. this function prints an ID one can later filter by to check logs +# because filtering the logs in a synchronous way is easier and safer; +# 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 ` 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' \ - | grep -E -o '[A-Z0-9]{9,12}' || true) + # + # First, we define the regular expressions we need for capturing the IDs. + 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}$" } diff --git a/test/tests/parallel/set1/spam_virus/postscreen.bats b/test/tests/parallel/set1/spam_virus/postscreen.bats index 750e78b0..75b14264 100644 --- a/test/tests/parallel/set1/spam_virus/postscreen.bats +++ b/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' - - # TODO: Prefer this approach when `_send_email_and_get_id()` can support separate client and server containers: - # local MAIL_ID=$(_send_email_and_get_id --port 25 --data 'postscreen') - # _print_mail_log_for_id "${MAIL_ID}" + # CONTAINER_NAME=${CONTAINER2_NAME} _send_email_and_get_id MAIL_ID_POSTSCREEN --server "${CONTAINER1_IP}" --data 'postscreen' + # _print_mail_log_for_id "${MAIL_ID_POSTSCREEN}" # assert_output --partial "stored mail into mailbox 'INBOX'" _run_in_container cat /var/log/mail.log diff --git a/test/tests/parallel/set1/spam_virus/rspamd_full.bats b/test/tests/parallel/set1/spam_virus/rspamd_full.bats index 2e610d72..64afaf36 100644 --- a/test/tests/parallel/set1/spam_virus/rspamd_full.bats +++ b/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 - # be rejected due to spam; the third one should be rejected due to a virus. - export MAIL_ID1=$(_send_email_and_get_id --from 'rspamd-pass@example.test' --data 'rspamd/pass') - export MAIL_ID2=$(_send_email_and_get_id --from 'rspamd-spam@example.test' --data 'rspamd/spam') - export MAIL_ID3=$(_send_email_and_get_id --from 'rspamd-virus@example.test' --data 'rspamd/virus') - export MAIL_ID4=$(_send_email_and_get_id --from 'rspamd-spam-header@example.test' --data 'rspamd/spam-header') + # We will send 4 emails: + # 1. The first one should pass just fine + _send_email_and_get_id MAIL_ID_PASS + # 2. The second one should be rejected due to spam (GTube pattern) + _send_email_and_get_id MAIL_ID_SPAM --body 'XJS*C4JDBQADN1.NSBN3*2IDNEN*GTUBE-STANDARD-ANTI-UBE-TEST-EMAIL*C.34X' + # 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 - [[ -n ${!ID} ]] || { echo "${ID} is empty - aborting!" ; return 1 ; } - done + _run_in_container cat /var/log/mail.log + assert_success + 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