495760 - msgDatabase loaded from .msf file with "outdated msf condition" is used without invoking mandatory Rebuild-Index, if the "out-dated-msf" folder is accessed/opened as move target folder by filter move, sent mail copy, junk move etc. first

Status: NEW

(MailNews Core :: Database, defect)

Description

[WADA:World Anti-bad-Duping Agency]

+++ This bug was initially created as a clone of Bug #493429 +++

Build Id:
> Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.9.1pre) Gecko/20090527 Shredder/3.0b3pre

If "outdated msf condition" existed for a folder, and if "copy of mail to the folder" happened without explicit folder open, internal Rebuild-Index is not invoked.

[ Test Scenario ]
(0) Local "Test" folder has mail-1(unread), and compacted normally.
    Terminate Thunderbird.
(1) Edit file of "Test" by text editor, and add mail data for mail-2(unread).
    File size of "Test" is increased. (Emulation of power failure)
(2) Restart Thunderbird.
    mail count=1 is displayed for "Test" folder at folder pane.
(3) Never touch "Test" folder,
    and copy unread mail-3 to "Test" folder from other mail folder.
    (emulation of filter move, junk move etc.)
    => Data of mail-3 is added to file of "Test".
    => Timestamp of "Test.msf" is not updated. (If Tb 2, "Test.msf" is deleted.)
    => Open(write mode) of "Test.msf" is successful.
       i.e. "Test.msf" is not opened in write mode by Tb.
    => Mail count of "Test" folder is still 1.
    If step (3) is repeated, same phenomenon is observed.
(4) Move cursor on "Test" folder at folder pane.
    => Next exception is issued in Error Console. (Phenomenon of Bug 493429)
    So, "outdated msf condition" is not resolved at step 3.
> Error: uncaught exception: [Exception... "Component returned failure code: 0x80550005 [nsIMsgFolder.msgDatabase]" nsresult: "0x80550005 (<unknown>)"
> location: "JS frame :: chrome://messenger/content/mailWidgets.xml :: parseFolder :: line 1951"  data: no]

Comment 1

[Wayne Mery (:wsmwk)]

wada, note bug 493429 was WONTFIXED

Comment 2

[ISHIKAWA, Chiaki]

Thank you, Wada san, this is I think what I saw during the testing of
Bug 634544, and I am not sure if I have time to look into this yet.

Comment 3

[WADA:World Anti-bad-Duping Agency]

Following is test result with Tb 24, which was originally reported to bug 905576 comment #187, which was test for bug 931303, bug 931303, bug 905576, and for this bug. See also bug 917769 comment #51.
Message filter looks to call DoCopy of MessageCopyService.
I guess that fault in DoCopy. DoCopy perhaps ignores 0x0550005 error upon MsgDatabase open, or wrongly handles the error.

