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

Changed all log messages to be handled through the LogMessageBuilder instead of through fprintf directly to the log file.

Browse Source 
Added a flag for the runtime %Log call and fixed its arguments checking. Use of %Log is only for debugging.
Review URL: http://codereview.chromium.org/21406

git-svn-id: http://v8.googlecode.com/svn/branches/bleeding_edge@1290 ce2b1a6d-e550-0410-aec6-3dcde31c8c00
This commit is contained in:
sgjesse@chromium.org 2009-02-17 12:49:35 +00:00
parent 8cd31d295b
commit 969d43e785
4 changed files with 161 additions and 109 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

1
src/flag-definitions.h
View File

@ -315,6 +315,7 @@ DEFINE_bool(trace_regexp_assembler, false,
DEFINE_bool(log, false,
"Minimal logging (no API, code, GC, suspect, or handles samples).")
DEFINE_bool(log_all, false, "Log all events to the log file.")
DEFINE_bool(log_runtime, false, "Activate runtime system %Log call.")
DEFINE_bool(log_api, false, "Log API events to the log file.")
DEFINE_bool(log_code, false,
"Log code events to the log file without profiling.")

263
src/log.cc
View File

@ -268,7 +268,10 @@ class LogMessageBuilder BASE_EMBEDDED {
~LogMessageBuilder() { }
void Append(const char* format, ...);
void Append(const char* format, va_list args);
void Append(const char c);
void Append(String *str);
void AppendDetailed(String* str, bool show_impl_info);
void WriteToLogFile();
@ -291,8 +294,17 @@ void LogMessageBuilder::Append(const char* format, ...) {
Logger::kMessageBufferSize - pos_);
va_list args;
va_start(args, format);
int result = v8::internal::OS::VSNPrintF(buf, format, args);
Append(format, args);
va_end(args);
ASSERT(pos_ <= Logger::kMessageBufferSize);
}
// Append string data to the log message.
void LogMessageBuilder::Append(const char* format, va_list args) {
Vector<char> buf(Logger::message_buffer_ + pos_,
Logger::kMessageBufferSize - pos_);
int result = v8::internal::OS::VSNPrintF(buf, format, args);
// Result is -1 if output was truncated.
if (result >= 0) {
@ -313,6 +325,46 @@ void LogMessageBuilder::Append(const char c) {
}
// Append a heap string.
void LogMessageBuilder::Append(String* str) {
AssertNoAllocation no_heap_allocation; // Ensure string stay valid.
StringShape shape(str);
int length = str->length(shape);
for (int i = 0; i < length; i++) {
Append(static_cast<char>(str->Get(shape, i)));
}
}
void LogMessageBuilder::AppendDetailed(String* str, bool show_impl_info) {
AssertNoAllocation no_heap_allocation; // Ensure string stay valid.
StringShape shape(str);
int len = str->length(shape);
if (len > 0x1000)
len = 0x1000;
if (show_impl_info) {
Append(shape.IsAsciiRepresentation() ? 'a' : '2');
if (shape.IsExternal())
Append('e');
if (shape.IsSymbol())
Append('#');
Append(":%i:", str->length());
}
for (int i = 0; i < len; i++) {
uc32 c = str->Get(shape, 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 {
Append("%lc", c);
}
}
}
// Write the log message to the log file currently opened.
void LogMessageBuilder::WriteToLogFile() {
ASSERT(pos_ <= Logger::kMessageBufferSize);
@ -338,8 +390,9 @@ SlidingStateWindow* Logger::sliding_state_window_ = NULL;
void Logger::Preamble(const char* content) {
#ifdef ENABLE_LOGGING_AND_PROFILING
if (logfile_ == NULL || !FLAG_log_code) return;
ScopedLock sl(mutex_);
fprintf(logfile_, "%s", content);
LogMessageBuilder msg;
msg.Append("%s", content);
msg.WriteToLogFile();
#endif
}
@ -354,8 +407,9 @@ void Logger::StringEvent(const char* name, const char* value) {
#ifdef ENABLE_LOGGING_AND_PROFILING
void Logger::UncheckedStringEvent(const char* name, const char* value) {
if (logfile_ == NULL) return;
ScopedLock sl(mutex_);
fprintf(logfile_, "%s,\"%s\"\n", name, value);
LogMessageBuilder msg;
msg.Append("%s,\"%s\"\n", name, value);
msg.WriteToLogFile();
}
#endif
@ -363,8 +417,9 @@ void Logger::UncheckedStringEvent(const char* name, const char* value) {
void Logger::IntEvent(const char* name, int value) {
#ifdef ENABLE_LOGGING_AND_PROFILING
if (logfile_ == NULL || !FLAG_log) return;
ScopedLock sl(mutex_);
fprintf(logfile_, "%s,%d\n", name, value);
LogMessageBuilder msg;
msg.Append("%s,%d\n", name, value);
msg.WriteToLogFile();
#endif
}
@ -372,9 +427,10 @@ void Logger::IntEvent(const char* name, int value) {
void Logger::HandleEvent(const char* name, Object** location) {
#ifdef ENABLE_LOGGING_AND_PROFILING
if (logfile_ == NULL || !FLAG_log_handles) return;
ScopedLock sl(mutex_);
fprintf(logfile_, "%s,0x%x\n", name,
reinterpret_cast<unsigned int>(location));
LogMessageBuilder msg;
msg.Append("%s,0x%x\n", name,
reinterpret_cast<unsigned int>(location));
msg.WriteToLogFile();
#endif
}
@ -385,10 +441,12 @@ void Logger::HandleEvent(const char* name, Object** location) {
// FLAG_log_api is true.
void Logger::ApiEvent(const char* format, ...) {
ASSERT(logfile_ != NULL && FLAG_log_api);
ScopedLock sl(mutex_);
LogMessageBuilder msg;
va_list ap;
va_start(ap, format);
vfprintf(logfile_, format, ap);
msg.Append(format, ap);
va_end(ap);
msg.WriteToLogFile();
}
#endif
@ -414,9 +472,10 @@ void Logger::SharedLibraryEvent(const char* library_path,
unsigned end) {
#ifdef ENABLE_LOGGING_AND_PROFILING
if (logfile_ == NULL || !FLAG_prof) return;
ScopedLock sl(mutex_);
fprintf(logfile_, "shared-library,\"%s\",0x%08x,0x%08x\n", library_path,
start, end);
LogMessageBuilder msg;
msg.Append("shared-library,\"%s\",0x%08x,0x%08x\n", library_path,
start, end);
msg.WriteToLogFile();
#endif
}
@ -426,79 +485,54 @@ void Logger::SharedLibraryEvent(const wchar_t* library_path,
unsigned end) {
#ifdef ENABLE_LOGGING_AND_PROFILING
if (logfile_ == NULL || !FLAG_prof) return;
ScopedLock sl(mutex_);
fprintf(logfile_, "shared-library,\"%ls\",0x%08x,0x%08x\n", library_path,
start, end);
LogMessageBuilder msg;
msg.Append("shared-library,\"%ls\",0x%08x,0x%08x\n", library_path,
start, end);
msg.WriteToLogFile();
#endif
}
#ifdef ENABLE_LOGGING_AND_PROFILING
void Logger::LogString(Handle<String> str, bool show_impl_info) {
StringShape shape(*str);
int len = str->length(shape);
if (len > 0x1000)
len = 0x1000;
if (show_impl_info) {
fputc(shape.IsAsciiRepresentation() ? 'a' : '2', logfile_);
if (shape.IsExternal())
fputc('e', logfile_);
if (shape.IsSymbol())
fputc('#', logfile_);
fprintf(logfile_, ":%i:", str->length());
}
for (int i = 0; i < len; i++) {
uc32 c = str->Get(shape, i);
if (c > 0xff) {
fprintf(logfile_, "\\u%04x", c);
} else if (c < 32 || c > 126) {
fprintf(logfile_, "\\x%02x", c);
} else if (c == ',') {
fprintf(logfile_, "\\,");
} else if (c == '\\') {
fprintf(logfile_, "\\\\");
} else {
fprintf(logfile_, "%lc", c);
}
}
}
void Logger::LogRegExpSource(Handle<JSRegExp> regexp) {
// Prints "/" + re.source + "/" +
// (re.global?"g":"") + (re.ignorecase?"i":"") + (re.multiline?"m":"")
LogMessageBuilder msg;
Handle<Object> source = GetProperty(regexp, "source");
if (!source->IsString()) {
fprintf(logfile_, "no source");
msg.Append("no source");
return;
}
switch (regexp->TypeTag()) {
case JSRegExp::ATOM:
fprintf(logfile_, "a");
msg.Append('a');
break;
default:
break;
}
fprintf(logfile_, "/");
LogString(Handle<String>::cast(source), false);
fprintf(logfile_, "/");
msg.Append('/');
msg.AppendDetailed(*Handle<String>::cast(source), false);
msg.Append('/');
// global flag
Handle<Object> global = GetProperty(regexp, "global");
if (global->IsTrue()) {
fprintf(logfile_, "g");
msg.Append('g');
}
// ignorecase flag
Handle<Object> ignorecase = GetProperty(regexp, "ignoreCase");
if (ignorecase->IsTrue()) {
fprintf(logfile_, "i");
msg.Append('i');
}
// multiline flag
Handle<Object> multiline = GetProperty(regexp, "multiline");
if (multiline->IsTrue()) {
fprintf(logfile_, "m");
msg.Append('m');
}
msg.WriteToLogFile();
}
#endif // ENABLE_LOGGING_AND_PROFILING
@ -506,19 +540,20 @@ void Logger::LogRegExpSource(Handle<JSRegExp> regexp) {
void Logger::RegExpCompileEvent(Handle<JSRegExp> regexp, bool in_cache) {
#ifdef ENABLE_LOGGING_AND_PROFILING
if (logfile_ == NULL || !FLAG_log_regexp) return;
ScopedLock sl(mutex_);
fprintf(logfile_, "regexp-compile,");
LogMessageBuilder msg;
msg.Append("regexp-compile,");
LogRegExpSource(regexp);
fprintf(logfile_, in_cache ? ",hit\n" : ",miss\n");
msg.Append(in_cache ? ",hit\n" : ",miss\n");
msg.WriteToLogFile();
#endif
}
void Logger::LogRuntime(Vector<const char> format, JSArray* args) {
#ifdef ENABLE_LOGGING_AND_PROFILING
ScopedLock sl(mutex_);
if (logfile_ == NULL || !FLAG_log_runtime) return;
HandleScope scope;
LogMessageBuilder msg;
for (int i = 0; i < format.length(); i++) {
char c = format[i];
if (c == '%' && i <= format.length() - 2) {
@ -528,28 +563,29 @@ void Logger::LogRuntime(Vector<const char> format, JSArray* args) {
i++;
switch (format[i]) {
case 's':
Logger::LogString(Handle<String>(String::cast(obj)), false);
msg.AppendDetailed(String::cast(obj), false);
break;
case 'S':
Logger::LogString(Handle<String>(String::cast(obj)), true);
msg.AppendDetailed(String::cast(obj), true);
break;
case 'r':
Logger::LogRegExpSource(Handle<JSRegExp>(JSRegExp::cast(obj)));
break;
case 'x':
fprintf(logfile_, "0x%x", Smi::cast(obj)->value());
msg.Append("0x%x", Smi::cast(obj)->value());
break;
case 'i':
fprintf(logfile_, "%i", Smi::cast(obj)->value());
msg.Append("%i", Smi::cast(obj)->value());
break;
default:
UNREACHABLE();
}
} else {
fputc(c, logfile_);
msg.Append(c);
}
}
fputc('\n', logfile_);
msg.Append('\n');
msg.WriteToLogFile();
#endif
}
@ -611,10 +647,11 @@ void Logger::ApiEntryCall(const char* name) {
void Logger::NewEvent(const char* name, void* object, size_t size) {
#ifdef ENABLE_LOGGING_AND_PROFILING
if (logfile_ == NULL || !FLAG_log) return;
ScopedLock sl(mutex_);
fprintf(logfile_, "new,%s,0x%x,%u\n", name,
reinterpret_cast<unsigned int>(object),
static_cast<unsigned int>(size));
LogMessageBuilder msg;
msg.Append("new,%s,0x%x,%u\n", name,
reinterpret_cast<unsigned int>(object),
static_cast<unsigned int>(size));
msg.WriteToLogFile();
#endif
}
@ -622,9 +659,10 @@ void Logger::NewEvent(const char* name, void* object, size_t size) {
void Logger::DeleteEvent(const char* name, void* object) {
#ifdef ENABLE_LOGGING_AND_PROFILING
if (logfile_ == NULL || !FLAG_log) return;
ScopedLock sl(mutex_);
fprintf(logfile_, "delete,%s,0x%x\n", name,
reinterpret_cast<unsigned int>(object));
LogMessageBuilder msg;
msg.Append("delete,%s,0x%x\n", name,
reinterpret_cast<unsigned int>(object));
msg.WriteToLogFile();
#endif
}
@ -637,7 +675,9 @@ void Logger::CodeCreateEvent(const char* tag, Code* code, const char* comment) {
reinterpret_cast<unsigned int>(code->address()),
code->instruction_size());
for (const char* p = comment; *p != '\0'; p++) {
if (*p == '\"') fprintf(logfile_, "\\");
if (*p == '"') {
msg.Append('\\');
}
msg.Append(*p);
}
msg.Append('"');
@ -757,16 +797,17 @@ void Logger::EndCodeRegionEvent(CodeRegion* region, Assembler* masm) {
void Logger::ResourceEvent(const char* name, const char* tag) {
#ifdef ENABLE_LOGGING_AND_PROFILING
if (logfile_ == NULL || !FLAG_log) return;
ScopedLock sl(mutex_);
fprintf(logfile_, "%s,%s,", name, tag);
LogMessageBuilder msg;
msg.Append("%s,%s,", name, tag);
uint32_t sec, usec;
if (OS::GetUserTime(&sec, &usec) != -1) {
fprintf(logfile_, "%d,%d,", sec, usec);
msg.Append("%d,%d,", sec, usec);
}
fprintf(logfile_, "%.0f", OS::TimeCurrentMillis());
msg.Append("%.0f", OS::TimeCurrentMillis());
fprintf(logfile_, "\n");
msg.Append('\n');
msg.WriteToLogFile();
#endif
}
@ -774,15 +815,19 @@ void Logger::ResourceEvent(const char* name, const char* tag) {
void Logger::SuspectReadEvent(String* name, Object* obj) {
#ifdef ENABLE_LOGGING_AND_PROFILING
if (logfile_ == NULL || !FLAG_log_suspect) return;
LogMessageBuilder msg;
String* class_name = obj->IsJSObject()
? JSObject::cast(obj)->class_name()
: Heap::empty_string();
ScopedLock sl(mutex_);
fprintf(logfile_, "suspect-read,");
class_name->PrintOn(logfile_);
fprintf(logfile_, ",\"");
name->PrintOn(logfile_);
fprintf(logfile_, "\"\n");
msg.Append("suspect-read,");
msg.Append(class_name);
msg.Append(',');
msg.Append('"');
msg.Append(name);
msg.Append('"');
msg.Append('\n');
msg.WriteToLogFile();
#endif
}
@ -790,8 +835,9 @@ void Logger::SuspectReadEvent(String* name, Object* obj) {
void Logger::HeapSampleBeginEvent(const char* space, const char* kind) {
#ifdef ENABLE_LOGGING_AND_PROFILING
if (logfile_ == NULL || !FLAG_log_gc) return;
ScopedLock sl(mutex_);
fprintf(logfile_, "heap-sample-begin,\"%s\",\"%s\"\n", space, kind);
LogMessageBuilder msg;
msg.Append("heap-sample-begin,\"%s\",\"%s\"\n", space, kind);
msg.WriteToLogFile();
#endif
}
@ -799,8 +845,9 @@ void Logger::HeapSampleBeginEvent(const char* space, const char* kind) {
void Logger::HeapSampleEndEvent(const char* space, const char* kind) {
#ifdef ENABLE_LOGGING_AND_PROFILING
if (logfile_ == NULL || !FLAG_log_gc) return;
ScopedLock sl(mutex_);
fprintf(logfile_, "heap-sample-end,\"%s\",\"%s\"\n", space, kind);
LogMessageBuilder msg;
msg.Append("heap-sample-end,\"%s\",\"%s\"\n", space, kind);
msg.WriteToLogFile();
#endif
}
@ -808,8 +855,9 @@ void Logger::HeapSampleEndEvent(const char* space, const char* kind) {
void Logger::HeapSampleItemEvent(const char* type, int number, int bytes) {
#ifdef ENABLE_LOGGING_AND_PROFILING
if (logfile_ == NULL || !FLAG_log_gc) return;
ScopedLock sl(mutex_);
fprintf(logfile_, "heap-sample-item,%s,%d,%d\n", type, number, bytes);
LogMessageBuilder msg;
msg.Append("heap-sample-item,%s,%d,%d\n", type, number, bytes);
msg.WriteToLogFile();
#endif
}
@ -817,8 +865,9 @@ void Logger::HeapSampleItemEvent(const char* type, int number, int bytes) {
void Logger::DebugTag(const char* call_site_tag) {
#ifdef ENABLE_LOGGING_AND_PROFILING
if (logfile_ == NULL || !FLAG_log) return;
ScopedLock sl(mutex_);
fprintf(logfile_, "debug-tag,%s\n", call_site_tag);
LogMessageBuilder msg;
msg.Append("debug-tag,%s\n", call_site_tag);
msg.WriteToLogFile();
#endif
}
@ -831,13 +880,13 @@ void Logger::DebugEvent(const char* event_type, Vector<uint16_t> parameter) {
s.AddCharacter(static_cast<char>(parameter[i]));
}
char* parameter_string = s.Finalize();
ScopedLock sl(mutex_);
fprintf(logfile_,
"debug-queue-event,%s,%15.3f,%s\n",
event_type,
OS::TimeCurrentMillis(),
parameter_string);
LogMessageBuilder msg;
msg.Append("debug-queue-event,%s,%15.3f,%s\n",
event_type,
OS::TimeCurrentMillis(),
parameter_string);
DeleteArray(parameter_string);
msg.WriteToLogFile();
#endif
}
@ -845,11 +894,14 @@ void Logger::DebugEvent(const char* event_type, Vector<uint16_t> parameter) {
#ifdef ENABLE_LOGGING_AND_PROFILING
void Logger::TickEvent(TickSample* sample, bool overflow) {
if (logfile_ == NULL || !FLAG_prof) return;
ScopedLock sl(mutex_);
fprintf(logfile_, "tick,0x%x,0x%x,%d", sample->pc, sample->sp,
static_cast<int>(sample->state));
if (overflow) fprintf(logfile_, ",overflow");
fprintf(logfile_, "\n");
LogMessageBuilder msg;
msg.Append("tick,0x%x,0x%x,%d", sample->pc, sample->sp,
static_cast<int>(sample->state));
if (overflow) {
msg.Append(",overflow");
}
msg.Append('\n');
msg.WriteToLogFile();
}
@ -873,6 +925,7 @@ bool Logger::Setup() {
#ifdef ENABLE_LOGGING_AND_PROFILING
// --log-all enables all the log flags.
if (FLAG_log_all) {
FLAG_log_runtime = true;
FLAG_log_api = true;
FLAG_log_code = true;
FLAG_log_gc = true;
@ -884,8 +937,8 @@ bool Logger::Setup() {
// --prof implies --log-code.
if (FLAG_prof) FLAG_log_code = true;
bool open_log_file = FLAG_log || FLAG_log_api || FLAG_log_code
|| FLAG_log_gc || FLAG_log_handles || FLAG_log_suspect
bool open_log_file = FLAG_log || FLAG_log_runtime || FLAG_log_api
|| FLAG_log_code || FLAG_log_gc || FLAG_log_handles || FLAG_log_suspect
|| FLAG_log_regexp || FLAG_log_state_changes;
// If we're logging anything, we need to open the log file.

2
src/log.h
View File

@ -218,8 +218,6 @@ class Logger {
// Emits the source code of a regexp. Used by regexp events.
static void LogRegExpSource(Handle<JSRegExp> regexp);
static void LogString(Handle<String> str, bool show_impl_info);
// Emits a profiler tick event. Used by the profiler thread.
static void TickEvent(TickSample* sample, bool overflow);

4
src/runtime.cc
View File

@ -6037,9 +6037,9 @@ static Object* Runtime_ListNatives(Arguments args) {
static Object* Runtime_Log(Arguments args) {
ASSERT(args.length() == 2);
String* format = String::cast(args[0]);
CONVERT_CHECKED(String, format, args[0]);
CONVERT_CHECKED(JSArray, elms, args[1]);
Vector<const char> chars = format->ToAsciiVector();
JSArray* elms = JSArray::cast(args[1]);
Logger::LogRuntime(chars, elms);
return Heap::undefined_value();
}