Cleanup nuisance DVLOG calls in safe_browsing_database.cc.

chrome/browser/safe_browsing/safe_browsing_database.cc

 // Copyright (c) 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/safe_browsing/safe_browsing_database.h"
 
 #include <algorithm>
 #include <iterator>
 
 #include "base/bind.h"
@@ skipping 487 matching lines @@
   DCHECK(side_effect_free_whitelist_filename_.empty());
   DCHECK(ip_blacklist_filename_.empty());
 
   browse_filename_ = BrowseDBFilename(filename_base);
   browse_prefix_set_filename_ = PrefixSetForFilename(browse_filename_);
 
   browse_store_->Init(
       browse_filename_,
       base::Bind(&SafeBrowsingDatabaseNew::HandleCorruptDatabase,
                  base::Unretained(this)));
-  DVLOG(1) << "Init browse store: " << browse_filename_.value();
 
   {
     // NOTE: There is no need to grab the lock in this function, since
     // until it returns, there are no pointers to this class on other
     // threads.  Then again, that means there is no possibility of
     // contention on the lock...
     base::AutoLock locked(lookup_lock_);
     cached_browse_hashes_.clear();
     LoadPrefixSet();
   }
 
   if (download_store_.get()) {
     download_filename_ = DownloadDBFilename(filename_base);
     download_store_->Init(
         download_filename_,
         base::Bind(&SafeBrowsingDatabaseNew::HandleCorruptDatabase,
                    base::Unretained(this)));
-    DVLOG(1) << "Init download store: " << download_filename_.value();
   }
 
   if (csd_whitelist_store_.get()) {
     csd_whitelist_filename_ = CsdWhitelistDBFilename(filename_base);
     csd_whitelist_store_->Init(
         csd_whitelist_filename_,
         base::Bind(&SafeBrowsingDatabaseNew::HandleCorruptDatabase,
                    base::Unretained(this)));
-    DVLOG(1) << "Init csd whitelist store: " << csd_whitelist_filename_.value();
+
     std::vector<SBAddFullHash> full_hashes;
     if (csd_whitelist_store_->GetAddFullHashes(&full_hashes)) {
       LoadWhitelist(full_hashes, &csd_whitelist_);
     } else {
       WhitelistEverything(&csd_whitelist_);
     }
   } else {
     WhitelistEverything(&csd_whitelist_);  // Just to be safe.
   }
 
   if (download_whitelist_store_.get()) {
     download_whitelist_filename_ = DownloadWhitelistDBFilename(filename_base);
     download_whitelist_store_->Init(
         download_whitelist_filename_,
         base::Bind(&SafeBrowsingDatabaseNew::HandleCorruptDatabase,
                    base::Unretained(this)));
-    DVLOG(1) << "Init download whitelist store: "
-             << download_whitelist_filename_.value();
+
     std::vector<SBAddFullHash> full_hashes;
     if (download_whitelist_store_->GetAddFullHashes(&full_hashes)) {
       LoadWhitelist(full_hashes, &download_whitelist_);
     } else {
       WhitelistEverything(&download_whitelist_);
     }
   } else {
     WhitelistEverything(&download_whitelist_);  // Just to be safe.
   }
 
   if (extension_blacklist_store_.get()) {
     extension_blacklist_filename_ = ExtensionBlacklistDBFilename(filename_base);
     extension_blacklist_store_->Init(
         extension_blacklist_filename_,
         base::Bind(&SafeBrowsingDatabaseNew::HandleCorruptDatabase,
                    base::Unretained(this)));
-    DVLOG(1) << "Init extension blacklist store: "
-             << extension_blacklist_filename_.value();
   }
 
   if (side_effect_free_whitelist_store_.get()) {
     side_effect_free_whitelist_filename_ =
         SideEffectFreeWhitelistDBFilename(filename_base);
     side_effect_free_whitelist_prefix_set_filename_ =
         PrefixSetForFilename(side_effect_free_whitelist_filename_);
     side_effect_free_whitelist_store_->Init(
         side_effect_free_whitelist_filename_,
         base::Bind(&SafeBrowsingDatabaseNew::HandleCorruptDatabase,
                    base::Unretained(this)));
-    DVLOG(1) << "Init side-effect free whitelist store: "
-             << side_effect_free_whitelist_filename_.value();
 
     // If there is no database, the filter cannot be used.
     base::File::Info db_info;
     if (base::GetFileInfo(side_effect_free_whitelist_filename_, &db_info)
         && db_info.size != 0) {
       const base::TimeTicks before = base::TimeTicks::Now();
       side_effect_free_whitelist_prefix_set_ =
           safe_browsing::PrefixSet::LoadFile(
               side_effect_free_whitelist_prefix_set_filename_);
-      DVLOG(1) << "SafeBrowsingDatabaseNew read side-effect free whitelist "
-               << "prefix set in "
-               << (base::TimeTicks::Now() - before).InMilliseconds() << " ms";
       UMA_HISTOGRAM_TIMES("SB2.SideEffectFreeWhitelistPrefixSetLoad",
                           base::TimeTicks::Now() - before);
       if (!side_effect_free_whitelist_prefix_set_.get())
         RecordFailure(FAILURE_SIDE_EFFECT_FREE_WHITELIST_PREFIX_SET_READ);
     }
   } else {
     // Delete any files of the side-effect free sidelist that may be around
     // from when it was previously enabled.
     SafeBrowsingStoreFile::DeleteStore(
         SideEffectFreeWhitelistDBFilename(filename_base));
   }
 
   if (ip_blacklist_store_.get()) {
     ip_blacklist_filename_ = IpBlacklistDBFilename(filename_base);
     ip_blacklist_store_->Init(
         ip_blacklist_filename_,
         base::Bind(&SafeBrowsingDatabaseNew::HandleCorruptDatabase,
                    base::Unretained(this)));
-    DVLOG(1) << "SafeBrowsingDatabaseNew read ip blacklist: "
-             << ip_blacklist_filename_.value();
+
     std::vector<SBAddFullHash> full_hashes;
     if (ip_blacklist_store_->GetAddFullHashes(&full_hashes)) {
       LoadIpBlacklist(full_hashes);
     } else {
-      DVLOG(1) << "Unable to load full hashes from the IP blacklist.";
       LoadIpBlacklist(std::vector<SBAddFullHash>());  // Clear the list.
     }
   }
 }
 
 bool SafeBrowsingDatabaseNew::ResetDatabase() {
   DCHECK_EQ(creation_loop_, base::MessageLoop::current());
 
   // Delete files on disk.
   // TODO(shess): Hard to see where one might want to delete without a
@@ skipping 123 matching lines @@
   // from disk, or the first update populates it.  Bail out without a hit if
   // not yet available.
   if (!side_effect_free_whitelist_prefix_set_.get())
     return false;
 
   return side_effect_free_whitelist_prefix_set_->Exists(full_hash);
 }
 
 bool SafeBrowsingDatabaseNew::ContainsMalwareIP(const std::string& ip_address) {
   net::IPAddressNumber ip_number;
-  if (!net::ParseIPLiteralToNumber(ip_address, &ip_number)) {
-    DVLOG(2) << "Unable to parse IP address: '" << ip_address << "'";
+  if (!net::ParseIPLiteralToNumber(ip_address, &ip_number))
     return false;
-  }
-  if (ip_number.size() == net::kIPv4AddressSize) {
+  if (ip_number.size() == net::kIPv4AddressSize)
     ip_number = net::ConvertIPv4NumberToIPv6Number(ip_number);
-  }
-  if (ip_number.size() != net::kIPv6AddressSize) {
-    DVLOG(2) << "Unable to convert IPv4 address to IPv6: '"
-             << ip_address << "'";
+  if (ip_number.size() != net::kIPv6AddressSize)
     return false;  // better safe than sorry.
-  }
+
   // This function can be called from any thread.
   base::AutoLock locked(lookup_lock_);
   for (IPBlacklist::const_iterator it = ip_blacklist_.begin();
        it != ip_blacklist_.end();
        ++it) {
     const std::string& mask = it->first;
     DCHECK_EQ(mask.size(), ip_number.size());
     std::string subnet(net::kIPv6AddressSize, '\0');
     for (size_t i = 0; i < net::kIPv6AddressSize; ++i) {
       subnet[i] = ip_number[i] & mask[i];
     }
     const std::string hash = base::SHA1HashString(subnet);
     DVLOG(2) << "Lookup Malware IP: "
              << " ip:" << ip_address
              << " mask:" << base::HexEncode(mask.data(), mask.size())
              << " subnet:" << base::HexEncode(subnet.data(), subnet.size())
              << " hash:" << base::HexEncode(hash.data(), hash.size());

[Scott Hess - ex-Googler, 2014/06/18 00:08:41]

I did not remove this one because it looks complicated enough that someone must
have used it once upon a time.  But I wouldn't need much encouragement to remove
it.

     if (it->second.count(hash) > 0) {
       return true;
     }
   }
   return false;
 }
 
 bool SafeBrowsingDatabaseNew::ContainsDownloadWhitelistedString(
     const std::string& str) {
   std::vector<SBFullHash> hashes;
@@ skipping 91 matching lines @@
   DCHECK_EQ(creation_loop_, base::MessageLoop::current());
 
   if (corruption_detected_ || chunks.empty())
     return;
 
   const base::TimeTicks before = base::TimeTicks::Now();
 
   // TODO(shess): The caller should just pass list_id.
   const safe_browsing_util::ListType list_id =
       safe_browsing_util::GetListId(list_name);
-  DVLOG(2) << list_name << ": " << list_id;
 
   SafeBrowsingStore* store = GetStore(list_id);
   if (!store) return;
 
   change_detected_ = true;
 
   // TODO(shess): I believe that the list is always add or sub.  Can this use
   // that productively?
   store->BeginChunk();
   for (size_t i = 0; i < chunks.size(); ++i) {
@@ skipping 345 matching lines @@
     // TODO(shess): If |CacheHashResults()| is posted between the
     // earlier lock and this clear, those pending hashes will be lost.
     // It could be fixed by only removing hashes which were collected
     // at the earlier point.  I believe that is fail-safe as-is (the
     // hash will be fetched again).
     cached_browse_hashes_.clear();
     prefix_miss_cache_.clear();
     browse_prefix_set_.swap(prefix_set);
   }
 
-  DVLOG(1) << "SafeBrowsingDatabaseImpl built prefix set in "
-           << (base::TimeTicks::Now() - before).InMilliseconds()
-           << " ms total.";
   UMA_HISTOGRAM_LONG_TIMES("SB2.BuildFilter", base::TimeTicks::Now() - before);
 
   // Persist the prefix set to disk.  Since only this thread changes
   // |browse_prefix_set_|, there is no need to lock.
   WritePrefixSet();
 
   // Gather statistics.
   if (got_counters && metric->GetIOCounters(&io_after)) {
     UMA_HISTOGRAM_COUNTS("SB2.BuildReadKilobytes",
                          static_cast<int>(io_after.ReadTransferCount -
@@ skipping 35 matching lines @@
 
   // Swap in the newly built prefix set.
   {
     base::AutoLock locked(lookup_lock_);
     side_effect_free_whitelist_prefix_set_.swap(prefix_set);
   }
 
   const base::TimeTicks before = base::TimeTicks::Now();
   const bool write_ok = side_effect_free_whitelist_prefix_set_->WriteFile(
       side_effect_free_whitelist_prefix_set_filename_);
-  DVLOG(1) << "SafeBrowsingDatabaseNew wrote side-effect free whitelist prefix "
-           << "set in " << (base::TimeTicks::Now() - before).InMilliseconds()
-           << " ms";
   UMA_HISTOGRAM_TIMES("SB2.SideEffectFreePrefixSetWrite",
                       base::TimeTicks::Now() - before);
 
   if (!write_ok)
     RecordFailure(FAILURE_SIDE_EFFECT_FREE_WHITELIST_PREFIX_SET_WRITE);
 
   // Gather statistics.
   int64 file_size = GetFileSizeOrZero(
       side_effect_free_whitelist_prefix_set_filename_);
   UMA_HISTOGRAM_COUNTS("SB2.SideEffectFreeWhitelistPrefixSetKilobytes",
@@ skipping 35 matching lines @@
     base::MessageLoop::current()->PostTask(FROM_HERE,
         base::Bind(&SafeBrowsingDatabaseNew::OnHandleCorruptDatabase,
                    reset_factory_.GetWeakPtr()));
   }
 }
 
 void SafeBrowsingDatabaseNew::OnHandleCorruptDatabase() {
   RecordFailure(FAILURE_DATABASE_CORRUPT_HANDLER);
   corruption_detected_ = true;  // Stop updating the database.
   ResetDatabase();
+
+  // NOTE(shess): ResetDatabase() should remove the corruption, so this should
+  // only happen once.  If you are here because you are hitting this after a
+  // restart, then I would be very interested in working with you to figure out
+  // what is happening, since it may affect real users.
   DLOG(FATAL) << "SafeBrowsing database was corrupt and reset";
 }
 
 // TODO(shess): I'm not clear why this code doesn't have any
 // real error-handling.
 void SafeBrowsingDatabaseNew::LoadPrefixSet() {
   DCHECK_EQ(creation_loop_, base::MessageLoop::current());
   DCHECK(!browse_prefix_set_filename_.empty());
 
   // If there is no database, the filter cannot be used.
   base::File::Info db_info;
   if (!base::GetFileInfo(browse_filename_, &db_info) || db_info.size == 0)
     return;
 
   // Cleanup any stale bloom filter (no longer used).
   // TODO(shess): Track failure to delete?
   base::FilePath bloom_filter_filename =
       BloomFilterForFilename(browse_filename_);
   base::DeleteFile(bloom_filter_filename, false);
 
   const base::TimeTicks before = base::TimeTicks::Now();
   browse_prefix_set_ = safe_browsing::PrefixSet::LoadFile(
       browse_prefix_set_filename_);
-  DVLOG(1) << "SafeBrowsingDatabaseNew read prefix set in "
-           << (base::TimeTicks::Now() - before).InMilliseconds() << " ms";
   UMA_HISTOGRAM_TIMES("SB2.PrefixSetLoad", base::TimeTicks::Now() - before);
 
   if (!browse_prefix_set_.get())
     RecordFailure(FAILURE_BROWSE_PREFIX_SET_READ);
 }
 
 bool SafeBrowsingDatabaseNew::Delete() {
   DCHECK_EQ(creation_loop_, base::MessageLoop::current());
 
   const bool r1 = browse_store_->Delete();
@@ skipping 48 matching lines @@
 
 void SafeBrowsingDatabaseNew::WritePrefixSet() {
   DCHECK_EQ(creation_loop_, base::MessageLoop::current());
 
   if (!browse_prefix_set_.get())
     return;
 
   const base::TimeTicks before = base::TimeTicks::Now();
   const bool write_ok = browse_prefix_set_->WriteFile(
       browse_prefix_set_filename_);
-  DVLOG(1) << "SafeBrowsingDatabaseNew wrote prefix set in "
-           << (base::TimeTicks::Now() - before).InMilliseconds() << " ms";
   UMA_HISTOGRAM_TIMES("SB2.PrefixSetWrite", base::TimeTicks::Now() - before);
 
   if (!write_ok)
     RecordFailure(FAILURE_BROWSE_PREFIX_SET_WRITE);
 
 #if defined(OS_MACOSX)
   base::mac::SetFileBackupExclusion(browse_prefix_set_filename_);
 #endif
 }
 
@@ skipping 29 matching lines @@
     base::AutoLock locked(lookup_lock_);
     whitelist->second = false;
     whitelist->first.swap(new_whitelist);
   }
 }
 
 void SafeBrowsingDatabaseNew::LoadIpBlacklist(
     const std::vector<SBAddFullHash>& full_hashes) {
   DCHECK_EQ(creation_loop_, base::MessageLoop::current());
   IPBlacklist new_blacklist;
-  DVLOG(2) << "Writing IP blacklist of size: " << full_hashes.size();
   for (std::vector<SBAddFullHash>::const_iterator it = full_hashes.begin();
        it != full_hashes.end();
        ++it) {
     const char* full_hash = it->full_hash.full_hash;
     DCHECK_EQ(crypto::kSHA256Length, arraysize(it->full_hash.full_hash));
     // The format of the IP blacklist is:
     // SHA-1(IPv6 prefix) + uint8(prefix size) + 11 unused bytes.
     std::string hashed_ip_prefix(full_hash, base::kSHA1Length);
     size_t prefix_size = static_cast<uint8>(full_hash[base::kSHA1Length]);
     if (prefix_size > kMaxIpPrefixSize || prefix_size < kMinIpPrefixSize) {
-      DVLOG(2) << "Invalid IP prefix size in IP blacklist: " << prefix_size;
       RecordFailure(FAILURE_IP_BLACKLIST_UPDATE_INVALID);
       new_blacklist.clear();  // Load empty blacklist.
       break;
     }
 
     // We precompute the mask for the given subnet size to speed up lookups.
     // Basically we need to create a 16B long string which has the highest
     // |size| bits sets to one.
     std::string mask(net::kIPv6AddressSize, '\0');
     mask.replace(0, prefix_size / 8, prefix_size / 8, '\xFF');
     if ((prefix_size % 8) != 0) {
       mask[prefix_size / 8] = 0xFF << (8 - (prefix_size % 8));
     }
     DVLOG(2) << "Inserting malicious IP: "
              << " raw:" << base::HexEncode(full_hash, crypto::kSHA256Length)
              << " mask:" << base::HexEncode(mask.data(), mask.size())
              << " prefix_size:" << prefix_size
              << " hashed_ip:" << base::HexEncode(hashed_ip_prefix.data(),

[Scott Hess - ex-Googler, 2014/06/18 00:08:41]

Likewise this one.

                                                  hashed_ip_prefix.size());
     new_blacklist[mask].insert(hashed_ip_prefix);
   }
 
   base::AutoLock locked(lookup_lock_);
   ip_blacklist_.swap(new_blacklist);
 }
 
 bool SafeBrowsingDatabaseNew::IsMalwareIPMatchKillSwitchOn() {
   SBFullHash malware_kill_switch = SBFullHashForString(kMalwareIPKillSwitchUrl);
   std::vector<SBFullHash> full_hashes;
   full_hashes.push_back(malware_kill_switch);
   return ContainsWhitelistedHashes(csd_whitelist_, full_hashes);
 }
 
 bool SafeBrowsingDatabaseNew::IsCsdWhitelistKillSwitchOn() {
   return csd_whitelist_.second;
 }