March 2009 - dovecot - dovecot.org

[Dovecot] THREAD X-REFERENCES2 index bug?
by Nathan Kinkade 04 Apr '09

04 Apr '09

Hi all, $ sudo dovecot --version 1.2.beta3 I just started using Dovecot a few weeks ago, and my client is also using the X-REFERENCES2 thread algorithm. The client is misbehaving when trying to list messages in my INBOX, but only when a threaded message exists. I have tracked it down to the thread index that Dovecot is returning, but the problem is only extant when using the X-REFERENCES2 thread algorithm. Here is a snippet of transcript from imap client that comes with Dovecot: $ export MAIL=maildir:~/Maildir:INBOX=~/Maildir/INBOX $ /usr/lib/dovecot/imap <snip> 1 SELECT "INBOX" <snip> 2 THREAD X-REFERENCES2 UTF-8 ALL * THREAD (0)(2)(1 3)(4) 2 OK Thread completed. There are, in fact, only 4 messages in my INBOX, and the reference to (0) seems spurious. When I do the same test, but passing REFERENCES instead of X-REFERENCES2 Dovecot returns an index which I believe to be correct: <snip> 2 THREAD REFERENCES UTF-8 ALL * THREAD (1 3)(2)(4) 2 OK Thread completed. <snip> Is this the normal and expected behavior of X-REFERENCES2 that the client just needs to take into account, or is the reference to thread index (0) an error? Thanks! Nathan

2 6

[Dovecot] ACL changes not respected by already loged in clients
by Sascha Wilde 03 Apr '09

03 Apr '09

Hi *, and yet another ACL problem. ;-) User A allows User B to access his mailbox foobar: * OK [CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE AUTH=PLAIN] Dovecot ready. l login userA secret l OK [CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE SORT THREAD=REFERENCES MULTIAPPEND UNSELECT IDLE CHILDREN NAMESPACE UIDPLUS LIST-EXTENDED I18NLEVEL=1 CONDSTORE QRESYNC ESEARCH ESORT SEARCHRES WITHIN CONTEXT=SEARCH ACL RIGHTS=texk ANNOTATEMORE] Logged in s setacl "INBOX/foobar" "B(a)example.com" eilprwtsd s OK Setacl complete. g getacl INBOX/foobar * ACL "INBOX/foobar" "B(a)example.com" eilprwtsd "A(a)example.com" lrwstipekxacd User B logs in to dovecot and sees the newly accessible mailbox: * OK [CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE AUTH=PLAIN] Dovecot ready. l login zwei 2 l OK [CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE SORT THREAD=REFERENCES MULTIAPPEND UNSELECT IDLE CHILDREN NAMESPACE UIDPLUS LIST-EXTENDED I18NLEVEL=1 CONDSTORE QRESYNC ESEARCH ESORT SEARCHRES WITHIN CONTEXT=SEARCH ACL RIGHTS=texk ANNOTATEMORE] Logged in l list "" "*" * LIST (\Noselect \HasChildren) "/" "user" * LIST (\Noselect \HasChildren) "/" "user/A(a)example.com" * LIST (\HasChildren) "/" "INBOX" * LIST (\HasNoChildren) "/" "INBOX/Gesendet" * LIST (\HasChildren) "/" "user/A(a)example.com/foobar" l OK List completed. se select "user/A(a)example.com/foobar" * FLAGS (\Answered \Flagged \Deleted \Seen \Draft) * OK [PERMANENTFLAGS (\Answered \Flagged \Deleted \Seen \Draft \*)] Flags permitted. * 1 EXISTS * 1 RECENT * OK [UIDVALIDITY 1236104897] UIDs valid * OK [UIDNEXT 2] Predicted next UID * OK [HIGHESTMODSEQ 1] Now User A changes his mind: s setacl "INBOX/foobar" "B(a)example.com" "" s OK Setacl complete. g getacl INBOX/foobar * ACL "INBOX/foobar" "A(a)example.com" lrwstipekxacd g OK Getacl completed. but as long as User B stays loged in, he is not affected, in fact he still can read A's mails: se select "user/A(a)example.com/foobar" * OK [CLOSED] * FLAGS (\Answered \Flagged \Deleted \Seen \Draft) * OK [PERMANENTFLAGS (\Answered \Flagged \Deleted \Seen \Draft \*)] Flags permitted. * 1 EXISTS * 0 RECENT * OK [UIDVALIDITY 1236104897] UIDs valid * OK [UIDNEXT 2] Predicted next UID * OK [HIGHESTMODSEQ 1] se OK [READ-WRITE] Select completed. f101 fetch 1 FAST * 1 FETCH (FLAGS (\Seen) INTERNALDATE "04-Mar-2009 13:11:06 +0100" RFC822.SIZE 3652) f101 OK Fetch completed. I think ACL changes should take immediate effect, or at least should be re-checked in reasonable intervals (which imo shouldn't exceed a few seconds). cheers sascha -- Sascha Wilde OpenPGP key: 4BB86568 http://www.intevation.de/~wilde/ http://www.intevation.de/ Intevation GmbH, Neuer Graben 17, 49074 Osnabrück; AG Osnabrück, HR B 18998 Geschäftsführer: Frank Koormann, Bernhard Reiter, Dr. Jan-Oliver Wagner

