Re: Postfix is slow accepting incoming mails

2018-03-12 Thread Wietse Venema 
Nikolai Dahlem:
> Am 2018-03-09 13:13, schrieb Wietse Venema:
> >> delay=0.51, delays=0.21/0/0.17/0.13
> > 
> > Just to be sure, these numbers include receiving and delivering mail.
> > 
> > 0.21time from message arrival to last active queue entry
> > 0   time from last active queue entry to connection setup

For comparison, inbound mail from the postfix-users list to my own
machine typically has "delays=0.13/0/...". Ping from my machine
to the list server says ~5ms.

> > The first number shows that it takes 0.2s to put mail into the
> > queue. Does your host run a LOCAL caching DNS server? If not, that
> > could explain sluggish performance for receiving and sending mail.
> > 
> > When receiving SMTP mail, Postfix looks up IPaddress->name and
> > name->IPaddress which can result in two DNS queries per inbound
> > connection.
> I run a local instance of unbound for dns caching

I also notice that you have configured a Milter.

To determine whether it is IPaddress/name lookup please re-run the
smtp-source experiment and set the -d flag to keep the SMTP connection
open:

time smtp-source -d -4 -m 20 -S Test -l 500 -t u...@xxx.yy 127.0.0.1

To determine whether it is Milter or something else, please re-run
the smtp-source experiment after

$ postconf -# smtpd_milters
$ postfix reload

smtp-source is talking to a local address, therefore network latency
should be negligible UNLESS you turned on traffic shaping in the
kernel.

> > The other numbers show that the total delays are dominated by
> > deliveries. Which Postfix delivery agent that was producing these
> > numbers? I suppose that was the SMTP client? If it is a local
> > delivery agent, then WHAT IS WRONG WITH YOUR FILE SYSTEM?
> 
> It was the SMTP Client.

As for outbound performance, that depends on network distance. 

 0.17time in connection setup, including DNS, EHLO and STARTTLS
 0.13time in message transmission (including response to '.')

Was this mail delivered over TLS? How large was the message?
Did the remote server announce PIPELINING in the EHLO response?

All these questions are better answered with a tcpdump recording.

Wietse

Re: Postfix is slow accepting incoming mails

2018-03-11 Thread Viktor Dukhovni 


> On Mar 9, 2018, at 7:23 AM, Nikolai Dahlem  wrote:
> 
> I run a local instance of unbound for dns caching

Good.

> Below is postconf -n output:
> 
> milter_default_action = accept
> milter_protocol = 6
> non_smtpd_milters = $smtpd_milters
> smtpd_milters = inet:127.0.0.1:8891

Everything else looks rather vanilla, so the next thing to look for is latency
in the milter.  What does this milter do?

Also check your syslog configuration, make sure it is not syncing the log file
to disk on every write.

-- 
Viktor.

Re: Postfix is slow accepting incoming mails

2018-03-09 Thread Nikolai Dahlem 

Am 2018-03-09 13:13, schrieb Wietse Venema:

delay=0.51, delays=0.21/0/0.17/0.13


Just to be sure, these numbers include receiving and delivering mail.

0.21time from message arrival to last active queue entry
0   time from last active queue entry to connection setup
0.17time in connection setup, including DNS, EHLO and STARTTLS
0.13time in message transmission

The first number shows that it takes 0.2s to put mail into the
queue. Does your host run a LOCAL caching DNS server? If not, that
could explain sluggish performance for receiving and sending mail.

When receiving SMTP mail, Postfix looks up IPaddress->name and
name->IPaddress which can result in two DNS queries per inbound
connection.

I run a local instance of unbound for dns caching


The other numbers show that the total delays are dominated by
deliveries. Which Postfix delivery agent that was producing these
numbers? I suppose that was the SMTP client? If it is a local
delivery agent, then WHAT IS WRONG WITH YOUR FILE SYSTEM?


It was the SMTP Client.




>I suspect that your mail sending program is too slow. You can test
>Postfix raw speed with smtp-source test program, part of the Postfix
>source bundle.

