1
0
forked from 0ad/0ad

Add per-turn counts to profiler, as well as per-frame.

Remove percent-of-parent and percent-of-frame timings since they're not
particularly useful.
Simplify profiler update code by using RingBuf.
Handle profiler keys via character codes rather than keysyms, to
hopefully work with different keyboard layouts.
Make console intercept all keys, to stop digits, shift-D, etc having
unexpected side-effects.
Disable console copy/paste when console is inactive.

This was SVN commit r8960.
This commit is contained in:
Ykkrosh 2011-02-20 20:50:26 +00:00
parent b24396740c
commit d7a243343d
8 changed files with 187 additions and 180 deletions

View File

@ -689,26 +689,26 @@ static bool isUnprintableChar(SDL_keysym key)
InReaction conInputHandler(const SDL_Event_* ev)
{
if( ev->ev.type == SDL_HOTKEYDOWN )
if (ev->ev.type == SDL_HOTKEYDOWN)
{
std::string hotkey = static_cast<const char*>(ev->ev.user.data1);
if( hotkey == "console.toggle" )
if (hotkey == "console.toggle")
{
g_Console->ToggleVisible();
return IN_HANDLED;
}
else if( hotkey == "console.copy" )
else if (g_Console->IsActive() && hotkey == "console.copy")
{
sys_clipboard_set( g_Console->GetBuffer() );
sys_clipboard_set(g_Console->GetBuffer());
return IN_HANDLED;
}
else if( hotkey == "console.paste" )
else if (g_Console->IsActive() && hotkey == "console.paste")
{
wchar_t* text = sys_clipboard_get();
if(text)
if (text)
{
for(wchar_t* c = text; *c; c++)
for (wchar_t* c = text; *c; c++)
g_Console->InsertChar(0, *c);
sys_clipboard_free(text);
@ -717,19 +717,22 @@ InReaction conInputHandler(const SDL_Event_* ev)
}
}
if( ev->ev.type != SDL_KEYDOWN)
if (!g_Console->IsActive())
return IN_PASS;
if (ev->ev.type != SDL_KEYDOWN)
return IN_PASS;
SDLKey sym = ev->ev.key.keysym.sym;
if(!g_Console->IsActive())
return IN_PASS;
// Stop unprintable characters (ctrl+, alt+ and escape),
// also prevent ` and/or ~ appearing in console every time it's toggled.
if( !isUnprintableChar(ev->ev.key.keysym) &&
!HotkeyIsPressed("console.toggle") )
g_Console->InsertChar(sym, (wchar_t)ev->ev.key.keysym.unicode );
if (!isUnprintableChar(ev->ev.key.keysym) &&
!HotkeyIsPressed("console.toggle"))
{
g_Console->InsertChar(sym, (wchar_t)ev->ev.key.keysym.unicode);
return IN_HANDLED;
}
return IN_PASS;
}

View File

@ -70,16 +70,17 @@ bool CCacheLoader::CanUseArchiveCache(const VfsPath& sourcePath, const VfsPath&
// We want to use the archive cache whenever possible,
// unless it's superseded by a source file that the user has edited
size_t sourcePriority = 0;
size_t archiveCachePriority = 0;
size_t sourcePriority = 0;
bool sourceExists = (m_VFS->GetFilePriority(sourcePath, &sourcePriority) >= 0);
bool archiveCacheExists = (m_VFS->GetFilePriority(archiveCachePath, &archiveCachePriority) >= 0);
// Can't use it if there's no cache
if (!archiveCacheExists)
return false;
bool sourceExists = (m_VFS->GetFilePriority(sourcePath, &sourcePriority) >= 0);
// Must use the cache if there's no source
if (!sourceExists)
return true;

View File

@ -236,6 +236,7 @@ bool CGame::Update(double deltaTime, bool doInterpolate)
PROFILE("update");
if (m_TurnManager->Update(deltaTime, maxTurns))
{
g_Profiler.Turn();
g_GUI->SendEventToAll("SimulationUpdate");
GetView()->GetLOSTexture().MakeDirty();
}

View File

@ -543,10 +543,10 @@ static void InitInput()
// processed.
in_add_handler(game_view_handler);
in_add_handler(conInputHandler);
in_add_handler(CProfileViewer::InputThunk);
in_add_handler(conInputHandler);
in_add_handler(HotkeyInputHandler);
// gui_handler needs to be registered after (i.e. called before!) the

View File

@ -233,17 +233,12 @@ InReaction HotkeyInputHandler( const SDL_Event_* ev )
if( g_HotkeyMap.find(keycode) == g_HotkeyMap.end() )
return( IN_PASS );
// Inhibit the dispatch of hotkey events caused by printable or control keys
// while the console is up. (But allow multiple-key - 'Ctrl+F' events, and whatever
// key toggles the console.)
// Inhibit the dispatch of hotkey events caused by real keys (not fake mouse button
// events) while the console is up.
bool consoleCapture = false;
if( g_Console->IsActive() && (
( keycode == 8 ) || ( keycode == 9 ) || ( keycode == 13 ) || /* Editing */
( ( keycode >= 32 ) && ( keycode < 273 ) ) || /* Printable (<128), 'World' (<256) */
( ( keycode >= 273 ) && ( keycode < 282 ) && /* Numeric keypad (<273), navigation */
( keycode != SDLK_INSERT ) ) ) ) /* keys (<282) except insert */
if( g_Console->IsActive() && keycode < SDLK_LAST )
consoleCapture = true;
// Here's an interesting bit:
@ -273,7 +268,6 @@ InReaction HotkeyInputHandler( const SDL_Event_* ev )
// Check to see if all auxiliary keys are down
bool accept = true;
bool isCapturable = true;
for( std::vector<SKey>::iterator itKey = it->requires.begin(); itKey != it->requires.end(); itKey++ )
{
@ -291,16 +285,9 @@ InReaction HotkeyInputHandler( const SDL_Event_* ev )
{
if( unified[itKey->code - UNIFIED_SHIFT] != rqdState ) accept = false;
}
// If this event requires a multiple keypress (with the exception
// of shift+key combinations) the console won't inhibit it.
if( rqdState && ( itKey->code != SDLK_RSHIFT ) && ( itKey->code != SDLK_LSHIFT ) )
isCapturable = false;
}
if( it->name == "console.toggle" ) isCapturable = false; // Because that would be silly.
if( accept && !( isCapturable && consoleCapture ) )
if( accept && !( consoleCapture && it->name != "console.toggle" ) )
{
// Tentatively set status to un-pressed, since it may be overridden by
// a closer match. (The closest matches will be set to pressed later.)

View File

@ -1,4 +1,4 @@
/* Copyright (C) 2009 Wildfire Games.
/* Copyright (C) 2011 Wildfire Games.
* This file is part of 0 A.D.
*
* 0 A.D. is free software: you can redistribute it and/or modify
@ -74,11 +74,12 @@ private:
ColumnDescription()
{
columns.push_back(ProfileColumn("Name", 230));
columns.push_back(ProfileColumn("calls/frame", 100));
columns.push_back(ProfileColumn("msec/frame", 100));
columns.push_back(ProfileColumn("%/frame", 100));
columns.push_back(ProfileColumn("%/parent", 100));
columns.push_back(ProfileColumn("mem allocs", 100));
columns.push_back(ProfileColumn("calls/frame", 80));
columns.push_back(ProfileColumn("msec/frame", 80));
columns.push_back(ProfileColumn("mallocs/frame", 120));
columns.push_back(ProfileColumn("calls/turn", 80));
columns.push_back(ProfileColumn("msec/turn", 80));
columns.push_back(ProfileColumn("mallocs/turn", 80));
}
};
@ -149,30 +150,38 @@ CStr CProfileNodeTable::GetCellText(size_t row, size_t col)
return "unlogged";
else if (col == 1)
return "";
else if (col == 4)
return "";
float unlogged = node->GetFrameTime();
long unlogged_mallocs = node->GetFrameMallocs();
double unlogged_time_frame = node->GetFrameTime();
double unlogged_time_turn = node->GetTurnTime();
double unlogged_mallocs_frame = node->GetFrameMallocs();
double unlogged_mallocs_turn = node->GetTurnMallocs();
CProfileNode::const_profile_iterator it;
for (it = node->GetChildren()->begin(); it != node->GetChildren()->end(); ++it)
{
unlogged -= (*it)->GetFrameTime();
unlogged_mallocs -= (*it)->GetFrameMallocs();
unlogged_time_frame -= (*it)->GetFrameTime();
unlogged_time_turn -= (*it)->GetTurnTime();
unlogged_mallocs_frame -= (*it)->GetFrameMallocs();
unlogged_mallocs_turn -= (*it)->GetTurnMallocs();
}
for (it = node->GetScriptChildren()->begin(); it != node->GetScriptChildren()->end(); ++it)
{
unlogged -= (*it)->GetFrameTime();
unlogged_mallocs -= (*it)->GetFrameMallocs();
unlogged_time_frame -= (*it)->GetFrameTime();
unlogged_time_turn -= (*it)->GetTurnTime();
unlogged_mallocs_frame -= (*it)->GetFrameMallocs();
unlogged_mallocs_turn -= (*it)->GetTurnMallocs();
}
if (col == 2)
sprintf_s(buf, ARRAY_SIZE(buf), "%.3f", unlogged * 1000.0f);
sprintf_s(buf, ARRAY_SIZE(buf), "%7.3f", unlogged_time_frame * 1000.0f);
else if (col == 3)
sprintf_s(buf, ARRAY_SIZE(buf), "%.1f", unlogged / g_Profiler.GetRoot()->GetFrameTime());
else if (col == 4)
sprintf_s(buf, ARRAY_SIZE(buf), "%.1f", unlogged * 100.0f / g_Profiler.GetRoot()->GetFrameTime());
sprintf_s(buf, ARRAY_SIZE(buf), "%7.1f", unlogged_mallocs_frame);
else if (col == 5)
sprintf_s(buf, ARRAY_SIZE(buf), "%ld", unlogged_mallocs);
sprintf_s(buf, ARRAY_SIZE(buf), "%7.3f", unlogged_time_turn * 1000.f);
else if (col == 6)
sprintf_s(buf, ARRAY_SIZE(buf), "%7.1f", unlogged_mallocs_turn);
return CStr(buf);
}
@ -184,23 +193,22 @@ CStr CProfileNodeTable::GetCellText(size_t row, size_t col)
return child->GetName();
case 1:
#ifdef PROFILE_AMORTIZE
sprintf_s(buf, ARRAY_SIZE(buf), "%.3f", child->GetFrameCalls());
#else
sprintf_s(buf, ARRAY_SIZE(buf), "%d", child->GetFrameCalls());
#endif
sprintf_s(buf, ARRAY_SIZE(buf), "%5.1f", child->GetFrameCalls());
break;
case 2:
sprintf_s(buf, ARRAY_SIZE(buf), "%.3f", child->GetFrameTime() * 1000.0f);
sprintf_s(buf, ARRAY_SIZE(buf), "%7.3f", child->GetFrameTime() * 1000.0f);
break;
case 3:
sprintf_s(buf, ARRAY_SIZE(buf), "%.1f", child->GetFrameTime() * 100.0 / g_Profiler.GetRoot()->GetFrameTime());
sprintf_s(buf, ARRAY_SIZE(buf), "%7.1f", child->GetFrameMallocs());
break;
case 4:
sprintf_s(buf, ARRAY_SIZE(buf), "%.1f", child->GetFrameTime() * 100.0 / node->GetFrameTime());
sprintf_s(buf, ARRAY_SIZE(buf), "%5.1f", child->GetTurnCalls());
break;
case 5:
sprintf_s(buf, ARRAY_SIZE(buf), "%ld", child->GetFrameMallocs());
sprintf_s(buf, ARRAY_SIZE(buf), "%7.3f", child->GetTurnTime() * 1000.0f);
break;
case 6:
sprintf_s(buf, ARRAY_SIZE(buf), "%7.1f", child->GetTurnMallocs());
break;
}
return CStr(buf);
@ -265,6 +273,44 @@ CProfileNode::~CProfileNode()
delete display_table;
}
template<typename T>
static double average(const T& collection)
{
if (collection.empty())
return 0.0;
return std::accumulate(collection.begin(), collection.end(), 0.0) / collection.size();
}
double CProfileNode::GetFrameCalls() const
{
return average(calls_per_frame);
}
double CProfileNode::GetFrameTime() const
{
return average(time_per_frame);
}
double CProfileNode::GetTurnCalls() const
{
return average(calls_per_turn);
}
double CProfileNode::GetTurnTime() const
{
return average(time_per_turn);
}
double CProfileNode::GetFrameMallocs() const
{
return average(mallocs_per_frame);
}
double CProfileNode::GetTurnMallocs() const
{
return average(mallocs_per_turn);
}
const CProfileNode* CProfileNode::GetChild( const char* childName ) const
{
const_profile_iterator it;
@ -316,75 +362,62 @@ bool CProfileNode::CanExpand()
void CProfileNode::Reset()
{
calls_total = 0;
calls_per_frame.clear();
calls_per_turn.clear();
calls_frame_current = 0;
#ifdef PROFILE_AMORTIZE
int i;
for( i = 0; i < PROFILE_AMORTIZE_FRAMES; i++ )
{
calls_frame_buffer[i] = 0;
time_frame_buffer[i] = 0.0;
}
calls_frame_last = calls_frame_buffer;
calls_frame_amortized = 0.0f;
#else
calls_frame_last = 0;
#endif
calls_turn_current = 0;
time_total = 0.0;
time_per_frame.clear();
time_per_turn.clear();
time_frame_current = 0.0;
#ifdef PROFILE_AMORTIZE
time_frame_last = time_frame_buffer;
time_frame_amortized = 0.0;
#else
time_frame_last = 0.0;
#endif
time_turn_current = 0.0;
mallocs_total = 0;
mallocs_per_frame.clear();
mallocs_per_turn.clear();
mallocs_frame_current = 0;
mallocs_frame_last = 0;
mallocs_turn_current = 0;
profile_iterator it;
for( it = children.begin(); it != children.end(); it++ )
for (it = children.begin(); it != children.end(); ++it)
(*it)->Reset();
for( it = script_children.begin(); it != script_children.end(); it++ )
for (it = script_children.begin(); it != script_children.end(); ++it)
(*it)->Reset();
}
void CProfileNode::Frame()
{
calls_total += calls_frame_current;
time_total += time_frame_current;
mallocs_total += mallocs_frame_current;
#ifdef PROFILE_AMORTIZE
calls_frame_amortized -= *calls_frame_last;
*calls_frame_last = calls_frame_current;
calls_frame_amortized += calls_frame_current;
time_frame_amortized -= *time_frame_last;
*time_frame_last = time_frame_current;
time_frame_amortized += time_frame_current;
if( ++calls_frame_last == ( calls_frame_buffer + PROFILE_AMORTIZE_FRAMES ) )
calls_frame_last = calls_frame_buffer;
if( ++time_frame_last == ( time_frame_buffer + PROFILE_AMORTIZE_FRAMES ) )
time_frame_last = time_frame_buffer;
#else
calls_frame_last = calls_frame_current;
time_frame_last = time_frame_current;
#endif
mallocs_frame_last = mallocs_frame_current;
calls_per_frame.push_back(calls_frame_current);
time_per_frame.push_back(time_frame_current);
mallocs_per_frame.push_back(mallocs_frame_current);
calls_frame_current = 0;
time_frame_current = 0.0;
mallocs_frame_current = 0;
profile_iterator it;
for( it = children.begin(); it != children.end(); it++ )
for (it = children.begin(); it != children.end(); ++it)
(*it)->Frame();
for( it = script_children.begin(); it != script_children.end(); it++ )
for (it = script_children.begin(); it != script_children.end(); ++it)
(*it)->Frame();
}
void CProfileNode::Turn()
{
calls_per_turn.push_back(calls_turn_current);
time_per_turn.push_back(time_turn_current);
mallocs_per_turn.push_back(mallocs_turn_current);
calls_turn_current = 0;
time_turn_current = 0.0;
mallocs_turn_current = 0;
profile_iterator it;
for (it = children.begin(); it != children.end(); ++it)
(*it)->Turn();
for (it = script_children.begin(); it != script_children.end(); ++it)
(*it)->Turn();
}
// TODO: these should probably only count allocations that occur in the thread being profiled
#if OS_WIN
@ -562,6 +595,7 @@ static long get_memory_alloc_count()
void CProfileNode::Call()
{
calls_frame_current++;
calls_turn_current++;
if( recursion++ == 0 )
{
start = timer_Time();
@ -571,32 +605,29 @@ void CProfileNode::Call()
bool CProfileNode::Return()
{
if( !parent ) return( false );
if (--recursion != 0)
return false;
if( ( --recursion == 0 ) && ( calls_frame_current != 0 ) )
{
time_frame_current += ( timer_Time() - start );
mallocs_frame_current += ( get_memory_alloc_count() - start_mallocs );
}
return( recursion == 0 );
double now = timer_Time();
long allocs = get_memory_alloc_count();
time_frame_current += (now - start);
time_turn_current += (now - start);
mallocs_frame_current += (allocs - start_mallocs);
mallocs_turn_current += (allocs - start_mallocs);
return true;
}
CProfileManager::CProfileManager()
CProfileManager::CProfileManager() :
root(NULL)
{
root = new CProfileNode( "root", NULL );
current = root;
StructuralReset();
frame_start = 0.0;
frame_start_mallocs = 0;
g_ProfileViewer.AddRootTable(root->display_table);
}
CProfileManager::~CProfileManager()
{
std::map<CStr8, const char*>::iterator it;
for( it = m_internedStrings.begin(); it != m_internedStrings.end(); it++ )
delete[]( it->second );
delete( root );
delete root;
}
void CProfileManager::Start( const char* name )
@ -613,20 +644,6 @@ void CProfileManager::StartScript( const char* name )
current->Call();
}
const char* CProfileManager::InternString( const CStr8& intern )
{
std::map<CStr8, const char*>::iterator it = m_internedStrings.find( intern );
if( it != m_internedStrings.end() )
return( it->second );
size_t length = intern.length();
char* data = new char[length + 1];
strcpy( data, intern.c_str() );
data[length] = 0;
m_internedStrings.insert( std::pair<CStr8, const char*>( intern, data ) );
return( data );
}
void CProfileManager::Stop()
{
if( current->Return() )
@ -644,18 +661,26 @@ void CProfileManager::Frame()
{
ONCE(alloc_hook_initialize());
root->time_frame_current = ( timer_Time() - frame_start );
root->mallocs_frame_current = ( get_memory_alloc_count() - frame_start_mallocs );
// Fake a return/call to update the root's stats
root->Return();
root->Call();
root->Frame();
frame_start = timer_Time();
frame_start_mallocs = get_memory_alloc_count();
}
void CProfileManager::Turn()
{
root->Turn();
}
void CProfileManager::StructuralReset()
{
delete( root );
root = new CProfileNode( "root", NULL );
delete root;
root = new CProfileNode("root", NULL);
root->Call();
current = root;
g_ProfileViewer.AddRootTable(root->display_table, true);
}

View File

@ -1,4 +1,4 @@
/* Copyright (C) 2009 Wildfire Games.
/* Copyright (C) 2011 Wildfire Games.
* This file is part of 0 A.D.
*
* 0 A.D. is free software: you can redistribute it and/or modify
@ -23,12 +23,13 @@
#define INCLUDED_PROFILE
#include <vector>
#include <map>
#include "Singleton.h"
#include "lib/adts.h"
#include "ps/Singleton.h"
#include "ps/ThreadUtil.h"
#define PROFILE_AMORTIZE
#define PROFILE_AMORTIZE_FRAMES 30
#define PROFILE_AMORTIZE_TURNS 1
class CProfileManager;
class CProfileNodeTable;
@ -43,29 +44,20 @@ class CProfileNode
const char* name;
int calls_total;
int calls_frame_current;
#ifdef PROFILE_AMORTIZE
int calls_frame_buffer[PROFILE_AMORTIZE_FRAMES];
int* calls_frame_last;
float calls_frame_amortized;
#else
int calls_frame_last;
#endif
int calls_turn_current;
RingBuf<int, PROFILE_AMORTIZE_FRAMES> calls_per_frame;
RingBuf<int, PROFILE_AMORTIZE_TURNS> calls_per_turn;
double time_total;
double time_frame_current;
#ifdef PROFILE_AMORTIZE
double time_frame_buffer[PROFILE_AMORTIZE_FRAMES];
double* time_frame_last;
double time_frame_amortized;
#else
double time_frame_last;
#endif
double time_turn_current;
RingBuf<double, PROFILE_AMORTIZE_FRAMES> time_per_frame;
RingBuf<double, PROFILE_AMORTIZE_TURNS> time_per_turn;
long mallocs_total;
long mallocs_frame_current;
long mallocs_frame_last;
long mallocs_turn_current;
RingBuf<long, PROFILE_AMORTIZE_FRAMES> mallocs_per_frame;
RingBuf<long, PROFILE_AMORTIZE_TURNS> mallocs_per_turn;
double start;
long start_mallocs;
@ -83,18 +75,14 @@ public:
CProfileNode( const char* name, CProfileNode* parent );
~CProfileNode();
const char* GetName() const { return( name ); }
int GetCalls() const { return( calls_total ); }
double GetTime() const { return( time_total ); }
const char* GetName() const { return name; }
#ifdef PROFILE_AMORTIZE
float GetFrameCalls() const { return( calls_frame_amortized / PROFILE_AMORTIZE_FRAMES ); }
double GetFrameTime() const { return( time_frame_amortized / PROFILE_AMORTIZE_FRAMES ); }
#else
int GetFrameCalls() const { return( calls_frame_last ); }
double GetFrameTime() const { return( time_frame_last ); }
#endif
long GetFrameMallocs() const { return( mallocs_frame_last ); }
double GetFrameCalls() const;
double GetFrameTime() const;
double GetTurnCalls() const;
double GetTurnTime() const;
double GetFrameMallocs() const;
double GetTurnMallocs() const;
const CProfileNode* GetChild( const char* name ) const;
const CProfileNode* GetScriptChild( const char* name ) const;
@ -111,6 +99,8 @@ public:
void Reset();
// Resets frame timings for this node and all its children
void Frame();
// Resets turn timings for this node and all its children
void Turn();
// Enters the node
void Call();
// Leaves the node. Returns true if the node has actually been left
@ -125,7 +115,6 @@ class CProfileManager : public Singleton<CProfileManager>
double frame_start;
long start_mallocs;
long frame_start_mallocs;
std::map<CStr8, const char*> m_internedStrings;
public:
CProfileManager();
@ -142,11 +131,12 @@ public:
void Reset();
// Resets frame timing information
void Frame();
// Resets turn timing information
// (Must not be called before Frame)
void Turn();
// Resets absolutely everything
void StructuralReset();
const char* InternString( const CStr8& intern );
inline const CProfileNode* GetCurrent() { return( current ); }
inline const CProfileNode* GetRoot() { return( root ); }
};

View File

@ -278,10 +278,10 @@ InReaction CProfileViewer::Input(const SDL_Event_* ev)
if (!m->profileVisible)
break;
int k = ev->ev.key.keysym.sym - SDLK_0;
if (k >= 0 && k <= 9)
u16 k = ev->ev.key.keysym.unicode;
if (k >= '0' && k <= '9')
{
m->NavigateTree(k);
m->NavigateTree(k - '0');
return IN_HANDLED;
}
break;