1.1 --- /dev/null Thu Jan 01 00:00:00 1970 +0000
1.2 +++ b/tools/profiler/ProfileEntry.cpp Wed Dec 31 06:09:35 2014 +0100
1.3 @@ -0,0 +1,532 @@
1.4 +/* -*- Mode: C++; tab-width: 2; indent-tabs-mode: nil; c-basic-offset: 2 -*- */
1.5 +/* This Source Code Form is subject to the terms of the Mozilla Public
1.6 + * License, v. 2.0. If a copy of the MPL was not distributed with this
1.7 + * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
1.8 +
1.9 +#include <ostream>
1.10 +#include <sstream>
1.11 +#include "platform.h"
1.12 +#include "nsThreadUtils.h"
1.13 +#include "nsXULAppAPI.h"
1.14 +#include "jsapi.h"
1.15 +
1.16 +// JSON
1.17 +#include "JSStreamWriter.h"
1.18 +
1.19 +// Self
1.20 +#include "ProfileEntry.h"
1.21 +
1.22 +#if _MSC_VER
1.23 + #define snprintf _snprintf
1.24 +#endif
1.25 +
1.26 +////////////////////////////////////////////////////////////////////////
1.27 +// BEGIN ProfileEntry
1.28 +
1.29 +ProfileEntry::ProfileEntry()
1.30 + : mTagData(nullptr)
1.31 + , mTagName(0)
1.32 +{ }
1.33 +
1.34 +// aTagData must not need release (i.e. be a string from the text segment)
1.35 +ProfileEntry::ProfileEntry(char aTagName, const char *aTagData)
1.36 + : mTagData(aTagData)
1.37 + , mTagName(aTagName)
1.38 +{ }
1.39 +
1.40 +ProfileEntry::ProfileEntry(char aTagName, ProfilerMarker *aTagMarker)
1.41 + : mTagMarker(aTagMarker)
1.42 + , mTagName(aTagName)
1.43 +{ }
1.44 +
1.45 +ProfileEntry::ProfileEntry(char aTagName, void *aTagPtr)
1.46 + : mTagPtr(aTagPtr)
1.47 + , mTagName(aTagName)
1.48 +{ }
1.49 +
1.50 +ProfileEntry::ProfileEntry(char aTagName, float aTagFloat)
1.51 + : mTagFloat(aTagFloat)
1.52 + , mTagName(aTagName)
1.53 +{ }
1.54 +
1.55 +ProfileEntry::ProfileEntry(char aTagName, uintptr_t aTagOffset)
1.56 + : mTagOffset(aTagOffset)
1.57 + , mTagName(aTagName)
1.58 +{ }
1.59 +
1.60 +ProfileEntry::ProfileEntry(char aTagName, Address aTagAddress)
1.61 + : mTagAddress(aTagAddress)
1.62 + , mTagName(aTagName)
1.63 +{ }
1.64 +
1.65 +ProfileEntry::ProfileEntry(char aTagName, int aTagLine)
1.66 + : mTagLine(aTagLine)
1.67 + , mTagName(aTagName)
1.68 +{ }
1.69 +
1.70 +ProfileEntry::ProfileEntry(char aTagName, char aTagChar)
1.71 + : mTagChar(aTagChar)
1.72 + , mTagName(aTagName)
1.73 +{ }
1.74 +
1.75 +bool ProfileEntry::is_ent_hint(char hintChar) {
1.76 + return mTagName == 'h' && mTagChar == hintChar;
1.77 +}
1.78 +
1.79 +bool ProfileEntry::is_ent_hint() {
1.80 + return mTagName == 'h';
1.81 +}
1.82 +
1.83 +bool ProfileEntry::is_ent(char tagChar) {
1.84 + return mTagName == tagChar;
1.85 +}
1.86 +
1.87 +void* ProfileEntry::get_tagPtr() {
1.88 + // No consistency checking. Oh well.
1.89 + return mTagPtr;
1.90 +}
1.91 +
1.92 +void ProfileEntry::log()
1.93 +{
1.94 + // There is no compiler enforced mapping between tag chars
1.95 + // and union variant fields, so the following was derived
1.96 + // by looking through all the use points of TableTicker.cpp.
1.97 + // mTagMarker (ProfilerMarker*) m
1.98 + // mTagData (const char*) c,s
1.99 + // mTagPtr (void*) d,l,L,B (immediate backtrace), S(start-of-stack)
1.100 + // mTagLine (int) n,f
1.101 + // mTagChar (char) h
1.102 + // mTagFloat (double) r,t,p
1.103 + switch (mTagName) {
1.104 + case 'm':
1.105 + LOGF("%c \"%s\"", mTagName, mTagMarker->GetMarkerName()); break;
1.106 + case 'c': case 's':
1.107 + LOGF("%c \"%s\"", mTagName, mTagData); break;
1.108 + case 'd': case 'l': case 'L': case 'B': case 'S':
1.109 + LOGF("%c %p", mTagName, mTagPtr); break;
1.110 + case 'n': case 'f':
1.111 + LOGF("%c %d", mTagName, mTagLine); break;
1.112 + case 'h':
1.113 + LOGF("%c \'%c\'", mTagName, mTagChar); break;
1.114 + case 'r': case 't': case 'p':
1.115 + LOGF("%c %f", mTagName, mTagFloat); break;
1.116 + default:
1.117 + LOGF("'%c' unknown_tag", mTagName); break;
1.118 + }
1.119 +}
1.120 +
1.121 +std::ostream& operator<<(std::ostream& stream, const ProfileEntry& entry)
1.122 +{
1.123 + if (entry.mTagName == 'r' || entry.mTagName == 't') {
1.124 + stream << entry.mTagName << "-" << std::fixed << entry.mTagFloat << "\n";
1.125 + } else if (entry.mTagName == 'l' || entry.mTagName == 'L') {
1.126 + // Bug 739800 - Force l-tag addresses to have a "0x" prefix on all platforms
1.127 + // Additionally, stringstream seemed to be ignoring formatter flags.
1.128 + char tagBuff[1024];
1.129 + unsigned long long pc = (unsigned long long)(uintptr_t)entry.mTagPtr;
1.130 + snprintf(tagBuff, 1024, "%c-%#llx\n", entry.mTagName, pc);
1.131 + stream << tagBuff;
1.132 + } else if (entry.mTagName == 'd') {
1.133 + // TODO implement 'd' tag for text profile
1.134 + } else {
1.135 + stream << entry.mTagName << "-" << entry.mTagData << "\n";
1.136 + }
1.137 + return stream;
1.138 +}
1.139 +
1.140 +// END ProfileEntry
1.141 +////////////////////////////////////////////////////////////////////////
1.142 +
1.143 +
1.144 +////////////////////////////////////////////////////////////////////////
1.145 +// BEGIN ThreadProfile
1.146 +
1.147 +#define DYNAMIC_MAX_STRING 512
1.148 +
1.149 +ThreadProfile::ThreadProfile(const char* aName, int aEntrySize,
1.150 + PseudoStack *aStack, Thread::tid_t aThreadId,
1.151 + PlatformData* aPlatform,
1.152 + bool aIsMainThread, void *aStackTop)
1.153 + : mWritePos(0)
1.154 + , mLastFlushPos(0)
1.155 + , mReadPos(0)
1.156 + , mEntrySize(aEntrySize)
1.157 + , mPseudoStack(aStack)
1.158 + , mMutex("ThreadProfile::mMutex")
1.159 + , mName(strdup(aName))
1.160 + , mThreadId(aThreadId)
1.161 + , mIsMainThread(aIsMainThread)
1.162 + , mPlatformData(aPlatform)
1.163 + , mGeneration(0)
1.164 + , mPendingGenerationFlush(0)
1.165 + , mStackTop(aStackTop)
1.166 +{
1.167 + mEntries = new ProfileEntry[mEntrySize];
1.168 +}
1.169 +
1.170 +ThreadProfile::~ThreadProfile()
1.171 +{
1.172 + free(mName);
1.173 + delete[] mEntries;
1.174 +}
1.175 +
1.176 +void ThreadProfile::addTag(ProfileEntry aTag)
1.177 +{
1.178 + // Called from signal, call only reentrant functions
1.179 + mEntries[mWritePos] = aTag;
1.180 + mWritePos = mWritePos + 1;
1.181 + if (mWritePos >= mEntrySize) {
1.182 + mPendingGenerationFlush++;
1.183 + mWritePos = mWritePos % mEntrySize;
1.184 + }
1.185 + if (mWritePos == mReadPos) {
1.186 + // Keep one slot open
1.187 + mEntries[mReadPos] = ProfileEntry();
1.188 + mReadPos = (mReadPos + 1) % mEntrySize;
1.189 + }
1.190 + // we also need to move the flush pos to ensure we
1.191 + // do not pass it
1.192 + if (mWritePos == mLastFlushPos) {
1.193 + mLastFlushPos = (mLastFlushPos + 1) % mEntrySize;
1.194 + }
1.195 +}
1.196 +
1.197 +// flush the new entries
1.198 +void ThreadProfile::flush()
1.199 +{
1.200 + mLastFlushPos = mWritePos;
1.201 + mGeneration += mPendingGenerationFlush;
1.202 + mPendingGenerationFlush = 0;
1.203 +}
1.204 +
1.205 +// discards all of the entries since the last flush()
1.206 +// NOTE: that if mWritePos happens to wrap around past
1.207 +// mLastFlushPos we actually only discard mWritePos - mLastFlushPos entries
1.208 +//
1.209 +// r = mReadPos
1.210 +// w = mWritePos
1.211 +// f = mLastFlushPos
1.212 +//
1.213 +// r f w
1.214 +// |-----------------------------|
1.215 +// | abcdefghijklmnopq | -> 'abcdefghijklmnopq'
1.216 +// |-----------------------------|
1.217 +//
1.218 +//
1.219 +// mWritePos and mReadPos have passed mLastFlushPos
1.220 +// f
1.221 +// w r
1.222 +// |-----------------------------|
1.223 +// |ABCDEFGHIJKLMNOPQRSqrstuvwxyz|
1.224 +// |-----------------------------|
1.225 +// w
1.226 +// r
1.227 +// |-----------------------------|
1.228 +// |ABCDEFGHIJKLMNOPQRSqrstuvwxyz| -> ''
1.229 +// |-----------------------------|
1.230 +//
1.231 +//
1.232 +// mWritePos will end up the same as mReadPos
1.233 +// r
1.234 +// w f
1.235 +// |-----------------------------|
1.236 +// |ABCDEFGHIJKLMklmnopqrstuvwxyz|
1.237 +// |-----------------------------|
1.238 +// r
1.239 +// w
1.240 +// |-----------------------------|
1.241 +// |ABCDEFGHIJKLMklmnopqrstuvwxyz| -> ''
1.242 +// |-----------------------------|
1.243 +//
1.244 +//
1.245 +// mWritePos has moved past mReadPos
1.246 +// w r f
1.247 +// |-----------------------------|
1.248 +// |ABCDEFdefghijklmnopqrstuvwxyz|
1.249 +// |-----------------------------|
1.250 +// r w
1.251 +// |-----------------------------|
1.252 +// |ABCDEFdefghijklmnopqrstuvwxyz| -> 'defghijkl'
1.253 +// |-----------------------------|
1.254 +
1.255 +void ThreadProfile::erase()
1.256 +{
1.257 + mWritePos = mLastFlushPos;
1.258 + mPendingGenerationFlush = 0;
1.259 +}
1.260 +
1.261 +char* ThreadProfile::processDynamicTag(int readPos,
1.262 + int* tagsConsumed, char* tagBuff)
1.263 +{
1.264 + int readAheadPos = (readPos + 1) % mEntrySize;
1.265 + int tagBuffPos = 0;
1.266 +
1.267 + // Read the string stored in mTagData until the null character is seen
1.268 + bool seenNullByte = false;
1.269 + while (readAheadPos != mLastFlushPos && !seenNullByte) {
1.270 + (*tagsConsumed)++;
1.271 + ProfileEntry readAheadEntry = mEntries[readAheadPos];
1.272 + for (size_t pos = 0; pos < sizeof(void*); pos++) {
1.273 + tagBuff[tagBuffPos] = readAheadEntry.mTagChars[pos];
1.274 + if (tagBuff[tagBuffPos] == '\0' || tagBuffPos == DYNAMIC_MAX_STRING-2) {
1.275 + seenNullByte = true;
1.276 + break;
1.277 + }
1.278 + tagBuffPos++;
1.279 + }
1.280 + if (!seenNullByte)
1.281 + readAheadPos = (readAheadPos + 1) % mEntrySize;
1.282 + }
1.283 + return tagBuff;
1.284 +}
1.285 +
1.286 +void ThreadProfile::IterateTags(IterateTagsCallback aCallback)
1.287 +{
1.288 + MOZ_ASSERT(aCallback);
1.289 +
1.290 + int readPos = mReadPos;
1.291 + while (readPos != mLastFlushPos) {
1.292 + // Number of tag consumed
1.293 + int incBy = 1;
1.294 + const ProfileEntry& entry = mEntries[readPos];
1.295 +
1.296 + // Read ahead to the next tag, if it's a 'd' tag process it now
1.297 + const char* tagStringData = entry.mTagData;
1.298 + int readAheadPos = (readPos + 1) % mEntrySize;
1.299 + char tagBuff[DYNAMIC_MAX_STRING];
1.300 + // Make sure the string is always null terminated if it fills up DYNAMIC_MAX_STRING-2
1.301 + tagBuff[DYNAMIC_MAX_STRING-1] = '\0';
1.302 +
1.303 + if (readAheadPos != mLastFlushPos && mEntries[readAheadPos].mTagName == 'd') {
1.304 + tagStringData = processDynamicTag(readPos, &incBy, tagBuff);
1.305 + }
1.306 +
1.307 + aCallback(entry, tagStringData);
1.308 +
1.309 + readPos = (readPos + incBy) % mEntrySize;
1.310 + }
1.311 +}
1.312 +
1.313 +void ThreadProfile::ToStreamAsJSON(std::ostream& stream)
1.314 +{
1.315 + JSStreamWriter b(stream);
1.316 + StreamJSObject(b);
1.317 +}
1.318 +
1.319 +void ThreadProfile::StreamJSObject(JSStreamWriter& b)
1.320 +{
1.321 + b.BeginObject();
1.322 + // Thread meta data
1.323 + if (XRE_GetProcessType() == GeckoProcessType_Plugin) {
1.324 + // TODO Add the proper plugin name
1.325 + b.NameValue("name", "Plugin");
1.326 + } else {
1.327 + b.NameValue("name", mName);
1.328 + }
1.329 + b.NameValue("tid", static_cast<int>(mThreadId));
1.330 +
1.331 + b.Name("samples");
1.332 + b.BeginArray();
1.333 +
1.334 + bool sample = false;
1.335 + int readPos = mReadPos;
1.336 + while (readPos != mLastFlushPos) {
1.337 + // Number of tag consumed
1.338 + ProfileEntry entry = mEntries[readPos];
1.339 +
1.340 + switch (entry.mTagName) {
1.341 + case 'r':
1.342 + {
1.343 + if (sample) {
1.344 + b.NameValue("responsiveness", entry.mTagFloat);
1.345 + }
1.346 + }
1.347 + break;
1.348 + case 'p':
1.349 + {
1.350 + if (sample) {
1.351 + b.NameValue("power", entry.mTagFloat);
1.352 + }
1.353 + }
1.354 + break;
1.355 + case 'f':
1.356 + {
1.357 + if (sample) {
1.358 + b.NameValue("frameNumber", entry.mTagLine);
1.359 + }
1.360 + }
1.361 + break;
1.362 + case 't':
1.363 + {
1.364 + if (sample) {
1.365 + b.NameValue("time", entry.mTagFloat);
1.366 + }
1.367 + }
1.368 + break;
1.369 + case 's':
1.370 + {
1.371 + // end the previous sample if there was one
1.372 + if (sample) {
1.373 + b.EndObject();
1.374 + }
1.375 + // begin the next sample
1.376 + b.BeginObject();
1.377 +
1.378 + sample = true;
1.379 +
1.380 + // Seek forward through the entire sample, looking for frames
1.381 + // this is an easier approach to reason about than adding more
1.382 + // control variables and cases to the loop that goes through the buffer once
1.383 + b.Name("frames");
1.384 + b.BeginArray();
1.385 +
1.386 + b.BeginObject();
1.387 + b.NameValue("location", "(root)");
1.388 + b.EndObject();
1.389 +
1.390 + int framePos = (readPos + 1) % mEntrySize;
1.391 + ProfileEntry frame = mEntries[framePos];
1.392 + while (framePos != mLastFlushPos && frame.mTagName != 's') {
1.393 + int incBy = 1;
1.394 + frame = mEntries[framePos];
1.395 + // Read ahead to the next tag, if it's a 'd' tag process it now
1.396 + const char* tagStringData = frame.mTagData;
1.397 + int readAheadPos = (framePos + 1) % mEntrySize;
1.398 + char tagBuff[DYNAMIC_MAX_STRING];
1.399 + // Make sure the string is always null terminated if it fills up
1.400 + // DYNAMIC_MAX_STRING-2
1.401 + tagBuff[DYNAMIC_MAX_STRING-1] = '\0';
1.402 +
1.403 + if (readAheadPos != mLastFlushPos && mEntries[readAheadPos].mTagName == 'd') {
1.404 + tagStringData = processDynamicTag(framePos, &incBy, tagBuff);
1.405 + }
1.406 +
1.407 + // Write one frame. It can have either
1.408 + // 1. only location - 'l' containing a memory address
1.409 + // 2. location and line number - 'c' followed by 'd's and an optional 'n'
1.410 + if (frame.mTagName == 'l') {
1.411 + b.BeginObject();
1.412 + // Bug 753041
1.413 + // We need a double cast here to tell GCC that we don't want to sign
1.414 + // extend 32-bit addresses starting with 0xFXXXXXX.
1.415 + unsigned long long pc = (unsigned long long)(uintptr_t)frame.mTagPtr;
1.416 + snprintf(tagBuff, DYNAMIC_MAX_STRING, "%#llx", pc);
1.417 + b.NameValue("location", tagBuff);
1.418 + b.EndObject();
1.419 + } else if (frame.mTagName == 'c') {
1.420 + b.BeginObject();
1.421 + b.NameValue("location", tagStringData);
1.422 + readAheadPos = (framePos + incBy) % mEntrySize;
1.423 + if (readAheadPos != mLastFlushPos &&
1.424 + mEntries[readAheadPos].mTagName == 'n') {
1.425 + b.NameValue("line", mEntries[readAheadPos].mTagLine);
1.426 + incBy++;
1.427 + }
1.428 + b.EndObject();
1.429 + }
1.430 + framePos = (framePos + incBy) % mEntrySize;
1.431 + }
1.432 + b.EndArray();
1.433 + }
1.434 + break;
1.435 + }
1.436 + readPos = (readPos + 1) % mEntrySize;
1.437 + }
1.438 + if (sample) {
1.439 + b.EndObject();
1.440 + }
1.441 + b.EndArray();
1.442 +
1.443 + b.Name("markers");
1.444 + b.BeginArray();
1.445 + readPos = mReadPos;
1.446 + while (readPos != mLastFlushPos) {
1.447 + ProfileEntry entry = mEntries[readPos];
1.448 + if (entry.mTagName == 'm') {
1.449 + entry.getMarker()->StreamJSObject(b);
1.450 + }
1.451 + readPos = (readPos + 1) % mEntrySize;
1.452 + }
1.453 + b.EndArray();
1.454 + b.EndObject();
1.455 +}
1.456 +
1.457 +JSObject* ThreadProfile::ToJSObject(JSContext *aCx)
1.458 +{
1.459 + JS::RootedValue val(aCx);
1.460 + std::stringstream ss;
1.461 + {
1.462 + // Define a scope to prevent a moving GC during ~JSStreamWriter from
1.463 + // trashing the return value.
1.464 + JSStreamWriter b(ss);
1.465 + StreamJSObject(b);
1.466 + NS_ConvertUTF8toUTF16 js_string(nsDependentCString(ss.str().c_str()));
1.467 + JS_ParseJSON(aCx, static_cast<const jschar*>(js_string.get()), js_string.Length(), &val);
1.468 + }
1.469 + return &val.toObject();
1.470 +}
1.471 +
1.472 +PseudoStack* ThreadProfile::GetPseudoStack()
1.473 +{
1.474 + return mPseudoStack;
1.475 +}
1.476 +
1.477 +void ThreadProfile::BeginUnwind()
1.478 +{
1.479 + mMutex.Lock();
1.480 +}
1.481 +
1.482 +void ThreadProfile::EndUnwind()
1.483 +{
1.484 + mMutex.Unlock();
1.485 +}
1.486 +
1.487 +mozilla::Mutex* ThreadProfile::GetMutex()
1.488 +{
1.489 + return &mMutex;
1.490 +}
1.491 +
1.492 +void ThreadProfile::DuplicateLastSample() {
1.493 + // Scan the whole buffer (even unflushed parts)
1.494 + // Adding mEntrySize makes the result of the modulus positive
1.495 + // We search backwards from mWritePos-1 to mReadPos
1.496 + for (int readPos = (mWritePos + mEntrySize - 1) % mEntrySize;
1.497 + readPos != (mReadPos + mEntrySize - 1) % mEntrySize;
1.498 + readPos = (readPos + mEntrySize - 1) % mEntrySize) {
1.499 + if (mEntries[readPos].mTagName == 's') {
1.500 + // Found the start of the last entry at position readPos
1.501 + int copyEndIdx = mWritePos;
1.502 + // Go through the whole entry and duplicate it
1.503 + for (;readPos != copyEndIdx; readPos = (readPos + 1) % mEntrySize) {
1.504 + switch (mEntries[readPos].mTagName) {
1.505 + // Copy with new time
1.506 + case 't':
1.507 + addTag(ProfileEntry('t', static_cast<float>((mozilla::TimeStamp::Now() - sStartTime).ToMilliseconds())));
1.508 + break;
1.509 + // Don't copy markers
1.510 + case 'm':
1.511 + break;
1.512 + // Copy anything else we don't know about
1.513 + // L, B, S, c, s, d, l, f, h, r, t, p
1.514 + default:
1.515 + addTag(mEntries[readPos]);
1.516 + break;
1.517 + }
1.518 + }
1.519 + break;
1.520 + }
1.521 + }
1.522 +}
1.523 +
1.524 +std::ostream& operator<<(std::ostream& stream, const ThreadProfile& profile)
1.525 +{
1.526 + int readPos = profile.mReadPos;
1.527 + while (readPos != profile.mLastFlushPos) {
1.528 + stream << profile.mEntries[readPos];
1.529 + readPos = (readPos + 1) % profile.mEntrySize;
1.530 + }
1.531 + return stream;
1.532 +}
1.533 +
1.534 +// END ThreadProfile
1.535 +////////////////////////////////////////////////////////////////////////
