content/media/Latency.cpp

Fri, 16 Jan 2015 04:50:19 +0100

author
Michael Schloh von Bennewitz <michael@schloh.com>
date
Fri, 16 Jan 2015 04:50:19 +0100
branch
TOR_BUG_9701
changeset 13
44a2da4a2ab2
permissions
-rw-r--r--

Replace accessor implementation with direct member state manipulation, by
request https://trac.torproject.org/projects/tor/ticket/9701#comment:32

michael@0 1 /* -*- Mode: C++; tab-width: 2; indent-tabs-mode: nil; c-basic-offset: 2 -*- */
michael@0 2 /* vim:set ts=2 sw=2 sts=2 et cindent: */
michael@0 3 /* This Source Code Form is subject to the terms of the Mozilla Public
michael@0 4 * License, v. 2.0. If a copy of the MPL was not distributed with this
michael@0 5 * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
michael@0 6
michael@0 7 // We want this available in opt builds
michael@0 8 #define FORCE_PR_LOG
michael@0 9
michael@0 10 #include "Latency.h"
michael@0 11 #include "nsThreadUtils.h"
michael@0 12 #include "prlog.h"
michael@0 13 #include <cmath>
michael@0 14 #include <algorithm>
michael@0 15
michael@0 16 #include <mozilla/Services.h>
michael@0 17 #include <mozilla/StaticPtr.h>
michael@0 18 #include "nsContentUtils.h"
michael@0 19
michael@0 20 using namespace mozilla;
michael@0 21
michael@0 22 const char* LatencyLogIndex2Strings[] = {
michael@0 23 "Audio MediaStreamTrack",
michael@0 24 "Video MediaStreamTrack",
michael@0 25 "Cubeb",
michael@0 26 "AudioStream",
michael@0 27 "NetEQ",
michael@0 28 "AudioCapture Base",
michael@0 29 "AudioCapture Samples",
michael@0 30 "AudioTrackInsertion",
michael@0 31 "MediaPipeline Audio Insertion",
michael@0 32 "AudioTransmit",
michael@0 33 "AudioReceive",
michael@0 34 "MediaPipelineAudioPlayout",
michael@0 35 "MediaStream Create",
michael@0 36 "AudioStream Create",
michael@0 37 "AudioSendRTP",
michael@0 38 "AudioRecvRTP"
michael@0 39 };
michael@0 40
michael@0 41 static StaticRefPtr<AsyncLatencyLogger> gAsyncLogger;
michael@0 42
michael@0 43 PRLogModuleInfo*
michael@0 44 GetLatencyLog()
michael@0 45 {
michael@0 46 static PRLogModuleInfo* sLog;
michael@0 47 if (!sLog) {
michael@0 48 sLog = PR_NewLogModule("MediaLatency");
michael@0 49 }
michael@0 50 return sLog;
michael@0 51 }
michael@0 52
michael@0 53
michael@0 54 class LogEvent : public nsRunnable
michael@0 55 {
michael@0 56 public:
michael@0 57 LogEvent(AsyncLatencyLogger::LatencyLogIndex aIndex, uint64_t aID, int64_t aValue,
michael@0 58 TimeStamp aTimeStamp) :
michael@0 59 mIndex(aIndex),
michael@0 60 mID(aID),
michael@0 61 mValue(aValue),
michael@0 62 mTimeStamp(aTimeStamp)
michael@0 63 {}
michael@0 64 LogEvent(AsyncLatencyLogger::LatencyLogIndex aIndex, uint64_t aID, int64_t aValue) :
michael@0 65 mIndex(aIndex),
michael@0 66 mID(aID),
michael@0 67 mValue(aValue),
michael@0 68 mTimeStamp(TimeStamp())
michael@0 69 {}
michael@0 70 ~LogEvent() {}
michael@0 71
michael@0 72 NS_IMETHOD Run() {
michael@0 73 AsyncLatencyLogger::Get(true)->WriteLog(mIndex, mID, mValue, mTimeStamp);
michael@0 74 return NS_OK;
michael@0 75 }
michael@0 76
michael@0 77 protected:
michael@0 78 AsyncLatencyLogger::LatencyLogIndex mIndex;
michael@0 79 uint64_t mID;
michael@0 80 int64_t mValue;
michael@0 81 TimeStamp mTimeStamp;
michael@0 82 };
michael@0 83
michael@0 84 void LogLatency(AsyncLatencyLogger::LatencyLogIndex aIndex, uint64_t aID, int64_t aValue)
michael@0 85 {
michael@0 86 AsyncLatencyLogger::Get()->Log(aIndex, aID, aValue);
michael@0 87 }
michael@0 88
michael@0 89 void LogTime(AsyncLatencyLogger::LatencyLogIndex aIndex, uint64_t aID, int64_t aValue)
michael@0 90 {
michael@0 91 TimeStamp now = TimeStamp::Now();
michael@0 92 AsyncLatencyLogger::Get()->Log(aIndex, aID, aValue, now);
michael@0 93 }
michael@0 94
michael@0 95 void LogTime(AsyncLatencyLogger::LatencyLogIndex aIndex, uint64_t aID, int64_t aValue, TimeStamp &aTime)
michael@0 96 {
michael@0 97 AsyncLatencyLogger::Get()->Log(aIndex, aID, aValue, aTime);
michael@0 98 }
michael@0 99
michael@0 100 void LogTime(uint32_t aIndex, uint64_t aID, int64_t aValue)
michael@0 101 {
michael@0 102 LogTime(static_cast<AsyncLatencyLogger::LatencyLogIndex>(aIndex), aID, aValue);
michael@0 103 }
michael@0 104 void LogTime(uint32_t aIndex, uint64_t aID, int64_t aValue, TimeStamp &aTime)
michael@0 105 {
michael@0 106 LogTime(static_cast<AsyncLatencyLogger::LatencyLogIndex>(aIndex), aID, aValue, aTime);
michael@0 107 }
michael@0 108 void LogLatency(uint32_t aIndex, uint64_t aID, int64_t aValue)
michael@0 109 {
michael@0 110 LogLatency(static_cast<AsyncLatencyLogger::LatencyLogIndex>(aIndex), aID, aValue);
michael@0 111 }
michael@0 112
michael@0 113 /* static */
michael@0 114 void AsyncLatencyLogger::InitializeStatics()
michael@0 115 {
michael@0 116 NS_ASSERTION(NS_IsMainThread(), "Main thread only");
michael@0 117 GetLatencyLog();
michael@0 118 gAsyncLogger = new AsyncLatencyLogger();
michael@0 119 }
michael@0 120
michael@0 121 /* static */
michael@0 122 void AsyncLatencyLogger::ShutdownLogger()
michael@0 123 {
michael@0 124 gAsyncLogger = nullptr;
michael@0 125 }
michael@0 126
michael@0 127 /* static */
michael@0 128 AsyncLatencyLogger* AsyncLatencyLogger::Get(bool aStartTimer)
michael@0 129 {
michael@0 130 // Users don't generally null-check the result since we should live longer than they
michael@0 131 MOZ_ASSERT(gAsyncLogger);
michael@0 132
michael@0 133 if (aStartTimer) {
michael@0 134 gAsyncLogger->Init();
michael@0 135 }
michael@0 136 return gAsyncLogger;
michael@0 137 }
michael@0 138
michael@0 139 NS_IMPL_ISUPPORTS(AsyncLatencyLogger, nsIObserver)
michael@0 140
michael@0 141 AsyncLatencyLogger::AsyncLatencyLogger()
michael@0 142 : mThread(nullptr),
michael@0 143 mMutex("AsyncLatencyLogger")
michael@0 144 {
michael@0 145 NS_ASSERTION(NS_IsMainThread(), "Main thread only");
michael@0 146 nsContentUtils::RegisterShutdownObserver(this);
michael@0 147 }
michael@0 148
michael@0 149 AsyncLatencyLogger::~AsyncLatencyLogger()
michael@0 150 {
michael@0 151 AsyncLatencyLogger::Shutdown();
michael@0 152 }
michael@0 153
michael@0 154 void AsyncLatencyLogger::Shutdown()
michael@0 155 {
michael@0 156 nsContentUtils::UnregisterShutdownObserver(this);
michael@0 157
michael@0 158 MutexAutoLock lock(mMutex);
michael@0 159 if (mThread) {
michael@0 160 mThread->Shutdown();
michael@0 161 }
michael@0 162 mStart = TimeStamp(); // make sure we don't try to restart it for any reason
michael@0 163 }
michael@0 164
michael@0 165 void AsyncLatencyLogger::Init()
michael@0 166 {
michael@0 167 MutexAutoLock lock(mMutex);
michael@0 168 if (mStart.IsNull()) {
michael@0 169 nsresult rv = NS_NewNamedThread("Latency Logger", getter_AddRefs(mThread));
michael@0 170 NS_ENSURE_SUCCESS_VOID(rv);
michael@0 171 mStart = TimeStamp::Now();
michael@0 172 }
michael@0 173 }
michael@0 174
michael@0 175 void AsyncLatencyLogger::GetStartTime(TimeStamp &aStart)
michael@0 176 {
michael@0 177 MutexAutoLock lock(mMutex);
michael@0 178 aStart = mStart;
michael@0 179 }
michael@0 180
michael@0 181 nsresult
michael@0 182 AsyncLatencyLogger::Observe(nsISupports* aSubject, const char* aTopic,
michael@0 183 const char16_t* aData)
michael@0 184 {
michael@0 185 MOZ_ASSERT(NS_IsMainThread());
michael@0 186 if (strcmp(aTopic, NS_XPCOM_SHUTDOWN_OBSERVER_ID) == 0) {
michael@0 187 Shutdown();
michael@0 188 }
michael@0 189 return NS_OK;
michael@0 190 }
michael@0 191
michael@0 192 // aID is a sub-identifier (in particular a specific MediaStramTrack)
michael@0 193 void AsyncLatencyLogger::WriteLog(LatencyLogIndex aIndex, uint64_t aID, int64_t aValue,
michael@0 194 TimeStamp aTimeStamp)
michael@0 195 {
michael@0 196 if (aTimeStamp.IsNull()) {
michael@0 197 PR_LOG(GetLatencyLog(), PR_LOG_DEBUG,
michael@0 198 ("Latency: %s,%llu,%lld,%lld",
michael@0 199 LatencyLogIndex2Strings[aIndex], aID, GetTimeStamp(), aValue));
michael@0 200 } else {
michael@0 201 PR_LOG(GetLatencyLog(), PR_LOG_DEBUG,
michael@0 202 ("Latency: %s,%llu,%lld,%lld,%lld",
michael@0 203 LatencyLogIndex2Strings[aIndex], aID, GetTimeStamp(), aValue,
michael@0 204 static_cast<int64_t>((aTimeStamp - gAsyncLogger->mStart).ToMilliseconds())));
michael@0 205 }
michael@0 206 }
michael@0 207
michael@0 208 int64_t AsyncLatencyLogger::GetTimeStamp()
michael@0 209 {
michael@0 210 TimeDuration t = TimeStamp::Now() - mStart;
michael@0 211 return t.ToMilliseconds();
michael@0 212 }
michael@0 213
michael@0 214 void AsyncLatencyLogger::Log(LatencyLogIndex aIndex, uint64_t aID, int64_t aValue)
michael@0 215 {
michael@0 216 TimeStamp null;
michael@0 217 Log(aIndex, aID, aValue, null);
michael@0 218 }
michael@0 219
michael@0 220 void AsyncLatencyLogger::Log(LatencyLogIndex aIndex, uint64_t aID, int64_t aValue, TimeStamp &aTime)
michael@0 221 {
michael@0 222 if (PR_LOG_TEST(GetLatencyLog(), PR_LOG_DEBUG)) {
michael@0 223 nsCOMPtr<nsIRunnable> event = new LogEvent(aIndex, aID, aValue, aTime);
michael@0 224 if (mThread) {
michael@0 225 mThread->Dispatch(event, NS_DISPATCH_NORMAL);
michael@0 226 }
michael@0 227 }
michael@0 228 }

mercurial