4 5

[Dovecot] v 1.1.13 / GSSAPI / Timeout waiting for handshake from auth server
by Jahnke-Zumbusch, Dirk 03 Apr '09

03 Apr '09

Dear all, I am trying to setup Dovecot with GSSAPI support. For testing purposes gssapi is the only method allowed for login. As I cannot login to my mailbox, I'vo got two questions about the following log entries: dovecot: Info: auth-worker(default): passwd-file /dovecot/store/db/test-userdb: Read 3 users dovecot: Info: auth(default): new auth connection: pid=3915 dovecot: Info: auth(default): client in: AUTH 1 GSSAPI service=imap lip=131.169.*.* rip=131.169.*.* lport=143 rport=35779 dovecot: Info: auth(default): gssapi(?,131.169.40.218): Obtaining credentials for imap(a)my.host.name dovecot: Error: imap-login: Timeout waiting for handshake from auth server. my pid=3918, input bytes=0 1. I am puzzled about the credentials "imap(a)my.host.name" being obtained; shouldn't this be something like "imap/my.host.name(a)MY.REALM" ? 2. what does "Timeout waiting for handshake from auth server." mean? Who is trying to handshake with whom? Any ideas? Best regards, Dirk -- Dirk Jahnke-Zumbusch Deutsches Elektronen-Synchrotron DESY IT Information Fabrics Member of the Helmholtz Association D-22603 Hamburg Notkestrasse 85 / 22607 Hamburg T: +49-40-899.81760 F: +49-40-899.41760 dirk.jahnke-zumbusch(a)desy.de

3 2

[Dovecot] dbox benchmarks
by Timo Sirainen 03 Apr '09

03 Apr '09

