Hi,
thanks for giving me the opportunity to post to the users mailinglist.
I do have a problem since I can not get mailrelay working.
The error I get is generally spoken: 550 authentication required
And it looks like it authentication does not go through.
My main.cf:
+++++
smtpd_banner = $myhostname ESMTP $mail_name (Ubuntu)
biff = no
append_dot_mydomain = no
readme_directory = no
###
### TLS parameters
###
smtpd_tls_cert_file=/etc/ssl/certs/ssl-cert-snakeoil.pem
smtpd_tls_key_file=/etc/ssl/private/ssl-cert-snakeoil.key
smtpd_use_tls=yes
smtp_tls_session_cache_database = btree:${data_directory}/smtp_scache
smtpd_tls_session_cache_database = btree:${data_directory}/smtpd_scache
#For Postfix 2.3 or above use:
smtp_tls_security_level = may
smtpd_tls_security_level = may
smtp_tls_note_starttls_offer = yes
smtpd_tls_received_header = yes
smtpd_tls_session_cache_timeout = 3600s
tls_random_source = dev:/dev/urandom
smtpd_sender_login_maps =
ldap:/etc/postfix/ldap-controlled_envelope_senders.cf
smtpd_recipient_restrictions =
permit_sasl_authenticated,
reject_unknown_sender_domain,
reject_non_fqdn_sender,
reject_invalid_hostname,
permit_mynetworks,
reject_unauth_destination,
permit
smtpd_tls_loglevel = 2
debug_peer_level = 3
debug_peer_list = webhosting43.1blu.de
###
### SASL parameters
###
smtpd_sasl_auth_enable = yes
smtpd_sasl_security_options = noanonymous
broken_sasl_auth_clients = yes
smtpd_sasl_authenticated_header = yes
# smtp_sasl_password_maps wird benötigt um user:password für den
relayhost zu hinterlegen.
smtp_sasl_password_maps = hash:/etc/postfix/smtp_auth
# SASL mit dovecot
smtpd_sasl_type = dovecot
smtpd_sasl_path = private/auth
###
### allgemeine parameter
###
myhostname = mail.averlon.loc
alias_maps = hash:/etc/aliases
alias_database = hash:/etc/aliases
myorigin = /etc/mailname
mydestination =
# relayhost; siehe auch smtp_sasl_password_maps
relayhost = webhosting43.1blu.de
mynetworks = 127.0.0.0/8 [::ffff:127.0.0.0]/104 [::1]/128
mailbox_size_limit = 0
recipient_delimiter = +
inet_interfaces = all
inet_protocols = all
home_mailbox = Maildir/
mailbox_command = /usr/lib/dovecot/deliver
###
### Virtual Mailbox Domain Settings
###
virtual_mailbox_domains = /etc/postfix/vhosts
virtual_mailbox_base = /home/vmail
virtual_mailbox_maps = ldap:/etc/postfix/ldap-virtual.cf
virtual_minimum_uid = 1000
virtual_uid_maps = static:5000
virtual_gid_maps = static:5000
virtual_transport = dovecot
++++
Content of the file /etc/postfix/smtp_auth
+++
webhosting43.1blu.de user:secret
+++
I naturally use the user and password provided by my ISP.
logfile content:
+++
Aug 14 15:32:06 F42252SE postfix/smtpd[1271]: connect from
unknown[192.168.110.165]
Aug 14 15:32:06 F42252SE postfix/smtpd[1271]: setting up TLS connection
from unknown[192.168.110.165]
Aug 14 15:32:06 F42252SE postfix/smtpd[1271]: unknown[192.168.110.165]:
TLS cipher list "ALL:+RC4:@STRENGTH"
Aug 14 15:32:06 F42252SE postfix/smtpd[1271]: SSL_accept:before/accept
initialization
Aug 14 15:32:06 F42252SE postfix/smtpd[1271]: SSL_accept:SSLv3 read
client hello A
Aug 14 15:32:06 F42252SE postfix/smtpd[1271]: SSL_accept:SSLv3 write
server hello A
Aug 14 15:32:06 F42252SE postfix/smtpd[1271]: SSL_accept:SSLv3 write
change cipher spec A
Aug 14 15:32:06 F42252SE postfix/smtpd[1271]: SSL_accept:SSLv3 write
finished A
Aug 14 15:32:06 F42252SE postfix/smtpd[1271]: SSL_accept:SSLv3 flush data
Aug 14 15:32:06 F42252SE postfix/smtpd[1271]: SSL_accept:SSLv3 read
finished A
Aug 14 15:32:06 F42252SE postfix/smtpd[1271]: unknown[192.168.110.165]:
Reusing old session
Aug 14 15:32:06 F42252SE postfix/smtpd[1271]: Anonymous TLS connection
established from unknown[192.168.110.165]: TLSv1 with cipher
DHE-RSA-AES256-SHA (256/256 bits)
Aug 14 15:32:06 F42252SE dovecot: auth(default): client in:
AUTH#0115#011PLAIN#011service=smtp#011nologin#011lip=192.168.110.150#011rip=192.168.110.165#011secured#011resp=AGF2YWRtaW5AYXZlcmxvbi5sb2MAYWJyYWhhbWE=
Aug 14 15:32:06 F42252SE dovecot: auth(default):
ldap(user...@av.loc,192.168.110.165): pass search:
base=ou=people,dc=av,dc=loc scope=onelevel
filter=(&(objectClass=posixAccount)(mail=user...@av.loc))
fields=mail,userPassword
Aug 14 15:32:06 F42252SE dovecot: auth(default):
ldap(user...@av.loc,192.168.110.165): result: mail(user)=user...@av.loc
userPassword(password)={SHA}biNnyookLkQyErLL77RXi2xapfc=
Aug 14 15:32:06 F42252SE dovecot: auth(default): client out:
OK#0115#011user=user...@av.loc#011mail=/home/vmail/av.loc/userxxx/Maildir/
Aug 14 15:32:06 F42252SE postfix/smtpd[1271]: 9B95D2423A8:
client=unknown[192.168.110.165], sasl_method=PLAIN,
sasl_username=user...@av.loc
Aug 14 15:32:06 F42252SE postfix/cleanup[1275]: 9B95D2423A8:
message-id=<4e47ce55.9040...@av.loc>
Aug 14 15:32:06 F42252SE postfix/qmgr[27444]: 9B95D2423A8:
from=<user...@av.loc>, size=759, nrcpt=1 (queue active)
Aug 14 15:32:06 F42252SE postfix/smtpd[1271]: disconnect from
unknown[192.168.110.165]
Aug 14 15:32:06 F42252SE postfix/smtp[1278]: <
webhosting43.1blu.de[88.84.137.182]:25: 220 webhosting43.1blu.de ESMTP
Exim 4.69 Sun, 14 Aug 2011 15:32:06 +0200
Aug 14 15:32:06 F42252SE postfix/smtp[1278]: >
webhosting43.1blu.de[88.84.137.182]:25: EHLO mail.av.loc
Aug 14 15:32:06 F42252SE postfix/smtp[1278]: <
webhosting43.1blu.de[88.84.137.182]:25: 250-webhosting43.1blu.de Hello
mail.av.loc [79.230.30.253]
Aug 14 15:32:06 F42252SE postfix/smtp[1278]: <
webhosting43.1blu.de[88.84.137.182]:25: 250-SIZE 52428800
Aug 14 15:32:06 F42252SE postfix/smtp[1278]: <
webhosting43.1blu.de[88.84.137.182]:25: 250-PIPELINING
Aug 14 15:32:06 F42252SE postfix/smtp[1278]: <
webhosting43.1blu.de[88.84.137.182]:25: 250-AUTH LOGIN PLAIN
Aug 14 15:32:06 F42252SE postfix/smtp[1278]: <
webhosting43.1blu.de[88.84.137.182]:25: 250-STARTTLS
Aug 14 15:32:06 F42252SE postfix/smtp[1278]: <
webhosting43.1blu.de[88.84.137.182]:25: 250 HELP
Aug 14 15:32:06 F42252SE postfix/smtp[1278]: server features: 0x101d
size 52428800
Aug 14 15:32:06 F42252SE postfix/smtp[1278]: Using ESMTP PIPELINING, TCP
send buffer size is 16384, PIPELINING buffer size is 4096
Aug 14 15:32:06 F42252SE postfix/smtp[1278]: >
webhosting43.1blu.de[88.84.137.182]:25: STARTTLS
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: <
webhosting43.1blu.de[88.84.137.182]:25: 220 TLS go ahead
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: auto_clnt_open: connected
to private/tlsmgr
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: send attr request = lookup
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: send attr cache_type = smtp
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: send attr cache_id =
smtp:88.84.137.182:25:webhosting43.1blu.de&p=1&c=ALL:+RC4:@STRENGTH
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: private/tlsmgr: wanted
attribute: status
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: input attribute name: status
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: input attribute value: 0
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: private/tlsmgr: wanted
attribute: session
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: input attribute name: session
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: input attribute value:
MIIFnAIBAQICAwEEAgA5BCB+X2keNzLzvEjdnuSjAo6MxeQV44WAVBRLuPRlDRqn9wQw9m7HZ0uqN5KkFurzF7h4hyy6ZAx7+O37nJw9wpETR7OL3sjb+cEvznoaAlVVwztgoQYCBE5HzhOiBAICASyjggUiMIIFHjCCBAagAwIBAgIRAKUve7AUVzuAPsAsw3KYHeswDQYJKoZIhvcNAQEFBQAwgZMxCzAJBgNVBAYTAlVTMQswCQYDVQQIEwJVVDEXMBUGA1UEBxMOU2FsdCBMYWtlIENpdHkxHjAcBgNVBAoTFVRoZSBVU0VSVFJVU1QgTmV0d29yazEhMB8GA1UECxMYaHR0cDovL3d3dy51c2VydHJ1c3QuY29tMRswGQYDVQQDExJVVE4gLSBEQVRBQ29ycCBTR0MwHhcNMDkxMTExMDAwMDAwWhcNMTIxMTEwMjM1OTU5WjCBojELMAkGA1UEBhMCREUxDjAMBgNVBBETBTEwNTU1MQ8wDQYDVQQIEwZCZXJsaW4xDzANBgNVBAcTBkJlcmxpbjEZMBcGA1UECRMQU3Ryb21zdHJhc3NlIDEtNTEQMA4GA1UEChMHMWJsdSBBRzEgMB4GA1UECxMXQ29tb2RvIFNHQyBTU0wgV2lsZGNhcmQxEjAQBgNVBAMUCSouMWJsdS5kZTCBnzANBgkqhkiG9w0BAQEFAAOBjQAwgYkCgYEAm2aXNlVsvMfeKWlZ6rndCpsxYAiwNcz8ki3/op0kD7SR0VAcXP7Q5m5RsRYIKO/zqhwjoK1otmBLZtujOntKnum6Sx+DwdPjq0iowE0gx9O9mU5LZm2e5V+0+CGkCDJ5gFoKDRkmjtDPw5U1hZLd8bhj2molywFiuEqB5FPcetECAwEAAaOCAd4wggHaMB8GA1UdIwQYMBaAFFMy0bPPf/rg8aBdhU6S0p5FHbRPMB0GA1UdDgQWBBQ5gp09IolG9XUbTzvYsIv3LEVJJzAOBgNVHQ8BAf8EBAMCBaAwDAYDVR0TAQH/BAIwADA0BgNVHSUELTArBggrBgEFBQcDAQYIKwYBBQUHAwIGCisGAQQBgjcKAwMGCWCGSAGG+EIEATBGBgNVHSAEPzA9MDsGDCsGAQQBsjEBAgEDBDArMCkGCCsGAQUFBwIBFh1odHRwczovL3NlY3VyZS5jb21vZG8ubmV0L0NQUzBtBgNVHR8EZjBkMDGgL6AthitodHRwOi8vY3JsLmNvbW9kb2NhLmNvbS9VVE4tREFUQUNvcnBTR0MuY3JsMC+gLaArhilodHRwOi8vY3JsLmNvbW9kby5uZXQvVVROLURBVEFDb3JwU0dDLmNybDBuBggrBgEFBQcBAQRiMGAwOAYIKwYBBQUHMAKGLGh0dHA6Ly9jcnQuY29tb2RvY2EuY29tL1VUTkFkZFRydXN0U0dDQ0EuY3J0MCQGCCsGAQUFBzABhhhodHRwOi8vb2NzcC5jb21vZG9jYS5jb20wHQYDVR0RBBYwFIIJKi4xYmx1LmRlggcxYmx1LmRlMA0GCSqGSIb3DQEBBQUAA4IBAQA+pHB+Ug83R6hIx3q0V+0R+QaSqit6zhnGk8Ax3YQ8wHbA7NNygV2T5PyW6KG5bnoi8SKgGKb454tEKM3fp86ZPOnT1BZvkRQaUozMTSZI6bxGx/X2GGHFzZXjXtgADCQbFVR77trD7bK8MrAeNxUmruMfLTq7P+q6Pk3mduNWZGU61RCcaf+K4EFcbDWnlFEObAOF3KO6u2DozsmDGY3qQelF7iaEvDHHpBsxYSskf+wkxWYKOh3A+fmy01AEQv8OKnEgLV4s/V9FkmK1W+pMGLEbyQIGce7gzz6rULNaunlYrpDJZzc5pJYcpAINfn6JzOO37CEMvYXalFylHSrbpAIEAKUDAgEb
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: private/tlsmgr: wanted
attribute: (list terminator)
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: input attribute name: (end)
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: send attr request = seed
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: send attr size = 32
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: private/tlsmgr: wanted
attribute: status
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: input attribute name: status
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: input attribute value: 0
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: private/tlsmgr: wanted
attribute: seed
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: input attribute name: seed
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: input attribute value:
Uk08YNNLZsuLPAG+2FGXM68C1CshO0qWMQZApgCaoOA=
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: private/tlsmgr: wanted
attribute: (list terminator)
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: input attribute name: (end)
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: certificate verification
failed for webhosting43.1blu.de[88.84.137.182]:25: untrusted issuer
/C=SE/O=AddTrust AB/OU=AddTrust External TTP Network/CN=AddTrust
External CA Root
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: send attr request = update
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: send attr cache_type = smtp
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: send attr cache_id =
smtp:88.84.137.182:25:webhosting43.1blu.de&p=1&c=ALL:+RC4:@STRENGTH
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: send attr session = [data
1440 bytes]
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: private/tlsmgr: wanted
attribute: status
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: input attribute name: status
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: input attribute value: 0
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: private/tlsmgr: wanted
attribute: (list terminator)
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: input attribute name: (end)
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: >
webhosting43.1blu.de[88.84.137.182]:25: EHLO mail.av.loc
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: <
webhosting43.1blu.de[88.84.137.182]:25: 250-webhosting43.1blu.de Hello
mail.av.loc [79.230.30.253]
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: <
webhosting43.1blu.de[88.84.137.182]:25: 250-SIZE 52428800
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: <
webhosting43.1blu.de[88.84.137.182]:25: 250-PIPELINING
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: <
webhosting43.1blu.de[88.84.137.182]:25: 250-AUTH LOGIN PLAIN
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: <
webhosting43.1blu.de[88.84.137.182]:25: 250 HELP
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: server features: 0x100d
size 52428800
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: Using ESMTP PIPELINING, TCP
send buffer size is 16384, PIPELINING buffer size is 4096
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: >
webhosting43.1blu.de[88.84.137.182]:25: MAIL FROM:<user...@av.loc>
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: >
webhosting43.1blu.de[88.84.137.182]:25: RCPT TO:<albatros_...@web.de>
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: >
webhosting43.1blu.de[88.84.137.182]:25: DATA
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: <
webhosting43.1blu.de[88.84.137.182]:25: 250 OK
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: <
webhosting43.1blu.de[88.84.137.182]:25: 550 authentication required
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: connect to subsystem
private/bounce
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: send attr nrequest = 0
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: send attr flags = 0
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: send attr queue_id =
9B95D2423A8
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: send attr
original_recipient = albatros_...@web.de
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: send attr recipient =
albatros_...@web.de
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: send attr offset = 670
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: send attr dsn_orig_rcpt =
rfc822;albatros_...@web.de
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: send attr notify_flags = 0
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: send attr status = 5.0.0
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: send attr diag_type = smtp
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: send attr diag_text = 550
authentication required
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: send attr mta_type = dns
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: send attr mta_mname =
webhosting43.1blu.de
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: send attr action = failed
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: send attr reason = host
webhosting43.1blu.de[88.84.137.182] said: 550 authentication required
(in reply to RCPT TO command)
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: private/bounce socket:
wanted attribute: status
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: input attribute name: status
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: input attribute value: 0
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: private/bounce socket:
wanted attribute: (list terminator)
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: input attribute name: (end)
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: 9B95D2423A8:
to=<albatros_...@web.de>, relay=webhosting43.1blu.de[88.84.137.182]:25,
delay=0.81, delays=0.08/0/0.64/0.09, dsn=5.0.0, status=bounced (host
webhosting43.1blu.de[88.84.137.182] said: 550 authentication required
(in reply to RCPT TO command))
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: <
webhosting43.1blu.de[88.84.137.182]:25: 503-All RCPT commands were
rejected with this error:
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: <
webhosting43.1blu.de[88.84.137.182]:25: 503-authentication required
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: <
webhosting43.1blu.de[88.84.137.182]:25: 503 Valid RCPT command must
precede DATA
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: >
webhosting43.1blu.de[88.84.137.182]:25: RSET
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: >
webhosting43.1blu.de[88.84.137.182]:25: QUIT
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: <
webhosting43.1blu.de[88.84.137.182]:25: 250 Reset OK
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: name_mask: resource
Aug 14 15:32:07 F42252SE postfix/smtp[1278]: name_mask: software
Aug 14 15:32:07 F42252SE postfix/cleanup[1275]: 7A6FC2423A9:
message-id=<20110814133207.7a6fc242...@mail.av.loc>
Aug 14 15:32:07 F42252SE postfix/bounce[1279]: 9B95D2423A8: sender
non-delivery notification: 7A6FC2423A9
Aug 14 15:32:07 F42252SE postfix/qmgr[27444]: 7A6FC2423A9: from=<>,
size=2734, nrcpt=1 (queue active)
Aug 14 15:32:07 F42252SE postfix/qmgr[27444]: 9B95D2423A8: removed
Aug 14 15:32:07 F42252SE dovecot: auth(default): master in:
USER#0111#011user...@av.loc#011service=deliver
Aug 14 15:32:07 F42252SE dovecot: auth(default): ldap(user...@av.loc):
pass search: base=ou=people,dc=av,dc=loc scope=onelevel
filter=(&(objectClass=posixAccount)(mail=user...@av.loc))
fields=mail,userPassword
Aug 14 15:32:07 F42252SE dovecot: auth(default): ldap(user...@av.loc):
result: mail(user)=user...@av.loc
userPassword(password)={SHA}biNnyookLkQyErLL77RXi2xapfc=
Aug 14 15:32:07 F42252SE dovecot: auth(default):
password(user...@av.loc): Credentials:
6e2367ca8a242e443212b2cbefb4578b6c5aa5f7
Aug 14 15:32:07 F42252SE dovecot: auth(default): master out:
USER#0111#011user...@av.loc#011uid=5000#011gid=5000#011home=/home/vmail/av.loc/userxxx
Aug 14 15:32:07 F42252SE dovecot: deliver(user...@av.loc):
msgid=<20110814133207.7a6fc242...@mail.av.loc>: saved mail to INBOX
Aug 14 15:32:07 F42252SE postfix/pipe[1280]: 7A6FC2423A9:
to=<user...@av.loc>, relay=dovecot, delay=0.14, delays=0.04/0/0/0.09,
dsn=2.0.0, status=sent (delivered via dovecot service)
Aug 14 15:32:07 F42252SE postfix/qmgr[27444]: 7A6FC2423A9: removed
+++
I have tested it also with another smtp-relay server from another ISP.
Same result.
I naturally appreciate any hints where the problem could be.
Regards
Karl-Heinz
