Closed
Bug 1172138
Opened 9 years ago
Closed 9 years ago
mozilla_sampler causes 5 instances of "XPCOM objects created/destroyed from static ctor/dtor" on startup
Categories
(Core :: Gecko Profiler, defect)
Core
Gecko Profiler
Tracking
()
RESOLVED
FIXED
mozilla41
Tracking | Status | |
---|---|---|
firefox41 | --- | fixed |
People
(Reporter: erahm, Assigned: erahm)
References
(Blocks 1 open bug)
Details
Attachments
(2 files)
(deleted),
text/plain
|
Details | |
(deleted),
patch
|
froydnj
:
review+
|
Details | Diff | Splinter Review |
At least on linux I'm seeing various mozilla_sampler related things causing the message: "XPCOM objects created/destroyed from static ctor/dtor" to be printed when starting firefox on debug builds.
I've attached stack traces at each point. The message is a bit misleading, these don't seem to be static ctor related, rather it's the GeckoProfiler poking xpcom things before xpcom has called NS_LogInit.
I'm not sure what the proper thing to do here is, possibly we need to delay starting the profiler until after xpcom init?
Comment 1•9 years ago
|
||
I think this is a dupe of bug 1067547.
Assignee | ||
Comment 2•9 years ago
|
||
This might be slightly different, these errors are only in the content process.
Assignee | ||
Comment 3•9 years ago
|
||
Attachment #8616242 -
Flags: review?(nfroyd)
Assignee | ||
Updated•9 years ago
|
Assignee: nobody → erahm
Status: NEW → ASSIGNED
Assignee | ||
Comment 4•9 years ago
|
||
Comment 5•9 years ago
|
||
Comment on attachment 8616242 [details] [diff] [review]
Call PR_LogInit before profiler_init
Review of attachment 8616242 [details] [diff] [review]:
-----------------------------------------------------------------
Your try run looks busted.
Also, it's not clear to me what the XPCOM objects here are. The stack traces suggest something around mutexes/deadlock detector bits, but I can't see anything calling NS_Log* after several minutes of poking around in that area. Can you figure out what exactly is triggering that (GDB?) ?
Attachment #8616242 -
Flags: review?(nfroyd)
Assignee | ||
Comment 6•9 years ago
|
||
Assignee | ||
Comment 7•9 years ago
|
||
(In reply to Nathan Froyd [:froydnj] [:nfroyd] from comment #5)
> Comment on attachment 8616242 [details] [diff] [review]
> Call PR_LogInit before profiler_init
>
> Review of attachment 8616242 [details] [diff] [review]:
> -----------------------------------------------------------------
>
> Your try run looks busted.
Yes, unfortunately I had another patch that turned on (unrelated) assertions applied from a previous try run.
> Also, it's not clear to me what the XPCOM objects here are. The stack
> traces suggest something around mutexes/deadlock detector bits, but I can't
> see anything calling NS_Log* after several minutes of poking around in that
> area. Can you figure out what exactly is triggering that (GDB?) ?
I'll do a GDB run w/o the patch to see what's up.
Assignee | ||
Comment 8•9 years ago
|
||
This is a bit of a pain to debug, the messages are coming from the child process (this doesn't repro on non-e10s). I managed to get slightly better stacks:
#0 AssertActivityIsLegal () at /home/erahm/dev/mozilla-central/xpcom/base/nsTraceRefcnt.cpp:155
#1 0x00007f6e81a9e186 in NS_LogCtor (aPtr=0x7f6e77d52820, aType=0x7f6e848914e0 "nsTArray_base", aInstanceSize=8)
at /home/erahm/dev/mozilla-central/xpcom/base/nsTraceRefcnt.cpp:1106
#2 0x00007f6e81b08299 in nsTArray_Impl (this=0x7f6e77d52820) at /home/erahm/dev/mozilla-central/xpcom/build/../glue/nsTArray.h:833
#3 nsTArray (this=0x7f6e77d52820) at /home/erahm/dev/mozilla-central/xpcom/build/../glue/nsTArray.h:1976
#4 OrderingEntry (aResource=0x7f6e77d52800, this=0x7f6e77d52820) at ../../dist/include/mozilla/DeadlockDetector.h:89
#5 mozilla::DeadlockDetector<mozilla::BlockingResourceBase>::Add (this=0x7f6e77d07300, aResource=0x7f6e77d52800)
at ../../dist/include/mozilla/DeadlockDetector.h:182
#6 0x00007f6e839ab3ac in OffTheBooksMutex (aName=0x7f6e84bf72fd "sRegisteredThreads mutex", this=0x7f6e77d52800)
at ../../dist/include/mozilla/Mutex.h:47
#7 Mutex (aName=0x7f6e84bf72fd "sRegisteredThreads mutex", this=0x7f6e77d52800) at ../../dist/include/mozilla/Mutex.h:124
#8 Sampler::Startup () at /home/erahm/dev/mozilla-central/tools/profiler/platform.cpp:89
#9 0x00007f6e839ad5e2 in mozilla_sampler_init (stackTop=stackTop@entry=0x7fff1be131c7)
at /home/erahm/dev/mozilla-central/tools/profiler/platform.cpp:471
#10 0x00007f6e83b62f35 in profiler_init (stackTop=0x7fff1be131c7) at ../../dist/include/GeckoProfilerImpl.h:66
#11 XRE_InitChildProcess (aArgc=5, aArgv=0x7fff1be14758, aGMPLoader=0x0)
at /home/erahm/dev/mozilla-central/toolkit/xre/nsEmbedFunctions.cpp:354
#12 0x0000000000408173 in content_process_main (argc=5, argv=0x7fff1be14758)
at /home/erahm/dev/mozilla-central/ipc/app/../contentproc/plugin-container.cpp:236
#13 0x00007f6e80409ec5 in __libc_start_main (main=0x407cf1 <main(int, char**)>, argc=6, argv=0x7fff1be14758, init=<optimized out>,
fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7fff1be14748) at libc-start.c:287
#14 0x0000000000407dcc in _start ()
So sampler creates a mutex, which gets added to the deadlock detector's list of entries, entry has an nsTArray which I guess does some LogCtor magic. Entry has two arrays so there's a second identical stack trace.
Then a stack trace for the Mutex:
#0 AssertActivityIsLegal () at /home/erahm/dev/mozilla-central/xpcom/base/nsTraceRefcnt.cpp:155
#1 0x00007f6e81a9e186 in NS_LogCtor (aPtr=0x7f6e77d52800, aType=0x7f6e848900d4 "Mutex", aInstanceSize=32)
at /home/erahm/dev/mozilla-central/xpcom/base/nsTraceRefcnt.cpp:1106
#2 0x00007f6e839ab3ee in Mutex (aName=0x7f6e84bf72fd "sRegisteredThreads mutex", this=0x7f6e77d52800)
at ../../dist/include/mozilla/Mutex.h:126
#3 Sampler::Startup () at /home/erahm/dev/mozilla-central/tools/profiler/platform.cpp:89
#4 0x00007f6e839ad5e2 in mozilla_sampler_init (stackTop=stackTop@entry=0x7fff1be131c7)
at /home/erahm/dev/mozilla-central/tools/profiler/platform.cpp:471
#5 0x00007f6e83b62f35 in profiler_init (stackTop=0x7fff1be131c7) at ../../dist/include/GeckoProfilerImpl.h:66
#6 XRE_InitChildProcess (aArgc=5, aArgv=0x7fff1be14758, aGMPLoader=0x0)
at /home/erahm/dev/mozilla-central/toolkit/xre/nsEmbedFunctions.cpp:354
#7 0x0000000000408173 in content_process_main (argc=5, argv=0x7fff1be14758)
at /home/erahm/dev/mozilla-central/ipc/app/../contentproc/plugin-container.cpp:236
#8 0x00007f6e80409ec5 in __libc_start_main (main=0x407cf1 <main(int, char**)>, argc=6, argv=0x7fff1be14758, init=<optimized out>,
fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7fff1be14748) at libc-start.c:287
#9 0x0000000000407dcc in _start ()
Then the sampler pokes the nsThreadManager, it has an OffTheBooksMutex, which causes another deadlock detector entry, which has 2 arrays that produce this stack trace:
#0 AssertActivityIsLegal () at /home/erahm/dev/mozilla-central/xpcom/base/nsTraceRefcnt.cpp:155
#1 0x00007f6e81a9e186 in NS_LogCtor (aPtr=0x7f6e77d52860, aType=0x7f6e848914e0 "nsTArray_base", aInstanceSize=8)
at /home/erahm/dev/mozilla-central/xpcom/base/nsTraceRefcnt.cpp:1106
#2 0x00007f6e81b08299 in nsTArray_Impl (this=0x7f6e77d52860) at /home/erahm/dev/mozilla-central/xpcom/build/../glue/nsTArray.h:833
#3 nsTArray (this=0x7f6e77d52860) at /home/erahm/dev/mozilla-central/xpcom/build/../glue/nsTArray.h:1976
#4 OrderingEntry (aResource=0x7f6e86c73d90 <nsThreadManager::get()::sInstance+96>, this=0x7f6e77d52860)
at ../../dist/include/mozilla/DeadlockDetector.h:89
#5 mozilla::DeadlockDetector<mozilla::BlockingResourceBase>::Add (this=0x7f6e77d07300,
aResource=0x7f6e86c73d90 <nsThreadManager::get()::sInstance+96>) at ../../dist/include/mozilla/DeadlockDetector.h:182
#6 0x00007f6e81a55595 in mozilla::OffTheBooksMutex::OffTheBooksMutex (this=0x7f6e86c73d90 <nsThreadManager::get()::sInstance+96>,
aName=<optimized out>) at ../../dist/include/mozilla/Mutex.h:47
#7 0x00007f6e81aead26 in nsThreadManager (this=0x7f6e86c73d30 <nsThreadManager::get()::sInstance>)
at /home/erahm/dev/mozilla-central/xpcom/threads/nsThreadManager.h:64
#8 nsThreadManager::get () at /home/erahm/dev/mozilla-central/xpcom/threads/nsThreadManager.h:25
#9 0x00007f6e81b0e726 in NS_GetCurrentThread () at /home/erahm/dev/mozilla-central/xpcom/glue/nsThreadUtils.cpp:322
#10 0x00007f6e839acc69 in ThreadInfo::ThreadInfo (this=this@entry=0x7f6e77d51d80, aName=<optimized out>, aThreadId=22949,
aIsMainThread=<optimized out>, aPseudoStack=aPseudoStack@entry=0x7f6e77d6e000, aStackTop=0x7fff1be131c7)
at /home/erahm/dev/mozilla-central/tools/profiler/platform.cpp:134
#11 0x00007f6e839acd21 in StackOwningThreadInfo::StackOwningThreadInfo (this=0x7f6e77d51d80, aName=<optimized out>,
aThreadId=<optimized out>, aIsMainThread=<optimized out>, aPseudoStack=0x7f6e77d6e000, aStackTop=<optimized out>)
at /home/erahm/dev/mozilla-central/tools/profiler/platform.cpp:161
#12 0x00007f6e83998aaa in Sampler::RegisterCurrentThread (aName=aName@entry=0x7f6e84bf775f "GeckoMain",
aPseudoStack=aPseudoStack@entry=0x7f6e77d6e000, aIsMainThread=aIsMainThread@entry=true, stackTop=stackTop@entry=0x7fff1be131c7)
at /home/erahm/dev/mozilla-central/tools/profiler/platform-linux.cc:532
#13 0x00007f6e839ad67d in mozilla_sampler_init (stackTop=stackTop@entry=0x7fff1be131c7)
at /home/erahm/dev/mozilla-central/tools/profiler/platform.cpp:479
#14 0x00007f6e83b62f35 in profiler_init (stackTop=0x7fff1be131c7) at ../../dist/include/GeckoProfilerImpl.h:66
#15 XRE_InitChildProcess (aArgc=5, aArgv=0x7fff1be14758, aGMPLoader=0x0)
at /home/erahm/dev/mozilla-central/toolkit/xre/nsEmbedFunctions.cpp:354
#16 0x0000000000408173 in content_process_main (argc=5, argv=0x7fff1be14758)
at /home/erahm/dev/mozilla-central/ipc/app/../contentproc/plugin-container.cpp:236
#17 0x00007f6e80409ec5 in __libc_start_main (main=0x407cf1 <main(int, char**)>, argc=6, argv=0x7fff1be14758, init=<optimized out>,
fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7fff1be14748) at libc-start.c:287
#18 0x0000000000407dcc in _start ()
Comment 9•9 years ago
|
||
Comment on attachment 8616242 [details] [diff] [review]
Call PR_LogInit before profiler_init
Review of attachment 8616242 [details] [diff] [review]:
-----------------------------------------------------------------
r+'ing this after discussing with Eric. Since infra is hosed right now, we can't get a good clean try run, but ideally we'll get a green debug run before this lands.
Attachment #8616242 -
Flags: review+
Assignee | ||
Comment 10•9 years ago
|
||
Assignee | ||
Comment 11•9 years ago
|
||
Comment 12•9 years ago
|
||
Status: ASSIGNED → RESOLVED
Closed: 9 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla41
You need to log in
before you can comment on or make changes to this bug.
Description
•