Last Comment Bug 803574 - Permanent orange: TEST-UNEXPECTED-FAIL | test_nntpPassword2.js application crashed
: Permanent orange: TEST-UNEXPECTED-FAIL | test_nntpPassword2.js application cr...
Status: RESOLVED FIXED
: intermittent-failure, regression
Product: MailNews Core
Classification: Components
Component: Backend (show other bugs)
: Trunk
: x86 Mac OS X
: -- normal (vote)
: Thunderbird 19.0
Assigned To: :Irving Reid (No longer working on Firefox)
:
:
Mentors:
Depends on:
Blocks: 804577 795562
  Show dependency treegraph
 
Reported: 2012-10-19 08:51 PDT by Mark Banner (:standard8, limited time in Dec)
Modified: 2012-11-25 19:31 PST (History)
4 users (show)
See Also:
Crash Signature:
(edit)
QA Whiteboard:
Iteration: ---
Points: ---


Attachments
Fix preference for News profile path to prevent DB open failures in test (3.98 KB, patch)
2012-10-23 06:46 PDT, :Irving Reid (No longer working on Firefox)
Pidgeot18: review+
Details | Diff | Splinter Review

Description Mark Banner (:standard8, limited time in Dec) 2012-10-19 08:51:09 PDT
Since the nsresult changes, we've been seeing this:

TEST-UNEXPECTED-FAIL | /Users/cltbld/talos-slave/test/build/xpcshell/tests/mailnews/news/test/unit/test_nntpPassword2.js | test failed (with xpcshell return code: 1), see following log:
>>>>>>>
### XPCOM_MEM_LEAK_LOG defined -- logging leaks to /var/folders/Hs/HsDn6a9SG8idoIya6p9mtE+++TI/-Tmp-/tmpTJ1iOE/runxpcshelltests_leaks.log

TEST-INFO | (xpcshell/head.js) | test 1 pending
Directory request for: NewsD that we (mailDirService.js) are not handling, leaving it to another handler.
Directory request for: MFCaF that we (mailDirService.js) are not handling, leaving it to another handler.
###!!! ASSERTION: morkBool_kFalse: 'Error', file ../../../../db/mork/src/morkConfig.cpp, line 24
Comment 1 :Irving Reid (No longer working on Firefox) 2012-10-19 09:07:17 PDT
The assertion is in a function that manipulates error codes; a helpful (?) programmer decided that future developers would love to have their mork-using applications crash when a file was not found or whatever.

However, taking the assertion out (or looking at opt test runs where the assertion is compiled out) the test still fails.

Part one of the problem is in the test code; where we set up the preferences for the NTTP server in the test case, we specify the server's profile directory to be under "Mail/"; that directory doesn't exist in the test profile

The real regression (aside from tripping the assertion) seems to be in the way we handle trying to open the mork database from the non-existent directory; the code fails out instead of working past the error.


diff --git a/mailnews/news/test/unit/test_nntpPassword2.js b/mailnews/news/test/unit/test_nntpPassword2.js
--- a/mailnews/news/test/unit/test_nntpPassword2.js
+++ b/mailnews/news/test/unit/test_nntpPassword2.js
@@ -40,7 +40,7 @@ function run_test() {
   Services.prefs.setCharPref("mail.server.server1.type", "none");
   Services.prefs.setCharPref("mail.server.server1.userName", "nobody");
   Services.prefs.setCharPref("mail.server.server2.directory-rel",
-                             "[ProfD]Mail/invalid");
+                             "[ProfD]News/invalid");
   Services.prefs.setCharPref("mail.server.server2.hostname", "invalid");
   Services.prefs.setCharPref("mail.server.server2.name",
                              "testnntp on localhost");


Changing the test to specify that the NNTP local store is under an existing directory in the profile, as above, leads to a different failure in the NNTP fakeserver; unfortunately that failure, which may have been around for a long time, causes the test to report success:



