Author: [email protected]
Date: Tue Mar 31 02:06:37 2009
New Revision: 1646
Modified:
branches/bleeding_edge/src/log.cc
branches/bleeding_edge/src/log.h
branches/bleeding_edge/src/platform-posix.cc
branches/bleeding_edge/src/platform-win32.cc
branches/bleeding_edge/src/platform.h
branches/bleeding_edge/src/regexp-macro-assembler-ia32.cc
branches/bleeding_edge/tools/tickprocessor.py
Log:
Fixed numerous issues that were causing errors in profiler log processing
on a real web application loaded in the test shell.
Also implemented output of JSON-encoded call stacks for profiler
prototype.
Review URL: http://codereview.chromium.org/56064
Modified: branches/bleeding_edge/src/log.cc
==============================================================================
--- branches/bleeding_edge/src/log.cc (original)
+++ branches/bleeding_edge/src/log.cc Tue Mar 31 02:06:37 2009
@@ -299,6 +299,7 @@
void AppendDetailed(String* str, bool show_impl_info);
void WriteToLogFile();
+ void WriteCStringToLogFile(const char* str);
private:
ScopedLock sl;
@@ -395,6 +396,14 @@
ASSERT(rv == static_cast<size_t>(pos_));
USE(rv);
}
+
+// Write a null-terminated string to to the log file currently opened.
+void LogMessageBuilder::WriteCStringToLogFile(const char* str) {
+ size_t len = strlen(str);
+ size_t rv = fwrite(str, 1, len, Logger::logfile_);
+ ASSERT(rv == len);
+ USE(rv);
+}
#endif
@@ -417,8 +426,7 @@
#ifdef ENABLE_LOGGING_AND_PROFILING
if (logfile_ == NULL || !FLAG_log_code) return;
LogMessageBuilder msg;
- msg.Append("%s", content);
- msg.WriteToLogFile();
+ msg.WriteCStringToLogFile(content);
#endif
}
@@ -758,6 +766,20 @@
}
+void Logger::RegExpCodeCreateEvent(Code* code, String* source) {
+#ifdef ENABLE_LOGGING_AND_PROFILING
+ if (logfile_ == NULL || !FLAG_log_code) return;
+ LogMessageBuilder msg;
+ msg.Append("code-creation,%s,0x%x,%d,\"", "RegExp",
+ reinterpret_cast<unsigned int>(code->address()),
+ code->ExecutableSize());
+ msg.AppendDetailed(source, false);
+ msg.Append("\"\n");
+ msg.WriteToLogFile();
+#endif
+}
+
+
void Logger::CodeAllocateEvent(Code* code, Assembler* assem) {
#ifdef ENABLE_LOGGING_AND_PROFILING
if (logfile_ == NULL || !FLAG_log_code) return;
@@ -1010,9 +1032,9 @@
}
}
SmartPointer<const char> expanded = stream.ToCString();
- logfile_ = OS::FOpen(*expanded, "w");
+ logfile_ = OS::FOpen(*expanded, OS::LogFileOpenMode);
} else {
- logfile_ = OS::FOpen(FLAG_logfile, "w");
+ logfile_ = OS::FOpen(FLAG_logfile, OS::LogFileOpenMode);
}
message_buffer_ = NewArray<char>(kMessageBufferSize);
mutex_ = OS::CreateMutex();
Modified: branches/bleeding_edge/src/log.h
==============================================================================
--- branches/bleeding_edge/src/log.h (original)
+++ branches/bleeding_edge/src/log.h Tue Mar 31 02:06:37 2009
@@ -167,6 +167,8 @@
static void CodeCreateEvent(const char* tag, Code* code, String* name,
String* source, int line);
static void CodeCreateEvent(const char* tag, Code* code, int args_count);
+ // Emits a code create event for a RegExp.
+ static void RegExpCodeCreateEvent(Code* code, String* source);
static void CodeAllocateEvent(Code* code, Assembler* assem);
// Emits a code move event.
static void CodeMoveEvent(Address from, Address to);
@@ -227,7 +229,7 @@
static void UncheckedStringEvent(const char* name, const char* value);
// Size of buffer used for formatting log messages.
- static const int kMessageBufferSize = 256;
+ static const int kMessageBufferSize = 2048;
// Buffer used for formatting log messages. This is a singleton buffer
and
// mutex_ should be acquired before using it.
Modified: branches/bleeding_edge/src/platform-posix.cc
==============================================================================
--- branches/bleeding_edge/src/platform-posix.cc (original)
+++ branches/bleeding_edge/src/platform-posix.cc Tue Mar 31 02:06:37 2009
@@ -113,6 +113,9 @@
}
+const char* OS::LogFileOpenMode = "w";
+
+
void OS::Print(const char* format, ...) {
va_list args;
va_start(args, format);
Modified: branches/bleeding_edge/src/platform-win32.cc
==============================================================================
--- branches/bleeding_edge/src/platform-win32.cc (original)
+++ branches/bleeding_edge/src/platform-win32.cc Tue Mar 31 02:06:37 2009
@@ -683,6 +683,10 @@
}
+// Open log file in binary mode to avoid /n -> /r/n conversion.
+const char* OS::LogFileOpenMode = "wb";
+
+
// Print (debug) message to console.
void OS::Print(const char* format, ...) {
va_list args;
Modified: branches/bleeding_edge/src/platform.h
==============================================================================
--- branches/bleeding_edge/src/platform.h (original)
+++ branches/bleeding_edge/src/platform.h Tue Mar 31 02:06:37 2009
@@ -151,6 +151,9 @@
static FILE* FOpen(const char* path, const char* mode);
+ // Log file open mode is platform-dependent due to line ends issues.
+ static const char* LogFileOpenMode;
+
// Print output to console. This is mostly used for debugging output.
// On platforms that has standard terminal output, the output
// should go to stdout.
@@ -484,7 +487,7 @@
unsigned int sp; // Stack pointer.
unsigned int fp; // Frame pointer.
StateTag state; // The state of the VM.
- static const int kMaxFramesCount = 5;
+ static const int kMaxFramesCount = 100;
EmbeddedVector<Address, kMaxFramesCount> stack; // Call stack.
int frames_count; // Number of captured frames.
};
Modified: branches/bleeding_edge/src/regexp-macro-assembler-ia32.cc
==============================================================================
--- branches/bleeding_edge/src/regexp-macro-assembler-ia32.cc (original)
+++ branches/bleeding_edge/src/regexp-macro-assembler-ia32.cc Tue Mar 31
02:06:37 2009
@@ -825,7 +825,7 @@
NULL,
Code::ComputeFlags(Code::REGEXP),
masm_->CodeObject());
- LOG(CodeCreateEvent("RegExp", *code, *(source->ToCString())));
+ LOG(RegExpCodeCreateEvent(*code, *source));
return Handle<Object>::cast(code);
}
Modified: branches/bleeding_edge/tools/tickprocessor.py
==============================================================================
--- branches/bleeding_edge/tools/tickprocessor.py (original)
+++ branches/bleeding_edge/tools/tickprocessor.py Tue Mar 31 02:06:37 2009
@@ -147,6 +147,27 @@
self.regions = []
+class FunctionEnumerator(object):
+
+ def __init__(self):
+ self.known_funcs = {}
+ self.next_func_id = 0
+
+ def GetFunctionId(self, name):
+ if not self.known_funcs.has_key(name):
+ self.known_funcs[name] = self.next_func_id
+ self.next_func_id += 1
+ return self.known_funcs[name]
+
+ def GetKnownFunctions(self):
+ known_funcs_items = self.known_funcs.items();
+ known_funcs_items.sort(key = itemgetter(1))
+ result = []
+ for func, id_not_used in known_funcs_items:
+ result.append(func)
+ return result
+
+
VMStates = { 'JS': 0, 'GC': 1, 'COMPILER': 2, 'OTHER': 3, 'EXTERNAL' : 4 }
@@ -170,37 +191,46 @@
self.number_of_gc_ticks = 0
# Flag indicating whether to ignore unaccounted ticks in the report
self.ignore_unknown = False
+ self.func_enum = FunctionEnumerator()
+ self.packed_stacks = []
- def ProcessLogfile(self, filename, included_state = None, ignore_unknown
= False, separate_ic = False):
+ def ProcessLogfile(self, filename, included_state = None, ignore_unknown
= False, separate_ic = False, call_graph_json = False):
self.log_file = filename
self.included_state = included_state
self.ignore_unknown = ignore_unknown
self.separate_ic = separate_ic
+ self.call_graph_json = call_graph_json
try:
logfile = open(filename, 'rb')
except IOError:
sys.exit("Could not open logfile: " + filename)
try:
- logreader = csv.reader(logfile)
- for row in logreader:
- if row[0] == 'tick':
- self.ProcessTick(int(row[1], 16), int(row[2], 16), int(row[3]),
self.PreprocessStack(row[4:]))
- elif row[0] == 'code-creation':
- self.ProcessCodeCreation(row[1], int(row[2], 16), int(row[3]),
row[4])
- elif row[0] == 'code-move':
- self.ProcessCodeMove(int(row[1], 16), int(row[2], 16))
- elif row[0] == 'code-delete':
- self.ProcessCodeDelete(int(row[1], 16))
- elif row[0] == 'shared-library':
- self.AddSharedLibraryEntry(row[1], int(row[2], 16), int(row[3],
16))
- self.ParseVMSymbols(row[1], int(row[2], 16), int(row[3], 16))
- elif row[0] == 'begin-code-region':
- self.ProcessBeginCodeRegion(int(row[1], 16), int(row[2], 16),
int(row[3], 16), row[4])
- elif row[0] == 'end-code-region':
- self.ProcessEndCodeRegion(int(row[1], 16), int(row[2], 16),
int(row[3], 16))
- elif row[0] == 'code-allocate':
- self.ProcessCodeAllocate(int(row[1], 16), int(row[2], 16))
+ try:
+ logreader = csv.reader(logfile)
+ row_num = 1
+ for row in logreader:
+ row_num += 1
+ if row[0] == 'tick':
+ self.ProcessTick(int(row[1], 16), int(row[2], 16),
int(row[3]), self.PreprocessStack(row[4:]))
+ elif row[0] == 'code-creation':
+ self.ProcessCodeCreation(row[1], int(row[2], 16), int(row[3]),
row[4])
+ elif row[0] == 'code-move':
+ self.ProcessCodeMove(int(row[1], 16), int(row[2], 16))
+ elif row[0] == 'code-delete':
+ self.ProcessCodeDelete(int(row[1], 16))
+ elif row[0] == 'shared-library':
+ self.AddSharedLibraryEntry(row[1], int(row[2], 16),
int(row[3], 16))
+ self.ParseVMSymbols(row[1], int(row[2], 16), int(row[3], 16))
+ elif row[0] == 'begin-code-region':
+ self.ProcessBeginCodeRegion(int(row[1], 16), int(row[2], 16),
int(row[3], 16), row[4])
+ elif row[0] == 'end-code-region':
+ self.ProcessEndCodeRegion(int(row[1], 16), int(row[2], 16),
int(row[3], 16))
+ elif row[0] == 'code-allocate':
+ self.ProcessCodeAllocate(int(row[1], 16), int(row[2], 16))
+ except csv.Error:
+ print("parse error in line " + str(row_num))
+ raise
finally:
logfile.close()
@@ -312,8 +342,25 @@
self.unaccounted_number_of_ticks += 1
else:
entry.Tick(pc, self.ProcessStack(stack))
+ if self.call_graph_json:
+ self.AddToPackedStacks(pc, stack)
+
+ def AddToPackedStacks(self, pc, stack):
+ full_stack = stack
+ full_stack.insert(0, pc)
+ func_names = self.ProcessStack(full_stack)
+ func_ids = []
+ for func in func_names:
+ func_ids.append(self.func_enum.GetFunctionId(func))
+ self.packed_stacks.append(func_ids)
def PrintResults(self):
+ if not self.call_graph_json:
+ self.PrintStatistics()
+ else:
+ self.PrintCallGraphJSON()
+
+ def PrintStatistics(self):
print('Statistical profiling result from %s, (%d ticks, %d
unaccounted, %d excluded).' %
(self.log_file,
self.total_number_of_ticks,
@@ -412,6 +459,16 @@
'call_path' : stack[0] + ' <- ' + stack[1]
})
+ def PrintCallGraphJSON(self):
+ print('\nvar __profile_funcs = ["' +
+ '",\n"'.join(self.func_enum.GetKnownFunctions()) +
+ '"];')
+ print('var __profile_ticks = [')
+ str_packed_stacks = []
+ for stack in self.packed_stacks:
+ str_packed_stacks.append('[' + ','.join(map(str, stack)) + ']')
+ print(',\n'.join(str_packed_stacks))
+ print('];')
class CmdLineProcessor(object):
@@ -422,12 +479,14 @@
"other",
"external",
"ignore-unknown",
- "separate-ic"]
+ "separate-ic",
+ "call-graph-json"]
# default values
self.state = None
self.ignore_unknown = False
self.log_file = None
self.separate_ic = False
+ self.call_graph_json = False
def ProcessArguments(self):
try:
@@ -449,6 +508,8 @@
self.ignore_unknown = True
if key in ("--separate-ic"):
self.separate_ic = True
+ if key in ("--call-graph-json"):
+ self.call_graph_json = True
self.ProcessRequiredArgs(args)
def ProcessRequiredArgs(self, args):
@@ -466,7 +527,8 @@
sys.exit(2)
def RunLogfileProcessing(self, tick_processor):
- tick_processor.ProcessLogfile(self.log_file, self.state,
self.ignore_unknown, self.separate_ic)
+ tick_processor.ProcessLogfile(self.log_file, self.state,
self.ignore_unknown,
+ self.separate_ic, self.call_graph_json)
if __name__ == '__main__':
--~--~---------~--~----~------------~-------~--~----~
v8-dev mailing list
[email protected]
http://groups.google.com/group/v8-dev
-~----------~----~----~----~------~----~------~--~---
