Mailing List CGatePro@mail.stalker.com Message #100663
From: Wiley Sanders <wsanders@wsanders.net>
Subject: More on Truncated MBOX files (was Users are losing the INBOX)
Date: Mon, 13 Sep 2010 11:50:51 -0700
To: CommuniGate Pro Discussions <CGatePro@mail.stalker.com>
Since I posted last I've a had a couple more users "accidentally
delete" their INBOX content. I've confirmed of these two users,
neither has ever connected with POP, one connects only with the
Webmail (HTTPU) interface, and the other only with IMAPm and they do
not have multiple clients. There are all on onboard storage, locally
mounted ext3 filesystems, but its unlikely it's an OS or CGPro file
locking problem..

At least for the IMAP user, and I am able to reproduce this, this is
MAYBE a Thunderbird bug/feature. It turns out, whether I select a
message and move it to the "Trash", hit the "delete" key, or click on
the big red "X", the message is moved to my Trash.mdir but is not
visible in the Thunderbird "Trash". This is with "Move it to this
folder: Trash" and not "remove it immediately" selected as my Deletion
preferences! So the message appears to have vanished completely.

If I uncheck "Clean Up (Expunge) Inbox on Exit" my Trash messages
reappear. However, I have "Empty Trash on Exit" set so it's possible
for me to go through an entire Thunderbird session without ever seeing
anything show up in my Trash.

So this may not have anything to do with the INBOX being an Mbox
instead of an Mdir. My users still can never describe in any detail
when messages disappeared and what caused them to disappear, but I
think what is happening is they are still accidentally deleting stuff
somehow, it never appears in their Trash, and then gets deleted when
they exit Thunderbird.

I do have some questions about the way this shows up in the log:

11:08:22.56 2 ROUTER LOCAL: 'user@stmarys-ca.edu' accepted: '' at 'user'
11:08:22.60 2 ROUTER LOCAL: '<user@stmarys-ca.edu>' accepted: '' at 'user'
11:08:22.72 2 MAILBOX(user/INBOX) {71014} appended @7513247: 59+15194 bytes
11:08:22.72 2 MAILBOX(user/INBOX) [1385298] stored as {71014}
11:08:22.72 2 ACCOUNT(user) [1385298] delivered
11:08:22.72 2 DEQUEUER [1385298] LOCAL(user) delivered: Delivered to
the user mailbox
11:10:49.72 2 MAILBOX(user/Archives/2010) {10} appended: 3420 bytes, 69 lines
11:15:36.03 2 MAILBOX(user/Trash) {95794} appended @9126875: 59+16968 bytes
11:16:51.54 2 ROUTER LOCAL: 'user@stmarys-ca.edu' accepted: '' at 'user'
11:16:51.60 2 EXTAUTH user@stmarys-ca.edu(IMAP) plain password verified
11:16:51.60 2 IMAP-815940([10.90.21.122]) 'user@stmarys-ca.edu'
connected(CLRTXT) from [10.90.21.122]:4917
11:18:49.11 2 MAILBOX(user/Trash) {95795} appended @9143902: 59+9075 bytes
11:18:49.11 2 MAILBOX(user/Trash) {95796} appended @9153036: 59+13250 bytes
...[about 20 lines deleted]
11:19:38.75 2 MAILBOX(user/Trash) {95808} appended @9412197: 59+10076 bytes
11:20:03.22 2 MAILBOX(user/Trash) {95809} appended @9422332: 59+4013161 bytes
11:20:08.92 2 IMAP-815940([10.90.21.122]) 'user@stmarys-ca.edu'
disconnected ([10.90.21.122]:4917)
11:20:08.92 2 MAILBOX(user/INBOX) {70950} deleted: overwrite
11:20:08.93 2 MAILBOX(user/INBOX) {70956} deleted: overwrite
..[about 20 lines deleted]
11:20:08.93 2 MAILBOX(user/INBOX) {71013} deleted: overwrite
11:20:08.93 2 MAILBOX(user/INBOX) {71014} deleted: overwrite
11:20:08.93 2 IMAP-814828([10.90.21.122]) 'user@stmarys-ca.edu'
disconnected ([10.90.21.122]:4432)
11:20:08.93 2 MAILBOX(user/INBOX) cut @1001297, 3 messages, last={71011}
11:20:08.93 2 IMAP-814906([10.90.21.122]) 'user@stmarys-ca.edu'
disconnected ([10.90.21.122]:4439)
11:21:56.36 2 ROUTER LOCAL: 'user@stmarys-ca.edu' accepted: '' at 'user'
11:21:56.41 2 EXTAUTH user@stmarys-ca.edu(IMAP) plain password verified
11:21:56.41 2 IMAP-816130([10.90.21.122]) 'user@stmarys-ca.edu'
connected(CLRTXT) from [10.90.21.122]:4948
11:22:06.22 2 ROUTER LOCAL: 'user@stmarys-ca.edu' accepted: '' at 'user'
11:22:06.26 2 EXTAUTH user@stmarys-ca.edu(IMAP) plain password verified
11:22:06.26 2 IMAP-816146([10.90.21.122]) 'user@stmarys-ca.edu'
connected(CLRTXT) from [10.90.21.122]:4951
11:27:11.58 2 IMAP-816146([10.90.21.122]) 'user@stmarys-ca.edu'
disconnected ([10.90.21.122]:4951)
11:27:11.58 2 IMAP-816130([10.90.21.122]) 'user@stmarys-ca.edu'
disconnected ([10.90.21.122]:4948)
11:27:44.79 2 ROUTER LOCAL: 'user@stmarys-ca.edu' accepted: '' at 'user'
11:27:44.79 2 EXTAUTH user@stmarys-ca.edu(IMAP) plain password verified
11:27:44.79 2 IMAP-816373([10.90.21.122]) 'user@stmarys-ca.edu'
connected(CLRTXT) from [10.90.21.122]:4969
11:27:53.40 2 ROUTER LOCAL: 'user@stmarys-ca.edu' accepted: '' at 'user'
11:27:53.40 2 EXTAUTH user@stmarys-ca.edu(IMAP) plain password verified
11:27:53.40 2 IMAP-816381([10.90.21.122]) 'user@stmarys-ca.edu'
connected(CLRTXT) from [10.90.21.122]:4973
11:57:38.98 2 IMAP-816381([10.90.21.122]) 'user@stmarys-ca.edu'
disconnected ([10.90.21.122]:4973)
12:13:53.03 2 ROUTER LOCAL: 'user@stmarys-ca.edu' accepted: '' at 'user'
12:27:15.20 2 ROUTER LOCAL: 'user@stmarys-ca.edu' accepted: '' at 'user'
12:27:15.24 2 ROUTER LOCAL: '<user@stmarys-ca.edu>' accepted: '' at 'user'
12:27:15.36 2 MAILBOX(user/INBOX) {71015} appended @1001297: 59+30840 bytes
12:27:15.36 2 MAILBOX(user/INBOX) [1390173] stored as {71015}
12:27:15.36 2 ACCOUNT(user) [1390173] delivered
12:27:15.36 2 DEQUEUER [1390173] LOCAL(user) delivered: Delivered to
the user mailbox

At some point between 11:08 and 12:27 the user "lost" his email. From
the logs you can see that his INBOX has shrunk considerably. He also
moved a bunch of stuff to the Trash, and messages were removed from
his INBOX. My questions are:

Is anyone else seeing disappearing Trash in Thunderbird?

What are the numbers in parentheses in the logs? Examples:

11:18:49.11 2 MAILBOX(user/Trash) {95796} appended @9153036: 59+13250 bytes
11:20:08.93 2 MAILBOX(user/INBOX) {70956} deleted: overwrite

They do not seem to be related to the message ID or the byte position
in the Mbox, other than they seems to be sequential. Trash
removals/truncations are logged similarly.

Thanks - one of these days I am going to be able to trace a Message
from when it was received to when it was "accidentally" deleted. So
far, no luck.

-W Sanders
 St Marys College of California
 http://wsanders.net
Subscribe (FEED) Subscribe (DIGEST) Subscribe (INDEX) Unsubscribe Mail to Listmaster