diff --git a/engine/MUNGA_L4/L4GLASSWIN.cpp b/engine/MUNGA_L4/L4GLASSWIN.cpp index 8d775ba..f9b89da 100644 --- a/engine/MUNGA_L4/L4GLASSWIN.cpp +++ b/engine/MUNGA_L4/L4GLASSWIN.cpp @@ -96,6 +96,8 @@ struct GButton struct GWin { + double perfMs; // [glassperf] paint ms this window, this second + int perfN; // [glassperf] paints this second const char *title; HWND hwnd; @@ -1695,7 +1697,20 @@ static LRESULT CALLBACK switch (message) { case WM_PAINT: - if (w != NULL) { PaintGlass(window, w); return 0; } + if (w != NULL) + { + // [glassperf] (#149): time EVERY panel paint. The blit is a + // HALFTONE StretchDIBits whose cost is strongly driver-dependent + // -- the whole point is to measure it on the machine that pays it. + LARGE_INTEGER t0, t1, fq; + QueryPerformanceCounter(&t0); + PaintGlass(window, w); + QueryPerformanceCounter(&t1); + QueryPerformanceFrequency(&fq); + w->perfMs += 1000.0 * (double)(t1.QuadPart - t0.QuadPart) / (double)fq.QuadPart; + ++w->perfN; + return 0; + } break; case WM_ERASEBKGND: @@ -2047,6 +2062,10 @@ void return; sLastPaint = now; + static const int sGlassPerf = + !(getenv("BT_PERF_LOG") && *getenv("BT_PERF_LOG") == '0'); + LARGE_INTEGER gt0, gt1, gfq; + QueryPerformanceCounter(>0); for (int i = 0; i < gWinCount; ++i) { if (gWins[i].hwnd != NULL) @@ -2055,4 +2074,31 @@ void UpdateWindow(gWins[i].hwnd); // synchronous paint, not the throttled queue } } + QueryPerformanceCounter(>1); + QueryPerformanceFrequency(&gfq); + + // [glassperf] (#149): one line per second -- the tick's total synchronous + // cost plus each window's own paint time. This runs INSIDE the render + // frame (L4VIDEO calls the tick), so on a machine where GDI serialises + // against D3D present, tickMs IS the per-frame tax and the per-window + // split names the guilty panel. Default ON like [segperf]; BT_PERF_LOG=0 + // opts out. + static double sTickMs = 0.0; static int sTicks = 0; + static unsigned long sLastReport = 0; + sTickMs += 1000.0 * (double)(gt1.QuadPart - gt0.QuadPart) / (double)gfq.QuadPart; + ++sTicks; + if (sGlassPerf && now - sLastReport >= 1000) + { + sLastReport = now; + DEBUG_STREAM << "[glassperf] ticks=" << sTicks << " tickMs=" << sTickMs; + for (int i = 0; i < gWinCount; ++i) + { + if (gWins[i].perfN > 0) + DEBUG_STREAM << " | " << gWins[i].title + << " n=" << gWins[i].perfN << " ms=" << gWins[i].perfMs; + gWins[i].perfMs = 0.0; gWins[i].perfN = 0; + } + DEBUG_STREAM << "\n" << std::flush; + sTickMs = 0.0; sTicks = 0; + } }