Virtual Users And Domains With Postfix, Courier And MySQL - TLS not working

Hi,

I noticed that TLS is not working:

telnet localhost 25
Trying 127.0.0.1...
Connected to localhost.
Escape character is '^]'.
220 mail.domain.com ESMTP Postfix
ehlo localhost
250-mail.domain.com
250-SIZE 10240000
250-VRFY
250-ETRN
250-AUTH PLAIN LOGIN
250-AUTH=PLAIN LOGIN
250-ENHANCEDSTATUSCODES
250-8BITMIME
250 DSN


I cannot find STARTTLS.

/var/log/mail.log indicates:

Apr 17 22:41:35 mail postfix/smtpd[4679]: connect from localhost[127.0.0.1]
Apr 17 22:46:35 mail postfix/smtpd[4679]: SSL_accept error from localhost[127.0.0.1]: -1
Apr 17 22:46:35 mail postfix/smtpd[4679]: lost connection after STARTTLS from localhost[127.0.0.1]

mail:/etc/postfix/ssl# openssl s_client -connect localhost:25 -starttls smtp
CONNECTED(00000003)
5480:error:140790E5:SSL routines:SSL23_WRITE:ssl handshake failure:s23_lib.c:188:


What could be the problem?

TIA

 

handshake failure is usually a problem with the certificates, check the postfix logs for that particular time should get some indication of what is wrong

 

Postfix logs:

#/var/log/mail.log

Apr 17 22:41:35 mail postfix/smtpd[4679]: connect from localhost[127.0.0.1]
Apr 17 22:46:35 mail postfix/smtpd[4679]: SSL_accept error from localhost[127.0.0.1]: -1
Apr 17 22:46:35 mail postfix/smtpd[4679]: lost connection after STARTTLS from localhost[127.0.0.1]

# netstat -ntlp
Active Internet connections (only servers)
Proto Recv-Q Send-Q Local Address Foreign Address State PID/Program name
tcp 0 0 0.0.0.0:55555 0.0.0.0:* LISTEN 2106/perl
tcp 0 0 127.0.0.1:3306 0.0.0.0:* LISTEN 1990/mysqld
tcp 0 0 0.0.0.0:111 0.0.0.0:* LISTEN 1664/portmap
tcp 0 0 0.0.0.0:2416 0.0.0.0:* LISTEN -
tcp 0 0 0.0.0.0:2801 0.0.0.0:* LISTEN 2426/rpc.statd
tcp 0 0 0.0.0.0:113 0.0.0.0:* LISTEN 2279/inetd
tcp 0 0 0.0.0.0:25 0.0.0.0:* LISTEN 2106/perl
tcp 0 0 0.0.0.0:125 0.0.0.0:* LISTEN 5436/master
tcp6 0 0 :::993 :::* LISTEN 4524/couriertcpd
tcp6 0 0 :::995 :::* LISTEN 4414/couriertcpd
tcp6 0 0 :::110 :::* LISTEN 4366/couriertcpd
tcp6 0 0 :::143 :::* LISTEN 4486/couriertcpd
tcp6 0 0 :::80 :::* LISTEN 2465/apache2
tcp6 0 0 :::22 :::* LISTEN 2370/sshd
tcp6 0 0 :::125 :::* LISTEN 5436/master

 

Are you sure that is all that is being logged ?

 

Yes, that's all you can see as far as the command:

# openssl s_client -connect localhost:25 -starttls smtp
CONNECTED(00000003)
5480:error:140790E5:SSL routines:SSL23_WRITE:ssl handshake failure:s23_lib.c:188:

Postfix Logs: /var/log/mail.log

Apr 17 22:41:35 mail postfix/smtpd[4679]: connect from localhost[127.0.0.1]
Apr 17 22:46:35 mail postfix/smtpd[4679]: SSL_accept error from localhost[127.0.0.1]: -1
Apr 17 22:46:35 mail postfix/smtpd[4679]: lost connection after STARTTLS from localhost[127.0.0.1]

#telnet localhost 25

