Faster reccmp.py on linux (#62)

* reccmp: avoid repeated execution of winepath

Executing winepath many times is slow,
so try we like to avoid it as much as possible.

When the path start with a known prefix, replace it with
a cached prefix and do some string manipulation.

This change reduces execution time of reccmp.py from 90s to 2s.

Which is nice.

m

* reccmp: continue looking when source cannot be found

Most often, the reasons is mismatched sources.

* reccmp: add basic logging + optional debug

* Read the addresses in the exe headers as little endian

tools/reccmp/reccmp.py

@@ -6,6 +6,7 @@
 import difflib
 import struct
 import subprocess
+import logging
 import os
 import sys
 import colorama
@@ -24,8 +25,14 @@
 parser.add_argument('--svg-icon', metavar='icon', help='Icon to use in SVG (PNG)')
 parser.add_argument('--print-rec-addr', action='store_true', help='Print addresses of recompiled functions too')
 
+parser.set_defaults(loglevel=logging.INFO)
+parser.add_argument('--debug', action='store_const', const=logging.DEBUG, dest='loglevel', help='Print script debug information')
+
 args = parser.parse_args()
 
+logging.basicConfig(level=args.loglevel, format='[%(levelname)s] %(message)s')
+logger = logging.getLogger(__name__)
+
 colorama.init()
 
 verbose = None
@@ -61,6 +68,7 @@
 # to file addresses
 class Bin:
   def __init__(self, filename):
+    logger.debug('Parsing headers of "%s"... ', filename)
     self.file = open(filename, 'rb')
 
     #HACK: Strictly, we should be parsing the header, but we know where
@@ -68,15 +76,16 @@ def __init__(self, filename):
 
     # Read ImageBase
     self.file.seek(0xB4)
-    self.imagebase = struct.unpack('i', self.file.read(4))[0]
+    self.imagebase, = struct.unpack('<i', self.file.read(4))
 
     # Read .text VirtualAddress
     self.file.seek(0x184)
-    self.textvirt = struct.unpack('i', self.file.read(4))[0]
+    self.textvirt, = struct.unpack('<i', self.file.read(4))
 
     # Read .text PointerToRawData
     self.file.seek(0x18C)
-    self.textraw = struct.unpack('i', self.file.read(4))[0]
+    self.textraw, = struct.unpack('<i', self.file.read(4))
+    logger.debug('... Parsing finished')
 
   def __del__(self):
     if self.file:
@@ -90,16 +99,38 @@ def read(self, offset, size):
     return self.file.read(size)
 
 class RecompiledInfo:
-  addr = None
-  size = None
-  name = None
-  start = None
+  def __init__(self):
+    self.addr = None
+    self.size = None
+    self.name = None
+    self.start = None
 
-def get_wine_path(fn):
-  return subprocess.check_output(['winepath', '-w', fn]).decode('utf-8').strip()
+class WinePathConverter:
+  def __init__(self, unix_cwd):
+    self.unix_cwd = unix_cwd
+    self.win_cwd = self._call_winepath_unix2win(self.unix_cwd)
 
-def get_unix_path(fn):
-  return subprocess.check_output(['winepath', fn]).decode('utf-8').strip()
+  def get_wine_path(self, unix_fn: str) -> str:
+    if unix_fn.startswith('./'):
+      return self.win_cmd + '\\' + unix_fn[2:].replace('/', '\\')
+    if unix_fn.startswith(self.unix_cwd):
+      return self.win_cwd + '\\' + unix_fn.removeprefix(self.unix_cwd).replace('/', '\\').lstrip('\\')
+    return self._call_winepath_unix2win(unix_fn)
+
+  def get_unix_path(self, win_fn: str) -> str:
+    if win_fn.startswith('.\\') or win_fn.startswith('./'):
+      return self.unix_cwd + '/' + win_fn[2:].replace('\\', '/')
+    if win_fn.startswith(self.win_cwd):
+      return self.unix_cwd + '/' + win_fn.removeprefix(self.win_cwd).replace('\\', '/')
+    return self._call_winepath_win2unix(win_fn)
+
+  @staticmethod
+  def _call_winepath_unix2win(fn: str) -> str:
+    return subprocess.check_output(['winepath', '-w', fn], text=True).strip()
+
+  @staticmethod
+  def _call_winepath_win2unix(fn: str) -> str:
+    return subprocess.check_output(['winepath', fn], text=True).strip()
 
 def get_file_in_script_dir(fn):
   return os.path.join(os.path.dirname(os.path.abspath(sys.argv[0])), fn)
@@ -109,22 +140,24 @@ class SymInfo:
   funcs = {}
   lines = {}
 
-  def __init__(self, pdb, file):
+  def __init__(self, pdb, file, wine_path_converter):
     call = [get_file_in_script_dir('cvdump.exe'), '-l', '-s']
 
-    if os.name != 'nt':
+    if wine_path_converter:
       # Run cvdump through wine and convert path to Windows-friendly wine path
       call.insert(0, 'wine')
-      call.append(get_wine_path(pdb))
+      call.append(wine_path_converter.get_wine_path(pdb))
     else:
       call.append(pdb)
 
-    print('Parsing %s...' % pdb)
-
+    logger.info('Parsing %s ...', pdb)
+    logger.debug('Command = %r', call)
     line_dump = subprocess.check_output(call).decode('utf-8').split('\r\n')
 
     current_section = None
 
+    logger.debug('Parsing output of cvdump.exe ...')
+
     for i, line in enumerate(line_dump):
       if line.startswith('***'):
         current_section = line[4:]
@@ -132,8 +165,6 @@ def __init__(self, pdb, file):
       if current_section == 'SYMBOLS' and 'S_GPROC32' in line:
         addr = int(line[26:34], 16)
 
-
-
         info = RecompiledInfo()
         info.addr = addr + recompfile.imagebase + recompfile.textvirt
 
@@ -155,9 +186,9 @@ def __init__(self, pdb, file):
       elif current_section == 'LINES' and line.startswith('  ') and not line.startswith('   '):
         sourcepath = line.split()[0]
 
-        if os.name != 'nt':
+        if wine_path_converter:
           # Convert filename to Unix path for file compare
-          sourcepath = get_unix_path(sourcepath)
+          sourcepath = wine_path_converter.get_unix_path(sourcepath)
 
         if sourcepath not in self.lines:
           self.lines[sourcepath] = {}
@@ -178,18 +209,23 @@ def __init__(self, pdb, file):
 
           j += 1
 
+    logger.debug('... Parsing output of cvdump.exe finished')
+
   def get_recompiled_address(self, filename, line):
     addr = None
     found = False
 
-    #print('Looking for ' + filename + ' line ' + str(line))
+    logger.debug('Looking for %s:%d', filename, line)
 
     for fn in self.lines:
       # Sometimes a PDB is compiled with a relative path while we always have
       # an absolute path. Therefore we must
-      if os.path.samefile(fn, filename):
-        filename = fn
-        break
+      try:
+        if os.path.samefile(fn, filename):
+          filename = fn
+          break
+      except FileNotFoundError as e:
+        continue
 
     if filename in self.lines and line in self.lines[fn]:
       addr = self.lines[fn][line]
@@ -197,13 +233,16 @@ def get_recompiled_address(self, filename, line):
       if addr in self.funcs:
         return self.funcs[addr]
       else:
-        print('Failed to find function symbol with address: %s' % hex(addr))
+        logger.error('Failed to find function symbol with address: 0x%x', addr)
     else:
-      print('Failed to find function symbol with filename and line: %s:%s' % (filename, str(line)))
+      logger.error('Failed to find function symbol with filename and line: %s:%d', filename, line)
 
+wine_path_converter = None
+if os.name != 'nt':
+  wine_path_converter = WinePathConverter(source)
 origfile = Bin(original)
 recompfile = Bin(recomp)
-syminfo = SymInfo(syms, recompfile)
+syminfo = SymInfo(syms, recompfile, wine_path_converter)
 
 print()