Enable Deep Memory Profiler in perf_endure.py.

chrome/test/functional/perf_endure.py

 #!/usr/bin/env python
 # Copyright (c) 2012 The Chromium Authors. All rights reserved.
 # Use of this source code is governed by a BSD-style license that can be
 # found in the LICENSE file.
 
 """Performance tests for Chrome Endure (long-running perf tests on Chrome).
 
 This module accepts the following environment variable inputs:
   TEST_LENGTH: The number of seconds in which to run each test.
   PERF_STATS_INTERVAL: The number of seconds to wait in-between each sampling
       of performance/memory statistics.
+
+  DEEP_MEMORY_PROFILE_INTERVAL: The number of seconds to wait in-between each
+      sampling for the Deep Memory Profiler.
+  DEEP_MEMORY_PROFILE_SAVE: Don't clean-up profile dump files if it's set.
 """
 
+from datetime import datetime
+import json
 import logging
 import os
 import re
+import subprocess
+import tempfile
 import time
 
 import perf
 import pyauto_functional  # Must be imported before pyauto.
 import pyauto
+import pyauto_utils
 import remote_inspector_client
 import selenium.common.exceptions
 from selenium.webdriver.support.ui import WebDriverWait
 
-
 class ChromeEndureBaseTest(perf.BasePerfTest):
   """Implements common functionality for all Chrome Endure tests.
 
   All Chrome Endure test classes should inherit from this class.
   """
 
   _DEFAULT_TEST_LENGTH_SEC = 60 * 60 * 6  # Tests run for 6 hours.
   _GET_PERF_STATS_INTERVAL = 60 * 10  # Measure perf stats every 10 minutes.
   _ERROR_COUNT_THRESHOLD = 300  # Number of ChromeDriver errors to tolerate.
+  _DEEP_MEMORY_PROFILE_INTERVAL = 0
+  _DEEP_MEMORY_PROFILE_SAVE = False
+
+  _DMPROF_DIR_PATH = os.path.join(
+      os.path.dirname(__file__), os.pardir, os.pardir, os.pardir,
+      'tools', 'deep_memory_profiler')
+
+  _DMPROF_SCRIPT_PATH = os.path.join(_DMPROF_DIR_PATH, 'dmprof')
+
+  # TODO(dmikurube): Need to find an actual running chrome.
+  _CHROME_BIN_PATH = os.path.join(
+      os.path.dirname(__file__), os.pardir, os.pardir, os.pardir,
+      'out', 'Debug', 'chrome')
 
   def setUp(self):
+    # These environment variables for the Deep Memory Profiler must be set
+    # before perf.BasePerfTest.setUp() to inherit them to Chrome.
+    self._deep_memory_profile_interval = 0
+    if self.IsLinux():
+      self._deep_memory_profile_interval = int(
+          os.environ.get('DEEP_MEMORY_PROFILE_INTERVAL',
+                         self._DEEP_MEMORY_PROFILE_INTERVAL))
+
+    if self._deep_memory_profile_interval > 0:
+      dir_prefix = 'endure.%s.' % datetime.today().strftime('%Y%m%d.%H%M%S')
+      self._deep_tempdir = tempfile.mkdtemp(prefix=dir_prefix)
+      os.environ['HEAPPROFILE'] = os.path.join(self._deep_tempdir, 'endure')
+      os.environ['HEAP_PROFILE_MMAP'] = 'True'
+      os.environ['DEEP_HEAP_PROFILE'] = 'True'
+      # TODO(dmikurube): Stop to set HEAP_PROFILE_TIME_INTERVAL when PyAuto
+      # supports to dump renderer heap profile.
+      os.environ['HEAP_PROFILE_TIME_INTERVAL'] = (
+          '%d' % self._deep_memory_profile_interval)
+
     perf.BasePerfTest.setUp(self)
 
     self._test_length_sec = int(
         os.environ.get('TEST_LENGTH', self._DEFAULT_TEST_LENGTH_SEC))
     self._get_perf_stats_interval = int(
         os.environ.get('PERF_STATS_INTERVAL', self._GET_PERF_STATS_INTERVAL))
 
+    self._deep_memory_profile_save = False
+    if self.IsLinux():
+      self._deep_memory_profile_save = bool(
+          os.environ.get('DEEP_MEMORY_PROFILE_SAVE',
+                         self._DEEP_MEMORY_PROFILE_SAVE))
+    self._deep_memory_profile_last_json_filename = ''
+
     logging.info('Running test for %d seconds.', self._test_length_sec)
     logging.info('Gathering perf stats every %d seconds.',
                  self._get_perf_stats_interval)
