Closed Bug 1674077 Opened 3 months ago Closed 3 months ago

debug perma - Assertion failure: NS_IsMainThread() - application crashed [@ nsStringBundle::LoadProperties() - comm/mail/base/test/unit/test_emptyTrash_dbViewWrapper.js, comm/mailnews/imap/test/unit/test_imapFilterActions.js and others

Categories

(MailNews Core :: Backend, defect, P1)

Tracking

(thunderbird_esr78 unaffected, thunderbird83 unaffected)

RESOLVED FIXED
84 Branch
Tracking Status
thunderbird_esr78 --- unaffected
thunderbird83 --- unaffected

People

(Reporter: intermittent-bug-filer, Assigned: benc)

References

(Regression)

Details

(Keywords: intermittent-failure)

Attachments

(1 file)

I think these are all related:

TEST-UNEXPECTED-FAIL | comm/mail/base/test/unit/test_emptyTrash_dbViewWrapper.js | xpcshell return code: -11
Logviewer
Assertion failure: NS_IsMainThread(), at /builds/worker/workspace/obj-build/dist/include/mozilla/ClearOnShutdown.h:133
Logviewer
PROCESS-CRASH | comm/mail/base/test/unit/test_emptyTrash_dbViewWrapper.js | application crashed [@ nsStringBundle::LoadProperties()]
Logviewer
TEST-UNEXPECTED-FAIL | comm/mail/base/test/unit/test_viewWrapper_imapFolder.js | xpcshell return code: -11
Logviewer
Assertion failure: NS_IsMainThread(), at /builds/worker/workspace/obj-build/dist/include/mozilla/ClearOnShutdown.h:133
Logviewer
PROCESS-CRASH | comm/mail/base/test/unit/test_viewWrapper_imapFolder.js | application crashed [@ nsStringBundle::LoadProperties()]
Logviewer
TEST-UNEXPECTED-FAIL | comm/mail/base/test/unit/test_viewWrapper_virtualFolderCustomTerm.js | xpcshell return code: -11
Logviewer
Assertion failure: NS_IsMainThread(), at /builds/worker/workspace/obj-build/dist/include/mozilla/ClearOnShutdown.h:133
Logviewer
PROCESS-CRASH | comm/mail/base/test/unit/test_viewWrapper_virtualFolderCustomTerm.js | application crashed [@ nsStringBundle::LoadProperties()]
Logviewer

Test is ok locally on c-c tip (with m-c not updated), so likely something from https://hg.mozilla.org/mozilla-central/pushloghtml?changeset=9b78e4ae32ae9fe7a22b4bb15efb51251d70c5e6

Also TEST-UNEXPECTED-FAIL | xpcshell-imap.ini:comm/mail/components/extensions/test/xpcshell/test_ext_experiments.js | xpcshell return code: -11

[task 2020-10-28T23:22:53.625Z] 23:22:53 INFO - PID 26434 | Assertion failure: NS_IsMainThread(), at /builds/worker/workspace/obj-build/dist/include/mozilla/ClearOnShutdown.h:133
[task 2020-10-28T23:22:53.625Z] 23:22:53 INFO - PID 26434 | #01: nsStringBundle::GetStringImpl(nsTSubstring<char> const&, nsTSubstring<char16_t>&) [intl/strres/nsStringBundle.cpp:573]
[task 2020-10-28T23:22:53.626Z] 23:22:53 INFO - PID 26434 | #02: nsStringBundleBase::GetStringFromName(char const*, nsTSubstring<char16_t>&) [intl/strres/nsStringBundle.cpp:568]
[task 2020-10-28T23:22:53.626Z] 23:22:53 INFO - PID 26434 | #03: nsStringBundleBase::FormatStringFromName(char const*, nsTArray<nsTString<char16_t> > const&, nsTSubstring<char16_t>&) [intl/strres/nsStringBundle.cpp:617]
[task 2020-10-28T23:22:53.626Z] 23:22:53 INFO - PID 26434 | #04: nsImapProtocol::ShowProgress() [comm/mailnews/imap/src/nsImapProtocol.cpp:5167]
[task 2020-10-28T23:22:53.627Z] 23:22:53 INFO - PID 26434 | #05: nsImapServerResponseParser::msg_fetch() [comm/mailnews/imap/src/nsImapServerResponseParser.cpp:939]
[task 2020-10-28T23:22:53.627Z] 23:22:53 INFO - PID 26434 | #06: nsImapServerResponseParser::response_data() [comm/mailnews/imap/src/nsImapServerResponseParser.cpp:659]
[task 2020-10-28T23:22:53.628Z] 23:22:53 INFO - PID 26434 | #07: nsImapServerResponseParser::ParseIMAPServerResponse(char const*, bool, char*) [comm/mailnews/imap/src/nsImapServerResponseParser.cpp:190]
[task 2020-10-28T23:22:53.628Z] 23:22:53 INFO - PID 26434 | #08: nsImapProtocol::FetchMessage(nsTString<char> const&, nsIMAPeFetchFields, char const*, unsigned int, unsigned int, char*) [comm/mailnews/imap/src/nsImapProtocol.cpp:3647]
[task 2020-10-28T23:22:53.629Z] 23:22:53 INFO - PID 26434 | #09: nsImapProtocol::FolderMsgDumpLoop(unsigned int*, unsigned int, nsIMAPeFetchFields) [comm/mailnews/imap/src/nsImapProtocol.cpp:4416]
[task 2020-10-28T23:22:53.630Z] 23:22:53 INFO - PID 26434 | #10: nsImapProtocol::ProcessMailboxUpdate(bool) [comm/mailnews/imap/src/nsImapProtocol.cpp:4299]
[task 2020-10-28T23:22:53.630Z] 23:22:53 INFO - PID 26434 | #11: nsImapProtocol::ProcessSelectedStateURL() [comm/mailnews/imap/src/nsImapProtocol.cpp:3135]
[task 2020-10-28T23:22:53.630Z] 23:22:53 INFO - PID 26434 | #12: nsImapProtocol::ProcessCurrentURL() [comm/mailnews/imap/src/nsImapProtocol.cpp:1798]
[task 2020-10-28T23:22:53.631Z] 23:22:53 INFO - PID 26434 | #13: nsImapProtocol::ImapThreadMainLoop() [comm/mailnews/imap/src/nsImapProtocol.cpp:1439]
[task 2020-10-28T23:22:53.631Z] 23:22:53 INFO - PID 26434 | #14: nsImapProtocol::Run() [comm/mailnews/imap/src/nsImapProtocol.cpp:1124]
[task 2020-10-28T23:22:53.632Z] 23:22:53 INFO - PID 26434 | #15: {virtual override thunk({offset(-8)}, nsImapProtocol::Run())} [/builds/worker/workspace/build/application/thunderbird/libxul.so + 0x4500805]
[task 2020-10-28T23:22:53.632Z] 23:22:53 INFO - PID 26434 | #16: nsThread::ProcessNextEvent(bool, bool*) [xpcom/threads/nsThread.cpp:1197]
[task 2020-10-28T23:22:53.632Z] 23:22:53 INFO - PID 26434 | #17: NS_ProcessNextEvent(nsIThread*, bool) [xpcom/threads/nsThreadUtils.cpp:513]
[task 2020-10-28T23:22:53.632Z] 23:22:53 INFO - PID 26434 | #18: mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate*) [ipc/glue/MessagePump.cpp:303]
[task 2020-10-28T23:22:53.633Z] 23:22:53 INFO - PID 26434 | #19: MessageLoop::RunInternal() [ipc/chromium/src/base/message_loop.cc:334]
[task 2020-10-28T23:22:53.633Z] 23:22:53 INFO - PID 26434 | #20: MessageLoop::Run() [ipc/chromium/src/base/message_loop.cc:310]
[task 2020-10-28T23:22:53.633Z] 23:22:53 INFO - PID 26434 | #21: nsThread::ThreadFunc(void*) [xpcom/threads/nsThread.cpp:444]
[task 2020-10-28T23:22:53.636Z] 23:22:53 INFO - PID 26434 | #22: _pt_root [nsprpub/pr/src/pthreads/ptthread.c:204]

Summary: perma comm/mail/base/test/unit/test_emptyTrash_dbViewWrapper.js | xpcshell return code: -11 → debug perma comm/mail/base/test/unit/test_emptyTrash_dbViewWrapper.js | xpcshell return code: -11

Must be from this: https://hg.mozilla.org/mozilla-central/rev/83bf4fd3b1fbca9dcbe23de9d1a1503eed62569a (bug 1667613)
Not sure if we're doing something wrong in IMAP or just not handling the (new) error as expected.

Regressed by: 1667613

Ben, please check what needs doing here.

Assignee: nobody → benc
Severity: normal → S2
Priority: P5 → P1

First impressions: It's a new bug introduced by the patch in Bug 1667613.

It's crashing because the IMAP logic is updating a progress message, and calls nsIStringBundle.formatStringFromName() which eventually calls PastShutdownPhase(), which asserts if we're not on the main thread.

I think this assert is wrong. My impression is that while nsIStringBundles must be created on the main thread, you're allowed to use them from other threads. The nsStringBundle implementation has a mutex to handle this and everything.

I_think_ the correct fix is for PastShutdownPhase() to be made threadsafe.
I guess this would entail protecting sCurrentShutdownPhase with a mutex (I'm happy to try doing this after the weekend).

PastShutdownPhase() was added recently in Bug 1663747. A lot of the other functions in ClearOnShutdown have a similar main-thread assertion, which is fine - most of those functions are mainthread-only. But the not-allowed-to-use-stringbundles-during shutdown rule added in Bug 1667613 seems entirely reasonable, and that implies being able to access the shutdown phase off the main thread. So stringbundles need a threadsafe PastShutdownPhase().

There's also a big elephant in the room: It seems awfully icky for the guts of the IMAP to be looking up strings for the GUI anyway! While I think PastShutdownPhase() should be threadsafe, I also think we should be purging GUIsms like this from our protocol code.

m_kato, what do you think about comment 9?

Flags: needinfo?(m_kato)
Summary: debug perma comm/mail/base/test/unit/test_emptyTrash_dbViewWrapper.js | xpcshell return code: -11 → debug perma - Assertion failure: NS_IsMainThread() - comm/mail/base/test/unit/test_emptyTrash_dbViewWrapper.js, comm/mailnews/imap/test/unit/test_imapFilterActions.js and others
Summary: debug perma - Assertion failure: NS_IsMainThread() - comm/mail/base/test/unit/test_emptyTrash_dbViewWrapper.js, comm/mailnews/imap/test/unit/test_imapFilterActions.js and others → debug perma - Assertion failure: NS_IsMainThread() - application crashed [@ nsStringBundle::LoadProperties() - comm/mail/base/test/unit/test_emptyTrash_dbViewWrapper.js, comm/mailnews/imap/test/unit/test_imapFilterActions.js and others

string bundle is XPCOM object and scriptable. Why does thunderbird use this on non-main thread?

Flags: needinfo?(m_kato)

(In reply to Makoto Kato [:m_kato] from comment #11)

string bundle is XPCOM object and scriptable.

Exposing my XPCOM-ignorance there, I think. To be honest I don't really know the exact restrictions that XPCOM and scriptable entail. I'm aware that in general it's frowned upon to use them off the main thread... but I wasn't sure how rigid that is (there's lots of historical TB-specific XPCOM stuff which is used cross-thread).
The stringbundle implementation seems to suggest they can be used off the main thread (as long as they are still created on the main thread):

https://searchfox.org/mozilla-central/search?q=thread&path=nsStringBundle.*&case=false&regexp=false

Why does thunderbird use this on non-main thread?

I'm not going to defend thunderbird at all here :-) For historical reasons there are a bunch of places down in the plumbing which poke the GUI in ways more direct than I'd really like. This is one of them, made worse by the fact it's on another thread.

Anyway, independent of whether or not it's valid to access stringbundle from off the main thread, here's a patch which should fix things.
It moves the stringbundle access out into the folder code. Still not quite as decoupled from the protocol layer as I'd like (that'd involve a big overhaul of the whole progress-communicating system(s)), but a step in the right direction at least.

Attachment #9185086 - Flags: review?(mkmelin+mozilla)
Comment on attachment 9185086 [details] [diff] [review]
1674077-move-imap-stringbundle-access-to-main-thread-1.patch

Review of attachment 9185086 [details] [diff] [review]:
-----------------------------------------------------------------

::: mailnews/imap/public/nsIImapMailFolderSink.idl
@@ +106,5 @@
>    void headerFetchCompleted(in nsIImapProtocol aProtocol);
>    void setBiffStateAndUpdate(in long biffState);
>    void progressStatusString(in nsIImapProtocol aProtocol, in string aMsgId, in wstring extraInfo);
> +  void percentProgress(in nsIImapProtocol aProtocol,
> +                       in ACString aFmtStringName, in AString aMailboxName,

A bit odd to have mixed string types in the idl.
Maybe both should be AUTF8String?

I would have thought this interface knows about the folder name, but apparently not...
Attachment #9185086 - Flags: review?(mkmelin+mozilla)

(In reply to Magnus Melin [:mkmelin] from comment #15)

> Review of attachment 9185086:
> -----------------------------------------------------------------
> 
> ::: mailnews/imap/public/nsIImapMailFolderSink.idl
> > +  void percentProgress(in nsIImapProtocol aProtocol,
> > +                       in ACString aFmtStringName, in AString aMailboxName,
> 
> A bit odd to have mixed string types in the idl.

Agreed, and I umm-ed and err-ed about it for a while, but I think the types are fine (it's just the interface as a whole which is screwed up ;- )

aFmtStringName is the name of the (localised) format string to look up in the bundle. Essentially a key, in ASCII.

aMailboxName, aCurrentProgress and aMaxProgress are parameters required to expand that format string. The formatting generates an AString, so it seems right that the string params (Mailbox) is also an AString.

Maybe both should be AUTF8String?

I think all strings should be passed in AUTF8String :-)

I would have thought this interface knows about the folder name, but
apparently not...

Well, the ultimate destination (an nsImapMailFolder) probably does know the mailbox name: the onlineName attr.
I don't think the folder would ever be given progress updates for another mailbox, but I'm not 100% sure on this. I've seen odder things.
The best argument for keeping the mailbox name as a parameter for now is that the format string expects three parameters (mailboxname, currentprogress, maxprogress), and it seems cleaner to pass them all along together.

What Should Happen (tm):

The progress interface shouldn't be passing the formatstring name, or any kind of string-based stuff at all. It should just tell the listener what's happening, along with whatever data the listener needs to compose a decent progress message itself. This probably means changing the interface to pass out an enum to say what the current operation is, rather than the formatstring name. Still need currentProgress and maxProgress params, but might not need the mailbox name.

Comment on attachment 9185086 [details] [diff] [review]
1674077-move-imap-stringbundle-access-to-main-thread-1.patch

Review of attachment 9185086 [details] [diff] [review]:
-----------------------------------------------------------------

Alright, let's take this
Attachment #9185086 - Flags: review+
Status: NEW → ASSIGNED
Target Milestone: --- → 84 Branch

Pushed by mkmelin@iki.fi:
https://hg.mozilla.org/comm-central/rev/f00c821955a9
Move IMAP GUI stringbundle access to main thread. r=mkmelin

Status: ASSIGNED → RESOLVED
Closed: 3 months ago
Resolution: --- → FIXED
You need to log in before you can comment on or make changes to this bug.