From f2ccab089c36cb8252b8966771bebcb22ef35f0b Mon Sep 17 00:00:00 2001 From: janwas Date: Mon, 10 Oct 2005 17:33:34 +0000 Subject: [PATCH] new cumulative timer as requested for entity slowdown investigation. use SUM_TIMER; see comments in source+header. (i've tested this on my laptop, but only get as far as the main menu. hopefully this won't break anything :S) This was SVN commit r2893. --- source/lib/timer.cpp | 74 +++++++++++++++++++++++++ source/lib/timer.h | 89 +++++++++++++++++++++++++++---- source/ps/GameSetup/GameSetup.cpp | 31 ++++++++--- 3 files changed, 178 insertions(+), 16 deletions(-) diff --git a/source/lib/timer.cpp b/source/lib/timer.cpp index 591c5bb86f..b074be4670 100755 --- a/source/lib/timer.cpp +++ b/source/lib/timer.cpp @@ -234,3 +234,77 @@ void calc_fps() // C float -> int rounds down; we want to round up to // hit vsync-locked framerates exactly. } + + +//----------------------------------------------------------------------------- + +// cumulative timer API, useful for profiling. +// this supplements in-game profiling by providing low-overhead, +// high resolution time accounting. + +struct TimerClient +{ + double sum; // total bill [s] + + // only store a pointer for efficiency. + const char* name; +}; + +// use static storage to ensure clients can be added at any time, +// especially before the heap has been initialized. +// that means there's a fixed limit, but that's not a problem since +// these timers are added manually for performance measuring. +static uint num_clients; +static const uint MAX_CLIENTS = 16; +static TimerClient clients[MAX_CLIENTS]; + + +// allocate a new TimerClient whose total (added to by timer_bill_client) +// will be displayed by timer_display_client_totals. +// notes: +// - uses static data; there is a fixed limit. rationale: see clients[]. +// - may be called at any time; +// - free() is not needed nor possible. +// - name must remain valid until exit; passing a string literal is safest. +TimerClient* timer_add_client(const char* name) +{ + if(num_clients == MAX_CLIENTS) + { + debug_warn("timer: increase MAX_CLIENTS"); + return 0; + } + TimerClient* tc = &clients[num_clients++]; + tc->name = name; + // note: tc->sum is already 0 (static data) + return tc; +} + + +// add
[s] to the client's total. +void timer_bill_client(TimerClient* tc, double dt) +{ + tc->sum += dt; +} + + +// display all clients' totals; does not reset them. +// typically called at exit. +void timer_display_client_totals() +{ + debug_printf("TIMER TOTALS (%d clients)\n", num_clients); + debug_printf("-----------------------------------------------------\n"); + for(uint i = 0; i < num_clients; i++) + { + const double sum = clients[i].sum; + // determine scale factor for pretty display + double scale = 1e6; + const char* unit = "us"; + if(sum > 1.0) + scale = 1, unit = "s"; + else if(sum > 1e-3) + scale = 1e3, unit = "ms"; + + debug_printf(" %s: %g %s\n", clients[i].name, sum*scale, unit); + } + debug_printf("-----------------------------------------------------\n"); +} diff --git a/source/lib/timer.h b/source/lib/timer.h index 8396e806eb..b6ca0fb521 100755 --- a/source/lib/timer.h +++ b/source/lib/timer.h @@ -40,6 +40,29 @@ extern int fps; extern void calc_fps(void); + +// +// cumulative timer API +// + +struct TimerClient; // opaque + +// allocate a new TimerClient whose total (added to by timer_bill_client) +// will be displayed by timer_display_client_totals. +// notes: +// - uses static data; there is a fixed limit. rationale: see clients[]. +// - may be called at any time; +// - free() is not needed nor possible. +// - name must remain valid until exit; passing a string literal is safest. +extern TimerClient* timer_add_client(const char* name); + +// add
[s] to the client's total. +extern void timer_bill_client(TimerClient* tc, double dt); + +// display all clients' totals; does not reset them. +// typically called at exit. +extern void timer_display_client_totals(); + #ifdef __cplusplus } #endif @@ -49,39 +72,85 @@ extern void calc_fps(void); class ScopedTimer { double t0; - const std::string name; + const char* name; public: ScopedTimer(const char* _name) - : name(_name) { t0 = get_time(); + name = _name; } ~ScopedTimer() { double t1 = get_time(); double dt = t1-t0; - // assume microseconds + // determine scale factor for pretty display double scale = 1e6; - char unit = 'u'; + const char* unit = "us"; if(dt > 1.0) - scale = 1, unit = ' '; - // milli + scale = 1, unit = "s"; else if(dt > 1e-3) - scale = 1e3, unit = 'm'; + scale = 1e3, unit = "ms"; - debug_printf("TIMER %s: %g %cs\n", name.c_str(), dt*scale, unit); + debug_printf("TIMER %s: %g %s\n", name, dt*scale, unit); } - // no copy ctor, since some members are const + // disallow copying (makes no sense) private: ScopedTimer& operator=(const ScopedTimer&); }; -#define TIMER(name) ScopedTimer st##name##instance(#name) +#define TIMER(name) ScopedTimer ST##name(#name) // Cheat a bit to make things slightly easier on the user #define TIMER_START(name) { ScopedTimer __timer( name ) #define TIMER_END(name) } + + + +/* +Example usage: + + static TimerClient* client = timer_add_client("description"); + + void func() + { + SUM_TIMER(client); + (code to be measured) + } + + [at exit] + timer_display_client_totals(); + +*/ + +class ScopedSumTimer +{ + double t0; + TimerClient* tc; + +public: + ScopedSumTimer(TimerClient* tc_) + { + t0 = get_time(); + tc = tc_; + } + ~ScopedSumTimer() + { + double t1 = get_time(); + double dt = t1-t0; + timer_bill_client(tc, dt); + } + + // disallow copying (makes no sense) +private: + ScopedSumTimer& operator=(const ScopedSumTimer&); +}; + +// bills to the time elapsed between execution reaching the +// point of macro invocation and end of the current basic block. +// total times for all clients are displayed by timer_display_client_totals. +#define SUM_TIMER(client) ScopedSumTimer UID__(client) + #endif // #ifndef TIMER_H diff --git a/source/ps/GameSetup/GameSetup.cpp b/source/ps/GameSetup/GameSetup.cpp index 0242777be9..8e78b5b010 100644 --- a/source/ps/GameSetup/GameSetup.cpp +++ b/source/ps/GameSetup/GameSetup.cpp @@ -771,6 +771,8 @@ void Shutdown() h_mgr_shutdown(); mem_shutdown(); + timer_display_client_totals(); + debug_shutdown(); delete &g_Logger; @@ -793,6 +795,9 @@ void Init(int argc, char* argv[], bool setup_gfx, bool setup_gui) debug_set_thread_name("main"); + // If you ever want to catch a particular allocation: + //_CrtSetBreakAlloc(187); + // Query CPU capabilities, possibly set some CPU-dependent flags cpu_init(); @@ -862,6 +867,9 @@ void Init(int argc, char* argv[], bool setup_gfx, bool setup_gui) uint quality = SANE_TEX_QUALITY_DEFAULT; // TODO: set value from config file SetTextureQuality(quality); + + // required by ogl_tex to detect broken gfx card/driver combos + get_gfx_info(); } oglCheck(); @@ -880,7 +888,7 @@ void Init(int argc, char* argv[], bool setup_gfx, bool setup_gui) } // (must come after SetVideoMode, since it calls oglInit) - const char* missing = oglHaveExtensions(0, "GL_ARB_multitexture", "GL_ARB_texture_env_combine", "GL_ARB_texture_env_dot3", "GL_ARB_texture_env_crossbar", 0); + const char* missing = oglHaveExtensions(0, "GL_ARB_multitexture", "GL_EXT_draw_range_elements", "GL_ARB_texture_env_combine", "GL_ARB_texture_env_dot3", "GL_ARB_texture_env_crossbar", 0); if(missing) { wchar_t buf[500]; @@ -906,20 +914,26 @@ void Init(int argc, char* argv[], bool setup_gfx, bool setup_gui) oglCheck(); InitRenderer(); - TIMER(init_after_InitRenderer); - + { + TIMER(Init_entitiessection); // This needs to be done after the renderer has loaded all its actors... new CBaseEntityCollection; // CEntityManager is managed by CWorld //new CEntityManager; - new CPathfindEngine; new CSelectedEntities; new CMouseoverEntities; + } + + { + TIMER(Init_miscgamesection); + new CPathfindEngine; new CBuildingPlacer; - new CSessionManager; - new CGameAttributes; + } + + { + TIMER(Init_misc); // Register a few Game/Network JS globals g_ScriptingHost.SetGlobal("g_GameAttributes", OBJECT_TO_JSVAL(g_GameAttributes.GetScript())); @@ -932,13 +946,18 @@ void Init(int argc, char* argv[], bool setup_gfx, bool setup_gui) InitInput(); oglCheck(); + } #ifndef NO_GUI + { + TIMER(Init_guiload); g_GUI.SendEventToAll("load"); + } #endif if (setup_gfx) { + TIMER(Init_renderblank); MICROLOG(L"render blank"); // render everything to a blank frame to force renderer to load everything RenderNoCull();