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