Commit 8bf237dd authored by Camillo Bruni's avatar Camillo Bruni Committed by Commit Bot

Revert "[test][d8] Add d8.log.getAndStop helper"

This reverts commit 95aa697b.

Reason for revert: breaks under tsan

Original change's description:
> [test][d8] Add d8.log.getAndStop helper
> 
> The new helper function allows us to write tests for log parsing
> without the need to first generating a log file. This makes it easier
> to spot errors when the log format changes.
> 
> - Add d8 global variable
> - Add file_name accessor to Logger and Log classes
> - Change OS::LogFileOpenMode to w+ / wb+
> - Use separate Log::WriteLogHeader method
> - Remove unused logger_ instance variable from Log
> 
> Bug: v8:10644
> Change-Id: Ifc7e35aa4e91b3f01f0847843263946e085944c3
> Reviewed-on: https://chromium-review.googlesource.com/c/v8/v8/+/2387563
> Commit-Queue: Camillo Bruni <cbruni@chromium.org>
> Reviewed-by: Michael Lippautz <mlippautz@chromium.org>
> Reviewed-by: Toon Verwaest <verwaest@chromium.org>
> Reviewed-by: Sathya Gunasekaran  <gsathya@chromium.org>
> Cr-Commit-Position: refs/heads/master@{#69715}

TBR=mlippautz@chromium.org,cbruni@chromium.org,gsathya@chromium.org,verwaest@chromium.org

Change-Id: Iad47d2f1e3391cae3c2f8c9e6c904c43925e1671
No-Presubmit: true
No-Tree-Checks: true
No-Try: true
Bug: v8:10644
Reviewed-on: https://chromium-review.googlesource.com/c/v8/v8/+/2396080Reviewed-by: 's avatarCamillo Bruni <cbruni@chromium.org>
Commit-Queue: Camillo Bruni <cbruni@chromium.org>
Cr-Commit-Position: refs/heads/master@{#69717}
parent 8e895596
...@@ -679,7 +679,9 @@ FILE* OS::OpenTemporaryFile() { ...@@ -679,7 +679,9 @@ FILE* OS::OpenTemporaryFile() {
return tmpfile(); return tmpfile();
} }
const char* const OS::LogFileOpenMode = "w+";
const char* const OS::LogFileOpenMode = "w";
void OS::Print(const char* format, ...) { void OS::Print(const char* format, ...) {
va_list args; va_list args;
......
...@@ -603,7 +603,8 @@ FILE* OS::OpenTemporaryFile() { ...@@ -603,7 +603,8 @@ FILE* OS::OpenTemporaryFile() {
// Open log file in binary mode to avoid /n -> /r/n conversion. // Open log file in binary mode to avoid /n -> /r/n conversion.
const char* const OS::LogFileOpenMode = "wb+"; const char* const OS::LogFileOpenMode = "wb";
// Print (debug) message to console. // Print (debug) message to console.
void OS::Print(const char* format, ...) { void OS::Print(const char* format, ...) {
......
This diff is collapsed.
...@@ -401,8 +401,6 @@ class Shell : public i::AllStatic { ...@@ -401,8 +401,6 @@ class Shell : public i::AllStatic {
static void RealmSharedSet(Local<String> property, Local<Value> value, static void RealmSharedSet(Local<String> property, Local<Value> value,
const PropertyCallbackInfo<void>& info); const PropertyCallbackInfo<void>& info);
static void LogGetAndStop(const v8::FunctionCallbackInfo<v8::Value>& args);
static void AsyncHooksCreateHook( static void AsyncHooksCreateHook(
const v8::FunctionCallbackInfo<v8::Value>& args); const v8::FunctionCallbackInfo<v8::Value>& args);
static void AsyncHooksExecutionAsyncId( static void AsyncHooksExecutionAsyncId(
...@@ -541,16 +539,7 @@ class Shell : public i::AllStatic { ...@@ -541,16 +539,7 @@ class Shell : public i::AllStatic {
static Local<String> Stringify(Isolate* isolate, Local<Value> value); static Local<String> Stringify(Isolate* isolate, Local<Value> value);
static void RunShell(Isolate* isolate); static void RunShell(Isolate* isolate);
static bool SetOptions(int argc, char* argv[]); static bool SetOptions(int argc, char* argv[]);
static Local<ObjectTemplate> CreateGlobalTemplate(Isolate* isolate); static Local<ObjectTemplate> CreateGlobalTemplate(Isolate* isolate);
static Local<ObjectTemplate> CreateOSTemplate(Isolate* isolate);
static Local<FunctionTemplate> CreateWorkerTemplate(Isolate* isolate);
static Local<ObjectTemplate> CreateAsyncHookTemplate(Isolate* isolate);
static Local<ObjectTemplate> CreateTestRunnerTemplate(Isolate* isolate);
static Local<ObjectTemplate> CreatePerformanceTemplate(Isolate* isolate);
static Local<ObjectTemplate> CreateRealmTemplate(Isolate* isolate);
static Local<ObjectTemplate> CreateD8Template(Isolate* isolate);
static MaybeLocal<Context> CreateRealm( static MaybeLocal<Context> CreateRealm(
const v8::FunctionCallbackInfo<v8::Value>& args, int index, const v8::FunctionCallbackInfo<v8::Value>& args, int index,
v8::MaybeLocal<Value> global_object); v8::MaybeLocal<Value> global_object);
......
...@@ -3077,8 +3077,7 @@ void Isolate::Deinit() { ...@@ -3077,8 +3077,7 @@ void Isolate::Deinit() {
cancelable_task_manager()->CancelAndWait(); cancelable_task_manager()->CancelAndWait();
heap_.TearDown(); heap_.TearDown();
FILE* logfile = logger_->TearDownAndGetLogFile(); logger_->TearDown();
if (logfile != nullptr) fclose(logfile);
if (wasm_engine_) { if (wasm_engine_) {
wasm_engine_->RemoveIsolate(this); wasm_engine_->RemoveIsolate(this);
......
...@@ -23,35 +23,25 @@ const char* const Log::kLogToTemporaryFile = "&"; ...@@ -23,35 +23,25 @@ const char* const Log::kLogToTemporaryFile = "&";
const char* const Log::kLogToConsole = "-"; const char* const Log::kLogToConsole = "-";
// static // static
FILE* Log::CreateOutputHandle(std::string file_name) { FILE* Log::CreateOutputHandle(const char* file_name) {
// If we're logging anything, we need to open the log file. // If we're logging anything, we need to open the log file.
if (!Log::InitLogAtStart()) { if (!Log::InitLogAtStart()) {
return nullptr; return nullptr;
} else if (Log::IsLoggingToConsole(file_name)) { } else if (strcmp(file_name, kLogToConsole) == 0) {
return stdout; return stdout;
} else if (Log::IsLoggingToTemporaryFile(file_name)) { } else if (strcmp(file_name, kLogToTemporaryFile) == 0) {
return base::OS::OpenTemporaryFile(); return base::OS::OpenTemporaryFile();
} else { } else {
return base::OS::FOpen(file_name.c_str(), base::OS::LogFileOpenMode); return base::OS::FOpen(file_name, base::OS::LogFileOpenMode);
} }
} }
// static Log::Log(Logger* logger, const char* file_name)
bool Log::IsLoggingToConsole(std::string file_name) { : output_handle_(Log::CreateOutputHandle(file_name)),
return file_name.compare(Log::kLogToConsole) == 0;
}
// static
bool Log::IsLoggingToTemporaryFile(std::string file_name) {
return file_name.compare(Log::kLogToTemporaryFile) == 0;
}
Log::Log(std::string file_name)
: file_name_(file_name),
output_handle_(Log::CreateOutputHandle(file_name)),
os_(output_handle_ == nullptr ? stdout : output_handle_), os_(output_handle_ == nullptr ? stdout : output_handle_),
is_enabled_(output_handle_ != nullptr), is_enabled_(output_handle_ != nullptr),
format_buffer_(NewArray<char>(kMessageBufferSize)) { format_buffer_(NewArray<char>(kMessageBufferSize)),
logger_(logger) {
// --log-all enables all the log flags. // --log-all enables all the log flags.
if (FLAG_log_all) { if (FLAG_log_all) {
FLAG_log_api = true; FLAG_log_api = true;
...@@ -66,13 +56,7 @@ Log::Log(std::string file_name) ...@@ -66,13 +56,7 @@ Log::Log(std::string file_name)
if (FLAG_prof) FLAG_log_code = true; if (FLAG_prof) FLAG_log_code = true;
if (output_handle_ == nullptr) return; if (output_handle_ == nullptr) return;
WriteLogHeader(); Log::MessageBuilder msg(this);
}
void Log::WriteLogHeader() {
std::unique_ptr<Log::MessageBuilder> msg_ptr = NewMessageBuilder();
if (!msg_ptr) return;
Log::MessageBuilder& msg = *msg_ptr.get();
LogSeparator kNext = LogSeparator::kSeparator; LogSeparator kNext = LogSeparator::kSeparator;
msg << "v8-version" << kNext << Version::GetMajor() << kNext msg << "v8-version" << kNext << Version::GetMajor() << kNext
<< Version::GetMinor() << kNext << Version::GetBuild() << kNext << Version::GetMinor() << kNext << Version::GetBuild() << kNext
...@@ -99,17 +83,20 @@ FILE* Log::Close() { ...@@ -99,17 +83,20 @@ FILE* Log::Close() {
base::MutexGuard guard(&mutex_); base::MutexGuard guard(&mutex_);
FILE* result = nullptr; FILE* result = nullptr;
if (output_handle_ != nullptr) { if (output_handle_ != nullptr) {
fflush(output_handle_); if (strcmp(FLAG_logfile, kLogToTemporaryFile) != 0) {
fclose(output_handle_);
} else {
result = output_handle_; result = output_handle_;
} }
}
output_handle_ = nullptr; output_handle_ = nullptr;
format_buffer_.reset(); format_buffer_.reset();
is_enabled_.store(false, std::memory_order_relaxed); is_enabled_.store(false, std::memory_order_relaxed);
return result; return result;
} }
std::string Log::file_name() const { return file_name_; }
Log::MessageBuilder::MessageBuilder(Log* log) Log::MessageBuilder::MessageBuilder(Log* log)
: log_(log), lock_guard_(&log_->mutex_) { : log_(log), lock_guard_(&log_->mutex_) {
DCHECK_NOT_NULL(log_->format_buffer_.get()); DCHECK_NOT_NULL(log_->format_buffer_.get());
......
...@@ -30,27 +30,22 @@ enum class LogSeparator { kSeparator }; ...@@ -30,27 +30,22 @@ enum class LogSeparator { kSeparator };
// Functions and data for performing output of log messages. // Functions and data for performing output of log messages.
class Log { class Log {
public: public:
explicit Log(std::string log_file_name); Log(Logger* log, const char* log_file_name);
static bool InitLogAtStart() { static bool InitLogAtStart() {
return FLAG_log || FLAG_log_all || FLAG_log_api || FLAG_log_code || return FLAG_log || FLAG_log_api || FLAG_log_code || FLAG_log_handles ||
FLAG_log_handles || FLAG_log_suspect || FLAG_ll_prof || FLAG_log_suspect || FLAG_ll_prof || FLAG_perf_basic_prof ||
FLAG_perf_basic_prof || FLAG_perf_prof || FLAG_log_source_code || FLAG_perf_prof || FLAG_log_source_code || FLAG_gdbjit ||
FLAG_gdbjit || FLAG_log_internal_timer_events || FLAG_prof_cpp || FLAG_log_internal_timer_events || FLAG_prof_cpp || FLAG_trace_ic ||
FLAG_trace_ic || FLAG_log_function_events || FLAG_trace_zone_stats || FLAG_log_function_events || FLAG_trace_zone_stats ||
FLAG_turbo_profiling_log_builtins; FLAG_turbo_profiling_log_builtins;
} }
V8_EXPORT_PRIVATE static bool IsLoggingToConsole(std::string file_name);
V8_EXPORT_PRIVATE static bool IsLoggingToTemporaryFile(std::string file_name);
// Frees all resources acquired in Initialize and Open... functions. // Frees all resources acquired in Initialize and Open... functions.
// When a temporary file is used for the log, returns its stream descriptor, // When a temporary file is used for the log, returns its stream descriptor,
// leaving the file open. // leaving the file open.
FILE* Close(); FILE* Close();
std::string file_name() const;
// Returns whether logging is enabled. // Returns whether logging is enabled.
bool IsEnabled() { return is_enabled_.load(std::memory_order_relaxed); } bool IsEnabled() { return is_enabled_.load(std::memory_order_relaxed); }
...@@ -114,15 +109,19 @@ class Log { ...@@ -114,15 +109,19 @@ class Log {
std::unique_ptr<Log::MessageBuilder> NewMessageBuilder(); std::unique_ptr<Log::MessageBuilder> NewMessageBuilder();
private: private:
static FILE* CreateOutputHandle(std::string file_name); static FILE* CreateOutputHandle(const char* file_name);
void WriteLogHeader(); // Implementation of writing to a log file.
int WriteToFile(const char* msg, int length) {
DCHECK_NOT_NULL(output_handle_);
os_.write(msg, length);
DCHECK(!os_.bad());
return length;
}
std::string file_name_;
// When logging is active output_handle_ is used to store a pointer to log // When logging is active output_handle_ is used to store a pointer to log
// destination. mutex_ should be acquired before using output_handle_. // destination. mutex_ should be acquired before using output_handle_.
FILE* output_handle_; FILE* output_handle_;
OFStream os_; OFStream os_;
// Stores whether logging is enabled. // Stores whether logging is enabled.
...@@ -135,6 +134,10 @@ class Log { ...@@ -135,6 +134,10 @@ class Log {
// Buffer used for formatting log messages. This is a singleton buffer and // Buffer used for formatting log messages. This is a singleton buffer and
// mutex_ should be acquired before using it. // mutex_ should be acquired before using it.
std::unique_ptr<char[]> format_buffer_; std::unique_ptr<char[]> format_buffer_;
Logger* logger_;
friend class Logger;
}; };
template <> template <>
......
...@@ -1974,13 +1974,16 @@ void Logger::LogAllMaps() { ...@@ -1974,13 +1974,16 @@ void Logger::LogAllMaps() {
} }
} }
static void AddIsolateIdIfNeeded(std::ostream& os, Isolate* isolate) { static void AddIsolateIdIfNeeded(std::ostream& os, // NOLINT
if (!FLAG_logfile_per_isolate) return; Isolate* isolate) {
os << "isolate-" << isolate << "-" << base::OS::GetCurrentProcessId() << "-"; if (FLAG_logfile_per_isolate) {
os << "isolate-" << isolate << "-" << base::OS::GetCurrentProcessId()
<< "-";
}
} }
static void PrepareLogFileName(std::ostream& os, Isolate* isolate, static void PrepareLogFileName(std::ostream& os, // NOLINT
const char* file_name) { Isolate* isolate, const char* file_name) {
int dir_separator_count = 0; int dir_separator_count = 0;
for (const char* p = file_name; *p; p++) { for (const char* p = file_name; *p; p++) {
if (base::OS::isDirectorySeparator(*p)) dir_separator_count++; if (base::OS::isDirectorySeparator(*p)) dir_separator_count++;
...@@ -2029,8 +2032,9 @@ bool Logger::SetUp(Isolate* isolate) { ...@@ -2029,8 +2032,9 @@ bool Logger::SetUp(Isolate* isolate) {
is_initialized_ = true; is_initialized_ = true;
std::ostringstream log_file_name; std::ostringstream log_file_name;
std::ostringstream source_log_file_name;
PrepareLogFileName(log_file_name, isolate, FLAG_logfile); PrepareLogFileName(log_file_name, isolate, FLAG_logfile);
log_ = std::make_unique<Log>(log_file_name.str()); log_ = std::make_unique<Log>(this, log_file_name.str().c_str());
#if V8_OS_LINUX #if V8_OS_LINUX
if (FLAG_perf_basic_prof) { if (FLAG_perf_basic_prof) {
...@@ -2059,7 +2063,9 @@ bool Logger::SetUp(Isolate* isolate) { ...@@ -2059,7 +2063,9 @@ bool Logger::SetUp(Isolate* isolate) {
ticker_ = std::make_unique<Ticker>(isolate, FLAG_prof_sampling_interval); ticker_ = std::make_unique<Ticker>(isolate, FLAG_prof_sampling_interval);
if (Log::InitLogAtStart()) is_logging_ = true; if (Log::InitLogAtStart()) {
is_logging_ = true;
}
timer_.Start(); timer_.Start();
...@@ -2069,7 +2075,9 @@ bool Logger::SetUp(Isolate* isolate) { ...@@ -2069,7 +2075,9 @@ bool Logger::SetUp(Isolate* isolate) {
profiler_->Engage(); profiler_->Engage();
} }
if (is_logging_) AddCodeEventListener(this); if (is_logging_) {
AddCodeEventListener(this);
}
return true; return true;
} }
...@@ -2096,7 +2104,6 @@ void Logger::SetCodeEventHandler(uint32_t options, ...@@ -2096,7 +2104,6 @@ void Logger::SetCodeEventHandler(uint32_t options,
} }
sampler::Sampler* Logger::sampler() { return ticker_.get(); } sampler::Sampler* Logger::sampler() { return ticker_.get(); }
std::string Logger::file_name() const { return log_.get()->file_name(); }
void Logger::StopProfilerThread() { void Logger::StopProfilerThread() {
if (profiler_ != nullptr) { if (profiler_ != nullptr) {
...@@ -2105,16 +2112,14 @@ void Logger::StopProfilerThread() { ...@@ -2105,16 +2112,14 @@ void Logger::StopProfilerThread() {
} }
} }
FILE* Logger::TearDownAndGetLogFile() { FILE* Logger::TearDown() {
if (!is_initialized_) return nullptr; if (!is_initialized_) return nullptr;
is_initialized_ = false; is_initialized_ = false;
is_logging_ = false;
// Stop the profiler thread before closing the file. // Stop the profiler thread before closing the file.
StopProfilerThread(); StopProfilerThread();
ticker_.reset(); ticker_.reset();
timer_.Stop();
#if V8_OS_LINUX #if V8_OS_LINUX
if (perf_basic_logger_) { if (perf_basic_logger_) {
......
...@@ -126,19 +126,18 @@ class Logger : public CodeEventListener { ...@@ -126,19 +126,18 @@ class Logger : public CodeEventListener {
// Acquires resources for logging if the right flags are set. // Acquires resources for logging if the right flags are set.
bool SetUp(Isolate* isolate); bool SetUp(Isolate* isolate);
// Frees resources acquired in SetUp.
// When a temporary file is used for the log, returns its stream descriptor,
// leaving the file open.
V8_EXPORT_PRIVATE FILE* TearDownAndGetLogFile();
// Sets the current code event handler. // Sets the current code event handler.
void SetCodeEventHandler(uint32_t options, JitCodeEventHandler event_handler); void SetCodeEventHandler(uint32_t options, JitCodeEventHandler event_handler);
sampler::Sampler* sampler(); sampler::Sampler* sampler();
V8_EXPORT_PRIVATE std::string file_name() const;
V8_EXPORT_PRIVATE void StopProfilerThread(); V8_EXPORT_PRIVATE void StopProfilerThread();
// Frees resources acquired in SetUp.
// When a temporary file is used for the log, returns its stream descriptor,
// leaving the file open.
V8_EXPORT_PRIVATE FILE* TearDown();
// Emits an event with a string value -> (name, value). // Emits an event with a string value -> (name, value).
V8_EXPORT_PRIVATE void StringEvent(const char* name, const char* value); V8_EXPORT_PRIVATE void StringEvent(const char* name, const char* value);
......
...@@ -83,8 +83,8 @@ class ScopedLoggerInitializer { ...@@ -83,8 +83,8 @@ class ScopedLoggerInitializer {
~ScopedLoggerInitializer() { ~ScopedLoggerInitializer() {
env_->Exit(); env_->Exit();
FILE* log_file = logger_->TearDownAndGetLogFile(); logger_->TearDown();
if (log_file != nullptr) fclose(log_file); if (temp_file_ != nullptr) fclose(temp_file_);
i::FLAG_prof = saved_prof_; i::FLAG_prof = saved_prof_;
i::FLAG_log = saved_log_; i::FLAG_log = saved_log_;
} }
...@@ -203,8 +203,9 @@ class ScopedLoggerInitializer { ...@@ -203,8 +203,9 @@ class ScopedLoggerInitializer {
private: private:
FILE* StopLoggingGetTempFile() { FILE* StopLoggingGetTempFile() {
temp_file_ = logger_->TearDownAndGetLogFile(); temp_file_ = logger_->TearDown();
CHECK(temp_file_); CHECK(temp_file_);
fflush(temp_file_);
rewind(temp_file_); rewind(temp_file_);
return temp_file_; return temp_file_;
} }
......
// Copyright 2020 the V8 project authors. All rights reserved.
// Use of this source code is governed by a BSD-style license that can be
// found in the LICENSE file.
// Flags: --log-all --log --no-stress-opt
function testFunctionWithFunnyName(o) {
return o.a;
}
(function testLoopWithFunnyName() {
const o = {a:1};
let result = 0;
for (let i = 0; i < 1000; i++) {
result += testFunctionWithFunnyName(o);
}
})();
const log = d8.log.getAndStop();
// Check that we have a minimally working log file.
assertTrue(log.length > 0);
assertTrue(log.indexOf('v8-version') == 0);
assertTrue(log.indexOf('testFunctionWithFunnyName') >= 10);
assertTrue(log.indexOf('testLoopWithFunnyName') >= 10);
Markdown is supported
0% or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment