- dovecot - dovecot.org

[Dovecot] Dovecot v2.0.beta5 (1b45f9641924): Auth Crashes
by Thomas Leuxner 08 Jun '10

08 Jun '10

Hi, not sure which change caused it, but one of the latest adds between those two snapshots breaks userdb lookup: Jun 1 21:53:30 spectre dovecot: master: Dovecot v2.0.beta5 (1b45f9641924) starting up Jun 1 21:53:30 spectre dovecot: master: Warning: Killed with signal 15 (by pid=6898 uid=0 […] Jun 1 21:53:40 spectre dovecot: master: Dovecot v2.0.beta5 (55b8480849b0) starting up Jun 1 21:53:40 spectre dovecot: master: Warning: Killed with signal 15 (by pid=8577 uid=0 code=kill) Jun 1 21:52:30 spectre postfix/lmtp[6787]: F151B408D: to=<tlx(a)leuxner.net>, relay=spectre.leuxner.net[private/dovecot-lmtp], delay=0.09, delays=0.06/0/0/0.04, dsn=4.3.0, status=deferred (host spectre.leuxner.net[private/dovecot-lmtp] said: 451 4.3.0 <tlx(a)leuxner.net> Internal error occurred. Refer to server log for more information. (in reply to RCPT TO command)) ==> /var/log/dovecot.log <== Jun 1 21:52:30 spectre dovecot: lmtp(6788): Connect from local Jun 1 21:52:30 spectre dovecot: master: Error: service(auth): child 6797 killed with signal 11 (core not dumped) Jun 1 21:52:30 spectre dovecot: lmtp(6788): Error: userdb lookup(tlx(a)leuxner.net): Disconnected unexpectedly Jun 1 21:52:30 spectre dovecot: master: Error: service(auth): command startup failed, throttling Jun 1 21:52:30 spectre dovecot: lmtp(6788): Disconnect from local: Client quit ==> /var/log/mail.log <== Jun 1 21:52:58 spectre postfix/qmgr[3246]: 5619A4086: from=<users-return-95390-lists=leuxner.net(a)httpd.apache.org>, size=6226, nrcpt=1 (queue active) ==> /var/log/dovecot.log <== Jun 1 21:52:58 spectre dovecot: lmtp(6788): Connect from local Reverting to changeset 55b8480849b0 restores functionality. Regards Thomas

3 10

[Dovecot] The driver said: (QUOTA) "Quota exceeded" (Ingo sieve filter in horde)
by Iced Fox 08 Jun '10

08 Jun '10

I have $conf['storage']['params']['driverconfig'] = 'horde'; $conf['storage']['driver'] = 'sql'; in /var/www/html/horde/ingo/config/conf.php I have 2,146 records for one of the users in ingo_lists table of horde DB. The size of the script (.dovecot.sieve file) is 99.965 bytes. When trying to activate script I get the following # Changes saved. # Error There was an error activating the script. The driver said: (QUOTA) "Quota exceeded" Please let me know where I can change that size of QUOTA

2 1

[Dovecot] Migration from Courier to Dovecot: is it recommended to "force" d.index* creation?
by Sandro Tosi 08 Jun '10

08 Jun '10

Hello, we are planning to migrate from Courier to Dovecot. We already know courier-dovecot-migrate.pl, that will convert UID list and subscriptions files to dovecot format, and we will run it in batch on all Maildir + enable it at login, once we do the switch But we are also wondering it it might be wise to "force" the creation of dovecot.index{,.cache} files at conversion-time. It seems that, at least, d.i.c is created at FETCH of a mail, i.e. reading it, but we do not want to "alter" mails status of our clients. Is there a way to create them in batch, or is it better to just let them be created once clients start accessing their mailboxes via dovecot? Thanks in advance, Sandro

2 1

[Dovecot] Problem after migrating from mbox to maildir and squirrelmail
by Wawan S 08 Jun '10

08 Jun '10

Hi all, I just finished migrating from mbox to maildir (and upgrade squirrelmail to the latest version) with some issue. We are using Postfix 2.3, Dovecot 1.2.7 and Squirrelmail 1.4.2. One of user report that suddenly all his Sent and Drafts emails were disapeared. After log in to webmail, I found out that there are 3 new folder called Drafts, Sent and Trash apart from Drafts,Sent,Trash underneath INBOX folder, and all his sent and draft emails were there. I thought I just move the email from Sent folder to the Sent underneath INBOX, but I was wrong. Now he got all sent emails in Sent items but after refreshed the webmail, INBOX wont open at all. it just blank but in the left side it said the amount of his email. what did i do wrong? is it something to do with the dovecot.index and index.cache or the uidlist? please enlighten me.... thank you Hendry

1 0

[Dovecot] dovecot transaction log permissions
by Jordan Tardif 08 Jun '10

08 Jun '10

So after some problems with NFS and transaction logs getting corrupted. Im tyring out storing them localy. via.. mail_location: maildir:~/Maildir:INDEX=/var/dovecot/indexes/%u the problem is with a large amount of users.. the indexes dir becomes huge with this setup. So a change to make this better is... mail_location: maildir:~/Maildir:INDEX=/var/dovecot/indexes/%d/%n to seperate the users dir's into domains. What seems to happen is dovecot creates the index's folder automaticly and its owned by that user.. eg.. drwx------ 3 10651674 2598184 4096 2010-06-02 19:08 domain.com this makes it so no other user of domain.com can get their transaction logs created cause the dir is owned by another user at that domain. Is there anyway around this? I see there used to be a umask option but that is gone in 1.2.x. -- Jordan Tardif DreamHost

3 4

[Dovecot] PAM ISSUE (auth-worker)
by Philip Coackley 08 Jun '10

08 Jun '10

Hello ISSUE: Intermittently getting username and password authentication in clients both OUTLOOK 2007 and latest Thunderbird, indicating that the client is not authenticated with the server. Ie the username and password dialogue constantly reappears. This only appears as more users logged into the system. TEMP FIX: Restart Dovecot. LOG FILES Mail.err Jun 7 15:23:07 mail dovecot: auth-worker(default): ltdb: tdb(/var/lib/samba/group_mapping.ldb): tdb_mmap failed for size 77824 (Cannot allocate memory) Jun 7 15:23:10 mail dovecot: auth(default): worker-server(shepherb,81.152.245.13): Aborted: Worker process died unexpectedly Jun 7 15:23:10 mail dovecot: child 4268 (auth-worker) killed with signal 11 Jun 7 15:46:00 mail dovecot: auth-worker(default): ltdb: tdb(/var/lib/samba/group_mapping.ldb): tdb_mmap failed for size 77824 (Cannot allocate memory) Earlier in the log Jun 7 12:08:02 mail dovecot: auth-worker(default): pam(xxx): pam_start() failed: Critical error - immediate abort FILESYSTEM: EXT3 - DOVECOT CONFIG: # 1.1.11: /etc/dovecot/dovecot.conf # OS: Linux 2.6.31-21-server x86_64 Ubuntu 9.10 log_timestamp: %Y-%m-%d %H:%M:%S listen: 127.0.0.1:143 ssl_listen: *:993 ssl_cert_file: /etc/exim4/exim.crt ssl_key_file: /etc/exim4/exim.key ssl_cipher_list: ALL:!LOW:!SSLv2 login_dir: /var/run/dovecot/login login_executable: /usr/lib/dovecot/imap-login login_greeting: Ready. mail_privileged_group: mail mail_location: maildir:~/Maildir auth default: worker_max_count: 60 worker_max_request_count: 25 passdb: driver: pam userdb: driver: passwd

2 2

[Dovecot] Questions about migration Sun Messaging -> Dovecot+Postfix+Ldap
by Javier de Miguel Rodríguez 07 Jun '10

07 Jun '10

Hello. We are planning a migration from Sun One Messaging Server to Dovecot+Postfix+Ldap. We are using Dovecot 1.2.11 with Sun One Directory Server 5.2 ldap (we will migrate to Directory Server 6.3.1) soon. In our University we have 65.000 students, 5.500 staff and 6.500 teachers. Our main ldap realm is dc=us,dc=es (us means University of Seville, Spain). We have two e-mail domains, @us.es (staff+teachers) and @alum.us.es (students). We use Sun One Directory Server to load data to our ldap from several sources (like Oracle databases, flat files, etc) Our ldap tree is like this: dc=us,dc=es | |----->ou=People,dc=us,dc=es // "special" users only used by apps | | |----->o=us.es,dc=us,dc=es // ldap branch for staff+teachers | | |----->o=alum.us.es,dc=us,dc=es // ldap branch for students A user id is unique, so there is only a "john_doe" in the ldap tree (I repeat, there is NOT uid=john_doe,o=us.es,dc=us,dc=es and uid=john_doe,o=alum.us.es,dc=us,dc=es). Below you will find a copy of the dovecot.conf and dovecot-ldap.conf. Our operating system is Red Hat Enteprise Linux 5 x64. These are our questions: 1) We are unable to make dbox work with quota, but we have no problem with maildir. Quota is stored in a ldap attibute called "mailQuota" 2) A user can be in different branches in the same time: for example, a teacher called pepito should be in the uid=pepito,o=us.es,dc=us,dc=es branch but if that teacher is also a student should have another ldap entry uid=pepitosurname,o=us.es,dc=us,dc=es. Our identity management is the piece of software that "promotes" a user in that case. How should we use "mail_location" to addres this? 3) We are planning to use two raid5 of 8 SAS 15.000 rpm disks for these mailboxes. We will use a "2.0, ajax-based webmail" like roundcube. Most of our users will use webmail (imap based). How many iops should we have in that enviroment? We would like to use dbox, but we are stuck in maildir because 1) 4) Some users could have their mailboxes "disabled". We use the following line: user_filter = (&(objectClass=inetorgperson)(uid=%n)(mailUserStatus=active)) but it does NOT work as expected. Any idea) 5) We are planning to use bacula to backup user mailboxes. Any known problem with this (i will ask in the bacula mailing list anyway) 6) I have read carefully perfomance in dovecot wiki. Can I use noatime in /etc/fstab safely with dovecot? Any perfomance hint apart from we already have in our config files? 7) When we set vacation messages they work but we see this error in the log: dovecot: deliver(jorgelp): file_dotlock_create(~/.dovecot.lda-dupes) failed: No such file or directory 8) When a user log in she uses his username "mary" (without @us.es or @alum.us.es) . Our dovecot search in all the ldap tree until it finds that uid. But we would like to store in our mail_location /buzones/us.es or /buzones/alum.us.es. How can we accomplish this? We should use the "upper branch name" as part of the mail_location. Thank you for your support (and for your patience). Regards Javier <---- Config files ------> dovecot.conf: # 1.2.11: /etc/dovecot.conf # OS: Linux 2.6.18-194.3.1.el5 i686 Red Hat Enterprise Linux Server release 5.5 (Tikanga) ext3 base_dir: /var/run/dovecot/ protocols: pop3 imap imaps pop3s managesieve listen(default): *, [::] listen(imap): *, [::] listen(pop3): *, [::] listen(managesieve): *:2000 login_dir: /var/run/dovecot//login login_executable(default): /usr/libexec/dovecot/imap-login login_executable(imap): /usr/libexec/dovecot/imap-login login_executable(pop3): /usr/libexec/dovecot/pop3-login login_executable(managesieve): /usr/libexec/dovecot/managesieve-login login_max_processes_count: 2000 max_mail_processes: 2000 verbose_proctitle: yes mail_uid: prueba mail_gid: prueba mail_location: maildir:/buzones/us.es/%M/%n/ fsync_disable: yes mail_executable(default): /usr/libexec/dovecot/rawlog /usr/libexec/dovecot/imap mail_executable(imap): /usr/libexec/dovecot/rawlog /usr/libexec/dovecot/imap mail_executable(pop3): /usr/libexec/dovecot/pop3 mail_executable(managesieve): /usr/libexec/dovecot/managesieve mail_plugins(default): quota imap_quota mail_plugins(imap): quota imap_quota mail_plugins(pop3): quota mail_plugins(managesieve): mail_plugin_dir(default): /usr/lib/dovecot/imap mail_plugin_dir(imap): /usr/lib/dovecot/imap mail_plugin_dir(pop3): /usr/lib/dovecot/pop3 mail_plugin_dir(managesieve): /usr/lib/dovecot/managesieve pop3_enable_last(default): no pop3_enable_last(imap): no pop3_enable_last(pop3): yes pop3_enable_last(managesieve): no pop3_uidl_format(default): %08Xu%08Xv pop3_uidl_format(imap): %08Xu%08Xv pop3_uidl_format(pop3): %08Xv%08Xu pop3_uidl_format(managesieve): %08Xu%08Xv lda: postmaster_address: javierdemiguel(a)us.es hostname: us.es mail_plugins: sieve log_path: info_log_path: syslog_facility: mail fsync_disable: no auth default_with_listener: mechanisms: plain login passdb: driver: ldap args: /etc/dovecot-ldap.conf userdb: driver: ldap args: /etc/dovecot-ldap-userdb.conf auth default: mechanisms: plain login passdb: driver: ldap args: /etc/dovecot-ldap.conf userdb: driver: ldap args: /etc/dovecot-ldap.conf socket: type: listen master: path: /var/run/dovecot/auth-master mode: 511 user: prueba plugin: quota: maildir:Cuota de usuario quota_warning: storage=95%% /usr/local/bin/quota-warning.sh 95 quota_warning2: storage=80%% /usr/local/bin/quota-warning.sh 80 sieve: /buzones/us.es/%M/%n/dovecot.sieve sieve_dir: /buzones/us.es/%M/%n/sieve/ dovecot-ldap.conf hosts = ip_address:389 dn = uid=nuevobuzon,ou=People,dc=us,dc=es dnpass = password auth_bind = yes auth_bind_userdn= uid=%n,o=us.es,dc=us,dc=es ldap_version = 3 base = dc=us,dc=es user_attrs = mailQuota=quota_rule=*:storage=%$B user_filter = (&(objectClass=inetorgperson)(uid=%n)(mailUserStatus=active))

2 2

[Dovecot] Dovecot 2.0 shared mailbox using ACLs problem
by p.quidacciolu＠libero.it 07 Jun '10

07 Jun '10

Hi, I'm trying to configure shared mailboxes using ACLs. On dovecot 1.2.10 it works fine, but the same configuration on dovecot 2.0. beta4 doesn't work. When I try to access to the shared mailbox I get the following message: Query: SELECT "users/user2/INBOX" Reason Given: Mailbox doesn't exist: users/user2/INBOX In the next the dovecot -n output and the dovecot-ldap.conf content: # 2.0.beta4: /usr/local/etc/dovecot/dovecot.conf # OS: Linux 2.6.9-89.ELsmp i686 Red Hat Enterprise Linux AS release 4 (Nahant Update 8) ext3 auth_mechanisms = plain login mail_debug = yes mail_gid = mailusers mail_location = maildir:/mnt/mbox1/mailusers/%n/Maildir mail_uid = mailusers namespace { inbox = yes location = prefix = separator = / type = private } namespace { hidden = no list = children location = maildir:/mnt/mbox1/mailusers/%%n/Maildir: INDEX=/mnt/mbox1/mailusers/%n/Maildir/users/%%n prefix = users/%%n/ separator = / subscriptions = no type = shared } passdb { args = /usr/local/etc/dovecot/dovecot-ldap.conf driver = ldap } plugin { acl = vfile acl_shared_dict = file:/var/tmp/shared-mailboxes.db } service auth { user = root } ssl = no userdb { driver = passwd } userdb { args = /usr/local/etc/dovecot/dovecot-ldap.conf driver = ldap } protocol imap { mail_plugins = quota imap_quota acl imap_acl # /usr/local/etc/dovecot/dovecot-ldap.conf hosts = ldap-vip base = o=mailusers user_attrs = mailQuota=quota_rule=*:backend=%$ user_filter = (&(objectClass=person)(|(uid=%u)(uid=%n))) pass_attrs = uid=user,userPassword=password pass_filter = (&(objectClass=person)(|(uid=%u)(uid=%n))) Regards, Pier Luigi

2 1

[Dovecot] dovecot 2 beta4 errors & core dumps
by de Lafond Guillaume 07 Jun '10

07 Jun '10

Hi, While running imaptest with "clients=50 seed=123 msgs=100000000 random secs=600", I got errors : "Error: user(a)domain.com[55]: Unexpected BYE: * BYE IMAP session state is inconsistent, please relogin.". dovecot.log : Apr 03 10:23:47 imap(user(a)domain.com): Panic: file index- transaction.c: line 145 (index_transaction_rollback): assertion failed: (box->transaction_count > 0 || box->view->transactions == 0) Apr 03 10:23:47 imap(user(a)domain.com): Error: Raw backtrace: /usr/ local/dovecot2/lib/dovecot/libdovecot.so.0 [0xb7e9adc1] -> /usr/local/ dovecot2/lib/dovecot/libdovecot.so.0 [0xb7e9ae3f] -> /usr/local/ dovecot2/lib/dovecot/libdovecot.so.0(i_error+0) [0xb7e9b0f8] -> /usr/ local/dovecot2/lib/dovecot/libdovecot-storage.so.0 [0xb7f3e9c2] -> / usr/local/dovecot2/lib/dovecot/lib10_quota_plugin.so [0xb7cdaaea] -> / usr/local/dovecot2/lib/dovecot/libdovecot-storage.so. 0(mailbox_transaction_rollback+0x20) [0xb7ef03f0] -> /usr/local/ dovecot2/lib/dovecot/lib10_quota_plugin.so [0xb7cda323] -> /usr/local/ dovecot2/lib/dovecot/lib10_quota_plugin.so [0xb7cda4df] -> /usr/local/ dovecot2/lib/dovecot/libdovecot-storage.so.0(maildir_sync_index+0x897) [0xb7f52bb7] -> /usr/local/dovecot2/lib/dovecot/libdovecot-storage.so. 0(maildir_transaction_save_commit_pre+0x710) [0xb7f50f70] -> /usr/ local/dovecot2/lib/dovecot/libdovecot-storage.so.0 [0xb7f3ee27] -> / usr/local/dovecot2/lib/dovecot/libdovecot-storage.so. 0(mail_index_transaction_commit_full+0x85) [0xb7f08ee5] -> /usr/local/ dovecot2/lib/dovecot/libdovecot-storage.so.0(index_transaction_commit +0x83) [0xb7f3ea53] -> /usr/local/dovecot2/lib/dovecot/ lib10_quota_plugin.so [0xb7cdab81] -> /usr/local/dovecot2/lib/dovecot/ libdovecot-storage.so.0(mailbox_transaction_commit_get_changes+0x42) [0xb7ef0c72] -> dovecot/imap [user(a)domain.com 10.0.0.5 APPEND] [0x804eab2] -> dovecot/imap [user(a)domain.com 10.0.0.5 APPEND] [0x804e8cb] -> dovecot/imap [user(a)domain.com 10.0.0.5 APPEND] [0x804ed02] -> dovecot/imap [user(a)domain.com 10.0.0.5 APPEND] (cmd_append+0x1d9) [0x804f069] -> dovecot/imap [user(a)domain.com 10.0.0.5 APPEND] [0x80562dc] -> dovecot/imap [user(a)domain.com 10.0.0.5 APPEND] [0x8056379] -> dovecot/imap [user(a)domain.com 10.0.0.5 APPEND] (client_handle_input+0x2d) [0x80564ed] -> dovecot/imap [user(a)domain.com 10.0.0.5 APPEND](client_input+0x5f) [0x8056f0f] -> / usr/local/dovecot2/lib/dovecot/libdovecot.so.0(io_loop_handler_run +0xf5) [0xb7ea7425] -> /usr/local/dovecot2/lib/dovecot/libdovecot.so. 0(io_loop_run+0x30) [0xb7ea6470] -> /usr/local/dovecot2/lib/dovecot/ libdovecot.so.0(master_service_run+0x2a) [0xb7e93eaa] -> dovecot/imap [user(a)domain.com 10.0.0.5 APPEND](main+0x2ad) [0x805f9ed] -> /lib/i686/cmov/libc.so. 6(__libc_start_main+0xe5) [0xb7d0f455] Apr 03 10:23:47 master: Error: service(imap): child 27371 killed with signal 6 (core dumped) Apr 03 10:23:50 imap(user(a)domain.com): Error: dotlock /var/mail/d/ domain.com/user/Maildir/dovecot-uidlist.lock was immediately deleted under us Apr 03 10:23:50 imap(user(a)domain.com): Error: dotlock /var/mail/d/ domain.com/user/Maildir/dovecot-uidlist.lock was immediately deleted under us Apr 03 10:23:50 imap(user(a)domain.com): Warning: Our dotlock file /var/ mail/d/domain.com/user/Maildir/dovecot-uidlist.lock was deleted (locked 0 secs ago, touched 0 secs ago) Apr 03 10:23:50 imap(user(a)domain.com): Warning: Our dotlock file /var/ mail/d/domain.com/user/Maildir/dovecot-uidlist.lock was deleted (locked 0 secs ago, touched 0 secs ago) Apr 03 10:23:50 imap(user(a)domain.com): Error: Log synchronization error at seq=2,offset=8188 for /var/mail/dovecot_indexes/d/domain.com/ user/.INBOX/dovecot.index: Append with UID 32, but next_uid = 33 Apr 03 10:23:50 imap(user(a)domain.com): Warning: fscking index file / var/mail/dovecot_indexes/d/domain.com/user/.INBOX/dovecot.index Apr 03 10:23:50 imap(user(a)domain.com): Error: Log synchronization error at seq=2,offset=8188 for /var/mail/dovecot_indexes/d/domain.com/ user/.INBOX/dovecot.index: Append with UID 32, but next_uid = 33 Apr 03 10:23:50 imap(user(a)domain.com): Warning: fscking index file / var/mail/dovecot_indexes/d/domain.com/user/.INBOX/dovecot.index Apr 03 10:23:50 imap(user(a)domain.com): Warning: Our dotlock file /var/ mail/d/domain.com/user/Maildir/dovecot-uidlist.lock was overridden (locked 0 secs ago, touched 0 secs ago) Apr 03 10:23:50 imap(user(a)domain.com): Error: dotlock /var/mail/d/ domain.com/user/Maildir/dovecot-uidlist.lock was immediately recreated under us Apr 03 10:23:50 imap(user(a)domain.com): Error: Log synchronization error at seq=2,offset=8188 for /var/mail/dovecot_indexes/d/domain.com/ user/.INBOX/dovecot.index: Append with UID 32, but next_uid = 33 Apr 03 10:23:50 imap(user(a)domain.com): Warning: fscking index file / var/mail/dovecot_indexes/d/domain.com/user/.INBOX/dovecot.index The backtrace : Core was generated by `dovecot/imap'. Program terminated with signal 6, Aborted. [New process 27371] #0 0xb7f85424 in __kernel_vsyscall () (gdb) bt full #0 0xb7f85424 in __kernel_vsyscall () No symbol table info available. #1 0xb7d24640 in raise () from /lib/i686/cmov/libc.so.6 No symbol table info available. #2 0xb7d26018 in abort () from /lib/i686/cmov/libc.so.6 No symbol table info available. #3 0xb7e9add5 in default_fatal_finish (type=<value optimized out>, status=0) at failures.c:164 backtrace = 0x80643d0 "/usr/local/dovecot2/lib/dovecot/libdovecot.so. 0 [0xb7e9adc1] -> /usr/local/dovecot2/lib/dovecot/libdovecot.so.0 [0xb7e9ae3f] -> /usr/local/dovecot2/lib/dovecot/libdovecot.so.0(i_error +0) [0xb7e9b0f8] "... #4 0xb7e9ae3f in i_internal_fatal_handler (type=LOG_TYPE_PANIC, status=0, fmt=0xb7f6f1c4 "file %s: line %d (%s): assertion failed: (%s)", args=0xbfffda44 "\2228??\221") at failures.c:592 No locals. #5 0xb7e9b0f8 in i_panic (format=0xb7f6f1c4 "file %s: line %d (%s): assertion failed: (%s)") at failures.c:230 No locals. #6 0xb7f3e9c2 in index_transaction_rollback (t=0x80b2a90) at index- transaction.c:144 box = (struct mailbox *) 0x808d340 itrans = (struct mail_index_transaction *) 0x0 __FUNCTION__ = "index_transaction_rollback" #7 0xb7cdaaea in quota_mailbox_transaction_rollback (ctx=0x80b2a90) at quota-storage.c:112 qt = (struct quota_transaction_context *) 0x80a9628 #8 0xb7ef03f0 in mailbox_transaction_rollback (_t=0x808d780) at mail- storage.c:1155 t = (struct mailbox_transaction_context *) 0x6aeb #9 0xb7cda323 in quota_mailbox_sync_cleanup (qbox=0x808d6c0) at quota- storage.c:246 No locals. #10 0xb7cda4df in quota_mailbox_sync_notify (box=0x808d340, uid=0, sync_type=<value optimized out>) at quota-storage.c:274 qbox = (struct quota_mailbox *) 0x808d6c0 i = <value optimized out> count = <value optimized out> size = <value optimized out> #11 0xb7f52bb7 in maildir_sync_index (ctx=0x80b45a0, partial=true) at maildir-sync-index.c:631 mbox = (struct maildir_mailbox *) 0x808d340 view = (struct mail_index_view *) 0x80a9270 view2 = (struct mail_index_view *) 0x0 iter = (struct maildir_uidlist_iter_ctx *) 0x0 trans = (struct mail_index_transaction *) 0x80b42c8 hdr = (const struct mail_index_header *) 0x80a85f8 empty_hdr = {major_version = 0 '\0', minor_version = 0 '\0', base_header_size = 0, header_size = 0, record_size = 576, compat_flags = 8 '\b', unused = "???", indexid = 3084301177, flags = 3085242720, uid_validity = 28, next_uid = 3085743644, messages_count = 134956776, unused_old_recent_messages_count = 576, seen_messages_count = 3221216296, deleted_messages_count = 3085530619, first_recent_uid = 3085747040, first_unseen_uid_lowwater = 0, first_deleted_uid_lowwater = 0, log_file_seq = 576, log_file_tail_offset = 28, log_file_head_offset = 1, sync_size = 13256344077235912704, sync_stamp = 3085747040, day_stamp = 134956776, day_first_uid = {3221216328, 3085530784, 3085747040, 3085781192, 3086502160, 3085743644, 4294967295, 3086618612}} rec = <value optimized out> seq = 0 seq2 = 0 uid = 29 prev_uid = 29 uflags = 0 filename = 0x80aee58 "1270283027.M108835P27367.test- mail,S=1837,W=1881:2," uid_validity = 1270283075 next_uid = <value optimized out> hdr_next_uid = 30 first_recent_uid = 30 first_uid = 1 changes = 4 ret = 0 time_before_sync = 1270283027 expunged_guid_128 = "?????o\216\bl\236?\000?8=\216" expunged = false full_rescan = false __FUNCTION__ = "maildir_sync_index" #12 0xb7f50f70 in maildir_transaction_save_commit_pre (_ctx=0x80ada00) at maildir-save.c:765 _t = (struct mailbox_transaction_context *) 0x80a9d38 last_mf = <value optimized out> sync_flags = <value optimized out> ret = <value optimized out> __FUNCTION__ = "maildir_transaction_save_commit_pre" #13 0xb7f3ee27 in index_transaction_index_commit (index_trans=0x80aa258, result_r=0xbfffddcc) at index-transaction.c:27 it = (struct index_transaction_context *) 0x80a9d38 ibox = (struct index_mailbox_context *) 0x808d558 ret = <value optimized out> __FUNCTION__ = "index_transaction_index_commit" #14 0xb7f08ee5 in mail_index_transaction_commit_full (_t=0xbfffdde8, result_r=0xbfffddcc) at mail-index-transaction.c:237 t = (struct mail_index_transaction *) 0x80aa258 index = (struct mail_index *) 0x806e708 index_undeleted = false #15 0xb7f3ea53 in index_transaction_commit (t=0x80a9d38, changes_r=0xbfffde8c) at index-transaction.c:123 box = (struct mailbox *) 0x808d340 itrans = (struct mail_index_transaction *) 0x0 result = {log_file_seq = 0, log_file_offset = 0, commit_size = 0, ignored_uid_changes = 0, ignored_modseq_changes = 0} ret = <value optimized out> __FUNCTION__ = "index_transaction_commit" #16 0xb7cdab81 in quota_mailbox_transaction_commit (ctx=0x80a9d38, changes_r=0xbfffde8c) at quota-storage.c:94 qt = (struct quota_transaction_context *) 0x80aa628 #17 0xb7ef0c72 in mailbox_transaction_commit_get_changes (_t=0x80893c8, changes_r=0xbfffde8c) at mail-storage.c:1143 _data_stack_cur_id = 4 t = (struct mailbox_transaction_context *) 0x80a9d38 ret = <value optimized out> #18 0x0804eab2 in cmd_append_continue_parsing (cmd=0x8089328) at cmd- append.c:265 sync_flags = <value optimized out> imap_flags = <value optimized out> changes = {pool = 0x80b3308, uid_validity = 0, saved_uids = {arr = {buffer = 0x80b3320, element_size = 8}, v = 0x80b3320, v_modifiable = 0x80b3320}, ignored_uid_changes = 0, ignored_modseq_changes = 0} msg = <value optimized out> client = (struct client *) 0x8084318 ctx = (struct cmd_append_context *) 0x80893b8 args = (const struct imap_arg *) 0x80ab218 flags_list = <value optimized out> flags = <value optimized out> keywords_list = <value optimized out> keywords = <value optimized out> internal_date_str = <value optimized out> internal_date = <value optimized out> ret = <value optimized out> timezone_offset = <value optimized out> save_count = <value optimized out> nonsync = <value optimized out> __FUNCTION__ = "cmd_append_continue_parsing" #19 0x0804e8cb in cmd_append_continue_message (cmd=0x8089328) at cmd- append.c:446 client = (struct client *) 0x8084318 ctx = (struct cmd_append_context *) 0x80893b8 size = 0 ret = <value optimized out> #20 0x0804ed02 in cmd_append_continue_parsing (cmd=0x8089328) at cmd- append.c:379 client = (struct client *) 0x8084318 ctx = (struct cmd_append_context *) 0x80893b8 args = (const struct imap_arg *) 0x80ab218 flags_list = (const struct imap_arg *) 0x0 flags = 0 keywords_list = (const char * const *) 0x80ab1e0 keywords = (struct mail_keywords *) 0x0 internal_date_str = 0x0 internal_date = -1 ret = 0 timezone_offset = 0 save_count = <value optimized out> nonsync = true __FUNCTION__ = "cmd_append_continue_parsing" #21 0x0804f069 in cmd_append (cmd=0x8089328) at cmd-append.c:540 client = (struct client *) 0x8084318 ctx = (struct cmd_append_context *) 0x80893b8 mailbox = 0x808abd8 "INBOX" #22 0x080562dc in client_command_input (cmd=0x8089328) at imap- client.c:647 client = (struct client *) 0x8084318 command = <value optimized out> __FUNCTION__ = "client_command_input" #23 0x08056379 in client_command_input (cmd=0x8089328) at imap- client.c:697 client = (struct client *) 0x8084318 command = <value optimized out> __FUNCTION__ = "client_command_input" #24 0x080564ed in client_handle_input (client=0x8084318) at imap- client.c:738 _data_stack_cur_id = 3 ret = false remove_io = <value optimized out> handled_commands = false __FUNCTION__ = "client_handle_input" #25 0x08056f0f in client_input (client=0x8084318) at imap-client.c:789 cmd = <value optimized out> output = (struct ostream *) 0x8083054 bytes = <value optimized out> __FUNCTION__ = "client_input" #26 0xb7ea7425 in io_loop_handler_run (ioloop=0x806c358) at ioloop- epoll.c:208 ctx = (struct ioloop_handler_context *) 0x806c478 event = (const struct epoll_event *) 0x806c4b8 list = (struct io_list *) 0x80830d8 io = (struct io_file *) 0x80830b0 tv = {tv_sec = 1799, tv_usec = 999126} t_id = 2 msecs = <value optimized out> ret = 1 i = 0 j = 0 call = <value optimized out> #27 0xb7ea6470 in io_loop_run (ioloop=0x806c358) at ioloop.c:350 No locals. #28 0xb7e93eaa in master_service_run (service=0x806c2a8, callback=0x805faa0 <client_connected>) at master-service.c:486 No locals. #29 0x0805f9ed in main (argc=Cannot access memory at address 0x0 ) at main.c:323 service_flags = <value optimized out> storage_service_flags = <value optimized out> postlogin_socket_path = 0x0 username = 0x0 c = <value optimized out> set_roots = {0x8062760, 0x0} (gdb) I don't have errors with clients=1 seed=123 msgs=100000000 random secs=600. -- Guillaume de Lafond Aqua Ray

2 1

[Dovecot] mangled user_attrs from LDAP
by markham breitbach 07 Jun '10

07 Jun '10

I have setup dovecot to allow users to login using their email address or uid and have found a strange behaviour when the user logs in using the email address for a "username". I am using OpenLDAP for a backend data store with a rather customized schema. This behaviour occurs for both POP3 and IMAP logins. For some users it works as expected, but for others the pass_attrs->user does not get mapped back to the uid, but remains the mailLocalAddress (dovecot-ldap.conf is attached at the end of this post). Here is an excerpt from the logs for a working and a malfunctioning user. In both cases the users were logged directly into the pop3 port (ie. telnet <mailserver> 110) and used the fully qualified email address as the user (ie. foo(a)ex.tld) Jun 02 13:23:19 pop3-login: Info: Login: user=<foo>, method=PLAIN, rip=64.247.129.10, lip=64.247.129.10, secured Jun 02 13:23:19 POP3(foo): Info: Loading modules from directory: /usr/local/lib/dovecot/pop3 Jun 02 13:23:19 POP3(foo): Info: Module loaded: /usr/local/lib/dovecot/pop3/lib10_quota_plugin.so Jun 02 13:23:19 POP3(foo): Info: Effective uid=14921, gid=2000, home=/nonexistent Jun 02 13:23:19 POP3(foo): Info: Quota root: name=User quota backend=maildir args= Jun 02 13:23:19 POP3(foo): Info: Quota rule: root=User quota mailbox=* bytes=0 messages=0 Jun 02 13:23:19 POP3(foo): Info: maildir: data=/var/mail/foo Jun 02 13:23:19 POP3(foo): Info: maildir++: root=/var/mail/foo, index=, control=, inbox=/var/mail/foo Jun 02 13:23:19 POP3(foo): Info: Namespace : Using permissions from /var/mail/foo: mode=0700 gid=-1 Jun 02 16:54:06 pop3-login: Info: Login: user=<bobs>, method=PLAIN, rip=199.247.84.12, lip=64.247.129.4 Jun 02 16:54:06 POP3(bob_smith(a)example.tld): Info: Loading modules from directory: /usr/local/lib/dovecot/pop3 Jun 02 16:54:06 POP3(bob_smith(a)example.tld): Info: Module loaded: /usr/local/lib/dovecot/pop3/lib10_quota_plugin.so Jun 02 16:54:06 POP3(bob_smith(a)example.tld): Info: Effective uid=38538, gid=2000, home=/nonexistent Jun 02 16:54:06 POP3(bob_smith(a)example.tld): Info: Quota root: name=User quota backend=maildir args= Jun 02 16:54:06 POP3(bob_smith(a)example.tld): Info: Quota rule: root=User quota mailbox=* bytes=524288000 messages=0 Jun 02 16:54:06 POP3(bob_smith(a)example.tld): Info: Quota rule: root=User quota mailbox=Trash bytes=52428800 messages=0 Jun 02 16:54:06 POP3(bob_smith(a)example.tld): Info: Quota rule: root=User quota mailbox=Deleted Messages bytes=52428800 messages=0 Jun 02 16:54:06 POP3(bob_smith(a)example.tld): Info: maildir: data=/var/mail/bob_smith(a)example.tld Jun 02 16:54:06 POP3(bob_smith(a)example.tld): Info: maildir++: root=/var/mail/bob_smith(a)example.tld, index=, control=, inbox=/var/mail/bob_smith(a)example.tld Jun 02 16:54:06 POP3(bob_smith(a)example.tld): Info: Namespace : Using permissions from /var/mail/bob_smith(a)example.tld: mode=0700 gid=-1 Jun 02 16:54:10 POP3(bob_smith(a)example.tld): Info: Disconnected: Logged out top=0/0, retr=0/0, del=0/0, size=0 After much searching for anything different between these records, some tcpdumps showed that the problem occured when LDAP returned the attributes in a different order than they are requested in. In this sample, you can see the request for uid,homeDirectory,uidNumber,gidNumber,mailQuota and the values are returned in the order gidNumber, uid, uidNumber, homeDirectory. There is no mailQuota set for this user. 16:54:06.145597 IP mail.xxxxx.com.62929 > closest-ldap.ldap: P 14:261(247) ack 15 win 33304 <nop,nop,timestamp 1521221146 267819447> 0x0000: 4500 012b fd4d 4000 4006 b87a 40f7 8104 E..+.M@.@..z@... 0x0010: 40f7 8112 f5d1 0185 41e1 8b7d 5aea 01d9 @.......A..}Z... 0x0020: 8018 8218 8522 0000 0101 080a 5aab fe1a ....."......Z... 0x0030: 0ff6 99b7 3081 f402 0120 6381 ee04 0b64 ....0.....c....d 0x0040: 633d 322c 6463 3d73 7369 0a01 020a 0100 c=2,dc=ssi...... 0x0050: 0201 0002 0100 0101 00a0 8198 a317 040d ................ 0x0060: 6163 636f 756e 7473 7461 7475 7304 0661 accountstatus..a 0x0070: 6374 6976 65a3 1c04 1265 6d61 696c 6163 ctive....emailac 0x0080: 636f 756e 7453 7461 7475 7304 0661 6374 countStatus..act 0x0090: 6976 65a1 5fa3 2704 0375 6964 0420 626f ive._.'..uid..bo 0x00a0: 625f 6d61 6364 6f6e 616c 6440 6772 6561 b_xxxxxxxxx@xxxx 0x00b0: 7473 6c61 7665 6865 6c69 2e63 6f6d a334 xxxxxxxxxx.com.4 0x00c0: 0410 6d61 696c 4c6f 6361 6c41 6464 7265 ..mailLocalAddre 0x00d0: 7373 0420 626f 625f 6d61 6364 6f6e 616c ss..bob_xxxxxxxx 0x00e0: 6440 6772 6561 7473 6c61 7665 6865 6c69 x@xxxxxxxxxxxxxx 0x00f0: 2e63 6f6d 3035 0403 7569 6404 0d68 6f6d .com05..uid..hom 0x0100: 6544 6972 6563 746f 7279 0409 7569 644e eDirectory..uidN 0x0110: 756d 6265 7204 0967 6964 4e75 6d62 6572 umber..gidNumber 0x0120: 0409 6d61 696c 5175 6f74 61 ..mailQuota 16:54:06.147464 IP closest-ldap.ldap > mail.xxxxx.com.62929: P 15:142(127) ack 261 win 32942 <nop,nop,timestamp 267819449 1521221146> 0x0000: 4500 00b3 bb91 4000 4006 faae 40f7 8112 E.....@.@...@... 0x0010: 40f7 8104 0185 f5d1 5aea 01d9 41e1 8c74 @.......Z...A..t 0x0020: 8018 80ae b708 0000 0101 080a 0ff6 99b9 ................ 0x0030: 5aab fe1a 307d 0201 2064 7804 1663 6e3d Z...0}...dx..cn= 0x0040: 6773 6862 6f62 6d2c 6463 3d32 2c64 633d xxxbobx,dc=2,dc= 0x0050: 7373 6930 5e30 1304 0967 6964 4e75 6d62 ssi0^0...gidNumb 0x0060: 6572 3106 0404 3230 3030 3010 0403 7569 er1...20000...ui 0x0070: 6431 0904 0767 7368 626f 626d 3014 0409 d1...xxxbobx0... 0x0080: 7569 644e 756d 6265 7231 0704 0533 3835 uidNumber1...385 0x0090: 3338 301f 040d 686f 6d65 4469 7265 6374 380...homeDirect 0x00a0: 6f72 7931 0e04 0c2f 6e6f 6e65 7869 7374 ory1.../nonexist 0x00b0: 656e 74 ent I will spare you the packet dump, but in the cases where the login works correctly, LDAP returns the values in the same order that they are requested in. This behaviour has been found with both OpenLDAP: slapd 2.3.39 and OpenLDAP: slapd 2.4.17, and is consistent with standard LDAP behaviour (ie, there is no guaranteed ordering in the LDAP database). A brief look at the code, seems to indicate that the values are being pulled from the LDAP return struct in a step-wise manner, which could certainly put them out of sync with the request if it is assumed that they will always be returned in the same order....This is just based on a quick review of the code though, and not any detailed tracing. Here is the obligatory dovecot -n: # 1.2.11: /usr/local/etc/dovecot.conf # OS: FreeBSD 6.4-RELEASE-p7 i386 nullfs log_path: /var/log/dovecot.log info_log_path: /var/log/dovecot-info.log protocols: pop3 pop3s imap imaps disable_plaintext_auth: no login_dir: /usr/local/var/run/dovecot/login login_executable(default): /usr/local/libexec/dovecot/imap-login login_executable(imap): /usr/local/libexec/dovecot/imap-login login_executable(pop3): /usr/local/libexec/dovecot/pop3-login first_valid_uid: 0 mail_location: maildir:/var/mail/%u mail_debug: yes mail_executable(default): /usr/local/libexec/dovecot/imap mail_executable(imap): /usr/local/libexec/dovecot/imap mail_executable(pop3): /usr/local/libexec/dovecot/pop3 mail_plugins(default): quota imap_quota mail_plugins(imap): quota imap_quota mail_plugins(pop3): quota mail_plugin_dir(default): /usr/local/lib/dovecot/imap mail_plugin_dir(imap): /usr/local/lib/dovecot/imap mail_plugin_dir(pop3): /usr/local/lib/dovecot/pop3 pop3_uidl_format(default): %08Xu%08Xv pop3_uidl_format(imap): %08Xu%08Xv pop3_uidl_format(pop3): %v.%u lda: postmaster_address: postmaster(a)ssimicro.com mail_plugins: quota log_path: info_log_path: auth default: passdb: driver: ldap args: /usr/local/etc/dovecot-ldap.conf userdb: driver: prefetch userdb: driver: ldap args: /usr/local/etc/dovecot-ldap.conf userdb: driver: passwd socket: type: listen master: path: /usr/local/var/run/dovecot/auth-master mode: 384 user: dovecot plugin: quota: maildir:User quota quota_rule: *:storage=500MB quota_rule2: Trash:storage=50MB quota_rule3: Deleted Messages:storage=50MB home: /tmp/thome and the dovecot-ldap.conf hosts = closest-ldap base = "dc=2,dc=ssi" scope = subtree auth_bind = yes pass_attrs = uid=user, homeDirectory=userdb_home,uidNumber=userdb_uid,gidNumber=userdb_gid,mailQuota=userdb_quota_rule=*:bytes=%$ user_attrs = mailQuota=quota_rule=*:bytes=%$, uidNumber=uid,gidNumber=gid pass_filter = (&(accountstatus=active)(emailaccountStatus=active)(|(uid=%u)(mailLocalAddress=%u)))

2 4