michael@0: #!/usr/bin/env python
michael@0: # This Source Code Form is subject to the terms of the Mozilla Public
michael@0: # License, v. 2.0. If a copy of the MPL was not distributed with this
michael@0: # file, You can obtain one at http://mozilla.org/MPL/2.0/.
michael@0: from __future__ import print_function
michael@0: 
michael@0: usage = """%prog: A test for OOM conditions in the shell.
michael@0: 
michael@0: %prog finds segfaults and other errors caused by incorrect handling of
michael@0: allocation during OOM (out-of-memory) conditions.
michael@0: """
michael@0: 
michael@0: help = """Check for regressions only. This runs a set of files with a known
michael@0: number of OOM errors (specified by REGRESSION_COUNT), and exits with a non-zero
michael@0: result if more or less errors are found. See js/src/Makefile.in for invocation.
michael@0: """
michael@0: 
michael@0: 
michael@0: import hashlib
michael@0: import re
michael@0: import shlex
michael@0: import subprocess
michael@0: import sys
michael@0: import threading
michael@0: import time
michael@0: 
michael@0: from optparse import OptionParser
michael@0: 
michael@0: #####################################################################
michael@0: # Utility functions
michael@0: #####################################################################
michael@0: def run(args, stdin=None):
michael@0:   class ThreadWorker(threading.Thread):
michael@0:     def __init__(self, pipe):
michael@0:       super(ThreadWorker, self).__init__()
michael@0:       self.all = ""
michael@0:       self.pipe = pipe
michael@0:       self.setDaemon(True)
michael@0: 
michael@0:     def run(self):
michael@0:       while True:
michael@0:         line = self.pipe.readline()
michael@0:         if line == '': break
michael@0:         else:
michael@0:           self.all += line
michael@0: 
michael@0:   try:
michael@0:     if type(args) == str:
michael@0:       args = shlex.split(args)
michael@0: 
michael@0:     args = [str(a) for a in args] # convert to strs
michael@0: 
michael@0:     stdin_pipe = subprocess.PIPE if stdin else None
michael@0:     proc = subprocess.Popen(args, stdin=stdin_pipe, stdout=subprocess.PIPE, stderr=subprocess.PIPE)
michael@0:     if stdin_pipe:
michael@0:       proc.stdin.write(stdin)
michael@0:       proc.stdin.close()
michael@0: 
michael@0:     stdout_worker = ThreadWorker(proc.stdout)
michael@0:     stderr_worker = ThreadWorker(proc.stderr)
michael@0:     stdout_worker.start()
michael@0:     stderr_worker.start()
michael@0: 
michael@0:     proc.wait()
michael@0:     stdout_worker.join()
michael@0:     stderr_worker.join()
michael@0: 
michael@0:   except KeyboardInterrupt as e:
michael@0:     sys.exit(-1)
michael@0: 
michael@0:   stdout, stderr = stdout_worker.all, stderr_worker.all
michael@0:   result = (stdout, stderr, proc.returncode)
michael@0:   return result
michael@0: 
michael@0: def get_js_files():
michael@0:   (out, err, exit) = run('find ../jit-test/tests -name "*.js"')
michael@0:   if (err, exit) != ("", 0):
michael@0:     sys.exit("Wrong directory, run from an objdir")
michael@0:   return out.split()
michael@0: 
michael@0: 
michael@0: 
michael@0: #####################################################################
michael@0: # Blacklisting
michael@0: #####################################################################
michael@0: def in_blacklist(sig):
michael@0:   return sig in blacklist
michael@0: 
michael@0: def add_to_blacklist(sig):
michael@0:   blacklist[sig] = blacklist.get(sig, 0)
michael@0:   blacklist[sig] += 1
michael@0: 
michael@0: # How often is a particular lines important for this.
michael@0: def count_lines():
michael@0:   """Keep track of the amount of times individual lines occur, in order to
michael@0:      prioritize the errors which occur most frequently."""
michael@0:   counts = {}
michael@0:   for string,count in blacklist.items():
michael@0:     for line in string.split("\n"):
michael@0:       counts[line] = counts.get(line, 0) + count
michael@0: 
michael@0:   lines = []
michael@0:   for k,v in counts.items():
michael@0:     lines.append("{0:6}: {1}".format(v, k))
michael@0: 
michael@0:   lines.sort()
michael@0: 
michael@0:   countlog = file("../OOM_count_log", "w")
michael@0:   countlog.write("\n".join(lines))
michael@0:   countlog.flush()
michael@0:   countlog.close()
michael@0: 
michael@0: 
michael@0: #####################################################################
michael@0: # Output cleaning
michael@0: #####################################################################
michael@0: def clean_voutput(err):
michael@0:   # Skip what we can't reproduce
michael@0:   err = re.sub(r"^--\d+-- run: /usr/bin/dsymutil \"shell/js\"$", "", err, flags=re.MULTILINE)
michael@0:   err = re.sub(r"^==\d+==", "", err, flags=re.MULTILINE)
michael@0:   err = re.sub(r"^\*\*\d+\*\*", "", err, flags=re.MULTILINE)
michael@0:   err = re.sub(r"^\s+by 0x[0-9A-Fa-f]+: ", "by: ", err, flags=re.MULTILINE)
michael@0:   err = re.sub(r"^\s+at 0x[0-9A-Fa-f]+: ", "at: ", err, flags=re.MULTILINE)
michael@0:   err = re.sub(r"(^\s+Address 0x)[0-9A-Fa-f]+( is not stack'd)", r"\1\2", err, flags=re.MULTILINE)
michael@0:   err = re.sub(r"(^\s+Invalid write of size )\d+", r"\1x", err, flags=re.MULTILINE)
michael@0:   err = re.sub(r"(^\s+Invalid read of size )\d+", r"\1x", err, flags=re.MULTILINE)
michael@0:   err = re.sub(r"(^\s+Address 0x)[0-9A-Fa-f]+( is )\d+( bytes inside a block of size )[0-9,]+( free'd)", r"\1\2\3\4", err, flags=re.MULTILINE)
michael@0: 
michael@0:   # Skip the repeating bit due to the segfault
michael@0:   lines = []
michael@0:   for l in err.split('\n'):
michael@0:     if l == " Process terminating with default action of signal 11 (SIGSEGV)":
michael@0:       break
michael@0:     lines.append(l)
michael@0:   err = '\n'.join(lines)
michael@0: 
michael@0:   return err
michael@0: 
michael@0: def remove_failed_allocation_backtraces(err):
michael@0:   lines = []
michael@0: 
michael@0:   add = True
michael@0:   for l in err.split('\n'):
michael@0: 
michael@0:     # Set start and end conditions for including text
michael@0:     if l == " The site of the failed allocation is:":
michael@0:       add = False
michael@0:     elif l[:2] not in ['by: ', 'at:']:
michael@0:       add = True
michael@0: 
michael@0:     if add:
michael@0:       lines.append(l)
michael@0: 
michael@0: 
michael@0:   err = '\n'.join(lines)
michael@0: 
michael@0:   return err
michael@0: 
michael@0: 
michael@0: def clean_output(err):
michael@0:   err = re.sub(r"^js\(\d+,0x[0-9a-f]+\) malloc: \*\*\* error for object 0x[0-9a-f]+: pointer being freed was not allocated\n\*\*\* set a breakppoint in malloc_error_break to debug\n$", "pointer being freed was not allocated", err, flags=re.MULTILINE)
michael@0: 
michael@0:   return err
michael@0: 
michael@0: 
michael@0: #####################################################################
michael@0: # Consts, etc
michael@0: #####################################################################
michael@0: 
michael@0: command_template = 'shell/js' \
michael@0:                  + ' -m -j -p' \
michael@0:                  + ' -e "const platform=\'darwin\'; const libdir=\'../jit-test/lib/\';"' \
michael@0:                  + ' -f ../jit-test/lib/prolog.js' \
michael@0:                  + ' -f {0}'
michael@0: 
michael@0: 
michael@0: # Blacklists are things we don't want to see in our logs again (though we do
michael@0: # want to count them when they happen). Whitelists we do want to see in our
michael@0: # logs again, principally because the information we have isn't enough.
michael@0: 
michael@0: blacklist = {}
michael@0: add_to_blacklist(r"('', '', 1)") # 1 means OOM if the shell hasn't launched yet.
michael@0: add_to_blacklist(r"('', 'out of memory\n', 1)")
michael@0: 
michael@0: whitelist = set()
michael@0: whitelist.add(r"('', 'out of memory\n', -11)") # -11 means OOM
michael@0: whitelist.add(r"('', 'out of memory\nout of memory\n', -11)")
michael@0: 
michael@0: 
michael@0: 
michael@0: #####################################################################
michael@0: # Program
michael@0: #####################################################################
michael@0: 
michael@0: # Options
michael@0: parser = OptionParser(usage=usage)
michael@0: parser.add_option("-r", "--regression", action="store", metavar="REGRESSION_COUNT", help=help,
michael@0:                   type="int", dest="regression", default=None)
michael@0:                   
michael@0: (OPTIONS, args) = parser.parse_args()
michael@0: 
michael@0: 
michael@0: if OPTIONS.regression != None:
michael@0:   # TODO: This should be expanded as we get a better hang of the OOM problems.
michael@0:   # For now, we'll just check that the number of OOMs in one short file does not
michael@0:   # increase.
michael@0:   files = ["../jit-test/tests/arguments/args-createontrace.js"]
michael@0: else:
michael@0:   files = get_js_files()
michael@0: 
michael@0:   # Use a command-line arg to reduce the set of files
michael@0:   if len (args):
michael@0:     files = [f for f in files if f.find(args[0]) != -1]
michael@0: 
michael@0: 
michael@0: if OPTIONS.regression == None:
michael@0:   # Don't use a logfile, this is automated for tinderbox.
michael@0:   log = file("../OOM_log", "w")
michael@0: 
michael@0: 
michael@0: num_failures = 0
michael@0: for f in files:
michael@0: 
michael@0:   # Run it once to establish boundaries
michael@0:   command = (command_template + ' -O').format(f)
michael@0:   out, err, exit = run(command)
michael@0:   max = re.match(".*OOM max count: (\d+).*", out, flags=re.DOTALL).groups()[0]
michael@0:   max = int(max)
michael@0:   
michael@0:   # OOMs don't recover well for the first 20 allocations or so.
michael@0:   # TODO: revisit this.
michael@0:   for i in range(20, max): 
michael@0: 
michael@0:     if OPTIONS.regression == None:
michael@0:       print("Testing allocation {0}/{1} in {2}".format(i,max,f))
michael@0:     else:
michael@0:       sys.stdout.write('.') # something short for tinderbox, no space or \n
michael@0: 
michael@0:     command = (command_template + ' -A {0}').format(f, i)
michael@0:     out, err, exit = run(command)
michael@0: 
michael@0:     # Success (5 is SM's exit code for controlled errors)
michael@0:     if exit == 5 and err.find("out of memory") != -1:
michael@0:       continue
michael@0: 
michael@0:     # Failure
michael@0:     else:
michael@0: 
michael@0:       if OPTIONS.regression != None:
michael@0:         # Just count them
michael@0:         num_failures += 1
michael@0:         continue
michael@0: 
michael@0:       #########################################################################
michael@0:       # The regression tests ends above. The rest of this is for running  the
michael@0:       # script manually.
michael@0:       #########################################################################
michael@0: 
michael@0:       problem = str((out, err, exit))
michael@0:       if in_blacklist(problem) and problem not in whitelist:
michael@0:         add_to_blacklist(problem)
michael@0:         continue
michael@0: 
michael@0:       add_to_blacklist(problem)
michael@0: 
michael@0: 
michael@0:       # Get valgrind output for a good stack trace
michael@0:       vcommand = "valgrind --dsymutil=yes -q --log-file=OOM_valgrind_log_file " + command
michael@0:       run(vcommand)
michael@0:       vout = file("OOM_valgrind_log_file").read()
michael@0:       vout = clean_voutput(vout)
michael@0:       sans_alloc_sites = remove_failed_allocation_backtraces(vout)
michael@0: 
michael@0:       # Don't print duplicate information
michael@0:       if in_blacklist(sans_alloc_sites):
michael@0:         add_to_blacklist(sans_alloc_sites)
michael@0:         continue
michael@0: 
michael@0:       add_to_blacklist(sans_alloc_sites)
michael@0: 
michael@0:       log.write ("\n")
michael@0:       log.write ("\n")
michael@0:       log.write ("=========================================================================")
michael@0:       log.write ("\n")
michael@0:       log.write ("An allocation failure at\n\tallocation {0}/{1} in {2}\n\t"
michael@0:                  "causes problems (detected using bug 624094)"
michael@0:                  .format(i, max, f))
michael@0:       log.write ("\n")
michael@0:       log.write ("\n")
michael@0: 
michael@0:       log.write ("Command (from obj directory, using patch from bug 624094):\n  " + command)
michael@0:       log.write ("\n")
michael@0:       log.write ("\n")
michael@0:       log.write ("stdout, stderr, exitcode:\n  " + problem)
michael@0:       log.write ("\n")
michael@0:       log.write ("\n")
michael@0: 
michael@0:       double_free = err.find("pointer being freed was not allocated") != -1
michael@0:       oom_detected = err.find("out of memory") != -1
michael@0:       multiple_oom_detected = err.find("out of memory\nout of memory") != -1
michael@0:       segfault_detected = exit == -11
michael@0: 
michael@0:       log.write ("Diagnosis: ")
michael@0:       log.write ("\n")
michael@0:       if multiple_oom_detected:
michael@0:         log.write ("  - Multiple OOMs reported")
michael@0:         log.write ("\n")
michael@0:       if segfault_detected:
michael@0:         log.write ("  - segfault")
michael@0:         log.write ("\n")
michael@0:       if not oom_detected:
michael@0:         log.write ("  - No OOM checking")
michael@0:         log.write ("\n")
michael@0:       if double_free:
michael@0:         log.write ("  - Double free")
michael@0:         log.write ("\n")
michael@0: 
michael@0:       log.write ("\n")
michael@0: 
michael@0:       log.write ("Valgrind info:\n" + vout)
michael@0:       log.write ("\n")
michael@0:       log.write ("\n")
michael@0:       log.flush()
michael@0: 
michael@0:   if OPTIONS.regression == None:
michael@0:     count_lines()
michael@0: 
michael@0: print()
michael@0: 
michael@0: # Do the actual regression check
michael@0: if OPTIONS.regression != None:
michael@0:   expected_num_failures = OPTIONS.regression
michael@0: 
michael@0:   if num_failures != expected_num_failures:
michael@0: 
michael@0:     print("TEST-UNEXPECTED-FAIL |", end='')
michael@0:     if num_failures > expected_num_failures:
michael@0:       print("More out-of-memory errors were found ({0}) than expected ({1}). "
michael@0:             "This probably means an allocation site has been added without a "
michael@0:             "NULL-check. If this is unavoidable, you can account for it by "
michael@0:             "updating Makefile.in.".format(num_failures, expected_num_failures),
michael@0:             end='')
michael@0:     else:
michael@0:       print("Congratulations, you have removed {0} out-of-memory error(s) "
michael@0:             "({1} remain)! Please account for it by updating Makefile.in." 
michael@0:             .format(expected_num_failures - num_failures, num_failures),
michael@0:             end='')
michael@0:     sys.exit(-1)
michael@0:   else:
michael@0:     print('TEST-PASS | find_OOM_errors | Found the expected number of OOM '
michael@0:           'errors ({0})'.format(expected_num_failures))
michael@0: