Add a "reason" argument to sleep_ms().

sleep_ms() should generally be avoided when possible. This can be used to try to track down unnecessary sleeps by adding some logging. This commit on its own doesn't actually add any logging.
hrydgard · Nov 21, 2024 · 08eda6b · 08eda6b
1 parent 489db6b
commit 08eda6b
Show file tree

Hide file tree

Showing 26 changed files with 52 additions and 54 deletions.
diff --git a/Common/File/PathBrowser.cpp b/Common/File/PathBrowser.cpp
@@ -235,7 +235,7 @@ bool PathBrowser::GetListing(std::vector<File::FileInfo> &fileInfo, const char *
 	while (!IsListingReady() && (!cancel || !*cancel)) {
 		// In case cancel changes, just sleep. TODO: Replace with condition variable.
 		guard.unlock();
-		sleep_ms(50);
+		sleep_ms(50, "pathbrowser-poll");
 		guard.lock();
 	}
 

diff --git a/Common/GPU/Vulkan/VulkanRenderManager.cpp b/Common/GPU/Vulkan/VulkanRenderManager.cpp
@@ -279,7 +279,7 @@ class CreateMultiPipelinesTask : public Task {
 
 void CreateMultiPipelinesTask::WaitForAll() {
 	while (tasksInFlight_.load() > 0) {
-		sleep_ms(2);
+		sleep_ms(2, "create-multi-pipelines-wait");
 	}
 }
 
@@ -522,7 +522,7 @@ void VulkanRenderManager::CompileThreadFunc() {
 		}
 
 		// Hold off just a bit before we check again, to allow bunches of pipelines to collect.
-		sleep_ms(1);
+		sleep_ms(1, "pipeline-collect");
 	}
 
 	std::unique_lock<std::mutex> lock(compileQueueMutex_);
@@ -579,7 +579,7 @@ void VulkanRenderManager::PresentWaitThreadFunc() {
 			waitedId++;
 		} else {
 			// We caught up somehow, which is a bad sign (we should have blocked, right?). Maybe we should break out of the loop?
-			sleep_ms(1);
+			sleep_ms(1, "present-wait-problem");
 			frameTimeHistory_[waitedId].waitCount++;
 		}
 		_dbg_assert_(waitedId <= frameIdGen_);

diff --git a/Common/Net/HTTPClient.cpp b/Common/Net/HTTPClient.cpp
@@ -211,7 +211,7 @@ bool Connection::Connect(int maxTries, double timeout, bool *cancelConnect) {
 			break;
 		}
 
-		sleep_ms(1);
+		sleep_ms(1, "connect");
 	}
 
 	// Nothing connected, unfortunately.

diff --git a/Common/Net/HTTPRequest.cpp b/Common/Net/HTTPRequest.cpp
@@ -130,14 +130,6 @@ void RequestManager::Update() {
 	}
 }
 
