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