[Dovecot] Problem with expire plugin and expunge

Sun Apr 10 10:11:58 EEST 2011

Hello,

Timo Sirainen wrote:

> > Is there any solution in sight for this? Is there some additional
> > information I can give you for solving that problem?
>
> Well, the weird thing is that the logs say it's expunging everything and
> you say it's not.. What about if you change the cronjob to do:
>
> doveadm fetch uid mailbox Trash
> doveadm expunge mailbox Trash ..
> doveadm fetch uid mailbox Trash
>
> so that it logs 1) a list of UIDs before expunge, 2) UIDs of what get
> expunged and 3) UIDs that exist after expunge.

I have attached a file with the output of yesterday's cron job's execution. As 
you can see, after expunging there are still messages in the Trash folder, 
though expunge itself says that it has removed the first message.

Regards
  Christoph  

-------------- next part --------------
/etc/cron.daily/dovecot:
uid: 4638
uid: 4639
uid: 4640
uid: 4641
uid: 4642
uid: 4643
uid: 4644
uid: 4645
uid: 4646
uid: 4647
uid: 4648
uid: 4649
uid: 4650
uid: 4651
uid: 4652
uid: 4653
uid: 4654
uid: 4655
uid: 4656
uid: 4657
uid: 4658
uid: 4659
uid: 4660
uid: 4661
uid: 4662
uid: 4663
uid: 4664
uid: 4665
uid: 4666
uid: 4667
uid: 4668
uid: 4669
uid: 4670
uid: 4671
uid: 4672
uid: 4673
uid: 4674
uid: 4675
uid: 4676
uid: 4677
uid: 4678
uid: 4679
uid: 4680
uid: 4681
uid: 4682
uid: 4683
uid: 4684
uid: 4685
uid: 4686
uid: 4687
uid: 4688
uid: 4689
uid: 4690
uid: 4691
uid: 4692
uid: 4693
uid: 4694
uid: 4695
uid: 4696
uid: 4697
uid: 4698
uid: 4699
uid: 4700
uid: 4701
uid: 4702
uid: 4703
uid: 4704
uid: 4705
uid: 4706
uid: 4707
uid: 4708
uid: 4709
uid: 4710
uid: 4711
uid: 4712
uid: 4713
uid: 4714
uid: 4715
uid: 4716
uid: 4717
uid: 4718
uid: 4719
uid: 4720
uid: 4721
uid: 4722
uid: 4723
uid: 4724
uid: 4725
uid: 4726
uid: 4727
uid: 4728
uid: 4729
uid: 4730
uid: 4731
uid: 4732
uid: 4733
uid: 4734
uid: 4735
uid: 4736
uid: 4737
uid: 4738
uid: 4739
uid: 4740
uid: 4741
uid: 4742
uid: 4743
uid: 4744
uid: 4745
uid: 4746
uid: 4747
uid: 4748
uid: 4749
uid: 4750
uid: 4751
uid: 4752
uid: 4753
uid: 4754
uid: 4755
uid: 4756
uid: 4757
uid: 4758
uid: 4759
uid: 4760
uid: 4761
uid: 4762
uid: 4763
uid: 4764
uid: 4765
uid: 4766
uid: 4767
uid: 4768
uid: 4769
uid: 4770
uid: 4771
uid: 4772
uid: 4773
uid: 4774
uid: 4775
uid: 4776
uid: 4777
uid: 4778
uid: 4779
uid: 4780
uid: 4781
uid: 4782
uid: 4783
uid: 4784
uid: 4785
uid: 4786
uid: 4787
uid: 4788
uid: 4789
uid: 4790
uid: 4791
uid: 4792
uid: 4793
uid: 4794
uid: 4795
uid: 4796
uid: 4797
uid: 4798
uid: 4799
uid: 4800
uid: 4801
uid: 4802
uid: 4803
uid: 4804
uid: 4805
uid: 4806
uid: 4807
uid: 4808
uid: 4809
uid: 4810
uid: 4811
uid: 4812
uid: 4813
uid: 4814
uid: 4815
uid: 4816
uid: 4817
uid: 4818
uid: 4819
uid: 4820
uid: 4821
uid: 4822
uid: 4823
uid: 4824
uid: 4825
uid: 4826
uid: 4827
uid: 4828
uid: 4829
uid: 4830
uid: 4831
uid: 4832
uid: 4833
uid: 4834
uid: 4835
uid: 4836
uid: 4837
uid: 4838
uid: 4839
uid: 4840
uid: 4841
uid: 4842
uid: 4843
uid: 4844
uid: 4845
uid: 4846
uid: 4847
uid: 4848
uid: 4849
uid: 4850
uid: 4851
uid: 4852
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: Skipping module doveadm_acl_plugin, because dlopen() failed: /usr/lib/dovecot/modules/doveadm/lib10_doveadm_acl_plugin.so: undefined symbol: acl_user_module (this is usually intentional, so just ignore this message)
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/Spam (1302158960 > 1302063905)
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: Skipping module doveadm_acl_plugin, because dlopen() failed: /usr/lib/dovecot/modules/doveadm/lib10_doveadm_acl_plugin.so: undefined symbol: acl_user_module (this is usually intentional, so just ignore this message)
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(christoph): Debug: auth input: christoph home=/mailhome/vmail/christoph
doveadm(christoph): Debug: Effective uid=110, gid=114, home=/mailhome/vmail/christoph
doveadm(christoph): Debug: fs: root=/mailhome/vmail/christoph/mdbox, index=, control=, inbox=
doveadm(christoph): Debug: Namespace : Using permissions from /mailhome/vmail/christoph/mdbox: mode=0700 gid=-1
doveadm(christoph): Debug: expunge: box=Trash uid=4638
doveadm(christoph): Debug: expunge: box=Trash uid=4639
doveadm(christoph): Debug: expunge: box=Trash uid=4640
doveadm(christoph): Debug: expunge: box=Trash uid=4641
doveadm(christoph): Debug: expunge: box=Trash uid=4642
doveadm(christoph): Debug: expunge: box=Trash uid=4643
doveadm(christoph): Debug: expunge: box=Trash uid=4644
doveadm(christoph): Debug: expunge: box=Trash uid=4645
doveadm(christoph): Debug: expunge: box=Trash uid=4646
doveadm(christoph): Debug: expunge: box=Trash uid=4647
doveadm(christoph): Debug: expunge: box=Trash uid=4648
doveadm(christoph): Debug: expunge: box=Trash uid=4649
doveadm(christoph): Debug: expunge: box=Trash uid=4650
doveadm(christoph): Debug: expunge: box=Trash uid=4651
doveadm(christoph): Debug: expunge: box=Trash uid=4652
doveadm(christoph): Debug: expunge: box=Trash uid=4653
doveadm(christoph): Debug: expunge: box=Trash uid=4654
doveadm(christoph): Debug: expunge: box=Trash uid=4655
doveadm(christoph): Debug: expunge: box=Trash uid=4656
doveadm(christoph): Debug: expunge: box=Trash uid=4657
doveadm(christoph): Debug: expunge: box=Trash uid=4658
doveadm(christoph): Debug: expunge: box=Trash uid=4659
doveadm(christoph): Debug: expunge: box=Trash uid=4660
doveadm(christoph): Debug: expunge: box=Trash uid=4661
doveadm(christoph): Debug: expunge: box=Trash uid=4662
doveadm(christoph): Debug: expunge: box=Trash uid=4663
doveadm(christoph): Debug: expunge: box=Trash uid=4664
doveadm(christoph): Debug: expunge: box=Trash uid=4665
doveadm(christoph): Debug: expunge: box=Trash uid=4666
doveadm(christoph): Debug: expunge: box=Trash uid=4667
doveadm(christoph): Debug: expunge: box=Trash uid=4668
doveadm(christoph): Debug: expunge: box=Trash uid=4669
doveadm(christoph): Debug: expunge: box=Trash uid=4670
doveadm(christoph): Debug: expunge: box=Trash uid=4671
doveadm(christoph): Debug: expunge: box=Trash uid=4672
doveadm(christoph): Debug: expunge: box=Trash uid=4673
doveadm(christoph): Debug: expunge: box=Trash uid=4674
doveadm(christoph): Debug: expunge: box=Trash uid=4675
doveadm(christoph): Debug: expunge: box=Trash uid=4676
doveadm(christoph): Debug: expunge: box=Trash uid=4677
doveadm(christoph): Debug: expunge: box=Trash uid=4678
doveadm(christoph): Debug: expunge: box=Trash uid=4679
doveadm(christoph): Debug: expunge: box=Trash uid=4680
doveadm(christoph): Debug: expunge: box=Trash uid=4681
doveadm(christoph): Debug: expunge: box=Trash uid=4682
doveadm(christoph): Debug: expunge: box=Trash uid=4683
doveadm(christoph): Debug: expunge: box=Trash uid=4684
doveadm(christoph): Debug: expunge: box=Trash uid=4685
doveadm(christoph): Debug: expunge: box=Trash uid=4686
doveadm(christoph): Debug: expunge: box=Trash uid=4687
doveadm(christoph): Debug: expunge: box=Trash uid=4688
doveadm(christoph): Debug: expunge: box=Trash uid=4689
doveadm(christoph): Debug: expunge: box=Trash uid=4690
doveadm(christoph): Debug: expunge: box=Trash uid=4691
doveadm(christoph): Debug: expunge: box=Trash uid=4692
doveadm(christoph): Debug: expunge: box=Trash uid=4693
doveadm(christoph): Debug: expunge: box=Trash uid=4694
doveadm(christoph): Debug: expunge: box=Trash uid=4695
doveadm(christoph): Debug: expunge: box=Trash uid=4696
doveadm(christoph): Debug: expunge: box=Trash uid=4697
doveadm(christoph): Debug: expunge: box=Trash uid=4698
doveadm(christoph): Debug: expunge: box=Trash uid=4699
doveadm(christoph): Debug: expunge: box=Trash uid=4700
doveadm(christoph): Debug: expunge: box=Trash uid=4701
doveadm(christoph): Debug: expunge: box=Trash uid=4702
doveadm(christoph): Debug: expunge: box=Trash uid=4703
doveadm(christoph): Debug: expunge: box=Trash uid=4704
doveadm(christoph): Debug: expunge: box=Trash uid=4705
doveadm(christoph): Debug: expunge: box=Trash uid=4706
doveadm(christoph): Debug: expunge: box=Trash uid=4707
doveadm(christoph): Debug: expunge: box=Trash uid=4708
doveadm(christoph): Debug: expunge: box=Trash uid=4709
doveadm(christoph): Debug: expunge: box=Trash uid=4710
doveadm(christoph): Debug: expunge: box=Trash uid=4711
doveadm(christoph): Debug: expunge: box=Trash uid=4712
doveadm(christoph): Debug: expunge: box=Trash uid=4713
doveadm(christoph): Debug: expunge: box=Trash uid=4714
doveadm(christoph): Debug: expunge: box=Trash uid=4715
doveadm(christoph): Debug: expunge: box=Trash uid=4716
doveadm(christoph): Debug: expunge: box=Trash uid=4717
doveadm(christoph): Debug: expunge: box=Trash uid=4718
doveadm(christoph): Debug: expunge: box=Trash uid=4719
doveadm(christoph): Debug: expunge: box=Trash uid=4720
doveadm(christoph): Debug: expunge: box=Trash uid=4721
doveadm(christoph): Debug: expunge: box=Trash uid=4722
doveadm(christoph): Debug: expunge: box=Trash uid=4723
doveadm(christoph): Debug: expunge: box=Trash uid=4724
doveadm(christoph): Debug: expunge: box=Trash uid=4725
doveadm(christoph): Debug: expunge: box=Trash uid=4726
doveadm(christoph): Debug: expunge: box=Trash uid=4727
doveadm(christoph): Debug: expunge: box=Trash uid=4728
doveadm(christoph): Debug: expunge: box=Trash uid=4729
doveadm(christoph): Debug: expunge: box=Trash uid=4730
doveadm(christoph): Debug: expunge: box=Trash uid=4731
doveadm(christoph): Debug: expunge: box=Trash uid=4732
doveadm(christoph): Debug: expunge: box=Trash uid=4733
doveadm(christoph): Debug: expunge: box=Trash uid=4734
doveadm(christoph): Debug: expunge: box=Trash uid=4735
doveadm(christoph): Debug: expunge: box=Trash uid=4736
doveadm(christoph): Debug: expunge: box=Trash uid=4737
doveadm(christoph): Debug: expunge: box=Trash uid=4738
doveadm(christoph): Debug: expunge: box=Trash uid=4739
doveadm(christoph): Debug: expunge: box=Trash uid=4740
doveadm(christoph): Debug: expunge: box=Trash uid=4741
doveadm(christoph): Debug: expunge: box=Trash uid=4742
doveadm(christoph): Debug: expunge: box=Trash uid=4743
doveadm(christoph): Debug: expunge: box=Trash uid=4744
doveadm(christoph): Debug: expunge: box=Trash uid=4745
doveadm(christoph): Debug: expunge: box=Trash uid=4746
doveadm(christoph): Debug: expunge: box=Trash uid=4747
doveadm(christoph): Debug: expunge: box=Trash uid=4748
doveadm(christoph): Debug: expunge: box=Trash uid=4749
doveadm(christoph): Debug: expunge: box=Trash uid=4750
doveadm(christoph): Debug: expunge: box=Trash uid=4751
doveadm(christoph): Debug: expunge: box=Trash uid=4752
doveadm(christoph): Debug: expunge: box=Trash uid=4753
doveadm(christoph): Debug: expunge: box=Trash uid=4754
doveadm(christoph): Debug: expunge: box=Trash uid=4755
doveadm(christoph): Debug: expunge: box=Trash uid=4756
doveadm(christoph): Debug: expunge: box=Trash uid=4757
doveadm(christoph): Debug: expunge: box=Trash uid=4758
doveadm(christoph): Debug: expunge: box=Trash uid=4759
doveadm(christoph): Debug: expunge: box=Trash uid=4760
doveadm(christoph): Debug: expunge: box=Trash uid=4761
doveadm(christoph): Debug: expunge: box=Trash uid=4762
doveadm(christoph): Debug: expunge: box=Trash uid=4763
doveadm(christoph): Debug: expunge: box=Trash uid=4764
doveadm(christoph): Debug: expunge: box=Trash uid=4765
doveadm(christoph): Debug: expunge: box=Trash uid=4766
doveadm(christoph): Debug: expunge: box=Trash uid=4767
doveadm(christoph): Debug: expunge: box=Trash uid=4768
doveadm(christoph): Debug: expunge: box=Trash uid=4769
doveadm(christoph): Debug: expunge: box=Trash uid=4770
doveadm(christoph): Debug: expunge: box=Trash uid=4771
doveadm(christoph): Debug: expunge: box=Trash uid=4772
doveadm(christoph): Debug: expunge: box=Trash uid=4773
doveadm(christoph): Debug: expunge: box=Trash uid=4774
doveadm(christoph): Debug: expunge: box=Trash uid=4775
doveadm(christoph): Debug: expunge: box=Trash uid=4776
doveadm(christoph): Debug: expunge: box=Trash uid=4777
doveadm(christoph): Debug: expunge: box=Trash uid=4778
doveadm(christoph): Debug: expunge: box=Trash uid=4779
doveadm(christoph): Debug: expunge: box=Trash uid=4780
doveadm(christoph): Debug: expunge: box=Trash uid=4781
doveadm(christoph): Debug: expunge: box=Trash uid=4782
doveadm(christoph): Debug: expunge: box=Trash uid=4783
doveadm(christoph): Debug: expunge: box=Trash uid=4784
doveadm(christoph): Debug: expunge: box=Trash uid=4785
doveadm(christoph): Debug: expunge: box=Trash uid=4786
doveadm(christoph): Debug: expunge: box=Trash uid=4787
doveadm(christoph): Debug: expunge: box=Trash uid=4788
doveadm(christoph): Debug: expunge: box=Trash uid=4789
doveadm(christoph): Debug: expunge: box=Trash uid=4790
doveadm(christoph): Debug: expunge: box=Trash uid=4791
doveadm(christoph): Debug: expunge: box=Trash uid=4792
doveadm(christoph): Debug: expunge: box=Trash uid=4793
doveadm(christoph): Debug: expunge: box=Trash uid=4794
doveadm(christoph): Debug: expunge: box=Trash uid=4795
doveadm(christoph): Debug: expunge: box=Trash uid=4796
doveadm(christoph): Debug: expunge: box=Trash uid=4797
doveadm(christoph): Debug: expunge: box=Trash uid=4798
doveadm(christoph): Debug: expunge: box=Trash uid=4799
doveadm(christoph): Debug: expire: Expunging first message in Trash, updating timestamp to 0
doveadm(christoph): Debug: expire: Stopping iteration on key shared/expire/christoph/Spam (1302158960 > 1302063905)

uid: 4800
uid: 4801
uid: 4802
uid: 4803
uid: 4804
uid: 4805
uid: 4806
uid: 4807
uid: 4808
uid: 4809
uid: 4810
uid: 4811
uid: 4812
uid: 4813
uid: 4814
uid: 4815
uid: 4816
uid: 4817
uid: 4818
uid: 4819
uid: 4820
uid: 4821
uid: 4822
uid: 4823
uid: 4824
uid: 4825
uid: 4826
uid: 4827
uid: 4828
uid: 4829
uid: 4830
uid: 4831
uid: 4832
uid: 4833
uid: 4834
uid: 4835
uid: 4836
uid: 4837
uid: 4838
uid: 4839
uid: 4840
uid: 4841
uid: 4842
uid: 4843
uid: 4844
uid: 4845
uid: 4846
uid: 4847
uid: 4848
uid: 4849
uid: 4850
uid: 4851
uid: 4852