time smtp-source -4 -m 20 -S Test -l 500 -t u...@xxx.yy 127.0.0.1
real0m4.097s
user0m0.007s
sys 0m0.017s

So one thread delivers 5 mail/sec to postfix. Multiple threads scale
well, but single thread performance seems really low.


It is consistent with the 0.21s above. Your measurement agrees with
Postfix's delays reporting.



Below is postconf -n output:

alias_database = hash:/etc/aliases
alias_maps = hash:/etc/aliases
broken_sasl_auth_clients = yes
command_directory = /usr/sbin
config_directory = /etc/postfix
daemon_directory = /usr/libexec/postfix
debug_peer_level = 1
default_process_limit = 150
delay_warning_time = 0
disable_vrfy_command = yes
html_directory = no
in_flow_delay = 0
inet_interfaces = 127.0.0.1
mail_owner = postfix
mailq_path = /usr/bin/mailq.postfix
manpage_directory = /usr/share/man
message_size_limit = 20971520
milter_default_action = accept
milter_protocol = 6
mydestination = localhost.$mydomain, localhost
mydomain = xxx.yy
myhostname = zz.xxx.yy
mynetworks = $config_directory/mynetworks
newaliases_path = /usr/bin/newaliases.postfix
non_smtpd_milters = $smtpd_milters
queue_directory = /var/spool/postfix
readme_directory = /usr/share/doc/postfix-2.6.6/README_FILES
recipient_delimiter = -
relay_domains = xxx.yy
relay_recipient_maps =
sample_directory = /usr/share/doc/postfix-2.6.6/samples
sendmail_path = /usr/sbin/sendmail.postfix
setgid_group = postdrop
smtp_connect_timeout = 15
smtp_helo_timeout = 60
smtp_tls_CAfile = /etc/pki/tls/certs/ca-bundle.crt
smtp_tls_note_starttls_offer = yes
smtp_tls_session_cache_database = 
btree:$data_directory/smtp_tls_session_cache

smtp_use_tls = yes
smtpd_client_restrictions =
smtpd_data_restrictions =
smtpd_helo_required = yes
smtpd_helo_restrictions =
smtpd_milters = inet:127.0.0.1:8891
smtpd_recipient_restrictions = permit_mynetworks,
   reject_unauth_destination

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 =
smtpd_tls_cert_file = /etc/pki/tls/certs/zz.xxx.yy.crt
smtpd_tls_key_file = /etc/pki/tls/private/zz.xxx.yy.key
smtpd_tls_loglevel = 1
smtpd_tls_received_header = yes
smtpd_tls_session_cache_timeout = 3600s
smtpd_use_tls = yes
tls_random_source = dev:/dev/urandom
transport_maps = hash:/etc/postfix/transport, 
regexp:/etc/postfix/transport.regexp

unknown_local_recipient_reject_code = 550
virtual_gid_maps = static:12
virtual_mailbox_base = /home/vmail
virtual_minimum_uid = 101
virtual_transport = dovecot
virtual_uid_maps = static:101

Re: Postfix is slow accepting incoming mails

2018-03-09 Thread Wietse Venema 
Nikolai Dahlem:
[inbound SMTP]
> delay=0.51, delays=0.21/0/0.17/0.13

Just to be sure, these numbers include receiving and delivering mail.

0.21time from message arrival to last active queue entry
0   time from last active queue entry to connection setup
0.17time in connection setup, including DNS, EHLO and STARTTLS
0.13time in message transmission

The first number shows that it takes 0.2s to put mail into the
queue. Does your host run a LOCAL caching DNS server? If not, that
could explain sluggish performance for receiving and sending mail.

When receiving SMTP mail, Postfix looks up IPaddress->name and
name->IPaddress which can result in two DNS queries per inbound
connection.

The other numbers show that the total delays are dominated by
deliveries. Which Postfix delivery agent that was producing these
numbers? I suppose that was the SMTP client? If it is a local
delivery agent, then WHAT IS WRONG WITH YOUR FILE SYSTEM?

