3party/easy_profiler
0
0
Fork 0
mirror of https://github.com/yse/easy_profiler.git synced 2024-12-26 08:01:51 +08:00
Code Issues Projects Releases Wiki Activity

(Core) First step for getting frame time at run-time.

Browse Source 
Now you can use EASY_FRAME_COUNTER (which is only frame-counter) or EASY_FRAME (which is EASY_FRAME_COUNTER + EASY_BLOCK) or EASY_FRAME_FUNCTION (which is EASY_FRAME_COUNTER + EASY_FUNCTION) to measure frame time even if profiler is disabled.
To get frame time you can use profiler::main_thread::frameTimeLocalMax to get maximum frame duration since last call or profiler::main_thread::frameTime to get last frame time.
--- NOTE: You have to put EASY_MAIN_THREAD to your main thread to be able to use profiler::main_thread functions.
If you do not want to then you can use same functions from profiler::this_thread, but you will have to call them from your main thread.
This commit is contained in:
Victor Zarubkin 2017-03-31 21:17:08 +03:00
parent 4b90fc3abb
commit 10b04a4748
6 changed files with 564 additions and 88 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

11
easy_profiler_core/include/easy/easy_net.h
View File

@ -73,7 +73,10 @@ enum MessageType : uint8_t
MESSAGE_TYPE_EVENT_TRACING_STATUS,
MESSAGE_TYPE_EVENT_TRACING_PRIORITY,
MESSAGE_TYPE_CHECK_CONNECTION
MESSAGE_TYPE_CHECK_CONNECTION,
MESSAGE_TYPE_REQUEST_MAIN_FRAME_LOCAL_MAX_US,
MESSAGE_TYPE_REPLY_MAIN_FRAME_LOCAL_MAX_US,
};
struct Message
@ -130,6 +133,12 @@ struct BoolMessage : public Message {
BoolMessage() = default;
};
struct TimestampMessage : public Message {
uint64_t timestamp = 0;
TimestampMessage(MessageType _t, uint64_t _timestamp) : Message(_t), timestamp(_timestamp) { }
TimestampMessage() = default;
};
#pragma pack(pop)
}//net

267
easy_profiler_core/include/easy/profiler.h
View File

