Bug 932898 - Bring back the shutdown leak detector r=ted
authorTim Taubert <ttaubert@mozilla.com>
Wed, 20 Nov 2013 21:53:08 +0100
changeset 156790 45dda1081309a8e9a471e4684e27c7924fb4e672
parent 156789 cd6b40046e85031fc78ceab262cba9e9c4ecf263
child 156791 2a99c5feb322a254d537267a6f240eee07b0d51f
push id25688
push userryanvm@gmail.com
push dateThu, 21 Nov 2013 19:32:18 +0000
treeherdermozilla-central@679410425704 [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewersted
bugs932898
milestone28.0a1
first release with
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
last release without
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
Bug 932898 - Bring back the shutdown leak detector r=ted From 246109686e62e3231ccba74a84adaa0774f2a1af Mon Sep 17 00:00:00 2001
build/automation.py.in
build/automationutils.py
testing/mochitest/browser-test.js
testing/mochitest/runtests.py
--- a/build/automation.py.in
+++ b/build/automation.py.in
@@ -835,17 +835,18 @@ class Automation(object):
 
   def checkForCrashes(self, minidumpDir, symbolsPath):
     return mozcrash.check_for_crashes(minidumpDir, symbolsPath, test_name=self.lastTestSeen)
 
   def runApp(self, testURL, env, app, profileDir, extraArgs,
              runSSLTunnel = False, utilityPath = None,
              xrePath = None, certPath = None,
              debuggerInfo = None, symbolsPath = None,
-             timeout = -1, maxTime = None, onLaunch = None):
+             timeout = -1, maxTime = None, onLaunch = None,
+             webapprtChrome = False):
     """
     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.
     """
 
     if utilityPath == None:
       utilityPath = self.DIST_BIN
     if xrePath == None:
--- a/build/automationutils.py
+++ b/build/automationutils.py
@@ -3,16 +3,17 @@
 # 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 __future__ import with_statement
 import glob, logging, os, platform, shutil, subprocess, sys, tempfile, urllib2, zipfile
 import base64
 import re
 from urlparse import urlparse
+from operator import itemgetter
 
 try:
   import mozinfo
 except ImportError:
   # Stub out fake mozinfo since this is not importable on Android 4.0 Opt.
   # This should be fixed; see
   # https://bugzilla.mozilla.org/show_bug.cgi?id=650881
   mozinfo = type('mozinfo', (), dict(info={}))()
@@ -41,16 +42,17 @@ except ImportError:
   "DEBUGGER_INFO",
   "replaceBackSlashes",
   "wrapCommand",
   'KeyValueParseError',
   'parseKeyValue',
   'systemMemory',
   'environment',
   'dumpScreen',
