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@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 [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@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 [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@xxx] 16181 ? D 0:00 \_ dovecot/lmtp [DATA 172.17.165.14 xxx@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@xxx] 16181 ? D 0:00 \_ dovecot/lmtp [DATA 172.17.165.14 xxx@xxx]
x 600
// Tom
And you are sure this is not related to your NFS?
Aki
On 15.03.2016 12:29, Aki Tuomi wrote:
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@xxx] 16181 ? D 0:00 \_ dovecot/lmtp [DATA 172.17.165.14 xxx@xxx]
x 600
// Tom
And you are sure this is not related to your NFS?
As a workaround, you could also try different low settings for lmtp_user_concurrency_limit and see if it removes the lock contention, but keeps lmtp performance bearable.
You do not have any external programs touching the maildir at the same time, right?
br, Teemu Huovila
On 2016-03-15 11:29, Aki Tuomi wrote:
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@xxx] 16181 ? D 0:00 \_ dovecot/lmtp [DATA 172.17.165.14 xxx@xxx]
x 600
// Tom
And you are sure this is not related to your NFS?
I think I solved it with lock_method = dotlock
Sorry for the noise and thanks for the quick reply.
// Tom
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?
-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1
On Thu, 17 Mar 2016, Tom Sommer wrote:
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?
Yes possibly. But also in order to update the index files.
For all I know this should happen only, if the mtime of the directory changes. Is there some external programm manipulating files in the new/cur directories bypassing Dovecot? E.g. a rm on command line?
Steffen Kaiser -----BEGIN PGP SIGNATURE----- Version: GnuPG v1
iQEVAwUBVuuqPHz1H7kL/d9rAQIEFggAmwDF11PTTIUOZ66udkcfxjZ944MvFBE0 I5jgSe/qRwSchfPE/leyc15uEC477YdJavbOv8TtsdZQVgUcWZgM7Wdtn0iCNWsT LttwfEp2Ft0swdtwE5948Swt2P99UHi6KVC7XkOHm/uH8O3zLRNMo8h04IYkwhV+ zCz0FAEF57opFATpoJ1VPJE01PslKBEo5sublCaA2c35kE0ukDnNOsocJkiIw8+t ax85THVWFjIv2ybBbjYIIYFipkIo1vxzYaxfKnrLg9OdbUPceVaL0yL/WXm44wP7 Yoouoh+42E8jDvCHSCWmyBjXUw0CvmKExMSwigwNYYYhabCpYmEctg== =LQdS -----END PGP SIGNATURE-----
On 2016-03-18 08:11, Steffen Kaiser wrote:
-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1
On Thu, 17 Mar 2016, Tom Sommer wrote:
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?
Yes possibly. But also in order to update the index files.
Seems the use of Maildir++ quota was the problem in this case.
For all I know this should happen only, if the mtime of the directory changes. Is there some external programm manipulating files in the new/cur directories bypassing Dovecot? E.g. a rm on command line?
Nope
// Tom
participants (4)
-
Aki Tuomi
-
Steffen Kaiser
-
Teemu Huovila
-
Tom Sommer