From 7e80cbeb4bd546352393267809402cb39ba87943 Mon Sep 17 00:00:00 2001 From: Adam Date: Wed, 11 Dec 2024 19:45:48 +0000 Subject: [PATCH] library: add tid to verbose logs --- src/library/dll/main.c | 32 +++++++++++++++++--------------- src/library/gl.c | 16 +++++++++++++--- src/library/so/main.c | 24 ++++++++++++++---------- 3 files changed, 44 insertions(+), 28 deletions(-) diff --git a/src/library/dll/main.c b/src/library/dll/main.c index 79240a8..846dfdd 100644 --- a/src/library/dll/main.c +++ b/src/library/dll/main.c @@ -71,9 +71,11 @@ static HCURSOR cursor_default; #if defined(VERBOSE) static LPCWSTR logfilename = L"bolt-log.txt"; static FILE* logfile = 0; -#define LOG(...) if(fprintf(logfile, __VA_ARGS__))fflush(logfile) +#define LOG(STR) if(fprintf(logfile, "[tid %u] " STR, GetCurrentThreadId()))fflush(logfile) +#define LOGF(STR, ...) if(fprintf(logfile, "[tid %u] " STR, GetCurrentThreadId(), __VA_ARGS__))fflush(logfile) #else #define LOG(...) +#define LOGF(...) #endif static void resolve_imports(HMODULE, PIMAGE_IMPORT_DESCRIPTOR, HMODULE luajit, PIMAGE_EXPORT_DIRECTORY luajit_exports, GETMODULEHANDLEW, GETPROCADDRESS, LOADLIBRARYW, VIRTUALPROTECT); @@ -199,7 +201,7 @@ static BOOL handle_mouse_event(WPARAM wParam, POINTS point, ptrdiff_t bool_offse // an example of a case when we wouldn't want to pass it to the game would be a mouse-click event // which got captured by an embedded plugin window. LRESULT hook_wndproc(HWND hWnd, UINT uMsg, WPARAM wParam, LPARAM lParam) { - LOG("WNDPROC(%u, %llu, %llu)\n", uMsg, (ULONGLONG)wParam, (ULONGLONG)lParam); + LOGF("WNDPROC(%u, %llu, %llu)\n", uMsg, (ULONGLONG)wParam, (ULONGLONG)lParam); switch (uMsg) { case WM_WINDOWPOSCHANGING: case WM_WINDOWPOSCHANGED: { @@ -256,7 +258,7 @@ LRESULT hook_wndproc(HWND hWnd, UINT uMsg, WPARAM wParam, LPARAM lParam) { static void* bolt_GetProcAddress(const char* proc) { void* ret = (void*)real_wglGetProcAddress((LPCSTR)proc); - LOG("bolt_GetProcAddress(\"%s\") -> %llu\n", proc, (ULONGLONG)ret); + LOGF("bolt_GetProcAddress(\"%s\") -> %llu\n", proc, (ULONGLONG)ret); return ret; } @@ -268,12 +270,12 @@ static HGLRC WINAPI hook_wglCreateContext(HDC hdc) { HGLRC ret = real_wglCreateContext(hdc); if (ret) _bolt_gl_onCreateContext(ret, NULL, &libgl, bolt_GetProcAddress, false); LeaveCriticalSection(&wgl_lock); - LOG("wglCreateContext -> %llu\n", (ULONGLONG)ret); + LOGF("wglCreateContext -> %llu\n", (ULONGLONG)ret); return ret; } static BOOL WINAPI hook_wglDeleteContext(HGLRC hglrc) { - LOG("wglDeleteContext(%llu)\n", (ULONGLONG)hglrc); + LOGF("wglDeleteContext(%llu)\n", (ULONGLONG)hglrc); BOOL ret = real_wglDeleteContext(hglrc); if (ret) { EnterCriticalSection(&wgl_lock); @@ -284,14 +286,14 @@ static BOOL WINAPI hook_wglDeleteContext(HGLRC hglrc) { } static PROC WINAPI hook_wglGetProcAddress(LPCSTR proc) { - LOG("wglGetProcAddress(\"%s\")\n", proc); + LOGF("wglGetProcAddress(\"%s\")\n", proc); if (!strcmp(proc, "wglCreateContextAttribsARB")) return (PROC)hook_wglCreateContextAttribsARB; void* ret = _bolt_gl_GetProcAddress(proc); return ret ? ret : real_wglGetProcAddress(proc); } static BOOL WINAPI hook_wglMakeCurrent(HDC hdc, HGLRC hglrc) { - LOG("wglMakeCurrent(%llu)\n", (ULONGLONG)hglrc); + LOGF("wglMakeCurrent(%llu)\n", (ULONGLONG)hglrc); BOOL ret = real_wglMakeCurrent(hdc, hglrc); if (ret) { @@ -300,17 +302,17 @@ static BOOL WINAPI hook_wglMakeCurrent(HDC hdc, HGLRC hglrc) { _bolt_gl_onMakeCurrent(hglrc); LeaveCriticalSection(&wgl_lock); } - LOG("wglMakeCurrent(%llu) -> %i\n", (ULONGLONG)hglrc, (int)ret); + LOGF("wglMakeCurrent(%llu) -> %i\n", (ULONGLONG)hglrc, (int)ret); return ret; } static BOOL WINAPI hook_SwapBuffers(HDC hdc) { - LOG("SwapBuffers\n"); + LOGF("SwapBuffers\n"); if (game_width > 0 && game_height > 0) { _bolt_gl_onSwapBuffers((uint32_t)game_width, (uint32_t)game_height); } BOOL ret = real_SwapBuffers(hdc); - LOG("SwapBuffers -> %i\n", (int)ret); + LOGF("SwapBuffers -> %i\n", (int)ret); return ret; } @@ -318,7 +320,7 @@ static HWND WINAPI hook_CreateWindowExA(DWORD dwExStyle, LPCSTR lpClassName, LPC #if defined(VERBOSE) if (!logfile) { _wfopen_s(&logfile, logfilename, L"wb"); _bolt_gl_set_logfile(logfile); } #endif - LOG("CreateWindowExA(class=\"%s\", name=\"%s\", x=%i, y=%i, w=%i, h=%i)\n", lpClassName, lpWindowName, X, Y, nWidth, nHeight); + LOGF("CreateWindowExA(class=\"%s\", name=\"%s\", x=%i, y=%i, w=%i, h=%i)\n", lpClassName, lpWindowName, X, Y, nWidth, nHeight); HWND ret = real_CreateWindowExA(dwExStyle, lpClassName, lpWindowName, dwStyle, X, Y, nWidth, nHeight, hWndParent, hMenu, hInstance, lpParam); if (!game_parent_hwnd) { game_parent_hwnd = ret; @@ -353,10 +355,10 @@ static LONG_PTR WINAPI hook_GetWindowLongPtrW(HWND hWnd, int nIndex) { } static void hook_glGenTextures(GLsizei n, GLuint* textures) { - LOG("glGenTextures(%i...)\n", n); + LOGF("glGenTextures(%i...)\n", n); libgl.GenTextures(n, textures); _bolt_gl_onGenTextures(n, textures); - LOG("glGenTextures end\n", n); + LOG("glGenTextures end\n"); } static void hook_glDrawElements(GLenum mode, GLsizei count, GLenum type, const void* indices) { @@ -416,12 +418,12 @@ static void hook_glViewport(GLint x, GLint y, GLsizei width, GLsizei height) { } static HGLRC __stdcall hook_wglCreateContextAttribsARB(HDC hdc, HGLRC hglrc, const int* attribList) { - LOG("wglCreateContextAttribsARB(%llu)\n", (ULONGLONG)hglrc); + LOGF("wglCreateContextAttribsARB(%llu)\n", (ULONGLONG)hglrc); EnterCriticalSection(&wgl_lock); HGLRC ret = real_wglCreateContextAttribsARB(hdc, hglrc, attribList); if (ret) _bolt_gl_onCreateContext(ret, hglrc, &libgl, bolt_GetProcAddress, true); LeaveCriticalSection(&wgl_lock); - LOG("wglCreateContextAttribsARB(%llu) -> %llu\n", (ULONGLONG)hglrc, (ULONGLONG)ret); + LOGF("wglCreateContextAttribsARB(%llu) -> %llu\n", (ULONGLONG)hglrc, (ULONGLONG)ret); return ret; } diff --git a/src/library/gl.c b/src/library/gl.c index ee0fda6..a6453cd 100644 --- a/src/library/gl.c +++ b/src/library/gl.c @@ -7,14 +7,24 @@ #include #include #include +#include // -D BOLT_LIBRARY_VERBOSE=1 #if defined(VERBOSE) +#if defined(WIN32) +#define gettid() (unsigned long)GetCurrentThreadId() +#else +#include +#define gettid() (unsigned long)syscall(SYS_gettid) +#endif + static FILE* logfile; void _bolt_gl_set_logfile(FILE* f) { logfile = f; } -#define LOG(...) if(fprintf(logfile, __VA_ARGS__))fflush(logfile) +#define LOG(STR) if(fprintf(logfile, "[tid %lu] " STR, gettid()))fflush(logfile) +#define LOGF(STR, ...) if(fprintf(logfile, "[tid %lu] " STR, gettid(), __VA_ARGS__))fflush(logfile) #else #define LOG(...) +#define LOGF(...) #endif struct GLArrayBuffer { @@ -1441,7 +1451,7 @@ static void _bolt_glBufferStorage(GLenum target, GLsizeiptr size, const void* da free(buffer->data); buffer->data = buffer_content; } - LOG("glBufferStorage end (%s)\n", binding_type == -1 ? "not intercepted" : "intercepted"); + LOGF("glBufferStorage end (%s)\n", binding_type == -1 ? "not intercepted" : "intercepted"); } static void _bolt_glFlushMappedBufferRange(GLenum target, GLintptr offset, GLsizeiptr length) { @@ -1457,7 +1467,7 @@ static void _bolt_glFlushMappedBufferRange(GLenum target, GLintptr offset, GLsiz } else { gl.FlushMappedBufferRange(target, offset, length); } - LOG("glFlushMappedBufferRange end (%s)\n", binding_type == -1 ? "not intercepted" : "intercepted"); + LOGF("glFlushMappedBufferRange end (%s)\n", binding_type == -1 ? "not intercepted" : "intercepted"); } static void _bolt_glActiveTexture(GLenum texture) { diff --git a/src/library/so/main.c b/src/library/so/main.c index 0a490ec..d62cebc 100644 --- a/src/library/so/main.c +++ b/src/library/so/main.c @@ -7,6 +7,7 @@ #include #include #include +#include #include "x.h" #include "../gl.h" @@ -15,9 +16,12 @@ // -D BOLT_LIBRARY_VERBOSE=1 #if defined(VERBOSE) -#define LOG(...) if(printf(__VA_ARGS__)) fflush(stdout) +#include +#define LOG(STR) if(printf("[tid %li] " STR, syscall(SYS_gettid)))fflush(stdout) +#define LOGF(STR, ...) if(printf("[tid %li] " STR, syscall(SYS_gettid), __VA_ARGS__))fflush(stdout) #else #define LOG(...) +#define LOGF(...) #endif #if defined(XCBVERBOSE) @@ -383,7 +387,7 @@ void glTexParameteri(GLenum target, GLenum pname, GLint param) { } void* eglGetProcAddress(const char* name) { - LOG("eglGetProcAddress('%s')\n", name); + LOGF("eglGetProcAddress('%s')\n", name); void* ret = _bolt_gl_GetProcAddress(name); return ret ? ret : real_eglGetProcAddress(name); } @@ -392,7 +396,7 @@ unsigned int eglSwapBuffers(void* display, void* surface) { LOG("eglSwapBuffers\n"); _bolt_gl_onSwapBuffers(main_window_width, main_window_height); unsigned int ret = real_eglSwapBuffers(display, surface); - LOG("eglSwapBuffers end (returned %u)\n", ret); + LOGF("eglSwapBuffers end (returned %u)\n", ret); return ret; } @@ -404,7 +408,7 @@ void* eglCreateContext(void* display, void* config, void* share_context, const v _bolt_gl_onCreateContext(ret, share_context, &libgl, real_eglGetProcAddress, true); pthread_mutex_unlock(&egl_lock); } - LOG("eglCreateContext end (returned %lu)\n", (uintptr_t)ret); + LOGF("eglCreateContext end (returned %lu)\n", (uintptr_t)ret); return ret; } @@ -416,12 +420,12 @@ unsigned int eglMakeCurrent(void* display, void* draw, void* read, void* context _bolt_gl_onMakeCurrent(context); pthread_mutex_unlock(&egl_lock); } - LOG("eglMakeCurrent end (returned %u)\n", ret); + LOGF("eglMakeCurrent end (returned %u)\n", ret); return ret; } unsigned int eglDestroyContext(void* display, void* context) { - LOG("eglDestroyContext %lu\n", (uintptr_t)context); + LOGF("eglDestroyContext %lu\n", (uintptr_t)context); unsigned int ret = real_eglDestroyContext(display, context); if (ret) { pthread_mutex_lock(&egl_lock); @@ -434,7 +438,7 @@ unsigned int eglDestroyContext(void* display, void* context) { } pthread_mutex_unlock(&egl_lock); } - LOG("eglDestroyContext end (returned %u)\n", ret); + LOGF("eglDestroyContext end (returned %u)\n", ret); return ret; } @@ -779,7 +783,7 @@ static void* _bolt_dl_lookup(void* handle, const char* symbol) { void* dlopen(const char* filename, int flags) { INIT(); void* ret = real_dlopen(filename, flags); - LOG("dlopen('%s', %i) -> %lu\n", filename, flags, (unsigned long)ret); + LOGF("dlopen('%s', %i) -> %lu\n", filename, flags, (unsigned long)ret); // recheck if any of the modules we want to hook are now in our address space. // we can't strcmp filename, because it might not be something of interest but depend on something // of interest. for example, filename might be "libX11.so.6", which isn't of interest to bolt, but @@ -790,14 +794,14 @@ void* dlopen(const char* filename, int flags) { void* dlsym(void* handle, const char* symbol) { INIT(); - LOG("dlsym(%lu, '%s')\n", (uintptr_t)handle, symbol); + LOGF("dlsym(%lu, '%s')\n", (uintptr_t)handle, symbol); void* f = _bolt_dl_lookup(handle, symbol); return f ? f : real_dlsym(handle, symbol); } void* dlvsym(void* handle, const char* symbol, const char* version) { INIT(); - LOG("dlvsym(%lu, '%s')\n", (uintptr_t)handle, symbol); + LOGF("dlvsym(%lu, '%s')\n", (uintptr_t)handle, symbol); void* f = _bolt_dl_lookup(handle, symbol); return f ? f : real_dlvsym(handle, symbol, version); }