Bug 1185244 - Improve mach support for running mochitests on Valgrind. r=jgraham, njn.

build/automation.py.in

@@ -529,7 +529,8 @@ class Automation(object):
              xrePath = None, certPath = None,
              debuggerInfo = None, symbolsPath = None,
              timeout = -1, maxTime = None, onLaunch = None,
-             detectShutdownLeaks = False, screenshotOnFail=False, testPath=None, bisectChunk=None):
+             detectShutdownLeaks = False, screenshotOnFail=False, testPath=None, bisectChunk=None,
+             valgrindPath=None, valgrindArgs=None, valgrindSuppFiles=None):
     """
     Run the app, log the duration it took to execute, return the status code.
     Kills the app if it runs for longer than |maxTime| seconds, or outputs nothing for |timeout| seconds.

layout/tools/reftest/remotereftest.py

@@ -310,7 +310,8 @@ class RemoteReftest(RefTest):
 
     def runApp(self, profile, binary, cmdargs, env,
                timeout=None, debuggerInfo=None,
-               symbolsPath=None, options=None):
+               symbolsPath=None, options=None,
+               valgrindPath=None, valgrindArgs=None, valgrindSuppFiles=None):
         status = self.automation.runApp(None, env,
                                         binary,
                                         profile.profile,

layout/tools/reftest/runreftest.py

@@ -585,7 +585,8 @@ class RefTest(object):
 
     def runApp(self, profile, binary, cmdargs, env,
                timeout=None, debuggerInfo=None,
-               symbolsPath=None, options=None):
+               symbolsPath=None, options=None,
+               valgrindPath=None, valgrindArgs=None, valgrindSuppFiles=None):
 
         def timeoutHandler():
             self.handleTimeout(

layout/tools/reftest/runreftestb2g.py

@@ -311,7 +311,8 @@ class B2GRemoteReftest(RefTest):
 
     def runApp(self, profile, binary, cmdargs, env,
                timeout=None, debuggerInfo=None,
-               symbolsPath=None, options=None):
+               symbolsPath=None, options=None,
+               valgrindPath=None, valgrindArgs=None, valgrindSuppFiles=None):
         status = self.automation.runApp(None, env,
                                         binary,
                                         profile.profile,

testing/mochitest/mochitest_options.py

@@ -30,6 +30,26 @@ except ImportError:
     conditions = None
 
 
+def get_default_valgrind_suppression_files():
+    # We are trying to locate files in the source tree.  So if we
+    # don't know where the source tree is, we must give up.
+    if build_obj is None or build_obj.topsrcdir is None:
+        return []
+
+    supps_path = os.path.join(build_obj.topsrcdir, "build", "valgrind")
+
+    rv = []
+    if mozinfo.os == "linux":
+        if mozinfo.processor == "x86_64":
+            rv.append(os.path.join(supps_path, "x86_64-redhat-linux-gnu.sup"))
+            rv.append(os.path.join(supps_path, "cross-architecture.sup"))
+        elif mozinfo.processor == "x86":
+            rv.append(os.path.join(supps_path, "i386-redhat-linux-gnu.sup"))
+            rv.append(os.path.join(supps_path, "cross-architecture.sup"))
+
+    return rv
+
+
 class ArgumentContainer():
     __metaclass__ = ABCMeta
 
@@ -475,6 +495,20 @@ class MochitestArguments(ArgumentContainer):
           "default": None,
           "help": "Arguments to pass to the debugger.",
           }],
+        [["--valgrind"],
+         {"default": None,
+          "help": "Valgrind binary to run tests with. Program name or path.",
+          }],
+        [["--valgrind-args"],
+         {"dest": "valgrindArgs",
+          "default": None,
+          "help": "Extra arguments to pass to Valgrind.",
+          }],
+        [["--valgrind-supp-files"],
+         {"dest": "valgrindSuppFiles",
+          "default": ",".join(get_default_valgrind_suppression_files()),
+          "help": "Comma-separated list of suppression files to pass to Valgrind.",
+          }],
         [["--debugger-interactive"],
          {"action": "store_true",
           "dest": "debuggerInteractive",

testing/mochitest/runtests.py

@@ -1631,6 +1631,9 @@ class Mochitest(MochitestUtilsMixin):
                extraArgs,
                utilityPath,
                debuggerInfo=None,
+               valgrindPath=None,
+               valgrindArgs=None,
+               valgrindSuppFiles=None,
                symbolsPath=None,
                timeout=-1,
                onLaunch=None,
@@ -1646,6 +1649,11 @@ class Mochitest(MochitestUtilsMixin):
         # configure the message logger buffering
         self.message_logger.buffering = quiet
 
+        # It can't be the case that both a with-debugger and an
+        # on-Valgrind run have been requested.  doTests() should have
+        # already excluded this possibility.
+        assert not(valgrindPath and debuggerInfo)
+
         # debugger information
         interactive = False
         debug_args = None
@@ -1653,10 +1661,32 @@ class Mochitest(MochitestUtilsMixin):
             interactive = debuggerInfo.interactive
             debug_args = [debuggerInfo.path] + debuggerInfo.args
 
+        # Set up Valgrind arguments.
+        if valgrindPath:
+            interactive = False
+            valgrindArgs_split = ([] if valgrindArgs is None
+                                  else valgrindArgs.split())
+            valgrindSuppFiles_split = ([] if valgrindSuppFiles is None
+                                       else valgrindSuppFiles.split(","))
+
+            valgrindSuppFiles_final = []
+            if valgrindSuppFiles is not None:
+                valgrindSuppFiles_final = ["--suppressions=" + path for path in valgrindSuppFiles.split(",")]
+
+            debug_args = ([valgrindPath]
+                          + mozdebug.get_default_valgrind_args()
+                          + valgrindArgs_split
+                          + valgrindSuppFiles_final)
+
         # fix default timeout
         if timeout == -1:
             timeout = self.DEFAULT_TIMEOUT
 
+        # Note in the log if running on Valgrind
+        if valgrindPath:
+            self.log.info("runtests.py | Running on Valgrind.  "
+                          + "Using timeout of %d seconds." % timeout)
+
         # copy env so we don't munge the caller's environment
         env = env.copy()
 
@@ -2125,6 +2155,26 @@ class Mochitest(MochitestUtilsMixin):
                 return 1
             self.mediaDevices = devices
 
+        # See if we were asked to run on Valgrind
+        valgrindPath = None
+        valgrindArgs = None
+        valgrindSuppFiles = None
+        if options.valgrind:
+            valgrindPath = options.valgrind
+        if options.valgrindArgs:
+            valgrindArgs = options.valgrindArgs
+        if options.valgrindSuppFiles:
+            valgrindSuppFiles = options.valgrindSuppFiles
+
+        if (valgrindArgs or valgrindSuppFiles) and not valgrindPath:
+            self.log.error("Specified --valgrind-args or --valgrind-supp-files,"
+                           " but not --valgrind")
+            return 1
+
+        if valgrindPath and debuggerInfo:
+            self.log.error("Can't use both --debugger and --valgrind together")
+            return 1
+
         # buildProfile sets self.profile .
         # This relies on sideeffects and isn't very stateful:
         # https://bugzilla.mozilla.org/show_bug.cgi?id=919300
@@ -2223,6 +2273,9 @@ class Mochitest(MochitestUtilsMixin):
                                      extraArgs=options.browserArgs,
                                      utilityPath=options.utilityPath,
                                      debuggerInfo=debuggerInfo,
+                                     valgrindPath=valgrindPath,
+                                     valgrindArgs=valgrindArgs,
+                                     valgrindSuppFiles=valgrindSuppFiles,
                                      symbolsPath=options.symbolsPath,
                                      timeout=timeout,
                                      onLaunch=onLaunch,
@@ -2518,7 +2571,8 @@ class Mochitest(MochitestUtilsMixin):
 
 def run_test_harness(options):
     logger_options = {
-        key: value for key, value in vars(options).iteritems() if key.startswith('log')}
+        key: value for key, value in vars(options).iteritems()
+        if key.startswith('log') or key == 'valgrind' }
     runner = Mochitest(logger_options)
 
     options.runByDir = False

testing/mozbase/mozdebug/mozdebug/mozdebug.py

@@ -11,7 +11,8 @@ from distutils.spawn import find_executable
 
 __all__ = ['get_debugger_info',
            'get_default_debugger_name',
-           'DebuggerSearch']
+           'DebuggerSearch',
+           'get_default_valgrind_args']
 
 '''
 Map of debugging programs to information about them, like default arguments
@@ -49,20 +50,6 @@ _DEBUGGER_INFO = {
     'wdexpress.exe': {
         'interactive': True,
         'args': ['-debugexe']
-    },
-
-    # valgrind doesn't explain much about leaks unless you set the
-    # '--leak-check=full' flag. But there are a lot of objects that are
-    # semi-deliberately leaked, so we set '--show-possibly-lost=no' to avoid
-    # uninteresting output from those objects. We set '--smc-check==all-non-file'
-    # and '--vex-iropt-register-updates=allregs-at-mem-access' so that valgrind
-    # deals properly with JIT'd JavaScript code.
-    'valgrind': {
-        'interactive': False,
-        'args': ['--leak-check=full',
-                '--show-possibly-lost=no',
-                '--smc-check=all-non-file',
-                '--vex-iropt-register-updates=allregs-at-mem-access']
     }
 }
 
@@ -166,3 +153,67 @@ def get_default_debugger_name(search=DebuggerSearch.OnlyFirst):
             return None
 
     return None
+
+# Defines default values for Valgrind flags.
+#
+# --smc-check=all-non-file is required to deal with code generation and
+#   patching by the various JITS.  Note that this is only necessary on
+#   x86 and x86_64, but not on ARM.  This flag is only necessary for
+#   Valgrind versions prior to 3.11.
+#
+# --vex-iropt-register-updates=allregs-at-mem-access is required so that
+#   Valgrind generates correct register values whenever there is a
+#   segfault that is caught and handled.  In particular OdinMonkey
+#   requires this.  More recent Valgrinds (3.11 and later) provide
+#   --px-default=allregs-at-mem-access and
+#   --px-file-backed=unwindregs-at-mem-access
+#   which provide a significantly cheaper alternative, by restricting the
+#   precise exception behaviour to JIT generated code only.
+#
+# --trace-children=yes is required to get Valgrind to follow into
+#   content and other child processes.  The resulting output can be
+#   difficult to make sense of, and --child-silent-after-fork=yes
+#   helps by causing Valgrind to be silent for the child in the period
+#   after fork() but before its subsequent exec().
+#
+# --trace-children-skip lists processes that we are not interested
+#   in tracing into.
+#
+# --leak-check=full requests full stack traces for all leaked blocks
+#   detected at process exit.
+#
+# --show-possibly-lost=no requests blocks for which only an interior
+#   pointer was found to be considered not leaked.
+#
+#
+# TODO: pass in the user supplied args for V (--valgrind-args=) and
+# use this to detect if a different tool has been selected.  If so
+# adjust tool-specific args appropriately.
+#
+# TODO: pass in the path to the Valgrind to be used (--valgrind=), and
+# check what flags it accepts.  Possible args that might be beneficial:
+#
+# --num-transtab-sectors=24   [reduces re-jitting overheads in long runs]
+# --px-default=allregs-at-mem-access
+# --px-file-backed=unwindregs-at-mem-access
+#                             [these reduce PX overheads as described above]
+#
+def get_default_valgrind_args():
+    return (['--fair-sched=yes',
+             '--smc-check=all-non-file',
+             '--vex-iropt-register-updates=allregs-at-mem-access',
+             '--trace-children=yes',
+             '--child-silent-after-fork=yes',
+             '--leak-check=full',
+             '--show-possibly-lost=no',
+             ('--trace-children-skip='
+              + '/usr/bin/hg,/bin/rm,*/bin/certutil,*/bin/pk12util,'
+              + '*/bin/ssltunnel,*/bin/uname,*/bin/which,*/bin/ps,'
+              + '*/bin/grep,*/bin/java'),
+            ]
+            + get_default_valgrind_tool_specific_args())
+
+def get_default_valgrind_tool_specific_args():
+    return [
+            '--partial-loads-ok=yes'
+    ]

testing/mozbase/mozlog/mozlog/commandline.py

@@ -39,6 +39,9 @@ def buffer_handler_wrapper(handler, buffer_limit):
         buffer_limit = int(buffer_limit)
     return handlers.BufferHandler(handler, buffer_limit)
 
+def valgrind_handler_wrapper(handler):
+    return handlers.ValgrindHandler(handler)
+
 def default_formatter_options(log_type, overrides):
     formatter_option_defaults = {
         "raw": {
@@ -151,17 +154,24 @@ def setup_handlers(logger, formatters, formatter_options):
     for fmt, streams in formatters.iteritems():
         formatter_cls = log_formatters[fmt][0]
         formatter = formatter_cls()
-        handler_wrapper, handler_option = None, ""
+        handler_wrappers_and_options = []
+
         for option, value in formatter_options[fmt].iteritems():
-            if option == "buffer":
+            wrapper, wrapper_args = None, ()
-                handler_wrapper, handler_option = fmt_options[option][0], value
+            if option == "valgrind":
+                wrapper = valgrind_handler_wrapper
+            elif option == "buffer":
+                wrapper, wrapper_args = fmt_options[option][0], (value,)
             else:
                 formatter = fmt_options[option][0](formatter, value)
 
+            if wrapper is not None:
+                handler_wrappers_and_options.append((wrapper, wrapper_args))
+
         for value in streams:
             handler = handlers.StreamHandler(stream=value, formatter=formatter)
-            if handler_wrapper:
+            for wrapper, wrapper_args in handler_wrappers_and_options:
-                handler = handler_wrapper(handler, handler_option)
+                handler = wrapper(handler, *wrapper_args)
             logger.add_handler(handler)
 
 
@@ -211,7 +221,9 @@ def setup_logging(logger, args, defaults=None, formatter_defaults=None):
         parts = name.split('_')
         if len(parts) > 3:
             continue
-        # Our args will be ['log', <formatter>] or ['log', <formatter>, <option>].
+        # Our args will be ['log', <formatter>]
+        #               or ['log', <formatter>, <option>]
+        #               or ['valgrind']
         if parts[0] == 'log' and values is not None:
             if len(parts) == 1 or parts[1] not in log_formatters:
                 continue
@@ -245,6 +257,10 @@ def setup_logging(logger, args, defaults=None, formatter_defaults=None):
         if name not in formatter_options:
             formatter_options[name] = default_formatter_options(name, formatter_defaults)
 
+    # If the user specified --valgrind, add it as an option for all formatters
+    if args.get('valgrind', None) is not None:
+        for name in formatters:
+            formatter_options[name]['valgrind'] = True
     setup_handlers(logger, formatters, formatter_options)
     set_default_logger(logger)
 

testing/mozbase/mozlog/mozlog/formatters/machformatter.py

@@ -232,6 +232,13 @@ class MachFormatter(base.BaseFormatter):
                 rv = rv[:-1]
         return rv
 
+    def valgrind_error(self, data):
+        rv = " " + data['primary'] + "\n"
+        for line in data['secondary']:
+            rv = rv + line + "\n"
+
+        return rv
+
     def test_status(self, data):
         self.summary_values["subtests"] += 1
 

testing/mozbase/mozlog/mozlog/formatters/tbplformatter.py

@@ -149,3 +149,10 @@ class TbplFormatter(BaseFormatter):
             return test_id
         else:
             return " ".join(test_id)
+
+    def valgrind_error(self, data):
+        rv = "TEST-VALGRIND-ERROR | " + data['primary'] + "\n"
+        for line in data['secondary']:
+            rv = rv + line + "\n"
+
+        return rv

testing/mozbase/mozlog/mozlog/handlers/__init__.py

@@ -5,3 +5,4 @@
 from .base import LogLevelFilter, StreamHandler, BaseHandler
 from .statushandler import StatusHandler
 from .bufferhandler import BufferHandler
+from .valgrindhandler import ValgrindHandler

testing/mozbase/mozlog/mozlog/handlers/valgrindhandler.py

@@ -0,0 +1,137 @@
+# This Source Code Form is subject to the terms of the Mozilla Public
+# License, v. 2.0. If a copy of the MPL was not distributed with this
+# file, You can obtain one at http://mozilla.org/MPL/2.0/.
+
+from .base import BaseHandler
+import re
+
+class ValgrindHandler(BaseHandler):
+
+    def __init__(self, inner):
+        BaseHandler.__init__(self, inner)
+        self.inner = inner
+        self.vFilter = ValgrindFilter()
+
+    def __call__(self, data):
+        tmp = self.vFilter(data)
+        if tmp is not None:
+            self.inner(tmp)
+
+class ValgrindFilter(object):
+    '''
+    A class for handling Valgrind output.
+
+    Valgrind errors look like this:
+
+    ==60741== 40 (24 direct, 16 indirect) bytes in 1 blocks are definitely lost in loss record 2,746 of 5,235
+    ==60741==    at 0x4C26B43: calloc (vg_replace_malloc.c:593)
+    ==60741==    by 0x63AEF65: PR_Calloc (prmem.c:443)
+    ==60741==    by 0x69F236E: PORT_ZAlloc_Util (secport.c:117)
+    ==60741==    by 0x69F1336: SECITEM_AllocItem_Util (secitem.c:28)
+    ==60741==    by 0xA04280B: ffi_call_unix64 (in /builds/slave/m-in-l64-valgrind-000000000000/objdir/toolkit/library/libxul.so)
+    ==60741==    by 0xA042443: ffi_call (ffi64.c:485)
+
+    For each such error, this class extracts most or all of the first (error
+    kind) line, plus the function name in each of the first few stack entries.
+    With this data it constructs and prints a TEST-UNEXPECTED-FAIL message that
+    TBPL will highlight.
+
+    It buffers these lines from which text is extracted so that the
+    TEST-UNEXPECTED-FAIL message can be printed before the full error.
+
+    Parsing the Valgrind output isn't ideal, and it may break in the future if
+    Valgrind changes the format of the messages, or introduces new error kinds.
+    To protect against this, we also count how many lines containing
+    "<insert_a_suppression_name_here>" are seen. Thanks to the use of
+    --gen-suppressions=yes, exactly one of these lines is present per error. If
+    the count of these lines doesn't match the error count found during
+    parsing, then the parsing has missed one or more errors and we can fail
+    appropriately.
+    '''
+
+    def __init__(self):
+        # The regexps in this list match all of Valgrind's errors. Note that
+        # Valgrind is English-only, so we don't have to worry about
+        # localization.
+        self.re_error = \
+            re.compile( \
+            r'==\d+== (' + \
+            r'(Use of uninitialised value of size \d+)|' + \
+            r'(Conditional jump or move depends on uninitialised value\(s\))|' + \
+            r'(Syscall param .* contains uninitialised byte\(s\))|' + \
+            r'(Syscall param .* points to (unaddressable|uninitialised) byte\(s\))|' + \
+            r'((Unaddressable|Uninitialised) byte\(s\) found during client check request)|' + \
+            r'(Invalid free\(\) / delete / delete\[\] / realloc\(\))|' + \
+            r'(Mismatched free\(\) / delete / delete \[\])|' + \
+            r'(Invalid (read|write) of size \d+)|' + \
+            r'(Jump to the invalid address stated on the next line)|' + \
+            r'(Source and destination overlap in .*)|' + \
+            r'(.* bytes in .* blocks are .* lost)' + \
+            r')' \
+            )
+        # Match identifer chars, plus ':' for namespaces, and '\?' in order to
+        # match "???" which Valgrind sometimes produces.
+        self.re_stack_entry = \
+            re.compile(r'^==\d+==.*0x[A-Z0-9]+: ([A-Za-z0-9_:\?]+)')
+        self.re_suppression = \
+            re.compile(r' *<insert_a_suppression_name_here>')
+        self.error_count = 0
+        self.suppression_count = 0
+        self.number_of_stack_entries_to_get = 0
+        self.curr_failure_msg = ""
+        self.buffered_lines = []
+
+    # Takes a message and returns a message
+    def __call__(self, msg):
+        # Pass through everything that isn't plain text
+        if msg['action'] != 'log':
+            return msg
+
+        line = msg['message']
+        output_message = None
+        if self.number_of_stack_entries_to_get == 0:
+            # Look for the start of a Valgrind error.
+            m = re.search(self.re_error, line)
+            if m:
+                self.error_count += 1
+                self.number_of_stack_entries_to_get = 4
+                self.curr_failure_msg = m.group(1) + " at "
+                self.buffered_lines = [line]
+            else:
+                output_message = msg
+
+        else:
+            # We've recently found a Valgrind error, and are now extracting
+            # details from the first few stack entries.
+            self.buffered_lines.append(line)
+            m = re.match(self.re_stack_entry, line)
+            if m:
+                self.curr_failure_msg += m.group(1)
+            else:
+                self.curr_failure_msg += '?!?'
+
+            self.number_of_stack_entries_to_get -= 1
+            if self.number_of_stack_entries_to_get != 0:
+                self.curr_failure_msg += ' / '
+            else:
+                # We've finished getting the first few stack entries.  Emit
+                # the failure action, comprising the primary message and the
+                # buffered lines, and then reset state.  Copy the mandatory
+                # fields from the incoming message, since there's nowhere
+                # else to get them from.
+                output_message = { # Mandatory fields
+                                   u"action": "valgrind_error",
+                                   u"time":   msg["time"],
+                                   u"thread": msg["thread"],
+                                   u"pid":    msg["pid"],
+                                   u"source": msg["source"],
+                                   # valgrind_error specific fields
+                                   u"primary":   self.curr_failure_msg,
+                                   u"secondary": self.buffered_lines }
+                self.curr_failure_msg = ""
+                self.buffered_lines = []
+
+        if re.match(self.re_suppression, line):
+            self.suppression_count += 1
+
+        return output_message

testing/mozbase/mozlog/mozlog/structuredlog.py

@@ -362,6 +362,11 @@ class StructuredLogger(object):
 
         self._log_data("crash", data)
 
+    @log_action(Unicode("primary", default=None),
+                List("secondary", Unicode, default=None))
+    def valgrind_error(self, data):
+        self._log_data("valgrind_error", data)
+
     @log_action(Unicode("process"),
                 Unicode("command", default=None, optional=True))
     def process_start(self, data):

testing/mozharness/mozharness/mozilla/structuredlog.py

@@ -96,6 +96,7 @@ class StructuredOutputParser(OutputParser):
         failure_conditions = [
             sum(summary.unexpected_statuses.values()) > 0,
             summary.action_counts.get('crash', 0) > summary.expected_statuses.get('CRASH', 0),
+            summary.action_counts.get('valgrind_error', 0) > 0
         ]
         for condition in failure_conditions:
             if condition:

testing/mozharness/mozharness/mozilla/testing/errors.py

@@ -91,6 +91,11 @@ TinderBoxPrintRe = {
         'minimum_regex': re.compile(r'''(TEST-UNEXPECTED|PROCESS-CRASH)'''),
         'retry_regex': re.compile(r'''FAIL-SHOULD-RETRY''')
     },
+    "valgrind_error": {
+        'substr': 'TEST-VALGRIND-ERROR',
+        'level': ERROR,
+        'explanation': 'Valgrind detected memory errors during the run'
+    },
 }
 
 TestPassed = [