Re: Postfix Not Sending Emails. Timeout on Cleanup socket error.

[Brian Evans - Postfix List]

On 12/13/2011 2:17 PM, Gonzo Fernandez wrote:

> Hi all,
>
> I'm not too familiar with postfix but our server seems to stop sending
> emails usually only on the weekends. The rest of the week it's fine
> but once it gets to about Saturday/Sunday morning it gets stuck. I've
> come in usually on Monday and type "mailq" only to find hundreds if
> not thousand or so emails stuck in the incoming queue. I have to
> restart the postfix service for all the emails to get sent.
>
> I was hoping someone a little more experienced than me can point me in
> the right direction and explain what's going on as I'm not that
> familiar with it yet. I'm sure I'm not the first to have this issue
> and I've searched online but have found nothing specific that could be
> causing this. This is what "cat /var/log/maillog | grep warning" shows:
>
> Dec 11 05:09:19 batch-ca4-02 postfix/cleanup[31691]: warning: timeout
> on cleanup socket while reading input attribute name
> Dec 11 05:31:27 batch-ca4-02 postfix/cleanup[31691]: warning:
> 8A2993E3003B: read timeout on cleanup socket

Did you only search for warnings?

http://www.postfix.org/DEBUG_README.html#logging says:

When Postfix does not receive or deliver mail, the first order of
business is to look for errors that prevent Postfix from working properly:

% *egrep '(warning|error|fatal|panic):' /some/log/file | more*

Note: the most important message is near the BEGINNING of the output.
Error messages that come later are less useful.


> Here is my postconf -n:
>
> alias_database = hash:/etc/aliases
> alias_maps = hash:/etc/aliases
> command_directory = /usr/sbin
> config_directory = /etc/postfix
> daemon_directory = /usr/libexec/postfix
> debug_peer_level = 2
> html_directory = no
> in_flow_delay = 10s
> inet_interfaces = localhost
> mail_owner = postfix
> mailq_path = /usr/bin/mailq.postfix
> manpage_directory = /usr/share/man
> mydestination = $myhostname, localhost.$mydomain, localhost
> mydomain = usaepay.com 
> myorigin = $mydomain
> newaliases_path = /usr/bin/newaliases.postfix
> queue_directory = /var/spool/postfix
> readme_directory = /usr/share/doc/postfix-2.3.3/README_FILES
> relayhost = 192.168.x.x
> sample_directory = /usr/share/doc/postfix-2.3.3/samples
> sendmail_path = /usr/sbin/sendmail.postfix
> setgid_group = postdrop
> unknown_local_recipient_reject_code = 550
>
> Can anyone please help?? If I need to submit more info please let me
> know. Thank you!
>
>
> Gonzo Fernandez
> Network Engineer
>

Re: Postfix Not Sending Emails. Timeout on Cleanup socket error.

[Wietse Venema]

Gonzo Fernandez:
> Dec 11 05:09:19 batch-ca4-02 postfix/cleanup[31691]: warning: timeout on 
> cleanup socket while reading input attribute name
> Dec 11 05:31:27 batch-ca4-02 postfix/cleanup[31691]: warning: 8A2993E3003B: 
> read timeout on cleanup socket

Did the email arrive via smtpd (network), or via pickup (local)?

$ grep 8A2993E3003B /the/log/file

Wietse

Re: Postfix Not Sending Emails. Timeout on Cleanup socket error.

[Gonzo Fernandez]

Hi Wietse,

I believe the email arrive via pickup as shown below. Also, running qshape on 
incoming queue showed all stuck there. Seems to happen between the late AM 
hours on Saturday. Thank you for your help. Any ideas?

This is what I get when with the following command:

[root@batch-ca4-02 ~]# egrep '(warning|error|fatal|panic):' /var/log/maillog | 
more

