1

Topic: Relay mail from external Mail Server

==== Required information ====
- iRedMail version (check /etc/iredmail-release): 0.9.6
- Linux/BSD distribution name and version: Ubuntu 16.04.2 LTS
- Store mail accounts in which backend (LDAP/MySQL/PGSQL): LDAP
- Web server (Apache or Nginx): Apache
- Manage mail accounts with iRedAdmin-Pro? 2.8.0
- Related log if you're reporting an issue:
====

Hi,

I try to configure a mail-relaying on iredmail but on he sending postfix server I get this log entry:

Mar 28 17:43:18 pve postfix/smtp[28147]: B212240BF6: to=<alert@xxxx.at>, relay=mail.efriends.at[XX.XX.XX.XX]:587, delay=2817, delays=2817/0.01/0.19/0, dsn=4.7.0, status=deferred (SASL authentication failed; cannot authenticate to server mail.xxxx.at[XX.XX.XX.XX]: no mechanism available)

postfix setting on sending server:
#relay mails to mail.xxxx.at
relayhost = [mail.xxxx.at]:587
smtp_use_tls = yes
smtp_sasl_auth_enable = yes
smtp_sasl_password_maps = hash:/etc/postfix/relay_passwords
smtp_sasl_security_options =
smtp_tls_note_starttls_offer = yes



Am I missing something?
I am not a postfix specialist so any help would be appreciated.

Thanks in advance
Günther

----

Spider Email Archiver: On-Premises, lightweight email archiving software developed by iRedMail team. Supports Amazon S3 compatible storage and custom branding.

2

Re: Relay mail from external Mail Server

Any related error in Postfix log file on iRedMail server?
Also, add IP of this server to Postfix 'debug_peer_list =' on iRedMail server to get detailed debug log.

3 (edited by guenther 2017-03-29 19:12:59)

Re: Relay mail from external Mail Server

Here is the log vom my iRedMail server

