Linode Forum
https://forum.linode.com/

Postfix SMTP not accepting authentication
https://forum.linode.com/viewtopic.php?f=11&t=7665
Page 1 of 2

Author:  Piki [ Wed Aug 31, 2011 7:00 pm ]
Post subject:  Postfix SMTP not accepting authentication

Hi,
I am working on setting up a mail server using Dovecot and Postfix on Debian Squeeze. So far I am able to connect to secure IMAP via Dovecot, and I am able to receive emails. However, I am unable to get Postfix to accept authentication for SMTP. My email client at home can make the connection initially, but then complains that the server doesn't support authentication and refuses to send messages.

Here are the lines that show up in /var/log/mail.log when I try to send to send a message (my IP is replaced for security):
Code:
Aug 31 18:55:23 li283-45 postfix/smtpd[29732]: connect from pool-XXX-XXX-XXX-XXX.pitbpa.fios.verizon.net[XXX.XXX.XXX.XXX]
Aug 31 18:55:34 li283-45 postfix/smtpd[29732]: lost connection after AUTH from pool-XXX-XXX-XXX-XXX.pitbpa.fios.verizon.net[XXX.XXX.XXX.XXX]
Aug 31 18:55:34 li283-45 postfix/smtpd[29732]: disconnect from pool-XXX-XXX-XXX-XXX.pitbpa.fios.verizon.net[XXX.XXX.XXX.XXX]


I've tried doing a google search, and everything suggested stuff with my sasl settings in main.cf, none of which worked (though I did apt-get install all the needed sasl packages). My current /etc/postfix/main.cf:
Code:
# See /usr/share/postfix/main.cf.dist for a commented, more complete version


# Debian specific:  Specifying a file name will cause the first
# line of that file to be used as the name.  The Debian default
# is /etc/mailname.
#myorigin = /etc/mailname

smtpd_banner = $myhostname ESMTP $mail_name (Debian/GNU)
biff = no

# appending .domain is the MUA's job.
append_dot_mydomain = no

# Uncomment the next line to generate "delayed mail" warnings
#delay_warning_time = 4h

readme_directory = no

# TLS parameters
smtpd_use_tls=yes
smtpd_tls_auth_only = yes
smtpd_tls_key_file = /etc/postfix/ssl/smtp.key
smtpd_tls_cert_file = /etc/postfix/ssl/smtp.cert
smtpd_tls_received_header = yes
smtpd_tls_session_cache_timeout = 3600s
tls_random_source = dev:/dev/urandom

# See /usr/share/doc/postfix/TLS_README.gz in the postfix-doc package for
# information on enabling SSL in the smtp client.

myhostname = www.youdolinux.com
alias_maps = hash:/etc/aliases
alias_database = hash:/etc/aliases
virtual_alias_maps = hash:/etc/postfix/virtual
home_mailbox = mail/
myorigin = youdolinux.com
mydestination = $myhostname, localhost.$mydomain, localhost, youdolinux.com, www.youdolinux.com, mail.youdolinux.com
#relayhost =
#mynetworks = 127.0.0.0/8 [::ffff:127.0.0.0]/104 [::1]/128
mailbox_size_limit = 0
recipient_delimiter = +
inet_interfaces = all
# SASL SUPPORT
smtpd_sasl_auth_enabled = yes
smtpd_sasl_security_options = noanonymous
smtpd_sasl_local_domain = $myhostname
smtpd_sasl_type = dovecot
smtpd_sasl_path = private/auth
smtpd_recipient_restrictions = permit_sasl_authenticated, permit_mynetworks, check_relay_domains

mailbox_command = /usr/bin/procmail

Author:  derfy [ Wed Aug 31, 2011 8:07 pm ]
Post subject: 

Need more info.

Follow the steps outlined here.

Thanks!

(Depending on how you're sending the mails, you may need to add the -v switch to the 'smtp' entry instead.)

Author:  Piki [ Mon Sep 05, 2011 12:28 pm ]
Post subject: 

Nice long log entry for postfix with the "-v" option added.... Once again, I replaced my IP for security.
Code:
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: connection established
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: master_notify: status 0
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: name_mask: resource
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: name_mask: software
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: connect from pool-XXX-XXX-XXX-XXX.pitbpa.fios.verizon.net[XXX.XXX.XXX.XXX]
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: match_list_match: pool-XXX-XXX-XXX-XXX.pitbpa.fios.verizon.net: no match
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: match_list_match: XXX.XXX.XXX.XXX: no match
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: match_list_match: pool-XXX-XXX-XXX-XXX.pitbpa.fios.verizon.net: no match
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: match_list_match: XXX.XXX.XXX.XXX: no match
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: match_hostname: pool-XXX-XXX-XXX-XXX.pitbpa.fios.verizon.net ~? 127.0.0.0/8
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: match_hostaddr: XXX.XXX.XXX.XXX ~? 127.0.0.0/8
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: match_hostname: pool-XXX-XXX-XXX-XXX.pitbpa.fios.verizon.net ~? 66.228.33.0/24
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: match_hostaddr: XXX.XXX.XXX.XXX ~? 66.228.33.0/24
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: match_list_match: pool-XXX-XXX-XXX-XXX.pitbpa.fios.verizon.net: no match
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: match_list_match: XXX.XXX.XXX.XXX: no match
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: send attr request = connect
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: send attr ident = submission:XXX.XXX.XXX.XXX
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: private/anvil: wanted attribute: status
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: input attribute name: status
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: input attribute value: 0
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: private/anvil: wanted attribute: count
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: input attribute name: count
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: input attribute value: 1
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: private/anvil: wanted attribute: rate
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: input attribute name: rate
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: input attribute value: 1
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: private/anvil: wanted attribute: (list terminator)
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: input attribute name: (end)
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: > pool-XXX-XXX-XXX-XXX.pitbpa.fios.verizon.net[XXX.XXX.XXX.XXX]: 220 www.youdolinux.com ESMTP Postfix (Debian/GNU)
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: < pool-XXX-XXX-XXX-XXX.pitbpa.fios.verizon.net[XXX.XXX.XXX.XXX]: EHLO debian.home
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: > pool-XXX-XXX-XXX-XXX.pitbpa.fios.verizon.net[XXX.XXX.XXX.XXX]: 250-www.youdolinux.com
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: > pool-XXX-XXX-XXX-XXX.pitbpa.fios.verizon.net[XXX.XXX.XXX.XXX]: 250-PIPELINING
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: > pool-XXX-XXX-XXX-XXX.pitbpa.fios.verizon.net[XXX.XXX.XXX.XXX]: 250-SIZE 10240000
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: > pool-XXX-XXX-XXX-XXX.pitbpa.fios.verizon.net[XXX.XXX.XXX.XXX]: 250-VRFY
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: > pool-XXX-XXX-XXX-XXX.pitbpa.fios.verizon.net[XXX.XXX.XXX.XXX]: 250-ETRN
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: match_list_match: pool-XXX-XXX-XXX-XXX.pitbpa.fios.verizon.net: no match
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: match_list_match: XXX.XXX.XXX.XXX: no match
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: > pool-XXX-XXX-XXX-XXX.pitbpa.fios.verizon.net[XXX.XXX.XXX.XXX]: 250-STARTTLS
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: > pool-XXX-XXX-XXX-XXX.pitbpa.fios.verizon.net[XXX.XXX.XXX.XXX]: 250-ENHANCEDSTATUSCODES
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: > pool-XXX-XXX-XXX-XXX.pitbpa.fios.verizon.net[XXX.XXX.XXX.XXX]: 250-8BITMIME
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: > pool-XXX-XXX-XXX-XXX.pitbpa.fios.verizon.net[XXX.XXX.XXX.XXX]: 250 DSN
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: < pool-XXX-XXX-XXX-XXX.pitbpa.fios.verizon.net[XXX.XXX.XXX.XXX]: STARTTLS
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: > pool-XXX-XXX-XXX-XXX.pitbpa.fios.verizon.net[XXX.XXX.XXX.XXX]: 220 2.0.0 Ready to start TLS
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: auto_clnt_open: connected to private/tlsmgr
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: send attr request = seed
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: send attr size = 32
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: private/tlsmgr: wanted attribute: status
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: input attribute name: status
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: input attribute value: 0
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: private/tlsmgr: wanted attribute: seed
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: input attribute name: seed
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: input attribute value: FNcLU9CMD+K8kBAspGHrw+GhgwdozRyg0S3MmAmwBGE=
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: private/tlsmgr: wanted attribute: (list terminator)
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: input attribute name: (end)
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: < pool-XXX-XXX-XXX-XXX.pitbpa.fios.verizon.net[XXX.XXX.XXX.XXX]: EHLO debian.home
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: > pool-XXX-XXX-XXX-XXX.pitbpa.fios.verizon.net[XXX.XXX.XXX.XXX]: 250-www.youdolinux.com
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: > pool-XXX-XXX-XXX-XXX.pitbpa.fios.verizon.net[XXX.XXX.XXX.XXX]: 250-PIPELINING
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: > pool-XXX-XXX-XXX-XXX.pitbpa.fios.verizon.net[XXX.XXX.XXX.XXX]: 250-SIZE 10240000
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: > pool-XXX-XXX-XXX-XXX.pitbpa.fios.verizon.net[XXX.XXX.XXX.XXX]: 250-VRFY
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: match_list_match: pool-XXX-XXX-XXX-XXX.pitbpa.fios.verizon.net: no match
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: match_list_match: XXX.XXX.XXX.XXX: no match
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: > pool-74-111-178-159.pitbpa.fios.verizon.net[74.111.178.159]: 250-ETRN
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: > pool-XXX-XXX-XXX-XXX.pitbpa.fios.verizon.net[XXX.XXX.XXX.XXX]: 250-ENHANCEDSTATUSCODES
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: > pool-XXX-XXX-XXX-XXX.pitbpa.fios.verizon.net[XXX.XXX.XXX.XXX]: 250-8BITMIME
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: > pool-XXX-XXX-XXX-XXX.pitbpa.fios.verizon.net[XXX.XXX.XXX.XXX]: 250 DSN
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: < pool-XXX-XXX-XXX-XXX.pitbpa.fios.verizon.net[XXX.XXX.XXX.XXX]: AUTH PLAIN <snip>==
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: > pool-XXX-XXX-XXX-XXX.pitbpa.fios.verizon.net[XXX.XXX.XXX.XXX]: 503 5.5.1 Error: authentication not enabled
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: smtp_get: EOF
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: match_hostname: pool-XXX-XXX-XXX-XXX.pitbpa.fios.verizon.net ~? 127.0.0.0/8
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: match_hostaddr: XXX.XXX.XXX.XXX ~? 127.0.0.0/8
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: match_hostname: pool-XXX-XXX-XXX-XXX.pitbpa.fios.verizon.net ~? 66.228.33.0/24
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: match_hostaddr: XXX.XXX.XXX.XXX ~? 66.228.33.0/24
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: match_list_match: pool-XXX-XXX-XXX-XXX.pitbpa.fios.verizon.net: no match
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: match_list_match: XXX.XXX.XXX.XXX: no match
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: send attr request = disconnect
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: send attr ident = submission:XXX.XXX.XXX.XXX
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: private/anvil: wanted attribute: status
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: input attribute name: status
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: input attribute value: 0
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: private/anvil: wanted attribute: (list terminator)
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: input attribute name: (end)
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: lost connection after AUTH from pool-XXX-XXX-XXX-XXX.pitbpa.fios.verizon.net[XXX.XXX.XXX.XXX]
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: disconnect from pool-74-111-178-159.pitbpa.fios.verizon.net[XXX.XXX.XXX.XXX]
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: master_notify: status 1
Sep  5 12:11:19 li283-45 postfix/smtpd[23608]: connection closed
Sep  5 12:11:24 li283-45 postfix/smtpd[23608]: auto_clnt_close: disconnect private/tlsmgr stream

There are a few references to a match list. Is this related to the "smtpd_recipient_restrictions" option near the end of my config? I want it to permit authenticated, which is there, but I can't authenticate.

Author:  Azathoth [ Mon Sep 05, 2011 1:00 pm ]
Post subject: 

What does your dovecot.conf say about exporting authentication services? Is the path to private/auth correct? Is the postfix' user set correctly? Is the listening even enabled?

Author:  Piki [ Mon Sep 05, 2011 1:17 pm ]
Post subject: 

From dovecot.conf, in the "auth default" section:
Code:
socket listen {
         client {
           path = /var/spool/postfix/private/auth
           mode = 0660
           user = postfix
           group = postfix
         }
       }

}


