RecentTabHelper: adds DVLOG and reload unit test.

chrome/browser/android/offline_pages/recent_tab_helper.cc

 // Copyright (c) 2016 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/android/offline_pages/recent_tab_helper.h"
 
 #include <queue>
 #include <vector>
 
 #include "base/bind.h"
@@ skipping 99 matching lines @@
     const ClientId& client_id, int64_t request_id) {
   // Note: as this implementation only supports one client namespace, enforce
   // that the call is from Downloads.
   DCHECK_EQ(kDownloadNamespace, client_id.name_space);
   auto new_downloads_snapshot_info =
       base::MakeUnique<SnapshotProgressInfo>(client_id, request_id);
 
   // If this tab helper is not enabled, immediately give the job back to
   // RequestCoordinator.
   if (!EnsureInitialized()) {
+    DVLOG(1) << "Snapshots disabled; ignored download request for: "
+             << web_contents()->GetLastCommittedURL().spec();
     ReportDownloadStatusToRequestCoordinator(new_downloads_snapshot_info.get(),
                                              false);
     return;
   }
 
   // If there is an ongoing snapshot request, completely ignore this one and
   // cancel the Background Offliner request.
   // TODO(carlosk): it might be better to make the decision to schedule or not
   // the background request here. See https://crbug.com/686165.
   // TODO(carlosk): there is an edge case that happens when the ongoing request
   // was automatically and transparently scheduled by a navigation event and
   // this call happens due to the user pressing the download button. The user's
   // request to download the page will be immediately dismissed. See
   // https://crbug.com/686283.
   if (downloads_ongoing_snapshot_info_) {
+    DVLOG(1) << "Ongoing request exist; ignored download request for: "
+             << web_contents()->GetLastCommittedURL().spec();
     ReportDownloadStatusToRequestCoordinator(new_downloads_snapshot_info.get(),
                                              true);
     return;
   }
 
   // Stores the new snapshot info.
   downloads_ongoing_snapshot_info_ = std::move(new_downloads_snapshot_info);
 
   // If the page is not yet ready for a snapshot return now as it will be
   // started later, once page loading advances.
   if (PageQuality::POOR == snapshot_controller_->current_page_quality()) {
+    DVLOG(1) << "Waiting for loading page to serve download request for: "
+             << web_contents()->GetLastCommittedURL().spec();
     downloads_snapshot_on_hold_ = true;
     return;
   }
 
   // Otherwise start saving the snapshot now.
+  DVLOG(1) << "Starting download request for: "
+           << web_contents()->GetLastCommittedURL().spec();
   SaveSnapshotForDownloads(false);
 }
 
 // Initialize lazily. It needs TabAndroid for initialization, which is also a
 // TabHelper - so can't initialize in constructor because of uncertain order
 // of creation of TabHelpers.
 bool RecentTabHelper::EnsureInitialized() {
   if (snapshot_controller_)  // Initialized already.
     return snapshots_enabled_;
 
@@ skipping 17 matching lines @@
         web_contents()->GetBrowserContext());
   }
 
   return snapshots_enabled_;
 }
 
 void RecentTabHelper::DidFinishNavigation(
     content::NavigationHandle* navigation_handle) {
   if (!navigation_handle->IsInMainFrame() ||
       !navigation_handle->HasCommitted() || navigation_handle->IsSamePage()) {
+    DVLOG_IF(1, navigation_handle->IsInMainFrame())
+        << "Main frame navigation ignored (reasons: "
+        << !navigation_handle->HasCommitted() << ", "
+        << navigation_handle->IsSamePage()
+        << ") to: " << web_contents()->GetLastCommittedURL().spec();
     return;
   }
 
   if (!EnsureInitialized())
     return;
+  DVLOG(1) << "Navigation acknowledged to: "
+           << web_contents()->GetLastCommittedURL().spec();
 
-  // If there is an ongoing downloads request, lets allow Background Offliner to
-  // continue downloading this page.
+  // If there is an ongoing downloads request, lets make Background Offliner
+  // take over downloading that page.
   if (downloads_ongoing_snapshot_info_) {
+    DVLOG(1) << " - Passing ongoing downloads request to Background Offliner";
     ReportDownloadStatusToRequestCoordinator(
         downloads_ongoing_snapshot_info_.get(), false);
   }
 
   // Cancel any and all in flight snapshot tasks from the previous page.
   CancelInFlightSnapshots();
   downloads_snapshot_on_hold_ = false;
 
   // Always reset so that posted tasks get canceled.
   snapshot_controller_->Reset();
 
   // Check for conditions that would cause us not to snapshot.
   bool can_save =
       !navigation_handle->IsErrorPage() &&
       OfflinePageModel::CanSaveURL(web_contents()->GetLastCommittedURL()) &&
       OfflinePageUtils::GetOfflinePageFromWebContents(web_contents()) ==
           nullptr;
+  DVLOG_IF(1, !can_save) << " - Page can not be saved";
 
   UMA_HISTOGRAM_BOOLEAN("OfflinePages.CanSaveRecentPage", can_save);
 
   if (!can_save)
     snapshot_controller_->Stop();
   last_n_listen_to_tab_hidden_ = can_save && !delegate_->IsLowEndDevice() &&
                                  IsOffliningRecentPagesEnabled();
+  DVLOG_IF(1, !last_n_listen_to_tab_hidden_) << " - Last_n is disabled";
 }
 
 void RecentTabHelper::DocumentAvailableInMainFrame() {
   EnsureInitialized();
   snapshot_controller_->DocumentAvailableInMainFrame();
 }
 
 void RecentTabHelper::DocumentOnLoadCompletedInMainFrame() {
   EnsureInitialized();
   snapshot_controller_->DocumentOnLoadCompletedInMainFrame();
 }
 
 void RecentTabHelper::WebContentsDestroyed() {
   // If there is an ongoing downloads request, lets allow Background Offliner to
   // continue downloading this page.
-  if (downloads_ongoing_snapshot_info_)
+  if (downloads_ongoing_snapshot_info_) {
+    DVLOG(1) << "WebContents destroyed; passing ongoing downloads request to "
+                "Background Offliner";
     ReportDownloadStatusToRequestCoordinator(
         downloads_ongoing_snapshot_info_.get(), false);
+  }
   // And cancel any ongoing snapshots.
   CancelInFlightSnapshots();
 }
 
 // TODO(carlosk): this method is also called when the tab is being closed, when
 // saving a snapshot is probably useless (low probability of the user undoing
 // the close). We should detect that and avoid the saving.
 void RecentTabHelper::WasHidden() {
   if (!IsOffliningRecentPagesEnabled())
     return;
 
-  // Return immediately if last_n is not listening to tab hidden events or if a
-  // last_n snapshot is currently being saved.
-  if (!last_n_listen_to_tab_hidden_ || last_n_ongoing_snapshot_info_)
+  // Return immediately if last_n is not listening to tab hidden events, if a
+  // last_n snapshot is currently being saved or if the tab is closing.
+  if (!last_n_listen_to_tab_hidden_ || last_n_ongoing_snapshot_info_) {
+    DVLOG(1) << "Will not snapshot for last_n (reasons: "
+             << !last_n_listen_to_tab_hidden_ << ", "
+             << !!last_n_ongoing_snapshot_info_
+             << ") for: " << web_contents()->GetLastCommittedURL().spec();
     return;
+  }
 
   // Do not save if page quality is too low.
   // Note: we assume page quality for a page can only increase.
-  if (snapshot_controller_->current_page_quality() == PageQuality::POOR)
+  if (snapshot_controller_->current_page_quality() == PageQuality::POOR) {
+    DVLOG(1) << "Will not snapshot for last_n (page quality too low) for: "
+             << web_contents()->GetLastCommittedURL().spec();
     return;
+  }
 
+  DVLOG(1) << "Starting last_n snapshot for: "
+           << web_contents()->GetLastCommittedURL().spec();
   last_n_ongoing_snapshot_info_ =
       base::MakeUnique<SnapshotProgressInfo>(GetRecentPagesClientId());
   DCHECK(last_n_ongoing_snapshot_info_->IsForLastN());
   DCHECK(snapshots_enabled_);
   // Remove previously captured pages for this tab.
   page_model_->GetOfflineIdsForClientId(
       GetRecentPagesClientId(),
       base::Bind(&RecentTabHelper::ContinueSnapshotWithIdsToPurge,
                  weak_ptr_factory_.GetWeakPtr(),
                  last_n_ongoing_snapshot_info_.get()));
 }
 
 // TODO(carlosk): rename this to RequestSnapshot and make it return a bool
 // representing the acceptance of the snapshot request.
 void RecentTabHelper::StartSnapshot() {
   DCHECK_NE(PageQuality::POOR, snapshot_controller_->current_page_quality());
 
   // As long as snapshots are enabled for this tab, there are two situations
   // that allow for a navigation event to start a snapshot:
   // 1) There is a request on hold waiting for the page to be minimally loaded.
   if (snapshots_enabled_ && downloads_snapshot_on_hold_) {
+    DVLOG(1) << "Resuming downloads snapshot request for: "
+             << web_contents()->GetLastCommittedURL().spec();
     downloads_snapshot_on_hold_ = false;
     SaveSnapshotForDownloads(false);
     return;
   }
 
   // 2) There's no ongoing snapshot and a previous one was saved with lower
   // expected quality than what would be possible now.
   if (snapshots_enabled_ &&
       (!downloads_ongoing_snapshot_info_ &&
        downloads_latest_saved_snapshot_info_ &&
        downloads_latest_saved_snapshot_info_->expected_page_quality <
            snapshot_controller_->current_page_quality())) {
+    DVLOG(1) << "Upgrading last downloads snapshot for: "
+             << web_contents()->GetLastCommittedURL().spec();
     SaveSnapshotForDownloads(true);
     return;
   }
 
   // Notify the controller that a snapshot was not started.
   snapshot_controller_->PendingSnapshotCompleted();
 }
 
 void RecentTabHelper::SaveSnapshotForDownloads(bool replace_latest) {
   DCHECK_NE(PageQuality::POOR, snapshot_controller_->current_page_quality());
@@ skipping 24 matching lines @@
 // 4) Notify requesters about the final result of the operation.
 //
 // For last_n requests the sequence is always started in 1). For downloads it
 // starts in either 2) or 3). Step 4) might be called anytime during the chain
 // for early termination in case of errors.
 void RecentTabHelper::ContinueSnapshotWithIdsToPurge(
     SnapshotProgressInfo* snapshot_info,
     const std::vector<int64_t>& page_ids) {
   DCHECK(snapshot_info);
 
+  DVLOG_IF(1, !page_ids.empty()) << "Deleting " << page_ids.size()
+                                 << " offline pages...";
   page_model_->DeletePagesByOfflineId(
       page_ids, base::Bind(&RecentTabHelper::ContinueSnapshotAfterPurge,
                            weak_ptr_factory_.GetWeakPtr(), snapshot_info));
 }
 
 void RecentTabHelper::ContinueSnapshotAfterPurge(
     SnapshotProgressInfo* snapshot_info,
     OfflinePageModel::DeletePageResult result) {
   if (result != OfflinePageModel::DeletePageResult::SUCCESS) {
     ReportSnapshotCompleted(snapshot_info, false);
@@ skipping 20 matching lines @@
   DCHECK(snapshot_info->IsForLastN() ||
          snapshot_info->request_id == offline_id);
   ReportSnapshotCompleted(snapshot_info, result == SavePageResult::SUCCESS);
 }
 
 // Note: this is the final step in the chain of callbacks and it's where the
 // behavior is different depending on this being a last_n or downloads snapshot.
 void RecentTabHelper::ReportSnapshotCompleted(
     SnapshotProgressInfo* snapshot_info,
     bool success) {
+  DVLOG(1) << (snapshot_info->IsForLastN() ? "Last_n" : "Downloads")
+           << " snapshot " << (success ? "succeeded" : "failed")
+           << " for: " << web_contents()->GetLastCommittedURL().spec();
   if (snapshot_info->IsForLastN()) {
     DCHECK_EQ(snapshot_info, last_n_ongoing_snapshot_info_.get());
     last_n_ongoing_snapshot_info_.reset();
     return;
   }
 
   DCHECK_EQ(snapshot_info, downloads_ongoing_snapshot_info_.get());
   snapshot_controller_->PendingSnapshotCompleted();
   // Tell RequestCoordinator how the request should be processed further.
   ReportDownloadStatusToRequestCoordinator(snapshot_info, success);
@@ skipping 36 matching lines @@
 }
 
 void RecentTabHelper::CancelInFlightSnapshots() {
   weak_ptr_factory_.InvalidateWeakPtrs();
   downloads_ongoing_snapshot_info_.reset();
   downloads_latest_saved_snapshot_info_.reset();
   last_n_ongoing_snapshot_info_.reset();
 }
 
 }  // namespace offline_pages