Log the path, name and size of files being restored at TRACE level for

users wanting more detailed restore output.

Disable printing dots when logging at TRACE level is enabled.

Warn rather than failing to restore when the file attributes could not
be restored. (merges [2745], [2827]).

6 files changed, 60 insertions, 23 deletions

diff --git a/bin/bbackupquery/BackupQueries.cpp b/bin/bbackupquery/BackupQueries.cpp
index 8bed080f..bed28367 100644
--- a/bin/bbackupquery/BackupQueries.cpp
+++ b/bin/bbackupquery/BackupQueries.cpp
@@ -2368,6 +2368,8 @@ void BackupQueries::CommandRestore(const std::vector<std::string> &args, const b
 	// Restoring deleted things?
 	bool restoreDeleted = opts['d'];
 
+	std::string storeDirEncoded;
+
 	// Get directory ID
 	int64_t dirID = 0;
 	if(opts['i'])
@@ -2379,15 +2381,17 @@ void BackupQueries::CommandRestore(const std::vector<std::string> &args, const b
 			BOX_ERROR("Not a valid object ID (specified in hex)");
 			return;
 		}
+		std::ostringstream oss;
+		oss << BOX_FORMAT_OBJECTID(args[0]);
+		storeDirEncoded = oss.str();
 	}
 	else
 	{
 #ifdef WIN32
-		std::string storeDirEncoded;
 		if(!ConvertConsoleToUtf8(args[0].c_str(), storeDirEncoded))
 			return;
 #else
-		const std::string& storeDirEncoded(args[0]);
+		storeDirEncoded = args[0];
 #endif
 	
 		// Look up directory ID
@@ -2432,9 +2436,14 @@ void BackupQueries::CommandRestore(const std::vector<std::string> &args, const b
 
 	try
 	{
+		// At TRACE level, we print a line for each file and
+		// directory, so we don't need dots.
+
+		bool printDots = ! Logging::IsEnabled(Log::TRACE);
+
 		result = BackupClientRestore(mrConnection, dirID, 
-			localName.c_str(), 
-			true /* print progress dots */, restoreDeleted, 
+			storeDirEncoded.c_str(), localName.c_str(), 
+			printDots /* print progress dots */, restoreDeleted, 
 			false /* don't undelete after restore! */, 
 			opts['r'] /* resume? */,
 			opts['f'] /* force continue after errors */);
diff --git a/lib/backupclient/BackupClientFileAttributes.cpp b/lib/backupclient/BackupClientFileAttributes.cpp
index af156a1d..b25ed9c7 100644
--- a/lib/backupclient/BackupClientFileAttributes.cpp
+++ b/lib/backupclient/BackupClientFileAttributes.cpp
@@ -843,9 +843,10 @@ void BackupClientFileAttributes::WriteAttributes(const char *Filename,
 		// Try to apply
 		if(::utimes(Filename, times) != 0)
 		{
-			BOX_LOG_SYS_ERROR("Failed to change times of "
-				"file '" << Filename << "'");
-			THROW_EXCEPTION(CommonException, OSFileError)
+			BOX_LOG_SYS_WARNING("Failed to change times of "
+				"file '" << Filename << "' to ctime=" <<
+				BOX_FORMAT_TIMESPEC(times[0]) << ", mtime=" << 
+				BOX_FORMAT_TIMESPEC(times[1]));
 		}
 	}
 
diff --git a/lib/backupclient/BackupClientRestore.cpp b/lib/backupclient/BackupClientRestore.cpp
index b1c5cd0f..fa61bb59 100644
--- a/lib/backupclient/BackupClientRestore.cpp
+++ b/lib/backupclient/BackupClientRestore.cpp
@@ -211,7 +211,8 @@ typedef struct
 //
 // --------------------------------------------------------------------------
 static int BackupClientRestoreDir(BackupProtocolClient &rConnection,
-	int64_t DirectoryID, std::string &rLocalDirectoryName,
+	int64_t DirectoryID, const std::string &rRemoteDirectoryName,
+	const std::string &rLocalDirectoryName,
 	RestoreParams &Params, RestoreResumeInfo &rLevel)
 {
 	// If we're resuming... check that we haven't got a next level to
@@ -223,7 +224,9 @@ static int BackupClientRestoreDir(BackupProtocolClient &rConnection,
 			DIRECTORY_SEPARATOR_ASCHAR + 
 			rLevel.mNextLevelLocalName);
 		BackupClientRestoreDir(rConnection, rLevel.mNextLevelID,
-			localDirname, Params, *rLevel.mpNextLevel);
+			rRemoteDirectoryName + '/' + 
+			rLevel.mNextLevelLocalName, localDirname,
+			Params, *rLevel.mpNextLevel);
 		
 		// Add it to the list of done itmes
 		rLevel.mRestoredObjects.insert(rLevel.mNextLevelID);
@@ -526,6 +529,11 @@ static int BackupClientRestoreDir(BackupProtocolClient &rConnection,
 					}
 				}
 				
+				BOX_TRACE("Restoring file: " <<
+					rRemoteDirectoryName + '/' + 
+					nm.GetClearFilename() << " (" <<
+					en->GetSizeInBlocks() << " blocks)");
+
 				// Request it from the store
 				rConnection.QueryGetFile(DirectoryID,
 					en->GetObjectID());
@@ -739,9 +747,16 @@ static int BackupClientRestoreDir(BackupProtocolClient &rConnection,
 						nm.GetClearFilename()));
 				
 				// Recurse
+
+				BOX_TRACE("Entering directory: " <<
+					rRemoteDirectoryName + '/' + 
+					nm.GetClearFilename());
+
 				int result = BackupClientRestoreDir(
 					rConnection, en->GetObjectID(), 
-					localDirname, Params, rnextLevel);
+					rRemoteDirectoryName + '/' + 
+					nm.GetClearFilename(), localDirname,
+					Params, rnextLevel);
 
 				if (result != Restore_Complete)
 				{
@@ -824,8 +839,8 @@ static int BackupClientRestoreDir(BackupProtocolClient &rConnection,
 //
 // --------------------------------------------------------------------------
 int BackupClientRestore(BackupProtocolClient &rConnection,
-	int64_t DirectoryID, const char *LocalDirectoryName,
-	bool PrintDots, bool RestoreDeleted,
+	int64_t DirectoryID, const char *RemoteDirectoryName,
+	const char *LocalDirectoryName, bool PrintDots, bool RestoreDeleted,
 	bool UndeleteAfterRestoreDeleted, bool Resume,
 	bool ContinueAfterErrors)
 {
@@ -872,9 +887,9 @@ int BackupClientRestore(BackupProtocolClient &rConnection,
 	}
 	
 	// Restore the directory
-	std::string localName(LocalDirectoryName);
 	int result = BackupClientRestoreDir(rConnection, DirectoryID, 
-		localName, params, params.mResumeInfo);
+		RemoteDirectoryName, LocalDirectoryName, params,
+		params.mResumeInfo);
 	if (result != Restore_Complete)
 	{
 		return result;
diff --git a/lib/backupclient/BackupClientRestore.h b/lib/backupclient/BackupClientRestore.h
index 7e492238..311a15bd 100644
--- a/lib/backupclient/BackupClientRestore.h
+++ b/lib/backupclient/BackupClientRestore.h
@@ -24,6 +24,7 @@ enum
 
 int BackupClientRestore(BackupProtocolClient &rConnection,
 	int64_t DirectoryID,
+	const char *RemoteDirectoryName,
 	const char *LocalDirectoryName,
 	bool PrintDots = false,
 	bool RestoreDeleted = false,
diff --git a/lib/backupclient/BackupStoreFile.cpp b/lib/backupclient/BackupStoreFile.cpp
index 44d96d0c..bd62b7ba 100644
--- a/lib/backupclient/BackupStoreFile.cpp
+++ b/lib/backupclient/BackupStoreFile.cpp
@@ -314,7 +314,15 @@ void BackupStoreFile::DecodeFile(IOStream &rEncodedFile, const char *DecodedFile
 		// ASSERT(drained == 0);
 		
 		// Write the attributes
-		stream->GetAttributes().WriteAttributes(DecodedFilename);
+		try
+		{
+			stream->GetAttributes().WriteAttributes(DecodedFilename);
+		}
+		catch (std::exception& e)
+		{
+			BOX_WARNING("Failed to restore attributes on " <<
+				DecodedFilename << ": " << e.what());
+		}
 	}
 	catch(...)
 	{
diff --git a/test/bbackupd/testbbackupd.cpp b/test/bbackupd/testbbackupd.cpp
index 2452c8c0..b82e83e3 100644
--- a/test/bbackupd/testbbackupd.cpp
+++ b/test/bbackupd/testbbackupd.cpp
@@ -521,7 +521,10 @@ void do_interrupted_restore(const TLSContext &context, int64_t restoredirid)
 			std::auto_ptr<BackupProtocolClientLoginConfirmed> loginConf(protocol.QueryLogin(0x01234567, BackupProtocolClientLogin::Flags_ReadOnly));
 			
 			// Test the restoration
-			TEST_THAT(BackupClientRestore(protocol, restoredirid, "testfiles/restore-interrupt", true /* print progress dots */) == Restore_Complete);
+			TEST_THAT(BackupClientRestore(protocol, restoredirid,
+				"Test1", "testfiles/restore-interrupt",
+				true /* print progress dots */)
+				== Restore_Complete);
 
 			// Log out
 			protocol.QueryFinished();
@@ -3431,7 +3434,7 @@ int test_bbackupd()
 
 			// Test the restoration
 			TEST_THAT(BackupClientRestore(*client, restoredirid, 
-				"testfiles/restore-Test1", 
+				"Test1", "testfiles/restore-Test1", 
 				true /* print progress dots */) 
 				== Restore_Complete);
 
@@ -3440,7 +3443,7 @@ int test_bbackupd()
 
 			// Make sure you can't restore a restored directory
 			TEST_THAT(BackupClientRestore(*client, restoredirid, 
-				"testfiles/restore-Test1", 
+				"Test1", "testfiles/restore-Test1", 
 				true /* print progress dots */) 
 				== Restore_TargetExists);
 			
@@ -3451,7 +3454,7 @@ int test_bbackupd()
 			// Just check it doesn't bomb out -- will check this 
 			// properly later (when bbackupd is stopped)
 			TEST_THAT(BackupClientRestore(*client, deldirid, 
-				"testfiles/restore-Test1-x1", 
+				"Test1", "testfiles/restore-Test1-x1", 
 				true /* print progress dots */, 
 				true /* deleted files */) 
 				== Restore_Complete);
@@ -3464,7 +3467,7 @@ int test_bbackupd()
 			{
 				Logging::Guard guard(Log::FATAL);
 				TEST_THAT(BackupClientRestore(*client,
-					restoredirid, 
+					restoredirid, "Test1",
 					"testfiles/no-such-path/subdir", 
 					true /* print progress dots */) 
 					== Restore_TargetPathNotFound);
@@ -3812,13 +3815,13 @@ int test_bbackupd()
 			// Check that the restore fn returns resume possible,
 			// rather than doing anything
 			TEST_THAT(BackupClientRestore(*client, restoredirid, 
-				"testfiles/restore-interrupt", 
+				"Test1", "testfiles/restore-interrupt", 
 				true /* print progress dots */) 
 				== Restore_ResumePossible);
 
 			// Then resume it
 			TEST_THAT(BackupClientRestore(*client, restoredirid, 
-				"testfiles/restore-interrupt", 
+				"Test1", "testfiles/restore-interrupt", 
 				true /* print progress dots */, 
 				false /* deleted files */, 
 				false /* undelete server */, 
@@ -3853,7 +3856,7 @@ int test_bbackupd()
 
 			// Do restore and undelete
 			TEST_THAT(BackupClientRestore(*client, deldirid, 
-				"testfiles/restore-Test1-x1-2", 
+				"Test1", "testfiles/restore-Test1-x1-2", 
 				true /* print progress dots */, 
 				true /* deleted files */, 
 				true /* undelete on server */)