[Dovecot] NFS issues

Brian Candler B.Candler at pobox.com
Thu Mar 25 12:58:34 EET 2010


On Tue, Mar 23, 2010 at 03:19:49PM +0200, Timo Sirainen wrote:
> > I have done some small-scale testing and it looks fine.
> 
> Stress testing by running imaptest for same user's same mailbox in 2+ different servers (i.e. two NFS clients reading/writing same mailbox files) should show up quickly what kind of errors you could get. http://imapwiki.org/ImapTest

OK, I've now set this up:

     ImapTest ---> dovecot (same host) -----> NFS server
             `---> dovecot (diff host) ----'

* 172.16.23.104: dovecot 1.2.11 and ImapTest-latest. FreeBSD 7.2.
* 172.16.23.101: dovecot 1.2.11 only. FreeBSD 7.2.
* 172.16.23.103: NFS server. Ubuntu Karmic.

All three hosts are ntpd synced.

The following was needed on the FreeBSD boxes to get fcntl locking working:

nfs_client_enable="YES"
rpc_lockd_enable="YES"
rpc_statd_enable="YES"

(imapd worked without these, but maillog showed errors about failing to
obtain locks, "operation not supported")

Test results
------------

* Pointing a single instance of imaptest at a single host, or two instances
of imaptest at the same host (with clients=5 to avoid hitting the 15 client
limit) was fine. ImapTest reported no errors, and nothing out of the ordinary
in maillog.

$ egrep -v "Login:|Disconnected:|Aborted login" /var/log/maillog

* Things went badly wrong with two instances of imaptest pointing at
different dovecot hosts.  I had seen this sort of thing when I'd previously
been using dot locking, and was hoping they'd be fixed by switching to
fcntl, but unfortunately not.

ImapTest reported errors including:

Error: brian at dev.example.com[8]: SELECT failed: 8.3 NO [SERVERBUG] Internal error occurred. Refer to server log for more information. [2010-03-25 10:22:23]
 - 6 stalled for 16 secs in command: 11 EXPUNGE

All sorts of errors reported in maillog, including:

Mar 25 10:22:23 freebsd-dev dovecot: IMAP(brian at dev.example.com): fscking index file /mail/0/6/37/30/brian%dev.example.com/dovecot.index
Mar 25 10:22:23 freebsd-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (10)
Mar 25 10:22:23 freebsd-dev dovecot: IMAP(brian at dev.example.com): Our dotlock file /mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist.lock was overridden (locked 0 secs ago, touched 0 secs ago)
Mar 25 10:22:23 freebsd-dev dovecot: IMAP(brian at dev.example.com): fscking index file /mail/0/6/37/30/brian%dev.example.com/dovecot.index
Mar 25 10:22:23 freebsd-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (11)
Mar 25 10:22:27 freebsd-dev dovecot: IMAP(brian at dev.example.com): /mail/0/6/37/30/brian%dev.example.com/dovecot.index reset, view is now inconsistent
Mar 25 10:22:46 freebsd-dev dovecot: IMAP(brian at dev.example.com): Panic: file mail-transaction-log-view.c: line 108 (mail_transaction_log_view_set): assertion failed: (min_file_seq <= max_file_seq)
Mar 25 10:22:48 freebsd-dev dovecot: IMAP(brian at dev.example.com): rename(/mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist.tmp, /mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist) failed: No such file or directory
Mar 25 10:22:48 freebsd-dev dovecot: IMAP(brian at dev.example.com): unlink(/mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist.tmp) failed: No such file or directory

Mar 25 10:22:36 wipe-dev dovecot: IMAP(brian at dev.example.com): ftruncate(/mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist.lock) failed: Stale NFS file handle

(Logs from a single test run are attached)

Interestingly, these messages imply that dovecot is still using dotlocking
in some circumstances, even though I've definitely set fcntl locking.

$ grep ^lock /usr/local/etc/dovecot.conf 
lock_method = fcntl

$ egrep '^mail_nfs|^mmap' /usr/local/etc/dovecot.conf 
mmap_disable = yes
mail_nfs_storage = yes
mail_nfs_index = yes

All this suggests I should use some sort of 'sticky' load balancing in front
so that all client conns from one IP hit the same frontend box.  However,
that contradicts the experience Adam McDougall has had with a similar setup:

http://dovecot.org/list/dovecot/2010-March/047815.html

It's possible that switching the Linux NFS server to a Netapp will help
(which is what it will be deployed onto eventually anyway)

Adam: did you do any tuning of FreeBSD client NFS settings? And have you
tried using ImapTest, or just real IMAP users?

I see there are a few tunables:

$ grep nfs /etc/defaults/rc.conf 
netfs_types="nfs:NFS nfs4:NFS4 smbfs:SMB portalfs:PORTAL nwfs:NWFS" # Net filesystems.
nfs_client_enable="NO"		# This host is an NFS client (or NO).
nfs_access_cache="60"		# Client cache timeout in seconds
nfs_server_enable="NO"		# This host is an NFS server (or NO).
nfs_server_flags="-u -t -n 4"	# Flags to nfsd (if enabled).
nfs_reserved_port_only="NO"	# Provide NFS only on secure port (or NO).
nfs_bufpackets=""		# bufspace (in packets) for client

I have tried rerunning with
    sysctl vfs.nfs.access_cache_timeout=0
but saw the same problems.

Maybe the load pattern from 'real' IMAP clients is such that these problems
generally don't show in practice?  (i.e.  it would be unusual for a single
IMAP client to make simultaneous changes to the same folder via different
TCP connections)

Regards,

Brian.
-------------- next part --------------
# 1.2.11: /usr/local/etc/dovecot.conf
# OS: FreeBSD 7.2-RELEASE i386  
base_dir: /var/run/dovecot/
protocols: imap imaps pop3 pop3s
ssl_cert_file: /etc/tisc/courier-imap/share/imapd.pem
ssl_key_file: /etc/tisc/courier-imap/share/imapd.pem
disable_plaintext_auth: no
login_dir: /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
login_user: nobody
verbose_proctitle: yes
first_valid_uid: 90
last_valid_uid: 90
first_valid_gid: 90
last_valid_gid: 90
mail_uid: exim
mail_gid: exim
mail_location: maildir:%h
mmap_disable: yes
mail_nfs_storage: yes
mail_nfs_index: 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_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
auth default:
  mechanisms: plain login
  passdb:
    driver: ldap
    args: /usr/local/etc/dovecot-ldap.conf
  userdb:
    driver: ldap
    args: /usr/local/etc/dovecot-ldap.conf
-------------- next part --------------
$ imaptest host=172.16.23.101 clients=5 user=brian at dev.example.com pass=xyzzy secs=60
Logi List Stat Sele Fetc Fet2 Stor Dele Expu Appe Logo 
100%  50%  50% 100% 100% 100%  50% 100% 100% 100% 100% 
                          30%                  5%      
   6    3    3    5    5    8    2    3    1    1    2   5/  5
   1    0    0    0    0    0    0    0    1    1    2   5/  5
   0    0    0    0    0    0    0    0    0    0    0   5/  5
   0    0    0    0    0    0    0    0    0    0    0   5/  5
   0    0    0    0    0    0    0    0    0    0    0   5/  5
   0    0    1    1    1    3    0    0    0    0    0   5/  5
Error: brian at dev.example.com[8]: SELECT failed: 8.3 NO [SERVERBUG] Internal error occurred. Refer to server log for more information. [2010-03-25 10:22:23]
   2    1    0    0    0    0    0    0    2    2    4   5/  5
   0    0    0    0    0    0    0    0    0    0    0   5/  5
   0    0    0    0    0    0    0    0    0    0    0   5/  5
Error: brian at dev.example.com[6]: Unexpected BYE: * BYE IMAP session state is inconsistent, please relogin.
Error: brian at dev.example.com[8]: APPEND failed: 8.4 NO [SERVERBUG] Internal error occurred. Refer to server log for more information. [2010-03-25 10:22:27]
Error: brian at dev.example.com[4]: Unexpected BYE: * BYE IMAP session state is inconsistent, please relogin.
   3    4    3    5    3    5    1    4    2    4   10   3/  5
Logi List Stat Sele Fetc Fet2 Stor Dele Expu Appe Logo 
100%  50%  50% 100% 100% 100%  50% 100% 100% 100% 100% 
                          30%                  5%      
   3    0    0    0    0    0    0    0    1    1    2   5/  5
   0    0    0    0    0    0    0    0    0    0    0   5/  5
   0    0    0    0    0    0    0    0    0    0    0   5/  5
   0    0    0    0    0    0    0    0    0    0    0   5/  5
   0    0    0    0    0    0    0    0    0    0    0   5/  5
Error: brian at dev.example.com[13]: SELECT failed: 13.3 NO [SERVERBUG] Internal error occurred. Refer to server log for more information. [2010-03-25 10:22:32]
Error: brian at dev.example.com[13]: APPEND failed: 13.4 NO [SERVERBUG] Internal error occurred. Refer to server log for more information. [2010-03-25 10:22:32]
Error: UIVALIDITY changed: 1269009321 -> 1269009316
   1    1    2    1    0    0    0    0    0    0    2   5/  5
   0    0    0    0    0    0    0    0    0    0    0   5/  5
   0    0    0    0    0    0    0    0    0    0    0   5/  5
Error: brian at dev.example.com[14]: Unexpected BYE: * BYE Mailbox UIDVALIDITY changed
   1    2    0    2    0    0    0    0    0    0    0   5/  5
Error: brian at dev.example.com[15]: Unexpected BYE: * BYE Mailbox UIDVALIDITY changed
Error: UIVALIDITY changed: 1269009316 -> 1269009321
   1    0    1    1    0    0    0    0    0    0    0   5/  5
Logi List Stat Sele Fetc Fet2 Stor Dele Expu Appe Logo 
100%  50%  50% 100% 100% 100%  50% 100% 100% 100% 100% 
                          30%                  5%      
   0    0    0    0    0    0    0    0    0    0    0   5/  5
   0    0    0    0    0    0    0    0    0    0    0   5/  5
   0    1    0    1    1    2    0    1    0    0    0   5/  5
   2    0    1    1    0    0    0    0    1    2    4   5/  5
   0    0    0    0    0    0    0    0    0    0    0   5/  5
   0    0    0    0    0    0    0    0    0    0    0   5/  5
 - 6 stalled for 16 secs in command: 11 EXPUNGE
 - 4 stalled for 16 secs in command: 9 EXPUNGE
Error: brian at dev.example.com[16]: UID=2276 MODSEQ dropped 30 -> 3: * 1 FETCH (MODSEQ (3) FLAGS (\Deleted \Seen \Draft $Label2 $Label5))
Error: brian at dev.example.com[16]: Unexpected BYE: * BYE IMAP session state is inconsistent, please relogin.
Error: brian at dev.example.com[19]: SELECT failed: 19.4 NO [SERVERBUG] Internal error occurred. Refer to server log for more information. [2010-03-25 10:22:44]
   1    1    1    0    1    1    0    1    0    0    0   5/  5
 - 6 stalled for 17 secs in command: 11 EXPUNGE
 - 4 stalled for 17 secs in command: 9 EXPUNGE
   4    2    1    4    3    3    2    2    1    3    6   5/  5
 - 6 stalled for 18 secs in command: 11 EXPUNGE
 - 4 stalled for 18 secs in command: 9 EXPUNGE
   0    0    0    0    0    0    0    0    0    0    0   5/  5
 - 6 stalled for 19 secs in command: 11 EXPUNGE
 - 4 stalled for 19 secs in command: 9 EXPUNGE
   0    0    0    0    0    0    0    0    0    0    0   5/  5
 - 6 stalled for 20 secs in command: 11 EXPUNGE
 - 4 stalled for 20 secs in command: 9 EXPUNGE
Logi List Stat Sele Fetc Fet2 Stor Dele Expu Appe Logo 
100%  50%  50% 100% 100% 100%  50% 100% 100% 100% 100% 
                          30%                  5%      
   0    0    0    0    0    0    0    0    0    0    0   5/  5
 - 6 stalled for 21 secs in command: 11 EXPUNGE
 - 4 stalled for 21 secs in command: 9 EXPUNGE
   1    1    1    2    2    4    0    1    2    1    2   5/  5
 - 6 stalled for 22 secs in command: 11 EXPUNGE
 - 4 stalled for 22 secs in command: 9 EXPUNGE
   0    0    0    0    0    0    0    0    0    0    0   5/  5
 - 6 stalled for 23 secs in command: 11 EXPUNGE
 - 4 stalled for 23 secs in command: 9 EXPUNGE
   0    0    0    0    0    0    0    0    0    0    0   5/  5
 - 6 stalled for 24 secs in command: 11 EXPUNGE
 - 4 stalled for 24 secs in command: 9 EXPUNGE
   1    0    0    0    0    0    0    0    1    1    2   5/  5
 - 6 stalled for 25 secs in command: 11 EXPUNGE
 - 4 stalled for 25 secs in command: 9 EXPUNGE
   0    0    0    0    0    0    0    0    0    0    0   5/  5
 - 6 stalled for 26 secs in command: 11 EXPUNGE
 - 4 stalled for 26 secs in command: 9 EXPUNGE
   0    0    0    0    0    0    0    0    0    0    0   5/  5
 - 6 stalled for 27 secs in command: 11 EXPUNGE
 - 4 stalled for 27 secs in command: 9 EXPUNGE
   0    0    0    0    0    0    0    0    0    0    0   5/  5
 - 6 stalled for 28 secs in command: 11 EXPUNGE
 - 4 stalled for 28 secs in command: 9 EXPUNGE
Error: brian at dev.example.com[27]: Unexpected BYE: * BYE IMAP session state is inconsistent, please relogin.
Error: brian at dev.example.com[25]: Unexpected BYE: * BYE IMAP session state is inconsistent, please relogin.
Error: UIVALIDITY changed: 1269009321 -> 1269009316
Error: brian at dev.example.com[26]: Unexpected BYE: * BYE IMAP session state is inconsistent, please relogin.
   4    2    3    5    2    3    0    1    0    1    2   5/  5
 - 6 stalled for 29 secs in command: 11 EXPUNGE
 - 4 stalled for 29 secs in command: 9 EXPUNGE
   0    0    0    0    1    1    0    1    1    0    0   5/  5
 - 6 stalled for 30 secs in command: 11 EXPUNGE
 - 4 stalled for 30 secs in command: 9 EXPUNGE
Logi List Stat Sele Fetc Fet2 Stor Dele Expu Appe Logo 
100%  50%  50% 100% 100% 100%  50% 100% 100% 100% 100% 
                          30%                  5%      
   0    0    0    0    0    0    0    0    0    0    0   5/  5
 - 6 stalled for 31 secs in command: 11 EXPUNGE
 - 4 stalled for 31 secs in command: 9 EXPUNGE
   0    0    0    0    2    2    0    2    1    0    0   5/  5
 - 6 stalled for 32 secs in command: 11 EXPUNGE
 - 4 stalled for 32 secs in command: 9 EXPUNGE
   3    0    0    1    1    1    0    1    2    3    6   5/  5
 - 6 stalled for 33 secs in command: 11 EXPUNGE
 - 4 stalled for 33 secs in command: 9 EXPUNGE
   0    0    0    0    0    0    0    0    0    0    0   5/  5
 - 6 stalled for 34 secs in command: 11 EXPUNGE
 - 4 stalled for 34 secs in command: 9 EXPUNGE
   0    0    0    0    0    0    0    0    0    0    0   5/  5
 - 6 stalled for 35 secs in command: 11 EXPUNGE
 - 4 stalled for 35 secs in command: 9 EXPUNGE
   0    1    0    2    0    0    0    0    0    0    0   5/  5
 - 6 stalled for 36 secs in command: 11 EXPUNGE
 - 4 stalled for 36 secs in command: 9 EXPUNGE
   0    0    0    0    1    2    1    0    0    0    0   5/  5
 - 6 stalled for 37 secs in command: 11 EXPUNGE
 - 4 stalled for 37 secs in command: 9 EXPUNGE
   0    0    0    0    0    0    0    0    0    0    0   5/  5
 - 6 stalled for 38 secs in command: 11 EXPUNGE
 - 4 stalled for 38 secs in command: 9 EXPUNGE
   2    1    1    1    2    4    1    1    1    2    4   5/  5
 - 6 stalled for 39 secs in command: 11 EXPUNGE
 - 4 stalled for 39 secs in command: 9 EXPUNGE
Error: brian at dev.example.com[36]: STORE failed: 36.7 NO [SERVERBUG] Internal error occurred. Refer to server log for more information. [2010-03-25 10:23:07]
   1    1    2    2    1    2    0    2    1    1    2   5/  5
 - 6 stalled for 40 secs in command: 11 EXPUNGE
 - 4 stalled for 40 secs in command: 9 EXPUNGE
Logi List Stat Sele Fetc Fet2 Stor Dele Expu Appe Logo 
100%  50%  50% 100% 100% 100%  50% 100% 100% 100% 100% 
                          30%                  5%      
   0    0    0    0    0    0    0    0    0    0    0   5/  5
 - 6 stalled for 41 secs in command: 11 EXPUNGE
 - 4 stalled for 41 secs in command: 9 EXPUNGE
   0    0    0    0    0    0    0    0    0    0    0   5/  5
 - 6 stalled for 42 secs in command: 11 EXPUNGE
 - 4 stalled for 42 secs in command: 9 EXPUNGE
   0    0    0    0    0    0    0    1    1    1    2   5/  5
 - 6 stalled for 43 secs in command: 11 EXPUNGE
 - 4 stalled for 43 secs in command: 9 EXPUNGE
   1    0    0    0    0    0    0    0    0    0    0   5/  5
 - 6 stalled for 44 secs in command: 11 EXPUNGE
 - 4 stalled for 44 secs in command: 9 EXPUNGE
   0    0    0    0    0    0    0    0    0    0    0   5/  5
 - 6 stalled for 45 secs in command: 11 EXPUNGE
 - 4 stalled for 45 secs in command: 9 EXPUNGE
   0    0    0    0    0    0    0    0    0    0    0   5/  5
 - 6 stalled for 46 secs in command: 11 EXPUNGE
 - 4 stalled for 46 secs in command: 9 EXPUNGE
Error: brian at dev.example.com[36]: APPEND failed: 36.9 NO [SERVERBUG] Internal error occurred. Refer to server log for more information. [2010-03-25 10:23:14]
   1    1    1    1    2    2    1    1    1    0    2   5/  5
 - 6 stalled for 47 secs in command: 11 EXPUNGE
 - 4 stalled for 47 secs in command: 9 EXPUNGE
   3    1    1    4    3    4    1    3    3    3    6   5/  5
 - 6 stalled for 48 secs in command: 11 EXPUNGE
 - 4 stalled for 48 secs in command: 9 EXPUNGE
   1    0    0    0    1    1    1    0    1    1    2   5/  5
 - 6 stalled for 49 secs in command: 11 EXPUNGE
 - 4 stalled for 49 secs in command: 9 EXPUNGE
   0    0    0    0    0    0    0    0    0    0    0   5/  5
 - 6 stalled for 50 secs in command: 11 EXPUNGE
 - 4 stalled for 50 secs in command: 9 EXPUNGE
Logi List Stat Sele Fetc Fet2 Stor Dele Expu Appe Logo 
100%  50%  50% 100% 100% 100%  50% 100% 100% 100% 100% 
                          30%                  5%      
   0    0    0    0    0    0    0    0    0    0    0   5/  5
 - 6 stalled for 51 secs in command: 11 EXPUNGE
 - 4 stalled for 51 secs in command: 9 EXPUNGE
   0    0    0    1    0    0    0    0    1    1    4   3/  3
 - 6 stalled for 52 secs in command: 11 EXPUNGE
 - 4 stalled for 52 secs in command: 9 EXPUNGE
^C
Totals:
Logi List Stat Sele Fetc Fet2 Stor Dele Expu Appe Logo 
100%  50%  50% 100% 100% 100%  50% 100% 100% 100% 100% 
                          30%                  5%      
  43   23   22   40   32   48   10   25   25   29   66 
-------------- next part --------------
$ imaptest host=172.16.23.104 clients=5 user=brian at dev.example.com pass=xyzzy secs=60
Logi List Stat Sele Fetc Fet2 Stor Dele Expu Appe Logo 
100%  50%  50% 100% 100% 100%  50% 100% 100% 100% 100% 
                          30%                  5%      
   5    2    2    3    1    3    0    0    0    0    0   5/  5
   0    0    0    0    0    0    0    0    0    0    0   5/  5
   0    0    0    0    0    0    0    0    0    0    0   5/  5
   0    0    0    0    0    0    0    0    0    0    0   5/  5
   1    1    1    2    3    3    1    2    1    1    2   5/  5
   0    0    0    0    0    0    0    0    0    0    0   5/  5
   0    0    0    0    0    0    0    0    0    0    0   5/  5
   0    0    0    0    0    0    0    0    0    0    0   5/  5
Error: brian at dev.example.com[2]: Unexpected BYE: * BYE IMAP session state is inconsistent, please relogin.
   1    1    2    2    0    0    0    0    0    0    0   5/  5
Error: brian at dev.example.com[3]: Unexpected BYE: * BYE IMAP session state is inconsistent, please relogin.
Error: brian at dev.example.com[1]: Unexpected BYE: * BYE IMAP session state is inconsistent, please relogin.
Error: brian at dev.example.com[4]: Unexpected BYE: * BYE IMAP session state is inconsistent, please relogin.
   5    0    1    3    3    3    0    4    1    2    4   5/  5
Error: brian at dev.example.com[10]: SELECT failed: 10.3 NO [SERVERBUG] Internal error occurred. Refer to server log for more information. [2010-03-25 10:22:28]
Logi List Stat Sele Fetc Fet2 Stor Dele Expu Appe Logo 
100%  50%  50% 100% 100% 100%  50% 100% 100% 100% 100% 
                          30%                  5%      
   3    1    1    1    1    2    0    1    1    3    6   5/  5
   0    0    0    0    0    0    0    0    0    0    0   5/  5
   0    0    0    0    0    0    0    0    0    0    0   5/  5
   2    1    1    2    1    1    1    1    2    2    4   5/  5
   0    0    1    1    0    0    0    0    0    0    0   5/  5
   0    0    0    0    0    0    0    0    0    0    0   5/  5
   0    0    0    0    0    0    0    0    0    0    0   5/  5
Error: brian at dev.example.com[13]: Unexpected BYE: * BYE IMAP session state is inconsistent, please relogin.
   2    0    1    1    2    3    0    0    1    1    2   5/  5
Error: brian at dev.example.com[16]: Unexpected BYE: * BYE IMAP session state is inconsistent, please relogin.
   2    1    3    4    3    4    1    1    1    1    2   5/  5
   0    0    0    0    0    0    0    0    0    0    0   5/  5
Logi List Stat Sele Fetc Fet2 Stor Dele Expu Appe Logo 
100%  50%  50% 100% 100% 100%  50% 100% 100% 100% 100% 
                          30%                  5%      
   0    0    0    0    0    0    0    0    0    0    0   5/  5
   0    0    0    0    0    0    0    0    0    0    0   5/  5
Error: brian at dev.example.com[14]: Unexpected BYE: * BYE IMAP session state is inconsistent, please relogin.
   5    0    2    3    5    7    0    4    3    3    6   4/  5
   1    0    0    0    0    0    0    0    0    0    0   5/  5
   0    0    0    0    0    0    0    0    0    0    0   5/  5
   0    0    0    0    0    0    0    0    0    0    0   5/  5
   0    0    1    1    0    0    0    0    0    0    0   5/  5
   0    0    0    0    0    0    0    0    0    0    0   5/  5
   0    0    0    0    0    0    0    0    0    0    0   5/  5
   0    1    1    1    0    0    0    0    0    0    0   5/  5
Error: brian at dev.example.com[25]: EXPUNGE failed: 25.8 NO [SERVERBUG] Internal error occurred. Refer to server log for more information. [2010-03-25 10:22:48]
Logi List Stat Sele Fetc Fet2 Stor Dele Expu Appe Logo 
100%  50%  50% 100% 100% 100%  50% 100% 100% 100% 100% 
                          30%                  5%      
   1    1    1    1    1    1    0    1    1    1    2   5/  5
   0    0    0    0    0    0    0    0    0    0    0   5/  5
   0    0    0    0    0    0    0    0    0    0    0   5/  5
   0    0    0    0    0    0    0    0    0    0    0   5/  5
   0    0    0    0    0    0    0    0    0    0    0   5/  5
 - 17 stalled for 16 secs in command: 8 STORE 1,3 +FLAGS \Deleted
   0    0    0    0    0    0    0    0    0    0    0   5/  5
 - 17 stalled for 17 secs in command: 8 STORE 1,3 +FLAGS \Deleted
   0    0    0    0    0    0    0    0    0    0    0   5/  5
 - 17 stalled for 18 secs in command: 8 STORE 1,3 +FLAGS \Deleted
Error: UIVALIDITY changed: 1269009321 -> 1269009316
Error: brian at dev.example.com[17]: Unexpected BYE: * BYE IMAP session state is inconsistent, please relogin.
   1    2    1    3    1    3    0    1    0    0    0   5/  5
   0    0    0    0    0    0    0    0    0    0    0   5/  5
   0    0    0    0    0    0    0    0    0    0    0   5/  5
Logi List Stat Sele Fetc Fet2 Stor Dele Expu Appe Logo 
100%  50%  50% 100% 100% 100%  50% 100% 100% 100% 100% 
                          30%                  5%      
   0    0    0    0    0    0    0    0    0    0    0   5/  5
   2    0    0    0    0    1    0    1    1    2    4   5/  5
   0    0    0    0    0    0    0    0    0    0    0   5/  5
   0    0    0    0    0    0    0    0    0    0    0   5/  5
   0    0    0    0    0    0    0    0    0    0    0   5/  5
   0    0    0    0    0    0    0    0    0    0    0   5/  5
 - 25 stalled for 16 secs in command: 5 FETCH 1:2 (BODY ENVELOPE BODYSTRUCTURE)
   0    0    0    0    0    0    0    0    0    0    0   5/  5
 - 25 stalled for 17 secs in command: 5 FETCH 1:2 (BODY ENVELOPE BODYSTRUCTURE)
 - 26 stalled for 16 secs in command: 5 FETCH 2:3 (UID INTERNALDATE BODY.PEEK[HEADER.FIELDS (Cc References Cc)])
   0    1    0    1    0    0    0    0    0    0    0   5/  5
 - 25 stalled for 18 secs in command: 5 FETCH 1:2 (BODY ENVELOPE BODYSTRUCTURE)
 - 26 stalled for 17 secs in command: 5 FETCH 2:3 (UID INTERNALDATE BODY.PEEK[HEADER.FIELDS (Cc References Cc)])
   3    0    2    2    1    2    0    1    1    3    6   5/  5
 - 25 stalled for 19 secs in command: 5 FETCH 1:2 (BODY ENVELOPE BODYSTRUCTURE)
 - 26 stalled for 18 secs in command: 5 FETCH 2:3 (UID INTERNALDATE BODY.PEEK[HEADER.FIELDS (Cc References Cc)])
   0    0    0    0    0    0    0    0    0    0    0   5/  5
 - 25 stalled for 20 secs in command: 5 FETCH 1:2 (BODY ENVELOPE BODYSTRUCTURE)
 - 26 stalled for 19 secs in command: 5 FETCH 2:3 (UID INTERNALDATE BODY.PEEK[HEADER.FIELDS (Cc References Cc)])
Logi List Stat Sele Fetc Fet2 Stor Dele Expu Appe Logo 
100%  50%  50% 100% 100% 100%  50% 100% 100% 100% 100% 
                          30%                  5%      
   0    0    0    0    0    0    0    0    0    0    0   5/  5
 - 25 stalled for 21 secs in command: 5 FETCH 1:2 (BODY ENVELOPE BODYSTRUCTURE)
 - 26 stalled for 20 secs in command: 5 FETCH 2:3 (UID INTERNALDATE BODY.PEEK[HEADER.FIELDS (Cc References Cc)])
   0    0    0    0    1    1    1    1    0    0    0   5/  5
 - 25 stalled for 22 secs in command: 5 FETCH 1:2 (BODY ENVELOPE BODYSTRUCTURE)
   0    0    0    0    0    0    0    0    0    0    0   5/  5
 - 25 stalled for 23 secs in command: 5 FETCH 1:2 (BODY ENVELOPE BODYSTRUCTURE)
   0    0    0    0    0    0    0    0    0    0    0   5/  5
 - 25 stalled for 24 secs in command: 5 FETCH 1:2 (BODY ENVELOPE BODYSTRUCTURE)
   0    0    0    0    0    0    0    0    0    0    0   5/  5
 - 25 stalled for 25 secs in command: 5 FETCH 1:2 (BODY ENVELOPE BODYSTRUCTURE)
Error: brian at dev.example.com[26]: Unexpected BYE: * BYE IMAP session state is inconsistent, please relogin.
Error: brian at dev.example.com[34]: APPEND failed: 34.9 NO [SERVERBUG] Internal error occurred. Refer to server log for more information. [2010-03-25 10:23:14]
   4    2    2    4    4    4    0    2    3    3    8   4/  5
 - 25 stalled for 26 secs in command: 5 FETCH 1:2 (BODY ENVELOPE BODYSTRUCTURE)
Error: brian at dev.example.com[37]: SELECT failed: 37.3 NO [SERVERBUG] Internal error occurred. Refer to server log for more information. [2010-03-25 10:23:14]
Error: brian at dev.example.com[25]: Unexpected BYE: * BYE IMAP session state is inconsistent, please relogin.
   4    0    1    1    1    2    0    0    1    2    4   5/  5
   3    2    2    5    5    6    1    3    4    3    6   5/  5
   0    0    0    0    0    0    0    0    0    0    0   5/  5
   0    0    0    0    0    0    0    0    0    0    0   5/  5
^C
Totals:
Logi List Stat Sele Fetc Fet2 Stor Dele Expu Appe Logo 
100%  50%  50% 100% 100% 100%  50% 100% 100% 100% 100% 
                          30%                  5%      
  45   16   26   41   33   46    5   23   21   27   56 
-------------- next part --------------
Mar 25 10:22:23 freebsd-dev dovecot: IMAP(brian at dev.example.com): fscking index file /mail/0/6/37/30/brian%dev.example.com/dovecot.index
Mar 25 10:22:23 freebsd-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (10)
Mar 25 10:22:23 freebsd-dev dovecot: IMAP(brian at dev.example.com): Our dotlock file /mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist.lock was overridden (locked 0 secs ago, touched 0 secs ago)
Mar 25 10:22:23 freebsd-dev dovecot: IMAP(brian at dev.example.com): fscking index file /mail/0/6/37/30/brian%dev.example.com/dovecot.index
Mar 25 10:22:23 freebsd-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (11)
Mar 25 10:22:27 freebsd-dev dovecot: IMAP(brian at dev.example.com): /mail/0/6/37/30/brian%dev.example.com/dovecot.index reset, view is now inconsistent
Mar 25 10:22:27 freebsd-dev dovecot: IMAP(brian at dev.example.com): Log synchronization error at seq=11,offset=188 for /mail/0/6/37/30/brian%dev.example.com/dovecot.index: uid_validity updated unexpectedly: 1269009321 -> 1269009321
Mar 25 10:22:27 freebsd-dev dovecot: IMAP(brian at dev.example.com): Log synchronization error at seq=11,offset=204 for /mail/0/6/37/30/brian%dev.example.com/dovecot.index: Append with UID 2257, but next_uid = 2260
Mar 25 10:22:27 freebsd-dev dovecot: IMAP(brian at dev.example.com): /mail/0/6/37/30/brian%dev.example.com/dovecot.index reset, view is now inconsistent
Mar 25 10:22:27 freebsd-dev dovecot: IMAP(brian at dev.example.com): Log synchronization error at seq=11,offset=188 for /mail/0/6/37/30/brian%dev.example.com/dovecot.index: uid_validity updated unexpectedly: 1269009321 -> 1269009321
Mar 25 10:22:27 freebsd-dev dovecot: IMAP(brian at dev.example.com): Log synchronization error at seq=11,offset=204 for /mail/0/6/37/30/brian%dev.example.com/dovecot.index: Append with UID 2257, but next_uid = 2260
Mar 25 10:22:27 freebsd-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (11)
Mar 25 10:22:27 freebsd-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (11)
Mar 25 10:22:28 freebsd-dev last message repeated 2 times
Mar 25 10:22:32 freebsd-dev dovecot: IMAP(brian at dev.example.com): /mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist: Duplicate file entry at line 5: 1269512543.M590622P26230.wipe-dev.localdomain,S=1258,W=1290:2, (uid 2264 -> 2276)
Mar 25 10:22:32 freebsd-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (11)
Mar 25 10:22:32 freebsd-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (11)
Mar 25 10:22:32 freebsd-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (11)
Mar 25 10:22:32 freebsd-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (11)
Mar 25 10:22:32 freebsd-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (11)
Mar 25 10:22:32 freebsd-dev dovecot: IMAP(brian at dev.example.com): Maildir /mail/0/6/37/30/brian%dev.example.com: UIDVALIDITY changed (1269009321 -> 1269009316)
Mar 25 10:22:33 freebsd-dev dovecot: IMAP(brian at dev.example.com): dotlock /mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist.lock was immediately recreated under us
Mar 25 10:22:36 freebsd-dev dovecot: IMAP(brian at dev.example.com): /mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist: Duplicate file entry at line 2: 1269512543.M590622P26230.wipe-dev.localdomain,S=1258,W=1290:2, (uid 2264 -> 2276)
Mar 25 10:22:36 freebsd-dev dovecot: IMAP(brian at dev.example.com): /mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist: Duplicate file entry at line 2: 1269512543.M590622P26230.wipe-dev.localdomain,S=1258,W=1290:2, (uid 2264 -> 2276)
Mar 25 10:22:36 freebsd-dev dovecot: IMAP(brian at dev.example.com): Broken file /mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist line 1: next_uid header was lowered (2278 -> 1557)
Mar 25 10:22:36 freebsd-dev dovecot: IMAP(brian at dev.example.com): /mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist: Duplicate file entry at line 2: 1269512556.M391298P57620.freebsd-dev.uk.intranet,S=2051,W=2105:2, (uid 2277 -> 2278)
Mar 25 10:22:37 freebsd-dev dovecot: IMAP(brian at dev.example.com): /mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist: Duplicate file entry at line 2: 1269512556.M439153P57621.freebsd-dev.uk.intranet,S=2116,W=2170:2,DRSa (uid 2278 -> 2279)
Mar 25 10:22:37 freebsd-dev dovecot: IMAP(brian at dev.example.com): dotlock /mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist.lock was immediately recreated under us
Mar 25 10:22:41 freebsd-dev dovecot: IMAP(brian at dev.example.com): fscking index file /mail/0/6/37/30/brian%dev.example.com/dovecot.index
Mar 25 10:22:41 freebsd-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (13)
Mar 25 10:22:41 freebsd-dev dovecot: IMAP(brian at dev.example.com): Our dotlock file /mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist.lock was overridden (locked 0 secs ago, touched 0 secs ago)
Mar 25 10:22:44 freebsd-dev dovecot: IMAP(brian at dev.example.com): /mail/0/6/37/30/brian%dev.example.com/dovecot.index reset, view is now inconsistent
Mar 25 10:22:44 freebsd-dev dovecot: IMAP(brian at dev.example.com): rename(/mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist.tmp, /mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist) failed: No such file or directory
Mar 25 10:22:44 freebsd-dev dovecot: IMAP(brian at dev.example.com): unlink(/mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist.tmp) failed: No such file or directory
Mar 25 10:22:45 freebsd-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (14)
Mar 25 10:22:45 freebsd-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (14)
Mar 25 10:22:45 freebsd-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (14)
Mar 25 10:22:45 freebsd-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (14)
Mar 25 10:22:45 freebsd-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (14)
Mar 25 10:22:45 freebsd-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (14)
Mar 25 10:22:45 freebsd-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (14)
Mar 25 10:22:45 freebsd-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (14)
Mar 25 10:22:45 freebsd-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (14)
Mar 25 10:22:45 freebsd-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (14)
Mar 25 10:22:45 freebsd-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (14)
Mar 25 10:22:45 freebsd-dev dovecot: IMAP(brian at dev.example.com): Sending log messages too fast, throttling..
Mar 25 10:22:45 freebsd-dev dovecot: dovecot: child 57629 (imap) killed with signal 6 (core not dumped - set mail_drop_priv_before_exec=yes)
Mar 25 10:22:46 freebsd-dev dovecot: IMAP(brian at dev.example.com): Panic: file mail-transaction-log-view.c: line 108 (mail_transaction_log_view_set): assertion failed: (min_file_seq <= max_file_seq)
Mar 25 10:22:48 freebsd-dev dovecot: IMAP(brian at dev.example.com): rename(/mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist.tmp, /mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist) failed: No such file or directory
Mar 25 10:22:48 freebsd-dev dovecot: IMAP(brian at dev.example.com): unlink(/mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist.tmp) failed: No such file or directory
Mar 25 10:22:49 freebsd-dev dovecot: IMAP(brian at dev.example.com): rename(/mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist.tmp, /mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist) failed: No such file or directory
Mar 25 10:22:49 freebsd-dev dovecot: IMAP(brian at dev.example.com): unlink(/mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist.tmp) failed: No such file or directory
Mar 25 10:22:49 freebsd-dev dovecot: IMAP(brian at dev.example.com): Our dotlock file /mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist.lock was overridden (locked 0 secs ago, touched 0 secs ago)
Mar 25 10:22:52 freebsd-dev dovecot: IMAP(brian at dev.example.com): dotlock /mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist.lock was immediately recreated under us
Mar 25 10:22:55 freebsd-dev dovecot: IMAP(brian at dev.example.com): Maildir /mail/0/6/37/30/brian%dev.example.com: UIDVALIDITY changed (1269009321 -> 1269009316)
Mar 25 10:22:55 freebsd-dev dovecot: IMAP(brian at dev.example.com): /mail/0/6/37/30/brian%dev.example.com/dovecot.index reset, view is now inconsistent
Mar 25 10:22:56 freebsd-dev dovecot: IMAP(brian at dev.example.com): /mail/0/6/37/30/brian%dev.example.com/dovecot.index reset, view is now inconsistent
Mar 25 10:22:56 freebsd-dev dovecot: IMAP(brian at dev.example.com): /mail/0/6/37/30/brian%dev.example.com/dovecot.index reset, view is now inconsistent
Mar 25 10:22:56 freebsd-dev dovecot: IMAP(brian at dev.example.com): Log synchronization error at seq=15,offset=124 for /mail/0/6/37/30/brian%dev.example.com/dovecot.index: uid_validity updated unexpectedly: 1269009321 -> 1269009316
Mar 25 10:22:56 freebsd-dev dovecot: IMAP(brian at dev.example.com): Log synchronization error at seq=15,offset=140 for /mail/0/6/37/30/brian%dev.example.com/dovecot.index: Append with UID 2296, but next_uid = 2299
Mar 25 10:22:56 freebsd-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (15)
Mar 25 10:22:56 freebsd-dev dovecot: IMAP(brian at dev.example.com): Our dotlock file /mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist.lock was deleted (locked 0 secs ago, touched 0 secs ago)
Mar 25 10:22:59 freebsd-dev dovecot: IMAP(brian at dev.example.com): /mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist: next_uid was lowered (2304 -> 2303, hdr=2303)
Mar 25 10:23:00 freebsd-dev dovecot: IMAP(brian at dev.example.com): /mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist: Duplicate file entry at line 4: 1269512579.M684036P57650.freebsd-dev.uk.intranet,S=2145,W=2200:2,DRSae (uid 2303 -> 2306)
Mar 25 10:23:00 freebsd-dev dovecot: IMAP(brian at dev.example.com): unlink(/mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist.lock) failed: Input/output error
Mar 25 10:23:03 freebsd-dev dovecot: IMAP(brian at dev.example.com): Our dotlock file /mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist.lock was overridden (locked 0 secs ago, touched 0 secs ago)
Mar 25 10:23:07 freebsd-dev dovecot: IMAP(brian at dev.example.com): Our dotlock file /mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist.lock was overridden (locked 0 secs ago, touched 0 secs ago)
Mar 25 10:23:07 freebsd-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (15)
Mar 25 10:23:07 freebsd-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (15)
Mar 25 10:23:07 freebsd-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (15)
Mar 25 10:23:07 freebsd-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (15)
Mar 25 10:23:07 freebsd-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (15)
Mar 25 10:23:07 freebsd-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (15)
Mar 25 10:23:07 freebsd-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (15)
Mar 25 10:23:07 freebsd-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (15)
Mar 25 10:23:07 freebsd-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (15)
Mar 25 10:23:07 freebsd-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (15)
Mar 25 10:23:07 freebsd-dev dovecot: IMAP(brian at dev.example.com): Sending log messages too fast, throttling..
Mar 25 10:23:08 freebsd-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (15)
Mar 25 10:23:08 freebsd-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (15)
Mar 25 10:23:14 freebsd-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (15)
Mar 25 10:23:14 freebsd-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (15)
Mar 25 10:23:14 freebsd-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (15)
Mar 25 10:23:14 freebsd-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (15)
Mar 25 10:23:14 freebsd-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (15)
Mar 25 10:23:14 freebsd-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (15)
Mar 25 10:23:16 freebsd-dev dovecot: IMAP(brian at dev.example.com): unlink(/mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist.lock) failed: Input/output error
Mar 25 10:23:19 freebsd-dev dovecot: IMAP(brian at dev.example.com): Our dotlock file /mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist.lock was overridden (locked 0 secs ago, touched 0 secs ago)
Mar 25 10:23:22 freebsd-dev dovecot: IMAP(brian at dev.example.com): Connection closed bytes=1710/5968
-------------- next part --------------
Mar 25 10:22:19 wipe-dev dovecot: IMAP(brian at dev.example.com): Our dotlock file /mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist.lock was overridden (locked 0 secs ago, touched 0 secs ago)
Mar 25 10:22:23 wipe-dev dovecot: IMAP(brian at dev.example.com): Our dotlock file /mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist.lock was overridden (locked 0 secs ago, touched 0 secs ago)
Mar 25 10:22:27 wipe-dev dovecot: IMAP(brian at dev.example.com): /mail/0/6/37/30/brian%dev.example.com/dovecot.index reset, view is now inconsistent
Mar 25 10:22:27 wipe-dev dovecot: IMAP(brian at dev.example.com): Log synchronization error at seq=11,offset=188 for /mail/0/6/37/30/brian%dev.example.com/dovecot.index: uid_validity updated unexpectedly: 1269009321 -> 1269009321
Mar 25 10:22:27 wipe-dev dovecot: IMAP(brian at dev.example.com): Log synchronization error at seq=11,offset=204 for /mail/0/6/37/30/brian%dev.example.com/dovecot.index: Append with UID 2257, but next_uid = 2258
Mar 25 10:22:27 wipe-dev dovecot: IMAP(brian at dev.example.com): /mail/0/6/37/30/brian%dev.example.com/dovecot.index reset, view is now inconsistent
Mar 25 10:22:27 wipe-dev dovecot: IMAP(brian at dev.example.com): Log synchronization error at seq=11,offset=188 for /mail/0/6/37/30/brian%dev.example.com/dovecot.index: uid_validity updated unexpectedly: 1269009321 -> 1269009321
Mar 25 10:22:27 wipe-dev dovecot: IMAP(brian at dev.example.com): Log synchronization error at seq=11,offset=204 for /mail/0/6/37/30/brian%dev.example.com/dovecot.index: Append with UID 2257, but next_uid = 2260
Mar 25 10:22:28 wipe-dev dovecot: IMAP(brian at dev.example.com): /mail/0/6/37/30/brian%dev.example.com/dovecot.index reset, view is now inconsistent
Mar 25 10:22:28 wipe-dev dovecot: IMAP(brian at dev.example.com): Log synchronization error at seq=11,offset=188 for /mail/0/6/37/30/brian%dev.example.com/dovecot.index: uid_validity updated unexpectedly: 1269009321 -> 1269009321
Mar 25 10:22:28 wipe-dev dovecot: IMAP(brian at dev.example.com): Log synchronization error at seq=11,offset=204 for /mail/0/6/37/30/brian%dev.example.com/dovecot.index: Append with UID 2257, but next_uid = 2260
Mar 25 10:22:28 wipe-dev dovecot: IMAP(brian at dev.example.com): rename(/mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist.tmp, /mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist) failed: No such file or directory
Mar 25 10:22:28 wipe-dev dovecot: IMAP(brian at dev.example.com): unlink(/mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist.tmp) failed: No such file or directory
Mar 25 10:22:28 wipe-dev dovecot: IMAP(brian at dev.example.com): /mail/0/6/37/30/brian%dev.example.com/dovecot.index reset, view is now inconsistent
Mar 25 10:22:28 wipe-dev dovecot: IMAP(brian at dev.example.com): Log synchronization error at seq=11,offset=188 for /mail/0/6/37/30/brian%dev.example.com/dovecot.index: uid_validity updated unexpectedly: 1269009321 -> 1269009321
Mar 25 10:22:28 wipe-dev dovecot: IMAP(brian at dev.example.com): Log synchronization error at seq=11,offset=204 for /mail/0/6/37/30/brian%dev.example.com/dovecot.index: Append with UID 2257, but next_uid = 2260
Mar 25 10:22:28 wipe-dev dovecot: IMAP(brian at dev.example.com): rename(/mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist.tmp, /mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist) failed: No such file or directory
Mar 25 10:22:28 wipe-dev dovecot: IMAP(brian at dev.example.com): unlink(/mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist.tmp) failed: No such file or directory
Mar 25 10:22:29 wipe-dev dovecot: IMAP(brian at dev.example.com): Our dotlock file /mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist.lock was deleted (locked 0 secs ago, touched 0 secs ago)
Mar 25 10:22:36 wipe-dev dovecot: IMAP(brian at dev.example.com): ftruncate(/mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist.lock) failed: Stale NFS file handle
Mar 25 10:22:36 wipe-dev dovecot: IMAP(brian at dev.example.com): file_dotlock_create(/mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist) failed: Stale NFS file handle
Mar 25 10:22:36 wipe-dev dovecot: IMAP(brian at dev.example.com): Maildir /mail/0/6/37/30/brian%dev.example.com: UIDVALIDITY changed (1269009316 -> 1269009321)
Mar 25 10:22:36 wipe-dev dovecot: IMAP(brian at dev.example.com): /mail/0/6/37/30/brian%dev.example.com/dovecot.index reset, view is now inconsistent
Mar 25 10:22:37 wipe-dev dovecot: IMAP(brian at dev.example.com): /mail/0/6/37/30/brian%dev.example.com/dovecot.index reset, view is now inconsistent
Mar 25 10:22:37 wipe-dev dovecot: IMAP(brian at dev.example.com): Log synchronization error at seq=13,offset=124 for /mail/0/6/37/30/brian%dev.example.com/dovecot.index: uid_validity updated unexpectedly: 1269009321 -> 1269009321
Mar 25 10:22:37 wipe-dev dovecot: IMAP(brian at dev.example.com): Log synchronization error at seq=13,offset=140 for /mail/0/6/37/30/brian%dev.example.com/dovecot.index: Append with UID 2271, but next_uid = 2281
Mar 25 10:22:41 wipe-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (13)
Mar 25 10:22:41 wipe-dev dovecot: IMAP(brian at dev.example.com): Panic: file mail-transaction-log-view.c: line 108 (mail_transaction_log_view_set): assertion failed: (min_file_seq <= max_file_seq)
Mar 25 10:22:41 wipe-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (13)
Mar 25 10:22:41 wipe-dev dovecot: IMAP(brian at dev.example.com): Panic: file mail-transaction-log-view.c: line 108 (mail_transaction_log_view_set): assertion failed: (min_file_seq <= max_file_seq)
Mar 25 10:22:41 wipe-dev dovecot: dovecot: child 26275 (imap) killed with signal 6 (core not dumped - set mail_drop_priv_before_exec=yes)
Mar 25 10:22:41 wipe-dev dovecot: dovecot: child 26276 (imap) killed with signal 6 (core not dumped - set mail_drop_priv_before_exec=yes)
Mar 25 10:22:41 wipe-dev dovecot: IMAP(brian at dev.example.com): /mail/0/6/37/30/brian%dev.example.com/dovecot.index reset, view is now inconsistent
Mar 25 10:22:45 wipe-dev dovecot: IMAP(brian at dev.example.com): /mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist: Duplicate file entry at line 5: 1269512560.M758222P57625.freebsd-dev.uk.intranet,S=2442,W=2493:2,DSTae (uid 2287 -> 2293)
Mar 25 10:22:45 wipe-dev dovecot: IMAP(brian at dev.example.com): rename(/mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist.tmp, /mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist) failed: No such file or directory
Mar 25 10:22:45 wipe-dev dovecot: IMAP(brian at dev.example.com): unlink(/mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist.tmp) failed: No such file or directory
Mar 25 10:22:45 wipe-dev dovecot: IMAP(brian at dev.example.com): Our dotlock file /mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist.lock was overridden (locked 0 secs ago, touched 0 secs ago)
Mar 25 10:22:48 wipe-dev dovecot: IMAP(brian at dev.example.com): /mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist: Duplicate file entry at line 5: 1269512560.M758222P57625.freebsd-dev.uk.intranet,S=2442,W=2493:2,DSTae (uid 2287 -> 2293)
Mar 25 10:22:48 wipe-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (14)
Mar 25 10:22:48 wipe-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (14)
Mar 25 10:22:48 wipe-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (14)
Mar 25 10:22:48 wipe-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (14)
Mar 25 10:22:48 wipe-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (14)
Mar 25 10:22:48 wipe-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (14)
Mar 25 10:22:48 wipe-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (14)
Mar 25 10:22:48 wipe-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (14)
Mar 25 10:22:48 wipe-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (14)
Mar 25 10:22:48 wipe-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (14)
Mar 25 10:22:48 wipe-dev dovecot: IMAP(brian at dev.example.com): Sending log messages too fast, throttling..
Mar 25 10:22:56 wipe-dev dovecot: IMAP(brian at dev.example.com): /mail/0/6/37/30/brian%dev.example.com/dovecot.index reset, view is now inconsistent
Mar 25 10:22:56 wipe-dev dovecot: IMAP(brian at dev.example.com): Log synchronization error at seq=15,offset=124 for /mail/0/6/37/30/brian%dev.example.com/dovecot.index: uid_validity updated unexpectedly: 1269009321 -> 1269009316
Mar 25 10:22:56 wipe-dev dovecot: IMAP(brian at dev.example.com): Log synchronization error at seq=15,offset=140 for /mail/0/6/37/30/brian%dev.example.com/dovecot.index: Append with UID 2296, but next_uid = 2299
Mar 25 10:23:00 wipe-dev dovecot: IMAP(brian at dev.example.com): Broken file /mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist line 1: next_uid header was lowered (2309 -> 1557)
Mar 25 10:23:10 wipe-dev dovecot: IMAP(brian at dev.example.com): unlink(/mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist.lock) failed: Input/output error
Mar 25 10:23:14 wipe-dev dovecot: IMAP(brian at dev.example.com): Broken file /mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist line 1: next_uid header was lowered (2320 -> 1557)
Mar 25 10:23:14 wipe-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (15)
Mar 25 10:23:14 wipe-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (15)
Mar 25 10:23:14 wipe-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (15)
Mar 25 10:23:14 wipe-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (15)
Mar 25 10:23:14 wipe-dev dovecot: IMAP(brian at dev.example.com): /mail/0/6/37/30/brian%dev.example.com/dovecot.index reset, view is now inconsistent
Mar 25 10:23:14 wipe-dev dovecot: IMAP(brian at dev.example.com): Log synchronization error at seq=15,offset=124 for /mail/0/6/37/30/brian%dev.example.com/dovecot.index: uid_validity updated unexpectedly: 1269009321 -> 1269009316
Mar 25 10:23:14 wipe-dev dovecot: IMAP(brian at dev.example.com): Log synchronization error at seq=15,offset=140 for /mail/0/6/37/30/brian%dev.example.com/dovecot.index: Append with UID 2296, but next_uid = 2299
Mar 25 10:23:14 wipe-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (15)
Mar 25 10:23:14 wipe-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (15)
Mar 25 10:23:14 wipe-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (15)
Mar 25 10:23:14 wipe-dev dovecot: IMAP(brian at dev.example.com): /mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist: Duplicate file entry at line 3: 1269512594.M94229P26298.wipe-dev.localdomain,S=1871,W=1917:2, (uid 2321 -> 2322)
Mar 25 10:23:14 wipe-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (15)
Mar 25 10:23:14 wipe-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (15)
Mar 25 10:23:14 wipe-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (15)
Mar 25 10:23:14 wipe-dev dovecot: IMAP(brian at dev.example.com): Sending log messages too fast, throttling..
Mar 25 10:23:14 wipe-dev dovecot: IMAP(brian at dev.example.com): rename(/mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist.tmp, /mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist) failed: No such file or directory
Mar 25 10:23:14 wipe-dev dovecot: IMAP(brian at dev.example.com): unlink(/mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist.tmp) failed: No such file or directory
Mar 25 10:23:14 wipe-dev dovecot: IMAP(brian at dev.example.com): Transaction log /mail/0/6/37/30/brian%dev.example.com/dovecot.index.log: duplicate transaction log sequence (15)
Mar 25 10:23:14 wipe-dev dovecot: IMAP(brian at dev.example.com): rename(/mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist.tmp, /mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist) failed: No such file or directory
Mar 25 10:23:14 wipe-dev dovecot: IMAP(brian at dev.example.com): unlink(/mail/0/6/37/30/brian%dev.example.com/dovecot-uidlist.tmp) failed: No such file or directory
Mar 25 10:23:15 wipe-dev dovecot: IMAP(brian at dev.example.com): /mail/0/6/37/30/brian%dev.example.com/dovecot.index reset, view is now inconsistent
Mar 25 10:23:22 wipe-dev dovecot: IMAP(brian at dev.example.com): Connection closed: Connection reset by peer bytes=79/793
Mar 25 10:23:22 wipe-dev dovecot: IMAP(brian at dev.example.com): Connection closed: Connection reset by peer bytes=1811/2146
Mar 25 10:23:22 wipe-dev dovecot: IMAP(brian at dev.example.com): Connection closed: Connection reset by peer bytes=1838/764
Mar 25 10:23:22 wipe-dev dovecot: IMAP(brian at dev.example.com): Connection closed: Connection reset by peer bytes=95/1044
Mar 25 10:23:22 wipe-dev dovecot: IMAP(brian at dev.example.com): Connection closed: Connection reset by peer bytes=2183/2131


More information about the dovecot mailing list