AuroraMiddleware/v8
1
0
Fork 0
Code Issues 2 Pull Requests Releases Wiki Activity

[logging] Use OFStream for log events

Browse Source 
This simplifies a few operations and removes the size limitations
implied by the message buffer used.

Change-Id: I8b873a0ffa399a037ff5c2501ba4b68158810968
Reviewed-on: https://chromium-review.googlesource.com/724285
Commit-Queue: Camillo Bruni <cbruni@chromium.org>
Reviewed-by: Adam Klein <adamk@chromium.org>
Cr-Commit-Position: refs/heads/master@{#48766}
This commit is contained in:
Camillo Bruni 2017-10-20 01:02:08 +02:00 committed by Commit Bot
parent 831bc23303
commit 06ff9e974a
3 changed files with 306 additions and 415 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

246
src/log-utils.cc
View File

@ -18,15 +18,26 @@ namespace internal {
const char* const Log::kLogToTemporaryFile = "&"; const char* const Log::kLogToTemporaryFile = "&";
const char* const Log::kLogToConsole = "-"; const char* const Log::kLogToConsole = "-";
Log::Log(Logger* logger) // static
FILE* Log::CreateOutputHandle(const char* file_name) {
// If we're logging anything, we need to open the log file.
if (!Log::InitLogAtStart()) {
return nullptr;
} else if (strcmp(file_name, kLogToConsole) == 0) {
return stdout;
} else if (strcmp(file_name, kLogToTemporaryFile) == 0) {
return base::OS::OpenTemporaryFile();
} else {
return base::OS::FOpen(file_name, base::OS::LogFileOpenMode);
}
}
Log::Log(Logger* logger, const char* file_name)
: is_stopped_(false), : is_stopped_(false),
output_handle_(nullptr), output_handle_(Log::CreateOutputHandle(file_name)),
message_buffer_(nullptr), os_(output_handle_ == nullptr ? stdout : output_handle_),
logger_(logger) {} format_buffer_(NewArray<char>(kMessageBufferSize)),
logger_(logger) {
void Log::Initialize(const char* log_file_name) {
message_buffer_ = NewArray<char>(kMessageBufferSize);
// --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;
@ -40,51 +51,21 @@ void Log::Initialize(const char* log_file_name) {
// --prof implies --log-code. // --prof implies --log-code.
if (FLAG_prof) FLAG_log_code = true; if (FLAG_prof) FLAG_log_code = true;
// If we're logging anything, we need to open the log file. if (output_handle_ != nullptr) {
if (Log::InitLogAtStart()) { Log::MessageBuilder msg(this);
if (strcmp(log_file_name, kLogToConsole) == 0) { if (strlen(Version::GetEmbedder()) == 0) {
OpenStdout(); msg.Append("v8-version,%d,%d,%d,%d,%d", Version::GetMajor(),
} else if (strcmp(log_file_name, kLogToTemporaryFile) == 0) { Version::GetMinor(), Version::GetBuild(), Version::GetPatch(),
OpenTemporaryFile(); Version::IsCandidate());
} else { } else {
OpenFile(log_file_name); msg.Append("v8-version,%d,%d,%d,%d,%s,%d", Version::GetMajor(),
} Version::GetMinor(), Version::GetBuild(), Version::GetPatch(),
Version::GetEmbedder(), Version::IsCandidate());
if (output_handle_ != nullptr) {
Log::MessageBuilder msg(this);
if (strlen(Version::GetEmbedder()) == 0) {
msg.Append("v8-version,%d,%d,%d,%d,%d", Version::GetMajor(),
Version::GetMinor(), Version::GetBuild(),
Version::GetPatch(), Version::IsCandidate());
} else {
msg.Append("v8-version,%d,%d,%d,%d,%s,%d", Version::GetMajor(),
Version::GetMinor(), Version::GetBuild(),
Version::GetPatch(), Version::GetEmbedder(),
Version::IsCandidate());
}
msg.WriteToLogFile();
} }
msg.WriteToLogFile();
} }
} }
void Log::OpenStdout() {
DCHECK(!IsEnabled());
output_handle_ = stdout;
}
void Log::OpenTemporaryFile() {
DCHECK(!IsEnabled());
output_handle_ = base::OS::OpenTemporaryFile();
}
void Log::OpenFile(const char* name) {
DCHECK(!IsEnabled());
output_handle_ = base::OS::FOpen(name, base::OS::LogFileOpenMode);
}
FILE* Log::Close() { FILE* Log::Close() {
FILE* result = nullptr; FILE* result = nullptr;
if (output_handle_ != nullptr) { if (output_handle_ != nullptr) {
@ -96,74 +77,63 @@ FILE* Log::Close() {
} }
output_handle_ = nullptr; output_handle_ = nullptr;
DeleteArray(message_buffer_); DeleteArray(format_buffer_);
message_buffer_ = nullptr; format_buffer_ = nullptr;
is_stopped_ = false; is_stopped_ = false;
return result; return result;
} }
Log::MessageBuilder::MessageBuilder(Log* log) Log::MessageBuilder::MessageBuilder(Log* log)
: log_(log), : log_(log), lock_guard_(&log_->mutex_) {
lock_guard_(&log_->mutex_), DCHECK_NOT_NULL(log_->format_buffer_);
pos_(0) {
DCHECK_NOT_NULL(log_->message_buffer_);
} }
void Log::MessageBuilder::Append(const char* format, ...) { void Log::MessageBuilder::Append(const char* format, ...) {
Vector<char> buf(log_->message_buffer_ + pos_,
Log::kMessageBufferSize - pos_);
va_list args; va_list args;
va_start(args, format); va_start(args, format);
AppendVA(format, args); AppendVA(format, args);
va_end(args); va_end(args);
DCHECK_LE(pos_, Log::kMessageBufferSize);
} }
void Log::MessageBuilder::AppendVA(const char* format, va_list args) { void Log::MessageBuilder::AppendVA(const char* format, va_list args) {
Vector<char> buf(log_->message_buffer_ + pos_, Vector<char> buf(log_->format_buffer_, Log::kMessageBufferSize);
Log::kMessageBufferSize - pos_); int length = v8::internal::VSNPrintF(buf, format, args);
int result = v8::internal::VSNPrintF(buf, format, args); // {length} is -1 if output was truncated.
if (length == -1) {
// Result is -1 if output was truncated. length = Log::kMessageBufferSize;
if (result >= 0) {
pos_ += result;
} else {
pos_ = Log::kMessageBufferSize;
} }
DCHECK_LE(pos_, Log::kMessageBufferSize); DCHECK_LE(length, Log::kMessageBufferSize);
} AppendStringPart(log_->format_buffer_, length);
void Log::MessageBuilder::Append(const char c) {
if (pos_ < Log::kMessageBufferSize) {
log_->message_buffer_[pos_++] = c;
}
DCHECK_LE(pos_, Log::kMessageBufferSize);
} }
void Log::MessageBuilder::AppendDoubleQuotedString(const char* string) { void Log::MessageBuilder::AppendDoubleQuotedString(const char* string) {
Append('"'); OFStream& os = log_->os_;
// TODO(cbruni): unify escaping.
os << '"';
for (const char* p = string; *p != '\0'; p++) { for (const char* p = string; *p != '\0'; p++) {
if (*p == '"') { if (*p == '"') os << '\\';
Append('\\'); os << *p;
}
Append(*p);
} }
Append('"'); os << '"';
} }
void Log::MessageBuilder::AppendDoubleQuotedString(String* string) {
OFStream& os = log_->os_;
os << '"';
// TODO(cbruni): unify escaping.
AppendEscapedString(string);
os << '"';
}
void Log::MessageBuilder::Append(String* str) { void Log::MessageBuilder::Append(String* string) {
DisallowHeapAllocation no_gc; // Ensure string stay valid. DisallowHeapAllocation no_gc; // Ensure string stay valid.
int length = str->length(); std::unique_ptr<char[]> characters =
for (int i = 0; i < length; i++) { string->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
Append(static_cast<char>(str->Get(i))); log_->os_ << characters.get();
}
} }
void Log::MessageBuilder::AppendAddress(Address addr) { void Log::MessageBuilder::AppendAddress(Address addr) {
@ -172,109 +142,69 @@ void Log::MessageBuilder::AppendAddress(Address addr) {
void Log::MessageBuilder::AppendSymbolName(Symbol* symbol) { void Log::MessageBuilder::AppendSymbolName(Symbol* symbol) {
DCHECK(symbol); DCHECK(symbol);
Append("symbol("); OFStream& os = log_->os_;
os << "symbol(";
if (!symbol->name()->IsUndefined(symbol->GetIsolate())) { if (!symbol->name()->IsUndefined(symbol->GetIsolate())) {
Append("\""); os << "\"";
AppendDetailed(String::cast(symbol->name()), false); AppendDetailed(String::cast(symbol->name()), false);
Append("\" "); os << "\" ";
} }
Append("hash %x)", symbol->Hash()); os << "hash " << std::hex << symbol->Hash() << std::dec << ")";
} }
void Log::MessageBuilder::AppendDetailed(String* str, bool show_impl_info) { void Log::MessageBuilder::AppendDetailed(String* str, bool show_impl_info) {
if (str == nullptr) return; if (str == nullptr) return;
DisallowHeapAllocation no_gc; // Ensure string stay valid. DisallowHeapAllocation no_gc; // Ensure string stay valid.
OFStream& os = log_->os_;
int len = str->length(); int len = str->length();
if (len > 0x1000) if (len > 0x1000) len = 0x1000;
len = 0x1000;
if (show_impl_info) { if (show_impl_info) {
Append(str->IsOneByteRepresentation() ? 'a' : '2'); os << (str->IsOneByteRepresentation() ? 'a' : '2');
if (StringShape(str).IsExternal()) if (StringShape(str).IsExternal()) os << 'e';
Append('e'); if (StringShape(str).IsInternalized()) os << '#';
if (StringShape(str).IsInternalized()) os << ':' << str->length() << ':';
Append('#');
Append(":%i:", str->length());
}
for (int i = 0; i < len; i++) {
uc32 c = str->Get(i);
if (c > 0xff) {
Append("\\u%04x", c);
} else if (c < 32 || c > 126) {
Append("\\x%02x", c);
} else if (c == ',') {
Append("\\,");
} else if (c == '\\') {
Append("\\\\");
} else if (c == '\"') {
Append("\"\"");
} else {
Append("%lc", c);
}
} }
AppendEscapedString(str, len);
} }
void Log::MessageBuilder::AppendUnbufferedHeapString(String* str) { void Log::MessageBuilder::AppendEscapedString(String* str) {
if (str == nullptr) return; if (str == nullptr) return;
DisallowHeapAllocation no_gc; // Ensure string stay valid.
ScopedVector<char> buffer(16);
int len = str->length(); int len = str->length();
AppendEscapedString(str, len);
}
void Log::MessageBuilder::AppendEscapedString(String* str, int len) {
DCHECK_LE(len, str->length());
DisallowHeapAllocation no_gc; // Ensure string stay valid.
OFStream& os = log_->os_;
// TODO(cbruni): unify escaping.
for (int i = 0; i < len; i++) { for (int i = 0; i < len; i++) {
uc32 c = str->Get(i); uc32 c = str->Get(i);
if (c >= 32 && c <= 126) { if (c >= 32 && c <= 126) {
if (c == '\"') { if (c == '\"') {
AppendUnbufferedCString("\"\""); os << "\"\"";
} else if (c == '\\') { } else if (c == '\\') {
AppendUnbufferedCString("\\\\"); os << "\\\\";
} else if (c == ',') {
os << "\\,";
} else { } else {
AppendUnbufferedChar(c); os << static_cast<char>(c);
} }
} else if (c > 0xff) { } else if (c > 0xff) {
int length = v8::internal::SNPrintF(buffer, "\\u%04x", c); Append("\\u%04x", c);
DCHECK_EQ(6, length);
log_->WriteToFile(buffer.start(), length);
} else { } else {
DCHECK_LE(c, 0xffff); DCHECK(c < 32 || (c > 126 && c <= 0xff));
int length = v8::internal::SNPrintF(buffer, "\\x%02x", c); Append("\\x%02x", c);
DCHECK_EQ(4, length);
log_->WriteToFile(buffer.start(), length);
} }
} }
} }
void Log::MessageBuilder::AppendUnbufferedChar(char c) {
log_->WriteToFile(&c, 1);
}
void Log::MessageBuilder::AppendUnbufferedCString(const char* str) {
log_->WriteToFile(str, static_cast<int>(strlen(str)));
}
void Log::MessageBuilder::AppendStringPart(const char* str, int len) { void Log::MessageBuilder::AppendStringPart(const char* str, int len) {
if (pos_ + len > Log::kMessageBufferSize) { log_->os_.write(str, len);
len = Log::kMessageBufferSize - pos_;
DCHECK_GE(len, 0);
if (len == 0) return;
}
Vector<char> buf(log_->message_buffer_ + pos_,
Log::kMessageBufferSize - pos_);
StrNCpy(buf, str, len);
pos_ += len;
DCHECK_LE(pos_, Log::kMessageBufferSize);
} }
void Log::MessageBuilder::WriteToLogFile() { void Log::MessageBuilder::WriteToLogFile() { log_->os_ << std::endl; }
DCHECK_LE(pos_, Log::kMessageBufferSize);
// Assert that we do not already have a new line at the end.
DCHECK(pos_ == 0 || log_->message_buffer_[pos_ - 1] != '\n');
if (pos_ == Log::kMessageBufferSize) pos_--;
log_->message_buffer_[pos_++] = '\n';
const int written = log_->WriteToFile(log_->message_buffer_, pos_);
if (written != pos_) {
log_->stop();
log_->logger_->LogFailure();
}
}
} // namespace internal } // namespace internal
} // namespace v8 } // namespace v8

42
src/log-utils.h
View File

@ -13,6 +13,7 @@
#include "src/base/compiler-specific.h" #include "src/base/compiler-specific.h"
#include "src/base/platform/mutex.h" #include "src/base/platform/mutex.h"
#include "src/flags.h" #include "src/flags.h"
#include "src/ostreams.h"
namespace v8 { namespace v8 {
namespace internal { namespace internal {
@ -22,8 +23,7 @@ class Logger;
// Functions and data for performing output of log messages. // Functions and data for performing output of log messages.
class Log { class Log {
public: public:
// Performs process-wide initialization. Log(Logger* log, const char* log_file_name);
void Initialize(const char* log_file_name);
// Disables logging, but preserves acquired resources. // Disables logging, but preserves acquired resources.
void stop() { is_stopped_ = true; } void stop() { is_stopped_ = true; }
@ -66,11 +66,9 @@ class Log {
// Append string data to the log message. // Append string data to the log message.
void PRINTF_FORMAT(2, 0) AppendVA(const char* format, va_list args); void PRINTF_FORMAT(2, 0) AppendVA(const char* format, va_list args);
// Append a character to the log message.
void Append(const char c);
// Append double quoted string to the log message. // Append double quoted string to the log message.
void AppendDoubleQuotedString(const char* string); void AppendDoubleQuotedString(const char* string);
void AppendDoubleQuotedString(String* string);
// Append a heap string. // Append a heap string.
void Append(String* str); void Append(String* str);
@ -88,37 +86,32 @@ class Log {
// Helpers for appending char, C-string and heap string without // Helpers for appending char, C-string and heap string without
// buffering. This is useful for entries that can exceed the 2kB // buffering. This is useful for entries that can exceed the 2kB
// limit. // limit.
void AppendUnbufferedChar(char c); void AppendEscapedString(String* source);
void AppendUnbufferedCString(const char* str); void AppendEscapedString(String* source, int len);
void AppendUnbufferedHeapString(String* source);
// Write the log message to the log file currently opened. // Delegate insertion to the underlying {log_}.
template <typename T>
MessageBuilder& operator<<(T value) {
log_->os_ << value;
return *this;
}
// Finish the current log line an flush the it to the log file.
void WriteToLogFile(); void WriteToLogFile();
private: private:
Log* log_; Log* log_;
base::LockGuard<base::Mutex> lock_guard_; base::LockGuard<base::Mutex> lock_guard_;
int pos_;
}; };
private: private:
explicit Log(Logger* logger); static FILE* CreateOutputHandle(const char* file_name);
// Opens stdout for logging.
void OpenStdout();
// Opens file for logging.
void OpenFile(const char* name);
// Opens a temporary file for logging.
void OpenTemporaryFile();
// Implementation of writing to a log file. // Implementation of writing to a log file.
int WriteToFile(const char* msg, int length) { int WriteToFile(const char* msg, int length) {
DCHECK_NOT_NULL(output_handle_); DCHECK_NOT_NULL(output_handle_);
size_t rv = fwrite(msg, 1, length, output_handle_); os_.write(msg, length);
DCHECK_EQ(length, rv); DCHECK(!os_.bad());
USE(rv);
return length; return length;
} }
@ -128,6 +121,7 @@ class Log {
// 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_;
// mutex_ is a Mutex used for enforcing exclusive // mutex_ is a Mutex used for enforcing exclusive
// access to the formatting buffer and the log file or log memory buffer. // access to the formatting buffer and the log file or log memory buffer.
@ -135,7 +129,7 @@ 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.
char* message_buffer_; char* format_buffer_;
Logger* logger_; Logger* logger_;

433
src/log.cc
View File

@ -725,7 +725,7 @@ Logger::Logger(Isolate* isolate)
profiler_(nullptr), profiler_(nullptr),
log_events_(nullptr), log_events_(nullptr),
is_logging_(false), is_logging_(false),
log_(new Log(this)), log_(nullptr),
perf_basic_logger_(nullptr), perf_basic_logger_(nullptr),
perf_jit_logger_(nullptr), perf_jit_logger_(nullptr),
ll_logger_(nullptr), ll_logger_(nullptr),
@ -749,7 +749,7 @@ void Logger::removeCodeEventListener(CodeEventListener* listener) {
void Logger::ProfilerBeginEvent() { void Logger::ProfilerBeginEvent() {
if (!log_->IsEnabled()) return; if (!log_->IsEnabled()) return;
Log::MessageBuilder msg(log_); Log::MessageBuilder msg(log_);
msg.Append("profiler,\"begin\",%d", FLAG_prof_sampling_interval); msg << "profiler,\"begin\"," << FLAG_prof_sampling_interval;
msg.WriteToLogFile(); msg.WriteToLogFile();
} }
@ -762,7 +762,7 @@ void Logger::StringEvent(const char* name, const char* value) {
void Logger::UncheckedStringEvent(const char* name, const char* value) { void Logger::UncheckedStringEvent(const char* name, const char* value) {
if (!log_->IsEnabled()) return; if (!log_->IsEnabled()) return;
Log::MessageBuilder msg(log_); Log::MessageBuilder msg(log_);
msg.Append("%s,\"%s\"", name, value); msg << name << ",\"" << value << "\"";
msg.WriteToLogFile(); msg.WriteToLogFile();
} }
@ -780,7 +780,7 @@ void Logger::IntPtrTEvent(const char* name, intptr_t value) {
void Logger::UncheckedIntEvent(const char* name, int value) { void Logger::UncheckedIntEvent(const char* name, int value) {
if (!log_->IsEnabled()) return; if (!log_->IsEnabled()) return;
Log::MessageBuilder msg(log_); Log::MessageBuilder msg(log_);
msg.Append("%s,%d", name, value); msg << name << "," << value;
msg.WriteToLogFile(); msg.WriteToLogFile();
} }
@ -796,7 +796,7 @@ void Logger::UncheckedIntPtrTEvent(const char* name, intptr_t value) {
void Logger::HandleEvent(const char* name, Object** location) { void Logger::HandleEvent(const char* name, Object** location) {
if (!log_->IsEnabled() || !FLAG_log_handles) return; if (!log_->IsEnabled() || !FLAG_log_handles) return;
Log::MessageBuilder msg(log_); Log::MessageBuilder msg(log_);
msg.Append("%s,%p", name, static_cast<void*>(location)); msg << name << "," << static_cast<void*>(location);
msg.WriteToLogFile(); msg.WriteToLogFile();
} }
@ -825,9 +825,9 @@ void Logger::SharedLibraryEvent(const std::string& library_path,
intptr_t aslr_slide) { intptr_t aslr_slide) {
if (!log_->IsEnabled() || !FLAG_prof_cpp) return; if (!log_->IsEnabled() || !FLAG_prof_cpp) return;
Log::MessageBuilder msg(log_); Log::MessageBuilder msg(log_);
msg.Append("shared-library,\"%s\",0x%08" V8PRIxPTR ",0x%08" V8PRIxPTR msg << "shared-library,\"" << library_path.c_str() << "\","
",%" V8PRIdPTR, << reinterpret_cast<void*>(start) << "," << reinterpret_cast<void*>(end)
library_path.c_str(), start, end, aslr_slide); << "," << aslr_slide;
msg.WriteToLogFile(); msg.WriteToLogFile();
} }
@ -837,7 +837,7 @@ void Logger::CodeDeoptEvent(Code* code, DeoptKind kind, Address pc,
Deoptimizer::DeoptInfo info = Deoptimizer::GetDeoptInfo(code, pc); Deoptimizer::DeoptInfo info = Deoptimizer::GetDeoptInfo(code, pc);
Log::MessageBuilder msg(log_); Log::MessageBuilder msg(log_);
int since_epoch = static_cast<int>(timer_.Elapsed().InMicroseconds()); int since_epoch = static_cast<int>(timer_.Elapsed().InMicroseconds());
msg.Append("code-deopt,%d,%d,", since_epoch, code->CodeSize()); msg << "code-deopt," << since_epoch << "," << code->CodeSize() << ",";
msg.AppendAddress(code->instruction_start()); msg.AppendAddress(code->instruction_start());
// Deoptimization position. // Deoptimization position.
@ -851,20 +851,20 @@ void Logger::CodeDeoptEvent(Code* code, DeoptKind kind, Address pc,
} else { } else {
deopt_location << "<unknown>"; deopt_location << "<unknown>";
} }
msg.Append(",%d,%d,", inlining_id, script_offset); msg << "," << inlining_id << "," << script_offset;
switch (kind) { switch (kind) {
case kLazy: case kLazy:
msg.Append("\"lazy\","); msg << "\"lazy\",";
break; break;
case kSoft: case kSoft:
msg.Append("\"soft\","); msg << "\"soft\",";
break; break;
case kEager: case kEager:
msg.Append("\"eager\","); msg << "\"eager\",";
break; break;
} }
msg.AppendDoubleQuotedString(deopt_location.str().c_str()); msg.AppendDoubleQuotedString(deopt_location.str().c_str());
msg.Append(","); msg << ",";
msg.AppendDoubleQuotedString(DeoptimizeReasonToString(info.deopt_reason)); msg.AppendDoubleQuotedString(DeoptimizeReasonToString(info.deopt_reason));
msg.WriteToLogFile(); msg.WriteToLogFile();
} }
@ -875,7 +875,7 @@ void Logger::CurrentTimeEvent() {
DCHECK(FLAG_log_internal_timer_events); DCHECK(FLAG_log_internal_timer_events);
Log::MessageBuilder msg(log_); Log::MessageBuilder msg(log_);
int since_epoch = static_cast<int>(timer_.Elapsed().InMicroseconds()); int since_epoch = static_cast<int>(timer_.Elapsed().InMicroseconds());
msg.Append("current-time,%d", since_epoch); msg << "current-time," << since_epoch;
msg.WriteToLogFile(); msg.WriteToLogFile();
} }
@ -883,12 +883,19 @@ void Logger::CurrentTimeEvent() {
void Logger::TimerEvent(Logger::StartEnd se, const char* name) { void Logger::TimerEvent(Logger::StartEnd se, const char* name) {
if (!log_->IsEnabled()) return; if (!log_->IsEnabled()) return;
Log::MessageBuilder msg(log_); Log::MessageBuilder msg(log_);
switch (se) {
case START:
msg << "timer-event-start";
break;
case END:
msg << "timer-event-end";
break;
case STAMP:
msg << "timer-event";
}
int since_epoch = static_cast<int>(timer_.Elapsed().InMicroseconds()); int since_epoch = static_cast<int>(timer_.Elapsed().InMicroseconds());
const char* format = (se == START) msg.AppendDoubleQuotedString(name);
? "timer-event-start,\"%s\",%ld" msg << "," << since_epoch;
: (se == END) ? "timer-event-end,\"%s\",%ld"
: "timer-event,\"%s\",%ld";
msg.Append(format, name, since_epoch);
msg.WriteToLogFile(); msg.WriteToLogFile();
} }
@ -972,7 +979,8 @@ void Logger::ApiEntryCall(const char* name) {
void Logger::NewEvent(const char* name, void* object, size_t size) { void Logger::NewEvent(const char* name, void* object, size_t size) {
if (!log_->IsEnabled() || !FLAG_log) return; if (!log_->IsEnabled() || !FLAG_log) return;
Log::MessageBuilder msg(log_); Log::MessageBuilder msg(log_);
msg.Append("new,%s,%p,%u", name, object, static_cast<unsigned int>(size)); msg << "new," << name << "," << object << ","
<< static_cast<unsigned int>(size);
msg.WriteToLogFile(); msg.WriteToLogFile();
} }
@ -980,7 +988,7 @@ void Logger::NewEvent(const char* name, void* object, size_t size) {
void Logger::DeleteEvent(const char* name, void* object) { void Logger::DeleteEvent(const char* name, void* object) {
if (!log_->IsEnabled() || !FLAG_log) return; if (!log_->IsEnabled() || !FLAG_log) return;
Log::MessageBuilder msg(log_); Log::MessageBuilder msg(log_);
msg.Append("delete,%s,%p", name, object); msg << "delete," << name << "," << object;
msg.WriteToLogFile(); msg.WriteToLogFile();
} }
@ -989,27 +997,19 @@ void Logger::CallbackEventInternal(const char* prefix, Name* name,
Address entry_point) { Address entry_point) {
if (!FLAG_log_code || !log_->IsEnabled()) return; if (!FLAG_log_code || !log_->IsEnabled()) return;
Log::MessageBuilder msg(log_); Log::MessageBuilder msg(log_);
msg.Append("%s,%s,-2,", msg << kLogEventsNames[CodeEventListener::CODE_CREATION_EVENT] << ","
kLogEventsNames[CodeEventListener::CODE_CREATION_EVENT], << kLogEventsNames[CodeEventListener::CALLBACK_TAG] << ",-2,";
kLogEventsNames[CodeEventListener::CALLBACK_TAG]);
int timestamp = static_cast<int>(timer_.Elapsed().InMicroseconds()); int timestamp = static_cast<int>(timer_.Elapsed().InMicroseconds());
msg.Append("%d,", timestamp); msg << timestamp << ",";
msg.AppendAddress(entry_point); msg.AppendAddress(entry_point);
if (name->IsString()) { if (name->IsString()) {
std::unique_ptr<char[]> str = msg << ",1,\"" << prefix;
String::cast(name)->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL); msg.AppendEscapedString(String::cast(name));
msg.Append(",1,\"%s%s\"", prefix, str.get()); msg << "\"";
} else { } else {
Symbol* symbol = Symbol::cast(name); Symbol* symbol = Symbol::cast(name);
if (symbol->name()->IsUndefined(symbol->GetIsolate())) { msg << ",1,";
msg.Append(",1,symbol(hash %x)", symbol->Hash()); msg.AppendSymbolName(symbol);
} else {
std::unique_ptr<char[]> str =
String::cast(symbol->name())
->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
msg.Append(",1,symbol(\"%s%s\" hash %x)", prefix, str.get(),
symbol->Hash());
}
} }
msg.WriteToLogFile(); msg.WriteToLogFile();
} }
@ -1031,17 +1031,15 @@ void Logger::SetterCallbackEvent(Name* name, Address entry_point) {
namespace { namespace {
void AppendCodeCreateHeader(Log::MessageBuilder* msg, void AppendCodeCreateHeader(Log::MessageBuilder& msg,
CodeEventListener::LogEventsAndTags tag, CodeEventListener::LogEventsAndTags tag,
AbstractCode* code, base::ElapsedTimer* timer) { AbstractCode* code, base::ElapsedTimer* timer) {
DCHECK(msg); msg << kLogEventsNames[CodeEventListener::CODE_CREATION_EVENT] << ","
msg->Append("%s,%s,%d,", << kLogEventsNames[tag] << "," << code->kind();
kLogEventsNames[CodeEventListener::CODE_CREATION_EVENT],
kLogEventsNames[tag], code->kind());
int timestamp = static_cast<int>(timer->Elapsed().InMicroseconds()); int timestamp = static_cast<int>(timer->Elapsed().InMicroseconds());
msg->Append("%d,", timestamp); msg << "," << timestamp << ",";
msg->AppendAddress(code->instruction_start()); msg.AppendAddress(code->instruction_start());
msg->Append(",%d,", code->instruction_size()); msg << "," << code->instruction_size() << ",";
} }
} // namespace } // namespace
@ -1051,7 +1049,7 @@ void Logger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
if (!is_logging_code_events()) return; if (!is_logging_code_events()) return;
if (!FLAG_log_code || !log_->IsEnabled()) return; if (!FLAG_log_code || !log_->IsEnabled()) return;
Log::MessageBuilder msg(log_); Log::MessageBuilder msg(log_);
AppendCodeCreateHeader(&msg, tag, code, &timer_); AppendCodeCreateHeader(msg, tag, code, &timer_);
msg.AppendDoubleQuotedString(comment); msg.AppendDoubleQuotedString(comment);
msg.WriteToLogFile(); msg.WriteToLogFile();
} }
@ -1061,11 +1059,9 @@ void Logger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
if (!is_logging_code_events()) return; if (!is_logging_code_events()) return;
if (!FLAG_log_code || !log_->IsEnabled()) return; if (!FLAG_log_code || !log_->IsEnabled()) return;
Log::MessageBuilder msg(log_); Log::MessageBuilder msg(log_);
AppendCodeCreateHeader(&msg, tag, code, &timer_); AppendCodeCreateHeader(msg, tag, code, &timer_);
if (name->IsString()) { if (name->IsString()) {
msg.Append('"'); msg.AppendDoubleQuotedString(String::cast(name));
msg.AppendDetailed(String::cast(name), false);
msg.Append('"');
} else { } else {
msg.AppendSymbolName(Symbol::cast(name)); msg.AppendSymbolName(Symbol::cast(name));
} }
@ -1083,17 +1079,15 @@ void Logger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
} }
Log::MessageBuilder msg(log_); Log::MessageBuilder msg(log_);
AppendCodeCreateHeader(&msg, tag, code, &timer_); AppendCodeCreateHeader(msg, tag, code, &timer_);
if (name->IsString()) { if (name->IsString()) {
std::unique_ptr<char[]> str = msg.AppendDoubleQuotedString(String::cast(name));
String::cast(name)->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
msg.Append("\"%s\"", str.get());
} else { } else {
msg.AppendSymbolName(Symbol::cast(name)); msg.AppendSymbolName(Symbol::cast(name));
} }
msg.Append(','); msg << ',';
msg.AppendAddress(shared->address()); msg.AppendAddress(shared->address());
msg.Append(",%s", ComputeMarker(shared, code)); msg << "," << ComputeMarker(shared, code);
msg.WriteToLogFile(); msg.WriteToLogFile();
} }
@ -1107,139 +1101,126 @@ void Logger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
if (!is_logging_code_events()) return; if (!is_logging_code_events()) return;
if (!FLAG_log_code || !log_->IsEnabled()) return; if (!FLAG_log_code || !log_->IsEnabled()) return;
{ Log::MessageBuilder msg(log_);
Log::MessageBuilder msg(log_); AppendCodeCreateHeader(msg, tag, code, &timer_);
AppendCodeCreateHeader(&msg, tag, code, &timer_); msg << "\"";
std::unique_ptr<char[]> name = msg.AppendEscapedString(shared->DebugName());
shared->DebugName()->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL); msg << " ";
msg.Append("\"%s ", name.get()); if (source->IsString()) {
if (source->IsString()) { msg.AppendEscapedString(String::cast(source));
std::unique_ptr<char[]> sourcestr = String::cast(source)->ToCString( } else {
DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL); msg.AppendSymbolName(Symbol::cast(source));
msg.Append("%s", sourcestr.get()); }
msg << ":" << line << ":" << column << "\",";
msg.AppendAddress(shared->address());
msg << "," << ComputeMarker(shared, code);
msg.WriteToLogFile();
if (!FLAG_log_source_code) return;
Object* script_object = shared->script();
if (!script_object->IsScript()) return;
// Make sure the script is written to the log file.
Script* script = Script::cast(script_object);
int script_id = script->id();
if (logged_source_code_.find(script_id) != logged_source_code_.end()) {
return;
}
// This script has not been logged yet.
logged_source_code_.insert(script_id);
Object* source_object = script->source();
if (source_object->IsString()) {
String* source_code = String::cast(source_object);
msg << "script," << script_id << ",\"";
// Log the script name.
if (script->name()->IsString()) {
msg.AppendEscapedString(String::cast(script->name()));
msg << "\",\"";
} else { } else {
msg.AppendSymbolName(Symbol::cast(source)); msg << "<unknown>\",\"";
} }
msg.Append(":%d:%d\",", line, column);
msg.AppendAddress(shared->address()); // Log the source code.
msg.Append(",%s", ComputeMarker(shared, code)); msg.AppendEscapedString(source_code);
msg << "\"";
msg.WriteToLogFile(); msg.WriteToLogFile();
} }
if (FLAG_log_source_code) { // We log source code information in the form:
Object* script_object = shared->script(); //
if (script_object->IsScript()) { // code-source-info <addr>,<script>,<start>,<end>,<pos>,<inline-pos>,<fns>
// Make sure the script is written to the log file. //
std::ostringstream os; // where
Script* script = Script::cast(script_object); // <addr> is code object address
int script_id = script->id(); // <script> is script id
if (logged_source_code_.find(script_id) == logged_source_code_.end()) { // <start> is the starting position inside the script
// This script has not been logged yet. // <end> is the end position inside the script
logged_source_code_.insert(script_id); // <pos> is source position table encoded in the string,
Object* source_object = script->source(); // it is a sequence of C<code-offset>O<script-offset>[I<inlining-id>]
if (source_object->IsString()) { // where
Log::MessageBuilder msg(log_); // <code-offset> is the offset within the code object
String* source_code = String::cast(source_object); // <script-offset> is the position within the script
os << "script," << script_id << ",\""; // <inlining-id> is the offset in the <inlining> table
msg.AppendUnbufferedCString(os.str().c_str()); // <inlining> table is a sequence of strings of the form
// F<function-id>O<script-offset>[I<inlining-id>
// where
// <function-id> is an index into the <fns> function table
// <fns> is the function table encoded as a sequence of strings
// S<shared-function-info-address>
msg << "code-source-info," << static_cast<void*>(code->instruction_start())
<< "," << script_id << "," << shared->start_position() << ","
<< shared->end_position() << ",";
// Log the script name. SourcePositionTableIterator iterator(code->source_position_table());
if (script->name()->IsString()) { bool is_first = true;
msg.AppendUnbufferedHeapString(String::cast(script->name())); bool hasInlined = false;
msg.AppendUnbufferedCString("\",\""); for (; !iterator.done(); iterator.Advance()) {
} else { if (is_first) {
msg.AppendUnbufferedCString("<unknown>\",\""); is_first = false;
} }
SourcePosition pos = iterator.source_position();
// Log the source code. msg << "C" << iterator.code_offset() << "O" << pos.ScriptOffset();
msg.AppendUnbufferedHeapString(source_code); if (pos.isInlined()) {
os.str(""); msg << "I" << pos.InliningId();
os << "\"" << std::endl; hasInlined = true;
msg.AppendUnbufferedCString(os.str().c_str());
os.str("");
}
}
// We log source code information in the form:
//
// code-source-info <addr>,<script>,<start>,<end>,<pos>,<inline-pos>,<fns>
//
// where
// <addr> is code object address
// <script> is script id
// <start> is the starting position inside the script
// <end> is the end position inside the script
// <pos> is source position table encoded in the string,
// it is a sequence of C<code-offset>O<script-offset>[I<inlining-id>]
// where
// <code-offset> is the offset within the code object
// <script-offset> is the position within the script
// <inlining-id> is the offset in the <inlining> table
// <inlining> table is a sequence of strings of the form
// F<function-id>O<script-offset>[I<inlining-id>
// where
// <function-id> is an index into the <fns> function table
// <fns> is the function table encoded as a sequence of strings
// S<shared-function-info-address>
os << "code-source-info," << static_cast<void*>(code->instruction_start())
<< "," << script_id << "," << shared->start_position() << ","
<< shared->end_position() << ",";
SourcePositionTableIterator iterator(code->source_position_table());
bool is_first = true;
bool hasInlined = false;
for (; !iterator.done(); iterator.Advance()) {
if (is_first) {
is_first = false;
}
SourcePosition pos = iterator.source_position();
os << "C" << iterator.code_offset();
os << "O" << pos.ScriptOffset();
if (pos.isInlined()) {
os << "I" << pos.InliningId();
hasInlined = true;
}
}
os << ",";
int maxInlinedId = -1;
if (hasInlined) {
PodArray<InliningPosition>* inlining_positions =
DeoptimizationData::cast(Code::cast(code)->deoptimization_data())
->InliningPositions();
for (int i = 0; i < inlining_positions->length(); i++) {
InliningPosition inlining_pos = inlining_positions->get(i);
os << "F";
if (inlining_pos.inlined_function_id != -1) {
os << inlining_pos.inlined_function_id;
if (inlining_pos.inlined_function_id > maxInlinedId) {
maxInlinedId = inlining_pos.inlined_function_id;
}
}
SourcePosition pos = inlining_pos.position;
os << "O" << pos.ScriptOffset();
if (pos.isInlined()) {
os << "I" << pos.InliningId();
}
}
}
os << ",";
if (hasInlined) {
DeoptimizationData* deopt_data =
DeoptimizationData::cast(Code::cast(code)->deoptimization_data());
os << std::hex;
for (int i = 0; i <= maxInlinedId; i++) {
os << "S"
<< static_cast<void*>(
deopt_data->GetInlinedFunction(i)->address());
}
os << std::dec;
}
os << std::endl;
Log::MessageBuilder msg(log_);
msg.AppendUnbufferedCString(os.str().c_str());
} }
} }
msg << ",";
int maxInlinedId = -1;
if (hasInlined) {
PodArray<InliningPosition>* inlining_positions =
DeoptimizationData::cast(Code::cast(code)->deoptimization_data())
->InliningPositions();
for (int i = 0; i < inlining_positions->length(); i++) {
InliningPosition inlining_pos = inlining_positions->get(i);
msg << "F";
if (inlining_pos.inlined_function_id != -1) {
msg << inlining_pos.inlined_function_id;
if (inlining_pos.inlined_function_id > maxInlinedId) {
maxInlinedId = inlining_pos.inlined_function_id;
}
}
SourcePosition pos = inlining_pos.position;
msg << "O" << pos.ScriptOffset();
if (pos.isInlined()) {
msg << "I" << pos.InliningId();
}
}
}
msg << ",";
if (hasInlined) {
DeoptimizationData* deopt_data =
DeoptimizationData::cast(Code::cast(code)->deoptimization_data());
msg << std::hex;
for (int i = 0; i <= maxInlinedId; i++) {
msg << "S"
<< static_cast<void*>(deopt_data->GetInlinedFunction(i)->address());
}
msg << std::dec;
}
msg.WriteToLogFile();
} }
void Logger::CodeDisableOptEvent(AbstractCode* code, void Logger::CodeDisableOptEvent(AbstractCode* code,
@ -1247,11 +1228,11 @@ void Logger::CodeDisableOptEvent(AbstractCode* code,
if (!is_logging_code_events()) return; if (!is_logging_code_events()) return;
if (!FLAG_log_code || !log_->IsEnabled()) return; if (!FLAG_log_code || !log_->IsEnabled()) return;
Log::MessageBuilder msg(log_); Log::MessageBuilder msg(log_);
msg.Append("%s,", kLogEventsNames[CodeEventListener::CODE_DISABLE_OPT_EVENT]); msg << kLogEventsNames[CodeEventListener::CODE_DISABLE_OPT_EVENT] << ",";
std::unique_ptr<char[]> name = msg.AppendDoubleQuotedString(shared->DebugName());
shared->DebugName()->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL); msg << ",";
msg.Append("\"%s\",", name.get()); msg.AppendDoubleQuotedString(
msg.Append("\"%s\"", GetBailoutReason(shared->disable_optimization_reason())); GetBailoutReason(shared->disable_optimization_reason()));
msg.WriteToLogFile(); msg.WriteToLogFile();
} }
@ -1266,10 +1247,10 @@ void Logger::RegExpCodeCreateEvent(AbstractCode* code, String* source) {
if (!is_logging_code_events()) return; if (!is_logging_code_events()) return;
if (!FLAG_log_code || !log_->IsEnabled()) return; if (!FLAG_log_code || !log_->IsEnabled()) return;
Log::MessageBuilder msg(log_); Log::MessageBuilder msg(log_);
AppendCodeCreateHeader(&msg, CodeEventListener::REG_EXP_TAG, code, &timer_); AppendCodeCreateHeader(msg, CodeEventListener::REG_EXP_TAG, code, &timer_);
msg.Append('"'); msg << '"';
msg.AppendDetailed(source, false); msg.AppendDetailed(source, false);
msg.Append('"'); msg << '"';
msg.WriteToLogFile(); msg.WriteToLogFile();
} }
@ -1301,8 +1282,8 @@ void Logger::CodeLinePosInfoRecordEvent(AbstractCode* code,
void Logger::CodeNameEvent(Address addr, int pos, const char* code_name) { void Logger::CodeNameEvent(Address addr, int pos, const char* code_name) {
if (code_name == nullptr) return; // Not a code object. if (code_name == nullptr) return; // Not a code object.
Log::MessageBuilder msg(log_); Log::MessageBuilder msg(log_);
msg.Append("%s,%d,", msg << kLogEventsNames[CodeEventListener::SNAPSHOT_CODE_NAME_EVENT] << ","
kLogEventsNames[CodeEventListener::SNAPSHOT_CODE_NAME_EVENT], pos); << pos;
msg.AppendDoubleQuotedString(code_name); msg.AppendDoubleQuotedString(code_name);
msg.WriteToLogFile(); msg.WriteToLogFile();
} }
@ -1317,9 +1298,9 @@ void Logger::MoveEventInternal(CodeEventListener::LogEventsAndTags event,
Address from, Address to) { Address from, Address to) {
if (!FLAG_log_code || !log_->IsEnabled()) return; if (!FLAG_log_code || !log_->IsEnabled()) return;
Log::MessageBuilder msg(log_); Log::MessageBuilder msg(log_);
msg.Append("%s,", kLogEventsNames[event]); msg << kLogEventsNames[event] << ",";
msg.AppendAddress(from); msg.AppendAddress(from);
msg.Append(','); msg << ",";
msg.AppendAddress(to); msg.AppendAddress(to);
msg.WriteToLogFile(); msg.WriteToLogFile();
} }
@ -1328,11 +1309,11 @@ void Logger::MoveEventInternal(CodeEventListener::LogEventsAndTags event,
void Logger::ResourceEvent(const char* name, const char* tag) { void Logger::ResourceEvent(const char* name, const char* tag) {
if (!log_->IsEnabled() || !FLAG_log) return; if (!log_->IsEnabled() || !FLAG_log) return;
Log::MessageBuilder msg(log_); Log::MessageBuilder msg(log_);
msg.Append("%s,%s,", name, tag); msg << name << "," << tag << ",";
uint32_t sec, usec; uint32_t sec, usec;
if (base::OS::GetUserTime(&sec, &usec) != -1) { if (base::OS::GetUserTime(&sec, &usec) != -1) {
msg.Append("%d,%d,", sec, usec); msg << sec << "," << usec << ",";
} }
msg.Append("%.0f", V8::GetCurrentPlatform()->CurrentClockTimeMillis()); msg.Append("%.0f", V8::GetCurrentPlatform()->CurrentClockTimeMillis());
msg.WriteToLogFile(); msg.WriteToLogFile();
@ -1345,13 +1326,9 @@ void Logger::SuspectReadEvent(Name* name, Object* obj) {
String* class_name = obj->IsJSObject() String* class_name = obj->IsJSObject()
? JSObject::cast(obj)->class_name() ? JSObject::cast(obj)->class_name()
: isolate_->heap()->empty_string(); : isolate_->heap()->empty_string();
msg.Append("suspect-read,"); msg << "suspect-read," << class_name << ",";
msg.Append(class_name);
msg.Append(',');
if (name->IsString()) { if (name->IsString()) {
msg.Append('"'); msg.AppendDoubleQuotedString(String::cast(name));
msg.Append(String::cast(name));
msg.Append('"');
} else { } else {
msg.AppendSymbolName(Symbol::cast(name)); msg.AppendSymbolName(Symbol::cast(name));
} }
@ -1364,8 +1341,8 @@ void Logger::HeapSampleBeginEvent(const char* space, const char* kind) {
Log::MessageBuilder msg(log_); Log::MessageBuilder msg(log_);
// Using non-relative system time in order to be able to synchronize with // Using non-relative system time in order to be able to synchronize with
// external memory profiling events (e.g. DOM memory size). // external memory profiling events (e.g. DOM memory size).
msg.Append("heap-sample-begin,\"%s\",\"%s\",%.0f", space, kind, msg << "heap-sample-begin,\"" << space << "\",\"" << kind << "\",";
V8::GetCurrentPlatform()->CurrentClockTimeMillis()); msg.Append("%.0f", V8::GetCurrentPlatform()->CurrentClockTimeMillis());
msg.WriteToLogFile(); msg.WriteToLogFile();
} }
@ -1373,7 +1350,7 @@ void Logger::HeapSampleBeginEvent(const char* space, const char* kind) {
void Logger::HeapSampleEndEvent(const char* space, const char* kind) { void Logger::HeapSampleEndEvent(const char* space, const char* kind) {
if (!log_->IsEnabled() || !FLAG_log_gc) return; if (!log_->IsEnabled() || !FLAG_log_gc) return;
Log::MessageBuilder msg(log_); Log::MessageBuilder msg(log_);
msg.Append("heap-sample-end,\"%s\",\"%s\"", space, kind); msg << "heap-sample-end,\"" << space << "\",\"" << kind << "\"";
msg.WriteToLogFile(); msg.WriteToLogFile();
} }
@ -1381,7 +1358,7 @@ void Logger::HeapSampleEndEvent(const char* space, const char* kind) {
void Logger::HeapSampleItemEvent(const char* type, int number, int bytes) { void Logger::HeapSampleItemEvent(const char* type, int number, int bytes) {
if (!log_->IsEnabled() || !FLAG_log_gc) return; if (!log_->IsEnabled() || !FLAG_log_gc) return;
Log::MessageBuilder msg(log_); Log::MessageBuilder msg(log_);
msg.Append("heap-sample-item,%s,%d,%d", type, number, bytes); msg << "heap-sample-item,\"" << type << "\"," << number << "," << bytes;
msg.WriteToLogFile(); msg.WriteToLogFile();
} }
@ -1391,7 +1368,7 @@ void Logger::RuntimeCallTimerEvent() {
RuntimeCallCounter* counter = stats->current_counter(); RuntimeCallCounter* counter = stats->current_counter();
if (counter == nullptr) return; if (counter == nullptr) return;
Log::MessageBuilder msg(log_); Log::MessageBuilder msg(log_);
msg.Append("active-runtime-timer,"); msg << "active-runtime-timer,";
msg.AppendDoubleQuotedString(counter->name()); msg.AppendDoubleQuotedString(counter->name());
msg.WriteToLogFile(); msg.WriteToLogFile();
} }
@ -1403,24 +1380,20 @@ void Logger::TickEvent(v8::TickSample* sample, bool overflow) {
RuntimeCallTimerEvent(); RuntimeCallTimerEvent();
} }
Log::MessageBuilder msg(log_); Log::MessageBuilder msg(log_);
msg.Append("%s,", kLogEventsNames[CodeEventListener::TICK_EVENT]); msg << kLogEventsNames[CodeEventListener::TICK_EVENT] << ','
msg.AppendAddress(reinterpret_cast<Address>(sample->pc)); << reinterpret_cast<void*>(sample->pc) << ','
msg.Append(",%d", static_cast<int>(timer_.Elapsed().InMicroseconds())); << static_cast<int>(timer_.Elapsed().InMicroseconds());
if (sample->has_external_callback) { if (sample->has_external_callback) {
msg.Append(",1,"); msg << ",1," << reinterpret_cast<void*>(sample->external_callback_entry);
msg.AppendAddress(
reinterpret_cast<Address>(sample->external_callback_entry));
} else { } else {
msg.Append(",0,"); msg << ",0," << reinterpret_cast<void*>(sample->tos);
msg.AppendAddress(reinterpret_cast<Address>(sample->tos));
} }
msg.Append(",%d", static_cast<int>(sample->state)); msg << ',' << static_cast<int>(sample->state);
if (overflow) { if (overflow) {
msg.Append(",overflow"); msg << ",overflow";
} }
for (unsigned i = 0; i < sample->frames_count; ++i) { for (unsigned i = 0; i < sample->frames_count; ++i) {
msg.Append(','); msg << ',' << reinterpret_cast<void*>(sample->stack[i]);
msg.AppendAddress(reinterpret_cast<Address>(sample->stack[i]));
} }
msg.WriteToLogFile(); msg.WriteToLogFile();
} }
@ -1431,26 +1404,21 @@ void Logger::ICEvent(const char* type, bool keyed, const Address pc, int line,
const char* slow_stub_reason) { const char* slow_stub_reason) {
if (!log_->IsEnabled() || !FLAG_trace_ic) return; if (!log_->IsEnabled() || !FLAG_trace_ic) return;
Log::MessageBuilder msg(log_); Log::MessageBuilder msg(log_);
if (keyed) msg.Append("Keyed"); if (keyed) msg << "Keyed";
msg.Append("%s,", type); msg << type << ",";
msg.AppendAddress(pc); msg.AppendAddress(pc);
msg.Append(",%d,%d,", line, column); msg << "," << line << "," << column << "," << old_state << "," << new_state
msg.Append(old_state); << "," << reinterpret_cast<void*>(map) << ",";
msg.Append(",");
msg.Append(new_state);
msg.Append(",");
msg.AppendAddress(reinterpret_cast<Address>(map));
msg.Append(",");
if (key->IsSmi()) { if (key->IsSmi()) {
msg.Append("%d", Smi::ToInt(key)); msg << Smi::ToInt(key);
} else if (key->IsNumber()) { } else if (key->IsNumber()) {
msg.Append("%lf", key->Number()); msg << key->Number();
} else if (key->IsString()) { } else if (key->IsString()) {
msg.AppendDetailed(String::cast(key), false); msg.AppendDetailed(String::cast(key), false);
} else if (key->IsSymbol()) { } else if (key->IsSymbol()) {
msg.AppendSymbolName(Symbol::cast(key)); msg.AppendSymbolName(Symbol::cast(key));
} }
msg.Append(",%s,", modifier); msg << "," << modifier << ",";
if (slow_stub_reason != nullptr) { if (slow_stub_reason != nullptr) {
msg.AppendDoubleQuotedString(slow_stub_reason); msg.AppendDoubleQuotedString(slow_stub_reason);
} }
@ -1466,7 +1434,6 @@ void Logger::StopProfiler() {
} }
} }
// This function can be called when Log's mutex is acquired, // This function can be called when Log's mutex is acquired,
// either from main or Profiler's thread. // either from main or Profiler's thread.
void Logger::LogFailure() { void Logger::LogFailure() {
@ -1782,7 +1749,7 @@ bool Logger::SetUp(Isolate* isolate) {
std::ostringstream log_file_name; std::ostringstream log_file_name;
std::ostringstream source_log_file_name; std::ostringstream source_log_file_name;
PrepareLogFileName(log_file_name, isolate, FLAG_logfile); PrepareLogFileName(log_file_name, isolate, FLAG_logfile);
log_->Initialize(log_file_name.str().c_str()); log_ = new Log(this, log_file_name.str().c_str());
if (FLAG_perf_basic_prof) { if (FLAG_perf_basic_prof) {
perf_basic_logger_ = new PerfBasicLogger(); perf_basic_logger_ = new PerfBasicLogger();