Irvings-MacBook-Pro% make SOLO_FILE="test_nntpPassword2.js" -C mailnews/news/test check-one
/usr/bin/python2.7 -u /Users/ireid/tbird/comm-central/mozilla/config/pythonpath.py \
	  -I/Users/ireid/tbird/comm-central/mozilla/build -I../../../mozilla/_tests/mozbase/mozinfo \
	  /Users/ireid/tbird/comm-central/mozilla/testing/xpcshell/runxpcshelltests.py \
	  --symbols-path=../../../mozilla/dist/crashreporter-symbols \
	  --build-info-json=../../../mozilla/mozinfo.json \
	  --test-path=test_nntpPassword2.js \
	  --profile-name=thunderbird \
	  --verbose \
	   \
	  /Users/ireid/tbird/obj/comm-central/mozilla/dist/bin/xpcshell \
	  ../../../mozilla/_tests/xpcshell/mailnews/news/test/unit
TEST-INFO | profile dir is /var/folders/13/5v1sbktd1cl05mvkntw3b4gc0000gn/T/thunderbird/xpcshellprofile
TEST-INFO | /Users/ireid/tbird/obj/comm-central/mozilla/_tests/xpcshell/mailnews/news/test/unit/test_nntpPassword2.js | running test ...
TEST-INFO | /Users/ireid/tbird/obj/comm-central/mozilla/_tests/xpcshell/mailnews/news/test/unit/test_nntpPassword2.js | full command: ['/Users/ireid/tbird/obj/comm-central/mozilla/dist/bin/xpcshell', '-g', '/Users/ireid/tbird/obj/comm-central/mozilla/dist/bin', '-a', '/Users/ireid/tbird/obj/comm-central/mozilla/dist/bin', '-r', '/Users/ireid/tbird/obj/comm-central/mozilla/dist/bin/components/httpd.manifest', '-m', '-n', '-s', '-e', 'const _HTTPD_JS_PATH = "/Users/ireid/tbird/obj/comm-central/mozilla/dist/bin/components/httpd.js";', '-e', 'const _HEAD_JS_PATH = "/Users/ireid/tbird/comm-central/mozilla/testing/xpcshell/head.js";', '-f', '/Users/ireid/tbird/comm-central/mozilla/testing/xpcshell/head.js', '-e', 'const _SERVER_ADDR = "localhost"', '-e', 'const _HEAD_FILES = ["/Users/ireid/tbird/obj/comm-central/mozilla/_tests/xpcshell/mailnews/news/test/unit/head_server_setup.js"];', '-e', 'const _TAIL_FILES = ["/Users/ireid/tbird/obj/comm-central/mozilla/_tests/xpcshell/mailnews/news/test/unit/tail_news.js"];', '-e', 'const _TEST_FILE = ["/Users/ireid/tbird/obj/comm-central/mozilla/_tests/xpcshell/mailnews/news/test/unit/test_nntpPassword2.js"];', '-e', '_execute_test(); quit(0);']
TEST-INFO | /Users/ireid/tbird/obj/comm-central/mozilla/_tests/xpcshell/mailnews/news/test/unit/test_nntpPassword2.js | current directory: '/Users/ireid/tbird/obj/comm-central/mozilla/_tests/xpcshell/mailnews/news/test/unit'
TEST-INFO | /Users/ireid/tbird/obj/comm-central/mozilla/_tests/xpcshell/mailnews/news/test/unit/test_nntpPassword2.js | environment: ['XPCOM_MEM_LEAK_LOG=/var/folders/13/5v1sbktd1cl05mvkntw3b4gc0000gn/T/thunderbird/xpcshellprofile/runxpcshelltests_leaks.log', 'XPCSHELL_TEST_PROFILE_DIR=/var/folders/13/5v1sbktd1cl05mvkntw3b4gc0000gn/T/thunderbird/xpcshellprofile', 'DYLD_LIBRARY_PATH=/Users/ireid/tbird/obj/comm-central/mozilla/dist/bin', 'NS_TRACE_MALLOC_DISABLE_STACKS=1', 'XPCOM_DEBUG_BREAK=stack-and-abort', 'MOZ_CRASHREPORTER_NO_REPORT=1']
TEST-PASS | /Users/ireid/tbird/obj/comm-central/mozilla/_tests/xpcshell/mailnews/news/test/unit/test_nntpPassword2.js | test passed (time: 940.078ms)
>>>>>>>
### XPCOM_MEM_LEAK_LOG defined -- logging leaks to /var/folders/13/5v1sbktd1cl05mvkntw3b4gc0000gn/T/thunderbird/xpcshellprofile/runxpcshelltests_leaks.log

