I also keep on getting funny errors of dovecot EVEN THOUGH I authenticated successfully through SMTP (Dovecto SASL) ?!?!
Just for debugging this entire issue I set those parameters:
debug_level = -1 auth_verbose = yes auth_verbose_passwords = yes auth_debug = yes auth_debug_passwords = yes mail_debug = yes verbose_ssl = yes
cat /var/loca/maillog
Jan 26 12:08:22 WM-01 postfix/postfix-script[97931]: starting the
Postfix mail system
Jan 26 12:08:22 WM-01 postfix/master[97933]: daemon started -- version
1.0, configuration /usr/local/etc/postfix
Jan 26 12:08:22 WM-01 dovecot: master: Dovecot v2.2.15 starting up for
imap, pop3, lmtp
Jan 26 12:08:59 WM-01 postfix/smtpd[99014]: connect from
localhost[127.0.0.1]
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ldap_extended_operation_s
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ldap_extended_operation
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ldap_send_initial_request
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ldap_new_connection 1 1 0
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ldap_int_open_connection
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ldap_connect_to_host: TCP
127.0.0.1:389
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ldap_new_socket: 32
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ldap_prepare_socket: 32
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ldap_connect_to_host: Trying
127.0.0.1:389
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ldap_pvt_connect: fd: 32 tm:
-1 async: 0
Jan 26 12:08:59 WM-01 dovecot: auth: Error: attempting to connect:
Jan 26 12:08:59 WM-01 dovecot: auth: Error: connect success
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ldap_open_defconn: successful
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ldap_send_server_request
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ldap_result ld 0x1245e100
msgid 1
Jan 26 12:08:59 WM-01 dovecot: auth: Error: wait4msg ld 0x1245e100 msgid
1 (infinite timeout)
Jan 26 12:08:59 WM-01 dovecot: auth: Error: wait4msg continue ld
0x1245e100 msgid 1 all 1
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ** ld 0x1245e100 Connections:
Jan 26 12:08:59 WM-01 dovecot: auth: Error: * host: 127.0.0.1 port: 389
(default)
Jan 26 12:08:59 WM-01 dovecot: auth: Error: refcnt: 2 status: Connected
Jan 26 12:08:59 WM-01 dovecot: auth: Error: last used: Mon Jan 26
12:08:59 2015
Jan 26 12:08:59 WM-01 dovecot: auth: Error:
Jan 26 12:08:59 WM-01 dovecot: auth: Error:
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ** ld 0x1245e100 Outstanding
Requests:
Jan 26 12:08:59 WM-01 dovecot: auth: Error: * msgid 1, origid 1,
status InProgress
Jan 26 12:08:59 WM-01 dovecot: auth: Error: outstanding referrals 0,
parent count 0
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ld 0x1245e100 request
count 1 (abandoned 0)
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ** ld 0x1245e100 Response Queue:
Jan 26 12:08:59 WM-01 dovecot: auth: Error: Empty
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ld 0x1245e100 response count 0
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ldap_chkResponseList ld
0x1245e100 msgid 1 all 1
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ldap_chkResponseList returns
ld 0x1245e100 NULL
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ldap_int_select
Jan 26 12:08:59 WM-01 dovecot: auth: Error: read1msg: ld 0x1245e100
msgid 1 all 1
Jan 26 12:08:59 WM-01 dovecot: auth: Error: read1msg: ld 0x1245e100
msgid 1 message type extended-result
Jan 26 12:08:59 WM-01 dovecot: auth: Error: read1msg: ld 0x1245e100 0
new referrals
Jan 26 12:08:59 WM-01 dovecot: auth: Error: read1msg: mark request
completed, ld 0x1245e100 msgid 1
Jan 26 12:08:59 WM-01 dovecot: auth: Error: request done: ld 0x1245e100
msgid 1
Jan 26 12:08:59 WM-01 dovecot: auth: Error: res_errno: 0, res_error: <>,
res_matched: <>
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ldap_free_request (origid 1,
msgid 1)
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ldap_parse_extended_result
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ldap_parse_result
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ldap_msgfree
Jan 26 12:08:59 WM-01 dovecot: auth: Error: TLS trace:
SSL_connect:before/connect initialization
Jan 26 12:08:59 WM-01 dovecot: auth: Error: TLS trace:
SSL_connect:SSLv2/v3 write client hello A
Jan 26 12:08:59 WM-01 dovecot: auth: Error: TLS trace: SSL_connect:SSLv3
read server hello A
Jan 26 12:08:59 WM-01 dovecot: auth: Error: TLS certificate
verification: depth: 1, err: 0, subject: [...]
Jan 26 12:08:59 WM-01 dovecot: auth: Error: TLS certificate
verification: depth: 0, err: 0, subject: [...]
Jan 26 12:08:59 WM-01 dovecot: auth: Error: TLS trace: SSL_connect:SSLv3
read server certificate A
Jan 26 12:08:59 WM-01 dovecot: auth: Error: TLS trace: SSL_connect:SSLv3
read server certificate request A
Jan 26 12:08:59 WM-01 dovecot: auth: Error: TLS trace: SSL_connect:SSLv3
read server done A
Jan 26 12:08:59 WM-01 dovecot: auth: Error: TLS trace: SSL_connect:SSLv3
write client certificate A
Jan 26 12:08:59 WM-01 dovecot: auth: Error: TLS trace: SSL_connect:SSLv3
write client key exchange A
Jan 26 12:08:59 WM-01 dovecot: auth: Error: TLS trace: SSL_connect:SSLv3
write certificate verify A
Jan 26 12:08:59 WM-01 dovecot: auth: Error: TLS trace: SSL_connect:SSLv3
write change cipher spec A
Jan 26 12:08:59 WM-01 dovecot: auth: Error: TLS trace: SSL_connect:SSLv3
write finished A
Jan 26 12:08:59 WM-01 dovecot: auth: Error: TLS trace: SSL_connect:SSLv3
flush data
Jan 26 12:08:59 WM-01 dovecot: auth: Error: TLS trace: SSL_connect:SSLv3
read server session ticket A
Jan 26 12:08:59 WM-01 dovecot: auth: Error: TLS trace: SSL_connect:SSLv3
read finished A
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ldap_bind
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ldap_simple_bind
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ldap_sasl_bind
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ldap_send_initial_request
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ldap_send_server_request
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ldap_result ld 0x1245e100
msgid -1
Jan 26 12:08:59 WM-01 dovecot: auth: Error: wait4msg ld 0x1245e100 msgid
-1 (timeout 0 usec)
Jan 26 12:08:59 WM-01 dovecot: auth: Error: wait4msg continue ld
0x1245e100 msgid -1 all 0
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ** ld 0x1245e100 Connections:
Jan 26 12:08:59 WM-01 dovecot: auth: Error: * host: 127.0.0.1 port: 389
(default)
Jan 26 12:08:59 WM-01 dovecot: auth: Error: refcnt: 2 status: Connected
Jan 26 12:08:59 WM-01 dovecot: auth: Error: last used: Mon Jan 26
12:08:59 2015
Jan 26 12:08:59 WM-01 dovecot: auth: Error:
Jan 26 12:08:59 WM-01 dovecot: auth: Error:
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ** ld 0x1245e100 Outstanding
Requests:
Jan 26 12:08:59 WM-01 dovecot: auth: Error: * msgid 2, origid 2,
status InProgress
Jan 26 12:08:59 WM-01 dovecot: auth: Error: outstanding referrals 0,
parent count 0
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ld 0x1245e100 request
count 1 (abandoned 0)
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ** ld 0x1245e100 Response Queue:
Jan 26 12:08:59 WM-01 dovecot: auth: Error: Empty
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ld 0x1245e100 response count 0
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ldap_chkResponseList ld
0x1245e100 msgid -1 all 0
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ldap_chkResponseList returns
ld 0x1245e100 NULL
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ldap_int_select
Jan 26 12:08:59 WM-01 dovecot: auth: Error: read1msg: ld 0x1245e100
msgid -1 all 0
Jan 26 12:08:59 WM-01 dovecot: auth: Error: read1msg: ld 0x1245e100
msgid 2 message type bind
Jan 26 12:08:59 WM-01 dovecot: auth: Error: read1msg: ld 0x1245e100 0
new referrals
Jan 26 12:08:59 WM-01 dovecot: auth: Error: read1msg: mark request
completed, ld 0x1245e100 msgid 2
Jan 26 12:08:59 WM-01 dovecot: auth: Error: request done: ld 0x1245e100
msgid 2
Jan 26 12:08:59 WM-01 dovecot: auth: Error: res_errno: 0, res_error: <>,
res_matched: <>
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ldap_free_request (origid 2,
msgid 2)
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ldap_parse_result
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ldap_msgfree
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ldap_result ld 0x1245e100
msgid -1
Jan 26 12:08:59 WM-01 dovecot: auth: Error: wait4msg ld 0x1245e100 msgid
-1 (timeout 0 usec)
Jan 26 12:08:59 WM-01 dovecot: auth: Error: wait4msg continue ld
0x1245e100 msgid -1 all 0
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ** ld 0x1245e100 Connections:
Jan 26 12:08:59 WM-01 dovecot: auth: Error: * host: 127.0.0.1 port: 389
(default)
Jan 26 12:08:59 WM-01 dovecot: auth: Error: refcnt: 1 status: Connected
Jan 26 12:08:59 WM-01 dovecot: auth: Error: last used: Mon Jan 26
12:08:59 2015
Jan 26 12:08:59 WM-01 dovecot: auth: Error:
Jan 26 12:08:59 WM-01 dovecot: auth: Error:
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ** ld 0x1245e100 Outstanding
Requests:
Jan 26 12:08:59 WM-01 dovecot: auth: Error: Empty
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ld 0x1245e100 request
count 0 (abandoned 0)
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ** ld 0x1245e100 Response Queue:
Jan 26 12:08:59 WM-01 dovecot: auth: Error: Empty
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ld 0x1245e100 response count 0
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ldap_chkResponseList ld
0x1245e100 msgid -1 all 0
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ldap_chkResponseList returns
ld 0x1245e100 NULL
Jan 26 12:08:59 WM-01 dovecot: auth: Error: ldap_int_select
Jan 26 12:08:59 WM-01 postfix/smtpd[99014]: Anonymous TLS connection
established from localhost[127.0.0.1]: TLSv1.2 with cipher
ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ldap_search
Jan 26 12:09:09 WM-01 dovecot: auth: Error: put_filter:
"(&(objectClass=mailAccount)(mailAccountStatus=active)(mailAddress=postmaster@mydomain.tld))"
Jan 26 12:09:09 WM-01 dovecot: auth: Error: put_filter: AND
Jan 26 12:09:09 WM-01 dovecot: auth: Error: put_filter_list
"(objectClass=mailAccount)(mailAccountStatus=active)(mailAddress=postmaster@mydomain.tld)"
Jan 26 12:09:09 WM-01 dovecot: auth: Error: put_filter:
"(objectClass=mailAccount)"
Jan 26 12:09:09 WM-01 dovecot: auth: Error: put_filter: simple
Jan 26 12:09:09 WM-01 dovecot: auth: Error: put_simple_filter:
"objectClass=mailAccount"
Jan 26 12:09:09 WM-01 dovecot: auth: Error: put_filter:
"(mailAccountStatus=active)"
Jan 26 12:09:09 WM-01 dovecot: auth: Error: put_filter: simple
Jan 26 12:09:09 WM-01 dovecot: auth: Error: put_simple_filter:
"mailAccountStatus=active"
Jan 26 12:09:09 WM-01 dovecot: auth: Error: put_filter:
"(mailAddress=postmaster@mydomain.tld)"
Jan 26 12:09:09 WM-01 dovecot: auth: Error: put_filter: simple
Jan 26 12:09:09 WM-01 dovecot: auth: Error: put_simple_filter:
"mailAddress=postmaster@mydomain.tld"
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ldap_build_search_req ATTRS:
mailAddress
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ldap_send_initial_request
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ldap_send_server_request
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ldap_result ld 0x1245e100
msgid -1
Jan 26 12:09:09 WM-01 dovecot: auth: Error: wait4msg ld 0x1245e100 msgid
-1 (timeout 0 usec)
Jan 26 12:09:09 WM-01 dovecot: auth: Error: wait4msg continue ld
0x1245e100 msgid -1 all 0
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ** ld 0x1245e100 Connections:
Jan 26 12:09:09 WM-01 dovecot: auth: Error: * host: 127.0.0.1 port: 389
(default)
Jan 26 12:09:09 WM-01 dovecot: auth: Error: refcnt: 2 status: Connected
Jan 26 12:09:09 WM-01 dovecot: auth: Error: last used: Mon Jan 26
12:09:09 2015
Jan 26 12:09:09 WM-01 dovecot: auth: Error:
Jan 26 12:09:09 WM-01 dovecot: auth: Error:
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ** ld 0x1245e100 Outstanding
Requests:
Jan 26 12:09:09 WM-01 dovecot: auth: Error: * msgid 3, origid 3,
status InProgress
Jan 26 12:09:09 WM-01 dovecot: auth: Error: outstanding referrals 0,
parent count 0
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ld 0x1245e100 request
count 1 (abandoned 0)
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ** ld 0x1245e100 Response Queue:
Jan 26 12:09:09 WM-01 dovecot: auth: Error: Empty
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ld 0x1245e100 response count 0
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ldap_chkResponseList ld
0x1245e100 msgid -1 all 0
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ldap_chkResponseList returns
ld 0x1245e100 NULL
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ldap_int_select
Jan 26 12:09:09 WM-01 dovecot: auth: Error: read1msg: ld 0x1245e100
msgid -1 all 0
Jan 26 12:09:09 WM-01 dovecot: auth: Error: read1msg: ld 0x1245e100
msgid 3 message type search-entry
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ldap_result ld 0x1245e100
msgid -1
Jan 26 12:09:09 WM-01 dovecot: auth: Error: wait4msg ld 0x1245e100 msgid
-1 (timeout 0 usec)
Jan 26 12:09:09 WM-01 dovecot: auth: Error: wait4msg continue ld
0x1245e100 msgid -1 all 0
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ** ld 0x1245e100 Connections:
Jan 26 12:09:09 WM-01 dovecot: auth: Error: * host: 127.0.0.1 port: 389
(default)
Jan 26 12:09:09 WM-01 dovecot: auth: Error: refcnt: 2 status: Connected
Jan 26 12:09:09 WM-01 dovecot: auth: Error: last used: Mon Jan 26
12:09:09 2015
Jan 26 12:09:09 WM-01 dovecot: auth: Error:
Jan 26 12:09:09 WM-01 dovecot: auth: Error:
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ** ld 0x1245e100 Outstanding
Requests:
Jan 26 12:09:09 WM-01 dovecot: auth: Error: * msgid 3, origid 3,
status InProgress
Jan 26 12:09:09 WM-01 dovecot: auth: Error: outstanding referrals 0,
parent count 0
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ld 0x1245e100 request
count 1 (abandoned 0)
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ** ld 0x1245e100 Response Queue:
Jan 26 12:09:09 WM-01 dovecot: auth: Error: Empty
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ld 0x1245e100 response count 0
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ldap_chkResponseList ld
0x1245e100 msgid -1 all 0
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ldap_chkResponseList returns
ld 0x1245e100 NULL
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ldap_int_select
Jan 26 12:09:09 WM-01 dovecot: auth: Error: read1msg: ld 0x1245e100
msgid -1 all 0
Jan 26 12:09:09 WM-01 dovecot: auth: Error: read1msg: ld 0x1245e100
msgid 3 message type search-result
Jan 26 12:09:09 WM-01 dovecot: auth: Error: read1msg: ld 0x1245e100 0
new referrals
Jan 26 12:09:09 WM-01 dovecot: auth: Error: read1msg: mark request
completed, ld 0x1245e100 msgid 3
Jan 26 12:09:09 WM-01 dovecot: auth: Error: request done: ld 0x1245e100
msgid 3
Jan 26 12:09:09 WM-01 dovecot: auth: Error: res_errno: 0, res_error: <>,
res_matched: <>
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ldap_free_request (origid 3,
msgid 3)
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ldap_parse_result
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ldap_first_attribute
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ldap_get_values
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ldap_next_attribute
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ldap_first_attribute
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ldap_get_values
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ldap_next_attribute
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ldap_get_dn
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ldap_bind
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ldap_simple_bind
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ldap_sasl_bind
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ldap_send_initial_request
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ldap_send_server_request
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ldap_msgfree
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ldap_msgfree
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ldap_result ld 0x1245e100
msgid -1
Jan 26 12:09:09 WM-01 dovecot: auth: Error: wait4msg ld 0x1245e100 msgid
-1 (timeout 0 usec)
Jan 26 12:09:09 WM-01 dovecot: auth: Error: wait4msg continue ld
0x1245e100 msgid -1 all 0
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ** ld 0x1245e100 Connections:
Jan 26 12:09:09 WM-01 dovecot: auth: Error: * host: 127.0.0.1 port: 389
(default)
Jan 26 12:09:09 WM-01 dovecot: auth: Error: refcnt: 2 status: Connected
Jan 26 12:09:09 WM-01 dovecot: auth: Error: last used: Mon Jan 26
12:09:09 2015
Jan 26 12:09:09 WM-01 dovecot: auth: Error:
Jan 26 12:09:09 WM-01 dovecot: auth: Error:
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ** ld 0x1245e100 Outstanding
Requests:
Jan 26 12:09:09 WM-01 dovecot: auth: Error: * msgid 4, origid 4,
status InProgress
Jan 26 12:09:09 WM-01 dovecot: auth: Error: outstanding referrals 0,
parent count 0
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ld 0x1245e100 request
count 1 (abandoned 0)
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ** ld 0x1245e100 Response Queue:
Jan 26 12:09:09 WM-01 dovecot: auth: Error: Empty
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ld 0x1245e100 response count 0
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ldap_chkResponseList ld
0x1245e100 msgid -1 all 0
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ldap_chkResponseList returns
ld 0x1245e100 NULL
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ldap_int_select
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ldap_result ld 0x1245e100
msgid -1
Jan 26 12:09:09 WM-01 dovecot: auth: Error: wait4msg ld 0x1245e100 msgid
-1 (timeout 0 usec)
Jan 26 12:09:09 WM-01 dovecot: auth: Error: wait4msg continue ld
0x1245e100 msgid -1 all 0
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ** ld 0x1245e100 Connections:
Jan 26 12:09:09 WM-01 dovecot: auth: Error: * host: 127.0.0.1 port: 389
(default)
Jan 26 12:09:09 WM-01 dovecot: auth: Error: refcnt: 2 status: Connected
Jan 26 12:09:09 WM-01 dovecot: auth: Error: last used: Mon Jan 26
12:09:09 2015
Jan 26 12:09:09 WM-01 dovecot: auth: Error:
Jan 26 12:09:09 WM-01 dovecot: auth: Error:
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ** ld 0x1245e100 Outstanding
Requests:
Jan 26 12:09:09 WM-01 dovecot: auth: Error: * msgid 4, origid 4,
status InProgress
Jan 26 12:09:09 WM-01 dovecot: auth: Error: outstanding referrals 0,
parent count 0
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ld 0x1245e100 request
count 1 (abandoned 0)
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ** ld 0x1245e100 Response Queue:
Jan 26 12:09:09 WM-01 dovecot: auth: Error: Empty
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ld 0x1245e100 response count 0
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ldap_chkResponseList ld
0x1245e100 msgid -1 all 0
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ldap_chkResponseList returns
ld 0x1245e100 NULL
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ldap_int_select
Jan 26 12:09:09 WM-01 dovecot: auth: Error: read1msg: ld 0x1245e100
msgid -1 all 0
Jan 26 12:09:09 WM-01 dovecot: auth: Error: read1msg: ld 0x1245e100
msgid 4 message type bind
Jan 26 12:09:09 WM-01 dovecot: auth: Error: read1msg: ld 0x1245e100 0
new referrals
Jan 26 12:09:09 WM-01 dovecot: auth: Error: read1msg: mark request
completed, ld 0x1245e100 msgid 4
Jan 26 12:09:09 WM-01 dovecot: auth: Error: request done: ld 0x1245e100
msgid 4
Jan 26 12:09:09 WM-01 dovecot: auth: Error: res_errno: 0, res_error: <>,
res_matched: <>
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ldap_free_request (origid 4,
msgid 4)
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ldap_parse_result
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ldap_parse_result
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ldap_msgfree
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ldap_result ld 0x1245e100
msgid -1
Jan 26 12:09:09 WM-01 dovecot: auth: Error: wait4msg ld 0x1245e100 msgid
-1 (timeout 0 usec)
Jan 26 12:09:09 WM-01 dovecot: auth: Error: wait4msg continue ld
0x1245e100 msgid -1 all 0
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ** ld 0x1245e100 Connections:
Jan 26 12:09:09 WM-01 dovecot: auth: Error: * host: 127.0.0.1 port: 389
(default)
Jan 26 12:09:09 WM-01 dovecot: auth: Error: refcnt: 1 status: Connected
Jan 26 12:09:09 WM-01 dovecot: auth: Error: last used: Mon Jan 26
12:09:09 2015
Jan 26 12:09:09 WM-01 dovecot: auth: Error:
Jan 26 12:09:09 WM-01 dovecot: auth: Error:
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ** ld 0x1245e100 Outstanding
Requests:
Jan 26 12:09:09 WM-01 dovecot: auth: Error: Empty
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ld 0x1245e100 request
count 0 (abandoned 0)
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ** ld 0x1245e100 Response Queue:
Jan 26 12:09:09 WM-01 dovecot: auth: Error: Empty
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ld 0x1245e100 response count 0
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ldap_chkResponseList ld
0x1245e100 msgid -1 all 0
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ldap_chkResponseList returns
ld 0x1245e100 NULL
Jan 26 12:09:09 WM-01 dovecot: auth: Error: ldap_int_select
Jan 26 12:09:20 WM-01 postfix/smtpd[99014]: lost connection after AUTH
from localhost[127.0.0.1]
Jan 26 12:09:20 WM-01 postfix/smtpd[99014]: disconnect from
localhost[127.0.0.1]
Am 26.01.15 um 11:27 schrieb Leander Schäfer:
Am 26.01.15 um 02:24 schrieb Edgar Pettijohn:
Sorry didn't scroll to the bottom to see the dovecot -n. I'm assuming freebsd has an /etc/login.conf similiar to openbsd. If so you may need to do something similiar to this:
dovecot:
:openfiles-cur=512:
:openfiles-max=2048:
:tc=daemon:Rebuild the login.conf.db file if necessary:
# [ -f /etc/login.conf.db ] && cap_mkdb /etc/login.conf
Hope this helps.
Thanks for the hint. FreeBSD takes sysctl(8) settings as a base to ulimit(3). I even tried tuning on those values.
sysctl kern.maxfilesperproc=405587 sysctl kern.maxfiles=428433
Unfortunately this does not solve the problem. I don't think it is the root of the problem.
The current value - even with Dovecot and Postfix already running is: kern.openfiles: 675 It is just, that Dovecot is kind of in a frozen condition when trying to login to it via telnet(1).
Am 26.01.15 um 02:20 schrieb Reindl Harald:
Am 26.01.2015 um 02:13 schrieb Leander Schäfer:
I just checked my ulimit again and it really seems like it has more than enough - so I still don't understand what I've configured wrong here ;/
root@WM-01 [~]$ su -m dovecot -c "ulimit -a" socket buffer size (bytes, -b) unlimited core file size (blocks, -c) unlimited data seg size (kbytes, -d) 33554432 file size (blocks, -f) unlimited max locked memory (kbytes, -l) 131072 max memory size (kbytes, -m) 7067352 open files (-n) 205587 pipe size (512 bytes, -p) 1 stack size (kbytes, -s) 8192 cpu time (seconds, -t) unlimited max user processes (-u) 11278 virtual memory (kbytes, -v) unlimited swap size (kbytes, -w) unlimited
besides that "imap-login" typically does *not* run under the same user (here dovenull versus dovecot) who tells you that 205587 is "more than enough" just because it is a high value?
Yes, because I am monitoring those values via Munin. I can clearly see that my system does not require a value even close to this. By average my system has 673 files open. In FreeBSD sysctl(8) is the base for ulimit(3) - meaning since I don't maintain user specific ulimit(3) - it is also the same values for dovenull, postfix, vmail and every other user on the system. My current sysctl(8) values should provide way enough space to grow super large:
sysctl kern.maxfilesperproc=205587 sysctl kern.maxfiles=228433
And this is where it becomes so absurd to me. I don't see where I should tune anymore. I more and more get the feeling it is a configuration error of dovecot itself?!
Thanks & Best Regards, Leander