This file exists, along with a bunch of other postfix stuff under /var/spool/postfix:
Code:
root@li283-45:~# ls /var/spool/postfix/
active  bounce  corrupt  defer  deferred  dev  etc  flush  hold  incoming  lib  maildrop  pid  private  public  saved  trace  usr  var
root@li283-45:~# ls /var/spool/postfix/private/
anvil  bounce  defer    error   lmtp   maildrop  proxymap    relay  rewrite  scalemail-backend  tlsmgr  uucp    virtual
auth   bsmtp   discard  ifmail  local  mailman   proxywrite  retry  scache   smtp               trace   verify
root@li283-45:~# ls /var/spool/postfix/private/auth
/var/spool/postfix/private/auth


I have both a user and a group called postfix.

What needs to be listening? Postfix and Dovecot both seem to be listening.

Author:  Azathoth [ Mon Sep 05, 2011 8:03 pm ]
Post subject: 

How about auth mechanisms? Plain? Login? Set auth_verbose to yes and see if that says anything in dovecot's log file.

Author:  derfy [ Mon Sep 05, 2011 9:56 pm ]
Post subject: 

You may also wish to snip
Quote:
Sep 5 12:11:19 li283-45 postfix/smtpd[23608]: < pool-XXX-XXX-XXX-XXX.pitbpa.fios.verizon.net[XXX.XXX.XXX.XXX]: AUTH PLAIN <text here>
as it contains your login info.

