xpcom/build/MainThreadIOLogger.cpp

   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 "MainThreadIOLogger.h"
   8
   9 #include "GeckoProfiler.h"
  10 #include "IOInterposerPrivate.h"
  11 #include "mozilla/IOInterposer.h"
  12 #include "mozilla/StaticPtr.h"
  13 #include "mozilla/TimeStamp.h"
  14 #include "mozilla/UniquePtr.h"
  15 #include "nsNativeCharsetUtils.h"
  16 #include "nsThreadUtils.h"
  17
  18 /**
  19  * This code uses NSPR stuff and STL containers because it must be detached
  20  * from leak checking code; this observer runs until the process terminates.
  21  */
  22
  23 #include <prenv.h>
  24 #include <prprf.h>
  25 #include <prthread.h>
  26 #include <vector>
  27
  28 namespace {
  29
  30 struct ObservationWithStack {
  31   explicit ObservationWithStack(mozilla::IOInterposeObserver::Observation& aObs,
  32                                 ProfilerBacktrace* aStack)
  33       : mObservation(aObs), mStack(aStack) {
  34     aObs.Filename(mFilename);
  35   }
  36
  37   mozilla::IOInterposeObserver::Observation mObservation;
  38   ProfilerBacktrace* mStack;
  39   nsString mFilename;
  40 };
  41
  42 class MainThreadIOLoggerImpl final : public mozilla::IOInterposeObserver {
  43  public:
  44   MainThreadIOLoggerImpl();
  45   ~MainThreadIOLoggerImpl();
  46
  47   bool Init();
  48
  49   void Observe(Observation& aObservation) override;
  50
  51  private:
  52   static void sIOThreadFunc(void* aArg);
  53   void IOThreadFunc();
  54
  55   mozilla::TimeStamp mLogStartTime;
  56   const char* mFileName;
  57   PRThread* mIOThread;
  58   mozilla::IOInterposer::Monitor mMonitor;
  59   bool mShutdownRequired MOZ_GUARDED_BY(mMonitor);
  60   std::vector<ObservationWithStack> mObservations MOZ_GUARDED_BY(mMonitor);
  61 };
  62
  63 static mozilla::StaticAutoPtr<MainThreadIOLoggerImpl> sImpl;
  64
  65 MainThreadIOLoggerImpl::MainThreadIOLoggerImpl()
  66     : mFileName(nullptr), mIOThread(nullptr), mShutdownRequired(false) {}
  67
  68 MainThreadIOLoggerImpl::~MainThreadIOLoggerImpl() {
  69   if (!mIOThread) {
  70     return;
  71   }
  72   {
  73     // Scope for lock
  74     mozilla::IOInterposer::MonitorAutoLock lock(mMonitor);
  75     mShutdownRequired = true;
  76     mMonitor.Notify();
  77   }
  78   PR_JoinThread(mIOThread);
  79   mIOThread = nullptr;
  80 }
  81
  82 bool MainThreadIOLoggerImpl::Init() {
  83   if (mFileName) {
  84     // Already initialized
  85     return true;
  86   }
  87   mFileName = PR_GetEnv("MOZ_MAIN_THREAD_IO_LOG");
  88   if (!mFileName) {
  89     // Can't start
  90     return false;
  91   }
  92   mIOThread =
  93       PR_CreateThread(PR_USER_THREAD, &sIOThreadFunc, this, PR_PRIORITY_LOW,
  94                       PR_GLOBAL_THREAD, PR_JOINABLE_THREAD, 0);
  95   if (!mIOThread) {
  96     return false;
  97   }
  98   return true;
  99 }
 100
 101 /* static */
 102 void MainThreadIOLoggerImpl::sIOThreadFunc(void* aArg) {
 103   AUTO_PROFILER_REGISTER_THREAD("MainThreadIOLogger");
 104
 105   NS_SetCurrentThreadName("MainThreadIOLogger");
 106   MainThreadIOLoggerImpl* obj = static_cast<MainThreadIOLoggerImpl*>(aArg);
 107   obj->IOThreadFunc();
 108 }
 109
 110 void MainThreadIOLoggerImpl::IOThreadFunc() {
 111   PRFileDesc* fd = PR_Open(mFileName, PR_WRONLY | PR_CREATE_FILE | PR_TRUNCATE,
 112                            PR_IRUSR | PR_IWUSR | PR_IRGRP);
 113   if (!fd) {
 114     mozilla::IOInterposer::MonitorAutoLock lock(mMonitor);
 115     mShutdownRequired = true;
 116     std::vector<ObservationWithStack>().swap(mObservations);
 117     return;
 118   }
 119   mLogStartTime = mozilla::TimeStamp::Now();
 120   {
 121     // Scope for lock
 122     mozilla::IOInterposer::MonitorAutoLock lock(mMonitor);
 123     while (true) {
 124       while (!mShutdownRequired && mObservations.empty()) {
 125         mMonitor.Wait();
 126       }
 127       if (mShutdownRequired) {
 128         break;
 129       }
 130       // Pull events off the shared array onto a local one
 131       std::vector<ObservationWithStack> observationsToWrite;
 132       observationsToWrite.swap(mObservations);
 133
 134       // Release the lock so that we're not holding anybody up during I/O
 135       mozilla::IOInterposer::MonitorAutoUnlock unlock(mMonitor);
 136
 137       // Now write the events.
 138       for (auto i = observationsToWrite.begin(), e = observationsToWrite.end();
 139            i != e; ++i) {
 140         if (i->mObservation.ObservedOperation() == OpNextStage) {
 141           PR_fprintf(
 142               fd, "%f,NEXT-STAGE\n",
 143               (mozilla::TimeStamp::Now() - mLogStartTime).ToMilliseconds());
 144           continue;
 145         }
 146         double durationMs = i->mObservation.Duration().ToMilliseconds();
 147         nsAutoCString nativeFilename;
 148         nativeFilename.AssignLiteral("(not available)");
 149         if (!i->mFilename.IsEmpty()) {
 150           if (NS_FAILED(NS_CopyUnicodeToNative(i->mFilename, nativeFilename))) {
 151             nativeFilename.AssignLiteral("(conversion failed)");
 152           }
 153         }
 154         // clang-format off
 155         /**
 156          * Format:
 157          * Start Timestamp (Milliseconds), Operation, Duration (Milliseconds), Event Source, Filename
 158          */
 159         // clang-format on
 160         if (PR_fprintf(
 161                 fd, "%f,%s,%f,%s,%s\n",
 162                 (i->mObservation.Start() - mLogStartTime).ToMilliseconds(),
 163                 i->mObservation.ObservedOperationString(), durationMs,
 164                 i->mObservation.Reference(), nativeFilename.get()) > 0) {
 165           // TODO: Write out the callstack
 166           i->mStack = nullptr;
 167         }
 168       }
 169     }
 170   }
 171   PR_Close(fd);
 172 }
 173
 174 void MainThreadIOLoggerImpl::Observe(Observation& aObservation) {
 175   if (!mFileName || !IsMainThread()) {
 176     return;
 177   }
 178   mozilla::IOInterposer::MonitorAutoLock lock(mMonitor);
 179   if (mShutdownRequired) {
 180     // The writer thread isn't running. Don't enqueue any more data.
 181     return;
 182   }
 183   // Passing nullptr as aStack parameter for now
 184   mObservations.push_back(ObservationWithStack(aObservation, nullptr));
 185   mMonitor.Notify();
 186 }
 187
 188 }  // namespace
 189
 190 namespace mozilla {
 191
 192 namespace MainThreadIOLogger {
 193
 194 bool Init() {
 195   auto impl = MakeUnique<MainThreadIOLoggerImpl>();
 196   if (!impl->Init()) {
 197     return false;
 198   }
 199   sImpl = impl.release();
 200   IOInterposer::Register(IOInterposeObserver::OpAllWithStaging, sImpl);
 201   return true;
 202 }
 203
 204 }  // namespace MainThreadIOLogger
 205
 206 }  // namespace mozilla