OSEC

Neohapsis is currently accepting applications for employment. For more information, please visit our website www.neohapsis.com or email hr@neohapsis.com
 
Subject: Re: Next performance issues
From: Dr. Walter Willmertinger (willmertingerconsys.de)
Date: Tue May 23 2000 - 09:37:22 CDT

I changed the parameter but this does not help. Can it be that if too
many users do
     default_process_limit = 50
a pop at the same time, when I send the message, that there is a locking
condition
between POP and SMTP?

I increased the debug_peer_level and got following messages in a
situation where the send process does not terminate.
I notices the message:
        May 23 15:26:01 uw7 postfix/smtpd[18076]: warning: rewrite_clnt: bad
write: Broken pipe
Maybe that's the reason why?

May 23 15:25:41 uw7 ipop3d[18089]: Login user=oezguert
host=[192.147.160.32] nmsgs=0/0
May 23 15:25:42 uw7 ipop3d[18089]: Logout user=oezguert
host=[192.147.160.32] nmsgs=0 ndele=0
May 23 15:26:01 uw7 postfix/smtpd[18076]: >
consysww.consys.de[192.147.160.3]: 220 consys.de ESMTP Postfix
May 23 15:26:01 uw7 postfix/smtpd[18076]: connect from
consysww.consys.de[192.147.160.3]
May 23 15:26:01 uw7 postfix/smtpd[18076]: vstream_fflush_some: fd 7
flush 29
May 23 15:26:01 uw7 postfix/master[16504]: reload configuration
May 23 15:26:01 uw7 postfix/smtpd[18076]: vstream_buf_get_ready: fd 7
got 16
May 23 15:26:01 uw7 postfix/smtpd[18076]: <
consysww.consys.de[192.147.160.3]: EHLO consys.de
May 23 15:26:01 uw7 postfix/smtpd[18076]: >
consysww.consys.de[192.147.160.3]: 250-consys.de
May 23 15:26:01 uw7 postfix/smtpd[18076]: >
consysww.consys.de[192.147.160.3]: 250-PIPELINING
May 23 15:26:01 uw7 postfix/smtpd[18076]: >
consysww.consys.de[192.147.160.3]: 250-SIZE 10240000
May 23 15:26:01 uw7 postfix/smtpd[18076]: >
consysww.consys.de[192.147.160.3]: 250-ETRN
May 23 15:26:01 uw7 postfix/smtpd[18076]: >
consysww.consys.de[192.147.160.3]: 250 8BITMIME
May 23 15:26:01 uw7 postfix/smtpd[18076]: vstream_fflush_some: fd 7
flush 74
May 23 15:26:01 uw7 postfix/smtpd[18076]: vstream_buf_get_ready: fd 7
got 37
May 23 15:26:01 uw7 postfix/smtpd[18076]: <
consysww.consys.de[192.147.160.3]: MAIL FROM:<willmertingerconsys.de>
May 23 15:26:01 uw7 postfix/smtpd[18076]: extract_addr: input:
<willmertingerconsys.de>
May 23 15:26:01 uw7 postfix/smtpd[18076]: extract_addr: result:
willmertingerconsys.de
May 23 15:26:01 uw7 postfix/smtpd[18076]: fsspace: .: block size 1024,
blocks free 15408837
May 23 15:26:01 uw7 postfix/smtpd[18076]: smtpd_check_size: blocks 1024
avail 15408837 min_free 0 size 0
May 23 15:26:01 uw7 postfix/smtpd[18076]: connect to subsystem
private/cleanup
May 23 15:26:01 uw7 postfix/smtpd[18076]: vstream_buf_get_ready: fd 10
got 10
May 23 15:26:01 uw7 postfix/smtpd[18076]: mail_scan_any: read string:
64190AC0D
May 23 15:26:01 uw7 postfix/smtpd[18076]: print int: 2
May 23 15:26:01 uw7 postfix/smtpd[18076]: 64190AC0D:
client=consysww.consys.de[192.147.160.3]
May 23 15:26:01 uw7 postfix/smtpd[18076]: rec_put: type T len 9 data
959088361
May 23 15:26:01 uw7 postfix/smtpd[18076]: rec_put: type S len 23 data
willmertin
May 23 15:26:01 uw7 postfix/smtpd[18076]: >
consysww.consys.de[192.147.160.3]: 250 Ok
May 23 15:26:01 uw7 postfix/smtpd[18076]: vstream_fflush_some: fd 7
flush 8
May 23 15:26:01 uw7 postfix/smtpd[18076]: vstream_buf_get_ready: fd 7
got 24
May 23 15:26:01 uw7 postfix/smtpd[18076]: <
consysww.consys.de[192.147.160.3]: RCPT TO:<wwconsys.de>
May 23 15:26:01 uw7 postfix/smtpd[18076]: extract_addr: input:
<wwconsys.de>
May 23 15:26:01 uw7 postfix/smtpd[18076]: extract_addr: result:
wwconsys.de
May 23 15:26:01 uw7 postfix/smtpd[18076]: generic_checks: START
May 23 15:26:01 uw7 postfix/smtpd[18076]: generic_checks:
name=permit_mynetworks
May 23 15:26:01 uw7 postfix/smtpd[18076]: permit_mynetworks:
consysww.consys.de 192.147.160.3
May 23 15:26:01 uw7 postfix/smtpd[18076]: match_hostaddr: 192.147.160.3
~? 127.0.0.0/8
May 23 15:26:01 uw7 postfix/smtpd[18076]: match_hostname:
consysww.consys.de ~? 127.0.0.0/8
May 23 15:26:01 uw7 postfix/smtpd[18076]: match_hostaddr: 192.147.160.3
~? 192.147.160.0/24
May 23 15:26:01 uw7 postfix/smtpd[18076]: generic_checks:
name=permit_mynetworks status=1
May 23 15:26:01 uw7 postfix/smtpd[18076]: generic_checks: START
May 23 15:26:01 uw7 postfix/smtpd[18076]: generic_checks:
name=permit_mynetworks
May 23 15:26:01 uw7 postfix/smtpd[18076]: permit_mynetworks:
consysww.consys.de 192.147.160.3
May 23 15:26:01 uw7 postfix/smtpd[18076]: match_hostaddr: 192.147.160.3
~? 127.0.0.0/8
May 23 15:26:01 uw7 postfix/smtpd[18076]: match_hostname:
consysww.consys.de ~? 127.0.0.0/8
May 23 15:26:01 uw7 postfix/smtpd[18076]: match_hostaddr: 192.147.160.3
~? 192.147.160.0/24
May 23 15:26:01 uw7 postfix/smtpd[18076]: generic_checks:
name=permit_mynetworks status=1
May 23 15:26:01 uw7 postfix/smtpd[18076]: smtpd_check_rcptmap:
wwconsys.de
May 23 15:26:01 uw7 postfix/smtpd[18076]: event_request_timer: reset
0x8054130 0x80706f0 100
May 23 15:26:01 uw7 postfix/smtpd[18076]: print string: rewrite
May 23 15:26:01 uw7 postfix/smtpd[18076]: print string: canonicalize
May 23 15:26:01 uw7 postfix/smtpd[18076]: print string: wwconsys.de
May 23 15:26:01 uw7 postfix/smtpd[18076]: vstream_fflush_some: fd 11
flush 34
May 23 15:26:01 uw7 postfix/smtpd[18076]: warning: rewrite_clnt: bad
write: Broken pipe
May 23 15:26:05 uw7 ipop3d[18093]: connect from 192.147.160.30
May 23 15:26:05 uw7 ipop3d[18093]: port 110 service init from
192.147.160.30
May 23 15:26:05 uw7 ipop3d[18093]: Auth user=olif host=[192.147.160.30]
nmsgs=40/40
May 23 15:26:05 uw7 ipop3d[18093]: Logout user=olif
host=[192.147.160.30] nmsgs=40 ndele=0
May 23 15:26:11 uw7 postfix/smtpd[18076]: rewrite stream disconnect
May 23 15:26:11 uw7 postfix/smtpd[18076]: event_disable_readwrite: fd 11
May 23 15:26:11 uw7 postfix/smtpd[18076]: event_cancel_timer: 0x8054130
0x80706f0 100
May 23 15:26:11 uw7 postfix/smtpd[18076]: vstream_fflush_some: fd 11
flush 34
May 23 15:26:11 uw7 postfix/smtpd[18076]: connect to subsystem
private/rewrite
May 23 15:26:11 uw7 postfix/smtpd[18076]: event_enable_read: fd 11
May 23 15:26:11 uw7 postfix/smtpd[18076]: event_request_timer: set
0x8054130 0x80706f0 100
May 23 15:26:11 uw7 postfix/smtpd[18076]: print string: rewrite
May 23 15:26:11 uw7 postfix/smtpd[18076]: print string: canonicalize
May 23 15:26:11 uw7 postfix/smtpd[18076]: print string: wwconsys.de
May 23 15:26:11 uw7 postfix/smtpd[18076]: vstream_fflush_some: fd 11
flush 34
May 23 15:26:11 uw7 postfix/smtpd[18076]: vstream_buf_get_ready: fd 11
got 13
May 23 15:26:11 uw7 postfix/smtpd[18076]: mail_scan_any: read string:
wwconsys.de
May 23 15:26:11 uw7 postfix/smtpd[18076]: rewrite_clnt: canonicalize:
wwconsys.de -> wwconsys.de
May 23 15:26:11 uw7 postfix/smtpd[18076]: event_request_timer: reset
0x8054130 0x80706f0 100
May 23 15:26:11 uw7 postfix/smtpd[18076]: print string: resolve
May 23 15:26:11 uw7 postfix/smtpd[18076]: print string: wwconsys.de
May 23 15:26:11 uw7 postfix/smtpd[18076]: vstream_fflush_some: fd 11
flush 21
May 23 15:26:11 uw7 postfix/smtpd[18076]: vstream_buf_get_ready: fd 11
got 31
May 23 15:26:11 uw7 postfix/smtpd[18076]: mail_scan_any: read string:
local
May 23 15:26:11 uw7 postfix/smtpd[18076]: mail_scan_any: read string:
consys.de
May 23 15:26:11 uw7 postfix/smtpd[18076]: mail_scan_any: read string:
wwconsys.de
May 23 15:26:11 uw7 postfix/smtpd[18076]: mail_scan_any: read integer: 0
May 23 15:26:11 uw7 postfix/smtpd[18076]: resolve_clnt_query:
`wwconsys.de' -> t=`local' h=`consys.de' r=`wwconsys.de'
May 23 15:26:11 uw7 postfix/smtpd[18076]: match_string: consys.de ~?
consys.de
May 23 15:26:11 uw7 postfix/smtpd[18076]: maps_find: consys.de: not
found
May 23 15:26:11 uw7 postfix/smtpd[18076]: rec_put: type R len 12 data
wwconsys.
May 23 15:26:11 uw7 postfix/smtpd[18076]: >
consysww.consys.de[192.147.160.3]: 250 Ok
May 23 15:26:11 uw7 postfix/smtpd[18076]: vstream_fflush_some: fd 7
flush 8
May 23 15:26:11 uw7 postfix/smtpd[18076]: vstream_buf_get_ready: fd 7
got 6
May 23 15:26:11 uw7 postfix/smtpd[18076]: <
consysww.consys.de[192.147.160.3]: DATA
May 23 15:26:11 uw7 postfix/smtpd[18076]: rec_put: type M len 0 data
May 23 15:26:11 uw7 postfix/smtpd[18076]: rec_put: type N len 61 data
Received:
May 23 15:26:11 uw7 postfix/smtpd[18076]: rec_put: type N len 47 data
?by consys
May 23 15:26:11 uw7 postfix/smtpd[18076]: rec_put: type N len 62 data
?for <wwc
May 23 15:26:11 uw7 postfix/smtpd[18076]: >
consysww.consys.de[192.147.160.3]: 354 End data with <CR><LF>.<CR><LF>
May 23 15:26:11 uw7 postfix/smtpd[18076]: vstream_fflush_some: fd 10
flush 230
May 23 15:26:11 uw7 postfix/smtpd[18076]: vstream_fflush_some: fd 7
flush 37
May 23 15:26:11 uw7 postfix/smtpd[18076]: vstream_buf_get_ready: fd 7
got 742
May 23 15:26:11 uw7 postfix/smtpd[18076]: rec_put: type N len 41 data
Message-ID
May 23 15:26:11 uw7 postfix/smtpd[18076]: rec_put: type N len 37 data
Date: Tue,
May 23 15:26:11 uw7 postfix/smtpd[18076]: rec_put: type N len 58 data
From: "Dr.
May 23 15:26:11 uw7 postfix/smtpd[18076]: rec_put: type N len 25 data
Organizati
May 23 15:26:11 uw7 postfix/smtpd[18076]: rec_put: type N len 37 data
X-Mailer:
May 23 15:26:11 uw7 postfix/smtpd[18076]: rec_put: type N len 24 data
X-Accept-L
May 23 15:26:11 uw7 postfix/smtpd[18076]: rec_put: type N len 17 data
MIME-Versi
May 23 15:26:11 uw7 postfix/smtpd[18076]: rec_put: type N len 21 data
To: ww <ww
May 23 15:26:11 uw7 postfix/smtpd[18076]: rec_put: type N len 23 data
Subject: (
May 23 15:26:11 uw7 postfix/smtpd[18076]: rec_put: type N len 44 data
Content-Ty
May 23 15:26:11 uw7 postfix/smtpd[18076]: rec_put: type N len 31 data
Content-Tr
May 23 15:26:11 uw7 postfix/smtpd[18076]: rec_put: type N len 0 data
May 23 15:26:11 uw7 letzte Meldung 2 Mal wiederholt
May 23 15:26:11 uw7 postfix/smtpd[18076]: rec_put: type N len 2 data --
May 23 15:26:11 uw7 postfix/smtpd[18076]: rec_put: type N len 0 data
May 23 15:26:11 uw7 postfix/smtpd[18076]: rec_put: type N len 24 data
Mit freund
May 23 15:26:11 uw7 postfix/smtpd[18076]: rec_put: type N len 0 data
May 23 15:26:11 uw7 postfix/smtpd[18076]: rec_put: type N len 24 data
Dr. Walter
May 23 15:26:11 uw7 postfix/smtpd[18076]: rec_put: type N len 0 data
May 23 15:26:11 uw7 postfix/smtpd[18076]: rec_put: type N len 69 data
CONSYS Ges
May 23 15:26:11 uw7 postfix/smtpd[18076]: rec_put: type N len 24 data
Dr. Walter
May 23 15:26:11 uw7 postfix/smtpd[18076]: rec_put: type N len 56 data
Landsberge
May 23 15:26:11 uw7 postfix/smtpd[18076]: rec_put: type N len 49 data
81241 Muen
May 23 15:26:11 uw7 postfix/smtpd[18076]: rec_put: type N len 48 data
Germany
May 23 15:26:11 uw7 postfix/smtpd[18076]: rec_put: type N len 34 data
WWW-Homepa
May 23 15:26:11 uw7 postfix/smtpd[18076]: rec_put: type N len 0 data
May 23 15:26:11 uw7 postfix/smtpd[18076]: vstream_buf_get_ready: fd 7
got 5
May 23 15:26:11 uw7 postfix/smtpd[18076]: rec_put: type N len 0 data
May 23 15:26:11 uw7 postfix/smtpd[18076]: rec_put: type X len 0 data
May 23 15:26:11 uw7 postfix/smtpd[18076]: rec_put: type E len 0 data
May 23 15:26:11 uw7 postfix/smtpd[18076]: vstream_fflush_some: fd 10
flush 748
May 23 15:26:11 uw7 postfix/cleanup[18091]: 64190AC0D:
message-id=<392A952A.A714745Fconsys.de>
May 23 15:26:11 uw7 postfix/qmgr[18092]: 64190AC0D:
from=<willmertingerconsys.de>, size=920 (queue active)
May 23 15:26:11 uw7 postfix/smtpd[18076]: vstream_buf_get_ready: fd 10
got 2
May 23 15:26:11 uw7 postfix/smtpd[18076]: mail_scan_any: read integer: 0
May 23 15:26:11 uw7 postfix/smtpd[18076]: >
consysww.consys.de[192.147.160.3]: 250 Ok: queued as 64190AC0D
May 23 15:26:11 uw7 postfix/smtpd[18076]: vstream_fflush_some: fd 7
flush 29
May 23 15:26:11 uw7 postfix/smtpd[18076]: vstream_buf_get_ready: fd 7
got 6
May 23 15:26:11 uw7 postfix/smtpd[18076]: <
consysww.consys.de[192.147.160.3]: QUIT
May 23 15:26:11 uw7 postfix/smtpd[18076]: >
consysww.consys.de[192.147.160.3]: 221 Bye
May 23 15:26:11 uw7 postfix/smtpd[18076]: disconnect from
consysww.consys.de[192.147.160.3]
May 23 15:26:11 uw7 postfix/local[18095]: warning: dict_nis_init: NIS
domain name not set - NIS lookups disabled
May 23 15:26:11 uw7 postfix/local[18095]: 64190AC0D:
to=<walterwconsys.de>, relay=local, delay=10, status=sent (mailbox)
May 23 15:26:11 uw7 in.comsat[18096]: connect from localhost
May 23 15:26:18 uw7 ipop3d[18097]: connect from 192.147.160.52
May 23 15:26:18 uw7 ipop3d[18097]: port 110 service init from
192.147.160.52
May 23 15:26:18 uw7 ipop3d[18097]: Login user=manus
host=[192.147.160.52] nmsgs=0/0
May 23 15:26:18 uw7 ipop3d[18097]: Logout user=manus
host=[192.147.160.52] nmsgs=0 ndele=0

Wietse Venema schrieb:

> Dr. Walter Willmertinger:
> > We have Postfix 19991231-pl06 under SCO unixware 7.1
> > We like it very much, but sometimes, when sending a mail from a Windows Client
> > with Netscape Messenger the send takes very long time.
> > I watched now, when I pressed the send button and it did not stop, the syslog
> > file and noticed that we just got some incoming mails on the postfix server. I
> > aborted the send command in messenger.
> > When all incoming mails were received, I pressed the send button again and all
> > was finished in a single moment.
> >
> > Can it be that incoming mails block the smtp server
>
> Postfix runs only a finite number of SMTP servers at the same time
> (instead of crashing the server under peak loads like some mailers).
>
> If your machine has sufficient capacity, then you can double the
> process limit in main.cf. The default setting is:
>
> default_process_limit = 50
>
> On small machines I usually trim that down to 10-20 or so.
>
> It is also possible to specify individual process limits on specific
> Postfix subsystems. See http://www.postfix.org/rate.html#process for
> details.
>
> Wietse
>
> Wietse 

--

Mit freundlichen Grüßen,

Dr. Walter Willmertinger

CONSYS Gesellschaft für Softwaretechnologie und Systementwicklung mbH
Dr. Walter Willmertinger
Landsberger Strasse 402   EMail: willmertingerconsys.de
81241 Muenchen            Phone: +49 89 580 81 81
Germany                     Fax: +49 89 588 77 6
WWW-Homepage: http://www.consys.de