diff --git a/QuickView/CompositionEngine.cpp b/QuickView/CompositionEngine.cpp index 3745e25..c3e7923 100644 --- a/QuickView/CompositionEngine.cpp +++ b/QuickView/CompositionEngine.cpp @@ -1,5 +1,7 @@ #include "pch.h" #include "CompositionEngine.h" +#include "QuickViewETW.h" +#include "DebugMetrics.h" #include #include "TileManager.h" #include "TileTypes.h" @@ -537,7 +539,7 @@ bool CompositionEngine::RefreshDisplayColorState(bool forceHdrSimulation) { m_surfaceFormat = m_isAdvancedColor ? DXGI_FORMAT_R16G16B16A16_FLOAT : DXGI_FORMAT_B8G8R8A8_UNORM; if (m_isAdvancedColor) { - OutputDebugStringW(L"[HDR] Advanced color active on current monitor. Using FP16 scRGB composition surfaces.\n"); + QV_LOG("CompositionEngine_Log", TraceLoggingWideString(L"[HDR] Advanced color active on current monitor. Using FP16 scRGB composition surfaces.", "Message")); } return changed; diff --git a/QuickView/ComputeEngine.cpp b/QuickView/ComputeEngine.cpp index 09bb274..46ea483 100644 --- a/QuickView/ComputeEngine.cpp +++ b/QuickView/ComputeEngine.cpp @@ -1,4 +1,6 @@ #include "pch.h" +#include "QuickViewETW.h" +#include "DebugMetrics.h" #include "ComputeEngine.h" #include #include @@ -653,11 +655,11 @@ HRESULT ComputeEngine::ComposeGainMap( ID3D11Texture2D** outTexture) { if (!m_valid || !sdrPixels || !gainPixels || !outTexture) { - OutputDebugStringW(L"[ComputeEngine] ComposeGainMap: Invalid arguments or engine state.\n"); + QV_LOG("QuickView_GlobalLog", TraceLoggingWideString(L"[ComputeEngine] ComposeGainMap: Invalid arguments or engine state.", "Message")); return E_INVALIDARG; } if (sdrW <= 0 || sdrH <= 0 || gainW <= 0 || gainH <= 0) { - OutputDebugStringW(L"[ComputeEngine] ComposeGainMap: Invalid dimensions.\n"); + QV_LOG("QuickView_GlobalLog", TraceLoggingWideString(L"[ComputeEngine] ComposeGainMap: Invalid dimensions.", "Message")); return E_INVALIDARG; } @@ -665,7 +667,7 @@ HRESULT ComputeEngine::ComposeGainMap( wchar_t logBuf[256]; swprintf_s(logBuf, L"[ComputeEngine] Compose: SDR %dx%d, Gain %dx%d, Headroom %.2f, MaxGain %.2f\n", sdrW, sdrH, gainW, gainH, payload.targetHeadroom, payload.gainMapMax[0]); - OutputDebugStringW(logBuf); + QV_LOG("QuickView_GlobalLog", TraceLoggingWideString(logBuf, "Message")); // 1. Upload SDR base layer (Can be BGRA8 or R32G32B32A32_FLOAT) D3D11_TEXTURE2D_DESC sdrDesc = {}; diff --git a/QuickView/HeavyLanePool.cpp b/QuickView/HeavyLanePool.cpp index 0654764..6c20937 100644 --- a/QuickView/HeavyLanePool.cpp +++ b/QuickView/HeavyLanePool.cpp @@ -1,5 +1,7 @@ #include "pch.h" #include "HeavyLanePool.h" +#include "QuickViewETW.h" +#include "DebugMetrics.h" #include "ImageEngine.h" #include "ImageLoaderSimd.h" #include "TileManager.h" @@ -89,7 +91,7 @@ void HeavyLanePool::UpdateIOLimit(int newLimit) { wchar_t buf[128]; swprintf_s(buf, L"[HeavyPool] IO Limit set to %d (SSD=%s)\n", (int)m_ioLimit, newLimit > 2 ? L"Yes" : L"No"); - OutputDebugStringW(buf); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(buf, "Message")); } void HeavyLanePool::SetTitanMode(bool enabled, int srcW, int srcH, const std::wstring& format) { @@ -118,7 +120,7 @@ void HeavyLanePool::SetTitanMode(bool enabled, int srcW, int srcH, const std::ws wchar_t buf[256]; swprintf_s(buf, L"[HeavyPool] Baseline CACHE HIT: %.2f MP/s → %d threads (%dx%d)\n", it->second.mps, m_concurrencyLimit.load(), srcW, srcH); - OutputDebugStringW(buf); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(buf, "Message")); TryExpand(); return; @@ -148,7 +150,7 @@ void HeavyLanePool::SetConcurrencyLimit(int limit) { wchar_t buf[128]; swprintf_s(buf, L"[HeavyPool] Concurrency Limit set to %d\n", limit); - OutputDebugStringW(buf); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(buf, "Message")); } void HeavyLanePool::SetUseThreadLocalHandle(bool use) { @@ -210,7 +212,7 @@ void HeavyLanePool::ResetBenchState() { m_lodCacheFailCount.store(0); // [B4] Reset fail counter on new image // IO type is set during Submit() via UpdateIOLimit - OutputDebugStringW(L"[HeavyPool] Baseline state RESET (Phase 5 Async GC). Phase: PENDING (2 threads).\n"); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(L"[HeavyPool] Baseline state RESET (Phase 5 Async GC). Phase: PENDING (2 threads).", "Message")); } // [Baseline Benchmark] Record performance from base layer decode @@ -225,7 +227,7 @@ void HeavyLanePool::RecordBaselineSample(double outPixels, double decodeMs, int swprintf_s(buf, L"[HeavyPool] Baseline: %.2f MP/s (%.1f MP in %.0f ms, Src=%dx%d, %s)\n", decodeMPS, outPixels / 1000000.0, decodeMs, srcWidth, srcHeight, isProgressiveJPEG ? L"Progressive" : L"Baseline"); - OutputDebugStringW(buf); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(buf, "Message")); ApplyBaselineConcurrency(decodeMPS, srcWidth, srcHeight, isProgressiveJPEG); } @@ -316,7 +318,7 @@ void HeavyLanePool::ApplyBaselineConcurrency(double decodeMPS, int srcWidth, int (double)availableRAM / (1024.0 * 1024 * 1024), (double)perThreadMemory / (1024.0 * 1024 * 1024), srcWidth, srcHeight, memoryLimitThreads); - OutputDebugStringW(memBuf); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(memBuf, "Message")); } } @@ -336,7 +338,7 @@ void HeavyLanePool::ApplyBaselineConcurrency(double decodeMPS, int srcWidth, int wchar_t buf[256]; swprintf_s(buf, L"[HeavyPool] Baseline Result: %.2f MP/s → Cap %d threads. Starting at %d via Regulator.\n", decodeMPS, bestThreads, initialLimit); - OutputDebugStringW(buf); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(buf, "Message")); m_benchPhase = BenchPhase::DECIDED; SetConcurrencyLimit(initialLimit); @@ -394,7 +396,7 @@ void HeavyLanePool::UpdateConcurrency(int decodeMs, std::chrono::steady_clock::t wchar_t buf[256]; swprintf_s(buf, L"[HeavyPool] Regulator: Latency High (%.0fms). Throttle DOWN to %d\n", oldLatency, newLimit); - OutputDebugStringW(buf); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(buf, "Message")); } } } else if (m_regulator.avgLatency < kLowLatencyThreshold) { @@ -417,7 +419,7 @@ void HeavyLanePool::UpdateConcurrency(int decodeMs, std::chrono::steady_clock::t wchar_t buf[256]; swprintf_s(buf, L"[HeavyPool] Regulator: Latency Low (%.0fms). Throttle UP to %d\n", oldLatency, newLimit); - OutputDebugStringW(buf); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(buf, "Message")); } } } else { @@ -782,7 +784,7 @@ void HeavyLanePool::ResumeDeferredJobs(ImageID imageId, int lod) { wchar_t buf[256]; swprintf_s(buf, L"[HeavyPool] Phase 4.1: Resumed %zu deferred tiles for LOD=%d\n", toResume.size(), lod); - OutputDebugStringW(buf); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(buf, "Message")); } } @@ -791,7 +793,7 @@ void HeavyLanePool::WorkerLoop(int workerId, std::stop_token st) { wchar_t buf[128]; swprintf_s(buf, L"[HeavyPool] Worker %d started\n", workerId); - OutputDebugStringW(buf); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(buf, "Message")); while (!st.stop_requested()) { JobInfo job; @@ -1218,7 +1220,7 @@ void HeavyLanePool::PerformDecode(int workerId, const JobInfo& job, std::stop_to bool warmupResolved = false; if (expectsMasterCache && m_masterWarmupImageId.load(std::memory_order_acquire) == job.imageId) { - OutputDebugStringW(L"[Phase4] Standard Job Waiting for Master Warmup...\n"); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(L"[Phase4] Standard Job Waiting for Master Warmup...", "Message")); std::unique_lock waitLock(m_lodCacheMutex); while (!m_masterWarmupReady.load(std::memory_order_acquire)) { if (cancelPred()) { @@ -1259,13 +1261,13 @@ void HeavyLanePool::PerformDecode(int workerId, const JobInfo& job, std::stop_to loaderName = L"MasterWarmup(MMF)"; hr = S_OK; warmupResolved = true; - OutputDebugStringW(L"[Phase4] Standard Job resolved via Master Warmup\n"); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(L"[Phase4] Standard Job resolved via Master Warmup", "Message")); } } } if (!warmupResolved) { - OutputDebugStringW(L"[Phase3] Titan Base Layer -> DecodeWorker subprocess\n"); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(L"[Phase3] Titan Base Layer -> DecodeWorker subprocess", "Message")); hr = LaunchDecodeWorker(self, job, targetW, targetH, rawFrame, meta, cancelPred); if (SUCCEEDED(hr)) { loaderName = L"DecodeWorker"; @@ -1338,7 +1340,7 @@ void HeavyLanePool::PerformDecode(int workerId, const JobInfo& job, std::stop_to // This would cause the auto-regulator to maliciously throttle the pool to < 3 threads, // crippling our N+1 Native Region Decoding. We simulate 100 MP/s to unlock full core usage! if (loaderName.contains(L"Fake Base")) { - OutputDebugStringW(L"[HeavyPool] Base Layer is Fake. Simulating 100.0 MP/s baseline to unlock Titan tiles.\n"); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(L"[HeavyPool] Base Layer is Fake. Simulating 100.0 MP/s baseline to unlock Titan tiles.", "Message")); RecordBaselineSample(10000000.0, 100.0, srcWidth, srcHeight, isProgressiveJPEG); } else { RecordBaselineSample(outPixels, (double)benchMs, srcWidth, srcHeight, isProgressiveJPEG); @@ -1350,7 +1352,7 @@ void HeavyLanePool::PerformDecode(int workerId, const JobInfo& job, std::stop_to if (m_titanFormat.load() == QuickView::TitanFormat::JXL) { if (loaderName.contains(L"Prog DC")) { m_isProgressiveJXL = true; - OutputDebugStringW(L"[HeavyPool] Detected Progressive JXL. Enabling native Region Decoding!\n"); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(L"[HeavyPool] Detected Progressive JXL. Enabling native Region Decoding!", "Message")); } else { m_isProgressiveJXL = false; } @@ -1361,7 +1363,7 @@ void HeavyLanePool::PerformDecode(int workerId, const JobInfo& job, std::stop_to // [Fix] If Base Layer decode aborted (e.g. Gigapixel JXL too massive for CPU), // MUST unlock concurrency so Native Region Decoding can blast through tiles! // We simulate a fast decode (100MP/s) to unlock ~14 threads. - OutputDebugStringW(L"[HeavyPool] Base Layer failed. Simulating 100MP/s baseline to unlock Titan tiles.\n"); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(L"[HeavyPool] Base Layer failed. Simulating 100MP/s baseline to unlock Titan tiles.", "Message")); RecordBaselineSample(10000000.0, 100.0, 10000, 10000, false); } } @@ -1373,7 +1375,7 @@ void HeavyLanePool::PerformDecode(int workerId, const JobInfo& job, std::stop_to wchar_t diag[256]; swprintf_s(diag, L"[HeavyPool] DIAGNOSTIC: Decoding Tile (4,0) LOD=%d. Region: x=%d y=%d w=%d h=%d Scale=%.4f\n", job.tileCoord.lod, job.region.srcRect.x, job.region.srcRect.y, job.region.srcRect.w, job.region.srcRect.h, scale); - OutputDebugStringW(diag); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(diag, "Message")); } { @@ -1444,7 +1446,7 @@ void HeavyLanePool::PerformDecode(int workerId, const JobInfo& job, std::stop_to webpSingleDecode ? L"Y" : L"N", jpegProgressiveSingleDecode ? L"Y" : L"N", m_isProgressiveJXL ? L"Y" : L"N"); - OutputDebugStringW(strat); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(strat, "Message")); } } @@ -1618,7 +1620,7 @@ tile_decode_done: ; // [P14] Jump target for fast path (skip legacy TJ decode) : L"DECODE"; swprintf_s(resultLog, L"[HeavyPool] Worker %d: %s %s in %d ms (Wait: %lld ms, Concurrency: %d, Mode: %s, Loader: %s, hr=0x%08X)\n", workerId, SUCCEEDED(hr) ? L"DONE" : L"FAIL", (job.type == JobType::Tile ? L"Tile" : L"Std"), (int)decodeMs, waitMs, activeWorkers, opMode, loaderName.c_str(), (uint32_t)hr); - OutputDebugStringW(resultLog); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(resultLog, "Message")); @@ -1741,7 +1743,7 @@ tile_decode_done: ; // [P14] Jump target for fast path (skip legacy TJ decode) wchar_t buf[256]; swprintf_s(buf, L"[HeavyPool] Standard Job Done: W=%d H=%d Stride=%d Buffer=%zu Pixels=%p\n", safeFrame->width, safeFrame->height, safeFrame->stride, bufferSize, safeFrame->pixels); - OutputDebugStringW(buf); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(buf, "Message")); } // [Fix] Compute histogram for HeavyLane results @@ -1765,7 +1767,7 @@ tile_decode_done: ; // [P14] Jump target for fast path (skip legacy TJ decode) wchar_t failLog[128]; swprintf_s(failLog, L"[HeavyPool] Failed/Invalid Tile: (%d,%d) LOD=%d. HR=0x%X\n", job.tileCoord.col, job.tileCoord.row, job.tileCoord.lod, hr); - OutputDebugStringW(failLog); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(failLog, "Message")); } } else { // [HEIC Fix] Explicitly notify Engine of Standard Load Failures @@ -1933,7 +1935,7 @@ void HeavyLanePool::WaitForTileJobs() { int active = m_activeTileJobs.load(); if (active == 0) return; - OutputDebugStringW(L"[HeavyPool] WaitForTileJobs: Waiting for workers to finish...\n"); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(L"[HeavyPool] WaitForTileJobs: Waiting for workers to finish...", "Message")); // Spin-wait with timeout (to prevent total freeze if bug) auto start = std::chrono::steady_clock::now(); @@ -1942,7 +1944,7 @@ void HeavyLanePool::WaitForTileJobs() { auto now = std::chrono::steady_clock::now(); if (std::chrono::duration_cast(now - start).count() > 5000) { - OutputDebugStringW(L"[HeavyPool] WaitForTileJobs: TIMEOUT! Forced continue. (Possible Leak)\n"); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(L"[HeavyPool] WaitForTileJobs: TIMEOUT! Forced continue. (Possible Leak)", "Message")); break; } } @@ -2046,7 +2048,7 @@ void HeavyLanePool::EnsureMasterWarmup(const std::wstring& path, ImageID imageId int imgStride = imgW * 4; // BGRA packed if (imgW <= 0 || imgH <= 0) { - OutputDebugStringW(L"[MMF] Warmup aborted: unknown image dimensions\n"); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(L"[MMF] Warmup aborted: unknown image dimensions", "Message")); return; } @@ -2055,7 +2057,7 @@ void HeavyLanePool::EnsureMasterWarmup(const std::wstring& path, ImageID imageId if (FAILED(hr)) { wchar_t fail[192]; swprintf_s(fail, L"[MMF] Warmup: BuildMasterBackingStoreEmpty failed: hr=0x%X\n", hr); - OutputDebugStringW(fail); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(fail, "Message")); // Fallback to old heap-based path goto fallback_heap; } @@ -2103,7 +2105,7 @@ void HeavyLanePool::EnsureMasterWarmup(const std::wstring& path, ImageID imageId wchar_t ok[192]; swprintf_s(ok, L"[MMF] Master warmup direct-to-MMF ready: %dx%d (%s)\n", decW, decH, QuickView::TitanFormatToString(m_titanFormat.load())); - OutputDebugStringW(ok); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(ok, "Message")); m_masterWarmupReady.store(true, std::memory_order_release); m_lodCacheCond.notify_all(); @@ -2114,7 +2116,7 @@ void HeavyLanePool::EnsureMasterWarmup(const std::wstring& path, ImageID imageId fallback_heap: // Fallback: old heap-based FullDecodeFromMemory + BuildMasterBackingStore (memcpy) { - OutputDebugStringW(L"[MMF] Direct-to-MMF failed, fallback to heap decode\n"); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(L"[MMF] Direct-to-MMF failed, fallback to heap decode", "Message")); ResetMasterBackingStore(); // Clean up any partial empty MMF QuickView::RawImageFrame fullFrame; @@ -2145,7 +2147,7 @@ void HeavyLanePool::EnsureMasterWarmup(const std::wstring& path, ImageID imageId if (FAILED(hr) || !fullFrame.IsValid()) { wchar_t fail[192]; swprintf_s(fail, L"[HeavyPool] Master warmup failed: hr=0x%X (%s)\n", hr, QuickView::TitanFormatToString(m_titanFormat.load())); - OutputDebugStringW(fail); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(fail, "Message")); return; } @@ -2156,14 +2158,14 @@ void HeavyLanePool::EnsureMasterWarmup(const std::wstring& path, ImageID imageId wchar_t ok[192]; swprintf_s(ok, L"[HeavyPool] Master warmup ready (heap fallback): %dx%d (%s)\n", fullFrame.width, fullFrame.height, QuickView::TitanFormatToString(m_titanFormat.load())); - OutputDebugStringW(ok); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(ok, "Message")); m_masterWarmupReady.store(true, std::memory_order_release); m_lodCacheCond.notify_all(); } else { wchar_t fail[192]; swprintf_s(fail, L"[HeavyPool] Master warmup MMF build failed: hr=0x%X (%s)\n", hr, QuickView::TitanFormatToString(m_titanFormat.load())); - OutputDebugStringW(fail); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(fail, "Message")); } } }); @@ -2176,7 +2178,7 @@ void HeavyLanePool::EnsureMasterWarmup(const std::wstring& path, ImageID imageId void HeavyLanePool::GCThreadFunc(std::stop_token st) { // [Phase 5] Set low priority so GC never starves decode threads SetThreadPriority(GetCurrentThread(), THREAD_PRIORITY_BELOW_NORMAL); - OutputDebugStringW(L"[GC] Garbage Collector thread started (BELOW_NORMAL priority)\n"); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(L"[GC] Garbage Collector thread started (BELOW_NORMAL priority)", "Message")); std::vector localBatch; // Double-buffer: swap under lock, destroy outside lock @@ -2212,11 +2214,11 @@ void HeavyLanePool::GCThreadFunc(std::stop_token st) { wchar_t buf[128]; swprintf_s(buf, L"[GC] Collected %d bags in %d ms\n", count, ms); - OutputDebugStringW(buf); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(buf, "Message")); } } - OutputDebugStringW(L"[GC] Garbage Collector thread exiting\n"); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(L"[GC] Garbage Collector thread exiting", "Message")); } void HeavyLanePool::EnqueueTrash(TrashBag&& bag) { @@ -2247,7 +2249,7 @@ void HeavyLanePool::EnqueueTrash(TrashBag&& bag) { } } if (!localBatch.empty()) { - OutputDebugStringW(L"[GC] CRITICAL: Trash backlog exceeded threshold. Performing synchronous recovery.\n"); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(L"[GC] CRITICAL: Trash backlog exceeded threshold. Performing synchronous recovery.", "Message")); for (auto& bag : localBatch) { if (bag.backing.isPooled) { RelinquishToPool(std::move(bag.backing)); @@ -2281,9 +2283,9 @@ void HeavyLanePool::RelinquishToPool(MasterBackingStore&& store) { std::lock_guard lock(m_mmfPoolMutex); if (m_reservePool.size() < kMasterPoolCapacity) { m_reservePool.push_back(std::move(store)); - OutputDebugStringW(L"[MMFPool] Store returned to reserve pool (View kept mapped).\n"); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(L"[MMFPool] Store returned to reserve pool (View kept mapped).", "Message")); } else { - OutputDebugStringW(L"[MMFPool] Reserve pool full, destroying store.\n"); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(L"[MMFPool] Reserve pool full, destroying store.", "Message")); } } @@ -2423,7 +2425,7 @@ HRESULT HeavyLanePool::BuildMasterBackingStoreEmpty(int width, int height, int s swprintf_s(msg, L"[MMFPool] REUSE Blackboard SUCCESS (View=%p, Size=%zu MB, CachedView=%s)\n", m_masterBacking.view, requiredBytes / (1024*1024), m_masterBacking.view ? L"YES" : L"NO"); - OutputDebugStringW(msg); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(msg, "Message")); return S_OK; } } @@ -2449,7 +2451,7 @@ HRESULT HeavyLanePool::BuildMasterBackingStoreEmpty(int width, int height, int s DWORD dwTemp = 0; if (!DeviceIoControl(hFile, FSCTL_SET_SPARSE, NULL, 0, NULL, 0, &dwTemp, NULL)) { // Fallback to normal if sparse fails for some reason (e.g. non-NTFS) - OutputDebugStringW(L"[MMFPool] WARNING: FSCTL_SET_SPARSE failed.\n"); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(L"[MMFPool] WARNING: FSCTL_SET_SPARSE failed.", "Message")); } // Step 2: Set file size (instantaneous on sparse files) @@ -2462,7 +2464,7 @@ HRESULT HeavyLanePool::BuildMasterBackingStoreEmpty(int width, int height, int s } // SE_MANAGE_VOLUME_NAME / SetFileValidData logic removed (Simplified) - OutputDebugStringW(L"[MMFPool] Sparse Allocation initialized.\n"); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(L"[MMFPool] Sparse Allocation initialized.", "Message")); HANDLE hMap = CreateFileMappingW(hFile, nullptr, PAGE_READWRITE, 0, 0, nullptr); if (!hMap) { @@ -2500,7 +2502,7 @@ HRESULT HeavyLanePool::BuildMasterBackingStoreEmpty(int width, int height, int s wchar_t dbg[256]; swprintf_s(dbg, L"[MMFPool] Global Master created: %s, Capacity=%zu MB, Initial=%dx%d\n", usePool ? L"POOLED" : L"DYNAMIC", allocationSize / (1024*1024), width, height); - OutputDebugStringW(dbg); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(dbg, "Message")); return S_OK; } @@ -2581,7 +2583,7 @@ bool HeavyLanePool::ShouldUseSingleDecode(int lod) const { swprintf_s(buf, L"[HeavyPool] P14: LOD=%d fmt=%s OK (output=%zu MB, peak=%zu MB, avail=%zu MB)\n", lod, QuickView::TitanFormatToString(singleFmt), outputBytes / (1024*1024), peakBytes / (1024*1024), (size_t)(available / (1024*1024))); } - OutputDebugStringW(buf); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(buf, "Message")); } } @@ -2613,7 +2615,7 @@ bool HeavyLanePool::ShouldUseSingleDecodeForWebP(int lod) const { swprintf_s(buf, L"[HeavyPool] WebP SingleDecode Guard: LOD=%d req=%.1fMB avail=%.1fMB limit=%.1fMB -> %s\n", lod, requiredRamMB, availableRamMB, availableRamMB * 0.40, canSingleDecode ? L"Y" : L"N"); - OutputDebugStringW(buf); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(buf, "Message")); } return canSingleDecode; @@ -2707,7 +2709,7 @@ HRESULT HeavyLanePool::LaunchDecodeWorker( WaitForSingleObject(worker.activeWorkerProcess, 500); CloseHandle(worker.activeWorkerProcess); worker.activeWorkerProcess = nullptr; - OutputDebugStringW(L"[Phase4] Killed lingering old DecodeWorker\n"); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(L"[Phase4] Killed lingering old DecodeWorker", "Message")); } STARTUPINFOW si{}; @@ -2732,7 +2734,7 @@ HRESULT HeavyLanePool::LaunchDecodeWorker( // [Phase 4.1] Double check cancel immediately AFTER creating process if (checkCancel && checkCancel()) { - OutputDebugStringW(L"[Phase4.1] Instantly killed new DecodeWorker due to cancel\n"); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(L"[Phase4.1] Instantly killed new DecodeWorker due to cancel", "Message")); TerminateProcess(pi.hProcess, static_cast(E_ABORT)); // We let the wait loop handle cleanup } @@ -2749,7 +2751,7 @@ HRESULT HeavyLanePool::LaunchDecodeWorker( wchar_t dbg[256]; swprintf_s(dbg, L"[Phase4] DecodeWorker launched: PID=%lu target=%dx%d\n", pi.dwProcessId, targetW, targetH); - OutputDebugStringW(dbg); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(dbg, "Message")); } // Poll loop: 15ms intervals, check for cancellation @@ -2761,7 +2763,7 @@ HRESULT HeavyLanePool::LaunchDecodeWorker( if (waitRes == WAIT_TIMEOUT) { if (checkCancel && checkCancel()) { - OutputDebugStringW(L"[Phase3] DecodeWorker KILLED by cancel\n"); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(L"[Phase3] DecodeWorker KILLED by cancel", "Message")); TerminateProcess(pi.hProcess, static_cast(E_ABORT)); WaitForSingleObject(pi.hProcess, 1000); waitHr = E_ABORT; @@ -2841,7 +2843,7 @@ HRESULT HeavyLanePool::LaunchDecodeWorker( wchar_t dbg[256]; swprintf_s(dbg, L"[Phase4] DecodeWorker OK (ZeroCopy): %dx%d stride=%d exif=%d\n", outFrame.width, outFrame.height, outFrame.stride, header->exifOrientation); - OutputDebugStringW(dbg); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(dbg, "Message")); } return S_OK; @@ -2891,7 +2893,7 @@ HRESULT HeavyLanePool::FullDecodeAndCacheLOD(Worker& worker, const JobInfo& job, wchar_t buf[256]; swprintf_s(buf, L"[HeavyPool] P14: Full decode LOD=%d (scale=%.4f, src=%dx%d)...\n", lod, scale, m_titanSrcW, m_titanSrcH); - OutputDebugStringW(buf); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(buf, "Message")); auto t0 = std::chrono::high_resolution_clock::now(); @@ -2955,7 +2957,7 @@ HRESULT HeavyLanePool::FullDecodeAndCacheLOD(Worker& worker, const JobInfo& job, wchar_t dbg[128]; swprintf_s(dbg, L"[P15] Master built + Instant software downscale → %dx%d (LOD=%d)\n", targetW, targetH, lod); - OutputDebugStringW(dbg); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(dbg, "Message")); } } else { if (masterFromRam) { @@ -2967,7 +2969,7 @@ HRESULT HeavyLanePool::FullDecodeAndCacheLOD(Worker& worker, const JobInfo& job, fullFrame.format = QuickView::PixelFormat::BGRA8888; fullFrame.memoryDeleter = [masterPixels](uint8_t* p) mutable { masterPixels.reset(); }; hr = S_OK; - OutputDebugStringW(L"[P15] Master built + Instant Zero-Copy for LOD 0\n"); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(L"[P15] Master built + Instant Zero-Copy for LOD 0", "Message")); } else { // MMF-backed cache: keep stable ownership by copying out for this one request. size_t dstSize = dstStride * targetH; @@ -2987,7 +2989,7 @@ HRESULT HeavyLanePool::FullDecodeAndCacheLOD(Worker& worker, const JobInfo& job, fullFrame.format = QuickView::PixelFormat::BGRA8888; fullFrame.memoryDeleter = [](uint8_t* p) { _aligned_free(p); }; hr = S_OK; - OutputDebugStringW(L"[P15] Master MMF + Copy-out for LOD 0\n"); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(L"[P15] Master MMF + Copy-out for LOD 0", "Message")); } } } @@ -3001,7 +3003,7 @@ HRESULT HeavyLanePool::FullDecodeAndCacheLOD(Worker& worker, const JobInfo& job, if (expectsMasterCache && m_masterWarmupImageId.load(std::memory_order_acquire) == job.imageId) { // Warmup is building the Master Cache — wait for it - OutputDebugStringW(L"[Phase4] Waiting for Master Warmup (Direct-to-MMF) instead of launching subprocess...\n"); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(L"[Phase4] Waiting for Master Warmup (Direct-to-MMF) instead of launching subprocess...", "Message")); std::unique_lock waitLock(m_lodCacheMutex); while (!m_masterWarmupReady.load(std::memory_order_acquire)) { @@ -3013,7 +3015,7 @@ HRESULT HeavyLanePool::FullDecodeAndCacheLOD(Worker& worker, const JobInfo& job, // Check if image changed while waiting if (m_masterWarmupImageId.load(std::memory_order_acquire) != job.imageId) { - OutputDebugStringW(L"[Phase4] Warmup image changed while waiting, aborting\n"); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(L"[Phase4] Warmup image changed while waiting, aborting", "Message")); guard.countFailure = false; return E_ABORT; } @@ -3051,12 +3053,12 @@ HRESULT HeavyLanePool::FullDecodeAndCacheLOD(Worker& worker, const JobInfo& job, wchar_t dbg[128]; swprintf_s(dbg, L"[P15] Master built + Software downscale → %dx%d (LOD=%d)\n", targetW, targetH, lod); - OutputDebugStringW(dbg); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(dbg, "Message")); } else { hr = E_OUTOFMEMORY; } } else { - OutputDebugStringW(L"[Phase4] Warmup completed but no Master Cache available — fallback to subprocess\n"); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(L"[Phase4] Warmup completed but no Master Cache available — fallback to subprocess", "Message")); hr = E_FAIL; // Will fall through to subprocess below } if (SUCCEEDED(hr)) warmupResolved = true; @@ -3072,7 +3074,7 @@ HRESULT HeavyLanePool::FullDecodeAndCacheLOD(Worker& worker, const JobInfo& job, if (!expectsMasterCache) { reqW = targetW; reqH = targetH; - OutputDebugStringW(L"[Phase4] Skipping Master cache construction. Requesting LOD size directly from DecodeWorker.\n"); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(L"[Phase4] Skipping Master cache construction. Requesting LOD size directly from DecodeWorker.", "Message")); } CImageLoader::ImageMetadata lodMeta; @@ -3100,7 +3102,7 @@ HRESULT HeavyLanePool::FullDecodeAndCacheLOD(Worker& worker, const JobInfo& job, hr = m_loader->LoadToFrame(job.path.c_str(), &fullFrame, nullptr, targetW, targetH, &loader, checkCancel, nullptr, true, false, job.targetHdrHeadroomStops); if (SUCCEEDED(hr)) { loader = L"WIC(LOD-Fallback)"; - OutputDebugStringW(L"[Phase4] Inline WIC fallback succeeded\n"); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(L"[Phase4] Inline WIC fallback succeeded", "Message")); } } @@ -3128,7 +3130,7 @@ HRESULT HeavyLanePool::FullDecodeAndCacheLOD(Worker& worker, const JobInfo& job, if (shouldBuildBacking) { if (SUCCEEDED(BuildMasterBackingStore(frameSharedPtr.get(), fullFrame.width, fullFrame.height, fullFrame.stride, job.imageId))) { backedByMmf = true; - OutputDebugStringW(L"[Phase4] Master cache persisted to MMF backing store\n"); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(L"[Phase4] Master cache persisted to MMF backing store", "Message")); } } @@ -3167,7 +3169,7 @@ HRESULT HeavyLanePool::FullDecodeAndCacheLOD(Worker& worker, const JobInfo& job, wchar_t dbg[128]; swprintf_s(dbg, L"[P15] Master built + Software downscale → %dx%d (LOD=%d)\n", targetW, targetH, lod); - OutputDebugStringW(dbg); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(dbg, "Message")); } } else { fullFrame.pixels = frameSharedPtr.get(); @@ -3176,7 +3178,7 @@ HRESULT HeavyLanePool::FullDecodeAndCacheLOD(Worker& worker, const JobInfo& job, fullFrame.stride = (int)dstStride; fullFrame.memoryDeleter = [frameSharedPtr](uint8_t* p) mutable { frameSharedPtr.reset(); }; - OutputDebugStringW(L"[P15] Master built + Zero-Copy for LOD 0\n"); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(L"[P15] Master built + Zero-Copy for LOD 0", "Message")); } } else { // [Direct LOD] Bypassed Master Cache. Subprocess already returned exact LOD target size. @@ -3188,7 +3190,7 @@ HRESULT HeavyLanePool::FullDecodeAndCacheLOD(Worker& worker, const JobInfo& job, wchar_t dbg[128]; swprintf_s(dbg, L"[Phase4] Subprocess rendered directly to LOD size: %dx%d. Applied instantly.\n", fullFrame.width, fullFrame.height); - OutputDebugStringW(dbg); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(dbg, "Message")); } } } @@ -3201,7 +3203,7 @@ HRESULT HeavyLanePool::FullDecodeAndCacheLOD(Worker& worker, const JobInfo& job, if (FAILED(hr) || !fullFrame.IsValid()) { swprintf_s(buf, L"[HeavyPool] P14: Full decode FAILED (hr=0x%X)\n", hr); - OutputDebugStringW(buf); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(buf, "Message")); return hr; } @@ -3214,7 +3216,7 @@ HRESULT HeavyLanePool::FullDecodeAndCacheLOD(Worker& worker, const JobInfo& job, swprintf_s(buf, L"[HeavyPool] P14: Full decode INVALID size %dx%d (< expected %dx%d). Rejecting cache.\n", fullFrame.width, fullFrame.height, expectedW, expectedH); - OutputDebugStringW(buf); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(buf, "Message")); return E_FAIL; } @@ -3223,7 +3225,7 @@ HRESULT HeavyLanePool::FullDecodeAndCacheLOD(Worker& worker, const JobInfo& job, swprintf_s(buf, L"[HeavyPool] P14: Full decode DONE in %d ms → %dx%d (%zu MB cached)\n", decodeMs, fullFrame.width, fullFrame.height, fullFrame.GetBufferSize() / (1024*1024)); - OutputDebugStringW(buf); + QV_LOG("HeavyLanePool_Log", TraceLoggingWideString(buf, "Message")); // Cache the full decoded buffer { diff --git a/QuickView/ImageEngine.cpp b/QuickView/ImageEngine.cpp index 0926f1b..6f0622e 100644 --- a/QuickView/ImageEngine.cpp +++ b/QuickView/ImageEngine.cpp @@ -1,5 +1,7 @@ #include "pch.h" #include "ImageEngine.h" +#include "QuickViewETW.h" +#include "DebugMetrics.h" #include "FileNavigator.h" #include "HeavyLanePool.h" // [N+1] Include pool implementation #include "EditState.h" // [v9.9] Access g_runtime.ForceRawDecode for dispatch decisions @@ -45,7 +47,7 @@ ImageEngine::ImageEngine(CImageLoader* loader) m_engineConfig.GetTierName(), m_pool.GetConfig().GetModeName(), m_engineConfig.maxHeavyWorkers); - OutputDebugStringW(buf); + QV_LOG("ImageEngine_Log", TraceLoggingWideString(buf, "Message")); } ImageEngine::~ImageEngine() { @@ -94,13 +96,19 @@ void ImageEngine::SetTargetHdrHeadroomStops(float stops) { } // Request full resolution decode for current image (used by JXL serial pipeline) -void ImageEngine::RequestFullDecode(const std::wstring& path, ImageID imageId) { +void ImageEngine::RequestFullDecode( + // Node B: Decoding Complete / Request Full Decode + QV_LOG("ImageEngine_FullDecode", + TraceLoggingInt32(g_debugMetrics.lastUploadChannel.load(), "LastUploadChannel"), + TraceLoggingInt32(g_debugMetrics.rawFrameUploadCount.load(), "RawUploadCount") + ); +const std::wstring& path, ImageID imageId) { if (path.empty()) return; if (!m_heavyPool) return; // Only proceed if this is still the current image if (imageId != m_currentImageId.load()) { - OutputDebugStringW(L"[FullDecode] RequestFullDecode cancelled - image changed\n"); + QV_LOG("ImageEngine_Log", TraceLoggingWideString(L"[FullDecode] RequestFullDecode cancelled - image changed", "Message")); return; } @@ -108,7 +116,7 @@ void ImageEngine::RequestFullDecode(const std::wstring& path, ImageID imageId) { // The Base Layer is already loaded (Scaled). We do NOT want a Full Decode // because it causes OOM/Seconds-long stall and logic issue. if (m_mmf && m_mmf->IsValid()) { - OutputDebugStringW(L"[FullDecode] RequestFullDecode skipped - Titan Mode Active (Tiles Handle Detail)\n"); + QV_LOG("ImageEngine_Log", TraceLoggingWideString(L"[FullDecode] RequestFullDecode skipped - Titan Mode Active (Tiles Handle Detail)", "Message")); return; } @@ -120,7 +128,7 @@ void ImageEngine::RequestFullDecode(const std::wstring& path, ImageID imageId) { wchar_t buf[256]; swprintf_s(buf, L"[FullDecode] Full decode requested: ImageID=%zu\n", imageId); - OutputDebugStringW(buf); + QV_LOG("ImageEngine_Log", TraceLoggingWideString(buf, "Message")); } // [Phase 2] Dispatcher Implementation @@ -198,7 +206,7 @@ void ImageEngine::DispatchImageLoad(const std::wstring& path, ImageID imageId, u swprintf_s(debugBuf, L"[Dispatch] Titan Mode ENABLED (%dx%d, %s) MMF=%s\n", info.width, info.height, fmtUpper.c_str(), (m_mmf && m_mmf->IsValid()) ? L"OK" : L"FAIL"); - OutputDebugStringW(debugBuf); + QV_LOG("ImageEngine_Log", TraceLoggingWideString(debugBuf, "Message")); // [Scientific 2.0] Enable Titan Mode - pool handles dynamic concurrency via Scout phase. // SetTitanMode(true) resets scout state, sets initial concurrency to 2, @@ -252,7 +260,7 @@ void ImageEngine::DispatchImageLoad(const std::wstring& path, ImageID imageId, u L"[Dispatch] JXL cache bypass: frame=%dx%d meta=%dx%d titan=%d\n", cacheW, cacheH, info.width, info.height, enableTitan ? 1 : 0); - OutputDebugStringW(dbg); + QV_LOG("ImageEngine_Log", TraceLoggingWideString(dbg, "Message")); } } @@ -325,7 +333,7 @@ void ImageEngine::DispatchImageLoad(const std::wstring& path, ImageID imageId, u (double)(info.width * info.height) / 1000000.0, info.format.c_str(), typeName); - OutputDebugStringW(buf); + QV_LOG("ImageEngine_Log", TraceLoggingWideString(buf, "Message")); } // Update State for UI @@ -344,7 +352,7 @@ void ImageEngine::DispatchImageLoad(const std::wstring& path, ImageID imageId, u // IDCT 1/8 scaling produces ~3-8MP preview (sufficient for 4K screens). // Tiles are triggered by main.cpp OnPaint only when zoom > basePreviewRatio. - OutputDebugStringW(L"[Dispatch] Titan Active: Routing Base Layer to Heavy Lane\n"); + QV_LOG("ImageEngine_Log", TraceLoggingWideString(L"[Dispatch] Titan Active: Routing Base Layer to Heavy Lane", "Message")); } // 2. Recursive RAW Check @@ -368,7 +376,7 @@ void ImageEngine::DispatchImageLoad(const std::wstring& path, ImageID imageId, u // Threshold: 2.5 MP (Conservative) // If embedded preview is huge, it will block FastLane. Force Heavy Lane. if (embPixels > 2500000) { - OutputDebugStringW(L"[Dispatch] RAW Embedded Preview TOO LARGE -> Force Heavy Lane\n"); + QV_LOG("ImageEngine_Log", TraceLoggingWideString(L"[Dispatch] RAW Embedded Preview TOO LARGE -> Force Heavy Lane", "Message")); // Override Classification: Treat as Heavy info.type = CImageLoader::ImageType::TypeB_Heavy; } @@ -398,7 +406,7 @@ void ImageEngine::DispatchImageLoad(const std::wstring& path, ImageID imageId, u useHeavy = false; } else { // [v7.2 Fix] Large WebP -> Force Heavy Direct (non-Titan is full decode). - OutputDebugStringW(L"[Dispatch] -> WebP Large: Heavy Direct\n"); + QV_LOG("ImageEngine_Log", TraceLoggingWideString(L"[Dispatch] -> WebP Large: Heavy Direct", "Message")); m_heavyPool->Submit(path, imageId, primaryMMF); return; } @@ -413,7 +421,7 @@ void ImageEngine::DispatchImageLoad(const std::wstring& path, ImageID imageId, u std::transform(fmtLower.begin(), fmtLower.end(), fmtLower.begin(), ::towlower); if (fmtLower == L"webp") { - OutputDebugStringW(L"[Dispatch] -> WebP Heavy: Heavy Direct\n"); + QV_LOG("ImageEngine_Log", TraceLoggingWideString(L"[Dispatch] -> WebP Heavy: Heavy Direct", "Message")); m_heavyPool->Submit(path, imageId, primaryMMF); // Base Layer Scaled return; } @@ -435,7 +443,7 @@ void ImageEngine::DispatchImageLoad(const std::wstring& path, ImageID imageId, u ((uint64_t)info.width * info.height < 2000000); if (isSmall) { - OutputDebugStringW(L"[Dispatch] -> JXL Small: FastLane Direct Full\n"); + QV_LOG("ImageEngine_Log", TraceLoggingWideString(L"[Dispatch] -> JXL Small: FastLane Direct Full", "Message")); // FastLane will use target=0 if detected as small m_fastLane.Push(path, imageId, m_targetHdrHeadroomStops.load(std::memory_order_relaxed)); } @@ -443,7 +451,7 @@ void ImageEngine::DispatchImageLoad(const std::wstring& path, ImageID imageId, u if (enableTitan) { // [v8.5] Hard Dispatch: Large JXL (>2MP or >3MB) // Skip FastLane entirely. HeavyLane handles everything (Deep Cancel Relay). - OutputDebugStringW(L"[Dispatch] -> JXL Titan: Heavy Direct (Skip FastLane)\n"); + QV_LOG("ImageEngine_Log", TraceLoggingWideString(L"[Dispatch] -> JXL Titan: Heavy Direct (Skip FastLane)", "Message")); // [Fix] Stage 2 Trigger explicitly needs these to be set for the pending heavy decode m_pendingJxlHeavyPath = path; @@ -453,7 +461,7 @@ void ImageEngine::DispatchImageLoad(const std::wstring& path, ImageID imageId, u } else { // [v3.2.5 Restore] 普通非Titan大型大图,像旧版一样直接跑 FullDecode // 免去 300ms 延迟,速度最快,并天然由解码端展示自带预览图! - OutputDebugStringW(L"[Dispatch] -> JXL Large: Heavy SubmitFullDecode (Skip FastLane)\n"); + QV_LOG("ImageEngine_Log", TraceLoggingWideString(L"[Dispatch] -> JXL Large: Heavy SubmitFullDecode (Skip FastLane)", "Message")); m_heavyPool->SubmitFullDecode(path, imageId, primaryMMF); } } @@ -504,12 +512,12 @@ void ImageEngine::DispatchImageLoad(const std::wstring& path, ImageID imageId, u if (isSmall) { wchar_t dbgBuf[128]; swprintf_s(dbgBuf, L"[Dispatch] -> %s Small (<30ms): FastLane\n", info.format.c_str()); - OutputDebugStringW(dbgBuf); + QV_LOG("ImageEngine_Log", TraceLoggingWideString(dbgBuf, "Message")); m_fastLane.Push(path, imageId, m_targetHdrHeadroomStops.load(std::memory_order_relaxed)); } else { wchar_t dbgBuf[128]; swprintf_s(dbgBuf, L"[Dispatch] -> %s Large: Heavy Lane\n", info.format.c_str()); - OutputDebugStringW(dbgBuf); + QV_LOG("ImageEngine_Log", TraceLoggingWideString(dbgBuf, "Message")); m_heavyPool->Submit(path, imageId, primaryMMF); } return; @@ -517,14 +525,14 @@ void ImageEngine::DispatchImageLoad(const std::wstring& path, ImageID imageId, u // 7. Standard Routing if (useHeavy) { - OutputDebugStringW(L"[Dispatch] -> Heavy Lane\n"); + QV_LOG("ImageEngine_Log", TraceLoggingWideString(L"[Dispatch] -> Heavy Lane", "Message")); m_heavyPool->Submit(path, imageId, primaryMMF); } if (useFastLane) { // Avoid parallel duplicate work if Heavy is already taking it? // Logic: TypeA -> FastLane only. TypeB -> Heavy only. // Unknown type -> Parallel (Both). - OutputDebugStringW(L"[Dispatch] -> FastLane\n"); + QV_LOG("ImageEngine_Log", TraceLoggingWideString(L"[Dispatch] -> FastLane", "Message")); m_fastLane.Push(path, imageId, m_targetHdrHeadroomStops.load(std::memory_order_relaxed)); } } @@ -631,7 +639,7 @@ std::vector ImageEngine::PollState() { // [JXL Serial] Trigger Stage 2 IMMEDIATELY for JXL (No 300ms wait) if (m_pendingJxlHeavyId == e.imageId && m_pendingJxlHeavyId != 0) { - OutputDebugStringW(L"[PollState] JXL Preview Ready -> Triggering Heavy Immediate\n"); + QV_LOG("ImageEngine_Log", TraceLoggingWideString(L"[PollState] JXL Preview Ready -> Triggering Heavy Immediate", "Message")); RequestFullDecode(m_pendingJxlHeavyPath, m_pendingJxlHeavyId); m_stage2Requested = true; m_pendingJxlHeavyId = 0; @@ -646,7 +654,7 @@ std::vector ImageEngine::PollState() { // [JXL Scene C] FastLane Aborted (Modular?) -> Trigger Heavy Immediately if (m_pendingJxlHeavyId == e.imageId && m_pendingJxlHeavyId != 0) { - OutputDebugStringW(L"[PollState] FastLane Failed (Modular?) -> Triggering Heavy Immediate\n"); + QV_LOG("ImageEngine_Log", TraceLoggingWideString(L"[PollState] FastLane Failed (Modular?) -> Triggering Heavy Immediate", "Message")); RequestFullDecode(m_pendingJxlHeavyPath, m_pendingJxlHeavyId); m_stage2Requested = true; // Mark as requested m_pendingJxlHeavyId = 0; // Consumed @@ -667,7 +675,7 @@ std::vector ImageEngine::PollState() { if (isHevcDependent && CImageLoader::ImageMetadata::IsWicCodecMissing(e.hr)) { wchar_t dbg[128]; swprintf_s(dbg, L"[ImageEngine] Detected missing HEVC codec: 0x%08X for format %s. Prompting user.\n", (uint32_t)e.hr, formatUpper.c_str()); - OutputDebugStringW(dbg); + QV_LOG("ImageEngine_Log", TraceLoggingWideString(dbg, "Message")); PostMessage(m_hwnd, WM_APP + 99, 0, 0); } std::lock_guard lock(m_pendingMutex); @@ -992,7 +1000,7 @@ void ImageEngine::FastLane::Push(const std::wstring& path, ImageID id, float tar wchar_t buf[512]; swprintf_s(buf, L"[FastLane] Push: %s (queue size=%d)\n", path.substr(path.find_last_of(L"\\/") + 1).c_str(), (int)m_queue.size()); - OutputDebugStringW(buf); + QV_LOG("ImageEngine_Log", TraceLoggingWideString(buf, "Message")); } // [Phase 10] Reset timer logic @@ -1032,7 +1040,7 @@ int ImageEngine::FastLane::GetResultsSize() const { } void ImageEngine::FastLane::QueueWorker() { - OutputDebugStringW(L"[FastLane] Worker Thread Started\n"); + QV_LOG("ImageEngine_Log", TraceLoggingWideString(L"[FastLane] Worker Thread Started", "Message")); while (!m_stopSignal) { FastLaneCommand cmd; @@ -1056,7 +1064,7 @@ void ImageEngine::FastLane::QueueWorker() { m_isWorking = true; // [HUD V4] Active std::wstring debugMsg = L"[FastLane] Processing: " + cmd.path.substr(cmd.path.find_last_of(L"\\/") + 1) + L"\n"; - OutputDebugStringW(debugMsg.c_str()); + QV_LOG("ImageEngine_Log", TraceLoggingWideString(debugMsg.c_str(), "Message")); // --- Work Stage (Unified RawImageFrame Architecture) --- auto start = std::chrono::high_resolution_clock::now(); @@ -1201,8 +1209,8 @@ void ImageEngine::FastLane::QueueWorker() { // Signal main thread m_parent->QueueEvent(EngineEvent{}); // Dummy event, just for notification - if (isClear) OutputDebugStringW(L"[FastLane] Output: FullReady (Final)\n"); - else { wchar_t buf[128]; swprintf_s(buf, L"[FastLane] Output: PreviewReady (Blurry) - targetW=%d, rawW=%d\n", targetW, rawFrame.width); OutputDebugStringW(buf); } + if (isClear) QV_LOG("ImageEngine_Log", TraceLoggingWideString(L"[FastLane] Output: FullReady (Final)", "Message")); + else { wchar_t buf[128]; swprintf_s(buf, L"[FastLane] Output: PreviewReady (Blurry) - targetW=%d, rawW=%d\n", targetW, rawFrame.width); QV_LOG("ImageEngine_Log", TraceLoggingWideString(buf, "Message")); } // [v3.1] If Fast Pass produced clear image, cancel Heavy Lane if (isClear) { @@ -1237,14 +1245,14 @@ void ImageEngine::FastLane::QueueWorker() { } catch (const std::exception& ex) { m_isWorking = false; // [HUD V4] Safety reset - OutputDebugStringW(L"[FastLane] CRITICAL EXCEPTION in QueueWorker: "); + QV_LOG("ImageEngine_Log", TraceLoggingWideString(L"[FastLane] CRITICAL EXCEPTION in QueueWorker: ", "Message")); OutputDebugStringA(ex.what()); - OutputDebugStringW(L"\n"); + QV_LOG("ImageEngine_Log", TraceLoggingWideString(L"", "Message")); } catch (...) { - OutputDebugStringW(L"[FastLane] CRITICAL UNKNOWN EXCEPTION in QueueWorker\n"); + QV_LOG("ImageEngine_Log", TraceLoggingWideString(L"[FastLane] CRITICAL UNKNOWN EXCEPTION in QueueWorker", "Message")); } } - OutputDebugStringW(L"[FastLane] Worker Thread Exiting\n"); + QV_LOG("ImageEngine_Log", TraceLoggingWideString(L"[FastLane] Worker Thread Exiting", "Message")); } void ImageEngine::SetPrefetchPolicy(const PrefetchPolicy& policy) { @@ -1253,7 +1261,7 @@ void ImageEngine::SetPrefetchPolicy(const PrefetchPolicy& policy) { void ImageEngine::TriggerPendingJxlHeavy() { if (!m_pendingJxlHeavyPath.empty() && m_pendingJxlHeavyId != 0) { - OutputDebugStringW(L"[JXL Sequential] FastLane done, triggering Heavy\n"); + QV_LOG("ImageEngine_Log", TraceLoggingWideString(L"[JXL Sequential] FastLane done, triggering Heavy", "Message")); m_heavyPool->Submit(m_pendingJxlHeavyPath, m_pendingJxlHeavyId); m_pendingJxlHeavyPath.clear(); m_pendingJxlHeavyId = 0; @@ -1288,7 +1296,7 @@ void ImageEngine::UpdateView(int currentIndex, QuickView::BrowseDirection dir) { wchar_t buf[128]; swprintf_s(buf, L"[ImageEngine] UpdateView: Idx=%d Dir=%d\n", currentIndex, dirInt); - OutputDebugStringW(buf); + QV_LOG("ImageEngine_Log", TraceLoggingWideString(buf, "Message")); // 1. Prune: Cancel old tasks not in visible range PruneQueue(currentIndex, dir); @@ -1378,7 +1386,7 @@ void ImageEngine::ScheduleJob(int index, QuickView::Priority pri) { path.substr(path.find_last_of(L"\\/") + 1).c_str(), predictedSize / 1048576.0, m_prefetchPolicy.maxCacheMemory / 1048576.0); - OutputDebugStringW(skipBuf); + QV_LOG("ImageEngine_Log", TraceLoggingWideString(skipBuf, "Message")); return; } } @@ -1642,7 +1650,7 @@ void ImageEngine::RequestFullMetadata() { tempLoader.Initialize(pFactory.Get()); factoryOk = true; } else { - OutputDebugStringW(L"[ImageEngine] Failed to create WIC Factory for async metadata!\n"); + QV_LOG("ImageEngine_Log", TraceLoggingWideString(L"[ImageEngine] Failed to create WIC Factory for async metadata!", "Message")); } } @@ -1672,7 +1680,7 @@ void ImageEngine::RequestFullMetadata() { if (SUCCEEDED(hr)) CoUninitialize(); } catch (...) { - OutputDebugStringW(L"[ImageEngine] Critical Exception in Async Metadata Thread!\n"); + QV_LOG("ImageEngine_Log", TraceLoggingWideString(L"[ImageEngine] Critical Exception in Async Metadata Thread!", "Message")); } // Destructor of 'cleaner' runs here, removing ID from pending set. diff --git a/QuickView/ImageLoader.cpp b/QuickView/ImageLoader.cpp index a4ef125..6e47dd9 100644 --- a/QuickView/ImageLoader.cpp +++ b/QuickView/ImageLoader.cpp @@ -8,6 +8,8 @@ #include #include "ImageLoader.h" +#include "QuickViewETW.h" +#include "DebugMetrics.h" #include "AnimationDecoder.h" #include "MemoryArena.h" // [Fix] Include for QuantumArena definition #include "EditState.h" // For g_runtime @@ -201,7 +203,7 @@ static void FindHeifGainMapManual(const uint8_t* data, size_t size, uint64_t* ou { wchar_t dbg[128]; swprintf_s(dbg, L"[Scanner] Found %d auxl candidates (infe=%u)\n", auxlCount, infeItemID); - OutputDebugStringW(dbg); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(dbg, "Message")); } // iloc resolver: returns offset+length for a given itemID @@ -288,7 +290,7 @@ static void FindHeifGainMapManual(const uint8_t* data, size_t size, uint64_t* ou wchar_t sdbg[256]; swprintf_s(sdbg, L"[Scanner] SOLVED! ItemID %u -> Offset %llu, Length %llu. PitmOff=%u PitmSize=%u\n", bestID, bestOff, bestLen, outPitmOffset ? *outPitmOffset : 0, outPitmSize ? *outPitmSize : 0); - OutputDebugStringW(sdbg); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(sdbg, "Message")); } } @@ -333,7 +335,7 @@ static void ProbeHdrMetadataNative(LPCWSTR filePath, QuickView::HdrStaticMetadat // Default headroom: 1.5 stops (Apple standard when no explicit tag found) if (pHdr->gainMapAlternateHeadroom <= 0.0f) pHdr->gainMapAlternateHeadroom = 1.5f; - OutputDebugStringW(L"[Metadata] Apple HDR Gain Map detected.\n"); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(L"[Metadata] Apple HDR Gain Map detected.", "Message")); break; } } @@ -350,7 +352,7 @@ void* CImageLoader::GetJxlRunner() { size_t threads = std::thread::hardware_concurrency(); if (threads == 0) threads = 4; s_jxlRunner = JxlThreadParallelRunnerCreate(NULL, threads); - OutputDebugStringW(L"[JXL] Global ThreadRunner created\n"); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(L"[JXL] Global ThreadRunner created", "Message")); } return s_jxlRunner; } @@ -360,7 +362,7 @@ void CImageLoader::ReleaseJxlRunner() { if (s_jxlRunner) { JxlThreadParallelRunnerDestroy(s_jxlRunner); s_jxlRunner = nullptr; - OutputDebugStringW(L"[JXL] Global ThreadRunner destroyed\n"); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(L"[JXL] Global ThreadRunner destroyed", "Message")); } } @@ -2003,7 +2005,7 @@ static HRESULT SafeLoadJpegRegion( return LoadJpegRegion_V3(data, size, rect, scale, out, tileManager, arena, explicitTargetW, explicitTargetH); } __except (GetExceptionCode() == EXCEPTION_IN_PAGE_ERROR ? EXCEPTION_EXECUTE_HANDLER : EXCEPTION_CONTINUE_SEARCH) { - OutputDebugStringW(L"[ImageLoader] CRITICAL: ReadFile fault (Network lost?)\n"); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(L"[ImageLoader] CRITICAL: ReadFile fault (Network lost?)", "Message")); return HRESULT_FROM_WIN32(ERROR_READ_FAULT); } } @@ -2038,7 +2040,7 @@ HRESULT CImageLoader::LoadTileFromMemory( return LoadJpegRegion_V3(sourceData, sourceSize, region, scale, outFrame, tileManager, nullptr /*arena*/, targetWidth, targetHeight); } __except (GetExceptionCode() == EXCEPTION_IN_PAGE_ERROR ? EXCEPTION_EXECUTE_HANDLER : EXCEPTION_CONTINUE_SEARCH) { - OutputDebugStringW(L"[ImageLoader] CRITICAL: ReadFile fault during Tile Decode\n"); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(L"[ImageLoader] CRITICAL: ReadFile fault during Tile Decode", "Message")); return HRESULT_FROM_WIN32(ERROR_READ_FAULT); } } @@ -2055,7 +2057,7 @@ HRESULT CImageLoader::FullDecodeFromMemory(const uint8_t* data, size_t size, std::wstring fmt = DetectFormatFromContent(data, size); if (!IsUnifiedBufferCodec(fmt)) { - OutputDebugStringW(L"[P15] FullDecodeFromMemory: unsupported format\n"); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(L"[P15] FullDecodeFromMemory: unsupported format", "Message")); return E_NOTIMPL; } @@ -2172,7 +2174,7 @@ HRESULT CImageLoader::FullDecodeToMMF(const uint8_t* data, size_t size, wchar_t dbg[192]; swprintf_s(dbg, L"[MMF] JXL needs %zu MB but MMF is %zu MB\n", needed / (1024*1024), mmfBufSize / (1024*1024)); - OutputDebugStringW(dbg); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(dbg, "Message")); JxlDecoderDestroy(dec); JxlThreadParallelRunnerDestroy(runner); return E_OUTOFMEMORY; @@ -2198,7 +2200,7 @@ HRESULT CImageLoader::FullDecodeToMMF(const uint8_t* data, size_t size, wchar_t dbg[192]; swprintf_s(dbg, L"[MMF] JXL FRAME_PROGRESSION: ratio=%zu, image=%ux%u (logged only, no flush)\n", ratio, info.xsize, info.ysize); - OutputDebugStringW(dbg); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(dbg, "Message")); // Continue decode loop for full quality } else if (st == JXL_DEC_FULL_IMAGE) { @@ -2211,7 +2213,7 @@ HRESULT CImageLoader::FullDecodeToMMF(const uint8_t* data, size_t size, JxlThreadParallelRunnerDestroy(runner); if (FAILED(hr) || !bufferSet) { - OutputDebugStringW(L"[MMF] JXL decode to MMF failed\n"); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(L"[MMF] JXL decode to MMF failed", "Message")); return FAILED(hr) ? hr : E_FAIL; } @@ -2225,7 +2227,7 @@ HRESULT CImageLoader::FullDecodeToMMF(const uint8_t* data, size_t size, wchar_t dbg[128]; swprintf_s(dbg, L"[MMF] JXL decoded direct-to-MMF OK (%ux%u)\n", info.xsize, info.ysize); - OutputDebugStringW(dbg); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(dbg, "Message")); return S_OK; } @@ -2242,7 +2244,7 @@ HRESULT CImageLoader::FullDecodeToMMF(const uint8_t* data, size_t size, }; if (!WuffsLoader::DecodePNG(data, size, &w, &h, allocator, nullptr) || !allocOK) { - OutputDebugStringW(L"[MMF] Wuffs PNG decode to MMF failed\n"); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(L"[MMF] Wuffs PNG decode to MMF failed", "Message")); return E_FAIL; } @@ -2252,7 +2254,7 @@ HRESULT CImageLoader::FullDecodeToMMF(const uint8_t* data, size_t size, wchar_t dbg[128]; swprintf_s(dbg, L"[MMF] PNG decoded direct-to-MMF OK (%ux%u)\n", w, h); - OutputDebugStringW(dbg); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(dbg, "Message")); return S_OK; } @@ -2269,7 +2271,7 @@ HRESULT CImageLoader::FullDecodeToMMF(const uint8_t* data, size_t size, wchar_t dbg[192]; swprintf_s(dbg, L"[MMF] Fallback: need %zu MB but MMF is %zu MB\n", needed / (1024*1024), mmfBufSize / (1024*1024)); - OutputDebugStringW(dbg); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(dbg, "Message")); return E_OUTOFMEMORY; } @@ -2282,7 +2284,7 @@ HRESULT CImageLoader::FullDecodeToMMF(const uint8_t* data, size_t size, wchar_t dbg[128]; swprintf_s(dbg, L"[MMF] %ls decoded via fallback+copy OK (%dx%d)\n", fmt.c_str(), heapFrame.width, heapFrame.height); - OutputDebugStringW(dbg); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(dbg, "Message")); return S_OK; } @@ -2622,14 +2624,14 @@ HRESULT CImageLoader::LoadJxlRegionToFrame(LPCWSTR filePath, QuickView::RegionRe JxlDecoderStatus st = JxlDecoderProcessInput(dec); if (st == JXL_DEC_ERROR) { - OutputDebugStringW(L"[JXL_ROI] Decoder Error during ProcessInput\n"); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(L"[JXL_ROI] Decoder Error during ProcessInput", "Message")); break; } if (st == JXL_DEC_SUCCESS) { hr = S_OK; break; } if (st == JXL_DEC_BASIC_INFO) { if (JXL_DEC_SUCCESS != JxlDecoderGetBasicInfo(dec, &info)) { - OutputDebugStringW(L"[JXL_ROI] Failed to get Basic Info\n"); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(L"[JXL_ROI] Failed to get Basic Info", "Message")); break; } @@ -2646,7 +2648,7 @@ HRESULT CImageLoader::LoadJxlRegionToFrame(LPCWSTR filePath, QuickView::RegionRe if (!BuildRegionScalePlan(srcRect, (int)info.xsize, (int)info.ysize, scale, explicitTargetW, explicitTargetH, &plan)) { - OutputDebugStringW(L"[JXL_ROI] Failed to Build Region Scale Plan\n"); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(L"[JXL_ROI] Failed to Build Region Scale Plan", "Message")); hr = E_FAIL; break; } @@ -2673,7 +2675,7 @@ HRESULT CImageLoader::LoadJxlRegionToFrame(LPCWSTR filePath, QuickView::RegionRe ctx.cropH = plan.cropH; if (JXL_DEC_SUCCESS != JxlDecoderSetImageOutCallback(dec, &pixFmt, JxlCropCallback, &ctx)) { - OutputDebugStringW(L"[JXL_ROI] Failed to Set Image Out Callback\n"); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(L"[JXL_ROI] Failed to Set Image Out Callback", "Message")); hr = E_FAIL; break; } } @@ -2682,7 +2684,7 @@ HRESULT CImageLoader::LoadJxlRegionToFrame(LPCWSTR filePath, QuickView::RegionRe break; } else if (st == JXL_DEC_NEED_MORE_INPUT) { - OutputDebugStringW(L"[JXL_ROI] Need more input but input is closed!\n"); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(L"[JXL_ROI] Need more input but input is closed!", "Message")); break; } } @@ -2690,7 +2692,7 @@ HRESULT CImageLoader::LoadJxlRegionToFrame(LPCWSTR filePath, QuickView::RegionRe if (FAILED(hr) || !tempBuf || !planReady) { wchar_t errObj[256]; swprintf_s(errObj, L"[JXL_ROI] Failure Exit: hr=0x%08X, tempBuf=%p, planReady=%d\n", hr, tempBuf, planReady); - OutputDebugStringW(errObj); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(errObj, "Message")); if (tempBuf && (!arena || !arena->Owns(tempBuf))) _aligned_free(tempBuf); return hr == S_OK ? E_FAIL : hr; } @@ -4245,7 +4247,7 @@ HRESULT CImageLoader::LoadAVIF(LPCWSTR filePath, IWICBitmap** ppBitmap, ImageMet avifResult result = avifDecoderSetIOMemory(decoder, avifBuf.data(), avifBuf.size()); if (result != AVIF_RESULT_OK) { wchar_t buf[128]; swprintf_s(buf, L"[LoadAVIF] SetIOMemory failed: %hs\n", avifResultToString(result)); - OutputDebugStringW(buf); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(buf, "Message")); avifDecoderDestroy(decoder); return E_FAIL; } @@ -4255,7 +4257,7 @@ HRESULT CImageLoader::LoadAVIF(LPCWSTR filePath, IWICBitmap** ppBitmap, ImageMet if (result != AVIF_RESULT_OK) { wchar_t buf[256]; swprintf_s(buf, L"[LoadAVIF] Parse failed: %hs | Diag: %hs\n", avifResultToString(result), decoder->diag.error); - OutputDebugStringW(buf); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(buf, "Message")); avifDecoderDestroy(decoder); return E_FAIL; } @@ -4264,7 +4266,7 @@ HRESULT CImageLoader::LoadAVIF(LPCWSTR filePath, IWICBitmap** ppBitmap, ImageMet result = avifDecoderNextImage(decoder); if (result != AVIF_RESULT_OK) { wchar_t buf[128]; swprintf_s(buf, L"[LoadAVIF] NextImage failed: %hs\n", avifResultToString(result)); - OutputDebugStringW(buf); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(buf, "Message")); avifDecoderDestroy(decoder); return E_FAIL; } @@ -4310,7 +4312,7 @@ HRESULT CImageLoader::LoadAVIF(LPCWSTR filePath, IWICBitmap** ppBitmap, ImageMet if (result != AVIF_RESULT_OK) { wchar_t buf[128]; swprintf_s(buf, L"[LoadAVIF] YUVToRGB failed: %hs\n", avifResultToString(result)); - OutputDebugStringW(buf); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(buf, "Message")); avifDecoderDestroy(decoder); return E_FAIL; } @@ -5102,11 +5104,11 @@ namespace QuickView { *outSize = bufSize - i; wchar_t logBuf[128]; swprintf_s(logBuf, L"[UltraHDR] Found potential second JPEG SOI at offset %zu, size %zu\n", i, *outSize); - OutputDebugStringW(logBuf); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(logBuf, "Message")); return true; } } - OutputDebugStringW(L"[UltraHDR] Second JPEG SOI NOT found in MPF scan.\n"); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(L"[UltraHDR] Second JPEG SOI NOT found in MPF scan.", "Message")); return false; } @@ -5119,7 +5121,7 @@ namespace QuickView { struct jpeg_error_mgr jerr; cinfo.err = jpeg_std_error(&jerr); jerr.error_exit = [](j_common_ptr ci) { - OutputDebugStringW(L"[UltraHDR] Gain Map JPEG decode fatal error.\n"); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(L"[UltraHDR] Gain Map JPEG decode fatal error.", "Message")); longjmp(*static_cast(ci->client_data), 1); }; @@ -5133,7 +5135,7 @@ namespace QuickView { jpeg_create_decompress(&cinfo); jpeg_mem_src(&cinfo, data, (unsigned long)size); if (jpeg_read_header(&cinfo, TRUE) != JPEG_HEADER_OK) { - OutputDebugStringW(L"[UltraHDR] Gain Map JPEG read_header failed.\n"); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(L"[UltraHDR] Gain Map JPEG read_header failed.", "Message")); jpeg_destroy_decompress(&cinfo); return nullptr; } @@ -5227,7 +5229,7 @@ namespace QuickView { marker->data_length > 1 ? marker->data[1] : 0, marker->data_length > 2 ? marker->data[2] : 0, marker->data_length > 3 ? marker->data[3] : 0); - OutputDebugStringW(logBuf); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(logBuf, "Message")); } // [UltraHDR Phase 1] Parse XMP while marker_list is alive @@ -5250,9 +5252,9 @@ namespace QuickView { ultraHdrPayload.sdrWidth = (uint32_t)cinfo.image_width; ultraHdrPayload.sdrHeight = (uint32_t)cinfo.image_height; ultraHdrPayloadParsed = true; - OutputDebugStringW(L"[UltraHDR] XMP Gain Map parameters found and parsed (Early stage).\n"); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(L"[UltraHDR] XMP Gain Map parameters found and parsed (Early stage).", "Message")); } else { - OutputDebugStringW(L"[UltraHDR] APP1 XMP found but ParseXmpToPayload failed.\n"); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(L"[UltraHDR] APP1 XMP found but ParseXmpToPayload failed.", "Message")); } } } @@ -5268,7 +5270,7 @@ namespace QuickView { { wchar_t logBuf[128]; swprintf_s(logBuf, L"[Loader] JPEG Markers Check: Found %d ICC segments. Total size: %zu\n", iccNumMarkers, iccTotalSize); - OutputDebugStringW(logBuf); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(logBuf, "Message")); } if (iccNumMarkers > 0) { @@ -5495,7 +5497,7 @@ namespace QuickView { size_t gainJpegSize = 0; if (ultraHdrPayloadParsed && UltraHdr::FindMpfSecondImage(pBuf, bufSize, &gainJpegData, &gainJpegSize)) { - OutputDebugStringW(L"[UltraHDR] MPF Secondary Image (Gain Map) found.\n"); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(L"[UltraHDR] MPF Secondary Image (Gain Map) found.", "Message")); auto auxLayer = UltraHdr::DecodeGainMapJpeg(gainJpegData, gainJpegSize, ctx); if (auxLayer) { result.blendOp = GpuBlendOp::UltraHdrGainMap; @@ -5992,7 +5994,7 @@ namespace QuickView { // [Fix] Prevent massive memory allocation stalls (e.g. 4.8GB for 1.2 GigaPixel JXL) // This prevents the OS from thrashing the page file for 15 seconds before crashing. if (ctx.allowFakeBase && bufferSize > 1024ULL * 1024ULL * 1024ULL) { // 1 GB limit - OutputDebugStringW(L"[JXL_DC] Image too large for base layer. Faking transparent stub but PRESERVING original dimensions for Titan Mode.\n"); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(L"[JXL_DC] Image too large for base layer. Faking transparent stub but PRESERVING original dimensions for Titan Mode.", "Message")); // We fake a 1x1 transparent pixel to satisfy the pipeline, // BUT we return the TRUE image dimensions to out results. // This ensures the Tile Engine correctly calculates regions. @@ -6388,7 +6390,7 @@ namespace QuickView { LibRaw RawProcessor; // Debug: Entry point - OutputDebugStringW(L"[RawCodec] Entering RawCodec::Load\n"); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(L"[RawCodec] Entering RawCodec::Load", "Message")); // [v9.3] Use wide-char path directly on Windows (fixes -100009 error) // LibRaw on Windows supports open_file(const wchar_t*) overload @@ -6408,10 +6410,10 @@ namespace QuickView { if (openResult != LIBRAW_SUCCESS) { wchar_t dbg[128]; swprintf_s(dbg, L"[RawCodec] open_file FAILED: %d\n", openResult); - OutputDebugStringW(dbg); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(dbg, "Message")); return E_FAIL; } - OutputDebugStringW(L"[RawCodec] open_file OK\n"); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(L"[RawCodec] open_file OK", "Message")); // [v10.1] Capture RAW orientation early int flip = RawProcessor.imgdata.sizes.flip; @@ -6443,14 +6445,14 @@ namespace QuickView { // Debug logging wchar_t dbg[256]; swprintf_s(dbg, L"[RawCodec] unpack_thumb: %d\n", unpackResult); - OutputDebugStringW(dbg); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(dbg, "Message")); if (unpackResult == LIBRAW_SUCCESS) { libraw_processed_image_t* thumb = RawProcessor.dcraw_make_mem_thumb(); swprintf_s(dbg, L"[RawCodec] thumb=%p, type=%d, size=%d\n", thumb, thumb ? thumb->type : -1, thumb ? thumb->data_size : 0); - OutputDebugStringW(dbg); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(dbg, "Message")); if (thumb) { if (thumb->type == LIBRAW_IMAGE_JPEG) { @@ -6462,10 +6464,10 @@ namespace QuickView { result.metadata.LoaderName = L"LibRaw (Preview)"; // We keep the ExifOrientation from JPEG::Load or the one we captured above if (result.metadata.ExifOrientation <= 1) result.metadata.ExifOrientation = exifOrientation; - OutputDebugStringW(L"[RawCodec] Preview JPEG decoded OK\n"); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(L"[RawCodec] Preview JPEG decoded OK", "Message")); return S_OK; } - OutputDebugStringW(L"[RawCodec] Preview JPEG decode FAILED\n"); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(L"[RawCodec] Preview JPEG decode FAILED", "Message")); } else if (thumb->type == LIBRAW_IMAGE_BITMAP) { // RGB Bitmap @@ -7247,18 +7249,18 @@ HRESULT CImageLoader::LoadImageUnified(LPCWSTR filePath, const DecodeContext& ct result.frameMeta = firstFrame->frameMeta; result.animator = std::move(animator); result.metadata.LoaderName = fmt == L"WebP" ? L"WebPAnimator" : (fmt == L"AVIF" ? L"AvifAnimator" : (fmt == L"JXL" ? L"JxlAnimator" : L"WuffsAnimator")); - OutputDebugStringW(L"[Anim] Animation hijack SUCCESS\n"); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(L"[Anim] Animation hijack SUCCESS", "Message")); return S_OK; } else { - OutputDebugStringW(L"[Anim] GetNextFrame() returned null or no pixels\n"); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(L"[Anim] GetNextFrame() returned null or no pixels", "Message")); } - // OutputDebugStringW(L"[Anim] IsAnimated() returned false, falling through to static decode\n"); + // QV_LOG("Anim_Log", TraceLoggingWideString(L"[Anim] IsAnimated() returned false, falling through to static decode", "Message")); } } else { - // OutputDebugStringW(L"[Anim] Initialize() FAILED, falling through to static decode\n"); + // QV_LOG("Anim_Log", TraceLoggingWideString(L"[Anim] Initialize() FAILED, falling through to static decode", "Message")); } } else { - OutputDebugStringW(L"[Anim] MappedFile invalid for animation\n"); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(L"[Anim] MappedFile invalid for animation", "Message")); } } @@ -9220,7 +9222,7 @@ static bool TryReadMetadataNative(LPCWSTR filePath, CImageLoader::ImageMetadata* info.xsize, info.ysize, info.bits_per_sample, info.exponent_bits_per_sample, info.num_extra_channels, info.uses_original_profile); - OutputDebugStringW(buf); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(buf, "Message")); pMetadata->Width = info.xsize; pMetadata->Height = info.ysize; @@ -10042,7 +10044,7 @@ HRESULT CImageLoader::LoadThumbJXL_DC(const uint8_t* pFile, size_t fileSize, Thu info.uses_original_profile, info.uses_original_profile ? L"YES→No DC Layer" : L"NO→VarDCT→DC possible", info.have_preview); - OutputDebugStringW(diagBuf); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(diagBuf, "Message")); } } else if (status == JXL_DEC_FRAME_PROGRESSION) { @@ -10135,7 +10137,7 @@ HRESULT CImageLoader::LoadThumbJXL_DC(const uint8_t* pFile, size_t fileSize, Thu wchar_t dbg[160]; swprintf_s(dbg, L"[JXL_DC] Using Preview fallback: %ux%u (no 1:8 DC)\n", info.preview.xsize, info.preview.ysize); - OutputDebugStringW(dbg); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(dbg, "Message")); continue; } } @@ -10152,7 +10154,7 @@ HRESULT CImageLoader::LoadThumbJXL_DC(const uint8_t* pFile, size_t fileSize, Thu swprintf_s(diagBuf, L"[JXL_DC] No 1:8 DC. isProgressive=%d, uses_original_profile=%d, have_preview=%d, image=%ux%u\n", isProgressive ? 1 : 0, info.uses_original_profile, info.have_preview, info.xsize, info.ysize); - OutputDebugStringW(diagBuf); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(diagBuf, "Message")); } bool isSmallEnough = ((uint64_t)info.xsize * info.ysize) < 2000000; // 2MP @@ -10179,7 +10181,7 @@ HRESULT CImageLoader::LoadThumbJXL_DC(const uint8_t* pFile, size_t fileSize, Thu } else if (allowFakeBase) { // Too large for FastLane full decode or too massive for HeavyLane CPU decoding. // We fake a 1x1 transparent pixel to satisfy the pipeline and unlock Titan Mode. - OutputDebugStringW(L"[JXL_DC] No 1:8 found and image too large. Faking 1x1 base layer for Region Decoder.\n"); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(L"[JXL_DC] No 1:8 found and image too large. Faking 1x1 base layer for Region Decoder.", "Message")); try { pData->pixels.assign(4, 0); // 1 pixel, 4 channels (RGBA), all 0 (transparent) @@ -11275,10 +11277,10 @@ HRESULT CImageLoader::LoadToFrame(LPCWSTR filePath, QuickView::RawImageFrame* ou MultiReplace(svgContent, replacements); wchar_t msg[128]; swprintf_s(msg, L"[SVG] Sanitized %d Unsafe IDs.\n", (int)replacements.size()); - OutputDebugStringW(msg); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(msg, "Message")); } } catch (...) { - OutputDebugStringW(L"[SVG] ID Sanitizer Pattern Failure\n"); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(L"[SVG] ID Sanitizer Pattern Failure", "Message")); } // ========================================================= @@ -11500,10 +11502,10 @@ HRESULT CImageLoader::LoadToFrame(LPCWSTR filePath, QuickView::RawImageFrame* ou if (inlinedCount > 0) { wchar_t msg[128]; swprintf_s(msg, L"[SVG] Inlined %d Styles (Fixed Black Silhouette).\n", inlinedCount); - OutputDebugStringW(msg); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(msg, "Message")); } } catch (...) { - OutputDebugStringW(L"[SVG] Style Inliner Failure\n"); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(L"[SVG] Style Inliner Failure", "Message")); } // Commit changes @@ -11540,7 +11542,7 @@ HRESULT CImageLoader::LoadToFrame(LPCWSTR filePath, QuickView::RawImageFrame* ou } } } catch (...) { - OutputDebugStringW(L"[SVG] Dimension parse failed, using default\n"); + QV_LOG("ImageLoader_Log", TraceLoggingWideString(L"[SVG] Dimension parse failed, using default", "Message")); } if (svgW <= 0) svgW = 512; diff --git a/QuickView/QuickViewETW.cpp b/QuickView/QuickViewETW.cpp new file mode 100644 index 0000000..7843b12 --- /dev/null +++ b/QuickView/QuickViewETW.cpp @@ -0,0 +1,23 @@ +#include "pch.h" +#include "QuickViewETW.h" + +// Define the "QuickView" ETW provider +// {YOUR-GUID-HERE-OR-AUTO-GENERATED-BY-MACRO} +// The macro automatically hashes the name "QuickView" to generate the GUID. +TRACELOGGING_DEFINE_PROVIDER( + g_hQuickViewProvider, + "QuickView", + (0xa3a9c9e8, 0x1d3a, 0x4d5b, 0xa1, 0x5d, 0x24, 0x98, 0xb7, 0x3d, 0x6e, 0x5a) // Explicit GUID generated via uuidgen or powershell [guid]::NewGuid() +); + +namespace QuickView { + namespace Logging { + void Initialize() { + TraceLoggingRegister(g_hQuickViewProvider); + } + + void Shutdown() { + TraceLoggingUnregister(g_hQuickViewProvider); + } + } +} diff --git a/QuickView/QuickViewETW.h b/QuickView/QuickViewETW.h new file mode 100644 index 0000000..911e785 --- /dev/null +++ b/QuickView/QuickViewETW.h @@ -0,0 +1,32 @@ +#pragma once + +#include +#include +#include "EditState.h" // For AppConfig g_config + +// Declare the ETW provider +TRACELOGGING_DECLARE_PROVIDER(g_hQuickViewProvider); + +namespace QuickView { + namespace Logging { + void Initialize(); + void Shutdown(); + } +} + +// RAII scope for managing ETW lifecycle in main +struct EtwScope { + EtwScope() { QuickView::Logging::Initialize(); } + ~EtwScope() { QuickView::Logging::Shutdown(); } +}; + +// Zero-overhead logging macro. +// Short-circuits completely if EnableDebugFeatures is false or the provider isn't listening. +extern AppConfig g_config; + +#define QV_LOG(EventName, ...) \ + do { \ + if (g_config.EnableDebugFeatures && TraceLoggingProviderEnabled(g_hQuickViewProvider, 0, 0)) { \ + TraceLoggingWrite(g_hQuickViewProvider, EventName, __VA_ARGS__); \ + } \ + } while(0) diff --git a/QuickView/RenderEngine.cpp b/QuickView/RenderEngine.cpp index 0a7b3dc..6ddd19e 100644 --- a/QuickView/RenderEngine.cpp +++ b/QuickView/RenderEngine.cpp @@ -5,6 +5,8 @@ #include #include #include "RenderEngine.h" +#include "QuickViewETW.h" +#include "DebugMetrics.h" #include "EditState.h" #include "ImageTypes.h" // [Direct D2D] RawImageFrame #include "ImageLoaderSimd.h" @@ -656,7 +658,7 @@ CRenderEngine::UploadRawFrameToGPU(const QuickView::RawImageFrame &frame, wchar_t dbg[256]; swprintf_s(dbg, L"[RenderEngine] GPU Bake Triggered (UltraHDR). Target Headroom: %.2f stops.\n", payload.targetHeadroom); - OutputDebugStringW(dbg); + QV_LOG("RenderEngine_Log", TraceLoggingWideString(dbg, "Message")); ComPtr pBaked; HRESULT hrBake = m_computeEngine->ComposeGainMap( @@ -703,7 +705,7 @@ CRenderEngine::UploadRawFrameToGPU(const QuickView::RawImageFrame &frame, wchar_t dbgUpload[256]; swprintf_s(dbgUpload, L"[RenderEngine] Upload: %dx%d, Format=%d, BlendOp=%d, AdvColor=%d\n", (int)frame.width, (int)frame.height, (int)frame.format, (int)frame.blendOp, (int)m_isAdvancedColor); - OutputDebugStringW(dbgUpload); + QV_LOG("RenderEngine_Log", TraceLoggingWideString(dbgUpload, "Message")); switch (frame.format) { case QuickView::PixelFormat::BGRA8888: diff --git a/QuickView/TileManager.cpp b/QuickView/TileManager.cpp index 5dcf8e9..16a5fc8 100644 --- a/QuickView/TileManager.cpp +++ b/QuickView/TileManager.cpp @@ -1,4 +1,6 @@ #include "pch.h" +#include "QuickViewETW.h" +#include "DebugMetrics.h" #include "TileManager.h" #include "SystemInfo.h" #include @@ -34,7 +36,7 @@ namespace QuickView { wchar_t log[128]; swprintf_s(log, L"[TileManager] Aggressive Caching Enabled. Budget: %llu MB (%d tiles)\n", budget / (1024*1024), m_maxTiles); - OutputDebugStringW(log); + QV_LOG("QuickView_GlobalLog", TraceLoggingWideString(log, "Message")); } TileManager::~TileManager() { @@ -133,7 +135,7 @@ namespace QuickView { swprintf_s(skipBuf, L"[TileManager] Skip trigger: zoom=%.4f base=%.4f img=%dx%d\n", zoom, basePreviewRatio, imageW, imageH); - OutputDebugStringW(skipBuf); + QV_LOG("QuickView_GlobalLog", TraceLoggingWideString(skipBuf, "Message")); } // Not in tile mode: clear viewport progress source so UI doesn't show stale progress. m_viewportTilesActive = false; @@ -196,7 +198,7 @@ namespace QuickView { wchar_t buf[256]; swprintf_s(buf, L"[TileManager] Update: LOD=%d Viewport=[%d, %d, %d, %d] Grid=[%d,%d] to [%d,%d]\n", lod, viewport.x, viewport.y, viewport.w, viewport.h, startX, startY, endX, endY); - OutputDebugStringW(buf); + QV_LOG("QuickView_GlobalLog", TraceLoggingWideString(buf, "Message")); } std::vector missing; diff --git a/QuickView/main.cpp b/QuickView/main.cpp index e7ec5a0..46e14d7 100644 --- a/QuickView/main.cpp +++ b/QuickView/main.cpp @@ -1,3 +1,4 @@ +#include "QuickViewETW.h" #include "pch.h" #include "CoroutineTypes.h" #include "CompositionEngine.h" @@ -5761,7 +5762,7 @@ static HRESULT SafeFullDecodeFromMemory(const uint8_t* data, size_t size, QuickV return InternalFullDecodeWrapper(data, size, outFrame); } __except (GetExceptionCode() == EXCEPTION_ACCESS_VIOLATION ? EXCEPTION_EXECUTE_HANDLER : EXCEPTION_CONTINUE_SEARCH) { - OutputDebugStringW(L"[Phase4] SEH: ACCESS_VIOLATION in FullDecodeFromMemory (caught)\n"); + QV_LOG("QuickView_GlobalLog", TraceLoggingWideString(L"[Phase4] SEH: ACCESS_VIOLATION in FullDecodeFromMemory (caught)", "Message")); return E_OUTOFMEMORY; } } @@ -5934,6 +5935,7 @@ static void ForceForegroundWindow(HWND hwnd) { } int WINAPI wWinMain(HINSTANCE hInstance, HINSTANCE, LPWSTR lpCmdLine, int nCmdShow) { + EtwScope etwScope; // === Priority 0: Tool subprocess dispatch (must be first) === int toolExitCode = 0; if (TryRunToolProcessFromCommandLine(&toolExitCode)) { @@ -6396,7 +6398,7 @@ LRESULT CALLBACK WndProc(HWND hwnd, UINT message, WPARAM wParam, LPARAM lParam) auto nextFrame = g_imageResource.animator->GetNextFrame(); if (!nextFrame || !nextFrame->pixels) { // EOF: Loop back to frame 0 - OutputDebugStringW(L"[Anim] EOF reached, looping to frame 0\n"); + QV_LOG("QuickView_GlobalLog", TraceLoggingWideString(L"[Anim] EOF reached, looping to frame 0", "Message")); nextFrame = g_imageResource.animator->SeekToFrame(0); } @@ -6419,10 +6421,10 @@ LRESULT CALLBACK WndProc(HWND hwnd, UINT message, WPARAM wParam, LPARAM lParam) RenderImageToDComp(hwnd, g_imageResource, true); RequestRepaint(PaintLayer::Image | PaintLayer::Dynamic); } else { - OutputDebugStringW(L"[Anim] UploadRawFrameToGPU FAILED\n"); + QV_LOG("QuickView_GlobalLog", TraceLoggingWideString(L"[Anim] UploadRawFrameToGPU FAILED", "Message")); } } else { - OutputDebugStringW(L"[Anim] SeekToFrame(0) also returned null, stopping\n"); + QV_LOG("QuickView_GlobalLog", TraceLoggingWideString(L"[Anim] SeekToFrame(0) also returned null, stopping", "Message")); KillTimer(hwnd, IDT_ANIMATION); } return 0; @@ -8262,13 +8264,13 @@ SKIP_EDGE_NAV:; case '3': g_slowMotionMode = !g_slowMotionMode; handled = true; break; case '4': g_showTileGrid = !g_showTileGrid; - OutputDebugStringW(g_showTileGrid ? L"Tile Grid: ON\n" : L"Tile Grid: OFF\n"); + QV_LOG("Main_Log", TraceLoggingWideString(g_showTileGrid ? L"Tile Grid: ON" : L"Tile Grid: OFF", "Message")); if (g_uiRenderer) g_uiRenderer->SetTileGridVisible(g_showTileGrid); handled = true; break; case '5': g_runtime.ForceHdrSimulation = !g_runtime.ForceHdrSimulation; - OutputDebugStringW(g_runtime.ForceHdrSimulation ? L"Force HDR Sim: ON\n" : L"Force HDR Sim: OFF\n"); + QV_LOG("Main_Log", TraceLoggingWideString(g_runtime.ForceHdrSimulation ? L"Force HDR Sim: ON" : L"Force HDR Sim: OFF", "Message")); handled = true; // Re-evaluate display color state to trigger FP16/8-bit UNORM surface swap in CompositionEngine RefreshDisplayColorPipeline(hwnd, false); @@ -10196,7 +10198,7 @@ void ProcessEngineEvents(HWND hwnd) { wchar_t debugBuf[256]; swprintf_s(debugBuf, L"[Main] AuxLayerReady: Gain Map applied via Auto-Gate and GPU Bake triggered\n"); - OutputDebugStringW(debugBuf); + QV_LOG("QuickView_GlobalLog", TraceLoggingWideString(debugBuf, "Message")); } } break; @@ -10208,7 +10210,7 @@ void ProcessEngineEvents(HWND hwnd) { wchar_t debugBuf[256]; swprintf_s(debugBuf, L"[Main] TileReady: LOD=%d (%d,%d) ID=%llu\n", evt.tileCoord->lod, evt.tileCoord->col, evt.tileCoord->row, evt.imageId); - OutputDebugStringW(debugBuf); + QV_LOG("QuickView_GlobalLog", TraceLoggingWideString(debugBuf, "Message")); if (g_imageEngine) { // [Infinity Engine] TileManager already updated by ImageEngine::PollState @@ -10219,7 +10221,7 @@ void ProcessEngineEvents(HWND hwnd) { wchar_t debugBuf[256]; swprintf_s(debugBuf, L"[Main] TileReady IGNORED: MatchID=%d HasCoord=%d HasFrame=%d\n", (evt.imageId == g_currentImageId.load()), evt.tileCoord.has_value(), (bool)evt.rawFrame); - OutputDebugStringW(debugBuf); + QV_LOG("QuickView_GlobalLog", TraceLoggingWideString(debugBuf, "Message")); } break; @@ -10494,7 +10496,7 @@ static void PrimePhase1Placeholder(HWND hwnd, const std::wstring& path, ImageID { bool isTitan = g_isNavigatingToTitan; if (!isTitan) { - OutputDebugStringW(L"[Phase1] Non-Titan: Skip Phase 1 completely.\n"); + QV_LOG("QuickView_GlobalLog", TraceLoggingWideString(L"[Phase1] Non-Titan: Skip Phase 1 completely.", "Message")); // [Fix] Do not apply skeleton. Leave current image intact for visual continuity. // Do not update metadata early to avoid DComp scaling artifacts on the old layer. return; // No Shell/WIC extraction and NO skeleton for non-Titan images @@ -10628,7 +10630,7 @@ static FireAndForget RunPhase2DispatchLoop() { if (task.imageId != g_currentImageId.load() || task.navToken != g_currentNavToken.load() || g_imagePath != task.path) { - OutputDebugStringW(L"[Phase2] QueueDispatch skipped stale task.\n"); + QV_LOG("QuickView_GlobalLog", TraceLoggingWideString(L"[Phase2] QueueDispatch skipped stale task.", "Message")); g_isPhase2Debouncing.store(false, std::memory_order_release); co_await ResumeBackground{}; continue; @@ -10640,7 +10642,7 @@ static FireAndForget RunPhase2DispatchLoop() { static_cast(task.imageId), static_cast(GetTickCount64() - task.enqueueTick), task.navigatorIndex); - OutputDebugStringW(dbg); + QV_LOG("QuickView_GlobalLog", TraceLoggingWideString(dbg, "Message")); DispatchNavigationToEngine( task.path, @@ -10697,7 +10699,7 @@ static void EnqueuePhase2NavigationTask( static_cast(droppedId), static_cast(droppedSerial), static_cast(g_phase2DroppedNavTasks.load())); - OutputDebugStringW(dropBuf); + QV_LOG("QuickView_GlobalLog", TraceLoggingWideString(dropBuf, "Message")); } wchar_t pushBuf[256]; @@ -10707,7 +10709,7 @@ static void EnqueuePhase2NavigationTask( static_cast(g_phase2NavSerial.load()), static_cast(kPhase2DebounceWindowMs), navigatorIndex); - OutputDebugStringW(pushBuf); + QV_LOG("QuickView_GlobalLog", TraceLoggingWideString(pushBuf, "Message")); g_isPhase2Debouncing.store(true, std::memory_order_release); @@ -11317,7 +11319,7 @@ void OnPaint(HWND hwnd) { previewW, baseRatio, absoluteZoom); - OutputDebugStringW(tileDbg); + QV_LOG("QuickView_GlobalLog", TraceLoggingWideString(tileDbg, "Message")); } g_imageEngine->UpdateTileViewport(vp, absoluteZoom, titanMeta.Width, titanMeta.Height, baseRatio, 0.0f, 0.0f); lastVP = vp;