Open Bug 1771270 Opened 4 years ago Updated 2 months ago

C-C TB many warnings of the form, XPCOM object XXYYZ destroyed from static ctor/dtor

Tracking

(Not tracked)

Status:

NEW

People

(Reporter: ishikawa, Unassigned)

Details

ISHIKAWA, Chiaki

Reporter

Description

•

4 years ago

I am testing C-C TB locally under Debian GNU/Linux.
I test the full DEBUG version of TB.
During mochitest and xpcshell tests, I get many warnings in the debug log.

From mochitest: the leading number is the frequency of occurrences.

   1496 Thread] WARNING: XPCOM object nsStringBuffer released from static ctor/dtor: file /NEW-SSD/NREF-COMM-CENTRAL/mozilla/xpcom/base/nsTraceRefcnt.cpp:206
    116 Main Thread] WARNING: XPCOM object nsStringBuffer released from static ctor/dtor: file /NEW-SSD/NREF-COMM-CENTRAL/mozilla/xpcom/base/nsTraceRefcnt.cpp:206
     15 Thread] WARNING: XPCOM object UrlClassifierFeatureBase released from static ctor/dtor: file /NEW-SSD/NREF-COMM-CENTRAL/mozilla/xpcom/base/nsTraceRefcnt.cpp:206
      2 Thread] WARNING: XPCOM object nsStringBundleBase released from static ctor/dtor: file /NEW-SSD/NREF-COMM-CENTRAL/mozilla/xpcom/base/nsTraceRefcnt.cpp:206
      2 Thread] WARNING: XPCOM object nsStringBundle released from static ctor/dtor: file /NEW-SSD/NREF-COMM-CENTRAL/mozilla/xpcom/base/nsTraceRefcnt.cpp:206

From xpcshell test: you have to run xpcshell test with "--verbose"
"--serialize" to obtain meaningful log.

   3534 Main Thread] WARNING: XPCOM object nsStringBuffer released from static ctor/dtor: file /NEW-SSD/NREF-COMM-CENTRAL/mozilla/xpcom/base/nsTraceRefcnt.cpp:206
    746 Main Thread] WARNING: XPCOM object SourceList destroyed from static ctor/dtor: file /NEW-SSD/NREF-COMM-CENTRAL/mozilla/xpcom/base/nsTraceRefcnt.cpp:206
    746 Main Thread] WARNING: XPCOM object PerThreadData destroyed from static ctor/dtor: file /NEW-SSD/NREF-COMM-CENTRAL/mozilla/xpcom/base/nsTraceRefcnt.cpp:206
     87 XPCOM object nsStringBuffer released from static ctor/dtor: file /NEW-SSD/NREF-COMM-CENTRAL/mozilla/xpcom/base/nsTraceRefcnt.cpp:206
      1 Main Thread] WARNING: XPCOM object nsStringBundleBase released from static ctor/dtor: file /NEW-SSD/NREF-COMM-CENTRAL/mozilla/xpcom/base/nsTraceRefcnt.cpp:206
      1 Main Thread] WARNING: XPCOM object nsStringBundle released from static ctor/dtor: file /NEW-SSD/NREF-COMM-CENTRAL/mozilla/xpcom/base/nsTraceRefcnt.cpp:206
      1 Main Thread] WARNING: XPCOM object nsPersistentProperties released from static ctor/dtor: file /NEW-SSD/NREF-COMM-CENTRAL/mozilla/xpcom/base/nsTraceRefcnt.cpp:206
      1 Main Thread] WARNING: XPCOM object Mutex destroyed from static ctor/dtor: file /NEW-SSD/NREF-COMM-CENTRAL/mozilla/xpcom/base/nsTraceRefcnt.cpp:206

Close to 5K lines are a bit too much.

(Couting does not merge the same warning due to a formatting issue due to the leading space character when the elapsed time is less than 10 minutes, i.e., when the minute portion has only a digit.)

So how do I debug this?
I looked at similar bugs, but not quite sure what to make of the message, and more to the point exactly which I should look for and fix.
https://bugzilla.mozilla.org/buglist.cgi?quicksearch=ctor%2Fdtor&list_id=16096644

Now I notice that I get an assertion stack dump if I define an environment variable |MOZ_FATAL_STATIC_XPCOM_CTORS_DTORS| for a debug build
(Lucikly, I am testing DEBUG version of TB).
https://searchfox.org/mozilla-central/source/xpcom/base/nsTraceRefcnt.cpp#203

