Logging fixes and cleanups around folder move

Common/File/AndroidStorage.cpp

@@ -4,6 +4,7 @@
 #include "Common/StringUtils.h"
 #include "Common/Log.h"
 #include "Common/TimeUtil.h"
+#include "Common/System/System.h"
 
 #include "android/jni/app-android.h"
 #include "Common/Thread/ThreadUtil.h"
@@ -277,12 +278,18 @@ int64_t Android_GetFreeSpaceByContentUri(const std::string &uri) {
 	return env->CallLongMethod(g_nativeActivity, contentUriGetFreeStorageSpace, param);
 }
 
+// Hm, this is never used? We use statvfs instead.
 int64_t Android_GetFreeSpaceByFilePath(const std::string &filePath) {
 	if (!g_nativeActivity) {
 		return false;
 	}
 	auto env = getEnv();
 
+	if (System_GetPropertyInt(SYSPROP_SYSTEMVERSION) < 26) {
+		// This is available from Android O.
+		return -1;
+	}
+
 	jstring param = env->NewStringUTF(filePath.c_str());
 	return env->CallLongMethod(g_nativeActivity, filePathGetFreeStorageSpace, param);
 }

Common/File/Path.cpp

@@ -267,7 +267,7 @@ bool Path::StartsWithGlobalAndNotEqual(const Path &other) const {
 		if (aLast == bLast) {
 			return false;
 		}
-		return startsWith(aLast, bLast);
+		return CountChar(aLast, '/') != CountChar(bLast, '/') && startsWith(aLast, bLast);
 	}
 	return *this != other && StartsWith(other);
 }

Common/StringUtils.h

@@ -106,7 +106,7 @@ std::string_view StripQuotes(std::string_view s);
 
 std::string_view StripPrefix(std::string_view prefix, std::string_view s);
 
-int countChar(std::string_view haystack, char needle);
+int CountChar(std::string_view haystack, char needle);
 
 // NOTE: str must live at least as long as all uses of output.
 void SplitString(std::string_view str, const char delim, std::vector<std::string_view> &output);

Common/TimeUtil.h

@@ -40,6 +40,7 @@ public:
 		return Instant();
 	}
 	double ElapsedSeconds() const;
+	double ElapsedMs() const { return ElapsedSeconds() * 1000.0; }
 	int64_t ElapsedNanos() const;
 private:
 	Instant();

Core/Util/MemStick.cpp

@@ -4,7 +4,9 @@
 #include "Common/File/Path.h"
 #include "Common/File/FileUtil.h"
 #include "Common/File/DirListing.h"
+#include "Common/System/System.h"
 #include "Common/Log.h"
+#include "Common/TimeUtil.h"
 #include "Common/StringUtils.h"
 #include "Common/Data/Text/I18n.h"
 #include "Common/Data/Text/Parsers.h"
@@ -115,13 +117,15 @@ bool MoveChildrenFast(const Path &moveSrc, const Path &moveDest, MoveProgressRep
 		Path fileSrc = file.fullName;
 		Path fileDest = moveDest / file.name;
 		progressReporter.SetProgress(file.name, i, files.size());
-		INFO_LOG(Log::System, "About to move PSP data from '%s' to '%s'", fileSrc.c_str(), fileDest.c_str());
+		INFO_LOG(Log::System, "Fast-moving PSP data from '%s' to '%s' (%d/%d)", fileSrc.c_str(), fileDest.c_str(), (int)i + 1, (int)files.size());
 		bool result = File::MoveIfFast(fileSrc, fileDest);
 		if (!result) {
 			// TODO: Should we try to move back anything that succeeded before this one?
+			INFO_LOG(Log::System, "Failed to fast-move '%s' to '%s'", fileSrc.c_str(), fileDest.c_str());
 			return false;
 		}
 	}
+	INFO_LOG(Log::System, "Done with fast-move.");
 	return true;
 }
 
@@ -130,16 +134,15 @@ std::string MoveProgressReporter::Format() {
 	{
 		std::lock_guard<std::mutex> guard(mutex_);
 		if (max_ > 0) {
-			str = StringFromFormat("(%d/%d) ", count_, max_);
+			str = StringFromFormat("(%d/%d) ", count_ + 1, max_);
 		} else if (max_ < 0) {
-			str = StringFromFormat("(%d) ", count_);
+			str = StringFromFormat("(%d/?) ", count_ + 1);
 		}
 		str += progress_;
 	}
 	return str;
 }
 
