MDEV-18200 MariaBackup full backup failed with InnoDB: Failing assertion: success

There are many filesystem related errors that can occur with
MariaBackup. These already outputed to stderr with a good description of
the error. Many of these are permission or resource (file descriptor)
limits where the assertion and resulting core crash doesn't offer
developers anything more than the log message. To the user, assertions
and core crashes come across as poor error handling.

As such we return an error and handle this all the way up the stack.

extra/mariabackup/xtrabackup.cc

@@ -4436,16 +4436,24 @@ bool Backup_datasinks::backup_low()
 
 		if (recv_find_max_checkpoint(&max_cp_field) == DB_SUCCESS
 		    && log_sys.log.format != 0) {
-			if (max_cp_field == LOG_CHECKPOINT_1) {
-				log_sys.log.read(max_cp_field,
+			switch (max_cp_field) {
+			case LOG_CHECKPOINT_1:
+				if (log_sys.log.read(max_cp_field,
 						     {log_sys.checkpoint_buf,
-						  OS_FILE_LOG_BLOCK_SIZE});
+						     OS_FILE_LOG_BLOCK_SIZE}))
+				{
+					/* metadata_to_lsn still 0 so error returns below */
+					msg("Error: recv_find_max_checkpoint() failed.");
+					break;
 				}
+				/* fallthrough */
+			default:
 				metadata_to_lsn = mach_read_from_8(
 					log_sys.checkpoint_buf + LOG_CHECKPOINT_LSN);
 				msg("mariabackup: The latest check point"
 				    " (for incremental): '" LSN_PF "'",
 				    metadata_to_lsn);
+			}
 		} else {
 			msg("Error: recv_find_max_checkpoint() failed.");
 		}
@@ -4661,14 +4669,14 @@ static bool xtrabackup_backup_func()
 		checkpoint_lsn_start = log_sys.log.get_lsn();
 		checkpoint_no_start = log_sys.next_checkpoint_no;
 
-		log_sys.log.read(max_cp_field, {buf, OS_FILE_LOG_BLOCK_SIZE});
+		err = log_sys.log.read(max_cp_field, {buf, OS_FILE_LOG_BLOCK_SIZE});
 
-		if (checkpoint_no_start
+		if (err == DB_SUCCESS && (checkpoint_no_start
 		    != mach_read_from_8(buf + LOG_CHECKPOINT_NO)
 		    || checkpoint_lsn_start
 		    != mach_read_from_8(buf + LOG_CHECKPOINT_LSN)
 		    || log_sys.log.get_lsn_offset()
-		    != mach_read_from_8(buf + LOG_CHECKPOINT_OFFSET))
+		    != mach_read_from_8(buf + LOG_CHECKPOINT_OFFSET)))
 			goto reread_log_header;
 	}
 	mysql_mutex_unlock(&log_sys.mutex);

mysql-test/suite/mariabackup/data_directory.result

@@ -11,3 +11,9 @@ SELECT * FROM t;
 a
 1
 DROP TABLE t;
+#
+# MDEV-18200 MariaBackup full backup failed with InnoDB: Failing assertion: success
+#
+#
+# End of 10.4 tests
+#

mysql-test/suite/mariabackup/data_directory.test

@@ -21,4 +21,19 @@ rmdir $table_data_dir;
 SELECT * FROM t;
 DROP TABLE t;
 rmdir $targetdir;
+
+--echo #
+--echo # MDEV-18200 MariaBackup full backup failed with InnoDB: Failing assertion: success
+--echo #
+let $DATADIR= `select @@datadir`;
+chmod 0000 $DATADIR/ibdata1;
+--disable_result_log
+--error 1
+exec $XTRABACKUP --defaults-file=$MYSQLTEST_VARDIR/my.cnf --backup --target-dir=$targetdir;
+--enable_result_log
+chmod 0755 $DATADIR/ibdata1;
 rmdir $table_data_dir;
+rmdir $targetdir;
+--echo #
+--echo # End of 10.4 tests
+--echo #

storage/innobase/fil/fil0fil.cc

@@ -363,6 +363,7 @@ fil_node_t* fil_space_t::add(const char* name, pfs_os_file_t handle,
 	return node;
 }
 
+__attribute__((warn_unused_result, nonnull))
 /** Open a tablespace file.
 @param node  data file
 @return whether the file was successfully opened */
