tests: normalizations#3747
Conversation
georglauterbach
added
area/tests
kind/improvement
|
@polarathene I'd love if you could assist me with the test failure in |
georglauterbach
removed
the
meta/feature freeze
I added `_send_email_unchecked` which performs no check so we can still use the helper for situations where we check for failure, and `_send_email` is a wrapper for `_send_mail_unchecked` with an additional `assert_success`. I also went through the tests and adjusted them where necessary.
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.
georglauterbach
force-pushed
the
tests/normalizations
branch
3 times, most recently
from
066086c to
783e8df
Compare
With `--data`, we do not need to handle STDIN. We do need additional quoting though, because we expand the array later as a simple string in `_run_in_container_bash`. Moreover, the `@` was added because, according to the documentation of `swaks`, it should be prepended when using file names...
because LOGIN is deprecated (according to swaks documentation).
These e-mails are mostly trivial in `swaks`, and we do not need extra files here.
georglauterbach
force-pushed
the
tests/normalizations
branch
from
783e8df to
2125e41
Compare
❤️ ! I really appreciate that and it'll make it much easier to review. At a glance, I see you've already addressed a bunch of TODO notes I've had written up but haven't published yet as a comment/issue 🤣
For future reader reference (since these failure logs get deleted by Github eventually): Test failureFails at Fails on the last assert at line 238: Failure found Commit that apparently (prior commits lack CI test runs) introduced test failure only removed the Current state of the function _send_email_unchecked() {
[[ -v CONTAINER_NAME ]] || return 1
# Parameter defaults common to our testing needs:
local EHLO='mail.external.tld'
local FROM='[email protected]'
local TO='[email protected]'
local SERVER='0.0.0.0'
local PORT=25
# Extra options for `swaks` that aren't covered by the default options above:
local ADDITIONAL_SWAKS_OPTIONS=()
while [[ ${#} -gt 0 ]]; do
case "${1}" in
( '--ehlo' ) EHLO=${2:?--ehlo given but no argument} ; shift 2 ;;
( '--from' ) FROM=${2:?--from given but no argument} ; shift 2 ;;
( '--to' ) TO=${2:?--to given but no argument} ; shift 2 ;;
( '--server' ) SERVER=${2:?--server given but no argument} ; shift 2 ;;
( '--port' ) PORT=${2:?--port given but no argument} ; shift 2 ;;
( '--data' )
ADDITIONAL_SWAKS_OPTIONS+=('--data')
ADDITIONAL_SWAKS_OPTIONS+=("@/tmp/docker-mailserver-test/emails/${2:?--data given but no argument provided}")
shift 2
;;
( * ) ADDITIONAL_SWAKS_OPTIONS+=("'${1}'") ; shift 1 ;;
esac
done
_run_in_container_bash "swaks --server '${SERVER}' --port '${PORT}' --ehlo '${EHLO}' --from '${FROM}' --to '${TO}' ${ADDITIONAL_SWAKS_OPTIONS[*]}"
}Resolved (See follow-up comment)At a glance, by dropping the We can see that the expected Message-ID header is being matched, just the FQDN is wrong (it's the # Got:
Message-Id: <[email protected]>
# Expected:
Message-Id: <[email protected]>
Comparing the two:
We also know that all earlier assertions for the ENV override of While the docs don't state it, part of the implicit defaults for the |
|
TL;DR: Issue was due to
Resolved
Just spun up a container and ran # Pretend mail is from `external.test` MTA, to the local DMS MTA:
$ swaks --server 0.0.0.0 --port 465 \
--ehlo external.test \
--to [email protected] \
--from [email protected] \
--auth-user [email protected] --auth-password bad-password
=== Trying 0.0.0.0:465...
=== Connected to 0.0.0.0.
<- 220 mail.example.test ESMTP
-> EHLO external.test
<- 250-mail.example.test
<- 250-PIPELINING
<- 250-SIZE 10240000
<- 250-ETRN
<- 250-AUTH PLAIN LOGIN
<- 250-AUTH=PLAIN LOGIN
<- 250-ENHANCEDSTATUSCODES
<- 250-8BITMIME
<- 250-DSN
<- 250 CHUNKING
-> AUTH LOGIN
<- 334 VXNlcm5hbWU6
-> aGVsbG9AZXhhbXBsZS50ZXN0
<- 334 UGFzc3dvcmQ6
-> YmFkLXBhc3N3b3Jk
<- 235 2.7.0 Authentication successful
-> MAIL FROM:<[email protected]>
<- 250 2.1.0 Ok
-> RCPT TO:<[email protected]>
<- 250 2.1.5 Ok
-> DATA
<- 354 End data with <CR><LF>.<CR><LF>
-> Date: Fri, 05 Jan 2024 02:50:43 +0000
-> To: [email protected]
-> From: [email protected]
-> Subject: test Fri, 05 Jan 2024 02:50:43 +0000
-> Message-Id: <[email protected]>
-> X-Mailer: swaks v20201014.0 jetmore.org/john/code/swaks/
->
-> This is a test mailing
->
->
-> .
<- 250 2.0.0 Ok: queued as 40D52131DB
-> QUIT
<- 221 2.0.0 Bye
=== Connection closed with remote host.Additional
|
|
Thanks for your help @polarathene, tests should now pass. I had to fix |
|
Sorry, at a limited capacity atm recovering from an injury that's cutting my time at the desk per day short. I wasn't able to review the actual commits today, only provide the investigation for the test failure. I'll try get the review in after some rest. Should be starting that in roughly 12 hours. Regarding the |
Thanks to @polarathene for helping me here! I also noticed the logic of `_send_email_unchecked` was not 100% sound when supplying the `--data` argument - this has also been fixed.
georglauterbach
force-pushed
the
tests/normalizations
branch
from
8274231 to
6284b20
Compare
|
I force-pushed only the last 3 commits (that IIRC you did not get to yet anyway) to correct a simple error of mine. |
You've included rspamd PR into this by accident. |
ref: #3747 (comment) I also added a bit more context to the function description and I added comments inside the function to help better understand what's going on.
This comment was marked as outdated.
This comment was marked as outdated.
This comment was marked as outdated.
This comment was marked as outdated.
This comment was marked as outdated.
This comment was marked as outdated.
👍🏼
Not quite, but since these some one of the newest tests, they use the helpers. I think all the other tests can use the new
I understand; I will adjust this test specifically in the future by adding more comments to explain what's going on in more detail.
Now I understand that I never had a lot of understanding for SA/Amavis myself 😆 Seems Rspamd and SA/Amavis behave quite differently here.
For non-GTUBE, if the score is high enough (for DMS at the moment a score of 11 IIRC) the mail is outright rejected. GTUBE can trigger such a reject instantly.
High-scoring spam mail will
See docker-mailserver/target/rspamd/local.d/actions.conf Lines 7 to 10 in 8d8936d GTUbe is just a short path of achieving that, or really, a way of testing the proper behavior.
Rspamd adds a few headers. Most important are default: False [-4.10 / 11.00]; SIGNED_SMIME(-2.00)[]; R_SPF_ALLOW(-1.00)[+ip4:212.227.17.0/27]; RWL_AMI_LASTHOP(-1.00)[212.227.17.13:from]; MIME_GOOD(-0.20)[multipart/signed,multipart/alternative,text/plain]; ONCE_RECEIVED(0.10)[]; RCVD_VIA_SMTP_AUTH(0.00)[]; RCVD_TLS_ALL(0.00)[]; RCPT_COUNT_ONE(0.00)[1]; ASN(0.00)[asn:8560, ipnet:212.227.0.0/16, country:DE]; RECEIVED_SPAMHAUS_PBL(0.00)[79.254.17.189:received]; MIME_TRACE(0.00)[0:+,1:+,2:+,3:~,4:~]; RCVD_COUNT_ONE(0.00)[1]; RWL_MAILSPIKE_POSSIBLE(0.00)[212.227.17.13:from]; MID_RHS_MATCH_FROM(0.00)[]; R_DKIM_NA(0.00)[]; ARC_NA(0.00)[]; FROM_EQ_ENVFROM(0.00)[]; FROM_HAS_DN(0.00)[]; RCVD_IN_DNSWL_NONE(0.00)[212.227.17.13:from]; TO_MATCH_ENVRCPT_ALL(0.00)[]; TO_DN_ALL(0.00)[]; PREVIOUSLY_DELIVERED(0.00)[[email protected]]; DMARC_DNSFAIL(0.00)[online.de : query refused]; HAS_ATTACHMENT(0.00)[]and then there is a corresponding |
|
Oh no, my last commit is broken. Please review everything except the last commit. I'am unable to continue today, will fix tomorrow. |
polarathene
left a comment
polarathene
left a comment
There was a problem hiding this comment.
- Optional revisions / suggestions.
- Add context comment on dead-code (
MESSAGE_ID) if keeping it. - Consider setting an explicit message ID header and using common Queue ID extraction if maintaining the branched handling provides no value.
I've also provided a context comment for how Postfix Queue ID is generated, and that your ARM64 findings might be filesystem specific rather than platform? Doesn't seem we can do much about the variable length though (which is fine).
| local QUEUE_ID_REGEX='[A-Z0-9]{9,12}' | ||
| local MESSAGE_ID_REGEX="[0-9]{14}\\.${QUEUE_ID_REGEX}" |
There was a problem hiding this comment.
Context comment, no action required.
Curious, I hit up the postfix docs and voila enable_long_queue_ids. That should explain the difference (seems related to the inode number?), it also notes how it defines both the Queue ID and Message ID generation for both yes / no (default) values.
So it may not have been AMD64 vs ARM64, but rather filesystems and the inode number being encoded into base 52 (yes) or base 16 (no)? Or just the inode number itself, since leading 0 is possibly dropped (so short IDs are 5 chars for time + 8 chars for 32-bit inode number)
With enable_long_queue_ids=yes you always get a z to delimit the time and inode encoded values. For the inode number encoded, base 16 vs base 51 (inode is enocded in base 52 without the z) on my system is producing 6 chars vs 3 chars. On your ARM64 system that is presumably a bit longer, but I don't know about it being ARM64 specific.
Other references:
-
Postfix QueueID Size whyscream/postfix-grok-patterns#115 (comment)
-
The queue ID is in part based on the message file's inode number (*).
The length of a queue ID therefore depends on the range of inode numbers in the file system. -
https://narkive.com/nthhd8C5.2
The current implementation, subject to change, uses the inode number followed by the (sub-second portion of the) time in microseconds.
The maximal length is determined by the maximal inode number.The 5 hex nibbles of microsecond time precede the hex nibbles of the inode
number.
| _wait_for_smtp_port_in_container | ||
| _wait_for_tcp_port_in_container 10024 # port 10024 is for Amavis | ||
| _send_email --from '[email protected]' --data 'amavis/spam' | ||
| _send_email --from '[email protected]' --data 'amavis/spam.txt' |
There was a problem hiding this comment.
Like here:
function send_spam() {
_send_email --from '[email protected]' --data "${GTUBE}"
}| _send_email --from '[email protected]' --data 'amavis/spam.txt' | |
| _send_spam |
Maybe for a future follow-up PR, since I had an approach in mind before the revised sending.bash PRs appeared 😝
There was a problem hiding this comment.
👍🏼 Future PR please :D
I'd only want to see that if it's providing value to the tests without introducing too much additional complexity / abstraction 😅 The previous approach with files was a bit straight forward to grok over without digging through actual tests using them to know what we're testing coverage wise. We lose that a bit with migrating from external files to equivalent in args at the specific test-cases using them and implicit logic / handling. In some cases that's a non-issue and We have a lot going on here in this PR already, so I've been avoiding discussing It'll be better for the default fallback values, since the current approach you chose to implement makes the args mandatory (or has required special handling during iterations). Precedence for Using RELATED: Alternative way of retrieving the Queue ID (only works when mail would be delivered? limiting it's usefulness)
Just pointing out the relevant rspamd docs / behaviour is sufficient. Main issue was I had familiarity with Similar to how LDAP support became a mystery no current maintainer at the time could grok from lack of context/familiarity.
That's understandable. I think we may have other bugs related to SA/Amavis too, but it's not really something any maintainer is deeply invested in or familiar with AFAIK 🤷♂️ When rspamd takes the spotlight as the new default, just something to be aware of. Potentially the test-suite will improve before then and I can unify common test cases for spam/dkim support which may help with catching those differences early. I am focused on v14 PRs, but running low on time to spare. I am not sure of my availability late Jan onwards.
That may be something to consider documenting awareness on when you introduce rspamd as default. When handling #3756 I added a reference to the The expectation was for mail to be delivered to spam by default regardless, not rejected / bounced. Perhaps 11 in rspamd is sufficient but the changelog should definitely communicate this difference in expectation.
That doesn't appear to be communicated at our rspamd docs page? If rspamd is to be the default in future, it'd be nice for users to more easily come across that information without having to sift through upstream docs or our related source files.
If so that may explain the header name, might be compatibility / convention for downstream services.
AFAIK that is the same with Amavis:
That's as much as I know about it 😅 |
Co-authored-by: Brennan Kinney <[email protected]>
|
From what I read so far: I will provide another PR just for Rspamd docs + tests (more information is required on these fronts). I will also push another commit which applies your proposal @polarathene for simplifying queue ID management in |
polarathene
left a comment
polarathene
left a comment
There was a problem hiding this comment.
Minor feedback. Otherwise LGTM 👍
| # But we also requre potential Dovecot sieve output, which requires the mesage ID, | ||
| # so we need to provide the message ID too. | ||
| ID_ENV_VAR_REF+="|${MID}" |
There was a problem hiding this comment.
Is $MID not obvious to the caller of _send_email_and_get_id()? ("<${1}@dms-tests>")
They could match against the Dovecot msgid with that same input then. Technically the whole need for the reference var vs just using a regular arg seems no longer required? 🤔
I'm fine with the PR merging with whichever approach you want to use.
There was a problem hiding this comment.
Is
$MIDnot obvious to the caller of_send_email_and_get_id()? ("<${1}@dms-tests>")
No, I actually think it is only obvious to me and you, but not to others.
They could match against the Dovecot
msgidwith that same input then.
Still easier to just use _print_mail_log_for_id IMO.
Technically the whole need for the reference var vs just using a regular arg seems no longer required? 🤔
I don't get why this is the case TBH. The reference is important to not rely on subshells, which hide exit codes and asserts.
I'm fine with the PR merging with whichever approach you want to use.
I'd definitely go with refs, since there is very good reason for choosing them.
There was a problem hiding this comment.
Is
$MIDnot obvious to the caller of_send_email_and_get_id()? ("<${1}@dms-tests>")No, I actually think it is only obvious to me and you, but not to others.
I meant, tests would just call something like:
# MID is set here, it's pretty obvious to the caller
# (who'd otherwise be able to pass this to current `_send_email_and_get_id()` anyway..)
local MID="<rspamd-gtube-reject@dms-tests>"
# Send an email as you normally would, but include the MID to match:
_send_email --expect-rejection \
--header "Message-Id: ${MID}" \
--body "XJS${GTUBE_SUFFIX}"
# Dedicated function that takes the MID, waits for empty queue and returns Queue ID
_print_mail_log_for_queue_id "$(_get_queue_id ${MID})"
# Actual asserts that matter:
assert_output --partial 'milter-reject'
assert_output --partial '5.7.1 Gtube pattern'
# Dovecot Sieve (spam to junk) shouldn't exist for this mail (QID doesn't exist on this log line)
_filter_service_log 'mail' "msgid=${MID}"
assert_failureThey could match against the Dovecot
msgidwith that same input then.Still easier to just use
_print_mail_log_for_idIMO.
As shown above with the Dovecot example, your method won't help as the queue ID is for Postfix, it's not part of the Dovecot log, unless we avoid providing our own message ID header and let Postfix generate one that includes the original queue ID (this is not the queue ID that you necessarily use to match logs, as I have shown it can change while message ID persists).
Thus Queue ID and Message ID values won't necessarily cover all log lines of interest alone. Hence the logic to match by message ID, and get the queue ID of a specific log entry that it is known the queue ID can differ.
Technically the whole need for the reference var vs just using a regular arg seems no longer required? 🤔
I don't get why this is the case TBH. The reference is important to not rely on subshells, which hide exit codes and asserts.
I'd definitely go with refs, since there is very good reason for choosing them.
I just prefer keeping the helpers simple. If the main purpose is just to get the Queue ID from a Message ID, I'm not sure how this differs from convention of other helpers regarding exit codes and asserts where the use of a reference is necessary.
If this was a nicer language like Rust I'd still probably opt for a function that takes an input parameter (as reference) and returns a value rather than a reference (or mutating a value from a reference).
I'm not great with bash, so if you feel it's really worthwhile/important, I'm not going to challenge that and trust your call, I just personally don't see the pragmatic benefit provided vs something simpler.
There was a problem hiding this comment.
Is
$MIDnot obvious to the caller of_send_email_and_get_id()? ("<${1}@dms-tests>")No, I actually think it is only obvious to me and you, but not to others.
I meant, tests would just call something like:
# MID is set here, it's pretty obvious to the caller # (who'd otherwise be able to pass this to current `_send_email_and_get_id()` anyway..) local MID="<rspamd-gtube-reject@dms-tests>" # Send an email as you normally would, but include the MID to match: _send_email --expect-rejection \ --header "Message-Id: ${MID}" \ --body "XJS${GTUBE_SUFFIX}" # Dedicated function that takes the MID, waits for empty queue and returns Queue ID _print_mail_log_for_queue_id "$(_get_queue_id ${MID})" # Actual asserts that matter: assert_output --partial 'milter-reject' assert_output --partial '5.7.1 Gtube pattern' # Dovecot Sieve (spam to junk) shouldn't exist for this mail (QID doesn't exist on this log line) _filter_service_log 'mail' "msgid=${MID}" assert_failure
That seems more verbose than it needs to be, IMO. Moreover, with the current approach, building MID is easy if it is ever required. The line _filter_service_log 'mail' "msgid=${MID}" fails, but filtering for ${MID} directly (as _send_email_and_get_id currently does) yields proper output.
They could match against the Dovecot
msgidwith that same input then.Still easier to just use
_print_mail_log_for_idIMO.As shown above with the Dovecot example, your method won't help as the queue ID is for Postfix, it's not part of the Dovecot log, unless we avoid providing our own message ID header and let Postfix generate one that includes the original queue ID (this is not the queue ID that you necessarily use to match logs, as I have shown it can change while message ID persists).
Thus Queue ID and Message ID values won't necessarily cover all log lines of interest alone. Hence the logic to match by message ID, and get the queue ID of a specific log entry that it is known the queue ID can differ.
Technically the whole need for the reference var vs just using a regular arg seems no longer required? 🤔
I don't get why this is the case TBH. The reference is important to not rely on subshells, which hide exit codes and asserts.
I'd definitely go with refs, since there is very good reason for choosing them.
I just prefer keeping the helpers simple. If the main purpose is just to get the Queue ID from a Message ID, I'm not sure how this differs from convention of other helpers regarding exit codes and asserts where the use of a reference is necessary.
If this was a nicer language like Rust I'd still probably opt for a function that takes an input parameter (as reference) and returns a value rather than a reference (or mutating a value from a reference).
I'm not great with bash, so if you feel it's really worthwhile/important, I'm not going to challenge that and trust your call, I just personally don't see the pragmatic benefit provided vs something simpler.
I think complexity is not too high really for _send_email_and_get_id. I think the local -n reference is required and I'd definitely go for it :)
There was a problem hiding this comment.
That seems more verbose than it needs to be, IMO. Moreover, with the current approach, building
MIDis easy if it is ever required.The line
_filter_service_log 'mail' "msgid=${MID}"fails, but filtering for${MID}directly (as_send_email_and_get_idcurrently does) yields proper output.
???
What is more verbose?
- The
_send_emailis the equivalent of your_send_email_and_get_id --expect-rejection --body ...for one of the rspamd calls. You pass a string to be part of the MID value instead of declaring the full header. - Middle portion is your own test case
- Final part shows Dovecot
msgidmatching. In this test case the log matching is expected to fail as the assert afterwards implies. It doesn't exist with the rspamd body triggering reject. - You would not get a match on this log line with your methods due to the MID being the search keyword needed, the queue ID isn't part of the log line 🤨 (my comment mentioned all that)
I think complexity is not too high really for
_send_email_and_get_id. I think thelocal -nreference is required and I'd definitely go for it :)
My example was to draw attention that it's doing extra work than appears necessary 🤷♂️ as opposed to something clearer which can also match a dovecot sieve msgid log line (when one is present).
There was a problem hiding this comment.
That seems more verbose than it needs to be, IMO. Moreover, with the current approach, building
MIDis easy if it is ever required.
The line_filter_service_log 'mail' "msgid=${MID}"fails, but filtering for${MID}directly (as_send_email_and_get_idcurrently does) yields proper output.???
Forget what I said, I was not reading correctly to begin with - sorry.
What is more verbose?
The
_send_emailis the equivalent of your_send_email_and_get_id --expect-rejection --body ...for one of the rspamd calls. You pass a string to be part of the MID value instead of declaring the full header.Middle portion is your own test case
Final part shows Dovecot
msgidmatching. In this test case the log matching is expected to fail as the assert afterwards implies. It doesn't exist with the rspamd body triggering reject.
Now I understand what you mean! We could implement this as well, I don't mind :)
- You would not get a match on this log line with your methods due to the MID being the search keyword needed, the queue ID isn't part of the log line 🤨 (my comment mentioned all that)
I don't quite get that though; ${MID} is part of the ID we're currently using (second part of the regex (|${MID})). I think we're talking about different things here; which log line are you referring to with "this"?
I think complexity is not too high really for
_send_email_and_get_id. I think thelocal -nreference is required and I'd definitely go for it :)My example was to draw attention that it's doing extra work than appears necessary 🤷♂️ as opposed to something clearer which can also match a dovecot sieve
msgidlog line (when one is present).
The rspamd_full test shows that _send_email_and_get_id is already capable of providing Dovecot Sieve log lines, or am I missing something?
docker-mailserver/test/tests/parallel/set1/spam_virus/rspamd_full.bats
Lines 225 to 226 in 06fab3f
Co-authored-by: Brennan Kinney <[email protected]>
polarathene
left a comment
polarathene
left a comment
There was a problem hiding this comment.
LGTM 👍
@casperklein may want to glance over sending.bash, but I think overall this is fine to merge :)
casperklein
left a comment
casperklein
left a comment
There was a problem hiding this comment.
LGTM 👍
@casperklein may want to glance over
sending.bash, but I think overall this is fine to merge :)
I had a quick look, but honestly, I can't take the time to really dig into it right now. If our tests run successful with that changes, that's the best approval 👍
Go ahead and merge 🚀
3 participants
Description
See #3739 for what is fixed with this PR. Review commit by commit - I really put more effort into single commits this time, I promise @polarathene 😆 ❤️
Fixes #3739
Fixes #3733
Type of change
Checklist:
docs/)CHANGELOG.md