[Issue #169] Calculate appoximate efficiency ratio when restoring backup

Author: gsmolk

src/data.c

@@ -966,10 +966,11 @@ restore_data_file(const char *to_path, pgFile *file, bool allow_truncate,
  * filelist of every chain member starting with FULL backup.
  * Apply changed blocks to destination file from every backup in parent chain.
  */
-void
+size_t
 restore_data_file_new(parray *parent_chain, pgFile *dest_file, FILE *out, const char *to_fullpath)
 {
 	int i;
+	size_t total_write_len = 0;
 
 	for (i = parray_num(parent_chain) - 1; i >= 0; i--)
 	{
@@ -1013,29 +1014,27 @@ restore_data_file_new(parray *parent_chain, pgFile *dest_file, FILE *out, const
 
 		in = fopen(from_fullpath, PG_BINARY_R);
 		if (in == NULL)
-		{
 			elog(INFO, "Cannot open backup file \"%s\": %s", from_fullpath,
 				 strerror(errno));
-			Assert(0);
-		}
 
 		/*
-		 * restore the file.
+		 * Restore the file.
 		 * Datafiles are backed up block by block and every block
 		 * have BackupPageHeader with meta information, so we cannot just
 		 * copy the file from backup.
 		 */
-		restore_data_file_internal(in, out, tmp_file,
+		total_write_len += restore_data_file_internal(in, out, tmp_file,
 					  parse_program_version(backup->program_version),
 					  from_fullpath, to_fullpath, dest_file->n_blocks);
 
-		if (fio_fclose(in) != 0)
+		if (fclose(in) != 0)
 			elog(ERROR, "Cannot close file \"%s\": %s", from_fullpath,
 				strerror(errno));
 	}
+	return total_write_len;
 }
 
-void
+size_t
 restore_data_file_internal(FILE *in, FILE *out, pgFile *file, uint32 backup_version,
 					  const char *from_fullpath, const char *to_fullpath, int nblocks)
 {
@@ -1067,7 +1066,7 @@ restore_data_file_internal(FILE *in, FILE *out, pgFile *file, uint32 backup_vers
 					 blknum, from_fullpath, strerror(errno_tmp));
 		}
 
-		/* Consider empty block */
+		/* Consider empty blockm. wtf empty block ? */
 		if (header.block == 0 && header.compressed_size == 0)
 		{
 			elog(VERBOSE, "Skip empty block of \"%s\"", from_fullpath);
@@ -1187,6 +1186,7 @@ restore_data_file_internal(FILE *in, FILE *out, pgFile *file, uint32 backup_vers
 	}
 
 	elog(VERBOSE, "Copied file \"%s\": %lu bytes", from_fullpath, write_len);
+	return write_len;
 }
 
 /*
@@ -1247,7 +1247,7 @@ restore_non_data_file_internal(FILE *in, FILE *out, pgFile *file,
 	elog(VERBOSE, "Copied file \"%s\": %lu bytes", from_fullpath, file->write_size);
 }
 
-void
+size_t
 restore_non_data_file(parray *parent_chain, pgBackup *dest_backup,
 					  pgFile *dest_file, FILE *out, const char *to_fullpath)
 {
@@ -1297,7 +1297,7 @@ restore_non_data_file(parray *parent_chain, pgBackup *dest_backup,
 
 			/* Full copy is found and it is null sized, nothing to do here */
 			if (tmp_file->write_size == 0)
-				return;
+				return 0;
 
 			/* Full copy is found */
 			if (tmp_file->write_size > 0)
@@ -1314,11 +1314,9 @@ restore_non_data_file(parray *parent_chain, pgBackup *dest_backup,
 		elog(ERROR, "Failed to locate a full copy of non-data file \"%s\"", to_fullpath);
 
 	if (tmp_file->external_dir_num == 0)
-//		pgBackupGetPath(tmp_backup, from_root, lengthof(from_root), DATABASE_DIR);
 		join_path_components(from_root, tmp_backup->root_dir, DATABASE_DIR);
 	else
 	{
-		// get external prefix for tmp_backup
 		char		external_prefix[MAXPGPATH];
 
 		join_path_components(external_prefix, tmp_backup->root_dir, EXTERNAL_DIR);
@@ -1329,16 +1327,17 @@ restore_non_data_file(parray *parent_chain, pgBackup *dest_backup,
 
 	in = fopen(from_fullpath, PG_BINARY_R);
 	if (in == NULL)
-	{
 		elog(ERROR, "Cannot open backup file \"%s\": %s", from_fullpath,
 			 strerror(errno));
-	}
 
+	/* do actual work */
 	restore_non_data_file_internal(in, out, tmp_file, from_fullpath, to_fullpath);
 
-	if (fio_fclose(in) != 0)
+	if (fclose(in) != 0)
 		elog(ERROR, "Cannot close file \"%s\": %s", from_fullpath,
 			strerror(errno));
+
+	return tmp_file->write_size;
 }
 
 /*

src/pg_probackup.h

@@ -840,11 +840,11 @@ extern void restore_data_file(const char *to_path,
 							  pgFile *file, bool allow_truncate,
 							  bool write_header,
 							  uint32 backup_version);
-extern void restore_data_file_new(parray *parent_chain, pgFile *dest_file,
+extern size_t restore_data_file_new(parray *parent_chain, pgFile *dest_file,
 								  FILE *out, const char *to_fullpath);
-extern void restore_data_file_internal(FILE *in, FILE *out, pgFile *file, uint32 backup_version,
+extern size_t restore_data_file_internal(FILE *in, FILE *out, pgFile *file, uint32 backup_version,
 								  const char *from_fullpath, const char *to_fullpath, int nblocks);
-extern void restore_non_data_file(parray *parent_chain, pgBackup *dest_backup,
+extern size_t restore_non_data_file(parray *parent_chain, pgBackup *dest_backup,
 								  pgFile *dest_file, FILE *out, const char *to_fullpath);
 extern void restore_non_data_file_internal(FILE *in, FILE *out, pgFile *file,
 										   const char *from_fullpath, const char *to_fullpath);

src/restore.c

@@ -44,6 +44,7 @@ typedef struct
 	parray	   *dbOid_exclude_list;
 	bool		skip_external_dirs;
 	const char *to_root;
+	size_t		restored_bytes;
 
 	/*
 	 * Return value from the thread.
@@ -524,6 +525,11 @@ restore_chain(pgBackup *dest_backup, parray *parent_chain,
 	restore_files_arg_new *threads_args;
 	bool		restore_isok = true;
 
+	/* fancy reporting */
+	char		pretty_dest_bytes[20];
+	char		pretty_total_bytes[20];
+	size_t		dest_bytes = 0;
+	size_t		total_bytes = 0;
 	char		pretty_time[20];
 	time_t		start_time, end_time;
 
@@ -608,6 +614,9 @@ restore_chain(pgBackup *dest_backup, parray *parent_chain,
 	{
 		pgFile	   *file = (pgFile *) parray_get(dest_files, i);
 
+		if (S_ISDIR(file->mode))
+			total_bytes += 4096;
+
 		if (!params->skip_external_dirs &&
 			file->external_dir_num && S_ISDIR(file->mode))
 		{
@@ -639,9 +648,15 @@ restore_chain(pgBackup *dest_backup, parray *parent_chain,
 												num_threads);
 
 	/* Restore files into target directory */
-	thread_interrupted = false;
-	elog(INFO, "Start restoring backup files");
+	if (dest_backup->stream)
+		dest_bytes = dest_backup->pgdata_bytes + dest_backup->wal_bytes;
+	else
+		dest_bytes = dest_backup->pgdata_bytes;
+
+	pretty_size(dest_bytes, pretty_dest_bytes, lengthof(pretty_dest_bytes));
+	elog(INFO, "Start restoring backup files. PGDATA size: %s", pretty_dest_bytes);
 	time(&start_time);
+	thread_interrupted = false;
 	for (i = 0; i < num_threads; i++)
 	{
 		restore_files_arg_new *arg = &(threads_args[i]);
@@ -653,6 +668,7 @@ restore_chain(pgBackup *dest_backup, parray *parent_chain,
 		arg->dbOid_exclude_list = dbOid_exclude_list;
 		arg->skip_external_dirs = params->skip_external_dirs;
 		arg->to_root = pgdata_path;
+		threads_args[i].restored_bytes = 0;
 		/* By default there are some error */
 		threads_args[i].ret = 1;
 
@@ -668,15 +684,27 @@ restore_chain(pgBackup *dest_backup, parray *parent_chain,
 		pthread_join(threads[i], NULL);
 		if (threads_args[i].ret == 1)
 			restore_isok = false;
+
+		total_bytes += threads_args[i].restored_bytes;
 	}
 
 	time(&end_time);
 	pretty_time_interval(difftime(end_time, start_time),
 						 pretty_time, lengthof(pretty_time));
+	pretty_size(total_bytes, pretty_total_bytes, lengthof(pretty_total_bytes));
+
 	if (restore_isok)
-		elog(INFO, "Backup files are restored, time elapsed: %s", pretty_time);
+	{
+		elog(INFO, "Backup files are restored. Transfered bytes: %s, time elapsed: %s",
+			pretty_total_bytes, pretty_time);
+
+		elog(INFO, "Approximate restore efficiency ratio: %.f%% (%s/%s)",
+			((float) dest_bytes / total_bytes) * 100,
+			pretty_dest_bytes, pretty_total_bytes);
+	}
 	else
-		elog(ERROR, "Backup files restoring failed, time elapsed: %s", pretty_time);
+		elog(ERROR, "Backup files restoring failed. Transfered bytes: %s, time elapsed: %s",
+			pretty_total_bytes, pretty_time);
 
 	if (no_sync)
 		elog(WARNING, "Restored files are not synced to disk");
@@ -841,11 +869,12 @@ restore_files_new(void *arg)
 		/* Restore destination file */
 		if (dest_file->is_datafile && !dest_file->is_cfs)
 			/* Destination file is data file */
-			restore_data_file_new(arguments->parent_chain, dest_file, out, to_fullpath);
+			arguments->restored_bytes += restore_data_file_new(arguments->parent_chain,
+																dest_file, out, to_fullpath);
 		else
 			/* Destination file is non-data file */
-			restore_non_data_file(arguments->parent_chain, arguments->dest_backup,
-				dest_file, out, to_fullpath);
+			arguments->restored_bytes += restore_non_data_file(arguments->parent_chain,
+										arguments->dest_backup, dest_file, out, to_fullpath);
 
 		/*
 		 * Destination file is data file.
@@ -875,11 +904,6 @@ restore_files_new(void *arg)
 		if (fio_fclose(out) != 0)
 			elog(ERROR, "Cannot close file \"%s\": %s", to_fullpath,
 				 strerror(errno));
-
-		/* print size of restored file */
-//		if (file->write_size != BYTES_INVALID)
-//			elog(VERBOSE, "Restored file %s : " INT64_FORMAT " bytes",
-//				 file->path, file->write_size);
 	}
 
 	/* Data files restoring is successful */