Author:  Piki [ Wed Sep 07, 2011 7:10 pm ]
Post subject: 

derfy: I don't see my login info in that line?

Author:  Piki [ Wed Sep 07, 2011 7:24 pm ]
Post subject: 

My system doesn't have a log dedicated to Dovecot, but Dovecot is dumping stuff into mail.log. The only addition to the log (after putting "auth_default = yes" in dovecot.conf and restarting that and Postfix) was Dovecot registering an IMAP connection, though my email client started checking for mail just after I click the send button. I can post the current mail.log, but I seriously doubt the extra Dovecot line would help.[/code]

Author:  bjl [ Wed Sep 07, 2011 7:52 pm ]
Post subject: 

Piki wrote:
derfy: I don't see my login info in that line?


derfy is correct. heck, even scrappy probably knows there's a base64 encoded string (with your username and password) on that line.

Author:  Piki [ Wed Sep 07, 2011 7:57 pm ]
Post subject: 

I masked it with <snip>. Did I get the right thing? I'm no expert on encoding stuff.

Author:  bjl [ Wed Sep 07, 2011 10:36 pm ]
Post subject: 

looks good.

Author:  skavoovie [ Fri Sep 09, 2011 9:04 am ]
Post subject: 

Still having the issue?

Post the output of

Code:
# postconf -n

Author:  Piki [ Sat Sep 10, 2011 8:38 pm ]
Post subject: 

I am able to send email without authenticating with my username/password, but I still want it to require authentication.

Here's the output:
Code:
root@li283-45:~# postconf -n
alias_database = hash:/etc/aliases
alias_maps = hash:/etc/aliases
append_dot_mydomain = no
biff = no
config_directory = /etc/postfix
home_mailbox = mail/
inet_interfaces = all
mailbox_command = /usr/bin/procmail
mailbox_size_limit = 0
mydestination = $myhostname, localhost.$mydomain, localhost, youdolinux.com, www.youdolinux.com, mail.youdolinux.com
myhostname = www.youdolinux.com
myorigin = youdolinux.com
readme_directory = no
recipient_delimiter = +
smtpd_banner = $myhostname ESMTP $mail_name (Debian/GNU)
smtpd_recipient_restrictions = permit_sasl_authenticated, permit_mynetworks, check_relay_domains
smtpd_sasl_local_domain = $myhostname
smtpd_sasl_path = private/auth
smtpd_sasl_security_options = noanonymous
smtpd_sasl_type = dovecot
smtpd_tls_auth_only = yes
smtpd_tls_cert_file = /etc/postfix/ssl/smtp.cert
smtpd_tls_key_file = /etc/postfix/ssl/smtp.key
smtpd_tls_received_header = yes
smtpd_tls_session_cache_timeout = 3600s
smtpd_use_tls = yes
tls_random_source = dev:/dev/urandom
virtual_alias_maps = hash:/etc/postfix/virtual

Author:  skavoovie [ Sun Sep 11, 2011 12:37 am ]
Post subject: 

Is this the entire output? If so, two things jump out at me:

1. postconf -n doesn't reflect auth --- where is your "smtpd_sasl_auth_enabled = yes"? Postfix indicates that is not currently configured. Check your syntax, restart postfix and re-check with postconf -n again.

2. smtpd_recipient_restrictions -- you need to add "reject_unauth_destination" at the end of this configuration. Remove the deprecated "check_relay_domains" and replace it with "reject_unauth_destination".

Postfix isn't going to support auth without these.


Additionally, you may want to add "broken_sasl_auth_clients = yes" as an SASL option if you'll be using Outlook Express and/or certain versions of Exchange.


Make those changes and test. If it still fails, post another copy of your postconf -n output. Alternatively you might want to use saslfinger to help you troubleshoot -- you'll want to test server-side with the -s argument:

http://postfix.state-of-mind.de/patrick ... aslfinger/

Page 1 of 2 All times are UTC-04:00
Powered by phpBB® Forum Software © phpBB Group
http://www.phpbb.com/