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