Skip to content

Commit

Permalink
added C++ profiler, removed unnecessary vischecking
Browse files Browse the repository at this point in the history
  • Loading branch information
@nullifiedcat
nullifiedcat committed Feb 25, 2017
1 parent 806b9e5 commit 7201cec
Show file tree
Hide file tree
Showing 6 changed files with 71 additions and 160 deletions.
2 changes: 1 addition & 1 deletion .cproject
View file
Original file line number Diff line number Diff line change
Expand Up @@ -31,7 +31,7 @@
<folderInfo id="cdt.managedbuild.config.gnu.exe.debug.1168214098." name="/" resourcePath="">
<toolChain id="cdt.managedbuild.toolchain.gnu.exe.debug.965909756" name="Linux GCC" nonInternalBuilderId="cdt.managedbuild.target.gnu.builder.exe.debug" superClass="cdt.managedbuild.toolchain.gnu.exe.debug">
<targetPlatform id="cdt.managedbuild.target.gnu.platform.exe.debug.1799148153" name="Debug Platform" superClass="cdt.managedbuild.target.gnu.platform.exe.debug"/>
<builder buildPath="${workspace_loc:/cathook}/TF2" id="cdt.managedbuild.target.gnu.builder.exe.debug.1548213350" name="Gnu Make Builder" parallelBuildOn="true" parallelizationNumber="optimal" superClass="cdt.managedbuild.target.gnu.builder.exe.debug"/>
<builder buildPath="${workspace_loc:/cathook}" id="cdt.managedbuild.target.gnu.builder.exe.debug.1548213350" keepEnvironmentInBuildfile="false" managedBuildOn="false" name="Gnu Make Builder" parallelBuildOn="true" parallelizationNumber="optimal" superClass="cdt.managedbuild.target.gnu.builder.exe.debug"/>
<tool id="cdt.managedbuild.tool.gnu.archiver.base.782611349" name="GCC Archiver" superClass="cdt.managedbuild.tool.gnu.archiver.base"/>
<tool command="g++" id="cdt.managedbuild.tool.gnu.cpp.compiler.exe.debug.883030293" name="GCC C++ Compiler" superClass="cdt.managedbuild.tool.gnu.cpp.compiler.exe.debug">
<option id="gnu.cpp.compiler.exe.debug.option.optimization.level.908662295" name="Optimization Level" superClass="gnu.cpp.compiler.exe.debug.option.optimization.level" useByScannerDiscovery="false" value="gnu.cpp.compiler.optimization.level.none" valueType="enumerated"/>
Expand Down
2 changes: 1 addition & 1 deletion makefile
View file
Original file line number Diff line number Diff line change
Expand Up @@ -21,7 +21,7 @@ OBJECTS := $(patsubst $(SRC_DIR)/%,$(OBJ_DIR)/%,$(patsubst %.cpp,%.o,$(SOURCES))

.PHONY: clean directories

all: directories cathook
all: clean directories cathook

directories:
mkdir -p bin
Expand Down
90 changes: 3 additions & 87 deletions src/entitycache.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -43,9 +43,6 @@ void EntityCache::Invalidate() {
void CachedEntity::Update(int idx) {
SEGV_BEGIN

#if ENTITY_CACHE_PROFILER == true
long p_begin = gECP.CurrentTime();
#endif
m_ESPOrigin.Zero();

m_nESPStrings = 0;
Expand Down Expand Up @@ -76,18 +73,15 @@ void CachedEntity::Update(int idx) {

m_ItemType = ITEM_NONE;

m_lSeenTicks = 0;
m_lLastSeen = 0;

m_bGrenadeProjectile = false;
m_bBonesSetup = false;

m_bVisCheckComplete = false;
if (m_pHitboxCache) {
#if ENTITY_CACHE_PROFILER == true
long p_begin = gECP.CurrentTime();
#endif
SAFE_CALL(m_pHitboxCache->Update());
#if ENTITY_CACHE_PROFILER == true
gECP.StoreData(ECPNodes::ECPN_HITBOX_UPDATE, p_begin);
#endif
}

if (m_iClassID == g_pClassID->C_Player) {
Expand Down Expand Up @@ -153,37 +147,17 @@ void CachedEntity::Update(int idx) {
m_bEnemy = (m_iTeam != g_pLocalPlayer->team);
m_iHealth = CE_INT(this, netvar.iHealth);
m_iMaxHealth = g_pPlayerResource->GetMaxHealth(this);
if (IsVisible()) {
m_lLastSeen = 0;
m_lSeenTicks++;
} else {
m_lSeenTicks = 0;
m_lLastSeen++;
}
}
if (m_Type == EntityType::ENTITY_BUILDING) {
m_iTeam = CE_INT(this, netvar.iTeamNum); // TODO
m_bEnemy = (m_iTeam != g_pLocalPlayer->team);
m_iHealth = CE_INT(this, netvar.iBuildingHealth);
m_iMaxHealth = CE_INT(this, netvar.iBuildingMaxHealth);
if (IsVisible()) {
m_lLastSeen = 0;
m_lSeenTicks++;
} else {
m_lSeenTicks = 0;
m_lLastSeen++;
}
}

#if ENTITY_CACHE_PROFILER == true
gECP.StoreData(ECPN_UPDATE, p_begin);
#endif

SEGV_END_INFO("Updating entity")
}

bool CachedEntity::IsVisible() {
long p_begin = gECP.CurrentTime();
if (m_bVisCheckComplete) return m_bAnyHitboxVisible;

bool vischeck0 = false;
Expand All @@ -192,7 +166,6 @@ bool CachedEntity::IsVisible() {
if (vischeck0) {
m_bAnyHitboxVisible = true;
m_bVisCheckComplete = true;
gECP.StoreData(ECPN_VISCHECK, p_begin);
return true;
}

Expand All @@ -202,11 +175,9 @@ bool CachedEntity::IsVisible() {
if (vischeck) {
m_bAnyHitboxVisible = true;
m_bVisCheckComplete = true;
gECP.StoreData(ECPN_VISCHECK, p_begin);
return true;
}
}
gECP.StoreData(ECPN_VISCHECK, p_begin);
m_bAnyHitboxVisible = false;
m_bVisCheckComplete = true;

Expand Down Expand Up @@ -258,66 +229,12 @@ EntityCache::~EntityCache() {
}

void EntityCache::Update() {
#if ENTITY_CACHE_PROFILER == true
long p_begin = gECP.CurrentTime();
#endif
m_nMax = interfaces::entityList->GetHighestEntityIndex();
for (int i = 0; i < m_nMax && i < MAX_ENTITIES; i++) {
//logging::Info("Updating %i", i);
m_pArray[i].Update(i);
//logging::Info("Back!");
}
#if ENTITY_CACHE_PROFILER == true
if (g_vEntityCacheProfiling->GetBool()) gECP.DoLog();
#endif
}

EntityCacheProfiling::EntityCacheProfiling() {
m_DataAvg = new long[ECPNodes::ECPN_TOTAL];
m_DataMax = new long[ECPNodes::ECPN_TOTAL];
Reset();
m_DataAvgAmount = 0;
m_nLastLog = 0;
}

EntityCacheProfiling::~EntityCacheProfiling() {
delete [] m_DataAvg;
delete [] m_DataMax;
}

long EntityCacheProfiling::CurrentTime() {
timespec ts;
clock_gettime(CLOCK_REALTIME, &ts);
return ts.tv_nsec;
}

void EntityCacheProfiling::Reset() {
for (int i = 0; i < ECPNodes::ECPN_TOTAL; i++) {
m_DataAvg[i] = 0;
m_DataMax[i] = 0;
}
m_nLastReset = CurrentTime();
m_DataAvgAmount = 0;
}

void EntityCacheProfiling::StoreData(int id, long begin) {
m_DataAvg[id] = (m_DataAvg[id] + (CurrentTime() - begin)) / 2;
if ((CurrentTime() - begin) > m_DataMax[id]) {
m_DataMax[id] = (CurrentTime() - begin);
}
}

void EntityCacheProfiling::DoLog() {
//if (CurrentTime() - m_nLastReset > 5000000000l) Reset();
if (time(0) - m_nLastLog > 2) {
logging::Info("[ECP] AVG: U:%lu (%.1f%%) | H:%lu (%.1f%%) | V:%lu (%.1f%%)",
m_DataAvg[ECPNodes::ECPN_UPDATE], 100.0f * (float)((float)m_DataAvg[ECPNodes::ECPN_UPDATE] / (float)m_DataAvg[ECPNodes::ECPN_UPDATE]),
m_DataAvg[ECPNodes::ECPN_HITBOX_UPDATE], 100.0f * (float)((float)m_DataAvg[ECPNodes::ECPN_HITBOX_UPDATE] / (float)m_DataAvg[ECPNodes::ECPN_UPDATE]),
m_DataAvg[ECPNodes::ECPN_VISCHECK], 100.0f * (float)((float)m_DataAvg[ECPNodes::ECPN_VISCHECK] / (float)m_DataAvg[ECPNodes::ECPN_UPDATE])
);
logging::Info("[ECP] MAX: U:%lu | H:%lu | V:%lu", m_DataMax[ECPNodes::ECPN_UPDATE], m_DataMax[ECPNodes::ECPN_HITBOX_UPDATE], m_DataMax[ECPNodes::ECPN_UPDATE]);
m_nLastLog = time(0);
}
}

CachedEntity* EntityCache::GetEntity(int idx) {
Expand All @@ -328,5 +245,4 @@ CachedEntity* EntityCache::GetEntity(int idx) {
return &(m_pArray[idx]);
}

EntityCacheProfiling gECP;
EntityCache gEntityCache;
31 changes: 0 additions & 31 deletions src/entitycache.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -15,8 +15,6 @@

struct matrix3x4_t;

#define ENTITY_CACHE_PROFILER false

class IClientEntity;
struct ESPStringCompound;
struct player_info_s;
Expand Down Expand Up @@ -175,35 +173,6 @@ class EntityCache {
int m_nMax;
};

enum ECPNodes {
ECPN_UPDATE,
ECPN_HITBOX_UPDATE,
ECPN_VISCHECK,
ECPN_TOTAL
};

class EntityCacheProfiling {
public:
EntityCacheProfiling();
~EntityCacheProfiling();
void Reset();
long CurrentTime();
void StoreData(int id, long time);
void DoLog();
long m_nLastReset;
long m_nLastLog;
long* m_DataAvg;
long m_DataAvgAmount;
long* m_DataMax;
};

extern EntityCacheProfiling gECP;

extern EntityCache gEntityCache;

#if ENTITY_CACHE_PROFILER == true
class CatVar;
extern CatVar* g_vEntityCacheProfiling;
#endif

#endif /* ENTITYCACHE_H_ */
60 changes: 33 additions & 27 deletions src/profiler.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -7,38 +7,44 @@

#include "profiler.h"

#include "common.h"
#include "sdk.h"
#include "logging.h"

#if ENABLE_PROFILER
ProfilerSection::ProfilerSection(std::string name) {
m_name = name;
m_calls = 0;
m_log = std::chrono::high_resolution_clock::now();
m_min = std::chrono::nanoseconds::zero();
m_max = std::chrono::nanoseconds::zero();
m_sum = std::chrono::nanoseconds::zero();
}

void ProfilerSection::OnNodeDeath(ProfilerNode& node) {
auto dur = std::chrono::duration_cast<std::chrono::nanoseconds>(std::chrono::high_resolution_clock::now() - node.m_start);
if (m_min == std::chrono::nanoseconds::zero()) m_min = dur;
else if (dur < m_min) m_min = dur;

int g_ProfilerDepth = 0;
long g_ProfilerSections[MAX_PROFILER_SECTIONS];
if (m_max == std::chrono::nanoseconds::zero()) m_max = dur;
else if (dur > m_max) m_max = dur;
m_sum += dur;
m_calls++;

void PROFILER_BeginSection() {
if (!ENABLE_PROFILER) return;
if (g_ProfilerDepth == MAX_PROFILER_SECTIONS - 1) {
logging::Info("Max profiler depth reached!");
return;
if (std::chrono::duration_cast<std::chrono::seconds>(std::chrono::high_resolution_clock::now() - m_log).count() > 3) {
logging::Info("[P] stats for '%-32s': MIN{%12llu} MAX{%12llu} AVG{%12llu}", m_name.c_str(),
std::chrono::duration_cast<std::chrono::nanoseconds>(m_min).count(),
std::chrono::duration_cast<std::chrono::nanoseconds>(m_max).count(),
std::chrono::duration_cast<std::chrono::nanoseconds>(m_sum).count() / (m_calls ? m_calls : 1));
m_log = std::chrono::high_resolution_clock::now();
m_min = std::chrono::nanoseconds::zero();
m_max = std::chrono::nanoseconds::zero();
m_sum = std::chrono::nanoseconds::zero();
m_calls = 0;
}
g_ProfilerDepth++;
timespec ts;
clock_gettime(CLOCK_REALTIME, &ts);
g_ProfilerSections[g_ProfilerDepth] = ts.tv_nsec;
}

void PROFILER_EndSection(char* name) {
if (!ENABLE_PROFILER) return;
if (g_ProfilerDepth == 0) {
logging::Info("Profiler underflow!");
return;
}
if (g_ProfilerDepth <= PROFILER_OUTPUT_DEPTH && g_Settings.bProfiler->GetBool()) {
timespec ts;
clock_gettime(CLOCK_REALTIME, &ts);
logging::Info("[PROF] %s took %ldus!", name, (ts.tv_nsec - g_ProfilerSections[g_ProfilerDepth]));
}
g_ProfilerDepth--;
ProfilerNode::ProfilerNode(ProfilerSection& section) : m_section(section) {
m_start = std::chrono::high_resolution_clock::now();
}

#endif
ProfilerNode::~ProfilerNode() {
m_section.OnNodeDeath(*this);
}
46 changes: 33 additions & 13 deletions src/profiler.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -8,23 +8,43 @@
#ifndef PROFILER_H_
#define PROFILER_H_

#include <time.h>
#include "beforecheaders.h"
#include <chrono>
#include <string>
#include "aftercheaders.h"

// TODO this whole profiler thing could be done a lot better..
class ProfilerNode;

#define ENABLE_PROFILER false
#define PROFILER_OUTPUT_DEPTH 7
#define MAX_PROFILER_SECTIONS 16
class ProfilerSection {
public:
ProfilerSection(std::string name);

#if ENABLE_PROFILER == true
#define PROF_BEGIN() PROFILER_BeginSection()
#define PROF_END(X) PROFILER_EndSection(X)
void OnNodeDeath(ProfilerNode& node);

std::chrono::nanoseconds m_min;
std::chrono::nanoseconds m_max;
std::chrono::nanoseconds m_sum;
unsigned m_calls;
std::chrono::time_point<std::chrono::high_resolution_clock> m_log;
std::string m_name;
};

class ProfilerNode {
public:
ProfilerNode(ProfilerSection& section);
~ProfilerNode();

std::chrono::time_point<std::chrono::high_resolution_clock> m_start;
ProfilerSection& m_section;
};

#define ENABLE_PROFILER true
#if ENABLE_PROFILER
#define PROF_SECTION(id) \
static ProfilerSection __PROFILER__##id(id); \
ProfilerNode __PROFILER_NODE__##id(__PROFILER__##id);
#else
#define PROF_BEGIN(X)
#define PROF_END(X)
#define PROF_SECTION(id)
#endif

void PROFILER_BeginSection();
void PROFILER_EndSection(char* name);

#endif /* PROFILER_H_ */

0 comments on commit 7201cec

Please sign in to comment.