TEST-INFO | (xpcshell/head.js) | test 1 pending
Directory request for: NewsD that we (mailDirService.js) are not handling, leaving it to another handler.
Directory request for: MFCaF that we (mailDirService.js) are not handling, leaving it to another handler.
2035865952[11a110070]: (11d57f800) creating
2035865952[11a110070]: (11d57f800) initializing, so unset m_currentGroup
2035865952[11a110070]: (11d57f800) setting busy to 1
2035865952[11a110070]: (11d57f800) ParseURL
2035865952[11a110070]: (11d57f800) opening connection to localhost on port 1143
2035865952[11a110070]: (11d57f800) setting busy to 1
2035865952[11a110070]: (11d57f800) ParseURL
2035865952[11a110070]: (11d57f800) m_messageID = 
2035865952[11a110070]: (11d57f800) group = *
2035865952[11a110070]: (11d57f800) m_key = -1
2035865952[11a110070]: (11d57f800) Next state: NNTP_RESPONSE
2035865952[11a110070]: (11d57f800) Receiving: 200 posting allowed
2035865952[11a110070]: (11d57f800) Next state: NNTP_LOGIN_RESPONSE
2035865952[11a110070]: (11d57f800) Next state: NNTP_SEND_MODE_READER
2035865952[11a110070]: (11d57f800) Sending: MODE READER
2035865952[11a110070]: (11d57f800) Next state: NNTP_RESPONSE
2035865952[11a110070]: (11d57f800) Receiving: 200 posting allowed
2035865952[11a110070]: (11d57f800) Next state: NNTP_SEND_MODE_READER_RESPONSE
2035865952[11a110070]: (11d57f800) Next state: SEND_FIRST_NNTP_COMMAND
2035865952[11a110070]: (11d57f800) Sending: LIST
2035865952[11a110070]: (11d57f800) Next state: NNTP_RESPONSE
2035865952[11a110070]: (11d57f800) Receiving: 480 Authentication required
2035865952[11a110070]: (11d57f800) Next state: NNTP_BEGIN_AUTHORIZE
2035865952[11a110070]: (11d57f800) Next state: NNTP_SUSPENDED
2035865952[11a110070]: (11d57f800) Next state: NNTP_BEGIN_AUTHORIZE
2035865952[11a110070]: (11d57f800) use testnews as the username
2035865952[11a110070]: (11d57f800) Sending: AUTHINFO user testnews
2035865952[11a110070]: (11d57f800) Next state: NNTP_RESPONSE
2035865952[11a110070]: (11d57f800) Receiving: 381 Password required
2035865952[11a110070]: (11d57f800) Next state: NNTP_AUTHORIZE_RESPONSE
2035865952[11a110070]: (11d57f800) Logging suppressed for this command (it probably contained authentication information)
2035865952[11a110070]: (11d57f800) Next state: NNTP_RESPONSE
2035865952[11a110070]: (11d57f800) Receiving: 281 Authentication Accepted
2035865952[11a110070]: (11d57f800) Next state: NNTP_PASSWORD_RESPONSE
2035865952[11a110070]: (11d57f800) Next state: SEND_FIRST_NNTP_COMMAND
2035865952[11a110070]: (11d57f800) Sending: LIST
InternalError: too much recursion
File: ../../../fakeserver/nntpd.js Line: 409
Stack trace:
.LIST@../../../fakeserver/nntpd.js:409
sub.parent.__noSuchMethod__@../../../fakeserver/nntpd.js:390
.LIST@../../../fakeserver/nntpd.js:409
sub.parent.__noSuchMethod__@../../../fakeserver/nntpd.js:390
.LIST@../../../fakeserver/nntpd.js:409
sub.parent.__noSuchMethod__@../../../fakeserver/nntpd.js:390
.LIST@../../../fakeserver/nntpd.js:409

... hundreds of lines of identical recursive calls

