SMTP postfix crashing - network_biopair_interop read timeout

Question

SMTP postfix crashing - network_biopair_interop read timeout

Periodically, my mail server goes into a crash cycle. Error messages like those below appear, and very quickly, the machine becomes unresponsive (I believe because it can't fork any more process - so OD won't authenticate, and any command which requires authentication (like a restart or service restart) hangs indefinitely).

The machine will crash every ~12 hours after being rebooted, for maybe 2-3 days before the problem mysteriously goes into remission. I don't know what confluence of events causes this, or how to see it coming sooner so I can stop and restart the mail service.

Any insight or solutions would be greatly appreciated.

/var/log/system.log:

Apr 25 07:37:43 mercury postfix/smtpd[8213]: warning: Read failed in network biopairinterop with errno=0: num_read=0, want_read=5
Apr 25 07:48:39 mercury postfix/smtpd[8475]: warning: Read failed in network biopairinterop with errno=0: num_read=0, want_read=5
Apr 25 07:50:06 mercury postfix/master[51]: warning: unix triggerevent: read timeout for service public/flush
Apr 25 07:55:50 mercury postfix/pipe[8467]: warning: pipe commandwrite: write time limit exceeded
Apr 25 07:55:50 mercury postfix/pipe[8470]: warning: pipe commandread: read time limit exceeded
Apr 25 07:57:08 mercury postfix/pipe[8479]: warning: pipe commandread: read time limit exceeded

G4 quicksilver, Mac OS X (10.4.6)

Posted on Apr 25, 2006 6:28 AM

Reply

Answer 1

pterobyte

Level 6

11,104 points

Apr 25, 2006 7:21 AM in response to Brian C. Howard

Please post the unmodified output of postconf -n
Also more log info would be useful. You log snippet refers to different processes (see the number in square brackets). It is important to "follow" one or two processes over a longer log extract. Also check your mailaccess.log for the same timeframe.

My gut feeling is that you have an issue with SSL certificates which gets triggered by certain users only. Thus, it doesn't happen all the time.
But it could be something completely different 😉

Reply

Answer 2

Apr 27, 2006 9:07 AM in response to pterobyte

The output of postconf -n:

mercury:/ root# postconf -n
alias_maps = hash:/etc/aliases,hash:/var/mailman/data/aliases
command_directory = /usr/sbin
config_directory = /etc/postfix
content_filter = smtp-amavis:[127.0.0.1]:10024
daemon_directory = /usr/libexec/postfix
debug peerlevel = 2
enable serveroptions = yes
html_directory = no
inet_interfaces = all
mail_owner = postfix
mailbox sizelimit = 0
mailbox_transport = cyrus
mailq_path = /usr/bin/mailq
manpage_directory = /usr/share/man
message sizelimit = 15728640
mydestination = $myhostname,localhost.$mydomain,tjs.org,staff.tjs.org,mercury.tjs.org,info.tjs. org
mydomain = tjs.org
mydomain_fallback = localhost
myhostname = mail.tjs.org
mynetworks = 127.0.0.1/32,10.1.1.0/24,66.148.181.0/24,66.90.0.0/16,192.168.1.0/24,66.93.192. 247/32,66.93.193.247/32
mynetworks_style = host
newaliases_path = /usr/bin/newaliases
owner requestspecial = no
queue_directory = /private/var/spool/postfix
readme_directory = /usr/share/doc/postfix
recipient_delimiter = +
sample_directory = /usr/share/doc/postfix/examples
sendmail_path = /usr/sbin/sendmail
setgid_group = postdrop
smtpd pw_server_securityoptions = cram-md5,gssapi
smtpd recipientrestrictions = permit sasl_authenticated,permit_mynetworks,reject_unauthdestination,permit
smtpd sasl_authenable = yes
smtpd tls_certfile = /etc/certificates/*.tjs.org.crt
smtpd tls_keyfile = /etc/certificates/*.tjs.org.key
smtpd use_pwserver = yes
smtpd usetls = yes
unknown local_recipient_rejectcode = 550

And here's a more full version of the logs. I think the increasing pids is a symptom of the problem:

Apr 27 10:34:58 mercury pop3[7164]: login: 66.148.181.178.nw.nuvox.net [66.148.181.178] XXX APOP User logged in
Apr 27 10:34:58 mercury pop3[7369]: login: 66.148.181.178.nw.nuvox.net [66.148.181.178] XXX APOP User logged in
Apr 27 10:35:18 mercury pop3[7164]: starttls: TLSv1 with cipher AES256-SHA (256/256 bits new) no authentication
Apr 27 10:35:19 mercury pop3[7164]: login: ppp-70-245-234-7.dsl.stlsmo.swbell.net [70.245.234.7] YYY APOP+TLS User logged in
Apr 27 10:35:28 mercury pop3[7369]: login: c-69-241-232-137.hsd1.mi.comcast.net [69.241.232.137] XXX APOP User logged in
Apr 27 10:35:59 mercury pop3[7164]: login: 66.148.181.178.nw.nuvox.net [66.148.181.178] XXX APOP User logged in
Apr 27 10:36:10 mercury pop3[7369]: login: dsl093-192-247.stl1.dsl.speakeasy.net [66.93.192.247] XXX APOP User logged in
Apr 27 10:36:11 mercury pop3[7164]: login: 66.148.181.178.nw.nuvox.net [66.148.181.178] XXX APOP User logged in
Apr 27 10:37:01 mercury pop3[7164]: login: 66.148.181.178.nw.nuvox.net [66.148.181.178] XXX APOP User logged in
Apr 27 10:37:01 mercury pop3[7369]: login: 66.148.181.178.nw.nuvox.net [66.148.181.178] XXX APOP User logged in
Apr 27 10:37:01 mercury pop3[7833]: login: 66.148.181.178.nw.nuvox.net [66.148.181.178] XXX APOP User logged in
Apr 27 10:37:07 mercury ctl_cyrusdb[7836]: checkpointing cyrus databases
Apr 27 10:37:08 mercury ctl_cyrusdb[7836]: done checkpointing cyrus databases
Apr 27 10:37:15 mercury pop3[7164]: login: dsl093-192-247.stl1.dsl.speakeasy.net [66.93.192.247] XXX APOP User logged in
Apr 27 10:37:26 mercury pop3[7833]: login: dsl093-192-247.stl1.dsl.speakeasy.net [66.93.192.247] XXX APOP User logged in
Apr 27 10:37:38 mercury pop3[7369]: login: 66.148.181.178.nw.nuvox.net [66.148.181.178] XXX APOP User logged in
Apr 27 10:37:52 mercury imap[7842]: login: localhost [::1] jroth CRAM-MD5 User logged in
Apr 27 10:37:52 mercury pop3[7164]: login: 66.148.181.178.nw.nuvox.net [66.148.181.178] XXX APOP User logged in
Apr 27 10:38:03 mercury imap[7842]: login: localhost [::1] XXX CRAM-MD5 User logged in
Apr 27 10:38:13 mercury imap[7842]: login: localhost [::1] XXX CRAM-MD5 User logged in
Apr 27 10:38:15 mercury imap[7842]: login: localhost [::1] XXX CRAM-MD5 User logged in
Apr 27 10:38:26 mercury pop3[7833]: login: 66.148.181.178.nw.nuvox.net [66.148.181.178] XXX APOP User logged in
Apr 27 10:38:30 mercury imap[7842]: login: localhost [::1] XXX CRAM-MD5 User logged in
Apr 27 10:40:18 mercury pop3[7871]: TLS server engine: cannot load CA data
Apr 27 10:40:19 mercury pop3[7871]: TLS server engine: No CA file specified. Client side certs may not work
Apr 27 10:40:19 mercury pop3[7871]: starttls: TLSv1 with cipher AES256-SHA (256/256 bits new) no authentication
Apr 27 10:41:41 mercury postfix/master[51]: warning: unix triggerevent: read timeout for service public/flush
Apr 27 10:50:18 mercury pop3[7913]: TLS server engine: cannot load CA data
Apr 27 10:50:18 mercury pop3[7913]: TLS server engine: No CA file specified. Client side certs may not work
Apr 27 10:50:18 mercury pop3[7913]: starttls: TLSv1 with cipher AES256-SHA (256/256 bits new) no authentication

And then the crash. Note this is a more recent crash cycle than the last one which I posted logs from.

Interesting that SSL certificates might be the issue. The one user, shown above as YYY, always triggers the log messages about TLS, which none of the other users seem to use. I haven't enabled SSL for email, but I wouldn't mind doing it to fix this problem.

Thanks for your thoughts and time.

---
Brian Howard

Reply

Answer 3

pterobyte

Level 6

11,104 points

Apr 27, 2006 10:17 AM in response to Brian C. Howard

smtpd tls_certfile =
/etc/certificates/*.tjs.org.crt
smtpd tls_keyfile = /etc/certificates/*.tjs.org.key
smtpd usetls = yes

I haven't enabled SSL for email,

According to your configuration, you have enabled it!
See http://www.postfix.org/postconf.5.html for more information.

Your server is doing as told. If I connect to it through telnet it offers TLS support and if I request it, it responds correctly. See below output.

alexs-pb-g4:~ alex$ telnet mercury.tjs.org 25
Trying 66.148.181.187...
Connected to mercury.tjs.org.
Escape character is '^]'.
220 mail.tjs.org ESMTP Postfix
EHLO FOO
250-mail.tjs.org
250-PIPELINING
250-SIZE 15728640
250-VRFY
250-ETRN
250-STARTTLS
250-AUTH CRAM-MD5 GSSAPI
250 8BITMIME
STARTTLS
220 Ready to start TLS

I remember there used to be an issue with some mail clients, but unfortunately I am out of the office and do not have all my docs and links at hand. Since you do not require TLS, ask your user(s) not to use it for a day or two to see if the problem goes away (or alternatively disable it on the server).

Alex

Reply