0

I have a problem with my mail server (Postfix+Dovecot) which can receive but sadly can not deliver mails!

For information, the server is running on Debian 9 and is hosted by OVH.

Here are the /var/log/mail.log entries of whats happening when I try to send a mail (from a client by using Thunderbird):

1 --  postfix/submission/smtpd[984]: input attribute value: 1
2 --  postfix/submission/smtpd[984]: private/tlsmgr: wanted attribute: timeout
3 --  postfix/submission/smtpd[984]: input attribute name: timeout
4 --  postfix/submission/smtpd[984]: input attribute value: 3600
5 --  postfix/submission/smtpd[984]: private/tlsmgr: wanted attribute: (list terminator)
6 --  postfix/submission/smtpd[984]: input attribute name: (end)
7 --  postfix/submission/smtpd[984]: match_string: parent_domain_matches_subdomains: fast_flush_domains ~? debug_peer_list
8 --  postfix/submission/smtpd[984]: match_string: parent_domain_matches_subdomains: fast_flush_domains ~? fast_flush_domains
9 --  postfix/submission/smtpd[984]: auto_clnt_create: transport=local endpoint=private/anvil
10 --  postfix/submission/smtpd[984]: connection established
11 --  postfix/submission/smtpd[984]: master_notify: status 0
12 --  postfix/submission/smtpd[984]: name_mask: resource
13 --  postfix/submission/smtpd[984]: name_mask: software
14 --  postfix/submission/smtpd[984]: connect from [CLIENTNAME][[CLIENTIP]]
15 --  postfix/submission/smtpd[984]: match_list_match: [CLIENTNAME]: no match
16 --  postfix/submission/smtpd[984]: match_list_match: [CLIENTIP]: no match
17 --  postfix/submission/smtpd[984]: match_list_match: [CLIENTNAME]: no match
18 --  postfix/submission/smtpd[984]: match_list_match: [CLIENTIP]: no match
19 --  postfix/submission/smtpd[984]: match_hostname: debug_peer_list: [CLIENTNAME] ~? 127.0.0.1
20 --  postfix/submission/smtpd[984]: match_hostaddr: debug_peer_list: [CLIENTIP] ~? 127.0.0.1
21 --  postfix/submission/smtpd[984]: match_hostname: debug_peer_list: [CLIENTNAME] ~? [MYDOMAIN]
22 --  postfix/submission/smtpd[984]: match_hostaddr: debug_peer_list: [CLIENTIP] ~? [MYDOMAIN]
23 --  postfix/submission/smtpd[984]: match_list_match: [CLIENTNAME]: no match
24 --  postfix/submission/smtpd[984]: match_list_match: [CLIENTIP]: no match
25 --  postfix/submission/smtpd[984]: smtp_stream_setup: maxtime=300 enable_deadline=0
26 --  postfix/submission/smtpd[984]: match_hostname: smtpd_client_event_limit_exceptions: [CLIENTNAME] ~? 127.0.0.0/8
27 --  postfix/submission/smtpd[984]: match_hostaddr: smtpd_client_event_limit_exceptions: [CLIENTIP] ~? 127.0.0.0/8
28 --  postfix/submission/smtpd[984]: match_list_match: [CLIENTNAME]: no match
29 --  postfix/submission/smtpd[984]: match_list_match: [CLIENTIP]: no match
30 --  postfix/submission/smtpd[984]: auto_clnt_open: connected to private/anvil
31 --  postfix/submission/smtpd[984]: send attr request = connect
32 --  postfix/submission/smtpd[984]: send attr ident = submission:[CLIENTIP]
33 --  postfix/submission/smtpd[984]: private/anvil: wanted attribute: status
34 --  postfix/submission/smtpd[984]: input attribute name: status
35 --  postfix/submission/smtpd[984]: input attribute value: 0
36 --  postfix/submission/smtpd[984]: private/anvil: wanted attribute: count
37 --  postfix/submission/smtpd[984]: input attribute name: count
38 --  postfix/submission/smtpd[984]: input attribute value: 1
39 --  postfix/submission/smtpd[984]: private/anvil: wanted attribute: rate
40 --  postfix/submission/smtpd[984]: input attribute name: rate
41 --  postfix/submission/smtpd[984]: input attribute value: 1
42 --  postfix/submission/smtpd[984]: private/anvil: wanted attribute: (list terminator)
43 --  postfix/submission/smtpd[984]: input attribute name: (end)
44 --  postfix/submission/smtpd[984]: > [CLIENTNAME][[CLIENTIP]]: 220 teshar.[MYDOMAIN] ESMTP Postfix (Debian/GNU)
45 --  postfix/submission/smtpd[984]: < [CLIENTNAME][[CLIENTIP]]: EHLO [192.168.0.10]
46 --  postfix/submission/smtpd[984]: match_list_match: [CLIENTNAME]: no match
47 --  postfix/submission/smtpd[984]: match_list_match: [CLIENTIP]: no match
48 --  postfix/submission/smtpd[984]: > [CLIENTNAME][[CLIENTIP]]: 250-[MYHOSTDOMAIN]
49 --  postfix/submission/smtpd[984]: > [CLIENTNAME][[CLIENTIP]]: 250-PIPELINING
50 --  postfix/submission/smtpd[984]: > [CLIENTNAME][[CLIENTIP]]: 250-SIZE 10240000
51 --  postfix/submission/smtpd[984]: > [CLIENTNAME][[CLIENTIP]]: 250-VRFY
52 --  postfix/submission/smtpd[984]: > [CLIENTNAME][[CLIENTIP]]: 250-ETRN
53 --  postfix/submission/smtpd[984]: > [CLIENTNAME][[CLIENTIP]]: 250-STARTTLS
54 --  postfix/submission/smtpd[984]: > [CLIENTNAME][[CLIENTIP]]: 250-ENHANCEDSTATUSCODES
55 --  postfix/submission/smtpd[984]: > [CLIENTNAME][[CLIENTIP]]: 250-8BITMIME
56 --  postfix/submission/smtpd[984]: > [CLIENTNAME][[CLIENTIP]]: 250-DSN
57 --  postfix/submission/smtpd[984]: > [CLIENTNAME][[CLIENTIP]]: 250 SMTPUTF8
58 --  postfix/submission/smtpd[984]: < [CLIENTNAME][[CLIENTIP]]: STARTTLS
59 --  postfix/submission/smtpd[984]: > [CLIENTNAME][[CLIENTIP]]: 220 2.0.0 Ready to start TLS
60 --  postfix/submission/smtpd[984]: setting up TLS connection from [CLIENTNAME][[CLIENTIP]]
61 --  postfix/submission/smtpd[984]: [CLIENTNAME][[CLIENTIP]]: TLS cipher list "aNULL:-aNULL:HIGH:MEDIUM:+RC4:@STRENGTH:!MD5:!DES:!ADH:!RC4:!PSD:!SRP:!3DES:!eNULL:!aNULL:!MD5:!DES:!ADH:!RC4:!PSD:!SRP:!3DES:!eNULL:!aNULL"
62 --  postfix/submission/smtpd[984]: send attr request = seed
63 --  postfix/submission/smtpd[984]: send attr size = 32
64 --  postfix/submission/smtpd[984]: private/tlsmgr: wanted attribute: status
65 --  postfix/submission/smtpd[984]: input attribute name: status
66 --  postfix/submission/smtpd[984]: input attribute value: 0
67 --  postfix/submission/smtpd[984]: private/tlsmgr: wanted attribute: seed
68 --  postfix/submission/smtpd[984]: input attribute name: seed
69 --  postfix/submission/smtpd[984]: input attribute value: KOIm2ud2wCvuYcE8nKhw1RrGwmpKX0gw7kT4sLbysT4=
70 --  postfix/submission/smtpd[984]: private/tlsmgr: wanted attribute: (list terminator)
71 --  postfix/submission/smtpd[984]: input attribute name: (end)
72 --  postfix/submission/smtpd[984]: SSL_accept:before SSL initialization
73 --  postfix/submission/smtpd[984]: SSL_accept:before SSL initialization
74 --  postfix/submission/smtpd[984]: send attr request = tktkey
75 --  postfix/submission/smtpd[984]: send attr keyname = [data 16 bytes]
76 --  postfix/submission/smtpd[984]: private/tlsmgr: wanted attribute: status
77 --  postfix/submission/smtpd[984]: input attribute name: status
78 --  postfix/submission/smtpd[984]: input attribute value: 4294967295
79 --  postfix/submission/smtpd[984]: private/tlsmgr: wanted attribute: keybuf
80 --  postfix/submission/smtpd[984]: input attribute name: keybuf
81 --  postfix/submission/smtpd[984]: input attribute value: 9oQDVRdjTvMeJ/jn0uOC3g==
82 --  postfix/submission/smtpd[984]: private/tlsmgr: wanted attribute: (list terminator)
83 --  postfix/submission/smtpd[984]: input attribute name: (end)
84 --  postfix/submission/smtpd[984]: SSL_accept:SSLv3/TLS read client hello
85 --  postfix/submission/smtpd[984]: SSL_accept:SSLv3/TLS write server hello
86 --  postfix/submission/smtpd[984]: SSL_accept:SSLv3/TLS write certificate
87 --  postfix/submission/smtpd[984]: SSL_accept:SSLv3/TLS write key exchange
88 --  postfix/submission/smtpd[984]: SSL_accept:SSLv3/TLS write server done
89 --  postfix/submission/smtpd[984]: SSL_accept:SSLv3/TLS write server done
90 --  postfix/submission/smtpd[984]: SSL_accept:SSLv3/TLS read client key exchange
91 --  postfix/submission/smtpd[984]: SSL_accept:SSLv3/TLS read change cipher spec
92 --  postfix/submission/smtpd[984]: SSL_accept:SSLv3/TLS read finished
93 --  postfix/submission/smtpd[984]: send attr request = tktkey
94 --  postfix/submission/smtpd[984]: send attr keyname = [data 0 bytes]
95 --  postfix/submission/smtpd[984]: private/tlsmgr: wanted attribute: status
96 --  postfix/submission/smtpd[984]: input attribute name: status
97 --  postfix/submission/smtpd[984]: input attribute value: 0
98 --  postfix/submission/smtpd[984]: private/tlsmgr: wanted attribute: keybuf
99 --  postfix/submission/smtpd[984]: input attribute name: keybuf
100 --  postfix/submission/smtpd[984]: input attribute value: GS4aMvZYYdXW1YceMhQci3PUTQMO/Y/DqBWSZmv8PmTQ8yVeCJL5ZN4VqHMk0jVglcG5vVfLUGluXxMUkDkHrvMcOWwBBjemd8eZhpQzfdP5iBddAAAAAA==
101 --  postfix/submission/smtpd[984]: private/tlsmgr: wanted attribute: (list terminator)
102 --  postfix/submission/smtpd[984]: input attribute name: (end)
103 --  postfix/submission/smtpd[984]: [CLIENTNAME][[CLIENTIP]]: Issuing session ticket, key expiration: 1561823481
104 --  postfix/submission/smtpd[984]: SSL_accept:SSLv3/TLS write session ticket
105 --  postfix/submission/smtpd[984]: SSL_accept:SSLv3/TLS write change cipher spec
106 --  postfix/submission/smtpd[984]: SSL_accept:SSLv3/TLS write finished
107 --  postfix/submission/smtpd[984]: Anonymous TLS connection established from [CLIENTNAME][[CLIENTIP]]: TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
108 --  postfix/submission/smtpd[984]: xsasl_dovecot_server_create: SASL service=smtp, realm=(null)
109 --  postfix/submission/smtpd[984]: name_mask: noanonymous
110 --  postfix/submission/smtpd[984]: xsasl_dovecot_server_connect: Connecting
111 --  postfix/submission/smtpd[984]: xsasl_dovecot_server_connect: auth reply: VERSION?1?1
112 --  postfix/submission/smtpd[984]: xsasl_dovecot_server_connect: auth reply: MECH?LOGIN?plaintext
113 --  postfix/submission/smtpd[984]: name_mask: plaintext
114 --  postfix/submission/smtpd[984]: xsasl_dovecot_server_connect: auth reply: SPID?989
115 --  postfix/submission/smtpd[984]: xsasl_dovecot_server_connect: auth reply: CUID?1
116 --  postfix/submission/smtpd[984]: xsasl_dovecot_server_connect: auth reply: COOKIE?f9b6043b1239b511c8d485c337183bad
117 --  postfix/submission/smtpd[984]: xsasl_dovecot_server_connect: auth reply: DONE
118 --  postfix/submission/smtpd[984]: xsasl_dovecot_server_mech_filter: keep mechanism: LOGIN
119 --  postfix/submission/smtpd[984]: < [CLIENTNAME][[CLIENTIP]]: EHLO [192.168.0.10]
120 --  postfix/submission/smtpd[984]: match_list_match: [CLIENTNAME]: no match
121 --  postfix/submission/smtpd[984]: match_list_match: [CLIENTIP]: no match
122 --  postfix/submission/smtpd[984]: > [CLIENTNAME][[CLIENTIP]]: 250-[MYHOSTDOMAIN]
123 --  postfix/submission/smtpd[984]: > [CLIENTNAME][[CLIENTIP]]: 250-PIPELINING
124 --  postfix/submission/smtpd[984]: > [CLIENTNAME][[CLIENTIP]]: 250-SIZE 10240000
125 --  postfix/submission/smtpd[984]: > [CLIENTNAME][[CLIENTIP]]: 250-VRFY
126 --  postfix/submission/smtpd[984]: > [CLIENTNAME][[CLIENTIP]]: 250-ETRN
127 --  postfix/submission/smtpd[984]: > [CLIENTNAME][[CLIENTIP]]: 250-AUTH LOGIN
128 --  postfix/submission/smtpd[984]: > [CLIENTNAME][[CLIENTIP]]: 250-AUTH=LOGIN
129 --  postfix/submission/smtpd[984]: > [CLIENTNAME][[CLIENTIP]]: 250-ENHANCEDSTATUSCODES
130 --  postfix/submission/smtpd[984]: > [CLIENTNAME][[CLIENTIP]]: 250-8BITMIME
131 --  postfix/submission/smtpd[984]: > [CLIENTNAME][[CLIENTIP]]: 250-DSN
132 --  postfix/submission/smtpd[984]: > [CLIENTNAME][[CLIENTIP]]: 250 SMTPUTF8
133 --  postfix/submission/smtpd[984]: < [CLIENTNAME][[CLIENTIP]]: QUIT
134 --  postfix/submission/smtpd[984]: > [CLIENTNAME][[CLIENTIP]]: 221 2.0.0 Bye
135 --  postfix/submission/smtpd[984]: match_hostname: smtpd_client_event_limit_exceptions: [CLIENTNAME] ~? 127.0.0.0/8
136 --  postfix/submission/smtpd[984]: match_hostaddr: smtpd_client_event_limit_exceptions: [CLIENTIP] ~? 127.0.0.0/8
137 --  postfix/submission/smtpd[984]: match_list_match: [CLIENTNAME]: no match
138 --  postfix/submission/smtpd[984]: match_list_match: [CLIENTIP]: no match
139 --  postfix/submission/smtpd[984]: send attr request = disconnect
140 --  postfix/submission/smtpd[984]: send attr ident = submission:[CLIENTIP]
141 --  postfix/submission/smtpd[984]: private/anvil: wanted attribute: status
142 --  postfix/submission/smtpd[984]: input attribute name: status
143 --  postfix/submission/smtpd[984]: input attribute value: 0
144 --  postfix/submission/smtpd[984]: private/anvil: wanted attribute: (list terminator)
145 --  postfix/submission/smtpd[984]: input attribute name: (end)
146 --  postfix/submission/smtpd[984]: disconnect from [CLIENTNAME][[CLIENTIP]] ehlo=2 starttls=1 quit=1 commands=4
147 --  postfix/submission/smtpd[984]: master_notify: status 1
148 --  postfix/submission/smtpd[984]: connection closed
149 --  postfix/submission/smtpd[984]: proxymap stream disconnect
150 --  postfix/submission/smtpd[984]: auto_clnt_close: disconnect private/tlsmgr stream