sub.parent.__noSuchMethod__@../../../fakeserver/nntpd.js:390
.LIST@../../../fakeserver/nntpd.js:409
sub.parent.__noSuchMethod__@../../../fakeserver/nntpd.js:390
.LIST@../../../fakeserver/nntpd.js:566
nsMailReader.prototype.onInputStreamReady@../../../fakeserver/maild.js:415
2035865952[11a110070]: (11d57f800) Next state: NNTP_RESPONSE
2035865952[11a110070]: (11d57f800) Receiving: 500 internal server error: InternalError: too much recursion
2035865952[11a110070]: (11d57f800) Next state: SEND_FIRST_NNTP_COMMAND_RESPONSE
2035865952[11a110070]: WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004003: file /Users/ireid/tbird/comm-central/mailnews/news/src/nsNNTPProtocol.cpp, line 1980
WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004003: file /Users/ireid/tbird/comm-central/mailnews/news/src/nsNNTPProtocol.cpp, line 1980
2035865952[11a110070]: (11d57f800) Next state: NNTP_ERROR
2035865952[11a110070]: (11d57f800) ClosingConnection
2035865952[11a110070]: (11d57f800) Sending: QUIT
2035865952[11a110070]: (11d57f800) ClosingSocket()
2035865952[11a110070]: (11d57f800) CleanupAfterRunningUrl()
2035865952[11a110070]: (11d57f800) setting busy to 0
2035865952[11a110070]: (11d57f800) ClosingSocket()
2035865952[11a110070]: (11d57f800) CleanupAfterRunningUrl()
2035865952[11a110070]: (11d57f800) setting busy to 0

TEST-PASS | /Users/ireid/tbird/obj/comm-central/mozilla/_tests/xpcshell/mailnews/news/test/unit/head_server_setup.js | [do_check_transaction : 183] MODE READER,LIST,AUTHINFO user testnews,AUTHINFO pass newstest,LIST == MODE READER,LIST,AUTHINFO user testnews,AUTHINFO pass newstest,LIST
Passed test news:*

TEST-INFO | (xpcshell/head.js) | test 1 finished

TEST-INFO | (xpcshell/head.js) | exiting test
2035865952[11a110070]: (11d57f800) destroying
Directory request for: DefRt that we (mailDirService.js) are not handling, leaving it to another handler.

TEST-PASS | (xpcshell/head.js) | 1 (+ 0) check(s) passed

TEST-INFO | (xpcshell/head.js) | 0 check(s) todo
2035865952[11a110070]: WARNING: nsExceptionService ignoring thread destruction after shutdown: file /Users/ireid/tbird/comm-central/mozilla/xpcom/base/nsExceptionService.cpp, line 166
WARNING: nsExceptionService ignoring thread destruction after shutdown: file /Users/ireid/tbird/comm-central/mozilla/xpcom/base/nsExceptionService.cpp, line 166
2035865952[11a110070]: WARNING: OOPDeinit() without successful OOPInit(): file /Users/ireid/tbird/comm-central/mozilla/toolkit/crashreporter/nsExceptionHandler.cpp, line 2252
WARNING: OOPDeinit() without successful OOPInit(): file /Users/ireid/tbird/comm-central/mozilla/toolkit/crashreporter/nsExceptionHandler.cpp, line 2252
nsStringStats
 => mAllocCount:           4321
 => mReallocCount:          709
 => mFreeCount:            4321
 => mShareCount:           9334
 => mAdoptCount:            321
 => mAdoptFreeCount:        321
<<<<<<<
INFO | Result summary:
INFO | Passed: 1
INFO | Failed: 0
INFO | Todo: 0
Irvings-MacBook-Pro%
Comment 2 Treeherder Robot 2012-10-19 18:49:56 PDT
ryanvm%gmail.com
https://tbpl.mozilla.org/php/getParsedLog.php?id=16286393&tree=Thunderbird-Trunk
TB Rev4 MacOSX Snow Leopard 10.6 comm-central debug test xpcshell on 2012-10-19 17:57:58
slave: talos-r4-snow-069

