Last night our mailserver networking seemed to die. This has happened approximately 3 times over the last year but I haven't been able to find what triggers it. In yesterday's mail log just before losing networking there is a verizon wireless connection attempt that postscreen rejects due to bare newlines and command pipelining. All connection activity stops immediately after this. Less than a minute later dovecot drops all imap connections due to inactivity. I don't see anything unusual in other logs around this time. The machine was unreachable for the next 10 hours (there are a couple local cron job email attempts). When I arrived this morning I could not reset the network interface. Restarting the machine cleared it. I know it's a long shot but could the command pipelining connection attempt have caused this?
postfix 2.10.2 and dovecot 2.2.9 Jan 28 17:40:24 mailbox postfix/postscreen[99504]: CONNECT from [70.211.5.13]:9788 to [192.168.0.254]:25 Jan 28 17:40:24 mailbox postfix/postscreen[99504]: PREGREET 198 after 0 from [70.211.5.13]:9788: \22\3\1\0\193\1\0\0\189\3\1R\232\\\t\158\\D GO6\138- QY!\158\234j2\174\30\142jh\223 \229\1615\231\6 \ Jan 28 17:40:24 mailbox postfix/dnsblog[99618]: addr 70.211.5.13 listed by domain zen.spamhaus.org as 127.0.0.11 Jan 28 17:40:24 mailbox postfix/dnsblog[99513]: addr 70.211.5.13 listed by domain dnsbl.sorbs.net as 127.0.0.10 Jan 28 17:40:24 mailbox postfix/postscreen[99504]: DNSBL rank 4 for [70.211.5.13]:9788 Jan 28 17:40:24 mailbox postfix/postscreen[99504]: BARE NEWLINE from [70.211.5.13]:9788 after \22\3\1\0\193\1\0\0\189\3\1R\232\\\t\158\\DGO6 \138- QY!\158\234j2\174\30\142jh\223 \229\1615\231\6 \192"\144\218\tY"\24\209\135V\146\224)\151fP-\233\27;]l\134\173\207\252\228\240\245) Jan 28 17:40:24 mailbox postfix/postscreen[99504]: COMMAND PIPELINING from [70.211.5.13]:9788 after ???: \0J\0\255\192$\192#\192\n\192\t\192 \a\192\b\192(\192'\192\20\192\19\192\17\192\18\192&\192%\192*\192)\192\5\192\4\192\2\192\3\192\15\192\14\192\f\192\r\0=\0<\0/\0\5\0\4\0005\0 \n\0g\0k\0003\0009\0\22\1\0\0*\0\0\0\20\0\18\0\0\15mailbox.dop Jan 28 17:40:24 mailbox postfix/postscreen[99504]: HANGUP after 0 from [70.211.5.13]:9788 in tests after SMTP handshake Jan 28 17:40:24 mailbox postfix/postscreen[99504]: DISCONNECT [70.211.5.13]:9788 Jan 28 17:40:24 mailbox postfix/postscreen[99504]: HANGUP after 0 from [70.211.5.13]:9788 in tests after SMTP handshake Jan 28 17:40:24 mailbox postfix/postscreen[99504]: DISCONNECT [70.211.5.13]:9788 Jan 28 17:40:24 mailbox postfix/submission/smtpd[99658]: connect from 13.sub-70-211-5.myvzw.com[70.211.5.13] Jan 28 17:40:25 mailbox postfix/submission/smtpd[99658]: lost connection after UNKNOWN from 13.sub-70-211-5.myvzw.com[70.211.5.13] Jan 28 17:40:25 mailbox postfix/submission/smtpd[99658]: disconnect from 13.sub-70-211-5.myvzw.com[70.211.5.13] Jan 28 17:41:09 mailbox dovecot[95697]: imap(us...@dop.com): Disconnected for inactivity in=2446 out=6067 Jan 28 17:42:44 mailbox dovecot[95697]: imap(us...@dop.com): Disconnected for inactivity in=948 out=58839 Jan 28 17:43:35 mailbox postfix/anvil[99466]: statistics: max connection rate 1/60s for (smtpd:66.96.196.194) at Jan 28 17:35:38 Jan 28 17:43:35 mailbox postfix/anvil[99466]: statistics: max connection count 1 for (smtpd:66.96.196.194) at Jan 28 17:35:38 Jan 28 17:43:35 mailbox postfix/anvil[99466]: statistics: max cache size 3 at Jan 28 17:38:00 Jan 28 17:43:55 mailbox dovecot[95697]: imap(us...@dop.com): Disconnected for inactivity in=333 out=3976 Jan 28 17:46:23 mailbox dovecot[95697]: imap(us...@dop.com): Disconnected for inactivity in=17 out=443 Jan 28 17:46:29 mailbox dovecot[95697]: imap(us...@dop.com): Disconnected for inactivity in=33 out=649 Jan 28 17:49:31 mailbox postfix/qmgr[95785]: 38BC719E55E4: from=<>, size=10965, nrcpt=1 (queue active) Jan 28 17:51:10 mailbox dovecot[95697]: imap(us...@dop.com): Disconnected for inactivity in=509 out=3728 Jan 28 17:51:38 mailbox dovecot[95697]: imap(us...@dop.com): Disconnected for inactivity in=292 out=2232 Jan 28 17:58:54 mailbox dovecot[95697]: imap(us...@dop.com): Disconnected for inactivity in=333 out=3976 Jan 28 17:59:44 mailbox dovecot[95697]: imap(us...@dop.com): Disconnected for inactivity in=6805 out=17328 Jan 28 18:07:36 mailbox dovecot[95697]: imap(us...@dop.com): Disconnected for inactivity in=902 out=45547 Jan 28 18:09:45 mailbox dovecot[95697]: imap(us...@dop.com): Disconnected for inactivity in=11812 out=29601 Jan 28 18:09:45 mailbox dovecot[95697]: imap(us...@dop.com): Disconnected for inactivity in=12046 out=29570 Jan 28 18:10:18 mailbox dovecot[95697]: imap(us...@dop.com): Disconnected for inactivity in=8586 out=14499 Jan 28 21:32:00 mailbox postfix/pickup[99702]: 6AFA719E60EF: uid=0 from=<root> Jan 28 21:32:00 mailbox postfix/cleanup[99717]: 6AFA719E60EF: message-id=<20140129053200.6afa719e6...@mailbox.dop.com> Jan 28 21:32:00 mailbox postfix/qmgr[95785]: 6AFA719E60EF: from=<r...@dop.com>, size=662, nrcpt=1 (queue active) Jan 28 21:48:40 mailbox postfix/pipe[99720]: warning: pipe_command_read: read time limit exceeded Jan 28 21:48:40 mailbox postfix/pipe[99720]: 6AFA719E60EF: to=<te...@dop.com>, relay=dovecot, delay=1000, delays=0.3/0.03/0/1000, dsn=5.3.0, status=bounced (Command time limit exceeded: "/opt/local/libexec/dovecot/deliver") Jan 28 21:48:40 mailbox postfix/cleanup[99726]: B1F5D19E60F3: message-id=<20140129054840.b1f5d19e6...@mailbox.dop.com> Jan 28 21:48:40 mailbox postfix/bounce[99724]: 6AFA719E60EF: sender non-delivery notification: B1F5D19E60F3 Jan 28 21:48:40 mailbox postfix/qmgr[95785]: B1F5D19E60F3: from=<>, size=2397, nrcpt=1 (queue active) Jan 28 21:48:40 mailbox postfix/qmgr[95785]: 6AFA719E60EF: removed Jan 28 22:05:20 mailbox postfix/pipe[99720]: warning: pipe_command_read: read time limit exceeded Jan 28 22:05:20 mailbox postfix/pipe[99720]: B1F5D19E60F3: to=<r...@dop.com>, relay=dovecot, delay=1000, delays=0.03/0.01/0/1000, dsn=5.3.0, status=bounced (Command time limit exceeded: "/opt/local/libexec/dovecot/deliver") Jan 28 22:05:20 mailbox postfix/qmgr[95785]: B1F5D19E60F3: removed Jan 28 22:49:31 mailbox postfix/qmgr[95785]: fatal: 38BC719E55E4: timeout receiving delivery status from transport: smtp Jan 28 22:49:32 mailbox postfix/master[377]: warning: process /opt/local/libexec/postfix/qmgr pid 95785 exit status 1 Jan 28 22:49:32 mailbox postfix/qmgr[99744]: 38BC719E55E4: skipped, still being delivered Jan 28 22:54:31 mailbox postfix/qmgr[99744]: 38BC719E55E4: skipped, still being delivered Jan 28 22:59:31 mailbox postfix/qmgr[99744]: 38BC719E55E4: skipped, still being delivered Jan 28 23:04:31 mailbox postfix/qmgr[99744]: 38BC719E55E4: skipped, still being delivered Jan 28 23:09:31 mailbox postfix/qmgr[99744]: 38BC719E55E4: skipped, still being delivered ... $ postconf -n broken_sasl_auth_clients = yes command_directory = /opt/local/sbin config_directory = /opt/local/etc/postfix daemon_directory = /opt/local/libexec/postfix data_directory = /opt/local/var/lib/postfix debugger_command = PATH=/opt/local/bin:/bin:/usr/bin:/usr/local/bin:/usr/X11R6/bin ddd $daemon_directory/$process_name $process_id & sleep 5 default_privs = nobody delay_warning_time = 4h dovecot_destination_recipient_limit = 1 dspam-lmtp_destination_recipient_limit = 1 home_mailbox = Maildir/ html_directory = no inet_protocols = ipv4 mail_owner = _postfix mailq_path = /opt/local/bin/mailq manpage_directory = /opt/local/share/man message_size_limit = 51200000 mydestination = $myhostname, localhost.$mydomain, localhost myhostname = mailbox.dop.com mynetworks = 192.168.0.0/23, 127.0.0.0/8, 50.56.203.34, 198.101.248.79, 198.101.238.188 myorigin = $mydomain newaliases_path = /opt/local/bin/newaliases postscreen_access_list = permit_mynetworks, cidr:/opt/local/etc/postfix/postscreen_access.cidr postscreen_bare_newline_action = enforce postscreen_bare_newline_enable = yes postscreen_blacklist_action = drop postscreen_dnsbl_action = enforce postscreen_dnsbl_sites = zen.spamhaus.org*3 b.barracudacentral.org*2 bl.spameatingmonkey.net*2 dnsbl.ahbl.org*2bl.spamcop.net dnsbl.sorbs.net psbl.surriel.com bl.mailspike.net swl.spamhaus.org*-4 postscreen_dnsbl_threshold = 3 postscreen_greet_action = enforce postscreen_non_smtp_command_enable = yes postscreen_pipelining_action = enforce postscreen_pipelining_enable = yes proxy_interfaces = 70.167.15.110 queue_directory = /opt/local/var/spool/postfix readme_directory = /opt/local/share/postfix/readme sample_directory = /opt/local/share/postfix/sample sendmail_path = /opt/local/sbin/sendmail setgid_group = _postdrop smtpd_banner = $myhostname ESMTP $mail_name smtpd_helo_required = yes smtpd_helo_restrictions = permit_mynetworks, permit_sasl_authenticated, reject_non_fqdn_helo_hostname smtpd_recipient_restrictions = permit_mynetworks, permit_sasl_authenticated, reject_non_fqdn_sender, reject_non_fqdn_recipient, reject_unknown_sender_domain, reject_unknown_recipient_domain, reject_unauth_pipelining, reject_unauth_destination, reject_unlisted_recipient, check_recipient_access pcre:/opt/local/etc/postfix/recipient_checks.pcre, check_helo_access hash:/opt/local/etc/postfix/helo_checks, check_sender_access hash:/opt/local/etc/postfix/sender_checks, check_client_access hash:/opt/local/etc/postfix/client_checks, check_client_access pcre:/opt/local/etc/postfix/fqrdns.pcre, reject_rhsbl_clientdbl.spamhaus.org, reject_rhsbl_sender dbl.spamhaus.org, reject_rhsbl_helo dbl.spamhaus.org, check_client_access pcre:/opt/local/etc/postfix/dspam_filter_access smtpd_reject_unlisted_sender = yes smtpd_sasl_auth_enable = yes smtpd_sasl_local_domain = $myhostname smtpd_sasl_path = private/auth smtpd_sasl_security_options = noanonymous smtpd_sasl_type = dovecot smtpd_sender_restrictions = permit_mynetworks, reject_unknown_address smtpd_tls_cert_file = /opt/local/etc/postfix/ssl/certs/postfix.cert smtpd_tls_key_file = /opt/local/etc/postfix/ssl/private/postfix.key smtpd_tls_loglevel = 1 smtpd_tls_security_level = may tls_random_source = dev:/dev/urandom transport_maps = hash:/opt/local/etc/postfix/transport unknown_local_recipient_reject_code = 550 vacation_destination_recipient_limit = 1 virtual_alias_maps = proxy:mysql:/opt/local/etc/postfix/mysql_virtual_alias_maps.cf virtual_gid_maps = static:_vmail virtual_mailbox_base = /Volumes/mail/vmail/ virtual_mailbox_domains = mysql:/opt/local/etc/postfix/mysql_virtual_mailbox_domains.cf virtual_mailbox_maps = proxy:mysql:/opt/local/etc/postfix/mysql_virtual_mailbox_maps.cf virtual_minimum_uid = _vmail virtual_transport = dovecot virtual_uid_maps = static:_vmail Thanks, -Terry Terry Barnum digital OutPost http://www.dop.com
