Inordinate amount of time spent processing dkim

[Quanah Gibson-Mount]

--On Friday, May 02, 2014 12:26 PM -0700 Quanah Gibson-Mount via 
amavis-users <amavis-users at amavis.org> wrote:

> 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%...

Likely due to incorrect DNS configuration by those controlling the DNS 
infrastructure, since resolved.

--Quanah

--

Quanah Gibson-Mount
Server Architect
Zimbra, Inc.
--------------------
Zimbra ::  the leader in open source messaging and collaboration