TEST-UNEXPECTED-FAIL | /Users/cltbld/talos-slave/test/build/xpcshell/tests/mailnews/news/test/unit/test_nntpPassword2.js | test failed (with xpcshell return code: 1), see following log:
PROCESS-CRASH | /Users/cltbld/talos-slave/test/build/xpcshell/tests/mailnews/news/test/unit/test_nntpPassword2.js | application crashed (minidump found)
Thread 0 (crashed)
Comment 3 Treeherder Robot 2012-10-19 18:50:03 PDT
ryanvm%gmail.com
https://tbpl.mozilla.org/php/getParsedLog.php?id=16286703&tree=Thunderbird-Trunk
TB Rev4 MacOSX Lion 10.7 comm-central debug test xpcshell on 2012-10-19 18:12:39
slave: talos-r4-lion-023

TEST-UNEXPECTED-FAIL | /Users/cltbld/talos-slave/test/build/xpcshell/tests/mailnews/news/test/unit/test_nntpPassword2.js | test failed (with xpcshell return code: 1), see following log:
PROCESS-CRASH | /Users/cltbld/talos-slave/test/build/xpcshell/tests/mailnews/news/test/unit/test_nntpPassword2.js | application crashed (minidump found)
Thread 0 (crashed)
Comment 4 Treeherder Robot 2012-10-19 19:47:03 PDT
ryanvm%gmail.com
https://tbpl.mozilla.org/php/getParsedLog.php?id=16288371&tree=Thunderbird-Trunk
TB Rev3 WINNT 5.1 comm-central debug test xpcshell on 2012-10-19 17:58:08
slave: talos-r3-xp-027

TEST-UNEXPECTED-FAIL | c:\talos-slave\test\build\xpcshell\tests\mailnews\news\test\unit\test_nntpPassword2.js | test failed (with xpcshell return code: -2147483645), see following log:
PROCESS-CRASH | c:\talos-slave\test\build\xpcshell\tests\mailnews\news\test\unit\test_nntpPassword2.js | application crashed (minidump found)
Thread 0 (crashed)
Comment 5 Treeherder Robot 2012-10-19 19:55:25 PDT
ryanvm%gmail.com
https://tbpl.mozilla.org/php/getParsedLog.php?id=16288770&tree=Thunderbird-Trunk
TB Rev3 WINNT 6.1 comm-central debug test xpcshell on 2012-10-19 17:57:52
slave: talos-r3-w7-014

TEST-UNEXPECTED-FAIL | c:\talos-slave\test\build\xpcshell\tests\mailnews\news\test\unit\test_nntpPassword2.js | test failed (with xpcshell return code: -2147483645), see following log:
PROCESS-CRASH | c:\talos-slave\test\build\xpcshell\tests\mailnews\news\test\unit\test_nntpPassword2.js | application crashed (minidump found)
Thread 0 (crashed)
Comment 6 :Irving Reid (No longer working on Firefox) 2012-10-20 08:07:48 PDT
After much searching and hacking away at the nsresult changes to try and figure out how they broke this, i finally went back and bisected - turns out this test broke just *before* the nsresult change landed.

The bisection points at Bug 795562. The failure shows up in some, but not all, of the TBPL build logs for that push, for example https://tbpl.mozilla.org/php/getParsedLog.php?id=16071636&tree=Thunderbird-Trunk&full=1#error0
Comment 7 Treeherder Robot 2012-10-20 09:12:27 PDT
IanN
https://tbpl.mozilla.org/php/getParsedLog.php?id=16298915&tree=Thunderbird-Try
TB Rev4 MacOSX Snow Leopard 10.6 try-comm-central debug test xpcshell on 2012-10-20 07:42:35
slave: talos-r4-snow-084

TEST-UNEXPECTED-FAIL | /Users/cltbld/talos-slave/test/build/xpcshell/tests/mailnews/news/test/unit/test_nntpPassword2.js | test failed (with xpcshell return code: 1), see following log:
PROCESS-CRASH | /Users/cltbld/talos-slave/test/build/xpcshell/tests/mailnews/news/test/unit/test_nntpPassword2.js | application crashed (minidump found)
Thread 0 (crashed)
Comment 8 :aceman 2012-10-20 11:36:56 PDT
So is this a mork bug that we now incidentally trigger?
Comment 9 Mark Banner (:standard8, limited time in Dec) 2012-10-21 07:37:03 PDT
Bug 795562 added a call to ContainsNewsgroup, that is now prompting any sub-folders to be created, and I think is initialising at least the root folder for the server. The mork assertion was probably due to something like we were previously getting away with the "incorrect" path, because of the call route meaning the "incorrect" path was somehow getting setup, or going via a call that allow recursive create.

