Inordinate amount of time spent processing dkim

[Mark Martinec via amavis-users]

Quanah,

> I recently discovered amavis-logwatch, which is quite handy.  One of
> the things it revealed to me is that the second highest area of time
> being spent in processing mail through amavis is in the DKIM
> processing.  SA is the highest at 47.67%.  digest_body_dkim takes
> 35.84% of processing time. This seems quite high to me.  In looking at
> the TIMING bits in my logs, I've seen it take up to 16 seconds?!
> 
> Here is one such example.
> 
> May  2 12:03:36 edge01 amavis[49794]: (49794-18) size: 14948, TIMING
> [total 16566 ms, cpu 334 ms, AM-cpu 79 ms, SA-cpu 255 ms] - SMTP
> greeting: 1.5 (0%)0, SMTP EHLO: 0.5 (0%)0, SMTP pre-MAIL: 0.4 (0%)0,
> lookup_ldap: 3.3 (0%)0, lookup_ldap: 3.8 (0%)0, SMTP pre-DATA-flush:
> 0.7 (0%)0, SMTP DATA: 32 (0%)0, check_init: 0.2 (0%)0, digest_hdr: 4.3
> (0%)0, digest_body_dkim: 16021 (97%)97, mime_decode: 18 (0%)97,
> get-file-type2: 12 (0%)97, decompose_part: 0.7 (0%)97, parts_decode:
> 0.1 (0%)97, check_header: 1.0 (0%)97, AV-scan-1: 16 (0%)97,
> spam-wb-list: 2.3 (0%)97, SA msg read: 0.6 (0%)97, SA parse: 4.0
> (0%)97, SA check: 386 (2%)100, decide_mail_destiny: 6 (0%)100,
> lookup_ldap: 3.9 (0%)100, notif-quar: 0.0 (0%)100, fwd-connect: 3.8
> (0%)100, fwd-mail-pip: 14 (0%)100, fwd-rcpt-pip: 0.2 (0%)100,
> fwd-data-chkpnt: 0.0 (0%)100, write-header: 1.0 (0%)100,
> fwd-data-contents: 0.3 (0%)100, fwd-end-chkpnt: 2.5 (0%)100,
> fwd-connect: 3.2 (0%)100, fwd-mail-pip: 12 (0%)100, fwd-rcpt-pip: 0.1
> (0%)100, fwd-data-chkpnt: 0.0 (0%...

This is most likely due to a DNS problem at the signing domain.
The digest_body_dkim timing section covers the computation of
the message digest as well as a DNS lookup to fetch the public
key of the signing domain.

As can be seen from the 'AM-cpu 79 ms' the total CPU time spent by
amavis was quite short, which confirms the suspicion that the 16 s
was spent waiting for a DNS reply. The mail message did have at least
one DKIM (or DomainKeys) signature, otherwise there would be no
DNS lookup.

Check the message in question and see which domain(s) the DKIM
signature(s) contains (the d= tag), the try manually to fetch their
public key, e.g.:  dig jakla2._domainkey.ijs.si txt +short

   Mark