http://hg.dovecot.org/dovecot-dbox-redesign/ Looks like multi-dbox scales pretty nicely. Even after 100k messages the peak saved msgs/sec is the same as the initial saved msgs/sec, even if the average slows down somewhat. I tested this by first deleting mailbox, then running "imaptest" for a second to get saving to start writing several fields to dovecot.index.cache file. Then ran imaptest for 60 seconds that did nothing but save messages using IMAP APPEND commands. The summary is that multi-dbox is almost 10x as fast as maildir when fsync is disabled and 2,5 faster with fsyncing: fsync_disable=yes: multi-dbox : ~1700 -> ~1500 msgs/sec, 90842 msgs/60 sec single-dbox: ~1700 -> ~1400 msgs/sec, 86149 msgs/60 sec maildir : ~330 -> ~110 msgs/sec, 9789 msgs/60 sec fsync_disable=no: multi-dbox : ~220 -> ~170 msgs/sec, 10113 msgs/60 sec maildir : ~100 -> ~70 msgs/sec, 4123 msgs/60 sec Also I just noticed that saving messages with two clients gets a peak of 2200 msgs/sec, most likely because two CPU cores can be used then. Hmm. I guess if there were no locking it should have reached 3400 msgs/sec, but it's better than no performance increase. And the raw data: multi-dbox, fsync_disable=yes imaptest clients=1 secs=1;imaptest clients=1 msgs=1000000 - logout=0 append=100,0 secs=60 Logi Sele Appe 100% 100% 100% 1 1 1759 1/ 1 0 0 1424 1/ 1 0 0 1734 1/ 1 ... 0 0 1701 1/ 1 0 0 1640 1/ 1 0 0 778 1/ 1 0 0 1305 1/ 1 0 0 1598 1/ 1 Totals: Logi Sele Appe 100% 100% 100% 1 1 90842 multi-dbox, fsync_disable=no imaptest clients=1 secs=1;imaptest clients=1 msgs=1000000 - logout=0 append=100,0 secs=60 Logi Sele Appe 100% 100% 100% 1 1 209 1/ 1 0 0 227 1/ 1 0 0 208 1/ 1 ... 0 0 203 1/ 1 0 0 145 1/ 1 0 0 156 1/ 1 0 0 180 1/ 1 0 0 162 1/ 1 Totals: Logi Sele Appe 100% 100% 100% 1 1 10113 maildir, fsync_disable=yes Logi Sele Appe 100% 100% 100% 1 1 331 1/ 1 0 0 311 1/ 1 0 0 288 1/ 1 ... 0 0 96 1/ 1 0 0 119 1/ 1 0 0 111 1/ 1 Totals: Logi Sele Appe 100% 100% 100% 1 1 9789 maildir, fsync_disable=no Logi Sele Appe 100% 100% 100% 1 1 77 1/ 1 0 0 101 1/ 1 0 0 45 1/ 1 ... 0 0 52 1/ 1 0 0 67 1/ 1 0 0 89 1/ 1 Totals: Logi Sele Appe 100% 100% 100% 1 1 4123 single-dbox, fsync_disable=yes imaptest clients=1 secs=1;imaptest clients=1 msgs=1000000 - logout=0 append=100,0 secs=60 Logi Sele Appe 100% 100% 100% 1 1 1765 1/ 1 0 0 1715 1/ 1 0 0 1764 1/ 1 ... 0 0 1722 1/ 1 0 0 1679 1/ 1 0 0 1678 1/ 1 0 0 828 1/ 1 0 0 1467 1/ 1 0 0 1469 1/ 1 0 0 1149 1/ 1 0 0 1135 1/ 1 Totals: Logi Sele Appe 100% 100% 100% 1 1 86149

3 4

[Dovecot] Fatal: imap-login: io_loop_handle_add: epoll_ctl(1, 4): Operation not permitted
by Jérôme Blanc 03 Apr '09

03 Apr '09

Hello, I'am following the beginning tutorial on the Wiki, but actually, I can't even start the server correctly so far. The imap-login child dies immediately. What I can guess from the log is that it tries some unpermietted operations on some files but I can't find out which files are concerned. Google is not my friend at all either on this matter. How can I know which files are concerned ? Some infos that might help : [root@Aries ~]# dovecot -n # 1.1.6: /etc/dovecot.conf # OS: Linux 2.6.27.14-server-1mnb i686 Mandriva Linux release 2009.0 (Official) for i586 ext3 ssl_cert_file: /etc/pki/tls/certs/dovecot.pem ssl_key_file: /etc/pki/tls/private/dovecot.pem login_dir: /var/run/dovecot/login login_executable: /usr/lib/dovecot/imap-login mail_privileged_group: mail mail_location: maildir:/var/mail/%n auth default: passdb: driver: passwd-file args: /etc/passwd.dovecot userdb: driver: passwd [root@Aries ~]# ls -ld /var/mail drwxrwx--x 3 root mail 4096 2009-03-10 18:06 /var/mail/ [root@Aries ~]# service dovecot start And here is what I get in the /var/log/syslog file : Mar 10 20:00:47 aries dovecot: Dovecot v1.1.6 starting up Mar 10 20:00:48 aries dovecot: Fatal: imap-login: io_loop_handle_add: epoll_ctl(1, 4): Operation not permitted Mar 10 20:00:48 aries dovecot: Temporary failure in creating login processes, slowing down for now Mar 10 20:00:48 aries dovecot: Fatal: imap-login: io_loop_handle_add: epoll_ctl(1, 4): Operation not permitted Mar 10 20:00:48 aries dovecot: Fatal: imap-login: io_loop_handle_add: epoll_ctl(1, 4): Operation not permitted Thanks -- Jérôme Blanc OpenPGP : 1024D/F44DB96C

2 18

[Dovecot] v1.2.beta2: Fatal: io_loop_handle_add: epoll_ctl(1, 10): Bad file descriptor
by Pascal Volk 02 Apr '09

02 Apr '09

