OSEC

Neohapsis is currently accepting applications for employment. For more information, please visit our website www.neohapsis.com or email hr@neohapsis.com
Sending hangs for no apparent reason..

From: Gaute Amundsen (gautepht.no)
Date: Mon Feb 02 2009 - 06:50:30 CST


We just had this strange hangup for the second time, that required me to
restart postfix to get sending going again.

I have not dug _very_ deeply into it yet, but being fairly new to postfix I'm
posting it here, in case someone can shed some light on the problem, or tell
me what I should try when it happens next time.

The situation is like this:

We use postfix to send newsletters and various mails from our customers
websites. The newsletter gets sent by a php script using smtp to localhost.
I got notified that mail was not going out, and after I did a
"/etc/init.d/postfix condrestart" the sending php process logged a whole lot
of lines like this:

PHP Warning: fsockopen(): unable to connect to 127.0.0.1:25 in
/usr/share/pear/Net/Socket.php on line 108

Looking in /var/log/maillog I notice that the string "postfix/smtp[" is absent
for for the period where the problem occured.
Snippets from the log where this started is included below.

There are 2 things that catch my eye:
1. DBERROR: reading /var/lib/imap/db/skipstamp
2. postfix/smtp[595]: fatal: watchdog timeout, and smtp: bad command startup

If 2. had occured in both logs, it would have been obvious what to research,
but only 1. does.

Any ideas anyone?

Thanks
Gaute Amundsen

Jan 25 02:41:36 hotell01 postfix/smtpd[14945]: disconnect from
localhost.localdomain[127.0.0.1]
Jan 25 03:31:01 hotell01 postfix/pickup[10767]: 76DC914764B: uid=0 from=<root>
Jan 25 03:31:01 hotell01 postfix/cleanup[22184]: 76DC914764B: message-
id=<20090125023101.76DC914764Bhotell01.pht.no>
Jan 25 04:02:15 hotell01 ctl_mboxlist[26676]: DBERROR: reading
/var/lib/imap/db/skipstamp, assuming the worst: No such file or directory
Jan 25 04:02:15 hotell01 ctl_mboxlist[26676]: skiplist: recovered
/var/lib/imap/mailboxes.db (0 records, 144 bytes) in 0 seconds
Jan 25 04:42:35 hotell01 postfix/pickup[24904]: DBAEF147648: uid=0 from=<root>
Jan 25 04:42:35 hotell01 postfix/cleanup[26374]: DBAEF147648: message-
id=<20090125034235.DBAEF147648hotell01.pht.no>
Jan 25 05:59:19 hotell01 postfix/smtp[595]: fatal: watchdog timeout
Jan 25 05:59:20 hotell01 postfix/master[734]: warning: process
/usr/libexec/postfix/smtp pid 595 exit status 1
Jan 25 05:59:20 hotell01 postfix/master[734]: warning:
/usr/libexec/postfix/smtp: bad command startup -- throttling
Jan 25 08:23:56 hotell01 postfix/smtpd[23133]: connect from
localhost.localdomain[127.0.0.1]
Jan 25 08:23:56 hotell01 postfix/smtpd[23133]: 353F51475E4:
client=localhost.localdomain[127.0.0.1]
Jan 25 08:23:56 hotell01 postfix/cleanup[23135]: 353F51475E4: message-
id=<20090125072355.22148.5933.hotell01.pht.nohotell01.pht.no>
Jan 25 08:24:06 hotell01 postfix/smtpd[23133]: disconnect from
localhost.localdomain[127.0.0.1]
Jan 25 09:59:46 hotell01 postfix/smtpd[4388]: connect from
localhost.localdomain[127.0.0.1]

Feb 1 00:48:12 hotell01 postfix/smtp[6779]: connect to
snickerigruppen.nu[69.25.75.72]: Connection timed out (port 25)
Feb 1 00:48:12 hotell01 postfix/smtp[6779]: 1B5301478A1:
to=<SNIPPEDsnickerigruppen.nu>, relay=none, delay=222520, status=deferred
(connect to snickerigru
ppen.nu[69.25.75.72]: Connection timed out)
Feb 1 03:31:02 hotell01 postfix/pickup[16148]: 85A79147607: uid=0 from=<root>
Feb 1 03:31:02 hotell01 postfix/cleanup[28806]: 85A79147607: message-
id=<20090201023102.85A79147607hotell01.pht.no>
Feb 1 04:02:14 hotell01 ctl_mboxlist[816]: DBERROR: reading
/var/lib/imap/db/skipstamp, assuming the worst: No such file or directory
Feb 1 04:02:14 hotell01 ctl_mboxlist[816]: skiplist: recovered
/var/lib/imap/mailboxes.db (0 records, 144 bytes) in 0 seconds
Feb 1 05:22:21 hotell01 postfix/pickup[6191]: 26CD9147601: uid=0 from=<root>
Feb 1 05:22:21 hotell01 postfix/cleanup[6192]: 26CD9147601: message-
id=<20090201042221.26CD9147601hotell01.pht.no>
Feb 1 09:22:32 hotell01 postfix/smtpd[6922]: connect from
localhost.localdomain[127.0.0.1]
Feb 1 09:22:32 hotell01 postfix/smtpd[6922]: 6270B1475E4:
client=localhost.localdomain[127.0.0.1]