Move timestamp de-duping logic from HistoryBackend to NavigationController

Encapsulate the de-duping logic in a new class TimeSmoother.  Improve
the logic to avoid dupes completely unless the clock jumps backwards.

Note that moving the de-duping logic to NavigationController means that timestamps
are de-duped per-tab.  But this is okay given the problem we're trying to solve (which I added a comment about).

Add function to override timestamp generation for testing.

BUG=128449


Review URL: https://chromiumcodereview.appspot.com/11043028

git-svn-id: svn://svn.chromium.org/chrome/trunk/src@160578 0039d316-1c4b-4281-b951-d872f2087c98

6 files changed, 179 insertions, 82 deletions

diff --git a/chrome/browser/history/history_backend.cc b/chrome/browser/history/history_backend.cc
index 2d62c04..61645a9 100644
--- a/chrome/browser/history/history_backend.cc
+++ b/chrome/browser/history/history_backend.cc
@@ -427,19 +427,6 @@ void HistoryBackend::AddPage(const HistoryAddPageArgs& request) {
   DCHECK(request.redirects.empty() ||
          request.redirects.back() == request.url);
 
-  // Avoid duplicating times in the database, at least as long as pages are
-  // added in order. However, we don't want to disallow pages from recording
-  // times earlier than our last_recorded_time_, because someone might set
-  // their machine's clock back.
-  //
-  // TODO(akalin): Put this logic in NavigationController.
-  if (last_requested_time_ == request.time) {
-    last_recorded_time_ = last_recorded_time_ + TimeDelta::FromMicroseconds(1);
-  } else {
-    last_requested_time_ = request.time;
-    last_recorded_time_ = last_requested_time_;
-  }
-
   // If the user is adding older history, we need to make sure our times
   // are correct.
   if (request.time < first_recorded_time_)
@@ -483,7 +470,7 @@ void HistoryBackend::AddPage(const HistoryAddPageArgs& request) {
         content::PAGE_TRANSITION_CHAIN_END);
 
     // No redirect case (one element means just the page itself).
-    last_ids = AddPageVisit(request.url, last_recorded_time_,
+    last_ids = AddPageVisit(request.url, request.time,
                             last_ids.second, t, request.visit_source);
 
     // Update the segment for this visit. KEYWORD_GENERATED visits should not
@@ -491,10 +478,10 @@ void HistoryBackend::AddPage(const HistoryAddPageArgs& request) {
     // visited db).
     if (!is_keyword_generated) {
       UpdateSegments(request.url, from_visit_id, last_ids.second, t,
-                     last_recorded_time_);
+                     request.time);
 
       // Update the referrer's duration.
-      UpdateVisitDuration(from_visit_id, last_recorded_time_);
+      UpdateVisitDuration(from_visit_id, request.time);
     }
   } else {
     // Redirect case. Add the redirect chain.
@@ -559,15 +546,15 @@ void HistoryBackend::AddPage(const HistoryAddPageArgs& request) {
       // them anyway, and if we ever decide to, we can reconstruct their order
       // from the redirect chain.
       last_ids = AddPageVisit(redirects[redirect_index],
-                              last_recorded_time_, last_ids.second,
+                              request.time, last_ids.second,
                               t, request.visit_source);
       if (t & content::PAGE_TRANSITION_CHAIN_START) {
         // Update the segment for this visit.
         UpdateSegments(redirects[redirect_index],
-                       from_visit_id, last_ids.second, t, last_recorded_time_);
+                       from_visit_id, last_ids.second, t, request.time);
 
         // Update the visit_details for this visit.
-        UpdateVisitDuration(from_visit_id, last_recorded_time_);
+        UpdateVisitDuration(from_visit_id, request.time);
       }
 
       // Subsequent transitions in the redirect list must all be server
@@ -596,7 +583,7 @@ void HistoryBackend::AddPage(const HistoryAddPageArgs& request) {
 
   if (text_database_.get()) {
     text_database_->AddPageURL(request.url, last_ids.first, last_ids.second,
-                               last_recorded_time_);
+                               request.time);
   }
 
   ScheduleCommit();
diff --git a/chrome/browser/history/history_backend.h b/chrome/browser/history/history_backend.h
index 505a009..d15f597 100644
--- a/chrome/browser/history/history_backend.h
+++ b/chrome/browser/history/history_backend.h
@@ -145,6 +145,7 @@ class HistoryBackend : public base::RefCountedThreadSafe<HistoryBackend>,
 
   // Navigation ----------------------------------------------------------------
 
+  // |request.time| must be unique with high probability.
   void AddPage(const HistoryAddPageArgs& request);
   virtual void SetPageTitle(const GURL& url, const string16& title);
   void AddPageNoVisitForBookmark(const GURL& url, const string16& title);
@@ -845,19 +846,6 @@ class HistoryBackend : public base::RefCountedThreadSafe<HistoryBackend>,
   typedef base::MRUCache<GURL, history::RedirectList> RedirectCache;
   RedirectCache recent_redirects_;
 
-  // Timestamp of the last page addition request. We use this to detect when
-  // multiple additions are requested at the same time (within the resolution
-  // of the timer), so we can try to ensure they're unique when they're added
-  // to the database by using the last_recorded_time_ (q.v.). We still can't
-  // enforce or guarantee uniqueness, since the user might set his clock back.
-  base::Time last_requested_time_;
-
-  // Timestamp of the last page addition, as it was recorded in the database.
-  // If two or more requests come in at the same time, we increment that time
-  // by 1 us between them so it's more likely to be unique in the database.
-  // This keeps track of that higher-resolution timestamp.
-  base::Time last_recorded_time_;
-
   // Timestamp of the first entry in our database.
   base::Time first_recorded_time_;
 
diff --git a/chrome/browser/history/history_unittest.cc b/chrome/browser/history/history_unittest.cc
index bddb08d..f4fa4d4 100644
--- a/chrome/browser/history/history_unittest.cc
+++ b/chrome/browser/history/history_unittest.cc
@@ -496,46 +496,6 @@ TEST_F(HistoryTest, AddPage) {
   EXPECT_FALSE(query_url_row_.hidden());  // Because loaded in main frame.
 }
 
-TEST_F(HistoryTest, AddPageSameTimes) {
-  scoped_refptr<HistoryService> history(new HistoryService);
-  history_service_ = history;
-  ASSERT_TRUE(history->Init(history_dir_, NULL));
-
-  Time now = Time::Now();
-  const GURL test_urls[] = {
-    GURL("http://timer.first.page/"),
-    GURL("http://timer.second.page/"),
-    GURL("http://timer.third.page/"),
-  };
-
-  // Make sure that two pages added at the same time with no intervening
-  // additions have different timestamps.
-  history->AddPage(test_urls[0], now, NULL, 0, GURL(),
-                   history::RedirectList(), content::PAGE_TRANSITION_LINK,
-                   history::SOURCE_BROWSED, false);
-  EXPECT_TRUE(QueryURL(history, test_urls[0]));
-  EXPECT_EQ(1, query_url_row_.visit_count());
-  EXPECT_TRUE(now == query_url_row_.last_visit());  // gtest doesn't like Time
-
-  history->AddPage(test_urls[1], now, NULL, 0, GURL(),
-                   history::RedirectList(), content::PAGE_TRANSITION_LINK,
-                   history::SOURCE_BROWSED, false);
-  EXPECT_TRUE(QueryURL(history, test_urls[1]));
-  EXPECT_EQ(1, query_url_row_.visit_count());
-  EXPECT_TRUE(now + TimeDelta::FromMicroseconds(1) ==
-      query_url_row_.last_visit());
-
-  // Make sure the next page, at a different time, is also correct.
-  history->AddPage(test_urls[2], now + TimeDelta::FromMinutes(1),
-                   NULL, 0, GURL(), history::RedirectList(),
-                   content::PAGE_TRANSITION_LINK, history::SOURCE_BROWSED,
-                   false);
-  EXPECT_TRUE(QueryURL(history, test_urls[2]));
-  EXPECT_EQ(1, query_url_row_.visit_count());
-  EXPECT_TRUE(now + TimeDelta::FromMinutes(1) ==
-      query_url_row_.last_visit());
-}
-
 TEST_F(HistoryTest, AddRedirect) {
   scoped_refptr<HistoryService> history(new HistoryService);
   history_service_ = history;
diff --git a/content/browser/web_contents/navigation_controller_impl.cc b/content/browser/web_contents/navigation_controller_impl.cc
index 3e749f7..e8f8bff 100644
--- a/content/browser/web_contents/navigation_controller_impl.cc
+++ b/content/browser/web_contents/navigation_controller_impl.cc
@@ -4,6 +4,7 @@
 
 #include "content/browser/web_contents/navigation_controller_impl.h"
 
+#include "base/bind.h"
 #include "base/file_util.h"
 #include "base/logging.h"
 #include "base/string_number_conversions.h"  // Temporary
@@ -198,6 +199,22 @@ void NavigationController::DisablePromptOnRepost() {
 
 }  // namespace content
 
+base::Time NavigationControllerImpl::TimeSmoother::GetSmoothedTime(
+    base::Time t) {
+  // If |t| is between the water marks, we're in a run of duplicates
+  // or just getting out of it, so increase the high-water mark to get
+  // a time that probably hasn't been used before and return it.
+  if (low_water_mark_ <= t && t <= high_water_mark_) {
+    high_water_mark_ += base::TimeDelta::FromMicroseconds(1);
+    return high_water_mark_;
+  }
+
+  // Otherwise, we're clear of the last duplicate run, so reset the
+  // water marks.
+  low_water_mark_ = high_water_mark_ = t;
+  return t;
+}
+
 NavigationControllerImpl::NavigationControllerImpl(
     WebContentsImpl* web_contents,
     BrowserContext* browser_context)
@@ -211,7 +228,8 @@ NavigationControllerImpl::NavigationControllerImpl(
       ALLOW_THIS_IN_INITIALIZER_LIST(ssl_manager_(this)),
       needs_reload_(false),
       is_initial_navigation_(true),
-      pending_reload_(NO_RELOAD) {
+      pending_reload_(NO_RELOAD),
+      get_timestamp_callback_(base::Bind(&base::Time::Now)) {
   DCHECK(browser_context_);
 }
 
@@ -756,12 +774,9 @@ bool NavigationControllerImpl::RendererDidNavigate(
   //
   // TODO(akalin): Use "sane time" as described in
   // http://www.chromium.org/developers/design-documents/sane-time .
-  //
-  // TODO(akalin): Make sure (to at least a high probability) that the
-  // generated timestamp is unique.  (Move the uniquifying logic from
-  // history_backend.cc.)
-  const base::Time timestamp = base::Time::Now();
-  DVLOG(1) << "Navigation finished at timestamp "
+  base::Time timestamp =
+      time_smoother_.GetSmoothedTime(get_timestamp_callback_.Run());
+  DVLOG(1) << "Navigation finished at (smoothed) timestamp "
            << timestamp.ToInternalValue();
 
   // All committed entries should have nonempty content state so WebKit doesn't
@@ -774,7 +789,6 @@ bool NavigationControllerImpl::RendererDidNavigate(
   // No longer needed since content state will hold the post data if any.
   active_entry->SetBrowserInitiatedPostData(NULL);
 
-
   // Once committed, we do not need to track if the entry was initiated by
   // the renderer.
   active_entry->set_is_renderer_initiated(false);
@@ -1607,3 +1621,8 @@ void NavigationControllerImpl::InsertEntriesFrom(
     }
   }
 }
+
+void NavigationControllerImpl::SetGetTimestampCallbackForTest(
+    const base::Callback<base::Time()>& get_timestamp_callback) {
+  get_timestamp_callback_ = get_timestamp_callback;
+}
diff --git a/content/browser/web_contents/navigation_controller_impl.h b/content/browser/web_contents/navigation_controller_impl.h
index bc88904..0a13bca 100644
--- a/content/browser/web_contents/navigation_controller_impl.h
+++ b/content/browser/web_contents/navigation_controller_impl.h
@@ -6,7 +6,9 @@
 #define CONTENT_BROWSER_WEB_CONTENTS_NAVIGATION_CONTROLLER_IMPL_H_
 
 #include "build/build_config.h"
+#include "base/callback.h"
 #include "base/compiler_specific.h"
+#include "base/gtest_prod_util.h"
 #include "base/memory/linked_ptr.h"
 #include "base/time.h"
 #include "content/browser/ssl/ssl_manager.h"
@@ -191,11 +193,34 @@ class CONTENT_EXPORT NavigationControllerImpl
   }
   static size_t max_entry_count();
 
+  void SetGetTimestampCallbackForTest(
+      const base::Callback<base::Time()>& get_timestamp_callback);
+
  private:
-  class RestoreHelper;
   friend class RestoreHelper;
   friend class WebContentsImpl;  // For invoking OnReservedPageIDRange.
 
+  FRIEND_TEST_ALL_PREFIXES(TimeSmoother, Basic);
+  FRIEND_TEST_ALL_PREFIXES(TimeSmoother, SingleDuplicate);
+  FRIEND_TEST_ALL_PREFIXES(TimeSmoother, ManyDuplicates);
+  FRIEND_TEST_ALL_PREFIXES(TimeSmoother, ClockBackwardsJump);
+
+  // Helper class to smooth out runs of duplicate timestamps while still
+  // allowing time to jump backwards.
+  //
+  // TODO(akalin): Use CONTENT_EXPORT_PRIVATE once we have that.
+  class CONTENT_EXPORT TimeSmoother {
+   public:
+    // Returns |t| with possibly some time added on.
+    base::Time GetSmoothedTime(base::Time t);
+
+   private:
+    // |low_water_mark_| is the first time in a sequence of adjusted
+    // times and |high_water_mark_| is the last.
+    base::Time low_water_mark_;
+    base::Time high_water_mark_;
+  };
+
   // Classifies the given renderer navigation (see the NavigationType enum).
   content::NavigationType ClassifyNavigation(
       const ViewHostMsg_FrameNavigate_Params& params) const;
@@ -352,6 +377,16 @@ class CONTENT_EXPORT NavigationControllerImpl
   // NO_RELOAD otherwise.
   ReloadType pending_reload_;
 
+  // Used to get timestamps for newly-created navigation entries.
+  base::Callback<base::Time()> get_timestamp_callback_;
+
+  // Used to smooth out timestamps from |get_timestamp_callback_|.
+  // Without this, whenever there is a run of redirects or
+  // code-generated navigations, those navigations may occur within
+  // the timer resolution, leading to things sometimes showing up in
+  // the wrong order in the history view.
+  TimeSmoother time_smoother_;
+
   DISALLOW_COPY_AND_ASSIGN(NavigationControllerImpl);
 };
 
diff --git a/content/browser/web_contents/navigation_controller_impl_unittest.cc b/content/browser/web_contents/navigation_controller_impl_unittest.cc
index bc80f1b..3d399e2 100644
--- a/content/browser/web_contents/navigation_controller_impl_unittest.cc
+++ b/content/browser/web_contents/navigation_controller_impl_unittest.cc
@@ -2,6 +2,8 @@
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
+#include "base/basictypes.h"
+#include "base/bind.h"
 #include "base/file_util.h"
 #include "base/memory/scoped_ptr.h"
 #include "base/path_service.h"
@@ -48,6 +50,63 @@ using content::TestRenderViewHost;
 using content::TestWebContents;
 using content::WebContents;
 
+// TimeSmoother tests ----------------------------------------------------------
+
+// With no duplicates, GetSmoothedTime should be the identity
+// function.
+TEST(TimeSmoother, Basic) {
+  NavigationControllerImpl::TimeSmoother smoother;
+  for (int64 i = 1; i < 1000; ++i) {
+    base::Time t = base::Time::FromInternalValue(i);
+    EXPECT_EQ(t, smoother.GetSmoothedTime(t));
+  }
+}
+
+// With a single duplicate and timestamps thereafter increasing by one
+// microsecond, the smoothed time should always be one behind.
+TEST(TimeSmoother, SingleDuplicate) {
+  NavigationControllerImpl::TimeSmoother smoother;
+  base::Time t = base::Time::FromInternalValue(1);
+  EXPECT_EQ(t, smoother.GetSmoothedTime(t));
+  for (int64 i = 1; i < 1000; ++i) {
+    base::Time expected_t = base::Time::FromInternalValue(i + 1);
+    t = base::Time::FromInternalValue(i);
+    EXPECT_EQ(expected_t, smoother.GetSmoothedTime(t));
+  }
+}
+
+// With k duplicates and timestamps thereafter increasing by one
+// microsecond, the smoothed time should always be k behind.
+TEST(TimeSmoother, ManyDuplicates) {
+  const int64 kNumDuplicates = 100;
+  NavigationControllerImpl::TimeSmoother smoother;
+  base::Time t = base::Time::FromInternalValue(1);
+  for (int64 i = 0; i < kNumDuplicates; ++i) {
+    base::Time expected_t = base::Time::FromInternalValue(i + 1);
+    EXPECT_EQ(expected_t, smoother.GetSmoothedTime(t));
+  }
+  for (int64 i = 1; i < 1000; ++i) {
+    base::Time expected_t =
+        base::Time::FromInternalValue(i + kNumDuplicates);
+    t = base::Time::FromInternalValue(i);
+    EXPECT_EQ(expected_t, smoother.GetSmoothedTime(t));
+  }
+}
+
+// If the clock jumps far back enough after a run of duplicates, it
+// should immediately jump to that value.
+TEST(TimeSmoother, ClockBackwardsJump) {
+  const int64 kNumDuplicates = 100;
+  NavigationControllerImpl::TimeSmoother smoother;
+  base::Time t = base::Time::FromInternalValue(1000);
+  for (int64 i = 0; i < kNumDuplicates; ++i) {
+    base::Time expected_t = base::Time::FromInternalValue(i + 1000);
+    EXPECT_EQ(expected_t, smoother.GetSmoothedTime(t));
+  }
+  t = base::Time::FromInternalValue(500);
+  EXPECT_EQ(t, smoother.GetSmoothedTime(t));
+}
+
 // NavigationControllerTest ----------------------------------------------------
 
 class NavigationControllerTest : public RenderViewHostImplTestHarness {
@@ -272,6 +331,55 @@ TEST_F(NavigationControllerTest, LoadURL) {
   EXPECT_FALSE(controller.GetActiveEntry()->GetTimestamp().is_null());
 }
 
+namespace {
+
+base::Time GetFixedTime(base::Time time) {
+  return time;
+}
+
+}  // namespace
+
+TEST_F(NavigationControllerTest, LoadURLSameTime) {
+  NavigationControllerImpl& controller = controller_impl();
+  TestNotificationTracker notifications;
+  RegisterForAllNavNotifications(&notifications, &controller);
+
+  // Set the clock to always return a timestamp of 1.
+  controller.SetGetTimestampCallbackForTest(
+      base::Bind(&GetFixedTime, base::Time::FromInternalValue(1)));
+
+  const GURL url1("http://foo1");
+  const GURL url2("http://foo2");
+
+  controller.LoadURL(
+      url1, content::Referrer(), content::PAGE_TRANSITION_TYPED, std::string());
+
+  test_rvh()->SendNavigate(0, url1);
+  EXPECT_TRUE(notifications.Check1AndReset(
+      content::NOTIFICATION_NAV_ENTRY_COMMITTED));
+
+  // Load another...
+  controller.LoadURL(
+      url2, content::Referrer(), content::PAGE_TRANSITION_TYPED, std::string());
+
+  // Simulate the beforeunload ack for the cross-site transition, and then the
+  // commit.
+  test_rvh()->SendShouldCloseACK(true);
+  test_rvh()->SendNavigate(1, url2);
+  EXPECT_TRUE(notifications.Check1AndReset(
+      content::NOTIFICATION_NAV_ENTRY_COMMITTED));
+
+  // The two loads should now be committed.
+  ASSERT_EQ(controller.GetEntryCount(), 2);
+
+  // Timestamps should be distinct despite the clock returning the
+  // same value.
+  EXPECT_EQ(1u,
+            controller.GetEntryAtIndex(0)->GetTimestamp().ToInternalValue());
+  EXPECT_EQ(2u,
+            controller.GetEntryAtIndex(1)->GetTimestamp().ToInternalValue());
+}
+
 void CheckNavigationEntryMatchLoadParams(
     NavigationController::LoadURLParams& load_params,
     NavigationEntryImpl* entry) {