+    if self._deep_memory_profile_interval > 0:
+      logging.info('Running with the Deep Memory Profiler every %d seconds.',
+                   self._deep_memory_profile_interval)
+      if self._deep_memory_profile_save:
+        logging.info('Dump files by the Deep Memory Profiler are not cleaned.')
 
     # Set up a remote inspector client associated with tab 0.
     logging.info('Setting up connection to remote inspector...')
     self._remote_inspector_client = (
         remote_inspector_client.RemoteInspectorClient())
     logging.info('Connection to remote inspector set up successfully.')
 
     self._dom_node_count_results = []
     self._event_listener_count_results = []
     self._browser_process_private_mem_results = []
     self._tab_process_private_mem_results = []
     self._v8_mem_used_results = []
     self._test_start_time = 0
     self._num_errors = 0
     self._iteration_num = 0
+    self._deep_memory_profile_json_f = None

[dennis_jeffrey, 2012/04/17 22:36:14]

I recommend using "file" instead of just "f", just to make it clear

[Dai Mikurube (NOT FULLTIME), 2012/04/18 04:59:51]

Done.

+    self._deep_memory_profile_proc = None
 
   def tearDown(self):
     logging.info('Terminating connection to remote inspector...')
     self._remote_inspector_client.Stop()
     logging.info('Connection to remote inspector terminated.')
+    if self._deep_memory_profile_interval > 0:
+      # TODO(dmikurube): Stop to set HEAP_PROFILE_TIME_INTERVAL in setUp when
+      # PyAuto supports to dump renderer heap profile.
+      del os.environ['HEAP_PROFILE_TIME_INTERVAL']
+      del os.environ['DEEP_HEAP_PROFILE']
+      del os.environ['HEAP_PROFILE_MMAP']
+      del os.environ['HEAPPROFILE']
     perf.BasePerfTest.tearDown(self)  # Must be done at end of this function.

[dennis_jeffrey, 2012/04/17 22:36:14]

Maybe we should move this line to the bottom of the current function.  That will
be consistent with what the comment suggests ;-)

[Dai Mikurube (NOT FULLTIME), 2012/04/18 04:59:51]

We have to remove the temporary directory after Chrome finishes, so I modified
the comments.

+    if (self._deep_memory_profile_interval > 0 and
+        not self._deep_memory_profile_save and
+        self._deep_tempdir):
+      pyauto_utils.RemovePath(self._deep_tempdir)
 
   def ExtraChromeFlags(self):
     """Ensures Chrome is launched with custom flags.
 
     Returns:
       A list of extra flags to pass to Chrome when it is launched.
     """
+    # The same with setUp, but need to fetch the environment variable since
+    # ExtraChromeFlags is called before setUp.
+    deep_memory_profile_interval = 0
+    if self.IsLinux():
+      deep_memory_profile_interval = int(
+          os.environ.get('DEEP_MEMORY_PROFILE_INTERVAL',
+                         self._DEEP_MEMORY_PROFILE_INTERVAL))
+
     # Ensure Chrome enables remote debugging on port 9222.  This is required to
     # interact with Chrome's remote inspector.
-    return (perf.BasePerfTest.ExtraChromeFlags(self) +
-            ['--remote-debugging-port=9222'])
+    extra_flags = ['--remote-debugging-port=9222']
+    if deep_memory_profile_interval > 0:
+      extra_flags.append('--no-sandbox')
+    return (perf.BasePerfTest.ExtraChromeFlags(self) + extra_flags)
 
   def _RunEndureTest(self, webapp_name, tab_title_substring, test_description,
                      do_scenario):
     """The main test harness function to run a general Chrome Endure test.
 
     After a test has performed any setup work and has navigated to the proper
     starting webpage, this function should be invoked to run the endurance test.
 
     Args:
       webapp_name: A string name for the webapp being tested.  Should not
           include spaces.  For example, 'Gmail', 'Docs', or 'Plus'.
       tab_title_substring: A unique substring contained within the title of
           the tab to use, for identifying the appropriate tab.
       test_description: A string description of what the test does, used for
           outputting results to be graphed.  Should not contain spaces.  For
           example, 'ComposeDiscard' for Gmail.
       do_scenario: A callable to be invoked that implements the scenario to be
           performed by this test.  The callable is invoked iteratively for the
           duration of the test.
     """
     self._num_errors = 0
     self._test_start_time = time.time()
     last_perf_stats_time = time.time()
+    # Note: this variable will be removed when committing.
+    last_deep_memory_profile_time = time.time()
     self._GetPerformanceStats(
         webapp_name, test_description, tab_title_substring)
     self._iteration_num = 0
     while time.time() - self._test_start_time < self._test_length_sec:
       self._iteration_num += 1
 
       if self._num_errors >= self._ERROR_COUNT_THRESHOLD:
         logging.error('Error count threshold (%d) reached. Terminating test '
                       'early.' % self._ERROR_COUNT_THRESHOLD)
         break
 
+      # Note: this block will be removed when committing.
+      # TODO(dmikurube): Need pid of the target process.
+      if (self._deep_memory_profile_interval > 0 and
+          time.time() - last_deep_memory_profile_time >=
+              self._deep_memory_profile_interval):
+        last_deep_memory_profile_time = time.time()
+        logging.info('HeapProfilerDump would be called here.')
+
       if time.time() - last_perf_stats_time >= self._get_perf_stats_interval:
         last_perf_stats_time = time.time()
         self._GetPerformanceStats(
             webapp_name, test_description, tab_title_substring)
 
       if self._iteration_num % 10 == 0:
         remaining_time = self._test_length_sec - (time.time() -
                                                   self._test_start_time)
         logging.info('Chrome interaction #%d. Time remaining in test: %d sec.' %
                      (self._iteration_num, remaining_time))
 
       do_scenario()
 
+    # Note: this block will be removed when committing.
+    if self._deep_memory_profile_interval > 0:
+      logging.info('HeapProfilerDump would be called here.')
+
     self._GetPerformanceStats(
-        webapp_name, test_description, tab_title_substring)
+        webapp_name, test_description, tab_title_substring, is_last=True)
 
   def _GetProcessInfo(self, tab_title_substring):
     """Gets process info associated with an open browser/tab.
 
     Args:
       tab_title_substring: A unique substring contained within the title of
           the tab to use; needed for locating the tab info.
 
     Returns:
       A dictionary containing information about the browser and specified tab
       process:
       {
         'browser_private_mem': integer,  # Private memory associated with the
                                          # browser process, in KB.
         'tab_private_mem': integer,  # Private memory associated with the tab
                                      # process, in KB.
+        'tab_pid': integer,  # Process ID of the tab process.
       }
     """
     browser_process_name = (
         self.GetBrowserInfo()['properties']['BrowserProcessExecutableName'])
     info = self.GetProcessInfo()
 
     # Get the information associated with the browser process.
     browser_proc_info = []
     for browser_info in info['browsers']:
       if browser_info['process_name'] == browser_process_name:
@@ skipping 16 matching lines @@
                      msg='Expected to find 1 %s tab process, but found %d '
                          'instead.\nCurrent process info:\n%s.' % (
                          tab_title_substring, len(tab_proc_info),
                          self.pformat(info)))
 
     browser_proc_info = browser_proc_info[0]
     tab_proc_info = tab_proc_info[0]
     return {
       'browser_private_mem': browser_proc_info['working_set_mem']['priv'],
       'tab_private_mem': tab_proc_info['working_set_mem']['priv'],
+      'tab_pid': tab_proc_info['pid'],
     }
 
   def _GetPerformanceStats(self, webapp_name, test_description,
-                           tab_title_substring):
+                           tab_title_substring, is_last=False):
     """Gets performance statistics and outputs the results.
 
     Args:
       webapp_name: A string name for the webapp being tested.  Should not
           include spaces.  For example, 'Gmail', 'Docs', or 'Plus'.
       test_description: A string description of what the test does, used for
           outputting results to be graphed.  Should not contain spaces.  For
           example, 'ComposeDiscard' for Gmail.
       tab_title_substring: A unique substring contained within the title of
           the tab to use, for identifying the appropriate tab.
+      is_last: A boolean value which should be True if it's the last call of
+          _GetPerformanceStats.  The default is False.
     """
     logging.info('Gathering performance stats...')
     elapsed_time = time.time() - self._test_start_time
     elapsed_time = int(round(elapsed_time))
 
     memory_counts = self._remote_inspector_client.GetMemoryObjectCounts()
 
     dom_node_count = memory_counts['DOMNodeCount']
     logging.info('  Total DOM node count: %d nodes' % dom_node_count)
     self._dom_node_count_results.append((elapsed_time, dom_node_count))
@@ skipping 11 matching lines @@
     logging.info('  Tab process private memory: %d KB' %
                  proc_info['tab_private_mem'])
     self._tab_process_private_mem_results.append(
         (elapsed_time, proc_info['tab_private_mem']))
 
     v8_info = self.GetV8HeapStats()  # First window, first tab.
     v8_mem_used = v8_info['v8_memory_used'] / 1024.0  # Convert to KB.
     logging.info('  V8 memory used: %f KB' % v8_mem_used)
     self._v8_mem_used_results.append((elapsed_time, v8_mem_used))
 