(copy of bug 905576 comment #187)
Log of "db error opening db 80550005" is not written by MSGDB:5 if filter move, even when "outdated msf condition actually/already exists.
(0) Enable NSPR logging with MSGDB:5,MsgCopyService:5
(1) Filter move target folder=FolderX
    Edit file named FolderX, and appened mail data(Seen bit=Off, so Unread mail)
(2) Run filter. actual move target = AAA/ABC
> request 4d125c0 DoCopy - src  mailbox://hidden%40h.h.h@hidden.h.h.h/Inbox/Sub1A
>                          dest mailbox:// ... /AAA/ABC numItems 4 type=0
> nsMsgDatabase::Open(C:\ ... \Mail\pop.ops.dti.ne.jp\AAA.sbd\ABC.msf, FALSE, 7341080, TRUE)
> closing database    C:\ ... \Mail\pop.ops.dti.ne.jp\AAA.sbd\ABC.msf
>   Open/close is executed for each moved mail,
>   and finally closed.
> nsMsgDatabase::Open(C:\ ... Mail\pop.ops.dti.ne.jp\AAA.sbd\ABC.msf, FALSE, 7341080, TRUE)
> closing database    C:\ ... \Mail\pop.ops.dti.ne.jp\AAA.sbd\ABC.msf
> NotifyCompletion - src  mailbox://hidden%40h.h.h@hidden.h.h.h/Inbox/Sub1A
>                    dest mailbox:// ... /AAA/ABC
> request 4d125c0 Clearing OK request
>   - src  mailbox://hidden%40h.h.h@hidden.h.h.h/Inbox/Sub1A
>     dest mailbox:// ... /AAA/ABC numItems 4 type=0
(a) As seen in log, "db error opening db 80550005(or 80550006)" is not written,
    even though outdated maf condition actually exists.
    This is perhaps due to difference of "MsgDB Open request type when DoCopy" from
    "MsgDB open type when explicit folder open". 
(b) MsgDBHdrAdded   event is not invoked at move target folder
    MsgDBHdrDeleted event is invoked at move source folder
(3) Open Virtual Folder which has "move target folder" in search target folder.
Following log is written, and rebuild-index is executed on move target folder, then Unread count of the move target folder is updated at folder pane.
> nsMsgDatabase::Open(C:\DOCUME~1\wada\LOCALS~1\Temp\MozillaMailnews\ABC.msf, FALSE, 73f04b0, TRUE)
> error opening db 80550006

Comment 4

[WADA:World Anti-bad-Duping Agency]

As known by bug 905576, rebuild-index is automatically/internally invoked when broken .msf is opened by Virtual Folder.
So, if Repair Folder is frequetly needed, defining many "filter move target folders" as "search target folder of Virtual Folder" may be helpful.
And, "getting NSPR log with MSGDB:5,MsgCopyService:5 in daily use" may help trouble shooting.

Comment 5

[WADA:World Anti-bad-Duping Agency]

If file size of .msf of filter move target folder(...ABC.msf in my test) is intentionally set to ZERO, phenomenon is undaertandable.

(0-1) 10 Unread mails(1KB mail) are held in AAA/ABC. Already Compacted.
    Filesize of ...\ABC.msf == 11KB. Filesize of ...\ABC == 10KB.
(0-2) 10 Unread mails in DEF folder, 10 Unread mails in GHI folder.
    Virual Folder named VF is defined:
      Search Target Folder of VF = ABC, DEF
      => Unread mail count of VF == 30
(1) Terminate Tb, Delete content of ...ABC.msf by Text Editor.
    Filesize of ...\AAA\ABC.msf == ZERO.
    This is emulation of following;
    - User's folder recovery by "delete msf file"
    - Somehow .msf file is cleared by Tb or someone else => Filesize=ZERO, null content
(2) Restart Tb => Unread mail count of ABC==10, Unread mail count of VF==30.
(3) When no one opened ABC folder or no one accessed msgDatabase for ABC,
    (msgDatabase is not opened yet and is not cached yet)
    move an 1KB Unread mail to ABC by message filter.
    =>
    Because nothing is held in ABC.msf file, "db error opening db 80550005" is written
    by MSGDB:58outdated msf condition is detected, and is returned to DoCopy).
    DoCopy ignores 0x80550005, and uses "initialized msgDatabase object from null data"
    as correct/valid msgDatabase object of ABC folder.
    Because nothing is held in msgDatabase for ABC folder, following occurs.
    - Mail is appened to after EndOfFile => MessageOffset == 10KB
    - MessageKey of the mail moved by filter == 1(or 10KB if Offset is used)
    - Following is set.
      msgFolder.msgDatabase.dBFolderInfo.numMessages       = 1
      msgFolder.msgDatabase.dBFolderInfo.numUnreadMessages = 1
    - 3KB data(heading+MsgDBHdr data of the only mail) is written to ABC.msf file.
    - MsgDBHdrAdded event is normally notified to event listener of ABC folder.
    i.e. "Existent mail data from 0KB to 10KB in file named ABC" is ignored.
         Status == "Only one mail is held in folder named ABC"
    This is same as phenomenon when garbage is held in msgStore file since initial.
    =>
    Unread mail count of ABC = 1 is shown at folder pane.
    Beecause status of msgDatabase is proper, message is normally shown,
    although only one mail is shown at thread pane.
    Beecause status of msgDatabase is proper, ABC folder is normally accessed.
