Bug 932898 - Bring back the shutdown leak detector r=ted

build/automation.py.in

@@ -840,7 +840,8 @@ class Automation(object):
              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.

build/automationutils.py

@@ -8,6 +8,7 @@ import glob, logging, os, platform, shutil, subprocess, sys, tempfile, urllib2,
 import base64
 import re
 from urlparse import urlparse
+from operator import itemgetter
 
 try:
   import mozinfo
@@ -46,6 +47,7 @@ __all__ = [
   'systemMemory',
   'environment',
   'dumpScreen',
+  "ShutdownLeaks"
   ]
 
 # Map of debugging programs to information about them, like default arguments
@@ -527,3 +529,121 @@ def dumpScreen(utilityPath):
   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)

testing/mochitest/browser-test.js

@@ -13,6 +13,9 @@ 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() {
@@ -194,7 +197,7 @@ Tester.prototype = {
       Services.console.unregisterListener(this);
       Services.obs.removeObserver(this, "chrome-document-global-created");
       Services.obs.removeObserver(this, "content-document-global-created");
-  
+
       this.dumper.dump("\nINFO TEST-START | Shutdown\n");
       if (this.tests.length) {
         this.dumper.dump("Browser Chrome Test Summary\n");
@@ -380,6 +383,34 @@ Tester.prototype = {
           gBrowser.removeCurrentTab();
         }
 
+        // 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();
+
+        // Uninitialize a few things explicitly so that they can clean up
+        // frames and browser intentionally kept alive until shutdown to
+        // eliminate false positives.
+        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.
 

testing/mochitest/runtests.py

@@ -28,7 +28,7 @@ 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
@@ -750,7 +750,8 @@ class Mochitest(MochitestUtilsMixin):
              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.
@@ -826,11 +827,17 @@ class Mochitest(MochitestUtilsMixin):
     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():
@@ -1006,7 +1013,8 @@ class Mochitest(MochitestUtilsMixin):
                            debuggerInfo=debuggerInfo,
                            symbolsPath=options.symbolsPath,
                            timeout=timeout,
-                           onLaunch=onLaunch
+                           onLaunch=onLaunch,
+                           webapprtChrome=options.webapprtChrome
                            )
     except KeyboardInterrupt:
       log.info("runtests.py | Received keyboard interrupt.\n");
@@ -1040,7 +1048,7 @@ class Mochitest(MochitestUtilsMixin):
 
   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
@@ -1049,6 +1057,7 @@ class Mochitest(MochitestUtilsMixin):
       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')
@@ -1078,6 +1087,7 @@ class Mochitest(MochitestUtilsMixin):
               self.record_last_test,
               self.dumpScreenOnTimeout,
               self.metro_subprocess_id,
+              self.trackShutdownLeaks,
               self.log,
               ]
 
@@ -1126,6 +1136,9 @@ class Mochitest(MochitestUtilsMixin):
         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
@@ -1159,6 +1172,11 @@ class Mochitest(MochitestUtilsMixin):
           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