Line data Source code
1 : /* -*- Mode: C++; tab-width: 8; indent-tabs-mode: nil; c-basic-offset: 4 -*-
2 : * vim: set ts=8 sts=4 et sw=4 tw=99:
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 "vm/TraceLogging.h"
8 :
9 : #include "mozilla/DebugOnly.h"
10 : #include "mozilla/EndianUtils.h"
11 : #include "mozilla/MemoryReporting.h"
12 : #include "mozilla/ScopeExit.h"
13 :
14 : #include <string.h>
15 : #include <utility>
16 :
17 : #include "jsapi.h"
18 :
19 : #include "jit/BaselineJIT.h"
20 : #include "jit/CompileWrappers.h"
21 : #include "js/Printf.h"
22 : #include "threading/LockGuard.h"
23 : #include "util/Text.h"
24 : #include "vm/JSScript.h"
25 : #include "vm/Runtime.h"
26 : #include "vm/Time.h"
27 : #include "vm/TraceLoggingGraph.h"
28 :
29 : #include "jit/JitFrames-inl.h"
30 :
31 : using namespace js;
32 : using namespace js::jit;
33 :
34 : using mozilla::DebugOnly;
35 :
36 : TraceLoggerThreadState* traceLoggerState = nullptr;
37 :
38 : #if defined(MOZ_HAVE_RDTSC)
39 :
40 : uint64_t inline rdtsc() {
41 1 : return ReadTimestampCounter();
42 : }
43 :
44 : #elif defined(__powerpc__)
45 : static __inline__ uint64_t
46 : rdtsc(void)
47 : {
48 : uint64_t result=0;
49 : uint32_t upper, lower,tmp;
50 : __asm__ volatile(
51 : "0: \n"
52 : "\tmftbu %0 \n"
53 : "\tmftb %1 \n"
54 : "\tmftbu %2 \n"
55 : "\tcmpw %2,%0 \n"
56 : "\tbne 0b \n"
57 : : "=r"(upper),"=r"(lower),"=r"(tmp)
58 : );
59 : result = upper;
60 : result = result<<32;
61 : result = result|lower;
62 :
63 : return result;
64 :
65 : }
66 : #elif defined(__arm__) || defined(__aarch64__)
67 :
68 : #include <sys/time.h>
69 :
70 : static __inline__ uint64_t
71 : rdtsc(void)
72 : {
73 : struct timeval tv;
74 : gettimeofday(&tv, NULL);
75 : uint64_t ret = tv.tv_sec;
76 : ret *= 1000000;
77 : ret += tv.tv_usec;
78 : return ret;
79 : }
80 :
81 : #else
82 :
83 : static __inline__ uint64_t
84 : rdtsc(void)
85 : {
86 : return 0;
87 : }
88 :
89 : #endif // defined(MOZ_HAVE_RDTSC)
90 :
91 : static bool
92 73875 : EnsureTraceLoggerState()
93 : {
94 0 : if (MOZ_LIKELY(traceLoggerState))
95 : return true;
96 :
97 1 : traceLoggerState = js_new<TraceLoggerThreadState>();
98 0 : if (!traceLoggerState)
99 : return false;
100 :
101 1 : if (!traceLoggerState->init()) {
102 0 : DestroyTraceLoggerThreadState();
103 0 : return false;
104 : }
105 :
106 : return true;
107 : }
108 :
109 : size_t
110 0 : js::SizeOfTraceLogState(mozilla::MallocSizeOf mallocSizeOf)
111 : {
112 0 : return traceLoggerState ? traceLoggerState->sizeOfIncludingThis(mallocSizeOf) : 0;
113 : }
114 :
115 : void
116 0 : js::DestroyTraceLoggerThreadState()
117 : {
118 0 : if (traceLoggerState) {
119 0 : js_delete(traceLoggerState);
120 0 : traceLoggerState = nullptr;
121 : }
122 0 : }
123 :
124 : #ifdef DEBUG
125 : bool
126 0 : js::CurrentThreadOwnsTraceLoggerThreadStateLock()
127 : {
128 0 : return traceLoggerState && traceLoggerState->lock.ownedByCurrentThread();
129 : }
130 : #endif
131 :
132 : void
133 0 : js::DestroyTraceLogger(TraceLoggerThread* logger)
134 : {
135 0 : if (!EnsureTraceLoggerState())
136 : return;
137 0 : traceLoggerState->destroyLogger(logger);
138 : }
139 :
140 : bool
141 8 : TraceLoggerThread::init()
142 : {
143 16 : if (!events.init())
144 : return false;
145 :
146 : // Minimum amount of capacity needed for operation to allow flushing.
147 : // Flushing requires space for the actual event and two spaces to log the
148 : // start and stop of flushing.
149 0 : if (!events.ensureSpaceBeforeAdd(3))
150 : return false;
151 :
152 8 : return true;
153 : }
154 :
155 : void
156 0 : TraceLoggerThread::initGraph()
157 : {
158 : // Create a graph. I don't like this is called reset, but it locks the
159 : // graph into the UniquePtr. So it gets deleted when TraceLoggerThread
160 : // is destructed.
161 0 : graph.reset(js_new<TraceLoggerGraph>());
162 0 : if (!graph.get())
163 : return;
164 :
165 0 : MOZ_ASSERT(traceLoggerState);
166 0 : uint64_t start = rdtsc() - traceLoggerState->startupTime;
167 0 : if (!graph->init(start)) {
168 0 : graph = nullptr;
169 0 : return;
170 : }
171 :
172 : // Report the textIds to the graph.
173 0 : for (uint32_t i = 0; i < TraceLogger_LastTreeItem; i++) {
174 0 : TraceLoggerTextId id = TraceLoggerTextId(i);
175 0 : graph->addTextId(i, TLTextIdString(id));
176 : }
177 0 : graph->addTextId(TraceLogger_LastTreeItem, "TraceLogger internal");
178 0 : for (uint32_t i = TraceLogger_LastTreeItem + 1; i < TraceLogger_Last; i++) {
179 0 : TraceLoggerTextId id = TraceLoggerTextId(i);
180 0 : graph->addTextId(i, TLTextIdString(id));
181 : }
182 : }
183 :
184 0 : TraceLoggerThread::~TraceLoggerThread()
185 : {
186 0 : if (graph.get()) {
187 0 : if (!failed)
188 0 : graph->log(events);
189 0 : graph = nullptr;
190 : }
191 0 : }
192 :
193 : bool
194 0 : TraceLoggerThread::enable()
195 : {
196 0 : if (enabled_ > 0) {
197 0 : enabled_++;
198 0 : return true;
199 : }
200 :
201 0 : if (failed)
202 : return false;
203 :
204 0 : enabled_ = 1;
205 0 : logTimestamp(TraceLogger_Enable);
206 :
207 0 : return true;
208 : }
209 :
210 : bool
211 0 : TraceLoggerThread::fail(JSContext* cx, const char* error)
212 : {
213 0 : JS_ReportErrorNumberASCII(cx, GetErrorMessage, nullptr, JSMSG_TRACELOGGER_ENABLE_FAIL, error);
214 0 : failed = true;
215 0 : enabled_ = 0;
216 :
217 0 : return false;
218 : }
219 :
220 : void
221 0 : TraceLoggerThread::silentFail(const char* error)
222 : {
223 0 : traceLoggerState->maybeSpewError(error);
224 0 : failed = true;
225 0 : enabled_ = 0;
226 0 : }
227 :
228 : size_t
229 0 : TraceLoggerThread::sizeOfExcludingThis(mozilla::MallocSizeOf mallocSizeOf) const
230 : {
231 0 : size_t size = 0;
232 : #ifdef DEBUG
233 0 : size += graphStack.sizeOfExcludingThis(mallocSizeOf);
234 : #endif
235 0 : size += events.sizeOfExcludingThis(mallocSizeOf);
236 0 : if (graph.get())
237 0 : size += graph->sizeOfIncludingThis(mallocSizeOf);
238 0 : return size;
239 : }
240 :
241 : size_t
242 0 : TraceLoggerThread::sizeOfIncludingThis(mozilla::MallocSizeOf mallocSizeOf) const
243 : {
244 0 : return mallocSizeOf(this) + sizeOfExcludingThis(mallocSizeOf);
245 : }
246 :
247 : bool
248 0 : TraceLoggerThread::enable(JSContext* cx)
249 : {
250 0 : if (!enable())
251 0 : return fail(cx, "internal error");
252 :
253 0 : if (enabled_ == 1) {
254 : // Get the top Activation to log the top script/pc (No inlined frames).
255 0 : ActivationIterator iter(cx);
256 0 : Activation* act = iter.activation();
257 :
258 0 : if (!act)
259 0 : return fail(cx, "internal error");
260 :
261 0 : JSScript* script = nullptr;
262 0 : int32_t engine = 0;
263 :
264 0 : if (act->isJit()) {
265 0 : JitFrameIter frame(iter->asJit());
266 :
267 0 : while (!frame.done()) {
268 0 : if (frame.isWasm()) {
269 : JS_ReportErrorNumberASCII(cx, GetErrorMessage, nullptr,
270 : JSMSG_TRACELOGGER_ENABLE_FAIL,
271 0 : "not yet supported in wasm code");
272 0 : return false;
273 : }
274 0 : if (frame.asJSJit().isScripted())
275 : break;
276 0 : ++frame;
277 : }
278 :
279 0 : MOZ_ASSERT(!frame.done());
280 :
281 0 : const JSJitFrameIter& jitFrame = frame.asJSJit();
282 0 : MOZ_ASSERT(jitFrame.isIonJS() || jitFrame.isBaselineJS());
283 :
284 0 : script = jitFrame.script();
285 0 : engine = jitFrame.isIonJS() ? TraceLogger_IonMonkey : TraceLogger_Baseline;
286 : } else {
287 0 : MOZ_ASSERT(act->isInterpreter());
288 0 : InterpreterFrame* fp = act->asInterpreter()->current();
289 0 : MOZ_ASSERT(!fp->runningInJit());
290 :
291 0 : script = fp->script();
292 0 : engine = TraceLogger_Interpreter;
293 : }
294 0 : if (script->compartment() != cx->compartment())
295 0 : return fail(cx, "compartment mismatch");
296 :
297 0 : TraceLoggerEvent event(TraceLogger_Scripts, script);
298 0 : startEvent(event);
299 0 : startEvent(engine);
300 : }
301 :
302 : return true;
303 : }
304 :
305 : bool
306 0 : TraceLoggerThread::disable(bool force, const char* error)
307 : {
308 0 : if (failed) {
309 0 : MOZ_ASSERT(enabled_ == 0);
310 : return false;
311 : }
312 :
313 0 : if (enabled_ == 0)
314 : return true;
315 :
316 0 : if (enabled_ > 1 && !force) {
317 0 : enabled_--;
318 0 : return true;
319 : }
320 :
321 0 : if (force)
322 0 : traceLoggerState->maybeSpewError(error);
323 :
324 0 : logTimestamp(TraceLogger_Disable);
325 0 : enabled_ = 0;
326 :
327 0 : return true;
328 : }
329 :
330 : const char*
331 0 : TraceLoggerThread::maybeEventText(uint32_t id)
332 : {
333 0 : if (id < TraceLogger_Last)
334 0 : return TLTextIdString(static_cast<TraceLoggerTextId>(id));
335 0 : return traceLoggerState->maybeEventText(id);
336 : }
337 :
338 : const char*
339 0 : TraceLoggerThreadState::maybeEventText(uint32_t id)
340 : {
341 0 : LockGuard<Mutex> guard(lock);
342 :
343 0 : TextIdHashMap::Ptr p = textIdPayloads.lookup(id);
344 0 : if (!p)
345 : return nullptr;
346 :
347 0 : return p->value()->string();
348 : }
349 :
350 : size_t
351 0 : TraceLoggerThreadState::sizeOfExcludingThis(mozilla::MallocSizeOf mallocSizeOf)
352 : {
353 0 : LockGuard<Mutex> guard(lock);
354 :
355 : // Do not count threadLoggers since they are counted by JSContext::traceLogger.
356 :
357 0 : size_t size = 0;
358 0 : size += pointerMap.sizeOfExcludingThis(mallocSizeOf);
359 0 : if (textIdPayloads.initialized()) {
360 0 : size += textIdPayloads.sizeOfExcludingThis(mallocSizeOf);
361 0 : for (TextIdHashMap::Range r = textIdPayloads.all(); !r.empty(); r.popFront())
362 0 : r.front().value()->sizeOfIncludingThis(mallocSizeOf);
363 : }
364 0 : return size;
365 : }
366 :
367 : bool
368 0 : TraceLoggerThread::textIdIsScriptEvent(uint32_t id)
369 : {
370 0 : if (id < TraceLogger_Last)
371 : return false;
372 :
373 : // Currently this works by checking if text begins with "script".
374 0 : const char* str = eventText(id);
375 0 : return EqualChars(str, "script", 6);
376 : }
377 :
378 : void
379 0 : TraceLoggerThread::extractScriptDetails(uint32_t textId, const char** filename, size_t* filename_len,
380 : const char** lineno, size_t* lineno_len, const char** colno,
381 : size_t* colno_len)
382 : {
383 0 : MOZ_ASSERT(textIdIsScriptEvent(textId));
384 :
385 0 : const char* script = eventText(textId);
386 :
387 : // Get the start of filename (remove 'script ' at the start).
388 0 : MOZ_ASSERT(EqualChars(script, "script ", 7));
389 0 : *filename = script + 7;
390 :
391 : // Get the start of lineno and colno.
392 0 : *lineno = script;
393 0 : *colno = script;
394 0 : const char* next = script - 1;
395 0 : while ((next = strchr(next + 1, ':'))) {
396 0 : *lineno = *colno;
397 0 : *colno = next;
398 : }
399 :
400 0 : MOZ_ASSERT(*lineno && *lineno != script);
401 0 : MOZ_ASSERT(*colno && *colno != script);
402 :
403 : // Remove the ':' at the front.
404 0 : *lineno = *lineno + 1;
405 0 : *colno = *colno + 1;
406 :
407 0 : *filename_len = *lineno - *filename - 1;
408 0 : *lineno_len = *colno - *lineno - 1;
409 0 : *colno_len = strlen(*colno);
410 0 : }
411 :
412 : TraceLoggerEventPayload*
413 0 : TraceLoggerThreadState::getOrCreateEventPayload(const char* text)
414 : {
415 0 : LockGuard<Mutex> guard(lock);
416 :
417 0 : PointerHashMap::AddPtr p = pointerMap.lookupForAdd((const void*)text);
418 0 : if (p) {
419 0 : MOZ_ASSERT(p->value()->textId() < nextTextId); // Sanity check.
420 0 : p->value()->use();
421 0 : return p->value();
422 : }
423 :
424 0 : UniqueChars str = DuplicateString(text);
425 0 : if (!str)
426 : return nullptr;
427 :
428 0 : uint32_t textId = nextTextId;
429 :
430 0 : auto* payload = js_new<TraceLoggerEventPayload>(textId, std::move(str));
431 0 : if (!payload)
432 : return nullptr;
433 :
434 0 : if (!textIdPayloads.putNew(textId, payload)) {
435 0 : js_delete(payload);
436 0 : payload = nullptr;
437 0 : return nullptr;
438 : }
439 :
440 0 : payload->use();
441 :
442 0 : nextTextId++;
443 :
444 0 : if (!pointerMap.add(p, text, payload))
445 : return nullptr;
446 :
447 0 : payload->incPointerCount();
448 :
449 0 : return payload;
450 : }
451 :
452 : TraceLoggerEventPayload*
453 0 : TraceLoggerThreadState::getOrCreateEventPayload(const char* filename,
454 : uint32_t lineno, uint32_t colno, const void* ptr)
455 : {
456 0 : if (!filename)
457 0 : filename = "<unknown>";
458 :
459 0 : LockGuard<Mutex> guard(lock);
460 :
461 0 : PointerHashMap::AddPtr p;
462 0 : if (ptr) {
463 0 : p = pointerMap.lookupForAdd(ptr);
464 0 : if (p) {
465 0 : MOZ_ASSERT(p->value()->textId() < nextTextId); // Sanity check.
466 0 : p->value()->use();
467 0 : return p->value();
468 : }
469 : }
470 :
471 0 : UniqueChars str = JS_smprintf("script %s:%u:%u", filename, lineno, colno);
472 0 : if (!str)
473 : return nullptr;
474 :
475 0 : uint32_t textId = nextTextId;
476 0 : auto* payload = js_new<TraceLoggerEventPayload>(textId, std::move(str));
477 0 : if (!payload)
478 : return nullptr;
479 :
480 0 : if (!textIdPayloads.putNew(textId, payload)) {
481 0 : js_delete(payload);
482 0 : payload = nullptr;
483 0 : return nullptr;
484 : }
485 :
486 0 : payload->use();
487 :
488 0 : nextTextId++;
489 :
490 0 : if (ptr) {
491 0 : if (!pointerMap.add(p, ptr, payload))
492 : return nullptr;
493 :
494 0 : payload->incPointerCount();
495 : }
496 :
497 0 : return payload;
498 : }
499 :
500 : TraceLoggerEventPayload*
501 0 : TraceLoggerThreadState::getOrCreateEventPayload(JSScript* script)
502 : {
503 0 : return getOrCreateEventPayload(script->filename(), script->lineno(), script->column(), nullptr);
504 : }
505 :
506 : void
507 0 : TraceLoggerThreadState::purgeUnusedPayloads()
508 : {
509 : // Care needs to be taken to maintain a coherent state in this function,
510 : // as payloads can have their use count change at any time from non-zero to
511 : // zero (but not the other way around; see TraceLoggerEventPayload::use()).
512 0 : LockGuard<Mutex> guard(lock);
513 :
514 : // Remove all the pointers to payloads that have no uses anymore
515 : // and decrease the pointer count of that payload.
516 0 : for (PointerHashMap::Enum e(pointerMap); !e.empty(); e.popFront()) {
517 0 : if (e.front().value()->uses() == 0) {
518 0 : e.front().value()->decPointerCount();
519 : e.removeFront();
520 : }
521 : }
522 :
523 : // Free all other payloads that have no uses anymore.
524 0 : for (TextIdHashMap::Enum e(textIdPayloads); !e.empty(); e.popFront()) {
525 0 : if (e.front().value()->uses() == 0 && e.front().value()->pointerCount() == 0) {
526 0 : js_delete(e.front().value());
527 : e.removeFront();
528 : }
529 : }
530 0 : }
531 :
532 : void
533 74139 : TraceLoggerThread::startEvent(TraceLoggerTextId id) {
534 74139 : startEvent(uint32_t(id));
535 74140 : }
536 :
537 : void
538 1 : TraceLoggerThread::startEvent(const TraceLoggerEvent& event) {
539 1 : if (!event.hasTextId()) {
540 0 : if (!enabled())
541 : return;
542 0 : startEvent(TraceLogger_Error);
543 : disable(/* force = */ true, "TraceLogger encountered an empty event. "
544 : "Potentially due to OOM during creation of "
545 0 : "this event. Disabling TraceLogger.");
546 0 : return;
547 : }
548 0 : startEvent(event.textId());
549 : }
550 :
551 : void
552 0 : TraceLoggerThread::startEvent(uint32_t id)
553 : {
554 1 : MOZ_ASSERT(TLTextIdIsTreeEvent(id) || id == TraceLogger_Error);
555 117230 : MOZ_ASSERT(traceLoggerState);
556 1 : if (!traceLoggerState->isTextIdEnabled(id))
557 : return;
558 :
559 : #ifdef DEBUG
560 0 : if (enabled_ > 0) {
561 0 : AutoEnterOOMUnsafeRegion oomUnsafe;
562 0 : if (!graphStack.append(id))
563 0 : oomUnsafe.crash("Could not add item to debug stack.");
564 : }
565 : #endif
566 :
567 0 : if (graph.get()) {
568 0 : for (uint32_t otherId = graph->nextTextId(); otherId <= id; otherId++)
569 0 : graph->addTextId(otherId, maybeEventText(id));
570 : }
571 :
572 0 : log(id);
573 : }
574 :
575 : void
576 1 : TraceLoggerThread::stopEvent(TraceLoggerTextId id) {
577 1 : stopEvent(uint32_t(id));
578 74361 : }
579 :
580 : void
581 1 : TraceLoggerThread::stopEvent(const TraceLoggerEvent& event) {
582 1 : if (!event.hasTextId()) {
583 : stopEvent(TraceLogger_Error);
584 : return;
585 : }
586 1 : stopEvent(event.textId());
587 : }
588 :
589 : void
590 0 : TraceLoggerThread::stopEvent(uint32_t id)
591 : {
592 0 : MOZ_ASSERT(TLTextIdIsTreeEvent(id) || id == TraceLogger_Error);
593 109268 : MOZ_ASSERT(traceLoggerState);
594 218536 : if (!traceLoggerState->isTextIdEnabled(id))
595 : return;
596 :
597 : #ifdef DEBUG
598 0 : if (enabled_ > 0 && !graphStack.empty()) {
599 0 : uint32_t prev = graphStack.popCopy();
600 0 : if (id == TraceLogger_Error || prev == TraceLogger_Error) {
601 : // When encountering an Error id the stack will most likely not be correct anymore.
602 : // Ignore this.
603 0 : } else if (id == TraceLogger_Engine) {
604 0 : MOZ_ASSERT(prev == TraceLogger_IonMonkey || prev == TraceLogger_Baseline ||
605 : prev == TraceLogger_Interpreter);
606 0 : } else if (id == TraceLogger_Scripts) {
607 0 : MOZ_ASSERT(prev >= TraceLogger_Last);
608 0 : } else if (id >= TraceLogger_Last) {
609 0 : MOZ_ASSERT(prev >= TraceLogger_Last);
610 0 : if (prev != id) {
611 : // Ignore if the text has been flushed already.
612 0 : MOZ_ASSERT_IF(maybeEventText(prev), strcmp(eventText(id), eventText(prev)) == 0);
613 : }
614 : } else {
615 0 : MOZ_ASSERT(id == prev);
616 : }
617 : }
618 : #endif
619 :
620 0 : log(TraceLogger_Stop);
621 : }
622 :
623 : void
624 1 : TraceLoggerThread::logTimestamp(TraceLoggerTextId id)
625 : {
626 1 : logTimestamp(uint32_t(id));
627 29 : }
628 :
629 : void
630 29 : TraceLoggerThread::logTimestamp(uint32_t id)
631 : {
632 29 : MOZ_ASSERT(id > TraceLogger_LastTreeItem && id < TraceLogger_Last);
633 29 : log(id);
634 1 : }
635 :
636 : void
637 29 : TraceLoggerThread::log(uint32_t id)
638 : {
639 29 : if (enabled_ == 0)
640 : return;
641 :
642 : #ifdef DEBUG
643 0 : if (id == TraceLogger_Disable)
644 0 : graphStack.clear();
645 : #endif
646 :
647 0 : MOZ_ASSERT(traceLoggerState);
648 :
649 : // We request for 3 items to add, since if we don't have enough room
650 : // we record the time it took to make more space. To log this information
651 : // we need 2 extra free entries.
652 0 : if (!events.hasSpaceForAdd(3)) {
653 0 : uint64_t start = rdtsc() - traceLoggerState->startupTime;
654 :
655 0 : if (!events.ensureSpaceBeforeAdd(3)) {
656 0 : if (graph.get())
657 0 : graph->log(events);
658 :
659 0 : iteration_++;
660 0 : events.clear();
661 :
662 : // Periodically remove unused payloads from the global logger state.
663 0 : traceLoggerState->purgeUnusedPayloads();
664 : }
665 :
666 : // Log the time it took to flush the events as being from the
667 : // Tracelogger.
668 0 : if (graph.get()) {
669 0 : MOZ_ASSERT(events.hasSpaceForAdd(2));
670 0 : EventEntry& entryStart = events.pushUninitialized();
671 0 : entryStart.time = start;
672 0 : entryStart.textId = TraceLogger_Internal;
673 :
674 0 : EventEntry& entryStop = events.pushUninitialized();
675 0 : entryStop.time = rdtsc() - traceLoggerState->startupTime;
676 0 : entryStop.textId = TraceLogger_Stop;
677 : }
678 :
679 : }
680 :
681 0 : uint64_t time = rdtsc() - traceLoggerState->startupTime;
682 :
683 0 : EventEntry& entry = events.pushUninitialized();
684 0 : entry.time = time;
685 0 : entry.textId = id;
686 : }
687 :
688 0 : TraceLoggerThreadState::~TraceLoggerThreadState()
689 : {
690 0 : while (TraceLoggerThread* logger = threadLoggers.popFirst())
691 : js_delete(logger);
692 :
693 0 : threadLoggers.clear();
694 :
695 0 : if (textIdPayloads.initialized()) {
696 0 : for (TextIdHashMap::Range r = textIdPayloads.all(); !r.empty(); r.popFront())
697 0 : js_delete(r.front().value());
698 : }
699 :
700 : #ifdef DEBUG
701 0 : initialized = false;
702 : #endif
703 0 : }
704 :
705 : static bool
706 67 : ContainsFlag(const char* str, const char* flag)
707 : {
708 67 : size_t flaglen = strlen(flag);
709 0 : const char* index = strstr(str, flag);
710 0 : while (index) {
711 0 : if ((index == str || index[-1] == ',') && (index[flaglen] == 0 || index[flaglen] == ','))
712 : return true;
713 0 : index = strstr(index + flaglen, flag);
714 : }
715 : return false;
716 : }
717 :
718 : bool
719 1 : TraceLoggerThreadState::init()
720 : {
721 1 : const char* env = getenv("TLLOG");
722 0 : if (!env)
723 0 : env = "";
724 :
725 1 : if (strstr(env, "help")) {
726 0 : fflush(nullptr);
727 : printf(
728 : "\n"
729 : "usage: TLLOG=option,option,option,... where options can be:\n"
730 : "\n"
731 : "Collections:\n"
732 : " Default Output all default. It includes:\n"
733 : " AnnotateScripts, Bailout, Baseline, BaselineCompilation, GC,\n"
734 : " GCAllocation, GCSweeping, Interpreter, IonAnalysis, IonCompilation,\n"
735 : " IonLinking, IonMonkey, MinorGC, Frontend, ParsingFull,\n"
736 : " ParsingSyntax, BytecodeEmission, IrregexpCompile, IrregexpExecute,\n"
737 : " Scripts, Engine, WasmCompilation\n"
738 : "\n"
739 : " IonCompiler Output all information about compilation. It includes:\n"
740 : " IonCompilation, IonLinking, PruneUnusedBranches, FoldTests,\n"
741 : " SplitCriticalEdges, RenumberBlocks, ScalarReplacement, \n"
742 : " DominatorTree, PhiAnalysis, MakeLoopsContiguous, ApplyTypes, \n"
743 : " EagerSimdUnbox, AliasAnalysis, GVN, LICM, Sincos, RangeAnalysis, \n"
744 : " LoopUnrolling, FoldLinearArithConstants, EffectiveAddressAnalysis, \n"
745 : " AlignmentMaskAnalysis, EliminateDeadCode, ReorderInstructions, \n"
746 : " EdgeCaseAnalysis, EliminateRedundantChecks, \n"
747 : " AddKeepAliveInstructions, GenerateLIR, RegisterAllocation, \n"
748 : " GenerateCode, Scripts, IonBuilderRestartLoop\n"
749 : "\n"
750 : " VMSpecific Output the specific name of the VM call\n"
751 : "\n"
752 : " Frontend Output all information about frontend compilation. It includes:\n"
753 : " Frontend, ParsingFull, ParsingSyntax, Tokenizing,\n"
754 : " BytecodeEmission, BytecodeFoldConstants, BytecodeNameFunctions\n"
755 : "Specific log items:\n"
756 0 : );
757 0 : for (uint32_t i = 1; i < TraceLogger_Last; i++) {
758 0 : TraceLoggerTextId id = TraceLoggerTextId(i);
759 0 : if (!TLTextIdIsTogglable(id))
760 : continue;
761 0 : printf(" %s\n", TLTextIdString(id));
762 : }
763 0 : printf("\n");
764 0 : exit(0);
765 : /*NOTREACHED*/
766 : }
767 :
768 141 : for (uint32_t i = 1; i < TraceLogger_Last; i++) {
769 70 : TraceLoggerTextId id = TraceLoggerTextId(i);
770 1 : if (TLTextIdIsTogglable(id))
771 1 : enabledTextIds[i] = ContainsFlag(env, TLTextIdString(id));
772 : else
773 1 : enabledTextIds[i] = true;
774 : }
775 :
776 1 : if (ContainsFlag(env, "Default")) {
777 0 : enabledTextIds[TraceLogger_AnnotateScripts] = true;
778 0 : enabledTextIds[TraceLogger_Bailout] = true;
779 0 : enabledTextIds[TraceLogger_Baseline] = true;
780 0 : enabledTextIds[TraceLogger_BaselineCompilation] = true;
781 0 : enabledTextIds[TraceLogger_GC] = true;
782 0 : enabledTextIds[TraceLogger_GCAllocation] = true;
783 0 : enabledTextIds[TraceLogger_GCSweeping] = true;
784 0 : enabledTextIds[TraceLogger_Interpreter] = true;
785 0 : enabledTextIds[TraceLogger_IonAnalysis] = true;
786 0 : enabledTextIds[TraceLogger_IonCompilation] = true;
787 0 : enabledTextIds[TraceLogger_IonLinking] = true;
788 0 : enabledTextIds[TraceLogger_IonMonkey] = true;
789 0 : enabledTextIds[TraceLogger_MinorGC] = true;
790 0 : enabledTextIds[TraceLogger_Frontend] = true;
791 0 : enabledTextIds[TraceLogger_ParsingFull] = true;
792 0 : enabledTextIds[TraceLogger_ParsingSyntax] = true;
793 0 : enabledTextIds[TraceLogger_BytecodeEmission] = true;
794 0 : enabledTextIds[TraceLogger_IrregexpCompile] = true;
795 0 : enabledTextIds[TraceLogger_IrregexpExecute] = true;
796 0 : enabledTextIds[TraceLogger_Scripts] = true;
797 0 : enabledTextIds[TraceLogger_Engine] = true;
798 0 : enabledTextIds[TraceLogger_WasmCompilation] = true;
799 : }
800 :
801 1 : if (ContainsFlag(env, "IonCompiler")) {
802 0 : enabledTextIds[TraceLogger_IonCompilation] = true;
803 0 : enabledTextIds[TraceLogger_IonLinking] = true;
804 0 : enabledTextIds[TraceLogger_PruneUnusedBranches] = true;
805 0 : enabledTextIds[TraceLogger_FoldTests] = true;
806 0 : enabledTextIds[TraceLogger_SplitCriticalEdges] = true;
807 0 : enabledTextIds[TraceLogger_RenumberBlocks] = true;
808 0 : enabledTextIds[TraceLogger_ScalarReplacement] = true;
809 0 : enabledTextIds[TraceLogger_DominatorTree] = true;
810 0 : enabledTextIds[TraceLogger_PhiAnalysis] = true;
811 0 : enabledTextIds[TraceLogger_MakeLoopsContiguous] = true;
812 0 : enabledTextIds[TraceLogger_ApplyTypes] = true;
813 0 : enabledTextIds[TraceLogger_EagerSimdUnbox] = true;
814 0 : enabledTextIds[TraceLogger_AliasAnalysis] = true;
815 0 : enabledTextIds[TraceLogger_GVN] = true;
816 0 : enabledTextIds[TraceLogger_LICM] = true;
817 0 : enabledTextIds[TraceLogger_Sincos] = true;
818 0 : enabledTextIds[TraceLogger_RangeAnalysis] = true;
819 0 : enabledTextIds[TraceLogger_LoopUnrolling] = true;
820 0 : enabledTextIds[TraceLogger_FoldLinearArithConstants] = true;
821 0 : enabledTextIds[TraceLogger_EffectiveAddressAnalysis] = true;
822 0 : enabledTextIds[TraceLogger_AlignmentMaskAnalysis] = true;
823 0 : enabledTextIds[TraceLogger_EliminateDeadCode] = true;
824 0 : enabledTextIds[TraceLogger_ReorderInstructions] = true;
825 0 : enabledTextIds[TraceLogger_EdgeCaseAnalysis] = true;
826 0 : enabledTextIds[TraceLogger_EliminateRedundantChecks] = true;
827 0 : enabledTextIds[TraceLogger_AddKeepAliveInstructions] = true;
828 0 : enabledTextIds[TraceLogger_GenerateLIR] = true;
829 0 : enabledTextIds[TraceLogger_RegisterAllocation] = true;
830 0 : enabledTextIds[TraceLogger_GenerateCode] = true;
831 0 : enabledTextIds[TraceLogger_Scripts] = true;
832 0 : enabledTextIds[TraceLogger_IonBuilderRestartLoop] = true;
833 : }
834 :
835 1 : if (ContainsFlag(env, "Frontend")) {
836 0 : enabledTextIds[TraceLogger_Frontend] = true;
837 0 : enabledTextIds[TraceLogger_ParsingFull] = true;
838 0 : enabledTextIds[TraceLogger_ParsingSyntax] = true;
839 0 : enabledTextIds[TraceLogger_BytecodeEmission] = true;
840 0 : enabledTextIds[TraceLogger_BytecodeFoldConstants] = true;
841 0 : enabledTextIds[TraceLogger_BytecodeNameFunctions] = true;
842 : }
843 :
844 1 : enabledTextIds[TraceLogger_Interpreter] = enabledTextIds[TraceLogger_Engine];
845 1 : enabledTextIds[TraceLogger_Baseline] = enabledTextIds[TraceLogger_Engine];
846 1 : enabledTextIds[TraceLogger_IonMonkey] = enabledTextIds[TraceLogger_Engine];
847 :
848 1 : enabledTextIds[TraceLogger_Error] = true;
849 :
850 1 : const char* options = getenv("TLOPTIONS");
851 1 : if (options) {
852 0 : if (strstr(options, "help")) {
853 0 : fflush(nullptr);
854 : printf(
855 : "\n"
856 : "usage: TLOPTIONS=option,option,option,... where options can be:\n"
857 : "\n"
858 : " EnableMainThread Start logging main threads immediately.\n"
859 : " EnableOffThread Start logging helper threads immediately.\n"
860 : " EnableGraph Enable spewing the tracelogging graph to a file.\n"
861 : " Errors Report errors during tracing to stderr.\n"
862 0 : );
863 0 : printf("\n");
864 0 : exit(0);
865 : /*NOTREACHED*/
866 : }
867 :
868 0 : if (strstr(options, "EnableMainThread"))
869 0 : mainThreadEnabled = true;
870 0 : if (strstr(options, "EnableOffThread"))
871 0 : helperThreadEnabled = true;
872 0 : if (strstr(options, "EnableGraph"))
873 0 : graphSpewingEnabled = true;
874 0 : if (strstr(options, "Errors"))
875 0 : spewErrors = true;
876 : }
877 :
878 1 : if (!pointerMap.init())
879 : return false;
880 2 : if (!textIdPayloads.init())
881 : return false;
882 :
883 1 : startupTime = rdtsc();
884 :
885 : #ifdef DEBUG
886 1 : initialized = true;
887 : #endif
888 :
889 1 : return true;
890 : }
891 :
892 : void
893 0 : TraceLoggerThreadState::enableTextId(JSContext* cx, uint32_t textId)
894 : {
895 0 : MOZ_ASSERT(TLTextIdIsTogglable(textId));
896 :
897 0 : if (enabledTextIds[textId])
898 : return;
899 :
900 0 : ReleaseAllJITCode(cx->runtime()->defaultFreeOp());
901 :
902 0 : enabledTextIds[textId] = true;
903 0 : if (textId == TraceLogger_Engine) {
904 0 : enabledTextIds[TraceLogger_IonMonkey] = true;
905 0 : enabledTextIds[TraceLogger_Baseline] = true;
906 0 : enabledTextIds[TraceLogger_Interpreter] = true;
907 : }
908 :
909 0 : if (textId == TraceLogger_Scripts)
910 0 : jit::ToggleBaselineTraceLoggerScripts(cx->runtime(), true);
911 0 : if (textId == TraceLogger_Engine)
912 0 : jit::ToggleBaselineTraceLoggerEngine(cx->runtime(), true);
913 :
914 : }
915 : void
916 0 : TraceLoggerThreadState::disableTextId(JSContext* cx, uint32_t textId)
917 : {
918 0 : MOZ_ASSERT(TLTextIdIsTogglable(textId));
919 :
920 0 : if (!enabledTextIds[textId])
921 : return;
922 :
923 0 : ReleaseAllJITCode(cx->runtime()->defaultFreeOp());
924 :
925 0 : enabledTextIds[textId] = false;
926 0 : if (textId == TraceLogger_Engine) {
927 0 : enabledTextIds[TraceLogger_IonMonkey] = false;
928 0 : enabledTextIds[TraceLogger_Baseline] = false;
929 0 : enabledTextIds[TraceLogger_Interpreter] = false;
930 : }
931 :
932 0 : if (textId == TraceLogger_Scripts)
933 0 : jit::ToggleBaselineTraceLoggerScripts(cx->runtime(), false);
934 0 : if (textId == TraceLogger_Engine)
935 0 : jit::ToggleBaselineTraceLoggerEngine(cx->runtime(), false);
936 : }
937 :
938 : TraceLoggerThread*
939 1 : js::TraceLoggerForCurrentThread(JSContext* maybecx)
940 : {
941 1 : if (!EnsureTraceLoggerState())
942 : return nullptr;
943 1 : return traceLoggerState->forCurrentThread(maybecx);
944 : }
945 :
946 : TraceLoggerThread*
947 1 : TraceLoggerThreadState::forCurrentThread(JSContext* maybecx)
948 : {
949 1 : MOZ_ASSERT(initialized);
950 132079 : MOZ_ASSERT_IF(maybecx, maybecx == TlsContext.get());
951 :
952 66473 : JSContext* cx = maybecx ? maybecx : TlsContext.get();
953 0 : if (!cx)
954 : return nullptr;
955 :
956 132368 : if (!cx->traceLogger) {
957 0 : LockGuard<Mutex> guard(lock);
958 :
959 8 : TraceLoggerThread* logger = js_new<TraceLoggerThread>();
960 8 : if (!logger)
961 0 : return nullptr;
962 :
963 0 : if (!logger->init()) {
964 0 : js_delete(logger);
965 0 : return nullptr;
966 : }
967 :
968 16 : threadLoggers.insertFront(logger);
969 16 : cx->traceLogger = logger;
970 :
971 0 : if (graphSpewingEnabled)
972 0 : logger->initGraph();
973 :
974 0 : if (CurrentHelperThread() ? helperThreadEnabled : mainThreadEnabled)
975 0 : logger->enable();
976 : }
977 :
978 0 : return cx->traceLogger;
979 : }
980 :
981 : void
982 0 : TraceLoggerThreadState::destroyLogger(TraceLoggerThread* logger)
983 : {
984 0 : MOZ_ASSERT(initialized);
985 0 : MOZ_ASSERT(logger);
986 0 : LockGuard<Mutex> guard(lock);
987 :
988 0 : logger->remove();
989 0 : js_delete(logger);
990 0 : }
991 :
992 : bool
993 7692 : js::TraceLogTextIdEnabled(uint32_t textId)
994 : {
995 7692 : if (!EnsureTraceLoggerState())
996 : return false;
997 7692 : return traceLoggerState->isTextIdEnabled(textId);
998 : }
999 :
1000 : void
1001 0 : js::TraceLogEnableTextId(JSContext* cx, uint32_t textId)
1002 : {
1003 0 : if (!EnsureTraceLoggerState())
1004 : return;
1005 0 : traceLoggerState->enableTextId(cx, textId);
1006 : }
1007 : void
1008 0 : js::TraceLogDisableTextId(JSContext* cx, uint32_t textId)
1009 : {
1010 0 : if (!EnsureTraceLoggerState())
1011 : return;
1012 0 : traceLoggerState->disableTextId(cx, textId);
1013 : }
1014 :
1015 1 : TraceLoggerEvent::TraceLoggerEvent(TraceLoggerTextId type, JSScript* script)
1016 32316 : : TraceLoggerEvent(type, script->filename(), script->lineno(), script->column())
1017 1 : { }
1018 :
1019 1 : TraceLoggerEvent::TraceLoggerEvent(TraceLoggerTextId type, const char* filename, uint32_t line,
1020 : uint32_t column)
1021 86184 : : payload_()
1022 : {
1023 43092 : MOZ_ASSERT(type == TraceLogger_Scripts || type == TraceLogger_AnnotateScripts ||
1024 : type == TraceLogger_InlinedScripts || type == TraceLogger_Frontend);
1025 :
1026 1 : if (!traceLoggerState)
1027 : return;
1028 :
1029 : // Only log scripts when enabled, otherwise use the more generic type
1030 : // (which will get filtered out).
1031 0 : if (!traceLoggerState->isTextIdEnabled(type)) {
1032 43092 : payload_.setTextId(type);
1033 : return;
1034 : }
1035 :
1036 0 : payload_.setEventPayload(
1037 0 : traceLoggerState->getOrCreateEventPayload(filename, line, column, nullptr));
1038 : }
1039 :
1040 0 : TraceLoggerEvent::TraceLoggerEvent(const char* text)
1041 0 : : payload_()
1042 : {
1043 0 : if (traceLoggerState)
1044 0 : payload_.setEventPayload(traceLoggerState->getOrCreateEventPayload(text));
1045 0 : }
1046 :
1047 86176 : TraceLoggerEvent::~TraceLoggerEvent()
1048 : {
1049 43088 : if (hasExtPayload())
1050 0 : extPayload()->release();
1051 1 : }
1052 :
1053 : uint32_t
1054 1 : TraceLoggerEvent::textId() const
1055 : {
1056 77998 : MOZ_ASSERT(hasTextId());
1057 1 : if (hasExtPayload())
1058 0 : return extPayload()->textId();
1059 1 : return payload_.textId();
1060 : }
1061 :
1062 : TraceLoggerEvent&
1063 0 : TraceLoggerEvent::operator=(const TraceLoggerEvent& other)
1064 : {
1065 0 : if (other.hasExtPayload())
1066 0 : other.extPayload()->use();
1067 0 : if (hasExtPayload())
1068 0 : extPayload()->release();
1069 :
1070 0 : payload_ = other.payload_;
1071 :
1072 0 : return *this;
1073 : }
1074 :
1075 0 : TraceLoggerEvent::TraceLoggerEvent(const TraceLoggerEvent& other)
1076 0 : : payload_(other.payload_)
1077 : {
1078 0 : if (hasExtPayload())
1079 0 : extPayload()->use();
1080 0 : }
|
