Include all the code in code creation log events. The code object header size...

Include all the code in code creation log events. The code object header size is now added to the size Before ticks the last instructions of a JavaScript functions ended up as unaccounted in the profile.Include ticks in the the last created code object in the profile.Show the unaccounted ticks in the profile as a percentage together with the rest. Added an option to ignore unaccounted ticks in the percentage calculation.
Review URL: http://codereview.chromium.org/21410

git-svn-id: http://v8.googlecode.com/svn/branches/bleeding_edge@1295 ce2b1a6d-e550-0410-aec6-3dcde31c8c00

src/log.cc

@@ -679,13 +679,22 @@ void Logger::DeleteEvent(const char* name, void* object) {
 }
 
 
+int Logger::CodeObjectSize(Code* code) {
+  // Check that the assumptions about the layout of the code object holds.
+  ASSERT_EQ(reinterpret_cast<unsigned int>(code->instruction_start()) -
+            reinterpret_cast<unsigned int>(code->address()),
+            Code::kHeaderSize);
+  return code->instruction_size() + Code::kHeaderSize;
+}
+
+
 void Logger::CodeCreateEvent(const char* tag, Code* code, const char* comment) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
   if (logfile_ == NULL || !FLAG_log_code) return;
   LogMessageBuilder msg;
   msg.Append("code-creation,%s,0x%x,%d,\"", tag,
              reinterpret_cast<unsigned int>(code->address()),
-             code->instruction_size());
+             CodeObjectSize(code));
   for (const char* p = comment; *p != '\0'; p++) {
     if (*p == '"') {
       msg.Append('\\');
@@ -707,7 +716,7 @@ void Logger::CodeCreateEvent(const char* tag, Code* code, String* name) {
       name->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
   msg.Append("code-creation,%s,0x%x,%d,\"%s\"\n", tag,
              reinterpret_cast<unsigned int>(code->address()),
-             code->instruction_size(), *str);
+             CodeObjectSize(code), *str);
   msg.WriteToLogFile();
 #endif
 }
@@ -724,7 +733,8 @@ void Logger::CodeCreateEvent(const char* tag, Code* code, String* name,
       source->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
   msg.Append("code-creation,%s,0x%x,%d,\"%s %s:%d\"\n", tag,
              reinterpret_cast<unsigned int>(code->address()),
-             code->instruction_size(), *str, *sourcestr, line);
+             CodeObjectSize(code),
+             *str, *sourcestr, line);
   msg.WriteToLogFile();
 #endif
 }
