Cancel coming updates when certain JumpList APIs time out to fail

chrome/browser/win/jumplist.cc

 // Copyright 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.
 
 #include "chrome/browser/win/jumplist.h"
 
 #include "base/base_paths.h"
 #include "base/bind.h"
 #include "base/bind_helpers.h"
 #include "base/command_line.h"
@@ skipping 58 matching lines @@
 
 // The delay before updating the JumpList to prevent update storms.
 constexpr base::TimeDelta kDelayForJumplistUpdate =
     base::TimeDelta::FromMilliseconds(3500);
 
 // The maximum allowed time for JumpListUpdater::BeginUpdate. Updates taking
 // longer than this are discarded to prevent bogging down slow machines.
 constexpr base::TimeDelta kTimeOutForJumplistBeginUpdate =
     base::TimeDelta::FromMilliseconds(500);
 
-// The maximum allowed time for updating both "most visited" and "recently
-// closed" categories via JumpListUpdater::AddCustomCategory.
+// The maximum allowed time for adding most visited pages custom category via
+// JumpListUpdater::AddCustomCategory.
 constexpr base::TimeDelta kTimeOutForAddCustomCategory =
-    base::TimeDelta::FromMilliseconds(500);
+    base::TimeDelta::FromMilliseconds(300);
 
 // The maximum allowed time for JumpListUpdater::CommitUpdate.
 constexpr base::TimeDelta kTimeOutForJumplistCommitUpdate =
     base::TimeDelta::FromMilliseconds(1000);
 
 // Appends the common switches to each shell link.
 void AppendCommonSwitches(ShellLinkItem* shell_link) {
   const char* kSwitchNames[] = { switches::kUserDataDir };
   const base::CommandLine& command_line =
       *base::CommandLine::ForCurrentProcess();
@@ skipping 20 matching lines @@
   if (!base::CreateTemporaryFileInDir(icon_dir, &path))
     return false;
 
   // Create an icon file from the favicon attached to the given |page|, and
   // save it as the temporary file.
   gfx::ImageFamily image_family;
   if (!image_skia.isNull()) {
     std::vector<float> supported_scales = image_skia.GetSupportedScales();
     for (auto& scale : supported_scales) {
       gfx::ImageSkiaRep image_skia_rep = image_skia.GetRepresentation(scale);
-      if (!image_skia_rep.is_null())
+      if (!image_skia_rep.is_null()) {
         image_family.Add(
             gfx::Image::CreateFrom1xBitmap(image_skia_rep.sk_bitmap()));
+      }
     }
   }
 
   if (!IconUtil::CreateIconFileFromImageFamily(image_family, path,
                                                IconUtil::NORMAL_WRITE)) {
     // Delete the file created by CreateTemporaryFileInDir as it won't be used.
     base::DeleteFile(path, false);
     return false;
   }
 
@@ skipping 561 matching lines @@
     bool most_visited_should_update,
     bool recently_closed_should_update,
     IncognitoModePrefs::Availability incognito_availability,
     UpdateTransaction* update_transaction) {
   DCHECK(update_transaction);
 
   JumpListUpdater jumplist_updater(app_id);
 
   base::ElapsedTimer begin_update_timer;
 
-  if (!jumplist_updater.BeginUpdate())
-    return;
+  bool begin_success = jumplist_updater.BeginUpdate();
 
-  // Discard this JumpList update if JumpListUpdater::BeginUpdate takes longer
-  // than the maximum allowed time, as it's very likely the following update
-  // steps will also take a long time.
+  // If JumpListUpdater::BeginUpdate takes longer than the maximum allowed time,
+  // abort the current update as it's very likely the following steps will also
+  // take a long time, and skip the next |kUpdatesToSkipUnderHeavyLoad| updates.
   if (begin_update_timer.Elapsed() >= kTimeOutForJumplistBeginUpdate) {
     update_transaction->update_timeout = true;
     return;
   }
 
+  if (!begin_success)
+    return;
+
   // Record the desired number of icons created in this JumpList update.
   int icons_created = 0;
 
   URLIconCache most_visited_icons_next;
   URLIconCache recently_closed_icons_next;
 
   // Update the icons for "Most Visisted" category of the JumpList if needed.
   if (most_visited_should_update) {
     icons_created += UpdateIconFiles(
         most_visited_icon_dir, most_visited_pages, kMostVisitedItems,
@@ skipping 12 matching lines @@
   UMA_HISTOGRAM_COUNTS_100("WinJumplist.CreateIconFilesCount", icons_created);
 
   // TODO(chengx): Remove the UMA histogram after fixing http://crbug.com/40407.
   SCOPED_UMA_HISTOGRAM_TIMER("WinJumplist.UpdateJumpListDuration");
 
   base::ElapsedTimer add_custom_category_timer;
 
   // Update the "Most Visited" category of the JumpList if it exists.
   // This update request is applied into the JumpList when we commit this
   // transaction.
-  if (!jumplist_updater.AddCustomCategory(
-          l10n_util::GetStringUTF16(IDS_NEW_TAB_MOST_VISITED),
-          most_visited_pages, kMostVisitedItems)) {
+  bool add_category_success = jumplist_updater.AddCustomCategory(
+      l10n_util::GetStringUTF16(IDS_NEW_TAB_MOST_VISITED), most_visited_pages,
+      kMostVisitedItems);
+
+  // If AddCustomCategory takes longer than the maximum allowed time, abort the
+  // current update and skip the next |kUpdatesToSkipUnderHeavyLoad| updates.
+  //
+  // We only time adding custom category for most visited pages because
+  // 1. If processing the first category times out or fails, there is no need to

[grt (UTC plus 2), 2017/07/03 06:24:15]

i understand why it makes sense to consider this a timeout if it fails after the
elapsed time (as you've done for BeginUpdate above), but i'm less certain about
the fine-tuning to ratchet down the timeout for only the first operation. i
think there are reasons why the first op may take > 5/8 of the total time, while
the second op may take < 3/8. how many users will be left without an accurate
jumplist due to this aggressive level of back-off? how can you measure the
benefit to the population "helped" by this in relation to the feature being
flaky for those "hurt" by it?

[chengx, 2017/07/09 23:08:49]

To answer your question, I landed crrev/2964873002 to log the ratio of the
duration spent adding the two categories ONLY when the most-visited category has
5 items and the recently-closed category has 3 items. The UMA histogram is
called "WinJumplist.RatioAddCategoryTime". The ratio is multiplied by 10 to
retain sub-decimal precision. The histogram has a Gaussian distribution with
peak value of 17 (so the ratio is 1.7 as it's multiplied by 10). This aligns
with the 5/3. 

I know this adjustment of this threshold is imperfect, but I think it's more
accurate than measuring the total time spent on two categories. The most-visited
category has 5 items for most of the time after the user closes 5-ish tabs
during his entire using Chrome. In comparison, the recently-closed category has
3 items only after the user closes 3 tabs in one Chrome session. It has a much
higher frequency of having less than 3 items. So measuring the most-visited
category alone is more stable than measuring both of them.

+  //    process the second category. In this case, we are not able to time both
+  //    categories. Then we need to select one category from the two.
+  // 2. Most visited category is selected because it always has 5 items, while

[grt (UTC plus 2), 2017/07/03 06:24:15]

why doesn't a newish user have fewer than 5?

to verify, i just launched 61.0.3147.0 canary with a new user data dir. with a
little fiddling, i can't get the jumplist to show anything at all. why doesn't
the following sequence result in a jumplist with one recently closed item:
- chrome.exe --user-data-dir=c:\some\new\dir
- open a new tab
- navigate to nytimes.com
- close that tab
- wait a few seconds
- open the jumplist

[chengx, 2017/07/09 23:08:49]

It does have fewer than 5 items. Then it should take less time than the new
threshold, therefore it won't time out. I have updated the comments to make it
more accurate.
 
I tried a few times but could not repro though. One thing I noticed is that it
took 7+ seconds to initialize the first update. This is due to that the tab
restore notification from the tab closure has to wait for 3.5 s to get through.
It then generates a TopSites sync, which updates both categories. The TopSites
notification waits for another 3.5 s to get through. Therefore, it takes 7+ s to
finish the first update. I've landed crrev/2965973002 to fix this.

+  //    the number of items in recently closed category varies from 1 to 3. This
+  //    means the runtime of AddCustomCategory API should be fixed for most
+  //    visited category, but not for recently closed category. So a fixed
+  //    timeout threshold is only valid for most visited category.
+  if (add_custom_category_timer.Elapsed() >= kTimeOutForAddCustomCategory) {
+    update_transaction->update_timeout = true;
     return;
   }
 
+  if (!add_category_success)
+    return;
+
   // Update the "Recently Closed" category of the JumpList.
   if (!jumplist_updater.AddCustomCategory(
           l10n_util::GetStringUTF16(IDS_RECENTLY_CLOSED), recently_closed_pages,
           kRecentlyClosedItems)) {
     return;
   }
 
-  // If AddCustomCategory takes longer than the maximum allowed time, abort the
-  // current update and skip the next |kUpdatesToSkipUnderHeavyLoad| updates.
-  if (add_custom_category_timer.Elapsed() >= kTimeOutForAddCustomCategory) {
-    update_transaction->update_timeout = true;
-    return;
-  }
-
   // Update the "Tasks" category of the JumpList.
   if (!UpdateTaskCategory(&jumplist_updater, incognito_availability))
     return;
 
   base::ElapsedTimer commit_update_timer;
 
   // Commit this transaction and send the updated JumpList to Windows.
   bool commit_success = jumplist_updater.CommitUpdate();
 
   // If CommitUpdate call takes longer than the maximum allowed time, skip the
@@ skipping 83 matching lines @@
                                const URLIconCache& icons_cache) {
   // Put all cached icon file paths into a set.
   base::flat_set<base::FilePath> cached_files;
   cached_files.reserve(icons_cache.size());
 
   for (const auto& url_path_pair : icons_cache)
     cached_files.insert(url_path_pair.second);
 
   DeleteNonCachedFiles(icon_dir, cached_files);
 }