content/media/Latency.cpp

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

mercurial