Very slow processing of postfix incoming queue

[Polleke]

As you can in the below logs, processing of the postfix incoming mail
queue (after mailscanner scanning the messages...) is veeeeerrrrry slow

It takes almost 4 minutes before the postfix quemanager picks op the
mail from the incoming queue

Any ideas on this ?





Nov  5 17:29:43 myhost cyrus/master[1868]: process 2364 exited, status 0
Nov  5 17:30:05 myhost postfix/pickup[2147]: 625CCB60FB4: uid=0 from=<root at myhost>
Nov  5 17:30:05 myhost postfix/cleanup[2372]: 625CCB60FB4: hold: header Received: by myhost.myhost.org (Postfix, from userid 0)??id 625CCB60FB4; Sat,  5 Nov 2016 17:30:05 +0100 (CET) from local; from=<root at myhost.org>
Nov  5 17:30:05 myhost postfix/cleanup[2372]: 625CCB60FB4: message-id=<20161105163005.625CCB60FB4 at myhost.myhost.org>
Nov  5 17:30:07 myhost MailScanner[1811]: New Batch: Scanning 1 messages, 570 bytes
Nov  5 17:30:07 myhost MailScanner[1811]: Virus and Content Scanning: Starting
Nov  5 17:30:23 myhost MailScanner[1811]: Requeue: 625CCB60FB4.A9074 to BE4ADB60FB1
Nov  5 17:30:23 myhost MailScanner[1811]: Uninfected: Delivered 1 messages
Nov  5 17:30:23 myhost MailScanner[1811]: Deleted 1 messages from processing-database
Nov  5 17:34:11 myhost postfix/qmgr[2148]: BE4ADB60FB1: from=<root at myhost.org>, size=340, nrcpt=1 (queue active)
Nov  5 17:34:12 myhost cyrus/lmtpunix[2363]: telling master 2
Nov  5 17:34:12 myhost cyrus/lmtpunix[2363]: accepted connection
Nov  5 17:34:12 myhost cyrus/lmtpunix[2363]: telling master 3
Nov  5 17:34:12 myhost cyrus/lmtpunix[2363]: lmtp connection preauth'd as postman
Nov  5 17:34:12 myhost cyrus/master[1868]: service lmtpunix pid 2363 in READY state: now unavailable and in BUSY state
Nov  5 17:34:12 myhost cyrus/lmtpunix[2363]: WARNING: sieve script /var/spool/sieve/t/test/defaultbc doesn't exist: No such file or directory
Nov  5 17:34:12 myhost cyrus/master[1868]: service lmtpunix now has 0 ready workers
Nov  5 17:34:12 myhost cyrus/master[1868]: service lmtpunix pid 2363 in BUSY state: now serving connection
Nov  5 17:34:12 myhost cyrus/master[1868]: service lmtpunix now has 0 ready workers
Nov  5 17:34:12 myhost cyrus/master[2961]: set maximum file descriptors to 256/256
Nov  5 17:34:12 myhost cyrus/master[2961]: about to exec /usr/lib/cyrus/bin/lmtpd
Nov  5 17:34:12 myhost cyrus/lmtpunix[2961]: executed
Nov  5 17:34:12 myhost cyrus/lmtpunix[2363]: Delivered: <20161105163005.625CCB60FB4 at myhost.myhost.org> to mailbox: user.test
Nov  5 17:34:12 myhost cyrus/idled[1878]: IDLE_NOTIFY 'user.test'
Nov  5 17:34:12 myhost cyrus/lmtpunix[2363]: USAGE test user: 0.000000 sys: 0.020000
Nov  5 17:34:12 myhost cyrus/lmtpunix[2363]: telling master 1
Nov  5 17:34:12 myhost cyrus/master[1868]: service lmtpunix pid 2363 in BUSY state: now available and in READY state
Nov  5 17:34:12 myhost cyrus/master[1868]: service lmtpunix now has 2 ready workers
Nov  5 17:34:12 myhost postfix/pipe[2959]: BE4ADB60FB1: to=<test at myhost.org>, relay=cyrus, delay=247, delays=247/0.05/0/0.05, dsn=2.0.0, status=sent (delivered via cyrus service)
Nov  5 17:34:12 myhost postfix/qmgr[2148]: BE4ADB60FB1: removed



-- 
Polleke <ervandepol at gmail.com>