Misleading SSL/TLS Log Messages

[Yahooguntu]

Hi all,

I think I've found a small bug in how Dovecot logs SSL/TLS info. Basically,
if I connect to the server using TLS, the logs have a lot of entries saying
I used SSLv3 (which is not allowed). Here's my system info:

OSX Yosemite (x86_64, HFS+)
Dovecot 2.2.15 (via Homebrew)
OpenSSL 0.9.8zd

The configuration (see below) disallows SSLv3, and if I try and connect
with OpenSSL to test that ("openssl s_client -connect localhost:993 -ssl3")
it fails as expected. If I do the same command, but with "-tls1" instead of
"-ssl3", I can connect and run IMAP commands. The problem is, if I open up
the Dovecot logs and look at the SSL log messages, they all say I used
SSLv3. As an example, this is a truncated log from when I connected to the
server and immediately did a LOGOUT:

14:50:59 : master: Warning: Killed with signal 15 (by pid=1 uid=0
code=unknown 0)
14:51:03 : master: Dovecot v2.2.15 starting up for imap, lmtp (core dumps
disabled)
14:51:13 : imap-login: Debug: SSL: elliptic curve secp384r1 will be used
for ECDH and ECDHE key exchanges
14:51:13 --- last message repeated 1 time ---
14:51:13 : imap-login: Debug: SSL: where=0x10, ret=1: before/accept
initialization [127.0.0.1]
14:51:13 : imap-login: Debug: SSL: where=0x2001, ret=1: before/accept
initialization [127.0.0.1]
14:51:13 : imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read client
hello A [127.0.0.1]
14:51:13 : imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write server
hello A [127.0.0.1]
14:51:13 : imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write
certificate A [127.0.0.1]
14:51:13 : imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write key
exchange A [127.0.0.1]
14:51:13 : imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write server
done A [127.0.0.1]
14:51:13 : imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 flush data
[127.0.0.1]
14:51:13 : imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read client
certificate A [127.0.0.1]
14:51:13 : imap-login: Debug: SSL: where=0x2002, ret=-1: SSLv3 read client
key exchange A [127.0.0.1]
14:51:13 --- last message repeated 1 time ---
14:51:13 : imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read client
key exchange A [127.0.0.1]
14:51:13 : imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read finished
A [127.0.0.1]
14:51:13 : imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write session
ticket A [127.0.0.1]
14:51:13 : imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write change
cipher spec A [127.0.0.1]
14:51:13 : imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write
finished A [127.0.0.1]
14:51:13 : imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 flush data
[127.0.0.1]
14:51:13 : imap-login: Debug: SSL: where=0x20, ret=1: SSL negotiation
finished successfully [127.0.0.1]
14:51:13 : imap-login: Debug: SSL: where=0x2002, ret=1: SSL negotiation
finished successfully [127.0.0.1]
14:51:19 : imap-login: Aborted login (no auth attempts in 6 secs): user=<>,
rip=127.0.0.1, lip=127.0.0.1, TLS, session=<QdX1YaIXTQB/AAAB>
14:51:19 : imap-login: Debug: SSL alert: close notify [127.0.0.1]

The second to last line, which indicates I never tried to log in, correctly
states that I used TLS. All the lines for SSL debugging, though, state I
used SSL or SSLv3.

This is a test setup, so it accepts any mail from @example.com addresses
over LMTP and allows any user to connect with the password
"staticpassword". Here's the output of "dovecot -n":

# 2.2.15: /usr/local/etc/dovecot/dovecot.conf
# OS: Darwin 14.3.0 x86_64  hfs
default_client_limit = 50
default_internal_user = _dovecot
default_login_user = _dovenull
default_process_limit = 10
listen = 127.0.0.1
mail_gid = admin
mail_location = mbox:/usr/local/etc/dovecot/mailboxes/%n
mail_uid = [my username]
namespace inbox {
  inbox = yes
  location =
  mailbox Drafts {
    special_use = \Drafts
  }
  mailbox Junk {
    special_use = \Junk
  }
  mailbox Sent {
    special_use = \Sent
  }
  mailbox "Sent Messages" {
    special_use = \Sent
  }
  mailbox Trash {
    special_use = \Trash
  }
  prefix =
}
passdb {
  args = password=staticpassword
  driver = static
}
postmaster_address = postmaster at example.com
protocols = imap lmtp
service lmtp {
  inet_listener lmtp {
    address = 127.0.0.1 ::1
    port = 24
  }
}
ssl = required
ssl_cert = </usr/local/etc/dovecot/ssl/cert.pem
ssl_key = </usr/local/etc/dovecot/ssl/key.pem
ssl_protocols = !SSLv2 !SSLv3
verbose_ssl = yes