(4) Open VF folder.
    ABC folder is normally accessed by VF
    => Unread mail count is changed from 30 to 21(ABC=1, DEF=10, GHI=10)
(5) Repair Folder of ABC folder
    => All mail data from Offset=ZERO to 10KB+1KB in file named ABC is reparsed,
       then 11 Unread mail is shown in ABC folder.
    => When VF folder is opened again, 31 Unread mails are shown in VF folder.

In above case, problem is merely that "all mail data from Offset=ZERO to EndOfFile before filter move" is completely ignored. Problem on msgDatabase won't occur, because msgDatabase itself was re-generated from scratch.

However, if actual "outdated msf condition" happened, existent "outdated msf condition" can be cleared without madatory rebuild-index, if msgDatabase is closed and ABC.msf is physically written(currently correct fileSize/fileDate is written in ABC.msf file).
However written ABC.msf data == "ABC.msf data of outdated-msf-state" + "MsgDBHdr data for newly appended mail". This ABC.msf data may be "broken .msf data". So, something bad can occur until Rebuild-Index will be invoked by someone or by user.
bug 931303, bug 931303, bug 905576 may be this problem.

Comment 6

[WADA:World Anti-bad-Duping Agency]

FYI.
If first access to msgFolder.msgDatabase using JavaScript via XPCOM,
"ABC.msf fileSize==ZERO" and "outdated msf condition" can be distinguished by following.
> try{ var summaryValid=msgFolder.msgDatabase.summaryValid; } catch(e){ var summaryValid=e; }
> (1) If ABC.msf is deleted, or ABC.msf conent==null(fileSize=ZERO),
>   msgFolder.msgDatabase.summaryValid = false is returned.
> (2) If"outdated msf" condition is generated in ABC.msf by altering ABC file content,
>   [Exception... "Component returned failure code: 0x80550005 [nsIMsgFolder.msgDatabase]"
>       nsresult: "0x80550005 (<unknown>)"

Comment 7

[WADA:World Anti-bad-Duping Agency]

Additional observation.
(0) Virtual Folder named "FolderV" : search target folder = FolderA, FolderB
    Select other folder named AAA at folder pane, terminate Tb.
(1) Restart Tb.
    Edit FolderA.msf, delete all content, save => fileSize of FolderA.msf==ZERO
    Edit FolderB and copy Unread mail data at bottom, save => outdated msf condition
(2) check msgFolder_of_FolderA.msgDatabase.summarValid by JavaScript
    => summarValid=false is returned. MsgDatabase open itself is OK, and it's cached.
    check msgFolder_of_FolderB.msgDatabase.summarValid by JavaScript
    => Exception with 0x80550005 occurs. MsgDatabase open fails, so it's not cached.
(3) Open Virtual folder named FolderV
    => FolderV tries to open FolderA, FolderB
       FolderA : Unread mail count is changed to ZERO,
                 because number of mail=ZERO is set by msf size=ZERO(no msgDBHdr in .msf)
       FolderB : rebuild index is invoked by open folder due to outdated msf condition,
                 then Unread mail count is updated
    => FolderV : Unread mail count is updated
(4) Select folder named AAA in order to close FolderV, FolderA, FolderB
(5) Don't access any msgFolder_of_FolderA.msgDatabase.??? property including summarValid.
    If accessed, msgDatabase is opened and is cached by this access. 
    Wait for close of FolderA(msf file size=0 => summaryValid=false)
    "Not cached(not opened)" can be confirmed by following.
    var Cached=false;if( MsgDBService.cachedDBForFolder(msgFolder_of_FolderA) )Cached=true;
(6) After FolderA is closed, check msgFolder_of_FolderA.msgDatabase.summarValid
    => open request of FolderA is issued
    => outdated msf condition is raised, perhaps because of summaryInvalid=false
    => Exception with 0x80550005 occurs upon access from JavaScript
(7) Open Virtual folder named FolderV
    => FolderV tries to open FolderA, FolderB
       FolderA : rebuild index is invoked by open folder due to outdated msf condition,
                 then Unread mail count is updated
       FolderB : normally read, because already recovered
    => FolderV : Unread mail count is updated, because FolderA is recovered