I'm seeing some problems on accounts which get a lot of spam (like, a lot). I get these errors: Mar 15 10:43:49 lmtp(12390): Error: Timeout (29s) while waiting for lock for transaction log file /var/spool/mail/dovecot/xxxx/xxxx/dovecot.list.index.log (WRITE lock held by pid 12193) --- Mar 15 10:43:49 lmtp(12034): Error: Transaction log file /var/spool/mail/dovecot/xxxxx/xxxx/dovecot.list.index.log: marked corrupted --- Mar 15 10:43:49 lmtp(12391): Error: Transaction log /var/spool/mail/dovecot/xxxx/xxxx/dovecot.list.index.log: duplicate transaction log sequence (3) ---- Mar 15 10:43:59 lmtp(xxxx at xxxx.dk): Error: Timeout (29s) while waiting for lock for transaction log file /var/spool/mail/dovecot/xxxx/xxxx/dovecot.list.index.log ---- Mar 15 10:43:51 lmtp(12294): Panic: file mail-transaction-log-file.c: line 104 (mail_transaction_log_file_free): assertion failed: (!file->locked) Mar 15 10:43:51 lmtp(12294): Error: Raw backtrace: /usr/lib/dovecot/libdovecot.so.0 [0x30d567e07a] -> /usr/lib/dovecot/libdovecot.so.0 [0x30d567e0e6] -> /usr/lib/dovecot/libdovecot.so.0 [0x30d567d4ac] -> /usr/lib/dovecot/libdovecot-storage.so.0 [0x30d5299ca7] -> /usr/lib/dovecot/libdovecot-storage.so.0(mail_transaction_logs_clean+0x28) [0x30d529b698] -> /usr/lib/dovecot/libdovecot-storage.so.0(mail_transaction_log_view_close+0x49) [0x30d529a7e9] -> /usr/lib/dovecot/libdovecot-storage.so.0 [0x30d5293c03] -> /usr/lib/dovecot/libdovecot-storage.so.0(mailbox_list_index_refresh_later+0x92) [0x30d525af62] -> /usr/lib/dovecot/libdovecot-storage.so.0 [0x30d52589eb] -> /usr/lib/dovecot/libdovecot-storage.so.0 [0x30d5259217] -> /usr/lib/dovecot/libdovecot-storage.so.0(mailbox_transaction_commit_get_changes+0x54) [0x30d52352c4] -> /usr/lib/dovecot/libdovecot-storage.so.0(mailbox_transaction_commit+0x16) [0x30d5235386] -> /usr/lib/dovecot/libdovecot-storage.so.0(mail_user_autoexpunge+0x1f8) [0x30d522a9b8] -> /usr/lib/dovecot/libdovecot-storage.so.0(mail_user_unref+0x2a) [0x30d523a16a] -> dovecot/lmtp [DATA 172.17.165.14] [0x40696b] -> dovecot/lmtp [DATA 172.17.165.14] [0x406bd6] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_call_io+0x49) [0x30d5690579] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_handler_run_internal+0xdc) [0x30d5691c3c] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_handler_run+0xa9) [0x30d56906b9] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_run+0x38) [0x30d56909e8] -> /usr/lib/dovecot/libdovecot.so.0(master_service_run+0x13) [0x30d562e533] -> dovecot/lmtp [DATA 172.17.165.14](main+0x15c) [0x404c8c] -> /lib64/libc.so.6(__libc_start_main+0xf4) [0x36aea1d9f4] -> dovecot/lmtp [DATA 172.17.165.14] [0x404a79] ---- The data is stored on NFS, with single-node access. mmap_disable is set to 'yes' Anyone know how to solve this? or can share some insights. Running dovecot 2.2.21 (5345f22) -- Tom Sommer
On 15.03.2016 11:53, Tom Sommer wrote:> I'm seeing some problems on accounts which get a lot of spam (like, a > lot). > > I get these errors: > > Mar 15 10:43:49 lmtp(12390): Error: Timeout (29s) while waiting for > lock for transaction log file > /var/spool/mail/dovecot/xxxx/xxxx/dovecot.list.index.log (WRITE lock > held by pid 12193) > > --- > > Mar 15 10:43:49 lmtp(12034): Error: Transaction log file > /var/spool/mail/dovecot/xxxxx/xxxx/dovecot.list.index.log: marked > corrupted > > --- > > Mar 15 10:43:49 lmtp(12391): Error: Transaction log > /var/spool/mail/dovecot/xxxx/xxxx/dovecot.list.index.log: duplicate > transaction log sequence (3) > > ---- > > Mar 15 10:43:59 lmtp(xxxx at xxxx.dk): Error: Timeout (29s) while waiting > for lock for transaction log file > /var/spool/mail/dovecot/xxxx/xxxx/dovecot.list.index.log > > ---- > > Mar 15 10:43:51 lmtp(12294): Panic: file mail-transaction-log-file.c: > line 104 (mail_transaction_log_file_free): assertion failed: > (!file->locked) > Mar 15 10:43:51 lmtp(12294): Error: Raw backtrace: > /usr/lib/dovecot/libdovecot.so.0 [0x30d567e07a] -> > /usr/lib/dovecot/libdovecot.so.0 [0x30d567e0e6] -> > /usr/lib/dovecot/libdovecot.so.0 [0x30d567d4ac] -> > /usr/lib/dovecot/libdovecot-storage.so.0 [0x30d5299ca7] -> > /usr/lib/dovecot/libdovecot-storage.so.0(mail_transaction_logs_clean+0x28) > [0x30d529b698] -> > /usr/lib/dovecot/libdovecot-storage.so.0(mail_transaction_log_view_close+0x49) > [0x30d529a7e9] -> /usr/lib/dovecot/libdovecot-storage.so.0 > [0x30d5293c03] -> > /usr/lib/dovecot/libdovecot-storage.so.0(mailbox_list_index_refresh_later+0x92) > [0x30d525af62] -> /usr/lib/dovecot/libdovecot-storage.so.0 > [0x30d52589eb] -> /usr/lib/dovecot/libdovecot-storage.so.0 > [0x30d5259217] -> > /usr/lib/dovecot/libdovecot-storage.so.0(mailbox_transaction_commit_get_changes+0x54) > [0x30d52352c4] -> > /usr/lib/dovecot/libdovecot-storage.so.0(mailbox_transaction_commit+0x16) > [0x30d5235386] -> > /usr/lib/dovecot/libdovecot-storage.so.0(mail_user_autoexpunge+0x1f8) > [0x30d522a9b8] -> > /usr/lib/dovecot/libdovecot-storage.so.0(mail_user_unref+0x2a) > [0x30d523a16a] -> dovecot/lmtp [DATA 172.17.165.14] [0x40696b] -> > dovecot/lmtp [DATA 172.17.165.14] [0x406bd6] -> > /usr/lib/dovecot/libdovecot.so.0(io_loop_call_io+0x49) [0x30d5690579] > -> /usr/lib/dovecot/libdovecot.so.0(io_loop_handler_run_internal+0xdc) > [0x30d5691c3c] -> > /usr/lib/dovecot/libdovecot.so.0(io_loop_handler_run+0xa9) > [0x30d56906b9] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_run+0x38) > [0x30d56909e8] -> > /usr/lib/dovecot/libdovecot.so.0(master_service_run+0x13) > [0x30d562e533] -> dovecot/lmtp [DATA 172.17.165.14](main+0x15c) > [0x404c8c] -> /lib64/libc.so.6(__libc_start_main+0xf4) [0x36aea1d9f4] > -> dovecot/lmtp [DATA 172.17.165.14] [0x404a79] > > ---- > > The data is stored on NFS, with single-node access. > > mmap_disable is set to 'yes' > > Anyone know how to solve this? or can share some insights. > > Running dovecot 2.2.21 (5345f22) >Hi! Can you please send output of doveconf -n? --- Aki Tuomi Dovecot Oy
On 2016-03-15 10:53, Tom Sommer wrote:> I'm seeing some problems on accounts which get a lot of spam (like, a > lot). > > I get these errors:When I do a process-list I see a lot of stuck lmtp processes on the same account: 16180 ? D 0:00 \_ dovecot/lmtp [DATA 172.17.165.14 xxx at xxx] 16181 ? D 0:00 \_ dovecot/lmtp [DATA 172.17.165.14 xxx at xxx] x 600 // Tom
On 15.03.2016 12:28, Tom Sommer wrote:> > On 2016-03-15 10:53, Tom Sommer wrote: >> I'm seeing some problems on accounts which get a lot of spam (like, a >> lot). >> >> I get these errors: > > When I do a process-list I see a lot of stuck lmtp processes on the > same account: > > 16180 ? D 0:00 \_ dovecot/lmtp [DATA 172.17.165.14 xxx at xxx] > 16181 ? D 0:00 \_ dovecot/lmtp [DATA 172.17.165.14 xxx at xxx] > > x 600 > > // TomAnd you are sure this is not related to your NFS? Aki
On 2016-03-15 10:53, Tom Sommer wrote:> I'm seeing some problems on accounts which get a lot of spam (like, a > lot).I did an "strace" on one of the hundreds of lmtp processes. It's doing stat() on all files in the new folder for the receiver: stat("/var/mail/dovecot/xxxx/xxxx/new/xx.xxx.xxxx.xxxx.com", {st_mode=S_IFREG|0600, st_size=15505, ...}) = 0 etc. The "new" folder contains hundreds of thousands of files. Is there any way to prevent all these stat() calls? It seems like something there would be an index or cache for? Thanks // Tom
On 2016-03-17 13:41, Tom Sommer wrote:> On 2016-03-15 10:53, Tom Sommer wrote: >> I'm seeing some problems on accounts which get a lot of spam (like, a >> lot). > > I did an "strace" on one of the hundreds of lmtp processes. > > It's doing stat() on all files in the new folder for the receiver: > > stat("/var/mail/dovecot/xxxx/xxxx/new/xx.xxx.xxxx.xxxx.com", > {st_mode=S_IFREG|0600, st_size=15505, ...}) = 0 > > etc. > > The "new" folder contains hundreds of thousands of files. > > Is there any way to prevent all these stat() calls? It seems like > something there would be an index or cache for?Seems like it might be due to maildir quota-recalculation?