> >I suspect that your mail sending program is too slow. You can test
> >Postfix raw speed with smtp-source test program, part of the Postfix
> >source bundle.
> 
> time smtp-source -4 -m 20 -S Test -l 500 -t u...@xxx.yy 127.0.0.1
> real0m4.097s
> user0m0.007s
> sys 0m0.017s
> 
> So one thread delivers 5 mail/sec to postfix. Multiple threads scale 
> well, but single thread performance seems really low.

It is consistent with the 0.21s above. Your measurement agrees with
Postfix's delays reporting.

Wietse

Re: Postfix is slow accepting incoming mails

2018-03-08 Thread Nikolai Dahlem 

   Would it be possible to say if this performance is sending or
   receiving mail?


It is receiving mail (time to finish the smtp dialog)


   Either way, show the `delays='' logging, which
   reports the time spent in different stages of delivery.

  The format of the "delays=a/b/c/d" logging is as follows:

  o  a = time from message arrival to last active queue 
entry


  o  b = time from last active queue entry to connection 
setup


  o  c = time in connection setup, including DNS, EHLO and 
STARTTLS


  o  d = time in message transmission


delay=0.51, delays=0.21/0/0.17/0.13



   I suspect that your mail sending program is too slow. You can test
   Postfix raw speed with smtp-source test program, part of the Postfix
   source bundle.



time smtp-source -4 -m 20 -S Test -l 500 -t u...@xxx.yy 127.0.0.1
real0m4.097s
user0m0.007s
sys 0m0.017s


So one thread delivers 5 mail/sec to postfix. Multiple threads scale 
well, but single thread performance seems really low.



regards

Nikolai

Re: Postfix is slow accepting incoming mails

2018-03-08 Thread Wietse Venema 
Nikolai Dahlem:
> Hi all,
> 
> I am running postfix 2.6.6 on CentOS 6.9 and I get a throughput of only 
> 3-5 mails per second.

Would it be possible to say if this performance is sending or
receiving mail? Either way, show the `delays='' logging, which
reports the time spent in different stages of delivery.

   The format of the "delays=a/b/c/d" logging is as follows:

   o  a = time from message arrival to last active queue entry

   o  b = time from last active queue entry to connection setup

   o  c = time in connection setup, including DNS, EHLO and STARTTLS

   o  d = time in message transmission

> It does not matter if I send via sendmail or SMTP 
> to localhost with keep-alive.

I suspect that your mail sending program is too slow. You can test
Postfix raw speed with smtp-source test program, part of the Postfix
source bundle.

> Below is the output of postconf:

postconf -n. No-one will look at a thousand lines of output.

Wiets

Re: Postfix is slow accepting incoming mails

2018-03-08 Thread Mike Guelfi 
postconf -nWould be more useful...

Postfix is slow accepting incoming mails

2018-03-08 Thread Nikolai Dahlem 

Hi all,

I am running postfix 2.6.6 on CentOS 6.9 and I get a throughput of only 
3-5 mails per second. It does not matter if I send via sendmail or SMTP 
to localhost with keep-alive.
There must be a Problem somewhere in my postfix config, but I haven't 
been able to find it.
I deactivated mysql-lookups, tls-auth, etc. only thing remaining is a 
opendkim-milter (deactivating makes no difference). Any help or 
suggestions how to pinpoint the Problem are greatly appreciated.



kind regards

Nikolai


Below is the output of postconf:


2bounce_notice_recipient = postmaster
access_map_defer_code = 450
access_map_reject_code = 554
address_verify_default_transport = $default_transport
address_verify_local_transport = $local_transport
address_verify_map =
address_verify_negative_cache = yes
address_verify_negative_expire_time = 3d
address_verify_negative_refresh_time = 3h
address_verify_poll_count = ${stress?1}${stress:3}
address_verify_poll_delay = 3s
address_verify_positive_expire_time = 31d
address_verify_positive_refresh_time = 7d
address_verify_relay_transport = $relay_transport
address_verify_relayhost = $relayhost
address_verify_sender = $double_bounce_sender
address_verify_sender_dependent_relayhost_maps = 
$sender_dependent_relayhost_maps

