Re: problem with relayhost (solved)

Sun, 14 Aug 2011 10:47:29 -0700 

Hi,
issue solved:
smtp_sasl_auth_enable = yes
was missing.

Thanks
Karl-Heinz

On 14.08.2011 19:04, Firma Averlon wrote:

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

Reply via email to