@@ -391,9 +392,9 @@ static bool fil_node_open_file_low(fil_node_t *node)
                                  : OS_FILE_OPEN | OS_FILE_ON_ERROR_NO_EXIT,
                                  OS_FILE_AIO, type,
                                  srv_read_only_mode, &success);
-    if (node->is_open())
+
+    if (success && node->is_open())
     {
-      ut_ad(success);
 #ifndef _WIN32
       if (!node->space->id && !srv_read_only_mode && my_disable_locking &&
           os_file_lock(node->handle, node->name))

storage/innobase/include/log0log.h

@@ -506,7 +506,8 @@ struct log_t{
     /** reads buffer from log file
     @param[in]	offset		offset in log file
     @param[in]	buf		buffer where to read */
-    void read(os_offset_t offset, span<byte> buf);
+    dberr_t MY_ATTRIBUTE((warn_unused_result)) read(os_offset_t offset,
+                                                    span<byte> buf);
     /** Tells whether writes require calling flush() */
     bool writes_are_durable() const noexcept;
     /** writes buffer to log file

storage/innobase/include/log0recv.h

@@ -283,7 +283,8 @@ struct recv_sys_t
   /** Last added LSN to pages. */
   lsn_t last_stored_lsn= 0;
 
-  void read(os_offset_t offset, span<byte> buf);
+  __attribute__((warn_unused_result))
+  dberr_t read(os_offset_t offset, span<byte> buf);
   inline size_t files_size();
   void close_files() { files.clear(); files.shrink_to_fit(); }
 

storage/innobase/log/log0log.cc

@@ -280,6 +280,7 @@ dberr_t file_os_io::close() noexcept
   return DB_SUCCESS;
 }
 
+__attribute__((warn_unused_result))
 dberr_t file_os_io::read(os_offset_t offset, span<byte> buf) noexcept
 {
   return os_file_read(IORequestRead, m_fd, buf.data(), offset, buf.size());
@@ -382,6 +383,7 @@ class file_pmem_io final : public file_io
                                                                    : DB_ERROR;
   }
   dberr_t close() noexcept final { return m_file.unmap(); }
+  __attribute__((warn_unused_result))
   dberr_t read(os_offset_t offset, span<byte> buf) noexcept final
   {
     memcpy(buf.data(), m_file.data() + offset, buf.size());
@@ -448,6 +450,8 @@ dberr_t log_file_t::close() noexcept
   return DB_SUCCESS;
 }
 
+
+__attribute__((warn_unused_result))
 dberr_t log_file_t::read(os_offset_t offset, span<byte> buf) noexcept
 {
   ut_ad(is_opened());
@@ -510,10 +514,10 @@ void log_t::file::write_header_durable(lsn_t lsn)
     log_sys.log.flush();
 }
 
-void log_t::file::read(os_offset_t offset, span<byte> buf)
+__attribute__((warn_unused_result))
+dberr_t log_t::file::read(os_offset_t offset, span<byte> buf)
 {
-  if (const dberr_t err= fd.read(offset, buf))
-    ib::fatal() << "read(" << fd.get_path() << ") returned "<< err;
+  return fd.read(offset, buf);
 }
 
 bool log_t::file::writes_are_durable() const noexcept

storage/innobase/log/log0recv.cc

@@ -762,14 +762,15 @@ void recv_sys_t::open_log_files_if_needed()
   }
 }
 
-void recv_sys_t::read(os_offset_t total_offset, span<byte> buf)
+MY_ATTRIBUTE((warn_unused_result))
+dberr_t
+recv_sys_t::read(os_offset_t total_offset, span<byte> buf)
 {
   open_log_files_if_needed();
 
   size_t file_idx= static_cast<size_t>(total_offset / log_sys.log.file_size);
   os_offset_t offset= total_offset % log_sys.log.file_size;
-  dberr_t err= recv_sys.files[file_idx].read(offset, buf);
-  ut_a(err == DB_SUCCESS);
+  return recv_sys.files[file_idx].read(offset, buf);
 }
 
 inline size_t recv_sys_t::files_size()
@@ -1107,7 +1108,8 @@ bool log_t::file::read_log_seg(lsn_t* start_lsn, lsn_t end_lsn)
 
 	ut_a((source_offset >> srv_page_size_shift) <= ULINT_MAX);
 
