/src/mozilla-central/dom/media/doctor/DDMediaLogs.cpp
Line | Count | Source (jump to first uncovered line) |
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 | | #include "DDMediaLogs.h" |
8 | | |
9 | | #include "DDLogUtils.h" |
10 | | #include "nsIThreadManager.h" |
11 | | #include "mozilla/JSONWriter.h" |
12 | | |
13 | | namespace mozilla { |
14 | | |
15 | | /* static */ DDMediaLogs::ConstructionResult |
16 | | DDMediaLogs::New() |
17 | 0 | { |
18 | 0 | nsCOMPtr<nsIThread> mThread; |
19 | 0 | nsresult rv = NS_NewNamedThread("DDMediaLogs", |
20 | 0 | getter_AddRefs(mThread), |
21 | 0 | nullptr, |
22 | 0 | nsIThreadManager::kThreadPoolStackSize); |
23 | 0 | if (NS_WARN_IF(NS_FAILED(rv))) { |
24 | 0 | return { rv, nullptr }; |
25 | 0 | } |
26 | 0 | |
27 | 0 | return { rv, new DDMediaLogs(std::move(mThread)) }; |
28 | 0 | } |
29 | | |
30 | | DDMediaLogs::DDMediaLogs(nsCOMPtr<nsIThread>&& aThread) |
31 | | : mMediaLogs(1) |
32 | | , mMutex("DDMediaLogs") |
33 | | , mThread(std::move(aThread)) |
34 | 0 | { |
35 | 0 | mMediaLogs.SetLength(1); |
36 | 0 | mMediaLogs[0].mMediaElement = nullptr; |
37 | 0 | DDL_INFO("DDMediaLogs constructed, processing thread: %p", mThread.get()); |
38 | 0 | } |
39 | | |
40 | | DDMediaLogs::~DDMediaLogs() |
41 | 0 | { |
42 | 0 | // Perform end-of-life processing, ensure the processing thread is shutdown. |
43 | 0 | Shutdown(/* aPanic = */ false); |
44 | 0 | } |
45 | | |
46 | | void |
47 | | DDMediaLogs::Panic() |
48 | 0 | { |
49 | 0 | Shutdown(/* aPanic = */ true); |
50 | 0 | } |
51 | | |
52 | | void |
53 | | DDMediaLogs::Shutdown(bool aPanic) |
54 | 0 | { |
55 | 0 | nsCOMPtr<nsIThread> thread; |
56 | 0 | { |
57 | 0 | MutexAutoLock lock(mMutex); |
58 | 0 | thread.swap(mThread); |
59 | 0 | } |
60 | 0 | if (!thread) { |
61 | 0 | // Already shutdown, nothing more to do. |
62 | 0 | return; |
63 | 0 | } |
64 | 0 | |
65 | 0 | DDL_INFO("DDMediaLogs::Shutdown will shutdown thread: %p", thread.get()); |
66 | 0 | // Will block until pending tasks have completed, and thread is dead. |
67 | 0 | thread->Shutdown(); |
68 | 0 |
|
69 | 0 | if (aPanic) { |
70 | 0 | mMessagesQueue.PopAll([](const DDLogMessage&) {}); |
71 | 0 | MutexAutoLock lock(mMutex); |
72 | 0 | mLifetimes.Clear(); |
73 | 0 | mMediaLogs.Clear(); |
74 | 0 | mObjectLinks.Clear(); |
75 | 0 | mPendingPromises.Clear(); |
76 | 0 | return; |
77 | 0 | } |
78 | 0 |
|
79 | 0 | // Final processing is only necessary to output to MOZ_LOG=DDLoggerEnd, |
80 | 0 | // so there's no point doing any of it if that MOZ_LOG is not enabled. |
81 | 0 | if (MOZ_LOG_TEST(sDecoderDoctorLoggerEndLog, mozilla::LogLevel::Info)) { |
82 | 0 | DDL_DEBUG("Perform final DDMediaLogs processing..."); |
83 | 0 | // The processing thread is dead, so we can safely call ProcessLog() |
84 | 0 | // directly from this thread. |
85 | 0 | ProcessLog(); |
86 | 0 |
|
87 | 0 | for (const DDMediaLog& mediaLog : mMediaLogs) { |
88 | 0 | if (mediaLog.mMediaElement) { |
89 | 0 | DDLE_INFO("---"); |
90 | 0 | } |
91 | 0 | DDLE_INFO("--- Log for HTMLMediaElement[%p] ---", mediaLog.mMediaElement); |
92 | 0 | for (const DDLogMessage& message : mediaLog.mMessages) { |
93 | 0 | DDLE_LOG(message.mCategory <= DDLogCategory::_Unlink |
94 | 0 | ? mozilla::LogLevel::Debug |
95 | 0 | : mozilla::LogLevel::Info, |
96 | 0 | "%s", |
97 | 0 | message.Print(mLifetimes).get()); |
98 | 0 | } |
99 | 0 | DDLE_DEBUG("--- End log for HTMLMediaElement[%p] ---", |
100 | 0 | mediaLog.mMediaElement); |
101 | 0 | } |
102 | 0 | } |
103 | 0 | } |
104 | | |
105 | | DDMediaLog& |
106 | | DDMediaLogs::LogForUnassociatedMessages() |
107 | 0 | { |
108 | 0 | MOZ_ASSERT(!mThread || mThread.get() == NS_GetCurrentThread()); |
109 | 0 | return mMediaLogs[0]; |
110 | 0 | } |
111 | | const DDMediaLog& |
112 | | DDMediaLogs::LogForUnassociatedMessages() const |
113 | 0 | { |
114 | 0 | MOZ_ASSERT(!mThread || mThread.get() == NS_GetCurrentThread()); |
115 | 0 | return mMediaLogs[0]; |
116 | 0 | } |
117 | | |
118 | | DDMediaLog* |
119 | | DDMediaLogs::GetLogFor(const dom::HTMLMediaElement* aMediaElement) |
120 | 0 | { |
121 | 0 | MOZ_ASSERT(!mThread || mThread.get() == NS_GetCurrentThread()); |
122 | 0 | if (!aMediaElement) { |
123 | 0 | return &LogForUnassociatedMessages(); |
124 | 0 | } |
125 | 0 | for (DDMediaLog& log : mMediaLogs) { |
126 | 0 | if (log.mMediaElement == aMediaElement) { |
127 | 0 | return &log; |
128 | 0 | } |
129 | 0 | } |
130 | 0 | return nullptr; |
131 | 0 | } |
132 | | |
133 | | DDMediaLog& |
134 | | DDMediaLogs::LogFor(const dom::HTMLMediaElement* aMediaElement) |
135 | 0 | { |
136 | 0 | MOZ_ASSERT(!mThread || mThread.get() == NS_GetCurrentThread()); |
137 | 0 | DDMediaLog* log = GetLogFor(aMediaElement); |
138 | 0 | if (!log) { |
139 | 0 | log = mMediaLogs.AppendElement(); |
140 | 0 | log->mMediaElement = aMediaElement; |
141 | 0 | } |
142 | 0 | return *log; |
143 | 0 | } |
144 | | |
145 | | void |
146 | | DDMediaLogs::SetMediaElement(DDLifetime& aLifetime, |
147 | | const dom::HTMLMediaElement* aMediaElement) |
148 | 0 | { |
149 | 0 | MOZ_ASSERT(!mThread || mThread.get() == NS_GetCurrentThread()); |
150 | 0 | DDMediaLog& log = LogFor(aMediaElement); |
151 | 0 |
|
152 | 0 | // List of lifetimes that are to be linked to aMediaElement. |
153 | 0 | nsTArray<DDLifetime*> lifetimes; |
154 | 0 | // We start with the given lifetime. |
155 | 0 | lifetimes.AppendElement(&aLifetime); |
156 | 0 | for (size_t i = 0; i < lifetimes.Length(); ++i) { |
157 | 0 | DDLifetime& lifetime = *lifetimes[i]; |
158 | 0 | // Link the lifetime to aMediaElement. |
159 | 0 | lifetime.mMediaElement = aMediaElement; |
160 | 0 | // Classified lifetime's tag is a positive index from the DDMediaLog. |
161 | 0 | lifetime.mTag = ++log.mLifetimeCount; |
162 | 0 | DDL_DEBUG( |
163 | 0 | "%s -> HTMLMediaElement[%p]", lifetime.Printf().get(), aMediaElement); |
164 | 0 |
|
165 | 0 | // Go through the lifetime's existing linked lifetimes, if any is not |
166 | 0 | // already linked to aMediaElement, add it to the list so it will get |
167 | 0 | // linked in a later loop. |
168 | 0 | for (auto& link : mObjectLinks) { |
169 | 0 | if (lifetime.IsAliveAt(link.mLinkingIndex)) { |
170 | 0 | if (lifetime.mObject == link.mParent) { |
171 | 0 | DDLifetime* childLifetime = |
172 | 0 | mLifetimes.FindLifetime(link.mChild, link.mLinkingIndex); |
173 | 0 | if (childLifetime && !childLifetime->mMediaElement && |
174 | 0 | !lifetimes.Contains(childLifetime)) { |
175 | 0 | lifetimes.AppendElement(childLifetime); |
176 | 0 | } |
177 | 0 | } else if (lifetime.mObject == link.mChild) { |
178 | 0 | DDLifetime* parentLifetime = |
179 | 0 | mLifetimes.FindLifetime(link.mParent, link.mLinkingIndex); |
180 | 0 | if (parentLifetime && !parentLifetime->mMediaElement && |
181 | 0 | !lifetimes.Contains(parentLifetime)) { |
182 | 0 | lifetimes.AppendElement(parentLifetime); |
183 | 0 | } |
184 | 0 | } |
185 | 0 | } |
186 | 0 | } |
187 | 0 | } |
188 | 0 |
|
189 | 0 | // Now we need to move yet-unclassified messages related to the just-set |
190 | 0 | // elements, to the appropriate MediaElement list. |
191 | 0 | DDMediaLog::LogMessages& messages = log.mMessages; |
192 | 0 | DDMediaLog::LogMessages& messages0 = LogForUnassociatedMessages().mMessages; |
193 | 0 | for (size_t i = 0; i < messages0.Length(); |
194 | 0 | /* increment inside the loop */) { |
195 | 0 | DDLogMessage& message = messages0[i]; |
196 | 0 | bool found = false; |
197 | 0 | for (const DDLifetime* lifetime : lifetimes) { |
198 | 0 | if (lifetime->mObject == message.mObject) { |
199 | 0 | found = true; |
200 | 0 | break; |
201 | 0 | } |
202 | 0 | } |
203 | 0 | if (found) { |
204 | 0 | messages.AppendElement(std::move(message)); |
205 | 0 | messages0.RemoveElementAt(i); |
206 | 0 | // No increment, as we've removed this element; next element is now at |
207 | 0 | // the same index. |
208 | 0 | } else { |
209 | 0 | // Not touching this element, increment index to go to next element. |
210 | 0 | ++i; |
211 | 0 | } |
212 | 0 | } |
213 | 0 | } |
214 | | |
215 | | DDLifetime& |
216 | | DDMediaLogs::FindOrCreateLifetime(const DDLogObject& aObject, |
217 | | DDMessageIndex aIndex, |
218 | | const DDTimeStamp& aTimeStamp) |
219 | 0 | { |
220 | 0 | MOZ_ASSERT(!mThread || mThread.get() == NS_GetCurrentThread()); |
221 | 0 | // Try to find lifetime corresponding to message object. |
222 | 0 | DDLifetime* lifetime = mLifetimes.FindLifetime(aObject, aIndex); |
223 | 0 | if (!lifetime) { |
224 | 0 | // No lifetime yet, create one. |
225 | 0 | lifetime = &(mLifetimes.CreateLifetime(aObject, aIndex, aTimeStamp)); |
226 | 0 | if (MOZ_UNLIKELY(aObject.TypeName() == |
227 | 0 | DDLoggedTypeTraits<dom::HTMLMediaElement>::Name())) { |
228 | 0 | const dom::HTMLMediaElement* mediaElement = |
229 | 0 | static_cast<const dom::HTMLMediaElement*>(aObject.Pointer()); |
230 | 0 | SetMediaElement(*lifetime, mediaElement); |
231 | 0 | DDL_DEBUG("%s -> new lifetime: %s with MediaElement %p", |
232 | 0 | aObject.Printf().get(), |
233 | 0 | lifetime->Printf().get(), |
234 | 0 | mediaElement); |
235 | 0 | } else { |
236 | 0 | DDL_DEBUG("%s -> new lifetime: %s", |
237 | 0 | aObject.Printf().get(), |
238 | 0 | lifetime->Printf().get()); |
239 | 0 | } |
240 | 0 | } |
241 | 0 |
|
242 | 0 | return *lifetime; |
243 | 0 | } |
244 | | |
245 | | void |
246 | | DDMediaLogs::LinkLifetimes(DDLifetime& aParentLifetime, |
247 | | const char* aLinkName, |
248 | | DDLifetime& aChildLifetime, |
249 | | DDMessageIndex aIndex) |
250 | 0 | { |
251 | 0 | MOZ_ASSERT(!mThread || mThread.get() == NS_GetCurrentThread()); |
252 | 0 | mObjectLinks.AppendElement(DDObjectLink{ |
253 | 0 | aParentLifetime.mObject, aChildLifetime.mObject, aLinkName, aIndex }); |
254 | 0 | if (aParentLifetime.mMediaElement) { |
255 | 0 | if (!aChildLifetime.mMediaElement) { |
256 | 0 | SetMediaElement(aChildLifetime, aParentLifetime.mMediaElement); |
257 | 0 | } |
258 | 0 | } else if (aChildLifetime.mMediaElement) { |
259 | 0 | if (!aParentLifetime.mMediaElement) { |
260 | 0 | SetMediaElement(aParentLifetime, aChildLifetime.mMediaElement); |
261 | 0 | } |
262 | 0 | } |
263 | 0 | } |
264 | | |
265 | | void |
266 | | DDMediaLogs::UnlinkLifetime(DDLifetime& aLifetime, DDMessageIndex aIndex) |
267 | 0 | { |
268 | 0 | MOZ_ASSERT(!mThread || mThread.get() == NS_GetCurrentThread()); |
269 | 0 | for (DDObjectLink& link : mObjectLinks) { |
270 | 0 | if ((link.mParent == aLifetime.mObject || |
271 | 0 | link.mChild == aLifetime.mObject) && |
272 | 0 | aLifetime.IsAliveAt(link.mLinkingIndex) && !link.mUnlinkingIndex) { |
273 | 0 | link.mUnlinkingIndex = Some(aIndex); |
274 | 0 | } |
275 | 0 | } |
276 | 0 | }; |
277 | | |
278 | | void |
279 | | DDMediaLogs::UnlinkLifetimes(DDLifetime& aParentLifetime, |
280 | | DDLifetime& aChildLifetime, |
281 | | DDMessageIndex aIndex) |
282 | 0 | { |
283 | 0 | MOZ_ASSERT(!mThread || mThread.get() == NS_GetCurrentThread()); |
284 | 0 | for (DDObjectLink& link : mObjectLinks) { |
285 | 0 | if ((link.mParent == aParentLifetime.mObject && |
286 | 0 | link.mChild == aChildLifetime.mObject) && |
287 | 0 | aParentLifetime.IsAliveAt(link.mLinkingIndex) && |
288 | 0 | aChildLifetime.IsAliveAt(link.mLinkingIndex) && !link.mUnlinkingIndex) { |
289 | 0 | link.mUnlinkingIndex = Some(aIndex); |
290 | 0 | } |
291 | 0 | } |
292 | 0 | } |
293 | | |
294 | | void |
295 | | DDMediaLogs::DestroyLifetimeLinks(const DDLifetime& aLifetime) |
296 | 0 | { |
297 | 0 | mObjectLinks.RemoveElementsBy([&](DDObjectLink& link) { |
298 | 0 | return (link.mParent == aLifetime.mObject || |
299 | 0 | link.mChild == aLifetime.mObject) && |
300 | 0 | aLifetime.IsAliveAt(link.mLinkingIndex); |
301 | 0 | }); |
302 | 0 | } |
303 | | |
304 | | size_t |
305 | | DDMediaLogs::SizeOfIncludingThis(MallocSizeOf aMallocSizeOf) const |
306 | 0 | { |
307 | 0 | size_t size = aMallocSizeOf(this) + |
308 | 0 | // This will usually be called after processing, so negligible |
309 | 0 | // external data should still be present in the queue. |
310 | 0 | mMessagesQueue.ShallowSizeOfExcludingThis(aMallocSizeOf) + |
311 | 0 | mLifetimes.SizeOfExcludingThis(aMallocSizeOf) + |
312 | 0 | mMediaLogs.ShallowSizeOfExcludingThis(aMallocSizeOf) + |
313 | 0 | mObjectLinks.ShallowSizeOfExcludingThis(aMallocSizeOf) + |
314 | 0 | mPendingPromises.ShallowSizeOfExcludingThis(aMallocSizeOf); |
315 | 0 | for (const DDMediaLog& log : mMediaLogs) { |
316 | 0 | size += log.SizeOfExcludingThis(aMallocSizeOf); |
317 | 0 | } |
318 | 0 | return size; |
319 | 0 | } |
320 | | |
321 | | void |
322 | | DDMediaLogs::ProcessBuffer() |
323 | 0 | { |
324 | 0 | MOZ_ASSERT(!mThread || mThread.get() == NS_GetCurrentThread()); |
325 | 0 |
|
326 | 0 | mMessagesQueue.PopAll([this](const DDLogMessage& message) { |
327 | 0 | DDL_DEBUG("Processing: %s", message.Print().Data()); |
328 | 0 |
|
329 | 0 | // Either this message will carry a new object for which to create a |
330 | 0 | // lifetime, or we'll find an existing one. |
331 | 0 | DDLifetime& lifetime = |
332 | 0 | FindOrCreateLifetime(message.mObject, message.mIndex, message.mTimeStamp); |
333 | 0 |
|
334 | 0 | // Copy the message contents (without the mValid flag) to the |
335 | 0 | // appropriate MediaLog corresponding to the message's object lifetime. |
336 | 0 | LogFor(lifetime.mMediaElement) |
337 | 0 | .mMessages.AppendElement(static_cast<const DDLogMessage&>(message)); |
338 | 0 |
|
339 | 0 | switch (message.mCategory) { |
340 | 0 | case DDLogCategory::_Construction: |
341 | 0 | // The FindOrCreateLifetime above will have set a construction time, |
342 | 0 | // so there's nothing more we need to do here. |
343 | 0 | MOZ_ASSERT(lifetime.mConstructionTimeStamp); |
344 | 0 | break; |
345 | 0 |
|
346 | 0 | case DDLogCategory::_DerivedConstruction: |
347 | 0 | // The FindOrCreateLifetime above will have set a construction time. |
348 | 0 | MOZ_ASSERT(lifetime.mConstructionTimeStamp); |
349 | 0 | // A derived construction must come with the base object. |
350 | 0 | MOZ_ASSERT(message.mValue.is<DDLogObject>()); |
351 | 0 | { |
352 | 0 | const DDLogObject& base = message.mValue.as<DDLogObject>(); |
353 | 0 | DDLifetime& baseLifetime = |
354 | 0 | FindOrCreateLifetime(base, message.mIndex, message.mTimeStamp); |
355 | 0 | // FindOrCreateLifetime could have moved `lifetime`. |
356 | 0 | DDLifetime* lifetime2 = |
357 | 0 | mLifetimes.FindLifetime(message.mObject, message.mIndex); |
358 | 0 | MOZ_ASSERT(lifetime2); |
359 | 0 | // Assume there's no multiple-inheritance (at least for the types |
360 | 0 | // we're watching.) |
361 | 0 | if (baseLifetime.mDerivedObject.Pointer()) { |
362 | 0 | DDL_WARN( |
363 | 0 | "base '%s' was already derived as '%s', now deriving as '%s'", |
364 | 0 | baseLifetime.Printf().get(), |
365 | 0 | baseLifetime.mDerivedObject.Printf().get(), |
366 | 0 | lifetime2->Printf().get()); |
367 | 0 | } |
368 | 0 | baseLifetime.mDerivedObject = lifetime2->mObject; |
369 | 0 | baseLifetime.mDerivedObjectLinkingIndex = message.mIndex; |
370 | 0 | // Link the base and derived objects, to ensure they go to the same |
371 | 0 | // log. |
372 | 0 | LinkLifetimes(*lifetime2, "is-a", baseLifetime, message.mIndex); |
373 | 0 | } |
374 | 0 | break; |
375 | 0 |
|
376 | 0 | case DDLogCategory::_Destruction: |
377 | 0 | lifetime.mDestructionIndex = message.mIndex; |
378 | 0 | lifetime.mDestructionTimeStamp = message.mTimeStamp; |
379 | 0 | UnlinkLifetime(lifetime, message.mIndex); |
380 | 0 | break; |
381 | 0 |
|
382 | 0 | case DDLogCategory::_Link: |
383 | 0 | MOZ_ASSERT(message.mValue.is<DDLogObject>()); |
384 | 0 | { |
385 | 0 | const DDLogObject& child = message.mValue.as<DDLogObject>(); |
386 | 0 | DDLifetime& childLifetime = |
387 | 0 | FindOrCreateLifetime(child, message.mIndex, message.mTimeStamp); |
388 | 0 | // FindOrCreateLifetime could have moved `lifetime`. |
389 | 0 | DDLifetime* lifetime2 = |
390 | 0 | mLifetimes.FindLifetime(message.mObject, message.mIndex); |
391 | 0 | MOZ_ASSERT(lifetime2); |
392 | 0 | LinkLifetimes( |
393 | 0 | *lifetime2, message.mLabel, childLifetime, message.mIndex); |
394 | 0 | } |
395 | 0 | break; |
396 | 0 |
|
397 | 0 | case DDLogCategory::_Unlink: |
398 | 0 | MOZ_ASSERT(message.mValue.is<DDLogObject>()); |
399 | 0 | { |
400 | 0 | const DDLogObject& child = message.mValue.as<DDLogObject>(); |
401 | 0 | DDLifetime& childLifetime = |
402 | 0 | FindOrCreateLifetime(child, message.mIndex, message.mTimeStamp); |
403 | 0 | // FindOrCreateLifetime could have moved `lifetime`. |
404 | 0 | DDLifetime* lifetime2 = |
405 | 0 | mLifetimes.FindLifetime(message.mObject, message.mIndex); |
406 | 0 | MOZ_ASSERT(lifetime2); |
407 | 0 | UnlinkLifetimes(*lifetime2, childLifetime, message.mIndex); |
408 | 0 | } |
409 | 0 | break; |
410 | 0 |
|
411 | 0 | default: |
412 | 0 | // Anything else: Nothing more to do. |
413 | 0 | break; |
414 | 0 | } |
415 | 0 | }); |
416 | 0 | } |
417 | | |
418 | | struct StringWriteFunc : public JSONWriteFunc |
419 | | { |
420 | | nsCString& mCString; |
421 | | explicit StringWriteFunc(nsCString& aCString) |
422 | | : mCString(aCString) |
423 | 0 | { |
424 | 0 | } |
425 | 0 | void Write(const char* aStr) override { mCString.Append(aStr); } |
426 | | }; |
427 | | |
428 | | void |
429 | | DDMediaLogs::FulfillPromises() |
430 | 0 | { |
431 | 0 | MOZ_ASSERT(!mThread || mThread.get() == NS_GetCurrentThread()); |
432 | 0 |
|
433 | 0 | MozPromiseHolder<LogMessagesPromise> promiseHolder; |
434 | 0 | const dom::HTMLMediaElement* mediaElement = nullptr; |
435 | 0 | { |
436 | 0 | // Grab the first pending promise (if any). |
437 | 0 | // Note that we don't pop it yet, so we don't potentially leave the list |
438 | 0 | // empty and therefore allow another processing task to be dispatched. |
439 | 0 | MutexAutoLock lock(mMutex); |
440 | 0 | if (mPendingPromises.IsEmpty()) { |
441 | 0 | return; |
442 | 0 | } |
443 | 0 | promiseHolder = std::move(mPendingPromises[0].mPromiseHolder); |
444 | 0 | mediaElement = mPendingPromises[0].mMediaElement; |
445 | 0 | } |
446 | 0 | for (;;) { |
447 | 0 | DDMediaLog* log = GetLogFor(mediaElement); |
448 | 0 | if (!log) { |
449 | 0 | // No such media element -> Reject this promise. |
450 | 0 | DDL_INFO("Rejecting promise for HTMLMediaElement[%p] - Cannot find log", |
451 | 0 | mediaElement); |
452 | 0 | promiseHolder.Reject(NS_ERROR_DOM_MEDIA_NOT_ALLOWED_ERR, __func__); |
453 | 0 | // Pop this rejected promise, fetch next one. |
454 | 0 | MutexAutoLock lock(mMutex); |
455 | 0 | mPendingPromises.RemoveElementAt(0); |
456 | 0 | if (mPendingPromises.IsEmpty()) { |
457 | 0 | break; |
458 | 0 | } |
459 | 0 | promiseHolder = std::move(mPendingPromises[0].mPromiseHolder); |
460 | 0 | mediaElement = mPendingPromises[0].mMediaElement; |
461 | 0 | continue; |
462 | 0 | } |
463 | 0 | |
464 | 0 | nsCString json; |
465 | 0 | JSONWriter jw{ MakeUnique<StringWriteFunc>(json) }; |
466 | 0 | jw.Start(); |
467 | 0 | jw.StartArrayProperty("messages"); |
468 | 0 | for (const DDLogMessage& message : log->mMessages) { |
469 | 0 | jw.StartObjectElement(JSONWriter::SingleLineStyle); |
470 | 0 | jw.IntProperty("i", message.mIndex.Value()); |
471 | 0 | jw.DoubleProperty("ts", ToSeconds(message.mTimeStamp)); |
472 | 0 | DDLifetime* lifetime = |
473 | 0 | mLifetimes.FindLifetime(message.mObject, message.mIndex); |
474 | 0 | if (lifetime) { |
475 | 0 | jw.IntProperty("ob", lifetime->mTag); |
476 | 0 | } else { |
477 | 0 | jw.StringProperty("ob", |
478 | 0 | nsPrintfCString(R"("%s[%p]")", |
479 | 0 | message.mObject.TypeName(), |
480 | 0 | message.mObject.Pointer()) |
481 | 0 | .get()); |
482 | 0 | } |
483 | 0 | jw.StringProperty("cat", ToShortString(message.mCategory)); |
484 | 0 | if (message.mLabel && message.mLabel[0] != '\0') { |
485 | 0 | jw.StringProperty("lbl", message.mLabel); |
486 | 0 | } |
487 | 0 | if (!message.mValue.is<DDNoValue>()) { |
488 | 0 | if (message.mValue.is<DDLogObject>()) { |
489 | 0 | const DDLogObject& ob2 = message.mValue.as<DDLogObject>(); |
490 | 0 | DDLifetime* lifetime2 = mLifetimes.FindLifetime(ob2, message.mIndex); |
491 | 0 | if (lifetime2) { |
492 | 0 | jw.IntProperty("val", lifetime2->mTag); |
493 | 0 | } else { |
494 | 0 | ToJSON(message.mValue, jw, "val"); |
495 | 0 | } |
496 | 0 | } else { |
497 | 0 | ToJSON(message.mValue, jw, "val"); |
498 | 0 | } |
499 | 0 | } |
500 | 0 | jw.EndObject(); |
501 | 0 | } |
502 | 0 | jw.EndArray(); |
503 | 0 | jw.StartObjectProperty("objects"); |
504 | 0 | mLifetimes.Visit( |
505 | 0 | mediaElement, |
506 | 0 | [&](const DDLifetime& lifetime) { |
507 | 0 | jw.StartObjectProperty(nsPrintfCString("%" PRIi32, lifetime.mTag).get(), |
508 | 0 | JSONWriter::SingleLineStyle); |
509 | 0 | jw.IntProperty("tag", lifetime.mTag); |
510 | 0 | jw.StringProperty("cls", lifetime.mObject.TypeName()); |
511 | 0 | jw.StringProperty( |
512 | 0 | "ptr", nsPrintfCString("%p", lifetime.mObject.Pointer()).get()); |
513 | 0 | jw.IntProperty("con", lifetime.mConstructionIndex.Value()); |
514 | 0 | jw.DoubleProperty("con_ts", ToSeconds(lifetime.mConstructionTimeStamp)); |
515 | 0 | if (lifetime.mDestructionTimeStamp) { |
516 | 0 | jw.IntProperty("des", lifetime.mDestructionIndex.Value()); |
517 | 0 | jw.DoubleProperty("des_ts", |
518 | 0 | ToSeconds(lifetime.mDestructionTimeStamp)); |
519 | 0 | } |
520 | 0 | if (lifetime.mDerivedObject.Pointer()) { |
521 | 0 | DDLifetime* derived = mLifetimes.FindLifetime( |
522 | 0 | lifetime.mDerivedObject, lifetime.mDerivedObjectLinkingIndex); |
523 | 0 | if (derived) { |
524 | 0 | jw.IntProperty("drvd", derived->mTag); |
525 | 0 | } |
526 | 0 | } |
527 | 0 | jw.EndObject(); |
528 | 0 | }, |
529 | 0 | // If there were no (new) messages, only give the main HTMLMediaElement |
530 | 0 | // object (used to identify this log against the correct element.) |
531 | 0 | log->mMessages.IsEmpty()); |
532 | 0 | jw.EndObject(); |
533 | 0 | jw.End(); |
534 | 0 | DDL_DEBUG("RetrieveMessages(%p) ->\n%s", mediaElement, json.get()); |
535 | 0 |
|
536 | 0 | // This log exists (new messages or not) -> Resolve this promise. |
537 | 0 | DDL_INFO("Resolving promise for HTMLMediaElement[%p] with messages %" PRImi |
538 | 0 | "-%" PRImi, |
539 | 0 | mediaElement, |
540 | 0 | log->mMessages.IsEmpty() ? 0 : log->mMessages[0].mIndex.Value(), |
541 | 0 | log->mMessages.IsEmpty() |
542 | 0 | ? 0 |
543 | 0 | : log->mMessages[log->mMessages.Length() - 1].mIndex.Value()); |
544 | 0 | promiseHolder.Resolve(std::move(json), __func__); |
545 | 0 |
|
546 | 0 | // Remove exported messages. |
547 | 0 | log->mMessages.Clear(); |
548 | 0 |
|
549 | 0 | // Pop this resolved promise, fetch next one. |
550 | 0 | MutexAutoLock lock(mMutex); |
551 | 0 | mPendingPromises.RemoveElementAt(0); |
552 | 0 | if (mPendingPromises.IsEmpty()) { |
553 | 0 | break; |
554 | 0 | } |
555 | 0 | promiseHolder = std::move(mPendingPromises[0].mPromiseHolder); |
556 | 0 | mediaElement = mPendingPromises[0].mMediaElement; |
557 | 0 | } |
558 | 0 | } |
559 | | |
560 | | void |
561 | | DDMediaLogs::CleanUpLogs() |
562 | 0 | { |
563 | 0 | MOZ_ASSERT(!mThread || mThread.get() == NS_GetCurrentThread()); |
564 | 0 |
|
565 | 0 | DDTimeStamp now = DDNow(); |
566 | 0 |
|
567 | 0 | // Keep up to 30s of unclassified messages (if a message doesn't get |
568 | 0 | // classified this quickly, it probably never will be.) |
569 | 0 | static const double sMaxAgeUnclassifiedMessages_s = 30.0; |
570 | 0 | // Keep "dead" log (video element and dependents were destroyed) for up to |
571 | 0 | // 2 minutes, in case the user wants to look at it after the facts. |
572 | 0 | static const double sMaxAgeDeadLog_s = 120.0; |
573 | 0 | // Keep old messages related to a live video for up to 5 minutes. |
574 | 0 | static const double sMaxAgeClassifiedMessages_s = 300.0; |
575 | 0 |
|
576 | 0 | for (size_t logIndexPlus1 = mMediaLogs.Length(); logIndexPlus1 != 0; |
577 | 0 | --logIndexPlus1) { |
578 | 0 | DDMediaLog& log = mMediaLogs[logIndexPlus1 - 1]; |
579 | 0 | if (log.mMediaElement) { |
580 | 0 | // Remove logs for which no lifetime still existed some time ago. |
581 | 0 | bool used = mLifetimes.VisitBreakable( |
582 | 0 | log.mMediaElement, [&](const DDLifetime& lifetime) { |
583 | 0 | // Do we still have a lifetime that existed recently enough? |
584 | 0 | return !lifetime.mDestructionTimeStamp || |
585 | 0 | (now - lifetime.mDestructionTimeStamp).ToSeconds() <= |
586 | 0 | sMaxAgeDeadLog_s; |
587 | 0 | }); |
588 | 0 | if (!used) { |
589 | 0 | DDL_INFO("Removed old log for media element %p", log.mMediaElement); |
590 | 0 | mLifetimes.Visit(log.mMediaElement, [&](const DDLifetime& lifetime) { |
591 | 0 | DestroyLifetimeLinks(lifetime); |
592 | 0 | }); |
593 | 0 | mLifetimes.RemoveLifetimesFor(log.mMediaElement); |
594 | 0 | mMediaLogs.RemoveElementAt(logIndexPlus1 - 1); |
595 | 0 | continue; |
596 | 0 | } |
597 | 0 | } |
598 | 0 |
|
599 | 0 | // Remove old messages. |
600 | 0 | size_t old = 0; |
601 | 0 | const size_t len = log.mMessages.Length(); |
602 | 0 | while (old < len && (now - log.mMessages[old].mTimeStamp).ToSeconds() > |
603 | 0 | (log.mMediaElement ? sMaxAgeClassifiedMessages_s |
604 | 0 | : sMaxAgeUnclassifiedMessages_s)) { |
605 | 0 | ++old; |
606 | 0 | } |
607 | 0 | if (old != 0) { |
608 | 0 | // We are going to remove `old` messages. |
609 | 0 | // First, remove associated destroyed lifetimes that are not used after |
610 | 0 | // these old messages. (We want to keep non-destroyed lifetimes, in |
611 | 0 | // case they get used later on.) |
612 | 0 | size_t removedLifetimes = 0; |
613 | 0 | for (size_t i = 0; i < old; ++i) { |
614 | 0 | auto RemoveDestroyedUnusedLifetime = [&](DDLifetime* lifetime) { |
615 | 0 | if (!lifetime->mDestructionTimeStamp) { |
616 | 0 | // Lifetime is still alive, keep it. |
617 | 0 | return; |
618 | 0 | } |
619 | 0 | bool used = false; |
620 | 0 | for (size_t after = old; after < len; ++after) { |
621 | 0 | const DDLogMessage message = log.mMessages[i]; |
622 | 0 | if (!lifetime->IsAliveAt(message.mIndex)) { |
623 | 0 | // Lifetime is already dead, and not used yet -> kill it. |
624 | 0 | break; |
625 | 0 | } |
626 | 0 | const DDLogObject& ob = message.mObject; |
627 | 0 | if (lifetime->mObject == ob) { |
628 | 0 | used = true; |
629 | 0 | break; |
630 | 0 | } |
631 | 0 | if (message.mValue.is<DDLogObject>()) { |
632 | 0 | if (lifetime->mObject == message.mValue.as<DDLogObject>()) { |
633 | 0 | used = true; |
634 | 0 | break; |
635 | 0 | } |
636 | 0 | } |
637 | 0 | } |
638 | 0 | if (!used) { |
639 | 0 | DestroyLifetimeLinks(*lifetime); |
640 | 0 | mLifetimes.RemoveLifetime(lifetime); |
641 | 0 | ++removedLifetimes; |
642 | 0 | } |
643 | 0 | }; |
644 | 0 |
|
645 | 0 | const DDLogMessage message = log.mMessages[i]; |
646 | 0 | const DDLogObject& ob = message.mObject; |
647 | 0 |
|
648 | 0 | DDLifetime* lifetime1 = mLifetimes.FindLifetime(ob, message.mIndex); |
649 | 0 | if (lifetime1) { |
650 | 0 | RemoveDestroyedUnusedLifetime(lifetime1); |
651 | 0 | } |
652 | 0 |
|
653 | 0 | if (message.mValue.is<DDLogObject>()) { |
654 | 0 | DDLifetime* lifetime2 = mLifetimes.FindLifetime( |
655 | 0 | message.mValue.as<DDLogObject>(), message.mIndex); |
656 | 0 | if (lifetime2) { |
657 | 0 | RemoveDestroyedUnusedLifetime(lifetime2); |
658 | 0 | } |
659 | 0 | } |
660 | 0 | } |
661 | 0 | DDL_INFO("Removed %zu messages (#%" PRImi " %f - #%" PRImi |
662 | 0 | " %f) and %zu lifetimes from log for media element %p", |
663 | 0 | old, |
664 | 0 | log.mMessages[0].mIndex.Value(), |
665 | 0 | ToSeconds(log.mMessages[0].mTimeStamp), |
666 | 0 | log.mMessages[old - 1].mIndex.Value(), |
667 | 0 | ToSeconds(log.mMessages[old - 1].mTimeStamp), |
668 | 0 | removedLifetimes, |
669 | 0 | log.mMediaElement); |
670 | 0 | log.mMessages.RemoveElementsAt(0, old); |
671 | 0 | } |
672 | 0 | } |
673 | 0 | } |
674 | | |
675 | | void |
676 | | DDMediaLogs::ProcessLog() |
677 | 0 | { |
678 | 0 | MOZ_ASSERT(!mThread || mThread.get() == NS_GetCurrentThread()); |
679 | 0 | ProcessBuffer(); |
680 | 0 | FulfillPromises(); |
681 | 0 | CleanUpLogs(); |
682 | 0 | DDL_INFO("ProcessLog() completed - DDMediaLog size: %zu", |
683 | 0 | SizeOfIncludingThis(moz_malloc_size_of)); |
684 | 0 | } |
685 | | |
686 | | nsresult |
687 | | DDMediaLogs::DispatchProcessLog(const MutexAutoLock& aProofOfLock) |
688 | 0 | { |
689 | 0 | if (!mThread) { |
690 | 0 | return NS_ERROR_SERVICE_NOT_AVAILABLE; |
691 | 0 | } |
692 | 0 | return mThread->Dispatch( |
693 | 0 | NS_NewRunnableFunction("ProcessLog", [this] { ProcessLog(); }), |
694 | 0 | NS_DISPATCH_NORMAL); |
695 | 0 | } |
696 | | |
697 | | nsresult |
698 | | DDMediaLogs::DispatchProcessLog() |
699 | 0 | { |
700 | 0 | DDL_INFO("DispatchProcessLog() - Yet-unprocessed message buffers: %d", |
701 | 0 | mMessagesQueue.LiveBuffersStats().mCount); |
702 | 0 | MutexAutoLock lock(mMutex); |
703 | 0 | return DispatchProcessLog(lock); |
704 | 0 | } |
705 | | |
706 | | RefPtr<DDMediaLogs::LogMessagesPromise> |
707 | | DDMediaLogs::RetrieveMessages(const dom::HTMLMediaElement* aMediaElement) |
708 | 0 | { |
709 | 0 | MozPromiseHolder<LogMessagesPromise> holder; |
710 | 0 | RefPtr<LogMessagesPromise> promise = holder.Ensure(__func__); |
711 | 0 | { |
712 | 0 | MutexAutoLock lock(mMutex); |
713 | 0 | // If there were unfulfilled promises, we know processing has already |
714 | 0 | // been requested. |
715 | 0 | if (mPendingPromises.IsEmpty()) { |
716 | 0 | // But if we're the first one, start processing. |
717 | 0 | nsresult rv = DispatchProcessLog(lock); |
718 | 0 | if (NS_FAILED(rv)) { |
719 | 0 | holder.Reject(rv, __func__); |
720 | 0 | } |
721 | 0 | } |
722 | 0 | mPendingPromises.AppendElement( |
723 | 0 | PendingPromise{ std::move(holder), aMediaElement }); |
724 | 0 | } |
725 | 0 | return promise; |
726 | 0 | } |
727 | | |
728 | | } // namespace mozilla |