MB-18476: Handle write failures more gracefully in the mutation log

Log and error message in case of a write failure and remove any unnecessary
asserts in that code path

Change-Id: I50b7e4de4d414e21bf00404a22863baff06c0f4f
Reviewed-on: http://review.couchbase.org/61116
Tested-by: buildbot <build@couchbase.com>
Reviewed-by: Chiyoung Seo <chiyoung@couchbase.com>

diff --git a/src/common.h b/src/common.h
index edad0f1..7a0da41 100644 (file)
--- a/src/common.h
+++ b/src/common.h
@@ -299,5 +299,29 @@ bool sorted(ForwardIterator first, ForwardIterator last, Compare compare) {
     return is_sorted;
 }
 
+/**
+ * Returns the last system call error as a string
+ */
+inline std::string getStringErrno(void) {
+    std::stringstream ss;
+#ifdef WIN32
+    char* win_msg = NULL;
+    DWORD err = GetLastError();
+    FormatMessageA(FORMAT_MESSAGE_ALLOCATE_BUFFER |
+                   FORMAT_MESSAGE_FROM_SYSTEM |
+                   FORMAT_MESSAGE_IGNORE_INSERTS,
+                   NULL, err,
+                   MAKELANGID(LANG_NEUTRAL, SUBLANG_DEFAULT),
+                   (LPTSTR) &win_msg,
+                   0, NULL);
+    ss << "errno = " << err << ": '" << win_msg << "'";
+    LocalFree(win_msg);
+#else
+    ss << "errno = " << errno << ": '" << strerror(errno) << "'";
+#endif
+
+    return ss.str();
+}
+
 #define GIGANTOR ((size_t)1<<(sizeof(size_t)*8-1))
 #endif  // SRC_COMMON_H_

diff --git a/src/couch-kvstore/couch-kvstore.cc b/src/couch-kvstore/couch-kvstore.cc
index 4db5dd0..eaa6472 100644 (file)
--- a/src/couch-kvstore/couch-kvstore.cc
+++ b/src/couch-kvstore/couch-kvstore.cc
@@ -90,27 +90,6 @@ static std::string getStrError(Db *db) {
     return errorStr;
 }
 
