On Tue, 2011-12-20 at 13:48 +0100, Maria Arrea wrote: > Hello Timo, thank you in advance. Full log here (1 hour time range)
It could be useful to have all error/warning messages logged to their own file, so you could quickly see a list of all errors from the last day or two. That's also the log I'd be more interested in seeing. What things do you have accessing mailboxes? * imap * pop3 * dovecot-lda * doveadm purge Nothing else? No dsync for example? > Dec 14 21:44:30 buzon dovecot: imap(fmcarrasco): Error: > /indices_dovecot/indices/07/47/fmcarrasco/mailboxes/INBOX/dovecot.index > reset, view is now inconsistent I think these should happen only when dbox is being rebuilt by another process at the same time.. But it's a bit strange that it happens again in another session: > Dec 14 21:45:30 buzon dovecot: imap-login: Login: user=<fmcarrasco>, > method=PLAIN, rip=192.168.1.13, lip=192.168.4.80, mpid=20035, TLS > Dec 14 22:01:27 buzon dovecot: imap(fmcarrasco): Error: > /indices_dovecot/indices/07/47/fmcarrasco/mailboxes/INBOX/dovecot.index > reset, view is now inconsistent Kind of looks as if it isn't fixing itself?.. Also it might be helpful to have PID in the log lines: mail_log_prefix = %s(%u %p): > The other one: > > Dec 14 21:50:38 buzon dovecot: imap(cfp): Error: > /indices_dovecot/indices/16/58/cfp/mailboxes/Sent/dovecot.index reset, view > is now inconsistent Again it's strange how this begins. > Dec 14 21:50:38 buzon dovecot: imap(cfp): Disconnected: IMAP session state > is inconsistent, please relogin. bytes=32118/127014 > Dec 14 21:50:38 buzon dovecot: imap(cfp): Error: Recent flags state > corrupted for mailbox Trash > Dec 14 21:50:38 buzon dovecot: imap(cfp): Error: > /indices_dovecot/indices/16/58/cfp/mailboxes/Trash/dovecot.index reset, view > is now inconsistent > Dec 14 21:50:38 buzon dovecot: imap(cfp): Disconnected: IMAP session state > is inconsistent, please relogin. bytes=38097/309083 > Dec 14 21:50:38 buzon dovecot: imap(cfp): Error: Recent flags state > corrupted for mailbox Preinscripcion > Dec 14 21:50:38 buzon dovecot: imap(cfp): Error: > /indices_dovecot/indices/16/58/cfp/mailboxes/Preinscripcion/dovecot.index > reset, view is now inconsistent > Dec 14 21:50:38 buzon dovecot: imap(cfp): Disconnected: IMAP session state > is inconsistent, please relogin. bytes=33263/164275 > Dec 14 21:50:38 buzon dovecot: imap(cfp): Error: > /indices_dovecot/indices/16/58/cfp/mailboxes/Emagister/dovecot.index reset, > view is now inconsistent > Dec 14 21:50:38 buzon dovecot: imap(cfp): Disconnected: IMAP session state > is inconsistent, please relogin. bytes=35437/111594 > Dec 14 21:50:38 buzon dovecot: imap-login: Login: user=<cfp>, method=PLAIN, > rip=192.168.1.13, lip=192.168.4.80, mpid=24811, TLS > Dec 14 21:50:39 buzon dovecot: imap-login: Login: user=<cfp>, method=PLAIN, > rip=192.168.1.13, lip=192.168.4.80, mpid=24822, TLS > Dec 14 21:52:12 buzon postfix/cleanup[21212]: 9A22CC816C: > message-id=<CAP3xem+Vzw4b_dmDnr=ajn9cfpa8tnotxavbkm5xobzxpfu...@mail.gmail.com> > Dec 14 22:00:27 buzon dovecot: imap(cfp): Error: > /indices_dovecot/indices/16/58/cfp/mailboxes/Sent/dovecot.index reset, view > is now inconsistent > Dec 14 22:00:27 buzon dovecot: imap(cfp): Disconnected: IMAP session state > is inconsistent, please relogin. bytes=554/169764 > Dec 14 22:00:27 buzon dovecot: imap(cfp): Error: > /indices_dovecot/indices/16/58/cfp/mailboxes/Trash/dovecot.index reset, view > is now inconsistent > Dec 14 22:00:27 buzon dovecot: imap(cfp): Disconnected: IMAP session state > is inconsistent, please relogin. bytes=533/10963 > Dec 14 22:00:27 buzon dovecot: imap(cfp): Error: > /indices_dovecot/indices/16/58/cfp/mailboxes/Preinscripcion/dovecot.index > reset, view is now inconsistent > Dec 14 22:00:27 buzon dovecot: imap(cfp): Disconnected: IMAP session state > is inconsistent, please relogin. bytes=629/39790 > Dec 14 22:00:27 buzon dovecot: imap(cfp): Error: > /indices_dovecot/indices/16/58/cfp/mailboxes/INBOX/dovecot.index reset, view > is now inconsistent > Dec 14 22:00:27 buzon dovecot: imap(cfp): Disconnected: IMAP session state > is inconsistent, please relogin. bytes=613/496956 But all of the rest of this is quite clearly caused by the first problem. > I do not see any pattern about this problem of index reset, logs from other > day, maybe the problem is I/O load based: > > Dec 15 13:16:19 buzon dovecot: imap(ehlers): Error: Mailbox > Archivador/Facultad/curso whiteboard: Corrupted index, uidvalidity=0 This is clearly an originating error. But perhaps this is a newly created mailbox? I just noticed that this can happen if a mailbox creation is slow, and another session opens the mailbox before its creation has been finished. Check with: doveadm dump ".../mdbox/mailboxes/Mailbox Archivador/Facultad/curso whiteboard/dbox-Mails" The interesting lines in the output are: index id ................. = 1324032275 (2011-12-16 12:44:35) uid validity ............. = 1324032275 (2011-12-16 12:44:35) > Dec 15 13:16:19 buzon dovecot: imap(ehlers): Warning: mdbox > /buzones/domain/11/53/ehlers/storage: rebuilding indexes This then caused all of the user's other existing processes to fail with: > Dec 15 13:16:32 buzon dovecot: imap(ehlers): Error: > /indices_dovecot/indices/11/53/ehlers/mailboxes/INBOX/dovecot.index reset, > view is now inconsistent Perhaps the other users' problems began with similar errors?
