[Dovecot] Wrong UIDs returned from mailbox_transaction_commit_get_uids()
Hi, Wrong UIDs are returned from mailbox_transaction_commit_get_uids() in dovecot-1.1.rc3. The problem is in: int mailbox_transaction_commit(struct mailbox_transaction_context **t) { uint32_t tmp; return mailbox_transaction_commit_get_uids(t, tmp, tmp, tmp); } It should be: int mailbox_transaction_commit(struct mailbox_transaction_context **t) { uint32_t tmp1, tmp2, tmp3; return mailbox_transaction_commit_get_uids(t, tmp1, tmp2, tmp3); } After this fix it works OK. Thanks, Ron You rock. That's why Blockbuster's offering you one month of Blockbuster Total Access, No Cost. http://tc.deals.yahoo.com/tc/blockbuster/text5.com
Re: [Dovecot] Wrong UIDs returned from mailbox_transaction_commit_get_uids()
It should be: int mailbox_transaction_commit(struct mailbox_transaction_context **t) { uint32_t tmp1, tmp2, tmp3; return mailbox_transaction_commit_get_uids(t, tmp1, tmp2, tmp3); } How/where does this help? The tmp values are ignored in any case, so I don't think this is the right fix for it. The problem occurs if transaction_commit() is hooked. In mail_log plugin I wanted to print the committed UIDs. I changed mail_log_transaction_commit() to: { ... ret = lbox-super.transaction_commit(t, uid_validity_r, first_saved_uid_r, last_saved_uid_r); if (0 == ret) { i_info(uid_validity=%u, first_uid=%u, last_uid=%u, *uid_validity_r, *first_saved_uid_r, *last_saved_uid_r); } return ret; } the result was: Apr 1 14:59:37 ha-test1 deliver([EMAIL PROTECTED]): uid_validity=1202218363, first_uid=1202218363, last_uid=1202218363 These values are equal to the UID validity. After changing mailbox_transaction_commit() as described above, I got correct values: Apr 1 15:09:50 ha-test1 deliver([EMAIL PROTECTED]): uid_validity=1202218363, first_uid=139, last_uid=139 Ron You rock. That's why Blockbuster's offering you one month of Blockbuster Total Access, No Cost. http://tc.deals.yahoo.com/tc/blockbuster/text5.com
[Dovecot] Flags can be changed in read-only mode
Hi, It seems that IMAP flags can be changed in EXAMINE read-only mode. Luckily, messages cannot be expunged. This happens in both dovecot 1.0.12 and 1.1.rc3: * OK Dovecot ready. 1 login *** *** 1 OK Logged in. 2 examine inbox * FLAGS (\Answered \Flagged \Deleted \Seen \Draft) * OK [PERMANENTFLAGS ()] Read-only mailbox. * 1 EXISTS * 1 RECENT * OK [UNSEEN 1] First unseen. * OK [UIDVALIDITY 1206865015] UIDs valid * OK [UIDNEXT 2] Predicted next UID 2 OK [READ-ONLY] Select completed. 3 fetch 1:* flags * 1 FETCH (FLAGS (\Recent)) 3 OK Fetch completed. 4 store 1:* +flags (\Deleted) * 1 FETCH (FLAGS (\Deleted \Recent)) 4 OK Store completed. 5 fetch 1:* flags * 1 FETCH (FLAGS (\Deleted \Recent)) 5 OK Fetch completed. 6 expunge 6 OK Expunge completed. 7 fetch 1:* flags * 1 FETCH (FLAGS (\Deleted \Recent)) 7 OK Fetch completed. Thanks, Ron Be a better friend, newshound, and know-it-all with Yahoo! Mobile. Try it now. http://mobile.yahoo.com/;_ylt=Ahu06i62sR8HDtDypao8Wcj9tAcJ
Re: [Dovecot] Wrong message information reported shortly after delivery
Can you reproduce it without your IMAP client? For example using imaptest (http://imapwiki.org/ImapTest) as the client and running: Hi, Here's some more information on how to easily reproduce the problem. First, I'd like to describe my environment: OS - RHEL4, FS - ext3, dovecot 1.0.12. See dovecot -n at end of message. Messages are delivered via dovecot deliver invoked by postfix. The problem is reproduced when the system is completely idle - no user is logged in, except the test user. I wrote a short python script (attached) that reproduces the problem very easily. The script sends an email via SMTP, then IMAP fetches from inbox to check when message arrives. Once it arrives it checks if the size is zero and reports it. The script ends when dovecot reports a non-zero message size. The script consistently reproduces the problem on every RHEL4 server I tested (weak and strong) and with any file size. The script is run as ./send_fetch_test.py USER PASSWORD FILE [SERVER] FILE - any file. Contents doesn't matter. NOTE - The script initially deletes all messages from inbox just to minimize output. The problem occurs also when other messages exist. Here's a sample output: 2008-03-09 17:00:41.449833 Sent 1011 bytes to [EMAIL PROTECTED] 2008-03-09 17:00:41.472034 No messages in INBOX. Waiting... 2008-03-09 17:00:42.480654 No messages in INBOX. Waiting... 2008-03-09 17:00:43.487617 ERROR: Got invalid RFC822.SIZE 0: 1 (FLAGS (\Recent) INTERNALDATE 01-Jan-1970 00:00:00 + RFC822.SIZE 0 UID 63) 2008-03-09 17:00:44.494382 ERROR: Got invalid RFC822.SIZE 0: 1 (FLAGS (\Recent) INTERNALDATE 01-Jan-1970 00:00:00 + RFC822.SIZE 0 UID 63) 2008-03-09 17:00:45.501444 ERROR: Got invalid RFC822.SIZE 0: 1 (FLAGS (\Recent) INTERNALDATE 01-Jan-1970 00:00:00 + RFC822.SIZE 0 UID 63) 2008-03-09 17:00:46.550623 ERROR: Got invalid RFC822.SIZE 0: 1 (FLAGS (\Recent) INTERNALDATE 01-Jan-1970 00:00:00 + RFC822.SIZE 0 UID 63) 2008-03-09 17:00:47.593704 Got valid RFC822.SIZE 1509: 1 (FLAGS (\Recent) INTERNALDATE 09-Mar-2008 17:00:41 +0200 RFC822.SIZE 1509 UID 63) For this output I attached also the IMAP network capture and a strace of the imap process. dovecot -n: # 1.0.12: /usr/local/etc/dovecot.conf log_timestamp: “%Y-%m-%d %H:%M:%S ” protocols: imap listen: *:143 ssl_disable: yes disable_plaintext_auth: no login_dir: /usr/local/var/run/dovecot/login login_executable: /usr/local/libexec/dovecot/imap-login login_process_per_connection: no first_valid_uid: 150 last_valid_uid: 150 dotlock_use_excl: yes fsync_disable: yes maildir_copy_with_hardlinks: yes maildir_copy_preserve_filename: yes mail_plugins: quota imap_quota auth default: mechanisms: plain login user: nobody master_user_separator: * passdb: driver: sql args: /usr/local/etc/dovecot-sql.conf passdb: driver: passwd-file args: /usr/local/etc/dovecot.masterusers master: yes userdb: driver: prefetch userdb: driver: sql args: /usr/local/etc/dovecot-sql.conf socket: type: listen client: path: /var/spool/postfix/private/auth mode: 432 user: postfix group: postfix master: path: /var/run/dovecot/auth-master mode: 432 user: vmail group: mail plugin: quota: maildir:storage=1024 I hope this helps, Thanks, Ron Never miss a thing. Make Yahoo your home page. http://www.yahoo.com/r/hs send_fetch_test.tgz Description: application/compressed
Re: [Dovecot] Wrong message information reported shortly after delivery
Thanks, in my previous tests I didn't use quota plugin with deliver which was needed to notice this. The problem is: 1. deliver adds message appended to index file 2. quota plugin runs for a while 3. deliver updates filename-uid mapping in dovecot-uidlist Thanks for the quick answer. Why does it take four seconds (!) from the time dovecot first reports an invalid message information until the correct information is reported? The time is measured for the delivery of a 1KB message to an empty mailbox on a completely idle system. 2008-03-09 17:00:41.449833 Sent 1011 bytes to [EMAIL PROTECTED] 2008-03-09 17:00:41.472034 No messages in INBOX. Waiting... 2008-03-09 17:00:42.480654 No messages in INBOX. Waiting... 2008-03-09 17:00:43.487617 ERROR: Got invalid RFC822.SIZE 0: 1 (FLAGS (\Recent) INTERNALDATE 01-Jan-1970 00:00:00 + RFC822.SIZE 0 UID 63) 2008-03-09 17:00:44.494382 ERROR: Got invalid RFC822.SIZE 0: 1 (FLAGS (\Recent) INTERNALDATE 01-Jan-1970 00:00:00 + RFC822.SIZE 0 UID 63) 2008-03-09 17:00:45.501444 ERROR: Got invalid RFC822.SIZE 0: 1 (FLAGS (\Recent) INTERNALDATE 01-Jan-1970 00:00:00 + RFC822.SIZE 0 UID 63) 2008-03-09 17:00:46.550623 ERROR: Got invalid RFC822.SIZE 0: 1 (FLAGS (\Recent) INTERNALDATE 01-Jan-1970 00:00:00 + RFC822.SIZE 0 UID 63) 2008-03-09 17:00:47.593704 Got valid RFC822.SIZE 1509: 1 (FLAGS (\Recent) INTERNALDATE 09-Mar-2008 17:00:41 +0200 RFC822.SIZE 1509 UID 63) Thanks again, Ron Never miss a thing. Make Yahoo your home page. http://www.yahoo.com/r/hs
[Dovecot] Wrong message information reported shortly after delivery
Hi, If an IMAP fetch is issued some short time after a message was delivered with dovecot deliver then dovecot reports wrong (zero) values for that new message. Afterward, it reports the information OK. This causes problems to our IMAP client. The problem is easily reproduced with a large message on a slow machine. I'm using dovecot 1.0.10 Here's a sample trace: 1 uid fetch 1:* fast * 1 FETCH (FLAGS (\Recent) INTERNALDATE 06-Mar-2008 17:20:50 +0200 RFC822.SIZE 3378380 UID 1) * 2 FETCH (FLAGS (\Recent) INTERNALDATE 06-Mar-2008 17:21:40 +0200 RFC822.SIZE 3378380 UID 2) * 3 FETCH (FLAGS (\Recent) INTERNALDATE 06-Mar-2008 17:23:38 +0200 RFC822.SIZE 3378380 UID 3) * 4 FETCH (FLAGS (\Recent) INTERNALDATE 06-Mar-2008 17:40:06 +0200 RFC822.SIZE 3378380 UID 4) 1 OK Fetch completed. Here dovecot reports a new message (5) arrived 1 uid fetch 1:* fast * 1 FETCH (FLAGS (\Recent) INTERNALDATE 06-Mar-2008 17:20:50 +0200 RFC822.SIZE 3378380 UID 1) * 2 FETCH (FLAGS (\Recent) INTERNALDATE 06-Mar-2008 17:21:40 +0200 RFC822.SIZE 3378380 UID 2) * 3 FETCH (FLAGS (\Recent) INTERNALDATE 06-Mar-2008 17:23:38 +0200 RFC822.SIZE 3378380 UID 3) * 4 FETCH (FLAGS (\Recent) INTERNALDATE 06-Mar-2008 17:40:06 +0200 RFC822.SIZE 3378380 UID 4) * 5 EXISTS * 5 RECENT 1 OK Fetch completed. This is where dovecot reports wrong information about message 5 1 uid fetch 1:* fast * 1 FETCH (FLAGS (\Recent) INTERNALDATE 06-Mar-2008 17:20:50 +0200 RFC822.SIZE 3378380 UID 1) * 2 FETCH (FLAGS (\Recent) INTERNALDATE 06-Mar-2008 17:21:40 +0200 RFC822.SIZE 3378380 UID 2) * 3 FETCH (FLAGS (\Recent) INTERNALDATE 06-Mar-2008 17:23:38 +0200 RFC822.SIZE 3378380 UID 3) * 4 FETCH (FLAGS (\Recent) INTERNALDATE 06-Mar-2008 17:40:06 +0200 RFC822.SIZE 3378380 UID 4) * 5 FETCH (FLAGS (\Recent) INTERNALDATE 01-Jan-1970 00:00:00 + RFC822.SIZE 0 UID 5) 1 OK Fetch completed. The same wrong information is repeated 1 uid fetch 1:* fast * 1 FETCH (FLAGS (\Recent) INTERNALDATE 06-Mar-2008 17:20:50 +0200 RFC822.SIZE 3378380 UID 1) * 2 FETCH (FLAGS (\Recent) INTERNALDATE 06-Mar-2008 17:21:40 +0200 RFC822.SIZE 3378380 UID 2) * 3 FETCH (FLAGS (\Recent) INTERNALDATE 06-Mar-2008 17:23:38 +0200 RFC822.SIZE 3378380 UID 3) * 4 FETCH (FLAGS (\Recent) INTERNALDATE 06-Mar-2008 17:40:06 +0200 RFC822.SIZE 3378380 UID 4) * 5 FETCH (FLAGS (\Recent) INTERNALDATE 01-Jan-1970 00:00:00 + RFC822.SIZE 0 UID 5) 1 OK Fetch completed. The same wrong information is repeated several times 1 uid fetch 1:* fast * 1 FETCH (FLAGS (\Recent) INTERNALDATE 06-Mar-2008 17:20:50 +0200 RFC822.SIZE 3378380 UID 1) * 2 FETCH (FLAGS (\Recent) INTERNALDATE 06-Mar-2008 17:21:40 +0200 RFC822.SIZE 3378380 UID 2) * 3 FETCH (FLAGS (\Recent) INTERNALDATE 06-Mar-2008 17:23:38 +0200 RFC822.SIZE 3378380 UID 3) * 4 FETCH (FLAGS (\Recent) INTERNALDATE 06-Mar-2008 17:40:06 +0200 RFC822.SIZE 3378380 UID 4) * 5 FETCH (FLAGS (\Recent) INTERNALDATE 01-Jan-1970 00:00:00 + RFC822.SIZE 0 UID 5) 1 OK Fetch completed. Trace truncated here Finally, correct information is reported 1 uid fetch 1:* fast * 1 FETCH (FLAGS (\Recent) INTERNALDATE 06-Mar-2008 17:20:50 +0200 RFC822.SIZE 3378380 UID 1) * 2 FETCH (FLAGS (\Recent) INTERNALDATE 06-Mar-2008 17:21:40 +0200 RFC822.SIZE 3378380 UID 2) * 3 FETCH (FLAGS (\Recent) INTERNALDATE 06-Mar-2008 17:23:38 +0200 RFC822.SIZE 3378380 UID 3) * 4 FETCH (FLAGS (\Recent) INTERNALDATE 06-Mar-2008 17:40:06 +0200 RFC822.SIZE 3378380 UID 4) * 5 FETCH (FLAGS (\Recent) INTERNALDATE 06-Mar-2008 17:41:07 +0200 RFC822.SIZE 3378380 UID 5) dovecot -n: # 1.0.10: /etc/dovecot.conf log_timestamp: “%Y-%m-%d %H:%M:%S ” protocols: imap listen: *:143 ssl_disable: yes login_dir: /var/run/dovecot/login login_executable: /usr/libexec/dovecot/imap-login login_process_per_connection: no first_valid_uid: 150 last_valid_uid: 150 dotlock_use_excl: yes fsync_disable: yes maildir_copy_with_hardlinks: yes maildir_copy_preserve_filename: yes mail_plugins: quota imap_quota auth default: mechanisms: plain login user: nobody master_user_separator: * passdb: driver: sql args: /etc/dovecot-sql.conf passdb: driver: passwd-file args: /etc/dovecot.masterusers master: yes userdb: driver: prefetch userdb: driver: sql args: /etc/dovecot-sql.conf socket: type: listen client: path: /var/spool/postfix/private/auth mode: 432 user: postfix group: postfix master: path: /var/run/dovecot/auth-master mode: 432 user: vmail group: mail plugin: quota: maildir:storage=1024 Thanks, Ron Never miss a thing. Make Yahoo your home page. http://www.yahoo.com/r/hs
Re: [Dovecot] Wrong message information reported shortly after delivery
On Thu, 2008-03-06 at 08:21 -0800, Ron Avriel wrote: If an IMAP fetch is issued some short time after a message was delivered with dovecot deliver then dovecot reports wrong (zero) values for that new message. Afterward, it reports the information OK. What OS/filesystem do you use? I don't see how this is possible. The mails are first written to tmp/ directory and then they're atomically rename()d to the new/ or cur/ directory. I also tested this myself, rapidly sending the same FETCH command 1000 times/sec while delivering 40MB mails to the maildir. The size was always correct. I'm using standard out of the box Redhat EL 4 with an ext3 filesystem. Since I can reproduce it easily on different RHEL4 machines, tell me what additional information you'd like. Thanks again, Ron Never miss a thing. Make Yahoo your home page. http://www.yahoo.com/r/hs
[Dovecot] How to log uid and keywords of delivered mail?
Hi, I’d like to extend the mail_log plugin to log the uid and keywords of a mail delivered by LDA. The keywords are set by the sieve plugin. I added a mail_log_save_finish() function hook listed below. However, the uid of the mail is always zero and trying to get the keywords results in assertion failure, probably because the message is not committed yet: Feb 13 08:07:42 ha-test1 deliver([EMAIL PROTECTED]): dest mail seq: 23, uid: 0 Feb 13 08:07:42 ha-test1 deliver([EMAIL PROTECTED]): file mail-index-view.c: line 217 (_view_lookup_full): assertion failed: (seq 0 seq = mail_index_view_get_messages_count(view)) Feb 13 08:07:42 ha-test1 deliver([EMAIL PROTECTED]): Raw backtrace: /usr/local/libexec/dovecot/deliver(i_syslog_panic_handler+0x21) [0x80965d9] - /usr/local/libexec/dovecot/deliver [0x8096443] - /usr/local/libexec/dovecot/deliver [0x80821d0] - /usr/local/libexec/dovecot/deliver [0x80827c3] - /usr/local/libexec/dovecot/deliver(mail_index_lookup_keywords+0x32) [0x8082aae] - /usr/local/libexec/dovecot/deliver(index_mail_get_keywords+0x6c) [0x806f038] - /usr/local/lib/dovecot/lda/lib20_mail_log_plugin.so [0xcbdac8] - /usr/local/libexec/dovecot/deliver(mail_storage_copy+0xa8) [0x808a600] - /usr/local/libexec/dovecot/deliver(maildir_copy+0x3e) [0x805e252] - /usr/local/lib/dovecot/lda/lib10_quota_plugin.so [0xfc9741] - /usr/local/lib/dovecot/lda/lib20_mail_log_plugin.so [0xcbd48f] - /usr/local/libexec/dovecot/deliver(deliver_save+0x192) [0x80559ea] - /usr/local/lib/dovecot/lda/lib90_cmusieve_plugin.so [0xaa16bf] - /usr/local/lib/dovecot/lda/lib90_cmusieve_plugin.so [0xaaea0d] - /usr/local/lib/dovecot/lda/lib9 static int mail_log_save_finish(struct mail_save_context *ctx, struct mail *dest_mail) { struct mail_log_mailbox *lbox = MAIL_LOG_CONTEXT(ctx-transaction-box); int ret; ret = lbox-super.save_finish(ctx, dest_mail); if (ret 0) { return ret; } if (dest_mail != NULL) { const char *const *kw_list; i_info(dest mail seq: %u, uid: %u, dest_mail-seq, dest_mail-uid); kw_list = mail_get_keywords(dest_mail); i_info(dest mail kw: %s, kw_list ? t_strarray_join(kw_list, ,) : NONE); } return ret; } Some mail data, such as flags and headers, can be retrieved OK. I'm using dovecot-1.0.10 and dovecot-sieve-1.0.2. Any help in getting the uid and keywords by mail_log plugin will be greatly appreciated. Thanks, Ron Looking for last minute shopping deals? Find them fast with Yahoo! Search. http://tools.search.yahoo.com/newsearch/category.php?category=shopping
[Dovecot] Segmentation fault in dovecot-sieve-1.1.2 + dovecot-1.1.beta13
Hi, dovecot-sieve-1.1.2 + dovecot-1.1.beta13 segfaults with the following sieve filter: --- require [imapflags]; if header :contains subject [test] { addflag $testflag; } --- when a message with a subject containing test is delivered via dovecot lda. The fault backtrace is: (gdb) run Starting program: /usr/local/libexec/dovecot/deliver -d [EMAIL PROTECTED] bad.txt Program received signal SIGSEGV, Segmentation fault. get_flags (sieve_flags=0xbfe7e438, flags_r=0xbfe7dee4, keywords_r=0x2) at /root/dovecot-1.1.beta13/src/lib/array.h:145 145 *count_r = array-buffer-used / array-element_size; (gdb) bt #0 get_flags (sieve_flags=0xbfe7e438, flags_r=0xbfe7dee4, keywords_r=0x2) at /root/dovecot-1.1.beta13/src/lib/array.h:145 #1 0x00f68744 in sieve_keep (ac=0x2, ic=0x0, sc=0xbfe7f4e0, mc=0xbfe7f480, errmsg=0xbfe7e3f0) at sieve-cmu.c:561 #2 0x00f779a5 in do_sieve_error (ret=0, interp=0x92dbf18, script_context=0xbfe7f4e0, message_context=0xbfe7f480, imapflags=0xbfe7e438, actions=0x92e42d8, notify_list=0x0, lastaction=8, implicit_keep=1, actions_string=0xbfe7e440 Action(s) taken:\n, errmsg=0x0) at script.c:627 #3 0x00f780d8 in sieve_execute_bytecode (exe=0x92dcc58, interp=0x92dbf18, script_context=0xbfe7f4e0, message_context=0xbfe7f480) at script.c:824 #4 0x00f69809 in cmu_sieve_run (namespaces=0x92d5c70, storage_r=0xbfe7f6ac, mail=0x92de358, script_path=0x92d3c82 /usr/local/etc/sieve_global.txt, destaddr=0xbff3fbb9 [EMAIL PROTECTED], username=0x92d4b05 [EMAIL PROTECTED], mailbox=0x80d0367 INBOX) at sieve-cmu.c:971 #5 0x00f67752 in cmusieve_deliver_mail (namespaces=0x92d5c70, storage_r=0xbfe7f6ac, mail=0x92de358, destaddr=0xbff3fbb9 [EMAIL PROTECTED], mailbox=0x80d0367 INBOX) at cmusieve-plugin.c:76 #6 0x0805aa4f in main (argc=3, argv=0xbfe7f794) at deliver.c:940 (gdb) I managed to fix the problem with this patch to sieve-cmu.c: --- sieve-cmu.c.orig 2007-12-31 10:21:54.0 +0200 +++ sieve-cmu.c 2007-12-31 10:24:18.0 +0200 @@ -495,6 +495,7 @@ ARRAY_DEFINE(keywords, const char *); const char *name; int i; +unsigned int count; *flags_r = 0; @@ -524,7 +525,7 @@ array_append(keywords, name, 1); *keywords_r = array_count(keywords) == 1 ? NULL : - array_get(keywords, 0); + array_get(keywords, count); } static int sieve_fileinto(void *ac, BTW, dovecot-sieve-1.0.2 + dovecot-1.0.9 work OK for the above. Happy New Year and thanks for a great product, Ron Never miss a thing. Make Yahoo your home page. http://www.yahoo.com/r/hs