@ -136,7 +136,7 @@ Name of the block automatically created with function name.
::profiler::Block EASY_UNIQUE_BLOCK(__LINE__)(EASY_UNIQUE_DESC(__LINE__), "");\
::profiler::beginBlock(EASY_UNIQUE_BLOCK(__LINE__)); // this is to avoid compiler warning about unused variable
/** Macro for completion of last opened block.
/** Macro for completion of last opened block explicitly.
\code
#include <easy/profiler.h>
@ -161,11 +161,113 @@ int foo()
*/
# define EASY_END_BLOCK ::profiler::endBlock();
/** Macro for creating event with custom name and color.
/** Macro for starting frame counter.
Event is a block with zero duration and special type.
Measures time even if profiler is disabled.
Use this if you want to observe your frame time at run-time to see if all is going right
or/and to find better moment to enable profiling.
\warning Event ends immidiately and calling EASY_END_BLOCK after EASY_EVENT
\warning This only changes value of profiler::this_thread::frameTime (or profiler::this_thread::frameTimeLocalMax).
This is not profiler::Block and is not saved to output file or sent via network.
You need to use this together with profiler::Block (or EASY_BLOCK, or EASY_FUNCTION).
\note All following calls to EASY_FRAME_COUNTER would have no effect
until EASY_END_FRAME_COUNTER called or FrameCounter object destroyed.
\note EASY_FRAME_COUNTER is not binded to Main thread only.
You are free to measure frame time of any thread you want.
\code
#include <easy/profiler.h>
int main()
{
EASY_MAIN_THREAD;
// main application cycle
while (true) {
EASY_FRAME_COUNTER; // new frame counter which is used just to get frame time
EASY_BLOCK("Frame"); // this is Frame block which would be saved into file or sent via network
// some code ...
// frame ends here
}
return 0;
}
\endcode
\ingroup profiler
*/
# define EASY_FRAME_COUNTER \
::profiler::FrameCounterGuard EASY_UNIQUE_FRAME_COUNTER(__LINE__);\
::profiler::beginFrame(EASY_UNIQUE_FRAME_COUNTER(__LINE__)); // this is to avoid compiler warning about unused variable
/** Macro for stopping frame counter explicitly.
\code
#include <easy/profiler.h>
int main()
{
EASY_MAIN_THREAD;
// main application cycle
while (true) {
EASY_FRAME_COUNTER; // new frame counter which is used just to get frame time
// some code ...
EASY_END_FRAME_COUNTER; // stop frame counter explicitly
// some another code which we do not want to profile ...
// frame really ends here, but we have explicitly said that it has ended earlier
}
return 0;
}
\endcode
\ingroup profiler
*/
# define EASY_END_FRAME_COUNTER ::profiler::endFrame();
/** Macro combining EASY_BLOCK with EASY_FRAME_COUNTER
\ingroup profiler
*/
# define EASY_FRAME(name, ...)\
EASY_LOCAL_STATIC_PTR(const ::profiler::BaseBlockDescriptor*, EASY_UNIQUE_DESC(__LINE__), ::profiler::registerDescription(::profiler::extract_enable_flag(__VA_ARGS__),\
EASY_UNIQUE_LINE_ID, EASY_COMPILETIME_NAME(name), __FILE__, __LINE__, ::profiler::BLOCK_TYPE_BLOCK, ::profiler::extract_color(__VA_ARGS__),\
::std::is_base_of<::profiler::ForceConstStr, decltype(name)>::value));\
::profiler::Block EASY_UNIQUE_BLOCK(__LINE__)(EASY_UNIQUE_DESC(__LINE__), EASY_RUNTIME_NAME(name));\
EASY_FRAME_COUNTER\
::profiler::beginBlock(EASY_UNIQUE_BLOCK(__LINE__)); // this is to avoid compiler warning about unused variable
/** Macro combining EASY_FUNCTION with EASY_FRAME_COUNTER
\ingroup profiler
*/
# define EASY_FRAME_FUNCTION(...)\
EASY_LOCAL_STATIC_PTR(const ::profiler::BaseBlockDescriptor*, EASY_UNIQUE_DESC(__LINE__), ::profiler::registerDescription(::profiler::extract_enable_flag(__VA_ARGS__),\
EASY_UNIQUE_LINE_ID, __func__, __FILE__, __LINE__, ::profiler::BLOCK_TYPE_BLOCK, ::profiler::extract_color(__VA_ARGS__), false));\
::profiler::Block EASY_UNIQUE_BLOCK(__LINE__)(EASY_UNIQUE_DESC(__LINE__), "");\
EASY_FRAME_COUNTER\
::profiler::beginBlock(EASY_UNIQUE_BLOCK(__LINE__)); // this is to avoid compiler warning about unused variable
/** Macro combining EASY_END_BLOCK with EASY_END_FRAME_COUNTER
\ingroup profiler
*/
# define EASY_END_FRAME \
EASY_END_BLOCK\
EASY_END_FRAME_COUNTER
/** Macro for creating event marker with custom name and color.
Event marker is a block with zero duration and special type.
\warning Event marker ends immidiately and calling EASY_END_BLOCK after EASY_EVENT
will end previously opened EASY_BLOCK or EASY_FUNCTION.
\ingroup profiler
@ -343,6 +445,11 @@ Otherwise, no log messages will be printed.
# define EASY_BLOCK(...)
# define EASY_FUNCTION(...)
# define EASY_END_BLOCK
# define EASY_FRAME_COUNTER
# define EASY_END_FRAME_COUNTER
# define EASY_FRAME(...)
# define EASY_FRAME_FUNCTION(...)
# define EASY_END_FRAME
# define EASY_PROFILER_ENABLE
# define EASY_PROFILER_DISABLE
# define EASY_EVENT(...)
@ -409,6 +516,12 @@ namespace profiler {
};
typedef BlockType block_type_t;
enum Duration : uint8_t
{
TICKS = 0, ///< CPU ticks
MICROSECONDS ///< Microseconds
};
//***********************************************
#pragma pack(push,1)
@ -506,12 +619,32 @@ namespace profiler {
//***********************************************
/** Scoped object used to stop frame timer implicitly.
EasyProfiler frame counter measures time even if profiler is disabled.
Use this if you want to observe your frame time at run-time to see if
all is going right or/and to find better moment to enable profiling.
\note It is not binded to Main thread only.
You are free to measure frame time of any thread you want.
\ingroup profiler
*/
class PROFILER_API FrameCounterGuard EASY_FINAL {
friend ::ProfileManager;
int8_t m_state = 0;
public:
~FrameCounterGuard();
}; // END of class FrameCounterGuard.
//***********************************************
class PROFILER_API ThreadGuard EASY_FINAL {
friend ::ProfileManager;
thread_id_t m_id = 0;
public:
~ThreadGuard();
};
}; // END of class ThreadGuard.
//////////////////////////////////////////////////////////////////////
// Core API
@ -548,6 +681,8 @@ namespace profiler {
/** Ends last started block.
Use this only if you want to finish block explicitly.
\ingroup profiler
*/
PROFILER_API void endBlock();
@ -653,13 +788,66 @@ namespace profiler {
*/
PROFILER_API const char* versionName();
/** Returns true if current thread has been marked as Main.
Otherwise, returns false.
*/
PROFILER_API bool isMainThread();
/** Begins Frame counter.
Measures time even if profiler is disabled.
Use this if you want to observe your frame time at run-time to see
if all is going right or/and to find better moment to enable profiling.
\note All following calls to beginFrame() would have no effect
until endFrame() called or FrameCounter object destroyed.
\note It is not binded to Main thread only.
You are free to measure frame time of any thread you want.
*/
PROFILER_API void beginFrame(FrameCounterGuard& _frameCounter);
/** Ends frame counter.
Use this only if you want to stop frame timer explicitly before it really finished.
*/
PROFILER_API void endFrame();
/** Returns last frame duration for current thread.
\param _durationCast desired duration units (could be cpu-ticks or microseconds)
*/
PROFILER_API timestamp_t this_thread_frameTime(Duration _durationCast);
/** Returns local max of frame duration for current thread.
Local max is maximum frame duration since last frameTimeLocalMax() call.
\param _durationCast desired duration units (could be cpu-ticks or microseconds)
*/
PROFILER_API timestamp_t this_thread_frameTimeLocalMax(Duration _durationCast);
/** Returns last frame duration for main thread.
\param _durationCast desired duration units (could be cpu-ticks or microseconds)
*/
PROFILER_API timestamp_t main_thread_frameTime(Duration _durationCast);
/** Returns local max of frame duration for main thread.
Local max is maximum frame duration since last frameTimeLocalMax() call.
\param _durationCast desired duration units (could be cpu-ticks or microseconds)
*/
PROFILER_API timestamp_t main_thread_frameTimeLocalMax(Duration _durationCast);
}
#else
inline const BaseBlockDescriptor* registerDescription(EasyBlockStatus, const char*, const char*, const char*, int, block_type_t, color_t, bool = false)
{ return reinterpret_cast<const BaseBlockDescriptor*>(0xbad); }
inline void endBlock() { }
inline void setEnabled(bool) { }
inline bool isEnabled(bool) { return false; }
inline bool isEnabled() { return false; }
inline void storeEvent(const BaseBlockDescriptor*, const char*) { }
inline void beginBlock(Block&) { }
inline uint32_t dumpBlocksToFile(const char*) { return 0; }
@ -679,8 +867,75 @@ namespace profiler {
inline uint16_t versionPatch() { return 0; }
inline uint32_t version() { return 0; }
inline const char* versionName() { return "v0.0.0_disabled"; }
inline bool isMainThread() { return false; }
inline void beginFrame(FrameCounterGuard&) { }
inline void endFrame() { }
inline timestamp_t this_thread_frameTime(Duration) { return 0; }
inline timestamp_t this_thread_frameTimeLocalMax(Duration) { return 0; }
inline timestamp_t main_thread_frameTime(Duration) { return 0; }
inline timestamp_t main_thread_frameTimeLocalMax(Duration) { return 0; }
#endif
/** API functions binded to current thread.
\ingroup profiler
*/
namespace this_thread {
inline const char* registrate(const char* _name) {
return ::profiler::registerThread(_name);
}
inline const char* registrate(const char* _name, ThreadGuard& _threadGuard) {
return ::profiler::registerThreadScoped(_name, _threadGuard);
}
inline void beginFrame(FrameCounterGuard& _frameCounter) {
::profiler::beginFrame(_frameCounter);
}
inline void endFrame() {
::profiler::endFrame();
}
inline timestamp_t frameTime(Duration _durationCast) {
return ::profiler::this_thread_frameTime(_durationCast);
}
inline timestamp_t frameTimeLocalMax(Duration _durationCast) {
return ::profiler::this_thread_frameTimeLocalMax(_durationCast);
}
inline bool isMain() {
return ::profiler::isMainThread();
}
} // END of namespace this_thread.
/** API functions binded to main thread.
Could be called from any thread.
\ingroup profiler
*/
namespace main_thread {
inline timestamp_t frameTime(Duration _durationCast) {
return ::profiler::main_thread_frameTime(_durationCast);
}
inline timestamp_t frameTimeLocalMax(Duration _durationCast) {
return ::profiler::main_thread_frameTimeLocalMax(_durationCast);
}
/** Always returns true.
*/
inline bool isMain() {
return true;
}
} // END of namespace main_thread.
//////////////////////////////////////////////////////////////////////
} // END of namespace profiler.

1
easy_profiler_core/include/easy/profiler_aux.h
View File

@ -91,6 +91,7 @@ namespace profiler {
# define EASY_TOKEN_JOIN(x, y) x ## y
# define EASY_TOKEN_CONCATENATE(x, y) EASY_TOKEN_JOIN(x, y)
# define EASY_UNIQUE_BLOCK(x) EASY_TOKEN_CONCATENATE(unique_profiler_mark_name_, x)
# define EASY_UNIQUE_FRAME_COUNTER(x) EASY_TOKEN_CONCATENATE(unique_profiler_frame_mark_name_, x)
# define EASY_UNIQUE_DESC(x) EASY_TOKEN_CONCATENATE(unique_profiler_descriptor_, x)
#ifdef BUILD_WITH_EASY_PROFILER

339
easy_profiler_core/profile_manager.cpp
View File

@ -50,6 +50,7 @@
#include <algorithm>
#include <fstream>
#include <assert.h>
#include "profile_manager.h"
#include <easy/serialized_block.h>
@ -148,6 +149,41 @@ const uint8_t FORCE_ON_FLAG = profiler::FORCE_ON & ~profiler::ON;
#ifdef _WIN32
decltype(LARGE_INTEGER::QuadPart) const CPU_FREQUENCY = ([](){ LARGE_INTEGER freq; QueryPerformanceFrequency(&freq); return freq.QuadPart; })();
# define TICKS_TO_US(ticks) ticks * 1000000LL / CPU_FREQUENCY
#elif defined(USE_STD_CHRONO)
# define TICKS_TO_US(ticks) ticks / 1000
#else
int64_t calculate_cpu_frequency()
{
double g_TicksPerNanoSec;
struct timespec begints, endts;
uint64_t begin = 0, end = 0;
clock_gettime(CLOCK_MONOTONIC, &begints);
begin = getCurrentTime();
volatile uint64_t i;
for (i = 0; i < 100000000; i++); /* must be CPU intensive */
end = getCurrentTime();
clock_gettime(CLOCK_MONOTONIC, &endts);
struct timespec tmpts;
const int NANO_SECONDS_IN_SEC = 1000000000;
tmpts.tv_sec = endts.tv_sec - begints.tv_sec;
tmpts.tv_nsec = endts.tv_nsec - begints.tv_nsec;
if (tmpts.tv_nsec < 0)
{
tmpts.tv_sec--;
tmpts.tv_nsec += NANO_SECONDS_IN_SEC;
}
uint64_t nsecElapsed = tmpts.tv_sec * 1000000000LL + tmpts.tv_nsec;
g_TicksPerNanoSec = (double)(end - begin) / (double)nsecElapsed;
int64_t cpu_frequency = int(g_TicksPerNanoSec * 1000000);
return cpu_frequency;
}
static std::atomic<int64_t> CPU_FREQUENCY = ATOMIC_VAR_INIT(1);
# define TICKS_TO_US(ticks) ticks * 1000 / CPU_FREQUENCY.load(std::memory_order_acquire)
#endif
extern const profiler::color_t EASY_COLOR_INTERNAL_EVENT = 0xffffffff; // profiler::colors::White
@ -157,8 +193,10 @@ const profiler::color_t EASY_COLOR_END = 0xfff44336; // profiler::colors::Red
//////////////////////////////////////////////////////////////////////////
EASY_THREAD_LOCAL static ::ThreadStorage* THREAD_STORAGE = nullptr;
EASY_THREAD_LOCAL static int32_t THREAD_STACK_SIZE = 0;
EASY_THREAD_LOCAL static ::ThreadStorage* THIS_THREAD = nullptr;
EASY_THREAD_LOCAL static int32_t THIS_THREAD_STACK_SIZE = 0;
EASY_THREAD_LOCAL static profiler::timestamp_t THIS_THREAD_FRAME_T = 0ULL;
EASY_THREAD_LOCAL static bool THIS_THREAD_IS_MAIN = false;
//////////////////////////////////////////////////////////////////////////
@ -187,6 +225,9 @@ EASY_THREAD_LOCAL static int32_t THREAD_STACK_SIZE = 0;
__FILE__, __LINE__, ::profiler::BLOCK_TYPE_EVENT, ::profiler::extract_color(__VA_ARGS__)));\
storeBlockForce2(ts, EASY_UNIQUE_DESC(__LINE__), EASY_RUNTIME_NAME(name), timestamp)
#else
# ifndef EASY_PROFILER_API_DISABLED
# define EASY_PROFILER_API_DISABLED
# endif
# define EASY_EVENT_RES(res, name, ...)
# define EASY_FORCE_EVENT(timestamp, name, ...)
# define EASY_FORCE_EVENT2(timestamp, name, ...)
@ -292,6 +333,64 @@ extern "C" {
{
return MANAGER.isListening();
}
PROFILER_API bool isMainThread()
{
return THIS_THREAD_IS_MAIN;
}
PROFILER_API void beginFrame(FrameCounterGuard& _frameCounter)
{
MANAGER.beginFrame(_frameCounter);
}
PROFILER_API void endFrame()
{
MANAGER.endFrame();
}
PROFILER_API timestamp_t this_thread_frameTime(Duration _durationCast)
{
assert(THIS_THREAD != nullptr);
if (_durationCast == profiler::TICKS)
return THIS_THREAD->frameTime.current;
return TICKS_TO_US(THIS_THREAD->frameTime.current);
}
PROFILER_API timestamp_t this_thread_frameTimeLocalMax(Duration _durationCast)
{
assert(THIS_THREAD != nullptr);
THIS_THREAD->frameTime.reset = true;
if (_durationCast == profiler::TICKS)
return THIS_THREAD->frameTime.maximum;
return TICKS_TO_US(THIS_THREAD->frameTime.maximum);
}
PROFILER_API timestamp_t main_thread_frameTime(Duration _durationCast)
{
const auto ticks = THIS_THREAD_IS_MAIN ? THIS_THREAD->frameTime.current : MANAGER.frameDuration();
if (_durationCast == profiler::TICKS)
return ticks;
return TICKS_TO_US(ticks);
}
PROFILER_API timestamp_t main_thread_frameTimeLocalMax(Duration _durationCast)
{
if (THIS_THREAD_IS_MAIN)
{
THIS_THREAD->frameTime.reset = true;
if (_durationCast == profiler::TICKS)
return THIS_THREAD->frameTime.maximum;
return TICKS_TO_US(THIS_THREAD->frameTime.maximum);
}
if (_durationCast == profiler::TICKS)
return MANAGER.maxFrameDuration();
return TICKS_TO_US(MANAGER.maxFrameDuration());
}
#else
PROFILER_API const BaseBlockDescriptor* registerDescription(EasyBlockStatus, const char*, const char*, const char*, int, block_type_t, color_t, bool) { return reinterpret_cast<const BaseBlockDescriptor*>(0xbad); }
PROFILER_API void endBlock() { }
@ -299,6 +398,8 @@ extern "C" {
PROFILER_API bool isEnabled() { return false; }
PROFILER_API void storeEvent(const BaseBlockDescriptor*, const char*) { }
PROFILER_API void beginBlock(Block&) { }
PROFILER_API void beginFrame(FrameCounter&) { }
PROFILER_API void endFrame() { }
PROFILER_API uint32_t dumpBlocksToFile(const char*) { return 0; }
PROFILER_API const char* registerThreadScoped(const char*, ThreadGuard&) { return ""; }
PROFILER_API const char* registerThread(const char*) { return ""; }
@ -311,6 +412,12 @@ extern "C" {
PROFILER_API void startListen(uint16_t) { }
PROFILER_API void stopListen() { }
PROFILER_API bool isListening() { return false; }
PROFILER_API bool isMainThread() { return false; }
PROFILER_API timestamp_t this_thread_frameTime(Duration) { return 0; }
PROFILER_API timestamp_t this_thread_frameTimeLocalMax(Duration) { return 0; }
PROFILER_API timestamp_t main_thread_frameTime(Duration) { return 0; }
PROFILER_API timestamp_t main_thread_frameTimeLocalMax(Duration) { return 0; }
#endif
PROFILER_API uint8_t versionMajor()
@ -493,13 +600,27 @@ void ThreadStorage::clearClosed()
ThreadGuard::~ThreadGuard()
{
#ifndef EASY_PROFILER_API_DISABLED
if (m_id != 0 && THREAD_STORAGE != nullptr && THREAD_STORAGE->id == m_id)
if (m_id != 0 && THIS_THREAD != nullptr && THIS_THREAD->id == m_id)
{
bool isMarked = false;
EASY_EVENT_RES(isMarked, "ThreadFinished", EASY_COLOR_THREAD_END, ::profiler::FORCE_ON);
THREAD_STORAGE->frame.store(false, std::memory_order_release);
THREAD_STORAGE->expired.store(isMarked ? 2 : 1, std::memory_order_release);
THREAD_STORAGE = nullptr;
THIS_THREAD->frame.store(false, std::memory_order_release);
THIS_THREAD->expired.store(isMarked ? 2 : 1, std::memory_order_release);
THIS_THREAD = nullptr;
}
#endif
}
//////////////////////////////////////////////////////////////////////////
FrameCounterGuard::~FrameCounterGuard()
{
#ifndef EASY_PROFILER_API_DISABLED
if (m_state & 2)
{
if (m_state & 1)
MANAGER.endFrame();
THIS_THREAD->frameCounters.pop_back();
}
#endif
}
@ -524,6 +645,11 @@ ProfileManager::ProfileManager() :
#if !defined(EASY_PROFILER_API_DISABLED) && EASY_OPTION_START_LISTEN_ON_STARTUP != 0
startListen(profiler::DEFAULT_PORT);
#endif
#if !defined(EASY_PROFILER_API_DISABLED) && !defined(_WIN32) && !defined(USE_STD_CHRONO)
const int64_t cpu_frequency = calculate_cpu_frequency();
CPU_FREQUENCY.store(cpu_frequency, std::memory_order_release);
#endif
}
ProfileManager::~ProfileManager()
@ -633,16 +759,16 @@ bool ProfileManager::storeBlock(const profiler::BaseBlockDescriptor* _desc, cons
if (state == EASY_PROF_DUMP)
{
if (THREAD_STORAGE == nullptr || THREAD_STORAGE->blocks.openedList.empty())
if (THIS_THREAD == nullptr || THIS_THREAD->blocks.openedList.empty())
return false;
}
else if (THREAD_STORAGE == nullptr)
else if (THIS_THREAD == nullptr)
{
THREAD_STORAGE = &threadStorage(getCurrentThreadId());
THIS_THREAD = &threadStorage(getCurrentThreadId());
}
#if EASY_ENABLE_BLOCK_STATUS != 0
if (!THREAD_STORAGE->allowChildren && !(_desc->m_status & FORCE_ON_FLAG))
if (!THIS_THREAD->allowChildren && !(_desc->m_status & FORCE_ON_FLAG))
return false;
#endif
@ -650,7 +776,7 @@ bool ProfileManager::storeBlock(const profiler::BaseBlockDescriptor* _desc, cons
b.start();
b.m_end = b.m_begin;
THREAD_STORAGE->storeBlock(b);
THIS_THREAD->storeBlock(b);
return true;
}
@ -662,11 +788,11 @@ void ProfileManager::storeBlockForce(const profiler::BaseBlockDescriptor* _desc,
if (!(_desc->m_status & profiler::ON))
return;
if (THREAD_STORAGE == nullptr)
THREAD_STORAGE = &threadStorage(getCurrentThreadId());
if (THIS_THREAD == nullptr)
THIS_THREAD = &threadStorage(getCurrentThreadId());
#if EASY_ENABLE_BLOCK_STATUS != 0
if (!THREAD_STORAGE->allowChildren && !(_desc->m_status & FORCE_ON_FLAG))
if (!THIS_THREAD->allowChildren && !(_desc->m_status & FORCE_ON_FLAG))
return;
#endif
@ -675,7 +801,7 @@ void ProfileManager::storeBlockForce(const profiler::BaseBlockDescriptor* _desc,
b.m_end = b.m_begin;
_timestamp = b.m_begin;
THREAD_STORAGE->storeBlock(b);
THIS_THREAD->storeBlock(b);
}
void ProfileManager::storeBlockForce2(const profiler::BaseBlockDescriptor* _desc, const char* _runtimeName, ::profiler::timestamp_t _timestamp)
@ -683,18 +809,18 @@ void ProfileManager::storeBlockForce2(const profiler::BaseBlockDescriptor* _desc
if (!(_desc->m_status & profiler::ON))
return;
if (THREAD_STORAGE == nullptr)
THREAD_STORAGE = &threadStorage(getCurrentThreadId());
if (THIS_THREAD == nullptr)
THIS_THREAD = &threadStorage(getCurrentThreadId());
#if EASY_ENABLE_BLOCK_STATUS != 0
if (!THREAD_STORAGE->allowChildren && !(_desc->m_status & FORCE_ON_FLAG))
if (!THIS_THREAD->allowChildren && !(_desc->m_status & FORCE_ON_FLAG))
return;
#endif
profiler::Block b(_desc, _runtimeName);
b.m_end = b.m_begin = _timestamp;
THREAD_STORAGE->storeBlock(b);
THIS_THREAD->storeBlock(b);
}
void ProfileManager::storeBlockForce2(ThreadStorage& _registeredThread, const profiler::BaseBlockDescriptor* _desc, const char* _runtimeName, ::profiler::timestamp_t _timestamp)
@ -708,38 +834,38 @@ void ProfileManager::storeBlockForce2(ThreadStorage& _registeredThread, const pr
void ProfileManager::beginBlock(Block& _block)
{
if (++THREAD_STACK_SIZE > 1)
if (++THIS_THREAD_STACK_SIZE > 1)
return;
const auto state = m_profilerStatus.load(std::memory_order_acquire);
if (state == EASY_PROF_DISABLED)
return;
THREAD_STACK_SIZE = 0;
THIS_THREAD_STACK_SIZE = 0;
bool empty = true;
if (state == EASY_PROF_DUMP)
{
if (THREAD_STORAGE == nullptr || THREAD_STORAGE->blocks.openedList.empty())
if (THIS_THREAD == nullptr || THIS_THREAD->blocks.openedList.empty())
return;
empty = false;
}
else if (THREAD_STORAGE == nullptr)
else if (THIS_THREAD == nullptr)
{
THREAD_STORAGE = &threadStorage(getCurrentThreadId());
THIS_THREAD = &threadStorage(getCurrentThreadId());
}
else
{
empty = THREAD_STORAGE->blocks.openedList.empty();
empty = THIS_THREAD->blocks.openedList.empty();
}
#if EASY_ENABLE_BLOCK_STATUS != 0
if (THREAD_STORAGE->allowChildren)
if (THIS_THREAD->allowChildren)
{
#endif
if (_block.m_status & profiler::ON)
_block.start();
#if EASY_ENABLE_BLOCK_STATUS != 0
THREAD_STORAGE->allowChildren = !(_block.m_status & profiler::OFF_RECURSIVE);
THIS_THREAD->allowChildren = !(_block.m_status & profiler::OFF_RECURSIVE);
}
else if (_block.m_status & FORCE_ON_FLAG)
{
@ -753,8 +879,8 @@ void ProfileManager::beginBlock(Block& _block)
#endif
if (empty)
THREAD_STORAGE->frame.store(true, std::memory_order_release);
THREAD_STORAGE->blocks.openedList.emplace(_block);
THIS_THREAD->frame.store(true, std::memory_order_release);
THIS_THREAD->blocks.openedList.emplace(_block);
}
void ProfileManager::beginContextSwitch(profiler::thread_id_t _thread_id, profiler::timestamp_t _time, profiler::thread_id_t _target_thread_id, const char* _target_process, bool _lockSpin)
@ -770,32 +896,32 @@ void ProfileManager::beginContextSwitch(profiler::thread_id_t _thread_id, profil
void ProfileManager::endBlock()
{
if (--THREAD_STACK_SIZE > 0 || m_profilerStatus.load(std::memory_order_acquire) == EASY_PROF_DISABLED)
if (--THIS_THREAD_STACK_SIZE > 0 || m_profilerStatus.load(std::memory_order_acquire) == EASY_PROF_DISABLED)
return;
THREAD_STACK_SIZE = 0;
if (THREAD_STORAGE == nullptr || THREAD_STORAGE->blocks.openedList.empty())
THIS_THREAD_STACK_SIZE = 0;
if (THIS_THREAD == nullptr || THIS_THREAD->blocks.openedList.empty())
return;
Block& lastBlock = THREAD_STORAGE->blocks.openedList.top();
Block& lastBlock = THIS_THREAD->blocks.openedList.top();
if (lastBlock.m_status & profiler::ON)
{
if (!lastBlock.finished())
lastBlock.finish();
THREAD_STORAGE->storeBlock(lastBlock);
THIS_THREAD->storeBlock(lastBlock);
}
else
{
lastBlock.m_end = lastBlock.m_begin; // this is to restrict endBlock() call inside ~Block()
}
THREAD_STORAGE->blocks.openedList.pop();
const bool empty = THREAD_STORAGE->blocks.openedList.empty();
THIS_THREAD->blocks.openedList.pop();
const bool empty = THIS_THREAD->blocks.openedList.empty();
if (empty)
THREAD_STORAGE->frame.store(false, std::memory_order_release);
THIS_THREAD->frame.store(false, std::memory_order_release);
#if EASY_ENABLE_BLOCK_STATUS != 0
THREAD_STORAGE->allowChildren = empty || !(THREAD_STORAGE->blocks.openedList.top().get().m_status & profiler::OFF_RECURSIVE);
THIS_THREAD->allowChildren = empty || !(THIS_THREAD->blocks.openedList.top().get().m_status & profiler::OFF_RECURSIVE);
#endif
}
@ -821,6 +947,71 @@ void ProfileManager::endContextSwitch(profiler::thread_id_t _thread_id, processi
//////////////////////////////////////////////////////////////////////////
void ProfileManager::beginFrame(profiler::FrameCounterGuard& _frameCounter)
{
if (THIS_THREAD == nullptr)
THIS_THREAD = &threadStorage(getCurrentThreadId());
if (THIS_THREAD->frameCounters.empty())
{
THIS_THREAD_FRAME_T = getCurrentTime();
_frameCounter.m_state = 3; // in thread list and started
}
else
{
_frameCounter.m_state = 2; // in thread list, but not started
}
THIS_THREAD->frameCounters.emplace_back(_frameCounter);
}
void ProfileManager::endFrame()
{
assert(THIS_THREAD != nullptr && !THIS_THREAD->frameCounters.empty());
profiler::FrameCounterGuard& frameCounter = THIS_THREAD->frameCounters.back();
if (frameCounter.m_state & 1)
{
const profiler::timestamp_t duration = getCurrentTime() - THIS_THREAD_FRAME_T;
frameCounter.m_state = 2; // stayed in thread list, but already finished
if (THIS_THREAD->frameTime.reset) {
THIS_THREAD->frameTime.reset = false;
THIS_THREAD->frameTime.maximum = 0;
}
THIS_THREAD->frameTime.current = duration;
if (duration > THIS_THREAD->frameTime.maximum)
THIS_THREAD->frameTime.maximum = duration;
if (THIS_THREAD_IS_MAIN)
{
auto maxDuration = m_frameMax.load(std::memory_order_acquire);
if (m_frameReset.exchange(false, std::memory_order_release))
maxDuration = 0;
if (duration > maxDuration)
m_frameMax.store(duration, std::memory_order_release);
m_frameCurr.store(duration, std::memory_order_release);
}
}
}
profiler::timestamp_t ProfileManager::maxFrameDuration()
{
auto duration = m_frameMax.load(std::memory_order_acquire);
m_frameReset.store(true, std::memory_order_release);
return duration;
}
profiler::timestamp_t ProfileManager::frameDuration() const
{
return m_frameCurr.load(std::memory_order_acquire);
}
//////////////////////////////////////////////////////////////////////////
void ProfileManager::enableEventTracer()
{
#ifdef _WIN32
@ -1054,32 +1245,11 @@ uint32_t ProfileManager::dumpBlocksToStream(profiler::OStream& _outputStream, bo
#if !defined(USE_STD_CHRONO)
EASY_LOGMSG("Calculating CPU frequency\n");
double g_TicksPerNanoSec;
struct timespec begints, endts;
uint64_t begin = 0, end = 0;
clock_gettime(CLOCK_MONOTONIC, &begints);
begin = getCurrentTime();
volatile uint64_t i;
for (i = 0; i < 100000000; i++); /* must be CPU intensive */
end = getCurrentTime();
clock_gettime(CLOCK_MONOTONIC, &endts);
struct timespec tmpts;
const int NANO_SECONDS_IN_SEC = 1000000000;
tmpts.tv_sec = endts.tv_sec - begints.tv_sec;
tmpts.tv_nsec = endts.tv_nsec - begints.tv_nsec;
if (tmpts.tv_nsec < 0) {
tmpts.tv_sec--;
tmpts.tv_nsec += NANO_SECONDS_IN_SEC;
}
const int64_t cpu_frequency = calculate_cpu_frequency();
_outputStream.write(cpu_frequency * 1000LL);
EASY_LOGMSG("Done calculating CPU frequency\n");
uint64_t nsecElapsed = tmpts.tv_sec * 1000000000LL + tmpts.tv_nsec;
g_TicksPerNanoSec = (double)(end - begin)/(double)nsecElapsed;
int64_t cpu_frequency = int(g_TicksPerNanoSec*1000000);
_outputStream.write(cpu_frequency*1000LL);
EASY_LOGMSG("Done calculating CPU frequency\n");
CPU_FREQUENCY.store(cpu_frequency, std::memory_order_release);
#else
_outputStream.write(0LL);
#endif
@ -1180,31 +1350,33 @@ uint32_t ProfileManager::dumpBlocksToFile(const char* _filename)
const char* ProfileManager::registerThread(const char* name, ThreadGuard& threadGuard)
{
if (THREAD_STORAGE == nullptr)
THREAD_STORAGE = &threadStorage(getCurrentThreadId());
if (THIS_THREAD == nullptr)
THIS_THREAD = &threadStorage(getCurrentThreadId());
THREAD_STORAGE->guarded = true;
if (!THREAD_STORAGE->named) {
THREAD_STORAGE->named = true;
THREAD_STORAGE->name = name;
THIS_THREAD->guarded = true;
if (!THIS_THREAD->named) {
THIS_THREAD->named = true;
THIS_THREAD->name = name;
THIS_THREAD_IS_MAIN = !strncmp(name, "Main", 4);
}
threadGuard.m_id = THREAD_STORAGE->id;
threadGuard.m_id = THIS_THREAD->id;
return THREAD_STORAGE->name.c_str();
return THIS_THREAD->name.c_str();
}
const char* ProfileManager::registerThread(const char* name)
{
if (THREAD_STORAGE == nullptr)
THREAD_STORAGE = &threadStorage(getCurrentThreadId());
if (THIS_THREAD == nullptr)
THIS_THREAD = &threadStorage(getCurrentThreadId());
if (!THREAD_STORAGE->named) {
THREAD_STORAGE->named = true;
THREAD_STORAGE->name = name;
if (!THIS_THREAD->named) {
THIS_THREAD->named = true;
THIS_THREAD->name = name;
THIS_THREAD_IS_MAIN = !strncmp(name, "Main", 4);
}
return THREAD_STORAGE->name.c_str();
return THIS_THREAD->name.c_str();
}
void ProfileManager::setBlockStatus(block_id_t _id, EasyBlockStatus _status)
@ -1278,8 +1450,8 @@ void ProfileManager::listen(uint16_t _port)
#else
false;
#endif
profiler::net::EasyProfilerStatus connectionReply(m_profilerStatus.load(std::memory_order_acquire) == EASY_PROF_ENABLED, m_isEventTracingEnabled.load(std::memory_order_acquire), wasLowPriorityET);
bytes = socket.send(&connectionReply, sizeof(connectionReply));
const profiler::net::EasyProfilerStatus connectionReply(m_profilerStatus.load(std::memory_order_acquire) == EASY_PROF_ENABLED, m_isEventTracingEnabled.load(std::memory_order_acquire), wasLowPriorityET);
bytes = socket.send(&connectionReply, sizeof(profiler::net::EasyProfilerStatus));
hasConnect = bytes > 0;
}
@ -1308,6 +1480,15 @@ void ProfileManager::listen(uint16_t _port)
break;
}
case profiler::net::MESSAGE_TYPE_REQUEST_MAIN_FRAME_LOCAL_MAX_US:
{
const profiler::timestamp_t duration = TICKS_TO_US(MANAGER.maxFrameDuration());
const profiler::net::TimestampMessage reply(profiler::net::MESSAGE_TYPE_REPLY_MAIN_FRAME_LOCAL_MAX_US, duration);
bytes = socket.send(&reply, sizeof(profiler::net::TimestampMessage));
hasConnect = bytes > 0;
break;
}
case profiler::net::MESSAGE_TYPE_REQUEST_START_CAPTURE:
{
EASY_LOGMSG("receive REQUEST_START_CAPTURE\n");

15
easy_profiler_core/profile_manager.h
View File

@ -320,13 +320,19 @@ struct BlocksList
}
};
struct ThreadStorage
{
BlocksList<std::reference_wrapper<profiler::Block>, SIZEOF_CSWITCH * (uint16_t)128U> blocks;
BlocksList<profiler::Block, SIZEOF_CSWITCH * (uint16_t)128U> sync;
std::vector<std::reference_wrapper<profiler::FrameCounterGuard> > frameCounters;
std::string name;
struct {
profiler::timestamp_t maximum = 0;
profiler::timestamp_t current = 0;
bool reset = false;
} frameTime;
#ifndef _WIN32
const pthread_t pthread_id;
#endif
@ -379,12 +385,15 @@ class ProfileManager
uint64_t m_usedMemorySize;
profiler::timestamp_t m_beginTime;
profiler::timestamp_t m_endTime;
std::atomic<profiler::timestamp_t> m_frameMax;
std::atomic<profiler::timestamp_t> m_frameCurr;
profiler::spin_lock m_spin;
profiler::spin_lock m_storedSpin;
profiler::spin_lock m_dumpSpin;
std::atomic<char> m_profilerStatus;
std::atomic_bool m_isEventTracingEnabled;
std::atomic_bool m_isAlreadyListening;
std::atomic_bool m_frameReset;
std::string m_csInfoFilename = "/tmp/cs_profiling_info.log";
@ -413,6 +422,10 @@ public:
bool storeBlock(const profiler::BaseBlockDescriptor* _desc, const char* _runtimeName);
void beginBlock(profiler::Block& _block);
void endBlock();
void beginFrame(profiler::FrameCounterGuard& _frameCounter);
void endFrame();
profiler::timestamp_t maxFrameDuration();
profiler::timestamp_t frameDuration() const;
void setEnabled(bool isEnable);
bool isEnabled() const;
void setEventTracingEnabled(bool _isEnable);

19
sample/main.cpp
View File

@ -19,7 +19,7 @@ int MODELLING_STEPS = 1500;
int RENDER_STEPS = 1500;
int RESOURCE_LOADING_COUNT = 50;
#define SAMPLE_NETWORK_TEST
//#define SAMPLE_NETWORK_TEST
void localSleep(int magic=200000)
{
@ -158,7 +158,10 @@ void modellingThread(){
#else
for (int i = 0; i < MODELLING_STEPS; i++){
#endif
EASY_FRAME_COUNTER;
modellingStep();
EASY_END_FRAME_COUNTER;
localSleep(1200000);
//std::this_thread::sleep_for(std::chrono::milliseconds(20));
}
@ -223,11 +226,25 @@ int main(int argc, char* argv[])
cv_m.unlock();
cv.notify_all();
std::atomic_bool stop = ATOMIC_VAR_INIT(false);
auto ttt = std::thread([&stop]()
{
while (!stop.load(std::memory_order_acquire))
{
std::cout << "Frame time: " << profiler::main_thread::frameTimeLocalMax(profiler::MICROSECONDS) << " us\n";
std::this_thread::sleep_for(std::chrono::seconds(1));
}
});
modellingThread();
stop.store(true, std::memory_order_release);
for(auto& t : threads)
t.join();
ttt.join();
auto end = std::chrono::system_clock::now();
auto elapsed =
std::chrono::duration_cast<std::chrono::microseconds>(end - start);