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)([email protected]))"
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)([email protected])"
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:
"([email protected])"
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:
"[email protected]"
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
