You signed in with another tab or window. Reload to refresh your session.You signed out in another tab or window. Reload to refresh your session.You switched accounts on another tab or window. Reload to refresh your session.Dismiss alert
Describe the bug
In case rbox_mail tries to get the metadata of a recently (old index data) deleted object. get_metadata fails with -2 and mail is set as expunged.
Because the rbox_set_expunge method does a index_refresh, the recently deleted mail may no longer set as as expunged in the index (index entry removed by the delete process). The result of rbox_set_expunge then is, that the index is marked as corrupt and rbox_sync will force a rebuild of the index!
Rebuilding the rbox index, is a really slow process, because it involves a scan for objects on all osds, and what may be worse a lock on the index.
wait for ' Warning: Errorcode: -2 cannot get x_attr(' with tail -f dovecot.log
check log for Rebuilding index messages.
Expected behavior
Because the email is no longer in the object store, a warning with (uid, processid) should be written to log file.
if a mail gets expunged (removed from storage), a log message with (uid, processid) should be written to log file.
Mail, because it no longer exist should, in any case be marked as expunged.
mail_read process exits gracefully, because it detects (mail marked as expunged) that it has read an old entry.
Logfiles, screenshots
Nov 29 02:04:18 imap(t659): Warning: Errorcode: -2 cannot get x_attr(G,G) from object c12919200f3bff5bb5340000d561c877, process 13390
Nov 29 02:04:18 imap(t659): Error: rbox /mnt/cephfs/mail/rbox/t659/mailboxes/INBOX/rbox-Mails: Unexpectedly lost uid=551
Nov 29 02:04:18 imap(t271): Warning: Errorcode: -2 cannot get x_attr(G,G) from object 799a1d200e3bff5bb5340000d561c877, process 13115
Nov 29 02:04:18 imap(t271): Error: rbox /mnt/cephfs/mail/rbox/t271/mailboxes/INBOX/rbox-Mails: Unexpectedly lost uid=492
Nov 29 02:04:18 imap(t845): Warning: Errorcode: -2 cannot get x_attr(G,G) from object 19742c1f023bff5b6b2c0000d561c877, process 8662
Nov 29 02:04:18 imap(t845): Error: rbox /mnt/cephfs/mail/rbox/t845/mailboxes/INBOX/rbox-Mails: Unexpectedly lost uid=473
Nov 29 02:04:18 imap(t845): Warning: rbox /mnt/cephfs/mail/rbox/t845/mailboxes/Drafts/rbox-Mails: Rebuilding index, guid: 1320f2201fc7fd5bf34c0000d561c877 , mailbox_name: Drafts, alt_storage: (null)
Nov 29 02:04:19 imap(t676): Warning: Errorcode: -2 cannot get x_attr(G,G) from object 91528902113bff5bb5340000d561c877, process 13395
Nov 29 02:04:19 imap(t676): Error: rbox /mnt/cephfs/mail/rbox/t676/mailboxes/INBOX/rbox-Mails: Unexpectedly lost uid=990
Nov 29 02:04:19 imap(t710): Warning: Errorcode: -2 cannot get x_attr(G,G) from object 993ba81f0d3bff5b16560000d561c877, process 5731
Nov 29 02:04:19 imap(t710): Error: rbox /mnt/cephfs/mail/rbox/t710/mailboxes/INBOX/rbox-Mails: Unexpectedly lost uid=516
Nov 29 02:04:19 imap(t659): Warning: rbox /mnt/cephfs/mail/rbox/t659/mailboxes/Drafts/rbox-Mails: Rebuilding index, guid: 6593b8336bc2fd5b20490000d561c877 , mailbox_name: Drafts, alt_storage: (null)
Nov 29 02:04:19 imap(t676): Warning: rbox /mnt/cephfs/mail/rbox/t676/mailboxes/Drafts/rbox-Mails: Rebuilding index, guid: 96c4c332d9c2fd5b77490000d561c877 , mailbox_name: Drafts, alt_storage: (null)
Nov 29 02:04:19 imap(t413): Warning: Errorcode: -2 cannot get x_attr(G,G) from object 91905b010c3bff5b8d070000d561c877, process 1012
Nov 29 02:04:19 imap(t413): Error: rbox /mnt/cephfs/mail/rbox/t413/mailboxes/INBOX/rbox-Mails: Unexpectedly lost uid=719
Nov 29 02:04:19 imap(t271): Warning: rbox /mnt/cephfs/mail/rbox/t271/mailboxes/Drafts/rbox-Mails: Rebuilding index, guid: ee569
Server (please complete the following information):
OS: ubuntu
Ceph Version [luminous]
Dovecot Version 2.2
Client (please complete the following information):
used client [imaptest]
Version [https://github.com/ceph-dovecot/imaptest]
Additional context
The problem will occur, when the read process of a user, tries to read a mail which another user process deletes. Because this is a timing issue, it may take several attempts or hours before the problem occurs.
The text was updated successfully, but these errors were encountered:
Describe the bug
In case rbox_mail tries to get the metadata of a recently (old index data) deleted object. get_metadata fails with -2 and mail is set as expunged.
Because the rbox_set_expunge method does a index_refresh, the recently deleted mail may no longer set as as expunged in the index (index entry removed by the delete process). The result of rbox_set_expunge then is, that the index is marked as corrupt and rbox_sync will force a rebuild of the index!
Rebuilding the rbox index, is a really slow process, because it involves a scan for objects on all osds, and what may be worse a lock on the index.
To Reproduce
Steps to reproduce the behavior:
Expected behavior
Logfiles, screenshots
Nov 29 02:04:18 imap(t659): Warning: Errorcode: -2 cannot get x_attr(G,G) from object c12919200f3bff5bb5340000d561c877, process 13390
Nov 29 02:04:18 imap(t659): Error: rbox /mnt/cephfs/mail/rbox/t659/mailboxes/INBOX/rbox-Mails: Unexpectedly lost uid=551
Nov 29 02:04:18 imap(t271): Warning: Errorcode: -2 cannot get x_attr(G,G) from object 799a1d200e3bff5bb5340000d561c877, process 13115
Nov 29 02:04:18 imap(t271): Error: rbox /mnt/cephfs/mail/rbox/t271/mailboxes/INBOX/rbox-Mails: Unexpectedly lost uid=492
Nov 29 02:04:18 imap(t845): Warning: Errorcode: -2 cannot get x_attr(G,G) from object 19742c1f023bff5b6b2c0000d561c877, process 8662
Nov 29 02:04:18 imap(t845): Error: rbox /mnt/cephfs/mail/rbox/t845/mailboxes/INBOX/rbox-Mails: Unexpectedly lost uid=473
Nov 29 02:04:18 imap(t845): Warning: rbox /mnt/cephfs/mail/rbox/t845/mailboxes/Drafts/rbox-Mails: Rebuilding index, guid: 1320f2201fc7fd5bf34c0000d561c877 , mailbox_name: Drafts, alt_storage: (null)
Nov 29 02:04:19 imap(t676): Warning: Errorcode: -2 cannot get x_attr(G,G) from object 91528902113bff5bb5340000d561c877, process 13395
Nov 29 02:04:19 imap(t676): Error: rbox /mnt/cephfs/mail/rbox/t676/mailboxes/INBOX/rbox-Mails: Unexpectedly lost uid=990
Nov 29 02:04:19 imap(t710): Warning: Errorcode: -2 cannot get x_attr(G,G) from object 993ba81f0d3bff5b16560000d561c877, process 5731
Nov 29 02:04:19 imap(t710): Error: rbox /mnt/cephfs/mail/rbox/t710/mailboxes/INBOX/rbox-Mails: Unexpectedly lost uid=516
Nov 29 02:04:19 imap(t659): Warning: rbox /mnt/cephfs/mail/rbox/t659/mailboxes/Drafts/rbox-Mails: Rebuilding index, guid: 6593b8336bc2fd5b20490000d561c877 , mailbox_name: Drafts, alt_storage: (null)
Nov 29 02:04:19 imap(t676): Warning: rbox /mnt/cephfs/mail/rbox/t676/mailboxes/Drafts/rbox-Mails: Rebuilding index, guid: 96c4c332d9c2fd5b77490000d561c877 , mailbox_name: Drafts, alt_storage: (null)
Nov 29 02:04:19 imap(t413): Warning: Errorcode: -2 cannot get x_attr(G,G) from object 91905b010c3bff5b8d070000d561c877, process 1012
Nov 29 02:04:19 imap(t413): Error: rbox /mnt/cephfs/mail/rbox/t413/mailboxes/INBOX/rbox-Mails: Unexpectedly lost uid=719
Nov 29 02:04:19 imap(t271): Warning: rbox /mnt/cephfs/mail/rbox/t271/mailboxes/Drafts/rbox-Mails: Rebuilding index, guid: ee569
Server (please complete the following information):
Client (please complete the following information):
Additional context
The problem will occur, when the read process of a user, tries to read a mail which another user process deletes. Because this is a timing issue, it may take several attempts or hours before the problem occurs.
The text was updated successfully, but these errors were encountered: