DXR is a code search and navigation tool aimed at making sense of large projects. It supports full-text and regex searches as well as structural queries.

Header

Mercurial (b6057e17f856)

VCS Links

Line Code
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 100 101 102 103 104 105 106 107 108 109 110 111 112 113 114 115 116 117 118 119 120 121 122 123 124 125 126 127 128 129 130 131 132 133 134 135 136 137 138 139 140 141 142 143 144 145 146 147 148 149 150 151 152 153 154 155 156 157 158 159 160 161 162 163 164 165 166 167 168 169 170 171 172 173 174 175 176 177 178 179 180 181 182 183 184 185 186 187 188 189 190 191 192 193 194 195 196 197 198 199 200 201 202 203 204 205 206 207 208 209 210 211 212 213 214 215 216 217 218 219 220 221 222 223
/* -*- Mode: C++; tab-width: 8; indent-tabs-mode: nil; c-basic-offset: 2 -*- */
/* vim: set ts=8 sts=2 et sw=2 tw=80: */
/* This Source Code Form is subject to the terms of the Mozilla Public
 * License, v. 2.0. If a copy of the MPL was not distributed with this
 * file, You can obtain one at http://mozilla.org/MPL/2.0/. */

#include "MainThreadIOLogger.h"

#include "GeckoProfiler.h"
#include "IOInterposerPrivate.h"
#include "mozilla/IOInterposer.h"
#include "mozilla/StaticPtr.h"
#include "mozilla/TimeStamp.h"
#include "nsAutoPtr.h"

/**
 * This code uses NSPR stuff and STL containers because it must be detached
 * from leak checking code; this observer runs until the process terminates.
 */

#include <prenv.h>
#include <prprf.h>
#include <prthread.h>
#include <vector>

namespace {

struct ObservationWithStack
{
  ObservationWithStack(mozilla::IOInterposeObserver::Observation& aObs,
                       ProfilerBacktrace *aStack)
    : mObservation(aObs)
    , mStack(aStack)
  {
    const char16_t* filename = aObs.Filename();
    if (filename) {
      mFilename = filename;
    }
  }
 
  mozilla::IOInterposeObserver::Observation mObservation;
  ProfilerBacktrace*                        mStack;
  nsString                                  mFilename;
};

} // anonymous namespace

namespace mozilla {

class MainThreadIOLoggerImpl MOZ_FINAL : public IOInterposeObserver
{
public:
  MainThreadIOLoggerImpl();
  ~MainThreadIOLoggerImpl();

  bool Init();

  void Observe(Observation& aObservation);

private:
  static void sIOThreadFunc(void* aArg);
  void IOThreadFunc();

