On 28/03/2019 09:36, Timo Sirainen wrote:
On 28 Mar 2019, at 10.15, Arkadiusz Miśkiewicz <arekm@maven.pl <mailto:arekm@maven.pl>> wrote:
error = 0x55e3e2b40ac0 "Fixed index file /var/mail/piast_efaktury/dovecot.index: log_file_seq 13 -> 15", nodiskspace = true,
This was one of the things I was first wondering, but I'm not sure why it's not logging an error. Anyway, you're using filesystem quota? And this index is large enough that trying to rewrite it brings the user over quota?
That's possible, fs quota and user is close to being full:
used: 19061.63 MiB (19987.57 MB) hard: 19073.49 MiB (20000.00 MB)
So some initial write/rewrite of indexes corrupts them and then fixing doesn't do anything because it can't do anything when it's over quota (but why it doesn't report over quota errors in logs?)
That's from current try, lmtp trying to write, index already corrupted earlier:
10068 openat(AT_FDCWD, "/var/mail/piast_efaktury/dovecot.index.log", O_RDWR|O_APPEND) = 15 10068 fstat(15, {st_mode=S_IFREG|0600, st_size=40, ...}) = 0 10068 pread64(15, "\1\3(\0\330\2\232\\\17\0\0\0\16\0\0\0(\200\0\0o&\232\\_\10\0\0\0\0\0\0\1\0\0\0\0\0\0\0", 40, 0) = 40 10068 openat(AT_FDCWD, "/var/mail/piast_efaktury/dovecot.index", O_RDWR) = 16 10068 fstat(16, {st_mode=S_IFREG|0600, st_size=13555228, ...}) = 0 10068 mmap(NULL, 13555228, PROT_READ|PROT_WRITE, MAP_PRIVATE, 16, 0) = 0x7f1abc8e3000 10068 openat(AT_FDCWD, "/var/mail/piast_efaktury/dovecot.index.log.2", O_RDWR|O_APPEND) = 17 10068 fstat(17, {st_mode=S_IFREG|0600, st_size=32808, ...}) = 0 10068 pread64(17, "\1\3(\0\330\2\232\\\16\0\0\0\r\0\0\0x\200\0\0\277 \232\\|\7\0\0\0\0\0\0\1\0\0\0\0\0\0\0", 40, 0) = 40 10068 close(17) = 0 10068 write(2, "\1\01010068 prefix=lmtp(piast_efaktury): pid=<10068> session=<kHc9H0eRnFxUJwAA9fPEKQ>, \n", 84) = 84 10068 write(2, "\1\00410068 Index /var/mail/piast_efaktury/dovecot.index: Lost log for seq=13 offset=25648: Missing middle file seq=13 (between 13..4294967295, we have seqs 14,15): .log.2 contains file_seq=14 (initial_ma"..., 229) = 229 10068 write(2, "\1\00310068 fscking index file /var/mail/piast_efaktury/dovecot.index\n", 66) = 66 10068 alarm(180) = 0 10068 fcntl(15, F_SETLKW, {l_type=F_WRLCK, l_whence=SEEK_SET, l_start=0, l_len=0}) = 0 10068 alarm(0) = 180 10068 stat("/var/mail/piast_efaktury/dovecot.index.log", {st_mode=S_IFREG|0600, st_size=40, ...}) = 0 10068 fstat(15, {st_mode=S_IFREG|0600, st_size=40, ...}) = 0 10068 write(2, "\1\00410068 Fixed index file /var/mail/piast_efaktury/dovecot.index: log_file_seq 13 -> 15\n", 87) = 87 10068 umask(000) = 077 10068 openat(AT_FDCWD, "/var/mail/piast_efaktury/dovecot.index.tmp", O_RDWR|O_CREAT|O_EXCL, 0600) = 17 10068 umask(077) = 000 10068 fstat(17, {st_mode=S_IFREG|0600, st_size=0, ...}) = 0 10068 write(17, "\7\3x\0\320\0\0\0\f\0\0\0\1\0\0\0\330\2\232\\\4\0\0\0\307A\260R\316\20D\0q<\21\0\0\0\0\0f\300\17\0\0\0\0\0\304\20D\0\303\224B\0\316\20D\0\17\0\0\0(\0\0\0(\0\0\0\0\0\0\0\177\34\232\\\0\0\0\0p]\231\\\240\363C\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\330\2\232\\\10\0\4\0\4\0\5\0cache\0\0\0$\0\0\0\0\0\0\0\0\0\0\0\0\0\7\0maildir\0\214\37\232\\\214\37\232\\\333!\0233\330\37\232\\\214\37\232\\\333!\0233\330\37\232\\T\250\31."..., 208) = 208 10068 write(17, "]\3242\0\10\0\0\0\0\0\0\0^\3242\0\10\0\0\0\0\0\0\0_\3242\0\10\0\0\0\0\0\0\0`\3242\0\10\0\0\0\0\0\0\0a\3242\0\10\0\0\0\0\0\0\0b\3242\0\10\0\0\0\0\0\0\0c\3242\0\10\0\0\0\0\0\0\0d\3242\0\10\0\0\0\0\0\0\0e\3242\0\10\0\0\0\0\0\0\0f\3242\0\10\0\0\0\0\0\0\0g\3242\0\10\0\0\0\0\0\0\0h\3242\0\10\0\0\0\0\0\0\0i\3242\0\10\0\0\0\0\0\0\0j\3242\0\10\0\0\0\0\0\0\0k\3242\0\10\0\0\0\0\0\0\0l\3242\0\10\0\0\0\0\0\0\0m\3242\0\10\0\0\0"..., 13555020) = 8912688 10068 write(17, "\241)>\0\10\0\0\0\0\0\0\0\242)>\0\10\0\0\0\0\0\0\0\243)>\0\10\0\0\0\0\0\0\0\244)>\0\10\0\0\0\0\0\0\0\245)>\0\10\0\0\0\0\0\0\0\246)>\0\10\0\0\0\0\0\0\0\247)>\0\10\0\0\0\0\0\0\0\250)>\0\10\0\0\0\0\0\0\0\251)>\0\10\0\0\0\0\0\0\0\252)>\0\10\0\0\0\0\0\0\0\253)>\0\10\0\0\0\0\0\0\0\254)>\0\10\0\0\0\0\0\0\0\255)>\0\10\0\0\0\0\0\0\0\256)>\0\10\0\0\0\0\0\0\0\257)>\0\10\0\0\0\0\0\0\0\260)>\0\10\0\0\0\0\0\0\0\261)>\0\10\0\0\0"..., 4642332) = -1 EDQUOT (Disk quota exceeded) 10068 close(17) = 0 10068 unlink("/var/mail/piast_efaktury/dovecot.index.tmp") = 0 10068 write(2, "\1\00610068 file mail-transaction-log-file.c: line 105 (mail_transaction_log_file_free): assertion failed: (!file->locked)\n", 119) = 119
(I guess I have to finally separate indexes out to separate partition (outside of quota) because more of these "not dealing right with fs quota" problems are there, previous one: https://dovecot.org/pipermail/dovecot/2018-November/113460.html . Unrelated to current issue)
Other solution could be to make dovecot treat soft quota as hard quota and just give a bit more hard quota for these index updates. Not sure if that's doable currently with dovecot.
-- Arkadiusz Miśkiewicz, arekm / ( maven.pl | pld-linux.org )