static void AssertActivityIsLegal(const char* aType, const char* aAction) {
  if (gActivityTLS == BAD_TLS_INDEX || PR_GetThreadPrivate(gActivityTLS)) {
    char buf[1024];
    SprintfLiteral(buf, "XPCOM object %s %s from static ctor/dtor", aType,
		   aAction);

    if (PR_GetEnv("MOZ_FATAL_STATIC_XPCOM_CTORS_DTORS")) {
      MOZ_CRASH_UNSAFE_PRINTF("%s", buf);
    } else {
      NS_WARNING(buf);
    }
  }
}

So I can get a stack dump at the first problem. Nice.

Here is such a stack dump.
I simply started and then stopped the debug version of C-C TB.
The first error occurred with "XPCOM object nsStringBuffer released from static ctor/dtor".

 0x00007f4978a4bbe5 in __GI___clock_nanosleep
    (clock_id=clock_id@entry=0, flags=flags@entry=0, req=req@entry=0x7fff7757a650, rem=rem@entry=0x7fff7757a650)
    at ../sysdeps/unix/sysv/linux/clock_nanosleep.c:43
#1  0x00007f4978a50ca3 in __GI___nanosleep
    (req=req@entry=0x7fff7757a650, rem=rem@entry=0x7fff7757a650)
    at ../sysdeps/unix/sysv/linux/nanosleep.c:25
#2  0x00007f4978a50bda in __sleep (seconds=0) at ../sysdeps/posix/sleep.c:55
#3  0x00007f496fd0c75e in common_crap_handler(int, void const*)
    (signum=11, aFirstFramePC=0x7f496fce0e9e <nsProfileLock::FatalSignalHandler(int, siginfo_t*, void*)+324>)
    at /NEW-SSD/NREF-COMM-CENTRAL/mozilla/toolkit/xre/nsSigHandlers.cpp:96
#4  0x00007f496fd0c77e in ah_crap_handler(int) (signum=<optimized out>)
    at /NEW-SSD/NREF-COMM-CENTRAL/mozilla/toolkit/xre/nsSigHandlers.cpp:104
#5  0x00007f496fce0e9e in nsProfileLock::FatalSignalHandler(int, siginfo_t*, void*) (signo=11, info=0x7fff7757a8b0, context=0x7fff7757a780)
    at /NEW-SSD/NREF-COMM-CENTRAL/mozilla/toolkit/profile/nsProfileLock.cpp:183
#6  0x00007f4978db6200 in <signal handler called> ()
    at /lib/x86_64-linux-gnu/libpthread.so.0
#7  MOZ_Crash
    (aReason=0x55d85435df80 <sPrintfCrashReason> "XPCOM object nsStringBuffer released from static ctor/dtor", aLine=204, aFilename=0x7f49729f9950 "/NEW-SSD/NREF-COMM-CENTRAL/mozilla/xpcom/base/nsTraceRefcnt.cpp")
    at /NEW-SSD/moz-obj-dir/objdir-tb3/dist/include/mozilla/Assertions.h:261
#8  AssertActivityIsLegal(char const*, char const*)
    (aType=aType@entry=0x7f49732b3ec4 "nsStringBuffer", aAction=aAction@entry=0x7f49732b8a84 "released")
    at /NEW-SSD/NREF-COMM-CENTRAL/mozilla/xpcom/base/nsTraceRefcnt.cpp:204
#9  0x00007f4969a007f5 in NS_LogRelease(void*, nsrefcnt, char const*)
    (aPtr=aPtr@entry=0x55d855c91680, aRefcnt=aRefcnt@entry=0, aClass=aClass@entry=0x7f49732b3ec4 "nsStringBuffer")
    at /NEW-SSD/NREF-COMM-CENTRAL/mozilla/xpcom/base/nsTraceRefcnt.cpp:936
#10 0x00007f496995d3e2 in nsStringBuffer::Release()
    (this=this@entry=0x55d855c91680)
    at /NEW-SSD/NREF-COMM-CENTRAL/mozilla/xpcom/string/nsSubstring.cpp:184
#11 0x00007f496995d427 in ReleaseData(void*, mozilla::detail::StringDataFlags)
    (aData=0x55d855c91688, aFlags=<optimized out>)
    at /NEW-SSD/NREF-COMM-CENTRAL/mozilla/xpcom/string/nsSubstring.cpp:110
