src/tools/heapcheck/heapcheck_test.py

   1 # Copyright (c) 2012 The Chromium Authors. All rights reserved.
   2 # Use of this source code is governed by a BSD-style license that can be
   3 # found in the LICENSE file.
   4
   5 """Wrapper for running the test under heapchecker and analyzing the output."""
   6
   7 import datetime
   8 import logging
   9 import os
  10 import re
  11
  12 import common
  13 import path_utils
  14 import suppressions
  15
  16
  17 class HeapcheckWrapper(object):
  18   TMP_FILE = 'heapcheck.log'
  19   SANITY_TEST_SUPPRESSION = "Heapcheck sanity test"
  20   LEAK_REPORT_RE = re.compile(
  21      'Leak of ([0-9]*) bytes in ([0-9]*) objects allocated from:')
  22   # Workaround for http://crbug.com/132867, see below.
  23   HOOKED_ALLOCATOR_RE = re.compile(
  24      'Hooked allocator frame not found, returning empty trace')
  25   STACK_LINE_RE = re.compile('\s*@\s*(?:0x)?[0-9a-fA-F]+\s*([^\n]*)')
  26   BORING_CALLERS = common.BoringCallers(mangled=False, use_re_wildcards=True)
  27
  28   def __init__(self, supp_files):
  29     self._mode = 'strict'
  30     self._timeout = 3600
  31     self._nocleanup_on_exit = False
  32     self._suppressions = []
  33     for fname in supp_files:
  34       self._suppressions.extend(suppressions.ReadSuppressionsFromFile(fname))
  35     if os.path.exists(self.TMP_FILE):
  36       os.remove(self.TMP_FILE)
  37
  38   def PutEnvAndLog(self, env_name, env_value):
  39     """Sets the env var |env_name| to |env_value| and writes to logging.info.
  40     """
  41     os.putenv(env_name, env_value)
  42     logging.info('export %s=%s', env_name, env_value)
  43
  44   def Execute(self):
  45     """Executes the app to be tested."""
  46     logging.info('starting execution...')
  47     proc = ['sh', path_utils.ScriptDir() + '/heapcheck_std.sh']
  48     proc += self._args
  49     self.PutEnvAndLog('G_SLICE', 'always-malloc')
  50     self.PutEnvAndLog('NSS_DISABLE_ARENA_FREE_LIST', '1')
  51     self.PutEnvAndLog('NSS_DISABLE_UNLOAD', '1')
  52     self.PutEnvAndLog('GTEST_DEATH_TEST_USE_FORK', '1')
  53     self.PutEnvAndLog('HEAPCHECK', self._mode)
  54     self.PutEnvAndLog('HEAP_CHECK_ERROR_EXIT_CODE', '0')
  55     self.PutEnvAndLog('HEAP_CHECK_MAX_LEAKS', '-1')
  56     self.PutEnvAndLog('KEEP_SHADOW_STACKS', '1')
  57     self.PutEnvAndLog('PPROF_PATH',
  58         path_utils.ScriptDir() +
  59         '/../../third_party/tcmalloc/chromium/src/pprof')
  60     self.PutEnvAndLog('LD_LIBRARY_PATH',
  61                       '/usr/lib/debug/:/usr/lib32/debug/')
  62     # CHROME_DEVEL_SANDBOX causes problems with heapcheck
  63     self.PutEnvAndLog('CHROME_DEVEL_SANDBOX', '');
  64
  65     return common.RunSubprocess(proc, self._timeout)
  66
  67   def Analyze(self, log_lines, check_sanity=False):
  68     """Analyzes the app's output and applies suppressions to the reports.
  69
  70     Analyze() searches the logs for leak reports and tries to apply
  71     suppressions to them. Unsuppressed reports and other log messages are
  72     dumped as is.
  73
  74     If |check_sanity| is True, the list of suppressed reports is searched for a
  75     report starting with SANITY_TEST_SUPPRESSION. If there isn't one, Analyze
  76     returns 2 regardless of the unsuppressed reports.
  77
  78     Args:
  79       log_lines:      An iterator over the app's log lines.
  80       check_sanity:   A flag that determines whether we should check the tool's
  81                       sanity.
  82     Returns:
  83       2, if the sanity check fails,
  84       1, if unsuppressed reports remain in the output and the sanity check
  85       passes,
  86       0, if all the errors are suppressed and the sanity check passes.
  87     """
  88     return_code = 0
  89     # leak signature: [number of bytes, number of objects]
  90     cur_leak_signature = None
  91     cur_stack = []
  92     cur_report = []
  93     reported_hashes = {}
  94     # Statistics grouped by suppression description:
  95     # [hit count, bytes, objects].
  96     used_suppressions = {}
  97     hooked_allocator_line_encountered = False
  98     for line in log_lines:
  99       line = line.rstrip()  # remove the trailing \n
 100       match = self.STACK_LINE_RE.match(line)
 101       if match:
 102         cur_stack.append(match.groups()[0])
 103         cur_report.append(line)
 104         continue
 105       else:
 106         if cur_stack:
 107           # Try to find the suppression that applies to the current leak stack.
 108           description = ''
 109           for supp in self._suppressions:
 110             if supp.Match(cur_stack):
 111               cur_stack = []
 112               description = supp.description
 113               break
 114           if cur_stack:
 115             if not cur_leak_signature:
 116               print 'Missing leak signature for the following stack: '
 117               for frame in cur_stack:
 118                 print '   ' + frame
 119               print 'Aborting...'
 120               return 3
 121
 122             # Drop boring callers from the stack to get less redundant info
 123             # and fewer unique reports.
 124             found_boring = False
 125             for i in range(1, len(cur_stack)):
 126               for j in self.BORING_CALLERS:
 127                 if re.match(j, cur_stack[i]):
 128                   cur_stack = cur_stack[:i]
 129                   cur_report = cur_report[:i]
 130                   found_boring = True
 131                   break
 132               if found_boring:
 133                 break
 134
 135             error_hash = hash("".join(cur_stack)) & 0xffffffffffffffff
 136             if error_hash not in reported_hashes:
 137               reported_hashes[error_hash] = 1
 138               # Print the report and set the return code to 1.
 139               print ('Leak of %d bytes in %d objects allocated from:'
 140                      % tuple(cur_leak_signature))
 141               print '\n'.join(cur_report)
 142               return_code = 1
 143               # Generate the suppression iff the stack contains more than one
 144               # frame (otherwise it's likely to be broken)
 145               if len(cur_stack) > 1 or found_boring:
 146                 print '\nSuppression (error hash=#%016X#):\n{'  % (error_hash)
 147                 print '   <insert_a_suppression_name_here>'
 148                 print '   Heapcheck:Leak'
 149                 for frame in cur_stack:
 150                   print '   fun:' + frame
 151                 print '}\n\n'
 152               else:
 153                 print ('This stack may be broken due to omitted frame pointers.'
 154                        ' It is not recommended to suppress it.\n')
 155           else:
 156             # Update the suppressions histogram.
 157             if description in used_suppressions:
 158               hits, bytes, objects = used_suppressions[description]
 159               hits += 1
 160               bytes += cur_leak_signature[0]
 161               objects += cur_leak_signature[1]
 162               used_suppressions[description] = [hits, bytes, objects]
 163             else:
 164               used_suppressions[description] = [1] + cur_leak_signature
 165         cur_stack = []
 166         cur_report = []
 167         cur_leak_signature = None
 168         match = self.LEAK_REPORT_RE.match(line)
 169         if match:
 170           cur_leak_signature = map(int, match.groups())
 171         else:
 172           match = self.HOOKED_ALLOCATOR_RE.match(line)
 173           if match:
 174             hooked_allocator_line_encountered = True
 175           else:
 176             print line
 177     # Print the list of suppressions used.
 178     is_sane = False
 179     if used_suppressions:
 180       print
 181       print '-----------------------------------------------------'
 182       print 'Suppressions used:'
 183       print '   count    bytes  objects name'
 184       histo = {}
 185       for description in used_suppressions:
 186         if description.startswith(HeapcheckWrapper.SANITY_TEST_SUPPRESSION):
 187           is_sane = True
 188         hits, bytes, objects = used_suppressions[description]
 189         line = '%8d %8d %8d %s' % (hits, bytes, objects, description)
 190         if hits in histo:
 191           histo[hits].append(line)
 192         else:
 193           histo[hits] = [line]
 194       keys = histo.keys()
 195       keys.sort()
 196       for count in keys:
 197         for line in histo[count]:
 198           print line
 199       print '-----------------------------------------------------'
 200     if hooked_allocator_line_encountered:
 201       print ('WARNING: Workaround for http://crbug.com/132867 (tons of '
 202              '"Hooked allocator frame not found, returning empty trace") '
 203              'in effect.')
 204     if check_sanity and not is_sane:
 205       logging.error("Sanity check failed")
 206       return 2
 207     else:
 208       return return_code
 209
 210   def RunTestsAndAnalyze(self, check_sanity):
 211     exec_retcode = self.Execute()
 212     log_file = file(self.TMP_FILE, 'r')
 213     analyze_retcode = self.Analyze(log_file, check_sanity)
 214     log_file.close()
 215
 216     if analyze_retcode:
 217       logging.error("Analyze failed.")
 218       return analyze_retcode
 219
 220     if exec_retcode:
 221       logging.error("Test execution failed.")
 222       return exec_retcode
 223     else:
 224       logging.info("Test execution completed successfully.")
 225
 226     return 0
 227
 228   def Main(self, args, check_sanity=False):
 229     self._args = args
 230     start = datetime.datetime.now()
 231     retcode = -1
 232     retcode = self.RunTestsAndAnalyze(check_sanity)
 233     end = datetime.datetime.now()
 234     seconds = (end - start).seconds
 235     hours = seconds / 3600
 236     seconds %= 3600
 237     minutes = seconds / 60
 238     seconds %= 60
 239     logging.info('elapsed time: %02d:%02d:%02d', hours, minutes, seconds)
 240     logging.info('For more information on the Heapcheck bot see '
 241                  'http://dev.chromium.org/developers/how-tos/'
 242                  'using-the-heap-leak-checker')
 243     return retcode
 244
 245
 246 def RunTool(args, supp_files, module):
 247   tool = HeapcheckWrapper(supp_files)
 248   MODULES_TO_SANITY_CHECK = ["base"]
 249   check_sanity = module in MODULES_TO_SANITY_CHECK
 250   return tool.Main(args[1:], check_sanity)