michael@0: /* -*- Mode: C++; tab-width: 8; indent-tabs-mode: nil; c-basic-offset: 2 -*- */
michael@0: /* vim: set ts=8 sts=2 et sw=2 tw=80: */
michael@0: /* This Source Code Form is subject to the terms of the Mozilla Public
michael@0:  * License, v. 2.0. If a copy of the MPL was not distributed with this
michael@0:  * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
michael@0: 
michael@0: #include "MainThreadIOLogger.h"
michael@0: 
michael@0: #include "GeckoProfiler.h"
michael@0: #include "IOInterposerPrivate.h"
michael@0: #include "mozilla/IOInterposer.h"
michael@0: #include "mozilla/StaticPtr.h"
michael@0: #include "mozilla/TimeStamp.h"
michael@0: #include "nsAutoPtr.h"
michael@0: 
michael@0: /**
michael@0:  * This code uses NSPR stuff and STL containers because it must be detached
michael@0:  * from leak checking code; this observer runs until the process terminates.
michael@0:  */
michael@0: 
michael@0: #include <prenv.h>
michael@0: #include <prprf.h>
michael@0: #include <prthread.h>
michael@0: #include <vector>
michael@0: 
michael@0: namespace {
michael@0: 
michael@0: struct ObservationWithStack
michael@0: {
michael@0:   ObservationWithStack(mozilla::IOInterposeObserver::Observation& aObs,
michael@0:                        ProfilerBacktrace *aStack)
michael@0:     : mObservation(aObs)
michael@0:     , mStack(aStack)
michael@0:   {
michael@0:     const char16_t* filename = aObs.Filename();
michael@0:     if (filename) {
michael@0:       mFilename = filename;
michael@0:     }
michael@0:   }
michael@0:  
michael@0:   mozilla::IOInterposeObserver::Observation mObservation;
michael@0:   ProfilerBacktrace*                        mStack;
michael@0:   nsString                                  mFilename;
michael@0: };
michael@0: 
michael@0: } // anonymous namespace
michael@0: 
michael@0: namespace mozilla {
michael@0: 
michael@0: class MainThreadIOLoggerImpl MOZ_FINAL : public IOInterposeObserver
michael@0: {
michael@0: public:
michael@0:   MainThreadIOLoggerImpl();
michael@0:   ~MainThreadIOLoggerImpl();
michael@0: 
michael@0:   bool Init();
michael@0: 
michael@0:   void Observe(Observation& aObservation);
michael@0: 
michael@0: private:
michael@0:   static void sIOThreadFunc(void* aArg);
michael@0:   void IOThreadFunc();
michael@0: 
michael@0:   TimeStamp             mLogStartTime;
michael@0:   const char*           mFileName;
michael@0:   PRThread*             mIOThread;
michael@0:   IOInterposer::Monitor mMonitor;
michael@0:   bool                  mShutdownRequired;
michael@0:   std::vector<ObservationWithStack> mObservations;
michael@0: };
michael@0: 
michael@0: static StaticAutoPtr<MainThreadIOLoggerImpl> sImpl;
michael@0: 
michael@0: MainThreadIOLoggerImpl::MainThreadIOLoggerImpl()
michael@0:   : mFileName(nullptr)
michael@0:   , mIOThread(nullptr)
michael@0:   , mShutdownRequired(false)
michael@0: {
michael@0: }
michael@0: 
michael@0: MainThreadIOLoggerImpl::~MainThreadIOLoggerImpl()
michael@0: {
michael@0:   if (!mIOThread) {
michael@0:     return;
michael@0:   }
michael@0:   { // Scope for lock
michael@0:     IOInterposer::MonitorAutoLock lock(mMonitor);
michael@0:     mShutdownRequired = true;
michael@0:     lock.Notify();
michael@0:   }
michael@0:   PR_JoinThread(mIOThread);
michael@0:   mIOThread = nullptr;
michael@0: }
michael@0: 
michael@0: bool
michael@0: MainThreadIOLoggerImpl::Init()
michael@0: {
michael@0:   if (mFileName) {
michael@0:     // Already initialized
michael@0:     return true;
michael@0:   }
michael@0:   mFileName = PR_GetEnv("MOZ_MAIN_THREAD_IO_LOG");
michael@0:   if (!mFileName) {
michael@0:     // Can't start
michael@0:     return false;
michael@0:   }
michael@0:   mIOThread = PR_CreateThread(PR_USER_THREAD, &sIOThreadFunc, this,
michael@0:                               PR_PRIORITY_LOW, PR_GLOBAL_THREAD,
michael@0:                               PR_JOINABLE_THREAD, 0);
michael@0:   if (!mIOThread) {
michael@0:     return false;
michael@0:   }
michael@0:   return true;
michael@0: }
michael@0: 
michael@0: /* static */ void
michael@0: MainThreadIOLoggerImpl::sIOThreadFunc(void* aArg)
michael@0: {
michael@0:   PR_SetCurrentThreadName("MainThreadIOLogger");
michael@0:   MainThreadIOLoggerImpl* obj = static_cast<MainThreadIOLoggerImpl*>(aArg);
michael@0:   obj->IOThreadFunc();
michael@0: }
michael@0: 
michael@0: void
michael@0: MainThreadIOLoggerImpl::IOThreadFunc()
michael@0: {
michael@0:   PRFileDesc* fd = PR_Open(mFileName, PR_WRONLY | PR_CREATE_FILE | PR_TRUNCATE,
michael@0:                            PR_IRUSR | PR_IWUSR | PR_IRGRP);
michael@0:   if (!fd) {
michael@0:     IOInterposer::MonitorAutoLock lock(mMonitor);
michael@0:     mShutdownRequired = true;
michael@0:     std::vector<ObservationWithStack>().swap(mObservations);
michael@0:     return;
michael@0:   }
michael@0:   mLogStartTime = TimeStamp::Now();
michael@0:   { // Scope for lock
michael@0:     IOInterposer::MonitorAutoLock lock(mMonitor);
michael@0:     while (true) {
michael@0:       while (!mShutdownRequired && mObservations.empty()) {
michael@0:         lock.Wait();
michael@0:       }
michael@0:       if (mShutdownRequired) {
michael@0:         break;
michael@0:       }
michael@0:       // Pull events off the shared array onto a local one
michael@0:       std::vector<ObservationWithStack> observationsToWrite;
michael@0:       observationsToWrite.swap(mObservations);
michael@0:  
michael@0:       // Release the lock so that we're not holding anybody up during I/O
michael@0:       IOInterposer::MonitorAutoUnlock unlock(mMonitor);
michael@0: 
michael@0:       // Now write the events.
michael@0:       for (std::vector<ObservationWithStack>::iterator
michael@0:              i = observationsToWrite.begin(), e = observationsToWrite.end();
michael@0:            i != e; ++i) {
michael@0:         if (i->mObservation.ObservedOperation() == OpNextStage) {
michael@0:           PR_fprintf(fd, "%f,NEXT-STAGE\n",
michael@0:                      (TimeStamp::Now() - mLogStartTime).ToMilliseconds());
michael@0:           continue;
michael@0:         }
michael@0:         double durationMs = i->mObservation.Duration().ToMilliseconds();
michael@0:         nsAutoCString nativeFilename;
michael@0:         nativeFilename.AssignLiteral("(not available)");
michael@0:         if (!i->mFilename.IsEmpty()) {
michael@0:           if (NS_FAILED(NS_CopyUnicodeToNative(i->mFilename, nativeFilename))) {
michael@0:             nativeFilename.AssignLiteral("(conversion failed)");
michael@0:           }
michael@0:         }
michael@0:         /**
michael@0:          * Format:
michael@0:          * Start Timestamp (Milliseconds), Operation, Duration (Milliseconds), Event Source, Filename
michael@0:          */
michael@0:         if (PR_fprintf(fd, "%f,%s,%f,%s,%s\n",
michael@0:                        (i->mObservation.Start() - mLogStartTime).ToMilliseconds(),
michael@0:                        i->mObservation.ObservedOperationString(), durationMs,
michael@0:                        i->mObservation.Reference(), nativeFilename.get()) > 0) {
michael@0:           ProfilerBacktrace* stack = i->mStack;
michael@0:           if (stack) {
michael@0:             // TODO: Write out the callstack
michael@0:             //       (This will be added in a later bug)
michael@0:             profiler_free_backtrace(stack);
michael@0:           }
michael@0:         }
michael@0:       }
michael@0:     }
michael@0:   }
michael@0:   PR_Close(fd);
michael@0: }
michael@0: 
michael@0: void
michael@0: MainThreadIOLoggerImpl::Observe(Observation& aObservation)
michael@0: {
michael@0:   if (!mFileName || !IsMainThread()) {
michael@0:     return;
michael@0:   }
michael@0:   IOInterposer::MonitorAutoLock lock(mMonitor);
michael@0:   if (mShutdownRequired) {
michael@0:     // The writer thread isn't running. Don't enqueue any more data.
michael@0:     return;
michael@0:   }
michael@0:   // Passing nullptr as aStack parameter for now
michael@0:   mObservations.push_back(ObservationWithStack(aObservation, nullptr));
michael@0:   lock.Notify();
michael@0: }
michael@0: 
michael@0: namespace MainThreadIOLogger {
michael@0: 
michael@0: bool
michael@0: Init()
michael@0: {
michael@0:   nsAutoPtr<MainThreadIOLoggerImpl> impl(new MainThreadIOLoggerImpl());
michael@0:   if (!impl->Init()) {
michael@0:     return false;
michael@0:   }
michael@0:   sImpl = impl.forget();
michael@0:   IOInterposer::Register(IOInterposeObserver::OpAllWithStaging, sImpl);
michael@0:   return true;
michael@0: }
michael@0: 
michael@0: } // namespace MainThreadIOLogger
michael@0: 
michael@0: } // namespace mozilla
michael@0: