[Dovecot] Problem with expire plugin and expunge
Hello,
I am running dovecot 2.0.9 with expire plugin, using the sqlite backend. The following command is executed every day by cron:
doveadm expunge -A mailbox Trash savedbefore 30d
I started to use the expire plugin about one month ago. Since then,
using "doveadm search -A mailbox Trash savedbefore <days>" with different
values for <days>, I could see every day how the messages were getting older.
Yesterday was the first time that the expression "savedbefore 30d" became
true for the oldest messages in the Trash mailbox and these messages were
actually deleted from Trash. But today, all messages that were not deleted
yesterday are new to "doveadm search", that means that "doveadm search -A
mailbox Trash savedbefore 0d" shows all messages from Trash, but "doveadm
search -A mailbox Trash savedbefore 1d" shows no messages from Trash, though
during the last month I moved messages to Trash every day.
Best Regards Christoph
On Sat, 2011-02-19 at 10:10 +0100, Christoph Pleger wrote:
I started to use the expire plugin about one month ago. Since then, using "doveadm search -A mailbox Trash savedbefore <days>" with different values for <days>, I could see every day how the messages were getting older.
Yesterday was the first time that the expression "savedbefore 30d" became true for the oldest messages in the Trash mailbox and these messages were actually deleted from Trash. But today, all messages that were not deleted yesterday are new to "doveadm search", that means that "doveadm search -A mailbox Trash savedbefore 0d" shows all messages from Trash, but "doveadm search -A mailbox Trash savedbefore 1d" shows no messages from Trash, though during the last month I moved messages to Trash every day.
Are the timestamps wrong in the database? They should contain the timestamp of the oldest save-date of message in the mailbox.
Also check that the save-dates are as expected in the mailbox itself:
doveadm fetch -u user@domain date.saved mailbox Trash 1
And finally, I added some more helpful error and debug logging (which you'll get with doveadm -D): http://hg.dovecot.org/dovecot-2.0/raw-rev/9862e8388a1c
Hello,
Are the timestamps wrong in the database? They should contain the timestamp of the oldest save-date of message in the mailbox.
How can I look at the timestamps and check them? I opened my database with sqlite3 and entered "select * from expires;" this showed only one line:
christoph|Trash|1298413406
Also check that the save-dates are as expected in the mailbox itself:
doveadm fetch -u user@domain date.saved mailbox Trash 1
This tells me:
date.saved: 2011-01-21 18:15:10
But 'doveadm search' shows me no messages older than three days ...
Regards Christoph
Hello,
How can I look at the timestamps? By opening my database with sqlite3 and then enter "select * from expires;"? I did that and it showed:
christoph|Trash|1298917682
How can I check if this timestamp is correct? It is not really human readable.
doveadm fetch -u user@domain date.saved mailbox Trash 1
This tells me:
date.saved: 2011-02-23 18:44:16
But 'doveadm search' shows me no messages older than zero days, see below.
For testing, I have set the expunge interval to five days, that means that messages are to be deleted five days after they have been moved to Trash. Today, this became true for the first time and I have the same problem as before: The oldest messages have been deleted, but newer messages, which have been four, three, two or one days old before (due to 'doveadm search') are now all zero days old.
Surprisingly, I did not even get output from the cron job. On the other days, I got:
/etc/cron.daily/dovecot: doveadm: Debug: Loading modules from directory: /usr/lib/dovecot/modules doveadm: Debug: Module loaded: /usr/lib/dovecot/modules/lib20_expire_plugin.so doveadm: Debug: Loading modules from directory: /usr/lib/dovecot/modules/doveadm doveadm: Debug: Module loaded: /usr/lib/dovecot/modules/doveadm/lib10_doveadm_expire_plugin.so doveadm: Debug: Skipping module doveadm_quota_plugin, because dlopen() failed: /usr/lib/dovecot/modules/doveadm/lib10_doveadm_quota_plugin.so: undefined symbol: quota_user_module (this is usually intentional, so just ignore this message) doveadm: Debug: Skipping module doveadm_zlib_plugin, because dlopen() failed: /usr/lib/dovecot/modules/doveadm/lib10_doveadm_zlib_plugin.so: undefined symbol: i_stream_create_deflate (this is usually intentional, so just ignore this message) doveadm: Debug: expire: Searching only users listed in expire database
doveadm: Debug: expire: Stopping iteration on key shared/expire/christoph/Trash (1298413406 > 1298360493) doveadm: Debug: Loading modules from directory: /usr/lib/dovecot/modules doveadm: Debug: Module loaded: /usr/lib/dovecot/modules/lib20_expire_plugin.so doveadm: Debug: Loading modules from directory: /usr/lib/dovecot/modules/doveadm doveadm: Debug: Module loaded: /usr/lib/dovecot/modules/doveadm/lib10_doveadm_expire_plugin.so doveadm: Debug: Skipping module doveadm_quota_plugin, because dlopen() failed: /usr/lib/dovecot/modules/doveadm/lib10_doveadm_quota_plugin.so: undefined symbol: quota_user_module (this is usually intentional, so just ignore this message) doveadm: Debug: Skipping module doveadm_zlib_plugin, because dlopen() failed: /usr/lib/dovecot/modules/doveadm/lib10_doveadm_zlib_plugin.so: undefined symbol: i_stream_create_deflate (this is usually intentional, so just ignore this message) doveadm: Debug: expire: Searching only users listed in expire database doveadm: Debug: expire: Stopping iteration on key shared/expire/christoph/Trash (1298413406 > 1298360493)
But it is possible that I did not receive output because I was just shutting down the computer, because my mail system is still in a test phase and I do not yet have a hardware which I can use exclusively for the mail server.
Is it possible that expire/expunge works only if the mailbox is in maildir format, with every mail in a single file? I am using mdbox right now.
Best regards Christoph
On Tuesday, 22 February 2011 10:07:40 Timo Sirainen wrote:
On Sat, 2011-02-19 at 10:10 +0100, Christoph Pleger wrote:
I started to use the expire plugin about one month ago. Since then, using "doveadm search -A mailbox Trash savedbefore <days>" with different values for <days>, I could see every day how the messages were getting older. Yesterday was the first time that the expression "savedbefore 30d" became true for the oldest messages in the Trash mailbox and these messages were actually deleted from Trash. But today, all messages that were not deleted yesterday are new to "doveadm search", that means that "doveadm search -A mailbox Trash savedbefore 0d" shows all messages from Trash, but "doveadm search -A mailbox Trash savedbefore 1d" shows no messages from Trash, though during the last month I moved messages to Trash every day.
Are the timestamps wrong in the database? They should contain the timestamp of the oldest save-date of message in the mailbox.
Also check that the save-dates are as expected in the mailbox itself:
doveadm fetch -u user@domain date.saved mailbox Trash 1
And finally, I added some more helpful error and debug logging (which you'll get with doveadm -D): http://hg.dovecot.org/dovecot-2.0/raw-rev/9862e8388a1c
On 2/28/2011 1:56 PM, Christoph Pleger wrote:
Hello,
How can I look at the timestamps? By opening my database with sqlite3 and then enter "select * from expires;"? I did that and it showed:
christoph|Trash|1298917682
How can I check if this timestamp is correct? It is not really human readable.
[~] # date -u -d @1298917682 Mon Feb 28 18:28:02 UTC 2011 [~] #
Hello,
Timo Sirainen wrote:
Are the timestamps wrong in the database? They should contain the timestamp of the oldest save-date of message in the mailbox.
Today, messages from Trash have been expunged again.
The only timestamp in the database is Sun Mar 6 08:37:55 UTC 2011. This is obviously not the time from when the oldest message in the Trash mailbox was moved into that mailbox; I am moving messages to Trash every day.
Does anyone have an idea what is going wrong with the timestamps?
Regards Christoph
On Sun, 2011-03-06 at 22:23 +0100, Christoph Pleger wrote:
Today, messages from Trash have been expunged again.
The only timestamp in the database is Sun Mar 6 08:37:55 UTC 2011. This is obviously not the time from when the oldest message in the Trash mailbox was moved into that mailbox; I am moving messages to Trash every day.
Does anyone have an idea what is going wrong with the timestamps?
So it's as if the timestamp keeps changing to the newest deleted message.. Maybe mail_debug=yes shows something helpful with these patches:
http://hg.dovecot.org/dovecot-2.0/rev/eac54c2dc98b http://hg.dovecot.org/dovecot-2.0/rev/63ed0d3f4f52 http://hg.dovecot.org/dovecot-2.0/rev/2cb0fb910441
Hello,
Timo Sirainen wrote:
Does anyone have an idea what is going wrong with the timestamps?
So it's as if the timestamp keeps changing to the newest deleted message.. Maybe mail_debug=yes shows something helpful with these patches:
http://hg.dovecot.org/dovecot-2.0/rev/eac54c2dc98b http://hg.dovecot.org/dovecot-2.0/rev/63ed0d3f4f52 http://hg.dovecot.org/dovecot-2.0/rev/2cb0fb910441
It seems to work now. Message were expunged today and 'doveadm search -A mailbox Trash savedbefore <days>d' still shows me messages that are four days old or younger.
Regards Christoph
Hello,
I wrote:
So it's as if the timestamp keeps changing to the newest deleted message.. Maybe mail_debug=yes shows something helpful with these patches:
http://hg.dovecot.org/dovecot-2.0/rev/eac54c2dc98b http://hg.dovecot.org/dovecot-2.0/rev/63ed0d3f4f52 http://hg.dovecot.org/dovecot-2.0/rev/2cb0fb910441
It seems to work now. Message were expunged today and 'doveadm search -A mailbox Trash savedbefore <days>d' still shows me messages that are four days old or younger.
Big surprise: Something bad must have happened after the messages were deleted from Trash; now all messages are zero days old.
Regards Christoph
On Sat, 2011-03-12 at 15:54 +0100, Christoph Pleger wrote:
So it's as if the timestamp keeps changing to the newest deleted message.. Maybe mail_debug=yes shows something helpful with these patches:
http://hg.dovecot.org/dovecot-2.0/rev/eac54c2dc98b http://hg.dovecot.org/dovecot-2.0/rev/63ed0d3f4f52 http://hg.dovecot.org/dovecot-2.0/rev/2cb0fb910441
It seems to work now. Message were expunged today and 'doveadm search -A mailbox Trash savedbefore <days>d' still shows me messages that are four days old or younger.
Big surprise: Something bad must have happened after the messages were deleted from Trash; now all messages are zero days old.
Are you using maildir? Did you run with those patches + mail_debug=yes?
Hello,
Timo Sirainen wrote:
It seems to work now. Message were expunged today and 'doveadm search -A mailbox Trash savedbefore <days>d' still shows me messages that are four days old or younger.
Big surprise: Something bad must have happened after the messages were deleted from Trash; now all messages are zero days old.
Are you using maildir?
No, like I already wrote earlier, I am using mdbox. Do I have to use maildir?
Did you run with those patches + mail_debug=yes?
Unfortunately no: I ran with those patches, but forgot to change the value for mail_debug. I did that now.
Regards Christoph
Hello,
Big surprise: Something bad must have happened after the messages were deleted from Trash; now all messages are zero days old.
Are you using maildir? Did you run with those patches + mail_debug=yes?
Today, the daily cronjob expired some messages. I have attached the output of the job.
It seems that the error occurs not when expunging, but when deleting the first message after expunging. Before deleting a message, "doveadm search" showed me messages that were between zero and four days old, but directly after deleting a message, all messages were zero days old. Here is my log entry from when I deleted that message:
Mar 18 09:50:28 joseph dovecot: imap(christoph): Debug: expire: Saving first message to Trash, updating timestamp to 1300438228
Regards Christoph
On Fri, 2011-03-18 at 10:02 +0100, Christoph Pleger wrote:
Today, the daily cronjob expired some messages. I have attached the output of the job.
It looks like it expunged all the messages from Trash. Did you check if that happened? Did it expunge too many messages?
Mar 18 09:50:28 joseph dovecot: imap(christoph): Debug: expire: Saving first message to Trash, updating timestamp to 1300438228
This happens, because it thinks the Trash was empty..
Hello,
Today, the daily cronjob expired some messages. I have attached the output of the job.
It looks like it expunged all the messages from Trash. Did you check if that happened? Did it expunge too many messages?
No, after expunging, there still were messages in the Trash folder. I am sure that exactly those messages were removed from Trash which were older than the number of days I had given in my "doveadm expunge" command.
Regards Christoph
participants (4)
-
Christoph Pleger
-
Christoph Pleger
-
Timo Sirainen
-
Tom Talpey