js/src/vm/TraceLogging.cpp

Sat, 03 Jan 2015 20:18:00 +0100

author
Michael Schloh von Bennewitz <michael@schloh.com>
date
Sat, 03 Jan 2015 20:18:00 +0100
branch
TOR_BUG_3246
changeset 7
129ffea94266
permissions
-rw-r--r--

Conditionally enable double key logic according to:
private browsing mode or privacy.thirdparty.isolate preference and
implement in GetCookieStringCommon and FindCookie where it counts...
With some reservations of how to convince FindCookie users to test
condition and pass a nullptr when disabling double key logic.

michael@0 1 /* -*- Mode: C++; tab-width: 8; indent-tabs-mode: nil; c-basic-offset: 4 -*-
michael@0 2 * vim: set ts=8 sts=4 et sw=4 tw=99:
michael@0 3 * This Source Code Form is subject to the terms of the Mozilla Public
michael@0 4 * License, v. 2.0. If a copy of the MPL was not distributed with this
michael@0 5 * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
michael@0 6
michael@0 7 #include "vm/TraceLogging.h"
michael@0 8
michael@0 9 #include "mozilla/DebugOnly.h"
michael@0 10
michael@0 11 #include <string.h>
michael@0 12
michael@0 13 #include "jsapi.h"
michael@0 14 #include "jsscript.h"
michael@0 15
michael@0 16 #include "jit/CompileWrappers.h"
michael@0 17 #include "vm/Runtime.h"
michael@0 18
michael@0 19 using namespace js;
michael@0 20
michael@0 21 #ifndef TRACE_LOG_DIR
michael@0 22 # if defined(_WIN32)
michael@0 23 # define TRACE_LOG_DIR ""
michael@0 24 # else
michael@0 25 # define TRACE_LOG_DIR "/tmp/"
michael@0 26 # endif
michael@0 27 #endif
michael@0 28
michael@0 29 #if defined(__i386__)
michael@0 30 static __inline__ uint64_t
michael@0 31 rdtsc(void)
michael@0 32 {
michael@0 33 uint64_t x;
michael@0 34 __asm__ volatile (".byte 0x0f, 0x31" : "=A" (x));
michael@0 35 return x;
michael@0 36 }
michael@0 37 #elif defined(__x86_64__)
michael@0 38 static __inline__ uint64_t
michael@0 39 rdtsc(void)
michael@0 40 {
michael@0 41 unsigned hi, lo;
michael@0 42 __asm__ __volatile__ ("rdtsc" : "=a"(lo), "=d"(hi));
michael@0 43 return ( (uint64_t)lo)|( ((uint64_t)hi)<<32 );
michael@0 44 }
michael@0 45 #elif defined(__powerpc__)
michael@0 46 static __inline__ uint64_t
michael@0 47 rdtsc(void)
michael@0 48 {
michael@0 49 uint64_t result=0;
michael@0 50 uint32_t upper, lower,tmp;
michael@0 51 __asm__ volatile(
michael@0 52 "0: \n"
michael@0 53 "\tmftbu %0 \n"
michael@0 54 "\tmftb %1 \n"
michael@0 55 "\tmftbu %2 \n"
michael@0 56 "\tcmpw %2,%0 \n"
michael@0 57 "\tbne 0b \n"
michael@0 58 : "=r"(upper),"=r"(lower),"=r"(tmp)
michael@0 59 );
michael@0 60 result = upper;
michael@0 61 result = result<<32;
michael@0 62 result = result|lower;
michael@0 63
michael@0 64 return result;
michael@0 65 }
michael@0 66 #endif
michael@0 67
michael@0 68 TraceLogging traceLoggers;
michael@0 69
michael@0 70 static const char* const text[] =
michael@0 71 {
michael@0 72 "TraceLogger failed to process text",
michael@0 73 #define NAME(x) #x,
michael@0 74 TRACELOGGER_TEXT_ID_LIST(NAME)
michael@0 75 #undef NAME
michael@0 76 };
michael@0 77
michael@0 78 TraceLogger::TraceLogger()
michael@0 79 : enabled(false),
michael@0 80 enabledTimes(0),
michael@0 81 failed(false),
michael@0 82 nextTextId(0),
michael@0 83 treeOffset(0),
michael@0 84 top(nullptr)
michael@0 85 { }
michael@0 86
michael@0 87 bool
michael@0 88 TraceLogger::init(uint32_t loggerId)
michael@0 89 {
michael@0 90 if (!pointerMap.init())
michael@0 91 return false;
michael@0 92 if (!tree.init())
michael@0 93 return false;
michael@0 94 if (!stack.init())
michael@0 95 return false;
michael@0 96 if (!events.init())
michael@0 97 return false;
michael@0 98
michael@0 99 MOZ_ASSERT(loggerId <= 999);
michael@0 100
michael@0 101 char dictFilename[sizeof TRACE_LOG_DIR "tl-dict.100.json"];
michael@0 102 sprintf(dictFilename, TRACE_LOG_DIR "tl-dict.%d.json", loggerId);
michael@0 103 dictFile = fopen(dictFilename, "w");
michael@0 104 if (!dictFile)
michael@0 105 return false;
michael@0 106
michael@0 107 char treeFilename[sizeof TRACE_LOG_DIR "tl-tree.100.tl"];
michael@0 108 sprintf(treeFilename, TRACE_LOG_DIR "tl-tree.%d.tl", loggerId);
michael@0 109 treeFile = fopen(treeFilename, "wb");
michael@0 110 if (!treeFile) {
michael@0 111 fclose(dictFile);
michael@0 112 dictFile = nullptr;
michael@0 113 return false;
michael@0 114 }
michael@0 115
michael@0 116 char eventFilename[sizeof TRACE_LOG_DIR "tl-event.100.tl"];
michael@0 117 sprintf(eventFilename, TRACE_LOG_DIR "tl-event.%d.tl", loggerId);
michael@0 118 eventFile = fopen(eventFilename, "wb");
michael@0 119 if (!eventFile) {
michael@0 120 fclose(dictFile);
michael@0 121 fclose(treeFile);
michael@0 122 dictFile = nullptr;
michael@0 123 treeFile = nullptr;
michael@0 124 return false;
michael@0 125 }
michael@0 126
michael@0 127 uint64_t start = rdtsc() - traceLoggers.startupTime;
michael@0 128
michael@0 129 TreeEntry &treeEntry = tree.pushUninitialized();
michael@0 130 treeEntry.setStart(start);
michael@0 131 treeEntry.setStop(0);
michael@0 132 treeEntry.setTextId(0);
michael@0 133 treeEntry.setHasChildren(false);
michael@0 134 treeEntry.setNextId(0);
michael@0 135
michael@0 136 StackEntry &stackEntry = stack.pushUninitialized();
michael@0 137 stackEntry.setTreeId(0);
michael@0 138 stackEntry.setLastChildId(0);
michael@0 139 stackEntry.setActive(true);
michael@0 140
michael@0 141 int written = fprintf(dictFile, "[");
michael@0 142 if (written < 0)
michael@0 143 fprintf(stderr, "TraceLogging: Error while writing.\n");
michael@0 144
michael@0 145 // Eagerly create the default textIds, to match their Tracelogger::TextId.
michael@0 146 for (uint32_t i = 0; i < LAST; i++) {
michael@0 147 mozilla::DebugOnly<uint32_t> textId = createTextId(text[i]);
michael@0 148 MOZ_ASSERT(textId == i);
michael@0 149 }
michael@0 150
michael@0 151 enabled = true;
michael@0 152 enabledTimes = 1;
michael@0 153 return true;
michael@0 154 }
michael@0 155
michael@0 156 bool
michael@0 157 TraceLogger::enable()
michael@0 158 {
michael@0 159 if (enabled) {
michael@0 160 enabledTimes++;
michael@0 161 return true;
michael@0 162 }
michael@0 163
michael@0 164 if (failed)
michael@0 165 return false;
michael@0 166
michael@0 167 if (!tree.ensureSpaceBeforeAdd(stack.size())) {
michael@0 168 if (!flush()) {
michael@0 169 fprintf(stderr, "TraceLogging: Couldn't write the data to disk.\n");
michael@0 170 failed = true;
michael@0 171 return false;
michael@0 172 }
michael@0 173 if (!tree.ensureSpaceBeforeAdd(stack.size())) {
michael@0 174 fprintf(stderr, "TraceLogging: Couldn't reserve enough space.\n");
michael@0 175 failed = true;
michael@0 176 return false;
michael@0 177 }
michael@0 178 }
michael@0 179
michael@0 180 uint64_t start = rdtsc() - traceLoggers.startupTime;
michael@0 181 StackEntry *parent = &stack[0];
michael@0 182 for (uint32_t i = 1; i < stack.size(); i++) {
michael@0 183 if (!traceLoggers.isTextIdEnabled(stack[i].textId()))
michael@0 184 continue;
michael@0 185 #ifdef DEBUG
michael@0 186 TreeEntry entry;
michael@0 187 if (!getTreeEntry(parent->treeId(), &entry))
michael@0 188 return false;
michael@0 189 #endif
michael@0 190
michael@0 191 if (parent->lastChildId() == 0) {
michael@0 192 MOZ_ASSERT(!entry.hasChildren());
michael@0 193 MOZ_ASSERT(parent->treeId() == tree.currentId() + treeOffset);
michael@0 194 if (!updateHasChildren(parent->treeId())) {
michael@0 195 fprintf(stderr, "TraceLogging: Couldn't update an entry.\n");
michael@0 196 failed = true;
michael@0 197 return false;
michael@0 198 }
michael@0 199 } else {
michael@0 200 MOZ_ASSERT(entry.hasChildren() == 1);
michael@0 201 if (!updateNextId(parent->lastChildId(), tree.nextId() + treeOffset)) {
michael@0 202 fprintf(stderr, "TraceLogging: Couldn't update an entry.\n");
michael@0 203 failed = true;
michael@0 204 return false;
michael@0 205 }
michael@0 206 }
michael@0 207
michael@0 208 TreeEntry &treeEntry = tree.pushUninitialized();
michael@0 209 treeEntry.setStart(start);
michael@0 210 treeEntry.setStop(0);
michael@0 211 treeEntry.setTextId(stack[i].textId());
michael@0 212 treeEntry.setHasChildren(false);
michael@0 213 treeEntry.setNextId(0);
michael@0 214
michael@0 215 stack[i].setActive(true);
michael@0 216 stack[i].setTreeId(tree.currentId() + treeOffset);
michael@0 217
michael@0 218 parent->setLastChildId(tree.currentId() + treeOffset);
michael@0 219
michael@0 220 parent = &stack[i];
michael@0 221 }
michael@0 222
michael@0 223 enabled = true;
michael@0 224 enabledTimes = 1;
michael@0 225
michael@0 226 return true;
michael@0 227 }
michael@0 228
michael@0 229 bool
michael@0 230 TraceLogger::disable()
michael@0 231 {
michael@0 232 if (failed)
michael@0 233 return false;
michael@0 234
michael@0 235 if (!enabled)
michael@0 236 return true;
michael@0 237
michael@0 238 if (enabledTimes > 1) {
michael@0 239 enabledTimes--;
michael@0 240 return true;
michael@0 241 }
michael@0 242
michael@0 243 uint64_t stop = rdtsc() - traceLoggers.startupTime;
michael@0 244 for (uint32_t i = 1; i < stack.size(); i++) {
michael@0 245 if (!stack[i].active())
michael@0 246 continue;
michael@0 247
michael@0 248 if (!updateStop(stack[i].treeId(), stop)) {
michael@0 249 fprintf(stderr, "TraceLogging: Failed to stop an event.\n");
michael@0 250 failed = true;
michael@0 251 enabled = false;
michael@0 252 return false;
michael@0 253 }
michael@0 254
michael@0 255 stack[i].setActive(false);
michael@0 256 }
michael@0 257
michael@0 258
michael@0 259 enabled = false;
michael@0 260 enabledTimes = 0;
michael@0 261
michael@0 262 return true;
michael@0 263 }
michael@0 264
michael@0 265 bool
michael@0 266 TraceLogger::flush()
michael@0 267 {
michael@0 268 MOZ_ASSERT(!failed);
michael@0 269
michael@0 270 if (treeFile) {
michael@0 271 // Format data in big endian.
michael@0 272 for (size_t i = 0; i < tree.size(); i++)
michael@0 273 entryToBigEndian(&tree[i]);
michael@0 274
michael@0 275 int success = fseek(treeFile, 0, SEEK_END);
michael@0 276 if (success != 0)
michael@0 277 return false;
michael@0 278
michael@0 279 size_t bytesWritten = fwrite(tree.data(), sizeof(TreeEntry), tree.size(), treeFile);
michael@0 280 if (bytesWritten < tree.size())
michael@0 281 return false;
michael@0 282
michael@0 283 treeOffset += tree.currentId();
michael@0 284 tree.clear();
michael@0 285 }
michael@0 286
michael@0 287 if (eventFile) {
michael@0 288 // Format data in big endian
michael@0 289 for (size_t i = 0; i < events.size(); i++) {
michael@0 290 events[i].time = htobe64(events[i].time);
michael@0 291 events[i].textId = htobe64(events[i].textId);
michael@0 292 }
michael@0 293
michael@0 294 size_t bytesWritten = fwrite(events.data(), sizeof(EventEntry), events.size(), eventFile);
michael@0 295 if (bytesWritten < events.size())
michael@0 296 return false;
michael@0 297 events.clear();
michael@0 298 }
michael@0 299
michael@0 300 return true;
michael@0 301 }
michael@0 302
michael@0 303 TraceLogger::~TraceLogger()
michael@0 304 {
michael@0 305 // Write dictionary to disk
michael@0 306 if (dictFile) {
michael@0 307 int written = fprintf(dictFile, "]");
michael@0 308 if (written < 0)
michael@0 309 fprintf(stderr, "TraceLogging: Error while writing.\n");
michael@0 310 fclose(dictFile);
michael@0 311
michael@0 312 dictFile = nullptr;
michael@0 313 }
michael@0 314
michael@0 315 if (!failed && treeFile) {
michael@0 316 // Make sure every start entry has a corresponding stop value.
michael@0 317 // We temporary enable logging for this. Stop doesn't need any extra data,
michael@0 318 // so is safe to do, even when we encountered OOM.
michael@0 319 enabled = true;
michael@0 320 while (stack.size() > 0)
michael@0 321 stopEvent();
michael@0 322 enabled = false;
michael@0 323 }
michael@0 324
michael@0 325 if (!failed && !flush()) {
michael@0 326 fprintf(stderr, "TraceLogging: Couldn't write the data to disk.\n");
michael@0 327 enabled = false;
michael@0 328 failed = true;
michael@0 329 }
michael@0 330
michael@0 331 if (treeFile) {
michael@0 332 fclose(treeFile);
michael@0 333 treeFile = nullptr;
michael@0 334 }
michael@0 335
michael@0 336 if (eventFile) {
michael@0 337 fclose(eventFile);
michael@0 338 eventFile = nullptr;
michael@0 339 }
michael@0 340 }
michael@0 341
michael@0 342 uint32_t
michael@0 343 TraceLogger::createTextId(const char *text)
michael@0 344 {
michael@0 345 assertNoQuotes(text);
michael@0 346
michael@0 347 PointerHashMap::AddPtr p = pointerMap.lookupForAdd((const void *)text);
michael@0 348 if (p)
michael@0 349 return p->value();
michael@0 350
michael@0 351 uint32_t textId = nextTextId++;
michael@0 352 if (!pointerMap.add(p, text, textId))
michael@0 353 return TraceLogger::TL_Error;
michael@0 354
michael@0 355 int written;
michael@0 356 if (textId > 0)
michael@0 357 written = fprintf(dictFile, ",\n\"%s\"", text);
michael@0 358 else
michael@0 359 written = fprintf(dictFile, "\"%s\"", text);
michael@0 360
michael@0 361 if (written < 0)
michael@0 362 return TraceLogger::TL_Error;
michael@0 363
michael@0 364 return textId;
michael@0 365 }
michael@0 366
michael@0 367 uint32_t
michael@0 368 TraceLogger::createTextId(JSScript *script)
michael@0 369 {
michael@0 370 assertNoQuotes(script->filename());
michael@0 371
michael@0 372 PointerHashMap::AddPtr p = pointerMap.lookupForAdd(script);
michael@0 373 if (p)
michael@0 374 return p->value();
michael@0 375
michael@0 376 uint32_t textId = nextTextId++;
michael@0 377 if (!pointerMap.add(p, script, textId))
michael@0 378 return TraceLogger::TL_Error;
michael@0 379
michael@0 380 int written;
michael@0 381 if (textId > 0) {
michael@0 382 written = fprintf(dictFile, ",\n\"script %s:%d:%d\"", script->filename(),
michael@0 383 script->lineno(), script->column());
michael@0 384 } else {
michael@0 385 written = fprintf(dictFile, "\"script %s:%d:%d\"", script->filename(),
michael@0 386 script->lineno(), script->column());
michael@0 387 }
michael@0 388
michael@0 389 if (written < 0)
michael@0 390 return TraceLogger::TL_Error;
michael@0 391
michael@0 392 return textId;
michael@0 393 }
michael@0 394
michael@0 395 uint32_t
michael@0 396 TraceLogger::createTextId(const JS::ReadOnlyCompileOptions &compileOptions)
michael@0 397 {
michael@0 398 assertNoQuotes(compileOptions.filename());
michael@0 399
michael@0 400 PointerHashMap::AddPtr p = pointerMap.lookupForAdd(&compileOptions);
michael@0 401 if (p)
michael@0 402 return p->value();
michael@0 403
michael@0 404 uint32_t textId = nextTextId++;
michael@0 405 if (!pointerMap.add(p, &compileOptions, textId))
michael@0 406 return TraceLogger::TL_Error;
michael@0 407
michael@0 408 int written;
michael@0 409 if (textId > 0) {
michael@0 410 written = fprintf(dictFile, ",\n\"script %s:%d:%d\"", compileOptions.filename(),
michael@0 411 compileOptions.lineno, compileOptions.column);
michael@0 412 } else {
michael@0 413 written = fprintf(dictFile, "\"script %s:%d:%d\"", compileOptions.filename(),
michael@0 414 compileOptions.lineno, compileOptions.column);
michael@0 415 }
michael@0 416
michael@0 417 if (written < 0)
michael@0 418 return TraceLogger::TL_Error;
michael@0 419
michael@0 420 return textId;
michael@0 421 }
michael@0 422
michael@0 423 void
michael@0 424 TraceLogger::logTimestamp(uint32_t id)
michael@0 425 {
michael@0 426 if (!enabled)
michael@0 427 return;
michael@0 428
michael@0 429 if (!events.ensureSpaceBeforeAdd()) {
michael@0 430 fprintf(stderr, "TraceLogging: Disabled a tracelogger due to OOM.\n");
michael@0 431 enabled = false;
michael@0 432 return;
michael@0 433 }
michael@0 434
michael@0 435 uint64_t time = rdtsc() - traceLoggers.startupTime;
michael@0 436
michael@0 437 EventEntry &entry = events.pushUninitialized();
michael@0 438 entry.time = time;
michael@0 439 entry.textId = id;
michael@0 440 }
michael@0 441
michael@0 442 void
michael@0 443 TraceLogger::entryToBigEndian(TreeEntry *entry)
michael@0 444 {
michael@0 445 entry->start_ = htobe64(entry->start_);
michael@0 446 entry->stop_ = htobe64(entry->stop_);
michael@0 447 entry->u.value_ = htobe32((entry->u.s.textId_ << 1) + entry->u.s.hasChildren_);
michael@0 448 entry->nextId_ = htobe32(entry->nextId_);
michael@0 449 }
michael@0 450
michael@0 451 void
michael@0 452 TraceLogger::entryToSystemEndian(TreeEntry *entry)
michael@0 453 {
michael@0 454 entry->start_ = be64toh(entry->start_);
michael@0 455 entry->stop_ = be64toh(entry->stop_);
michael@0 456
michael@0 457 uint32_t data = be32toh(entry->u.value_);
michael@0 458 entry->u.s.textId_ = data >> 1;
michael@0 459 entry->u.s.hasChildren_ = data & 0x1;
michael@0 460
michael@0 461 entry->nextId_ = be32toh(entry->nextId_);
michael@0 462 }
michael@0 463
michael@0 464 bool
michael@0 465 TraceLogger::getTreeEntry(uint32_t treeId, TreeEntry *entry)
michael@0 466 {
michael@0 467 // Entry is still in memory
michael@0 468 if (treeId >= treeOffset) {
michael@0 469 *entry = tree[treeId];
michael@0 470 return true;
michael@0 471 }
michael@0 472
michael@0 473 int success = fseek(treeFile, treeId * sizeof(TreeEntry), SEEK_SET);
michael@0 474 if (success != 0)
michael@0 475 return false;
michael@0 476
michael@0 477 size_t itemsRead = fread((void *)entry, sizeof(TreeEntry), 1, treeFile);
michael@0 478 if (itemsRead < 1)
michael@0 479 return false;
michael@0 480
michael@0 481 entryToSystemEndian(entry);
michael@0 482 return true;
michael@0 483 }
michael@0 484
michael@0 485 bool
michael@0 486 TraceLogger::saveTreeEntry(uint32_t treeId, TreeEntry *entry)
michael@0 487 {
michael@0 488 int success = fseek(treeFile, treeId * sizeof(TreeEntry), SEEK_SET);
michael@0 489 if (success != 0)
michael@0 490 return false;
michael@0 491
michael@0 492 entryToBigEndian(entry);
michael@0 493
michael@0 494 size_t itemsWritten = fwrite(entry, sizeof(TreeEntry), 1, treeFile);
michael@0 495 if (itemsWritten < 1)
michael@0 496 return false;
michael@0 497
michael@0 498 return true;
michael@0 499 }
michael@0 500
michael@0 501 bool
michael@0 502 TraceLogger::updateHasChildren(uint32_t treeId, bool hasChildren)
michael@0 503 {
michael@0 504 if (treeId < treeOffset) {
michael@0 505 TreeEntry entry;
michael@0 506 if (!getTreeEntry(treeId, &entry))
michael@0 507 return false;
michael@0 508 entry.setHasChildren(hasChildren);
michael@0 509 if (!saveTreeEntry(treeId, &entry))
michael@0 510 return false;
michael@0 511 return true;
michael@0 512 }
michael@0 513
michael@0 514 tree[treeId - treeOffset].setHasChildren(hasChildren);
michael@0 515 return true;
michael@0 516 }
michael@0 517
michael@0 518 bool
michael@0 519 TraceLogger::updateNextId(uint32_t treeId, uint32_t nextId)
michael@0 520 {
michael@0 521 if (treeId < treeOffset) {
michael@0 522 TreeEntry entry;
michael@0 523 if (!getTreeEntry(treeId, &entry))
michael@0 524 return false;
michael@0 525 entry.setNextId(nextId);
michael@0 526 if (!saveTreeEntry(treeId, &entry))
michael@0 527 return false;
michael@0 528 return true;
michael@0 529 }
michael@0 530
michael@0 531 tree[treeId - treeOffset].setNextId(nextId);
michael@0 532 return true;
michael@0 533 }
michael@0 534
michael@0 535 bool
michael@0 536 TraceLogger::updateStop(uint32_t treeId, uint64_t timestamp)
michael@0 537 {
michael@0 538 if (treeId < treeOffset) {
michael@0 539 TreeEntry entry;
michael@0 540 if (!getTreeEntry(treeId, &entry))
michael@0 541 return false;
michael@0 542 entry.setStop(timestamp);
michael@0 543 if (!saveTreeEntry(treeId, &entry))
michael@0 544 return false;
michael@0 545 return true;
michael@0 546 }
michael@0 547
michael@0 548 tree[treeId - treeOffset].setStop(timestamp);
michael@0 549 return true;
michael@0 550 }
michael@0 551
michael@0 552 void
michael@0 553 TraceLogger::startEvent(uint32_t id)
michael@0 554 {
michael@0 555 if (failed)
michael@0 556 return;
michael@0 557
michael@0 558 if (!stack.ensureSpaceBeforeAdd()) {
michael@0 559 fprintf(stderr, "TraceLogging: Failed to allocate space to keep track of the stack.\n");
michael@0 560 enabled = false;
michael@0 561 failed = true;
michael@0 562 return;
michael@0 563 }
michael@0 564
michael@0 565 if (!enabled) {
michael@0 566 StackEntry &stackEntry = stack.pushUninitialized();
michael@0 567 stackEntry.setTreeId(tree.currentId() + treeOffset);
michael@0 568 stackEntry.setLastChildId(0);
michael@0 569 stackEntry.setTextId(id);
michael@0 570 stackEntry.setActive(false);
michael@0 571 return;
michael@0 572 }
michael@0 573
michael@0 574 if (!tree.ensureSpaceBeforeAdd()) {
michael@0 575 uint64_t start = rdtsc() - traceLoggers.startupTime;
michael@0 576 if (!flush()) {
michael@0 577 fprintf(stderr, "TraceLogging: Couldn't write the data to disk.\n");
michael@0 578 enabled = false;
michael@0 579 failed = true;
michael@0 580 return;
michael@0 581 }
michael@0 582
michael@0 583 // Log the time it took to flush the events as being from the
michael@0 584 // Tracelogger.
michael@0 585 if (!startEvent(TraceLogger::TL, start)) {
michael@0 586 fprintf(stderr, "TraceLogging: Failed to start an event.\n");
michael@0 587 enabled = false;
michael@0 588 failed = true;
michael@0 589 return;
michael@0 590 }
michael@0 591 stopEvent();
michael@0 592 }
michael@0 593
michael@0 594 uint64_t start = rdtsc() - traceLoggers.startupTime;
michael@0 595 if (!startEvent(id, start)) {
michael@0 596 fprintf(stderr, "TraceLogging: Failed to start an event.\n");
michael@0 597 enabled = false;
michael@0 598 failed = true;
michael@0 599 return;
michael@0 600 }
michael@0 601 }
michael@0 602
michael@0 603 TraceLogger::StackEntry &
michael@0 604 TraceLogger::getActiveAncestor()
michael@0 605 {
michael@0 606 uint32_t parentId = stack.currentId();
michael@0 607 while (!stack[parentId].active())
michael@0 608 parentId--;
michael@0 609 return stack[parentId];
michael@0 610 }
michael@0 611
michael@0 612 bool
michael@0 613 TraceLogger::startEvent(uint32_t id, uint64_t timestamp)
michael@0 614 {
michael@0 615 // When a textId is disabled, a stack entry still needs to be pushed,
michael@0 616 // together with an annotation that nothing needs to get done when receiving
michael@0 617 // the stop event.
michael@0 618 if (!traceLoggers.isTextIdEnabled(id)) {
michael@0 619 StackEntry &stackEntry = stack.pushUninitialized();
michael@0 620 stackEntry.setActive(false);
michael@0 621 return true;
michael@0 622 }
michael@0 623
michael@0 624 // Patch up the tree to be correct. There are two scenarios:
michael@0 625 // 1) Parent has no children yet. So update parent to include children.
michael@0 626 // 2) Parent has already children. Update last child to link to the new
michael@0 627 // child.
michael@0 628 StackEntry &parent = getActiveAncestor();
michael@0 629 #ifdef DEBUG
michael@0 630 TreeEntry entry;
michael@0 631 if (!getTreeEntry(parent.treeId(), &entry))
michael@0 632 return false;
michael@0 633 #endif
michael@0 634
michael@0 635 if (parent.lastChildId() == 0) {
michael@0 636 MOZ_ASSERT(!entry.hasChildren());
michael@0 637 MOZ_ASSERT(parent.treeId() == tree.currentId() + treeOffset);
michael@0 638
michael@0 639 if (!updateHasChildren(parent.treeId()))
michael@0 640 return false;
michael@0 641 } else {
michael@0 642 MOZ_ASSERT(entry.hasChildren());
michael@0 643
michael@0 644 if (!updateNextId(parent.lastChildId(), tree.nextId() + treeOffset))
michael@0 645 return false;
michael@0 646 }
michael@0 647
michael@0 648 // Add a new tree entry.
michael@0 649 TreeEntry &treeEntry = tree.pushUninitialized();
michael@0 650 treeEntry.setStart(timestamp);
michael@0 651 treeEntry.setStop(0);
michael@0 652 treeEntry.setTextId(id);
michael@0 653 treeEntry.setHasChildren(false);
michael@0 654 treeEntry.setNextId(0);
michael@0 655
michael@0 656 // Add a new stack entry.
michael@0 657 StackEntry &stackEntry = stack.pushUninitialized();
michael@0 658 stackEntry.setTreeId(tree.currentId() + treeOffset);
michael@0 659 stackEntry.setLastChildId(0);
michael@0 660 stackEntry.setActive(true);
michael@0 661
michael@0 662 // Set the last child of the parent to this newly added entry.
michael@0 663 parent.setLastChildId(tree.currentId() + treeOffset);
michael@0 664
michael@0 665 return true;
michael@0 666 }
michael@0 667
michael@0 668 void
michael@0 669 TraceLogger::stopEvent(uint32_t id)
michael@0 670 {
michael@0 671 #ifdef DEBUG
michael@0 672 TreeEntry entry;
michael@0 673 MOZ_ASSERT_IF(stack.current().active(), getTreeEntry(stack.current().treeId(), &entry));
michael@0 674 MOZ_ASSERT_IF(stack.current().active(), entry.textId() == id);
michael@0 675 #endif
michael@0 676 stopEvent();
michael@0 677 }
michael@0 678
michael@0 679 void
michael@0 680 TraceLogger::stopEvent()
michael@0 681 {
michael@0 682 if (enabled && stack.current().active()) {
michael@0 683 uint64_t stop = rdtsc() - traceLoggers.startupTime;
michael@0 684 if (!updateStop(stack.current().treeId(), stop)) {
michael@0 685 fprintf(stderr, "TraceLogging: Failed to stop an event.\n");
michael@0 686 enabled = false;
michael@0 687 failed = true;
michael@0 688 return;
michael@0 689 }
michael@0 690 }
michael@0 691 stack.pop();
michael@0 692 }
michael@0 693
michael@0 694 TraceLogging::TraceLogging()
michael@0 695 {
michael@0 696 initialized = false;
michael@0 697 enabled = false;
michael@0 698 mainThreadEnabled = true;
michael@0 699 offThreadEnabled = true;
michael@0 700 loggerId = 0;
michael@0 701
michael@0 702 #ifdef JS_THREADSAFE
michael@0 703 lock = PR_NewLock();
michael@0 704 if (!lock)
michael@0 705 MOZ_CRASH();
michael@0 706 #endif // JS_THREADSAFE
michael@0 707 }
michael@0 708
michael@0 709 TraceLogging::~TraceLogging()
michael@0 710 {
michael@0 711 if (out) {
michael@0 712 fprintf(out, "]");
michael@0 713 fclose(out);
michael@0 714 out = nullptr;
michael@0 715 }
michael@0 716
michael@0 717 for (size_t i = 0; i < mainThreadLoggers.length(); i++)
michael@0 718 delete mainThreadLoggers[i];
michael@0 719
michael@0 720 mainThreadLoggers.clear();
michael@0 721
michael@0 722 #ifdef JS_THREADSAFE
michael@0 723 if (threadLoggers.initialized()) {
michael@0 724 for (ThreadLoggerHashMap::Range r = threadLoggers.all(); !r.empty(); r.popFront())
michael@0 725 delete r.front().value();
michael@0 726
michael@0 727 threadLoggers.finish();
michael@0 728 }
michael@0 729
michael@0 730 if (lock) {
michael@0 731 PR_DestroyLock(lock);
michael@0 732 lock = nullptr;
michael@0 733 }
michael@0 734 #endif // JS_THREADSAFE
michael@0 735
michael@0 736 enabled = false;
michael@0 737 }
michael@0 738
michael@0 739 static bool
michael@0 740 ContainsFlag(const char *str, const char *flag)
michael@0 741 {
michael@0 742 size_t flaglen = strlen(flag);
michael@0 743 const char *index = strstr(str, flag);
michael@0 744 while (index) {
michael@0 745 if ((index == str || index[-1] == ',') && (index[flaglen] == 0 || index[flaglen] == ','))
michael@0 746 return true;
michael@0 747 index = strstr(index + flaglen, flag);
michael@0 748 }
michael@0 749 return false;
michael@0 750 }
michael@0 751
michael@0 752 bool
michael@0 753 TraceLogging::lazyInit()
michael@0 754 {
michael@0 755 if (initialized)
michael@0 756 return enabled;
michael@0 757
michael@0 758 initialized = true;
michael@0 759
michael@0 760 out = fopen(TRACE_LOG_DIR "tl-data.json", "w");
michael@0 761 if (!out)
michael@0 762 return false;
michael@0 763 fprintf(out, "[");
michael@0 764
michael@0 765 #ifdef JS_THREADSAFE
michael@0 766 if (!threadLoggers.init())
michael@0 767 return false;
michael@0 768 #endif // JS_THREADSAFE
michael@0 769
michael@0 770 const char *env = getenv("TLLOG");
michael@0 771 if (!env)
michael@0 772 env = "";
michael@0 773
michael@0 774 if (strstr(env, "help")) {
michael@0 775 fflush(nullptr);
michael@0 776 printf(
michael@0 777 "\n"
michael@0 778 "usage: TLLOG=option,option,option,... where options can be:\n"
michael@0 779 "\n"
michael@0 780 "Collections:\n"
michael@0 781 " Default Output all default\n"
michael@0 782 " IonCompiler Output all information about compilation\n"
michael@0 783 "\n"
michael@0 784 "Specific log items:\n"
michael@0 785 );
michael@0 786 for (uint32_t i = 1; i < TraceLogger::LAST; i++) {
michael@0 787 printf(" %s\n", text[i]);
michael@0 788 }
michael@0 789 printf("\n");
michael@0 790 exit(0);
michael@0 791 /*NOTREACHED*/
michael@0 792 }
michael@0 793
michael@0 794 for (uint32_t i = 1; i < TraceLogger::LAST; i++)
michael@0 795 enabledTextIds[i] = ContainsFlag(env, text[i]);
michael@0 796
michael@0 797 enabledTextIds[TraceLogger::TL_Error] = true;
michael@0 798 enabledTextIds[TraceLogger::TL] = true;
michael@0 799
michael@0 800 if (ContainsFlag(env, "Default") || strlen(env) == 0) {
michael@0 801 enabledTextIds[TraceLogger::Bailout] = true;
michael@0 802 enabledTextIds[TraceLogger::Baseline] = true;
michael@0 803 enabledTextIds[TraceLogger::BaselineCompilation] = true;
michael@0 804 enabledTextIds[TraceLogger::GC] = true;
michael@0 805 enabledTextIds[TraceLogger::GCAllocation] = true;
michael@0 806 enabledTextIds[TraceLogger::GCSweeping] = true;
michael@0 807 enabledTextIds[TraceLogger::Interpreter] = true;
michael@0 808 enabledTextIds[TraceLogger::IonCompilation] = true;
michael@0 809 enabledTextIds[TraceLogger::IonLinking] = true;
michael@0 810 enabledTextIds[TraceLogger::IonMonkey] = true;
michael@0 811 enabledTextIds[TraceLogger::MinorGC] = true;
michael@0 812 enabledTextIds[TraceLogger::ParserCompileFunction] = true;
michael@0 813 enabledTextIds[TraceLogger::ParserCompileLazy] = true;
michael@0 814 enabledTextIds[TraceLogger::ParserCompileScript] = true;
michael@0 815 enabledTextIds[TraceLogger::YarrCompile] = true;
michael@0 816 enabledTextIds[TraceLogger::YarrInterpret] = true;
michael@0 817 enabledTextIds[TraceLogger::YarrJIT] = true;
michael@0 818 }
michael@0 819
michael@0 820 if (ContainsFlag(env, "IonCompiler") || strlen(env) == 0) {
michael@0 821 enabledTextIds[TraceLogger::IonCompilation] = true;
michael@0 822 enabledTextIds[TraceLogger::IonLinking] = true;
michael@0 823 enabledTextIds[TraceLogger::SplitCriticalEdges] = true;
michael@0 824 enabledTextIds[TraceLogger::RenumberBlocks] = true;
michael@0 825 enabledTextIds[TraceLogger::DominatorTree] = true;
michael@0 826 enabledTextIds[TraceLogger::PhiAnalysis] = true;
michael@0 827 enabledTextIds[TraceLogger::ApplyTypes] = true;
michael@0 828 enabledTextIds[TraceLogger::ParallelSafetyAnalysis] = true;
michael@0 829 enabledTextIds[TraceLogger::AliasAnalysis] = true;
michael@0 830 enabledTextIds[TraceLogger::GVN] = true;
michael@0 831 enabledTextIds[TraceLogger::UCE] = true;
michael@0 832 enabledTextIds[TraceLogger::LICM] = true;
michael@0 833 enabledTextIds[TraceLogger::RangeAnalysis] = true;
michael@0 834 enabledTextIds[TraceLogger::EffectiveAddressAnalysis] = true;
michael@0 835 enabledTextIds[TraceLogger::EliminateDeadCode] = true;
michael@0 836 enabledTextIds[TraceLogger::EdgeCaseAnalysis] = true;
michael@0 837 enabledTextIds[TraceLogger::EliminateRedundantChecks] = true;
michael@0 838 }
michael@0 839
michael@0 840 const char *options = getenv("TLOPTIONS");
michael@0 841 if (options) {
michael@0 842 if (strstr(options, "help")) {
michael@0 843 fflush(nullptr);
michael@0 844 printf(
michael@0 845 "\n"
michael@0 846 "usage: TLOPTIONS=option,option,option,... where options can be:\n"
michael@0 847 "\n"
michael@0 848 " DisableMainThread Don't start logging the mainThread automatically.\n"
michael@0 849 " DisableOffThread Don't start logging the off mainThread automatically.\n"
michael@0 850 );
michael@0 851 printf("\n");
michael@0 852 exit(0);
michael@0 853 /*NOTREACHED*/
michael@0 854 }
michael@0 855
michael@0 856 if (strstr(options, "DisableMainThread"))
michael@0 857 mainThreadEnabled = false;
michael@0 858 if (strstr(options, "DisableOffThread"))
michael@0 859 offThreadEnabled = false;
michael@0 860 }
michael@0 861
michael@0 862 startupTime = rdtsc();
michael@0 863 enabled = true;
michael@0 864 return true;
michael@0 865 }
michael@0 866
michael@0 867 TraceLogger *
michael@0 868 js::TraceLoggerForMainThread(jit::CompileRuntime *runtime)
michael@0 869 {
michael@0 870 return traceLoggers.forMainThread(runtime);
michael@0 871 }
michael@0 872
michael@0 873 TraceLogger *
michael@0 874 TraceLogging::forMainThread(jit::CompileRuntime *runtime)
michael@0 875 {
michael@0 876 return forMainThread(runtime->mainThread());
michael@0 877 }
michael@0 878
michael@0 879 TraceLogger *
michael@0 880 js::TraceLoggerForMainThread(JSRuntime *runtime)
michael@0 881 {
michael@0 882 return traceLoggers.forMainThread(runtime);
michael@0 883 }
michael@0 884
michael@0 885 TraceLogger *
michael@0 886 TraceLogging::forMainThread(JSRuntime *runtime)
michael@0 887 {
michael@0 888 return forMainThread(&runtime->mainThread);
michael@0 889 }
michael@0 890
michael@0 891 TraceLogger *
michael@0 892 TraceLogging::forMainThread(PerThreadData *mainThread)
michael@0 893 {
michael@0 894 if (!mainThread->traceLogger) {
michael@0 895 AutoTraceLoggingLock lock(this);
michael@0 896
michael@0 897 if (!lazyInit())
michael@0 898 return nullptr;
michael@0 899
michael@0 900 TraceLogger *logger = create();
michael@0 901 mainThread->traceLogger = logger;
michael@0 902
michael@0 903 if (!mainThreadLoggers.append(logger))
michael@0 904 return nullptr;
michael@0 905
michael@0 906 if (!mainThreadEnabled)
michael@0 907 logger->disable();
michael@0 908 }
michael@0 909
michael@0 910 return mainThread->traceLogger;
michael@0 911 }
michael@0 912
michael@0 913 TraceLogger *
michael@0 914 js::TraceLoggerForCurrentThread()
michael@0 915 {
michael@0 916 #ifdef JS_THREADSAFE
michael@0 917 PRThread *thread = PR_GetCurrentThread();
michael@0 918 return traceLoggers.forThread(thread);
michael@0 919 #else
michael@0 920 MOZ_ASSUME_UNREACHABLE("No threads supported. Use TraceLoggerForMainThread for the main thread.");
michael@0 921 #endif // JS_THREADSAFE
michael@0 922 }
michael@0 923
michael@0 924 #ifdef JS_THREADSAFE
michael@0 925 TraceLogger *
michael@0 926 TraceLogging::forThread(PRThread *thread)
michael@0 927 {
michael@0 928 AutoTraceLoggingLock lock(this);
michael@0 929
michael@0 930 if (!lazyInit())
michael@0 931 return nullptr;
michael@0 932
michael@0 933 ThreadLoggerHashMap::AddPtr p = threadLoggers.lookupForAdd(thread);
michael@0 934 if (p)
michael@0 935 return p->value();
michael@0 936
michael@0 937 TraceLogger *logger = create();
michael@0 938 if (!logger)
michael@0 939 return nullptr;
michael@0 940
michael@0 941 if (!threadLoggers.add(p, thread, logger)) {
michael@0 942 delete logger;
michael@0 943 return nullptr;
michael@0 944 }
michael@0 945
michael@0 946 if (!offThreadEnabled)
michael@0 947 logger->disable();
michael@0 948
michael@0 949 return logger;
michael@0 950 }
michael@0 951 #endif // JS_THREADSAFE
michael@0 952
michael@0 953 TraceLogger *
michael@0 954 TraceLogging::create()
michael@0 955 {
michael@0 956 if (loggerId > 999) {
michael@0 957 fprintf(stderr, "TraceLogging: Can't create more than 999 different loggers.");
michael@0 958 return nullptr;
michael@0 959 }
michael@0 960
michael@0 961 if (loggerId > 0) {
michael@0 962 int written = fprintf(out, ",\n");
michael@0 963 if (written < 0)
michael@0 964 fprintf(stderr, "TraceLogging: Error while writing.\n");
michael@0 965 }
michael@0 966
michael@0 967 loggerId++;
michael@0 968
michael@0 969 int written = fprintf(out, "{\"tree\":\"tl-tree.%d.tl\", \"events\":\"tl-event.%d.tl\", \"dict\":\"tl-dict.%d.json\", \"treeFormat\":\"64,64,31,1,32\"}",
michael@0 970 loggerId, loggerId, loggerId);
michael@0 971 if (written < 0)
michael@0 972 fprintf(stderr, "TraceLogging: Error while writing.\n");
michael@0 973
michael@0 974
michael@0 975 TraceLogger *logger = new TraceLogger();
michael@0 976 if (!logger)
michael@0 977 return nullptr;
michael@0 978
michael@0 979 if (!logger->init(loggerId)) {
michael@0 980 delete logger;
michael@0 981 return nullptr;
michael@0 982 }
michael@0 983
michael@0 984 return logger;
michael@0 985 }
michael@0 986
michael@0 987 bool
michael@0 988 js::TraceLogTextIdEnabled(uint32_t textId)
michael@0 989 {
michael@0 990 return traceLoggers.isTextIdEnabled(textId);
michael@0 991 }

mercurial