-void RequestManager::WaitForAll() {
-	// TODO: Should lock? Though, OK if called from main thread, where Update() is called from.
-	while (!downloads_.empty()) {
-		Update();
-		sleep_ms(10);
-	}
-}
-
 void RequestManager::CancelAll() {
 	for (size_t i = 0; i < downloads_.size(); i++) {
 		downloads_[i]->Cancel();

diff --git a/Common/Net/HTTPRequest.h b/Common/Net/HTTPRequest.h
@@ -108,7 +108,6 @@ class RequestManager {
 	void Update();
 	void CancelAll();
 
-	void WaitForAll();
 	void SetUserAgent(const std::string &userAgent) {
 		userAgent_ = userAgent;
 	}

diff --git a/Common/Net/Resolve.cpp b/Common/Net/Resolve.cpp
@@ -105,7 +105,7 @@ bool DNSResolve(const std::string &host, const std::string &service, addrinfo **
 	int result = getaddrinfo(host.c_str(), servicep, &hints, res);
 	if (result == EAI_AGAIN) {
 		// Temporary failure.  Since this already blocks, let's just try once more.
-		sleep_ms(1);
+		sleep_ms(1, "dns-resolve-poll");
 		result = getaddrinfo(host.c_str(), servicep, &hints, res);
 	}
 

diff --git a/Common/TimeUtil.cpp b/Common/TimeUtil.cpp
@@ -251,7 +251,7 @@ double Instant::ElapsedSeconds() const {
 
 #endif
 
-void sleep_ms(int ms) {
+void sleep_ms(int ms, const char *reason) {
 #ifdef _WIN32
 	Sleep(ms);
 #elif defined(HAVE_LIBNX)

diff --git a/Common/TimeUtil.h b/Common/TimeUtil.h
@@ -18,7 +18,9 @@ double from_time_raw_relative(uint64_t raw_time);
 double time_now_unix_utc();
 
 // Sleep. Does not necessarily have millisecond granularity, especially on Windows.
-void sleep_ms(int ms);
+// Requires a "reason" since sleeping generally should be very sparingly used. This
+// can be logged if desired to figure out where we're wasting time.
+void sleep_ms(int ms, const char *reason);
 
 // Precise sleep. Can consume a little bit of CPU on Windows at least.
 void sleep_precise(double seconds);

diff --git a/Core/Core.cpp b/Core/Core.cpp
@@ -222,15 +222,15 @@ bool UpdateScreenScale(int width, int height) {
 void UpdateRunLoop(GraphicsContext *ctx) {
 	NativeFrame(ctx);
 	if (windowHidden && g_Config.bPauseWhenMinimized) {
-		sleep_ms(16);
+		sleep_ms(16, "window-hidden");
 		return;
 	}
 }
 
 // Note: not used on Android.
 void Core_RunLoop(GraphicsContext *ctx) {
 	if (windowHidden && g_Config.bPauseWhenMinimized) {
-		sleep_ms(16);
+		sleep_ms(16, "window-hidden");
 		return;
 	}
 

diff --git a/Core/FileLoaders/CachingFileLoader.cpp b/Core/FileLoaders/CachingFileLoader.cpp
@@ -110,7 +110,7 @@ void CachingFileLoader::ShutdownCache() {
 	// We can't delete while the thread is running, so have to wait.
 	// This should only happen from the menu.
 	while (aheadThreadRunning_) {
-		sleep_ms(1);
+		sleep_ms(1, "shutdown-cache-poll");
 	}
 	if (aheadThread_.joinable())
 		aheadThread_.join();

diff --git a/Core/FileLoaders/RamCachingFileLoader.cpp b/Core/FileLoaders/RamCachingFileLoader.cpp
@@ -106,7 +106,7 @@ void RamCachingFileLoader::ShutdownCache() {
 	// We can't delete while the thread is running, so have to wait.
 	// This should only happen from the menu.
 	while (aheadThreadRunning_) {
-		sleep_ms(1);
+		sleep_ms(1, "shutdown-ram-cache-poll");
 	}
 	if (aheadThread_.joinable())
 		aheadThread_.join();

diff --git a/Core/FrameTiming.cpp b/Core/FrameTiming.cpp
@@ -35,7 +35,7 @@ FrameTiming g_frameTiming;
 void WaitUntil(double now, double timestamp) {
 #ifdef _WIN32
 	while (time_now_d() < timestamp) {
-		sleep_ms(1); // Sleep for 1ms on this thread
+		sleep_ms(1, "wait-until"); // Sleep for 1ms on this thread
 	}
 #else
 	const double left = timestamp - now;

diff --git a/Core/HLE/proAdhoc.cpp b/Core/HLE/proAdhoc.cpp
@@ -1780,10 +1780,11 @@ int friendFinder(){
 			}
 		}
 		// This delay time should be 100ms when there is an event otherwise 500ms ?
-		sleep_ms(10); // Using 1ms for faster response just like AdhocServer?
+		sleep_ms(10, "pro-adhoc-poll-2"); // Using 1ms for faster response just like AdhocServer?
 
 		// Don't do anything if it's paused, otherwise the log will be flooded
-		while (Core_IsStepping() && coreState != CORE_POWERDOWN && friendFinderRunning) sleep_ms(10);
+		while (Core_IsStepping() && coreState != CORE_POWERDOWN && friendFinderRunning)
+			sleep_ms(10, "pro-adhoc-paused-poll-2");
 	}
 
 	// Groups/Networks should be deallocated isn't?
@@ -2257,7 +2258,7 @@ int initNetwork(SceNetAdhocctlAdhocId *adhoc_id){
 					errorcode = ETIMEDOUT;
 				break;
 			}
-			sleep_ms(10);
+			sleep_ms(10, "pro-adhoc-socket-poll");
 		}
 		if (!done) {
 			ERROR_LOG(Log::sceNet, "Socket error (%i) when connecting to AdhocServer [%s/%s:%u]", errorcode, g_Config.proAdhocServer.c_str(), ip2str(g_adhocServerIP.in.sin_addr).c_str(), ntohs(g_adhocServerIP.in.sin_port));

diff --git a/Core/HLE/proAdhocServer.cpp b/Core/HLE/proAdhocServer.cpp
@@ -2081,10 +2081,12 @@ int server_loop(int server)
 		}
 
 		// Prevent needless CPU Overload (1ms Sleep)
-		sleep_ms(10);
+		// !!!! COMMENT NOT REFLECTING REALITY
+		sleep_ms(10, "pro-adhoc-poll");
 
 		// Don't do anything if it's paused, otherwise the log will be flooded
-		while (adhocServerRunning && Core_IsStepping() && coreState != CORE_POWERDOWN) sleep_ms(10);
+		while (adhocServerRunning && Core_IsStepping() && coreState != CORE_POWERDOWN)
+			sleep_ms(10, "pro-adhot-paused-poll");
 	}
 
 	// Free User Database Memory

diff --git a/Core/HLE/sceDisplay.cpp b/Core/HLE/sceDisplay.cpp
@@ -483,7 +483,7 @@ static void DoFrameIdleTiming() {
 		double cur_time;
 		while ((cur_time = time_now_d()) < goal) {
 #ifdef _WIN32
-			sleep_ms(1);
+			sleep_ms(1, "frame-idle");
 #else
 			const double left = goal - cur_time;
 			if (left > 0.0f && left < 1.0f) {  // Sanity check

diff --git a/Core/HLE/sceNetAdhoc.cpp b/Core/HLE/sceNetAdhoc.cpp
@@ -7577,10 +7577,11 @@ int matchingEventThread(int matchingId)
 			}
 
 			// Share CPU Time
-			sleep_ms(10); //1 //sceKernelDelayThread(10000);
+			sleep_ms(10, "pro-adhoc-poll-3"); //1 //sceKernelDelayThread(10000);
 
 			// Don't do anything if it's paused, otherwise the log will be flooded
-			while (Core_IsStepping() && coreState != CORE_POWERDOWN && contexts != NULL && context->eventRunning) sleep_ms(10);
+			while (Core_IsStepping() && coreState != CORE_POWERDOWN && contexts != NULL && context->eventRunning)
+				sleep_ms(10, "pro-adhoc-event-poll-3");
 		}
 
 		// Process Last Messages
@@ -7847,10 +7848,11 @@ int matchingInputThread(int matchingId) // TODO: The MatchingInput thread is usi
 					break;
 			}
 			// Share CPU Time
-			sleep_ms(10); //1 //sceKernelDelayThread(10000);
+			sleep_ms(10, "pro-adhoc-4"); //1 //sceKernelDelayThread(10000);
 
 			// Don't do anything if it's paused, otherwise the log will be flooded
-			while (Core_IsStepping() && coreState != CORE_POWERDOWN && contexts != NULL && context->inputRunning) sleep_ms(10);
+			while (Core_IsStepping() && coreState != CORE_POWERDOWN && contexts != NULL && context->inputRunning)
+				sleep_ms(10, "pro-adhoc-input-4");
 		}
 
 		if (contexts != NULL) {

diff --git a/Core/System.cpp b/Core/System.cpp
@@ -536,7 +536,7 @@ bool PSP_Init(const CoreParameter &coreParam, std::string *error_string) {
 		return false;
 
 	while (!PSP_InitUpdate(error_string))
-		sleep_ms(10);
+		sleep_ms(10, "psp-init-poll");
 	return pspIsInited;
 }
 

diff --git a/UI/GameInfoCache.cpp b/UI/GameInfoCache.cpp
@@ -935,7 +935,7 @@ void GameInfoCache::PurgeType(IdentifiedFileType fileType) {
 			}
 		}
 
-		sleep_ms(10);
+		sleep_ms(10, "game-info-cache-purge-poll");
 	} while (retry);
 }
 

diff --git a/UI/NativeApp.cpp b/UI/NativeApp.cpp
@@ -1165,7 +1165,7 @@ void NativeFrame(GraphicsContext *graphicsContext) {
 		double diffTime = time_now_d() - startTime;
 		int sleepTime = (int)(1000.0 / refreshRate) - (int)(diffTime * 1000.0);
 		if (sleepTime > 0)
-			sleep_ms(sleepTime);
+			sleep_ms(sleepTime, "fallback-throttle");
 	}
 }
 

diff --git a/UI/RemoteISOScreen.cpp b/UI/RemoteISOScreen.cpp
@@ -457,7 +457,7 @@ RemoteISOConnectScreen::~RemoteISOConnectScreen() {
 	int maxWait = 5000;
 	scanCancelled = true;
 	while (GetStatus() == ScanStatus::SCANNING || GetStatus() == ScanStatus::LOADING) {
-		sleep_ms(1);
+		sleep_ms(1, "remote-iso-scan");
 		if (--maxWait < 0) {
 			// If it does ever wake up, it may crash... but better than hanging?
 			scanAborted = true;

diff --git a/android/jni/app-android.cpp b/android/jni/app-android.cpp
@@ -316,7 +316,7 @@ static void EmuThreadFunc() {
 	// Wait for render loop to get started.
 	INFO_LOG(Log::System, "Runloop: Waiting for displayInit...");
 	while (!graphicsContext || graphicsContext->GetState() == GraphicsContextState::PENDING) {
-		sleep_ms(5);
+		sleep_ms(5, "graphics-poll");
 	}
 
 	// Check the state of the graphics context before we try to feed it into NativeInitGraphics.
@@ -1700,7 +1700,7 @@ extern "C" jstring Java_org_ppsspp_ppsspp_ShortcutActivity_queryGameName(JNIEnv
 	if (info) {
 		INFO_LOG(Log::System, "GetInfo successful, waiting");
 		while (!info->Ready(GameInfoFlags::PARAM_SFO)) {
-			sleep_ms(1);
+			sleep_ms(1, "info-poll");
 		}
 		INFO_LOG(Log::System, "Done waiting");
 		if (info->fileType != IdentifiedFileType::UNKNOWN) {
@@ -1754,7 +1754,7 @@ Java_org_ppsspp_ppsspp_ShortcutActivity_queryGameIcon(JNIEnv * env, jclass clazz
 		INFO_LOG(Log::System, "GetInfo successful, waiting");
         int attempts = 1000;
         while (!info->Ready(GameInfoFlags::ICON)) {
-            sleep_ms(1);
+            sleep_ms(1, "icon-poll");
             attempts--;
             if (!attempts) {
                 break;

diff --git a/headless/Headless.cpp b/headless/Headless.cpp
@@ -222,7 +222,7 @@ bool RunAutoTest(HeadlessHost *headlessHost, CoreParameter &coreParameter, const
 		headlessHost->SetComparisonScreenshot(ExpectedScreenshotFromFilename(coreParameter.fileToStart), opt.maxScreenshotError);
 
 	while (!PSP_InitUpdate(&error_string))
-		sleep_ms(1);
+		sleep_ms(1, "auto-test");
 	if (!PSP_IsInited()) {
 		TeamCityPrint("testFailed name='%s' message='Startup failed'", currentTestName.c_str());
 		TeamCityPrint("testFinished name='%s'", currentTestName.c_str());

diff --git a/headless/SDLHeadlessHost.cpp b/headless/SDLHeadlessHost.cpp
@@ -175,7 +175,7 @@ bool SDLHeadlessHost::InitGraphics(std::string *error_message, GraphicsContext *
 
 	std::thread th([&]{
 		while (threadState_ == RenderThreadState::IDLE)
-			sleep_ms(1);
+			sleep_ms(1, "sdl-idle-poll");
 		threadState_ = RenderThreadState::STARTING;
 
 		std::string err;
@@ -201,15 +201,15 @@ bool SDLHeadlessHost::InitGraphics(std::string *error_message, GraphicsContext *
 
 	threadState_ = RenderThreadState::START_REQUESTED;
 	while (threadState_ == RenderThreadState::START_REQUESTED || threadState_ == RenderThreadState::STARTING)
-		sleep_ms(1);
+		sleep_ms(1, "sdl-start-poll");
 
 	return threadState_ == RenderThreadState::STARTED;
 }
 
 void SDLHeadlessHost::ShutdownGraphics() {
 	gfx_->StopThread();
 	while (threadState_ != RenderThreadState::STOPPED && threadState_ != RenderThreadState::START_FAILED)
-		sleep_ms(1);
+		sleep_ms(1, "sdl-stop-poll");
 
 	gfx_->Shutdown();
 	delete gfx_;

diff --git a/headless/WindowsHeadlessHost.cpp b/headless/WindowsHeadlessHost.cpp
@@ -117,7 +117,7 @@ bool WindowsHeadlessHost::InitGraphics(std::string *error_message, GraphicsConte
 	if (needRenderThread) {
 		std::thread th([&]{
 			while (threadState_ == RenderThreadState::IDLE)
-				sleep_ms(1);
+				sleep_ms(1, "render-thread-idle-poll");
 			threadState_ = RenderThreadState::STARTING;
 
 			std::string err;
@@ -145,7 +145,7 @@ bool WindowsHeadlessHost::InitGraphics(std::string *error_message, GraphicsConte
 	if (needRenderThread) {
 		threadState_ = RenderThreadState::START_REQUESTED;
 		while (threadState_ == RenderThreadState::START_REQUESTED || threadState_ == RenderThreadState::STARTING)
-			sleep_ms(1);
+			sleep_ms(1, "render-thread-start-poll");
 
 		return threadState_ == RenderThreadState::STARTED;
 	}
@@ -156,7 +156,7 @@ bool WindowsHeadlessHost::InitGraphics(std::string *error_message, GraphicsConte
 void WindowsHeadlessHost::ShutdownGraphics() {
 	gfx_->StopThread();
 	while (threadState_ != RenderThreadState::STOPPED && threadState_ != RenderThreadState::IDLE)
-		sleep_ms(1);
+		sleep_ms(1, "render-thread-stop-poll");
 
 	gfx_->Shutdown();
 	delete gfx_;

diff --git a/libretro/libretro.cpp b/libretro/libretro.cpp
@@ -1383,7 +1383,7 @@ namespace Libretro
                emuThreadState = EmuThreadState::PAUSED;
                /* fallthrough */
             case EmuThreadState::PAUSED:
-               sleep_ms(1);
+               sleep_ms(1, "libretro-paused");
                break;
             default:
             case EmuThreadState::QUIT_REQUESTED:
@@ -1432,7 +1432,7 @@ namespace Libretro
       ctx->ThreadFrame(); // Eat 1 frame
 
       while (emuThreadState != EmuThreadState::PAUSED)
-         sleep_ms(1);
+         sleep_ms(1, "libretro-pause-poll");
    }
 
 } // namespace Libretro
@@ -1644,7 +1644,7 @@ void retro_run(void)
    {
       std::string error_string;
       while (!PSP_InitUpdate(&error_string))
-         sleep_ms(4);
+         sleep_ms(4, "libretro-init-poll");
 
       if (!PSP_IsInited())
       {
@@ -1736,7 +1736,7 @@ bool retro_serialize(void *data, size_t size)
    if (useEmuThread)
    {
       EmuThreadStart();
-      sleep_ms(4);
+      sleep_ms(4, "libretro-serialize");
    }
 
    return retVal;
@@ -1759,7 +1759,7 @@ bool retro_unserialize(const void *data, size_t size)
    if (useEmuThread)
    {
       EmuThreadStart();
-      sleep_ms(4);
+      sleep_ms(4, "libretro-unserialize");
    }
 
    return retVal;