-	recv_sys.read(source_offset, {buf, len});
+	if (recv_sys.read(source_offset, {buf, len}))
+		return false;
 
 	for (ulint l = 0; l < len; l += OS_FILE_LOG_BLOCK_SIZE,
 		     buf += OS_FILE_LOG_BLOCK_SIZE,
@@ -1272,6 +1274,7 @@ inline uint32_t log_block_calc_checksum_format_0(const byte *b)
 ATTRIBUTE_COLD static dberr_t recv_log_recover_pre_10_2()
 {
   uint64_t max_no= 0;
+  dberr_t err;
   byte *buf= log_sys.buf;
 
   ut_ad(log_sys.log.format == 0);
@@ -1295,7 +1298,8 @@ ATTRIBUTE_COLD static dberr_t recv_log_recover_pre_10_2()
   for (ulint field= LOG_CHECKPOINT_1; field <= LOG_CHECKPOINT_2;
        field += LOG_CHECKPOINT_2 - LOG_CHECKPOINT_1)
   {
-    log_sys.log.read(field, {buf, OS_FILE_LOG_BLOCK_SIZE});
+    if ((err= log_sys.log.read(field, {buf, OS_FILE_LOG_BLOCK_SIZE})))
+      return err;
 
     if (static_cast<uint32_t>(ut_fold_binary(buf, CHECKSUM_1)) !=
         mach_read_from_4(buf + CHECKSUM_1) ||
@@ -1347,7 +1351,8 @@ ATTRIBUTE_COLD static dberr_t recv_log_recover_pre_10_2()
     "InnoDB: Upgrade after a crash is not supported."
     " This redo log was created before MariaDB 10.2.2";
 
-  recv_sys.read(source_offset & ~511, {buf, 512});
+  if ((err= recv_sys.read(source_offset & ~511, {buf, 512})))
+    return err;
 
   if (log_block_calc_checksum_format_0(buf) != log_block_get_checksum(buf) &&
       !log_crypt_101_read_block(buf, lsn))
@@ -1414,8 +1419,9 @@ static dberr_t recv_log_recover_10_4()
 		return DB_CORRUPTION;
 	}
 
-	recv_sys.read(source_offset & ~lsn_t(OS_FILE_LOG_BLOCK_SIZE - 1),
-		      {buf, OS_FILE_LOG_BLOCK_SIZE});
+	if (dberr_t err= recv_sys.read(source_offset & ~lsn_t(OS_FILE_LOG_BLOCK_SIZE - 1),
+		      {buf, OS_FILE_LOG_BLOCK_SIZE}))
+		return err;
 
 	ulint crc = log_block_calc_checksum_crc32(buf);
 	ulint cksum = log_block_get_checksum(buf);
@@ -1473,7 +1479,8 @@ recv_find_max_checkpoint(ulint* max_field)
 
 	buf = log_sys.checkpoint_buf;
 
-	log_sys.log.read(0, {buf, OS_FILE_LOG_BLOCK_SIZE});
+	if (dberr_t err= log_sys.log.read(0, {buf, OS_FILE_LOG_BLOCK_SIZE}))
+		return err;
 	/* Check the header page checksum. There was no
 	checksum in the first redo log format (version 0). */
 	log_sys.log.format = mach_read_from_4(buf + LOG_HEADER_FORMAT);
@@ -1512,7 +1519,8 @@ recv_find_max_checkpoint(ulint* max_field)
 
 	for (field = LOG_CHECKPOINT_1; field <= LOG_CHECKPOINT_2;
 	     field += LOG_CHECKPOINT_2 - LOG_CHECKPOINT_1) {
-		log_sys.log.read(field, {buf, OS_FILE_LOG_BLOCK_SIZE});
+		if (dberr_t err= log_sys.log.read(field, {buf, OS_FILE_LOG_BLOCK_SIZE}))
+			return err;
 
 		const ulint crc32 = log_block_calc_checksum_crc32(buf);
 		const ulint cksum = log_block_get_checksum(buf);
@@ -3452,7 +3460,10 @@ recv_recovery_from_checkpoint_start(lsn_t flush_lsn)
 	}
 
 	buf = log_sys.checkpoint_buf;
-	log_sys.log.read(max_cp_field, {buf, OS_FILE_LOG_BLOCK_SIZE});
+	if ((err= log_sys.log.read(max_cp_field, {buf, OS_FILE_LOG_BLOCK_SIZE}))) {
+		mysql_mutex_unlock(&log_sys.mutex);
+		return(err);
+	}
 
 	checkpoint_lsn = mach_read_from_8(buf + LOG_CHECKPOINT_LSN);
 	checkpoint_no = mach_read_from_8(buf + LOG_CHECKPOINT_NO);