557050 - [Windows, SeaMonkey (2.1)] xpcshell-tests: 28 MailNews tests fail with "ASSERTION: unable to initialize resource / nsRDFService.cpp", due to Windows (O.E.) A.B. not being disabled

Status: VERIFIED FIXED

(MailNews Core :: Networking: SMTP, defect)

Description

[Serge Gautherie (:sgautherie)]

(I overlooked this one until now because of bug 541235 :-<)

{
http://tinderbox.mozilla.org/showlog.cgi?log=SeaMonkey/1270333452.1270335188.28875.gz
WINNT 5.2 comm-central-trunk debug test xpcshell on 2010/04/03 15:24:12

TEST-PASS | e:\builds\slave\comm-central-trunk-win32-debug-unittest-xpcshell\build\xpcshell\tests\test_compose\unit\test_bug155172.js | test passed

command timed out: 1200 seconds without output
program finished with exit code 1
}

Sadly, the test log is not printed in this case :-/

Comment 1

[Serge Gautherie (:sgautherie)]

Ftr, it passes on:
http://tinderbox.mozilla.org/showlog.cgi?log=SeaMonkey2.0/1270298085.1270306165.3014.gz&fulltext=1
WINNT 5.2 comm-1.9.1 unit test on 2010/04/03 05:34:45
and
http://tinderbox.mozilla.org/showlog.cgi?log=Thunderbird/1270329217.1270333203.25810.gz&fulltext=1
WINNT 5.2 comm-central check on 2010/04/03 14:13:37

Then the issue should be related to package-tests.

Comment 2

[Serge Gautherie (:sgautherie)]

[Mozilla/5.0 (Windows; U; Windows NT 5.0; en-US; rv:1.9.3a4pre) Gecko/20100328 SeaMonkey/2.1a1pre] (comm-central-trunk-win32-debug/1269807367)

I don't reproduce locally, running either the test alone or the test_compose/unit/ directory.

KaiRo, could you try to reproduce (to get the test output/log) on a tinderbox?

Comment 3

[Robert Kaiser]

I won't manually try to mess around on buildbot machines.

Comment 4

[Serge Gautherie (:sgautherie)]

