It turns out, that this errors "too many open files ..." occurred because a) missing "index ATTRIBUTE eq" for username and password in slapd.conf as well as b) password attribute was not read properly by dovecot from LDAP - I had to remove it from my schema and instead use "userPassword" from "objectclass: simpleSecurityObject"
This two changes made the "too many open files ..." errors disapear.
BUT, I still have the problem of receiving all those "dovecot: auth: Error:" lines in my maillog. I know I could turn them off by reducing debug parameters - but why is it declared as error in the first place - even though user authentication is working fine?
Thanks & Best Regards, Leander
Am 26.01.15 um 12:16 schrieb Leander Schäfer:
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.confHope 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