Now we've got ContainsNewsgroup, it seems to be expecting the News/ bit to be created first.

So we can probably just take the preference change.

The remaining question would be the recursion - Irving, can you see if that happened before bug 795562 as well? If so, I think we should fix the pref here, and spin out the recursion to a separate bug.
Comment 10 Treeherder Robot 2012-10-22 18:44:12 PDT
RyanVM
https://tbpl.mozilla.org/php/getParsedLog.php?id=16361037&tree=Thunderbird-Trunk
TB Rev4 MacOSX Snow Leopard 10.6 comm-central debug test xpcshell on 2012-10-22 17:14:56
slave: talos-r4-snow-011

TEST-UNEXPECTED-FAIL | /Users/cltbld/talos-slave/test/build/xpcshell/tests/mailnews/news/test/unit/test_nntpPassword2.js | test failed (with xpcshell return code: 1), see following log:
PROCESS-CRASH | /Users/cltbld/talos-slave/test/build/xpcshell/tests/mailnews/news/test/unit/test_nntpPassword2.js | application crashed (minidump found)
Thread 0 (crashed)
Comment 11 Treeherder Robot 2012-10-22 18:44:19 PDT
RyanVM
https://tbpl.mozilla.org/php/getParsedLog.php?id=16361047&tree=Thunderbird-Trunk
TB Rev4 MacOSX Lion 10.7 comm-central debug test xpcshell on 2012-10-22 17:15:55
slave: talos-r4-lion-011

TEST-UNEXPECTED-FAIL | /Users/cltbld/talos-slave/test/build/xpcshell/tests/mailnews/local/test/unit/test_pop3PasswordFailure2.js | test failed (with xpcshell return code: 0), see following log:
TEST-UNEXPECTED-FAIL | /Users/cltbld/talos-slave/test/build/xpcshell/tests/mailnews/local/test/unit/test_pop3PasswordFailure2.js | 2147500037 == 0 - See following stack:
TEST-UNEXPECTED-FAIL | /Users/cltbld/talos-slave/test/build/xpcshell/tests/mailnews/local/test/unit/test_pop3PasswordFailure2.js | 2147500036 - See following stack:
TEST-UNEXPECTED-FAIL | /Users/cltbld/talos-slave/test/build/xpcshell/tests/mailnews/news/test/unit/test_nntpPassword2.js | test failed (with xpcshell return code: 1), see following log:
PROCESS-CRASH | /Users/cltbld/talos-slave/test/build/xpcshell/tests/mailnews/news/test/unit/test_nntpPassword2.js | application crashed (minidump found)
Thread 0 (crashed)
Comment 12 Treeherder Robot 2012-10-22 19:33:31 PDT
RyanVM
https://tbpl.mozilla.org/php/getParsedLog.php?id=16363508&tree=Thunderbird-Trunk
TB Rev3 WINNT 5.1 comm-central debug test xpcshell on 2012-10-22 18:04:10
slave: talos-r3-xp-057

TEST-UNEXPECTED-FAIL | c:\talos-slave\test\build\xpcshell\tests\mailnews\news\test\unit\test_nntpPassword2.js | test failed (with xpcshell return code: -2147483645), see following log:
PROCESS-CRASH | c:\talos-slave\test\build\xpcshell\tests\mailnews\news\test\unit\test_nntpPassword2.js | application crashed (minidump found)
Thread 0 (crashed)
Comment 13 :Irving Reid (No longer working on Firefox) 2012-10-23 06:46:20 PDT
Created attachment 674221 [details] [diff] [review]
Fix preference for News profile path to prevent DB open failures in test

The fakeserver still fails when running this test; I'll file a separate bug for that.

If you object to slipping warning cleanup in along with the fix, I'll split it out and only land the test pref change.
Comment 14 Mark Banner (:standard8, limited time in Dec) 2012-10-25 01:30:28 PDT
I've landed this to help clear up some of the oranges on the tree:

https://hg.mozilla.org/comm-central/rev/09a3ffdfb241

Note You need to log in before you can comment on or make changes to this bug.