-
 MoveResult *MoveDirectoryContentsSafe(Path moveSrc, Path moveDest, MoveProgressReporter &progressReporter) {
 	auto ms = GetI18NCategory(I18NCat::MEMSTICK);
 	if (moveSrc.GetFilename() != "PSP") {
@@ -152,14 +155,16 @@ MoveResult *MoveDirectoryContentsSafe(Path moveSrc, Path moveDest, MoveProgressR
 
 	INFO_LOG(Log::System, "About to move PSP data from '%s' to '%s'", moveSrc.c_str(), moveDest.c_str());
 
+	Instant moveStart = Instant::Now();
+
 	// First, we try the cheapest and safest way to move: Can we move files directly within the same device?
 	// We loop through the files/dirs in the source directory and just try to move them, it should work.
 	if (MoveChildrenFast(moveSrc, moveDest, progressReporter)) {
-		INFO_LOG(Log::System, "Quick-move succeeded");
-		progressReporter.SetProgress(ms->T("Done!"));
-		return new MoveResult{
-			true, ""
-		};
+		INFO_LOG(Log::System, "Quick-move succeeded after %0.1f ms", moveStart.ElapsedMs());
+		progressReporter.SetProgress(StringFromFormat("%s (%0.3s)", ms->T_cstr("Done!"), moveStart.ElapsedSeconds()));
+		return new MoveResult{ true, "" };
+	} else {
+		INFO_LOG(Log::System, "Quick move denied after %0.1f ms, falling back to slow move.", moveStart.ElapsedMs());
 	}
 
 	// If this doesn't work, we'll fall back on a recursive *copy* (disk space is less of a concern when
@@ -179,7 +184,7 @@ MoveResult *MoveDirectoryContentsSafe(Path moveSrc, Path moveDest, MoveProgressR
 		return new MoveResult{ false, error };
 	}
 
-	bool dryRun = false;  // Useful for debugging.
+	bool dryRun = false;  // Useful for debugging. Probably want to remove the MoveChildrenFast path above to test it.
 
 	size_t failedFileCount = 0;
 

UI/MemStickScreen.cpp

@@ -589,7 +589,7 @@ void ConfirmMemstickMoveScreen::update() {
 				FinishFolderMove();
 			} else {
 				progressReporter_.SetProgress(ms->T("Failed to move some files!"));
-				INFO_LOG(Log::System, "Move data task failed!");
+				INFO_LOG(Log::System, "Move data task finished with failures!");
 				// What do we do here? We might be in the middle of a move... Bad.
 				RecreateViews();
 			}
@@ -620,7 +620,9 @@ UI::EventReturn ConfirmMemstickMoveScreen::OnConfirm(UI::EventParams &params) {
 		moveDataTask_ = Promise<MoveResult *>::Spawn(&g_threadManager, [&]() -> MoveResult * {
 			Path moveSrc = g_Config.memStickDirectory;
 			Path moveDest = newMemstickFolder_;
-			return MoveDirectoryContentsSafe(moveSrc, moveDest, progressReporter_);
+			MoveResult *result = MoveDirectoryContentsSafe(moveSrc, moveDest, progressReporter_);
+			NOTICE_LOG(Log::System, "Move task finished: %b", result != nullptr);
+			return result;
 		}, TaskType::IO_BLOCKING, TaskPriority::HIGH);
 
 		RecreateViews();
@@ -643,6 +645,8 @@ void ConfirmMemstickMoveScreen::FinishFolderMove() {
 		return;
 	}
 
+	INFO_LOG(Log::System, "Move from '%s' to '%s' complete. Updating config.", oldMemstickFolder.c_str(), newMemstickFolder_.c_str());
+
 	// If the chosen folder already had a config, reload it!
 	g_Config.Load();
 
@@ -655,14 +659,17 @@ void ConfirmMemstickMoveScreen::FinishFolderMove() {
 
 	if (!initialSetup_) {
 		// We restart the app here, to get the new settings.
+		INFO_LOG(Log::System, "Not initial setup. Restarting!");
 		System_RestartApp("");
 	} else {
 		// This is initial setup, we now switch to the main screen, if we were successful
 		// (which we better have been...)
 		if (g_Config.Save("MemstickPathChanged")) {
+			INFO_LOG(Log::System, "Initial setup succeeded. Switching to main screen!");
 			// TriggerFinish(DialogResult::DR_OK);
 			screenManager()->switchScreen(new MainScreen());
 		} else {
+			INFO_LOG(Log::System, "Initial setup failed.");
 			error_ = ms->T("Failed to save config");
 			RecreateViews();
 		}

android/src/org/ppsspp/ppsspp/PpssppActivity.java

@@ -20,6 +20,8 @@ import android.os.storage.StorageManager;
 import android.content.ContentResolver;
 import android.database.Cursor;
 import android.provider.DocumentsContract;
+
+import androidx.annotation.RequiresApi;
 import androidx.documentfile.provider.DocumentFile;
 
 import java.util.ArrayList;
@@ -387,7 +389,10 @@ public class PpssppActivity extends NativeActivity {
 			Uri srcUri = Uri.parse(srcFileUri);
 			Uri srcParentUri = Uri.parse(srcParentDirUri);
 			Uri dstParentUri = Uri.parse(dstParentDirUri);
-			return DocumentsContract.moveDocument(getContentResolver(), srcUri, srcParentUri, dstParentUri) != null ? STORAGE_ERROR_SUCCESS : STORAGE_ERROR_UNKNOWN;
+			Log.i(TAG, "DocumentsContract.moveDocument");
+			int result = DocumentsContract.moveDocument(getContentResolver(), srcUri, srcParentUri, dstParentUri) != null ? STORAGE_ERROR_SUCCESS : STORAGE_ERROR_UNKNOWN;
+			Log.i(TAG, "DocumentsContract.moveDocument done");
+			return result;
 		} catch (Exception e) {
 			Log.e(TAG, "contentUriMoveFile exception: " + e);
 			return STORAGE_ERROR_UNKNOWN;
@@ -474,7 +479,7 @@ public class PpssppActivity extends NativeActivity {
 	// There's also a way to beg the OS for more space, which might clear caches, but
 	// let's just not bother with that for now.
 	// NOTE: This is really super slow!
-	@TargetApi(Build.VERSION_CODES.M)
+	@RequiresApi(Build.VERSION_CODES.M)
 	public long contentUriGetFreeStorageSpaceSlow(Uri uri) {
 		try {
 			ParcelFileDescriptor pfd = getContentResolver().openFileDescriptor(uri, "r");