  TimeStamp             mLogStartTime;
  const char*           mFileName;
  PRThread*             mIOThread;
  IOInterposer::Monitor mMonitor;
  bool                  mShutdownRequired;
  std::vector<ObservationWithStack> mObservations;
};

static StaticAutoPtr<MainThreadIOLoggerImpl> sImpl;

MainThreadIOLoggerImpl::MainThreadIOLoggerImpl()
  : mFileName(nullptr)
  , mIOThread(nullptr)
  , mShutdownRequired(false)
{
}

MainThreadIOLoggerImpl::~MainThreadIOLoggerImpl()
{
  if (!mIOThread) {
    return;
  }
  { // Scope for lock
    IOInterposer::MonitorAutoLock lock(mMonitor);
    mShutdownRequired = true;
    lock.Notify();
  }
  PR_JoinThread(mIOThread);
  mIOThread = nullptr;
}

bool
MainThreadIOLoggerImpl::Init()
{
  if (mFileName) {
    // Already initialized
    return true;
  }
  mFileName = PR_GetEnv("MOZ_MAIN_THREAD_IO_LOG");
  if (!mFileName) {
    // Can't start
    return false;
  }
  mIOThread = PR_CreateThread(PR_USER_THREAD, &sIOThreadFunc, this,
                              PR_PRIORITY_LOW, PR_GLOBAL_THREAD,
                              PR_JOINABLE_THREAD, 0);
  if (!mIOThread) {
    return false;
  }
  return true;
}

/* static */ void
MainThreadIOLoggerImpl::sIOThreadFunc(void* aArg)
{
  PR_SetCurrentThreadName("MainThreadIOLogger");
  MainThreadIOLoggerImpl* obj = static_cast<MainThreadIOLoggerImpl*>(aArg);
  obj->IOThreadFunc();
}

void
MainThreadIOLoggerImpl::IOThreadFunc()
{
  PRFileDesc* fd = PR_Open(mFileName, PR_WRONLY | PR_CREATE_FILE | PR_TRUNCATE,
                           PR_IRUSR | PR_IWUSR | PR_IRGRP);
  if (!fd) {
    IOInterposer::MonitorAutoLock lock(mMonitor);
    mShutdownRequired = true;
    std::vector<ObservationWithStack>().swap(mObservations);
    return;
  }
  mLogStartTime = TimeStamp::Now();
  { // Scope for lock
    IOInterposer::MonitorAutoLock lock(mMonitor);
    while (true) {
      while (!mShutdownRequired && mObservations.empty()) {
        lock.Wait();
      }
      if (mShutdownRequired) {
        break;
      }
      // Pull events off the shared array onto a local one
      std::vector<ObservationWithStack> observationsToWrite;
      observationsToWrite.swap(mObservations);
 
      // Release the lock so that we're not holding anybody up during I/O
      IOInterposer::MonitorAutoUnlock unlock(mMonitor);

      // Now write the events.
      for (std::vector<ObservationWithStack>::iterator
             i = observationsToWrite.begin(), e = observationsToWrite.end();
           i != e; ++i) {
        if (i->mObservation.ObservedOperation() == OpNextStage) {
          PR_fprintf(fd, "%f,NEXT-STAGE\n",
                     (TimeStamp::Now() - mLogStartTime).ToMilliseconds());
          continue;
        }
        double durationMs = i->mObservation.Duration().ToMilliseconds();
        nsAutoCString nativeFilename;
        nativeFilename.AssignLiteral("(not available)");
        if (!i->mFilename.IsEmpty()) {
          if (NS_FAILED(NS_CopyUnicodeToNative(i->mFilename, nativeFilename))) {
            nativeFilename.AssignLiteral("(conversion failed)");
          }
        }
        /**
         * Format:
         * Start Timestamp (Milliseconds), Operation, Duration (Milliseconds), Event Source, Filename
         */
        if (PR_fprintf(fd, "%f,%s,%f,%s,%s\n",
                       (i->mObservation.Start() - mLogStartTime).ToMilliseconds(),
                       i->mObservation.ObservedOperationString(), durationMs,
                       i->mObservation.Reference(), nativeFilename.get()) > 0) {
          ProfilerBacktrace* stack = i->mStack;
          if (stack) {
            // TODO: Write out the callstack
            //       (This will be added in a later bug)
            profiler_free_backtrace(stack);
          }
        }
      }
    }
  }
  PR_Close(fd);
}

void
MainThreadIOLoggerImpl::Observe(Observation& aObservation)
{
  if (!mFileName || !IsMainThread()) {
    return;
  }
  IOInterposer::MonitorAutoLock lock(mMonitor);
  if (mShutdownRequired) {
    // The writer thread isn't running. Don't enqueue any more data.
    return;
  }
  // Passing nullptr as aStack parameter for now
  mObservations.push_back(ObservationWithStack(aObservation, nullptr));
  lock.Notify();
}

namespace MainThreadIOLogger {

bool
Init()
{
  nsAutoPtr<MainThreadIOLoggerImpl> impl(new MainThreadIOLoggerImpl());
  if (!impl->Init()) {
    return false;
  }
  sImpl = impl.forget();
  IOInterposer::Register(IOInterposeObserver::OpAllWithStaging, sImpl);
  return true;
}

} // namespace MainThreadIOLogger

} // namespace mozilla