From ed34be6ec309a87e25cbbdbfd173a71287677a8d Mon Sep 17 00:00:00 2001 From: icex2 Date: Mon, 20 Jan 2025 20:13:57 +0100 Subject: [PATCH] wip frame pacing code Summary: Test Plan: --- src/main/debug-overlay/dllmain.c | 3 + src/main/iidxhook-d3d9/Module.mk | 1 + src/main/iidxhook-d3d9/frame-pace.c | 194 ++++++++++++++ src/main/iidxhook-d3d9/frame-pace.h | 13 + src/main/iidxhook-util/Module.mk | 1 + src/main/iidxhook-util/d3d9.c | 16 +- src/main/iidxhook-util/frame-graph.c | 374 +++++++++++++++++++++++++++ src/main/iidxhook-util/frame-graph.h | 10 + src/main/iidxhook-util/log-server.c | 14 +- src/main/iidxhook3/Module.mk | 1 + src/main/iidxhook3/dllmain.c | 10 +- 11 files changed, 626 insertions(+), 11 deletions(-) create mode 100644 src/main/debug-overlay/dllmain.c create mode 100644 src/main/iidxhook-d3d9/frame-pace.c create mode 100644 src/main/iidxhook-d3d9/frame-pace.h create mode 100644 src/main/iidxhook-util/frame-graph.c create mode 100644 src/main/iidxhook-util/frame-graph.h diff --git a/src/main/debug-overlay/dllmain.c b/src/main/debug-overlay/dllmain.c new file mode 100644 index 0000000..9918b89 --- /dev/null +++ b/src/main/debug-overlay/dllmain.c @@ -0,0 +1,3 @@ +// TODO have a separate dll that acts as a debug +// overlay for btools in general providing stuff +// like frame graph, text sections for IO timings etc. \ No newline at end of file diff --git a/src/main/iidxhook-d3d9/Module.mk b/src/main/iidxhook-d3d9/Module.mk index 361651b..4f64262 100644 --- a/src/main/iidxhook-d3d9/Module.mk +++ b/src/main/iidxhook-d3d9/Module.mk @@ -6,3 +6,4 @@ libs_iidxhook-d3d9 := \ src_iidxhook-d3d9 := \ bb-scale-hd.c \ + frame-pace.c \ diff --git a/src/main/iidxhook-d3d9/frame-pace.c b/src/main/iidxhook-d3d9/frame-pace.c new file mode 100644 index 0000000..289eb76 --- /dev/null +++ b/src/main/iidxhook-d3d9/frame-pace.c @@ -0,0 +1,194 @@ +#define LOG_MODULE "iidxhook-d3d-frame-pace" + +#include + +#include + +#include "hook/table.h" + +#include "util/log.h" + +#include "frame-pace.h" + +static void STDCALL my_Sleep(DWORD dwMilliseconds); +static void (STDCALL *real_Sleep)(DWORD dwMilliseconds); + +static DWORD STDCALL my_SleepEx(DWORD dwMilliseconds, BOOL bAlertable); +static DWORD (STDCALL *real_SleepEx)(DWORD dwMilliseconds, BOOL bAlertable); + +static const struct hook_symbol iidxhok_d3d9_frame_pace_hook_syms[] = { + { + .name = "Sleep", + .patch = my_Sleep, + .link = (void **) &real_Sleep, + }, + { + .name = "SleepEx", + .patch = my_SleepEx, + .link = (void **) &real_SleepEx, + }, +}; + +static bool iidxhook_d3d9_frame_pace_initialized; + +static DWORD iidxhook_d3d9_frame_pace_main_thread_id = -1; + +static int64_t iidxhook_d3d9_frame_pace_target_frame_time_cpu_ticks; +static int64_t iidxhook_d3d9_frame_pace_frame_time_start_cpu_ticks; + +static uint64_t iidxhook_d3d9_frame_pace_get_cpu_tick_frequency() +{ + LARGE_INTEGER freq; + + QueryPerformanceFrequency(&freq); + + return freq.QuadPart; +} + +static uint64_t iidxhook_d3d9_frame_pace_get_cpu_ticks() +{ + LARGE_INTEGER tick; + + QueryPerformanceCounter(&tick); + + return tick.QuadPart; +} + +// Source and reference implementation: +// https://github.com/PCSX2/pcsx2/blob/f26031cada6893ac306af73255d337e50a8f73f9/pcsx2/Counters.cpp#L563 +static void iidxhook_d3d9_frame_pace_do_post_frame() +{ + // ----------------------------------------------------------------------- + + const int64_t m_iTicks = iidxhook_d3d9_frame_pace_target_frame_time_cpu_ticks; + int64_t m_iStart = iidxhook_d3d9_frame_pace_frame_time_start_cpu_ticks; + + // Compute when we would expect this frame to end, assuming everything goes perfectly perfect. + const uint64_t uExpectedEnd = m_iStart + m_iTicks; + // The current tick we actually stopped on. + const uint64_t iEnd = iidxhook_d3d9_frame_pace_get_cpu_ticks(); + // The diff between when we stopped and when we expected to. + const int64_t sDeltaTime = iEnd - uExpectedEnd; + + // If frame ran too long... + if (sDeltaTime >= m_iTicks) + { + // ... Fudge the next frame start over a bit. Prevents fast forward zoomies. + m_iStart += (sDeltaTime / m_iTicks) * m_iTicks; + iidxhook_d3d9_frame_pace_frame_time_start_cpu_ticks = m_iStart; + return; + } + + // Conversion of delta from CPU ticks (microseconds) to milliseconds + int32_t msec = (int32_t) ((sDeltaTime * -1000) / (int64_t) iidxhook_d3d9_frame_pace_get_cpu_tick_frequency()); + + // If any integer value of milliseconds exists, sleep it off. + // Prior comments suggested that 1-2 ms sleeps were inaccurate on some OSes; + // further testing suggests instead that this was utter bullshit. + if (msec > 1) + { + real_Sleep(msec - 1); + } + + // Conversion to milliseconds loses some precision; after sleeping off whole milliseconds, + // spin the thread without sleeping until we finally reach our expected end time. + while (iidxhook_d3d9_frame_pace_get_cpu_ticks() < uExpectedEnd) + { + // SKREEEEEEEE + } + + // Finally, set our next frame start to when this one ends + m_iStart = uExpectedEnd; + iidxhook_d3d9_frame_pace_frame_time_start_cpu_ticks = m_iStart; +} + +// TODO must be renamed to framerate monitor with smoother/pacer +// TODO have feature flag to print framerate performance counters etc every X seconds +// as misc debug log output +// TODO make sure to record a decent amount of data/frame time accordingly over these +// seconds to report proper avg. frame time/rate, min, max, p95, p99, p999 +// TODO move this to a separate module that can be re-used on d3d9ex + +// fill up unused frametime on short frames to simulate hardware accuracy +// and match the timing of the target monitor's refresh rate as close as possible +// this fixes frame pacing issues with too short frames not being smoothened +// correctly by the game which either relies entirely on the hardware/GPU driver +// to do that or on tricoro+ era games, on SleepEx which only has max of 1 ms +// accuracy. the further the target monitor refresh rate is away from the desired +// refresh rate, e.g. 60 hz vsync, the more apparent the frame pacing issues +// become in the form of "random stuttering during gameplay" + +static void STDCALL my_Sleep(DWORD dwMilliseconds) +{ + // Heuristic, but seems to kill the poorly implemented frame pacing code + // fairly reliable without impacting other parts of the code negatively + if (iidxhook_d3d9_frame_pace_main_thread_id == GetCurrentThreadId()) { + if (dwMilliseconds <= 16) { + return; + } + } + + real_Sleep(dwMilliseconds); +} + +static DWORD STDCALL my_SleepEx(DWORD dwMilliseconds, BOOL bAlertable) +{ + // Heuristic, but applies only in two spots + // - frame pacing code (dynamic value) + // - Another spot with sleep time set to 1 -> reduces CPU banging + if (iidxhook_d3d9_frame_pace_main_thread_id == GetCurrentThreadId()) { + if (dwMilliseconds <= 16) { + return 0; + } + } + + return real_SleepEx(dwMilliseconds, bAlertable); +} + +static void iidxhook_d3d9_frame_pace_timings_init(double target_frame_rate_hz) +{ + double tick_rate; + + tick_rate = iidxhook_d3d9_frame_pace_get_cpu_tick_frequency(); + iidxhook_d3d9_frame_pace_target_frame_time_cpu_ticks = (int64_t) (tick_rate / target_frame_rate_hz); + iidxhook_d3d9_frame_pace_frame_time_start_cpu_ticks = iidxhook_d3d9_frame_pace_get_cpu_ticks(); +} + +void iidxhook_d3d9_frame_pace_init(DWORD main_thread_id, double target_frame_rate_hz) +{ + log_assert(main_thread_id != -1); + + iidxhook_d3d9_frame_pace_timings_init(target_frame_rate_hz); + + iidxhook_d3d9_frame_pace_main_thread_id = main_thread_id; + + iidxhook_d3d9_frame_pace_initialized = true; + + hook_table_apply( + NULL, "kernel32.dll", iidxhok_d3d9_frame_pace_hook_syms, lengthof(iidxhok_d3d9_frame_pace_hook_syms)); + + log_info("Initialized, target frame rate in hz %f, target frame time in cpu ticks %llu", target_frame_rate_hz, iidxhook_d3d9_frame_pace_target_frame_time_cpu_ticks); +} + +HRESULT iidxhook_d3d9_frame_pace_d3d9_irp_handler(struct hook_d3d9_irp *irp) +{ + HRESULT hr; + + log_assert(irp); + + if (!iidxhook_d3d9_frame_pace_initialized) { + return hook_d3d9_irp_invoke_next(irp); + } + + if (irp->op == HOOK_D3D9_IRP_OP_DEV_PRESENT) { + hr = hook_d3d9_irp_invoke_next(irp); + + if (hr == S_OK) { + iidxhook_d3d9_frame_pace_do_post_frame(); + } + + return hr; + } else { + return hook_d3d9_irp_invoke_next(irp); + } +} \ No newline at end of file diff --git a/src/main/iidxhook-d3d9/frame-pace.h b/src/main/iidxhook-d3d9/frame-pace.h new file mode 100644 index 0000000..b7da8cd --- /dev/null +++ b/src/main/iidxhook-d3d9/frame-pace.h @@ -0,0 +1,13 @@ +#ifndef IIDXHOOK_D3D9_FRAME_PACE_H +#define IIDXHOOK_D3D9_FRAME_PCE_H + +#include +#include + +#include "hook/d3d9.h" + +void iidxhook_d3d9_frame_pace_init(DWORD main_thread_id, double target_frame_rate_hz); + +HRESULT iidxhook_d3d9_frame_pace_d3d9_irp_handler(struct hook_d3d9_irp *irp); + +#endif \ No newline at end of file diff --git a/src/main/iidxhook-util/Module.mk b/src/main/iidxhook-util/Module.mk index 92fe44d..932f14b 100644 --- a/src/main/iidxhook-util/Module.mk +++ b/src/main/iidxhook-util/Module.mk @@ -16,5 +16,6 @@ src_iidxhook-util := \ d3d9.c \ eamuse.c \ effector.c \ + frame-graph.c \ log-server.c \ settings.c \ diff --git a/src/main/iidxhook-util/d3d9.c b/src/main/iidxhook-util/d3d9.c index 9c87719..66d84e5 100644 --- a/src/main/iidxhook-util/d3d9.c +++ b/src/main/iidxhook-util/d3d9.c @@ -13,6 +13,7 @@ #include "hook/table.h" #include "iidxhook-util/d3d9.h" +#include "iidxhook-util/frame-graph.h" #include "iidxhook-util/vertex-shader.h" #include "util/defs.h" @@ -232,7 +233,7 @@ iidxhook_util_d3d9_log_create_device_params(struct hook_d3d9_irp *irp) "hDeviceWindow %p, Windowed %d, " "EnableAutoDepthStencil " "%d, AutoDepthStencilFormat %d, Flags %lX, " - "FullScreen_RefreshRateInHz %d", + "FullScreen_RefreshRateInHz %d, PresentationInterval %d", irp->args.ctx_create_device.pp->BackBufferWidth, irp->args.ctx_create_device.pp->BackBufferHeight, irp->args.ctx_create_device.pp->BackBufferFormat, @@ -244,7 +245,8 @@ iidxhook_util_d3d9_log_create_device_params(struct hook_d3d9_irp *irp) irp->args.ctx_create_device.pp->EnableAutoDepthStencil, irp->args.ctx_create_device.pp->AutoDepthStencilFormat, irp->args.ctx_create_device.pp->Flags, - irp->args.ctx_create_device.pp->FullScreen_RefreshRateInHz); + irp->args.ctx_create_device.pp->FullScreen_RefreshRateInHz, + irp->args.ctx_create_device.pp->PresentationInterval); } static void @@ -267,6 +269,9 @@ static void iidxhook_util_d3d9_fix_create_device_apply_window_mode( log_assert(irp->op == HOOK_D3D9_IRP_OP_CTX_CREATE_DEVICE); D3DPRESENT_PARAMETERS *pp = irp->args.ctx_create_device.pp; + // TODO temporarily remove vsync for testing + pp->PresentationInterval = D3DPRESENT_INTERVAL_IMMEDIATE; + if (iidxhook_util_d3d9_config.windowed) { pp->Windowed = TRUE; pp->FullScreen_RefreshRateInHz = 0; @@ -1190,7 +1195,14 @@ iidxhook_util_d3d9_irp_handler(struct hook_d3d9_irp *irp) return hook_d3d9_irp_invoke_next(irp); + // TODO is there always ever just a single scene being rendered? + case HOOK_D3D9_IRP_OP_DEV_END_SCENE: + DrawFrameGraph(irp->args.dev_present.self); + + return hook_d3d9_irp_invoke_next(irp); + case HOOK_D3D9_IRP_OP_DEV_PRESENT: + iidxhook_util_d3d9_scale_render_target_to_back_buffer(irp); iidxhook_util_d3d9_set_back_buffer_rt(irp); diff --git a/src/main/iidxhook-util/frame-graph.c b/src/main/iidxhook-util/frame-graph.c new file mode 100644 index 0000000..92e5135 --- /dev/null +++ b/src/main/iidxhook-util/frame-graph.c @@ -0,0 +1,374 @@ +#include +#include +#include +#include +#include +#include +#include + +#include "util/log.h" +#include "util/time.h" + +#define MAX_SAMPLES 600 // 10 seconds at 60 FPS +#define GRAPH_WIDTH 300 +#define GRAPH_HEIGHT 100 +#define GRAPH_X 300 // Left position of graph +#define GRAPH_Y 30 // Top position of graph +#define AXIS_COLOR D3DCOLOR_XRGB(128, 128, 128) // Gray color for axes +#define GRAPH_COLOR D3DCOLOR_XRGB(255, 255, 0) // Yellow color for the graph +#define TEXT_COLOR D3DCOLOR_XRGB(255, 255, 0) // Yellow color for text + +// // TODO have a separate module that wraps all of these somewhat +typedef HRESULT WINAPI (*func_D3DXCreateFontA)( + struct IDirect3DDevice9 *device, + INT height, + UINT width, + UINT weight, + UINT miplevels, + BOOL italic, + DWORD charset, + DWORD precision, + DWORD quality, + DWORD pitchandfamily, + const char *facename, + struct ID3DXFont **font); + +typedef HRESULT WINAPI (*func_D3DXCreateLine)( + struct IDirect3DDevice9 *device, + struct ID3DXLine **line); + +typedef struct { + double frameTimes[MAX_SAMPLES]; + int currentIndex; + double minTime; + double maxTime; + double avgTime; + int sampleCount; + + ID3DXFont* font; // For regular text + ID3DXFont* smallFont; // For axis labels + ID3DXLine* line; + bool resourcesInitialized; +} PerfMetrics; + +PerfMetrics g_metrics = {0}; + +static HRESULT createLine( + IDirect3DDevice9 *dev, + struct ID3DXLine **line) +{ + HMODULE d3d9_24; + + d3d9_24 = GetModuleHandleA("d3dx9_24.dll"); + + if (d3d9_24 == NULL) { + log_fatal( + "Failed to load d3dx9_24.dll to create a font for displaying " + "framerate on monitor check."); + return 0; + } + + func_D3DXCreateLine d3dxCreateLine = + (func_D3DXCreateLine) GetProcAddress(d3d9_24, "D3DXCreateLine"); + + if (d3dxCreateLine == NULL) { + log_fatal("Failed to find function D3DXCreateLine"); + return 0; + } + + return d3dxCreateLine( + dev, + line); +} + +static HRESULT createFontA( + IDirect3DDevice9 *dev, + INT height, + UINT width, + UINT weight, + UINT miplevels, + BOOL italic, + DWORD charset, + DWORD precision, + DWORD quality, + DWORD pitchandfamily, + const char *facename, + ID3DXFont **font) +{ + HMODULE d3d9_24; + + d3d9_24 = GetModuleHandleA("d3dx9_24.dll"); + + if (d3d9_24 == NULL) { + log_fatal( + "Failed to load d3dx9_24.dll to create a font for displaying " + "framerate on monitor check."); + return 0; + } + + func_D3DXCreateFontA d3dxCreateFontA = + (func_D3DXCreateFontA) GetProcAddress(d3d9_24, "D3DXCreateFontA"); + + if (d3dxCreateFontA == NULL) { + log_fatal("Failed to find function D3DXCreateFontA"); + return 0; + } + + return d3dxCreateFontA( + dev, + height, + width, + weight, + miplevels, + italic, + charset, + precision, + quality, + pitchandfamily, + facename, + font); +} + +// Update performance metrics with new frame time +void UpdateMetrics(double frameTime) { + g_metrics.frameTimes[g_metrics.currentIndex] = frameTime; + g_metrics.currentIndex = (g_metrics.currentIndex + 1) % MAX_SAMPLES; + + if (g_metrics.sampleCount < MAX_SAMPLES) + g_metrics.sampleCount++; + + // Update min/max/avg + g_metrics.minTime = frameTime; + g_metrics.maxTime = frameTime; + g_metrics.avgTime = 0; + + for (int i = 0; i < g_metrics.sampleCount; i++) { + double time = g_metrics.frameTimes[i]; + g_metrics.minTime = min(g_metrics.minTime, time); + g_metrics.maxTime = max(g_metrics.maxTime, time); + g_metrics.avgTime += time; + } + + g_metrics.avgTime /= g_metrics.sampleCount; +} + +bool InitializeOverlayResources(IDirect3DDevice9* device) { + if (g_metrics.resourcesInitialized) return true; + + // Create main font (larger, for FPS display) + if (FAILED(createFontA(device, 20, 0, FW_BOLD, 1, FALSE, DEFAULT_CHARSET, + OUT_DEFAULT_PRECIS, DEFAULT_QUALITY, DEFAULT_PITCH | FF_DONTCARE, + "Arial", &g_metrics.font))) { + return false; + } + + // Create smaller font for axis labels + if (FAILED(createFontA(device, 12, 0, FW_NORMAL, 1, FALSE, DEFAULT_CHARSET, + OUT_DEFAULT_PRECIS, DEFAULT_QUALITY, DEFAULT_PITCH | FF_DONTCARE, + "Arial", &g_metrics.smallFont))) { + ID3DXFont_Release(g_metrics.font); + return false; + } + + if (FAILED(createLine(device, &g_metrics.line))) { + ID3DXFont_Release(g_metrics.font); + ID3DXFont_Release(g_metrics.smallFont); + return false; + } + + g_metrics.resourcesInitialized = true; + return true; +} + +void DrawGraph(IDirect3DDevice9* device) { + // Draw the frame time graph + D3DXVECTOR2 points[MAX_SAMPLES]; + float xStep = (float)GRAPH_WIDTH / (MAX_SAMPLES - 1); + + // Find min/max times in current sample range + double minTime = g_metrics.frameTimes[0]; + double maxTime = g_metrics.frameTimes[0]; + for (int i = 0; i < g_metrics.sampleCount; i++) { + int idx = (g_metrics.currentIndex - g_metrics.sampleCount + i + MAX_SAMPLES) % MAX_SAMPLES; + double time = g_metrics.frameTimes[idx]; + minTime = min(minTime, time); + maxTime = max(maxTime, time); + } + + // Add small padding to prevent graph from touching edges + double padding = (maxTime - minTime) * 0.1; + maxTime += padding; + minTime = max(0, minTime - padding); + + float yScale = (float)GRAPH_HEIGHT / (maxTime - minTime); + + for (int i = 0; i < g_metrics.sampleCount; i++) { + int idx = (g_metrics.currentIndex - g_metrics.sampleCount + i + MAX_SAMPLES) % MAX_SAMPLES; + points[i].x = GRAPH_X + i * xStep; + points[i].y = GRAPH_Y + GRAPH_HEIGHT - (g_metrics.frameTimes[idx] - minTime) * yScale; + } + + ID3DXLine_SetWidth(g_metrics.line, 1.0f); + ID3DXLine_Draw(g_metrics.line, points, g_metrics.sampleCount, GRAPH_COLOR); +} + +// TODO add option to have fixed min and max for the Y scale (so that the graph doesn't scale when the frame rate changes) +// keep this an option though with uncapped to also see really bad frame times on screen +void DrawOverlay(IDirect3DDevice9* device) { + if (!InitializeOverlayResources(device)) + return; + + // Draw black background + D3DRECT rect = {GRAPH_X, GRAPH_Y - 30, GRAPH_X + GRAPH_WIDTH, GRAPH_Y + GRAPH_HEIGHT}; + IDirect3DDevice9_Clear(device, 1, &rect, D3DCLEAR_TARGET, D3DCOLOR_ARGB(255, 0, 0, 0), 0, 0); + + // Draw X and Y axes + D3DXVECTOR2 xAxis[] = { + { .x = GRAPH_X, .y = GRAPH_Y + GRAPH_HEIGHT }, + { .x = GRAPH_X + GRAPH_WIDTH, .y = GRAPH_Y + GRAPH_HEIGHT } + }; + + D3DXVECTOR2 yAxis[] = { + { .x = GRAPH_X, .y = GRAPH_Y }, + { .x = GRAPH_X, .y = GRAPH_Y + GRAPH_HEIGHT } + }; + + ID3DXLine_SetWidth(g_metrics.line, 1.0f); + ID3DXLine_Draw(g_metrics.line, xAxis, 2, AXIS_COLOR); + ID3DXLine_Draw(g_metrics.line, yAxis, 2, AXIS_COLOR); + + // Draw X axis labels (time) + char buffer[32]; + RECT textRect; + for (int i = 0; i <= 10; i++) { + float x = GRAPH_X + (GRAPH_WIDTH * i / 10.0f); + sprintf(buffer, "%.1fs", (10.0f - i)); + textRect.left = (LONG)x - 15; + textRect.top = GRAPH_Y + GRAPH_HEIGHT + 5; + textRect.right = (LONG)x + 15; + textRect.bottom = GRAPH_Y + GRAPH_HEIGHT + 20; + ID3DXFont_DrawTextA(g_metrics.smallFont, NULL, buffer, -1, &textRect, DT_CENTER, AXIS_COLOR); + } + + // Find min/max times in current sample range + double minTime = g_metrics.frameTimes[0]; + double maxTime = g_metrics.frameTimes[0]; + for (int i = 0; i < g_metrics.sampleCount; i++) { + int idx = (g_metrics.currentIndex - g_metrics.sampleCount + i + MAX_SAMPLES) % MAX_SAMPLES; + double time = g_metrics.frameTimes[idx]; + minTime = min(minTime, time); + maxTime = max(maxTime, time); + } + + float yScale = (float)GRAPH_HEIGHT / (maxTime - minTime); + + // Draw Y axis labels (frame time) + for (int i = 0; i <= 8; i++) { + float y = GRAPH_Y + GRAPH_HEIGHT - (GRAPH_HEIGHT * i / 8.0f); + float ms = minTime + ((maxTime - minTime) * i / 8.0f); + sprintf(buffer, "%.1fms", ms); + textRect.left = GRAPH_X - 45; + textRect.top = (LONG)y - 6; + textRect.right = GRAPH_X - 5; + textRect.bottom = (LONG)y + 6; + ID3DXFont_DrawTextA(g_metrics.smallFont, NULL, buffer, -1, &textRect, DT_RIGHT, AXIS_COLOR); + } + + // TODO add some kind of coloring to the frame rate graph/line whenever the line is above or below a certain threshold of the reference line + + // Draw 60 FPS reference line (16.67ms) + const float targetFrameTime = 1000.0f/60.0f; // 16.67ms + float y60fps = GRAPH_Y + GRAPH_HEIGHT - ((targetFrameTime - minTime) * yScale); + + // Only draw reference line if it's within the visible range + if (targetFrameTime >= minTime && targetFrameTime <= maxTime) { + D3DXVECTOR2 refLine[2]; + refLine[0].x = GRAPH_X; + refLine[0].y = y60fps; + refLine[1].x = GRAPH_X + GRAPH_WIDTH; + refLine[1].y = y60fps; + + ID3DXLine_SetWidth(g_metrics.line, 1.0f); + ID3DXLine_Draw(g_metrics.line, refLine, 2, D3DCOLOR_ARGB(128, 255, 255, 0)); // Semi-transparent yellow + + // Draw reference line label + char refBuffer[32]; + sprintf(refBuffer, "16.67ms (60 FPS)"); + RECT refTextRect; + refTextRect.left = GRAPH_X + GRAPH_WIDTH + 5; + refTextRect.top = y60fps - 8; // Center text vertically with line + refTextRect.right = refTextRect.left + 100; + refTextRect.bottom = refTextRect.top + 16; + ID3DXFont_DrawTextA(g_metrics.smallFont, NULL, refBuffer, -1, &refTextRect, DT_LEFT, D3DCOLOR_ARGB(128, 255, 255, 0)); + } + + // ------------------------------------------------------------------------- + + // Draw the frame time graph + D3DXVECTOR2 points[MAX_SAMPLES]; + float xStep = (float)GRAPH_WIDTH / (MAX_SAMPLES - 1); + + // Add small padding to prevent graph from touching edges + double padding = (maxTime - minTime) * 0.1; + maxTime += padding; + minTime = max(0, minTime - padding); + + for (int i = 0; i < g_metrics.sampleCount; i++) { + int idx = (g_metrics.currentIndex - g_metrics.sampleCount + i + MAX_SAMPLES) % MAX_SAMPLES; + points[i].x = GRAPH_X + i * xStep; + points[i].y = GRAPH_Y + GRAPH_HEIGHT - (g_metrics.frameTimes[idx] - minTime) * yScale; + } + + ID3DXLine_SetWidth(g_metrics.line, 1.0f); + ID3DXLine_Draw(g_metrics.line, points, g_metrics.sampleCount, GRAPH_COLOR); + + // ------------------------------------------------------------------------- + + // Calculate current FPS + double currentFrameTime = g_metrics.frameTimes[(g_metrics.currentIndex - 1 + MAX_SAMPLES) % MAX_SAMPLES]; + double fps = 1000.0 / currentFrameTime; + + // Draw FPS text + sprintf(buffer, "%.3f FPS", fps); + textRect.left = GRAPH_X + GRAPH_WIDTH - 100; + textRect.top = GRAPH_Y - 25; + textRect.right = GRAPH_X + GRAPH_WIDTH; + textRect.bottom = GRAPH_Y - 5; + ID3DXFont_DrawTextA(g_metrics.font, NULL, buffer, -1, &textRect, DT_RIGHT, TEXT_COLOR); + + // Draw current frame time in ms + sprintf(buffer, "%.3f ms", currentFrameTime); + textRect.left = GRAPH_X + GRAPH_WIDTH - 200; // Position to the left of FPS + textRect.top = GRAPH_Y - 25; + textRect.right = GRAPH_X + GRAPH_WIDTH - 110; // Leave space for FPS text + textRect.bottom = GRAPH_Y - 5; + ID3DXFont_DrawTextA(g_metrics.font, NULL, buffer, -1, &textRect, DT_RIGHT, TEXT_COLOR); + + // TODO draw derivation graph and average derivation time over the current frame scope + + // Draw "Framerate" label + textRect.left = GRAPH_X; + textRect.top = GRAPH_Y - 25; + textRect.right = GRAPH_X + 100; + textRect.bottom = GRAPH_Y - 5; + ID3DXFont_DrawTextA(g_metrics.font, NULL, "Framerate", -1, &textRect, DT_LEFT, TEXT_COLOR); +} + +// Hooked Present function +void DrawFrameGraph(IDirect3DDevice9* device) { + + static uint64_t lastTime = 0; + uint64_t currentTime = time_get_counter(); + + if (lastTime != 0) { + uint64_t frameTime = currentTime - lastTime; + double frameTimeMs = time_get_elapsed_us(frameTime) / 1000.0; + UpdateMetrics(frameTimeMs); + } + + lastTime = currentTime; + + //IDirect3DDevice9_BeginScene(device); + DrawOverlay(device); + //IDirect3DDevice9_EndScene(device); +} \ No newline at end of file diff --git a/src/main/iidxhook-util/frame-graph.h b/src/main/iidxhook-util/frame-graph.h new file mode 100644 index 0000000..945db68 --- /dev/null +++ b/src/main/iidxhook-util/frame-graph.h @@ -0,0 +1,10 @@ +#ifndef IIDXHOOK_FRAME_GRAPH_H +#define IIDXHOOK_FRAME_GRAPH_H + +#include +#include +#include + +void DrawFrameGraph(IDirect3DDevice9* device); + +#endif \ No newline at end of file diff --git a/src/main/iidxhook-util/log-server.c b/src/main/iidxhook-util/log-server.c index cc866d2..e2ce01c 100644 --- a/src/main/iidxhook-util/log-server.c +++ b/src/main/iidxhook-util/log-server.c @@ -118,15 +118,15 @@ log_post(char level, const char *module, const char *fmt, va_list ap) { // TODO test if this addresses performance issues and stuttering // TODO measure time how long waiting takes here? - // if (WaitForSingleObject(log_rv_producer, INFINITE)) { - // return; - // } + if (WaitForSingleObject(log_rv_producer, INFINITE)) { + return; + } - // log_rv_level = level; - // log_rv_module = module; - // str_vformat(log_rv_buffer, sizeof(log_rv_buffer), fmt, ap); + log_rv_level = level; + log_rv_module = module; + str_vformat(log_rv_buffer, sizeof(log_rv_buffer), fmt, ap); - // ReleaseSemaphore(log_rv_consumer, 1, NULL); + ReleaseSemaphore(log_rv_consumer, 1, NULL); } #define LOG_POST_IMPL(name, level) \ diff --git a/src/main/iidxhook3/Module.mk b/src/main/iidxhook3/Module.mk index e328bec..ddafbd1 100644 --- a/src/main/iidxhook3/Module.mk +++ b/src/main/iidxhook3/Module.mk @@ -6,6 +6,7 @@ ldflags_iidxhook3 := \ libs_iidxhook3 := \ iidxhook-util \ + iidxhook-d3d9 \ ezusb-emu \ ezusb-iidx-16seg-emu \ ezusb2-emu \ diff --git a/src/main/iidxhook3/dllmain.c b/src/main/iidxhook3/dllmain.c index f00ba6f..987aa43 100644 --- a/src/main/iidxhook3/dllmain.c +++ b/src/main/iidxhook3/dllmain.c @@ -27,6 +27,8 @@ #include "hooklib/rs232.h" #include "hooklib/setupapi.h" +#include "iidxhook-d3d9/frame-pace.h" + #include "iidxhook-util/acio.h" #include "iidxhook-util/chart-patch.h" #include "iidxhook-util/clock.h" @@ -52,6 +54,9 @@ static const hook_d3d9_irp_handler_t iidxhook_d3d9_handlers[] = { iidxhook_util_d3d9_irp_handler, + // Order is important for performance, frame pacing must come at the very end + // to include all timings from any prior hooks + //iidxhook_d3d9_frame_pace_d3d9_irp_handler, }; static HANDLE STDCALL my_OpenProcess(DWORD, BOOL, DWORD); @@ -69,6 +74,8 @@ iidxhook3_setup_d3d9_hooks(const struct iidxhook_config_gfx *config_gfx) { struct iidxhook_util_d3d9_config d3d9_config; + iidxhook_d3d9_frame_pace_init(GetCurrentThreadId(), 60.0); + iidxhook_util_d3d9_init_config(&d3d9_config); d3d9_config.windowed = config_gfx->windowed; @@ -246,8 +253,7 @@ skip: BOOL WINAPI DllMain(HMODULE mod, DWORD reason, void *ctx) { if (reason == DLL_PROCESS_ATTACH) { - // TODO switched to null writer to see if it addresses performance issues - log_to_writer(log_writer_null, NULL); + log_to_writer(log_writer_debug, NULL); /* Bootstrap hook for further init tasks (see above) */