-static std::string getSystemStrerror(void) {
-    std::stringstream ss;
-#ifdef WIN32
-    char* win_msg = NULL;
-    DWORD err = GetLastError();
-    FormatMessageA(FORMAT_MESSAGE_ALLOCATE_BUFFER |
-                   FORMAT_MESSAGE_FROM_SYSTEM |
-                   FORMAT_MESSAGE_IGNORE_INSERTS,
-                   NULL, err,
-                   MAKELANGID(LANG_NEUTRAL, SUBLANG_DEFAULT),
-                   (LPTSTR) &win_msg,
-                   0, NULL);
-    ss << "errno = " << err << ": '" << win_msg << "'";
-    LocalFree(win_msg);
-#else
-    ss << "errno = " << errno << ": '" << strerror(errno) << "'";
-#endif
-
-    return ss.str();
-}
-
 static uint8_t determine_datatype(const unsigned char* value,
                                   size_t length) {
     if (checkUTF8JSON(value, length)) {
@@ -861,7 +840,7 @@ bool CouchKVStore::compactVBucket(const uint16_t vbid,
         LOG(EXTENSION_LOG_WARNING,
             "Warning: failed to rename '%s' to '%s': %s",
             compact_file.c_str(), new_file.c_str(),
-            getSystemStrerror().c_str());
+            getStringErrno().c_str());
 
         removeCompactFile(compact_file);
         return false;
@@ -877,7 +856,7 @@ bool CouchKVStore::compactVBucket(const uint16_t vbid,
         if (remove(new_file.c_str()) != 0) {
             LOG(EXTENSION_LOG_WARNING,
                 "Warning: Failed to remove '%s': %s",
-                new_file.c_str(), getSystemStrerror().c_str());
+                new_file.c_str(), getStringErrno().c_str());
         }
         return false;
     }
@@ -1437,7 +1416,7 @@ couchstore_error_t CouchKVStore::openDB(uint16_t vbucketId,
             dbFileName.c_str(), options,
             ((newRevNum > fileRev) ? newRevNum : fileRev),
             couchstore_strerror(errorCode),
-            getSystemStrerror().c_str());
+            getStringErrno().c_str());
     } else {
         if (newRevNum > fileRev) {
             // new revision number found, update it
@@ -1466,7 +1445,7 @@ couchstore_error_t CouchKVStore::openDB_retry(std::string &dbfile,
         LOG(EXTENSION_LOG_INFO, "INFO: couchstore_open_db failed, name=%s "
             "options=%" PRIX64 " error=%s [%s], try it again!",
             dbfile.c_str(), options, couchstore_strerror(errCode),
-            getSystemStrerror().c_str());
+            getStringErrno().c_str());
         *newFileRev = checkNewRevNum(dbfile);
         ++retry;
         if (retry == MAX_OPEN_DB_RETRY - 1 && options == 0 &&
@@ -1521,7 +1500,7 @@ void CouchKVStore::populateFileNameMap(std::vector<std::string> &filenames,
                     } else {
                         LOG(EXTENSION_LOG_WARNING,
                             "Warning: Failed to remove the stale file '%s': %s",
-                            old_file.str().c_str(), getSystemStrerror().c_str());
+                            old_file.str().c_str(), getStringErrno().c_str());
                     }
                 } else {
                     LOG(EXTENSION_LOG_WARNING,
@@ -2526,7 +2505,7 @@ void CouchKVStore::removeCompactFile(const std::string &filename) {
         else {
             LOG(EXTENSION_LOG_WARNING,
                 "Warning: Failed to remove compact file '%s': %s",
-                filename.c_str(), getSystemStrerror().c_str());
+                filename.c_str(), getStringErrno().c_str());
 
             if (errno != ENOENT) {
                 pendingFileDeletions.push(const_cast<std::string &>(filename));

diff --git a/src/mutation_log.cc b/src/mutation_log.cc
index b6672fc..77fee0f 100644 (file)
--- a/src/mutation_log.cc
+++ b/src/mutation_log.cc
@@ -33,7 +33,6 @@ const char *mutation_log_type_names[] = {
     "new", "del", "del_all", "commit1", "commit2", NULL
 };
 
-
 #ifdef WIN32
 ssize_t pread(file_handle_t fd, void *buf, size_t nbyte, uint64_t offset)
 {
@@ -70,11 +69,13 @@ static inline ssize_t doWrite(file_handle_t fd, const uint8_t *buf,
                               size_t nbytes) {
     DWORD byteswritten;
     if (!WriteFile(fd, buf, nbytes, &byteswritten, NULL)) {
-        /* luckily we don't check errno so we don't need to care about that */
+        const std::string& err_str = getStringErrno();
+        LOG(EXTENSION_LOG_WARNING,
+            "Failed to write to mutation log with error: %s",
+            err_str.c_str());
         return -1;
     }
 
-    cb_assert(GetLastError() != ERROR_IO_PENDING);
     return byteswritten;
 }
 
@@ -94,22 +95,6 @@ static inline int doFsync(file_handle_t fd) {
     }
 }
 
-static inline std::string getErrorString(void) {
-    std::string ret;
-    char* win_msg = NULL;
-    DWORD err = GetLastError();
-    FormatMessageA(FORMAT_MESSAGE_ALLOCATE_BUFFER |
-        FORMAT_MESSAGE_FROM_SYSTEM |
-        FORMAT_MESSAGE_IGNORE_INSERTS,
-        NULL, err,
-        MAKELANGID(LANG_NEUTRAL, SUBLANG_DEFAULT),
-        (LPTSTR)&win_msg,
-        0, NULL);
-    ret.assign(win_msg);
-    LocalFree(win_msg);
-    return ret;
-}
-
 static int64_t SeekFile(file_handle_t fd, const std::string &fname,
                         uint64_t offset, bool end)
 {
@@ -125,7 +110,7 @@ static int64_t SeekFile(file_handle_t fd, const std::string &fname,
     if (li.LowPart == INVALID_SET_FILE_POINTER && GetLastError() != NO_ERROR) {
         std::stringstream ss;
         ss << "FATAL: SetFilePointer failed " << fname << ": " <<
-              getErrorString();
+              getStringErrno();
         LOG(EXTENSION_LOG_WARNING, ss.str().c_str());
         li.QuadPart = -1;
     }
@@ -155,7 +140,7 @@ file_handle_t OpenFile(const std::string &fname, std::string &error,
     }
 
     if (fd == INVALID_FILE_VALUE) {
-        error.assign(getErrorString());
+        error.assign(getStringErrno());
     }
 
     return fd;
@@ -239,14 +224,18 @@ int64_t getFileSize(file_handle_t fd) {
 #endif
 
 
-static void writeFully(file_handle_t fd, const uint8_t *buf, size_t nbytes) {
+static bool writeFully(file_handle_t fd, const uint8_t *buf, size_t nbytes) {
     while (nbytes > 0) {
         ssize_t written = doWrite(fd, buf, nbytes);
-        cb_assert(written >= 0);
-
-        nbytes -= written;
-        buf += written;
+        if (written >= 0) {
+            nbytes -= written;
+            buf += written;
+        } else {
+            return false;
+        }
     }
+
+    return true;
 }
 
 uint64_t MutationLogEntry::rowid() const {
@@ -334,6 +323,7 @@ void MutationLog::commit1() {
                                                            0, ML_COMMIT1, 0,
                                                            "");
         writeEntry(mle);
+
         if ((getSyncConfig() & FLUSH_COMMIT_1) != 0) {
             flush();
         }
@@ -349,6 +339,7 @@ void MutationLog::commit2() {
                                                            0, ML_COMMIT2, 0,
                                                            "");
         writeEntry(mle);
+
         if ((getSyncConfig() & FLUSH_COMMIT_2) != 0) {
             flush();
         }
@@ -364,7 +355,9 @@ bool MutationLog::writeInitialBlock() {
     cb_assert(isOpen());
     headerBlock.set(blockSize);
 
-    writeFully(file, (uint8_t*)&headerBlock, sizeof(headerBlock));
+    if (!writeFully(file, (uint8_t*)&headerBlock, sizeof(headerBlock))) {
+        return false;
+    }
 
     int64_t seek_result = SeekFile(file, getLogFile(),
                             std::max(
@@ -376,8 +369,11 @@ bool MutationLog::writeInitialBlock() {
             getLogFile().c_str(), strerror(errno));
         return false;
     }
+
     uint8_t zero(0);
-    writeFully(file, &zero, sizeof(zero));
+    if (!writeFully(file, &zero, sizeof(zero))) {
+        return false;
+    }
     return true;
 }
 
@@ -589,9 +585,14 @@ bool MutationLog::replaceWith(MutationLog &mlog) {
     cb_assert(mlog.isEnabled());
     cb_assert(isEnabled());
 
-    mlog.flush();
+    if (!mlog.flush()) {
+        return false;
+    }
     mlog.close();
-    flush();
+
+    if (!flush()) {
+        return false;
+    }
     close();
 
     for (int i(0); i < MUTATION_LOG_TYPES; ++i) {
@@ -616,7 +617,7 @@ bool MutationLog::replaceWith(MutationLog &mlog) {
     return true;
 }
 
-void MutationLog::flush() {
+bool MutationLog::flush() {
     if (isEnabled() && blockPos > HEADER_RESERVED) {
         cb_assert(isOpen());
         needWriteAccess();
@@ -635,12 +636,20 @@ void MutationLog::flush() {
         uint16_t crc16(htons(crc32 & 0xffff));
         memcpy(blockBuffer, &crc16, sizeof(crc16));
 
-        writeFully(file, blockBuffer, blockSize);
-        logSize.fetch_add(blockSize);
-
-        blockPos = HEADER_RESERVED;
-        entries = 0;
+        if (writeFully(file, blockBuffer, blockSize)) {
+            logSize.fetch_add(blockSize);
+            blockPos = HEADER_RESERVED;
+            entries = 0;
+        } else {
+            /* write to the mutation log failed. Disable the log */
+            disabled = true;
+            LOG(EXTENSION_LOG_WARNING,
+                "Disabling access log due to write failures");
+            return false;
+        }
     }
+
+    return true;
 }
 
 void MutationLog::writeEntry(MutationLogEntry *mle) {

diff --git a/src/mutation_log.h b/src/mutation_log.h
index 9786787..2b8f687 100644 (file)
--- a/src/mutation_log.h
+++ b/src/mutation_log.h
@@ -319,7 +319,7 @@ public:
 
     void commit2();
 
-    void flush();
+    bool flush();
 
     void sync();