Dec 11 05:09:19 batch-ca4-02 postfix/cleanup[31691]: warning: timeout on 
cleanup socket while reading input attribute name
Dec 11 05:31:27 batch-ca4-02 postfix/cleanup[31691]: warning: 8A2993E3003B: 
read timeout on cleanup socket
Dec 11 11:02:41 batch-ca4-02 postfix/smtpd[2339]: warning: Illegal address 
syntax from localhost[127.0.0.1] in RCPT command: em...@.com;em...@.com
Dec 11 12:30:19 batch-ca4-02 postfix/smtpd[9697]: warning: Illegal address 
syntax from localhost[127.0.0.1] in RCPT command: email@x...@.biz;
Dec 11 12:30:59 batch-ca4-02 postfix/smtpd[9697]: warning: Illegal address 
syntax from localhost[127.0.0.1] in RCPT command: em...@.com;em...@.edu
Dec 12 10:08:50 batch-ca4-02 postfix/pickup[26935]: warning: 7009C3E30026: 
message has been queued for 1 days
Dec 12 10:08:50 batch-ca4-02 postfix/pickup[26935]: warning: 884643E30022: 
message has been queued for 1 days
Dec 12 10:08:50 batch-ca4-02 postfix/pickup[26935]: warning: AAE8F3E30024: 
message has been queued for 1 days
Dec 12 10:08:50 batch-ca4-02 postfix/pickup[26935]: warning: B5F633E30023: 
message has been queued for 1 days
Dec 12 10:08:50 batch-ca4-02 postfix/pickup[26935]: warning: D80833E30025: 
message has been queued for 1 days
Dec 12 10:08:50 batch-ca4-02 postfix/pickup[26935]: warning: DDA2F3E30026: 
message has been queued for 1 days
Dec 12 10:08:51 batch-ca4-02 postfix/pickup[26935]: warning: 034C63E30023: 
message has been queued for 1 days
Dec 12 10:08:51 batch-ca4-02 postfix/pickup[26935]: warning: 36B823E30028: 
message has been queued for 1 days
Dec 12 10:08:51 batch-ca4-02 postfix/pickup[26935]: warning: 3CF9C3E30026: 
message has been queued for 1 days
Dec 12 10:08:51 batch-ca4-02 postfix/pickup[26935]: warning: 4CABC3E3003A: 
message has been queued for 1 days
Dec 12 10:08:51 batch-ca4-02 postfix/pickup[26935]: warning: 519D43E30021: 
message has been queued for 1 days
Dec 12 10:08:51 batch-ca4-02 postfix/pickup[26935]: warning: 550333E30029: 
message has been queued for 1 days
Dec 12 10:08:51 batch-ca4-02 postfix/pickup[26935]: warning: 7582E3E30024: 
message has been queued for 1 days
Dec 12 10:08:51 batch-ca4-02 postfix/pickup[26935]: warning: 8567D3E30023: 
message has been queued for 1 days
Dec 12 10:08:51 batch-ca4-02 postfix/pickup[26935]: warning: 903FC3E30039: 
message has been queued for 1 days
Dec 12 10:08:51 batch-ca4-02 postfix/pickup[26935]: warning: 95C123E3003B: 
message has been queued for 1 days
Dec 12 10:08:51 batch-ca4-02 postfix/pickup[26935]: warning: C954E3E30021: 
message has been queued for 1 days
Dec 12 10:08:51 batch-ca4-02 postfix/pickup[26935]: warning: CCD493E30022: 
message has been queued for 1 days
Dec 12 10:08:51 batch-ca4-02 postfix/pickup[26935]: warning: E0EEC3E3002A: 
message has been queued for 1 days
Dec 12 10:08:52 batch-ca4-02 postfix/pickup[26935]: warning: 116183E30052: 
message has been queued for 1 days
Dec 12 10:08:52 batch-ca4-02 postfix/pickup[26935]: warning: 1767C3E3005B: 
message has been queued for 1 days
Dec 12 10:08:52 batch-ca4-02 postfix/pickup[26935]: warning: 206773E30068: 
message has been queued for 1 days
Dec 12 10:08:52 batch-ca4-02 postfix/pickup[26935]: warning: 3271B3E30091: 
message has been queued for 1 days
Dec 12 10:08:52 batch-ca4-02 postfix/pickup[26935]: warning: 3A4F93E30095: 
message has been queued for 1 days
Dec 12 10:08:52 batch-ca4-02 postfix/pickup[26935]: warning: 419043E30099: 
message has been queued for 1 days
Dec 12 10:08:52 batch-ca4-02 postfix/pickup[26935]: warning: 516FA3E300AE: 
message has been queued for 1 days
Dec 12 10:08:52 batch-ca4-02 postfix/pickup[26935]: warning: 5EC883E300BE: 
message has been queued for 1 days
Dec 12 10:08:52 batch-ca4-02 postfix/pickup[26935]: warning: 86ACD3E3002B: 
message has been queued for 1 days
Dec 12 10:08:52 batch-ca4-02 postfix/pickup[26935]: warning: 9E2F93E30037: 
message has been queued for 1 days
Dec 12 10:08:52 batch-ca4-02 postfix/pickup[26935]: warning: A29793E3003A: 
message has been queued for 1 days
Dec 12 10:08:52 batch-ca4-02 postfix/pickup[26935]: warning: B7E723E30040: 
message has been queued for 1 days
Dec 12 10:08:53 batch-ca4-02 postfix/pickup[26935]: warning: 7F8373E30025: 
message has been queued for 1 days
Dec 12 10:08:53 batch-ca4-02 postfix/pickup[26935]: warning: 9C0973E30025: 
message has been queued for 1 days
Dec 12 10:08:53 batch-ca4-02 postfix/pickup[26935]: warning: ACEDF3E30024: 
message has been queued for 1 days
Dec 12 10:08:53 batch-ca4-02 postfix/pickup[26935]: warning: BE4A93E30021: 
message has been queued for 1 days
Dec 12 10:08:53 batch-ca4-02 postfix/pickup[26935]: warning: 