Trying 127.0.0.1...
Connected to localhost.
Escape character is '^]'.
220 mail.domain.com ESMTP Postfix
ehlo domain.com
250-mail.domain.com
250-SIZE 10240000
250-VRFY
250-ETRN
250-AUTH PLAIN LOGIN
250-AUTH=PLAIN LOGIN
250-ENHANCEDSTATUSCODES
250-8BITMIME
250 DSN
quit
221 2.0.0 Bye


Postfix Logs: /var/log/mail.log

Apr 18 00:25:34 mail postfix/smtpd[5615]: connect from localhost[127.0.0.1]
Apr 18 00:26:02 mailpostfix/smtpd[5615]: disconnect from localhost[127.0.0.1]
Apr 18 00:29:46 mail postfix/smtpd[5618]: warning: dict_nis_init: NIS domain name not set - NIS lookups disabled
Apr 18 00:29:46 mail postfix/smtpd[5618]: connect from localhost[127.0.0.1]
qApr 18 00:30:04 mail postfix/smtpd[5618]: disconnect from localhost[127.0.0.1]

 

What of syslog ?

 

Here's the syslog output:

Apr 18 00:25:34 mail postfix/smtpd[5615]: warning: dict_nis_init: NIS domain name not set - NIS lookups disabled
Apr 18 00:25:34 mail postfix/smtpd[5615]: connect from localhost[127.0.0.1]
Apr 18 00:26:02 mail postfix/smtpd[5615]: disconnect from localhost[127.0.0.1]
Apr 18 00:29:46 mail postfix/smtpd[5618]: warning: dict_nis_init: NIS domain name not set - NIS lookups disabled
Apr 18 00:29:46 mail postfix/smtpd[5618]: connect from localhost[127.0.0.1]
Apr 18 00:30:04 mail postfix/smtpd[5618]: disconnect from localhost[127.0.0.1]

Also, I already recreated the ssl cert for a couple of times that doesn't help at all. Can't find any good results in Google either.

Thank you so much.

 

post your main.cf

 

myhostname = mail.domain.com
mydestination = $myhostname, localhost.domain.com,localhost.localdomain, localhost
mynetworks = 127.0.0.0/8
virtual_alias_domains =
virtual_alias_maps = proxy:mysql:/etc/postfix/mysql-virtual_forwardings.cf, mysql:/etc/postfix/mysql-virtual_email2email.cf
virtual_mailbox_domains = proxy:mysql:/etc/postfix/mysql-virtual_domains.cf
virtual_mailbox_maps = proxy:mysql:/etc/postfix/mysql-virtual_mailboxes.cf
virtual_mailbox_base = /home/vmail
virtual_uid_maps = static:5000
virtual_gid_maps = static:5000
smtpd_sasl_auth_enable = yes
smtpd_sasl_security_options = noanonymous
broken_sasl_auth_clients = yes
smtpd_recipient_restrictions = permit_mynetworks, permit_sasl_authenticated, reject_unauth_destination
smtpd_use_tls = yes
smtpd_tls_loglevel = 1
smtpd_tls_received_header = yes
smtpd_tls_session_cache_timeout = 3600s
smtpd_tls_cert_file = /etc/postfix/ssl/smtpd.cert
smtpd_tls_key_file = /etc/postfix/ssl/smtpd.key
smtpd_tls_CAfile = /etc/postfix/ssl/cacert.pem
tls_random_source = dev:/dev/urandom
transport_maps = proxy:mysql:/etc/postfix/mysql-virtual_transports.cf
virtual_create_maildirsize = yes
virtual_mailbox_extended = yes
virtual_mailbox_limit_maps = proxy:mysql:/etc/postfix/mysql-virtual_mailbox_limit_maps.cf
virtual_mailbox_limit_override = yes
virtual_maildir_limit_message = "The user you are trying to reach is over quota."
virtual_overquota_bounce = yes
proxy_read_maps = $local_recipient_maps $mydestination $virtual_alias_maps $virtual_alias_domains $virtual_mailbox_maps $virtual_mailbox_domains $relay_reci$
myorigin = /etc/mailname
relayhost =
mailbox_command = procmail -a "$EXTENSION"
mailbox_size_limit = 0
recipient_delimiter = +
inet_interfaces = all
inet_protocols = all

 

Looks good try increasing the log level for tls

Code:

postconf -e 'smtpd_tls_loglevel = 4'

 

# tail -f /var/log/mail.log
Apr 18 00:26:02 mail postfix/smtpd[5615]: disconnect from localhost[127.0.0. 1]
Apr 18 00:29:46 mail postfix/smtpd[5618]: warning: dict_nis_init: NIS domain name not set - NIS lookups disabled
Apr 18 00:29:46 mail postfix/smtpd[5618]: connect from localhost[127.0.0.1]
Apr 18 00:30:04 mail postfix/smtpd[5618]: disconnect from localhost[127.0.0. 1]
Apr 18 15:09:26 mail authdaemond: modules="authmysql", daemons=5
Apr 18 15:09:27 mail authdaemond: Installing libauthmysql
Apr 18 15:09:27 mail authdaemond: Installation complete: authmysql
Apr 18 15:09:33 hercules postfix/master[2248]: daemon started -- version 2.3.8, configuration /etc/postfix
Apr 18 15:15:43 mail postfix/master[2248]: terminating on signal 15
Apr 18 15:15:43 mail postfix/master[2487]: daemon started -- version 2.3.8, configuration /etc/postfix
Apr 18 15:17:00 mail postfix/smtpd[2502]: warning: dict_nis_init: NIS domain name not set - NIS lookups disabled
Apr 18 15:17:00 mail postfix/smtpd[2502]: initializing the server-side TLS engine
Apr 18 15:17:00 mail postfix/smtpd[2502]: connect from localhost[127.0.0.1]
Apr 18 15:17:18 mail postfix/smtpd[2502]: disconnect from localhost[127.0.0.1]


# tail -f /var/log/syslog
Apr 18 15:09:35 mail /usr/sbin/cron[2339]: (CRON) INFO (Running @reboot jobs)
Apr 18 15:09:39 mail kernel: eth0: no IPv6 routers present
Apr 18 15:15:43 mail postfix/master[2248]: terminating on signal 15
Apr 18 15:15:43 mailpostfix/master[2487]: daemon started -- version 2.3.8, configuration /etc/postfix
Apr 18 15:17:00 mail postfix/smtpd[2502]: warning: dict_nis_init: NIS domain name not set - NIS lookups disabled
Apr 18 15:17:00 mail postfix/smtpd[2502]: initializing the server-side TLS engine
Apr 18 15:17:00 mail postfix/smtpd[2502]: connect from localhost[127.0.0.1]

TIA

 

What's the output of

Code:

postconf -d | grep nis

?

 

Here's the result of the command:

#postconf -d | grep nis
alias_maps = hash:/etc/aliases, nis:mail.aliases
lmtp_sasl_mechanism_filter =
smtp_sasl_mechanism_filter =

 

Run

Code:

postconf -e 'alias_maps = hash:/etc/aliases'
/etc/init.d/postfix restart

 

Hi falko,

Here's the result after applying the above command.

# openssl s_client -connect mail.domain.com:25
CONNECTED(00000003)
5558:error:140770FC:SSL routines:SSL23_GET_SERVER_HELLO:unknown

#tail -f /var/log/mail.log

Apr 21 17:56:14 mail postfix/smtpd[5563]: connect from hercules.alsterph.com[192.168.1.221]
Apr 21 17:56:14 mail postfix/smtpd[5563]: lost connection after UNKNOWN from mail.domain.com[192.168.1.221]
Apr 21 17:56:14 mails postfix/smtpd[5563]: disconnect from mail.domain.com[192.168.1.221]

#tail -f /var/log/syslog

Apr 21 17:57:21 mail postfix/anvil[5559]: statistics: max connection rate 2/60s for (125:192.168.1.221) at Apr 21 17:56:14
Apr 21 17:57:21 mail postfix/anvil[5559]: statistics: max connection count 1 for (125:192.168.1.221) at Apr 21 17:47:21
Apr 21 17:57:21 mail postfix/anvil[5559]: statistics: max cache size 1 at Apr 21 17:47:21
Apr 21 17:57:33 mail postfix/smtpd[5563]: connect from mail .domain.com[192.168.1.221]
Apr 21 17:57:33 mail postfix/smtpd[5563]: lost connection after UNKNOWN from mail.domain.com[192.168.1.221]
Apr 21 17:57:33 mail postfix/smtpd[5563]: disconnect from mail.domain.com[192.168.1.221]


# openssl s_client -connect localhost:25 -starttls smtp
CONNECTED(00000003)
5560:error:140790E5:SSL routines:SSL23_WRITE:ssl handshake failure:s23_lib.c:188:

#tail -f /var/log/mail.log
Apr 21 18:00:01 mail postfix/smtpd[5571]: connect from localhost[127.0.0.1]
Apr 21 18:00:01 mail postfix/smtpd[5571]: setting up TLS connection from localhost[127.0.0.1]
Apr 21 18:00:01 mail postfix/smtpd[5571]: SSL_accept:before/accept initialization
Apr 21 18:00:01 mail postfix/smtpd[5571]: read from 08096F80 [080A1F68] (11 bytes => -1 (0xFFFFFFFF))
Apr 21 18:00:01 mail postfix/smtpd[5571]: SSL_accept:error in SSLv2/v3 read client hello A
Apr 21 18:00:01 mail postfix/smtpd[5571]: read from 08096F80 [080A1F68] (11 bytes => 11 (0xB))
Apr 21 18:00:01 mail postfix/smtpd[5571]: 0000 80 74 01 03 01 00 4b .t....K
Apr 21 18:00:01 mail postfix/smtpd[5571]: 0007 - <SPACES/NULLS>
Apr 21 18:00:01 mail postfix/smtpd[5571]: read from 08096F80 [080A1F73] (107 bytes => -1 (0xFFFFFFFF))
Apr 21 18:00:01 mail postfix/smtpd[5571]: SSL_accept:error in SSLv2/v3 read client hello B
Apr 21 18:00:01 mail postfix/smtpd[5571]: read from 08096F80 [080A1F73] (107 bytes => 18 (0x12))
Apr 21 18:00:01 hercules postfix/smtpd[5571]: 0000 00 00 39 00 00 38 00 00|35 00 00 16 00 00 13 00 ..9..8.. 5.......
Apr 21 18:00:01 hercules postfix/smtpd[5571]: 0010 00 0a ..
Apr 21 18:00:01 hercules postfix/smtpd[5571]: read from 08096F80 [080A1F85] (89 bytes => -1 (0xFFFFFFFF))
Apr 21 18:00:01 mail postfix/smtpd[5571]: SSL_accept:error in SSLv2/v3 read client hello B


#tail -f /var/log/syslog
Apr 21 18:02:16 mail postfix/smtpd[5571]: connect from localhost[127.0.0.1]
Apr 21 18:02:16 mail postfix/smtpd[5571]: setting up TLS connection from localhost[127.0.0.1]
Apr 21 18:02:16 mail postfix/smtpd[5571]: SSL_accept:before/accept initialization
Apr 21 18:02:16 mail postfix/smtpd[5571]: read from 0808F9F8 [080A0F58] (11 bytes => -1 (0xFFFFFFFF))
Apr 21 18:02:16 mail postfix/smtpd[5571]: SSL_accept:error in SSLv2/v3 read client hello A
Apr 21 18:02:16 mail postfix/smtpd[5571]: read from 0808F9F8 [080A0F58] (11 bytes => 11 (0xB))
Apr 21 18:02:16 hercules postfix/smtpd[5571]: 0000 80 74 01 03 01 00 4b .t....K
Apr 21 18:02:16 mail postfix/smtpd[5571]: 0007 - <SPACES/NULLS>
Apr 21 18:02:16 mail postfix/smtpd[5571]: read from 0808F9F8 [080A0F63] (107 bytes => -1 (0xFFFFFFFF))
Apr 21 18:02:16 mail postfix/smtpd[5571]: SSL_accept:error in SSLv2/v3 read client hello B
Apr 21 18:02:16 mail postfix/smtpd[5571]: read from 0808F9F8 [080A0F63] (107 bytes => 18 (0x12))
Apr 21 18:02:16 mail postfix/smtpd[5571]: 0000 00 00 39 00 00 38 00 00|35 00 00 16 00 00 13 00 ..9..8.. 5.......
Apr 21 18:02:16 mail postfix/smtpd[5571]: 0010 00 0a ..
Apr 21 18:02:16 mail postfix/smtpd[5571]: read from 0808F9F8 [080A0F75] (89 bytes => -1 (0xFFFFFFFF))
Apr 21 18:02:16 mail postfix/smtpd[5571]: SSL_accept:error in SSLv2/v3 read client hello B


