Do not CHECK on the result of Sql::Statement::Run.

content/browser/media/webrtc_identity_store_backend.cc

 // Copyright 2013 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 "content/browser/media/webrtc_identity_store_backend.h"
 
 #include "base/file_util.h"
 #include "base/files/file_path.h"
+#include "base/strings/string_util.h"
 #include "content/public/browser/browser_thread.h"
 #include "net/base/net_errors.h"
 #include "sql/error_delegate_util.h"
 #include "sql/statement.h"
 #include "sql/transaction.h"
 #include "url/gurl.h"
 #include "webkit/browser/quota/special_storage_policy.h"
 
 namespace content {
 
@@ skipping 317 matching lines @@
 }
 
 WebRTCIdentityStoreBackend::~WebRTCIdentityStoreBackend() {}
 
 void WebRTCIdentityStoreBackend::OnLoaded(scoped_ptr<IdentityMap> out_map) {
   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
 
   if (state_ != LOADING)
     return;
 
-  DVLOG(2) << "WebRTC identity store has loaded.";
+  DVLOG(3) << "WebRTC identity store has loaded.";
 
   state_ = LOADED;
   identities_.swap(*out_map);
 
   for (size_t i = 0; i < pending_find_requests_.size(); ++i) {
     FindIdentity(pending_find_requests_[i]->origin,
                  pending_find_requests_[i]->identity_name,
                  pending_find_requests_[i]->common_name,
                  pending_find_requests_[i]->callback);
     delete pending_find_requests_[i];
   }
   pending_find_requests_.clear();
 }
 
 //
 // Implementation of SqlLiteStorage.
 //
 
 void WebRTCIdentityStoreBackend::SqlLiteStorage::Load(IdentityMap* out_map) {
   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::DB));
   DCHECK(!db_.get());
 
   // Ensure the parent directory for storing certs is created before reading
   // from it.
   const base::FilePath dir = path_.DirName();
   if (!base::PathExists(dir) && !base::CreateDirectory(dir)) {
-    DLOG(ERROR) << "Unable to open DB file path.";
+    DVLOG(2) << "Unable to open DB file path.";
     return;
   }
 
   db_.reset(new sql::Connection());
 
   db_->set_error_callback(base::Bind(&SqlLiteStorage::OnDatabaseError, this));
 
   if (!db_->Open(path_)) {
-    DLOG(ERROR) << "Unable to open DB.";
+    DVLOG(2) << "Unable to open DB.";

[Scott Hess - ex-Googler, 2014/05/24 05:06:41]

For all of these log lines, please verify that you're not just duplicating
something already covered in sql/.  These are debug-only, so they won't bloat up
the release binary, but it's still annoying to get 12 lines of redundant
information when you trip something.

Hmm, I guess more to the point, are there any circumstances where you imagine
someone will enable the --verbose flags to see these AND will even have compiled
things with the right flags that the code is even there AND won't be in a
position to just layer in some additional spot logging or run it in a debugger?

[jiayl, 2014/05/27 18:18:31]

I don't think it's redundant with the sql/ logs, which does not tell which
caller is hit by the DB error and gives no hint on what feature may be broken.

It's true that these logs will be not be shown/useful for most of the time, but
it will still make it more convenient for the developers to nail down problems
without touching the code. E.g. a webrtc/libjingle developer may expierience
issues with DTLS but has no idea about this part of the code in Chrome.

Maybe I should raise the level of the log, say DLOG(WARNING)?

     db_.reset();
     return;
   }
 
   if (!InitDB(db_.get())) {
-    DLOG(ERROR) << "Unable to init DB.";
+    DVLOG(2) << "Unable to init DB.";
     db_.reset();
     return;
   }
 
   db_->Preload();
 
   // Delete expired identities.
   DeleteBetween(base::Time(), base::Time::Now() - validity_period_);
 
   // Slurp all the identities into the out_map.
@@ skipping 64 matching lines @@
       SQL_FROM_HERE,
       "DELETE FROM webrtc_identity_store"
       " WHERE creation_time >= ? AND creation_time <= ?"));
   CHECK(del_stmt.is_valid());
 
   del_stmt.BindInt64(0, delete_begin.ToInternalValue());
   del_stmt.BindInt64(1, delete_end.ToInternalValue());
 
   sql::Transaction transaction(db_.get());
   if (!transaction.Begin()) {
-    DLOG(ERROR) << "Failed to begin the transaction.";
+    DVLOG(2) << "Failed to begin the transaction.";
     return;
   }
 
-  CHECK(del_stmt.Run());
-  transaction.Commit();
+  if (!del_stmt.Run()) {
+    DVLOG(2) << "Failed to run the delete statement.";
+    return;
+  }
+
+  if (!transaction.Commit())
+    DVLOG(2) << "Failed to commit the transaction.";
 }
 
 void WebRTCIdentityStoreBackend::SqlLiteStorage::OnDatabaseError(
     int error,
     sql::Statement* stmt) {
   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::DB));