#12 0x00007f4969960623 in nsTSubstring<char16_t>::Finalize()
    (this=this@entry=0x7f497639c680 <nsMsgDBView::mLabelPrefDescriptions+64>)
    at /NEW-SSD/NREF-COMM-CENTRAL/mozilla/xpcom/string/nsTSubstring.cpp:258
#13 0x00007f496fe1667d in nsTSubstring<char16_t>::~nsTSubstring()
    (this=0x7f497639c680 <nsMsgDBView::mLabelPrefDescriptions+64>, __in_chrg=<o--Type <RET> for more, q to quit, c to continue without paging--
ptimized out>)
    at /NEW-SSD/moz-obj-dir/objdir-tb3/dist/include/nsTSubstring.h:322
#14 nsTString<char16_t>::~nsTString()
    (this=0x7f497639c680 <nsMsgDBView::mLabelPrefDescriptions+64>, __in_chrg=<optimized out>) at /NEW-SSD/moz-obj-dir/objdir-tb3/dist/include/nsTString.h:26
#15 __tcf_0(void*) ()
    at /NEW-SSD/NREF-COMM-CENTRAL/mozilla/comm/mailnews/base/src/nsMsgDBView.cpp:82
#16 0x00007f49789c4f77 in __run_exit_handlers
    (status=0, listp=0x7f4978b58738 <__exit_funcs>, run_list_atexit=run_list_atexit@entry=true, run_dtors=run_dtors@entry=true) at exit.c:108
#17 0x00007f49789c511a in __GI_exit (status=<optimized out>) at exit.c:139
#18 0x00007f49789ad804 in __libc_start_main (main=
    0x55d8542919d5 <main(int, char**, char**)>, argc=1, argv=0x7fff7757b378, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7fff7757b368) at ../csu/libc-start.c:366
#19 0x000055d854290c1a in _start ()
(gdb)

I tried to search for suspect, but found only "static member/field" inside a Class. They don't count as suspect, or do they?

find calendar chat mail mailnews third_party tools -type f -name "*.[cphCPH]*" | xargs egrep "static[ \t]*nsString"
mailnews/base/src/nsMsgDBView.h:  static nsString kHighestPriorityString;
mailnews/base/src/nsMsgDBView.h:  static nsString kHighPriorityString;
mailnews/base/src/nsMsgDBView.h:  static nsString kLowestPriorityString;
mailnews/base/src/nsMsgDBView.h:  static nsString kLowPriorityString;
mailnews/base/src/nsMsgDBView.h:  static nsString kNormalPriorityString;
mailnews/base/src/nsMsgDBView.h:  static nsString kReadString;
mailnews/base/src/nsMsgDBView.h:  static nsString kRepliedString;
mailnews/base/src/nsMsgDBView.h:  static nsString kForwardedString;
mailnews/base/src/nsMsgDBView.h:  static nsString kRedirectedString;
mailnews/base/src/nsMsgDBView.h:  static nsString kNewString;
mailnews/base/src/nsMsgDBView.h:  static nsString kTodayString;
mailnews/base/src/nsMsgDBView.h:  static nsString kYesterdayString;
mailnews/base/src/nsMsgDBView.h:  static nsString kLastWeekString;
mailnews/base/src/nsMsgDBView.h:  static nsString kTwoWeeksAgoString;
mailnews/base/src/nsMsgDBView.h:  static nsString kOldMailString;
mailnews/base/src/nsMsgDBView.h:  static nsString kFutureDateString;
mailnews/base/src/nsMsgDBView.h:  static nsString mLabelPrefDescriptions[PREF_LABELS_MAX];
mailnews/base/src/nsMsgDBView.h:  static nsString m_connectorPattern;
mailnews/base/src/nsMsgDBFolder.h:  static nsString kLocalizedInboxName;
mailnews/base/src/nsMsgDBFolder.h:  static nsString kLocalizedTrashName;
mailnews/base/src/nsMsgDBFolder.h:  static nsString kLocalizedSentName;
mailnews/base/src/nsMsgDBFolder.h:  static nsString kLocalizedDraftsName;
mailnews/base/src/nsMsgDBFolder.h:  static nsString kLocalizedTemplatesName;
mailnews/base/src/nsMsgDBFolder.h:  static nsString kLocalizedUnsentName;
mailnews/base/src/nsMsgDBFolder.h:  static nsString kLocalizedJunkName;
mailnews/base/src/nsMsgDBFolder.h:  static nsString kLocalizedArchivesName;
mailnews/base/src/nsMsgDBFolder.h:  static nsString kLocalizedBrandShortName;
ishikawa@ip030:/NREF-COMM-CENTRAL/mozilla/comm$

OK, most of the field names start with the letter 'k' suggesting they
are constant (initialized at startup time, but would remain the same
until shutdown.).
There are a couple field variables that start with "m"

mailnews/base/src/nsMsgDBView.h:  static nsString mLabelPrefDescriptions[PREF_LABELS_MAX];
mailnews/base/src/nsMsgDBView.h:  static nsString m_connectorPattern;

From searchfox, I found that m_connectPattern is initialized by assignment.
https://searchfox.org/comm-central/search?q=m_connectorPattern&path=&case=false&regexp=false

	mailnews/base/src/nsMsgDBView.cpp
80	nsString nsMsgDBView::m_connectorPattern; <--- why missing |static|?
113	nsMsgDBView::m_connectorPattern.Truncate();
642	if (nsMsgDBView::m_connectorPattern.IsEmpty()) {
651	nsMsgDBView::m_connectorPattern = NS_ConvertUTF8toUTF16(str); <--- 
654	nsAutoString pattern(nsMsgDBView::m_connectorPattern);
	mailnews/base/src/nsMsgDBView.h
547	static nsString m_connectorPattern;

Is it being passed a static string on line 651? Unlikely, but who knows?

For mLabelPrefDescriptions
https://searchfox.org/comm-central/search?q=mLabelPrefDescriptions&path=&case=false&regexp=false

Textual Occurrences
	mailnews/base/src/nsMsgDBView.cpp
82	nsString nsMsgDBView::mLabelPrefDescriptions[PREF_LABELS_MAX];  <- why no |static|?
206	nsMsgDBView::mLabelPrefDescriptions[i]);
867	// We need to subtract 1 because mLabelPrefDescriptions is 0 based.
868	aLabelString = nsMsgDBView::mLabelPrefDescriptions[label - 1];
	mailnews/base/src/nsMsgDBView.h
499	static nsString mLabelPrefDescriptions[PREF_LABELS_MAX];

Line 206 above refers to the following code. mLabelPrefDescriptions
get initialized there.
https://searchfox.org/comm-central/source/mailnews/base/src/nsMsgDBView.cpp#206

nsresult nsMsgDBView::InitLabelStrings() {
  nsresult rv = NS_OK;
  nsCString prefString;

  for (int32_t i = 0; i < PREF_LABELS_MAX; i++) {
    prefString.Assign(PREF_LABELS_DESCRIPTION);
    prefString.AppendInt(i + 1);
    rv = GetPrefLocalizedString(prefString.get(),
                                nsMsgDBView::mLabelPrefDescriptions[i]);
  }
  return rv;
}

So, now I am not sure what to make of the situation.
How would I proceed with debugging the problem?.

Any tips on how a debugging process for this type of ctor/dtor problem should proceed is appreciated.

I am not familiar with this type of problems in mozilla code.
But given the paucity of developer man-power for TB, I think someone needs to dig up at least a few surface layers to find where the problem lies.

Wayne Mery (:wsmwk)

Updated

•

4 years ago

Component: Untriaged → General

Product: Thunderbird → MailNews Core

Wayne Mery (:wsmwk)

Comment 1

•

3 months ago

Still seeing this?

Flags: needinfo?(ishikawa)

ISHIKAWA, Chiaki

Reporter

Comment 2

•

2 months ago

Yes, I do.There are still many of them.

At this moment, this bug is low priority.
I am trying push the IMAP patches, Bug 1956408,
ThreadSanitizer: data race /builds/worker/checkouts/gecko/comm/mailnews/imap/src/nsImapProtocol.cpp:1278:23 in nsImapProtocol::TellThreadToDie(bool),
after fixing bitrot and certain hard-to-diagnose test failures recently seen on treeherder and locally.

Flags: needinfo?(ishikawa)

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

Bugzilla

C-C TB many warnings of the form, XPCOM object XXYYZ destroyed from static ctor/dtor

Categories

(MailNews Core :: General, defect)

Tracking

(Not tracked)

People

(Reporter: ishikawa, Unassigned)

References

Details

Crash Data

Security

(public)

User Story

Description

Updated

Comment 1

Comment 2