# Postfix SMTP AUTH on Port 587 Issue

## KCSB

So I really, REALLY tried avoiding posting this, as I'm certain I am missing something simple. But, at this point, having another set of eyes might be useful. 

And I'm pretty much following the main Gentoo/Postfix/virtual setup guide (without the virtual hosting and MYSQL backend). 

I'm trying to set up a very simple local delivery postfix/courier-imap system (one domain, a small amount of users, nothing overly complicated). I've got everything working EXCEPT the authenticated SMTP - which I'd really like to have ONLY available on Port 587. For some reason, I just can't get it to work - and I'm pretty stumped as to why. I've also regenerated the certs a few times, but the CN matches the server name, so I'm nearly certain that is not it. 

I should note that I'm setting this all up on a testbed machine with the hopes of migrating over from our current Sendmail based system (there's a good reason for this migration - it's more than you want to know). And I'm under a bit of a deadline to get this done by Thursday, so any help would be GREATLY appreciated. I really feel like it's close, but there's got to be something I'm just not seeing. 

My master.cf:

```
#

# Postfix master process configuration file.  For details on the format

# of the file, see the master(5) manual page (command: "man 5 master").

#

# Do not forget to execute "postfix reload" after editing this file.

#

# ==========================================================================

# service type  private unpriv  chroot  wakeup  maxproc command + args

#               (yes)   (yes)   (yes)   (never) (100)

# ==========================================================================

smtp      inet  n       -       n       -       -       smtpd -v

submission inet n       -       n       -       -       smtpd -v

  -o smtpd_tls_security_level=encrypt

  -o smtpd_sasl_auth_enable=yes

#  -o smtpd_client_restrictions=permit_sasl_authenticated,reject

# -o milter_macro_daemon_name=ORIGINATING

#smtps     inet  n       -       n       -       -       smtpd -v

#  -o smtpd_tls_wrappermode=yes

#  -o smtpd_sasl_auth_enable=yes

#  -o smtpd_client_restrictions=permit_sasl_authenticated,reject

#  -o milter_macro_daemon_name=ORIGINATING

#628       inet  n       -       n       -       -       qmqpd

pickup    fifo  n       -       n       60      1       pickup

cleanup   unix  n       -       n       -       0       cleanup

qmgr      fifo  n       -       n       300     1       qmgr

#qmgr     fifo  n       -       n       300     1       oqmgr

tlsmgr    unix  -       -       n       1000?   1       tlsmgr

rewrite   unix  -       -       n       -       -       trivial-rewrite

bounce    unix  -       -       n       -       0       bounce

defer     unix  -       -       n       -       0       bounce

trace     unix  -       -       n       -       0       bounce

verify    unix  -       -       n       -       1       verify

flush     unix  n       -       n       1000?   0       flush

proxymap  unix  -       -       n       -       -       proxymap

proxywrite unix -       -       n       -       1       proxymap

smtp      unix  -       -       n       -       -       smtp

# When relaying mail as backup MX, disable fallback_relay to avoid MX loops

relay     unix  -       -       n       -       -       smtp

   -o smtp_fallback_relay=

#       -o smtp_helo_timeout=5 -o smtp_connect_timeout=5

showq     unix  n       -       n       -       -       showq

error     unix  -       -       n       -       -       error

retry     unix  -       -       n       -       -       error

discard   unix  -       -       n       -       -       discard

local     unix  -       n       n       -       -       local

virtual   unix  -       n       n       -       -       virtual

lmtp      unix  -       -       n       -       -       lmtp

anvil     unix  -       -       n       -       1       anvil

scache    unix  -       -       n       -       1       scache

```

My main.cf:

```
broken_sasl_auth_clients = yes

command_directory = /usr/sbin

config_directory = /etc/postfix

daemon_directory = /usr/lib/postfix

debug_peer_level = 2

default_destination_concurrency_limit = 10

home_mailbox = .maildir/

html_directory = /usr/share/doc/postfix-2.4.6-r2/html

inet_interfaces = all

local_destination_concurrency_limit = 2

mail_owner = postfix

mailq_path = /usr/bin/mailq

manpage_directory = /usr/share/man

maps_rbl_domains = dun.dnsrbl.net,spam.dnsrbl.net

mydestination = $myhostname, localhost.$mydomain $mydomain

mydomain = my.domain

myhostname = server.my.domain

newaliases_path = /usr/bin/newaliases

queue_directory = /var/spool/postfix

readme_directory = /usr/share/doc/postfix-2.4.6-r2/readme

sample_directory = /etc/postfix

sendmail_path = /usr/sbin/sendmail

setgid_group = postdrop

smtp_tls_note_starttls_offer = yes

smtp_use_tls = yes

smtpd_recipient_restrictions = reject_unauth_destination,permit_mynetworks,permit_sasl_authenticated

#smtpd_recipient_restrictions = permit_sasl_authenticated

smtpd_sasl_auth_enable = yes

smtpd_sasl_local_domain = $myhostname

smtpd_sasl_security_options = noanonymous

smtpd_tls_CAfile = /etc/postfix/cacert.pem

smtpd_tls_auth_only = yes

smtpd_tls_cert_file = /etc/postfix/newcert.pem

smtpd_tls_key_file = /etc/postfix/newkey.pem

smtpd_tls_loglevel = 3

#smtpd_tls_received_header = yes

smtpd_tls_session_cache_timeout = 3600s

tls_random_source = dev:/dev/urandom

unknown_local_recipient_reject_code = 550

```

