0
0
mirror of https://github.com/yse/easy_profiler.git synced 2024-12-26 08:01:51 +08:00

(Core) Frame counter: significantly simplified interface - there is no need to start frame counter explicitly. Top block is frame.

This commit is contained in:
Victor Zarubkin 2017-04-02 14:23:11 +03:00
parent 10b04a4748
commit a2b62613a2
4 changed files with 83 additions and 260 deletions

View File

@ -161,108 +161,6 @@ int foo()
*/
# define EASY_END_BLOCK ::profiler::endBlock();
/** Macro for starting 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.
\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.
@ -445,11 +343,6 @@ 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(...)
@ -619,26 +512,6 @@ 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;
@ -793,31 +666,11 @@ namespace profiler {
*/
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);
PROFILER_API timestamp_t this_thread_frameTime(Duration _durationCast = ::profiler::MICROSECONDS);
/** Returns local max of frame duration for current thread.
@ -825,13 +678,13 @@ namespace profiler {
\param _durationCast desired duration units (could be cpu-ticks or microseconds)
*/
PROFILER_API timestamp_t this_thread_frameTimeLocalMax(Duration _durationCast);
PROFILER_API timestamp_t this_thread_frameTimeLocalMax(Duration _durationCast = ::profiler::MICROSECONDS);
/** 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);
PROFILER_API timestamp_t main_thread_frameTime(Duration _durationCast = ::profiler::MICROSECONDS);
/** Returns local max of frame duration for main thread.
@ -839,7 +692,7 @@ namespace profiler {
\param _durationCast desired duration units (could be cpu-ticks or microseconds)
*/
PROFILER_API timestamp_t main_thread_frameTimeLocalMax(Duration _durationCast);
PROFILER_API timestamp_t main_thread_frameTimeLocalMax(Duration _durationCast = ::profiler::MICROSECONDS);
}
#else
@ -868,12 +721,10 @@ namespace profiler {
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; }
inline timestamp_t this_thread_frameTime(Duration = ::profiler::MICROSECONDS) { return 0; }
inline timestamp_t this_thread_frameTimeLocalMax(Duration = ::profiler::MICROSECONDS) { return 0; }
inline timestamp_t main_thread_frameTime(Duration = ::profiler::MICROSECONDS) { return 0; }
inline timestamp_t main_thread_frameTimeLocalMax(Duration = ::profiler::MICROSECONDS) { return 0; }
#endif
/** API functions binded to current thread.
@ -890,19 +741,11 @@ namespace profiler {
return ::profiler::registerThreadScoped(_name, _threadGuard);
}
inline void beginFrame(FrameCounterGuard& _frameCounter) {
::profiler::beginFrame(_frameCounter);
}
inline void endFrame() {
::profiler::endFrame();
}
inline timestamp_t frameTime(Duration _durationCast) {
inline timestamp_t frameTime(Duration _durationCast = ::profiler::MICROSECONDS) {
return ::profiler::this_thread_frameTime(_durationCast);
}
inline timestamp_t frameTimeLocalMax(Duration _durationCast) {
inline timestamp_t frameTimeLocalMax(Duration _durationCast = ::profiler::MICROSECONDS) {
return ::profiler::this_thread_frameTimeLocalMax(_durationCast);
}
@ -920,11 +763,11 @@ namespace profiler {
*/
namespace main_thread {
inline timestamp_t frameTime(Duration _durationCast) {
inline timestamp_t frameTime(Duration _durationCast = ::profiler::MICROSECONDS) {
return ::profiler::main_thread_frameTime(_durationCast);
}
inline timestamp_t frameTimeLocalMax(Duration _durationCast) {
inline timestamp_t frameTimeLocalMax(Duration _durationCast = ::profiler::MICROSECONDS) {
return ::profiler::main_thread_frameTimeLocalMax(_durationCast);
}

View File

@ -196,8 +196,13 @@ const profiler::color_t EASY_COLOR_END = 0xfff44336; // profiler::colors::Red
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_FRAME = false;
EASY_THREAD_LOCAL static bool THIS_THREAD_IS_MAIN = false;
EASY_THREAD_LOCAL static profiler::timestamp_t THIS_THREAD_FRAME_T_MAX = 0ULL;
EASY_THREAD_LOCAL static profiler::timestamp_t THIS_THREAD_FRAME_T_CUR = 0ULL;
EASY_THREAD_LOCAL static bool THIS_THREAD_FRAME_T_RESET = false;
//////////////////////////////////////////////////////////////////////////
#ifdef BUILD_WITH_EASY_PROFILER
@ -339,38 +344,24 @@ extern "C" {
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);
return THIS_THREAD_FRAME_T_CUR;
return TICKS_TO_US(THIS_THREAD_FRAME_T_CUR);
}
PROFILER_API timestamp_t this_thread_frameTimeLocalMax(Duration _durationCast)
{
assert(THIS_THREAD != nullptr);
THIS_THREAD->frameTime.reset = true;
THIS_THREAD_FRAME_T_RESET = true;
if (_durationCast == profiler::TICKS)
return THIS_THREAD->frameTime.maximum;
return TICKS_TO_US(THIS_THREAD->frameTime.maximum);
return THIS_THREAD_FRAME_T_MAX;
return TICKS_TO_US(THIS_THREAD_FRAME_T_MAX);
}
PROFILER_API timestamp_t main_thread_frameTime(Duration _durationCast)
{
const auto ticks = THIS_THREAD_IS_MAIN ? THIS_THREAD->frameTime.current : MANAGER.frameDuration();
const auto ticks = THIS_THREAD_IS_MAIN ? THIS_THREAD_FRAME_T_CUR : MANAGER.frameDuration();
if (_durationCast == profiler::TICKS)
return ticks;
return TICKS_TO_US(ticks);
@ -380,10 +371,10 @@ extern "C" {
{
if (THIS_THREAD_IS_MAIN)
{
THIS_THREAD->frameTime.reset = true;
THIS_THREAD_FRAME_T_RESET = true;
if (_durationCast == profiler::TICKS)
return THIS_THREAD->frameTime.maximum;
return TICKS_TO_US(THIS_THREAD->frameTime.maximum);
return THIS_THREAD_FRAME_T_MAX;
return TICKS_TO_US(THIS_THREAD_FRAME_T_MAX);
}
if (_durationCast == profiler::TICKS)
@ -398,8 +389,6 @@ 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 ""; }
@ -613,20 +602,6 @@ ThreadGuard::~ThreadGuard()
//////////////////////////////////////////////////////////////////////////
FrameCounterGuard::~FrameCounterGuard()
{
#ifndef EASY_PROFILER_API_DISABLED
if (m_state & 2)
{
if (m_state & 1)
MANAGER.endFrame();
THIS_THREAD->frameCounters.pop_back();
}
#endif
}
//////////////////////////////////////////////////////////////////////////
ProfileManager::ProfileManager() :
#ifdef _WIN32
m_processId(GetProcessId(GetCurrentProcess()))
@ -839,9 +814,11 @@ void ProfileManager::beginBlock(Block& _block)
const auto state = m_profilerStatus.load(std::memory_order_acquire);
if (state == EASY_PROF_DISABLED)
{
beginFrame();
return;
}
THIS_THREAD_STACK_SIZE = 0;
bool empty = true;
if (state == EASY_PROF_DUMP)
{
@ -858,6 +835,8 @@ void ProfileManager::beginBlock(Block& _block)
empty = THIS_THREAD->blocks.openedList.empty();
}
THIS_THREAD_STACK_SIZE = 0;
#if EASY_ENABLE_BLOCK_STATUS != 0
if (THIS_THREAD->allowChildren)
{
@ -879,7 +858,11 @@ void ProfileManager::beginBlock(Block& _block)
#endif
if (empty)
{
beginFrame();
THIS_THREAD->frame.store(true, std::memory_order_release);
}
THIS_THREAD->blocks.openedList.emplace(_block);
}
@ -896,9 +879,15 @@ void ProfileManager::beginContextSwitch(profiler::thread_id_t _thread_id, profil
void ProfileManager::endBlock()
{
if (--THIS_THREAD_STACK_SIZE > 0 || m_profilerStatus.load(std::memory_order_acquire) == EASY_PROF_DISABLED)
if (--THIS_THREAD_STACK_SIZE > 0)
return;
if (m_profilerStatus.load(std::memory_order_acquire) == EASY_PROF_DISABLED)
{
endFrame();
return;
}
THIS_THREAD_STACK_SIZE = 0;
if (THIS_THREAD == nullptr || THIS_THREAD->blocks.openedList.empty())
return;
@ -918,10 +907,18 @@ void ProfileManager::endBlock()
THIS_THREAD->blocks.openedList.pop();
const bool empty = THIS_THREAD->blocks.openedList.empty();
if (empty)
{
THIS_THREAD->frame.store(false, std::memory_order_release);
endFrame();
#if EASY_ENABLE_BLOCK_STATUS != 0
THIS_THREAD->allowChildren = empty || !(THIS_THREAD->blocks.openedList.top().get().m_status & profiler::OFF_RECURSIVE);
THIS_THREAD->allowChildren = true;
}
else
{
THIS_THREAD->allowChildren = !(THIS_THREAD->blocks.openedList.top().get().m_status & profiler::OFF_RECURSIVE);
}
#else
}
#endif
}
@ -947,54 +944,43 @@ void ProfileManager::endContextSwitch(profiler::thread_id_t _thread_id, processi
//////////////////////////////////////////////////////////////////////////
void ProfileManager::beginFrame(profiler::FrameCounterGuard& _frameCounter)
void ProfileManager::beginFrame()
{
if (THIS_THREAD == nullptr)
THIS_THREAD = &threadStorage(getCurrentThreadId());
if (THIS_THREAD->frameCounters.empty())
if (!THIS_THREAD_FRAME)
{
THIS_THREAD_FRAME_T = getCurrentTime();
_frameCounter.m_state = 3; // in thread list and started
THIS_THREAD_FRAME = true;
}
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());
if (!THIS_THREAD_FRAME)
return;
profiler::FrameCounterGuard& frameCounter = THIS_THREAD->frameCounters.back();
if (frameCounter.m_state & 1)
const profiler::timestamp_t duration = getCurrentTime() - THIS_THREAD_FRAME_T;
THIS_THREAD_FRAME = false;
if (THIS_THREAD_FRAME_T_RESET)
{
const profiler::timestamp_t duration = getCurrentTime() - THIS_THREAD_FRAME_T;
THIS_THREAD_FRAME_T_RESET = false;
THIS_THREAD_FRAME_T_MAX = 0;
}
frameCounter.m_state = 2; // stayed in thread list, but already finished
THIS_THREAD_FRAME_T_CUR = duration;
if (duration > THIS_THREAD_FRAME_T_MAX)
THIS_THREAD_FRAME_T_MAX = duration;
if (THIS_THREAD->frameTime.reset) {
THIS_THREAD->frameTime.reset = false;
THIS_THREAD->frameTime.maximum = 0;
}
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;
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);
}
if (duration > maxDuration)
m_frameMax.store(duration, std::memory_order_release);
m_frameCurr.store(duration, std::memory_order_release);
}
}

View File

@ -324,15 +324,8 @@ 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
@ -422,8 +415,6 @@ 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);
@ -452,6 +443,9 @@ public:
private:
void beginFrame();
void endFrame();
void enableEventTracer();
void disableEventTracer();

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,9 +158,9 @@ void modellingThread(){
#else
for (int i = 0; i < MODELLING_STEPS; i++){
#endif
EASY_FRAME_COUNTER;
//EASY_FRAME_COUNTER;
modellingStep();
EASY_END_FRAME_COUNTER;
//EASY_END_FRAME_COUNTER;
localSleep(1200000);
//std::this_thread::sleep_for(std::chrono::milliseconds(20));
@ -231,7 +231,7 @@ int main(int argc, char* argv[])
{
while (!stop.load(std::memory_order_acquire))
{
std::cout << "Frame time: " << profiler::main_thread::frameTimeLocalMax(profiler::MICROSECONDS) << " us\n";
std::cout << "Frame time: " << profiler::main_thread::frameTimeLocalMax() << " us\n";
std::this_thread::sleep_for(std::chrono::seconds(1));
}
});