Chris,
Mark, now I'm confused. As you can see the 'action 0 .....' takes place
before the DKIM lookup
Oct 22 09:16:14.220 [8459] dbg: check: tagrun - action 0 blocking on
tags DKIMDOMAIN
Yes, that's normal. It happens immediately after basic information
has been extracted from a mail header ('extract_metadata' plugins hook).
In case of this dependency on DKIMDOMAIN it is a direct consequence
of having rules DKIMDOMAIN_IN_DWL and __DKIMDOMAIN_IN_DWL_ANY,
regardless of the actual message.
The 'check: tagrun - action ... blocking on ...' log message
just says that a callback routine has been provided, which is
to be called at some point later if/when a tag value for a
tag DKIMDOMAIN becomes available.
Oct 22 09:16:14.623 [8459] dbg: dkim: signature verification result:
FAIL (BODY HAS BEEN ALTERED)
Oct 22 09:16:14.623 [8459] dbg: dkim: FAILED signature by
shop.identitydirect.com, author en...@shop.identitydirect.com, no valid
matches
Oct 22 09:16:14.624 [8459] dbg: dkim: FAILED signature by
shop.identitydirect.com, author en...@shop.identitydirect.com, no valid
matches
Oct 22 09:16:14.624 [8459] dbg: dkim: author
en...@shop.identitydirect.com, not in any dkim whitelist
The tests show that the DKIM test failed
Right. So the DKIM signature was not valid, so the tag
DKIMDOMAIN never got its value assigned, so a callback routine
attached to DKIMDOMAIN tag was never called, which yields the:
dbg: check: tagrun - tag DKIMDOMAIN is still blocking action 0
at the end of mail processing. Normal.
yet the SA headers show AFAICT it's good.
,DKIM_SIGNED=0.1, DKIM_VALID=-0.1,DKIM_VALID_AU=-0.1
You are probably looking at the report header from a previous
spamassassin run. The messages that you provided in your test run
was somehow clobbered, invalidating a DKIM signature.
Mark