And the logs (sorry about the length - I'm logging pretty aggressively at this point):

```
Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  mail

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  ipv4

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: name_mask: ipv4

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  server.my.domain

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  my.domain

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  Postfix

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: expand ${multi_instance_name:postfix}${multi_instance_name?$multi_instance_name} -> postfix

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  postfix

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  postdrop

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: expand $myhostname, localhost.$mydomain $mydomain -> server.my.domain, localhost.my.domain my.domain

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: expand $myhostname -> server.my.domain

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  /usr/lib/postfix

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  /var/lib/postfix

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  /usr/sbin

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  /var/spool/postfix

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  pid

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  all

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  double-bounce

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  nobody

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  hash:/etc/mail/aliases

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  20110509

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  2.7.4

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  hash

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  deferred, defer

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: expand $mydestination -> server.my.domain, localhost.my.domain my.domain

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: expand $relay_domains -> server.my.domain, localhost.my.domain my.domain

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  TZ MAIL_CONFIG LANG

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  MAIL_CONFIG MAIL_DEBUG MAIL_LOGTAG TZ XAUTHORITY DISPLAY LANG=C

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  subnet

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  +=

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  -=+

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  debug_peer_list,fast_flush_domains,mynetworks,permit_mx_backup_networks,qmqpd_authorized_clients,relay_domains,smtpd_access_maps

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  bounce

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  cleanup

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  defer

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  pickup

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  qmgr

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  rewrite

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  showq

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  error

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  flush

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  verify

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  trace

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  proxymap

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  proxywrite

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  2

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  100s

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  100s

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  100s

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  100s

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  3600s

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  3600s

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  5s

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  5s

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  1000s

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  1000s

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  10s

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  10s

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  1s

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  1s

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  1s

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  1s

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  500s

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  500s

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  18000s

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  18000s

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  1s

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  1s

Aug  2 06:29:01 localhost postfix/smtpd[25867]: name_mask: subnet

Aug  2 06:29:01 localhost postfix/smtpd[25867]: inet_addr_local: configured 2 IPv4 addresses

Aug  2 06:29:01 localhost postfix/smtpd[25867]: been_here: 127.0.0.0/8: 0

Aug  2 06:29:01 localhost postfix/smtpd[25867]: been_here: my.server.ip.addr/26: 0

Aug  2 06:29:01 localhost postfix/smtpd[25867]: mynetworks: 127.0.0.0/8 my.server.ip.addr/26 

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  127.0.0.0/8 my.server.ip.addr/26 

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  10

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: expand ${stress?1}${stress:20} -> 20

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: expand ${stress?1}${stress:100} -> 100

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: expand ${stress?1}${stress:3} -> 3

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  550

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  3

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: expand $myhostname ESMTP $mail_name -> server.my.domain ESMTP Postfix

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  resource, software

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  reject_unauth_destination,permit_mynetworks,permit_sasl_authenticated

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  dun.dnsrbl.net,spam.dnsrbl.net

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  postmaster

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: expand $virtual_maps -> 

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  hash:/etc/mail/aliases

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: expand proxy:unix:passwd.byname $alias_maps -> proxy:unix:passwd.byname hash:/etc/mail/aliases

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  noanonymous

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  smtpd

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: expand $myhostname -> server.my.domain

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  CONNECT GET POST

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  <>

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: expand $double_bounce_sender -> double-bounce

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: expand $authorized_verp_clients -> 

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: expand $myhostname -> server.my.domain

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: expand ${smtpd_client_connection_limit_exceptions:$mynetworks} -> 127.0.0.0/8 my.server.ip.addr/26 

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  permit_inet_interfaces

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: expand $smtpd_sasl_security_options -> noanonymous

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  /etc/postfix/newcert.pem

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  /etc/postfix/newkey.pem

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: expand $smtpd_tls_dcert_file -> 

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: expand $smtpd_tls_eccert_file -> 

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  /etc/postfix/cacert.pem

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  export

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  medium

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  SSLv3, TLSv1

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  none

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  md5

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  encrypt

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  cyrus

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  j {daemon_name} v

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  {tls_version} {cipher} {cipher_bits} {cert_subject} {cert_issuer}

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  i {auth_type} {auth_authen} {auth_author} {mail_addr} {mail_host} {mail_mailer}

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  i {rcpt_addr} {rcpt_host} {rcpt_mailer}

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  i

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  i

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  i

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  6

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  tempfail

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: expand $myhostname -> server.my.domain

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: expand $mail_name $mail_version -> Postfix 2.7.4

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  defer_if_permit

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: expand $reject_tempfail_action -> defer_if_permit

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: expand $reject_tempfail_action -> defer_if_permit

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: expand $reject_tempfail_action -> defer_if_permit

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: expand $reject_tempfail_action -> defer_if_permit

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  yes

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  yes

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  yes

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: expand ${stress?10}${stress:300}s -> 300s

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: expand ${stress?10}${stress:300}s -> 300s

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  1s

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  1s

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  100s

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  100s

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  3s

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  3s

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  100s

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  100s

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  300s

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  300s

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  1000s

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  1000s

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  300s

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  300s

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  3600s

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  3600s

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  3600s

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  30s

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  30s

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  30s

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  30s

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  300s

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  300s

Aug  2 06:29:01 localhost postfix/smtpd[25867]: process generation: 3 (3)

Aug  2 06:29:01 localhost postfix/smtpd[25867]: match_string: mynetworks ~? debug_peer_list

Aug  2 06:29:01 localhost postfix/smtpd[25867]: match_string: mynetworks ~? fast_flush_domains

Aug  2 06:29:01 localhost postfix/smtpd[25867]: match_string: mynetworks ~? mynetworks

Aug  2 06:29:01 localhost postfix/smtpd[25867]: match_string: relay_domains ~? debug_peer_list

Aug  2 06:29:01 localhost postfix/smtpd[25867]: match_string: relay_domains ~? fast_flush_domains

Aug  2 06:29:01 localhost postfix/smtpd[25867]: match_string: relay_domains ~? mynetworks

Aug  2 06:29:01 localhost postfix/smtpd[25867]: match_string: relay_domains ~? permit_mx_backup_networks

Aug  2 06:29:01 localhost postfix/smtpd[25867]: match_string: relay_domains ~? qmqpd_authorized_clients

Aug  2 06:29:01 localhost postfix/smtpd[25867]: match_string: relay_domains ~? relay_domains

Aug  2 06:29:01 localhost postfix/smtpd[25867]: match_string: permit_mx_backup_networks ~? debug_peer_list

Aug  2 06:29:01 localhost postfix/smtpd[25867]: match_string: permit_mx_backup_networks ~? fast_flush_domains

Aug  2 06:29:01 localhost postfix/smtpd[25867]: match_string: permit_mx_backup_networks ~? mynetworks

Aug  2 06:29:01 localhost postfix/smtpd[25867]: match_string: permit_mx_backup_networks ~? permit_mx_backup_networks

Aug  2 06:29:01 localhost postfix/smtpd[25867]: connect to subsystem private/proxymap

Aug  2 06:29:01 localhost postfix/smtpd[25867]: send attr request = open

Aug  2 06:29:01 localhost postfix/smtpd[25867]: send attr table = unix:passwd.byname

Aug  2 06:29:01 localhost postfix/smtpd[25867]: send attr flags = 16448

Aug  2 06:29:01 localhost postfix/smtpd[25867]: private/proxymap socket: wanted attribute: status

Aug  2 06:29:01 localhost postfix/smtpd[25867]: input attribute name: status

Aug  2 06:29:01 localhost postfix/smtpd[25867]: input attribute value: 0

Aug  2 06:29:01 localhost postfix/smtpd[25867]: private/proxymap socket: wanted attribute: flags

Aug  2 06:29:01 localhost postfix/smtpd[25867]: input attribute name: flags

Aug  2 06:29:01 localhost postfix/smtpd[25867]: input attribute value: 16464

Aug  2 06:29:01 localhost postfix/smtpd[25867]: private/proxymap socket: wanted attribute: (list terminator)

Aug  2 06:29:01 localhost postfix/smtpd[25867]: input attribute name: (end)

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_proxy_open: connect to map=unix:passwd.byname status=0 server_flags=fixed|lock|fold_fix

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_open: proxy:unix:passwd.byname

Aug  2 06:29:01 localhost postfix/smtpd[25867]: Compiled against Berkeley DB: 4.8.30?

Aug  2 06:29:01 localhost postfix/smtpd[25867]: Run-time linked against Berkeley DB: 4.8.30?

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_open: hash:/etc/mail/aliases

Aug  2 06:29:01 localhost postfix/smtpd[25867]: match_string: smtpd_access_maps ~? debug_peer_list

Aug  2 06:29:01 localhost postfix/smtpd[25867]: match_string: smtpd_access_maps ~? fast_flush_domains

Aug  2 06:29:01 localhost postfix/smtpd[25867]: match_string: smtpd_access_maps ~? mynetworks

Aug  2 06:29:01 localhost postfix/smtpd[25867]: match_string: smtpd_access_maps ~? permit_mx_backup_networks

Aug  2 06:29:01 localhost postfix/smtpd[25867]: match_string: smtpd_access_maps ~? qmqpd_authorized_clients

Aug  2 06:29:01 localhost postfix/smtpd[25867]: match_string: smtpd_access_maps ~? relay_domains

Aug  2 06:29:01 localhost postfix/smtpd[25867]: match_string: smtpd_access_maps ~? smtpd_access_maps

Aug  2 06:29:01 localhost postfix/smtpd[25867]: unknown_helo_hostname_tempfail_action = defer_if_permit

Aug  2 06:29:01 localhost postfix/smtpd[25867]: unknown_address_tempfail_action = defer_if_permit

Aug  2 06:29:01 localhost postfix/smtpd[25867]: unverified_recipient_tempfail_action = defer_if_permit

Aug  2 06:29:01 localhost postfix/smtpd[25867]: unverified_sender_tempfail_action = defer_if_permit

Aug  2 06:29:01 localhost postfix/smtpd[25867]: xsasl_cyrus_server_init: SASL config file is smtpd.conf

Aug  2 06:29:01 localhost postfix/smtpd[25867]: initializing the server-side TLS engine

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  aNULL:-aNULL:ALL:!EXPORT:!LOW:!MEDIUM:+RC4:@STRENGTH

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  aNULL:-aNULL:ALL:!EXPORT:!LOW:+RC4:@STRENGTH

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  aNULL:-aNULL:ALL:!EXPORT:+RC4:@STRENGTH

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  aNULL:-aNULL:ALL:+RC4:@STRENGTH

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  eNULL:!aNULL

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  prime256v1

Aug  2 06:29:01 localhost postfix/smtpd[25867]: dict_eval: const  secp384r1

Aug  2 06:29:01 localhost postfix/smtpd[25867]: auto_clnt_create: transport=local endpoint=private/tlsmgr

Aug  2 06:29:01 localhost postfix/smtpd[25867]: auto_clnt_open: connected to private/tlsmgr

Aug  2 06:29:01 localhost postfix/smtpd[25867]: send attr request = seed

Aug  2 06:29:01 localhost postfix/smtpd[25867]: send attr size = 32

Aug  2 06:29:01 localhost postfix/smtpd[25867]: private/tlsmgr: wanted attribute: status

Aug  2 06:29:01 localhost postfix/smtpd[25867]: input attribute name: status

Aug  2 06:29:01 localhost postfix/smtpd[25867]: input attribute value: 0

Aug  2 06:29:01 localhost postfix/smtpd[25867]: private/tlsmgr: wanted attribute: seed

Aug  2 06:29:01 localhost postfix/smtpd[25867]: input attribute name: seed

Aug  2 06:29:01 localhost postfix/smtpd[25867]: input attribute value: c/684Ew7HLQRN9bCmbQJsDXS/Xf3J1rMO2vW+G/H+58=

Aug  2 06:29:01 localhost postfix/smtpd[25867]: private/tlsmgr: wanted attribute: (list terminator)

Aug  2 06:29:01 localhost postfix/smtpd[25867]: input attribute name: (end)

Aug  2 06:29:01 localhost postfix/smtpd[25867]: send attr request = policy

Aug  2 06:29:01 localhost postfix/smtpd[25867]: send attr cache_type = smtpd

Aug  2 06:29:01 localhost postfix/smtpd[25867]: private/tlsmgr: wanted attribute: status

Aug  2 06:29:01 localhost postfix/smtpd[25867]: input attribute name: status

Aug  2 06:29:01 localhost postfix/smtpd[25867]: input attribute value: 0

Aug  2 06:29:01 localhost postfix/smtpd[25867]: private/tlsmgr: wanted attribute: cachable

Aug  2 06:29:01 localhost postfix/smtpd[25867]: input attribute name: cachable

Aug  2 06:29:01 localhost postfix/smtpd[25867]: input attribute value: 0

Aug  2 06:29:01 localhost postfix/smtpd[25867]: private/tlsmgr: wanted attribute: (list terminator)

Aug  2 06:29:01 localhost postfix/smtpd[25867]: input attribute name: (end)

Aug  2 06:29:01 localhost postfix/smtpd[25867]: match_string: fast_flush_domains ~? debug_peer_list

Aug  2 06:29:01 localhost postfix/smtpd[25867]: match_string: fast_flush_domains ~? fast_flush_domains

Aug  2 06:29:01 localhost postfix/smtpd[25867]: auto_clnt_create: transport=local endpoint=private/anvil

Aug  2 06:29:01 localhost postfix/smtpd[25867]: connection established

Aug  2 06:29:01 localhost postfix/smtpd[25867]: master_notify: status 0

Aug  2 06:29:01 localhost postfix/smtpd[25867]: name_mask: resource

Aug  2 06:29:01 localhost postfix/smtpd[25867]: name_mask: software

Aug  2 06:29:01 localhost postfix/smtpd[25867]: connect from my.isp.domain.addr[my.remote.ip.addr]

Aug  2 06:29:01 localhost postfix/smtpd[25867]: match_list_match: my.isp.domain.addr: no match

Aug  2 06:29:01 localhost postfix/smtpd[25867]: match_list_match: my.remote.ip.addr: no match

Aug  2 06:29:01 localhost postfix/smtpd[25867]: match_list_match: my.isp.domain.addr: no match

Aug  2 06:29:01 localhost postfix/smtpd[25867]: match_list_match: my.remote.ip.addr: no match

Aug  2 06:29:01 localhost postfix/smtpd[25867]: match_hostname: my.isp.domain.addr ~? 127.0.0.0/8

Aug  2 06:29:01 localhost postfix/smtpd[25867]: match_hostaddr: my.remote.ip.addr ~? 127.0.0.0/8

Aug  2 06:29:01 localhost postfix/smtpd[25867]: match_hostname: my.isp.domain.addr ~? my.server.ip.addr/26

Aug  2 06:29:01 localhost postfix/smtpd[25867]: match_hostaddr: my.remote.ip.addr ~? my.server.ip.addr/26

Aug  2 06:29:01 localhost postfix/smtpd[25867]: match_list_match: my.isp.domain.addr: no match

Aug  2 06:29:01 localhost postfix/smtpd[25867]: match_list_match: my.remote.ip.addr: no match

Aug  2 06:29:01 localhost postfix/smtpd[25867]: auto_clnt_open: connected to private/anvil

Aug  2 06:29:01 localhost postfix/smtpd[25867]: send attr request = connect

Aug  2 06:29:01 localhost postfix/smtpd[25867]: send attr ident = submission:my.remote.ip.addr

Aug  2 06:29:01 localhost postfix/smtpd[25867]: private/anvil: wanted attribute: status

Aug  2 06:29:01 localhost postfix/smtpd[25867]: input attribute name: status

Aug  2 06:29:01 localhost postfix/smtpd[25867]: input attribute value: 0

Aug  2 06:29:01 localhost postfix/smtpd[25867]: private/anvil: wanted attribute: count

Aug  2 06:29:01 localhost postfix/smtpd[25867]: input attribute name: count

Aug  2 06:29:01 localhost postfix/smtpd[25867]: input attribute value: 1

Aug  2 06:29:01 localhost postfix/smtpd[25867]: private/anvil: wanted attribute: rate

Aug  2 06:29:01 localhost postfix/smtpd[25867]: input attribute name: rate

Aug  2 06:29:01 localhost postfix/smtpd[25867]: input attribute value: 1

Aug  2 06:29:01 localhost postfix/smtpd[25867]: private/anvil: wanted attribute: (list terminator)

Aug  2 06:29:01 localhost postfix/smtpd[25867]: input attribute name: (end)

Aug  2 06:29:01 localhost postfix/smtpd[25867]: > my.isp.domain.addr[my.remote.ip.addr]: 220 server.my.domain ESMTP Postfix

Aug  2 06:29:01 localhost postfix/smtpd[25867]: < my.isp.domain.addr[my.remote.ip.addr]: EHLO [192.168.1.106]

Aug  2 06:29:01 localhost postfix/smtpd[25867]: > my.isp.domain.addr[my.remote.ip.addr]: 250-server.my.domain

Aug  2 06:29:01 localhost postfix/smtpd[25867]: > my.isp.domain.addr[my.remote.ip.addr]: 250-PIPELINING

Aug  2 06:29:01 localhost postfix/smtpd[25867]: > my.isp.domain.addr[my.remote.ip.addr]: 250-SIZE 10240000

Aug  2 06:29:01 localhost postfix/smtpd[25867]: > my.isp.domain.addr[my.remote.ip.addr]: 250-VRFY

Aug  2 06:29:01 localhost postfix/smtpd[25867]: > my.isp.domain.addr[my.remote.ip.addr]: 250-ETRN

Aug  2 06:29:01 localhost postfix/smtpd[25867]: match_list_match: my.isp.domain.addr: no match

Aug  2 06:29:01 localhost postfix/smtpd[25867]: match_list_match: my.remote.ip.addr: no match

Aug  2 06:29:01 localhost postfix/smtpd[25867]: > my.isp.domain.addr[my.remote.ip.addr]: 250-STARTTLS

Aug  2 06:29:01 localhost postfix/smtpd[25867]: > my.isp.domain.addr[my.remote.ip.addr]: 250-ENHANCEDSTATUSCODES

Aug  2 06:29:01 localhost postfix/smtpd[25867]: > my.isp.domain.addr[my.remote.ip.addr]: 250-8BITMIME

Aug  2 06:29:01 localhost postfix/smtpd[25867]: > my.isp.domain.addr[my.remote.ip.addr]: 250 DSN

Aug  2 06:29:01 localhost postfix/smtpd[25867]: < my.isp.domain.addr[my.remote.ip.addr]: STARTTLS

Aug  2 06:29:01 localhost postfix/smtpd[25867]: > my.isp.domain.addr[my.remote.ip.addr]: 220 2.0.0 Ready to start TLS

Aug  2 06:29:01 localhost postfix/smtpd[25867]: setting up TLS connection from my.isp.domain.addr[my.remote.ip.addr]

Aug  2 06:29:01 localhost postfix/smtpd[25867]: my.isp.domain.addr[my.remote.ip.addr]: TLS cipher list "aNULL:-aNULL:ALL:!EXPORT:!LOW:+RC4:@STRENGTH"

Aug  2 06:29:01 localhost postfix/smtpd[25867]: send attr request = seed

Aug  2 06:29:01 localhost postfix/smtpd[25867]: send attr size = 32

Aug  2 06:29:01 localhost postfix/smtpd[25867]: private/tlsmgr: wanted attribute: status

Aug  2 06:29:01 localhost postfix/smtpd[25867]: input attribute name: status

Aug  2 06:29:01 localhost postfix/smtpd[25867]: input attribute value: 0

Aug  2 06:29:01 localhost postfix/smtpd[25867]: private/tlsmgr: wanted attribute: seed

Aug  2 06:29:01 localhost postfix/smtpd[25867]: input attribute name: seed

Aug  2 06:29:01 localhost postfix/smtpd[25867]: input attribute value: NFPrxufNjH8x774wMfuG5OyPd6aqrDc5m9uapzMsSbM=

Aug  2 06:29:01 localhost postfix/smtpd[25867]: private/tlsmgr: wanted attribute: (list terminator)

Aug  2 06:29:01 localhost postfix/smtpd[25867]: input attribute name: (end)

Aug  2 06:29:01 localhost postfix/smtpd[25867]: SSL_accept:before/accept initialization

Aug  2 06:29:01 localhost postfix/smtpd[25867]: read from 09880D20 [098923E8] (11 bytes => -1 (0xFFFFFFFF))

Aug  2 06:29:01 localhost postfix/smtpd[25867]: read from 09880D20 [098923E8] (11 bytes => 11 (0xB))

Aug  2 06:29:01 localhost postfix/smtpd[25867]: 0000 16 03 01 00 9d 01 00 00|99 03 01                 ........ ...

Aug  2 06:29:01 localhost postfix/smtpd[25867]: read from 09880D20 [098923F6] (151 bytes => -1 (0xFFFFFFFF))

Aug  2 06:29:01 localhost postfix/smtpd[25867]: read from 09880D20 [098923F6] (151 bytes => 151 (0x97))

Aug  2 06:29:01 localhost postfix/smtpd[25867]: 0000 4e 37 fb 9e 76 96 d5 2f|22 06 fc 00 83 df f8 1b  N7..v../ ".......

Aug  2 06:29:01 localhost postfix/smtpd[25867]: 0010 f7 06 eb 1d a4 9c bc 8d|9e f8 82 ea c3 3d 07 b0  ........ .....=..

Aug  2 06:29:01 localhost postfix/smtpd[25867]: 0020 00 00 46 c0 0a c0 09 c0|07 c0 08 c0 13 c0 14 c0  ..F..... ........

Aug  2 06:29:01 localhost postfix/smtpd[25867]: 0030 11 c0 12 c0 04 c0 05 c0|02 c0 03 c0 0e c0 0f c0  ........ ........

Aug  2 06:29:01 localhost postfix/smtpd[25867]: 0040 0c c0 0d 00 2f 00 05 00|04 00 35 00 0a 00 09 00  ..../... ..5.....

Aug  2 06:29:01 localhost postfix/smtpd[25867]: 0050 03 00 08 00 06 00 32 00|33 00 38 00 39 00 16 00  ......2. 3.8.9...

Aug  2 06:29:01 localhost postfix/smtpd[25867]: 0060 15 00 14 00 13 00 12 00|11 01 00 00 2a 00 00 00  ........ ....*...

Aug  2 06:29:01 localhost postfix/smtpd[25867]: 0070 14 00 12 00 00 0f 73 65|72 76 65 72 2e 6b 63 73  ......se rver.my

Aug  2 06:29:01 localhost postfix/smtpd[25867]: 0080 62 2e 6f 72 67 00 0a 00|08 00 06 00 17 00 18 00  domain... ........

Aug  2 06:29:01 localhost postfix/smtpd[25867]: 0090 19 00 0b 00 02 01                                ......

Aug  2 06:29:01 localhost postfix/smtpd[25867]: 0096 - <SPACES/NULLS>

Aug  2 06:29:01 localhost postfix/smtpd[25867]: SSL_accept:SSLv3 read client hello B

Aug  2 06:29:01 localhost postfix/smtpd[25867]: SSL_accept:SSLv3 write server hello A

Aug  2 06:29:01 localhost postfix/smtpd[25867]: SSL_accept:SSLv3 write certificate A

Aug  2 06:29:01 localhost postfix/smtpd[25867]: SSL_accept:SSLv3 write server done A

Aug  2 06:29:01 localhost postfix/smtpd[25867]: write to 09880D20 [0989FE40] (1732 bytes => 1732 (0x6C4))

Aug  2 06:29:01 localhost postfix/smtpd[25867]: 0000 16 03 01 00 4a 02 00 00|46 03 01 4e 37 fb 9d f3  ....J... F..N7...

Aug  2 06:29:01 localhost postfix/smtpd[25867]: 0010 f0 b3 3e 3c 8d 87 46 63|2a 20 85 df b9 27 54 09  ..><..Fc * ...'T.

Aug  2 06:29:01 localhost postfix/smtpd[25867]: 0020 a9 86 cc 98 8d 4b 61 ad|d5 91 1b 20 2e 31 ec 4a  .....Ka. ... .1.J

<cert info>

Aug  2 06:29:01 localhost postfix/smtpd[25867]: 06b0 bf f4 b2 c2 de 8d 45 29|7a 7d 35 16 03 01 00 04  ......E) z}5.....

Aug  2 06:29:01 localhost postfix/smtpd[25867]: 06c0 0e                                               .

Aug  2 06:29:01 localhost postfix/smtpd[25867]: 06c1 - <SPACES/NULLS>

Aug  2 06:29:01 localhost postfix/smtpd[25867]: SSL_accept:SSLv3 flush data

Aug  2 06:29:01 localhost postfix/smtpd[25867]: read from 09880D20 [098923EB] (5 bytes => -1 (0xFFFFFFFF))

Aug  2 06:29:01 localhost postfix/smtpd[25867]: SSL_accept error from my.isp.domain.addr[my.remote.ip.addr]: -1

Aug  2 06:29:01 localhost postfix/smtpd[25867]: match_hostname: my.isp.domain.addr ~? 127.0.0.0/8

Aug  2 06:29:01 localhost postfix/smtpd[25867]: match_hostaddr: my.remote.ip.addr ~? 127.0.0.0/8

Aug  2 06:29:01 localhost postfix/smtpd[25867]: match_hostname: my.isp.domain.addr ~? my.server.ip.addr/26

Aug  2 06:29:01 localhost postfix/smtpd[25867]: match_hostaddr: my.remote.ip.addr ~? my.server.ip.addr/26

Aug  2 06:29:01 localhost postfix/smtpd[25867]: match_list_match: my.isp.domain.addr: no match

Aug  2 06:29:01 localhost postfix/smtpd[25867]: match_list_match: my.remote.ip.addr: no match

Aug  2 06:29:01 localhost postfix/smtpd[25867]: send attr request = disconnect

Aug  2 06:29:01 localhost postfix/smtpd[25867]: send attr ident = submission:my.remote.ip.addr

Aug  2 06:29:01 localhost postfix/smtpd[25867]: private/anvil: wanted attribute: status

Aug  2 06:29:01 localhost postfix/smtpd[25867]: input attribute name: status

Aug  2 06:29:01 localhost postfix/smtpd[25867]: input attribute value: 0

Aug  2 06:29:01 localhost postfix/smtpd[25867]: private/anvil: wanted attribute: (list terminator)

Aug  2 06:29:01 localhost postfix/smtpd[25867]: input attribute name: (end)

Aug  2 06:29:01 localhost postfix/smtpd[25867]: lost connection after STARTTLS from my.isp.domain.addr[my.remote.ip.addr]

Aug  2 06:29:01 localhost postfix/smtpd[25867]: disconnect from my.isp.domain.addr[my.remote.ip.addr]

Aug  2 06:29:01 localhost postfix/smtpd[25867]: master_notify: status 1

Aug  2 06:29:01 localhost postfix/smtpd[25867]: connection closed

Aug  2 06:29:06 localhost postfix/smtpd[25867]: proxymap stream disconnect

Aug  2 06:29:06 localhost postfix/smtpd[25867]: auto_clnt_close: disconnect private/tlsmgr stream

Aug  2 06:30:41 localhost postfix/smtpd[25867]: idle timeout -- exiting

Aug  2 06:32:21 localhost postfix/anvil[25870]: statistics: max connection rate 1/60s for (submission:my.remote.ip.addr) at Aug  2 06:29:01

Aug  2 06:32:21 localhost postfix/anvil[25870]: statistics: max connection count 1 for (submission:my.remote.ip.addr) at Aug  2 06:29:01

Aug  2 06:32:21 localhost postfix/anvil[25870]: statistics: max cache size 1 at Aug  2 06:29:01

Aug  2 06:33:11 localhost imapd-ssl: TIMEOUT, user=bryan, ip=[::ffff:my.remote.ip.addr], headers=0, body=0, rcvd=86, sent=349, time=1800, starttls=1

```

telnet localhost 587

```
Trying 127.0.0.1...

Connected to localhost.

Escape character is '^]'.

220 server.my.domain ESMTP Postfix

ehlo localhost

250-server.my.domain

250-PIPELINING

250-SIZE 10240000

250-VRFY

250-ETRN

250-STARTTLS

250-ENHANCEDSTATUSCODES

250-8BITMIME

250 DSN

quit

221 2.0.0 Bye
```

One thing I just noticed is that there's no 250-AUTH LOGIN PLAIN indicated when I issued the EHLO (also not in the log above either) - and the client just spins for a while before disconnecting. It doesn't look like the client is effectively passing the username and password.  So, additionally, here's my cyrus-sasl confs:

cat /etc/conf.d/saslauthd

```
# Config file for /etc/init.d/saslauthd

SASLAUTHD_OPTS=""

SASLAUTHD_OPTS="${SASLAUTHD_OPTS} -a pam"
```

 cat /etc/sasl2/smtpd.conf

```
mech_list: PLAIN LOGIN

pwcheck_method:saslauthd

log_level: 5
```

Again, I've regenerated the certs and they have the only I can think of CN (server.my.domain) and this box only has that name, so I don't see what else it could be. Anyway... I'm convinced it's something simple, so any advice would be great.Last edited by KCSB on Tue Aug 02, 2011 4:03 pm; edited 1 time in total

----------

## audiodef

Oh, it's always something simple, although I'm not the one to spot it. 

It sounds like the mail guide linked in my sig below might be perfect for you. Cachrr0 wrote it, using me as the document tester, so it's been pored over a few times. Check out it, and if you follow it and still have trouble, post to this thread. 

Hope this helps.

----------

## KCSB

I think your guide is great - and if I had more time, I would ABSOLUTELY go that route. 

But I think, given that we already authenticate using PAM (for all of its flaws), it'll be easier (in theory at this point), to migrate accounts and passwords without having to use a MySQL backend given the time frame. If I can get this going, I can pretty much keep us down for a minimal amount of time while I copy email to the new box. 

And since everything is pretty much working save for the SMTP authentication, I'd have to pretty much go back and start from the near-beginning.

----------

## fillerbunny

Is the reason you are not seeing 250-AUTH LOGIN PLAIN during telnet because you have

```
smtpd_tls_auth_only = yes 
```

in main.cf?

I think in this scenario you only get the AUTH flag after STARTTLS has been done.

You can test starttls using openssl from the command line:

```
openssl s_client -starttls smtp -crlf -connect localhost:587
```

not sure this helps you but it might get you closer?

Roy

----------

