Coverage Report

Created: 2018-09-25 14:53

/src/mozilla-central/xpcom/build/MainThreadIOLogger.cpp
Line
Count
Source (jump to first uncovered line)
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 "nsAutoPtr.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
{
32
  explicit ObservationWithStack(mozilla::IOInterposeObserver::Observation& aObs
33
#ifdef MOZ_GECKO_PROFILER
34
                                , ProfilerBacktrace* aStack
35
#endif
36
                                )
37
    : mObservation(aObs)
38
#ifdef MOZ_GECKO_PROFILER
39
    , mStack(aStack)
40
#endif
41
0
  {
42
0
    aObs.Filename(mFilename);
43
0
  }
44
45
  mozilla::IOInterposeObserver::Observation mObservation;
46
#ifdef MOZ_GECKO_PROFILER
47
  ProfilerBacktrace*                        mStack;
48
#endif
49
  nsString                                  mFilename;
50
};
51
52
class MainThreadIOLoggerImpl final : public mozilla::IOInterposeObserver
53
{
54
public:
55
  MainThreadIOLoggerImpl();
56
  ~MainThreadIOLoggerImpl();
57
58
  bool Init();
59
60
  void Observe(Observation& aObservation) override;
61
62
private:
63
  static void sIOThreadFunc(void* aArg);
64
  void IOThreadFunc();
65
66
  TimeStamp             mLogStartTime;
67
  const char*           mFileName;
68
  PRThread*             mIOThread;
69
  IOInterposer::Monitor mMonitor;
70
  bool                  mShutdownRequired;
71
  std::vector<ObservationWithStack> mObservations;
72
};
73
74
static StaticAutoPtr<MainThreadIOLoggerImpl> sImpl;
75
76
MainThreadIOLoggerImpl::MainThreadIOLoggerImpl()
77
  : mFileName(nullptr)
78
  , mIOThread(nullptr)
79
  , mShutdownRequired(false)