Re: Postfix Not Sending Emails. Timeout on Cleanup socket error.

[Wietse Venema]

Gonzo Fernandez:
> Hi Wietse,
> 
> I believe the email arrive via pickup as shown below. Also, running
> qshape on incoming queue showed all stuck there. Seems to happen
> between the late AM hours on Saturday. Thank you for your help.
> Any ideas?
> 
> This is what I get when with the following command:
> 
> [root@batch-ca4-02 ~]# egrep '(warning|error|fatal|panic):' /var/log/maillog 
> | more

That is not what I asked.

Wietse

Re: Postfix Not Sending Emails. Timeout on Cleanup socket error.

[Gonzo Fernandez]

Hi Wietse,

I apologize for the confusion. Here is the result of the following command. The 
mail arrived via pickup (local).

# grep 8A2993E3003B /var/log/maillog
Dec 11 05:31:27 batch-ca4-02 postfix/cleanup[31691]: warning: 8A2993E3003B: 
read timeout on cleanup socket


Gonzo Fernandez
Network Engineer

On Dec 13, 2011, at 12:35 PM, Wietse Venema wrote:

> Gonzo Fernandez:
>> Dec 11 05:09:19 batch-ca4-02 postfix/cleanup[31691]: warning: timeout on 
>> cleanup socket while reading input attribute name
>> Dec 11 05:31:27 batch-ca4-02 postfix/cleanup[31691]: warning: 8A2993E3003B: 
>> read timeout on cleanup socket
> 
> Did the email arrive via smtpd (network), or via pickup (local)?
> 
> $ grep 8A2993E3003B /the/log/file
> 
>   Wietse

Re: Postfix Not Sending Emails. Timeout on Cleanup socket error.

[Wietse Venema]

Gonzo Fernandez:
> Hi Wietse,
> 
> I apologize for the confusion. Here is the result of the following command. 
> The mail arrived via pickup (local).

PLEASE show the logfile records that I asked for.

Wietse

> # grep 8A2993E3003B /var/log/maillog
> Dec 11 05:31:27 batch-ca4-02 postfix/cleanup[31691]: warning: 8A2993E3003B: 
> read timeout on cleanup socket
> 
> 
> Gonzo Fernandez
> Network Engineer
> 
> On Dec 13, 2011, at 12:35 PM, Wietse Venema wrote:
> 
> > Gonzo Fernandez:
> >> Dec 11 05:09:19 batch-ca4-02 postfix/cleanup[31691]: warning: timeout on 
> >> cleanup socket while reading input attribute name
> >> Dec 11 05:31:27 batch-ca4-02 postfix/cleanup[31691]: warning: 
> >> 8A2993E3003B: read timeout on cleanup socket
> > 
> > Did the email arrive via smtpd (network), or via pickup (local)?
> > 
> > $ grep 8A2993E3003B /the/log/file
> > 
> > Wietse
> 

Re: Postfix Not Sending Emails. Timeout on Cleanup socket error.

[Gonzo Fernandez]

I'm not sure I'm understanding the log file info you would like. I tried doing 
grep search for 8A2993E3003B on all log files under /var/log/* and only found 
the following line to show up:

Dec 11 05:31:27 batch-ca4-02 postfix/cleanup[31691]: warning: 8A2993E3003B: 
read timeout on cleanup socket

Can you please be more specific? Thanks for your patience and help. 

Gonzo Fernandez
Network Engineer


On Dec 14, 2011, at 4:12 PM, Wietse Venema wrote:

> Gonzo Fernandez:
>> Hi Wietse,
>> 
>> I apologize for the confusion. Here is the result of the following command. 
>> The mail arrived via pickup (local).
> 
> PLEASE show the logfile records that I asked for.
> 
>   Wietse
> 
>> # grep 8A2993E3003B /var/log/maillog
>> Dec 11 05:31:27 batch-ca4-02 postfix/cleanup[31691]: warning: 8A2993E3003B: 
>> read timeout on cleanup socket
>> 
>> 
>> Gonzo Fernandez
>> Network Engineer
>> 
>> On Dec 13, 2011, at 12:35 PM, Wietse Venema wrote:
>> 
>>> Gonzo Fernandez:
 Dec 11 05:09:19 batch-ca4-02 postfix/cleanup[31691]: warning: timeout on 
 cleanup socket while reading input attribute name
 Dec 11 05:31:27 batch-ca4-02 postfix/cleanup[31691]: warning: 
 8A2993E3003B: read timeout on cleanup socket
>>> 
>>> Did the email arrive via smtpd (network), or via pickup (local)?
>>> 
>>> $ grep 8A2993E3003B /the/log/file
>>> 
>>> Wietse
>> 

Re: Postfix Not Sending Emails. Timeout on Cleanup socket error.

[Lorens Kockum]

On Wed, Dec 14, 2011 at 05:43:58PM -0800, Gonzo Fernandez wrote:
> I'm not sure I'm understanding the log file info you would like. I tried 
> doing grep search for 8A2993E3003B on all log files under /var/log/* and only 
> found the following line to show up:
> 
> Dec 11 05:31:27 batch-ca4-02 postfix/cleanup[31691]: warning: 8A2993E3003B: 
> read timeout on cleanup socket
> 
> Can you please be more specific? Thanks for your patience and help. 


Your log line is dated 5 AM plus a little. Maybe your log file
got rotated (that usually happens at 4 or 5 AM). The reason
that your grep on all log files did not yield the result is
probably that the rotated log files are zipped. zgrep (at least
my version) behaves nicely when the files aren't zipped, so

zgrep 8A2993E3003B /var/log/maillog*

should yield the information Wietse was asking for. If not, an

ls -ld /var/log/maillog*

would be useful.

Is this a very heavily used system?

Re: Postfix Not Sending Emails. Timeout on Cleanup socket error.

[Wietse Venema]

Gonzo Fernandez:
> I'm not sure I'm understanding the log file info you would like. I tried 
> doing grep search for 8A2993E3003B on all log files under /var/log/* and only 
> found the following line to show up:
> 
> Dec 11 05:31:27 batch-ca4-02 postfix/cleanup[31691]: warning: 8A2993E3003B: 
> read timeout on cleanup socket
> 
> Can you please be more specific? Thanks for your patience and help. 

PLEASE show ALL logfile records for message 8A2993E3003B. 

The pickup or smtpd record may be in a different file than the
cleanup record.

Wietse

> Gonzo Fernandez
> Network Engineer
> 
> 
> On Dec 14, 2011, at 4:12 PM, Wietse Venema wrote:
> 
> > Gonzo Fernandez:
> >> Hi Wietse,
> >> 
> >> I apologize for the confusion. Here is the result of the following 
> >> command. The mail arrived via pickup (local).
> > 
> > PLEASE show the logfile records that I asked for.
> > 
> > Wietse
> > 
> >> # grep 8A2993E3003B /var/log/maillog
> >> Dec 11 05:31:27 batch-ca4-02 postfix/cleanup[31691]: warning: 
> >> 8A2993E3003B: read timeout on cleanup socket
> >> 
> >> 
> >> Gonzo Fernandez
> >> Network Engineer
> >> 
> >> On Dec 13, 2011, at 12:35 PM, Wietse Venema wrote:
> >> 
> >>> Gonzo Fernandez:
>  Dec 11 05:09:19 batch-ca4-02 postfix/cleanup[31691]: warning: timeout on 
>  cleanup socket while reading input attribute name
>  Dec 11 05:31:27 batch-ca4-02 postfix/cleanup[31691]: warning: 
>  8A2993E3003B: read timeout on cleanup socket
> >>> 
> >>> Did the email arrive via smtpd (network), or via pickup (local)?
> >>> 
> >>> $ grep 8A2993E3003B /the/log/file
> >>> 
> >>>   Wietse
> >> 
> 

Re: Postfix Not Sending Emails. Timeout on Cleanup socket error.

[Gonzo Fernandez]

Hi guys,

So far no luck searching for 8A2993E3003B. :(
The system is heavily used. From what I understand this machine relays all mail 
to our main mx server and we have a lot of email being relayed daily. The 
strange part is that it works all week up until late Saturday/Sunday in the AM 
hours.

Here are all log files for mail. I have searched all log files for the specific 
string but no luck. Performing another search for all warning, error, fatal, 
panic on all previous log files has given me a bit more info. The following is 
certain errors I have noticed pop up more often than not:

 #  egrep (warning|error|fatal|panic): /var/log/maillog* | more

/var/log/maillog:Dec 11 05:09:19 batch-ca4-02 postfix/cleanup[31691]: warning: 
timeout on cleanup socket while reading input attribute name
/var/log/maillog:Dec 11 05:31:27 batch-ca4-02 postfix/cleanup[31691]: warning: 
8A2993E3003B: read timeout on cleanup socket
/var/log/maillog:Dec 13 12:04:13 batch-ca4-02 postfix/postdrop[15153]: warning: 
uid=0: Illegal seek
/var/log/maillog:Dec 13 04:04:13 batch-ca4-02 postfix/sendmail[15152]: fatal: 
root(0): queue file write error
/var/log/maillog:Dec 14 12:03:07 batch-ca4-02 postfix/postdrop[12285]: warning: 
uid=0: Illegal seek
/var/log/maillog:Dec 14 04:03:07 batch-ca4-02 postfix/sendmail[12280]: fatal: 
root(0): queue file write error
/var/log/maillog:Dec 15 12:03:07 batch-ca4-02 postfix/postdrop[21744]: warning: 
uid=0: Illegal seek
/var/log/maillog:Dec 15 04:03:07 batch-ca4-02 postfix/sendmail[21739]: fatal: 
root(0): queue file write error
/var/log/maillog.1:Dec  4 05:18:29 batch-ca4-02 postfix/cleanup[6555]: warning: 
timeout on cleanup socket while reading input attribute name
/var/log/maillog.1:Dec  4 05:45:13 batch-ca4-02 postfix/cleanup[6555]: warning: 
0433D3E3003A: read timeout on cleanup socket
/var/log/maillog:Dec 15 12:03:07 batch-ca4-02 postfix/postdrop[21744]: warning: 
uid=0: Illegal seek
/var/log/maillog:Dec 15 04:03:07 batch-ca4-02 postfix/sendmail[21739]: fatal: 
root(0): queue file write error
/var/log/maillog.1:Dec  5 12:03:47 batch-ca4-02 postfix/postdrop[4667]: 
warning: uid=0: Illegal seek
/var/log/maillog.1:Dec  5 04:03:47 batch-ca4-02 postfix/sendmail[4660]: fatal: 
root(0): queue file write error

(I tried searching for 0433D3E3003A as well but to no avail.)

# ls -ld /var/log/maillog*
-rw--- 1 root root 194889523 Dec 15 10:48 /var/log/maillog
-rw--- 1 root root 370337428 Dec 11 04:04 /var/log/maillog.1
-rw--- 1 root root 644886321 Dec  4 04:03 /var/log/maillog.2
-rw--- 1 root root 250479845 Nov 27 04:03 /var/log/maillog.3
-rw--- 1 root root  11139266 Nov 20 04:02 /var/log/maillog.4

I also commented out fallback relay as it was active but left blank in 
master.cf. Not sure if that has anything to do with it but better safe than 
sorry.

# When relaying mail as backup MX, disable fallback_relay to avoid MX loops
relay unix  -   -   n   -   -   smtp
#   -o fallback_relay=

I'm going to wait and see what happens this weekend and when it happens again 
I'll try to get more info for you. Thanks again for the help.

Gonzo Fernandez
Network Engineer


On Dec 14, 2011, at 11:01 PM, Lorens Kockum wrote:

> On Wed, Dec 14, 2011 at 05:43:58PM -0800, Gonzo Fernandez wrote:
>> I'm not sure I'm understanding the log file info you would like. I tried 
>> doing grep search for 8A2993E3003B on all log files under /var/log/* and 
>> only found the following line to show up:
>> 
>> Dec 11 05:31:27 batch-ca4-02 postfix/cleanup[31691]: warning: 8A2993E3003B: 
>> read timeout on cleanup socket
>> 
>> Can you please be more specific? Thanks for your patience and help. 
> 
> 
> Your log line is dated 5 AM plus a little. Maybe your log file
> got rotated (that usually happens at 4 or 5 AM). The reason
> that your grep on all log files did not yield the result is
> probably that the rotated log files are zipped. zgrep (at least
> my version) behaves nicely when the files aren't zipped, so
> 
>   zgrep 8A2993E3003B /var/log/maillog*
> 
> should yield the information Wietse was asking for. If not, an
> 
>ls -ld /var/log/maillog*
> 
> would be useful.
> 
> Is this a very heavily used system?

Re: Postfix Not Sending Emails. Timeout on Cleanup socket error.

[Wietse Venema]

Gonzo Fernandez:
> Hi guys,
> 
> So far no luck searching for 8A2993E3003B. :(

Can you then show some other pickup records?

Wietse

Re: Postfix Not Sending Emails. Timeout on Cleanup socket error.

[Wietse Venema]

Wietse Venema:
> Gonzo Fernandez:
> > Hi guys,
> > 
> > So far no luck searching for 8A2993E3003B. :(
> 
> Can you then show some other pickup records?

In particular I am looking for NON-ERROR LOGGING from the pickup
daemon around the time of the incident.

Wietse

Re: Postfix Not Sending Emails. Timeout on Cleanup socket error.

[Lorens Kockum]

On Thu, Dec 15, 2011 at 11:49:35AM -0800, Gonzo Fernandez wrote:
> /var/log/maillog:Dec 14 04:03:07 batch-ca4-02 postfix/sendmail[12280]: fatal: 
> root(0): queue file write error
> /var/log/maillog:Dec 15 12:03:07 batch-ca4-02 postfix/postdrop[21744]: 
> warning: uid=0: Illegal seek

In addition to what Wietse asked for in another mail just now,
do look at the output of the commands

mount

dmesg

That should show if there is a hardware problem.

If it is not, then is it not possible that the 8A2993E3003B you
are worrying about is a locally submitted mail from some system
daemon (like logwatch) that is too big for your configured
system limits? The times on the error messages make me suspect
some kind of cron job.

See:

http://www.electrictoolbox.com/logwatch-postfix-sendmail-errors/


http://www.cyberciti.biz/tips/linux-unix-posttfix-mutt-illegal-seek-error.html

8A2993E3003B would then be a minor consequence of your main
problem, which is mail freezing up over weekends.

To diagnose that problem, it would be interesting to grep on a
queue id that was correctly queued, like (from an earlier mail):

Dec 12 10:08:50 batch-ca4-02 postfix/pickup[26935]: warning: 884643E30022: 
message has been queued for 1 days

Since mails such as those have been correctly queued, there
should be a wealth of information about when and how and why
it's staying in the queue so long.

HTH

Re: Postfix Not Sending Emails. Timeout on Cleanup socket error.

[Gonzo Fernandez]

Lorens,

Thanks for your info about the mailbox size limit. I do have log watch running 
and have not received any emails. Took care of that by expanding the size limit 
to 20MB. As for doing a grep search on 884643E30022 (The ID that said stuck in 
queue for 1 day), here is the output:

# egrep 884643E30022 /var/log/maillog

Dec 12 10:08:50 batch-ca4-02 postfix/pickup[26935]: warning: 884643E30022: 
message has been queued for 1 days
Dec 12 10:08:50 batch-ca4-02 postfix/pickup[26935]: 884643E30022: uid=500 
from=
Dec 12 10:08:50 batch-ca4-02 postfix/cleanup[26937]: 884643E30022: 
message-id=<20111212180850.884643E30022@batch-ca4-02>
Dec 12 10:08:50 batch-ca4-02 postfix/qmgr[26936]: qmgr_active_feed: 
incoming/884643E30022
Dec 12 10:08:50 batch-ca4-02 postfix/qmgr[26936]: qmgr_message_alloc: active 
884643E30022
Dec 12 10:08:50 batch-ca4-02 postfix/qmgr[26936]: 884643E30022: 
from=, size=1503, nrcpt=1 (queue active)
Dec 12 10:08:50 batch-ca4-02 postfix/qmgr[26936]: qmgr_peer_select: 
884643E30022 smtp 192.168.X.X (5 of 10)
Dec 12 10:08:50 batch-ca4-02 postfix/qmgr[26936]: qmgr_job_retire: 884643E30022
Dec 12 10:08:50 batch-ca4-02 postfix/qmgr[26936]: send attr queue_id = 
884643E30022
Dec 12 10:08:50 batch-ca4-02 postfix/smtp[26956]: input attribute value: 
884643E30022
Dec 12 10:08:50 batch-ca4-02 postfix/smtp[26956]: deliver_request_get: file 
active/884643E30022
Dec 12 10:08:50 batch-ca4-02 postfix/smtp[26956]: 884643E30022: 
to=, relay=192.168.X.X[192.168.X.X]:25, delay=102997, 
delays=102997/0/0/0.05, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 
8DBA6D0016E)
Dec 12 10:08:50 batch-ca4-02 postfix/qmgr[26936]: qmgr_active_done: 884643E30022
Dec 12 10:08:50 batch-ca4-02 postfix/qmgr[26936]: 884643E30022: removed
Dec 12 10:08:50 batch-ca4-02 postfix/qmgr[26936]: qmgr_job_free: 884643E30022 
smtp

Here is everything that I could find between the hours where the "read timeout 
on cleanup socket error" happened. 
(Dec 11 05:31:27 batch-ca4-02 postfix/cleanup[31691]: warning: 8A2993E3003B: 
read timeout on cleanup socket)

Dec 11 04:04:26 batch-ca4-02 postfix/pickup[25527]: 9CC1F3E3003A: uid=0 
from=
Dec 11 04:06:17 batch-ca4-02 postfix/smtpd[31631]: dict_eval: const  pickup
Dec 11 04:06:17 batch-ca4-02 postfix/smtp[31689]: dict_eval: const  pickup
Dec 11 04:09:19 batch-ca4-02 postfix/pickup[25527]: 7905B3E3003A: uid=500 
from=
Dec 11 07:15:59 batch-ca4-02 postfix/smtpd[5663]: dict_eval: const  pickup

And here is everything before the "read timeout on cleanup socket":

Dec 11 04:07:59 batch-ca4-02 postfix/qmgr[28082]: input attribute name: 
diag_type
Dec 11 04:07:59 batch-ca4-02 postfix/qmgr[28082]: input attribute value: (end)
Dec 11 04:07:59 batch-ca4-02 postfix/qmgr[28082]: private/smtp socket: wanted 
attribute: diag_text
Dec 11 04:07:59 batch-ca4-02 postfix/qmgr[28082]: input attribute name: 
diag_text
Dec 11 04:07:59 batch-ca4-02 postfix/qmgr[28082]: input attribute value: (end)
Dec 11 04:07:59 batch-ca4-02 postfix/qmgr[28082]: private/smtp socket: wanted 
attribute: mta_type
Dec 11 04:07:59 batch-ca4-02 postfix/qmgr[28082]: input attribute name: mta_type
Dec 11 04:07:59 batch-ca4-02 postfix/qmgr[28082]: input attribute value: (end)
Dec 11 04:07:59 batch-ca4-02 postfix/qmgr[28082]: private/smtp socket: wanted 
attribute: mta_mname
Dec 11 04:07:59 batch-ca4-02 postfix/qmgr[28082]: input attribute name: 
mta_mname
Dec 11 04:07:59 batch-ca4-02 postfix/qmgr[28082]: input attribute value: (end)
Dec 11 04:07:59 batch-ca4-02 postfix/qmgr[28082]: private/smtp socket: wanted 
attribute: action
Dec 11 04:07:59 batch-ca4-02 postfix/qmgr[28082]: input attribute name: action
Dec 11 04:07:59 batch-ca4-02 postfix/qmgr[28082]: input attribute value: (end)
Dec 11 04:07:59 batch-ca4-02 postfix/qmgr[28082]: private/smtp socket: wanted 
attribute: reason
Dec 11 04:07:59 batch-ca4-02 postfix/qmgr[28082]: input attribute name: reason
Dec 11 04:07:59 batch-ca4-02 postfix/qmgr[28082]: input attribute value: (end)
Dec 11 04:07:59 batch-ca4-02 postfix/qmgr[28082]: private/smtp socket: wanted 
attribute: status
Dec 11 04:07:59 batch-ca4-02 postfix/qmgr[28082]: input attribute name: status
Dec 11 04:07:59 batch-ca4-02 postfix/qmgr[28082]: input attribute value: 0
Dec 11 04:07:59 batch-ca4-02 postfix/qmgr[28082]: private/smtp socket: wanted 
attribute: (list terminator)
Dec 11 04:07:59 batch-ca4-02 postfix/qmgr[28082]: input attribute name: (end)
Dec 11 04:07:59 batch-ca4-02 postfix/qmgr[28082]: qmgr_queue_unthrottle: queue 
192.168.X.X
Dec 11 04:07:59 batch-ca4-02 postfix/qmgr[28082]: qmgr_active_done: 177013E30037
Dec 11 04:07:59 batch-ca4-02 postfix/smtp[31689]: master_notify: status 1
Dec 11 04:07:59 batch-ca4-02 postfix/smtp[31689]: connection closed
Dec 11 04:07:59 batch-ca4-02 postfix/qmgr[28082]: 177013E30037: removed
Dec 11 04:07:59 batch-ca4-02 postfix/qmgr[28082]: qmgr_job_free: 177013E30037 
smtp
Dec 11 04:09:19 batch-ca4-02 postfix/pickup[25527]: 7905B3E3003A: uid=500 
from=
Dec 11 04:09:19 batch-ca4-02 postfix/cle

Re: Postfix Not Sending Emails. Timeout on Cleanup socket error.

[Wietse Venema]

Gonzo Fernandez:
> # egrep 884643E30022 /var/log/maillog
> 
> Dec 12 10:08:50 batch-ca4-02 postfix/pickup[26935]: warning: 884643E30022: 
> message has been queued for 1 days
> Dec 12 10:08:50 batch-ca4-02 postfix/pickup[26935]: 884643E30022: uid=500 
> from=

What user acccount has uid=500? Is this your web server? Perhaps
you have an exploitable web application. This is very popular with
spammers.

To block local submissions from this user,

/etc/postfix/main.cf:
authorized_submit_users = !username, static:anyone

> Dec 12 10:08:50 batch-ca4-02 postfix/qmgr[26936]: qmgr_active_feed: 
> incoming/884643E30022

Please turn off all your verbose logging in master.cf. It makes
Postfix VERY VERY SLOW and makes mail overload problems much worse.

On the other hand, if your email overload is caused by spam, please
turn on verbose logging on everything, to slow down the delivery
of spam.

Wietse

Re: Postfix Not Sending Emails. Timeout on Cleanup socket error.

[Gonzo Fernandez]

Hi Wietse,

The UID 500 is from our batch email not spam. It constantly sends out emails to 
our clients on a regular basis. Also, I turned off verbose logging on all 
options. I originally turned it on to try and figure out why it was getting 
stuck on the weekends, but now it is off. I will see if that helps this 
weekend. Thank you.

Gonzo Fernandez
Network Engineer

On Dec 15, 2011, at 5:35 PM, Wietse Venema wrote:

> Gonzo Fernandez:
>> # egrep 884643E30022 /var/log/maillog
>> 
>> Dec 12 10:08:50 batch-ca4-02 postfix/pickup[26935]: warning: 884643E30022: 
>> message has been queued for 1 days
>> Dec 12 10:08:50 batch-ca4-02 postfix/pickup[26935]: 884643E30022: uid=500 
>> from=
> 
> What user acccount has uid=500? Is this your web server? Perhaps
> you have an exploitable web application. This is very popular with
> spammers.
> 
> To block local submissions from this user,
> 
> /etc/postfix/main.cf:
>authorized_submit_users = !username, static:anyone
> 
>> Dec 12 10:08:50 batch-ca4-02 postfix/qmgr[26936]: qmgr_active_feed: 
>> incoming/884643E30022
> 
> Please turn off all your verbose logging in master.cf. It makes
> Postfix VERY VERY SLOW and makes mail overload problems much worse.
> 
> On the other hand, if your email overload is caused by spam, please
> turn on verbose logging on everything, to slow down the delivery
> of spam.
> 
>   Wietse