address_verify_service_name = verify
address_verify_transport_maps = $transport_maps
address_verify_virtual_transport = $virtual_transport
alias_database = hash:/etc/aliases
alias_maps = hash:/etc/aliases
allow_mail_to_commands = alias, forward
allow_mail_to_files = alias, forward
allow_min_user = no
allow_percent_hack = yes
allow_untrusted_routing = no
alternate_config_directories =
always_add_missing_headers = no
always_bcc =
anvil_rate_time_unit = 60s
anvil_status_update_time = 600s
append_at_myorigin = yes
append_dot_mydomain = yes
application_event_drain_time = 100s
authorized_flush_users = static:anyone
authorized_mailq_users = static:anyone
authorized_submit_users = static:anyone
backwards_bounce_logfile_compatibility = yes
berkeley_db_create_buffer_size = 16777216
berkeley_db_read_buffer_size = 131072
best_mx_transport =
biff = yes
body_checks =
body_checks_size_limit = 51200
bounce_notice_recipient = postmaster
bounce_queue_lifetime = 5d
bounce_service_name = bounce
bounce_size_limit = 5
bounce_template_file =
broken_sasl_auth_clients = yes
canonical_classes = envelope_sender, envelope_recipient, header_sender, 
header_recipient

canonical_maps =
cleanup_service_name = cleanup
command_directory = /usr/sbin
command_execution_directory =
command_expansion_filter = 
1234567890!@%-_=+:,./abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ

command_time_limit = 1000s
config_directory = /etc/postfix
connection_cache_protocol_timeout = 5s
connection_cache_service_name = scache
connection_cache_status_update_time = 600s
connection_cache_ttl_limit = 2s
content_filter =
cyrus_sasl_config_path =
daemon_directory = /usr/libexec/postfix
daemon_timeout = 18000s
data_directory = /var/lib/postfix
debug_peer_level = 1
debug_peer_list =
default_database_type = hash
default_delivery_slot_cost = 5
default_delivery_slot_discount = 50
default_delivery_slot_loan = 3
default_destination_concurrency_failed_cohort_limit = 1
default_destination_concurrency_limit = 20
default_destination_concurrency_negative_feedback = 1
default_destination_concurrency_positive_feedback = 1
default_destination_rate_delay = 0s
default_destination_recipient_limit = 50
default_extra_recipient_limit = 1000
default_minimum_delivery_slots = 3
default_privs = nobody
default_process_limit = 150
default_rbl_reply = $rbl_code Service unavailable; $rbl_class 
[$rbl_what] blocked using $rbl_domain${rbl_reason?; $rbl_reason}

default_recipient_limit = 2
default_recipient_refill_delay = 5s
default_recipient_refill_limit = 100
default_transport = smtp
default_verp_delimiters = +=
defer_code = 450
defer_service_name = defer
defer_transports =
delay_logging_resolution_limit = 2
delay_notice_recipient = postmaster
delay_warning_time = 0
deliver_lock_attempts = 20
deliver_lock_delay = 1s
destination_concurrency_feedback_debug = no
detect_8bit_encoding_header = yes
disable_dns_lookups = no
disable_mime_input_processing = no
disable_mime_output_conversion = no
disable_verp_bounces = no
disable_vrfy_command = yes
dont_remove = 0
double_bounce_sender = double-bounce
duplicate_filter_limit = 1000
empty_address_recipient = MAILER-DAEMON
empty_address_relayhost_maps_lookup_key = <>
enable_original_recipient = yes
error_notice_recipient = postmaster
error_service_name = error
execution_directory_expansion_filter = 
1234567890!@%-_=+:,./abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ

expand_owner_alias = no
export_environment = TZ MAIL_CONFIG LANG
fallback_transport =
fallback_transport_maps =
fast_flush_domains = $relay_domains
fast_flush_purge_time = 7d
fast_flush_refresh_time = 12h
fault_injection_code = 0
flush_service_name = flush
fork_attempts = 5
fork_delay = 1s
forward_expansion_filter =