+    # TODO(dmikurube): A part of this block should be carved out as a function.
+    if self._deep_memory_profile_interval > 0:
+      logging.info('Profiling with the Deep Memory Profiler...')
+
+      # Wait for a running dmprof process for last _GetPerformanceStat call to
+      # cover last dump files.
+      if is_last and self._deep_memory_profile_proc:
+        logging.info('  Waiting for the last dmprof.')
+        self._deep_memory_profile_proc.wait()
+        self._deep_memory_profile_proc = None
+        if self._deep_memory_profile_json_f:
+          self._deep_memory_profile_last_json_filename = (
+              self._deep_memory_profile_json_f.name)
+          self._deep_memory_profile_json_f.close()
+          self._deep_memory_profile_json_f = None
+
+      if (self._deep_memory_profile_proc and
+          self._deep_memory_profile_proc.poll() is None):
+        logging.info('  Last dmprof is still running.')
+      else:
+        if self._deep_memory_profile_json_f:
+          self._deep_memory_profile_last_json_filename = (
+              self._deep_memory_profile_json_f.name)
+          self._deep_memory_profile_json_f.close()
+          self._deep_memory_profile_json_f = None
+        first_dump = ''
+        last_dump = ''
+        for filename in sorted(os.listdir(self._deep_tempdir)):
+          if re.match('^endure.%05d.\d+.heap$' % proc_info['tab_pid'],
+                      filename):
+            logging.info('  Profiled dump file: %s' % filename)
+            last_dump = filename
+            if not first_dump:
+              first_dump = filename
+        if first_dump:
+          logging.info('  First dump file: %s' % first_dump)
+          matched= re.match('^endure.\d+.(\d+).heap$', last_dump)
+          last_sequence_id = matched.group(1)
+          self._deep_memory_profile_json_f = open(
+              os.path.join(self._deep_tempdir,
+                           'endure.%05d.%s.json' % (proc_info['tab_pid'],
+                                                    last_sequence_id)), 'w+')
+          self._deep_memory_profile_proc = subprocess.Popen(
+              '%s --json %s %s %s' % (self._DMPROF_SCRIPT_PATH,
+                                      self._CHROME_BIN_PATH,
+                                      os.path.join(self._DMPROF_DIR_PATH,
+                                                   'policy.l2.txt'),
+                                      os.path.join(self._deep_tempdir,
+                                                   first_dump)),
+              shell=True, stdout=self._deep_memory_profile_json_f)
+          # Don't wait for the new process since dmprof may take long time.
+
+          if is_last:
+            self._deep_memory_profile_proc.wait()
+            self._deep_memory_profile_last_json_filename = (
+                self._deep_memory_profile_json_f.name)
+            self._deep_memory_profile_json_f.close()
+
+        else:
+          logging.info('  No dump files.')
+
     # Output the results seen so far, to be graphed.
     self._OutputPerfGraphValue(
         'TotalDOMNodeCount', self._dom_node_count_results, 'nodes',
         graph_name='%s%s-Nodes-DOM' % (webapp_name, test_description),
         units_x='seconds')
     self._OutputPerfGraphValue(
         'EventListenerCount', self._event_listener_count_results, 'listeners',
         graph_name='%s%s-EventListeners' % (webapp_name, test_description),
         units_x='seconds')
     self._OutputPerfGraphValue(
         'BrowserPrivateMemory', self._browser_process_private_mem_results, 'KB',
         graph_name='%s%s-BrowserMem-Private' % (webapp_name, test_description),
         units_x='seconds')
     self._OutputPerfGraphValue(
         'TabPrivateMemory', self._tab_process_private_mem_results, 'KB',
         graph_name='%s%s-TabMem-Private' % (webapp_name, test_description),
         units_x='seconds')
     self._OutputPerfGraphValue(
         'V8MemoryUsed', self._v8_mem_used_results, 'KB',
         graph_name='%s%s-V8MemUsed' % (webapp_name, test_description),
         units_x='seconds')
+    if self._deep_memory_profile_interval > 0:
+      deep_memory_profile_results = {}
+      if self._deep_memory_profile_last_json_filename:
+        json_data = {}
+        with open(self._deep_memory_profile_last_json_filename) as json_f:
+          json_data = json.load(json_f)
+        if json_data['version'] == 'JSON_DEEP_1':
+          for component in json_data['legends']:
+            deep_memory_profile_results[component] = []
+            for snapshot in json_data['snapshots']:
+              deep_memory_profile_results[component].append(snapshot[component])
+      # TODO(dmikurube): Output graph values (for multi-lined graphs), here.
+      # 'deep_memory_profile_results' is the value to be output.
 
   def _GetElement(self, find_by, value):
     """Gets a WebDriver element object from the webpage DOM.
 
     Args:
       find_by: A callable that queries WebDriver for an element from the DOM.
       value: A string value that can be passed to the |find_by| callable.
 
     Returns:
       The identified WebDriver element object, if found in the DOM, or
@@ skipping 581 matching lines @@
           self._driver, self._wait, 'id("state")[text()="offline"]'):
         self._num_errors += 1
       time.sleep(1)
 
     self._RunEndureTest(self._webapp_name, self._tab_title_substring,
                         test_description, scenario)
 
 
 if __name__ == '__main__':
   pyauto_functional.Main()