skipped, still being delivered
Julian Field
mailscanner at ecs.soton.ac.uk
Fri Oct 3 23:13:14 IST 2003
Okay, you got my attention :-)
Can you reproduce it? If so, can you do
lsof | grep /var/spool/postfix
this time instead, so I can see all the files open in the incoming and
outgoing queues? In actual fact, you could skip the "grep" altogether and
just mail me the whole lot. I want to see if the same inode number crops up
more than once, which implies postfix is moving the file around at the time.
Thanks for this, it's *really* helpful. Just not quite enough, yet :-)
At 21:15 03/10/2003, you wrote:
>====================
>[root at Gabriel log]# lsof | grep /var/spool/postfix.in/incoming
>nqmgr 15792 root 8r DIR 72,2 4096 1954564
>/var/spool/postfix.in/incoming
>nqmgr 15792 root 12r DIR 72,2 4096 521221
>/var/spool/postfix.in/incoming/6
>nqmgr 15792 root 13r DIR 72,2 4096 895861
>/var/spool/postfix.in/incoming/6/3
>MailScann 15897 root 5u REG 72,2 3226 1956954
>/var/spool/postfix.in/incoming/1/8/18C9A1DDC5A
>MailScann 15897 root 19u REG 72,2 8602 1957133
>/var/spool/postfix.in/incoming/4/3/43B771DDD0D
>MailScann 15897 root 20u REG 72,2 8713 1957134
>/var/spool/postfix.in/incoming/4/7/473F31DDD0E
>MailScann 15897 root 21u REG 72,2 8256 1956916
>/var/spool/postfix.in/incoming/4/1/411D11DDC34
><snip>
>MailScann 15963 root 28u REG 72,2 2687 1956812
>/var/spool/postfix.in/incoming/1/8/18A571DDBCC
>cleanup 16029 root 12u REG 72,2 0 1957467
>/var/spool/postfix.in/incoming/C/A/CADDD1DDE5B
>cleanup 16276 root 12u REG 72,2 0 1957469
>/var/spool/postfix.in/incoming/A/8/A85B71DDE5D
>cleanup 16308 root 12u REG 72,2 0 1957464
>/var/spool/postfix.in/incoming/9/D/9D1D51DDE58
>cleanup 16366 root 12u REG 72,2 0 1957466
>/var/spool/postfix.in/incoming/7/D/7D3C21DDE5A
>cleanup 16372 root 12u REG 72,2 0 1957468
>/var/spool/postfix.in/incoming/8/6/86CB71DDE5C
>MailScann 16375 root 14u REG 72,2 2131 1957194
>/var/spool/postfix.in/incoming/4/1/41AD51DDD4A
><snip>
>====================
>...For brevity's sake I don't feel it necessary to include the rest of the
>output, as they're all various queue files being accessed by MailScanner
>or cleanup, but I certainly can if folks want (I omitted maybe two dozen
>lines or so).
>
>Similarly, I can post my full configs, but I think this is sufficient for now:
>Incoming Queue Dir = /var/spool/postfix.in/deferred
>Incoming Work Dir = /var/spool/MailScanner/incoming
>Outgoing Queue Dir = /var/spool/postfix/incoming
>
>While it's obvious that MailScanner should read queue files in
>/var/spool/postfix.in/DEFERRED/ [my caps] and write them to
>/var/spool/postfix/incoming/ , I don't think it should be touching
>anything in /var/spool/postfix.IN/INCOMING/ . Am I wrong in this?
>
>Below are some other pieces of information which may or may not be helpful:
>
>1) I'm running RedHat 7.3 on a Compaq DL360 with two 1GHz processors and
>1GB RAM; I've seen no problems with system load.
>
>2) MailScanner version is 4.22-5; Postfix version 1.1.12; SpamAssassin
>version 2.55.
>
>3) I thought I had turned off all defunct DNS-based spam checks, but MS
>seemed (sorry, no hard numbers) to be taking a long time to scan messages,
>especially late last night (between roughly midnight and 2am GMT-04, but I
>was also actively changing configurations and restarting MS & Co., which
>seemed to cause bursts of duplicate/blank emails and "skipped, still being
>delivered" messages). I was unable to get MS to complain of any RBL
>timeouts (including with Debug = yes in MailScanner.conf), but to make a
>long story shorter, I turned off all of the following DNS-based spam
>checks on a hunch (some, again, had already been offf):
>
>====================
>Fri Oct 3 15:56:36 /etc/MailScanner
>root at Gabriel# ls -l /etc/mail/spamassassin/local.cf
>-r--r--r-- 1 root root 780 Oct 3 02:13
>/etc/mail/spamassassin/local.cf
>
>Fri Oct 3 15:56:39 /etc/MailScanner
>root at Gabriel# grep score /etc/mail/spamassassin/local.cf
>score RCVD_IN_RELAYS_ORDB_ORG 0.0
>score RCVD_IN_OSIRUSOFT_COM 0.0
>score X_OSIRU_DUL 0.0
>score X_OSIRU_DUL_FH 0.0
>score X_OSIRU_OPEN_RELAY 0.0
>score X_OSIRU_SPAMWARE_SITE 0.0
>score X_OSIRU_SPAM_SRC 0.0
>score RCVD_IN_RFCI 0.0
>score RCVD_IN_ORBS 0.0
>score RCVD_IN_DSBL 0.0
>score RCVD_IN_MULTIHOP_DSBL 0.0
>score RCVD_IN_SBL 0.0
>score RCVD_IN_UNCONFIRMED_DSBL 0.0
>score RCVD_IN_BONDEDSENDER 0.0
>score RCVD_IN_OPM 0.0
>score RCVD_IN_NJABL 0.0
>score X_NJABL_OPEN_PROXY 0.0
>score X_NJABL_DIALUP 0.0
>====================
>
>4) Very quickly after that, my inbound queue from from 6,000 to "zero" and
>my "skipped, still being delivered" messages stopped - from this I
>hypothesize that some DNS-based spam check was timing out (I tested some,
>but not all), causing MailScanner (and I'm going well beyond my expertise
>here) to start losing a race condition of some sort with the inbound
>Postfix process.
>
>====================
>Fri Oct 3 02:16:16 /etc/mail/spamassassin
>
>---------->Checking inbound, pre-MS/SA queue<----------
>
>root at Gabriel# postqueue -c /etc/postfix.in -p | tail -1
>-- 74771 Kbytes in 6368 Requests.
>
>Fri Oct 3 02:16:32 /etc/mail/spamassassin
>
>---------->Checking outbound, post-MS/SA queue<----------
>
>root at Gabriel# postqueue -p | tail -1
>-- 511 Kbytes in 257 Requests.
>
>Fri Oct 3 02:16:35 /etc/mail/spamassassin
>root at Gabriel# postqueue -c /etc/postfix.in -p | tail -1
>-- 74904 Kbytes in 6384 Requests.
>
>Fri Oct 3 02:18:38 /etc/mail/spamassassin
>root at Gabriel# postqueue -p | tail -1
>-- 644 Kbytes in 360 Requests.
>
>Fri Oct 3 02:18:42 /etc/mail/spamassassin
>root at Gabriel# postqueue -c /etc/postfix.in -p | tail -1
>-- 75055 Kbytes in 6402 Requests.
>
>Fri Oct 3 02:21:19 /etc/mail/spamassassin
>root at Gabriel# postqueue -p | tail -1
>-- 1168 Kbytes in 628 Requests.
>
>Fri Oct 3 02:21:25 /etc/mail/spamassassin
>root at Gabriel# postqueue -c /etc/postfix.in -p | tail -1
>-- 74947 Kbytes in 6394 Requests.
>
>Fri Oct 3 02:22:54 /etc/mail/spamassassin
>root at Gabriel# postqueue -p | tail -1
>-- 889 Kbytes in 465 Requests.
>
>Fri Oct 3 02:22:56 /etc/mail/spamassassin
>root at Gabriel# postqueue -c /etc/postfix.in -p | tail -1
>-- 73887 Kbytes in 6245 Requests.
>
>Fri Oct 3 02:26:04 /etc/mail/spamassassin
>root at Gabriel# postqueue -p | tail -1
>-- 2131 Kbytes in 665 Requests.
>
>Fri Oct 3 02:26:07 /etc/mail/spamassassin
>root at Gabriel# postqueue -c /etc/postfix.in -p | tail -1
>-- 71968 Kbytes in 5934 Requests.
>
>Fri Oct 3 02:27:12 /etc/mail/spamassassin
>root at Gabriel# postqueue -p | tail -1
>-- 3866 Kbytes in 851 Requests.
>
>Fri Oct 3 02:27:18 /etc/mail/spamassassin
>root at Gabriel#
>
>Fri Oct 3 02:30:28 /etc/mail/spamassassin
>root at Gabriel# postqueue -c /etc/postfix.in -p | tail -1
>-- 68222 Kbytes in 5465 Requests.
>
>Fri Oct 3 02:30:37 /etc/mail/spamassassin
>root at Gabriel# postqueue -p | tail -1
>-- 7310 Kbytes in 1032 Requests.
>
>Fri Oct 3 02:30:43 /etc/mail/spamassassin
>root at Gabriel#
>
>Fri Oct 3 03:46:02 /etc/mail/spamassassin
>root at Gabriel# postqueue -c /etc/postfix.in -p | tail -1
>Mail queue is empty
>
>Fri Oct 3 03:46:03 /etc/mail/spamassassin
>root at Gabriel# postqueue -p | tail -1
>-- 2032 Kbytes in 310 Requests.
>
>Fri Oct 3 03:46:06 /etc/mail/spamassassin
>root at Gabriel#
>
>Fri Oct 3 09:26:59 /etc/mail/spamassassin
>root at Gabriel# postqueue -c /etc/postfix.in -p | tail -1
>Mail queue is empty
>
>Fri Oct 3 09:27:00 /etc/mail/spamassassin
>root at Gabriel# postqueue -p | tail -1
>-- 35 Kbytes in 6 Requests.
>
>Fri Oct 3 09:27:02 /etc/mail/spamassassin
>root at Gabriel#
>
>Fri Oct 3 11:13:48 /etc/mail/spamassassin
>root at Gabriel# postqueue -c /etc/postfix.in -p | tail -1
>Mail queue is empty
>
>Fri Oct 3 11:13:49 /etc/mail/spamassassin
>root at Gabriel# postqueue -p | tail -1
>-- 35 Kbytes in 6 Requests.
>Fri Oct 3 11:58:53 /etc/mail/spamassassin
>root at Gabriel# postqueue -c /etc/postfix.in -p | tail -1
>Mail queue is empty
>
>Fri Oct 3 11:58:54 /etc/mail/spamassassin
>root at Gabriel# postqueue -p | tail -1
>-- 39 Kbytes in 7 Requests.
>
>Fri Oct 3 11:58:57 /etc/mail/spamassassin
>
>Fri Oct 3 16:05:27 /etc/MailScanner
>root at Gabriel# grep "skipped, still being delivered" /var/log/maillog | tail -2
>Oct 3 02:51:24 Gabriel postfix/nqmgr[13729]: 095461DE774: skipped, still
>being delivered
>Oct 3 02:51:24 Gabriel postfix/nqmgr[13729]: 09AE61DEBC9: skipped, still
>being delivered
>====================
>
>I still need to finish testing the DNS-based spam checks to find which
>one(s) were timing out. My testing and documentation weren't the best on
>this one, but I apparently did something which coincided with the
>remission of my immediate problem. :)
>
>--Eric
--
Julian Field
www.MailScanner.info
Professional Support Services at www.MailScanner.biz
MailScanner thanks transtec Computers for their support
PGP footprint: EE81 D763 3DB0 0BFD E1DC 7222 11F6 5947 1415 B654
More information about the MailScanner
mailing list