Check that all symbolized methods in the output orderfile are in their own linker section in the or…

tools/cygprofile/symbolize.py

 #!/usr/bin/python
 # Copyright 2013 The Chromium Authors. All rights reserved.
 # Use of this source code is governed by a BSD-style license that can be
 # found in the LICENSE file.
 
 """Symbolize log file produced by cypgofile instrumentation.
 
 Given a log file and the binary being profiled (e.g. executable, shared
 library), the script can produce three different outputs: 1) symbols for the
 addresses, 2) function and line numbers for the addresses, or 3) an order file.
@@ skipping 45 matching lines @@
   for call_line in call_lines:
     (sec_timestamp, usec_timestamp) = map(int, call_line[0:2])
     callee_id = call_line[2]
     addr = int(call_line[3], 16)
     if vm_start < addr:
       addr -= vm_start
       call_info.append((sec_timestamp, usec_timestamp, callee_id, addr))
 
   return call_info
 
+def GetOutputLines(cmd):

[pasko, 2014/12/10 12:07:05]

we are ignoring stderr (which is arguable also an output?), so probably a good
idea to call it like:
GetStdoutFromCommand()

[azarchs, 2014/12/10 17:13:33]

Done.

+  p = subprocess.Popen(cmd, stdout=subprocess.PIPE)
+  output = p.communicate()[0]
+  return output.split('\n')
 
 def ParseLibSymbols(lib_file):
   """Get output from running nm and greping for text symbols.
 
   Args:
     lib_file: the library or executable that contains the profiled code
 
   Returns:
     list of sorted unique addresses and corresponding size of function symbols
     in lib_file and map of addresses to all symbols at a particular address
   """
   cmd = ['nm', '-S', '-n', lib_file]
-  nm_p = subprocess.Popen(cmd, stdout=subprocess.PIPE)
-  output = nm_p.communicate()[0]
-  nm_lines = output.split('\n')
+  nm_lines = GetOutputLines(cmd)
 
   nm_symbols = []
   for nm_line in nm_lines:
     if any(str in nm_line for str in (' t ', ' W ', ' T ')):
       nm_symbols.append(nm_line)
 
   nm_index = 0
   unique_addrs = []
   address_map = {}
   while nm_index < len(nm_symbols):
@@ skipping 72 matching lines @@
 
 def FindFunctions(addr, unique_addrs, address_map):
   """Find function symbol names at address addr."""
   return address_map[BinarySearchAddresses(addr, 0, len(unique_addrs) - 1,
                                            unique_addrs)]
 
 
 def AddrToLine(addr, lib_file):
   """Use addr2line to determine line info of a particular address."""
   cmd = ['addr2line', '-f', '-e', lib_file, hex(addr)]
-  p = subprocess.Popen(cmd, stdout=subprocess.PIPE)
-  output = (p.communicate()[0]).split('\n')
+  output = GetOutputLines(cmd)
   line = output[0]
   index = 1
   while index < len(output):

[pasko, 2014/12/10 12:07:05]

with the given arguments addr2line always outputs 2 lines, so it would be *much*
clearer to:
assert(len(output) == 2)
line = ':'.join(output)

wtf_per_day += 1

[azarchs, 2014/12/10 17:13:33]

Done.

     line = line + ':' + output[index]
     index += 1
   return line
 
+def ObjectFiles(obj_dir):

[pasko, 2014/12/10 12:07:05]

GetObjectFiles

[azarchs, 2014/12/10 17:13:33]

Done.

+  """ Gets the list of object files in the output folder """

[pasko, 2014/12/10 12:07:05]

this is on linux, so s/folder/directory./ :)

[azarchs, 2014/12/10 17:13:33]

Done.

+  obj_files = []
+  for (dirpath, dirnames, filenames) in os.walk(obj_dir):
+    for file_name in filenames:
+      if file_name.endswith('.o'):
+        obj_files.append(os.path.join(dirpath, file_name))
+  return obj_files
+
+def SymbolToSection(obj_dir):
+  """ Gets a mapping from symbol to linker section name by scanning all
+      of the object files """

[pasko, 2014/12/10 12:07:05]

s/files/files./

+  object_files = ObjectFiles(obj_dir)
+  symbol_map = {}
+  for obj_file in object_files:
+    cmd = ['objdump', '-w', '-t', obj_file]
+    objects = GetOutputLines(cmd)

[pasko, 2014/12/10 12:07:05]

in lunix/binutils land 'object' and 'object file' are synonymous, and these are
rather symbol_lines (which we then later extract a symbols from)

[azarchs, 2014/12/10 17:13:33]

Done.

+    for object_line in objects:
+      items = object_line.split()

[pasko, 2014/12/10 12:07:05]

it is non-obvious that simple splitting like this works because the
one-character fields are not necessarily separated by spaces (unfortunately).
But we can do it because in object files we see only these patterns:
" g     F" <- global function
" l     F" <- local function
"  w    F" <- weak function (overrideable at link-time, both dynamic and static
linking)

all of them can be parsed as 2 fields. Please explain that in a comment.

[azarchs, 2014/12/10 17:13:33]

Done.

+      if len(items) > 4 and items[2] == 'F':
+        # This symbol is a function
+        symbol = items[len(items) - 1]

[pasko, 2014/12/10 12:07:05]

more pythonic, but arguably less readable:
symbol = items[-1]

what is our style?

[azarchs, 2014/12/10 17:13:33]

Style guide says nothing on the subject.  I prefer the more readable version.

[pasko, 2014/12/10 17:56:09]

Acknowledged.

+        if symbol.startswith('.LTHUNK'):
+          continue
+        section = items[3]
+        if symbol in symbol_map and symbol_map[symbol] != section:
+          sys.stderr.write('WARNING: Symbol ' + symbol +
+                           ' in conflicting sections ' + section +

[pasko, 2014/12/10 12:07:05]

I really don't see a problem with having a single symbol be in different
sections. It may mean different valid things (like not supposed to be linked
together, or having a weak symbol and a strong one in a different file).

[azarchs, 2014/12/10 17:13:33]

It doesn't currently happen.  If it did, which section would be specify in the
order file?  All of them?

+                           ' and ' + symbol_map[symbol] + '\n')
+        elif not section.startswith('.text.'):
+          sys.stderr.write('WARNING: Symbol ' + symbol +

[pasko, 2014/12/10 12:07:04]

should we limit the number of messages like this to say a 100? I am afraid that
something may go completely wrong, and we would print 250000 warningz

[azarchs, 2014/12/10 17:13:33]

Done.

+                           ' in incorrect section ' + section + '\n')
+        else:
+          symbol_map[symbol] = section

[pasko, 2014/12/10 12:07:05]

section_map or symbol_to_section_map would be better because when you write:
"""
section_map[symbol]
"""

it more clearly suggests that we are mapping symbols to sections.

[azarchs, 2014/12/10 17:13:33]

Done.

+  return symbol_map
 
 def main():
   """Write output for profiled run to standard out.
 
   The format of the output depends on the output type specified as the third
   command line argument.  The default output type is to symbolize the addresses
   of the functions called.
   """
   parser = optparse.OptionParser('usage: %prog [options] log_file lib_file')
   parser.add_option('-t', '--outputType', dest='output_type',
                     default='symbolize', type='string',
                     help='lineize or symbolize or orderfile')
 
   # Option for output type.  The log file and lib file arguments are required
   # by the script and therefore are not options.
   (options, args) = parser.parse_args()
   if len(args) != 2:
     parser.error('expected 2 args: log_file lib_file')
 
   (log_file, lib_file) = args
   output_type = options.output_type
 
+  obj_dir = os.path.abspath(os.path.join(os.path.dirname(lib_file), '../obj'))
+
   lib_name = lib_file.split('/')[-1].strip()
   log_file_lines = map(string.rstrip, open(log_file).readlines())
   call_info = ParseLogLines(log_file_lines)
   (unique_addrs, address_map) = ParseLibSymbols(lib_file)
 
   # Check for duplicate addresses in the log file, and print a warning if
   # duplicates are found. The instrumentation that produces the log file
   # should only print the first time a function is entered.
   addr_list = []
   for call in call_info:
     addr = call[3]
     if addr not in addr_list:
       addr_list.append(addr)
     else:
       print('WARNING: Address ' + hex(addr) + ' (line= ' +
             AddrToLine(addr, lib_file) + ') already profiled.')
 
+  symbol_map = SymbolToSection(obj_dir)
+
   for call in call_info:
     if output_type == 'lineize':
       symbol = AddrToLine(call[3], lib_file)
       print(str(call[0]) + ' ' + str(call[1]) + '\t' + str(call[2]) + '\t'
             + symbol)
     elif output_type == 'orderfile':
       try:
         symbols = FindFunctions(call[3], unique_addrs, address_map)
         for symbol in symbols:
-          print '.text.' + symbol
+          if symbol in symbol_map:
+            print symbol_map[symbol]
+          else:
+            sys.stderr.write('WARNING: Unknown symbol ' + symbol + '\n')

[pasko, 2014/12/10 12:07:05]

so this happens when a symbol is in the final library, but we did not find it in
an object, right? It makes sense to explain it in the comment or in the message
itself.

Same here about the amount of warnings printed, can we limit with a 100? Maybe a
class to print 100 first messages and ignore the rest? I see a pattern here :)

[azarchs, 2014/12/10 17:13:33]

Done.

         print ''
       except SymbolNotFoundException as e:
         sys.stderr.write('WARNING: Did not find function in binary. addr: '
                       + hex(addr) + '\n')
     else:
       try:
         symbols = FindFunctions(call[3], unique_addrs, address_map)
         print(str(call[0]) + ' ' + str(call[1]) + '\t' + str(call[2]) + '\t'
               + symbols[0])
         first_symbol = True
         for symbol in symbols:
           if not first_symbol:
             print '\t\t\t\t\t' + symbol
           else:
             first_symbol = False
       except SymbolNotFoundException as e:
         sys.stderr.write('WARNING: Did not find function in binary. addr: '
                       + hex(addr) + '\n')
 
 if __name__ == '__main__':
   main()