Telemetry: Update exception handling in FastNavigationProfileExtender.

tools/perf/profile_creators/fast_navigation_profile_extender.py

 # Copyright 2015 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.
 import time
 
 from profile_creators import profile_extender
 from telemetry.core import exceptions
+from telemetry.core import util
 
 
 class FastNavigationProfileExtender(profile_extender.ProfileExtender):
   """Extends a Chrome profile.
 
   This class creates or extends an existing profile by performing a set of tab
   navigations in large batches. This is accomplished by opening a large number
   of tabs, simultaneously navigating all the tabs, and then waiting for all the
   tabs to load. This provides two benefits:
     - Takes advantage of the high number of logical cores on modern CPUs.
@@ skipping 11 matching lines @@
     super(FastNavigationProfileExtender, self).__init__(finder_options)
 
     # The instance keeps a list of Tabs that can be navigated successfully.
     # This means that the Tab is not crashed, and is processing JavaScript in a
     # timely fashion.
     self._navigation_tabs = []
 
     # The number of tabs to use.
     self._NUM_TABS = maximum_batch_size
 
-    # The amount of time to wait for a batch of pages to finish loading.
-    self._BATCH_PAGE_LOAD_TIMEOUT_IN_SECONDS = 10
+    # The amount of additional time to wait for a batch of pages to finish
+    # loading for each page in the batch.
+    self._BATCH_TIMEOUT_PER_PAGE_IN_SECONDS = 20
 
-    # The default amount of time to wait for the retrieval of the URL of a tab.
-    self._TAB_URL_RETRIEVAL_TIMEOUT_IN_SECONDS = 1
+    # The amount of time to wait for a page to quiesce. Some pages will never
+    # quiesce.
+    self._TIME_TO_WAIT_FOR_PAGE_TO_QUIESCE_IN_SECONDS = 10
 
   def Run(self):
     """Superclass override."""
     try:
       self.SetUpBrowser()
       self._PerformNavigations()
     finally:
       self.TearDownBrowser()
 
+    # When there hasn't been an exception, verify that the profile was
+    # correctly extended.
+    # TODO(erikchen): I've intentionally omitted my implementation of
+    # VerifyProfileWasExtended() in small_profile_extender, since the profile
+    # is not being correctly extended. http://crbug.com/484833
+    # http://crbug.com/484880
+    self.VerifyProfileWasExtended()
+
   def GetUrlIterator(self):
     """Gets URLs for the browser to navigate to.
 
     Intended for subclass override.
 
     Returns:
       An iterator whose elements are urls to be navigated to.
     """
     raise NotImplementedError()
 
   def ShouldExitAfterBatchNavigation(self):
     """Returns a boolean indicating whether profile extension is finished.
 
     Intended for subclass override.
     """
     raise NotImplementedError()
 
   def CleanUpAfterBatchNavigation(self):
     """A hook for subclasses to perform cleanup after each batch of
     navigations.
 
     Can be overridden by subclasses.
     """
     pass
 
   def _AddNewTab(self):

[nednguyen, 2015/05/12 16:07:43]

The content of this method can just be moved to  _RefreshNavigationTab

[erikchen, 2015/05/12 18:43:48]

Done.

     """Adds a new tab to the browser."""
-
-    # Adding a new tab requires making a request over devtools. This can fail
-    # for a variety of reasons. Retry 3 times.
-    retry_count = 3
-    for i in range(retry_count):
-      try:
-        self._navigation_tabs.append(self._browser.tabs.New())
-      except exceptions.Error:
-        if i == retry_count - 1:
-          raise
-      else:
-        break
+    self._navigation_tabs.append(self._browser.tabs.New())
 
   def _RefreshNavigationTabs(self):
     """Updates the member self._navigation_tabs to contain self._NUM_TABS
     elements, each of which is not crashed. The crashed tabs are intentionally
     leaked, since Telemetry doesn't have a good way of killing crashed tabs.
 
     It is also possible for a tab to be stalled in an infinite JavaScript loop.
     These tabs will be in self.browser.tabs, but not in self._navigation_tabs.
     There is no way to kill these tabs, so they are also leaked. This method is
     careful to only use tabs in self._navigation_tabs, or newly created tabs.
     """
     live_tabs = [tab for tab in self._navigation_tabs if tab.IsAlive()]
     self._navigation_tabs = live_tabs
 
     while len(self._navigation_tabs) < self._NUM_TABS:
       self._AddNewTab()
 
   def _RemoveNavigationTab(self, tab):
     """Removes a tab which is no longer in a useable state from
     self._navigation_tabs. The tab is not removed from self.browser.tabs,
     since there is no guarantee that the tab can be safely removed."""
     self._navigation_tabs.remove(tab)
 
   def _RetrieveTabUrl(self, tab, timeout):
     """Retrives the URL of the tab."""
-    try:
-      return tab.EvaluateJavaScript('document.URL', timeout)
-    except exceptions.Error:
-      return None
+    # TODO(erikchen): Use tab.url instead, which talks to the browser process
+    # instead of the renderer process. http://crbug.com/486119
+    return tab.EvaluateJavaScript('document.URL', timeout)
 
-  def _WaitForUrlToChange(self, tab, initial_url, timeout):
-    """Waits for the tab to navigate away from its initial url."""
-    end_time = time.time() + timeout
+  def _WaitForUrlToChange(self, tab, initial_url, end_time):
+    """Waits for the tab to navigate away from its initial url.
+
+    If time.time() is larger than end_time, the function does nothing.
+    Otherwise, the function tries to return no later than end_time.
+    """
     while True:
       seconds_to_wait = end_time - time.time()
-      seconds_to_wait = max(0, seconds_to_wait)
-
-      if seconds_to_wait == 0:
+      if seconds_to_wait <= 0:

[nednguyen, 2015/05/12 16:07:43]

what about:
if time.time() >= end_time:
  break

[erikchen, 2015/05/12 18:43:48]

Each iteration of the loop should only call time.time() once. In your
suggestion, a second call of time.time() is required to generate
seconds_to_wait.

[nednguyen, 2015/05/12 19:37:57]

ah, I didn't show the seconds_to_wait below.

         break
 
       current_url = self._RetrieveTabUrl(tab, seconds_to_wait)
-      if current_url != initial_url:
+      if current_url != initial_url and current_url != "":
         break
 
       # Retrieving the current url is a non-trivial operation. Add a small
       # sleep here to prevent this method from contending with the actual
       # navigation.
       time.sleep(0.01)
 
+  def _WaitForTabToBeReady(self, tab, end_time):

[nednguyen, 2015/05/12 16:07:43]

Why do we need this? Ain't  HasReachedQuiescence check below is good enough?

[erikchen, 2015/05/12 18:43:48]

Through experimental testing, it isn't sufficient. Just because the network has
quiesced does not necessarily mean that the page has finished loading, for
example.

[nednguyen, 2015/05/12 19:37:57]

Ok, this makes sense. I think we should also move the tab.HasReachedQuiescence
here (tab ready == page finished loading + network quiescen)

[erikchen, 2015/05/12 19:44:38]

Done.

+    """Waits for the tab to be ready.
+
+    If time.time() is larger than end_time, the function does nothing.
+    Otherwise, the function tries to return no later than end_time.
+    """
+    seconds_to_wait = end_time - time.time()
+    if seconds_to_wait <= 0:
+      return
+    tab.WaitForDocumentReadyStateToBeComplete(seconds_to_wait)
+
   def _BatchNavigateTabs(self, batch):
     """Performs a batch of tab navigations with minimal delay.
 
     Args:
       batch: A list of tuples (tab, url).
 
     Returns:
       A list of tuples (tab, initial_url). |initial_url| is the url of the
       |tab| prior to a navigation command being sent to it.
     """
-    timeout_in_seconds = 0
+    # Attempting to pass in a timeout of 0 seconds results in a synchronous
+    # socket error from the websocket library. Pass in a very small timeout
+    # instead so that the websocket library raises a Timeout exception. This
+    # prevents the logic from accidentally catching different socket
+    # exceptions.
+    timeout_in_seconds = 0.01
 
     queued_tabs = []
     for tab, url in batch:
-      initial_url = self._RetrieveTabUrl(tab,
-          self._TAB_URL_RETRIEVAL_TIMEOUT_IN_SECONDS)
-
+      initial_url = self._RetrieveTabUrl(tab, 20)
       try:
         tab.Navigate(url, None, timeout_in_seconds)
-      except exceptions.Error:
-        # We expect a time out. It's possible for other problems to arise, but
-        # this method is not responsible for dealing with them. Ignore all
-        # exceptions.
+      except exceptions.TimeoutException:
+        # We expect to receive a timeout exception, since we're not waiting for
+        # the navigation to complete.
         pass
-
       queued_tabs.append((tab, initial_url))
     return queued_tabs
 
   def _WaitForQueuedTabsToLoad(self, queued_tabs):
     """Waits for all the batch navigated tabs to finish loading.
 
     Args:
       queued_tabs: A list of tuples (tab, initial_url). Each tab is guaranteed
       to have already been sent a navigation command.
     """
-    end_time = time.time() + self._BATCH_PAGE_LOAD_TIMEOUT_IN_SECONDS
+    total_batch_timeout = (len(queued_tabs) *
+        self._BATCH_TIMEOUT_PER_PAGE_IN_SECONDS)
+    end_time = time.time() + total_batch_timeout
     for tab, initial_url in queued_tabs:
+      # Since we didn't wait any time for the tab url navigation to commit, it's
+      # possible that the tab hasn't started navigating yet.
+      self._WaitForUrlToChange(tab, initial_url, end_time)
+      self._WaitForTabToBeReady(tab, end_time)
+
+      # Wait up to 10 seconds for the page to quiesce. If the page hasn't
+      # quiesced in 10 seconds, it will probably never quiesce.
       seconds_to_wait = end_time - time.time()
       seconds_to_wait = max(0, seconds_to_wait)
-
-      if seconds_to_wait == 0:
-        break
-
-      # Since we don't wait any time for the tab url navigation to commit, it's
-      # possible that the tab hasn't started navigating yet.
-      self._WaitForUrlToChange(tab, initial_url, seconds_to_wait)
-
-      seconds_to_wait = end_time - time.time()
-      seconds_to_wait = max(0, seconds_to_wait)
-
       try:
-        tab.WaitForDocumentReadyStateToBeComplete(seconds_to_wait)
+        util.WaitFor(tab.HasReachedQuiescence, seconds_to_wait)
       except exceptions.TimeoutException:
-        # Ignore time outs.
         pass
-      except exceptions.Error:
-        # If any error occurs, remove the tab. it's probably in an
-        # unrecoverable state.
-        self._RemoveNavigationTab(tab)
 
   def _GetUrlsToNavigate(self, url_iterator):
     """Returns an array of urls to navigate to, given a url_iterator."""
     urls = []
     for _ in xrange(self._NUM_TABS):
       try:
         urls.append(url_iterator.next())
       except StopIteration:
         break
     return urls
@@ skipping 17 matching lines @@
         tab = self._navigation_tabs[i]
         batch.append((tab, url))
 
       queued_tabs = self._BatchNavigateTabs(batch)
       self._WaitForQueuedTabsToLoad(queued_tabs)
 
       self.CleanUpAfterBatchNavigation()
 
       if self.ShouldExitAfterBatchNavigation():
         break