How to justify amavisd-new delay

Hello,

I submit you this few maillog rows:

Mar 19 12:25:38 av5 postfix/cleanup[16063]: C059E228463:
message-id=<OFD2D31BB7.3D3F9A55-ONC1257411.003E6D71-C1257
411.003EBFD9do
main1spa.it>
Mar 19 12:25:38 av5 postfix/qmgr[20646]: C059E228463:
from=<francesco.casinidomain1spa.it>,
size=3494, nrcpt=1 (queue active)
Mar 19 13:00:56 av5 postfix/smtp[28218]: C059E228463:
to=<Alberto.Brazzabenisttspa.it>,
relay=127.0.0.1[127.0.0.1]:10024,
conn_use=19, delay=2118, delays=0.07/2107/0/11, dsn=2.0.0,
status=sent
(250 2.0.0 Ok: queued as E262322FBAA)
Mar 19 13:00:56 av5 postfix/qmgr[20646]: C059E228463:
removed
av5:/etc/rc.d # cat /var/log/mail | grep E262322FBAA
Mar 19 13:00:56 av5 postfix/smtpd[28145]: E262322FBAA:
client=localhost[127.0.0.1]
Mar 19 13:00:56 av5 postfix/cleanup[27101]: E262322FBAA:
message-id=<OFD2D31BB7.3D3F9A55-ONC1257411.003E6D71-C1257
411.003EBFD9do
main1spa.it>
Mar 19 13:00:56 av5 postfix/qmgr[20646]: E262322FBAA:
from=<francesco.casinidomain1spa.it>,
size=3932, nrcpt=1 (queue active)
Mar 19 13:00:56 av5 postfix/smtp[28218]: C059E228463:
to=<Alberto.Brazzabenidomain2.it>,
relay=127.0.0.1[127.0.0.1]:10024,
conn_use=19, delay=2118, delays=0.07/2107/0/11, dsn=2.0.0,
status=sent
(250 2.0.0 Ok: queued as E262322FBAA)
Mar 19 13:00:57 av5 postfix/smtp[22672]: E262322FBAA:
to=<Alberto.Brazzabenidomain2.it>,
relay=mail4.domain2.it[xxx.yyy.zzz.www]:25, delay=0.28,
delays=0.02/0.03/0.01/0.22, dsn=2.0.0, status=sent (250 Ok:
queued as
F119A109806A)

My SMTP gateway is work heavily.. I noted that the
bottleneck is
amavisd-new since for some messages (even if they are simple
short text
message) it takes a long time to scan them (see above).

Or maybe am I wrong? Maybe (2107 bytes) the delay include
the time the
message is waiting in some queue before to be scanned?

Thanks,

rocsca

------------------------------------------------------------
-------------
This SF.net email is sponsored by: Microsoft
Defy all challenges. Microsoft(R) Visual Studio 2008.
http://clk.atdmt.com/MRT/go/vse0120000070mrt/direct/01/
_______________________________________________
AMaViS-user mailing list
AMaViS-userlists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/amavis-user

AMaViS-FAQ:http://www.amav
is.org/amavis-faq.php3
AMaViS-HowTos:http://www.amavis.org/ho
wto/