+  "ShutdownLeaks"
   ]
 
 # Map of debugging programs to information about them, like default arguments
 # and whether or not they are interactive.
 DEBUGGER_INFO = {
   # gdb requires that you supply the '--args' flag in order to pass arguments
   # after the executable name to the executable.
   "gdb": {
@@ -522,8 +524,126 @@ def dumpScreen(utilityPath):
         image = imgfile.read()
   except IOError, err:
     log.info("Failed to read image from %s", imgoutput)
 
   encoded = base64.b64encode(image)
   uri = "data:image/png;base64,%s" %  encoded
   log.info("SCREENSHOT: %s", uri)
   return uri
+
+class ShutdownLeaks(object):
+  """
+  Parses the mochitest run log when running a debug build, assigns all leaked
+  DOM windows (that are still around after test suite shutdown, despite running
+  the GC) to the tests that created them and prints leak statistics.
+  """
+
+  def __init__(self, logger):
+    self.logger = logger
+    self.tests = []
+    self.leakedWindows = {}
+    self.leakedDocShells = set()
+    self.currentTest = None
+    self.seenShutdown = False
+
+  def log(self, line):
+    if line[2:11] == "DOMWINDOW":
+      self._logWindow(line)
+    elif line[2:10] == "DOCSHELL":
+      self._logDocShell(line)
+    elif line.startswith("TEST-START"):
+      fileName = line.split(" ")[-1].strip().replace("chrome://mochitests/content/browser/", "")
+      self.currentTest = {"fileName": fileName, "windows": set(), "docShells": set()}
+    elif line.startswith("INFO TEST-END"):
+      # don't track a test if no windows or docShells leaked
+      if self.currentTest and (self.currentTest["windows"] or self.currentTest["docShells"]):
+        self.tests.append(self.currentTest)
+      self.currentTest = None
+    elif line.startswith("INFO TEST-START | Shutdown"):
+      self.seenShutdown = True
+
+  def process(self):
+    leakingTests = self._parseLeakingTests()
+
+    if leakingTests:
+      totalWindows = sum(len(test["leakedWindows"]) for test in leakingTests)
+      totalDocShells = sum(len(test["leakedDocShells"]) for test in leakingTests)
+      self.logger("TEST-UNEXPECTED-FAIL | ShutdownLeaks | leaked %d DOMWindow(s) and %d DocShell(s) until shutdown", totalWindows, totalDocShells)
+
+    for test in leakingTests:
+      for url, count in self._zipLeakedWindows(test["leakedWindows"]):
+        self.logger("TEST-UNEXPECTED-FAIL | %s | leaked %d window(s) until shutdown [url = %s]", test["fileName"], count, url)
+
+      if test["leakedDocShells"]:
+        self.logger("TEST-UNEXPECTED-FAIL | %s | leaked %d docShell(s) until shutdown", test["fileName"], len(test["leakedDocShells"]))
+
+  def _logWindow(self, line):
+    created = line[:2] == "++"
+    pid = self._parseValue(line, "pid")
+    serial = self._parseValue(line, "serial")
+
+    # log line has invalid format
+    if not pid or not serial:
+      self.logger("TEST-UNEXPECTED-FAIL | ShutdownLeaks | failed to parse line <%s>", line)
+      return
+
+    key = pid + "." + serial
+
+    if self.currentTest:
+      windows = self.currentTest["windows"]
+      if created:
+        windows.add(key)
+      else:
+        windows.discard(key)
+    elif self.seenShutdown and not created:
+      self.leakedWindows[key] = self._parseValue(line, "url")
+
+  def _logDocShell(self, line):
+    created = line[:2] == "++"
+    pid = self._parseValue(line, "pid")
+    id = self._parseValue(line, "id")
+
+    # log line has invalid format
+    if not pid or not id:
+      self.logger("TEST-UNEXPECTED-FAIL | ShutdownLeaks | failed to parse line <%s>", line)
+      return
+
+    key = pid + "." + id
+
+    if self.currentTest:
+      docShells = self.currentTest["docShells"]
+      if created:
+        docShells.add(key)
+      else:
+        docShells.discard(key)
+    elif self.seenShutdown and not created:
+      self.leakedDocShells.add(key)
+
+  def _parseValue(self, line, name):
+    match = re.search("\[%s = (.+?)\]" % name, line)
+    if match:
+      return match.group(1)
+    return None
+
+  def _parseLeakingTests(self):
+    leakingTests = []
+
+    for test in self.tests:
+      test["leakedWindows"] = [self.leakedWindows[id] for id in test["windows"] if id in self.leakedWindows]
+      test["leakedDocShells"] = [id for id in test["docShells"] if id in self.leakedDocShells]
+      test["leakCount"] = len(test["leakedWindows"]) + len(test["leakedDocShells"])
+
+      if test["leakCount"]:
+        leakingTests.append(test)
+
+    return sorted(leakingTests, key=itemgetter("leakCount"), reverse=True)
+
+  def _zipLeakedWindows(self, leakedWindows):
+    counts = []
+    counted = set()
+
+    for url in leakedWindows:
+      if not url in counted:
+        counts.append((url, leakedWindows.count(url)))
+        counted.add(url)
+
+    return sorted(counts, key=itemgetter(1), reverse=True)
--- a/testing/mochitest/browser-test.js
+++ b/testing/mochitest/browser-test.js
@@ -8,16 +8,19 @@ if (Cc === undefined) {
   var Cu = Components.utils;
 }
 
 Cu.import("resource://gre/modules/XPCOMUtils.jsm");
 
 XPCOMUtils.defineLazyModuleGetter(this, "Services",
   "resource://gre/modules/Services.jsm");
 
+XPCOMUtils.defineLazyModuleGetter(this, "BrowserNewTabPreloader",
+  "resource:///modules/BrowserNewTabPreloader.jsm", "BrowserNewTabPreloader");
+
 window.addEventListener("load", testOnLoad, false);
 
 function testOnLoad() {
   window.removeEventListener("load", testOnLoad, false);
 
   gConfig = readConfig();
   if (gConfig.testRoot == "browser" ||
       gConfig.testRoot == "metro" ||
@@ -377,16 +380,46 @@ Tester.prototype = {
         // will erroneously be blamed for leaking this new tab's DOM window and
         // docshell until shutdown. We can prevent this by removing this tab now
         // that all tests are done.
         if (window.gBrowser) {
           gBrowser.addTab();
           gBrowser.removeCurrentTab();
         }
 
+        // Uninitialize a few things explicitly so that they can clean up
+        // frames and browser intentionally kept alive until shutdown to
+        // eliminate false positives.
+        if (gConfig.testRoot == "browser") {
+          // Replace the document currently loaded in the browser's sidebar.
+          // This will prevent false positives for tests that were the last
+          // to touch the sidebar. They will thus not be blamed for leaking
+          // a document.
+          let sidebar = document.getElementById("sidebar");
+          sidebar.setAttribute("src", "data:text/html;charset=utf-8,");
+          sidebar.docShell.createAboutBlankContentViewer(null);
+          sidebar.setAttribute("src", "about:blank");
+
+          // Do the same for the social sidebar.
+          let socialSidebar = document.getElementById("social-sidebar-browser");
+          socialSidebar.setAttribute("src", "data:text/html;charset=utf-8,");
+          socialSidebar.docShell.createAboutBlankContentViewer(null);
+          socialSidebar.setAttribute("src", "about:blank");
+
+          // Destroy BackgroundPageThumbs resources.
+          let {BackgroundPageThumbs} =
+            Cu.import("resource://gre/modules/BackgroundPageThumbs.jsm", {});
+          BackgroundPageThumbs._destroy();
+
+          BrowserNewTabPreloader.uninit();
+          SocialFlyout.unload();
+          SocialShare.uninit();
+          TabView.uninit();
+        }
+
         // Schedule GC and CC runs before finishing in order to detect
         // DOM windows leaked by our tests or the tested code.
 
         let checkForLeakedGlobalWindows = aCallback => {
           Cu.schedulePreciseGC(() => {
             let analyzer = new CCAnalyzer();
             analyzer.run(() => {
               let results = [];
--- a/testing/mochitest/runtests.py
+++ b/testing/mochitest/runtests.py
@@ -23,17 +23,17 @@ import re
 import shutil
 import signal
 import subprocess
 import tempfile
 import time
 import traceback
 import urllib2
 
-from automationutils import environment, getDebuggerInfo, isURL, KeyValueParseError, parseKeyValue, processLeakLog, systemMemory, dumpScreen
+from automationutils import environment, getDebuggerInfo, isURL, KeyValueParseError, parseKeyValue, processLeakLog, systemMemory, dumpScreen, ShutdownLeaks
 from datetime import datetime
 from manifestparser import TestManifest
 from mochitest_options import MochitestOptions
 from mozprofile import Profile, Preferences
 from mozprofile.permissions import ServerLocations
 from urllib import quote_plus as encodeURIComponent
 
 # This should use the `which` module already in tree, but it is
@@ -745,17 +745,18 @@ class Mochitest(MochitestUtilsMixin):
              profile,
              extraArgs,
              utilityPath,
              xrePath,
              certPath,
              debuggerInfo=None,
              symbolsPath=None,
              timeout=-1,
-             onLaunch=None):
+             onLaunch=None,
+             webapprtChrome=False):
     """
     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.
     """
 
     # debugger information
     interactive = False
     debug_args = None
@@ -821,21 +822,27 @@ class Mochitest(MochitestUtilsMixin):
     cmd = os.path.abspath(app)
     args = list(extraArgs)
     # TODO: mozrunner should use -foreground at least for mac
     # https://bugzilla.mozilla.org/show_bug.cgi?id=916512
     args.append('-foreground')
     if testUrl:
        args.append(testUrl)
 
+    if mozinfo.info["debug"] and not webapprtChrome:
+      shutdownLeaks = ShutdownLeaks(log.info)
+    else:
+      shutdownLeaks = None
+
     # create an instance to process the output
     outputHandler = self.OutputHandler(harness=self,
                                        utilityPath=utilityPath,
                                        symbolsPath=symbolsPath,
                                        dump_screen_on_timeout=not debuggerInfo,
+                                       shutdownLeaks=shutdownLeaks,
       )
 
     def timeoutHandler():
       browserProcessId = outputHandler.browserProcessId
       self.handleTimeout(timeout, proc, utilityPath, debuggerInfo, browserProcessId)
     kp_kwargs = {'kill_on_timeout': False,
                  'onTimeout': [timeoutHandler]}
     # if the output handler is a pipe, it will process output via the subprocess
@@ -1001,17 +1008,18 @@ class Mochitest(MochitestUtilsMixin):
                            profile=self.profile,
                            extraArgs=options.browserArgs,
                            utilityPath=options.utilityPath,
                            xrePath=options.xrePath,
                            certPath=options.certPath,
                            debuggerInfo=debuggerInfo,
                            symbolsPath=options.symbolsPath,
                            timeout=timeout,
-                           onLaunch=onLaunch
+                           onLaunch=onLaunch,
+                           webapprtChrome=options.webapprtChrome
                            )
     except KeyboardInterrupt:
       log.info("runtests.py | Received keyboard interrupt.\n");
       status = -1
     except:
       traceback.print_exc()
       log.error("Automation Error: Received unexpected exception while running application\n")
       status = 1
@@ -1035,25 +1043,26 @@ class Mochitest(MochitestUtilsMixin):
     log.info("TEST-UNEXPECTED-FAIL | %s | application timed out after %d seconds with no output", self.lastTestSeen, int(timeout))
     browserProcessId = browserProcessId or proc.pid
     self.killAndGetStack(browserProcessId, utilityPath, debuggerInfo, dump_screen=not debuggerInfo)
 
   ### output processing
 
   class OutputHandler(object):
     """line output handler for mozrunner"""
-    def __init__(self, harness, utilityPath, symbolsPath=None, dump_screen_on_timeout=True):
+    def __init__(self, harness, utilityPath, symbolsPath=None, dump_screen_on_timeout=True, shutdownLeaks=None):
       """
       harness -- harness instance
       dump_screen_on_timeout -- whether to dump the screen on timeout
       """
       self.harness = harness
       self.utilityPath = utilityPath
       self.symbolsPath = symbolsPath
       self.dump_screen_on_timeout = dump_screen_on_timeout
+      self.shutdownLeaks = shutdownLeaks
 
       # perl binary to use
       self.perl = which('perl')
 
       # With metro browser runs this script launches the metro test harness which launches the browser.
       # The metro test harness hands back the real browser process id via log output which we need to
       # pick up on and parse out. This variable tracks the real browser process id if we find it.
       self.browserProcessId = None
@@ -1073,16 +1082,17 @@ class Mochitest(MochitestUtilsMixin):
 
     def outputHandlers(self):
       """returns ordered list of output handlers"""
       return [self.fix_stack,
               self.format,
               self.record_last_test,
               self.dumpScreenOnTimeout,
               self.metro_subprocess_id,
+              self.trackShutdownLeaks,
               self.log,
               ]
 
     def stackFixer(self):
       """
       return 2-tuple, (stackFixerFunction, StackFixerProcess),
       if any, to use on the output lines
       """
@@ -1121,16 +1131,19 @@ class Mochitest(MochitestUtilsMixin):
         self.stackFixerProcess.run(outputTimeout=outputTimeout)
 
     def finish(self, didTimeout):
       if self.stackFixerProcess:
         status = self.stackFixerProcess.wait()
         if status and not didTimeout:
           log.info("TEST-UNEXPECTED-FAIL | runtests.py | Stack fixer process exited with code %d during test run", status)
 
+      if self.shutdownLeaks:
+        self.shutdownLeaks.process()
+
 
     # output line handlers:
     # these take a line and return a line
 
     def fix_stack(self, line):
       if self.stackFixerFunction:
         return self.stackFixerFunction(line)
       return line
@@ -1154,16 +1167,21 @@ class Mochitest(MochitestUtilsMixin):
       """look for metro browser subprocess id"""
       if "METRO_BROWSER_PROCESS" in line:
         index = line.find("=")
         if index != -1:
           self.browserProcessId = line[index+1:].rstrip()
           log.info("INFO | runtests.py | metro browser sub process id detected: %s", self.browserProcessId)
       return line
 
+    def trackShutdownLeaks(self, line):
+      if self.shutdownLeaks:
+        self.shutdownLeaks.log(line)
+      return line
+
     def log(self, line):
       log.info(line)
       return line
 
 
   def makeTestConfig(self, options):
     "Creates a test configuration file for customizing test execution."
     def jsonString(val):