Any suggestions?

 

What's the output of

Code:

ls -la /etc/postfix

?

 

Hi falko,

Thank you for your reply. Actually, I'm still stuck with this problem and Googling for almost a week now.

Here's the result of command.

# ls -la /etc/postfix/
total 188
drwxr-xr-x 6 root root 4096 2008-04-14 15:05 .
drwxr-xr-x 68 root root 4096 2008-04-23 08:05 ..
-rw-r--r-- 1 root root 373 2002-04-25 16:13 dynamicmaps.cf
-rw-r--r-- 1 root root 24 2002-05-05 16:01 header_checks
-rw-r--r-- 1 root root 12288 2002-05-05 16:01 header_checks.db
-rw-r--r-- 1 root root 5852 2002-05-05 19:16 main.cf
-rw-r--r-- 1 root root 1830 2002-04-25 17:57 main.cf_orig
-rw-r--r-- 1 root root 5939 2008-04-14 15:05 master.cf
-rw-r--r-- 1 root root 6079 2008-04-14 15:05 master.cf-old.20080414
-rw-r--r-- 1 root root 596 2002-05-05 16:02 mime_checks
-rw-r--r-- 1 root root 12288 2002-05-05 16:02 mime_checks.db
-rw-r--r-- 1 root root 249 2002-04-25 17:39 mysql_virtual_alias_maps.cf
-rw-r--r-- 1 root root 567 2002-04-25 17:50 mysql_virtual_domains_maps.cf
-rw------- 1 root root 43 2002-04-26 00:31 mysql_virtual_domains_maps.cf.sav e
-rw-r--r-- 1 root root 274 2002-04-25 17:51 mysql_virtual_mailbox_limit_maps. cf
-rw-r--r-- 1 root root 307 2002-04-25 17:52 mysql_virtual_mailbox_maps.cf
-rw-r--r-- 1 root root 272 2002-04-25 17:53 mysql_virtual_transports.cf
-rwxr-xr-x 1 root root 10312 2008-04-14 15:04 postfix-chroot.sh
-rw-r--r-- 1 root root 17975 2007-03-21 19:17 postfix-files
-rwxr-xr-x 1 root root 6840 2007-03-21 19:17 postfix-script
-rwxr-xr-x 1 root root 22239 2007-03-21 19:17 post-install
drwxr-xr-x 2 root root 4096 2002-05-05 16:31 procmail
drwxr-xr-x 2 root root 4096 2002-05-05 16:53 sasl
drwxr-xr-x 2 root root 4096 2008-04-14 15:20 signature
-rw-r--r-- 1 root root 140 2002-05-05 16:03 transport
-rw-r--r-- 1 root root 12288 2002-05-05 16:03 transport.db
drwxr-xr-x 2 root root 4096 2002-05-05 18:59 vmailsql

Any suggestions?

TIA

 

You're using

Code:

smtpd_tls_cert_file = /etc/postfix/ssl/smtpd.cert
smtpd_tls_key_file = /etc/postfix/ssl/smtpd.key
smtpd_tls_CAfile = /etc/postfix/ssl/cacert.pem

in your main.cf, but /etc/postfix/ssl doesn't exist...

 

Hi falco,

I corrected the directory location as indicated. But the same error exists.

TIA

 

Did you also create the SSL certs?