-  if (!sql::IsErrorCatastrophic(error))
+
+  std::string statement(stmt->GetSQLStatement());
+
+  // "DELETE" failures are always non-recoverable, because we don't want to keep
+  // unwanted identities (e.g. expired, or user requested to delete) in the
+  // database.
+  if (!sql::IsErrorCatastrophic(error) &&
+      !StartsWithASCII(statement, "DELETE", false)) {

[Ami GONE FROM CHROMIUM, 2014/05/23 23:30:30]

ಠ_ಠ 

What about "dElEte"?
(should you ToLower() the statement before text-compare?)

More generally this seems quite brittle for something that's supposed to be
managing security-related things.
What's the cost of getting this wrong (using a corrupt/out-of-date DB)?
What's the cost of being overzealous (always nuking the DB on error)?

[jiayl, 2014/05/23 23:34:54]

The comparison is case insensitive.
DB corruption will be a catastrophic error. See
https://code.google.com/p/chromium/codesearch#chromium/src/sql/error_delegate...
What do you mean by "out of date"? We always try to delete expired identifies at
the startup of the class.

[Ami GONE FROM CHROMIUM, 2014/05/23 23:47:01]

So it is!  
(I missed the "false")
When I said "corrupt" I was referring to a DB whose contents may be correct as
far as the DB layer is concerned but incorrect as far as this class is
concerned.  In other words, does this class expect semantics from the DB not
expressed in the schema?  Or is the DB just a list of records with no
inter-relation, and is only used a serialization mechanism for persistence?

[jiayl, 2014/05/23 23:53:25]

The expectations of this class and not expressed in the DB schema are
1. the (origin, identit_name) can uniquely identify a record in the DB
2. expired records are deleted on startup

These can only be violated if "DELETE" fails. "ADD" or "SELECT" failures will
not cause "corruption".

[Scott Hess - ex-Googler, 2014/05/24 05:06:41]

If you're going to use this kind of assumption to test results, then please add
some sort of DCHECK somewhere to prove that the code is adhering to your
assumptions (as opposed to containing leading whitespace or a leading comment or
something).  Obviously putting that DCHECK here has coverage issues, I'd be
comfortable with having it in sql/, but am not offering to do the gruntwork to
flush out whoever is already doing that.

Also, there is support code in sql/test to allow injecting some types of
corruption into databases.  If you're committed to handling error cases, you
really should test them.  There have been cases where the error-handling code
was simply wrong, and we found out when thousands of people started crashing.

[I haven't read your code thoroughly, perhaps there are tests of this sort out
there.  But obviously they can't be testing _these_ cases, because of the
CHECKs.]
I'm not sure what you're getting at with this comment, but keep in mind that:
 - in the fleet, corruption happens because hardware is broken.
 - corruption can manifest as broken schema.

Long-term, you might want to tighten the screws past what the "is catastrophic"
test returns.  The other cases aren't necessarily going to recover themselves,
they were just deemed too uncertain to act on.  Personally I've never been
convinced that we can have a global sense of unrecoverable, due to differences
in how sub-systems are structured.

[jiayl, 2014/05/27 18:18:31]

Now all DB errors will trigger RazeAndClose. A test was added.

     return;
+  }
+
+  DVLOG(2) << "Database error " << error << " for statement " << statement;
   db_->RazeAndClose();
+  db_.reset();
 }
 
 void WebRTCIdentityStoreBackend::SqlLiteStorage::BatchOperation(
     OperationType type,
     const GURL& origin,
     const std::string& identity_name,
     const Identity& identity) {
   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::DB));
   // Commit every 30 seconds.
   static const base::TimeDelta kCommitInterval(
@@ skipping 37 matching lines @@
   CHECK(add_stmt.is_valid());
 
   sql::Statement del_stmt(db_->GetCachedStatement(
       SQL_FROM_HERE,
       "DELETE FROM webrtc_identity_store WHERE origin=? AND identity_name=?"));
 
   CHECK(del_stmt.is_valid());
 
   sql::Transaction transaction(db_.get());
   if (!transaction.Begin()) {
-    DLOG(ERROR) << "Failed to begin the transaction.";
+    DVLOG(2) << "Failed to begin the transaction.";
     return;
   }
 
   for (PendingOperationList::iterator it = pending_operations_.begin();
        it != pending_operations_.end();
        ++it) {
     scoped_ptr<PendingOperation> po(*it);
     switch (po->type) {
       case ADD_IDENTITY: {
         add_stmt.Reset(true);
         add_stmt.BindString(0, po->origin.spec());
         add_stmt.BindString(1, po->identity_name);
         add_stmt.BindString(2, po->identity.common_name);
         const std::string& cert = po->identity.certificate;
         add_stmt.BindBlob(3, cert.data(), cert.size());
         const std::string& private_key = po->identity.private_key;
         add_stmt.BindBlob(4, private_key.data(), private_key.size());
         add_stmt.BindInt64(5, po->identity.creation_time);
-        CHECK(add_stmt.Run());
+        if (!add_stmt.Run()) {
+          DVLOG(2) << "Failed to add the identity to DB.";
+          return;
+        }
         break;
       }
       case DELETE_IDENTITY:
         del_stmt.Reset(true);
         del_stmt.BindString(0, po->origin.spec());
         del_stmt.BindString(1, po->identity_name);
-        CHECK(del_stmt.Run());
+        if (!del_stmt.Run()) {
+          DVLOG(2) << "Failed to delete the identity from DB.";
+          return;
+        }
         break;
 
       default:
         NOTREACHED();
         break;
     }
   }
-  transaction.Commit();
+
+  if (!transaction.Commit()) {
+    DVLOG(2) << "Failed to commit the transaction.";
+    return;
+  }
+
   pending_operations_.clear();
 }
 
 }  // namespace content