[Dovecot] Installing Dovecot on Gentoo

Christian Rößner cr at sys4.de
Sun Jan 13 16:46:54 EET 2013


Hi,

I have an already working dovecot server on Ubuntu 10.04 with self-created packages version 2.1.13. This setup is working prefect. Now that I do not wish to continue using Ubuntu (to much work for Upgrading), I decided to switch to Gentoo, as I had made best experiences in the past… 

I have installed Dovecot on Gentoo and I copied over all my configs and certs and stuff. Also created a user vmail with identical uid/gid and also checked all permissions for the certificate stuff.

Dovecot starts. I also can connect to it. But when trying to login, I get errors:

-------------------------------------------------------
telnet localhost 143
Trying ::1...
Connected to localhost.
Escape character is '^]'.
* OK [CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE IDLE STARTTLS AUTH=PLAIN AUTH=LOGIN AUTH=CRAM-MD5 AUTH=DIGEST-MD5 AUTH=NTLM] Dovecot ready.
. login croessner <hiddenpw>
. NO [UNAVAILABLE] Temporary authentication failure. [mx0:2013-01-13 14:24:02]

-------------------------------------------------------

In the logs it looks like this:

-------------------------------------------------------
Jan 13 15:22:30 mx0 dovecot: master: Dovecot v2.1.13 starting up (core dumps disabled)
Jan 13 15:23:11 mx0 dovecot: auth: Debug: Loading modules from directory: /usr/lib64/dovecot/auth
Jan 13 15:23:11 mx0 dovecot: auth: Debug: passwd-file /etc/dovecot/master-users: Read 1 users in 0 secs
Jan 13 15:23:11 mx0 dovecot: auth: Error: ldap_extended_operation_s
Jan 13 15:23:11 mx0 dovecot: auth: Error: ldap_extended_operation
Jan 13 15:23:11 mx0 dovecot: auth: Error: ldap_send_initial_request
Jan 13 15:23:11 mx0 dovecot: auth: Error: ldap_new_connection 1 1 0
Jan 13 15:23:11 mx0 dovecot: auth: Error: ldap_int_open_connection
Jan 13 15:23:11 mx0 dovecot: auth: Error: ldap_connect_to_host: TCP db.roessner-net.de:389
Jan 13 15:23:11 mx0 dovecot: auth: Error: ldap_new_socket: 17
Jan 13 15:23:11 mx0 dovecot: auth: Error: ldap_prepare_socket: 17
Jan 13 15:23:11 mx0 dovecot: auth: Error: ldap_connect_to_host: Trying 193.239.107.37:389
Jan 13 15:23:11 mx0 dovecot: auth: Error: ldap_pvt_connect: fd: 17 tm: -1 async: 0
Jan 13 15:23:11 mx0 dovecot: auth: Error: ldap_open_defconn: successful
Jan 13 15:23:11 mx0 dovecot: auth: Error: ldap_send_server_request
Jan 13 15:23:11 mx0 dovecot: auth: Error: ldap_result ld 0x35d6dd481c0 msgid 1
Jan 13 15:23:11 mx0 dovecot: auth: Error: wait4msg ld 0x35d6dd481c0 msgid 1 (infinite timeout)
Jan 13 15:23:11 mx0 dovecot: auth: Error: wait4msg continue ld 0x35d6dd481c0 msgid 1 all 1
Jan 13 15:23:11 mx0 dovecot: auth: Error: ** ld 0x35d6dd481c0 Connections:
Jan 13 15:23:11 mx0 dovecot: auth: Error: * host: db.roessner-net.de  port: 389  (default)
Jan 13 15:23:11 mx0 dovecot: auth: Error:   refcnt: 2  status: Connected
Jan 13 15:23:11 mx0 dovecot: auth: Error:   last used: Sun Jan 13 15:23:11 2013
Jan 13 15:23:11 mx0 dovecot: auth: Error: 
Jan 13 15:23:11 mx0 dovecot: auth: Error: 
Jan 13 15:23:11 mx0 dovecot: auth: Error: ** ld 0x35d6dd481c0 Outstanding Requests:
Jan 13 15:23:11 mx0 dovecot: auth: Error:  * msgid 1,  origid 1, status InProgress
Jan 13 15:23:11 mx0 dovecot: auth: Error:    outstanding referrals 0, parent count 0
Jan 13 15:23:11 mx0 dovecot: auth: Error:   ld 0x35d6dd481c0 request count 1 (abandoned 0)
Jan 13 15:23:11 mx0 dovecot: auth: Error: ** ld 0x35d6dd481c0 Response Queue:
Jan 13 15:23:11 mx0 dovecot: auth: Error:    Empty
Jan 13 15:23:11 mx0 dovecot: auth: Error:   ld 0x35d6dd481c0 response count 0
Jan 13 15:23:11 mx0 dovecot: auth: Error: ldap_chkResponseList ld 0x35d6dd481c0 msgid 1 all 1
Jan 13 15:23:11 mx0 dovecot: auth: Error: ldap_chkResponseList returns ld 0x35d6dd481c0 NULL
Jan 13 15:23:11 mx0 dovecot: auth: Error: ldap_int_select
Jan 13 15:23:11 mx0 dovecot: auth: Error: read1msg: ld 0x35d6dd481c0 msgid 1 all 1
Jan 13 15:23:11 mx0 dovecot: auth: Error: read1msg: ld 0x35d6dd481c0 msgid 1 message type extended-result
Jan 13 15:23:11 mx0 dovecot: auth: Error: read1msg: ld 0x35d6dd481c0 0 new referrals
Jan 13 15:23:11 mx0 dovecot: auth: Error: read1msg:  mark request completed, ld 0x35d6dd481c0 msgid 1
Jan 13 15:23:11 mx0 dovecot: auth: Error: request done: ld 0x35d6dd481c0 msgid 1
Jan 13 15:23:11 mx0 dovecot: auth: Error: res_errno: 0, res_error: <>, res_matched: <>
Jan 13 15:23:11 mx0 dovecot: auth: Error: ldap_free_request (origid 1, msgid 1)
Jan 13 15:23:11 mx0 dovecot: auth: Error: ldap_parse_extended_result
Jan 13 15:23:11 mx0 dovecot: auth: Error: ldap_parse_result
Jan 13 15:23:11 mx0 dovecot: auth: Error: ldap_msgfree


