February 2013 - dovecot

[Dovecot] Public folders and dsync replication Dovecot v2.1.7
by Steve Brown 21 Feb '13

21 Feb '13

Dear all I have a few public folders setup and working fine, and one such public folder is 'Public/General'. I'm trying to sort dsync replication out to another server and notice that the system log is full of error messages similar to: dovecot: doveadm: Error: dsync-remote(username: Error: Can't update subscription Pu blic/General: Invalid mailbox name The replication setup is basically as per the v2 wiki. It seems that when a mail client subscribes to a public folder, the folder name is put into '~/Maildir/subscriptions' and this seems to be the cause of the error during replication. The mails are not synchronised to the other server. Public namespace is: namespace { type = public separator = / prefix = Public/ location = maildir:/home/shared/public subscriptions = no list = yes } Hopefully somebody can send the clue bus over? Steve -- Steve Brown Operations Manager Connection Services Ltd +44 (0)1189 711 765 Direct +44 (0)870 751 7571 Fax www.connectionservices.com www.hotspot-directory.com

3 2

Re: [Dovecot] Dovecot LDA LDAP lookups on samba4 server ends very often in timeouts (Christian Wiese)
by Marco Carcano 21 Feb '13

21 Feb '13

Dear Christian thank you very much - you got it at the very first shot: modified /etc/ openldap/ldap.conf adding REFERRALS off en everything works without issues now many thanks Marco Carcano

1 0

[Dovecot] Dovecot LDA LDAP lookups on samba4 server ends very often in timeouts
by marco＠carcano.ch 20 Feb '13

20 Feb '13

