There's a bug in "folder delete" for lazy expunge, type "1 namespace", as descibed on https://wiki2.dovecot.org/Plugins/Lazyexpunge
When trying to delete a mailbox that still has messages in it, but that has no EXPUNGED/<name> counterpart, the process hangs after the imap "DELETE" command, and the following appears in the log file after a 60s timeout:
Jun 22 15:48:15 userimap6 dovecot: imap(xtra30): Error: Couldn't create mailbox list lock /var/mail/.8d1/index/4/03/xtra30/index/mailboxes.lock: file_create_locked(/var/mail/.8d1/index/4/03/xtra30/index/mailboxes.lock) failed: flock(/var/mail/.8d1/index/4/03/xtra30/index/mailboxes.lock, write-lock) failed: Timed out after 60 seconds (BUG: lock is held by our own process) Jun 22 15:48:15 userimap6 dovecot: imap(xtra30): Error: lazy_expunge: Couldn't open expunge mailbox: Failed to create mailbox EXPUNGED/Test: Internal error occurred. Refer to server log for more information. [2018-06-22 15:47:15] Jun 22 15:48:15 userimap6 dovecot: imap(xtra30): Error: Lazy-expunge transaction failed: Internal error occurred. Refer to server log for more information. [2018-06-22 15:47:15]
very quick summage of settings: ----8<----- mail_plugins = $mail_plugins lazy_expunge mail_location = mdbox:/var/mail/.8d1/mail/4/03/xtra30:INDEX=/var/mail/.8d1/index/4/03/xtra30/index ### from userdb namespace { inbox = yes list = yes prefix = separator = / } namespace expunged { hidden = yes inbox = no list = no prefix = EXPUNGED/ separator = / location = mdbox:/var/mail/.8d1/mail/4/03/xtra30:INDEX=/var/mail/.8d1/index/4/03/xtra30/index:MAILBOXDIR=expunged:LISTINDEX=expunged.list.index:SUBSCRIPTIONS=expunged.subscriptions ### also from userdb } plugin { lazy_expunge = EXPUNGED/ } ----8<----- (full doveconf available on request)
State of the account before delete: mailbox "Test" exists, 20 messages in it:
x LIST * *
- LIST (\HasNoChildren \UnMarked \Trash) "/" Trash
- LIST (\HasNoChildren \Marked) "/" Test
- LIST (\HasNoChildren \UnMarked \Junk) "/" Spam
- LIST (\HasNoChildren \UnMarked) "/" Sent
- LIST (\HasNoChildren \UnMarked) "/" Drafts
- LIST (\HasNoChildren) "/" INBOX x OK List completed (0.009 + 0.000 + 0.008 secs). x LIST EXPUNGED/* * x OK List completed (0.001 + 0.000 secs). x DELETE Test x NO [SERVERBUG] Internal error occurred. Refer to server log for more information. [2018-06-22 15:47:15] (60.064 + 0.000 + 60.063 secs).
... resulting in the above log lines.
However, if you first delete one message (causing EXPUNGED/Test to be created), and then remove the folder, it works fine:
x SELECT Test
- FLAGS (\Answered \Flagged \Deleted \Seen \Draft)
- OK [PERMANENTFLAGS (\Answered \Flagged \Deleted \Seen \Draft \*)] Flags permitted.
- 20 EXISTS
- 2 RECENT
- OK [UNSEEN 1] First unseen.
- OK [UIDVALIDITY 1352910749] UIDs valid
- OK [UIDNEXT 21] Predicted next UID
- OK [HIGHESTMODSEQ 21] Highest x OK [READ-WRITE] Select completed (0.010 + 0.000 + 0.009 secs). x FETCH 1:* (FLAGS)
- 1 FETCH (FLAGS ()) [...boring...]
- 20 FETCH (FLAGS (\Recent)) x OK Fetch completed (0.002 + 0.000 + 0.001 secs). x STORE 1 +FLAGS (\Deleted)
- 1 FETCH (FLAGS (\Deleted)) x OK Store completed (0.011 + 0.000 + 0.010 secs). x EXPUNGE
- 1 EXPUNGE x OK Expunge completed (0.131 + 0.000 + 0.130 secs). X LIST * *
- LIST (\HasNoChildren \UnMarked \Trash) "/" Trash
- LIST (\HasNoChildren \UnMarked) "/" Test
- LIST (\HasNoChildren \UnMarked \Junk) "/" Spam
- LIST (\HasNoChildren \UnMarked) "/" Sent
- LIST (\HasNoChildren \UnMarked) "/" Drafts
- LIST (\HasNoChildren) "/" INBOX X OK List completed (0.005 + 0.000 + 0.004 secs). x LIST EXPUNGED/* *
- LIST (\HasNoChildren \Marked) "/" EXPUNGED/Test x OK List completed (0.002 + 0.000 + 0.001 secs). x SELECT INBOX
- OK [CLOSED] Previous mailbox closed.
- FLAGS (\Answered \Flagged \Deleted \Seen \Draft) [...INBOX opening msgs...] x OK [READ-WRITE] Select completed (0.005 + 0.000 + 0.004 secs). x DELETE Test x OK Delete completed (0.129 + 0.000 + 0.128 secs). x LIST * *
- LIST (\HasNoChildren \UnMarked \Trash) "/" Trash
- LIST (\HasNoChildren \UnMarked \Junk) "/" Spam
- LIST (\HasNoChildren \UnMarked) "/" Sent
- LIST (\HasNoChildren \UnMarked) "/" Drafts
- LIST (\HasNoChildren) "/" INBOX x OK List completed (0.005 + 0.000 + 0.004 secs). x LIST EXPUNGED/* *
- LIST (\HasNoChildren \Marked) "/" EXPUNGED/Test x OK List completed (0.003 + 0.000 + 0.002 secs).
Seems the delete opeation locks the mailbox list, and then the expunge create hits the same lock. Is this something we can fix by changing settings? Eg use another location for the expunge lock?
-- Jan-Pieter Cornet johnpc@xs4all.net Systeembeheer XS4ALL Internet bv www.xs4all.nl