Re: Experience with the new speed_adjust feature

2009-11-13 Thread Victor Duchovni
On Fri, Nov 13, 2009 at 01:17:07PM -0500, Wietse Venema wrote:

> Mark Martinec:
> > On Friday 13 November 2009 18:52:03 Wietse Venema wrote:
> > > Thanks for the logging. If you have time, can you change the code
> > > to print information about the non-zero size? This could be a
> > > filesystem feature where ftruncate() does not reset st_size until
> > > the file is rewritten or closed (in which case my attempt to force
> > > easly release of disk blocks are in vain).
> 
> Victor found it (missing fflush before ftruncate). If you can back
> out the changes and apply the patch below.

We could also choose to rewind the proxy log stream in the "free"
code-path (and check that it is already re-wound in the re-use code-path),
which would look something like:

Index: src/smtpd/smtpd_proxy.c
--- src/smtpd/smtpd_proxy.c 11 Nov 2009 04:41:53 -  1.1.1.5
+++ src/smtpd/smtpd_proxy.c 13 Nov 2009 18:41:04 -
@@ -966,16 +966,13 @@
  * truncating the file redundantly.
  */
 if (smtpd_proxy_replay_stream != 0) {
-   if (vstream_fseek(smtpd_proxy_replay_stream, (off_t) 0, SEEK_SET) < 0) {
-   msg_warn("seek before-queue filter speed-adjust log: %m");
-   (void) vstream_fclose(smtpd_proxy_replay_stream);
-   smtpd_proxy_replay_stream = 0;
-   } else if (fstat(vstream_fileno(smtpd_proxy_replay_stream), &st) < 0) {
+   if (fstat(vstream_fileno(smtpd_proxy_replay_stream), &st) < 0) {
msg_warn("fstat before-queue filter speed-adjust log: %m");
(void) vstream_fclose(smtpd_proxy_replay_stream);
smtpd_proxy_replay_stream = 0;
} else {
-   if (st.st_size > 0)
+   if (st.st_size > 0
+   || vstream_ftell(smtpd_proxy_replay_stream) != 0)
msg_panic("%s: non-empty before-queue filter speed-adjust log",
  myname);
vstream_clearerr(smtpd_proxy_replay_stream);
@@ -1126,6 +1123,17 @@
  */
 if (smtpd_proxy_replay_stream == 0)
return;
+
+/*
+ * Rewind the stream for re-use.
+ * NOTE: This has the side-effect of flushing any buffered data!
+ */
+if (vstream_fseek(smtpd_proxy_replay_stream, (off_t) 0, SEEK_SET) < 0) {
+   msg_warn("seek before-queue filter speed-adjust log: %m");
+   (void) vstream_fclose(smtpd_proxy_replay_stream);
+   smtpd_proxy_replay_stream = 0;
+   return;
+}
 if (vstream_ferror(smtpd_proxy_replay_stream)) {
(void) vstream_fclose(smtpd_proxy_replay_stream);
smtpd_proxy_replay_stream = 0;

-- 
Viktor.

Disclaimer: off-list followups get on-list replies or get ignored.
Please do not ignore the "Reply-To" header.

To unsubscribe from the postfix-users list, visit
http://www.postfix.org/lists.html or click the link below:


If my response solves your problem, the best way to thank me is to not
send an "it worked, thanks" follow-up. If you must respond, please put
"It worked, thanks" in the "Subject" so I can delete these quickly.


Re: Experience with the new speed_adjust feature

2009-11-13 Thread Wietse Venema
Wietse Venema:
> Mark Martinec:
> > On Friday 13 November 2009 18:52:03 Wietse Venema wrote:
> > > Thanks for the logging. If you have time, can you change the code
> > > to print information about the non-zero size? This could be a
> > > filesystem feature where ftruncate() does not reset st_size until
> > > the file is rewritten or closed (in which case my attempt to force
> > > easly release of disk blocks are in vain).
> 
> Victor found it (missing fflush before ftruncate). If you can back
> out the changes and apply the patch below.
> 

To be really safe, replace vstream_fflush(stream) by 
(vstream_bufstat(stream, VSTREAM_BST_OUT_PEND) && vstream_fflush(stream)).

Wietse

*** ./smtpd_proxy.c.origMon Nov  9 19:41:50 2009
--- ./smtpd_proxy.c Fri Nov 13 13:29:55 2009
***
*** 1030,1035 
--- 1030,1041 
 (p)->a10, (p)->a11, (p))
  
  /*
+  * Sanity check.
+  */
+ if (state->proxy != 0)
+   msg_panic("smtpd_proxy_create: handle still exists");
+ 
+ /*
   * Connect to the before-queue filter immediately.
   */
  if ((flags & SMTPD_PROXY_FLAG_SPEED_ADJUST) == 0) {
***
*** 1126,1132 
   */
  if (smtpd_proxy_replay_stream == 0)
return;
! if (vstream_ferror(smtpd_proxy_replay_stream)) {
(void) vstream_fclose(smtpd_proxy_replay_stream);
smtpd_proxy_replay_stream = 0;
return;
--- 1132,1140 
   */
  if (smtpd_proxy_replay_stream == 0)
return;
! if ((vstream_bufstat(smtpd_proxy_replay_stream, VSTREAM_BST_OUT_PEND) > 0
!&& vstream_fflush(smtpd_proxy_replay_stream) != 0)
!   || vstream_ferror(smtpd_proxy_replay_stream)) {
(void) vstream_fclose(smtpd_proxy_replay_stream);
smtpd_proxy_replay_stream = 0;
return;


Re: Experience with the new speed_adjust feature

2009-11-13 Thread Mark Martinec
On Friday 13 November 2009 19:17:07 Wietse Venema wrote:
> Victor found it (missing fflush before ftruncate).
> If you can back out the changes and apply the patch below.
> *** ./smtpd_proxy.c.orig  Mon Nov  9 19:41:50 2009
> --- ./smtpd_proxy.c   Fri Nov 13 13:15:25 2009

Thanks, done. So far so good, running smoothly.

  Mark


Re: Experience with the new speed_adjust feature

2009-11-13 Thread Wietse Venema
Mark Martinec:
> On Friday 13 November 2009 18:52:03 Wietse Venema wrote:
> > Thanks for the logging. If you have time, can you change the code
> > to print information about the non-zero size? This could be a
> > filesystem feature where ftruncate() does not reset st_size until
> > the file is rewritten or closed (in which case my attempt to force
> > easly release of disk blocks are in vain).

Victor found it (missing fflush before ftruncate). If you can back
out the changes and apply the patch below.

Wietse

*** ./smtpd_proxy.c.origMon Nov  9 19:41:50 2009
--- ./smtpd_proxy.c Fri Nov 13 13:15:25 2009
***
*** 1030,1035 
--- 1030,1041 
 (p)->a10, (p)->a11, (p))
  
  /*
+  * Sanity check.
+  */
+ if (state->proxy != 0)
+   msg_panic("smtpd_proxy_create: handle still exists");
+ 
+ /*
   * Connect to the before-queue filter immediately.
   */
  if ((flags & SMTPD_PROXY_FLAG_SPEED_ADJUST) == 0) {
***
*** 1126,1132 
   */
  if (smtpd_proxy_replay_stream == 0)
return;
! if (vstream_ferror(smtpd_proxy_replay_stream)) {
(void) vstream_fclose(smtpd_proxy_replay_stream);
smtpd_proxy_replay_stream = 0;
return;
--- 1132,1139 
   */
  if (smtpd_proxy_replay_stream == 0)
return;
! if (vstream_fflush(smtpd_proxy_replay_stream)
!   || vstream_ferror(smtpd_proxy_replay_stream)) {
(void) vstream_fclose(smtpd_proxy_replay_stream);
smtpd_proxy_replay_stream = 0;
return;


Re: Experience with the new speed_adjust feature

2009-11-13 Thread Mark Martinec
On Friday 13 November 2009 18:52:03 Wietse Venema wrote:
> Thanks for the logging. If you have time, can you change the code
> to print information about the non-zero size? This could be a
> filesystem feature where ftruncate() does not reset st_size until
> the file is rewritten or closed (in which case my attempt to force
> easly release of disk blocks are in vain).

This is running on FreeBSD 7.2-RELEASE-p2. The usual UFS file system.

> *** ./smtpd_proxy.c.orig  Mon Nov  9 19:41:50 2009
> --- ./smtpd_proxy.c   Fri Nov 13 12:44:46 2009

Thanks, applied the patch.

$ tail -500 -f /var/log/mail.log | egrep -i 'panic|smtpd_proxy|speed-adjust'

Nov 13 19:04:14 dorothy postfix/smtpd[65777]: warning: 
smtpd_proxy_replay_setup: non-zero speed-adjust logfile size: 20081 

   
Nov 13 19:04:38 dorothy postfix/smtpd[65645]: warning: 
smtpd_proxy_replay_setup: non-zero speed-adjust logfile size: 114   

   
Nov 13 19:04:40 dorothy postfix/smtpd[65624]: warning: 
smtpd_proxy_replay_setup: non-zero speed-adjust logfile size: 201   

   
Nov 13 19:05:04 dorothy postfix/smtpd[67884]: warning: 
smtpd_proxy_replay_setup: non-zero speed-adjust logfile size: 49

   
Nov 13 19:05:12 dorothy postfix/smtpd[68082]: warning: 
smtpd_proxy_replay_setup: non-zero speed-adjust logfile size: 37

   
Nov 13 19:05:21 dorothy postfix/smtpd[68339]: warning: 
smtpd_proxy_replay_setup: non-zero speed-adjust logfile size: 37
Nov 13 19:05:45 dorothy postfix/smtpd[67901]: warning: 
smtpd_proxy_replay_setup: non-zero speed-adjust logfile size: 43
Nov 13 19:05:45 dorothy postfix/smtpd[67884]: warning: 
smtpd_proxy_replay_setup: non-zero speed-adjust logfile size: 31
Nov 13 19:06:01 dorothy postfix/smtpd[68614]: warning: 
smtpd_proxy_replay_setup: non-zero speed-adjust logfile size: 26
Nov 13 19:06:12 dorothy postfix/smtpd[67997]: warning: 
smtpd_proxy_replay_setup: non-zero speed-adjust logfile size: 25
Nov 13 19:06:13 dorothy postfix/smtpd[68397]: warning: 
smtpd_proxy_replay_setup: non-zero speed-adjust logfile size: 32
Nov 13 19:06:19 dorothy postfix/smtpd[68557]: warning: 
smtpd_proxy_replay_setup: non-zero speed-adjust logfile size: 31
Nov 13 19:06:22 dorothy postfix/smtpd[68064]: warning: 
smtpd_proxy_replay_setup: non-zero speed-adjust logfile size: 26
Nov 13 19:06:23 dorothy postfix/smtpd[68155]: warning: 
smtpd_proxy_replay_setup: non-zero speed-adjust logfile size: 35
Nov 13 19:06:23 dorothy postfix/smtpd[67953]: warning: 
smtpd_proxy_replay_setup: non-zero speed-adjust logfile size: 218
Nov 13 19:06:26 dorothy postfix/smtpd[67999]: warning: 
smtpd_proxy_replay_setup: non-zero speed-adjust logfile size: 37
Nov 13 19:06:27 dorothy postfix/smtpd[68670]: warning: 
smtpd_proxy_replay_setup: non-zero speed-adjust logfile size: 38


but no more panics.

  Mark


Re: Experience with the new speed_adjust feature

2009-11-13 Thread Wietse Venema
Thanks for the logging. If you have time, can you change the code
to print information about the non-zero size? This could be a
filesystem feature where ftruncate() does not reset st_size until
the file is rewritten or closed (in which case my attempt to force
easly release of disk blocks are in vain).

Otherwise, I'll try some experiments over the weekend.

Wietse

*** ./smtpd_proxy.c.origMon Nov  9 19:41:50 2009
--- ./smtpd_proxy.c Fri Nov 13 12:44:46 2009
***
*** 975,983 
(void) vstream_fclose(smtpd_proxy_replay_stream);
smtpd_proxy_replay_stream = 0;
} else {
!   if (st.st_size > 0)
!   msg_panic("%s: non-empty before-queue filter speed-adjust log",
! myname);
vstream_clearerr(smtpd_proxy_replay_stream);
if (msg_verbose)
msg_info("%s: reuse speed-adjust stream fd=%d", myname,
--- 975,992 
(void) vstream_fclose(smtpd_proxy_replay_stream);
smtpd_proxy_replay_stream = 0;
} else {
!   /* This file system does not reset st_size after ftruncate(). */
!   if (st.st_size > 0) {
!   msg_warn("%s: non-zero speed-adjust logfile size: %lu",
!myname, (unsigned long) st.st_size);
!   if (ftruncate(vstream_fileno(smtpd_proxy_replay_stream), 
(off_t) 0) < 0) {
!   msg_warn("truncate before-queue filter speed-adjust log: 
%m");
!   (void) vstream_fclose(smtpd_proxy_replay_stream);
!   smtpd_proxy_replay_stream = 0;
!   }
!   }
!   }
!   if (smtpd_proxy_replay_stream != 0) {
vstream_clearerr(smtpd_proxy_replay_stream);
if (msg_verbose)
msg_info("%s: reuse speed-adjust stream fd=%d", myname,


Re: Experience with the new speed_adjust feature

2009-11-13 Thread Mark Martinec
On Friday 13 November 2009 14:48:27 Wietse Venema wrote:
> 20091105-nonprod has a known problem when the temp file
> can't be written for some reason (fixed in 20091109).
> As for the second problem, it would help if you could add
> a missing sanity check here:

Thanks. Done both: upgraded to 20091109 and applied the patch.

> Assume that the maximal number of filter processes is tuned such
> that the machine does not collapse under that load.

For the time being it is all very comfortable, less then 10% of
available content filtering processes are actually busy.
 
> It will help to get closer to the root cause.

So far no "smtpd_proxy_create: handle still exists" were logged,
despite several panics.

I have simplified the setup, no more postscreen, and TLS is no longer
offered, but the problem remains. Here is another fresh sample, this
one covers the full lifetime of one smtpd process (full grep by its PID):

Nov 13 17:42:44 dorothy postfix/smtpd[28345]: warning: 190.205.148.176: 
hostname 190-205-148-176.dyn.dsl.cantv.net verification failed: hostname nor 
servname provided, or not known
Nov 13 17:42:44 dorothy postfix/smtpd[28345]: connect from 
unknown[190.205.148.176]
Nov 13 17:42:46 dorothy postfix/smtpd[28345]: NOQUEUE: reject: RCPT from 
unknown[190.205.148.176]: 550 5.1.8 : Sender address 
rejected: Domain not found; 
from= to= proto=ESMTP 
helo=
Nov 13 17:42:48 dorothy postfix/smtpd[28345]: NOQUEUE: reject: RCPT from 
unknown[190.205.148.176]: 550 5.1.8 : Sender address 
rejected: Domain not found; 
from= to= proto=ESMTP 
helo=
Nov 13 17:42:50 dorothy postfix/smtpd[28345]: NOQUEUE: reject: RCPT from 
unknown[190.205.148.176]: 550 5.1.8 : Sender 
address rejected: Domain not found; 
from= to= proto=ESMTP 
helo=
Nov 13 17:42:51 dorothy postfix/smtpd[28345]: disconnect from 
unknown[190.205.148.176]
Nov 13 17:42:56 dorothy postfix/smtpd[28345]: connect from 
gtwout2.ill.fr[193.49.43.102]
Nov 13 17:42:56 dorothy postfix/smtpd[28345]: NOQUEUE: 
client=gtwout2.ill.fr[193.49.43.102]
Nov 13 17:42:59 dorothy postfix/smtpd[28345]: disconnect from 
gtwout2.ill.fr[193.49.43.102]
Nov 13 17:42:59 dorothy postfix/smtpd[28345]: warning: 189.20.244.170: hostname 
189-20-244-170.customer.tdatabrasil.net.br verification failed: hostname nor 
servname provided, or not 
known
Nov 13 17:42:59 dorothy postfix/smtpd[28345]: connect from 
unknown[189.20.244.170]
Nov 13 17:43:01 dorothy postfix/smtpd[28345]: NOQUEUE: 
client=unknown[189.20.244.170]
Nov 13 17:43:03 dorothy postfix/smtpd[28345]: disconnect from 
unknown[189.20.244.170]
Nov 13 17:43:08 dorothy postfix/smtpd[28345]: connect from 
71-231-58-66.gci.net[66.58.231.71]
Nov 13 17:43:09 dorothy postfix/smtpd[28345]: NOQUEUE: 
client=71-231-58-66.gci.net[66.58.231.71]
Nov 13 17:43:13 dorothy postfix/smtpd[28345]: disconnect from 
71-231-58-66.gci.net[66.58.231.71]
Nov 13 17:43:15 dorothy postfix/smtpd[28345]: connect from 
cernmx13.cern.ch[137.138.142.200]
Nov 13 17:43:15 dorothy postfix/smtpd[28345]: NOQUEUE: 
client=cernmx13.cern.ch[137.138.142.200]
Nov 13 17:43:18 dorothy postfix/smtpd[28345]: NOQUEUE: 
client=cernmx13.cern.ch[137.138.142.200]
Nov 13 17:43:25 dorothy postfix/smtpd[28345]: disconnect from 
cernmx13.cern.ch[137.138.142.200]
Nov 13 17:43:28 dorothy postfix/smtpd[28345]: connect from 
bpost.kek.jp[130.87.105.111]
Nov 13 17:43:29 dorothy postfix/smtpd[28345]: NOQUEUE: 
client=bpost.kek.jp[130.87.105.111]
Nov 13 17:43:33 dorothy postfix/smtpd[28345]: disconnect from 
bpost.kek.jp[130.87.105.111]
Nov 13 17:43:37 dorothy postfix/smtpd[28345]: connect from 
host-93-124-65-201.dsl.sura.ru[93.124.65.201]
Nov 13 17:43:37 dorothy postfix/smtpd[28345]: NOQUEUE: 
client=host-93-124-65-201.dsl.sura.ru[93.124.65.201]
Nov 13 17:43:41 dorothy postfix/smtpd[28345]: disconnect from 
host-93-124-65-201.dsl.sura.ru[93.124.65.201]
Nov 13 17:43:44 dorothy postfix/smtpd[28345]: connect from 
backup002.host1.eu[62.75.216.27]
Nov 13 17:43:46 dorothy postfix/smtpd[28345]: NOQUEUE: 
client=backup002.host1.eu[62.75.216.27]
Nov 13 17:43:51 dorothy postfix/smtpd[28345]: disconnect from 
backup002.host1.eu[62.75.216.27]
Nov 13 17:43:56 dorothy postfix/smtpd[28345]: connect from unknown[41.130.65.71]
Nov 13 17:43:57 dorothy postfix/smtpd[28345]: NOQUEUE: 
client=unknown[41.130.65.71]
Nov 13 17:44:02 dorothy postfix/smtpd[28345]: disconnect from 
unknown[41.130.65.71]
Nov 13 17:44:05 dorothy postfix/smtpd[28345]: connect from 
unknown[195.94.133.112]
Nov 13 17:44:09 dorothy postfix/smtpd[28345]: NOQUEUE: reject: RCPT from 
unknown[195.94.133.112]: 550 5.1.7 : Sender address rejected: 
undeliverable address: ...
Nov 13 17:44:11 dorothy postfix/smtpd[28345]: disconnect from 
unknown[195.94.133.112]
Nov 13 17:44:11 dorothy postfix/smtpd[28345]: warning: 78.138.169.171: hostname 
171.169.138.78.in-addr.arpa verification failed: hostname nor servname 
provided, or not known
Nov 13 17:44:11 dorothy postfix/smtpd[28345]: connect from 
unknown[78.138.169.171]
Nov 13 17:44:11 dorothy postfi

Re: Experience with the new speed_adjust feature

2009-11-13 Thread Wietse Venema
Mark Martinec:
> For the last couple of days I'm now experimenting with the
> 2.7-20091105-nonprod with the new speed_adjust experimental feature
> turned on at the MX port, along with the postscreen. Seems to work
> as advertised: timing reports by a pre-queue proxy content filter confirm
> that the content filter is invoked only after data has been received.
> Current mail load on our server is not high, so I haven't yet seen
> what happens under high mail rate conditions.

Thanks.  20091105-nonprod has a known problem when the temp file
can't be written for some reason (fixed in 20091109).

I speculate that under load, clients will experience delays at a
different point in the conversation.

Assume that the maximal number of filter processes is tuned such
that the machine does not collapse under that load.

Without speed-match, there is exactly one smtpd process for each
filter.  As soon as all smtpd processes are busy (whether or not
these sessions rejecting mail early), new tcp connections will get
queued, and clients experience a delay before the 220 welcome
greeting.

With speed-match, there can be more smtpd processes than filters,
Once all filters are busy, clients that complete an SMTP delivery
will experience a delay after sending ".".  When the load increases
to the point that all smtpd processes are busy, which should happen
later than in the "no speed-match" scenario, new tcp connections
will get queued and clients experience a delay before the 220
welcome greeting.

As for the second problem, it would help if you could add a missing
sanity check here:

*** ./smtpd_proxy.c-Thu Nov  5 16:48:53 2009
--- ./smtpd_proxy.c Fri Nov 13 08:27:37 2009
***
*** 1027,1032 
--- 1027,1038 
 (p)->a10, (p)->a11, (p))
  
  /*
+  * Sanity check.
+  */
+ if (state->proxy != 0)
+   msg_panic("smtpd_proxy_create: handle still exists");
+ 
+ /*
   * Connect to the before-queue filter immediately.
   */
  if ((flags & SMTPD_PROXY_FLAG_SPEED_ADJUST) == 0) {

It will help to get closer to the root cause. Meanwhile, I can set
up a null-filter measurement on my tiny site and see if this triggers
something. I thought that every mail transaction ends with truncating
the temporary file, even when the transaction is aborted early.

> Two things are on my mind:
> 
> 1. I'm dearly missing in the postfix log the SMTP response from a
> pre-queue content filter (or better, a response that was sent back to a SMTP
> client), at least in case of a 5xx or 4xx response. With a post-queue filter
> setup the response is clearly logged, unlike in the pre-queue setup where it
> is not. It makes it hard to correlate a spartanic postfix log of a rejected
> transaction (due to a proxy filter rejection) with a log from a content
> filter. Even if the correlation were somehow available, seeing a confirmation
> of what was really sent back to the client in a postfix log would contribute
> to the confidence in the correctness of operation.

I assumed that the filter will already log the rejects (possible with the
client name/address from xforward), and therefore Postfix would
not need to add to the noise, but this can be changed.

Wietse


Experience with the new speed_adjust feature

2009-11-13 Thread Mark Martinec
For the last couple of days I'm now experimenting with the
2.7-20091105-nonprod with the new speed_adjust experimental feature
turned on at the MX port, along with the postscreen. Seems to work
as advertised: timing reports by a pre-queue proxy content filter confirm
that the content filter is invoked only after data has been received.
Current mail load on our server is not high, so I haven't yet seen
what happens under high mail rate conditions.

Here is the relevant part of my master.cf:

dnsblog  unix  -   -   n   -   0   dnsblog
smtp inet  n   -   n   -   1   postscreen
smtpdpass  -   -   n   -  150  smtpd
-o smtpd_proxy_filter=127.0.0.1:10010
-o smtpd_proxy_options=speed_adjust
-o smtpd_client_connection_count_limit=30
-o smtpd_proxy_timeout=600

Two things are on my mind:

1. I'm dearly missing in the postfix log the SMTP response from a
pre-queue content filter (or better, a response that was sent back to a SMTP
client), at least in case of a 5xx or 4xx response. With a post-queue filter
setup the response is clearly logged, unlike in the pre-queue setup where it
is not. It makes it hard to correlate a spartanic postfix log of a rejected
transaction (due to a proxy filter rejection) with a log from a content
filter. Even if the correlation were somehow available, seeing a confirmation
of what was really sent back to the client in a postfix log would contribute
to the confidence in the correctness of operation.


2. A couple of times per day I see that postfix terminates its smtpd service:

  +pid 9297 (smtpd), uid 125: exited on signal 6
  +pid 12680 (smtpd), uid 125: exited on signal 6
  +pid 9306 (smtpd), uid 125: exited on signal 6

and a corresponding log entry from a smtpd process:

  panic: smtpd_proxy_replay_setup:
non-empty before-queue filter speed-adjust log

The log (some other PIDs) can look like (a grep by PID,
showing previous two transaction of the same process):

Nov 13 13:07:07 dorothy postfix/smtpd[82601]:
 connect from unknown[74.63.109.233]
Nov 13 13:07:08 dorothy postfix/smtpd[82601]:
 NOQUEUE: client=unknown[74.63.109.233]
Nov 13 13:07:12 dorothy postfix/smtpd[82601]:
 disconnect from unknown[74.63.109.233]

Nov 13 13:07:29 dorothy postfix/smtpd[82601]:
 connect from 201-92-220-64.dsl.telesp.net.br[201.92.220.64]
Nov 13 13:07:30 dorothy postfix/smtpd[82601]:
 NOQUEUE: client=201-92-220-64.dsl.telesp.net.br[201.92.220.64]
Nov 13 13:07:36 dorothy postfix/smtpd[82601]:
 disconnect from 201-92-220-64.dsl.telesp.net.br[201.92.220.64]

Nov 13 13:07:43 dorothy postfix/smtpd[82601]:
 warning: 122.168.228.121: hostname
 ABTS-mpdynamic-121.228.168.122.airtelbroadband.in
 verification failed: hostname nor servname provided, or not known
Nov 13 13:07:43 dorothy postfix/smtpd[82601]:
 connect from unknown[122.168.228.121]
Nov 13 13:08:26 dorothy postfix/smtpd[82601]:
 NOQUEUE: client=unknown[122.168.228.121]
Nov 13 13:08:26 dorothy postfix/smtpd[82601]:
 lost connection after RCPT from unknown[122.168.228.121]
Nov 13 13:08:26 dorothy postfix/smtpd[82601]:
 disconnect from unknown[122.168.228.121]

Nov 13 13:08:32 dorothy postfix/smtpd[82601]:
 connect from unknown[121.139.242.179]
Nov 13 13:08:34 dorothy postfix/smtpd[82601]:
 panic: smtpd_proxy_replay_setup: non-empty before-queue
 filter speed-adjust log


Here is another case:

Nov 13 13:52:43 dorothy postfix/smtpd[4186]:
 NOQUEUE: client=200-199-119-208.user.neoline.com.br[200.199.119.208]
Nov 13 13:52:53 dorothy postfix/smtpd[4186]:
 disconnect from 200-199-119-208.user.neoline.com.br[200.199.119.208]

Nov 13 13:52:58 dorothy postfix/smtpd[4186]:
 connect from unknown[77.29.4.99]
Nov 13 13:53:01 dorothy postfix/smtpd[4186]:
 NOQUEUE: client=unknown[77.29.4.99]
Nov 13 13:54:23 dorothy postfix/smtpd[4186]:
 lost connection after DATA (1589 bytes) from unknown[77.29.4.99]
Nov 13 13:54:23 dorothy postfix/smtpd[4186]:
 disconnect from unknown[77.29.4.99]

Nov 13 13:54:28 dorothy postfix/smtpd[4186]:
 connect from unknown[170.51.195.142]
Nov 13 13:54:31 dorothy postfix/smtpd[4186]:
 panic: smtpd_proxy_replay_setup: non-empty before-queue
 filter speed-adjust log


So what does this mean?

  Mark