I hope that someone will be so kind to help me into solving this really strange thing (don't know if it is a bug or not) I have a samba4 server and want to use postfix+dovecot - dovecot version is 2.0.11 as for the postfix side everything is OK (all the LDAP lookups works without any error, tested also manually with postmap -q) the real pain is with dovecot deliver: it seems that sometimes lda tries to lookup to the LDPA (samba 4) server, got a reply, an then report(after 2 minutes) a lookup timeout error the really strange thing is that (very seldom) lda works, but most of the times I got the timeout error. The strange thing is that if I use ldapsearch I never got timeout neither late replies, and even postfix performs its lookups without any issue it seems something related to lda itself (I do not know if I have a wrong configuration, but I think this is not a configuration issue, otherwise it should not work at all) here are the information logged when it does not work - after this log you will find the one when I got the failure (if needed I can provide a .pcap file too) (trailing and leading spaces of AT charcater has been added by me) ############################## FAULTY DELIVER LOG ############################################# Feb 20 12:20:50 sng02 postfix/smtpd[8928]: connect from localhost[127.0.0.1] Feb 20 12:21:14 sng02 postfix/smtpd[8928]: A38D4407F5: client=localhost[127.0.0.1] Feb 20 12:21:20 sng02 postfix/cleanup[8891]: A38D4407F5: warning: header Subject: prova from localhost[127.0.0.1]; from=<marco @ senderdomain.tld> to=<mac @ mydomain.com> proto=SMTP helo=<senderdomain.tld> Feb 20 12:21:20 sng02 postfix/cleanup[8891]: A38D4407F5: message-id=<20130220112114.A38D4407F5 @ srv01.mydomain.local> Feb 20 12:21:20 sng02 postfix/qmgr[8889]: A38D4407F5: from=<marco @ senderdomain.tld>, size=371, nrcpt=1 (queue active) Feb 20 12:21:20 sng02 dovecot: lda: Debug: Loading modules from directory: /usr/lib64/dovecot Feb 20 12:21:20 sng02 dovecot: lda: Debug: Module loaded: /usr/lib64/dovecot/lib10_quota_plugin.so Feb 20 12:21:20 sng02 dovecot: lda: Debug: Module loaded: /usr/lib64/dovecot/lib20_expire_plugin.so Feb 20 12:21:20 sng02 dovecot: lda: Debug: Module loaded: /usr/lib64/dovecot/lib90_sieve_plugin.so Feb 20 12:21:20 sng02 dovecot: auth: Debug: Loading modules from directory: /usr/lib64/dovecot/auth Feb 20 12:21:20 sng02 dovecot: auth: Debug: Module loaded: /usr/lib64/dovecot/auth/libauthdb_ldap.so Feb 20 12:21:20 sng02 dovecot: auth: Debug: Module loaded: /usr/lib64/dovecot/auth/libdriver_mysql.so Feb 20 12:21:20 sng02 dovecot: auth: Debug: Module loaded: /usr/lib64/dovecot/auth/libdriver_pgsql.so Feb 20 12:21:20 sng02 dovecot: auth: Debug: Module loaded: /usr/lib64/dovecot/auth/libdriver_sqlite.so Feb 20 12:21:20 sng02 dovecot: auth: Debug: Module loaded: /usr/lib64/dovecot/auth/libmech_gssapi.so Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_bind Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_simple_bind Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_sasl_bind Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_send_initial_request Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_new_connection 1 1 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_int_open_connection Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_connect_to_host: TCP localhost:389 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_new_socket: 16 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_prepare_socket: 16 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_connect_to_host: Trying ::1 389 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_pvt_connect: fd: 16 tm: -1 async: 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_open_defconn: successful Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_send_server_request Feb 20 12:21:20 sng02 dovecot: auth: Debug: master in: USER#0111#011marco.carcano#011service=lda Feb 20 12:21:20 sng02 dovecot: auth: Debug: password(marco.carcano): passdb doesn't support credential lookups Feb 20 12:21:20 sng02 dovecot: auth: Error: static(marco.carcano): passdb doesn't support lookups, can't verify user's existence Feb 20 12:21:20 sng02 dovecot: auth: Debug: ldap(marco.carcano): user search: base=DC=mydomain,DC=local scope=subtree filter=(sAMAccountname=marco.carcano) fields=Mailbox,dovecotMailQuota Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_result ld 0x6cba60 msgid -1 Feb 20 12:21:20 sng02 dovecot: auth: Error: wait4msg ld 0x6cba60 msgid -1 (timeout 0 usec) Feb 20 12:21:20 sng02 dovecot: auth: Error: wait4msg continue ld 0x6cba60 msgid -1 all 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ** ld 0x6cba60 Connections: Feb 20 12:21:20 sng02 dovecot: auth: Error: * host: localhost port: 389 (default) Feb 20 12:21:20 sng02 dovecot: auth: Error: refcnt: 2 status: Connected Feb 20 12:21:20 sng02 dovecot: auth: Error: last used: Wed Feb 20 12:21:20 2013 Feb 20 12:21:20 sng02 dovecot: auth: Error: Feb 20 12:21:20 sng02 dovecot: auth: Error: Feb 20 12:21:20 sng02 dovecot: auth: Error: ** ld 0x6cba60 Outstanding Requests: Feb 20 12:21:20 sng02 dovecot: auth: Error: * msgid 1, origid 1, status InProgress Feb 20 12:21:20 sng02 dovecot: auth: Error: outstanding referrals 0, parent count 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ld 0x6cba60 request count 1 (abandoned 0) Feb 20 12:21:20 sng02 dovecot: auth: Error: ** ld 0x6cba60 Response Queue: Feb 20 12:21:20 sng02 dovecot: auth: Error: Empty Feb 20 12:21:20 sng02 dovecot: auth: Error: ld 0x6cba60 response count 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_chkResponseList ld 0x6cba60 msgid -1 all 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_chkResponseList returns ld 0x6cba60 NULL Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_int_select Feb 20 12:21:20 sng02 dovecot: auth: Error: read1msg: ld 0x6cba60 msgid -1 all 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: read1msg: ld 0x6cba60 msgid 1 message type bind Feb 20 12:21:20 sng02 dovecot: auth: Error: read1msg: ld 0x6cba60 0 new referrals Feb 20 12:21:20 sng02 dovecot: auth: Error: read1msg: mark request completed, ld 0x6cba60 msgid 1 Feb 20 12:21:20 sng02 dovecot: auth: Error: request done: ld 0x6cba60 msgid 1 Feb 20 12:21:20 sng02 dovecot: auth: Error: res_errno: 0, res_error: <>, res_matched: <> Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_free_request (origid 1, msgid 1) Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_parse_result Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_search Feb 20 12:21:20 sng02 dovecot: auth: Error: put_filter: "(sAMAccountname=marco.carcano)" Feb 20 12:21:20 sng02 dovecot: auth: Error: put_filter: simple Feb 20 12:21:20 sng02 dovecot: auth: Error: put_simple_filter: "sAMAccountname=marco.carcano" Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_send_initial_request Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_send_server_request Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_msgfree Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_result ld 0x6cba60 msgid -1 Feb 20 12:21:20 sng02 dovecot: auth: Error: wait4msg ld 0x6cba60 msgid -1 (timeout 0 usec) Feb 20 12:21:20 sng02 dovecot: auth: Error: wait4msg continue ld 0x6cba60 msgid -1 all 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ** ld 0x6cba60 Connections: Feb 20 12:21:20 sng02 dovecot: auth: Error: * host: localhost port: 389 (default) Feb 20 12:21:20 sng02 dovecot: auth: Error: refcnt: 2 status: Connected Feb 20 12:21:20 sng02 dovecot: auth: Error: last used: Wed Feb 20 12:21:20 2013 Feb 20 12:21:20 sng02 dovecot: auth: Error: Feb 20 12:21:20 sng02 dovecot: auth: Error: Feb 20 12:21:20 sng02 dovecot: auth: Error: ** ld 0x6cba60 Outstanding Requests: Feb 20 12:21:20 sng02 dovecot: auth: Error: * msgid 2, origid 2, status InProgress Feb 20 12:21:20 sng02 dovecot: auth: Error: outstanding referrals 0, parent count 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ld 0x6cba60 request count 1 (abandoned 0) Feb 20 12:21:20 sng02 dovecot: auth: Error: ** ld 0x6cba60 Response Queue: Feb 20 12:21:20 sng02 dovecot: auth: Error: Empty Feb 20 12:21:20 sng02 dovecot: auth: Error: ld 0x6cba60 response count 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_chkResponseList ld 0x6cba60 msgid -1 all 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_chkResponseList returns ld 0x6cba60 NULL Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_int_select Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_result ld 0x6cba60 msgid -1 Feb 20 12:21:20 sng02 dovecot: auth: Error: wait4msg ld 0x6cba60 msgid -1 (timeout 0 usec) Feb 20 12:21:20 sng02 dovecot: auth: Error: wait4msg continue ld 0x6cba60 msgid -1 all 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ** ld 0x6cba60 Connections: Feb 20 12:21:20 sng02 dovecot: auth: Error: * host: localhost port: 389 (default) Feb 20 12:21:20 sng02 dovecot: auth: Error: refcnt: 2 status: Connected Feb 20 12:21:20 sng02 dovecot: auth: Error: last used: Wed Feb 20 12:21:20 2013 Feb 20 12:21:20 sng02 dovecot: auth: Error: Feb 20 12:21:20 sng02 dovecot: auth: Error: Feb 20 12:21:20 sng02 dovecot: auth: Error: ** ld 0x6cba60 Outstanding Requests: Feb 20 12:21:20 sng02 dovecot: auth: Error: * msgid 2, origid 2, status InProgress Feb 20 12:21:20 sng02 dovecot: auth: Error: outstanding referrals 0, parent count 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ld 0x6cba60 request count 1 (abandoned 0) Feb 20 12:21:20 sng02 dovecot: auth: Error: ** ld 0x6cba60 Response Queue: Feb 20 12:21:20 sng02 dovecot: auth: Error: Empty Feb 20 12:21:20 sng02 dovecot: auth: Error: ld 0x6cba60 response count 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_chkResponseList ld 0x6cba60 msgid -1 all 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_chkResponseList returns ld 0x6cba60 NULL Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_int_select Feb 20 12:21:20 sng02 dovecot: auth: Error: read1msg: ld 0x6cba60 msgid -1 all 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: read1msg: ld 0x6cba60 msgid 2 message type search-entry Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_first_attribute Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_get_values Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_next_attribute Feb 20 12:21:20 sng02 dovecot: auth: Debug: ldap(marco.carcano): result: dovecotMailQuota(quota_rule=%$)=*:storage=8192M Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_msgfree Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_result ld 0x6cba60 msgid -1 Feb 20 12:21:20 sng02 dovecot: auth: Error: wait4msg ld 0x6cba60 msgid -1 (timeout 0 usec) Feb 20 12:21:20 sng02 dovecot: auth: Error: wait4msg continue ld 0x6cba60 msgid -1 all 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ** ld 0x6cba60 Connections: Feb 20 12:21:20 sng02 dovecot: auth: Error: * host: localhost port: 389 (default) Feb 20 12:21:20 sng02 dovecot: auth: Error: refcnt: 2 status: Connected Feb 20 12:21:20 sng02 dovecot: auth: Error: last used: Wed Feb 20 12:21:20 2013 Feb 20 12:21:20 sng02 dovecot: auth: Error: Feb 20 12:21:20 sng02 dovecot: auth: Error: Feb 20 12:21:20 sng02 dovecot: auth: Error: ** ld 0x6cba60 Outstanding Requests: Feb 20 12:21:20 sng02 dovecot: auth: Error: * msgid 2, origid 2, status InProgress Feb 20 12:21:20 sng02 dovecot: auth: Error: outstanding referrals 0, parent count 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ld 0x6cba60 request count 1 (abandoned 0) Feb 20 12:21:20 sng02 dovecot: auth: Error: ** ld 0x6cba60 Response Queue: Feb 20 12:21:20 sng02 dovecot: auth: Error: Empty Feb 20 12:21:20 sng02 dovecot: auth: Error: ld 0x6cba60 response count 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_chkResponseList ld 0x6cba60 msgid -1 all 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_chkResponseList returns ld 0x6cba60 NULL Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_int_select Feb 20 12:21:20 sng02 dovecot: auth: Error: read1msg: ld 0x6cba60 msgid -1 all 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: read1msg: ld 0x6cba60 msgid 2 message type search-reference Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_chase_v3referrals Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_url_parse_ext(ldap://mydomain.local/CN=Configuration,DC=mydomain,DC=local) Feb 20 12:21:20 sng02 dovecot: auth: Error: re_encode_request: new msgid 3, new dn <CN=Configuration,DC=mydomain,DC=local> Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_chase_v3referral: msgid 2, url "ldap://mydomain.local/CN=Configuration,DC=mydomain,DC=local" Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_send_server_request Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_new_connection 0 1 1 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_int_open_connection Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_connect_to_host: TCP mydomain.local:389 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_new_socket: 18 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_prepare_socket: 18 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_connect_to_host: Trying 192.168.32.2:389 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_pvt_connect: fd: 18 tm: -1 async: 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: anonymous rebind via ldap_sasl_bind("") Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_sasl_bind Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_send_initial_request Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_send_server_request Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_result ld 0x6cba60 msgid 4 Feb 20 12:21:20 sng02 dovecot: auth: Error: wait4msg ld 0x6cba60 msgid 4 (timeout 100000 usec) Feb 20 12:21:20 sng02 dovecot: auth: Error: wait4msg continue ld 0x6cba60 msgid 4 all 1 Feb 20 12:21:20 sng02 dovecot: auth: Error: ** ld 0x6cba60 Connections: Feb 20 12:21:20 sng02 dovecot: auth: Error: * host: mydomain.local port: 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: refcnt: 2 status: Connected Feb 20 12:21:20 sng02 dovecot: auth: Error: last used: Wed Feb 20 12:21:20 2013 Feb 20 12:21:20 sng02 dovecot: auth: Error: rebind in progress Feb 20 12:21:20 sng02 dovecot: auth: Error: queue is empty Feb 20 12:21:20 sng02 dovecot: auth: Error: Feb 20 12:21:20 sng02 dovecot: auth: Error: * host: localhost port: 389 (default) Feb 20 12:21:20 sng02 dovecot: auth: Error: refcnt: 3 status: Connected Feb 20 12:21:20 sng02 dovecot: auth: Error: last used: Wed Feb 20 12:21:20 2013 Feb 20 12:21:20 sng02 dovecot: auth: Error: Feb 20 12:21:20 sng02 dovecot: auth: Error: Feb 20 12:21:20 sng02 dovecot: auth: Error: ** ld 0x6cba60 Outstanding Requests: Feb 20 12:21:20 sng02 dovecot: auth: Error: * msgid 4, origid 4, status InProgress Feb 20 12:21:20 sng02 dovecot: auth: Error: outstanding referrals 0, parent count 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: * msgid 2, origid 2, status InProgress Feb 20 12:21:20 sng02 dovecot: auth: Error: outstanding referrals 1, parent count 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ld 0x6cba60 request count 2 (abandoned 0) Feb 20 12:21:20 sng02 dovecot: auth: Error: ** ld 0x6cba60 Response Queue: Feb 20 12:21:20 sng02 dovecot: auth: Error: Empty Feb 20 12:21:20 sng02 dovecot: auth: Error: ld 0x6cba60 response count 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_chkResponseList ld 0x6cba60 msgid 4 all 1 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_chkResponseList returns ld 0x6cba60 NULL Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_int_select Feb 20 12:21:20 sng02 dovecot: auth: Error: read1msg: ld 0x6cba60 msgid 4 all 1 Feb 20 12:21:20 sng02 dovecot: auth: Error: read1msg: ld 0x6cba60 msgid 2 message type search-result Feb 20 12:21:20 sng02 dovecot: auth: Error: read1msg: ld 0x6cba60 0 new referrals Feb 20 12:21:20 sng02 dovecot: auth: Error: read1msg: mark request completed, ld 0x6cba60 msgid 2 Feb 20 12:21:20 sng02 dovecot: auth: Error: wait4msg ld 0x6cba60 0 s 99952 us to go Feb 20 12:21:20 sng02 dovecot: auth: Error: wait4msg continue ld 0x6cba60 msgid 4 all 1 Feb 20 12:21:20 sng02 dovecot: auth: Error: ** ld 0x6cba60 Connections: Feb 20 12:21:20 sng02 dovecot: auth: Error: * host: mydomain.local port: 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: refcnt: 2 status: Connected Feb 20 12:21:20 sng02 dovecot: auth: Error: last used: Wed Feb 20 12:21:20 2013 Feb 20 12:21:20 sng02 dovecot: auth: Error: rebind in progress Feb 20 12:21:20 sng02 dovecot: auth: Error: queue is empty Feb 20 12:21:20 sng02 dovecot: auth: Error: Feb 20 12:21:20 sng02 dovecot: auth: Error: * host: localhost port: 389 (default) Feb 20 12:21:20 sng02 dovecot: auth: Error: refcnt: 2 status: Connected Feb 20 12:21:20 sng02 dovecot: auth: Error: last used: Wed Feb 20 12:21:20 2013 Feb 20 12:21:20 sng02 dovecot: auth: Error: Feb 20 12:21:20 sng02 dovecot: auth: Error: Feb 20 12:21:20 sng02 dovecot: auth: Error: ** ld 0x6cba60 Outstanding Requests: Feb 20 12:21:20 sng02 dovecot: auth: Error: * msgid 4, origid 4, status InProgress Feb 20 12:21:20 sng02 dovecot: auth: Error: outstanding referrals 0, parent count 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: * msgid 2, origid 2, status RequestCompleted Feb 20 12:21:20 sng02 dovecot: auth: Error: outstanding referrals 1, parent count 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ld 0x6cba60 request count 2 (abandoned 0) Feb 20 12:21:20 sng02 dovecot: auth: Error: ** ld 0x6cba60 Response Queue: Feb 20 12:21:20 sng02 dovecot: auth: Error: Empty Feb 20 12:21:20 sng02 dovecot: auth: Error: ld 0x6cba60 response count 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_chkResponseList ld 0x6cba60 msgid 4 all 1 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_chkResponseList returns ld 0x6cba60 NULL Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_int_select Feb 20 12:21:20 sng02 dovecot: auth: Error: read1msg: ld 0x6cba60 msgid 4 all 1 Feb 20 12:21:20 sng02 dovecot: auth: Error: read1msg: ld 0x6cba60 msgid 4 message type bind Feb 20 12:21:20 sng02 dovecot: auth: Error: read1msg: ld 0x6cba60 0 new referrals Feb 20 12:21:20 sng02 dovecot: auth: Error: read1msg: mark request completed, ld 0x6cba60 msgid 4 Feb 20 12:21:22 sng02 postfix/smtpd[8928]: disconnect from localhost[127.0.0.1] Feb 20 12:23:55 sng02 dovecot: lda: Error: userdb lookup(marco.carcano): Request timed out Feb 20 12:23:55 sng02 dovecot: lda: Fatal: Internal error occurred. Refer to server log for more information. Feb 20 12:23:56 sng02 postfix/pipe[8897]: A38D4407F5: to=<marco.carcano @ mydomain.local>, orig_to=<mac @ mydomain.com>, relay=dovecot, delay=171, delays=16/0.01/0/155, dsn=4.3.0, status=deferred (temporary failure) Feb 20 12:24:10 sng02 dovecot: master: Warning: Killed with signal 15 (by pid=8946 uid=0 code=kill) Feb 20 12:24:10 sng02 dovecot: auth: ldap(marco.carcano): Shutting down Feb 20 12:24:10 sng02 dovecot: auth: Debug: master out: FAIL#0111 Feb 20 12:24:10 sng02 dovecot: auth: Error: ldap_unbind Feb 20 12:24:10 sng02 dovecot: auth: Error: ldap_free_request (origid 2, msgid 3) Feb 20 12:24:10 sng02 dovecot: auth: Error: ldap_free_request (origid 2, msgid 2) Feb 20 12:24:10 sng02 dovecot: auth: Error: ldap_free_connection 1 1 Feb 20 12:24:10 sng02 dovecot: auth: Error: ldap_send_unbind Feb 20 12:24:10 sng02 dovecot: auth: Error: ldap_free_connection: actually freed Feb 20 12:24:10 sng02 dovecot: auth: Error: ldap_free_connection 1 1 Feb 20 12:24:10 sng02 dovecot: auth: Error: ldap_send_unbind Feb 20 12:24:10 sng02 dovecot: auth: Error: ldap_free_connection: actually freed Feb 20 12:24:18 sng02 postfix/postfix-script[8962]: stopping the Postfix mail system Feb 20 12:24:18 sng02 postfix/master[8886]: terminating on signal 15 ############################## END OF FAULTY DELIVER LOG ############################################# I'll add the log of a succefully delivered message in another mail (otherwise I exceed message size limit of the list)

2 1

Re: [Dovecot] Dovecot LDA LDAP lookups on samba4 server ends very often in timeouts
by marco＠carcano.ch 20 Feb '13

20 Feb '13

just to complete the informations of this thread, here is the log of a mail delivered succesfully (trailing and leading spaces of AT charcater has been added by me) ############################## MAIL SUCCEFFULLY DELIVERED LOG ############################################# Feb 19 17:41:01 sng02 postfix/smtpd[4006]: connect from localhost[127.0.0.1] Feb 19 17:41:28 sng02 postfix/smtpd[4006]: 95659407F5: client=localhost[127.0.0.1] Feb 19 17:41:36 sng02 postfix/cleanup[4011]: 95659407F5: warning: header Subject: prova from localhost[127.0.0.1]; from=<marco @ senderdomain.tld> to=<mac @ mydomain.com> proto=SMTP helo=<senderdomain.tld> Feb 19 17:41:36 sng02 postfix/cleanup[4011]: 95659407F5: message-id=<20130219164128.95659407F5 @ srv01.mydomain.local> Feb 19 17:41:36 sng02 postfix/qmgr[3992]: 95659407F5: from=<marco @ senderdomain.tld>, size=371, nrcpt=1 (queue active) Feb 19 17:41:36 sng02 dovecot: lda: Debug: Loading modules from directory: /usr/lib64/dovecot Feb 19 17:41:36 sng02 dovecot: lda: Debug: Module loaded: /usr/lib64/dovecot/lib10_quota_plugin.so Feb 19 17:41:36 sng02 dovecot: lda: Debug: Module loaded: /usr/lib64/dovecot/lib20_expire_plugin.so Feb 19 17:41:36 sng02 dovecot: lda: Debug: Module loaded: /usr/lib64/dovecot/lib90_sieve_plugin.so Feb 19 17:41:36 sng02 dovecot: auth: Debug: master in: USER#0111#011marco.carcano#011service=lda Feb 19 17:41:36 sng02 dovecot: auth: Debug: password(marco.carcano): passdb doesn't support credential lookups Feb 19 17:41:36 sng02 dovecot: auth: Error: static(marco.carcano): passdb doesn't support lookups, can't verify user's existence Feb 19 17:41:36 sng02 dovecot: auth: Debug: ldap(marco.carcano): user search: base=DC=mydomain,DC=local scope=subtree filter=(sAMAccountname=marco.carcano) fields=Mailbox,dovecotMailQuota Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap(marco.carcano): Connection appears to be hanging, reconnecting Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_unbind Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_free_request (origid 2, msgid 3) Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_free_request (origid 2, msgid 2) Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_free_connection 1 1 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_send_unbind Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_free_connection: actually freed Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_free_connection 1 1 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_send_unbind Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_free_connection: actually freed Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_create Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_bind Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_simple_bind Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_sasl_bind Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_send_initial_request Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_new_connection 1 1 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_int_open_connection Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_connect_to_host: TCP localhost:389 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_new_socket: 16 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_prepare_socket: 16 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_connect_to_host: Trying ::1 389 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_pvt_connect: fd: 16 tm: -1 async: 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_open_defconn: successful Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_send_server_request Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_result ld 0x666a60 msgid -1 Feb 19 17:41:36 sng02 dovecot: auth: Error: wait4msg ld 0x666a60 msgid -1 (timeout 0 usec) Feb 19 17:41:36 sng02 dovecot: auth: Error: wait4msg continue ld 0x666a60 msgid -1 all 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: ** ld 0x666a60 Connections: Feb 19 17:41:36 sng02 dovecot: auth: Error: * host: localhost port: 389 (default) Feb 19 17:41:36 sng02 dovecot: auth: Error: refcnt: 2 status: Connected Feb 19 17:41:36 sng02 dovecot: auth: Error: last used: Tue Feb 19 17:41:36 2013 Feb 19 17:41:36 sng02 dovecot: auth: Error: Feb 19 17:41:36 sng02 dovecot: auth: Error: Feb 19 17:41:36 sng02 dovecot: auth: Error: ** ld 0x666a60 Outstanding Requests: Feb 19 17:41:36 sng02 dovecot: auth: Error: * msgid 1, origid 1, status InProgress Feb 19 17:41:36 sng02 dovecot: auth: Error: outstanding referrals 0, parent count 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: ld 0x666a60 request count 1 (abandoned 0) Feb 19 17:41:36 sng02 dovecot: auth: Error: ** ld 0x666a60 Response Queue: Feb 19 17:41:36 sng02 dovecot: auth: Error: Empty Feb 19 17:41:36 sng02 dovecot: auth: Error: ld 0x666a60 response count 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_chkResponseList ld 0x666a60 msgid -1 all 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_chkResponseList returns ld 0x666a60 NULL Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_int_select Feb 19 17:41:36 sng02 dovecot: auth: Error: read1msg: ld 0x666a60 msgid -1 all 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: read1msg: ld 0x666a60 msgid 1 message type bind Feb 19 17:41:36 sng02 dovecot: auth: Error: read1msg: ld 0x666a60 0 new referrals Feb 19 17:41:36 sng02 dovecot: auth: Error: read1msg: mark request completed, ld 0x666a60 msgid 1 Feb 19 17:41:36 sng02 dovecot: auth: Error: request done: ld 0x666a60 msgid 1 Feb 19 17:41:36 sng02 dovecot: auth: Error: res_errno: 0, res_error: <>, res_matched: <> Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_free_request (origid 1, msgid 1) Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_parse_result Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_search Feb 19 17:41:36 sng02 dovecot: auth: Error: put_filter: "(sAMAccountname=marco.carcano)" Feb 19 17:41:36 sng02 dovecot: auth: Error: put_filter: simple Feb 19 17:41:36 sng02 dovecot: auth: Error: put_simple_filter: "sAMAccountname=marco.carcano" Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_send_initial_request Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_send_server_request Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_search Feb 19 17:41:36 sng02 dovecot: auth: Error: put_filter: "(sAMAccountname=marco.carcano)" Feb 19 17:41:36 sng02 dovecot: auth: Error: put_filter: simple Feb 19 17:41:36 sng02 dovecot: auth: Error: put_simple_filter: "sAMAccountname=marco.carcano" Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_send_initial_request Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_send_server_request Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_msgfree Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_result ld 0x666a60 msgid -1 Feb 19 17:41:36 sng02 dovecot: auth: Error: wait4msg ld 0x666a60 msgid -1 (timeout 0 usec) Feb 19 17:41:36 sng02 dovecot: auth: Error: wait4msg continue ld 0x666a60 msgid -1 all 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: ** ld 0x666a60 Connections: Feb 19 17:41:36 sng02 dovecot: auth: Error: * host: localhost port: 389 (default) Feb 19 17:41:36 sng02 dovecot: auth: Error: refcnt: 3 status: Connected Feb 19 17:41:36 sng02 dovecot: auth: Error: last used: Tue Feb 19 17:41:36 2013 Feb 19 17:41:36 sng02 dovecot: auth: Error: Feb 19 17:41:36 sng02 dovecot: auth: Error: Feb 19 17:41:36 sng02 dovecot: auth: Error: ** ld 0x666a60 Outstanding Requests: Feb 19 17:41:36 sng02 dovecot: auth: Error: * msgid 3, origid 3, status InProgress Feb 19 17:41:36 sng02 dovecot: auth: Error: outstanding referrals 0, parent count 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: * msgid 2, origid 2, status InProgress Feb 19 17:41:36 sng02 dovecot: auth: Error: outstanding referrals 0, parent count 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: ld 0x666a60 request count 2 (abandoned 0) Feb 19 17:41:36 sng02 dovecot: auth: Error: ** ld 0x666a60 Response Queue: Feb 19 17:41:36 sng02 dovecot: auth: Error: Empty Feb 19 17:41:36 sng02 dovecot: auth: Error: ld 0x666a60 response count 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_chkResponseList ld 0x666a60 msgid -1 all 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_chkResponseList returns ld 0x666a60 NULL Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_int_select Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_result ld 0x666a60 msgid -1 Feb 19 17:41:36 sng02 dovecot: auth: Error: wait4msg ld 0x666a60 msgid -1 (timeout 0 usec) Feb 19 17:41:36 sng02 dovecot: auth: Error: wait4msg continue ld 0x666a60 msgid -1 all 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: ** ld 0x666a60 Connections: Feb 19 17:41:36 sng02 dovecot: auth: Error: * host: localhost port: 389 (default) Feb 19 17:41:36 sng02 dovecot: auth: Error: refcnt: 3 status: Connected Feb 19 17:41:36 sng02 dovecot: auth: Error: last used: Tue Feb 19 17:41:36 2013 Feb 19 17:41:36 sng02 dovecot: auth: Error: Feb 19 17:41:36 sng02 dovecot: auth: Error: Feb 19 17:41:36 sng02 dovecot: auth: Error: ** ld 0x666a60 Outstanding Requests: Feb 19 17:41:36 sng02 dovecot: auth: Error: * msgid 3, origid 3, status InProgress Feb 19 17:41:36 sng02 dovecot: auth: Error: outstanding referrals 0, parent count 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: * msgid 2, origid 2, status InProgress Feb 19 17:41:36 sng02 dovecot: auth: Error: outstanding referrals 0, parent count 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: ld 0x666a60 request count 2 (abandoned 0) Feb 19 17:41:36 sng02 dovecot: auth: Error: ** ld 0x666a60 Response Queue: Feb 19 17:41:36 sng02 dovecot: auth: Error: Empty Feb 19 17:41:36 sng02 dovecot: auth: Error: ld 0x666a60 response count 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_chkResponseList ld 0x666a60 msgid -1 all 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_chkResponseList returns ld 0x666a60 NULL Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_int_select Feb 19 17:41:36 sng02 dovecot: auth: Error: read1msg: ld 0x666a60 msgid -1 all 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: read1msg: ld 0x666a60 msgid 2 message type search-entry Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_msgfree Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_result ld 0x666a60 msgid -1 Feb 19 17:41:36 sng02 dovecot: auth: Error: wait4msg ld 0x666a60 msgid -1 (timeout 0 usec) Feb 19 17:41:36 sng02 dovecot: auth: Error: wait4msg continue ld 0x666a60 msgid -1 all 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: ** ld 0x666a60 Connections: Feb 19 17:41:36 sng02 dovecot: auth: Error: * host: localhost port: 389 (default) Feb 19 17:41:36 sng02 dovecot: auth: Error: refcnt: 3 status: Connected Feb 19 17:41:36 sng02 dovecot: auth: Error: last used: Tue Feb 19 17:41:36 2013 Feb 19 17:41:36 sng02 dovecot: auth: Error: Feb 19 17:41:36 sng02 dovecot: auth: Error: Feb 19 17:41:36 sng02 dovecot: auth: Error: ** ld 0x666a60 Outstanding Requests: Feb 19 17:41:36 sng02 dovecot: auth: Error: * msgid 3, origid 3, status InProgress Feb 19 17:41:36 sng02 dovecot: auth: Error: outstanding referrals 0, parent count 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: * msgid 2, origid 2, status InProgress Feb 19 17:41:36 sng02 dovecot: auth: Error: outstanding referrals 0, parent count 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: ld 0x666a60 request count 2 (abandoned 0) Feb 19 17:41:36 sng02 dovecot: auth: Error: ** ld 0x666a60 Response Queue: Feb 19 17:41:36 sng02 dovecot: auth: Error: Empty Feb 19 17:41:36 sng02 dovecot: auth: Error: ld 0x666a60 response count 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_chkResponseList ld 0x666a60 msgid -1 all 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_chkResponseList returns ld 0x666a60 NULL Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_int_select Feb 19 17:41:36 sng02 dovecot: auth: Error: read1msg: ld 0x666a60 msgid -1 all 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: read1msg: ld 0x666a60 msgid 2 message type search-reference Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_chase_v3referrals Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_url_parse_ext(ldap://mydomain.local/CN=Configuration,DC=mydomain,DC=local) Feb 19 17:41:36 sng02 dovecot: auth: Error: re_encode_request: new msgid 4, new dn <CN=Configuration,DC=mydomain,DC=local> Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_chase_v3referral: msgid 2, url "ldap://mydomain.local/CN=Configuration,DC=mydomain,DC=local" Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_send_server_request Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_new_connection 0 1 1 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_int_open_connection Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_connect_to_host: TCP mydomain.local:389 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_new_socket: 18 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_prepare_socket: 18 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_connect_to_host: Trying 192.168.32.2:389 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_pvt_connect: fd: 18 tm: -1 async: 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: anonymous rebind via ldap_sasl_bind("") Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_sasl_bind Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_send_initial_request Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_send_server_request Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_result ld 0x666a60 msgid 5 Feb 19 17:41:36 sng02 dovecot: auth: Error: wait4msg ld 0x666a60 msgid 5 (timeout 100000 usec) Feb 19 17:41:36 sng02 dovecot: auth: Error: wait4msg continue ld 0x666a60 msgid 5 all 1 Feb 19 17:41:36 sng02 dovecot: auth: Error: ** ld 0x666a60 Connections: Feb 19 17:41:36 sng02 dovecot: auth: Error: * host: mydomain.local port: 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: refcnt: 2 status: Connected Feb 19 17:41:36 sng02 dovecot: auth: Error: last used: Tue Feb 19 17:41:36 2013 Feb 19 17:41:36 sng02 dovecot: auth: Error: rebind in progress Feb 19 17:41:36 sng02 dovecot: auth: Error: queue is empty Feb 19 17:41:36 sng02 dovecot: auth: Error: Feb 19 17:41:36 sng02 dovecot: auth: Error: * host: localhost port: 389 (default) Feb 19 17:41:36 sng02 dovecot: auth: Error: refcnt: 4 status: Connected Feb 19 17:41:36 sng02 dovecot: auth: Error: last used: Tue Feb 19 17:41:36 2013 Feb 19 17:41:36 sng02 dovecot: auth: Error: Feb 19 17:41:36 sng02 dovecot: auth: Error: Feb 19 17:41:36 sng02 dovecot: auth: Error: ** ld 0x666a60 Outstanding Requests: Feb 19 17:41:36 sng02 dovecot: auth: Error: * msgid 5, origid 5, status InProgress Feb 19 17:41:36 sng02 dovecot: auth: Error: outstanding referrals 0, parent count 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: * msgid 3, origid 3, status InProgress Feb 19 17:41:36 sng02 dovecot: auth: Error: outstanding referrals 0, parent count 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: * msgid 2, origid 2, status InProgress Feb 19 17:41:36 sng02 dovecot: auth: Error: outstanding referrals 1, parent count 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: ld 0x666a60 request count 3 (abandoned 0) Feb 19 17:41:36 sng02 dovecot: auth: Error: ** ld 0x666a60 Response Queue: Feb 19 17:41:36 sng02 dovecot: auth: Error: Empty Feb 19 17:41:36 sng02 dovecot: auth: Error: ld 0x666a60 response count 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_chkResponseList ld 0x666a60 msgid 5 all 1 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_chkResponseList returns ld 0x666a60 NULL Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_int_select Feb 19 17:41:36 sng02 dovecot: auth: Error: read1msg: ld 0x666a60 msgid 5 all 1 Feb 19 17:41:36 sng02 dovecot: auth: Error: read1msg: ld 0x666a60 msgid 2 message type search-result Feb 19 17:41:36 sng02 dovecot: auth: Error: read1msg: ld 0x666a60 0 new referrals Feb 19 17:41:36 sng02 dovecot: auth: Error: read1msg: mark request completed, ld 0x666a60 msgid 2 Feb 19 17:41:36 sng02 dovecot: auth: Error: wait4msg ld 0x666a60 0 s 99954 us to go Feb 19 17:41:36 sng02 dovecot: auth: Error: wait4msg continue ld 0x666a60 msgid 5 all 1 Feb 19 17:41:36 sng02 dovecot: auth: Error: ** ld 0x666a60 Connections: Feb 19 17:41:36 sng02 dovecot: auth: Error: * host: mydomain.local port: 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: refcnt: 2 status: Connected Feb 19 17:41:36 sng02 dovecot: auth: Error: last used: Tue Feb 19 17:41:36 2013 Feb 19 17:41:36 sng02 dovecot: auth: Error: rebind in progress Feb 19 17:41:36 sng02 dovecot: auth: Error: queue is empty Feb 19 17:41:36 sng02 dovecot: auth: Error: Feb 19 17:41:36 sng02 dovecot: auth: Error: * host: localhost port: 389 (default) Feb 19 17:41:36 sng02 dovecot: auth: Error: refcnt: 3 status: Connected Feb 19 17:41:36 sng02 dovecot: auth: Error: last used: Tue Feb 19 17:41:36 2013 Feb 19 17:41:36 sng02 dovecot: auth: Error: Feb 19 17:41:36 sng02 dovecot: auth: Error: Feb 19 17:41:36 sng02 dovecot: auth: Error: ** ld 0x666a60 Outstanding Requests: Feb 19 17:41:36 sng02 dovecot: lda: Debug: auth input: marco.carcano quota_rule=*:storage=8192M Feb 19 17:41:36 sng02 dovecot: lda: Debug: Added userdb setting: plugin/quota_rule=*:storage=8192M Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: Effective uid=8, gid=12, home= Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: Quota root: name=User quota backend=maildir args= Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: Quota rule: root=User quota mailbox=* bytes=8589934592 messages=0 Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: Quota rule: root=User quota mailbox=Trash bytes=+104857600 messages=0 Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: Quota warning: bytes=8160437862 (95%) messages=0 reverse=no command=quota-warning 95 marco.carcano Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: Quota warning: bytes=7301444403 (85%) messages=0 reverse=no command=quota-warning 85 marco.carcano Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: Quota warning: bytes=6442450944 (75%) messages=0 reverse=no command=quota-warning 75 marco.carcano Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: Quota root: name=Shared quota backend=maildir args=ns=Public/ Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: Quota rule: root=Shared quota mailbox=* bytes=20971520000 messages=0 Feb 19 17:41:36 sng02 dovecot: lda: Error: user marco.carcano: Auth USER lookup failed Feb 19 17:41:36 sng02 dovecot: lda: Debug: auth input: Feb 19 17:41:36 sng02 dovecot: lda: Fatal: Internal error occurred. Refer to server log for more information. Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: Namespace : type=private, prefix=, sep=/, inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:/home/mailboxstore/marco.carcano/Maildir Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: maildir++: root=/home/mailboxstore/marco.carcano/Maildir, index=, control=, inbox=/home/mailboxstore/marco.carcano/Maildir Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: Namespace : type=shared, prefix=shared/%u/, sep=/, inbox=no, hidden=no, list=children, subscriptions=no location=maildir:/home/mailboxstore/%Lu/Maildir:INDEX=/home/mailboxstore/marco.carcano/Maildir/shared/%Lu Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: shared: root=/var/run/dovecot, index=, control=, inbox= Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: Namespace : type=public, prefix=Public/, sep=/, inbox=no, hidden=no, list=yes, subscriptions=no location=maildir:/home/mailboxstore/public Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: maildir++: root=/home/mailboxstore/public, index=, control=, inbox= Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: expire: No expire setting - plugin disabled Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: Quota root: name=User quota backend=maildir args= Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: Quota rule: root=User quota mailbox=* bytes=1073741824 messages=0 Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: Quota rule: root=User quota mailbox=Trash bytes=+104857600 messages=0 Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: Quota warning: bytes=1020054732 (95%) messages=0 reverse=no command=quota-warning 95 marco.carcano Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: Quota warning: bytes=912680550 (85%) messages=0 reverse=no command=quota-warning 85 marco.carcano Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: Quota warning: bytes=805306368 (75%) messages=0 reverse=no command=quota-warning 75 marco.carcano Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: Quota root: name=Shared quota backend=maildir args=ns=Public/ Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: Quota rule: root=Shared quota mailbox=* bytes=20971520000 messages=0 Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: none: root=, index=, control=, inbox= Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Error: User marco.carcano doesn't have home dir set, disabling duplicate database Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: sieve: user's script path /home/mailboxstore/marco.carcano/.dovecot.sieve doesn't exist (using global script path in stead) Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: sieve: user has no valid personal script Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: sieve: no scripts to execute: reverting to default delivery. Feb 19 17:41:36 sng02 postfix/pipe[3995]: 7D9AE407E7: to=<marco.carcano @ mydomain.local>, orig_to=<mac @ mydomain.com>, relay=dovecot, delay=17102, delays=17034/0.05/0/68, dsn=4.3.0, status=deferred (temporary failure) Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): msgid=<20130219164128.95659407F5 @ srv01.mydomain.local>: saved mail to INBOX Feb 19 17:41:36 sng02 postfix/pipe[4013]: 95659407F5: to=<marco.carcano @ mydomain.local>, orig_to=<mac @ mydomain.com>, relay=dovecot, delay=22, delays=22/0.02/0/0.14, dsn=2.0.0, status=sent (delivered via dovecot service) Feb 19 17:41:36 sng02 postfix/qmgr[3992]: 95659407F5: removed Feb 19 17:41:38 sng02 postfix/smtpd[4006]: disconnect from localhost[127.0.0.1] ############################## END OF MAIL SUCCEFFULLY DELIVERED LOG #############################################

1 0

[Dovecot] Changin password in LDAP
by Arto Saraniva 20 Feb '13

20 Feb '13

We are using now dovecot 2.0.21 with open-ldap, but this situations has already taken a quite long time. When user changes the password, we have to reload dovecot every time, otherwise the change is ignored and dovecot sees only the old password. Any ideas where the problem might exist? Conf: # 2.0.21: /etc/dovecot/dovecot.conf # OS: Linux 2.6.18-308.24.1.el5 i686 CentOS release 5.9 (Final) auth_cache_size = 100 M auth_mechanisms = plain login auth_verbose = yes default_process_limit = 5000 disable_plaintext_auth = no info_log_path = /var/log/dovecot.log mail_location = maildir:~/Maildir:INDEX=/var/spool/indexes/%u 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 mbox_write_locks = fcntl passdb { args = /etc/dovecot/dovecot-ldap.conf.ext driver = ldap } plugin { quota = maildir:User Quota sieve = ~/.dovecot.sieve sieve_dir = ~/sieve } postmaster_address = postmaster(a)artio.net service auth { unix_listener /var/spool/postfix/private/auth { mode = 0666 } } service imap-login { service_count = 0 } service imap-postlogin { executable = script-login /usr/local/sbin/dovecot-postscript-imap user = root } service imap { executable = imap imap-postlogin } service pop3-postlogin { executable = script-login /usr/local/sbin/dovecot-postscript-pop3 user = root } service pop3 { executable = pop3 pop3-postlogin } ssl_ca = </usr/share/ssl/certs/mail_artio_net-2012-geotrust.ca ssl_cert = </usr/share/ssl/certs/mail_artio_net-2012-geotrust.crt ssl_key = </usr/share/ssl/private/mail_artio_net-2012-geotrust.key userdb { args = /etc/dovecot/dovecot-ldap.conf.ext driver = ldap } protocol lda { mail_plugins = sieve quota } protocol imap { mail_max_userip_connections = 50 mail_plugins = quota imap_quota } protocol pop3 { mail_plugins = quota pop3_uidl_format = %08Xu%08Xv } Dovecot-ldap.conf: # NOTE: We don't support "authentication binds", so you'll have to give # dovecot-auth read access to userPassword field in LDAP server. With OpenLDAP # this is done by modifying /etc/ldap/slapd.conf. There should already be # something like this: # access to attribute=userPassword # by dn="<dovecot's dn>" read # add this # by anonymous auth # by self write # by * none # Space separated list of LDAP hosts to use. host:port is allowed too. #hosts = hosts = 123.123.123.123 123.123.123.124 # Distinguished Name - the username used to login to the LDAP server #dn = # Password for LDAP server #dnpass = # LDAP protocol version to use. Likely 2 or 3. ldap_version = 3 # LDAP base #base = uid=someone, dc=foo, dc=bar, dc=org base = dc=artio,dc=net # Dereference: never, searching, finding, always deref = never # Search scope: base, onelevel, subtree scope = subtree # User attributes in order: # Virtual user name (user@domain) # Home directory # MAIL environment # System user name (for getting user's groups from /etc/group) # - For virtual users you don't want to use this, so this defaults to none. # System UID # System GID #user_attrs = uid,homeDirectory,,,uidNumber,gidNumber # user_attrs = homeDirectory=home,uidNumber=uid,gidNumber=gid # user_attrs = cn,homeDirectory,,uid,uidNumber,gidNumber #user_attrs = homeDirectory=home,uidNumber=uid,gidNumber=gid user_attrs = homeDirectory=home,uidNumber=uid,gidNumber=gid,artioMailQuotaSize=quota_rule=*:storage=%$M # Filter for user lookup. Some variables can be used: # %u - username # %n - user part in user@domain, same as %u if there's no domain # %d - domain part in user@domain, empty if user there's no domain #user_filter = (&(objectClass=posixAccount)(uid=%u)) user_filter = (&(objectClass=posixAccount)(|(uid=%u)(mail=%u))) # Password checking attributes in order: # Virtual user name (user@domain) # Password, may optionally start with {type}, eg. {crypt} #pass_attrs = uid,userPassword # pass_attrs = cn,userPassword pass_attrs = uid=user, userPassword=password # Filter for password lookups #pass_filter = (&(objectClass=posixAccount)(uid=%u)) pass_filter = (&(objectClass=posixAccount)(|(uid=%u)(mail=%u))) # Default password scheme. "{scheme}" before password overrides this. # Currently supported schemes include PLAIN, PLAIN-MD5, DIGEST-MD5, CRYPT #default_pass_scheme = CRYPT default_pass_scheme = CRYPT # You can use same UID and GID for all user accounts if you really want to. # If the UID/GID is still found from LDAP reply, it overrides these values. #user_global_uid = #user_global_gid = Pam: /etc/pam.d/dovecot #%PAM-1.0 auth required pam_nologin.so auth include system-auth account include system-auth session include system-auth

1 0

[Dovecot] Dovecot 2 + Quota - CentOS 6.3
by drum.lucas＠gmail.com 20 Feb '13

20 Feb '13

Hello, I've a postfix+postfixadmin+mysql server+roundcubemail centos 6 mail server. My question is as follows: In postfixadmin it's possible that he show me how the mailbox is full. Show this information is dovecot service? What is the purpose of quota in dovecot? Thanks! *Lucas Possamai *

2 1

[Dovecot] 1.x with mbox files to 2.x with mdbox, I think?
by Ken A 20 Feb '13

20 Feb '13

Hi, I have a couple questions about migrating from 1.x to 2.x I'm needing to support larger mailbox sizes and mdbox seems like the right format to use to get larger size boxes and maintain, or possibly even increase speed. Is that correct? Am I correct that the best way to accomplish this migration is to copy the mboxes over to the new server and then use dsync to convert them to mdbox? Thanks for your thoughts! Ken -- Ken Anderson Pacific Internet - http://www.pacific.net Latest Pacific.Net Status - http://twitter.com/pacnetstatus

1 0

[Dovecot] Ping re: error running indexer-worker as non-root user
by Mike Abbott 19 Feb '13

19 Feb '13

Any hints about the issue I wrote about on Feb. 11? http://markmail.org/message/6g7itsu2u3fdnfkd Thanks.

1 0

[Dovecot] Dovecot-2.1.14 - pop3 processes always hangs forever - another follow-up
by Axel Luttgens 19 Feb '13

19 Feb '13

Hello, With the same basic configs as in my previous messages, I tried with the maildir format instead of the mbox format. That is, in both cases ("virtual" uids/gids vs a single "real" uid/gid), doveconf -n shows: mail_location = maildir:~/maildir instead of: mail_location = mbox:~/mboxes:INBOX=~/mboxes/inbox Here too, with "virtual" uids/gids, connections thru pop hang forever, while imap connections behave flawlessly. And with a single "real" uid/gid, connections thru both pop and imap behave as expected. As a result, it could be inferred that the problems I am encountering with pop connections do not depend on the mailbox format in use, and that they are entirely related to "virtual" uids/gids. To recap: with this very basic config # 2.1.14: /_ETC/dovecot/dovecot.conf # OS: Darwin 12.2.1 x86_64 auth_verbose = yes disable_plaintext_auth = no mail_debug = yes mail_location = mbox:~/mboxes:INBOX=~/mboxes/inbox passdb { args = /_ETC/dovecot/db.conf driver = sql } ssl = no userdb { driver = prefetch } a pop connection hangs forever after the pass command $ telnet 127.0.0.1 110 Trying 127.0.0.1... Connected to localhost. Escape character is '^]'. +OK Dovecot ready. user user2 +OK pass pass2 and the log shows (here, when the user connects for the first time) dovecot[2997]: pop3-login: Login: user=<user2>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=3113, secured, session=<GTOlMjfV3gB/AAAB> dovecot[2997]: pop3(user2): Debug: Effective uid=100003, gid=100003, home=/_Data/Mailstores/100003 dovecot[2997]: pop3(user2): Debug: Home dir not found: /_Data/Mailstores/100003 dovecot[2997]: pop3(user2): Debug: fs: root=/_Data/Mailstores/100003/mboxes, index=, control=, inbox=/_Data/Mailstores/100003/mboxes/inbox, alt= dovecot[2997]: pop3(user2): Debug: Namespace : /_Data/Mailstores/100003/mboxes doesn't exist yet, using default permissions dovecot[2997]: pop3(user2): Debug: Namespace : Using permissions from /_Data/Mailstores/100003/mboxes: mode=0700 gid=-1 dovecot[2997]: pop3(user2): Debug: Namespace : /_Data/Mailstores/100003/mboxes/inbox doesn't exist yet, using default permissions dovecot[2997]: pop3(user2): Debug: Namespace : Using permissions from /_Data/Mailstores/100003/mboxes: mode=0700 gid=-1 dovecot[2997]: pop3(user2): Debug: Namespace : /_Data/Mailstores/100003/mboxes/inbox doesn't exist yet, using default permissions dovecot[2997]: pop3(user2): Debug: Namespace : Using permissions from /_Data/Mailstores/100003/mboxes: mode=0700 gid=-1 With exactly the same config, imap connections are fully functional. Does someone have an explanation? TIA, Axel

2 11

[Dovecot] Defer emails until the user is ready to deal with them (snooze button / bring-forward file / bring-up file for emails)
by Chris Laif 19 Feb '13

19 Feb '13

Hi, I would like to add a feature to my email-client (Thunderbird) which stops emails from showing up until a specific time (e.g. having buttons for: show again this evening, tomorrow, next week, next month ...). As far as I've learned this is not possible with IMAP: - storing the 'do-not-show-until-time' within a custom header-field requires down- and uploading of the whole email and therefore causes problems especially with large emails - IMAP keywords are limited are limited in quantity and can not be compared with datetime functions Any suggestions will be greatly appreciated! Chris

6 20