Hi all,
after upgrade from some 2.0 version to 2.2.19 (debian) i face map login
problems:
# doveconf -n
# 2.2.19 (ca91d540fd87): /etc/dovecot/dovecot.conf
# Pigeonhole version 0.4.9
# OS: Linux 2.6.32-5-amd64 x86_64 Debian 8.2 ext4
auth_debug = yes
auth_debug_passwords = yes
auth_verbose = yes
auth_verbose_passwords = plain
debug_log_path = /var/log/dovecot-debug.log
hostname = test.my.domain.de
info_log_path = /var/log/dovecot.log
mail_access_groups = smmta
mail_debug = yes
mail_location =
mbox:/extra/mail/mbox.dir/%u/mailboxes:DIRNAME=mBoX-MeSsAgEs:INDEX=/extra/mail/mbox.dir/%u/index:CONTROL=/extra/mail/mbox.dir/%u/control:INBOX=/extra/mail/%u
mail_plugins = quota
mail_privileged_group = smmta
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 index ihave duplicate
namespace inbox {
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 {
driver = pam
}
plugin {
mail_log_events = delete undelete expunge copy mailbox_delete mailbox_rename
flag_change append
quota = fs:User quota
quota_rule = *:storage=1G
quota_rule2 = Trash:storage=+100M
quota_warning = storage=95%% quota-warning 95 %u
quota_warning2 = storage=80%% quota-warning 80 %u
sieve = file:~/sieve;active=~/.dovecot.sieve
}
postmaster_address = postmaster at my.domain.de
protocols = " imap sieve pop3"
quota_full_tempfail = yes
ssl = required
ssl_cert = </etc/ssl/StartCom/test.my.domain.pem
ssl_cipher_list =
EECDH+ECDSA+AESGCM:EECDH+aRSA+AESGCM:EECDH+ECDSA+SHA256:EECDH+aRSA+RC4:EDH+aRSA
EECDH RC4:!aNULL:!eNULL:!LOW:!3DES:!MD5:!EXP:!PSK:!SRP:!DSS
ssl_key = </etc/ssl/StartCom/test.my.domain.key
ssl_prefer_server_ciphers = yes
ssl_protocols = !SSLv2 !SSLv3
userdb {
driver = passwd
}
verbose_ssl = yes
protocol lda {
mail_plugins =
}
When I try to log in with openssl:
$ openssl s_client -connect test.familie-rust.de:993
CONNECTED(00000003)
depth=1 C = IL, O = StartCom Ltd., OU = Secure Digital Certificate Signing, CN =
StartCom Class 1 Primary Intermediate Server CA
verify error:num=20:unable to get local issuer certificate
---
Certificate chain
0 s:/C=DE/CN=test.my.domain.de/emailAddress=postmaster at my.domain.de
i:/C=IL/O=StartCom Ltd./OU=Secure Digital Certificate Signing/CN=StartCom
Class 1 Primary Intermediate Server CA
1 s:/C=IL/O=StartCom Ltd./OU=Secure Digital Certificate Signing/CN=StartCom
Class 1 Primary Intermediate Server CA
i:/C=IL/O=StartCom Ltd./OU=Secure Digital Certificate Signing/CN=StartCom
Certification Authority
---
Server certificate
-----BEGIN CERTIFICATE??
(?)
-----END CERTIFICATE-----
subject=/C=DE/CN=test.my.domain.de/emailAddress=postmaster at my.domain.de
issuer=/C=IL/O=StartCom Ltd./OU=Secure Digital Certificate Signing/CN=StartCom
Class 1 Primary Intermediate Server CA
---
No client certificate CA names sent
Peer signing digest: SHA512
Server Temp Key: ECDH, P-384, 384 bits
---
SSL handshake has read 4328 bytes and written 506 bytes
---
New, TLSv1/SSLv3, Cipher is ECDHE-RSA-AES256-GCM-SHA384
Server public key is 4096 bit
Secure Renegotiation IS supported
Compression: NONE
Expansion: NONE
No ALPN negotiated
SSL-Session:
Protocol : TLSv1.2
Cipher : ECDHE-RSA-AES256-GCM-SHA384
Session-ID: B0...5B
Session-ID-ctx:
Master-Key: 59D...EC0
Key-Arg : None
PSK identity: None
PSK identity hint: None
SRP username: None
TLS session ticket lifetime hint: 300 (seconds)
TLS session ticket:
0000 - 35 47 73 57 22 45 21 7d-fe ea a4 36 f1 35 76 3a 5GsW"E!}?6.5v:
(?)
Start Time: 1447309592
Timeout : 300 (sec)
Verify return code: 20 (unable to get local issuer certificate)
---
* OK [CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE IDLE
AUTH=PLAIN] Dovecot ready.
01 login frank myPassword
* BYE Internal error occurred. Refer to server log for more information.
closed
And in the log files I find following information:
dovecot.log
Nov 12 07:47:27 imap-login: Info: Login: user=<frank>, method=PLAIN,
rip=134.169.39.105, lip=134.169.39.22, mpid=9475, TLS, session=<...>
dovecot-debug.log:
Nov 12 07:47:27 imap-login: Debug: SSL: elliptic curve secp384r1 will be used
for ECDH and ECDHE key exchanges
Nov 12 07:47:27 auth: Debug: auth client connected (pid=11158)
Nov 12 07:47:27 imap-login: Debug: SSL: where=0x10, ret=1: before/accept
initialization [134.169.39.105]
Nov 12 07:47:27 imap-login: Debug: SSL: where=0x2001, ret=1: before/accept
initialization [134.169.39.105]
Nov 12 07:47:27 imap-login: Debug: SSL: where=0x2001, ret=1: unknown state
[134.169.39.105]
Nov 12 07:47:27 imap-login: Debug: SSL: where=0x2001, ret=1: unknown state
[134.169.39.105]
Nov 12 07:47:27 imap-login: Debug: SSL: where=0x2001, ret=1: unknown state
[134.169.39.105]
Nov 12 07:47:27 imap-login: Debug: SSL: where=0x2001, ret=1: unknown state
[134.169.39.105]
Nov 12 07:47:27 imap-login: Debug: SSL: where=0x2001, ret=1: unknown state
[134.169.39.105]
Nov 12 07:47:27 imap-login: Debug: SSL: where=0x2001, ret=1: unknown state
[134.169.39.105]
Nov 12 07:47:27 imap-login: Debug: SSL: where=0x2002, ret=-1: unknown state
[134.169.39.105]
Nov 12 07:47:27 imap-login: Debug: SSL: where=0x2002, ret=-1: unknown state
[134.169.39.105]
Nov 12 07:47:27 imap-login: Debug: SSL: where=0x2001, ret=1: unknown state
[134.169.39.105]
Nov 12 07:47:27 imap-login: Debug: SSL: where=0x2002, ret=-1: unknown state
[134.169.39.105]
Nov 12 07:47:27 imap-login: Debug: SSL: where=0x2001, ret=1: unknown state
[134.169.39.105]
Nov 12 07:47:27 imap-login: Debug: SSL: where=0x2001, ret=1: unknown state
[134.169.39.105]
Nov 12 07:47:27 imap-login: Debug: SSL: where=0x2001, ret=1: unknown state
[134.169.39.105]
Nov 12 07:47:27 imap-login: Debug: SSL: where=0x2001, ret=1: unknown state
[134.169.39.105]
Nov 12 07:47:27 imap-login: Debug: SSL: where=0x20, ret=1: SSL negotiation
finished successfully [134.169.39.105]
Nov 12 07:47:27 imap-login: Debug: SSL: where=0x2002, ret=1: SSL negotiation
finished successfully [134.169.39.105]
Nov 12 07:47:27 auth: Debug: client in: AUTH 1 PLAIN service=imap secured
session=QkLwUFIkXsCGqSdp lip=134.169.39.22 rip=134.169.39.105 lport=993
rport=49246 resp=xxxx (previous base64 data removed)
Nov 12 07:47:27 auth-worker(11140): Debug: pam(frank,134.169.39.105): lookup
service=dovecot
Nov 12 07:47:27 auth-worker(11140): Debug: pam(frank,134.169.39.105): #1/1
style=1 msg=Password:
Nov 12 07:47:27 auth: Debug: client passdb out: OK 1 user=frank
Nov 12 07:47:27 auth: Debug: master in: REQUEST 3038248961 11158 1
4e2362c2872f9288b7c8c3ebd8469620 session_pid=11159 request_auth_token
Nov 12 07:47:27 auth-worker(11140): Debug: pam(frank,134.169.39.105): lookup
Nov 12 07:47:27 auth: Debug: master userdb out: USER 3038248961 frank
system_groups_user=frank uid=1000 gid=100 home=/home/frank
auth_token=1e04d2c61fb327ec14c1e54ff678d73a325d20bf
Nov 12 07:47:27 imap(frank): Debug: Loading modules from directory:
/usr/lib/dovecot/modules
Nov 12 07:47:27 imap(frank): Debug: Module loaded:
/usr/lib/dovecot/modules/lib10_quota_plugin.so
Nov 12 07:47:27 imap(frank): Debug: Effective uid=1000, gid=100,
home=/home/frank
Nov 12 07:47:27 imap(frank): Debug: Quota root: name=User quota backend=fs
argsNov 12 07:47:27 imap(frank): Debug: Quota rule: root=User quota mailbox=*
bytes=1073741824 messages=0
Nov 12 07:47:27 imap(frank): Debug: Quota rule: root=User quota mailbox=Trash
bytes=+104857600 messages=0
Nov 12 07:47:27 imap(frank): Debug: Quota warning: bytes=1020054732 (95%)
messages=0 reverse=no command=quota-warning 95 frank
Nov 12 07:47:27 imap(frank): Debug: Quota warning: bytes=858993459 (80%)
messages=0 reverse=no command=quota-warning 80 frank
Nov 12 07:47:27 imap(frank): Debug: Quota grace: root=User quota bytes=107374182
(10%)
Nov 12 07:47:27 imap(frank): Debug: Namespace inbox: type=private, prefix=,
sep=, inbox=no, hidden=no, list=yes, subscriptions=yes
location=mbox:/extra/mail/mbox.dir/frank/mailboxes:DIRNAME=mBoX-MeSsAgEs:INDEX=/extra/mail/mbox.dir/frank/index:CONTROL=/extra/mail/mbox.dir/frank/control:INBOX=/extra/mail/frank
Nov 12 07:47:27 imap(frank): Debug: fs:
root=/extra/mail/mbox.dir/frank/mailboxes,
index=/extra/mail/mbox.dir/frank/index, indexpvt=,
control=/extra/mail/mbox.dir/frank/control, inbox=/extra/mail/frank, altNov 12
07:47:27 imap(frank): Debug: fs quota add mailbox dir =
/extra/mail/mbox.dir/frank/mailboxes
Nov 12 07:47:27 imap(frank): Debug: fs quota block device =
/dev/mapper/ownCloudVG-ownCloudData
Nov 12 07:47:27 imap(frank): Debug: fs quota mount point = /extra
Nov 12 07:47:27 imap(frank): Debug: fs quota mount type = ext4
Nov 12 07:47:27 imap-login: Debug: SSL alert: close notify [134.169.39.105]
What could cause the problem?
The problem is not quota related (I enhanced the allowed quota and got the same
results)
best regards,
Frank