#149: [glassperf] -- per-window glass paint timing, one line per second, default on

Oracle confirmed the separate-window glass mode WAS fast and tanked ~2 builds
back, so the regression is real and expresses only on his machine.  This names
the cost from inside his own session log:

  [glassperf] ticks=N tickMs=T | <window> n=paints ms=cost | ...

tickMs is the synchronous UpdateWindow sweep measured INSIDE the render frame
(L4VIDEO calls the tick), so on a machine where GDI serialises against D3D
present it IS the per-frame tax, and the per-window split names the panel.
Each WM_PAINT is QPC-timed at the dispatch chokepoint (the HALFTONE
StretchDIBits whose cost is driver-dependent).  Default ON like [segperf];
BT_PERF_LOG=0 opts out.  Smoke-tested: lines live in a 60s panel run.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_018SgmXGNMXavXiafKXf9MDC
This commit is contained in:
Joe DiPrima
2026-08-09 18:51:51 -05:00
co-authored by Claude Opus 5
parent 2b6b0276fd
commit 9e78d1cc23
+47 -1
View File
@@ -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(&gt0);
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(&gt1);
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;
}
}