(In reply to comment #3)

How should we proceed then?

Comment 5

[Robert Kaiser]

(In reply to comment #4)
> (In reply to comment #3)
> 
> How should we proceed then?

No idea, have you tried with the actual build and test packages from our machines?

It's just that for manual testing, I need to take out a long time of work as I don't know how even to do it and I need to take a machine off the buildbot pool to have no disturbances, and I need to work on a not too responsive remote screen, etc. and that is really more than suboptimal and messing with a system that is made for automatic execution and not manual messing around.

Comment 6

[Robert Kaiser]

Is it possible that this is a variant of the same problem as we have with mailnews tests on the other platforms?

Comment 7

[Serge Gautherie (:sgautherie)]

(In reply to comment #5)

> have you tried with the actual build and test packages from our machines?

I tried that in comment 2.

> It's just that for manual testing

At first, you just need to check what is going on during the 20 mn timeout: no need to mess with anything...

Comment 8

[Serge Gautherie (:sgautherie)]

(In reply to comment #6)
> Is it possible that this is a variant of the same problem as we have with
> mailnews tests on the other platforms?

It might be, but that's impossible to tell without any clue.

Comment 9

[Robert Kaiser]

(In reply to comment #7)
> At first, you just need to check what is going on during the 20 mn timeout: no
> need to mess with anything...

Any going in and doing stuff in the shell is "messing around" IMHO and I have a ton of other stuff to do, I have no time to risk that.

Comment 10

[Robert Kaiser]

One thing probably worth noting is that every time I log into the Windows machines, I have Windows crash prompts shown, that seem to originate from xpcshell.exe - might that be related in some way?

Comment 11

[Serge Gautherie (:sgautherie)]

(In reply to comment #10)

> One thing probably worth noting is that every time I log into the Windows
> machines, I have Windows crash prompts shown, that seem to originate from

Yeah, Windows crash prompts are exactly the sort of things I was thinking about!
I don't know in this very case, but we know they disturbed things in the past.

Maybe what is missing is an auto-cleanup of them: like killing "drwatson.exe" processes or the like?
(I assume the "auto-reboot" feature Firefox boxes have would somehow help in such cases...)

> xpcshell.exe - might that be related in some way?

At least, it would be good to narrow down what causes these crashes.
First question is: is it this very test or remnants of unrelated crashes/runs?

Comment 12

[Serge Gautherie (:sgautherie)]

(In reply to comment #11)
> (I assume the "auto-reboot" feature Firefox boxes have would somehow help in
> such cases...)

I filed bug 558873.

Comment 13

[Robert Kaiser]

OK, we are definitely crashing exactly where we are "timing out", and the debugger I have forgotten to switch off in one of the boxes shows that the crash is in dbgheap.c free() and I suspect that we are actually crashing in the msvcr80d.dll!free which is quite far up in the call stack, which might explain why we don't catch the crash correctly.

Comment 14

[Robert Kaiser]

umm, even more fun: when I close the crash prompt in time before xpcshell-tests times out, it says "TEST-PASS" etc. and continues, so it sounds like a shutdown crash in that test, maybe debug-only.

Comment 15

[Robert Kaiser]

One more detail: Multiple other tests crashed - probably the same way - during my run of the composer tests on that machine, but else all but one succeeded and the test suite ended itself correctly.

Comment 16

[Robert Kaiser]

Yay, now that I updated all our Windows slaves to not show any Windows or MSVC crash prompts (I expect that the install of the Win7 SDK might have re-set that unintentionally), we do not hang or time out any more, it seems!

Comment 17

[Robert Kaiser]

OK, so the test now really reports TEST-PASS, but after that an assertion, a leak (I'll leave that out), and a crash:

TEST-INFO | (xpcshell/head.js) | test 1 pending
TEST-INFO | (xpcshell/head.js) | test 1 finished
TEST-INFO | (xpcshell/head.js) | exiting test
TEST-PASS | e:/builds/slave/comm-central-trunk-win32-debug-unittest-xpcshell/build/xpcshell/tests/test_compose/unit/test_bug474774.js | [anonymous : 32] true == true
### ERROR: SymGetModuleInfo64: The specified module could not be found.

###!!! ASSERTION: unable to initialize resource: 'Error', file e:/builds/slave/comm-central-trunk-win32-debug/build/mozilla/rdf/base/src/nsRDFService.cpp, line 1030
addrbook!NSGetModule+0x0000000000046A5E
addrbook!NSGetModule+0x000000000001ED21
addrbook!NSGetModule+0x000000000001F2B0
addrbook!NSGetModule+0x000000000001EFD7
addrbook!NSGetModule+0x0000000000002BF1
addrbook!NSGetModule+0x0000000000037768
addrbook!NSGetModule+0x0000000000037DA3
addrbook!NSGetModule+0x0000000000037C5E
msgcompo!NSGetModule+0x00000000000409CC
msgcompo!NSGetModule+0x0000000000040676
msgcompo!NSGetModule+0x0000000000042902
msgcompo!NSGetModule+0x000000000004996C
msgcompo!NSGetModule+0x000000000004877A
msgbsutl!nsMsgDBFolder::GetPurgeThreshold+0x000000000005E04D
msglocal!NSGetModule+0x000000000003DDE9
necko!NSGetModule+0x000000000002807D
necko!NSGetModule+0x0000000000027A4F
xpcom_core!nsLinebreakConverter::ConvertStringLineBreaks+0x0000000000000EAA
xpcom_core!nsEventQueue::PutEvent+0x000000000000811A
xpcom_core!NS_InvokeByIndex_P+0x0000000000000027
xpc3250!DumpJSValue+0x0000000000061518
xpc3250!DumpJSValue+0x000000000006FDBB
### ERROR: SymGetModuleInfo64: The specified module could not be found.

Leaked URLs:
   [too many to list here]
nsStringStats
 => mAllocCount:           5771
 => mReallocCount:          245
 => mFreeCount:            4907  --  LEAKED 864 !!!
 => mShareCount:           3896
 => mAdoptCount:           1203
 => mAdoptFreeCount:       1192  --  LEAKED 11 !!!
0x00000000091DFE6C
mozjs!js_CreateTypedArrayWithArray+0x0000000000169A10
mozjs!js_CreateTypedArrayWithArray+0x0000000000169434
mozjs!js_CreateTypedArrayWithArray+0x000000000016C16F
mozjs!js_CreateTypedArrayWithArray+0x0000000000081DEE
mozjs!js_CreateTypedArrayWithArray+0x000000000007D860
xpc3250!DumpJSValue+0x00000000000566EF
xpc3250!DumpJSValue+0x000000000004D28B
xpcom_core!NS_InvokeByIndex_P+0x0000000000000556
xpcom_core!NS_InvokeByIndex_P+0x0000000000000226
msgcompo!NSGetModule+0x000000000004262F
msgcompo!NSGetModule+0x0000000000076FAB
msgbase!NSGetModule+0x0000000000051CA4
msgbase!NSGetModule+0x0000000000053071
msglocal!NSGetModule+0x0000000000024BA0
msglocal!NSGetModule+0x0000000000029BCC
msglocal!NSGetModule+0x000000000002797F
msgbase!NSGetModule+0x0000000000052220
msgbase!NSGetModule+0x0000000000051ECC
msgbase!NSGetModule+0x0000000000052F81
msgcompo!NSGetModule+0x00000000000778CC
msgcompo!NSGetModule+0x0000000000077609
msgcompo!NSGetModule+0x00000000000441D3
msgcompo!NSGetModule+0x0000000000044049
msgcompo!NSGetModule+0x0000000000042AC0
msgcompo!NSGetModule+0x000000000004046E
msgcompo!NSGetModule+0x0000000000042902
xpcom_core!NS_InvokeByIndex_P+0x0000000000000027
xpc3250!DumpJSValue+0x0000000000061518
xpc3250!DumpJSValue+0x000000000006FDBB
mozjs!js_CreateTypedArrayWithArray+0x000000000007D81B
mozjs!js_CreateTypedArrayWithArray+0x000000000008ECF7
mozjs!js_CreateTypedArrayWithArray+0x000000000007EA88
mozjs!js_CreateTypedArrayWithArray+0x0000000000022BBD
mozjs!js_CreateTypedArrayWithArray+0x0000000000022A10
0x000000000040546F
0x000000000040434F
0x0000000000411B56
0x00000000004119AD
kernel32!ProcessIdToSessionId+0x0000000000000209

Comment 18

[Serge Gautherie (:sgautherie)]

["Mid-air collision detected!": posting anyway...]

Great! And now we get the logs too :-)

http://tinderbox.mozilla.org/showlog.cgi?log=SeaMonkey/1271363022.1271368276.2278.gz&fulltext=1
WINNT 5.2 comm-central-trunk debug test xpcshell on 2010/04/15 13:23:42
{
TEST-UNEXPECTED-FAIL | e:\builds\slave\comm-central-trunk-win32-debug-unittest-xpcshell\build\xpcshell\tests\test_compose\unit\test_bug474774.js | test failed (with xpcshell return code: -1073741819), see following log:
[...]
WARNING: No valid default account found, just using first (FIXME): file e:/builds/slave/comm-central-trunk-win32-debug/build/mailnews/base/src/nsMsgAccountManager.cpp, line 772
CopyListener::OnStartCopy()
WARNING: This method is lossy. Use GetCanonicalPath !: file e:/builds/slave/comm-central-trunk-win32-debug/build/mozilla/xpcom/io/nsLocalFileWin.cpp, line 2964
[...]
###!!! ASSERTION: unable to initialize resource: 'Error', file e:/builds/slave/comm-central-trunk-win32-debug/build/mozilla/rdf/base/src/nsRDFService.cpp, line 1030
addrbook!NSGetModule+0x0000000000046A5E
[...]
}

And 27 other MailNews tests fail with the same assertion.

Comment 19

[Robert Kaiser]

test_sendBackground.js, test_sendMessageFile.js, test_sendMessageLater.js, test_sendMessageLater2.js, test_sendMessageLater3.js all show exactly the same signature. I'm not completely sure, but maybe it's actually the assertion that is the fatal thing here.

Comment 20

[Robert Kaiser]

Serge, can we backtrack when this started appearing? It's possible that this is really debug-only as assertions might be fatal on debug but ignored on opt builds, and TB is not testing debug, AFAIK.

Comment 21

[Serge Gautherie (:sgautherie)]

(In reply to comment #20)
> Serge, can we backtrack when this started appearing?

Hum, let me make my comment 0 much more explicit:

1)
This test was first run on
http://tinderbox.mozilla.org/showlog.cgi?log=SeaMonkey/1267734856.1267740723.10083.gz&fulltext=1
WINNT 5.2 comm-central-trunk debug test xpcshell on 2010/03/04 12:34:16

2)
On
http://tinderbox.mozilla.org/showbuilds.cgi?tree=SeaMonkey&maxdate=1268218877&hours=24&legend=0&norules=1

The test ran up to
http://tinderbox.mozilla.org/showlog.cgi?log=SeaMonkey/1268156274.1268160910.27835.gz&fulltext=1
WINNT 5.2 comm-central-trunk debug test xpcshell on 2010/03/09 09:37:54
rev:2acf5df83607
moz:eaf1574b10b6
{
e:/builds/slave/comm-central-trunk-win32-debug-unittest-xpcshell/build/xpcshell/tests/test_compose/unit/test_bug474774.js:18: TypeError: Cc['@mozilla.org/messengercompose/sendlater;1'] is undefined
}

The next builds did not start:
from
http://tinderbox.mozilla.org/showlog.cgi?log=SeaMonkey/1268167099.1268168870.18265.gz
WINNT 5.2 comm-central-trunk debug test xpcshell on 2010/03/09 12:38:19
rev:bbb5625de160
moz:88529662c474
to
http://tinderbox.mozilla.org/showlog.cgi?log=SeaMonkey/1268189193.1268190844.15324.gz
WINNT 5.2 comm-central-trunk debug test xpcshell on 2010/03/09 18:46:33
rev:af22d45bc8ab
moz:120330e515e6

Then the test started timing out:
http://tinderbox.mozilla.org/showlog.cgi?log=SeaMonkey/1268194152.1268198782.1728.gz
WINNT 5.2 comm-central-trunk debug test xpcshell on 2010/03/09 20:09:12
rev:4bdfa97ef732
moz:120330e515e6
{
command timed out: 1200 seconds without output
}

Regression timeframe(s):
http://hg.mozilla.org/comm-central/pushloghtml?fromchange=2acf5df83607&tochange=4bdfa97ef732
And I expect the improved log is due to bug 550018.
(It behaved worse only because of what you now fixed in comment 16 :-<)

Comment 22

[Dan Mosedale (:dmosedale, :dmose)]

From what I can tell from skimming the bug, we don't currently have reason to believe that this something severe that would effect a significant number of users.  Marking blocking- based on that assumption.  If I've misunderstood, please renominate.  Thanks!

Comment 23

[Robert Kaiser]

From what I've seen, this test has never worked in SeaMonkey debug builds. bummer. So we run into an assertion in mailnews tests, probably always have, all our testing is bogus there probably for this, as non-green equals unhelpful, but as it was always that way and we obviously could ship with that, it's deemed non-important by Thunderbird people.

In the end, this sounds like "go to hell and ignore testing" - even if I know that's not the intended message...

Comment 24

[Serge Gautherie (:sgautherie)]

(In reply to comment #20)

> It's possible that this is really debug-only

It may even be likely, but impossible to confirm until bug 558851.

> as assertions [are] fatal on debug

Yet, I double-checked my comment 2 and still don't reproduce locally:
so it may still be related to something (else) on the tinderboxes.

Fwiw,
I don't get the assertion nor the "WARNING: No valid default account found"...
But I get a
{
WARNING: NS_ENSURE_TRUE(aCallbacks) failed: file e:/builds/slave/comm-central-trunk-win32-debug/build/mailnews/compose/src/nsSmtpUrl.cpp, line 815
}

That's all I can test until bug 557060 is fixed :-|

Comment 25

[Dan Mosedale (:dmosedale, :dmose)]

(In reply to comment #23)
> From what I've seen, this test has never worked in SeaMonkey debug builds.
> bummer. So we run into an assertion in mailnews tests, probably always have,
> all our testing is bogus there probably for this, as non-green equals
> unhelpful, but as it was always that way and we obviously could ship with that,
> it's deemed non-important by Thunderbird people.
> 
> In the end, this sounds like "go to hell and ignore testing" - even if I know
> that's not the intended message...

So, um, I'm relatively speechless.  You're putting a large number of words in my words which I very much have not said.

The blocking-thunderbird3.1 flags means exactly what it says; nothing more and nothing less.  Which is to say that if this bug were the last bug standing, we wouldn't allow it to prevent Thunderbird 3.1 from shipping.  This says quite literally _nothing_ about the importance of this test or any other.

Comment 26

[Robert Kaiser]

(In reply to comment #24)
> (In reply to comment #20)
> 
> > It's possible that this is really debug-only
> 
> It may even be likely, but impossible to confirm until bug 558851.

Unless it rains build machines for us, I'd rather go and have all mailnews tests disabled for SeaMonkey. Who cares if it doesn't work for us anyhow? Fewer tests, fewer problems.

> Yet, I double-checked my comment 2 and still don't reproduce locally:

Umm, I thought you can't run debug builds? If so, assertions are hidden anyhow in opt builds, so you don't notice. Additionally, 1) I doubt the WARNING has anything to do with the assertion, and 2) that one might be debug-only as well.

Comment 27

[Robert Kaiser]

(In reply to comment #25)
> So, um, I'm relatively speechless.  You're putting a large number of words in
> my words which I very much have not said.

Note my usage of "sounds like" and "I know that's not the intended message". I used both for a reason.

Comment 28

[Serge Gautherie (:sgautherie)]

(In reply to comment #26)

> Umm, I thought you can't run debug builds?

Could you stop playing stupid with me? (here and elsewhere)
I already replied to you in some other comment/bug that this build was made _before_ bug 557060 existed!

Comment 29

[Mark Banner (:standard8)]

Ok, so what I can glean so far: Serge can't reproduce locally. AFAIK no other Thunderbird devs are having issues with these tests asserting (I haven't explicitly asked, but I'd be surprised if they hadn't already mentioned it).

From the test perspective:

- It isn't a shutdown assertion. Comparing the debug output with the code, the message to send has been formed, and the assertion is happening around the time when SendMessageLater is called.

- The assertion is RDF (as we know) so something is failing to initialise.

Making a guess:

- As the message to be sent has already been formed, it is unlikely to be an account or folder data source issue.

- One of the steps that goes on when sending a message is to update the popularity count of cards in the address book. This would cause an initialisation of the AB RDF datasources to take place.

- SM enables Outlook type AB interfaces by default.

Therefore my guess is that the SM tinderboxes don't have the MAPI installed (or whatever is required) and the outlook interfaces don't initialise properly. This doesn't affect the address book unit tests because there the outlook address book is disabled by the code:

http://mxr.mozilla.org/comm-central/source/mailnews/test/resources/abSetup.js#50

I suspect this disabling hasn't got into the compose tests (its not obvious it is required) and is therefore causing the assertion concerned. Hence this bug doesn't affect Thunderbird because Thunderbird hasn't enabled the outlook interfaces by default.

I'd therefore suggest getting that file included in an appropriate location - maybe the head file in the compose tests (make sure it isn't included in some of the other compose test files as well).

Comment 30

[Robert Kaiser]

(In reply to comment #28)
> I already replied to you in some other comment/bug that this build was made
> _before_ bug 557060 existed!

Sorry, I didn't keep that in my head. I'm reading so much info a day that I can lose some of it on the way.

(In reply to comment #29)
> Therefore my guess is that the SM tinderboxes don't have the MAPI installed (or
> whatever is required) and the outlook interfaces don't initialise properly.

Thanks, Mark, that is entirely possible, of course. Setting up the boxes I follow Firefox reference build instructions, it's surely possible that misses something we're using on the mailnews side of things.

> I'd therefore suggest getting that file included in an appropriate location -
> maybe the head file in the compose tests (make sure it isn't included in some
> of the other compose test files as well).

That suggestion sounds good to me, thanks for the analysis!

Comment 31

[Serge Gautherie (:sgautherie)]

Attachment: (Av1) Include abSetup.js where it is needed to disable the W.A.B. [Checkin: Comment 32]

Per your comment 29 suggestion.
http://mxr.mozilla.org/comm-central/search?string=abSetup.js&case=1&find=%2Fmailnews%2F

I tested this with test_nsMsgCompose1.js, I can only hope for the others.

Comment 32

[Serge Gautherie (:sgautherie)]

Comment on attachment 439664 [details] [diff] [review]
(Av1) Include abSetup.js where it is needed to disable the W.A.B.
[Checkin: Comment 32]


http://hg.mozilla.org/comm-central/rev/45efc7943ebc

Comment 33

[Serge Gautherie (:sgautherie)]

http://tinderbox.mozilla.org/showlog.cgi?log=SeaMonkey/1271690281.1271693997.25920.gz
WINNT 5.2 comm-central-trunk debug test xpcshell on 2010/04/19 08:18:01

V.Fixed