tests(fix): lmtp_ip.bats improve partial failure output (#3552)

Instead of exit status of `124` (_signifies timeout_), it should fail with `1` (failure) like the others. Handled via using `_run_in_container_bash()` (_`timeout` failure `124` does not propagate and is treated as `1` instead_).

In this case we are waiting on the status of the mail being sent, the pattern provided to `grep` is too specific and results in a timeout. Instead since we only expect the one log entry, match any status and assert the expected pattern afterwards.

This provides a more helpful failure output that informs us that mail was at least processed by Postfix, but the sent status is not what we expected.

### Before

```
 ✗ [ENV] (POSTFIX_DAGENT) delivers mail to existing account [60327]
   (from function `assert_success' in file test/test_helper/bats-assert/src/assert_success.bash, line 42,
    in test file test/tests/parallel/set3/mta/lmtp_ip.bats, line 47)
     `assert_success' failed

   -- command failed --
   status : 124
   output :
   --
```

### After

```
 ✗ [ENV] (POSTFIX_DAGENT) delivers mail to existing account [1425]
   (from function `assert_output' in file test/test_helper/bats-assert/src/assert_output.bash, line 178,
    in test file test/tests/parallel/set3/mta/lmtp_ip.bats, line 48)
     `assert_output --regexp "${MATCH_LOG_LINE}=sent .* Saved)"' failed

   -- regular expression does not match output --
   regexp : postfix/lmtp.* status=sent .* Saved)
   output : Sep 28 04:12:52 mail postfix/lmtp[721]: 23701B575: to=<user1@localhost.localdomain>, relay=127.0.0.1[127.0.0.1]:24, delay=0.08, delays=0.07/0/0.01/0, dsn=4.2.0, status=deferred (host 127.0.0.1[127.0.0.1] said: 451 4.2.0 <user1@localhost.localdomain> Internal error occurred. Refer to server log for more information. [2023-09-28 04:12:52] (in reply to end of DATA command))
   --
```

The expected pattern is logged as `assert_success` confirms a valid match for the log line of interest was found, and we have the mismatched value to debug the failure against.
This commit is contained in:
Brennan Kinney 2023-09-29 10:17:57 +13:00 committed by GitHub
parent a9d6e329cd
commit 89cb6d85b9
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23

View file

@ -42,7 +42,9 @@ function teardown_file() { _default_teardown ; }
# Verify delivery was successful, log line should look similar to: # Verify delivery was successful, log line should look similar to:
# postfix/lmtp[1274]: 0EA424ABE7D9: to=<user1@localhost.localdomain>, relay=127.0.0.1[127.0.0.1]:24, delay=0.13, delays=0.07/0.01/0.01/0.05, dsn=2.0.0, status=sent (250 2.0.0 <user1@localhost.localdomain> ixPpB+Zvv2P7BAAAUi6ngw Saved) # postfix/lmtp[1274]: 0EA424ABE7D9: to=<user1@localhost.localdomain>, relay=127.0.0.1[127.0.0.1]:24, delay=0.13, delays=0.07/0.01/0.01/0.05, dsn=2.0.0, status=sent (250 2.0.0 <user1@localhost.localdomain> ixPpB+Zvv2P7BAAAUi6ngw Saved)
local MATCH_LOG_LINE='postfix/lmtp.* status=sent .* Saved)' local MATCH_LOG_LINE='postfix/lmtp.* status'
run timeout 60 docker exec "${CONTAINER_NAME}" bash -c "tail -F /var/log/mail/mail.log | grep --max-count 1 '${MATCH_LOG_LINE}'" _run_in_container_bash "timeout 60 tail -F /var/log/mail/mail.log | grep --max-count 1 '${MATCH_LOG_LINE}'"
assert_success assert_success
# Assertion of full pattern here (instead of via grep) is a bit more helpful for debugging partial failures:
assert_output --regexp "${MATCH_LOG_LINE}=sent .* Saved)"
} }