bytecode/SamplingTool.cpp

   1 /*
   2  * Copyright (C) 2008, 2009 Apple Inc. All rights reserved.
   3  *
   4  * Redistribution and use in source and binary forms, with or without
   5  * modification, are permitted provided that the following conditions
   6  * are met:
   7  *
   8  * 1.  Redistributions of source code must retain the above copyright
   9  *     notice, this list of conditions and the following disclaimer.
  10  * 2.  Redistributions in binary form must reproduce the above copyright
  11  *     notice, this list of conditions and the following disclaimer in the
  12  *     documentation and/or other materials provided with the distribution.
  13  * 3.  Neither the name of Apple Inc. ("Apple") nor the names of
  14  *     its contributors may be used to endorse or promote products derived
  15  *     from this software without specific prior written permission.
  16  *
  17  * THIS SOFTWARE IS PROVIDED BY APPLE AND ITS CONTRIBUTORS "AS IS" AND ANY
  18  * EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE IMPLIED
  19  * WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE ARE
  20  * DISCLAIMED. IN NO EVENT SHALL APPLE OR ITS CONTRIBUTORS BE LIABLE FOR ANY
  21  * DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES
  22  * (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES;
  23  * LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND
  24  * ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
  25  * (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE OF
  26  * THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
  27  */
  28
  29 #include "config.h"
  30 #include "SamplingTool.h"
  31
  32 #include "CodeBlock.h"
  33 #include "Interpreter.h"
  34 #include "Opcode.h"
  35 #include "JSCInlines.h"
  36
  37 #if !OS(WINDOWS)
  38 #include <unistd.h>
  39 #endif
  40
  41 namespace JSC {
  42
  43 #if ENABLE(SAMPLING_FLAGS)
  44
  45 void SamplingFlags::sample()
  46 {
  47     uint32_t mask = static_cast<uint32_t>(1 << 31);
  48     unsigned index;
  49
  50     for (index = 0; index < 32; ++index) {
  51         if (mask & s_flags)
  52             break;
  53         mask >>= 1;
  54     }
  55
  56     s_flagCounts[32 - index]++;
  57 }
  58
  59 void SamplingFlags::start()
  60 {
  61     for (unsigned i = 0; i <= 32; ++i)
  62         s_flagCounts[i] = 0;
  63 }
  64 void SamplingFlags::stop()
  65 {
  66     uint64_t total = 0;
  67     for (unsigned i = 0; i <= 32; ++i)
  68         total += s_flagCounts[i];
  69
  70     if (total) {
  71         dataLogF("\nSamplingFlags: sample counts with flags set: (%lld total)\n", total);
  72         for (unsigned i = 0; i <= 32; ++i) {
  73             if (s_flagCounts[i])
  74                 dataLogF("  [ %02d ] : %lld\t\t(%03.2f%%)\n", i, s_flagCounts[i], (100.0 * s_flagCounts[i]) / total);
  75         }
  76         dataLogF("\n");
  77     } else
  78     dataLogF("\nSamplingFlags: no samples.\n\n");
  79 }
  80 uint64_t SamplingFlags::s_flagCounts[33];
  81
  82 #else
  83 void SamplingFlags::start() {}
  84 void SamplingFlags::stop() {}
  85 #endif
  86
  87 #if ENABLE(SAMPLING_REGIONS)
  88 volatile uintptr_t SamplingRegion::s_currentOrReserved;
  89 Spectrum<const char*>* SamplingRegion::s_spectrum;
  90 unsigned long SamplingRegion::s_noneOfTheAbove;
  91 unsigned SamplingRegion::s_numberOfSamplesSinceDump;
  92
  93 SamplingRegion::Locker::Locker()
  94 {
  95     uintptr_t previous;
  96     while (true) {
  97         previous = s_currentOrReserved;
  98         if (previous & 1) {
  99 #if OS(UNIX)
 100             sched_yield();
 101 #endif
 102             continue;
 103         }
 104         if (WTF::weakCompareAndSwapUIntPtr(&s_currentOrReserved, previous, previous | 1))
 105             break;
 106     }
 107 }
 108
 109 SamplingRegion::Locker::~Locker()
 110 {
 111     // We don't need the CAS, but we do it out of an
 112     // abundance of caution (and because it gives us a memory fence, which is
 113     // never bad).
 114     uintptr_t previous;
 115     do {
 116         previous = s_currentOrReserved;
 117     } while (!WTF::weakCompareAndSwapUIntPtr(&s_currentOrReserved, previous, previous & ~1));
 118 }
 119
 120 void SamplingRegion::sample()
 121 {
 122     // Make sure we lock s_current.
 123     Locker locker;
 124
 125     // Create a spectrum if we don't have one already.
 126     if (!s_spectrum)
 127         s_spectrum = new Spectrum<const char*>();
 128
 129     ASSERT(s_currentOrReserved & 1);
 130
 131     // Walk the region stack, and record each region we see.
 132     SamplingRegion* region = bitwise_cast<SamplingRegion*>(s_currentOrReserved & ~1);
 133     if (region) {
 134         for (; region; region = region->m_previous)
 135             s_spectrum->add(region->m_name);
 136     } else
 137         s_noneOfTheAbove++;
 138
 139     if (s_numberOfSamplesSinceDump++ == SamplingThread::s_hertz) {
 140         s_numberOfSamplesSinceDump = 0;
 141         dumpInternal();
 142     }
 143 }
 144
 145 void SamplingRegion::dump()
 146 {
 147     Locker locker;
 148
 149     dumpInternal();
 150 }
 151
 152 void SamplingRegion::dumpInternal()
 153 {
 154     if (!s_spectrum) {
 155         dataLogF("\nSamplingRegion: was never sampled.\n\n");
 156         return;
 157     }
 158
 159     Vector<Spectrum<const char*>::KeyAndCount> list = s_spectrum->buildList();
 160
 161     unsigned long total = s_noneOfTheAbove;
 162     for (unsigned i = list.size(); i--;)
 163         total += list[i].count;
 164
 165     dataLogF("\nSamplingRegion: sample counts for regions: (%lu samples)\n", total);
 166
 167     for (unsigned i = list.size(); i--;)
 168         dataLogF("    %3.2lf%%  %s\n", (100.0 * list[i].count) / total, list[i].key);
 169 }
 170 #else // ENABLE(SAMPLING_REGIONS)
 171 void SamplingRegion::dump() { }
 172 #endif // ENABLE(SAMPLING_REGIONS)
 173
 174 /*
 175   Start with flag 16 set.
 176   By doing this the monitoring of lower valued flags will be masked out
 177   until flag 16 is explictly cleared.
 178 */
 179 uint32_t SamplingFlags::s_flags = 1 << 15;
 180
 181
 182 #if OS(WINDOWS)
 183
 184 static void sleepForMicroseconds(unsigned us)
 185 {
 186     unsigned ms = us / 1000;
 187     if (us && !ms)
 188         ms = 1;
 189     Sleep(ms);
 190 }
 191
 192 #else
 193
 194 static void sleepForMicroseconds(unsigned us)
 195 {
 196     usleep(us);
 197 }
 198
 199 #endif
 200
 201 static inline unsigned hertz2us(unsigned hertz)
 202 {
 203     return 1000000 / hertz;
 204 }
 205
 206
 207 SamplingTool* SamplingTool::s_samplingTool = 0;
 208
 209
 210 bool SamplingThread::s_running = false;
 211 unsigned SamplingThread::s_hertz = 10000;
 212 ThreadIdentifier SamplingThread::s_samplingThread;
 213
 214 void SamplingThread::threadStartFunc(void*)
 215 {
 216     while (s_running) {
 217         sleepForMicroseconds(hertz2us(s_hertz));
 218
 219 #if ENABLE(SAMPLING_FLAGS)
 220         SamplingFlags::sample();
 221 #endif
 222 #if ENABLE(SAMPLING_REGIONS)
 223         SamplingRegion::sample();
 224 #endif
 225 #if ENABLE(OPCODE_SAMPLING)
 226         SamplingTool::sample();
 227 #endif
 228     }
 229 }
 230
 231
 232 void SamplingThread::start(unsigned hertz)
 233 {
 234     ASSERT(!s_running);
 235     s_running = true;
 236     s_hertz = hertz;
 237
 238     s_samplingThread = createThread(threadStartFunc, 0, "JavaScriptCore::Sampler");
 239 }
 240
 241 void SamplingThread::stop()
 242 {
 243     ASSERT(s_running);
 244     s_running = false;
 245     waitForThreadCompletion(s_samplingThread);
 246 }
 247
 248
 249 void ScriptSampleRecord::sample(CodeBlock* codeBlock, Instruction* vPC)
 250 {
 251     if (!m_samples) {
 252         m_size = codeBlock->instructions().size();
 253         m_samples = static_cast<int*>(calloc(m_size, sizeof(int)));
 254         m_codeBlock = codeBlock;
 255     }
 256
 257     ++m_sampleCount;
 258
 259     unsigned offest = vPC - codeBlock->instructions().begin();
 260     // Since we don't read and write codeBlock and vPC atomically, this check
 261     // can fail if we sample mid op_call / op_ret.
 262     if (offest < m_size) {
 263         m_samples[offest]++;
 264         m_opcodeSampleCount++;
 265     }
 266 }
 267
 268 void SamplingTool::doRun()
 269 {
 270     Sample sample(m_sample, m_codeBlock);
 271     ++m_sampleCount;
 272
 273     if (sample.isNull())
 274         return;
 275
 276     if (!sample.inHostFunction()) {
 277         unsigned opcodeID = m_interpreter->getOpcodeID(sample.vPC()[0].u.opcode);
 278
 279         ++m_opcodeSampleCount;
 280         ++m_opcodeSamples[opcodeID];
 281
 282         if (sample.inCTIFunction())
 283             m_opcodeSamplesInCTIFunctions[opcodeID]++;
 284     }
 285
 286 #if ENABLE(CODEBLOCK_SAMPLING)
 287     if (CodeBlock* codeBlock = sample.codeBlock()) {
 288         MutexLocker locker(m_scriptSampleMapMutex);
 289         ScriptSampleRecord* record = m_scopeSampleMap->get(codeBlock->ownerExecutable());
 290         ASSERT(record);
 291         record->sample(codeBlock, sample.vPC());
 292     }
 293 #endif
 294 }
 295
 296 void SamplingTool::sample()
 297 {
 298     s_samplingTool->doRun();
 299 }
 300
 301 void SamplingTool::notifyOfScope(VM& vm, ScriptExecutable* script)
 302 {
 303 #if ENABLE(CODEBLOCK_SAMPLING)
 304     MutexLocker locker(m_scriptSampleMapMutex);
 305     m_scopeSampleMap->set(script, adoptPtr(new ScriptSampleRecord(vm, script)));
 306 #else
 307     UNUSED_PARAM(vm);
 308     UNUSED_PARAM(script);
 309 #endif
 310 }
 311
 312 void SamplingTool::setup()
 313 {
 314     s_samplingTool = this;
 315 }
 316
 317 #if ENABLE(OPCODE_SAMPLING)
 318
 319 struct OpcodeSampleInfo {
 320     OpcodeID opcode;
 321     long long count;
 322     long long countInCTIFunctions;
 323 };
 324
 325 struct LineCountInfo {
 326     unsigned line;
 327     unsigned count;
 328 };
 329
 330 static int compareOpcodeIndicesSampling(const void* left, const void* right)
 331 {
 332     const OpcodeSampleInfo* leftSampleInfo = reinterpret_cast<const OpcodeSampleInfo*>(left);
 333     const OpcodeSampleInfo* rightSampleInfo = reinterpret_cast<const OpcodeSampleInfo*>(right);
 334
 335     return (leftSampleInfo->count < rightSampleInfo->count) ? 1 : (leftSampleInfo->count > rightSampleInfo->count) ? -1 : 0;
 336 }
 337
 338 #if ENABLE(CODEBLOCK_SAMPLING)
 339 static int compareLineCountInfoSampling(const void* left, const void* right)
 340 {
 341     const LineCountInfo* leftLineCount = reinterpret_cast<const LineCountInfo*>(left);
 342     const LineCountInfo* rightLineCount = reinterpret_cast<const LineCountInfo*>(right);
 343
 344     return (leftLineCount->line > rightLineCount->line) ? 1 : (leftLineCount->line < rightLineCount->line) ? -1 : 0;
 345 }
 346
 347 static int compareScriptSampleRecords(const void* left, const void* right)
 348 {
 349     const ScriptSampleRecord* const leftValue = *static_cast<const ScriptSampleRecord* const *>(left);
 350     const ScriptSampleRecord* const rightValue = *static_cast<const ScriptSampleRecord* const *>(right);
 351
 352     return (leftValue->m_sampleCount < rightValue->m_sampleCount) ? 1 : (leftValue->m_sampleCount > rightValue->m_sampleCount) ? -1 : 0;
 353 }
 354 #endif
 355
 356 void SamplingTool::dump(ExecState* exec)
 357 {
 358     // Tidies up SunSpider output by removing short scripts - such a small number of samples would likely not be useful anyhow.
 359     if (m_sampleCount < 10)
 360         return;
 361
 362     // (1) Build and sort 'opcodeSampleInfo' array.
 363
 364     OpcodeSampleInfo opcodeSampleInfo[numOpcodeIDs];
 365     for (int i = 0; i < numOpcodeIDs; ++i) {
 366         opcodeSampleInfo[i].opcode = static_cast<OpcodeID>(i);
 367         opcodeSampleInfo[i].count = m_opcodeSamples[i];
 368         opcodeSampleInfo[i].countInCTIFunctions = m_opcodeSamplesInCTIFunctions[i];
 369     }
 370
 371     qsort(opcodeSampleInfo, numOpcodeIDs, sizeof(OpcodeSampleInfo), compareOpcodeIndicesSampling);
 372
 373     // (2) Print Opcode sampling results.
 374
 375     dataLogF("\nBytecode samples [*]\n");
 376     dataLogF("                             sample   %% of       %% of     |   cti     cti %%\n");
 377     dataLogF("opcode                       count     VM        total    |  count   of self\n");
 378     dataLogF("-------------------------------------------------------   |  ----------------\n");
 379
 380     for (int i = 0; i < numOpcodeIDs; ++i) {
 381         long long count = opcodeSampleInfo[i].count;
 382         if (!count)
 383             continue;
 384
 385         OpcodeID opcodeID = opcodeSampleInfo[i].opcode;
 386
 387         const char* opcodeName = opcodeNames[opcodeID];
 388         const char* opcodePadding = padOpcodeName(opcodeID, 28);
 389         double percentOfVM = (static_cast<double>(count) * 100) / m_opcodeSampleCount;
 390         double percentOfTotal = (static_cast<double>(count) * 100) / m_sampleCount;
 391         long long countInCTIFunctions = opcodeSampleInfo[i].countInCTIFunctions;
 392         double percentInCTIFunctions = (static_cast<double>(countInCTIFunctions) * 100) / count;
 393         debugDebugPrintf("%s:%s%-6lld %.3f%%\t%.3f%%\t  |   %-6lld %.3f%%\n", opcodeName, opcodePadding, count, percentOfVM, percentOfTotal, countInCTIFunctions, percentInCTIFunctions);
 394     }
 395
 396     dataLogF("\n[*] Samples inside host code are not charged to any Bytecode.\n\n");
 397     dataLogF("\tSamples inside VM:\t\t%lld / %lld (%.3f%%)\n", m_opcodeSampleCount, m_sampleCount, (static_cast<double>(m_opcodeSampleCount) * 100) / m_sampleCount);
 398     dataLogF("\tSamples inside host code:\t%lld / %lld (%.3f%%)\n\n", m_sampleCount - m_opcodeSampleCount, m_sampleCount, (static_cast<double>(m_sampleCount - m_opcodeSampleCount) * 100) / m_sampleCount);
 399     dataLogF("\tsample count:\tsamples inside this opcode\n");
 400     dataLogF("\t%% of VM:\tsample count / all opcode samples\n");
 401     dataLogF("\t%% of total:\tsample count / all samples\n");
 402     dataLogF("\t--------------\n");
 403     dataLogF("\tcti count:\tsamples inside a CTI function called by this opcode\n");
 404     dataLogF("\tcti %% of self:\tcti count / sample count\n");
 405
 406 #if ENABLE(CODEBLOCK_SAMPLING)
 407
 408     // (3) Build and sort 'codeBlockSamples' array.
 409
 410     int scopeCount = m_scopeSampleMap->size();
 411     Vector<ScriptSampleRecord*> codeBlockSamples(scopeCount);
 412     ScriptSampleRecordMap::iterator iter = m_scopeSampleMap->begin();
 413     for (int i = 0; i < scopeCount; ++i, ++iter)
 414         codeBlockSamples[i] = iter->value.get();
 415
 416     qsort(codeBlockSamples.begin(), scopeCount, sizeof(ScriptSampleRecord*), compareScriptSampleRecords);
 417
 418     // (4) Print data from 'codeBlockSamples' array.
 419
 420     dataLogF("\nCodeBlock samples\n\n");
 421
 422     for (int i = 0; i < scopeCount; ++i) {
 423         ScriptSampleRecord* record = codeBlockSamples[i];
 424         CodeBlock* codeBlock = record->m_codeBlock;
 425
 426         double blockPercent = (record->m_sampleCount * 100.0) / m_sampleCount;
 427
 428         if (blockPercent >= 1) {
 429             //Instruction* code = codeBlock->instructions().begin();
 430             dataLogF("#%d: %s:%d: %d / %lld (%.3f%%)\n", i + 1, record->m_executable->sourceURL().utf8().data(), codeBlock->lineNumberForBytecodeOffset(0), record->m_sampleCount, m_sampleCount, blockPercent);
 431             if (i < 10) {
 432                 HashMap<unsigned,unsigned> lineCounts;
 433                 codeBlock->dump(exec);
 434
 435                 dataLogF("    Opcode and line number samples [*]\n\n");
 436                 for (unsigned op = 0; op < record->m_size; ++op) {
 437                     int count = record->m_samples[op];
 438                     if (count) {
 439                         dataLogF("    [% 4d] has sample count: % 4d\n", op, count);
 440                         unsigned line = codeBlock->lineNumberForBytecodeOffset(op);
 441                         lineCounts.set(line, (lineCounts.contains(line) ? lineCounts.get(line) : 0) + count);
 442                     }
 443                 }
 444                 dataLogF("\n");
 445
 446                 int linesCount = lineCounts.size();
 447                 Vector<LineCountInfo> lineCountInfo(linesCount);
 448                 int lineno = 0;
 449                 for (HashMap<unsigned,unsigned>::iterator iter = lineCounts.begin(); iter != lineCounts.end(); ++iter, ++lineno) {
 450                     lineCountInfo[lineno].line = iter->key;
 451                     lineCountInfo[lineno].count = iter->value;
 452                 }
 453
 454                 qsort(lineCountInfo.begin(), linesCount, sizeof(LineCountInfo), compareLineCountInfoSampling);
 455
 456                 for (lineno = 0; lineno < linesCount; ++lineno) {
 457                     dataLogF("    Line #%d has sample count %d.\n", lineCountInfo[lineno].line, lineCountInfo[lineno].count);
 458                 }
 459                 dataLogF("\n");
 460                 dataLogF("    [*] Samples inside host code are charged to the calling Bytecode.\n");
 461                 dataLogF("        Samples on a call / return boundary are not charged to a specific opcode or line.\n\n");
 462                 dataLogF("            Samples on a call / return boundary: %d / %d (%.3f%%)\n\n", record->m_sampleCount - record->m_opcodeSampleCount, record->m_sampleCount, (static_cast<double>(record->m_sampleCount - record->m_opcodeSampleCount) * 100) / record->m_sampleCount);
 463             }
 464         }
 465     }
 466 #else
 467     UNUSED_PARAM(exec);
 468 #endif
 469 }
 470
 471 #else
 472
 473 void SamplingTool::dump(ExecState*)
 474 {
 475 }
 476
 477 #endif
 478
 479 } // namespace JSC