1 /* -*- Mode: C++; tab-width: 8; indent-tabs-mode: nil; c-basic-offset: 2 -*- */
2 /* vim: set ts=8 sts=2 et sw=2 tw=80: */
3 /* This Source Code Form is subject to the terms of the Mozilla Public
4 * License, v. 2.0. If a copy of the MPL was not distributed with this
5 * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
6
7 #include "nsTraceRefcnt.h"
8 #include "mozilla/Attributes.h"
9 #include "mozilla/AutoRestore.h"
10 #include "mozilla/CycleCollectedJSContext.h"
11 #include "mozilla/IntegerPrintfMacros.h"
12 #include "mozilla/Path.h"
13 #include "mozilla/StaticPtr.h"
14 #include "nsXPCOMPrivate.h"
15 #include "nscore.h"
16 #include "nsClassHashtable.h"
17 #include "nsContentUtils.h"
18 #include "nsISupports.h"
19 #include "nsHashKeys.h"
20 #include "nsPrintfCString.h"
21 #include "nsTArray.h"
22 #include "nsTHashtable.h"
23 #include "prenv.h"
24 #include "plstr.h"
25 #include "prlink.h"
26 #include "nsCRT.h"
27 #include <math.h>
28 #include "nsHashKeys.h"
29 #include "mozilla/StackWalk.h"
30 #include "nsThreadUtils.h"
31 #include "CodeAddressService.h"
32
33 #include "nsXULAppAPI.h"
34 #ifdef XP_WIN
35 # include <process.h>
36 # define getpid _getpid
37 #else
38 # include <unistd.h>
39 #endif
40
41 #include "mozilla/Atomics.h"
42 #include "mozilla/AutoRestore.h"
43 #include "mozilla/BlockingResourceBase.h"
44 #include "mozilla/PoisonIOInterposer.h"
45 #include "mozilla/UniquePtr.h"
46
47 #include <string>
48 #include <vector>
49
50 #ifdef HAVE_DLOPEN
51 # include <dlfcn.h>
52 #endif
53
54 #ifdef MOZ_DMD
55 # include "base/process_util.h"
56 # include "nsMemoryInfoDumper.h"
57 #endif
58
59 // dynamic_cast<void*> is not supported on Windows without RTTI.
60 #ifndef _WIN32
61 # define HAVE_CPP_DYNAMIC_CAST_TO_VOID_PTR
62 #endif
63
64 ////////////////////////////////////////////////////////////////////////////////
65
66 #include "prthread.h"
67
68 // We use a spin lock instead of a regular mutex because this lock is usually
69 // only held for a very short time, and gets grabbed at a very high frequency
70 // (~100000 times per second). On Mac, the overhead of using a regular lock
71 // is very high, see bug 1137963.
72 static mozilla::Atomic<uintptr_t, mozilla::ReleaseAcquire> gTraceLogLocked;
73
74 struct MOZ_STACK_CLASS AutoTraceLogLock final {
75 bool doRelease;
AutoTraceLogLockAutoTraceLogLock76 AutoTraceLogLock() : doRelease(true) {
77 uintptr_t currentThread =
78 reinterpret_cast<uintptr_t>(PR_GetCurrentThread());
79 if (gTraceLogLocked == currentThread) {
80 doRelease = false;
81 } else {
82 while (!gTraceLogLocked.compareExchange(0, currentThread)) {
83 PR_Sleep(PR_INTERVAL_NO_WAIT); /* yield */
84 }
85 }
86 }
~AutoTraceLogLockAutoTraceLogLock87 ~AutoTraceLogLock() {
88 if (doRelease) gTraceLogLocked = 0;
89 }
90 };
91
92 class BloatEntry;
93 struct SerialNumberRecord;
94
95 using mozilla::AutoRestore;
96 using mozilla::CodeAddressService;
97 using mozilla::CycleCollectedJSContext;
98 using mozilla::StaticAutoPtr;
99
100 using BloatHash = nsClassHashtable<nsDepCharHashKey, BloatEntry>;
101 using CharPtrSet = nsTHashtable<nsCharPtrHashKey>;
102 using IntPtrSet = nsTHashtable<IntPtrHashKey>;
103 using SerialHash = nsClassHashtable<nsVoidPtrHashKey, SerialNumberRecord>;
104
105 static StaticAutoPtr<BloatHash> gBloatView;
106 static StaticAutoPtr<CharPtrSet> gTypesToLog;
107 static StaticAutoPtr<IntPtrSet> gObjectsToLog;
108 static StaticAutoPtr<SerialHash> gSerialNumbers;
109
110 static intptr_t gNextSerialNumber;
111 static bool gDumpedStatistics = false;
112 static bool gLogJSStacks = false;
113
114 // By default, debug builds only do bloat logging. Bloat logging
115 // only tries to record when an object is created or destroyed, so we
116 // optimize the common case in NS_LogAddRef and NS_LogRelease where
117 // only bloat logging is enabled and no logging needs to be done.
118 enum LoggingType { NoLogging, OnlyBloatLogging, FullLogging };
119
120 static LoggingType gLogging;
121
122 static bool gLogLeaksOnly;
123
124 #define BAD_TLS_INDEX ((unsigned)-1)
125
126 // if gActivityTLS == BAD_TLS_INDEX, then we're
127 // unitialized... otherwise this points to a NSPR TLS thread index
128 // indicating whether addref activity is legal. If the PTR_TO_INT32 is 0 then
129 // activity is ok, otherwise not!
130 static unsigned gActivityTLS = BAD_TLS_INDEX;
131
132 static bool gInitialized;
133 static nsrefcnt gInitCount;
134
135 static FILE* gBloatLog = nullptr;
136 static FILE* gRefcntsLog = nullptr;
137 static FILE* gAllocLog = nullptr;
138 static FILE* gCOMPtrLog = nullptr;
139
140 static void WalkTheStackSavingLocations(std::vector<void*>& aLocations,
141 const void* aFirstFramePC);
142
143 struct SerialNumberRecord {
SerialNumberRecordSerialNumberRecord144 SerialNumberRecord()
145 : serialNumber(++gNextSerialNumber), refCount(0), COMPtrCount(0) {}
146
147 intptr_t serialNumber;
148 int32_t refCount;
149 int32_t COMPtrCount;
150 // We use std:: classes here rather than the XPCOM equivalents because the
151 // XPCOM equivalents do leak-checking, and if you try to leak-check while
152 // leak-checking, you're gonna have a bad time.
153 std::vector<void*> allocationStack;
154 mozilla::UniquePtr<char[]> jsStack;
155
SaveJSStackSerialNumberRecord156 void SaveJSStack() {
157 // If this thread isn't running JS, there's nothing to do.
158 if (!CycleCollectedJSContext::Get()) {
159 return;
160 }
161
162 if (!nsContentUtils::IsInitialized()) {
163 return;
164 }
165
166 JSContext* cx = nsContentUtils::GetCurrentJSContext();
167 if (!cx) {
168 return;
169 }
170
171 JS::UniqueChars chars = xpc_PrintJSStack(cx,
172 /*showArgs=*/false,
173 /*showLocals=*/false,
174 /*showThisProps=*/false);
175 size_t len = strlen(chars.get());
176 jsStack = mozilla::MakeUnique<char[]>(len + 1);
177 memcpy(jsStack.get(), chars.get(), len + 1);
178 }
179 };
180
181 struct nsTraceRefcntStats {
182 uint64_t mCreates;
183 uint64_t mDestroys;
184
HaveLeaksnsTraceRefcntStats185 bool HaveLeaks() const { return mCreates != mDestroys; }
186
ClearnsTraceRefcntStats187 void Clear() {
188 mCreates = 0;
189 mDestroys = 0;
190 }
191
NumLeakednsTraceRefcntStats192 int64_t NumLeaked() const { return (int64_t)(mCreates - mDestroys); }
193 };
194
195 #ifdef DEBUG
196 static const char kStaticCtorDtorWarning[] =
197 "XPCOM objects created/destroyed from static ctor/dtor";
198
AssertActivityIsLegal()199 static void AssertActivityIsLegal() {
200 if (gActivityTLS == BAD_TLS_INDEX || PR_GetThreadPrivate(gActivityTLS)) {
201 if (PR_GetEnv("MOZ_FATAL_STATIC_XPCOM_CTORS_DTORS")) {
202 MOZ_CRASH_UNSAFE(kStaticCtorDtorWarning);
203 } else {
204 NS_WARNING(kStaticCtorDtorWarning);
205 }
206 }
207 }
208 # define ASSERT_ACTIVITY_IS_LEGAL \
209 do { \
210 AssertActivityIsLegal(); \
211 } while (0)
212 #else
213 # define ASSERT_ACTIVITY_IS_LEGAL \
214 do { \
215 } while (0)
216 #endif // DEBUG
217
218 ////////////////////////////////////////////////////////////////////////////////
219
220 mozilla::StaticAutoPtr<CodeAddressService<>> gCodeAddressService;
221
222 ////////////////////////////////////////////////////////////////////////////////
223
224 class BloatEntry {
225 public:
BloatEntry(const char * aClassName,uint32_t aClassSize)226 BloatEntry(const char* aClassName, uint32_t aClassSize)
227 : mClassSize(aClassSize), mStats() {
228 MOZ_ASSERT(strlen(aClassName) > 0, "BloatEntry name must be non-empty");
229 mClassName = PL_strdup(aClassName);
230 mStats.Clear();
231 mTotalLeaked = 0;
232 }
233
~BloatEntry()234 ~BloatEntry() { PL_strfree(mClassName); }
235
GetClassSize()236 uint32_t GetClassSize() { return (uint32_t)mClassSize; }
GetClassName()237 const char* GetClassName() { return mClassName; }
238
Ctor()239 void Ctor() { mStats.mCreates++; }
240
Dtor()241 void Dtor() { mStats.mDestroys++; }
242
Total(BloatEntry * aTotal)243 void Total(BloatEntry* aTotal) {
244 aTotal->mStats.mCreates += mStats.mCreates;
245 aTotal->mStats.mDestroys += mStats.mDestroys;
246 aTotal->mClassSize +=
247 mClassSize * mStats.mCreates; // adjust for average in DumpTotal
248 aTotal->mTotalLeaked += mClassSize * mStats.NumLeaked();
249 }
250
DumpTotal(FILE * aOut)251 void DumpTotal(FILE* aOut) {
252 mClassSize /= mStats.mCreates;
253 Dump(-1, aOut);
254 }
255
PrintDumpHeader(FILE * aOut,const char * aMsg)256 bool PrintDumpHeader(FILE* aOut, const char* aMsg) {
257 fprintf(aOut, "\n== BloatView: %s, %s process %d\n", aMsg,
258 XRE_GetProcessTypeString(), getpid());
259 if (gLogLeaksOnly && !mStats.HaveLeaks()) {
260 return false;
261 }
262
263 // clang-format off
264 fprintf(aOut,
265 "\n" \
266 " |<----------------Class--------------->|<-----Bytes------>|<----Objects---->|\n" \
267 " | | Per-Inst Leaked| Total Rem|\n");
268 // clang-format on
269
270 this->DumpTotal(aOut);
271
272 return true;
273 }
274
Dump(int aIndex,FILE * aOut)275 void Dump(int aIndex, FILE* aOut) {
276 if (gLogLeaksOnly && !mStats.HaveLeaks()) {
277 return;
278 }
279
280 if (mStats.HaveLeaks() || mStats.mCreates != 0) {
281 fprintf(aOut,
282 "%4d |%-38.38s| %8d %8" PRId64 "|%8" PRIu64 " %8" PRId64 "|\n",
283 aIndex + 1, mClassName, GetClassSize(),
284 nsCRT::strcmp(mClassName, "TOTAL")
285 ? (mStats.NumLeaked() * GetClassSize())
286 : mTotalLeaked,
287 mStats.mCreates, mStats.NumLeaked());
288 }
289 }
290
291 protected:
292 char* mClassName;
293 // mClassSize is stored as a double because of the way we compute the avg
294 // class size for total bloat.
295 double mClassSize;
296 // mTotalLeaked is only used for the TOTAL entry.
297 int64_t mTotalLeaked;
298 nsTraceRefcntStats mStats;
299 };
300
EnsureBloatView()301 static void EnsureBloatView() {
302 if (!gBloatView) {
303 gBloatView = new BloatHash(256);
304 }
305 }
306
GetBloatEntry(const char * aTypeName,uint32_t aInstanceSize)307 static BloatEntry* GetBloatEntry(const char* aTypeName,
308 uint32_t aInstanceSize) {
309 EnsureBloatView();
310 BloatEntry* entry = gBloatView->Get(aTypeName);
311 if (!entry && aInstanceSize > 0) {
312 entry = gBloatView
313 ->InsertOrUpdate(
314 aTypeName, MakeUnique<BloatEntry>(aTypeName, aInstanceSize))
315 .get();
316 } else {
317 MOZ_ASSERT(
318 aInstanceSize == 0 || entry->GetClassSize() == aInstanceSize,
319 "Mismatched sizes were recorded in the memory leak logging table. "
320 "The usual cause of this is having a templated class that uses "
321 "MOZ_COUNT_{C,D}TOR in the constructor or destructor, respectively. "
322 "As a workaround, the MOZ_COUNT_{C,D}TOR calls can be moved to a "
323 "non-templated base class. Another possible cause is a runnable with "
324 "an mName that matches another refcounted class, or two refcounted "
325 "classes with the same class name in different C++ namespaces.");
326 }
327 return entry;
328 }
329
DumpSerialNumbers(const SerialHash::ConstIterator & aHashEntry,FILE * aFd,bool aDumpAsStringBuffer)330 static void DumpSerialNumbers(const SerialHash::ConstIterator& aHashEntry,
331 FILE* aFd, bool aDumpAsStringBuffer) {
332 SerialNumberRecord* record = aHashEntry.UserData();
333 auto* outputFile = aFd;
334 #ifdef HAVE_CPP_DYNAMIC_CAST_TO_VOID_PTR
335 fprintf(outputFile, "%" PRIdPTR " @%p (%d references; %d from COMPtrs)\n",
336 record->serialNumber, aHashEntry.Key(), record->refCount,
337 record->COMPtrCount);
338 #else
339 fprintf(outputFile, "%" PRIdPTR " @%p (%d references)\n",
340 record->serialNumber, aHashEntry.Key(), record->refCount);
341 #endif
342
343 if (aDumpAsStringBuffer) {
344 // This output will be wrong if the nsStringBuffer was used to
345 // store a char16_t string.
346 auto* buffer = static_cast<const nsStringBuffer*>(aHashEntry.Key());
347 nsDependentCString bufferString(static_cast<char*>(buffer->Data()));
348 fprintf(outputFile,
349 "Contents of leaked nsStringBuffer with storage size %d as a "
350 "char*: %s\n",
351 buffer->StorageSize(), bufferString.get());
352 }
353
354 if (!record->allocationStack.empty()) {
355 static const size_t bufLen = 1024;
356 char buf[bufLen];
357 fprintf(outputFile, "allocation stack:\n");
358 for (size_t i = 0, length = record->allocationStack.size(); i < length;
359 ++i) {
360 gCodeAddressService->GetLocation(i, record->allocationStack[i], buf,
361 bufLen);
362 fprintf(outputFile, "%s\n", buf);
363 }
364 }
365
366 if (gLogJSStacks) {
367 if (record->jsStack) {
368 fprintf(outputFile, "JS allocation stack:\n%s\n", record->jsStack.get());
369 } else {
370 fprintf(outputFile, "There is no JS context on the stack.\n");
371 }
372 }
373 }
374
375 template <>
376 class nsDefaultComparator<BloatEntry*, BloatEntry*> {
377 public:
Equals(BloatEntry * const & aEntry1,BloatEntry * const & aEntry2) const378 bool Equals(BloatEntry* const& aEntry1, BloatEntry* const& aEntry2) const {
379 return PL_strcmp(aEntry1->GetClassName(), aEntry2->GetClassName()) == 0;
380 }
LessThan(BloatEntry * const & aEntry1,BloatEntry * const & aEntry2) const381 bool LessThan(BloatEntry* const& aEntry1, BloatEntry* const& aEntry2) const {
382 return PL_strcmp(aEntry1->GetClassName(), aEntry2->GetClassName()) < 0;
383 }
384 };
385
DumpStatistics()386 nsresult nsTraceRefcnt::DumpStatistics() {
387 if (!gBloatLog || !gBloatView) {
388 return NS_ERROR_FAILURE;
389 }
390
391 AutoTraceLogLock lock;
392
393 MOZ_ASSERT(!gDumpedStatistics,
394 "Calling DumpStatistics more than once may result in "
395 "bogus positive or negative leaks being reported");
396 gDumpedStatistics = true;
397
398 // Don't try to log while we hold the lock, we'd deadlock.
399 AutoRestore<LoggingType> saveLogging(gLogging);
400 gLogging = NoLogging;
401
402 BloatEntry total("TOTAL", 0);
403 for (const auto& data : gBloatView->Values()) {
404 if (nsCRT::strcmp(data->GetClassName(), "TOTAL") != 0) {
405 data->Total(&total);
406 }
407 }
408
409 const char* msg;
410 if (gLogLeaksOnly) {
411 msg = "ALL (cumulative) LEAK STATISTICS";
412 } else {
413 msg = "ALL (cumulative) LEAK AND BLOAT STATISTICS";
414 }
415 const bool leaked = total.PrintDumpHeader(gBloatLog, msg);
416
417 nsTArray<BloatEntry*> entries(gBloatView->Count());
418 for (const auto& data : gBloatView->Values()) {
419 entries.AppendElement(data.get());
420 }
421
422 const uint32_t count = entries.Length();
423
424 if (!gLogLeaksOnly || leaked) {
425 // Sort the entries alphabetically by classname.
426 entries.Sort();
427
428 for (uint32_t i = 0; i < count; ++i) {
429 BloatEntry* entry = entries[i];
430 entry->Dump(i, gBloatLog);
431 }
432
433 fprintf(gBloatLog, "\n");
434 }
435
436 fprintf(gBloatLog, "nsTraceRefcnt::DumpStatistics: %d entries\n", count);
437
438 if (gSerialNumbers) {
439 bool onlyLoggingStringBuffers = gTypesToLog && gTypesToLog->Count() == 1 &&
440 gTypesToLog->Contains("nsStringBuffer");
441
442 fprintf(gBloatLog, "\nSerial Numbers of Leaked Objects:\n");
443 for (auto iter = gSerialNumbers->ConstIter(); !iter.Done(); iter.Next()) {
444 DumpSerialNumbers(iter, gBloatLog, onlyLoggingStringBuffers);
445 }
446 }
447
448 return NS_OK;
449 }
450
ResetStatistics()451 void nsTraceRefcnt::ResetStatistics() {
452 AutoTraceLogLock lock;
453 gBloatView = nullptr;
454 }
455
GetSerialNumber(void * aPtr,bool aCreate,void * aFirstFramePC)456 static intptr_t GetSerialNumber(void* aPtr, bool aCreate, void* aFirstFramePC) {
457 if (!aCreate) {
458 auto record = gSerialNumbers->Get(aPtr);
459 return record ? record->serialNumber : 0;
460 }
461
462 gSerialNumbers->WithEntryHandle(aPtr, [aFirstFramePC](auto&& entry) {
463 if (entry) {
464 MOZ_CRASH(
465 "If an object already has a serial number, we should be destroying "
466 "it.");
467 }
468
469 auto& record = entry.Insert(MakeUnique<SerialNumberRecord>());
470 WalkTheStackSavingLocations(record->allocationStack, aFirstFramePC);
471 if (gLogJSStacks) {
472 record->SaveJSStack();
473 }
474 });
475 return gNextSerialNumber;
476 }
477
RecycleSerialNumberPtr(void * aPtr)478 static void RecycleSerialNumberPtr(void* aPtr) { gSerialNumbers->Remove(aPtr); }
479
LogThisObj(intptr_t aSerialNumber)480 static bool LogThisObj(intptr_t aSerialNumber) {
481 return gObjectsToLog->Contains(aSerialNumber);
482 }
483
484 using EnvCharType = mozilla::filesystem::Path::value_type;
485
InitLog(const EnvCharType * aEnvVar,const char * aMsg,FILE ** aResult,const char * aProcType)486 static bool InitLog(const EnvCharType* aEnvVar, const char* aMsg,
487 FILE** aResult, const char* aProcType) {
488 #ifdef XP_WIN
489 // This is gross, I know.
490 const wchar_t* envvar = reinterpret_cast<const wchar_t*>(aEnvVar);
491 const char16_t* value = reinterpret_cast<const char16_t*>(::_wgetenv(envvar));
492 # define ENVVAR_PRINTF "%S"
493 #else
494 const char* envvar = aEnvVar;
495 const char* value = ::getenv(aEnvVar);
496 # define ENVVAR_PRINTF "%s"
497 #endif
498
499 if (value) {
500 nsTDependentString<EnvCharType> fname(value);
501 if (fname.EqualsLiteral("1")) {
502 *aResult = stdout;
503 fprintf(stdout, "### " ENVVAR_PRINTF " defined -- logging %s to stdout\n",
504 envvar, aMsg);
505 return true;
506 }
507 if (fname.EqualsLiteral("2")) {
508 *aResult = stderr;
509 fprintf(stdout, "### " ENVVAR_PRINTF " defined -- logging %s to stderr\n",
510 envvar, aMsg);
511 return true;
512 }
513 if (!XRE_IsParentProcess()) {
514 bool hasLogExtension =
515 fname.RFind(".log", true, -1, 4) == kNotFound ? false : true;
516 if (hasLogExtension) {
517 fname.Cut(fname.Length() - 4, 4);
518 }
519 fname.Append('_');
520 fname.AppendASCII(aProcType);
521 fname.AppendLiteral("_pid");
522 fname.AppendInt((uint32_t)getpid());
523 if (hasLogExtension) {
524 fname.AppendLiteral(".log");
525 }
526 }
527 #ifdef XP_WIN
528 FILE* stream = ::_wfopen(fname.get(), L"wN");
529 const wchar_t* fp = (const wchar_t*)fname.get();
530 #else
531 FILE* stream = ::fopen(fname.get(), "w");
532 const char* fp = fname.get();
533 #endif
534 if (stream) {
535 MozillaRegisterDebugFD(fileno(stream));
536 #ifdef MOZ_ENABLE_FORKSERVER
537 base::RegisterForkServerNoCloseFD(fileno(stream));
538 #endif
539 *aResult = stream;
540 fprintf(stderr,
541 "### " ENVVAR_PRINTF " defined -- logging %s to " ENVVAR_PRINTF
542 "\n",
543 envvar, aMsg, fp);
544
545 return true;
546 }
547
548 fprintf(stderr,
549 "### " ENVVAR_PRINTF
550 " defined -- unable to log %s to " ENVVAR_PRINTF "\n",
551 envvar, aMsg, fp);
552 MOZ_ASSERT(false, "Tried and failed to create an XPCOM log");
553
554 #undef ENVVAR_PRINTF
555 }
556 return false;
557 }
558
maybeUnregisterAndCloseFile(FILE * & aFile)559 static void maybeUnregisterAndCloseFile(FILE*& aFile) {
560 if (!aFile) {
561 return;
562 }
563
564 MozillaUnRegisterDebugFILE(aFile);
565 fclose(aFile);
566 aFile = nullptr;
567 }
568
DoInitTraceLog(const char * aProcType)569 static void DoInitTraceLog(const char* aProcType) {
570 #ifdef XP_WIN
571 # define ENVVAR(x) u"" x
572 #else
573 # define ENVVAR(x) x
574 #endif
575
576 bool defined = InitLog(ENVVAR("XPCOM_MEM_BLOAT_LOG"), "bloat/leaks",
577 &gBloatLog, aProcType);
578 if (!defined) {
579 gLogLeaksOnly =
580 InitLog(ENVVAR("XPCOM_MEM_LEAK_LOG"), "leaks", &gBloatLog, aProcType);
581 }
582 if (defined || gLogLeaksOnly) {
583 // Use the same bloat view, if there is one, to keep it consistent
584 // between the fork server and content processes.
585 EnsureBloatView();
586 } else if (gBloatView) {
587 nsTraceRefcnt::ResetStatistics();
588 }
589
590 InitLog(ENVVAR("XPCOM_MEM_REFCNT_LOG"), "refcounts", &gRefcntsLog, aProcType);
591
592 InitLog(ENVVAR("XPCOM_MEM_ALLOC_LOG"), "new/delete", &gAllocLog, aProcType);
593
594 const char* classes = getenv("XPCOM_MEM_LOG_CLASSES");
595
596 #ifdef HAVE_CPP_DYNAMIC_CAST_TO_VOID_PTR
597 if (classes) {
598 InitLog(ENVVAR("XPCOM_MEM_COMPTR_LOG"), "nsCOMPtr", &gCOMPtrLog, aProcType);
599 } else {
600 if (getenv("XPCOM_MEM_COMPTR_LOG")) {
601 fprintf(stdout,
602 "### XPCOM_MEM_COMPTR_LOG defined -- "
603 "but XPCOM_MEM_LOG_CLASSES is not defined\n");
604 }
605 }
606 #else
607 const char* comptr_log = getenv("XPCOM_MEM_COMPTR_LOG");
608 if (comptr_log) {
609 fprintf(stdout,
610 "### XPCOM_MEM_COMPTR_LOG defined -- "
611 "but it will not work without dynamic_cast\n");
612 }
613 #endif // HAVE_CPP_DYNAMIC_CAST_TO_VOID_PTR
614
615 #undef ENVVAR
616
617 if (classes) {
618 // if XPCOM_MEM_LOG_CLASSES was set to some value, the value is interpreted
619 // as a list of class names to track
620 //
621 // Use the same |gTypesToLog| and |gSerialNumbers| to keep them
622 // consistent through the fork server and content processes.
623 // Without this, counters will be incorrect.
624 if (!gTypesToLog) {
625 gTypesToLog = new CharPtrSet(256);
626 }
627
628 fprintf(stdout,
629 "### XPCOM_MEM_LOG_CLASSES defined -- "
630 "only logging these classes: ");
631 const char* cp = classes;
632 for (;;) {
633 char* cm = (char*)strchr(cp, ',');
634 if (cm) {
635 *cm = '\0';
636 }
637 if (!gTypesToLog->Contains(cp)) {
638 gTypesToLog->PutEntry(cp);
639 }
640 fprintf(stdout, "%s ", cp);
641 if (!cm) {
642 break;
643 }
644 *cm = ',';
645 cp = cm + 1;
646 }
647 fprintf(stdout, "\n");
648
649 if (!gSerialNumbers) {
650 gSerialNumbers = new SerialHash(256);
651 }
652 } else {
653 gTypesToLog = nullptr;
654 gSerialNumbers = nullptr;
655 }
656
657 const char* objects = getenv("XPCOM_MEM_LOG_OBJECTS");
658 if (objects) {
659 gObjectsToLog = new IntPtrSet(256);
660
661 if (!(gRefcntsLog || gAllocLog || gCOMPtrLog)) {
662 fprintf(stdout,
663 "### XPCOM_MEM_LOG_OBJECTS defined -- "
664 "but none of XPCOM_MEM_(REFCNT|ALLOC|COMPTR)_LOG is defined\n");
665 } else {
666 fprintf(stdout,
667 "### XPCOM_MEM_LOG_OBJECTS defined -- "
668 "only logging these objects: ");
669 const char* cp = objects;
670 for (;;) {
671 char* cm = (char*)strchr(cp, ',');
672 if (cm) {
673 *cm = '\0';
674 }
675 intptr_t top = 0;
676 intptr_t bottom = 0;
677 while (*cp) {
678 if (*cp == '-') {
679 bottom = top;
680 top = 0;
681 ++cp;
682 }
683 top *= 10;
684 top += *cp - '0';
685 ++cp;
686 }
687 if (!bottom) {
688 bottom = top;
689 }
690 for (intptr_t serialno = bottom; serialno <= top; serialno++) {
691 gObjectsToLog->PutEntry(serialno);
692 fprintf(stdout, "%" PRIdPTR " ", serialno);
693 }
694 if (!cm) {
695 break;
696 }
697 *cm = ',';
698 cp = cm + 1;
699 }
700 fprintf(stdout, "\n");
701 }
702 }
703
704 if (getenv("XPCOM_MEM_LOG_JS_STACK")) {
705 fprintf(stdout, "### XPCOM_MEM_LOG_JS_STACK defined\n");
706 gLogJSStacks = true;
707 }
708
709 if (gBloatLog) {
710 gLogging = OnlyBloatLogging;
711 }
712
713 if (gRefcntsLog || gAllocLog || gCOMPtrLog) {
714 gLogging = FullLogging;
715 }
716 }
717
InitTraceLog()718 static void InitTraceLog() {
719 if (gInitialized) {
720 return;
721 }
722 gInitialized = true;
723
724 DoInitTraceLog(XRE_GetProcessTypeString());
725 }
726
727 extern "C" {
728
EnsureWrite(FILE * aStream,const char * aBuf,size_t aLen)729 static void EnsureWrite(FILE* aStream, const char* aBuf, size_t aLen) {
730 #ifdef XP_WIN
731 int fd = _fileno(aStream);
732 #else
733 int fd = fileno(aStream);
734 #endif
735 while (aLen > 0) {
736 #ifdef XP_WIN
737 auto written = _write(fd, aBuf, aLen);
738 #else
739 auto written = write(fd, aBuf, aLen);
740 #endif
741 if (written <= 0 || size_t(written) > aLen) {
742 break;
743 }
744 aBuf += written;
745 aLen -= written;
746 }
747 }
748
PrintStackFrameCached(uint32_t aFrameNumber,void * aPC,void * aSP,void * aClosure)749 static void PrintStackFrameCached(uint32_t aFrameNumber, void* aPC, void* aSP,
750 void* aClosure) {
751 auto stream = static_cast<FILE*>(aClosure);
752 static const int buflen = 1024;
753 char buf[buflen + 5] = " "; // 5 for leading " " and trailing '\n'
754 int len =
755 gCodeAddressService->GetLocation(aFrameNumber, aPC, buf + 4, buflen);
756 len = std::min(len, buflen + 1 - 2) + 4;
757 buf[len++] = '\n';
758 buf[len] = '\0';
759 fflush(stream);
760 EnsureWrite(stream, buf, len);
761 }
762
RecordStackFrame(uint32_t,void * aPC,void *,void * aClosure)763 static void RecordStackFrame(uint32_t /*aFrameNumber*/, void* aPC,
764 void* /*aSP*/, void* aClosure) {
765 auto locations = static_cast<std::vector<void*>*>(aClosure);
766 locations->push_back(aPC);
767 }
768 }
769
770 /**
771 * This is a variant of |MozWalkTheStack| that uses |CodeAddressService| to
772 * cache the results of |NS_DescribeCodeAddress|. If |WalkTheStackCached| is
773 * being called frequently, it will be a few orders of magnitude faster than
774 * |MozWalkTheStack|. However, the cache uses a lot of memory, which can cause
775 * OOM crashes. Therefore, this should only be used for things like refcount
776 * logging which walk the stack extremely frequently.
777 */
WalkTheStackCached(FILE * aStream,const void * aFirstFramePC)778 static void WalkTheStackCached(FILE* aStream, const void* aFirstFramePC) {
779 if (!gCodeAddressService) {
780 gCodeAddressService = new CodeAddressService<>();
781 }
782 MozStackWalk(PrintStackFrameCached, aFirstFramePC, /* maxFrames */ 0,
783 aStream);
784 }
785
WalkTheStackSavingLocations(std::vector<void * > & aLocations,const void * aFirstFramePC)786 static void WalkTheStackSavingLocations(std::vector<void*>& aLocations,
787 const void* aFirstFramePC) {
788 if (!gCodeAddressService) {
789 gCodeAddressService = new CodeAddressService<>();
790 }
791 MozStackWalk(RecordStackFrame, aFirstFramePC, /* maxFrames */ 0, &aLocations);
792 }
793
794 //----------------------------------------------------------------------
795
796 EXPORT_XPCOM_API(void)
NS_LogInit()797 NS_LogInit() {
798 NS_SetMainThread();
799
800 // FIXME: This is called multiple times, we should probably not allow that.
801 if (++gInitCount) {
802 nsTraceRefcnt::SetActivityIsLegal(true);
803 }
804 }
805
806 EXPORT_XPCOM_API(void)
NS_LogTerm()807 NS_LogTerm() { mozilla::LogTerm(); }
808
809 #ifdef MOZ_DMD
810 // If MOZ_DMD_SHUTDOWN_LOG is set, dump a DMD report to a file.
811 // The value of this environment variable is used as the prefix
812 // of the file name, so you probably want something like "/tmp/".
813 // By default, this is run in all processes, but you can record a
814 // log only for a specific process type by setting MOZ_DMD_LOG_PROCESS
815 // to the process type you want to log, such as "default" or "tab".
816 // This method can't use the higher level XPCOM file utilities
817 // because it is run very late in shutdown to avoid recording
818 // information about refcount logging entries.
LogDMDFile()819 static void LogDMDFile() {
820 const char* dmdFilePrefix = PR_GetEnv("MOZ_DMD_SHUTDOWN_LOG");
821 if (!dmdFilePrefix) {
822 return;
823 }
824
825 const char* logProcessEnv = PR_GetEnv("MOZ_DMD_LOG_PROCESS");
826 if (logProcessEnv && !!strcmp(logProcessEnv, XRE_GetProcessTypeString())) {
827 return;
828 }
829
830 nsPrintfCString fileName("%sdmd-%d.log.gz", dmdFilePrefix,
831 base::GetCurrentProcId());
832 FILE* logFile = fopen(fileName.get(), "w");
833 if (NS_WARN_IF(!logFile)) {
834 return;
835 }
836
837 nsMemoryInfoDumper::DumpDMDToFile(logFile);
838 }
839 #endif // MOZ_DMD
840
841 namespace mozilla {
LogTerm()842 void LogTerm() {
843 NS_ASSERTION(gInitCount > 0, "NS_LogTerm without matching NS_LogInit");
844
845 if (--gInitCount == 0) {
846 #ifdef DEBUG
847 /* FIXME bug 491977: This is only going to operate on the
848 * BlockingResourceBase which is compiled into
849 * libxul/libxpcom_core.so. Anyone using external linkage will
850 * have their own copy of BlockingResourceBase statics which will
851 * not be freed by this method.
852 *
853 * It sounds like what we really want is to be able to register a
854 * callback function to call at XPCOM shutdown. Note that with
855 * this solution, however, we need to guarantee that
856 * BlockingResourceBase::Shutdown() runs after all other shutdown
857 * functions.
858 */
859 BlockingResourceBase::Shutdown();
860 #endif
861
862 if (gInitialized) {
863 nsTraceRefcnt::DumpStatistics();
864 nsTraceRefcnt::ResetStatistics();
865 }
866 nsTraceRefcnt::Shutdown();
867 nsTraceRefcnt::SetActivityIsLegal(false);
868 gActivityTLS = BAD_TLS_INDEX;
869
870 #ifdef MOZ_DMD
871 LogDMDFile();
872 #endif
873 }
874 }
875
876 } // namespace mozilla
877
878 EXPORT_XPCOM_API(MOZ_NEVER_INLINE void)
NS_LogAddRef(void * aPtr,nsrefcnt aRefcnt,const char * aClass,uint32_t aClassSize)879 NS_LogAddRef(void* aPtr, nsrefcnt aRefcnt, const char* aClass,
880 uint32_t aClassSize) {
881 ASSERT_ACTIVITY_IS_LEGAL;
882 if (!gInitialized) {
883 InitTraceLog();
884 }
885 if (gLogging == NoLogging) {
886 return;
887 }
888 if (aRefcnt == 1 || gLogging == FullLogging) {
889 AutoTraceLogLock lock;
890
891 if (aRefcnt == 1 && gBloatLog) {
892 BloatEntry* entry = GetBloatEntry(aClass, aClassSize);
893 if (entry) {
894 entry->Ctor();
895 }
896 }
897
898 // Here's the case where MOZ_COUNT_CTOR was not used,
899 // yet we still want to see creation information:
900
901 bool loggingThisType = (!gTypesToLog || gTypesToLog->Contains(aClass));
902 intptr_t serialno = 0;
903 if (gSerialNumbers && loggingThisType) {
904 serialno = GetSerialNumber(aPtr, aRefcnt == 1, CallerPC());
905 MOZ_ASSERT(serialno != 0,
906 "Serial number requested for unrecognized pointer! "
907 "Are you memmoving a refcounted object?");
908 auto record = gSerialNumbers->Get(aPtr);
909 if (record) {
910 ++record->refCount;
911 }
912 }
913
914 bool loggingThisObject = (!gObjectsToLog || LogThisObj(serialno));
915 if (aRefcnt == 1 && gAllocLog && loggingThisType && loggingThisObject) {
916 fprintf(gAllocLog, "\n<%s> %p %" PRIdPTR " Create [thread %p]\n", aClass,
917 aPtr, serialno, PR_GetCurrentThread());
918 WalkTheStackCached(gAllocLog, CallerPC());
919 }
920
921 if (gRefcntsLog && loggingThisType && loggingThisObject) {
922 // Can't use MOZ_LOG(), b/c it truncates the line
923 fprintf(gRefcntsLog,
924 "\n<%s> %p %" PRIuPTR " AddRef %" PRIuPTR " [thread %p]\n",
925 aClass, aPtr, serialno, aRefcnt, PR_GetCurrentThread());
926 WalkTheStackCached(gRefcntsLog, CallerPC());
927 fflush(gRefcntsLog);
928 }
929 }
930 }
931
932 EXPORT_XPCOM_API(MOZ_NEVER_INLINE void)
NS_LogRelease(void * aPtr,nsrefcnt aRefcnt,const char * aClass)933 NS_LogRelease(void* aPtr, nsrefcnt aRefcnt, const char* aClass) {
934 ASSERT_ACTIVITY_IS_LEGAL;
935 if (!gInitialized) {
936 InitTraceLog();
937 }
938 if (gLogging == NoLogging) {
939 return;
940 }
941 if (aRefcnt == 0 || gLogging == FullLogging) {
942 AutoTraceLogLock lock;
943
944 if (aRefcnt == 0 && gBloatLog) {
945 BloatEntry* entry = GetBloatEntry(aClass, 0);
946 if (entry) {
947 entry->Dtor();
948 }
949 }
950
951 bool loggingThisType = (!gTypesToLog || gTypesToLog->Contains(aClass));
952 intptr_t serialno = 0;
953 if (gSerialNumbers && loggingThisType) {
954 serialno = GetSerialNumber(aPtr, false, CallerPC());
955 MOZ_ASSERT(serialno != 0,
956 "Serial number requested for unrecognized pointer! "
957 "Are you memmoving a refcounted object?");
958 auto record = gSerialNumbers->Get(aPtr);
959 if (record) {
960 --record->refCount;
961 }
962 }
963
964 bool loggingThisObject = (!gObjectsToLog || LogThisObj(serialno));
965 if (gRefcntsLog && loggingThisType && loggingThisObject) {
966 // Can't use MOZ_LOG(), b/c it truncates the line
967 fprintf(gRefcntsLog,
968 "\n<%s> %p %" PRIuPTR " Release %" PRIuPTR " [thread %p]\n",
969 aClass, aPtr, serialno, aRefcnt, PR_GetCurrentThread());
970 WalkTheStackCached(gRefcntsLog, CallerPC());
971 fflush(gRefcntsLog);
972 }
973
974 // Here's the case where MOZ_COUNT_DTOR was not used,
975 // yet we still want to see deletion information:
976
977 if (aRefcnt == 0 && gAllocLog && loggingThisType && loggingThisObject) {
978 fprintf(gAllocLog, "\n<%s> %p %" PRIdPTR " Destroy [thread %p]\n", aClass,
979 aPtr, serialno, PR_GetCurrentThread());
980 WalkTheStackCached(gAllocLog, CallerPC());
981 }
982
983 if (aRefcnt == 0 && gSerialNumbers && loggingThisType) {
984 RecycleSerialNumberPtr(aPtr);
985 }
986 }
987 }
988
989 EXPORT_XPCOM_API(MOZ_NEVER_INLINE void)
NS_LogCtor(void * aPtr,const char * aType,uint32_t aInstanceSize)990 NS_LogCtor(void* aPtr, const char* aType, uint32_t aInstanceSize) {
991 ASSERT_ACTIVITY_IS_LEGAL;
992 if (!gInitialized) {
993 InitTraceLog();
994 }
995
996 if (gLogging == NoLogging) {
997 return;
998 }
999
1000 AutoTraceLogLock lock;
1001
1002 if (gBloatLog) {
1003 BloatEntry* entry = GetBloatEntry(aType, aInstanceSize);
1004 if (entry) {
1005 entry->Ctor();
1006 }
1007 }
1008
1009 bool loggingThisType = (!gTypesToLog || gTypesToLog->Contains(aType));
1010 intptr_t serialno = 0;
1011 if (gSerialNumbers && loggingThisType) {
1012 serialno = GetSerialNumber(aPtr, true, CallerPC());
1013 MOZ_ASSERT(serialno != 0,
1014 "GetSerialNumber should never return 0 when passed true");
1015 }
1016
1017 bool loggingThisObject = (!gObjectsToLog || LogThisObj(serialno));
1018 if (gAllocLog && loggingThisType && loggingThisObject) {
1019 fprintf(gAllocLog, "\n<%s> %p %" PRIdPTR " Ctor (%d)\n", aType, aPtr,
1020 serialno, aInstanceSize);
1021 WalkTheStackCached(gAllocLog, CallerPC());
1022 }
1023 }
1024
1025 EXPORT_XPCOM_API(MOZ_NEVER_INLINE void)
NS_LogDtor(void * aPtr,const char * aType,uint32_t aInstanceSize)1026 NS_LogDtor(void* aPtr, const char* aType, uint32_t aInstanceSize) {
1027 ASSERT_ACTIVITY_IS_LEGAL;
1028 if (!gInitialized) {
1029 InitTraceLog();
1030 }
1031
1032 if (gLogging == NoLogging) {
1033 return;
1034 }
1035
1036 AutoTraceLogLock lock;
1037
1038 if (gBloatLog) {
1039 BloatEntry* entry = GetBloatEntry(aType, aInstanceSize);
1040 if (entry) {
1041 entry->Dtor();
1042 }
1043 }
1044
1045 bool loggingThisType = (!gTypesToLog || gTypesToLog->Contains(aType));
1046 intptr_t serialno = 0;
1047 if (gSerialNumbers && loggingThisType) {
1048 serialno = GetSerialNumber(aPtr, false, CallerPC());
1049 MOZ_ASSERT(serialno != 0,
1050 "Serial number requested for unrecognized pointer! "
1051 "Are you memmoving a MOZ_COUNT_CTOR-tracked object?");
1052 RecycleSerialNumberPtr(aPtr);
1053 }
1054
1055 bool loggingThisObject = (!gObjectsToLog || LogThisObj(serialno));
1056
1057 // (If we're on a losing architecture, don't do this because we'll be
1058 // using LogDeleteXPCOM instead to get file and line numbers.)
1059 if (gAllocLog && loggingThisType && loggingThisObject) {
1060 fprintf(gAllocLog, "\n<%s> %p %" PRIdPTR " Dtor (%d)\n", aType, aPtr,
1061 serialno, aInstanceSize);
1062 WalkTheStackCached(gAllocLog, CallerPC());
1063 }
1064 }
1065
1066 EXPORT_XPCOM_API(MOZ_NEVER_INLINE void)
NS_LogCOMPtrAddRef(void * aCOMPtr,nsISupports * aObject)1067 NS_LogCOMPtrAddRef(void* aCOMPtr, nsISupports* aObject) {
1068 #ifdef HAVE_CPP_DYNAMIC_CAST_TO_VOID_PTR
1069 // Get the most-derived object.
1070 void* object = dynamic_cast<void*>(aObject);
1071
1072 // This is a very indirect way of finding out what the class is
1073 // of the object being logged. If we're logging a specific type,
1074 // then
1075 if (!gTypesToLog || !gSerialNumbers) {
1076 return;
1077 }
1078 if (!gInitialized) {
1079 InitTraceLog();
1080 }
1081 if (gLogging == FullLogging) {
1082 AutoTraceLogLock lock;
1083
1084 intptr_t serialno = GetSerialNumber(object, false, CallerPC());
1085 if (serialno == 0) {
1086 return;
1087 }
1088
1089 auto record = gSerialNumbers->Get(object);
1090 int32_t count = record ? ++record->COMPtrCount : -1;
1091 bool loggingThisObject = (!gObjectsToLog || LogThisObj(serialno));
1092
1093 if (gCOMPtrLog && loggingThisObject) {
1094 fprintf(gCOMPtrLog, "\n<?> %p %" PRIdPTR " nsCOMPtrAddRef %d %p\n",
1095 object, serialno, count, aCOMPtr);
1096 WalkTheStackCached(gCOMPtrLog, CallerPC());
1097 }
1098 }
1099 #endif // HAVE_CPP_DYNAMIC_CAST_TO_VOID_PTR
1100 }
1101
1102 EXPORT_XPCOM_API(MOZ_NEVER_INLINE void)
NS_LogCOMPtrRelease(void * aCOMPtr,nsISupports * aObject)1103 NS_LogCOMPtrRelease(void* aCOMPtr, nsISupports* aObject) {
1104 #ifdef HAVE_CPP_DYNAMIC_CAST_TO_VOID_PTR
1105 // Get the most-derived object.
1106 void* object = dynamic_cast<void*>(aObject);
1107
1108 // This is a very indirect way of finding out what the class is
1109 // of the object being logged. If we're logging a specific type,
1110 // then
1111 if (!gTypesToLog || !gSerialNumbers) {
1112 return;
1113 }
1114 if (!gInitialized) {
1115 InitTraceLog();
1116 }
1117 if (gLogging == FullLogging) {
1118 AutoTraceLogLock lock;
1119
1120 intptr_t serialno = GetSerialNumber(object, false, CallerPC());
1121 if (serialno == 0) {
1122 return;
1123 }
1124
1125 auto record = gSerialNumbers->Get(object);
1126 int32_t count = record ? --record->COMPtrCount : -1;
1127 bool loggingThisObject = (!gObjectsToLog || LogThisObj(serialno));
1128
1129 if (gCOMPtrLog && loggingThisObject) {
1130 fprintf(gCOMPtrLog, "\n<?> %p %" PRIdPTR " nsCOMPtrRelease %d %p\n",
1131 object, serialno, count, aCOMPtr);
1132 WalkTheStackCached(gCOMPtrLog, CallerPC());
1133 }
1134 }
1135 #endif // HAVE_CPP_DYNAMIC_CAST_TO_VOID_PTR
1136 }
1137
ClearLogs(bool aKeepCounters)1138 static void ClearLogs(bool aKeepCounters) {
1139 gCodeAddressService = nullptr;
1140 // These counters from the fork server process will be preserved
1141 // for the content processes to keep them consistent.
1142 if (!aKeepCounters) {
1143 gBloatView = nullptr;
1144 gTypesToLog = nullptr;
1145 gSerialNumbers = nullptr;
1146 }
1147 gObjectsToLog = nullptr;
1148 gLogJSStacks = false;
1149 gLogLeaksOnly = false;
1150 maybeUnregisterAndCloseFile(gBloatLog);
1151 maybeUnregisterAndCloseFile(gRefcntsLog);
1152 maybeUnregisterAndCloseFile(gAllocLog);
1153 maybeUnregisterAndCloseFile(gCOMPtrLog);
1154 }
1155
Shutdown()1156 void nsTraceRefcnt::Shutdown() { ClearLogs(false); }
1157
SetActivityIsLegal(bool aLegal)1158 void nsTraceRefcnt::SetActivityIsLegal(bool aLegal) {
1159 if (gActivityTLS == BAD_TLS_INDEX) {
1160 PR_NewThreadPrivateIndex(&gActivityTLS, nullptr);
1161 }
1162
1163 PR_SetThreadPrivate(gActivityTLS, reinterpret_cast<void*>(!aLegal));
1164 }
1165
1166 #ifdef MOZ_ENABLE_FORKSERVER
ResetLogFiles(const char * aProcType)1167 void nsTraceRefcnt::ResetLogFiles(const char* aProcType) {
1168 AutoRestore<LoggingType> saveLogging(gLogging);
1169 gLogging = NoLogging;
1170
1171 ClearLogs(true);
1172
1173 // Create log files with the correct process type in the name.
1174 DoInitTraceLog(aProcType);
1175 }
1176 #endif
1177