Therefore, it seems that the client asks for a STARTTLS transmission (line 122). It leads to a TLS handshate (-> line 106) and authentication (-> line 118). Then it seems that the connection is restarted (at line 122 ) ending up by a "QUIT" by the client (l133).

There is no entry in /var/log/mail.err, systemctl status postfix, systemctl status dovecot.

From my mail client (thunderbird), I receive the following error message: "Sending of the message failed."

I think that something is wrong with my AUTH process but would need your help to clarify this.

Here is the output of "postconf -n"

alias_database = hash:/etc/aliases
alias_maps = hash:/etc/aliases
biff = no
broken_sasl_auth_clients = yes
compatibility_level = 2
debug_peer_level = 10
debug_peer_list = 127.0.0.1, $mydomain
home_mailbox = Maildir/
inet_interfaces = all
inet_protocols = ipv4
mailbox_size_limit = 0
mydestination = $myhostname, $mydomain, localhost.$mydomain, localhost
myhostname = [HIDDEN]
mynetworks = 127.0.0.0/8
myorigin = /etc/mailname
readme_directory = no
recipient_delimiter = +
relayhost =
smtp_tls_cert_file = /etc/letsencrypt/live/[MYDOMAIN]/fullchain.pem
smtp_tls_ciphers = medium
smtp_tls_exclude_ciphers = MD5, DES ADH, RC4, PSD, SRP, 3DES, eNULL, aNULL
smtp_tls_key_file = /etc/letsencrypt/live/[MYDOMAIN]/privkey.pem
smtp_tls_mandatory_ciphers = medium
smtp_tls_mandatory_exclude_ciphers = MD5, DES ADH, RC4, PSD, SRP, 3DES, eNULL, aNULL
smtp_tls_mandatory_protocols = !SSLv2, !SSLv3, !TLSv1
smtp_tls_note_starttls_offer = yes
smtp_tls_protocols = !SSLv2,!SSLv3,!TLSv1
smtp_tls_security_level = may
smtp_tls_session_cache_database = btree:${data_directory}/smtp_scache
smtp_use_tls = yes
smtpd_banner = $myhostname ESMTP $mail_name (Debian/GNU)
smtpd_helo_required = yes
smtpd_helo_restrictions = permit_mynetworks, permit_sasl_authenticated
smtpd_sasl_auth_enable = yes
smtpd_sasl_path = private/auth
smtpd_sasl_security_options = noanonymous
smtpd_sasl_type = dovecot
smtpd_tls_auth_only = yes
smtpd_tls_cert_file = /etc/letsencrypt/live/[MYDOMAIN]/fullchain.pem
smtpd_tls_ciphers = medium
smtpd_tls_exclude_ciphers = MD5, DES ADH, RC4, PSD, SRP, 3DES, eNULL, aNULL
smtpd_tls_key_file = /etc/letsencrypt/live/[MYDOMAIN]/privkey.pem
smtpd_tls_loglevel = 3
smtpd_tls_mandatory_ciphers = medium
smtpd_tls_mandatory_exclude_ciphers = MD5, DES ADH, RC4, PSD, SRP, 3DES, eNULL, aNULL
smtpd_tls_mandatory_protocols = !SSLv2, !SSLv3, !TLSv1
smtpd_tls_protocols = !SSLv2,!SSLv3, !TLSv1
smtpd_tls_received_header = yes
smtpd_tls_security_level = may
smtpd_tls_session_cache_database = btree:${data_directory}/smtpd_scache
smtpd_use_tls = yes
tls_preempt_cipherlist = yes

