Hi,
The CPU usage is low:
[root@mailgate2 incoming]# uptime
09:36:24 up 77 days, 23:19, 1 user, load average: 0.01, 0.00, 0.00
top - 09:47:30 up 77 days, 23:30, 1 user, load average: 0.00, 0.00, 0.00
Tasks: 151 total, 1 running, 150 sleeping, 0 stopped, 0 zombie
Cpu(s): 0.3% us, 0.0% sy, 0.0% ni, 98.3% id, 1.3% wa, 0.0% hi, 0.0% si
Mem: 1032956k total, 900284k used, 132672k free, 137260k buffers
Swap: 1228932k total, 160k used, 1228772k free, 458140k cached
There're ample of space in swap and no swapping at all:
[root@mailgate2 incoming]# free -m
total used free shared buffers cached
Mem: 1008 865 143 0 134 431
-/+ buffers/cache: 299 709
Swap: 1200 0 1199
There's no header_check nor body_check set in main.cf.
While other incoming mails are delivered, these incoming mails are slowly being
spooled for hours and the file size are growing:
[root@mailgate2 incoming]# ls -l
total 106988
-rw------- 1 postfix postfix 34369536 Jan 15 09:40 004207F3B
-rw------- 1 postfix postfix 438272 Jan 15 09:40 0F00F7F0B
-rw------- 1 postfix postfix 221184 Jan 15 09:41 1B4937F04
-rw------- 1 postfix postfix 581632 Jan 15 09:40 1CB727F38
-rw------- 1 postfix postfix 647168 Jan 15 09:41 1E9917F39
-rw------- 1 postfix postfix 299008 Jan 15 09:41 262047F07
-rw------- 1 postfix postfix 622592 Jan 15 09:42 2CD407F0D
-rw------- 1 postfix postfix 466944 Jan 15 09:42 34CE07F3F
-rw------- 1 postfix postfix 499712 Jan 15 09:41 4188A7F44
-rw------- 1 postfix postfix 331776 Jan 15 09:42 478677F48
-rw------- 1 postfix postfix 528384 Jan 15 09:41 4A0CA7F40
-rw------- 1 postfix postfix 9830400 Jan 15 09:41 6721F7F47
-rw------- 1 postfix postfix 11264000 Jan 15 09:42 86FD67F0E
-rw------- 1 postfix postfix 655360 Jan 15 09:41 9465B7F17
-rw------- 1 postfix postfix 43028480 Jan 15 09:40 952BA7F1D
-rw------- 1 postfix postfix 425984 Jan 15 09:40 A37077F15
-rw------- 1 postfix postfix 630784 Jan 15 09:41 A5A3F7F24
-rw------- 1 postfix postfix 401408 Jan 15 09:41 A9CBC7F46
-rw------- 1 postfix postfix 294912 Jan 15 09:41 A9D3D7F0F
-rw------- 1 postfix postfix 282624 Jan 15 09:41 B68E47F22
-rw------- 1 postfix postfix 1216512 Jan 15 09:40 CD97F7F49
-rw------- 1 postfix postfix 45056 Jan 15 09:40 D2FA87F2A
-rw------- 1 postfix postfix 692224 Jan 15 09:41 D9CA37F1F
-rw------- 1 postfix postfix 561152 Jan 15 09:42 EACE47F3A
-rw------- 1 postfix postfix 528384 Jan 15 09:40 EBE027F42
-rw------- 1 postfix postfix 483328 Jan 15 09:41 EDED87F45
[root@mailgate2 incoming]# tail -f /var/log/maillog
...
Jan 15 09:43:41 mailgate2 postfix/qmgr[28984]: 2246E7F4A: removed
Jan 15 09:43:46 mailgate2 postfix/anvil[21437]: statistics: max connection rate
4/60s for (smtp:210.17.183.8) at Jan 15 09:42:23
Jan 15 09:43:46 mailgate2 postfix/anvil[21437]: statistics: max connection
count 23 for (smtp:210.17.183.8) at Jan 15 09:38:58
Jan 15 09:43:46 mailgate2 postfix/anvil[21437]: statistics: max cache size 4 at
Jan 15 09:37:53
Jan 15 09:43:55 mailgate2 postfix/smtpd[23450]: connect from
ttsenmta4.ttasia.com[210.17.183.10]
Jan 15 09:43:55 mailgate2 postfix/smtpd[23450]: A92557F4A:
client=ttsenmta4.ttasia.com[210.17.183.10]
Jan 15 09:43:55 mailgate2 postfix/cleanup[23452]: A92557F4A:
message-id=<005301cdf2c2$7d202bd0$77608370$@com>
Jan 15 09:43:55 mailgate2 postfix/qmgr[28984]: A92557F4A:
from=<[email protected]>, size=8608, nrcpt=1 (queue active)
Jan 15 09:43:55 mailgate2 postfix/smtp[24076]: A92557F4A:
to=<[email protected]>, relay=192.168.1.21[192.168.1.21]:25, delay=0.14,
delays=0.12/0/0/0.01, dsn=2.0.0, status=sent (250 Mail queued for delivery)
Jan 15 09:43:55 mailgate2 postfix/qmgr[28984]: A92557F4A: removed
Jan 15 09:43:55 mailgate2 postfix/smtpd[23450]: disconnect from
ttsenmta4.ttasia.com[210.17.183.10]
Jan 15 09:44:08 mailgate2 postfix/smtpd[23450]: connect from
ttsenmta4.ttasia.com[210.17.183.10]
Jan 15 09:44:08 mailgate2 postfix/smtpd[23450]: EE40B7F4A:
client=ttsenmta4.ttasia.com[210.17.183.10]
Jan 15 09:44:09 mailgate2 postfix/cleanup[23452]: EE40B7F4A:
message-id=<[email protected]>
Jan 15 09:44:09 mailgate2 postfix/qmgr[28984]: EE40B7F4A:
from=<[email protected]>, size=8481, nrcpt=1 (queue active)
Jan 15 09:44:09 mailgate2 postfix/smtp[24080]: EE40B7F4A:
to=<[email protected]>, relay=192.168.1.21[192.168.1.21]:25, delay=0.33,
delays=0.32/0/0/0.01, dsn=2.0.0, status=sent (250 Mail queued for delivery)
Jan 15 09:44:09 mailgate2 postfix/qmgr[28984]: EE40B7F4A: removed
Jan 15 09:44:09 mailgate2 postfix/smtpd[23450]: disconnect from
ttsenmta4.ttasia.com[210.17.183.10]
Jan 15 09:44:32 mailgate2 postfix/qmgr[28984]: 1B4937F04:
from=<[email protected]>, size=332932, nrcpt=1 (queue active)
Jan 15 09:44:32 mailgate2 postfix/smtpd[23905]: disconnect from
ttsenmta4.ttasia.com[210.17.183.10]
Jan 15 09:44:32 mailgate2 postfix/smtp[24076]: 1B4937F04:
to=<[email protected]>, relay=192.168.1.21[192.168.1.21]:25, delay=2947,
delays=2946/0/0/0.62, dsn=2.0.0, status=sent (250 Mail queued for delivery)
Jan 15 09:44:32 mailgate2 postfix/qmgr[28984]: 1B4937F04: removed
I may check on the possibiity of bad disk blocks ...
Any other things I need to check?
Thanks.
Regards,Fred​
On Tue, 01/15/2013 09:35 AM, Wietse Venema <[email protected]> wrote:
> Fred Ho:
> > Hi,
> >
> > I found there're quite a lot of cleanup processes running and found
> > that the incoming mails are still being spooled to
> > /var/spool/postfix/incoming which started hours ago.
> >
> > May I ask why the spooling is taking so long? Is it the network? Thanks.
>
> You haven't even tried to find out if it is CPU bound, memory
> exhaustion, or disk overload?
>
> 1) It's CPU bound because of many header_checks or body_checks. Use
> a content filter instead.
>
> 2) It's I/O bound because of a slow file system, slow disk drive,
> bad RAID implementation (parity blocks but no battery-backed write
> buffer), or a slow file server.
>
> 3) It's low on memory causing the system to swap.
>
> Recently a colleague of mine found a troubling failure mode where
> disks would silenty retry bad blocks without ever reporting an
> error. This was slowing down write performance by a huge factor.
> Look for recoverable errors in your SMART logs.
>
> Wietse
>
>