Jan 13 15:23:11 mx0 dovecot: auth: Error: TLS: could not use key file `/etc/ssl/private/mx0.roessner-net.de.key.pem'.
Jan 13 15:23:11 mx0 dovecot: auth: Error: TLS: error:0200100D:system library:fopen:Permission denied bss_file.c:398
Jan 13 15:23:11 mx0 dovecot: auth: Error: TLS: error:20074002:BIO routines:FILE_CTRL:system lib bss_file.c:400
Jan 13 15:23:11 mx0 dovecot: auth: Error: TLS: error:140B0002:SSL routines:SSL_CTX_use_PrivateKey_file:system lib ssl_rsa.c:648


Jan 13 15:23:11 mx0 dovecot: auth: Error: ldap_err2string
Jan 13 15:23:11 mx0 dovecot: auth: Error: LDAP: ldap_start_tls_s() failed: Connect error
Jan 13 15:23:11 mx0 dovecot: auth: Error: ldap_extended_operation_s
Jan 13 15:23:11 mx0 dovecot: auth: Error: ldap_extended_operation
Jan 13 15:23:11 mx0 dovecot: auth: Error: ldap_send_initial_request
Jan 13 15:23:11 mx0 dovecot: auth: Error: ldap_send_server_request
Jan 13 15:23:11 mx0 dovecot: auth: Error: ldap_result ld 0x35d6dd481c0 msgid 2
Jan 13 15:23:11 mx0 dovecot: auth: Error: wait4msg ld 0x35d6dd481c0 msgid 2 (infinite timeout)
Jan 13 15:23:11 mx0 dovecot: auth: Error: wait4msg continue ld 0x35d6dd481c0 msgid 2 all 1
Jan 13 15:23:11 mx0 dovecot: auth: Error: ** ld 0x35d6dd481c0 Connections:
Jan 13 15:23:11 mx0 dovecot: auth: Error: * host: db.roessner-net.de  port: 389  (default)
Jan 13 15:23:11 mx0 dovecot: auth: Error:   refcnt: 2  status: Connected
Jan 13 15:23:11 mx0 dovecot: auth: Error:   last used: Sun Jan 13 15:23:11 2013
Jan 13 15:23:11 mx0 dovecot: auth: Error: 
Jan 13 15:23:11 mx0 dovecot: auth: Error: 
Jan 13 15:23:11 mx0 dovecot: auth: Error: ** ld 0x35d6dd481c0 Outstanding Requests:
Jan 13 15:23:11 mx0 dovecot: auth: Error:  * msgid 2,  origid 2, status InProgress
Jan 13 15:23:11 mx0 dovecot: auth: Error:    outstanding referrals 0, parent count 0
Jan 13 15:23:11 mx0 dovecot: auth: Error:   ld 0x35d6dd481c0 request count 1 (abandoned 0)
Jan 13 15:23:11 mx0 dovecot: auth: Error: ** ld 0x35d6dd481c0 Response Queue:
Jan 13 15:23:11 mx0 dovecot: auth: Error:    Empty
Jan 13 15:23:11 mx0 dovecot: auth: Error:   ld 0x35d6dd481c0 response count 0
Jan 13 15:23:11 mx0 dovecot: auth: Error: ldap_chkResponseList ld 0x35d6dd481c0 msgid 2 all 1
Jan 13 15:23:11 mx0 dovecot: auth: Error: ldap_chkResponseList returns ld 0x35d6dd481c0 NULL
Jan 13 15:23:11 mx0 dovecot: auth: Error: ldap_int_select
Jan 13 15:23:11 mx0 dovecot: auth: Error: read1msg: ld 0x35d6dd481c0 msgid 2 all 1
Jan 13 15:23:11 mx0 dovecot: auth: Error: ldap_err2string
Jan 13 15:23:11 mx0 dovecot: auth: Error: LDAP: ldap_start_tls_s() failed: Can't contact LDAP server
Jan 13 15:23:11 mx0 dovecot: auth: Debug: auth client connected (pid=24045)
Jan 13 15:24:00 mx0 dovecot: auth: Debug: client in: AUTH#0111#011PLAIN#011service=imap#011secured#011session=YAanRyzTOAAAAAAAAAAAAAAAAAAAAAAB#011lip=::1#011rip=::1#011lport=143#011rport=59960#011resp=<hidden>
Jan 13 15:24:00 mx0 dovecot: auth: Error: ldap_extended_operation_s
Jan 13 15:24:00 mx0 dovecot: auth: Error: ldap_extended_operation
Jan 13 15:24:00 mx0 dovecot: auth: Error: ldap_send_initial_request
Jan 13 15:24:00 mx0 dovecot: auth: Error: ldap_send_server_request
Jan 13 15:24:00 mx0 dovecot: auth: Error: ldap_err2string
Jan 13 15:24:00 mx0 dovecot: auth: Error: LDAP: ldap_start_tls_s() failed: Can't contact LDAP server
Jan 13 15:24:02 mx0 dovecot: auth: Debug: client passdb out: FAIL#0111#011user=croessner#011temp
Jan 13 15:26:11 mx0 dovecot: imap-login: Disconnected: Inactivity (auth failed, 1 attempts in 131 secs): user=<croessner>, method=PLAIN, rip=::1, lip=::1, secured, session=<YAanRyzTOAAAAAAAAAAAAAAAAAAAAAAB>
Jan 13 15:27:11 mx0 dovecot: auth: Error: ldap_unbind
Jan 13 15:27:11 mx0 dovecot: auth: Error: ldap_free_request (origid 2, msgid 2)
Jan 13 15:27:11 mx0 dovecot: auth: Error: ldap_free_connection 1 1
Jan 13 15:27:11 mx0 dovecot: auth: Error: ldap_free_connection: actually freed
-------------------------------------------------------

I checked if Dovecot would even try to access the key:

-------------------------------------------------------
inotifywait -m -r --format '%:e %f' /etc/ssl
Setting up watches.  Beware: since -r was given, this may take a while!
Watches established.
OPEN mail.roessner-net.de.pem
ACCESS mail.roessner-net.de.pem
CLOSE_NOWRITE:CLOSE mail.roessner-net.de.pem
OPEN mail.roessner-net.de.key.pem
ACCESS mail.roessner-net.de.key.pem
CLOSE_NOWRITE:CLOSE mail.roessner-net.de.key.pem
OPEN SSL123_CA_Bundle.pem
ACCESS SSL123_CA_Bundle.pem
CLOSE_NOWRITE:CLOSE SSL123_CA_Bundle.pem
OPEN mail.roessner-net.de.pem
ACCESS mail.roessner-net.de.pem
ACCESS mail.roessner-net.de.pem
ACCESS mail.roessner-net.de.pem
ACCESS mail.roessner-net.de.pem
ACCESS mail.roessner-net.de.pem
CLOSE_NOWRITE:CLOSE mail.roessner-net.de.pem
OPEN mail.roessner-net.de.key.pem
ACCESS mail.roessner-net.de.key.pem
ACCESS mail.roessner-net.de.key.pem
CLOSE_NOWRITE:CLOSE mail.roessner-net.de.key.pem
OPEN SSL123_CA_Bundle.pem
ACCESS SSL123_CA_Bundle.pem
ACCESS SSL123_CA_Bundle.pem
ACCESS SSL123_CA_Bundle.pem
ACCESS SSL123_CA_Bundle.pem
CLOSE_NOWRITE:CLOSE SSL123_CA_Bundle.pem
OPEN ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
ACCESS ca-certificates.crt
CLOSE_NOWRITE:CLOSE ca-certificates.crt
OPEN mx0.roessner-net.de.pem
ACCESS mx0.roessner-net.de.pem
CLOSE_NOWRITE:CLOSE mx0.roessner-net.de.pem
OPEN openssl.cnf
ACCESS openssl.cnf
ACCESS openssl.cnf
ACCESS openssl.cnf
CLOSE_NOWRITE:CLOSE openssl.cnf
OPEN openssl.cnf
ACCESS openssl.cnf
ACCESS openssl.cnf
ACCESS openssl.cnf
CLOSE_NOWRITE:CLOSE openssl.cnf
-------------------------------------------------------

I can not find any line talking about mx0.roessner-net.de.key.pem. The file exists and has proper permissions:

-------------------------------------------------------
l /etc/ssl/private/
total 16
drwxr-s---+ 2 root ssl-cert 4096 Jan 12 19:29 ./
drwxr-xr-x  8 root root     4096 Jan 13 15:26 ../
-rw-r--r--  1 root root        0 Dec 10 18:14 .keep_dev-libs_openssl-0
-r--r-----  1 root ssl-cert 1679 Jan 12 17:23 mail.roessner-net.de.key.pem
-r--r-----+ 1 root ssl-cert  887 Jan 12 17:14 mx0.roessner-net.de.key.pem

getfacl /etc/ssl/private/ /etc/ssl/private/mx0.roessner-net.de.key.pem 
getfacl: Removing leading '/' from absolute path names
# file: etc/ssl/private/
# owner: root
# group: ssl-cert
# flags: -s-
user::rwx
user:amavis:r-x
group::---
mask::r-x
other::---

# file: etc/ssl/private/mx0.roessner-net.de.key.pem
# owner: root
# group: ssl-cert
user::r--
user:amavis:r-x			#effective:r--
group::r--
mask::r--
other::---
-------------------------------------------------------

Here is my doveconf -n:

-------------------------------------------------------
# 2.1.13: /etc/dovecot/dovecot.conf
# OS: Linux 3.7.0-hardened x86_64 Gentoo Base System release 2.1 
auth_debug = yes
auth_master_user_separator = *
auth_mechanisms = plain login cram-md5 digest-md5 ntlm
auth_verbose = yes
hostname = mail.roessner-net.de
lda_mailbox_autocreate = yes
lda_mailbox_autosubscribe = yes
mail_access_groups = vmail
mail_attachment_dir = /var/mail/virtual/copymail/attachments
mail_debug = yes
mail_gid = vmail
mail_location = mdbox:~/mdbox
mail_plugins = autocreate quota acl fts fts_solr zlib
mail_privileged_group = mail
mail_uid = vmail
managesieve_notify_capability = mailto
managesieve_sieve_capability = fileinto reject envelope encoded-character vacation subaddress comparator-i;ascii-numeric relational regex imap4flags copy include variables body enotify environment mailbox date ihave
mdbox_rotate_size = 128 M
namespace {
  list = children
  location = mdbox:%%h/mdbox
  prefix = shared/%%u/
  separator = /
  subscriptions = no
  type = shared
}
namespace inbox {
  inbox = yes
  location = 
  mailbox "Deleted Messages" {
    special_use = \Trash
  }
  mailbox Drafts {
    special_use = \Drafts
  }
  mailbox Junk-E-Mail {
    special_use = \Junk
  }
  mailbox Junk {
    special_use = \Junk
  }
  mailbox Sent {
    special_use = \Sent
  }
  mailbox "Sent Messages" {
    special_use = \Sent
  }
  mailbox Trash {
    special_use = \Trash
  }
  mailbox junkmail {
    special_use = \Junk
  }
  prefix = 
  separator = /
  type = private
}
passdb {
  args = /etc/dovecot/master-users
  driver = passwd-file
  master = yes
  pass = yes
}
passdb {
  args = /etc/dovecot/dovecot-ldap.conf.ext
  driver = ldap
}
plugin {
  acl = vfile
  acl_shared_dict = file:/var/mail/virtual/shared-mailboxes.db
  autocreate = Trash
  autocreate2 = Sent
  autocreate3 = Drafts
  autocreate4 = junkmail
  autosubscribe = Trash
  autosubscribe2 = Sent
  autosubscribe3 = Drafts
  autosubscribe4 = junkmail
  fts = solr
  fts_solr = break-imap-search url=http://localhost:8080/solr/
  quota = dict:User quota::file:%h/mdbox/dovecot-quota
  quota_rule = *:storage=300M:messages=20000
  quota_warning = storage=95%% quota-warning 95 %u
  quota_warning2 = storage=80%% quota-warning 80 %u
  sieve = ~/.dovecot.sieve
  sieve_dir = ~/sieve
  zlib_save = gz
  zlib_save_level = 6
}
protocols = imap pop3 lmtp sieve
service auth-worker {
  extra_groups = ssl-cert
  unix_listener auth-worker {
    mode = 0600
    user = vmail
  }
  user = vmail
}
service auth {
  extra_groups = ssl-cert
  unix_listener auth-userdb {
    mode = 0600
    user = vmail
  }
  user = vmail
}
service dict {
  unix_listener dict {
    mode = 0600
    user = vmail
  }
}
service lmtp {
  unix_listener /var/spool/postfix/private/lmtp-dovecot {
    group = postfix
    mode = 0666
    user = postfix
  }
}
service quota-warning {
  executable = script /usr/local/bin/quota-warning.sh
  unix_listener quota-warning {
    user = vmail
  }
  user = dovecot
}
ssl_ca = </etc/ssl/certs/SSL123_CA_Bundle.pem
ssl_cert = </etc/ssl/certs/mail.roessner-net.de.pem
ssl_key = </etc/ssl/private/mail.roessner-net.de.key.pem
userdb {
  args = /etc/dovecot/dovecot-ldap.conf.ext
  driver = ldap
}
verbose_proctitle = yes
verbose_ssl = yes
protocol lmtp {
  mail_plugins = autocreate quota acl fts fts_solr zlib sieve
}
protocol imap {
  imap_client_workarounds = tb-extra-mailbox-sep tb-lsub-flags
  mail_max_userip_connections = 50
  mail_plugins = autocreate quota acl fts fts_solr zlib imap_quota imap_acl imap_zlib
}
-------------------------------------------------------

LDAP looks like this:

-------------------------------------------------------
uris = ldap://db.roessner-net.de/ ldap://roessner1.roessner-net.de/
sasl_bind = yes
sasl_mech = EXTERNAL
tls = yes
tls_ca_cert_file = /etc/ssl/certs/ca-certificates.crt
tls_cert_file = /etc/ssl/certs/mx0.roessner-net.de.pem
tls_key_file = /etc/ssl/private/mx0.roessner-net.de.key.pem
tls_require_cert = hard
debug_level = 7
base = ou=people,ou=it,dc=roessner-net,dc=de
user_attrs = rnsMSQuota=quota_rule=*:storage=%$,rnsMSMailboxHome=home
user_filter = (&(objectClass=rnsMSDovecotAccount)(|(rnsMSRecipientAddress=%u)(uniqueIdentifier=%u)))
pass_attrs = rnsMSDeliverToAddress=user,userPassword=password
pass_filter = (&(objectClass=rnsMSDovecotAccount)(|(rnsMSRecipientAddress=%u)(uniqueIdentifier=%u))(rnsMSEnableDovecot=TRUE))
iterate_attrs = rnsMSDovecotUser=user
iterate_filter = (objectClass=rnsMSDovecotAccount)
default_pass_scheme = PLAIN
-------------------------------------------------------

Some portage information

-------------------------------------------------------
[ebuild   R    ] net-nds/openldap-2.4.30  USE="berkdb crypt ipv6 minimal sasl ssl syslog tcpd -cxx -debug -experimental -gnutls -icu -iodbc -kerberos -odbc -overlays -perl -samba (-selinux) -slp -smbkrb5passwd" 0 kB
[ebuild   R    ] dev-libs/cyrus-sasl-2.1.25-r3:2  USE="berkdb gdbm ldapdb openldap pam ssl urandom -authdaemond -java -kerberos -mysql -postgres -sample -sqlite -srp -static-libs" 0 kB
[ebuild   R   ~] net-mail/dovecot-2.1.13::croessner  USE="bzip2 caps imapc ipv6 ldap maildir managesieve mbox mdbox pam pop3c sdbox sieve solr sqlite ssl suid zlib -cydir -doc -kerberos -lucene -mysql -postgres (-selinux) -static-libs -vpopmail" 0 kB
-------------------------------------------------------

As you can see, I have spent some time on this without luck and currently I have no idea, what the problem is.

Any ideas on that?

Thanks in advance

-Christian Rößner

--
[*] sys4 AG

http://sys4.de, +49 (89) 30 90 46 64
Franziskanerstraße 15, 81669 München

Sitz der Gesellschaft: München, Amtsgericht München: HRB 199263
Vorstand: Patrick Ben Koetter, Axel von der Ohe, Marc Schiffbauer
Aufsichtsratsvorsitzender: Joerg Heidrich




More information about the dovecot mailing list