@@ -736,7 +746,7 @@ void Logger::CodeCreateEvent(const char* tag, Code* code, int args_count) {
   LogMessageBuilder msg;
   msg.Append("code-creation,%s,0x%x,%d,\"args_count: %d\"\n", tag,
              reinterpret_cast<unsigned int>(code->address()),
-             code->instruction_size(),
+             CodeObjectSize(code),
              args_count);
   msg.WriteToLogFile();
 #endif

src/log.h

@@ -215,6 +215,10 @@ class Logger {
 
  private:
 
+  // Calculate the size of the code object to report for log events. This takes
+  // the layout of the code object into account.
+  static int CodeObjectSize(Code* code);
+
   // Emits the source code of a regexp. Used by regexp events.
   static void LogRegExpSource(Handle<JSRegExp> regexp);
 

tools/linux-tick-processor.py

@@ -60,9 +60,10 @@ def Usage():
 
 def Main():
   # parse command line options
+  ignore_unknown = False
   state = None;
   try:
-    opts, args = getopt.getopt(sys.argv[1:], "jgco", ["js", "gc", "compiler", "other"])
+    opts, args = getopt.getopt(sys.argv[1:], "jgco", ["js", "gc", "compiler", "other", "ignore-unknown"])
   except getopt.GetoptError:
     usage()
   # process options.
@@ -75,11 +76,13 @@ def Main():
       state = 2
     if key in ("-o", "--other"):
       state = 3
+    if key in ("--ignore-unknown"):
+      ignore_unknown = True
   # do the processing.
   if len(args) != 1:
       Usage();
   tick_processor = LinuxTickProcessor()
-  tick_processor.ProcessLogfile(args[0], state)
+  tick_processor.ProcessLogfile(args[0], state, ignore_unknown)
   tick_processor.PrintResults()
 
 if __name__ == '__main__':

tools/tickprocessor.py

@@ -156,10 +156,14 @@ class TickProcessor(object):
     self.number_of_library_ticks = 0
     self.unaccounted_number_of_ticks = 0
     self.excluded_number_of_ticks = 0
+    # Flag indicating whether to ignore unaccounted ticks in the report
+    self.ignore_unknown = False
 
-  def ProcessLogfile(self, filename, included_state = None):
+  def ProcessLogfile(self, filename, included_state = None, ignore_unknown = False):
     self.log_file = filename
     self.included_state = included_state
+    self.ignore_unknown = ignore_unknown
+
     try:
       logfile = open(filename, 'rb')
     except IOError:
@@ -253,7 +257,7 @@ class TickProcessor(object):
         return entry
     max = self.js_entries.FindMax()
     min = self.js_entries.FindMin()
-    if max != None and pc < max.key and pc > min.key:
+    if max != None and pc < (max.key + max.value.size) and pc > min.key:
       return self.js_entries.FindGreatestsLessThan(pc).value
     return None
 
@@ -289,6 +293,13 @@ class TickProcessor(object):
       js_entries = self.js_entries.ExportValueList()
       js_entries.extend(self.deleted_code)
       cpp_entries = self.cpp_entries.ExportValueList()
+      # Print the unknown ticks percentage if they are not ignored.
+      if not self.ignore_unknown and self.unaccounted_number_of_ticks > 0:
+        self.PrintHeader('Unknown')
+        unknown_percentage = self.unaccounted_number_of_ticks * 100.0 / self.total_number_of_ticks
+        print('  %(total)5.1f%%' % {
+          'total' : unknown_percentage,
+        })
       # Print the library ticks.
       self.PrintHeader('Shared libraries')
       self.PrintEntries(cpp_entries, lambda e:e.IsSharedLibraryEntry())
@@ -309,7 +320,12 @@ class TickProcessor(object):
     print('   total  nonlib   name')
 
   def PrintEntries(self, entries, condition):
-    number_of_accounted_ticks = self.total_number_of_ticks - self.unaccounted_number_of_ticks
+    # If ignoring unaccounted ticks don't include these in percentage
+    # calculations
+    number_of_accounted_ticks = self.total_number_of_ticks
+    if self.ignore_unknown:
+      number_of_accounted_ticks -= self.unaccounted_number_of_ticks
+
     number_of_non_library_ticks = number_of_accounted_ticks - self.number_of_library_ticks
     entries.sort(key=lambda e:e.tick_count, reverse=True)
     for entry in entries:

tools/windows-tick-processor.py

@@ -113,9 +113,10 @@ def Usage():
 
 def Main():
   # parse command line options
+  ignore_unknown = False
   state = None;
   try:
-    opts, args = getopt.getopt(sys.argv[1:], "jgco", ["js", "gc", "compiler", "other"])
+    opts, args = getopt.getopt(sys.argv[1:], "jgco", ["js", "gc", "compiler", "other", "ignore-unknown"])
   except getopt.GetoptError:
     usage()
   # process options.
@@ -128,12 +129,14 @@ def Main():
       state = 2
     if key in ("-o", "--other"):
       state = 3
+    if key in ("--ignore-unknown"):
+      ignore_unknown = True
   # do the processing.
   if len(args) != 2:
       Usage();
   tickprocessor = WindowsTickProcessor()
   tickprocessor.ParseMapFile(args[0])
-  tickprocessor.ProcessLogfile(args[1], state)
+  tickprocessor.ProcessLogfile(args[1], state, ignore_unknown)
   tickprocessor.PrintResults()
 
 if __name__ == '__main__':