#############
Mar 29 13:04:32 mail postfix/smtpd[29536]: connect from o51.xxxx.at[XX.XX.XX.XX]
Mar 29 13:04:32 mail postfix/smtpd[29536]: smtp_stream_setup: maxtime=300 enable_deadline=0
Mar 29 13:04:32 mail postfix/smtpd[29536]: match_hostname: smtpd_client_event_limit_exceptions: o51.xxxx.at ~? 127.0.0.1
Mar 29 13:04:32 mail postfix/smtpd[29536]: match_hostaddr: smtpd_client_event_limit_exceptions: XX.XX.XX.XX ~? 127.0.0.1
Mar 29 13:04:32 mail postfix/smtpd[29536]: match_list_match: o51.xxxx.at: no match
Mar 29 13:04:32 mail postfix/smtpd[29536]: match_list_match: XX.XX.XX.XX: no match
Mar 29 13:04:32 mail postfix/smtpd[29536]: auto_clnt_open: connected to private/anvil
Mar 29 13:04:32 mail postfix/smtpd[29536]: send attr request = connect
Mar 29 13:04:32 mail postfix/smtpd[29536]: send attr ident = submission:XX.XX.XX.XX
Mar 29 13:04:32 mail postfix/smtpd[29536]: private/anvil: wanted attribute: status
Mar 29 13:04:32 mail postfix/smtpd[29536]: input attribute name: status
Mar 29 13:04:32 mail postfix/smtpd[29536]: input attribute value: 0
Mar 29 13:04:32 mail postfix/smtpd[29536]: private/anvil: wanted attribute: count
Mar 29 13:04:32 mail postfix/smtpd[29536]: input attribute name: count
Mar 29 13:04:32 mail postfix/smtpd[29536]: input attribute value: 1
Mar 29 13:04:32 mail postfix/smtpd[29536]: private/anvil: wanted attribute: rate
Mar 29 13:04:32 mail postfix/smtpd[29536]: input attribute name: rate
Mar 29 13:04:32 mail postfix/smtpd[29536]: input attribute value: 1
Mar 29 13:04:32 mail postfix/smtpd[29536]: private/anvil: wanted attribute: (list terminator)
Mar 29 13:04:32 mail postfix/smtpd[29536]: input attribute name: (end)
Mar 29 13:04:32 mail postfix/smtpd[29536]: > o51.xxxx.at[XX.XX.XX.XX]: 220 mail.xxxx.at ESMTP Postfix (Ubuntu)
Mar 29 13:04:32 mail postfix/smtpd[29536]: watchdog_pat: 0x7f4556c796e0
Mar 29 13:04:32 mail postfix/smtpd[29536]: < o51.xxxx.at[XX.XX.XX.XX]: EHLO o51.xxxx.at
Mar 29 13:04:32 mail postfix/smtpd[29536]: match_list_match: o51.xxxx.at: no match
Mar 29 13:04:32 mail postfix/smtpd[29536]: match_list_match: XX.XX.XX.XX: no match
Mar 29 13:04:32 mail postfix/smtpd[29536]: > o51.xxxx.at[XX.XX.XX.XX]: 250-mail.xxxx.at
Mar 29 13:04:32 mail postfix/smtpd[29536]: > o51.xxxx.at[XX.XX.XX.XX]: 250-PIPELINING
Mar 29 13:04:32 mail postfix/smtpd[29536]: > o51.xxxx.at[XX.XX.XX.XX]: 250-SIZE 104857600
Mar 29 13:04:32 mail postfix/smtpd[29536]: > o51.xxxx.at[XX.XX.XX.XX]: 250-ETRN
Mar 29 13:04:32 mail postfix/smtpd[29536]: > o51.xxxx.at[XX.XX.XX.XX]: 250-STARTTLS
Mar 29 13:04:32 mail postfix/smtpd[29536]: > o51.xxxx.at[XX.XX.XX.XX]: 250-ENHANCEDSTATUSCODES
Mar 29 13:04:32 mail postfix/smtpd[29536]: > o51.xxxx.at[XX.XX.XX.XX]: 250-8BITMIME
Mar 29 13:04:32 mail postfix/smtpd[29536]: > o51.xxxx.at[XX.XX.XX.XX]: 250-DSN
Mar 29 13:04:32 mail postfix/smtpd[29536]: > o51.xxxx.at[XX.XX.XX.XX]: 250 SMTPUTF8
Mar 29 13:04:32 mail postfix/smtpd[29536]: watchdog_pat: 0x7f4556c796e0
Mar 29 13:04:32 mail postfix/smtpd[29536]: < o51.xxxx.at[XX.XX.XX.XX]: STARTTLS
Mar 29 13:04:32 mail postfix/smtpd[29536]: > o51.xxxx.at[XX.XX.XX.XX]: 220 2.0.0 Ready to start TLS
Mar 29 13:04:32 mail postfix/smtpd[29536]: send attr request = seed
Mar 29 13:04:32 mail postfix/smtpd[29536]: send attr size = 32
Mar 29 13:04:32 mail postfix/smtpd[29536]: private/tlsmgr: wanted attribute: status
Mar 29 13:04:32 mail postfix/smtpd[29536]: input attribute name: status
Mar 29 13:04:32 mail postfix/smtpd[29536]: input attribute value: 0
Mar 29 13:04:32 mail postfix/smtpd[29536]: private/tlsmgr: wanted attribute: seed
Mar 29 13:04:32 mail postfix/smtpd[29536]: input attribute name: seed
Mar 29 13:04:32 mail postfix/smtpd[29536]: input attribute value: d6VWTEMcOu5w2SO0V8qkk+C6VTngfpGHQiPwvd22Dto=
Mar 29 13:04:32 mail postfix/smtpd[29536]: private/tlsmgr: wanted attribute: (list terminator)
Mar 29 13:04:32 mail postfix/smtpd[29536]: input attribute name: (end)
Mar 29 13:04:32 mail postfix/smtpd[29536]: send attr request = tktkey
Mar 29 13:04:32 mail postfix/smtpd[29536]: send attr keyname = [data 0 bytes]
Mar 29 13:04:32 mail postfix/smtpd[29536]: private/tlsmgr: wanted attribute: status
Mar 29 13:04:32 mail postfix/smtpd[29536]: input attribute name: status
Mar 29 13:04:32 mail postfix/smtpd[29536]: input attribute value: 0
Mar 29 13:04:32 mail postfix/smtpd[29536]: private/tlsmgr: wanted attribute: keybuf
Mar 29 13:04:32 mail postfix/smtpd[29536]: input attribute name: keybuf
Mar 29 13:04:32 mail postfix/smtpd[29536]: input attribute value: MvIylU7V53SFuAVuR/m/63GPIfiboRmVzWBkReTvgiNNjQuAnH4moY+cO6QqlWoe5j5Rrv9k96y5SEtIppjdtF6s+sr63BLxvDLZ6U5JaOjHm9tYAAAAAA==
Mar 29 13:04:32 mail postfix/smtpd[29536]: private/tlsmgr: wanted attribute: (list terminator)
Mar 29 13:04:32 mail postfix/smtpd[29536]: input attribute name: (end)
Mar 29 13:04:32 mail postfix/smtpd[29536]: xsasl_dovecot_server_create: SASL service=smtp, realm=(null)
Mar 29 13:04:32 mail postfix/smtpd[29536]: name_mask: noanonymous
Mar 29 13:04:32 mail postfix/smtpd[29536]: xsasl_dovecot_server_connect: Connecting
Mar 29 13:04:32 mail postfix/smtpd[29536]: xsasl_dovecot_server_connect: auth reply: VERSION?1?1
Mar 29 13:04:32 mail postfix/smtpd[29536]: xsasl_dovecot_server_connect: auth reply: MECH?PLAIN?plaintext
Mar 29 13:04:32 mail postfix/smtpd[29536]: name_mask: plaintext
Mar 29 13:04:32 mail postfix/smtpd[29536]: xsasl_dovecot_server_connect: auth reply: MECH?LOGIN?plaintext
Mar 29 13:04:32 mail postfix/smtpd[29536]: name_mask: plaintext
Mar 29 13:04:32 mail postfix/smtpd[29536]: xsasl_dovecot_server_connect: auth reply: SPID?32297
Mar 29 13:04:32 mail postfix/smtpd[29536]: xsasl_dovecot_server_connect: auth reply: CUID?11385
Mar 29 13:04:32 mail postfix/smtpd[29536]: xsasl_dovecot_server_connect: auth reply: COOKIE?30f77a95a05168fb49811fc31edfaccc
Mar 29 13:04:32 mail postfix/smtpd[29536]: xsasl_dovecot_server_connect: auth reply: DONE
Mar 29 13:04:32 mail postfix/smtpd[29536]: xsasl_dovecot_server_mech_filter: keep mechanism: PLAIN
Mar 29 13:04:32 mail postfix/smtpd[29536]: xsasl_dovecot_server_mech_filter: keep mechanism: LOGIN
Mar 29 13:04:32 mail postfix/smtpd[29536]: watchdog_pat: 0x7f4556c796e0
Mar 29 13:04:32 mail postfix/smtpd[29536]: < o51.xxxx.at[XX.XX.XX.XX]: EHLO o51.xxxx.at
Mar 29 13:04:32 mail postfix/smtpd[29536]: match_list_match: o51.xxxx.at: no match
Mar 29 13:04:32 mail postfix/smtpd[29536]: match_list_match: XX.XX.XX.XX: no match
Mar 29 13:04:32 mail postfix/smtpd[29536]: > o51.xxxx.at[XX.XX.XX.XX]: 250-mail.xxxx.at
Mar 29 13:04:32 mail postfix/smtpd[29536]: > o51.xxxx.at[XX.XX.XX.XX]: 250-PIPELINING
Mar 29 13:04:32 mail postfix/smtpd[29536]: > o51.xxxx.at[XX.XX.XX.XX]: 250-SIZE 104857600
Mar 29 13:04:32 mail postfix/smtpd[29536]: > o51.xxxx.at[XX.XX.XX.XX]: 250-ETRN
Mar 29 13:04:32 mail postfix/smtpd[29536]: > o51.xxxx.at[XX.XX.XX.XX]: 250-AUTH PLAIN LOGIN
Mar 29 13:04:32 mail postfix/smtpd[29536]: > o51.xxxx.at[XX.XX.XX.XX]: 250-AUTH=PLAIN LOGIN
Mar 29 13:04:32 mail postfix/smtpd[29536]: > o51.xxxx.at[XX.XX.XX.XX]: 250-ENHANCEDSTATUSCODES
Mar 29 13:04:32 mail postfix/smtpd[29536]: > o51.xxxx.at[XX.XX.XX.XX]: 250-8BITMIME
Mar 29 13:04:32 mail postfix/smtpd[29536]: > o51.xxxx.at[XX.XX.XX.XX]: 250-DSN
Mar 29 13:04:32 mail postfix/smtpd[29536]: > o51.xxxx.at[XX.XX.XX.XX]: 250 SMTPUTF8
Mar 29 13:04:32 mail postfix/smtpd[29536]: watchdog_pat: 0x7f4556c796e0
Mar 29 13:04:32 mail postfix/smtpd[29536]: < o51.xxxx.at[XX.XX.XX.XX]: QUIT
Mar 29 13:04:32 mail postfix/smtpd[29536]: > o51.xxxx.at[XX.XX.XX.XX]: 221 2.0.0 Bye
Mar 29 13:04:32 mail postfix/smtpd[29536]: match_hostname: smtpd_client_event_limit_exceptions: o51.xxxx.at ~? 127.0.0.1
Mar 29 13:04:32 mail postfix/smtpd[29536]: match_hostaddr: smtpd_client_event_limit_exceptions: XX.XX.XX.XX ~? 127.0.0.1
Mar 29 13:04:32 mail postfix/smtpd[29536]: match_list_match: o51.xxxx.at: no match
Mar 29 13:04:32 mail postfix/smtpd[29536]: match_list_match: XX.XX.XX.XX: no match
Mar 29 13:04:32 mail postfix/smtpd[29536]: send attr request = disconnect
Mar 29 13:04:32 mail postfix/smtpd[29536]: send attr ident = submission:XX.XX.XX.XX
Mar 29 13:04:32 mail postfix/smtpd[29536]: private/anvil: wanted attribute: status
Mar 29 13:04:32 mail postfix/smtpd[29536]: input attribute name: status
Mar 29 13:04:32 mail postfix/smtpd[29536]: input attribute value: 0
Mar 29 13:04:32 mail postfix/smtpd[29536]: private/anvil: wanted attribute: (list terminator)
Mar 29 13:04:32 mail postfix/smtpd[29536]: input attribute name: (end)
Mar 29 13:04:32 mail postfix/smtpd[29536]: disconnect from o51.xxxx.at[XX.XX.XX.XX] ehlo=2 starttls=1 quit=1 commands=4
#############



Log-file from the sending server:
#############
Mar 29 13:04:25 pve postfix/postfix-script[15931]: refreshing the Postfix mail system
Mar 29 13:04:25 pve postfix/master[4195]: reload -- version 2.11.3, configuration /etc/postfix
Mar 29 13:04:25 pve postfix/pickup[15936]: A932640BF0: uid=0 from=<root>
Mar 29 13:04:25 pve postfix/cleanup[15937]: A932640BF0: message-id=<20170329110425.A932640BF0@o51.xxxx.at>
Mar 29 13:04:25 pve postfix/qmgr[15938]: A932640BF0: from=<root@pve.xxxx.local>, size=289, nrcpt=1 (queue active)
Mar 29 13:04:25 pve postfix/smtp[15940]: warning: SASL authentication failure: No worthy mechs found
Mar 29 13:04:25 pve postfix/smtp[15940]: A932640BF0: to=<alert@xxxx.at>, relay=mail.xxxx.at[XX.XX.XX.XX]:587, delay=0.37, delays=0.17/0.01/0.19/0, dsn=4.7.0, status=deferred (SASL authentication failed; cannot authenticate to server mail.xxxx.at[XX.XX.XX.XX]: no mechanism available)
############

4

Re: Relay mail from external Mail Server

Please turn on debug mode in Dovecot and try again, we need related log in Dovecot log file.
FYI: http://www.iredmail.org/docs/debug.dovecot.html

5

Re: Relay mail from external Mail Server

Thanks for help. Sorry that I didn't replay in march (!).
This problem is not important anymore, since we have solved it in the pve software.

coffee is on the way :-)

6

Re: Relay mail from external Mail Server

Thanks for the coffee. smile