80
3
{
81
3
}
82
83
MainThreadIOLoggerImpl::~MainThreadIOLoggerImpl()
84
3
{
85
3
  if (!mIOThread) {
86
3
    return;
87
3
  }
88
0
  {
89
0
    // Scope for lock
90
0
    IOInterposer::MonitorAutoLock lock(mMonitor);
91
0
    mShutdownRequired = true;
92
0
    lock.Notify();
93
0
  }
94
0
  PR_JoinThread(mIOThread);
95
0
  mIOThread = nullptr;
96
0
}
97
98
bool
99
MainThreadIOLoggerImpl::Init()
100
3
{
101
3
  if (mFileName) {
102
0
    // Already initialized
103
0
    return true;
104
0
  }
105
3
  mFileName = PR_GetEnv("MOZ_MAIN_THREAD_IO_LOG");
106
3
  if (!mFileName) {
107
3
    // Can't start
108
3
    return false;
109
3
  }
110
0
  mIOThread = PR_CreateThread(PR_USER_THREAD, &sIOThreadFunc, this,
111
0
                              PR_PRIORITY_LOW, PR_GLOBAL_THREAD,
112
0
                              PR_JOINABLE_THREAD, 0);
113
0
  if (!mIOThread) {
114
0
    return false;
115
0
  }
116
0
  return true;
117
0
}
118
119
/* static */ void
120
MainThreadIOLoggerImpl::sIOThreadFunc(void* aArg)
121
0
{
122
0
  AUTO_PROFILER_REGISTER_THREAD("MainThreadIOLogger");
123
0
124
0
  NS_SetCurrentThreadName("MainThreadIOLogger");
125
0
  MainThreadIOLoggerImpl* obj = static_cast<MainThreadIOLoggerImpl*>(aArg);
126
0
  obj->IOThreadFunc();
127
0
}
128
129
void
130
MainThreadIOLoggerImpl::IOThreadFunc()
131
0
{
132
0
  PRFileDesc* fd = PR_Open(mFileName, PR_WRONLY | PR_CREATE_FILE | PR_TRUNCATE,
133
0
                           PR_IRUSR | PR_IWUSR | PR_IRGRP);
134
0
  if (!fd) {
135
0
    IOInterposer::MonitorAutoLock lock(mMonitor);
136
0
    mShutdownRequired = true;
137
0
    std::vector<ObservationWithStack>().swap(mObservations);
138
0
    return;
139
0
  }
140
0
  mLogStartTime = TimeStamp::Now();
141
0
  {
142
0
    // Scope for lock
143
0
    IOInterposer::MonitorAutoLock lock(mMonitor);
144
0
    while (true) {
145
0
      while (!mShutdownRequired && mObservations.empty()) {
146
0
        lock.Wait();
147
0
      }
148
0
      if (mShutdownRequired) {
149
0
        break;
150
0
      }
151
0
      // Pull events off the shared array onto a local one
152
0
      std::vector<ObservationWithStack> observationsToWrite;
153
0
      observationsToWrite.swap(mObservations);
154
0
155
0
      // Release the lock so that we're not holding anybody up during I/O
156
0
      IOInterposer::MonitorAutoUnlock unlock(mMonitor);
157
0
158
0
      // Now write the events.
159
0
      for (auto i = observationsToWrite.begin(), e = observationsToWrite.end();
160
0
           i != e; ++i) {
161
0
        if (i->mObservation.ObservedOperation() == OpNextStage) {
162
0
          PR_fprintf(fd, "%f,NEXT-STAGE\n",
163
0
                     (TimeStamp::Now() - mLogStartTime).ToMilliseconds());
164
0
          continue;
165
0
        }
166
0
        double durationMs = i->mObservation.Duration().ToMilliseconds();
167
0
        nsAutoCString nativeFilename;
168
0
        nativeFilename.AssignLiteral("(not available)");
169
0
        if (!i->mFilename.IsEmpty()) {
170
0
          if (NS_FAILED(NS_CopyUnicodeToNative(i->mFilename, nativeFilename))) {
171
0
            nativeFilename.AssignLiteral("(conversion failed)");
172
0
          }
173
0
        }
174
0
        /**
175
0
         * Format:
176
0
         * Start Timestamp (Milliseconds), Operation, Duration (Milliseconds), Event Source, Filename
177
0
         */
178
0
        if (PR_fprintf(fd, "%f,%s,%f,%s,%s\n",
179
0
                       (i->mObservation.Start() - mLogStartTime).ToMilliseconds(),
180
0
                       i->mObservation.ObservedOperationString(), durationMs,
181
0
                       i->mObservation.Reference(), nativeFilename.get()) > 0) {
182
0
#ifdef MOZ_GECKO_PROFILER
183
0
          // TODO: Write out the callstack
184
0
          i->mStack = nullptr;
185
0
#endif
186
0
        }
187
0
      }
188
0
    }
189
0
  }
190
0
  PR_Close(fd);
191
0
}
192
193
void
194
MainThreadIOLoggerImpl::Observe(Observation& aObservation)
195
0
{
196
0
  if (!mFileName || !IsMainThread()) {
197
0
    return;
198
0
  }
199
0
  IOInterposer::MonitorAutoLock lock(mMonitor);
200
0
  if (mShutdownRequired) {
201
0
    // The writer thread isn't running. Don't enqueue any more data.
202
0
    return;
203
0
  }
204
0
  // Passing nullptr as aStack parameter for now
205
0
  mObservations.push_back(ObservationWithStack(aObservation
206
0
#ifdef MOZ_GECKO_PROFILER
207
0
                                               , nullptr
208
0
#endif
209
0
                                               ));
210
0
  lock.Notify();
211
0
}
212
213
} // namespace
214
215
namespace mozilla {
216
217
namespace MainThreadIOLogger {
218
219
bool
220
Init()
221
3
{
222
3
  nsAutoPtr<MainThreadIOLoggerImpl> impl(new MainThreadIOLoggerImpl());
223
3
  if (!impl->Init()) {
224
3
    return false;
225
3
  }
226
0
  sImpl = impl.forget();
227
0
  IOInterposer::Register(IOInterposeObserver::OpAllWithStaging, sImpl);
228
0
  return true;
229
0
}
230
231
} // namespace MainThreadIOLogger
232
233
} // namespace mozilla