1 Topic by chrisjrob

  • chrisjrob
  • chrisjrob
  • Member
  • Offline
  • From: United Kingdom
  • Registered: 2012-06-22
  • Posts: 20

Topic: Improper command pipelining after DATA

======== Required information ====
- iRedMail version: 0.8.5
- iRedAdmin-Pro-LDAP version: 1.9.0
- iRedAPD version: 1.4.1
- Store mail accounts in which backend (LDAP/MySQL/PGSQL): LDAP
- Linux/BSD distribution name and version: Ubuntu 12.04.3 LTS
- Related log if you're reporting an issue: /var/log/syslog
====

Our incoming mail is delivered first to a anti-spam relay (Bytemark) before being passed onto our iredmail server (a VPS hosted by Bytemark). From time to time I am seeing the following entries appearing in our logs and wondered what they mean and whether they indicate a problem:

postfix/smtpd[2913]: improper command pipelining after DATA from nospam1.sh.bytemark.co.uk[89.16.184.148]

I have logged a call with Bytemark on this issue and they are looking into it, but I believe at the moment it is as much a mystery to them. They cannot see corresponding errors in their mail logs.

Any advice gratefully received.

----

Spider Email Archiver: On-Premises, lightweight email archiving software developed by iRedMail team. Supports Amazon S3 compatible storage and custom branding.

chrisjrob's Website

2 Reply by ZhangHuangbin

  • ZhangHuangbin
  • ZhangHuangbin
  • iRedMail Developers
  • Offline
  • Registered: 2009-05-06
  • Posts: 30,768

Re: Improper command pipelining after DATA

No idea at all. I suggest you read this mailing list thread as reference:
http://readlist.com/lists/postfix.org/p … 76929.html

I think you need to turn on debug for this bytemark IP address in Postfix to check detailed SMTP session.

3 Reply by chrisjrob

  • chrisjrob
  • chrisjrob
  • Member
  • Offline
  • From: United Kingdom
  • Registered: 2012-06-22
  • Posts: 20

Re: Improper command pipelining after DATA

Thank you, I have added the Bytemark addresses to debug_peer_list in main.cf and the following two are examples of the more verbose logs resulting:

Nov 24 10:29:19 mail2 postfix/smtpd[32718]: 05E9498061: client=nospam2.sh.bytemark.co.uk[89.16.184.149]
Nov 24 10:29:19 mail2 postfix/smtpd[32718]: improper command pipelining after DATA from nospam2.sh.bytemark.co.uk[89.16.184.149]: 
Nov 24 10:29:19 mail2 postfix/smtpd[32718]: 05E9498061: reject: DATA from nospam2.sh.bytemark.co.uk[89.16.184.149]: 503 5.5.0 <DATA>: Data command rejected: Improper use of SMTP command pipelining; from=<blackballmedialz.F.7805.2.0@blackballmedia.gtml2.com> to=<snh@tridentgarages.co.uk> proto=ESMTP helo=<nospam2.sh.bytemark.co.uk>
Nov 24 10:29:19 mail2 postfix/smtpd[32718]: lost connection after DATA from nospam2.sh.bytemark.co.uk[89.16.184.149]
Nov 24 10:29:19 mail2 postfix/smtpd[32718]: disconnect from nospam2.sh.bytemark.co.uk[89.16.184.149]
Nov 24 10:29:36 mail2 postfix/smtpd[32718]: connect from nospam2.sh.bytemark.co.uk[89.16.184.149]
Nov 24 10:29:36 mail2 postfix/smtpd[32718]: 94AEF98061: client=nospam2.sh.bytemark.co.uk[89.16.184.149]
Nov 24 10:29:37 mail2 postfix/smtpd[32718]: disconnect from nospam2.sh.bytemark.co.uk[89.16.184.149]
Nov 24 10:29:40 mail2 postfix/smtpd[32718]: connect from nospam3.sh.bytemark.co.uk[89.16.184.150]
Nov 24 10:29:40 mail2 postfix/smtpd[32718]: 37AD398286: client=nospam3.sh.bytemark.co.uk[89.16.184.150]
Nov 24 10:41:34 mail2 postfix/smtpd[516]: 5867698061: client=nospam1.sh.bytemark.co.uk[89.16.184.148]
Nov 24 10:41:34 mail2 postfix/smtpd[516]: improper command pipelining after DATA from nospam1.sh.bytemark.co.uk[89.16.184.148]: 
Nov 24 10:41:34 mail2 postfix/smtpd[516]: 5867698061: reject: DATA from nospam1.sh.bytemark.co.uk[89.16.184.148]: 503 5.5.0 <DATA>: Data command rejected: Improper use of SMTP command pipelining; from=<shredonsitelz.F.20956.36.0@shredonsite.gtml2.com> to=<webmaster@tridentgarages.co.uk> proto=ESMTP helo=<nospam1.sh.bytemark.co.uk>
Nov 24 10:41:34 mail2 postfix/smtpd[516]: lost connection after DATA from nospam1.sh.bytemark.co.uk[89.16.184.148]
Nov 24 10:41:34 mail2 postfix/smtpd[516]: disconnect from nospam1.sh.bytemark.co.uk[89.16.184.148]
Nov 24 10:42:39 mail2 postfix/smtpd[516]: connect from nospam2.sh.bytemark.co.uk[89.16.184.149]
Nov 24 10:42:39 mail2 postfix/smtpd[516]: 1772198061: client=nospam2.sh.bytemark.co.uk[89.16.184.149]
Nov 24 10:42:40 mail2 postfix/smtpd[516]: disconnect from nospam2.sh.bytemark.co.uk[89.16.184.149]
Nov 24 10:42:41 mail2 postfix/smtpd[516]: connect from 121.8.187.81.in-addr.arpa[81.187.8.121]
Nov 24 10:42:41 mail2 postfix/smtpd[516]: disconnect from 121.8.187.81.in-addr.arpa[81.187.8.121]

Bytemark are saying that they are seeing a timeout, but our mailserver is never under any significant load (it barely exceeds zero load average). This is an example of what they're seeing in the logs:

2013-11-25 05:46:50 1VjThK-0003f7-F9 == snh@tridentgarages.co.uk
R=hubbed_hosts_abmx T=remote_smtp defer (110): Connection timed out:
SMTP timeout while connected to 212.110.190.52 [212.110.190.52] after
MAIL FROM:<principalitlz.F.35437.125.0@principal.sgml1.co.uk> SIZE=21166

Once again, any suggestions gratefully received!

--
Chris

chrisjrob's Website

4 Reply by ZhangHuangbin

  • ZhangHuangbin
  • ZhangHuangbin
  • iRedMail Developers
  • Offline
  • Registered: 2009-05-06
  • Posts: 30,768

Re: Improper command pipelining after DATA

Could you please show us output of command "postconf -n" to help troubleshoot?

If it's caused by timeout, please try to increase time for below two Postfix parameters in main.cf:

smtp_data_done_timeout =    # <- Default is 600s (600 seconds), increase to, for example, 1200s.
smtp_data_xfer_timeout =    # <- Default is 180s, increase to, for example, 360s.

Restarting Postfix is recommended after changed its parameters.

References:
http://www.postfix.org/postconf.5.html# … ne_timeout
http://www.postfix.org/postconf.5.html# … er_timeout

5 Reply by chrisjrob

  • chrisjrob
  • chrisjrob
  • Member
  • Offline
  • From: United Kingdom
  • Registered: 2012-06-22
  • Posts: 20

Re: Improper command pipelining after DATA

ZhangHuangbin wrote:

Could you please show us output of command "postconf -n" to help troubleshoot?

I have pastebinned it to:

http://paste.ubuntu.com/6484460/

ZhangHuangbin wrote:

If it's caused by timeout, please try to increase time for below two Postfix parameters in main.cf:
smtp_data_done_timeout =    # <- Default is 600s (600 seconds), increase to, for example, 1200s.
smtp_data_xfer_timeout =    # <- Default is 180s, increase to, for example, 360s.
Restarting Postfix is recommended after changed its parameters.

I will certainly try that.

Thank you.

--
Chris

chrisjrob's Website