js/src/vm/TraceLogging.h

branch
TOR_BUG_3246
changeset 7
129ffea94266
equal deleted inserted replaced
-1:000000000000 0:59acd3db0ad4
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 #ifndef TraceLogging_h
8 #define TraceLogging_h
9
10 #include "jsalloc.h"
11 #ifdef JS_THREADSAFE
12 # include "jslock.h"
13 #endif
14
15 #include "mozilla/GuardObjects.h"
16
17 #include "js/HashTable.h"
18 #include "js/TypeDecls.h"
19 #include "js/Vector.h"
20
21 struct JSRuntime;
22
23 namespace JS {
24 class ReadOnlyCompileOptions;
25 }
26
27 namespace js {
28 class PerThreadData;
29
30 namespace jit {
31 class CompileRuntime;
32 }
33
34 /*
35 * Tracelogging overview.
36 *
37 * Tracelogging makes it possible to trace the timestamp of a single event and/or
38 * the duration of an event. This is implemented to give an as low overhead as
39 * possible so it doesn't interfere with running.
40 *
41 * The output of a tracelogging session is saved in /tmp/tl-data.json.
42 * The format of that file is a JS array per tracelogger (=thread), with a map
43 * containing:
44 * - dict: Name of the file containing a json table with the log text.
45 * All other files only contain a index to this table when logging.
46 * - events: Name of the file containing a flat list of log events saved
47 * in binary format.
48 * (64bit: Time Stamp Counter, 32bit index to dict)
49 * - tree: Name of the file containing the events with duration. The content
50 * is already in a tree data structure. This is also saved in a
51 * binary file.
52 * - treeFormat: The format used to encode the tree. By default "64,64,31,1,32".
53 * There are currently no other formats to save the tree.
54 * - 64,64,31,1,31 signifies how many bytes are used for the different
55 * parts of the tree.
56 * => 64 bits: Time Stamp Counter of start of event.
57 * => 64 bits: Time Stamp Counter of end of event.
58 * => 31 bits: Index to dict file containing the log text.
59 * => 1 bit: Boolean signifying if this entry has children.
60 * When true, the child can be found just behind this entry.
61 * => 32 bits: Containing the ID of the next event on the same depth
62 * or 0 if there isn't an event on the same depth anymore.
63 *
64 * /-> The position in the file. Id is this divided by size of entry.
65 * | So in this case this would be 1 (192bits per entry).
66 * | /-> Indicates there are children. The
67 * | | first child is located at current
68 * | | ID + 1. So 1 + 1 in this case: 2.
69 * | | Or 0x00180 in the tree file.
70 * | | /-> Next event on the same depth is
71 * | | | located at 4. So 0x00300 in the
72 * | | | tree file.
73 * 0x0000C0: [start, end, dictId, 1, 4]
74 *
75 *
76 * Example:
77 * 0x0: [start, end, dictId, 1, 0]
78 * |
79 * /----------------------------------\
80 * | |
81 * 0xC0: [start, end, dictId, 0, 2] 0x180 [start, end, dictId, 1, 0]
82 * |
83 * /----------------------------------\
84 * | |
85 * 0x240: [start, end, dictId, 0, 4] 0x300 [start, end, dictId, 0, 0]
86 *
87 *
88 * Logging something is done in 3 stages.
89 * 1) Get the tracelogger of the current thread.
90 * - TraceLoggerForMainThread(JSRuntime *)
91 * - TraceLoggerForCurrentThread(); // Should NOT be used for the mainthread.
92 * 2) Optionally create a textId for the text that needs to get logged. This
93 * step takes some time, so try to do this beforehand, outside the hot
94 * path and don't do unnecessary repetitions, since it will criple
95 * performance.
96 * - TraceLogCreateTextId(logger, ...);
97 *
98 * There are also some text IDs created beforehand. They are located in
99 * Tracelogger::TextId.
100 * 3) Log the timestamp of an event:
101 * - TraceLogTimestamp(logger, textId);
102 *
103 * or the duration:
104 * - TraceLogStartEvent(logger, textId);
105 * - TraceLogStopEvent(logger, textId);
106 *
107 * or the duration with a RAII class:
108 * - AutoTraceLog logger(logger, textId);
109 */
110
111 #define TRACELOGGER_TEXT_ID_LIST(_) \
112 _(Bailout) \
113 _(Baseline) \
114 _(BaselineCompilation) \
115 _(GC) \
116 _(GCAllocation) \
117 _(GCSweeping) \
118 _(Interpreter) \
119 _(Invalidation) \
120 _(IonCompilation) \
121 _(IonLinking) \
122 _(IonMonkey) \
123 _(MinorGC) \
124 _(ParserCompileFunction) \
125 _(ParserCompileLazy) \
126 _(ParserCompileScript) \
127 _(TL) \
128 _(YarrCompile) \
129 _(YarrInterpret) \
130 _(YarrJIT) \
131 _(VM) \
132 \
133 /* Specific passes during ion compilation */ \
134 _(SplitCriticalEdges) \
135 _(RenumberBlocks) \
136 _(DominatorTree) \
137 _(PhiAnalysis) \
138 _(ApplyTypes) \
139 _(ParallelSafetyAnalysis) \
140 _(AliasAnalysis) \
141 _(GVN) \
142 _(UCE) \
143 _(LICM) \
144 _(RangeAnalysis) \
145 _(EffectiveAddressAnalysis) \
146 _(EliminateDeadCode) \
147 _(EdgeCaseAnalysis) \
148 _(EliminateRedundantChecks)
149
150 class AutoTraceLog;
151
152 template <class T>
153 class ContinuousSpace {
154 T *data_;
155 uint32_t next_;
156 uint32_t capacity_;
157
158 public:
159 ContinuousSpace ()
160 : data_(nullptr)
161 { }
162
163 bool init() {
164 capacity_ = 64;
165 next_ = 0;
166 data_ = (T *) js_malloc(capacity_ * sizeof(T));
167 if (!data_)
168 return false;
169
170 return true;
171 }
172
173 T *data() {
174 return data_;
175 }
176
177 uint32_t capacity() {
178 return capacity_;
179 }
180
181 uint32_t size() {
182 return next_;
183 }
184
185 uint32_t nextId() {
186 return next_;
187 }
188
189 T &next() {
190 return data()[next_];
191 }
192
193 uint32_t currentId() {
194 MOZ_ASSERT(next_ > 0);
195 return next_ - 1;
196 }
197
198 T &current() {
199 return data()[currentId()];
200 }
201
202 bool ensureSpaceBeforeAdd(uint32_t count = 1) {
203 if (next_ + count <= capacity_)
204 return true;
205
206 uint32_t nCapacity = capacity_ * 2;
207 if (next_ + count > nCapacity)
208 nCapacity = next_ + count;
209 T *entries = (T *) js_realloc(data_, nCapacity * sizeof(T));
210
211 if (!entries)
212 return false;
213
214 data_ = entries;
215 capacity_ = nCapacity;
216
217 return true;
218 }
219
220 T &operator[](size_t i) {
221 MOZ_ASSERT(i < next_);
222 return data()[i];
223 }
224
225 void push(T &data) {
226 MOZ_ASSERT(next_ < capacity_);
227 data()[next_++] = data;
228 }
229
230 T &pushUninitialized() {
231 MOZ_ASSERT(next_ < capacity_);
232 return data()[next_++];
233 }
234
235 void pop() {
236 MOZ_ASSERT(next_ > 0);
237 next_--;
238 }
239
240 void clear() {
241 next_ = 0;
242 }
243 };
244
245 class TraceLogger
246 {
247 public:
248 // Predefined IDs for common operations. These IDs can be used
249 // without using TraceLogCreateTextId, because there are already created.
250 enum TextId {
251 TL_Error = 0,
252 # define DEFINE_TEXT_ID(textId) textId,
253 TRACELOGGER_TEXT_ID_LIST(DEFINE_TEXT_ID)
254 # undef DEFINE_TEXT_ID
255 LAST
256 };
257
258 #ifdef JS_TRACE_LOGGING
259 private:
260 typedef HashMap<const void *,
261 uint32_t,
262 PointerHasher<const void *, 3>,
263 SystemAllocPolicy> PointerHashMap;
264
265 // The layout of the tree in memory and in the log file. Readable by JS
266 // using TypedArrays.
267 struct TreeEntry {
268 uint64_t start_;
269 uint64_t stop_;
270 union {
271 struct {
272 uint32_t textId_: 31;
273 uint32_t hasChildren_: 1;
274 } s;
275 uint32_t value_;
276 } u;
277 uint32_t nextId_;
278
279 TreeEntry(uint64_t start, uint64_t stop, uint32_t textId, bool hasChildren,
280 uint32_t nextId)
281 {
282 start_ = start;
283 stop_ = stop;
284 u.s.textId_ = textId;
285 u.s.hasChildren_ = hasChildren;
286 nextId_ = nextId;
287 }
288 TreeEntry()
289 { }
290 uint64_t start() {
291 return start_;
292 }
293 uint64_t stop() {
294 return stop_;
295 }
296 uint32_t textId() {
297 return u.s.textId_;
298 }
299 bool hasChildren() {
300 return u.s.hasChildren_;
301 }
302 uint32_t nextId() {
303 return nextId_;
304 }
305 void setStart(uint64_t start) {
306 start_ = start;
307 }
308 void setStop(uint64_t stop) {
309 stop_ = stop;
310 }
311 void setTextId(uint32_t textId) {
312 MOZ_ASSERT(textId < uint32_t(1<<31) );
313 u.s.textId_ = textId;
314 }
315 void setHasChildren(bool hasChildren) {
316 u.s.hasChildren_ = hasChildren;
317 }
318 void setNextId(uint32_t nextId) {
319 nextId_ = nextId;
320 }
321 };
322
323 // Helper structure for keeping track of the current entries in
324 // the tree. Pushed by `start(id)`, popped by `stop(id)`. The active flag
325 // is used to know if a subtree doesn't need to get logged.
326 struct StackEntry {
327 uint32_t treeId_;
328 uint32_t lastChildId_;
329 struct {
330 uint32_t textId_: 31;
331 uint32_t active_: 1;
332 } s;
333 StackEntry(uint32_t treeId, uint32_t lastChildId, bool active = true)
334 : treeId_(treeId), lastChildId_(lastChildId)
335 {
336 s.textId_ = 0;
337 s.active_ = active;
338 }
339 uint32_t treeId() {
340 return treeId_;
341 }
342 uint32_t lastChildId() {
343 return lastChildId_;
344 }
345 uint32_t textId() {
346 return s.textId_;
347 }
348 bool active() {
349 return s.active_;
350 }
351 void setTreeId(uint32_t treeId) {
352 treeId_ = treeId;
353 }
354 void setLastChildId(uint32_t lastChildId) {
355 lastChildId_ = lastChildId;
356 }
357 void setTextId(uint32_t textId) {
358 MOZ_ASSERT(textId < uint32_t(1<<31) );
359 s.textId_ = textId;
360 }
361 void setActive(bool active) {
362 s.active_ = active;
363 }
364 };
365
366 // The layout of the event log in memory and in the log file.
367 // Readable by JS using TypedArrays.
368 struct EventEntry {
369 uint64_t time;
370 uint32_t textId;
371 EventEntry(uint64_t time, uint32_t textId)
372 : time(time), textId(textId)
373 { }
374 };
375
376 FILE *dictFile;
377 FILE *treeFile;
378 FILE *eventFile;
379
380 bool enabled;
381 uint32_t enabledTimes;
382 bool failed;
383 uint32_t nextTextId;
384
385 PointerHashMap pointerMap;
386
387 ContinuousSpace<TreeEntry> tree;
388 ContinuousSpace<StackEntry> stack;
389 ContinuousSpace<EventEntry> events;
390
391 uint32_t treeOffset;
392
393 public:
394 AutoTraceLog *top;
395
396 private:
397 // Helper functions that convert a TreeEntry in different endianness
398 // in place.
399 void entryToBigEndian(TreeEntry *entry);
400 void entryToSystemEndian(TreeEntry *entry);
401
402 // Helper functions to get/save a tree from file.
403 bool getTreeEntry(uint32_t treeId, TreeEntry *entry);
404 bool saveTreeEntry(uint32_t treeId, TreeEntry *entry);
405
406 // Return the first StackEntry that is active.
407 StackEntry &getActiveAncestor();
408
409 // This contains the meat of startEvent, except the test for enough space,
410 // the test if tracelogger is enabled and the timestamp computation.
411 bool startEvent(uint32_t id, uint64_t timestamp);
412
413 // Update functions that can adjust the items in the tree,
414 // both in memory or already written to disk.
415 bool updateHasChildren(uint32_t treeId, bool hasChildren = true);
416 bool updateNextId(uint32_t treeId, uint32_t nextId);
417 bool updateStop(uint32_t treeId, uint64_t timestamp);
418
419 // Flush the tree and events.
420 bool flush();
421
422 public:
423 TraceLogger();
424 ~TraceLogger();
425
426 bool init(uint32_t loggerId);
427
428 bool enable();
429 bool disable();
430
431 // The createTextId functions map a unique input to a logger ID.
432 // This ID can be used to log something. Calls to these functions should be
433 // limited if possible, because of the overhead.
434 uint32_t createTextId(const char *text);
435 uint32_t createTextId(JSScript *script);
436 uint32_t createTextId(const JS::ReadOnlyCompileOptions &script);
437
438 // Log an event (no start/stop, only the timestamp is recorded).
439 void logTimestamp(uint32_t id);
440
441 // Record timestamps for start and stop of an event.
442 // In the stop method, the ID is only used in debug builds to test
443 // correctness.
444 void startEvent(uint32_t id);
445 void stopEvent(uint32_t id);
446 void stopEvent();
447
448 private:
449 void assertNoQuotes(const char *text) {
450 #ifdef DEBUG
451 const char *quote = strchr(text, '"');
452 MOZ_ASSERT(!quote);
453 #endif
454 }
455 #endif
456 };
457
458 class TraceLogging
459 {
460 #ifdef JS_TRACE_LOGGING
461 #ifdef JS_THREADSAFE
462 typedef HashMap<PRThread *,
463 TraceLogger *,
464 PointerHasher<PRThread *, 3>,
465 SystemAllocPolicy> ThreadLoggerHashMap;
466 #endif // JS_THREADSAFE
467 typedef Vector<TraceLogger *, 1, js::SystemAllocPolicy > MainThreadLoggers;
468
469 bool initialized;
470 bool enabled;
471 bool enabledTextIds[TraceLogger::LAST];
472 bool mainThreadEnabled;
473 bool offThreadEnabled;
474 #ifdef JS_THREADSAFE
475 ThreadLoggerHashMap threadLoggers;
476 #endif // JS_THREADSAFE
477 MainThreadLoggers mainThreadLoggers;
478 uint32_t loggerId;
479 FILE *out;
480
481 public:
482 uint64_t startupTime;
483 #ifdef JS_THREADSAFE
484 PRLock *lock;
485 #endif // JS_THREADSAFE
486
487 TraceLogging();
488 ~TraceLogging();
489
490 TraceLogger *forMainThread(JSRuntime *runtime);
491 TraceLogger *forMainThread(jit::CompileRuntime *runtime);
492 #ifdef JS_THREADSAFE
493 TraceLogger *forThread(PRThread *thread);
494 #endif // JS_THREADSAFE
495
496 bool isTextIdEnabled(uint32_t textId) {
497 if (textId < TraceLogger::LAST)
498 return enabledTextIds[textId];
499 return true;
500 }
501
502 private:
503 TraceLogger *forMainThread(PerThreadData *mainThread);
504 TraceLogger *create();
505 bool lazyInit();
506 #endif
507 };
508
509 #ifdef JS_TRACE_LOGGING
510 TraceLogger *TraceLoggerForMainThread(JSRuntime *runtime);
511 TraceLogger *TraceLoggerForMainThread(jit::CompileRuntime *runtime);
512 TraceLogger *TraceLoggerForCurrentThread();
513 #else
514 inline TraceLogger *TraceLoggerForMainThread(JSRuntime *runtime) {
515 return nullptr;
516 };
517 inline TraceLogger *TraceLoggerForMainThread(jit::CompileRuntime *runtime) {
518 return nullptr;
519 };
520 inline TraceLogger *TraceLoggerForCurrentThread() {
521 return nullptr;
522 };
523 #endif
524
525 inline bool TraceLoggerEnable(TraceLogger *logger) {
526 #ifdef JS_TRACE_LOGGING
527 if (logger)
528 return logger->enable();
529 #endif
530 return false;
531 }
532 inline bool TraceLoggerDisable(TraceLogger *logger) {
533 #ifdef JS_TRACE_LOGGING
534 if (logger)
535 return logger->disable();
536 #endif
537 return false;
538 }
539
540 inline uint32_t TraceLogCreateTextId(TraceLogger *logger, JSScript *script) {
541 #ifdef JS_TRACE_LOGGING
542 if (logger)
543 return logger->createTextId(script);
544 #endif
545 return TraceLogger::TL_Error;
546 }
547 inline uint32_t TraceLogCreateTextId(TraceLogger *logger,
548 const JS::ReadOnlyCompileOptions &compileOptions)
549 {
550 #ifdef JS_TRACE_LOGGING
551 if (logger)
552 return logger->createTextId(compileOptions);
553 #endif
554 return TraceLogger::TL_Error;
555 }
556 inline uint32_t TraceLogCreateTextId(TraceLogger *logger, const char *text) {
557 #ifdef JS_TRACE_LOGGING
558 if (logger)
559 return logger->createTextId(text);
560 #endif
561 return TraceLogger::TL_Error;
562 }
563 #ifdef JS_TRACE_LOGGING
564 bool TraceLogTextIdEnabled(uint32_t textId);
565 #else
566 inline bool TraceLogTextIdEnabled(uint32_t textId) {
567 return false;
568 }
569 #endif
570 inline void TraceLogTimestamp(TraceLogger *logger, uint32_t textId) {
571 #ifdef JS_TRACE_LOGGING
572 if (logger)
573 logger->logTimestamp(textId);
574 #endif
575 }
576 inline void TraceLogStartEvent(TraceLogger *logger, uint32_t textId) {
577 #ifdef JS_TRACE_LOGGING
578 if (logger)
579 logger->startEvent(textId);
580 #endif
581 }
582 inline void TraceLogStopEvent(TraceLogger *logger, uint32_t textId) {
583 #ifdef JS_TRACE_LOGGING
584 if (logger)
585 logger->stopEvent(textId);
586 #endif
587 }
588 inline void TraceLogStopEvent(TraceLogger *logger) {
589 #ifdef JS_TRACE_LOGGING
590 if (logger)
591 logger->stopEvent();
592 #endif
593 }
594
595 // Automatic logging at the start and end of function call.
596 class AutoTraceLog {
597 #ifdef JS_TRACE_LOGGING
598 TraceLogger *logger;
599 uint32_t textId;
600 bool executed;
601 AutoTraceLog *prev;
602
603 public:
604 AutoTraceLog(TraceLogger *logger, uint32_t textId MOZ_GUARD_OBJECT_NOTIFIER_PARAM)
605 : logger(logger),
606 textId(textId),
607 executed(false)
608 {
609 MOZ_GUARD_OBJECT_NOTIFIER_INIT;
610 if (logger) {
611 TraceLogStartEvent(logger, textId);
612
613 prev = logger->top;
614 logger->top = this;
615 }
616 }
617
618 ~AutoTraceLog()
619 {
620 if (logger) {
621 while (this != logger->top)
622 logger->top->stop();
623 stop();
624 }
625 }
626 private:
627 void stop() {
628 if (!executed) {
629 executed = true;
630 TraceLogStopEvent(logger, textId);
631 }
632
633 if (logger->top == this)
634 logger->top = prev;
635 }
636 #else
637 public:
638 AutoTraceLog(TraceLogger *logger, uint32_t textId MOZ_GUARD_OBJECT_NOTIFIER_PARAM)
639 {
640 MOZ_GUARD_OBJECT_NOTIFIER_INIT;
641 }
642 #endif
643
644 private:
645 MOZ_DECL_USE_GUARD_OBJECT_NOTIFIER
646 };
647
648 #ifdef JS_TRACE_LOGGING
649 class AutoTraceLoggingLock
650 {
651 TraceLogging *logging;
652
653 public:
654 AutoTraceLoggingLock(TraceLogging *logging MOZ_GUARD_OBJECT_NOTIFIER_PARAM)
655 : logging(logging)
656 {
657 MOZ_GUARD_OBJECT_NOTIFIER_INIT;
658 #ifdef JS_THREADSAFE
659 PR_Lock(logging->lock);
660 #endif // JS_THREADSAFE
661 }
662 ~AutoTraceLoggingLock() {
663 #ifdef JS_THREADSAFE
664 PR_Unlock(logging->lock);
665 #endif // JS_THREADSAFE
666 }
667 private:
668 MOZ_DECL_USE_GUARD_OBJECT_NOTIFIER
669 };
670 #endif
671
672 } /* namedata js */
673
674 #endif /* TraceLogging_h */

mercurial