Hi Timo, I'm playing with Dovecot v1.2.beta2 currently. When the dict process was started via deliver(?) and Dovecot is killed (kill $PID_OF_DOVECOT) after delivering only one message, it logs: Fatal: io_loop_handle_add: epoll_ctl(1, 10): Bad file descriptor If the dict process was not started or deliver has delivered more than one message, the error doesn't occur. I'm not using SELinux or AppArmor or something similar. # 1.2.beta2: /usr/local/dovecot12/etc/dovecot.conf # OS: Linux 2.6.26-1-amd64 x86_64 Debian squeeze/sid log_path: /usr/local/dovecot12/var/log/dovecot.log protocols: imap listen: 10.11.12.13:10143 ssl: no disable_plaintext_auth: no login_dir: /usr/local/dovecot12/var/run/dovecot/login login_executable: /usr/local/dovecot12/libexec/dovecot/imap-login verbose_proctitle: yes first_valid_uid: 70000 first_valid_gid: 70000 mail_privileged_group: mail mail_location: maildir:~/Maildir mail_plugins: quota imap_quota auth default: mechanisms: digest-md5 cram-md5 login plain user: nobody verbose: yes debug: yes passdb: driver: sql args: /usr/local/dovecot12/etc/dovecot-sql.conf userdb: driver: sql args: /usr/local/dovecot12/etc/dovecot-sql.conf socket: type: listen master: path: /usr/local/dovecot12/var/run/dovecot/auth-master mode: 384 plugin: quota: dict:user::noenforcing:proxy::quotadict quota_rule: *:storage=10M:messages=11 quota_rule2: Trash:storage=50%% mail_debug: yes dict: quotadict: pgsql:/usr/local/dovecot12/etc/dovecot-dict-quota.conf Regards, Pascal -- The trapper recommends today: cafefeed.0907505(a)localdomain.org

2 2

[Dovecot] quota-fs: get nfs GROUP quota (patch)
by fandorin＠rol.ru 02 Apr '09

02 Apr '09

Hi all. Unfortunately, the existing quota-fs does not know how to get GROUP quota with NFS storage. But there is a tool for Linux quota-tools (http://slackware.rol.ru/slackware/slackware-12.2/source/a/quota/). This patch is made on the basis quota-tools. The patch was successful alpha testing. Suggestions and comments are welcome. diff -ruN dovecot-1.1.11.orig/src/plugins/quota/quota-fs.c dovecot-1.1.11/src/plugins/quota/quota-fs.c --- dovecot-1.1.11.orig/src/plugins/quota/quota-fs.c 2009-01-06 17:33:51.000000000 +0300 +++ dovecot-1.1.11/src/plugins/quota/quota-fs.c 2009-02-11 12:57:55.000000000 +0300 @@ -288,17 +288,26 @@ #ifdef HAVE_RQUOTA /* retrieve user quota from a remote host */ -static int do_rquota(struct fs_quota_root *root, bool bytes, +static int do_rquota(struct fs_quota_root *root, bool group, bool bytes, uint64_t *value_r, uint64_t *limit_r) { - struct getquota_rslt result; - struct getquota_args args; - struct timeval timeout; + struct getquota_rslt *result; + static struct getquota_rslt clnt_res; enum clnt_stat call_status; - CLIENT *cl; + CLIENT *clnt; struct fs_quota_mountpoint *mount = root->mount; const char *host; char *path; + int type, id; + struct timeval timeout = { 2, 0 }; + + union { + getquota_args arg; + ext_getquota_args ext_arg; + } args; + + type = group ? GRPQUOTA : USRQUOTA; + id = group ? root->gid : root->uid; path = strchr(mount->device_path, ':'); if (path == NULL) { @@ -311,82 +320,211 @@ path++; if (getenv("DEBUG") != NULL) { + if (group) { + i_info("quota-fs: host=%s, path=%s, gid=%s", + host, path, dec2str(root->gid)); + } else { i_info("quota-fs: host=%s, path=%s, uid=%s", host, path, dec2str(root->uid)); + } } - /* clnt_create() polls for a while to establish a connection */ - cl = clnt_create(host, RQUOTAPROG, RQUOTAVERS, "udp"); - if (cl == NULL) { - i_error("quota-fs: could not contact RPC service on %s", - host); - return -1; - } - - /* Establish some RPC credentials */ - auth_destroy(cl->cl_auth); - cl->cl_auth = authunix_create_default(); - - /* make the rquota call on the remote host */ - args.gqa_pathp = path; - args.gqa_uid = root->uid; - - timeout.tv_sec = RQUOTA_GETQUOTA_TIMEOUT_SECS; - timeout.tv_usec = 0; - call_status = clnt_call(cl, RQUOTAPROC_GETQUOTA, - (xdrproc_t)xdr_getquota_args, (char *)&args, - (xdrproc_t)xdr_getquota_rslt, (char *)&result, - timeout); + /* + * First try EXT_RQUOTAPROG (Extended (LINUX) RPC quota program) + */ + args.ext_arg.gqa_pathp = path; + args.ext_arg.gqa_id = id; + args.ext_arg.gqa_type = type; - /* the result has been deserialized, let the client go */ - auth_destroy(cl->cl_auth); - clnt_destroy(cl); - - if (call_status != RPC_SUCCESS) { - const char *rpc_error_msg = clnt_sperrno(call_status); - + /* + * Create a RPC client. + */ + + if ((clnt = clnt_create(host, RQUOTAPROG, EXT_RQUOTAVERS, "udp")) != NULL) { + /* + * Initialize unix authentication + */ + clnt->cl_auth = authunix_create_default(); + + /* + * Setup protocol timeout. + */ + clnt_control(clnt, CLSET_TIMEOUT, (caddr_t) & timeout); + + /* + * Do RPC call and check result. + */ + + memset((char *)&clnt_res, 0, sizeof(clnt_res)); + call_status = clnt_call (clnt, RQUOTAPROC_GETQUOTA, + (xdrproc_t) xdr_ext_getquota_args, (caddr_t) &args.ext_arg, + (xdrproc_t) xdr_getquota_rslt, (caddr_t) &clnt_res, + timeout); + result = &clnt_res; + /* + * Destroy unix authentication and RPC client structure. + */ + auth_destroy(clnt->cl_auth); + clnt_destroy(clnt); + + if (call_status != RPC_SUCCESS) { + const char *rpc_error_msg = clnt_sperrno(call_status); i_error("quota-fs: remote rquota call failed: %s", rpc_error_msg); return -1; - } - - switch (result.status) { - case Q_OK: { + } + + switch (result->status) { + case Q_OK: { /* convert the results from blocks to bytes */ - rquota *rq = &result.getquota_rslt_u.gqr_rquota; + rquota *rq = &result->getquota_rslt_u.gqr_rquota; if (rq->rq_active) { - if (bytes) { - *value_r = (uint64_t)rq->rq_curblocks * - (uint64_t)rq->rq_bsize; - *limit_r = (uint64_t)rq->rq_bsoftlimit * - (uint64_t)rq->rq_bsize; - } else { - *value_r = rq->rq_curfiles; - *limit_r = rq->rq_fsoftlimit; - } + if (bytes) { + *value_r = (uint64_t)rq->rq_curblocks * + (uint64_t)rq->rq_bsize; + *limit_r = (uint64_t)rq->rq_bsoftlimit * + (uint64_t)rq->rq_bsize; + } else { + *value_r = rq->rq_curfiles; + *limit_r = rq->rq_fsoftlimit; + } } if (getenv("DEBUG") != NULL) { + if (group) { + i_info("quota-fs: gid=%s, value=%llu, " + "limit=%llu, active=%d", dec2str(root->gid), + (unsigned long long)*value_r, + (unsigned long long)*limit_r, rq->rq_active); + } else { i_info("quota-fs: uid=%s, value=%llu, " "limit=%llu, active=%d", dec2str(root->uid), (unsigned long long)*value_r, (unsigned long long)*limit_r, rq->rq_active); + } } return 1; - } - case Q_NOQUOTA: + } + case Q_NOQUOTA: if (getenv("DEBUG") != NULL) { + if (group) { + i_info("quota-fs: gid=%s, limit=unlimited", + dec2str(root->gid)); + } else { i_info("quota-fs: uid=%s, limit=unlimited", dec2str(root->uid)); + } } return 1; - case Q_EPERM: + case Q_EPERM: i_error("quota-fs: permission denied to rquota service"); return -1; - default: + default: i_error("quota-fs: unrecognized status code (%d) " - "from rquota service", result.status); + "from rquota service", result->status); return -1; + } + } else { + result = NULL; + } + + if (result == NULL || !result->status) { + if (type == USRQUOTA) { + /* + * Try RQUOTAPROG because server doesn't seem to understand EXT_RQUOTAPROG. (NON-LINUX servers.) + */ + args.arg.gqa_pathp = path; + args.arg.gqa_uid = id; + + /* + * Create a RPC client. + */ + if ((clnt = clnt_create(host, RQUOTAPROG, RQUOTAVERS, "udp")) != NULL) { + /* + * Initialize unix authentication + */ + clnt->cl_auth = authunix_create_default(); + + /* + * Setup protocol timeout. + */ + clnt_control(clnt, CLSET_TIMEOUT, (caddr_t) & timeout); + + /* + * Do RPC call and check result. + */ + memset((char *)&clnt_res, 0, sizeof(clnt_res)); + call_status = clnt_call (clnt, RQUOTAPROC_GETQUOTA, + (xdrproc_t) xdr_getquota_args, (caddr_t) &args.arg, + (xdrproc_t) xdr_getquota_rslt, (caddr_t) &clnt_res, + timeout); + result = &clnt_res; + /* + * Destroy unix authentication and RPC client structure. + */ + auth_destroy(clnt->cl_auth); + clnt_destroy(clnt); + + if (call_status != RPC_SUCCESS) { + const char *rpc_error_msg = clnt_sperrno(call_status); + i_error("quota-fs: remote rquota call failed: %s", + rpc_error_msg); + return -1; + } + + switch (result->status) { + case Q_OK: { + /* convert the results from blocks to bytes */ + rquota *rq = &result->getquota_rslt_u.gqr_rquota; + + if (rq->rq_active) { + if (bytes) { + *value_r = (uint64_t)rq->rq_curblocks * + (uint64_t)rq->rq_bsize; + *limit_r = (uint64_t)rq->rq_bsoftlimit * + (uint64_t)rq->rq_bsize; + } else { + *value_r = rq->rq_curfiles; + *limit_r = rq->rq_fsoftlimit; + } + } + if (getenv("DEBUG") != NULL) { + if (group) { + i_info("quota-fs: gid=%s, value=%llu, " + "limit=%llu, active=%d", dec2str(root->gid), + (unsigned long long)*value_r, + (unsigned long long)*limit_r, rq->rq_active); + } else { + i_info("quota-fs: uid=%s, value=%llu, " + "limit=%llu, active=%d", dec2str(root->uid), + (unsigned long long)*value_r, + (unsigned long long)*limit_r, rq->rq_active); + } + } + return 1; + } + case Q_NOQUOTA: + if (getenv("DEBUG") != NULL) { + if (group) { + i_info("quota-fs: gid=%s, limit=unlimited", + dec2str(root->gid)); + } else { + i_info("quota-fs: uid=%s, limit=unlimited", + dec2str(root->uid)); + } + } + return 1; + case Q_EPERM: + i_error("quota-fs: permission denied to rquota service"); + return -1; + default: + i_error("quota-fs: unrecognized status code (%d) " + "from rquota service", result->status); + return -1; + } + + } + } } } #endif @@ -602,6 +740,7 @@ uint64_t limit = 0; bool bytes; int ret; + bool group; *value_r = 0; @@ -614,7 +753,12 @@ #ifdef HAVE_RQUOTA if (strcmp(root->mount->type, "nfs") == 0) { T_BEGIN { - ret = do_rquota(root, bytes, value_r, &limit); + if (root->group_disabled){ + group = FALSE; + } else { + group = TRUE; + } + ret = do_rquota(root, group, bytes, value_r, &limit); } T_END; } else #endif

2 3

[Dovecot] 1.11 bug?: file client-common.c: line 25 (client_unlink): assertion failed: (clients_count > 0)
by Long Le Dinh 02 Apr '09

02 Apr '09

Hi, I got below log in last 2 days, I have to restart dovecot as pop3-login failed and service cannot respond. Mar 26 14:19:31 Info: pop3-login: Disconnected: Shutting down (auth failed, 1 attempts): method=PLAIN, rip=x.x.x.x Mar 26 14:19:31 Info: pop3-login: Disconnected: Shutting down (tried to use disabled plaintext auth): method=??<B7> Mar 26 14:19:31 Panic: pop3-login: file client-common.c: line 25 (client_unlink): assertion failed: (clients_count > 0) Mar 26 14:19:31 Error: child 31902 (login) killed with signal 6 (ip=x.x.x.x) My system info: dovecot -n # 1.1.11: /etc/dovecot.conf # OS: Linux 2.6.18-8.el5 i686 CentOS release 5 (Final) ext3 log_path: /var/log/dovecot.log 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 mail_gid: 100 mail_location: maildir:/home/%u/Maildir mail_executable(default): /usr/libexec/dovecot/imap mail_executable(imap): /usr/libexec/dovecot/imap mail_executable(pop3): /usr/libexec/dovecot/pop3 mail_plugin_dir(default): /usr/lib/dovecot/imap mail_plugin_dir(imap): /usr/lib/dovecot/imap mail_plugin_dir(pop3): /usr/lib/dovecot/pop3 auth default: verbose: yes debug: yes passdb: driver: ldap args: /etc/dovecot-ldap.conf userdb: driver: passwd userdb: driver: ldap args: /etc/dovecot-ldap.conf We're using Maildir format, no NFS. Any help/clue is appreciated. Thanks, - Long Le

2 6

[Dovecot] odd epoll() errors
by Ralf Hildebrandt 02 Apr '09

02 Apr '09

>From my log: Dec 29 16:43:58 postamt dovecot: Dovecot v1.1.7 starting up Dec 29 16:43:59 postamt dovecot: Fatal: imap-login: epoll_create(): Too many open files Dec 29 16:43:59 postamt dovecot: Temporary failure in creating login processes, slowing down for now Dec 29 16:43:59 postamt dovecot: Fatal: imap-login: epoll_create(): Too many open files Dec 29 16:43:59 postamt dovecot: Fatal: pop3-login: epoll_create(): Too many open files Dec 29 16:43:59 postamt dovecot: Fatal: imap-login: epoll_create(): Too many open files Dec 29 16:43:59 postamt dovecot: Fatal: imap-login: epoll_create(): Too many open files Dec 29 16:43:59 postamt dovecot: Fatal: pop3-login: epoll_create(): Too many open files Dec 29 16:44:59 postamt dovecot: Fatal: imap-login: epoll_create(): Too many open files Dec 29 16:44:59 postamt dovecot: Fatal: pop3-login: epoll_create(): Too many open files Dec 29 16:44:59 postamt dovecot: Fatal: pop3-login: epoll_create(): Too many open files Dec 29 16:44:59 postamt dovecot: Fatal: imap-login: epoll_create(): Too many open files Dec 29 16:44:59 postamt dovecot: child 15976 (login) returned error 89 (Fatal failure) Dec 29 16:44:59 postamt dovecot: child 15977 (login) returned error 89 (Fatal failure) Dec 29 16:44:59 postamt dovecot: child 15978 (login) returned error 89 (Fatal failure) Dec 29 16:44:59 postamt dovecot: child 15979 (login) returned error 89 (Fatal failure) Dec 29 16:44:59 postamt dovecot: child 15981 (login) returned error 89 (Fatal failure) Dec 29 16:44:59 postamt dovecot: child 15982 (login) returned error 89 (Fatal failure) Dec 29 16:44:59 postamt dovecot: Fatal: imap-login: epoll_create(): Too many open files Dec 29 16:45:59 postamt dovecot: Fatal: pop3-login: epoll_create(): Too many open files Dec 29 16:45:59 postamt dovecot: Fatal: pop3-login: epoll_create(): Too many open files Dec 29 16:45:59 postamt dovecot: child 17052 (login) returned error 89 (Fatal failure) Dec 29 16:45:59 postamt dovecot: child 17053 (login) returned error 89 (Fatal failure) Dec 29 16:45:59 postamt dovecot: child 17054 (login) returned error 89 (Fatal failure) Dec 29 16:45:59 postamt dovecot: child 17055 (login) returned error 89 (Fatal failure) Dec 29 16:45:59 postamt dovecot: child 17056 (login) returned error 89 (Fatal failure) Dec 29 16:45:59 postamt dovecot: child 17057 (login) returned error 89 (Fatal failure) Dec 29 16:45:59 postamt dovecot: Fatal: imap-login: epoll_create(): Too many open files Dec 29 16:46:59 postamt dovecot: Fatal: pop3-login: epoll_create(): Too many open files Dec 29 16:46:59 postamt dovecot: Fatal: pop3-login: epoll_create(): Too many open files Dec 29 16:46:59 postamt dovecot: child 17984 (login) returned error 89 (Fatal failure) Dec 29 16:46:59 postamt dovecot: child 17985 (login) returned error 89 (Fatal failure) Dec 29 16:46:59 postamt dovecot: child 17986 (login) returned error 89 (Fatal failure) Dec 29 16:46:59 postamt dovecot: child 17987 (login) returned error 89 (Fatal failure) Dec 29 16:46:59 postamt dovecot: child 17988 (login) returned error 89 (Fatal failure) Dec 29 16:46:59 postamt dovecot: child 17989 (login) returned error 89 (Fatal failure) Dec 29 16:46:59 postamt dovecot: child 17990 (login) returned error 89 (Fatal failure) Dec 29 16:46:59 postamt dovecot: Fatal: imap-login: epoll_create(): Too many open files Dec 29 16:47:59 postamt dovecot: Fatal: pop3-login: epoll_create(): Too many open files Dec 29 16:47:59 postamt dovecot: Fatal: pop3-login: epoll_create(): Too many open files Dec 29 16:47:59 postamt dovecot: child 18791 (login) returned error 89 (Fatal failure) Dec 29 16:47:59 postamt dovecot: child 18792 (login) returned error 89 (Fatal failure) Dec 29 16:47:59 postamt dovecot: child 18793 (login) returned error 89 (Fatal failure) Dec 29 16:47:59 postamt dovecot: child 18794 (login) returned error 89 (Fatal failure) Dec 29 16:47:59 postamt dovecot: child 18796 (login) returned error 89 (Fatal failure) Dec 29 16:47:59 postamt dovecot: Fatal: imap-login: epoll_create(): Too many open files Dec 29 16:47:59 postamt dovecot: Fatal: imap-login: epoll_create(): Too many open files Dec 29 16:48:59 postamt dovecot: Fatal: pop3-login: epoll_create(): Too many open files Dec 29 16:48:59 postamt dovecot: Fatal: imap-login: epoll_create(): Too many open files Dec 29 16:48:59 postamt dovecot: child 19618 (login) returned error 89 (Fatal failure) Dec 29 16:48:59 postamt dovecot: child 19614 (login) returned error 89 (Fatal failure) Dec 29 16:48:59 postamt dovecot: child 19620 (login) returned error 89 (Fatal failure) Dec 29 16:48:59 postamt dovecot: Fatal: imap-login: epoll_create(): Too many open files Dec 29 16:48:59 postamt dovecot: Fatal: imap-login: epoll_create(): Too many open files Dec 29 16:48:59 postamt dovecot: Fatal: pop3-login: epoll_create(): Too many open files Dec 29 16:48:59 postamt dovecot: Fatal: imap-login: epoll_create(): Too many open files ... Dec 29 20:58:59 postamt dovecot: Fatal: imap-login: epoll_create(): Too many open files Dec 29 20:58:59 postamt dovecot: child 5268 (login) returned error 89 (Fatal failure) Dec 29 20:58:59 postamt dovecot: child 5269 (login) returned error 89 (Fatal failure) Dec 29 20:58:59 postamt dovecot: child 5274 (login) returned error 89 (Fatal failure) Dec 29 20:58:59 postamt dovecot: Fatal: imap-login: epoll_create(): Too many open files -- Ralf Hildebrandt (Ralf.Hildebrandt(a)charite.de) snickebo(a)charite.de Postfix - Einrichtung, Betrieb und Wartung Tel. +49 (0)30-450 570-155 http://www.arschkrebs.de "Java is, in many ways, C++--." - Michael Feldman.

3 4

[Dovecot] 1.2.beta4: Fatal: io_loop_handle_add: epoll_ctl(1, 11): Bad file descriptor
by e-frog 02 Apr '09

02 Apr '09

Whenever dovecot is stopped while a dict process is running I see Fatal: io_loop_handle_add: epoll_ctl(1, 11): Bad file descriptor in the error log. The following patch fixes this for me. I'm sure there is a better way though. --- dovecot-1.2.beta4/src/master/dict-process.c.orig 2009-03-27 16:44:59.000000000 +0100 +++ dovecot-1.2.beta4/src/master/dict-process.c 2009-03-27 18:59:24.000000000 +0100 @@ -209,11 +209,6 @@ dict_process_destroyed(struct child_proc struct dict_listener *listener = process->listener; dict_process_deinit(process); - if (listener->processes == NULL) { - /* last listener died, create new ones */ - listener->io = io_add(listener->fd, IO_READ, - dict_listener_input, listener); - } } void dict_processes_init(void)

2 2