ec06732236
ReadFile returned a Vector with ownership transfer, i.e. the client needed to call Dispose to free the memory. This CL changes the interface to return a std::string instead, which manages ownership. As it turns out, there is only one user of ReadString that sometimes calls an API function which expects to take ownership of its Vector argument. Bug: v8:7932 Cq-Include-Trybots: luci.chromium.try:linux_chromium_headless_rel;luci.chromium.try:linux_chromium_rel_ng;master.tryserver.blink:linux_trusty_blink_rel Change-Id: Ie624a7a65cf5814fddce7a57bc557e4b9876bc53 Reviewed-on: https://chromium-review.googlesource.com/1155115 Commit-Queue: Sigurd Schneider <sigurds@chromium.org> Reviewed-by: Camillo Bruni <cbruni@chromium.org> Cr-Commit-Position: refs/heads/master@{#54805}
1149 lines
39 KiB
C++
1149 lines
39 KiB
C++
// Copyright 2006-2009 the V8 project authors. All rights reserved.
|
|
// Redistribution and use in source and binary forms, with or without
|
|
// modification, are permitted provided that the following conditions are
|
|
// met:
|
|
//
|
|
// * Redistributions of source code must retain the above copyright
|
|
// notice, this list of conditions and the following disclaimer.
|
|
// * Redistributions in binary form must reproduce the above
|
|
// copyright notice, this list of conditions and the following
|
|
// disclaimer in the documentation and/or other materials provided
|
|
// with the distribution.
|
|
// * Neither the name of Google Inc. nor the names of its
|
|
// contributors may be used to endorse or promote products derived
|
|
// from this software without specific prior written permission.
|
|
//
|
|
// THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS
|
|
// "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT
|
|
// LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR
|
|
// A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT
|
|
// OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
|
|
// SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT
|
|
// LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE,
|
|
// DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY
|
|
// THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
|
|
// (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
|
|
// OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
|
|
//
|
|
// Tests of logging functions from log.h
|
|
|
|
#ifdef __linux__
|
|
#include <pthread.h>
|
|
#include <signal.h>
|
|
#include <unistd.h>
|
|
#include <cmath>
|
|
#endif // __linux__
|
|
|
|
#include <unordered_set>
|
|
#include <vector>
|
|
// The C++ style guide recommends using <re2> instead of <regex>. However, the
|
|
// former isn't available in V8.
|
|
#include <regex> // NOLINT(build/c++11)
|
|
#include "src/api-inl.h"
|
|
#include "src/log-utils.h"
|
|
#include "src/log.h"
|
|
#include "src/objects-inl.h"
|
|
#include "src/profiler/cpu-profiler.h"
|
|
#include "src/snapshot/natives.h"
|
|
#include "src/utils.h"
|
|
#include "src/v8.h"
|
|
#include "src/v8threads.h"
|
|
#include "src/version.h"
|
|
#include "src/vm-state-inl.h"
|
|
#include "test/cctest/cctest.h"
|
|
|
|
using v8::internal::Address;
|
|
using v8::internal::EmbeddedVector;
|
|
using v8::internal::Logger;
|
|
using v8::internal::StrLength;
|
|
|
|
namespace {
|
|
|
|
|
|
#define SETUP_FLAGS() \
|
|
bool saved_log = i::FLAG_log; \
|
|
bool saved_prof = i::FLAG_prof; \
|
|
i::FLAG_log = true; \
|
|
i::FLAG_prof = true; \
|
|
i::FLAG_logfile = i::Log::kLogToTemporaryFile; \
|
|
i::FLAG_logfile_per_isolate = false
|
|
|
|
static const char* StrNStr(const char* s1, const char* s2, size_t n) {
|
|
CHECK_EQ(s1[n], '\0');
|
|
return strstr(s1, s2);
|
|
}
|
|
|
|
// Look for a log line which starts with {prefix} and ends with {suffix}.
|
|
static const char* FindLogLine(const char* start, const char* end,
|
|
const char* prefix,
|
|
const char* suffix = nullptr) {
|
|
CHECK_LT(start, end);
|
|
CHECK_EQ(end[0], '\0');
|
|
size_t prefixLength = strlen(prefix);
|
|
// Loop through the input until we find /{prefix}[^\n]+{suffix}/.
|
|
while (start < end) {
|
|
const char* prefixResult = strstr(start, prefix);
|
|
if (!prefixResult) return NULL;
|
|
if (suffix == nullptr) return prefixResult;
|
|
const char* suffixResult =
|
|
StrNStr(prefixResult, suffix, (end - prefixResult));
|
|
if (!suffixResult) return NULL;
|
|
// Check that there are no newlines in between the {prefix} and the {suffix}
|
|
// results.
|
|
const char* newlineResult =
|
|
StrNStr(prefixResult, "\n", (end - prefixResult));
|
|
if (!newlineResult) return prefixResult;
|
|
if (newlineResult > suffixResult) return prefixResult;
|
|
start = prefixResult + prefixLength;
|
|
}
|
|
return NULL;
|
|
}
|
|
|
|
class ScopedLoggerInitializer {
|
|
public:
|
|
ScopedLoggerInitializer(bool saved_log, bool saved_prof, v8::Isolate* isolate)
|
|
: saved_log_(saved_log),
|
|
saved_prof_(saved_prof),
|
|
temp_file_(nullptr),
|
|
isolate_(isolate),
|
|
isolate_scope_(isolate),
|
|
scope_(isolate),
|
|
env_(v8::Context::New(isolate)),
|
|
logger_(reinterpret_cast<i::Isolate*>(isolate)->logger()) {
|
|
env_->Enter();
|
|
}
|
|
|
|
~ScopedLoggerInitializer() {
|
|
env_->Exit();
|
|
logger_->TearDown();
|
|
if (temp_file_ != nullptr) fclose(temp_file_);
|
|
i::FLAG_prof = saved_prof_;
|
|
i::FLAG_log = saved_log_;
|
|
}
|
|
|
|
v8::Local<v8::Context>& env() { return env_; }
|
|
|
|
v8::Isolate* isolate() { return isolate_; }
|
|
|
|
i::Isolate* i_isolate() { return reinterpret_cast<i::Isolate*>(isolate()); }
|
|
|
|
Logger* logger() { return logger_; }
|
|
|
|
void PrintLog(int requested_nof_lines = 0, const char* start = nullptr) {
|
|
if (requested_nof_lines <= 0) {
|
|
printf("%s", log_.c_str());
|
|
return;
|
|
}
|
|
// Try to print the last {requested_nof_lines} of the log.
|
|
if (start == nullptr) start = log_.c_str();
|
|
const char* current = start + log_.length();
|
|
int nof_lines = requested_nof_lines;
|
|
while (current > start && nof_lines > 0) {
|
|
current--;
|
|
if (*current == '\n') nof_lines--;
|
|
}
|
|
printf(
|
|
"======================================================\n"
|
|
"Last %i log lines:\n"
|
|
"======================================================\n"
|
|
"...\n%s\n"
|
|
"======================================================\n",
|
|
requested_nof_lines, current);
|
|
}
|
|
|
|
v8::Local<v8::String> GetLogString() {
|
|
int length = static_cast<int>(log_.size());
|
|
return v8::String::NewFromUtf8(isolate_, log_.c_str(),
|
|
v8::NewStringType::kNormal, length)
|
|
.ToLocalChecked();
|
|
}
|
|
|
|
void StopLogging() {
|
|
bool exists = false;
|
|
log_ = i::ReadFile(StopLoggingGetTempFile(), &exists, true);
|
|
CHECK(exists);
|
|
}
|
|
|
|
const char* GetEndPosition() { return log_.c_str() + log_.size(); }
|
|
|
|
const char* FindLine(const char* prefix, const char* suffix = nullptr,
|
|
const char* start = nullptr) {
|
|
// Make sure that StopLogging() has been called before.
|
|
CHECK(log_.size());
|
|
if (start == nullptr) start = log_.c_str();
|
|
const char* end = GetEndPosition();
|
|
return FindLogLine(start, end, prefix, suffix);
|
|
}
|
|
|
|
// Find all log lines specified by the {prefix, suffix} pairs and ensure they
|
|
// occurr in the specified order.
|
|
void FindLogLines(const char* pairs[][2], size_t limit,
|
|
const char* start = nullptr) {
|
|
const char* prefix = pairs[0][0];
|
|
const char* suffix = pairs[0][1];
|
|
const char* last_position = FindLine(prefix, suffix, start);
|
|
if (last_position == nullptr) {
|
|
PrintLog(100, start);
|
|
V8_Fatal(__FILE__, __LINE__, "Could not find log line: %s ... %s", prefix,
|
|
suffix);
|
|
}
|
|
CHECK(last_position);
|
|
for (size_t i = 1; i < limit; i++) {
|
|
prefix = pairs[i][0];
|
|
suffix = pairs[i][1];
|
|
const char* position = FindLine(prefix, suffix, start);
|
|
if (position == nullptr) {
|
|
PrintLog(100, start);
|
|
V8_Fatal(__FILE__, __LINE__, "Could not find log line: %s ... %s",
|
|
prefix, suffix);
|
|
}
|
|
// Check that all string positions are in order.
|
|
if (position <= last_position) {
|
|
PrintLog(100, start);
|
|
V8_Fatal(__FILE__, __LINE__,
|
|
"Log statements not in expected order (prev=%p, current=%p): "
|
|
"%s ... %s",
|
|
reinterpret_cast<const void*>(last_position),
|
|
reinterpret_cast<const void*>(position), prefix, suffix);
|
|
}
|
|
last_position = position;
|
|
}
|
|
}
|
|
|
|
void LogCompiledFunctions() { logger_->LogCompiledFunctions(); }
|
|
|
|
void StringEvent(const char* name, const char* value) {
|
|
logger_->StringEvent(name, value);
|
|
}
|
|
|
|
void ExtractAllAddresses(std::unordered_set<uintptr_t>* map,
|
|
const char* prefix, int field_index) {
|
|
// Make sure that StopLogging() has been called before.
|
|
CHECK(log_.size());
|
|
const char* current = log_.c_str();
|
|
while (current != nullptr) {
|
|
current = FindLine(prefix, nullptr, current);
|
|
if (current == nullptr) return;
|
|
// Find token number {index}.
|
|
const char* previous;
|
|
for (int i = 0; i <= field_index; i++) {
|
|
previous = current;
|
|
current = strchr(current + 1, ',');
|
|
if (current == nullptr) break;
|
|
// Skip the comma.
|
|
current++;
|
|
}
|
|
if (current == nullptr) break;
|
|
uintptr_t address = strtoll(previous, nullptr, 16);
|
|
CHECK_LT(0, address);
|
|
map->insert(address);
|
|
}
|
|
}
|
|
|
|
private:
|
|
FILE* StopLoggingGetTempFile() {
|
|
temp_file_ = logger_->TearDown();
|
|
CHECK(temp_file_);
|
|
fflush(temp_file_);
|
|
rewind(temp_file_);
|
|
return temp_file_;
|
|
}
|
|
|
|
const bool saved_log_;
|
|
const bool saved_prof_;
|
|
FILE* temp_file_;
|
|
v8::Isolate* isolate_;
|
|
v8::Isolate::Scope isolate_scope_;
|
|
v8::HandleScope scope_;
|
|
v8::Local<v8::Context> env_;
|
|
Logger* logger_;
|
|
std::string log_;
|
|
|
|
DISALLOW_COPY_AND_ASSIGN(ScopedLoggerInitializer);
|
|
};
|
|
|
|
class TestCodeEventHandler : public v8::CodeEventHandler {
|
|
public:
|
|
explicit TestCodeEventHandler(v8::Isolate* isolate)
|
|
: v8::CodeEventHandler(isolate), isolate_(isolate) {}
|
|
|
|
size_t CountLines(std::string prefix, std::string suffix = std::string()) {
|
|
if (!log_.length()) return 0;
|
|
|
|
std::regex expression("(^|\\n)" + prefix + ".*" + suffix + "(?=\\n|$)");
|
|
|
|
size_t match_count(std::distance(
|
|
std::sregex_iterator(log_.begin(), log_.end(), expression),
|
|
std::sregex_iterator()));
|
|
|
|
return match_count;
|
|
}
|
|
|
|
void Handle(v8::CodeEvent* code_event) override {
|
|
std::string log_line = "";
|
|
log_line += v8::CodeEvent::GetCodeEventTypeName(code_event->GetCodeType());
|
|
log_line += " ";
|
|
log_line += FormatName(code_event);
|
|
log_line += "\n";
|
|
log_ += log_line;
|
|
}
|
|
|
|
private:
|
|
std::string FormatName(v8::CodeEvent* code_event) {
|
|
std::string name = std::string(code_event->GetComment());
|
|
if (name.empty()) {
|
|
v8::Local<v8::String> functionName = code_event->GetFunctionName();
|
|
std::string buffer(functionName->Utf8Length(isolate_) + 1, 0);
|
|
functionName->WriteUtf8(isolate_, &buffer[0],
|
|
functionName->Utf8Length(isolate_) + 1);
|
|
// Sanitize name, removing unwanted \0 resulted from WriteUtf8
|
|
name = std::string(buffer.c_str());
|
|
}
|
|
|
|
return name;
|
|
}
|
|
|
|
std::string log_;
|
|
v8::Isolate* isolate_;
|
|
};
|
|
|
|
} // namespace
|
|
|
|
TEST(FindLogLine) {
|
|
const char* string =
|
|
"prefix1, stuff, suffix1\n"
|
|
"prefix2, stuff\n, suffix2\n"
|
|
"prefix3suffix3\n"
|
|
"prefix4 suffix4";
|
|
const char* end = string + strlen(string);
|
|
// Make sure the vector contains the terminating \0 character.
|
|
CHECK(FindLogLine(string, end, "prefix1, stuff, suffix1"));
|
|
CHECK(FindLogLine(string, end, "prefix1, stuff"));
|
|
CHECK(FindLogLine(string, end, "prefix1"));
|
|
CHECK(FindLogLine(string, end, "prefix1", "suffix1"));
|
|
CHECK(FindLogLine(string, end, "prefix1", "suffix1"));
|
|
CHECK(!FindLogLine(string, end, "prefix2", "suffix2"));
|
|
CHECK(!FindLogLine(string, end, "prefix1", "suffix2"));
|
|
CHECK(!FindLogLine(string, end, "prefix1", "suffix3"));
|
|
CHECK(FindLogLine(string, end, "prefix3", "suffix3"));
|
|
CHECK(FindLogLine(string, end, "prefix4", "suffix4"));
|
|
CHECK(!FindLogLine(string, end, "prefix4", "suffix4XXXXXXXXXXXX"));
|
|
CHECK(
|
|
!FindLogLine(string, end, "prefix4XXXXXXXXXXXXXXXXXXXXXXxxx", "suffix4"));
|
|
CHECK(!FindLogLine(string, end, "suffix", "suffix5XXXXXXXXXXXXXXXXXXXX"));
|
|
}
|
|
|
|
// BUG(913). Need to implement support for profiling multiple VM threads.
|
|
#if 0
|
|
|
|
namespace {
|
|
|
|
class LoopingThread : public v8::internal::Thread {
|
|
public:
|
|
explicit LoopingThread(v8::internal::Isolate* isolate)
|
|
: v8::internal::Thread(isolate),
|
|
semaphore_(new v8::internal::Semaphore(0)),
|
|
run_(true) {
|
|
}
|
|
|
|
virtual ~LoopingThread() { delete semaphore_; }
|
|
|
|
void Run() {
|
|
self_ = pthread_self();
|
|
RunLoop();
|
|
}
|
|
|
|
void SendSigProf() { pthread_kill(self_, SIGPROF); }
|
|
|
|
void Stop() { run_ = false; }
|
|
|
|
bool WaitForRunning() { return semaphore_->Wait(1000000); }
|
|
|
|
protected:
|
|
bool IsRunning() { return run_; }
|
|
|
|
virtual void RunLoop() = 0;
|
|
|
|
void SetV8ThreadId() {
|
|
v8_thread_id_ = v8::V8::GetCurrentThreadId();
|
|
}
|
|
|
|
void SignalRunning() { semaphore_->Signal(); }
|
|
|
|
private:
|
|
v8::internal::Semaphore* semaphore_;
|
|
bool run_;
|
|
pthread_t self_;
|
|
int v8_thread_id_;
|
|
};
|
|
|
|
|
|
class LoopingJsThread : public LoopingThread {
|
|
public:
|
|
explicit LoopingJsThread(v8::internal::Isolate* isolate)
|
|
: LoopingThread(isolate) { }
|
|
void RunLoop() {
|
|
v8::Locker locker;
|
|
CHECK_NOT_NULL(CcTest::i_isolate());
|
|
CHECK_GT(CcTest::i_isolate()->thread_manager()->CurrentId(), 0);
|
|
SetV8ThreadId();
|
|
while (IsRunning()) {
|
|
v8::HandleScope scope;
|
|
v8::Persistent<v8::Context> context = v8::Context::New();
|
|
CHECK(!context.IsEmpty());
|
|
{
|
|
v8::Context::Scope context_scope(context);
|
|
SignalRunning();
|
|
CompileRun(
|
|
"var j; for (var i=0; i<10000; ++i) { j = Math.sin(i); }");
|
|
}
|
|
context.Dispose();
|
|
i::OS::Sleep(v8::base::TimeDelta::FromMilliseconds(1));
|
|
}
|
|
}
|
|
};
|
|
|
|
|
|
class LoopingNonJsThread : public LoopingThread {
|
|
public:
|
|
explicit LoopingNonJsThread(v8::internal::Isolate* isolate)
|
|
: LoopingThread(isolate) { }
|
|
void RunLoop() {
|
|
v8::Locker locker;
|
|
v8::Unlocker unlocker;
|
|
// Now thread has V8's id, but will not run VM code.
|
|
CHECK_NOT_NULL(CcTest::i_isolate());
|
|
CHECK_GT(CcTest::i_isolate()->thread_manager()->CurrentId(), 0);
|
|
double i = 10;
|
|
SignalRunning();
|
|
while (IsRunning()) {
|
|
i = std::sin(i);
|
|
i::OS::Sleep(v8::base::TimeDelta::FromMilliseconds(1));
|
|
}
|
|
}
|
|
};
|
|
|
|
|
|
class TestSampler : public v8::internal::Sampler {
|
|
public:
|
|
explicit TestSampler(v8::internal::Isolate* isolate)
|
|
: Sampler(isolate, 0, true, true),
|
|
semaphore_(new v8::internal::Semaphore(0)),
|
|
was_sample_stack_called_(false) {
|
|
}
|
|
|
|
~TestSampler() { delete semaphore_; }
|
|
|
|
void SampleStack(v8::internal::TickSample*) {
|
|
was_sample_stack_called_ = true;
|
|
}
|
|
|
|
void Tick(v8::internal::TickSample*) { semaphore_->Signal(); }
|
|
|
|
bool WaitForTick() { return semaphore_->Wait(1000000); }
|
|
|
|
void Reset() { was_sample_stack_called_ = false; }
|
|
|
|
bool WasSampleStackCalled() { return was_sample_stack_called_; }
|
|
|
|
private:
|
|
v8::internal::Semaphore* semaphore_;
|
|
bool was_sample_stack_called_;
|
|
};
|
|
|
|
|
|
} // namespace
|
|
|
|
TEST(ProfMultipleThreads) {
|
|
TestSampler* sampler = nullptr;
|
|
{
|
|
v8::Locker locker;
|
|
sampler = new TestSampler(CcTest::i_isolate());
|
|
sampler->Start();
|
|
CHECK(sampler->IsActive());
|
|
}
|
|
|
|
LoopingJsThread jsThread(CcTest::i_isolate());
|
|
jsThread.Start();
|
|
LoopingNonJsThread nonJsThread(CcTest::i_isolate());
|
|
nonJsThread.Start();
|
|
|
|
CHECK(!sampler->WasSampleStackCalled());
|
|
jsThread.WaitForRunning();
|
|
jsThread.SendSigProf();
|
|
CHECK(sampler->WaitForTick());
|
|
CHECK(sampler->WasSampleStackCalled());
|
|
sampler->Reset();
|
|
CHECK(!sampler->WasSampleStackCalled());
|
|
nonJsThread.WaitForRunning();
|
|
nonJsThread.SendSigProf();
|
|
CHECK(!sampler->WaitForTick());
|
|
CHECK(!sampler->WasSampleStackCalled());
|
|
sampler->Stop();
|
|
|
|
jsThread.Stop();
|
|
nonJsThread.Stop();
|
|
jsThread.Join();
|
|
nonJsThread.Join();
|
|
|
|
delete sampler;
|
|
}
|
|
|
|
#endif // __linux__
|
|
|
|
|
|
// Test for issue http://crbug.com/23768 in Chromium.
|
|
// Heap can contain scripts with already disposed external sources.
|
|
// We need to verify that LogCompiledFunctions doesn't crash on them.
|
|
namespace {
|
|
|
|
class SimpleExternalString : public v8::String::ExternalStringResource {
|
|
public:
|
|
explicit SimpleExternalString(const char* source)
|
|
: utf_source_(StrLength(source)) {
|
|
for (int i = 0; i < utf_source_.length(); ++i)
|
|
utf_source_[i] = source[i];
|
|
}
|
|
virtual ~SimpleExternalString() {}
|
|
virtual size_t length() const { return utf_source_.length(); }
|
|
virtual const uint16_t* data() const { return utf_source_.start(); }
|
|
private:
|
|
i::ScopedVector<uint16_t> utf_source_;
|
|
};
|
|
|
|
} // namespace
|
|
|
|
TEST(Issue23768) {
|
|
v8::HandleScope scope(CcTest::isolate());
|
|
v8::Local<v8::Context> env = v8::Context::New(CcTest::isolate());
|
|
env->Enter();
|
|
|
|
SimpleExternalString source_ext_str("(function ext() {})();");
|
|
v8::Local<v8::String> source =
|
|
v8::String::NewExternalTwoByte(CcTest::isolate(), &source_ext_str)
|
|
.ToLocalChecked();
|
|
// Script needs to have a name in order to trigger InitLineEnds execution.
|
|
v8::Local<v8::String> origin =
|
|
v8::String::NewFromUtf8(CcTest::isolate(), "issue-23768-test",
|
|
v8::NewStringType::kNormal)
|
|
.ToLocalChecked();
|
|
v8::Local<v8::Script> evil_script = CompileWithOrigin(source, origin);
|
|
CHECK(!evil_script.IsEmpty());
|
|
CHECK(!evil_script->Run(env).IsEmpty());
|
|
i::Handle<i::ExternalTwoByteString> i_source(
|
|
i::ExternalTwoByteString::cast(*v8::Utils::OpenHandle(*source)),
|
|
CcTest::i_isolate());
|
|
// This situation can happen if source was an external string disposed
|
|
// by its owner.
|
|
i_source->SetResource(CcTest::i_isolate(), nullptr);
|
|
|
|
// Must not crash.
|
|
CcTest::i_isolate()->logger()->LogCompiledFunctions();
|
|
}
|
|
|
|
|
|
static void ObjMethod1(const v8::FunctionCallbackInfo<v8::Value>& args) {
|
|
}
|
|
|
|
|
|
TEST(LogCallbacks) {
|
|
SETUP_FLAGS();
|
|
v8::Isolate::CreateParams create_params;
|
|
create_params.array_buffer_allocator = CcTest::array_buffer_allocator();
|
|
v8::Isolate* isolate = v8::Isolate::New(create_params);
|
|
{
|
|
ScopedLoggerInitializer logger(saved_log, saved_prof, isolate);
|
|
|
|
v8::Local<v8::FunctionTemplate> obj = v8::Local<v8::FunctionTemplate>::New(
|
|
isolate, v8::FunctionTemplate::New(isolate));
|
|
obj->SetClassName(v8_str("Obj"));
|
|
v8::Local<v8::ObjectTemplate> proto = obj->PrototypeTemplate();
|
|
v8::Local<v8::Signature> signature = v8::Signature::New(isolate, obj);
|
|
proto->Set(v8_str("method1"),
|
|
v8::FunctionTemplate::New(isolate, ObjMethod1,
|
|
v8::Local<v8::Value>(), signature),
|
|
static_cast<v8::PropertyAttribute>(v8::DontDelete));
|
|
|
|
logger.env()
|
|
->Global()
|
|
->Set(logger.env(), v8_str("Obj"),
|
|
obj->GetFunction(logger.env()).ToLocalChecked())
|
|
.FromJust();
|
|
CompileRun("Obj.prototype.method1.toString();");
|
|
|
|
logger.LogCompiledFunctions();
|
|
|
|
logger.StopLogging();
|
|
|
|
Address ObjMethod1_entry = reinterpret_cast<Address>(ObjMethod1);
|
|
#if USES_FUNCTION_DESCRIPTORS
|
|
ObjMethod1_entry = *FUNCTION_ENTRYPOINT_ADDRESS(ObjMethod1_entry);
|
|
#endif
|
|
i::EmbeddedVector<char, 100> ref_data;
|
|
i::SNPrintF(ref_data, ",0x%" V8PRIxPTR ",1,method1", ObjMethod1_entry);
|
|
CHECK(logger.FindLine("code-creation,Callback,-2,", ref_data.start()));
|
|
}
|
|
isolate->Dispose();
|
|
}
|
|
|
|
|
|
static void Prop1Getter(v8::Local<v8::String> property,
|
|
const v8::PropertyCallbackInfo<v8::Value>& info) {
|
|
}
|
|
|
|
static void Prop1Setter(v8::Local<v8::String> property,
|
|
v8::Local<v8::Value> value,
|
|
const v8::PropertyCallbackInfo<void>& info) {
|
|
}
|
|
|
|
static void Prop2Getter(v8::Local<v8::String> property,
|
|
const v8::PropertyCallbackInfo<v8::Value>& info) {
|
|
}
|
|
|
|
|
|
TEST(LogAccessorCallbacks) {
|
|
SETUP_FLAGS();
|
|
v8::Isolate::CreateParams create_params;
|
|
create_params.array_buffer_allocator = CcTest::array_buffer_allocator();
|
|
v8::Isolate* isolate = v8::Isolate::New(create_params);
|
|
{
|
|
ScopedLoggerInitializer logger(saved_log, saved_prof, isolate);
|
|
|
|
v8::Local<v8::FunctionTemplate> obj = v8::Local<v8::FunctionTemplate>::New(
|
|
isolate, v8::FunctionTemplate::New(isolate));
|
|
obj->SetClassName(v8_str("Obj"));
|
|
v8::Local<v8::ObjectTemplate> inst = obj->InstanceTemplate();
|
|
inst->SetAccessor(v8_str("prop1"), Prop1Getter, Prop1Setter);
|
|
inst->SetAccessor(v8_str("prop2"), Prop2Getter);
|
|
|
|
logger.logger()->LogAccessorCallbacks();
|
|
|
|
logger.StopLogging();
|
|
|
|
Address Prop1Getter_entry = reinterpret_cast<Address>(Prop1Getter);
|
|
#if USES_FUNCTION_DESCRIPTORS
|
|
Prop1Getter_entry = *FUNCTION_ENTRYPOINT_ADDRESS(Prop1Getter_entry);
|
|
#endif
|
|
EmbeddedVector<char, 100> prop1_getter_record;
|
|
i::SNPrintF(prop1_getter_record, ",0x%" V8PRIxPTR ",1,get prop1",
|
|
Prop1Getter_entry);
|
|
CHECK(logger.FindLine("code-creation,Callback,-2,",
|
|
prop1_getter_record.start()));
|
|
|
|
Address Prop1Setter_entry = reinterpret_cast<Address>(Prop1Setter);
|
|
#if USES_FUNCTION_DESCRIPTORS
|
|
Prop1Setter_entry = *FUNCTION_ENTRYPOINT_ADDRESS(Prop1Setter_entry);
|
|
#endif
|
|
EmbeddedVector<char, 100> prop1_setter_record;
|
|
i::SNPrintF(prop1_setter_record, ",0x%" V8PRIxPTR ",1,set prop1",
|
|
Prop1Setter_entry);
|
|
CHECK(logger.FindLine("code-creation,Callback,-2,",
|
|
prop1_setter_record.start()));
|
|
|
|
Address Prop2Getter_entry = reinterpret_cast<Address>(Prop2Getter);
|
|
#if USES_FUNCTION_DESCRIPTORS
|
|
Prop2Getter_entry = *FUNCTION_ENTRYPOINT_ADDRESS(Prop2Getter_entry);
|
|
#endif
|
|
EmbeddedVector<char, 100> prop2_getter_record;
|
|
i::SNPrintF(prop2_getter_record, ",0x%" V8PRIxPTR ",1,get prop2",
|
|
Prop2Getter_entry);
|
|
CHECK(logger.FindLine("code-creation,Callback,-2,",
|
|
prop2_getter_record.start()));
|
|
}
|
|
isolate->Dispose();
|
|
}
|
|
|
|
// Test that logging of code create / move events is equivalent to traversal of
|
|
// a resulting heap.
|
|
TEST(EquivalenceOfLoggingAndTraversal) {
|
|
// This test needs to be run on a "clean" V8 to ensure that snapshot log
|
|
// is loaded. This is always true when running using tools/test.py because
|
|
// it launches a new cctest instance for every test. To be sure that launching
|
|
// cctest manually also works, please be sure that no tests below
|
|
// are using V8.
|
|
|
|
// Start with profiling to capture all code events from the beginning.
|
|
SETUP_FLAGS();
|
|
v8::Isolate::CreateParams create_params;
|
|
create_params.array_buffer_allocator = CcTest::array_buffer_allocator();
|
|
v8::Isolate* isolate = v8::Isolate::New(create_params);
|
|
{
|
|
ScopedLoggerInitializer logger(saved_log, saved_prof, isolate);
|
|
|
|
// Compile and run a function that creates other functions.
|
|
CompileRun(
|
|
"(function f(obj) {\n"
|
|
" obj.test =\n"
|
|
" (function a(j) { return function b() { return j; } })(100);\n"
|
|
"})(this);");
|
|
logger.logger()->StopProfiler();
|
|
reinterpret_cast<i::Isolate*>(isolate)->heap()->CollectAllGarbage(
|
|
i::Heap::kMakeHeapIterableMask, i::GarbageCollectionReason::kTesting);
|
|
logger.StringEvent("test-logging-done", "");
|
|
|
|
// Iterate heap to find compiled functions, will write to log.
|
|
logger.LogCompiledFunctions();
|
|
logger.StringEvent("test-traversal-done", "");
|
|
|
|
logger.StopLogging();
|
|
|
|
v8::Local<v8::String> log_str = logger.GetLogString();
|
|
logger.env()
|
|
->Global()
|
|
->Set(logger.env(), v8_str("_log"), log_str)
|
|
.FromJust();
|
|
|
|
// Load the Test snapshot's sources, see log-eq-of-logging-and-traversal.js
|
|
i::Vector<const char> source =
|
|
i::NativesCollection<i::TEST>::GetScriptsSource();
|
|
v8::Local<v8::String> source_str =
|
|
v8::String::NewFromUtf8(isolate, source.start(),
|
|
v8::NewStringType::kNormal, source.length())
|
|
.ToLocalChecked();
|
|
v8::TryCatch try_catch(isolate);
|
|
v8::Local<v8::Script> script = CompileWithOrigin(source_str, "");
|
|
if (script.IsEmpty()) {
|
|
v8::String::Utf8Value exception(isolate, try_catch.Exception());
|
|
FATAL("compile: %s\n", *exception);
|
|
}
|
|
v8::Local<v8::Value> result;
|
|
if (!script->Run(logger.env()).ToLocal(&result)) {
|
|
v8::String::Utf8Value exception(isolate, try_catch.Exception());
|
|
FATAL("run: %s\n", *exception);
|
|
}
|
|
// The result either be the "true" literal or problem description.
|
|
if (!result->IsTrue()) {
|
|
v8::Local<v8::String> s = result->ToString(logger.env()).ToLocalChecked();
|
|
i::ScopedVector<char> data(s->Utf8Length(isolate) + 1);
|
|
CHECK(data.start());
|
|
s->WriteUtf8(isolate, data.start());
|
|
FATAL("%s\n", data.start());
|
|
}
|
|
}
|
|
isolate->Dispose();
|
|
}
|
|
|
|
|
|
TEST(LogVersion) {
|
|
SETUP_FLAGS();
|
|
v8::Isolate::CreateParams create_params;
|
|
create_params.array_buffer_allocator = CcTest::array_buffer_allocator();
|
|
v8::Isolate* isolate = v8::Isolate::New(create_params);
|
|
{
|
|
ScopedLoggerInitializer logger(saved_log, saved_prof, isolate);
|
|
logger.StopLogging();
|
|
|
|
i::EmbeddedVector<char, 100> ref_data;
|
|
i::SNPrintF(ref_data, "%d,%d,%d,%d,%d", i::Version::GetMajor(),
|
|
i::Version::GetMinor(), i::Version::GetBuild(),
|
|
i::Version::GetPatch(), i::Version::IsCandidate());
|
|
CHECK(logger.FindLine("v8-version,", ref_data.start()));
|
|
}
|
|
isolate->Dispose();
|
|
}
|
|
|
|
|
|
// https://crbug.com/539892
|
|
// CodeCreateEvents with really large names should not crash.
|
|
TEST(Issue539892) {
|
|
class FakeCodeEventLogger : public i::CodeEventLogger {
|
|
public:
|
|
explicit FakeCodeEventLogger(i::Isolate* isolate)
|
|
: CodeEventLogger(isolate) {}
|
|
|
|
void CodeMoveEvent(i::AbstractCode* from, i::AbstractCode* to) override {}
|
|
void CodeDisableOptEvent(i::AbstractCode* code,
|
|
i::SharedFunctionInfo* shared) override {}
|
|
|
|
private:
|
|
void LogRecordedBuffer(i::AbstractCode* code, i::SharedFunctionInfo* shared,
|
|
const char* name, int length) override {}
|
|
void LogRecordedBuffer(const i::wasm::WasmCode* code, const char* name,
|
|
int length) override {}
|
|
} code_event_logger(CcTest::i_isolate());
|
|
SETUP_FLAGS();
|
|
v8::Isolate::CreateParams create_params;
|
|
create_params.array_buffer_allocator = CcTest::array_buffer_allocator();
|
|
v8::Isolate* isolate = v8::Isolate::New(create_params);
|
|
|
|
{
|
|
ScopedLoggerInitializer logger(saved_log, saved_prof, isolate);
|
|
logger.logger()->AddCodeEventListener(&code_event_logger);
|
|
|
|
// Function with a really large name.
|
|
const char* source_text =
|
|
"(function "
|
|
"baaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa"
|
|
"aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa"
|
|
"aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa"
|
|
"aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa"
|
|
"aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa"
|
|
"aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa"
|
|
"aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa"
|
|
"aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa"
|
|
"aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa"
|
|
"aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa"
|
|
"aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa"
|
|
"aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa"
|
|
"aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa"
|
|
"aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa"
|
|
"aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa"
|
|
"aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa"
|
|
"aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaac"
|
|
"(){})();";
|
|
|
|
CompileRun(source_text);
|
|
|
|
// Must not crash.
|
|
logger.LogCompiledFunctions();
|
|
}
|
|
isolate->Dispose();
|
|
}
|
|
|
|
TEST(LogAll) {
|
|
SETUP_FLAGS();
|
|
i::FLAG_log_all = true;
|
|
v8::Isolate::CreateParams create_params;
|
|
create_params.array_buffer_allocator = CcTest::array_buffer_allocator();
|
|
v8::Isolate* isolate = v8::Isolate::New(create_params);
|
|
|
|
{
|
|
ScopedLoggerInitializer logger(saved_log, saved_prof, isolate);
|
|
|
|
// Function that will
|
|
const char* source_text =
|
|
"function testAddFn(a,b) { return a + b };"
|
|
"let result;"
|
|
"for (let i = 0; i < 100000; i++) { result = testAddFn(i, i); };"
|
|
"testAddFn('1', 1);"
|
|
"for (let i = 0; i < 100000; i++) { result = testAddFn('1', i); }";
|
|
CompileRun(source_text);
|
|
|
|
logger.StopLogging();
|
|
|
|
// We should find at least one code-creation even for testAddFn();
|
|
CHECK(logger.FindLine("api,v8::Context::New"));
|
|
CHECK(logger.FindLine("timer-event-start", "V8.CompileCode"));
|
|
CHECK(logger.FindLine("timer-event-end", "V8.CompileCode"));
|
|
CHECK(logger.FindLine("code-creation,Script", ":1:1"));
|
|
CHECK(logger.FindLine("api,v8::Script::Run"));
|
|
CHECK(logger.FindLine("code-creation,LazyCompile,", "testAddFn"));
|
|
if (i::FLAG_opt && !i::FLAG_always_opt) {
|
|
CHECK(logger.FindLine("code-deopt,", "soft"));
|
|
CHECK(logger.FindLine("timer-event-start", "V8.DeoptimizeCode"));
|
|
CHECK(logger.FindLine("timer-event-end", "V8.DeoptimizeCode"));
|
|
}
|
|
}
|
|
isolate->Dispose();
|
|
}
|
|
|
|
TEST(LogInterpretedFramesNativeStack) {
|
|
SETUP_FLAGS();
|
|
i::FLAG_interpreted_frames_native_stack = true;
|
|
v8::Isolate::CreateParams create_params;
|
|
create_params.array_buffer_allocator = CcTest::array_buffer_allocator();
|
|
v8::Isolate* isolate = v8::Isolate::New(create_params);
|
|
|
|
{
|
|
ScopedLoggerInitializer logger(saved_log, saved_prof, isolate);
|
|
|
|
const char* source_text =
|
|
"function testLogInterpretedFramesNativeStack(a,b) { return a + b };"
|
|
"testLogInterpretedFramesNativeStack('1', 1);";
|
|
CompileRun(source_text);
|
|
|
|
logger.StopLogging();
|
|
|
|
CHECK(logger.FindLine("InterpretedFunction",
|
|
"testLogInterpretedFramesNativeStack"));
|
|
}
|
|
isolate->Dispose();
|
|
}
|
|
|
|
TEST(ExternalCodeEventListener) {
|
|
i::FLAG_log = false;
|
|
i::FLAG_prof = false;
|
|
|
|
v8::Isolate::CreateParams create_params;
|
|
create_params.array_buffer_allocator = CcTest::array_buffer_allocator();
|
|
v8::Isolate* isolate = v8::Isolate::New(create_params);
|
|
|
|
{
|
|
v8::HandleScope scope(isolate);
|
|
v8::Isolate::Scope isolate_scope(isolate);
|
|
v8::Local<v8::Context> context = v8::Context::New(isolate);
|
|
context->Enter();
|
|
|
|
TestCodeEventHandler code_event_handler(isolate);
|
|
|
|
const char* source_text_before_start =
|
|
"function testCodeEventListenerBeforeStart(a,b) { return a + b };"
|
|
"testCodeEventListenerBeforeStart('1', 1);";
|
|
CompileRun(source_text_before_start);
|
|
|
|
CHECK_EQ(code_event_handler.CountLines("LazyCompile",
|
|
"testCodeEventListenerBeforeStart"),
|
|
0);
|
|
|
|
code_event_handler.Enable();
|
|
|
|
CHECK_GE(code_event_handler.CountLines("LazyCompile",
|
|
"testCodeEventListenerBeforeStart"),
|
|
1);
|
|
|
|
const char* source_text_after_start =
|
|
"function testCodeEventListenerAfterStart(a,b) { return a + b };"
|
|
"testCodeEventListenerAfterStart('1', 1);";
|
|
CompileRun(source_text_after_start);
|
|
|
|
CHECK_GE(code_event_handler.CountLines("LazyCompile",
|
|
"testCodeEventListenerAfterStart"),
|
|
1);
|
|
|
|
context->Exit();
|
|
}
|
|
isolate->Dispose();
|
|
}
|
|
|
|
TEST(ExternalCodeEventListenerWithInterpretedFramesNativeStack) {
|
|
i::FLAG_log = false;
|
|
i::FLAG_prof = false;
|
|
i::FLAG_interpreted_frames_native_stack = true;
|
|
|
|
v8::Isolate::CreateParams create_params;
|
|
create_params.array_buffer_allocator = CcTest::array_buffer_allocator();
|
|
v8::Isolate* isolate = v8::Isolate::New(create_params);
|
|
|
|
{
|
|
v8::HandleScope scope(isolate);
|
|
v8::Isolate::Scope isolate_scope(isolate);
|
|
v8::Local<v8::Context> context = v8::Context::New(isolate);
|
|
context->Enter();
|
|
|
|
TestCodeEventHandler code_event_handler(isolate);
|
|
|
|
const char* source_text_before_start =
|
|
"function testCodeEventListenerBeforeStart(a,b) { return a + b };"
|
|
"testCodeEventListenerBeforeStart('1', 1);";
|
|
CompileRun(source_text_before_start);
|
|
|
|
CHECK_EQ(code_event_handler.CountLines("InterpretedFunction",
|
|
"testCodeEventListenerBeforeStart"),
|
|
0);
|
|
|
|
code_event_handler.Enable();
|
|
|
|
CHECK_GE(code_event_handler.CountLines("InterpretedFunction",
|
|
"testCodeEventListenerBeforeStart"),
|
|
1);
|
|
|
|
const char* source_text_after_start =
|
|
"function testCodeEventListenerAfterStart(a,b) { return a + b };"
|
|
"testCodeEventListenerAfterStart('1', 1);";
|
|
CompileRun(source_text_after_start);
|
|
|
|
CHECK_GE(code_event_handler.CountLines("InterpretedFunction",
|
|
"testCodeEventListenerAfterStart"),
|
|
1);
|
|
|
|
CHECK_EQ(
|
|
code_event_handler.CountLines("Builtin", "InterpreterEntryTrampoline"),
|
|
1);
|
|
|
|
context->Exit();
|
|
}
|
|
isolate->Dispose();
|
|
}
|
|
|
|
TEST(TraceMaps) {
|
|
SETUP_FLAGS();
|
|
i::FLAG_trace_maps = true;
|
|
v8::Isolate::CreateParams create_params;
|
|
create_params.array_buffer_allocator = CcTest::array_buffer_allocator();
|
|
v8::Isolate* isolate = v8::Isolate::New(create_params);
|
|
{
|
|
ScopedLoggerInitializer logger(saved_log, saved_prof, isolate);
|
|
// Try to create many different kind of maps to make sure the logging won't
|
|
// crash. More detailed tests are implemented separately.
|
|
const char* source_text =
|
|
"let a = {};"
|
|
"for (let i = 0; i < 500; i++) { a['p'+i] = i };"
|
|
"class Test { constructor(i) { this.a = 1; this['p'+i] = 1; }};"
|
|
"let t = new Test();"
|
|
"t.b = 1; t.c = 1; t.d = 3;"
|
|
"for (let i = 0; i < 100; i++) { t = new Test(i) };"
|
|
"t.b = {};";
|
|
CompileRun(source_text);
|
|
|
|
logger.StopLogging();
|
|
|
|
// Mostly superficial checks.
|
|
CHECK(logger.FindLine("map,InitialMap", ",0x"));
|
|
CHECK(logger.FindLine("map,Transition", ",0x"));
|
|
CHECK(logger.FindLine("map-details", ",0x"));
|
|
}
|
|
i::FLAG_trace_maps = false;
|
|
isolate->Dispose();
|
|
}
|
|
|
|
TEST(LogMaps) {
|
|
// Test that all Map details from Maps in the snapshot are logged properly.
|
|
SETUP_FLAGS();
|
|
i::FLAG_trace_maps = true;
|
|
v8::Isolate::CreateParams create_params;
|
|
create_params.array_buffer_allocator = CcTest::array_buffer_allocator();
|
|
v8::Isolate* isolate = v8::Isolate::New(create_params);
|
|
{
|
|
ScopedLoggerInitializer logger(saved_log, saved_prof, isolate);
|
|
logger.StopLogging();
|
|
// Extract all the map-detail entry addresses from the log.
|
|
std::unordered_set<uintptr_t> map_addresses;
|
|
logger.ExtractAllAddresses(&map_addresses, "map-details", 2);
|
|
i::Heap* heap = reinterpret_cast<i::Isolate*>(isolate)->heap();
|
|
i::HeapIterator iterator(heap);
|
|
i::DisallowHeapAllocation no_gc;
|
|
|
|
// Iterate over all maps on the heap.
|
|
size_t i = 0;
|
|
for (i::HeapObject* obj = iterator.next(); obj != nullptr;
|
|
obj = iterator.next()) {
|
|
i++;
|
|
if (!obj->IsMap()) continue;
|
|
uintptr_t address = reinterpret_cast<uintptr_t>(obj);
|
|
if (map_addresses.find(address) != map_addresses.end()) continue;
|
|
logger.PrintLog(200);
|
|
i::Map::cast(obj)->Print();
|
|
V8_Fatal(__FILE__, __LINE__,
|
|
"Map (%p, #%zu) was not logged during startup with --trace-maps!"
|
|
"\n# Expected Log Line: map_details, ... %p"
|
|
"\n# Use logger::PrintLog() for more details.",
|
|
reinterpret_cast<void*>(obj), i, reinterpret_cast<void*>(obj));
|
|
}
|
|
logger.PrintLog(200);
|
|
}
|
|
i::FLAG_log_function_events = false;
|
|
isolate->Dispose();
|
|
}
|
|
|
|
TEST(ConsoleTimeEvents) {
|
|
SETUP_FLAGS();
|
|
v8::Isolate::CreateParams create_params;
|
|
create_params.array_buffer_allocator = CcTest::array_buffer_allocator();
|
|
v8::Isolate* isolate = v8::Isolate::New(create_params);
|
|
{
|
|
ScopedLoggerInitializer logger(saved_log, saved_prof, isolate);
|
|
// Test that console time events are properly logged
|
|
const char* source_text =
|
|
"console.time();"
|
|
"console.timeEnd();"
|
|
"console.timeStamp();"
|
|
"console.time('timerEvent1');"
|
|
"console.timeEnd('timerEvent1');"
|
|
"console.timeStamp('timerEvent2');"
|
|
"console.timeStamp('timerEvent3');";
|
|
CompileRun(source_text);
|
|
|
|
logger.StopLogging();
|
|
|
|
const char* pairs[][2] = {{"timer-event-start,default,", nullptr},
|
|
{"timer-event-end,default,", nullptr},
|
|
{"timer-event,default,", nullptr},
|
|
{"timer-event-start,timerEvent1,", nullptr},
|
|
{"timer-event-end,timerEvent1,", nullptr},
|
|
{"timer-event,timerEvent2,", nullptr},
|
|
{"timer-event,timerEvent3,", nullptr}};
|
|
logger.FindLogLines(pairs, arraysize(pairs));
|
|
}
|
|
|
|
isolate->Dispose();
|
|
}
|
|
|
|
TEST(LogFunctionEvents) {
|
|
// Always opt and stress opt will break the fine-grained log order.
|
|
if (i::FLAG_always_opt) return;
|
|
|
|
SETUP_FLAGS();
|
|
i::FLAG_log_function_events = true;
|
|
v8::Isolate::CreateParams create_params;
|
|
create_params.array_buffer_allocator = CcTest::array_buffer_allocator();
|
|
v8::Isolate* isolate = v8::Isolate::New(create_params);
|
|
|
|
{
|
|
ScopedLoggerInitializer logger(saved_log, saved_prof, isolate);
|
|
|
|
// Run some warmup code to help ignoring existing log entries.
|
|
CompileRun(
|
|
"function warmUp(a) {"
|
|
" let b = () => 1;"
|
|
" return function(c) { return a+b+c; };"
|
|
"};"
|
|
"warmUp(1)(2);"
|
|
"(function warmUpEndMarkerFunction(){})();");
|
|
|
|
const char* source_text =
|
|
"function lazyNotExecutedFunction() { return 'lazy' };"
|
|
"function lazyFunction() { "
|
|
" function lazyInnerFunction() { return 'lazy' };"
|
|
" return lazyInnerFunction;"
|
|
"};"
|
|
"let innerFn = lazyFunction();"
|
|
"innerFn();"
|
|
"(function eagerFunction(){ return 'eager' })();"
|
|
"function Foo() { this.foo = function(){}; };"
|
|
"let i = new Foo(); i.foo();";
|
|
CompileRun(source_text);
|
|
|
|
logger.StopLogging();
|
|
|
|
// Ignore all the log entries that happened before warmup
|
|
const char* start =
|
|
logger.FindLine("function,first-execution", "warmUpEndMarkerFunction");
|
|
CHECK_NOT_NULL(start);
|
|
const char* pairs[][2] = {
|
|
// Create a new script
|
|
{"script,create", nullptr},
|
|
{"script-details", nullptr},
|
|
// Step 1: parsing top-level script, preparsing functions
|
|
{"function,preparse-", ",lazyNotExecutedFunction"},
|
|
// Missing name for preparsing lazyInnerFunction
|
|
// {"function,preparse-", nullptr},
|
|
{"function,preparse-", ",lazyFunction"},
|
|
{"function,full-parse,", ",eagerFunction"},
|
|
{"function,preparse-", ",Foo"},
|
|
// Missing name for inner preparsing of Foo.foo
|
|
// {"function,preparse-", nullptr},
|
|
// Missing name for top-level script.
|
|
{"function,parse-script,", nullptr},
|
|
|
|
// Step 2: compiling top-level script and eager functions
|
|
// - Compiling script without name.
|
|
{"function,compile,", nullptr},
|
|
{"function,compile,", ",eagerFunction"},
|
|
|
|
// Step 3: start executing script
|
|
// Step 4. - lazy parse, lazy compiling and execute skipped functions
|
|
// - execute eager functions.
|
|
{"function,parse-function,", ",lazyFunction"},
|
|
{"function,compile-lazy,", ",lazyFunction"},
|
|
{"function,first-execution,", ",lazyFunction"},
|
|
|
|
{"function,parse-function,", ",lazyInnerFunction"},
|
|
{"function,compile-lazy,", ",lazyInnerFunction"},
|
|
{"function,first-execution,", ",lazyInnerFunction"},
|
|
|
|
{"function,first-execution,", ",eagerFunction"},
|
|
|
|
{"function,parse-function,", ",Foo"},
|
|
{"function,compile-lazy,", ",Foo"},
|
|
{"function,first-execution,", ",Foo"},
|
|
|
|
{"function,parse-function,", ",Foo.foo"},
|
|
{"function,compile-lazy,", ",Foo.foo"},
|
|
{"function,first-execution,", ",Foo.foo"},
|
|
};
|
|
logger.FindLogLines(pairs, arraysize(pairs), start);
|
|
}
|
|
i::FLAG_log_function_events = false;
|
|
isolate->Dispose();
|
|
}
|