Fix HOME-exit hang by handing ProcUI lifecycle to SDL2-wuhb

Author: timkicker

src/app/App.cpp

@@ -19,6 +19,8 @@ extern void elogf(const char* fmt, ...);
 #include <SDL2/SDL.h>
 #include <whb/proc.h>
 #include <proc_ui/procui.h>
+#include <coreinit/thread.h>
+#include <coreinit/time.h>
 #include <SDL2/SDL_ttf.h>
 #include <SDL2/SDL_image.h>
 
@@ -32,6 +34,11 @@ extern "C" {
 App::App() = default;
 
 App::~App() {
+    // Standard SDL2-on-Wii-U teardown order. SDL_Quit() internally drives
+    // SYSLaunchMenu + ProcUIProcessMessages drain + ProcUIShutdown via its
+    // WIIU_VideoQuit handler (because we let SDL_Init claim ProcUI in
+    // main() by NOT calling WHBProcInit). No custom ProcUI bookkeeping
+    // needed on our side.
     elog("~App: DownloadQueue stop");
     DownloadQueue::get().stop();
     elog("~App: clearing screens");
@@ -48,7 +55,7 @@ App::~App() {
     IMG_Quit();
     elog("~App: TTF_Quit");
     TTF_Quit();
-    elog("~App: SDL_Quit");
+    elog("~App: SDL_Quit (drains ProcUI internally)");
     SDL_Quit();
     elog("~App: done");
 }
@@ -60,10 +67,16 @@ bool App::init() {
     // Without these calls, Cemu's emulated socket layer never finishes
     // setup and curl connect() hangs. The previous BUILD_HW gate broke
     // cemu mode entirely (app stuck on "Loading repos...").
-    nn::ac::Initialize();
-    nn::ac::Connect();
+    {
+        nn::Result r = nn::ac::Initialize();
+        elogf("Network: nn::ac::Initialize -> %s", r.IsSuccess() ? "ok" : "FAILED");
+    }
+    {
+        nn::Result r = nn::ac::Connect();
+        elogf("Network: nn::ac::Connect -> %s", r.IsSuccess() ? "ok" : "FAILED");
+    }
     socket_lib_init();
-    elog("Network ready");
+    elog("Network: socket_lib_init done, network ready");
 #endif
 
     if (SDL_Init(SDL_INIT_VIDEO | SDL_INIT_JOYSTICK | SDL_INIT_GAMECONTROLLER) != 0) {
@@ -130,7 +143,11 @@ bool App::init() {
     elog("mkdir done");
     Logger::get().init(Paths::modstoreBase() + "/app.log");
     elog("logger init done");
-    LOG_INFO("App started");
+#ifdef APP_VERSION
+    LOG_INFO("App started (CoffeeShop %s)", APP_VERSION);
+#else
+    LOG_INFO("App started (no version define)");
+#endif
     elog("before pushScreen");
     pushScreen(std::make_unique<MainLayout>(this));
     elog("after pushScreen");
@@ -164,62 +181,67 @@ void App::run() {
     m_running = true;
     int pruneCounter = 0;
     int frameNum = 0;
-    elogf("App::run entering -- screens=%zu running=%d procRunning=%d",
-          m_screens.size(), (int)m_running,
-#ifdef __WUT__
-          (int)WHBProcIsRunning()
-#else
-          1
-#endif
-    );
+    elogf("App::run entering -- screens=%zu running=%d", m_screens.size(), (int)m_running);
+    // NOTE: We deliberately do NOT call WHBProcIsRunning() here -- it would
+    // run ProcUIProcessMessages and then ProcUIShutdown() because WHB's
+    // sRunning flag is false (we never called WHBProcInit). That would tear
+    // down ProcUI before we ever rendered a frame. SDL drives ProcUI for
+    // us inside SDL_PollEvent below.
 
-    while (m_running && !m_screens.empty() && WHBProcIsRunning()) {
-        if (frameNum < 10 || frameNum % 60 == 0) {
-            elogf("frame %d begin", frameNum);
-        }
+    // SDL2-wuhb owns the ProcUI lifecycle (we don't call WHBProcInit, so
+    // SDL_Init claims it via ProcUIInitEx and sets handleProcUI=TRUE on
+    // its side). SDL drives ProcUI from WIIU_PumpEvents (called by
+    // SDL_PollEvent below) and fires SDL_QUIT when EXITING is received.
+    // We must NOT use WHBProcIsRunning() as a loop guard: WHB's sRunning
+    // flag is false because we never called WHBProcInit, and the first
+    // WHBProcIsRunning() call would call ProcUIShutdown() and return
+    // false, exiting the loop with 0 frames. Use SDL_QUIT (set via
+    // m_running=false) as the canonical exit trigger instead.
+    while (m_running && !m_screens.empty()) {
+        // Log only the first 10 frames to confirm the loop started cleanly.
+        // Periodic per-second pulses were diagnostic for the HOME-exit hang
+        // and are no longer needed; they'd just bloat early.log.
+        if (frameNum < 10) elogf("frame %d begin", frameNum);
         SDL_Event event;
         while (SDL_PollEvent(&event)) {
             if (event.type == SDL_QUIT) {
                 elog("got SDL_QUIT");
                 m_running = false;
             }
         }
-        if (frameNum < 5) elog("  before update");
         update();
-        if (frameNum < 5) elog("  after update");
         render();
-        if (frameNum < 5) elogf("  after render (sdl_err='%s')", SDL_GetError());
         TextCache::get().tick();
         if (++pruneCounter > 300) {
             TextCache::get().prune();
             pruneCounter = 0;
-            elogf("frame %d: pruned text cache", frameNum);
         }
         frameNum++;
     }
-    elogf("App::run loop exited -- frames=%d running=%d screens=%zu procRunning=%d",
-          frameNum, (int)m_running, m_screens.size(),
-#ifdef __WUT__
-          (int)WHBProcIsRunning()
-#else
-          1
-#endif
-    );
-#ifdef __WUT__
-    // Drain ProcUI until Aroma confirms exit - required for WHBProcShutdown to work
-    while (WHBProcIsRunning()) {}
-#endif
+    elogf("App::run loop exited -- frames=%d running=%d screens=%zu exiting=%d",
+          frameNum, (int)m_running, m_screens.size(), (int)m_exiting);
+    // No ProcUI drain here. SDL_Quit's WIIU_VideoQuit handles the exit
+    // transition: it calls SYSLaunchMenu, then loops on
+    // ProcUIProcessMessages(TRUE) handling RELEASE_FOREGROUND and exiting
+    // when EXITING is received, then calls ProcUIShutdown. We just need
+    // to return from run() so main() can let the App destructor (and
+    // therefore SDL_Quit) run.
 }
 
 void App::quit() {
+    elog("App::quit called -- setting m_running=false (no SYSLaunchMenu)");
     m_running = false;
 }
 void App::startExit() {
+    // Just stop the main loop. SDL2-wuhb is the single owner of the
+    // ProcUI/SYSLaunchMenu handshake: SDL_Quit's WIIU_VideoQuit detects
+    // !exitingProcUI and calls SYSLaunchMenu + drains ProcUI itself.
+    // Calling SYSLaunchMenu here too would issue it twice in flight
+    // (once now, once during SDL_Quit) and reproduce the original
+    // "Wii U Menu loading" hang. See Codex review 2026-05-..
+    elog("App::startExit called -- m_running=false, SDL_Quit will own SYSLaunchMenu");
     m_exiting = true;
     m_running = false;
-#ifdef __WUT__
-    SYSLaunchMenu();
-#endif
 }
 
 void App::pushScreen(std::unique_ptr<Screen> screen) {
@@ -228,11 +250,15 @@ void App::pushScreen(std::unique_ptr<Screen> screen) {
 }
 
 void App::popScreen() {
+    elogf("App::popScreen -- stack=%zu before", m_screens.size());
     if (!m_screens.empty()) {
         m_screens.back()->onExit();
         m_screens.pop_back();
     }
-    if (m_screens.empty()) m_running = false;
+    if (m_screens.empty()) {
+        elog("App::popScreen -- stack empty, setting m_running=false (no SYSLaunchMenu)");
+        m_running = false;
+    }
 }
 
 void App::update() {

src/audio/AudioManager.cpp

@@ -39,7 +39,11 @@ void AudioManager::init() {
 }
 
 void AudioManager::shutdown() {
-    if (!m_initialized) return;
+    if (!m_initialized) {
+        LOG_INFO("AudioManager::shutdown: already shut down, skipping");
+        return;
+    }
+    LOG_INFO("AudioManager::shutdown begin");
     stopMusic();
     for (auto& [id, chunk] : m_sounds) Mix_FreeChunk(chunk);
     m_sounds.clear();
@@ -50,6 +54,7 @@ void AudioManager::shutdown() {
     Mix_CloseAudio();
     Mix_Quit();
     m_initialized = false;
+    LOG_INFO("AudioManager::shutdown done");
 }
 
 void AudioManager::playSound(SoundId id) {

src/main.cpp

@@ -22,13 +22,17 @@ extern "C" {
 }
 #endif
 
+#include "util/LogClock.h"
+
 static const char* g_elog_path = nullptr;
+
 void elog(const char* msg) {
-    WHBLogPrintf("[elog] %s", msg);
+    double t = LogClock::elapsedSec();
+    WHBLogPrintf("[elog %8.3f] %s", t, msg);
     if (g_elog_path) {
         FILE* f = fopen(g_elog_path, "a");
         if (f) {
-            fprintf(f, "%s\n", msg);
+            fprintf(f, "[%8.3f] %s\n", t, msg);
             fclose(f);
         }
     }
@@ -46,6 +50,11 @@ void elogf(const char* fmt, ...) {
 }
 
 int main(int argc, char** argv) {
+    // Set the log epoch as the very first thing so every subsequent timestamp
+    // is relative to "process started". Anything that fired before this point
+    // is pre-runtime and not interesting to log.
+    LogClock::init();
+
     // Diagnostic: prove main() was called before ANY WHB/SDL init.
     {
         FILE* probe = fopen("/vol/external01/wiiu/apps/coffeeshop/main_called.txt", "w");
@@ -55,7 +64,15 @@ int main(int argc, char** argv) {
         }
     }
 
-    WHBProcInit();
+    // NOTE: We do NOT call WHBProcInit() here. SDL_Init() will detect that
+    // ProcUI isn't running yet and call ProcUIInitEx() itself, claiming
+    // ownership of the ProcUI lifecycle. With handleProcUI=TRUE on its side,
+    // SDL drives ProcUI from PumpEvents (sending SDL_QUIT on EXITING) and
+    // properly drains it on SDL_Quit (SYSLaunchMenu + ProcUIProcessMessages
+    // loop). If we initialised ProcUI first, SDL would back off and we'd
+    // be stuck handling the entire state machine ourselves -- which is
+    // exactly the rabbit hole that produced the HOME-exit hang. See
+    // SDL_wiiuvideo.c:WIIU_VideoInit / WIIU_VideoQuit.
     WHBLogUdpInit();
 
 #ifdef __WUT__
@@ -84,6 +101,11 @@ int main(int argc, char** argv) {
         }
     }
     elog("START");
+#ifdef APP_VERSION
+    elogf("CoffeeShop %s", APP_VERSION);
+#else
+    elog("CoffeeShop (no version define)");
+#endif
     elog(Paths::sdMounted ? "SD mounted" : "SD failed");
 
     // Crash dump catcher: writes a minimal report on SIGSEGV/etc so users
@@ -131,9 +153,9 @@ int main(int argc, char** argv) {
     socket_lib_finish();
     elog("ac::Finalize");
     nn::ac::Finalize();
+    // No WHBProcShutdown: SDL_Quit's WIIU_VideoQuit already ran SYSLaunchMenu,
+    // drained ProcUI, and called ProcUIShutdown via its handleProcUI path.
+    // Calling WHBProcShutdown again would either no-op or interfere.
 #endif
-    // elog uses open+write+close per call; nothing to fclose at exit.
-    // WHBProcShutdown intentionally omitted (CLAUDE.md): App::run drains
-    // ProcUI and SYSLaunchMenu hands control back to the OS.
     return 0;
 }

src/net/DownloadQueue.cpp

@@ -63,6 +63,7 @@ void DownloadQueue::start() {
 }
 
 void DownloadQueue::stop() {
+    LOG_INFO("DownloadQueue: stop() called, signalling %d worker(s)", (int)m_workers.size());
     {
         std::lock_guard<std::mutex> lock(m_mutex);
         for (auto& j : m_jobs) j.cancel = true;
@@ -71,19 +72,22 @@ void DownloadQueue::stop() {
     m_cv.notify_all();
     for (auto& w : m_workers) if (w.joinable()) w.join();
     m_workers.clear();
+    LOG_INFO("DownloadQueue: stop() done");
 }
 
 void DownloadQueue::cancelJob(int index) {
     std::lock_guard<std::mutex> lock(m_mutex);
     if (index >= 0 && index < (int)m_jobs.size()) {
         auto& j = m_jobs[index];
         if (j.state == DownloadJob::State::Pending) {
+            LOG_INFO("DownloadQueue: cancelled pending job '%s'", j.mod.name.c_str());
             j.state        = DownloadJob::State::Error;
             j.error        = "Cancelled";
             j.hasFinishedAt = true;
             j.finishedAt   = std::chrono::steady_clock::now();
         } else if (j.state == DownloadJob::State::Downloading ||
                    j.state == DownloadJob::State::Extracting) {
+            LOG_INFO("DownloadQueue: cancel flag set on active job '%s'", j.mod.name.c_str());
             j.cancel = true;
         }
     }
@@ -162,8 +166,10 @@ void DownloadQueue::workerLoop() {
             jobCancel  = &m_jobs[pendingIdx].cancel;
         }
 
+        LOG_INFO("DownloadQueue: starting job '%s' for title %s", jobMod.name.c_str(), jobTitleId.c_str());
         processJob(pendingIdx, jobMod, jobTitleId, jobCancel);
     }
+    LOG_INFO("DownloadQueue: worker exiting");
 }
 
 void DownloadQueue::processJob(int idx, const Mod& mod,

src/ui/DetailScreen.cpp

@@ -2,6 +2,7 @@
 #include "ui/RegionSelectScreen.h"
 #include "mods/InstallHelper.h"
 #include "util/TextCache.h"
+#include "util/Logger.h"
 #include "mods/InstallChecker.h"
 #include "mods/InstalledScanner.h"
 #include "net/DownloadQueue.h"
@@ -38,6 +39,7 @@ void DetailScreen::handleInput(const Input& input) {
 
     if (m_confirmUninstall) {
         if (input.a) {
+            LOG_INFO("DetailScreen: confirm uninstall '%s'", m_mod.id.c_str());
             auto mods = InstalledScanner::scan();
             for (auto& inst : mods) {
                 if (inst.id == m_mod.id) {
@@ -47,7 +49,10 @@ void DetailScreen::handleInput(const Input& input) {
             }
             m_app->popScreen();
         }
-        if (input.b) m_confirmUninstall = false;
+        if (input.b) {
+            LOG_INFO("DetailScreen: cancel uninstall '%s'", m_mod.id.c_str());
+            m_confirmUninstall = false;
+        }
         return;
     }
 
@@ -58,18 +63,24 @@ void DetailScreen::handleInput(const Input& input) {
     if (!m_loaded) return;
 
     if (input.y && m_installStatus.installed) {
+        LOG_INFO("DetailScreen: prompt uninstall '%s'", m_mod.id.c_str());
         m_confirmUninstall = true;
         return;
     }
 
     if (input.a && !m_titleIds.empty()) {
-        if (m_installStatus.installed && !m_installStatus.updateAvail) return;
+        if (m_installStatus.installed && !m_installStatus.updateAvail) {
+            LOG_INFO("DetailScreen: A pressed but '%s' already installed at latest version", m_mod.id.c_str());
+            return;
+        }
         auto entries = InstallHelper::detectInstalled(m_titleIds);
         if (entries.size() == 1) {
+            LOG_INFO("DetailScreen: install '%s' to title %s", m_mod.id.c_str(), entries[0].id.c_str());
             AudioManager::get().playSound(SoundId::DownloadStart);
             DownloadQueue::get().enqueue(m_mod, entries[0].id);
             m_app->popScreen();
         } else {
+            LOG_INFO("DetailScreen: %zu title regions found, opening RegionSelect for '%s'", entries.size(), m_mod.id.c_str());
             m_app->pushScreen(std::make_unique<RegionSelectScreen>(
                 m_app, m_mod, entries));
         }