824259 - [Exception... "Component returned failure code: 0x80004003 (NS_ERROR_INVALID_POINTER) [nsIMsgDBView.getMsgHdrsForSelection]" nsresult: "0x80004003 (NS_ERROR_INVALID_POINTER)" location: "JS frame :: chrome://messenger/content/folderDisplay.js :: FolderDi

Status: NEW

(Thunderbird :: General, defect)

Description

[ISHIKAWA, Chiaki]

This is about Thunderbird from comm-central:

hg identify
99fd4744910d+ tip

When I run "make mozmill" check under MOZOBJ
I get the following line in the log:


TEST-START | /TB-NEW/TB-3HG/new-src/mail/test/mozmill/folder-display/test-savedsearch-reload-after-compact.js | test_setup_virtual_folder_and_compact
Step Pass: {"function": "Controller.keypress()"}
[Exception... "Component returned failure code: 0x80004003 (NS_ERROR_INVALID_POINTER) [nsIMsgDBView.getMsgHdrsForSelection]"  nsresult: "0x80004003 (NS_ERROR_INVALID_POINTER)"  location: "JS frame :: chrome://messenger/content/folderDisplay.js :: FolderDisplayWidget.prototype.selectedMessages :: line 2010"  data: no]
-- Exception object --
+ QueryInterface (function) 3 lines
+ message (string) 'Component returned failure code: 0x80004003 (NS_ERROR_INVALID_POINTER) [nsIMsgDBView.getMsgHdrsForSelection]'
+ result (number) 2147500035
+ name (string) hg identify
99fd4744910d+ tip
+ filename (string) 'chrome://messenger/content/folderDisplay.js'
+ lineNumber (number) 2010
+ columnNumber (number) 0
+ location (object) JS frame :: chrome://messenger/content/folderDisplay.js :: FolderDisplayWidget.prototype.selectedMessages :: line 2010
+ inner (object) null
+ data (object) null
+ initialize (function) 3 lines
*

Since the failure to catch the error in the JavaScript code properly
indicates there is an error, I am reporting this.

While searching bugzilla using nsIMsgDBView, I thought the following was closest to the error reported here, but then I realize the particular
function mentioned the error log is not quite similar.

Bug 799430 - Error: NS_ERROR_INVALID_POINTER: Component returned failure code: 0x80004003 (NS_ERROR_INVALID_POINTER) [nsIMsgDBView.open] when clicking the Templates/Drafts/Junk folder in Unified folder view

(But the date the above bug was filed indicates that a similar bug might have manifested in the last month or so?)

TIA

Comment 1

[ISHIKAWA, Chiaki]

Attachment: Log to show the problem.

OK, here is an update on this bug. (Hmm, it was almost three months...)

I am attaching the log for the single test:

   make SOLO_TEST=folder-display//test-savedsearch-reload-after-compact.js mozmill-one

Quote from the test:

   * We delete the first message in the local folder, so compaction of the
   * folder will invalidate the key of the second message in the folder. Then,
   * we select the second message and issue the compact. This causes saving the
   * selection on the compaction notification to fail. We test the saved search
   * view still gets rebuilt, such that there is a valid msg hdr at row 0.

The test cause the following uncaught error to be printed in the
session log (the dump on the tty console where the test is run).
This looks bad, a serious error is not caught by JavaScript routine.
e.g:

[Exception... "Component returned failure code: 0x80004003 (NS_ERROR_INVALID_POINTER) [nsIMsgDBView.getMsgHdrsForSelection]"  nsresult: "0x80004003 (NS_ERROR_INVALID_POINTER)"	 location: "JS frame :: chrome://messenger/content/folderDisplay.js :: FolderDisplayWidget.prototype.selectedMessages :: line 1993"  data: no]
-- Exception object --
+ QueryInterface (function) 3 lines
+ message (string) 'Component returned failure code: 0x80004003 (NS_ERROR_INVALID_POINTER) [nsIMsgDBView.getMsgHdrsForSelection]'
+ result (number) 2147500035
+ name (string) 'NS_ERROR_INVALID_POINTER'
+ filename (string) 'chrome://messenger/content/folderDisplay.js'
+ lineNumber (number) 1993
+ columnNumber (number) 0
+ location (object) JS frame :: chrome://messenger/content/folderDisplay.js :: FolderDisplayWidget.prototype.selectedMessages :: line 1993
+ inner (object) null
+ data (object) null
+ initialize (function) 3 lines
*

I sprinkled a few comments in the attached log since I inserted a few
fprintf() statements, the line numbers of WARNING: messages may be a
few lines off, and so I explained where they come from to be sure
the line numbers are not confusing .

I am not sure what the test is doing, especially about the rebuilt-part:.
"We test the saved search view still gets rebuilt, 
such that there is a valid msg hdr at row 0".
Is the rebuilt supposed to take place automatically?
If so, maybe that is broken now.

Has this ever run successfully before?  I suppose so...
Then somewhere the error crept in.

To my unaided eyes skimming throught the log, there seem to be a few
cached search results, and I am afraid that one of them lingers too
long EVEN AFTER the compaction which, according to the comment in the
test, would have made the cached results invalid if I am not mistaken.
(But that is an early conjecture.)

:aceman, you will be interested in this. I say this
because "compaction" of a virtual folder is something
that deals primarily with index, msgKey and such and
file size doesn't matter (!)

Also, note the long series of WARNING lines due to the failures of
pusher.Push(aBoundElement) in the teardownModule processing.

So this is from the teardonw module. I changed a line in
comm-central/mozilla/content/base/src/nsContentUtils.cpp so that an
error in nsCxPusher::Push(nsIDOMEventTarget *aCurrentTarget) does not
print WARNING: line.  This precedes each and every line of the form
WARNING: NS_ENSURE_TRUE(pusher.Push(aBoundElement)) failed: file
/COMM-CENTRAL/comm-central/mozilla/content/xbl/src/nsXBLProtoImplMethod.cpp,
line 308 and expanded the size of log file very much.

Oh, about the verbosity of the warning.

I don't believe there are any real differences.

BUT, note that the mozmill test involves

  invoking setupModule

  bulk of test(s)

  invoking teardownModule

Even for a single test using SOLO_TEST syntax such as

   make SOLO_TEST=folder-display//test-savedsearch-reload-after-compact.js mozmill-one

the number of lines (warnings and various information) printed from
setupModule and teardownModule remain the same.

So you may get the feeling that the log file is rather large for a
single smallish test in comparison to log that invokes
many tests such as the whole "make mozmill".

If you simply divide the number of lines by the number of tests performed, 

   lines/tests

you will get much higher ratio for a single test like this one.

TIA

Comment 2

[ISHIKAWA, Chiaki]

Attachment: Log with the error state in GetSearchResultsTable that leads to the error.

Here is a log to show the error state in the function GetSearchResults() 
that leads to the error reported.

The error is reported/thrown in the JavaScript code below:
(marked with *-> at the beginning of the line. )

  /**
   * Provides a list of the message headers for the currently selected messages.
   *  If summarizeSelectionInFolder is true, then any collapsed thread roots
   *  that are selected will also (conceptually) have all of the messages in
   *  that thread selected and they will be included in the returned list.
   *
   * If the user has right-clicked on a message, this will return that message
   *  (and any collapsed children if so enabled) and not the selection prior to
   *  the right-click.
   *
   * @return a list of the message headers for the currently selected messages.
   *     If there are no selected messages, the result is an empty list.
   */
  get selectedMessages() {
    if (!this.view.dbView)
      return [];
    // getMsgHdrsForSelection returns an nsIMutableArray.  We want our callers
    //  to have a user-friendly JS array and not have to worry about
    //  QueryInterfacing the values (or needing to know to use fixIterator).
    return [msgHdr for
              (msgHdr in fixIterator(
*->                       this.view.dbView.getMsgHdrsForSelection(),
                          Components.interfaces.nsIMsgDBHdr))];
  },

I have instrumented the getMSgHdrsForSelection() in
mailnews/base/src/nsMsgDBView.cpp as follows.
The debug messages shown in the log are produced by the changes.


NS_IMETHODIMP nsMsgDBView::GetMsgHdrsForSelection(nsIMutableArray **aResult)
{
  nsMsgViewIndexArray selection;
  GetSelectedIndices(selection);
  uint32_t numIndices = selection.Length();

  nsresult rv;
  nsCOMPtr<nsIMutableArray> messages(do_CreateInstance(NS_ARRAY_CONTRACTID, &rv));
#if DEBUG
  if(rv != NS_OK)
    fprintf(stderr,"do_CreateInstance failed:rv=%08x, numIndices=%d\n", rv, numIndices);
#endif
  NS_ENSURE_SUCCESS(rv, rv);
  rv = GetHeadersFromSelection(selection.Elements(), numIndices, messages);
#if DEBUG
  if(rv != NS_OK)
    fprintf(stderr,"GetHeadersFromSelection failed. "
            "rv=0x%08x, numIndices=%d\n", rv, numIndices);
#endif
  NS_ENSURE_SUCCESS(rv, rv);
  messages.forget(aResult);
  return rv;
}

Messages printed by GetSearchResultsTable() is by the changes to the
file mailnews/db/msgdb/src/nsMsgDatabase.cpp.
I am attaching the patch as next attachment.

I hope the log with the sprinkled messages will help us here.

Comment 3

[ISHIKAWA, Chiaki]

Attachment: Changes to GetSearchResultsTable() and a few others to obtain internal state.

Changes to print the messages found in the previous log.

Comment 4

[ISHIKAWA, Chiaki]

Attachment: More detailed log that shows something went bust after compaction.

With the patch to a few functions, which follows this upload, I printed out more detailed outputfrom routines about the use of internal cache and such.
This attached log clearly shows that something went wrong after the compaction.
(The binary was created from comm-central under 64bits linux and a few extra messages that were meant to debug 4GB mail folder issues, etc.)
Here is the crux of the log:


At the steady state, so to speak, starting from GetSearchResultsTable(),
we hit an internal cache entry to retrieve header information.
But once the compaction happend, something went wrong.
Cache no longer works (I think we should expect this.)

But some required processing is forgotten, and the internal data
structure becomes incorrect/corrupt, and header information can't be
found any more once.

*HOWEVER*, after a couple of GetSearchResultsTable calls (first is to
look for an entry and found the table is not there, the second is to
create the search table (I think)), the cache seems to work again(!),
and by this time, the internal data structure seems to be A-OK again.


	    ... omissions ...
GetSearchResultsTable:StringToToken()=0x00000000, searchFolderUri=mailbox://nobody@Local%20Folders/SavedSearch
GetSearchResultsTable: GetTableKind()=0x00000000, numTables=0, *table=0x5b8fd28
nsMsgSearchDBView::GetMsgHdrForViewIndex index=0, m_folders.Count()=1
GetMsgHdrForKey: pmsgHdr=0x7fff6a976750, m_mdbAllMsgHeadersTable=0x2ea1fe8, m_mdbStore=0x2ea41b8
GetHdrFromUseCache returned err=0x00000000, *pmsgHdr=0x56852e0
Use the result from GetHdrFromUseCache returned err=0x00000000
GetMsgHdrForViewIndex:GetMsgHdrForKey returned error: rv=0x00000000
GetMsgHdrForViewIndex: returns rv = 0x00000000
nsMsgSearchDBView::GetMsgHdrForViewIndex index=0, m_folders.Count()=1
GetMsgHdrForKey: pmsgHdr=0x7fff6a9766d0, m_mdbAllMsgHeadersTable=0x2ea1fe8, m_mdbStore=0x2ea41b8
GetHdrFromUseCache returned err=0x00000000, *pmsgHdr=0x56852e0
Use the result from GetHdrFromUseCache returned err=0x00000000
GetMsgHdrForViewIndex:GetMsgHdrForKey returned error: rv=0x00000000
GetMsgHdrForViewIndex: returns rv = 0x00000000
		       ...
		       ... many similar lines
		       ...
GetMsgHdrForKey: pmsgHdr=0x7fff6a9766d0, m_mdbAllMsgHeadersTable=0x2ea1fe8, m_mdbStore=0x2ea41b8
GetHdrFromUseCache returned err=0x00000000, *pmsgHdr=0x56852e0
Use the result from GetHdrFromUseCache returned err=0x00000000
GetMsgHdrForViewIndex:GetMsgHdrForKey returned error: rv=0x00000000
GetMsgHdrForViewIndex: returns rv = 0x00000000
nsMsgSearchDBView::GetMsgHdrForViewIndex index=0, m_folders.Count()=1
GetMsgHdrForKey: pmsgHdr=0x7fff6a9764a0, m_mdbAllMsgHeadersTable=0x2ea1fe8, m_mdbStore=0x2ea41b8
GetHdrFromUseCache returned err=0x00000000, *pmsgHdr=0x56852e0
Use the result from GetHdrFromUseCache returned err=0x00000000
GetMsgHdrForViewIndex:GetMsgHdrForKey returned error: rv=0x00000000
GetMsgHdrForViewIndex: returns rv = 0x00000000
GetMsgHdrForKey: pmsgHdr=0x5b52948, m_mdbAllMsgHeadersTable=0x2ea1fe8, m_mdbStore=0x2ea41b8
GetHdrFromUseCache returned err=0x00000000, *pmsgHdr=0x56852e0
Use the result from GetHdrFromUseCache returned err=0x00000000
offset = 0
key sent to EnsureKeyExists = 0
row for the key created.
new key = 0
EndCopy                        <--- compaction happened: my message from EndCopy().
key sent into hdr = 0
key sent to EnsureKeyExists = 0
nsMsgSearchDBView::GetMsgHdrForViewIndex index=0, m_folders.Count()=1
GetMsgHdrForKey: pmsgHdr=0x7fff6a972c80, m_mdbAllMsgHeadersTable=0x2ea49d8, m_mdbStore=0x5b224f8
GetHdrFromUseCache returned err=0x80004005, *pmsgHdr=(nil)
		   <--- cache no longer works.
key =283, m_hdrRowScopeToken=0x00000080           
GetMsgHdrForKey: hasOid returned err=0x00000000  <--- hasOid returned OK, but
hdrRow was NULL                                  <--- hdrRow was NULL !? Why, oh, why?
GetMsgHdrForKey: finally returned err=0x80004003  <--- This error propagates to the JavaScript error.
GetMsgHdrForViewIndex:GetMsgHdrForKey returned error: rv=0x80004003
GetMsgHdrForViewIndex: returns rv = 0x80004003
GetHeadersFromSelection: GetMsgHdrForViewIndex failed, rv=0x80004003, viewIndex=0, index=0, numIndices=1
GetHeadersFromSelection failed. rv=0x80004003, numIndices=1
WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004003: file /COMM-CENTRAL/comm-central/mailnews/base/src/nsMsgDBView.cpp, line 2434
[Exception... "Component returned failure code: 0x80004003 (NS_ERROR_INVALID_POINTER) [nsIMsgDBView.getMsgHdrsForSelection]"  nsresult: "0x80004003 (NS_ERROR_INVALID_POINTER)"  location: "JS frame :: chrome://messenger/content/folderDisplay.js :: FolderDisplayWidget.prototype.selectedMessages :: line 2028"  data: no]
-- Exception object --
+ QueryInterface (function) 3 lines
+ message (string) 'Component returned failure code: 0x80004003 (NS_ERROR_INVALID_POINTER) [nsIMsgDBView.getMsgHdrsForSelection]'
+ result (number) 2147500035
+ name (string) 'NS_ERROR_INVALID_POINTER'
+ filename (string) 'chrome://messenger/content/folderDisplay.js'
+ lineNumber (number) 2028
+ columnNumber (number) 0
+ location (object) JS frame :: chrome://messenger/content/folderDisplay.js :: FolderDisplayWidget.prototype.selectedMessages :: line 2028
+ inner (object) null
+ data (object) null
+ initialize (function) 3 lines
*
GetSearchResultsTable:StringToToken()=0x00000000, searchFolderUri=mailbox://nobody@Local%20Folders/SavedSearch
GetSearchResultsTable: GetTableKind()=0x00000000, numTables=0, *table=0x5b8fc38
GetSearchResultsTable:StringToToken()=0x00000000, searchFolderUri=mailbox://nobody@Local%20Folders/SavedSearch
GetSearchResultsTable: GetTableKind()=0x00000000, skipped numTables, *table=(nil)
WARNING: NS_ENSURE_SUCCESS(err, err) failed with result 0x80004005: file /COMM-CENTRAL/comm-central/mailnews/db/msgdb/src/nsMsgDatabase.cpp, line 5956
	 <--- GetSearchResultsTable() error in GetCachedHits()
GetSearchResultsTable:StringToToken()=0x00000000, searchFolderUri=mailbox://nobody@Local%20Folders/SavedSearch
GetSearchResultsTable: GetTableKind()=0x00000000, numTables=0, *table=0x5b8fc38
GetSearchResultsTable:StringToToken()=0x00000000, searchFolderUri=mailbox://nobody@Local%20Folders/SavedSearch
GetSearchResultsTable: GetTableKind()=0x00000000, skipped numTables, *table=(nil)
GetSearchResultsTable: NewTable()=0x00000000, *table=0x5b72c18
nsMsgSearchDBView::GetMsgHdrForViewIndex index=0, m_folders.Count()=1
GetMsgHdrForKey: pmsgHdr=0x7fff6a976750, m_mdbAllMsgHeadersTable=0x2ea49d8, m_mdbStore=0x5b224f8
GetHdrFromUseCache returned err=0x00000000, *pmsgHdr=0x5bf4320
Use the result from GetHdrFromUseCache returned err=0x00000000
GetMsgHdrForViewIndex:GetMsgHdrForKey returned error: rv=0x00000000
GetMsgHdrForViewIndex: returns rv = 0x00000000
nsMsgSearchDBView::GetMsgHdrForViewIndex index=0, m_folders.Count()=1
GetMsgHdrForKey: pmsgHdr=0x7fff6a9766d0, m_mdbAllMsgHeadersTable=0x2ea49d8, m_mdbStore=0x5b224f8
GetHdrFromUseCache returned err=0x00000000, *pmsgHdr=0x5bf4320
Use the result from GetHdrFromUseCache returned err=0x00000000
    	<--- Wow, cache becomes valid again! 
	<--- We can peform similar processing to make the cache valid again, I suppose.
	<--- But exactly what should we do?
	<--- Like the above, we search for something and if we found the internal table is nil?
	<--- create it by passing create table flag to GetSearchResultsTable()?

GetMsgHdrForViewIndex:GetMsgHdrForKey returned error: rv=0x00000000
GetMsgHdrForViewIndex: returns rv = 0x00000000
nsMsgSearchDBView::GetMsgHdrForViewIndex index=0, m_folders.Count()=1
GetMsgHdrForKey: pmsgHdr=0x7fff6a9764a0, m_mdbAllMsgHeadersTable=0x2ea49d8, m_mdbStore=0x5b224f8
GetHdrFromUseCache returned err=0x00000000, *pmsgHdr=0x5bf4320
Use the result from GetHdrFromUseCache returned err=0x00000000
GetMsgHdrForViewIndex:GetMsgHdrForKey returned error: rv=0x00000000
GetMsgHdrForViewIndex: returns rv = 0x00000000


Hope this helps.

TIA


PS: BTW, please note that even for this simple test, we see
the problem of non-orderly shutdown sequence of various threads near the end of the log.
I am quite convinced that some crashes I see when I try to close thunderbird are related to such issues.

Comment 5

[ISHIKAWA, Chiaki]

Attachment: More changes to print out the messages in the preceding log.

These are the changes made to the comm-source tree additionally to obtain the
detailed log (preceding upload).

TIA

Comment 6

[ISHIKAWA, Chiaki]

(In reply to ISHIKAWA, Chiaki from comment #4)
> Created attachment 797298 [details]
> More detailed log that shows something went bust after compaction.
> 
> 
> At the steady state, so to speak, starting from GetSearchResultsTable(),
> we hit an internal cache entry to retrieve header information.
> But once the compaction happend, something went wrong.
> Cache no longer works (I think we should expect this.)
> 
> But some required processing is forgotten, and the internal data
> structure becomes incorrect/corrupt, and header information can't be
> found any more once.
> 

The test that triggered this is
>TEST-START | /COMM-CENTRAL/comm-central/mail/test/mozmill/folder-display/test-savedsearch-reload-after-compact.js | test_setup_virtual_folder_and_compact

It creates a virtual folder and does compaction.

Below is the code in its entire form.
Note the comment: "...  We test the saved search
   * view still gets rebuilt, such that there is a valid msg hdr at row 0. "

I am a little confused. 
Does virtual folder also creates and header cache? 
Does virtual folder use .msf file?
I suppose it is unlikely (?) Or maybe I am wrong here.
It seems the code leading to the handling of header cache, which is
involved in the original error, is a little flawed in the
case of virtual folder. 
The code seems to assume that .msf is accessed for every folder (including virtual case)
and does a strange processing when .msf is not available (I suppose virtual folder
does not use .msf file, correct?)


/**
 * Test reload of saved searches over local folders after compaction
 * of local folders.
 */

var MODULE_NAME = 'test-vf-load-after-compact';

var RELATIVE_ROOT = '../shared-modules';
var MODULE_REQUIRES = ['folder-display-helpers', 'window-helpers'];

var folderInbox, folderVirtual;

function setupModule(module) {
  let fdh = collector.getModule('folder-display-helpers');
  fdh.installInto(module);
  let wh = collector.getModule('window-helpers');
  wh.installInto(module);
}

/**
 * Add some messages to a folder, delete the first one, and create a saved
 * search over the inbox and the folder. Then, compact folders.
 */
function test_setup_virtual_folder_and_compact() {
  otherFolder = create_folder("otherFolder");
  let [msgSet] = make_new_sets_in_folder(otherFolder, [{count: 2}]);

  /**
   * We delete the first message in the local folder, so compaction of the
   * folder will invalidate the key of the second message in the folder. Then,
   * we select the second message and issue the compact. This causes saving the
   * selection on the compaction notification to fail. We test the saved search
   * view still gets rebuilt, such that there is a valid msg hdr at row 0.
   */
  be_in_folder(otherFolder);
  let curMessage = select_click_row(0);
  press_delete();

  folderVirtual = create_virtual_folder([inboxFolder, otherFolder], {},
                                        true, "SavedSearch");

  be_in_folder(folderVirtual);
  curMessage = select_click_row(0);
  let urlListener = {
    compactDone: false,

    OnStartRunningUrl: function (aUrl) {
    },
    OnStopRunningUrl: function (aUrl, aExitCode) {
      this.compactDone = true;
    }
  };
  if (otherFolder.msgStore.supportsCompaction) {
    otherFolder.compactAll(urlListener, null, false);

    mc.waitFor(function () urlListener.compactDone,
               "Timeout waiting for compact to complete", 30000, 100);
  }
  // Let the event queue clear.
  mc.sleep(100);
  // Check view is still valid
  let msgHdr = mc.dbView.getMsgHdrAt(0);
}


Anyway, trying to modify a few files related to this issue to obtain more information and
what I thought was the correct handling of non-existing .msf file for virtual folder's case,
I now obtain

>Test Failure: Component returned failure code: 0x80550005 [nsIMsgFolder.msgDatabase]

in my session log. This is printed without much
context, etc. :-(
I must have modified files incorrectly. But I am left without much clue what went wrong.
I will ask dev mailing list about this.

TIA

Comment 7

[ISHIKAWA, Chiaki]

Thanks to a help from Joshua Cranmer regarding the error code, I could
home into where the error occurs.

Basically a call to GetRow() returns a null pointer into the out
parameter. This translates into the XPCOM error we see in |make
mozmill| session log.

So why the failure?

After a false start of trying to figure out what is going on with the
handling of virtual folder (saved search folder) that would lead to
GetRow() returning null pointer into the out parameter, I came to a
conclusion that somehow the fact of successful "Compact" is NOT
NOTIFIED PROPERLY to the listener placed by the test program
and that some internal structure
remained stale due to this failure of notification.

Where is the notification supposed to be sent for "compacting a
folder"?  The following piece of code is at the heart of the issue.

http://mxr.mozilla.org/comm-central/source/mailnews/base/src/nsMsgFolderCompactor.cpp#191

191      {
192        bool valid;  
193        rv = db->GetSummaryValid(&valid); 
194        if (!valid) //we are probably parsing the folder because we selected it.
195        {
196          folder->NotifyCompactCompleted();
197          if (m_compactAll)
198            return CompactNextFolder();
199          else
200            return NS_OK;
201        }
202      }
203    }

I found out that, for whatever the reason, during the execution of
|make mozmill| test suite (at least for the particular test that
caused the NS_ERROR_INVALID_POINTER error), |valid| on line 194 is
|true| and thus NotifyCompactCompleted() is never called leading to a
stale data structure, and the failure of GetRow() to return non-null
output.

(Due to the complex internal processing of lower-level functions,
I could not exactly fathom why GetSummaryValid() returns true value
for &valid, and whether it is bad or good at all.)

As a bandage solution, I made a patch locally to call
NotifyCompactCompleted() even if |valid| is |true|. With this local
patch, there was no longer the NS_ERROR_INVALID_POINTER_EXCEPTION when
I ran |make mozmill| test for this particular test target file.

The change in my local fix is rather arbitrary and is a bandage fix.

However, with the cryptic comment on the line 194, I can't exactly
figure out what the test in if() is supposed to accomplish.  Maybe we
need to loosen the check one way or the other, but I have no idea.
The code related to the folder processing is NOT COMMENTED VERY WELL
AT ALL.

(I will test whether such a change will affect thunderbird adversely by running
the full test of |make mozmill| and xpctest for mozmill. But it will take time since I modified the source code heavily and reverting back to pristine state takes time due to disk capacity shortage.).

I would like to hear the opinions of people in the know whether
calling NotifyCompactCompleted() always is a good idea, or if we
should change the condition in if() into somewhat lenient form.  (But
again, since I have no idea what the if() check is supposed to
accomplish, I have no clue about the latter.)

Comments will be appreciated.

TIA

PS: The false start of analyzing the handling of virtual folder 
to see the cause of the exception was not a complete waste.

Although the code is not commented very well, I could discern, based
on copious output from my local modification of TB, a few interesting
things:

(1) The following is what I wrote for my local modification
  of the file
  mailnews/local/src/nsMsgBrkMBoxStore.cpp
  about a function called
  void nsMsgBrkMBoxStore::GetMailboxModProperties()
http://mxr.mozilla.org/comm-central/source/mailnews/local/src/nsMsgBrkMBoxStore.cpp#163

// Say a search result is stored as a search folder with a name, "last-3-days"
// in Local Folder. What files are created?
//
// In the case of virtual folder (under linux), this is what happens.
//
// Two entries are created in the file system.
//  Local Folder/last-3-days.msf  (a standard file)
//  Local Folder/last-3-days      (a directory)
//
//  Subsequently GetMailboxModProperties are called for
//  these file and directory.
//  Tricky part is that GetFileSize for "last-3-days" (since it is a  directory) fails internally and return 0.
//  But we should pretend it is OK :-(
//  Otherwise, the upper logic fails.
//  Hmm...

(2) The very obscure piece of code 
in a function isSummaryFileValid() in the same file
is dealing with virtual (saved search) folder [which is created
as directory.]
http://mxr.mozilla.org/comm-central/source/mailnews/local/src/nsMsgBrkMBoxStore.cpp#243

243   if (folderSize == fileSize && numUnreadMessages >= 0)
244   {
245     if (!folderSize)	<--- This!
246     {
247       *aResult = true;
248       return NS_OK;
249     }

The above code on the line 245 deals with the case of
folderSize == 0 and fileSize == 0 which happens for the virtual folder
(native "directory entry) case.
I wish the code here handles this special case MORE EXPLICITLY
(by stating that this handles special virtual folder case),
and above all else, it had MORE COMMENT LINES!!!

(3) To create folder (real and virtual), TB seems to go through
various DB-open-related functions many times until it gets it right.
(Three or four times. I gave up counting.)

It seems a waste of processing. But getting into a consistent state of
various data objects such as external disk-resident .msf file,
internal cached database for messages (key <-> real message pair???), the
cache for messages displayed (being viewed on the screen.???) seems to
require multiple passes over lower-level open-related functions to get
it right. This part smells of a real legacy code. 
I could not understand the processing
fully after dumping calls with various arguments, etc.

I am attaching the log of failed case and successful case with
relevant function calls, etc. (Not all calls are traced, and not
every single if is traced. Only what seemed important to me 
were traced by liberal use of fprintf(stderr, "...", ...);
Only with this approach, I could figure out that something was wrong
with the internal data processing and could home into the failure of
notification. In hindsight, this is one suspect that ought to have been
investigated early, but the not well commented code was a challenge in
itself :-(

Comment 8

[ISHIKAWA, Chiaki]

Attachment: The session log with copious debug output when INVALID POINTER error is thrown.

This is the session log of locally modified TB to print out various data and relevant function calls.
Note the following line about 3/4 into the file:
WARNING: (debug) Compact: NOT calling NotifyCompact Completed (valid).

Because the notification is not sent to the rest of TB, the
failure occurs.

Log for successful session follows.

Comment 9

[ISHIKAWA, Chiaki]

Attachment: Log of successful session : calling NotifyCompactCompleted() even if IsSummaryFileValid() produces |true| out parameter

This is a session log of successful case. The INVALID POINTER is not
thrown any more.

Please note the following lines about 70% into the file:
WARNING: (debug) Compact: NOT calling NotifyCompact Completed (valid).
WARNING: (debug) Compact: We forcibly call it: a bandage fix... (valid).

NotifyCompactCompleted() is called irrespective of the value of |valid|
preceding the call.
This fixes the problem for this particular test.

I am preparing the full run of |make mozmill| after restoring the source to
the pristine state and only apply this change.

TIA

Comment 10

[ISHIKAWA, Chiaki]

IMHO, the not-well-commented lines of certain parts of TB are not quite amenable to
"community supported software" idea.
Unless we comment these lines of code very well before people familiar with the code
disappear from the scene one by one, we are doomed. TB will face a bit rot in the next 12 months or so, I am afraid.

Think about it. This exception was there for all to see in the thunderbird mozmill test log
since last year (at least in December or something) and presumably for much longer, and nobody noticed???
(Maybe noticed, but there was no clue to where to begin. The not-well-commented lines in some parts
of TB code pose too high a barrier for casual "community support", I am afraid.)
Just a thought.

Comment 11

[Magnus Melin [:mkmelin]]

Can't comment on the rest, but if you find stuff that need commenting, comment patches are likely accepted :)

Comment 12

[ISHIKAWA, Chiaki]

(In reply to Magnus Melin from comment #11)
> Can't comment on the rest, but if you find stuff that need commenting,
> comment patches are likely accepted :)

Thank you :-)
I will first upload comment-only patches to a few files.

After figuring out the correct patch, I will modify the file(s) accordingly.

TIA

Comment 13

[ISHIKAWA, Chiaki]

Cleaning up modified files to pristine state after so many #if DEBUG
DEBUG/#endif turned out to be a problem (even with hg source revision
control). I need to separate the comment changes and #if DEBUG/#endif
changes. Hmm... So I am pulling out a new pristine source and have
begun applying patches one by one. There are OTHER pathces that need
sorting out, too.

With the patch, I could test the successful operation of the 
single mozmill target file using SOLO_TEST.
But strangely, if I ran all the |mozmill| test as a whole, this
particular test target won't finish (due to some strange error
message.)
This is another reason I am trying with the newly freshed pristine
source.

It is possible fixing several bugs in this year may have unearthed a
dormant problem in mozmill test program(s) that was hidden since the
execution path did not hit it in the past due to other bugs
terminating tests prematurely.

In the meantime, here is a comparison of the surrouding code where
NotifyCompactCompleted() is called. 

Comparing similar codes, I am inclined to believe that we can possibly
remove this |!valid| check on lin 194.  OR, we could argue that
|!valid| test is missing in other places even.

I really wonder if someone knows the history of |!valid| test.


Comparisoin of NotifyCompatcCompleted()

(1) This is the case under discussion.			 

156 nsFolderCompactState::Compact(nsIMsgFolder *folder, bool aOfflineStore,
157 156 nsFolderCompactState::Compact(nsIMsgFolder *folder, bool aOfflineStore,
157 
      else
191      {
192        bool valid;  
193        rv = db->GetSummaryValid(&valid); 
194        if (!valid) //we are probably parsing the folder because we selected it.
195        {
196          folder->NotifyCompactCompleted();
197          if (m_compactAll)
198            return CompactNextFolder();
199          else
200            return NS_OK;
201        }
202      }

(2) A call inside function Compact().
    This is where a Lock was not available.

    I think we ought to call NotifyCompactCompleted() no matter what
    to proceed before signalling the error.

226    else
227    {
228      m_folder->NotifyCompactCompleted();
229      m_folder->ThrowAlertMsg("compactFolderDeniedLock", m_window);
230      CleanupTempFilesAfterError();
231      if (m_compactAll)
232        return CompactNextFolder();
233      else
234        return NS_OK;
235    }

(3) A call inside the function FinishCompact.

    I wonder why this does not have similar tst (|!valid|) as in case
    (1).
    

370 nsresult
371 nsFolderCompactState::FinishCompact()
372 {

523 
524   // Notify that compaction of the folder is completed.
525   nsCOMPtr<nsIMsgFolderNotificationService>
526     notifier(do_GetService(NS_MSGNOTIFICATIONSERVICE_CONTRACTID));
527   if (notifier)
528     notifier->NotifyItemEvent(m_folder,
529                               NS_LITERAL_CSTRING("FolderCompactFinish"),
530                               nullptr);
531   m_folder->NotifyCompactCompleted();
532 
533   if (m_compactAll)
534     rv = CompactNextFolder();
535   else
536     CompactCompleted(NS_OK);
537       

(4)  Inside OnStopRequest.

     In OnStopRequsst(case 4, and case 5), 
     I think we should call NotifyCompactCompleted() no matter what.


622 NS_IMETHODIMP
623 nsFolderCompactState::OnStopRequest(nsIRequest *request, nsISupports *ctxt,
624                                     nsresult status)
625 {
626   nsCOMPtr<nsIMsgDBHdr> msgHdr;
627   nsCOMPtr<nsIMsgDBHdr> newMsgHdr;
628   if (NS_FAILED(status))
629   {
630     m_status = status; // set the m_status to status so the destructor can remove the
631                        // temp folder and database
632     m_folder->NotifyCompactCompleted();
633     ReleaseFolderLock();
634   }
635   else

(5)   Inside OnStopRequest.

	OnStopRequest()

 else
646     {
647       // in case we're not getting an error, we still need to pretend we did get an error,
648       // because the compact did not successfully complete.
649       m_folder->NotifyCompactCompleted();
650       CleanupTempFilesAfterError();
651       ReleaseFolderLock();
652     }

(6)	FinishCompact

	I wonder why this does not have (!valid) test simialr to the
	case (1) above.


1033 nsresult
1034 nsOfflineStoreCompactState::FinishCompact()
1035 {

    // rename the copied folder to be the original folder 
1071   m_file->MoveToNative((nsIFile *) nullptr, leafName);
1072 
1073   ShowStatusMsg(EmptyString());
1074   m_folder->NotifyCompactCompleted();
1075   if (m_compactAll)
1076     rv = CompactNextFolder();

Comment 14

[ISHIKAWA, Chiaki]

(I am running freshly fetched source files.
They mysterious error I referred to in my post was not
caused by a uninteneded change in my local mods, but
rather a problem : 
Bug 918267 - orange: test-session-store.js | test-session-store.js::test_clean_shutdown_session_persistence_simple

I saw this message along with a myserious failure, and so
am re-checking with the new source which presumably fixed bug 918267.

Stay tuned. I hope I can get rid of the INVALID POINTER error from this particular test target for good.

TIA

Comment 15

[Magnus Melin [:mkmelin]]

the !valid test comes from http://bonsai.mozilla.org/cvsblame.cgi?file=mozilla/mailnews/base/src/nsMsgFolderCompactor.cpp&rev=1.84&mark=215#215 -> bug 136784 where it is actually explained

Comment 16

[ISHIKAWA, Chiaki]

(In reply to Magnus Melin from comment #15)
> the !valid test comes from
> http://bonsai.mozilla.org/cvsblame.cgi?file=mozilla/mailnews/base/src/
> nsMsgFolderCompactor.cpp&rev=1.84&mark=215#215 -> bug 136784 where it is
> actually explained

Thank you for the pointer.
I will try to see if I can digest the thread and understood the subtle issues.

A problem I noticed already.
 - there is no mozmill test for the scenario explained in bug 136784. (or is there? The test files
are very irregular in terms of the amount of comments inside. Some are very well commented, but
not many are commented well.)

 - I am afraid that no mozmill test seems to cover all the code paths mentioned in my comment 13.

Anyway, I will try to re-create the situation mentioned in the scenario and
why the particular mozmill test seemed to produce the error (INVALID POINTER).