PVer4: Test checksum on startup outside the hotpath of DB load

components/safe_browsing_db/v4_store.cc

 // Copyright 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 "base/base64.h"
 #include "base/bind.h"
 #include "base/files/file_util.h"
 #include "base/memory/ptr_util.h"
 #include "base/metrics/histogram_macros.h"
 #include "base/metrics/sparse_histogram.h"
@@ skipping 112 matching lines @@
 
 std::string V4Store::DebugString() const {
   std::string state_base64;
   base::Base64Encode(state_, &state_base64);
 
   return base::StringPrintf("path: %" PRIsFP "; state: %s",
                             store_path_.value().c_str(), state_base64.c_str());
 }
 
 bool V4Store::Reset() {
-  // TODO(vakh): Implement skeleton.
+  hash_prefix_map_.clear();

[Nathan Parker, 2016/10/03 02:26:49]

This should delete the file too, according to the .h file.  And just return
void, since there's no possibility of another value.

[vakh (use Gerrit instead), 2016/10/04 07:14:39]

Done. Don't need to delete the file since it would be over-written on next
update.

   state_ = "";
   return true;
 }
 
 ApplyUpdateResult V4Store::ProcessPartialUpdateAndWriteToDisk(
     const HashPrefixMap& hash_prefix_map_old,
     std::unique_ptr<ListUpdateResponse> response) {
   DCHECK(response->has_response_type());
   DCHECK_EQ(ListUpdateResponse::PARTIAL_UPDATE, response->response_type());
 
@@ skipping 79 matching lines @@
     expected_checksum = response->checksum().sha256();
   }
 
   base::TimeTicks before = base::TimeTicks::Now();
   apply_update_result = MergeUpdate(hash_prefix_map_old, hash_prefix_map,
                                     raw_removals, expected_checksum);
   base::TimeTicks after = base::TimeTicks::Now();
   if (apply_update_result != APPLY_UPDATE_SUCCESS) {
     return apply_update_result;
   }
   RecordMergeUpdateTime(after - before);

[Nathan Parker, 2016/10/03 02:26:48]

This mergeupdatetime entry will be for a different code path on startup, so
maybe not really comparable to regular updates. I'm not sure if it matters... 
One idea would be to not put the just-copy-on-startup in MergeUpdate, but call a
different function here if map_old is empty, and record it in a different 
metric.

Just make sure you think about how you'll use this metric, and if this code is
sufficient.

[vakh (use Gerrit instead), 2016/10/04 07:14:39]

Done. With the latest patch, the time metrics are logged separately for
ReadFromDisk, ProcessFullUpdate and ProcessPartialUpdate.

[vakh (use Gerrit instead), 2016/10/04 20:34:50]