Here is the output of "postconf -Mf"

smtp       inet  n       -       n       -       -       smtpd -v
submission inet  n       -       n       -       -       smtpd -v
    -o syslog_name=postfix/submission
    -o smtpd_tls_security_level=encrypt
    -o smtpd_sasl_auth_enable=yes
    -o smtpd_reject_unlisted_recipient=no
smtps      inet  n       -       n       -       -       smtpd -v
pickup     unix  n       -       n       60      1       pickup
cleanup    unix  n       -       n       -       0       cleanup
qmgr       unix  n       -       n       300     1       qmgr
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
relay      unix  -       -       n       -       -       smtp
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 flags=DRhu
    user=vmail argv=/usr/bin/maildrop -d ${recipient}

Thanks for your time and consideration :)

EDIT: removed time + hostname entries in the /var/log/mail.log

GreenK
  • 3
  • 4

2 Answers2

0

Problem partially solved by allowing encrypted password transmission on server-side thanks to this tutorial Dovecot Wiki.

GreenK
  • 3
  • 4
0

Your configuration deviates from what is common and expected by mail clients: You are offering STARTTLS on all smtpd ports. Your mail client simply quits (I suspect because it was not configured for this setup).

Typically, you would offer clean TLS on Port 465 - while expecting clients to first say STARTTLS on port 25 and 587. Any modern mail clients would then automatically get the settings right, because both methods of initiating a secure connection would work with the defaults.

Change your master.cf to tell postfix to highlight non-STARTTLS initiated sessions in your logs and offer the direct TLS initiation on port 465 similar to how you did for port 587:

smtps      inet  n       -       n       -       -       smtpd -v
  -o syslog_name=postfix/smtps
  -o smtpd_tls_wrappermode=yes
  -o smtpd_sasl_auth_enable=yes
  -o smtpd_reject_unlisted_recipient=no

Then, remove your insecure smtpd_sasl_auth_enable and smtpd_sasl_security_options in your main.cf - since you probably do NOT want to allow mail clients to deliver authenticated mail on port 25, only on the two submission ports explicitly enabled for that purpose.

When everything works you might also wish to remove the -v and inet_protocols flags, I guess they are leftovers from testing.

anx
  • 8,963
  • 5
  • 24
  • 48
  • Thanks you it works! The options are applied to all 25, 465 and 567 by adding `smtpd_sasl_auth_enable` and `stmpd_sasl_security_options` in main.cf,? – GreenK Jul 01 '19 at 08:54
  • Yes. You should use `main.cf` for options that should affect all applicable services, while in master.cf you can define specific per-service options in a more legible way. – anx Jul 01 '19 at 08:58