On 3/19/08, Rocco Scappatura wrote:
> Hello,
>
> I submit you this few maillog rows:
>
> Mar 19 12:25:38 av5 postfix/cleanup[16063]:
C059E228463:
>
message-id=<OFD2D31BB7.3D3F9A55-ONC1257411.003E6D71-C1257
411.003EBFD9do
> main1spa.it>
> Mar 19 12:25:38 av5 postfix/qmgr[20646]: C059E228463:
> from=<francesco.casinidomain1spa.it>,
size=3494, nrcpt=1 (queue active)
> Mar 19 13:00:56 av5 postfix/smtp[28218]: C059E228463:
> to=<Alberto.Brazzabenisttspa.it>,
relay=127.0.0.1[127.0.0.1]:10024,
> conn_use=19, delay=2118, delays=0.07/2107/0/11,
dsn=2.0.0, status=sent
> (250 2.0.0 Ok: queued as E262322FBAA)
> Mar 19 13:00:56 av5 postfix/qmgr[20646]: C059E228463:
removed
> av5:/etc/rc.d # cat /var/log/mail | grep E262322FBAA
> Mar 19 13:00:56 av5 postfix/smtpd[28145]: E262322FBAA:
> client=localhost[127.0.0.1]
> Mar 19 13:00:56 av5 postfix/cleanup[27101]:
E262322FBAA:
>
message-id=<OFD2D31BB7.3D3F9A55-ONC1257411.003E6D71-C1257
411.003EBFD9do
> main1spa.it>
> Mar 19 13:00:56 av5 postfix/qmgr[20646]: E262322FBAA:
> from=<francesco.casinidomain1spa.it>,
size=3932, nrcpt=1 (queue active)
> Mar 19 13:00:56 av5 postfix/smtp[28218]: C059E228463:
> to=<Alberto.Brazzabenidomain2.it>,
relay=127.0.0.1[127.0.0.1]:10024,
> conn_use=19, delay=2118, delays=0.07/2107/0/11,
dsn=2.0.0, status=sent
> (250 2.0.0 Ok: queued as E262322FBAA)
> Mar 19 13:00:57 av5 postfix/smtp[22672]: E262322FBAA:
> to=<Alberto.Brazzabenidomain2.it>,
> relay=mail4.domain2.it[xxx.yyy.zzz.www]:25,
delay=0.28,
> delays=0.02/0.03/0.01/0.22, dsn=2.0.0, status=sent (250
Ok: queued as
> F119A109806A)
>
> My SMTP gateway is work heavily.. I noted that the
bottleneck is
> amavisd-new since for some messages (even if they are
simple short text
> message) it takes a long time to scan them (see
above).
>
> Or maybe am I wrong? Maybe (2107 bytes) the delay
include the time the
> message is waiting in some queue before to be scanned?
>
> Thanks,
>
> rocsca
>

>From what I understand from these posts:
http://marc.info/?l=postfix-users&m=117199107216689
http://marc.info/?l=postfix-users&m=118582818426445
your active queue is overloaded. If this is the case, this
often is a
result of messages coming in faster than they are going out
(quite
often due to the amount of time it takes to scan messages).
I think
you have been fighting this same problem for years now, as a
number of
others have too.

Essentially, from:
http://www.postfix.org/QSHAPE_README.html#active_queue

"Congestion occurs in the active queue when one or more
destinations
drain slower than the corresponding message input
rate."

I would start by looking at some TIMING data ($log_level =
2;) to see
how much time amavis spends on various functions (very
likely
spamassassin is where the most time is spent). If it is
spamassassin,
I would next break down exactly what SA is spending the most
time on.

http://marc.info/?l=amavis-user&m=120284838504641
http://marc.info/?l=amavis-user&m=118799923325417
http://marc.info/?l=amavis-user&m=120283445607760

This happens frequently. You can walk through a number of
posts from
the postfix-users archives from this link:
http://marc.info/?l=postfix-users&am
p;w=2&r=1&s=active+queue&q=t

Also interesting reading (even if are not running Postfix
2.5):
http://www.
postfix.org/STRESS_README.html

-- 
Gary V

------------------------------------------------------------
-------------
This SF.net email is sponsored by: Microsoft
Defy all challenges. Microsoft(R) Visual Studio 2008.
http://clk.atdmt.com/MRT/go/vse0120000070mrt/direct/01/
_______________________________________________
AMaViS-user mailing list
AMaViS-userlists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/amavis-user

AMaViS-FAQ:http://www.amav
is.org/amavis-faq.php3
AMaViS-HowTos:http://www.amavis.org/ho
wto/