Actually, I removed that change to keep this CL simple and focussed. I'll add
that back very soon.

 
   state_ = response->new_client_state();
   return APPLY_UPDATE_SUCCESS;
 }
 
 void V4Store::ApplyUpdate(
     std::unique_ptr<ListUpdateResponse> response,
     const scoped_refptr<base::SingleThreadTaskRunner>& callback_task_runner,
     UpdatedStoreReadyCallback callback) {
   std::unique_ptr<V4Store> new_store(
@@ skipping 158 matching lines @@
 
     (*prefix_map_to_update)[prefix_size].reserve(existing_capacity +
                                                  prefix_length_to_add);
   }
 }
 
 ApplyUpdateResult V4Store::MergeUpdate(const HashPrefixMap& old_prefixes_map,
                                        const HashPrefixMap& additions_map,
                                        const RepeatedField<int32>* raw_removals,
                                        const std::string& expected_checksum) {
+  DCHECK(task_runner_->RunsTasksOnCurrentThread());
   DCHECK(hash_prefix_map_.empty());
+
+  bool calculate_checksum = !expected_checksum.empty();
+  if (old_prefixes_map.empty()) {
+    // If the old map is empty, which it is at startup, then just copy over the
+    // additions map.
+    DCHECK(!raw_removals);
+    hash_prefix_map_ = additions_map;
+
+    if (calculate_checksum) {
+      task_runner_->PostTask(

[Nathan Parker, 2016/10/03 02:26:49]

Add a comment to why this is not run synchronously.

[vakh (use Gerrit instead), 2016/10/04 07:14:39]

Done.

+          FROM_HERE, base::Bind(&V4Store::VerifyChecksum,

[Nathan Parker, 2016/10/03 02:26:49]

How many CPU seconds will this take, when it does run?  If it's substantian
(>100's of ms of CPU), we really should put it off till after startup is really
done.  Otherwise, it'll contend with other startup tasks for CPU time.

You could post it with a 5 minute delay.

[vakh (use Gerrit instead), 2016/10/04 07:14:39]

It takes 2-3 seconds on my machine.
That's a good point but it shouldn't contend with other important tasks because
it is scheduled on the task runner, which by design, is for less critical tasks.
All important tasks should be scheduled on the IO thread, which gets preference
over task runner.
[I ran an experiment and scheduled a task on the IO thread and another on the
task runner in MergeUpdate. The one on IO thread consistently ran much earlier
than the one on task runner].
As I explained above, this should not be necessary if the checksum verification
is scheduled on the task runner.

+                                base::Unretained(this), expected_checksum));
+    }
+
+    return APPLY_UPDATE_SUCCESS;
+  }
+
   hash_prefix_map_.clear();
   ReserveSpaceInPrefixMap(old_prefixes_map, &hash_prefix_map_);
   ReserveSpaceInPrefixMap(additions_map, &hash_prefix_map_);
 
   IteratorMap old_iterator_map;
   HashPrefix next_smallest_prefix_old;
   InitializeIteratorMap(old_prefixes_map, &old_iterator_map);
   bool old_has_unmerged = GetNextSmallestUnmergedPrefix(
       old_prefixes_map, old_iterator_map, &next_smallest_prefix_old);
 
   IteratorMap additions_iterator_map;
   HashPrefix next_smallest_prefix_additions;
   InitializeIteratorMap(additions_map, &additions_iterator_map);
   bool additions_has_unmerged = GetNextSmallestUnmergedPrefix(
       additions_map, additions_iterator_map, &next_smallest_prefix_additions);
 
   // Classical merge sort.
   // The two constructs to merge are maps: old_prefixes_map, additions_map.
   // At least one of the maps still has elements that need to be merged into the
   // new store.
 
-  bool calculate_checksum = !expected_checksum.empty();
   std::unique_ptr<crypto::SecureHash> checksum_ctx(
       crypto::SecureHash::Create(crypto::SecureHash::SHA256));
 
   // Keep track of the number of elements picked from the old map. This is used
   // to determine which elements to drop based on the raw_removals. Note that
   // picked is not the same as merged. A picked element isn't merged if its
   // index is on the raw_removals list.
   int total_picked_from_old = 0;
   const int* removals_iter = raw_removals ? raw_removals->begin() : nullptr;
   while (old_has_unmerged || additions_has_unmerged) {
     // If the same hash prefix appears in the existing store and the additions
     // list, something is clearly wrong. Discard the update.
     if (old_has_unmerged && additions_has_unmerged &&
         next_smallest_prefix_old == next_smallest_prefix_additions) {
       return ADDITIONS_HAS_EXISTING_PREFIX_FAILURE;
     }
 
     // Select which map to pick the next hash prefix from to keep the result in
     // lexographically sorted order.
     bool pick_from_old =
         old_has_unmerged &&
         (!additions_has_unmerged ||
          (next_smallest_prefix_old < next_smallest_prefix_additions));
 
     PrefixSize next_smallest_prefix_size;
     if (pick_from_old) {
       next_smallest_prefix_size = next_smallest_prefix_old.size();
 
       // Update the iterator map, which means that we have merged one hash
-      // prefix of size |next_size_for_old| from the old store.
+      // prefix of size |next_smallest_prefix_size| from the old store.
       old_iterator_map[next_smallest_prefix_size] += next_smallest_prefix_size;
 
       if (!raw_removals || removals_iter == raw_removals->end() ||
           *removals_iter != total_picked_from_old) {
         // Append the smallest hash to the appropriate list.
         hash_prefix_map_[next_smallest_prefix_size] += next_smallest_prefix_old;
 
         if (calculate_checksum) {
           checksum_ctx->Update(base::string_as_array(&next_smallest_prefix_old),
                                next_smallest_prefix_size);
@@ skipping 38 matching lines @@
   }
 
   if (calculate_checksum) {
     std::string checksum(crypto::kSHA256Length, 0);
     checksum_ctx->Finish(base::string_as_array(&checksum), checksum.size());
     if (checksum != expected_checksum) {
       std::string checksum_base64, expected_checksum_base64;
       base::Base64Encode(checksum, &checksum_base64);
       base::Base64Encode(expected_checksum, &expected_checksum_base64);
       DVLOG(1) << "Failure: Checksum mismatch: calculated: " << checksum_base64
-               << " expected: " << expected_checksum_base64;
+               << "; expected: " << expected_checksum_base64
+               << "; store: " << *this;
+      ;
       return CHECKSUM_MISMATCH_FAILURE;
     }
   }
 
   return APPLY_UPDATE_SUCCESS;
 }
 
 StoreReadResult V4Store::ReadFromDisk() {
   DCHECK(task_runner_->RunsTasksOnCurrentThread());
 
@@ skipping 109 matching lines @@
   int result = hash_prefix.compare(mid_prefix);
   if (result == 0) {
     return true;
   } else if (result < 0) {
     return HashPrefixMatches(hash_prefix, begin, mid);
   } else {
     return HashPrefixMatches(hash_prefix, mid + prefix_size, end);
   }
 }
 
+void V4Store::VerifyChecksum(const std::string& expected_checksum) {

[Nathan Parker, 2016/10/03 02:26:49]

Maybe call this VerifyChecksumDelayed, so as to differentiate it from the
checksum check above.

[vakh (use Gerrit instead), 2016/10/04 07:14:39]

Done.

+  DCHECK(task_runner_->RunsTasksOnCurrentThread());
+
+  IteratorMap iterator_map;
+  HashPrefix next_smallest_prefix;
+  InitializeIteratorMap(hash_prefix_map_, &iterator_map);
+  bool has_unmerged = GetNextSmallestUnmergedPrefix(
+      hash_prefix_map_, iterator_map, &next_smallest_prefix);
+
+  std::unique_ptr<crypto::SecureHash> checksum_ctx(
+      crypto::SecureHash::Create(crypto::SecureHash::SHA256));
+  while (has_unmerged) {
+    PrefixSize next_smallest_prefix_size;
+    next_smallest_prefix_size = next_smallest_prefix.size();
+
+    // Update the iterator map, which means that we have read one hash
+    // prefix of size |next_smallest_prefix_size| from hash_prefix_map_.
+    iterator_map[next_smallest_prefix_size] += next_smallest_prefix_size;
+
+    checksum_ctx->Update(base::string_as_array(&next_smallest_prefix),
+                         next_smallest_prefix_size);
+
+    // Find the next smallest unmerged element in the map.
+    has_unmerged = GetNextSmallestUnmergedPrefix(hash_prefix_map_, iterator_map,
+                                                 &next_smallest_prefix);
+  }
+
+  std::string checksum(crypto::kSHA256Length, 0);
+  checksum_ctx->Finish(base::string_as_array(&checksum), checksum.size());
+  if (checksum == expected_checksum) {
+    return;
+  }
+
+  std::string checksum_base64, expected_checksum_base64;
+  base::Base64Encode(checksum, &checksum_base64);
+  base::Base64Encode(expected_checksum, &expected_checksum_base64);
+  DVLOG(1) << "Failure: Checksum mismatch: calculated: " << checksum_base64
+           << "; expected: " << expected_checksum_base64
+           << "; store: " << *this;
+  RecordApplyUpdateResultWhenReadingFromDisk(CHECKSUM_MISMATCH_FAILURE);

[Nathan Parker, 2016/10/03 02:26:49]

This should probably be a different enum, since checksum failures due to disk
corruption are quite different than those from bad merges.

[vakh (use Gerrit instead), 2016/10/04 07:14:39]

Yes, but it is different. This one is:
RecordApplyUpdateResultWhenReadingFromDisk. The other one is logged using:
RecordApplyUpdateResult

+
+  Reset();

[Nathan Parker, 2016/10/03 02:26:49]

This is a race if someone is accessing the store on the IO thread right now. 
Maybe Reset should post to the IO thread to do the clearing.

[vakh (use Gerrit instead), 2016/10/04 07:14:39]

Done.

+}
+
 }  // namespace safe_browsing