diff --git a/src/CMakeLists.txt b/src/CMakeLists.txt index f454e3e0..1a451904 100644 --- a/src/CMakeLists.txt +++ b/src/CMakeLists.txt @@ -22,6 +22,12 @@ if ( ${QHELP} ) add_definitions( -D_USE_QHELP ) endif() +if ( ${FCEU_PROFILER_ENABLE} ) + message( STATUS "FCEU Profiler Enabled") + add_definitions( -D__FCEU_PROFILER_ENABLE__ ) +endif() + + if ( ${QT6} ) find_package( Qt6 REQUIRED COMPONENTS Widgets OpenGL OpenGLWidgets ${QtHelpModule}) add_definitions( ${Qt6Widgets_DEFINITIONS} ${Qt6Help_DEFINITIONS} ${Qt6OpenGLWidgets_DEFINITIONS} ) @@ -309,6 +315,7 @@ set(SRC_CORE ${CMAKE_CURRENT_SOURCE_DIR}/nsf.cpp ${CMAKE_CURRENT_SOURCE_DIR}/oldmovie.cpp ${CMAKE_CURRENT_SOURCE_DIR}/palette.cpp + ${CMAKE_CURRENT_SOURCE_DIR}/profiler.cpp ${CMAKE_CURRENT_SOURCE_DIR}/ppu.cpp ${CMAKE_CURRENT_SOURCE_DIR}/sound.cpp ${CMAKE_CURRENT_SOURCE_DIR}/state.cpp diff --git a/src/drivers/Qt/ConsoleWindow.cpp b/src/drivers/Qt/ConsoleWindow.cpp index 20a91243..79add172 100644 --- a/src/drivers/Qt/ConsoleWindow.cpp +++ b/src/drivers/Qt/ConsoleWindow.cpp @@ -54,6 +54,7 @@ #include "../../movie.h" #include "../../wave.h" #include "../../state.h" +#include "../../profiler.h" #include "../../version.h" #include "common/os_utils.h" @@ -4484,6 +4485,7 @@ int consoleWin_t::getPeriodicInterval(void) void consoleWin_t::transferVideoBuffer(void) { + FCEU_PROFILE_FUNC(prof, "VideoXfer"); if ( nes_shm->blitUpdated ) { nes_shm->blitUpdated = 0; @@ -4525,6 +4527,7 @@ void consoleWin_t::emuFrameFinish(void) void consoleWin_t::updatePeriodic(void) { + FCEU_PROFILE_FUNC(prof, "updatePeriodic"); static bool eventProcessingInProg = false; if ( eventProcessingInProg ) diff --git a/src/fceu.cpp b/src/fceu.cpp index 90ba9985..37d61a53 100644 --- a/src/fceu.cpp +++ b/src/fceu.cpp @@ -36,6 +36,7 @@ #include "unif.h" #include "cheat.h" #include "palette.h" +#include "profiler.h" #include "state.h" #include "movie.h" #include "video.h" @@ -734,6 +735,7 @@ extern unsigned int frameAdvHoldTimer; ///Skip may be passed in, if FRAMESKIP is #defined, to cause this to emulate more than one frame void FCEUI_Emulate(uint8 **pXBuf, int32 **SoundBuf, int32 *SoundBufSize, int skip) { + FCEU_PROFILE_FUNC(prof, "Emulate Single Frame"); //skip initiates frame skip if 1, or frame skip and sound skip if 2 FCEU_MAYBE_UNUSED int r; int ssize; diff --git a/src/profiler.cpp b/src/profiler.cpp new file mode 100644 index 00000000..c7582eae --- /dev/null +++ b/src/profiler.cpp @@ -0,0 +1,257 @@ +/* FCE Ultra - NES/Famicom Emulator + * + * Copyright notice for this file: + * Copyright (C) 2002 Xodnizel + * + * This program is free software; you can redistribute it and/or modify + * it under the terms of the GNU General Public License as published by + * the Free Software Foundation; either version 2 of the License, or + * (at your option) any later version. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU General Public License for more details. + * + * You should have received a copy of the GNU General Public License + * along with this program; if not, write to the Free Software + * Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA + */ +// profiler.cpp +// +#ifdef __FCEU_PROFILER_ENABLE__ + +#include + +#include "utils/mutex.h" +#include "profiler.h" + +namespace FCEU +{ +static thread_local profilerFuncMap threadProfileMap; + +class profilerManager +{ + public: + profilerManager(void) + { + printf("profilerManager Constructor\n"); + if (pLog == nullptr) + { + pLog = stdout; + } + } + + ~profilerManager(void) + { + printf("profilerManager Destructor\n"); + { + autoScopedLock aLock(threadListMtx); + threadList.clear(); + } + + if (pLog && (pLog != stdout)) + { + fclose(pLog); pLog = nullptr; + } + } + + int addThreadProfiler( profilerFuncMap *m ) + { + autoScopedLock aLock(threadListMtx); + threadList.push_back(m); + return 0; + } + + int removeThreadProfiler( profilerFuncMap *m, bool shouldDestroy = false ) + { + int result = -1; + autoScopedLock aLock(threadListMtx); + + for (auto it = threadList.begin(); it != threadList.end(); it++) + { + if (*it == m ) + { + threadList.erase(it); + if (shouldDestroy) + { + delete m; + } + result = 0; + break; + } + } + return result; + } + + static FILE *pLog; + private: + + mutex threadListMtx; + std::list threadList; + +}; +FILE *profilerManager::pLog = nullptr; + +static profilerManager pMgr; + +//------------------------------------------------------------------------- +//---- Time Stamp Record +//------------------------------------------------------------------------- +void timeStampRecord::readNew(void) +{ +#if defined(__linux__) || defined(__APPLE__) || defined(__unix__) + clock_gettime( CLOCK_REALTIME, &ts ); +#else + ts = 0; +#endif +} + +//------------------------------------------------------------------------- +//---- Function Profile Record +//------------------------------------------------------------------------- +funcProfileRecord::funcProfileRecord(const char *fileNameStringLiteral, + const int fileLineNumber, + const char *funcNameStringLiteral, + const char *commentStringLiteral) + + : fileLineNum(fileLineNumber), fileName(fileNameStringLiteral), + funcName(funcNameStringLiteral), comment(commentStringLiteral) +{ + min.zero(); + max.zero(); + sum.zero(); + numCalls = 0; + recursionCount = 0; +} +//------------------------------------------------------------------------- +void funcProfileRecord::reset(void) +{ + min.zero(); + max.zero(); + sum.zero(); + numCalls = 0; +} +//------------------------------------------------------------------------- +double funcProfileRecord::average(void) +{ + double avg = 0.0; + + if (numCalls) + { + avg = sum.toSeconds() / static_cast(numCalls); + } + return avg; +} +//------------------------------------------------------------------------- +//---- Profile Scoped Function Class +//------------------------------------------------------------------------- +profileFuncScoped::profileFuncScoped(const char *fileNameStringLiteral, + const int fileLineNumber, + const char *funcNameStringLiteral, + const char *commentStringLiteral) +{ + rec = nullptr; + + //if (threadProfileMap == nullptr) + //{ + // threadProfileMap = new profilerFuncMap(); + //} + + rec = threadProfileMap.findRecord( fileNameStringLiteral, fileLineNumber, + funcNameStringLiteral, commentStringLiteral, true); + + if (rec) + { + threadProfileMap.pushStack(rec); + start.readNew(); + rec->numCalls++; + rec->recursionCount++; + } +} +//------------------------------------------------------------------------- +profileFuncScoped::~profileFuncScoped(void) +{ + if (rec) + { + timeStampRecord ts, dt; + ts.readNew(); + dt = ts - start; + + rec->sum += dt; + if (dt < rec->min) rec->min = dt; + if (dt > rec->max) rec->max = dt; + + rec->recursionCount--; + + //printf("%s: %u %f %f %f %f\n", rec->funcName, rec->numCalls, dt.toSeconds(), rec->average(), rec->min.toSeconds(), rec->max.toSeconds()); + threadProfileMap.popStack(rec); + } +} +//------------------------------------------------------------------------- +//---- Profile Function Record Map +//------------------------------------------------------------------------- +profilerFuncMap::profilerFuncMap(void) +{ + printf("profilerFuncMap Constructor: %p\n", this); + pMgr.addThreadProfiler(this); +} +//------------------------------------------------------------------------- +profilerFuncMap::~profilerFuncMap(void) +{ + printf("profilerFuncMap Destructor: %p\n", this); + pMgr.removeThreadProfiler(this); + + for (auto it = _map.begin(); it != _map.end(); it++) + { + delete it->second; + } + _map.clear(); +} +//------------------------------------------------------------------------- +void profilerFuncMap::pushStack(funcProfileRecord *rec) +{ + stack.push_back(rec); +} +//------------------------------------------------------------------------- +void profilerFuncMap::popStack(funcProfileRecord *rec) +{ + stack.pop_back(); +} +//------------------------------------------------------------------------- +funcProfileRecord *profilerFuncMap::findRecord(const char *fileNameStringLiteral, + const int fileLineNumber, + const char *funcNameStringLiteral, + const char *commentStringLiteral, + bool create) +{ + char lineString[64]; + funcProfileRecord *rec = nullptr; + + sprintf( lineString, ":%i", fileLineNumber); + + std::string fname(fileNameStringLiteral); + + fname.append( lineString ); + + auto it = _map.find(fname); + + if (it != _map.end()) + { + rec = it->second; + } + else if (create) + { + fprintf( pMgr.pLog, "Creating Function Profile Record: %s %s\n", fname.c_str(), funcNameStringLiteral); + + rec = new funcProfileRecord( fileNameStringLiteral, fileLineNumber, + funcNameStringLiteral, commentStringLiteral); + + _map[fname] = rec; + } + return rec; +} +//------------------------------------------------------------------------- +// +} +#endif // __FCEU_PROFILER_ENABLE__ diff --git a/src/profiler.h b/src/profiler.h new file mode 100644 index 00000000..5b41e0db --- /dev/null +++ b/src/profiler.h @@ -0,0 +1,220 @@ +/* FCE Ultra - NES/Famicom Emulator + * + * Copyright notice for this file: + * Copyright (C) 2002 Xodnizel + * + * This program is free software; you can redistribute it and/or modify + * it under the terms of the GNU General Public License as published by + * the Free Software Foundation; either version 2 of the License, or + * (at your option) any later version. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU General Public License for more details. + * + * You should have received a copy of the GNU General Public License + * along with this program; if not, write to the Free Software + * Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA + */ +// profiler.h + +#pragma once + +/* + * This module is intended for debug use only. This allows for high precision timing of function + * execution. This functionality is not included in the build unless __FCEU_PROFILER_ENABLE__ + * is defined. To check timing on a particular function, add FCEU_PROFILE_FUNC macro to the top + * of the function body in the following manner. + * FCEU_PROFILE_FUNC(prof, "String Literal comment, whatever I want it to say") + * When __FCEU_PROFILER_ENABLE__ is not defined, the FCEU_PROFILE_FUNC macro evaluates to nothing + * so it won't break the regular build by having it used in code. + */ +#ifdef __FCEU_PROFILER_ENABLE__ + +#include +#include +#include +#include +#include + + +#if defined(__linux__) || defined(__APPLE__) || defined(__unix__) +#include +#endif + +namespace FCEU +{ + struct timeStampRecord + { +#if defined(__linux__) || defined(__APPLE__) || defined(__unix__) + struct timespec ts; + + timeStampRecord& operator = (const timeStampRecord& in) + { + ts = in.ts; + return *this; + } + + timeStampRecord& operator += (const timeStampRecord& op) + { + ts.tv_sec += op.ts.tv_sec; + ts.tv_nsec += op.ts.tv_nsec; + + if (ts.tv_nsec >= 1000000000) + { + ts.tv_nsec -= 1000000000; + ts.tv_sec++; + } + return *this; + } + + timeStampRecord operator + (const timeStampRecord& op) + { + timeStampRecord res; + + res.ts.tv_sec = ts.tv_sec + op.ts.tv_sec; + res.ts.tv_nsec = ts.tv_nsec + op.ts.tv_nsec; + + if (res.ts.tv_nsec >= 1000000000) + { + res.ts.tv_nsec -= 1000000000; + res.ts.tv_sec++; + } + return res; + } + + timeStampRecord operator - (const timeStampRecord& op) + { + timeStampRecord res; + + res.ts.tv_sec = ts.tv_sec - op.ts.tv_sec; + res.ts.tv_nsec = ts.tv_nsec - op.ts.tv_nsec; + + if (res.ts.tv_nsec < 0) + { + res.ts.tv_nsec += 1000000000; + res.ts.tv_sec--; + } + return res; + } + + bool operator > (const timeStampRecord& op) + { + bool res = false; + if (ts.tv_sec == op.ts.tv_sec) + { + res = (ts.tv_nsec > op.ts.tv_nsec); + } + else if (ts.tv_sec > op.ts.tv_sec) + { + res = (ts.tv_sec > op.ts.tv_sec); + } + return res; + } + + bool operator < (const timeStampRecord& op) + { + bool res = false; + if (ts.tv_sec == op.ts.tv_sec) + { + res = (ts.tv_nsec < op.ts.tv_nsec); + } + else if (ts.tv_sec > op.ts.tv_sec) + { + res = (ts.tv_sec < op.ts.tv_sec); + } + return res; + } + + void zero(void) + { + ts.tv_sec = 0; + ts.tv_nsec = 0; + } + + double toSeconds(void) + { + double sec = static_cast(ts.tv_sec) + ( static_cast(ts.tv_nsec) * 1.0e-9 ); + return sec; + } +#else // WIN32 + uint64_t ts; +#endif + + void readNew(void); + + //timeStampRecord& operator = (timeStampRecord&); + }; + + struct funcProfileRecord + { + const int fileLineNum; + const char *fileName; + const char *funcName; + const char *comment; + + timeStampRecord min; + timeStampRecord max; + timeStampRecord sum; + unsigned int numCalls; + unsigned int recursionCount; + + funcProfileRecord(const char *fileNameStringLiteral, + const int fileLineNumber, + const char *funcNameStringLiteral, + const char *commentStringLiteral); + + void reset(void); + + double average(void); + }; + + struct profileFuncScoped + { + funcProfileRecord *rec; + timeStampRecord start; + + profileFuncScoped(const char *fileNameStringLiteral, + const int fileLineNumber, + const char *funcNameStringLiteral, + const char *commentStringLiteral); + + ~profileFuncScoped(void); + }; + + class profilerFuncMap + { + public: + profilerFuncMap(); + ~profilerFuncMap(); + + funcProfileRecord *findRecord(const char *fileNameStringLiteral, + const int fileLineNumber, + const char *funcNameStringLiteral, + const char *commentStringLiteral, + bool create = false); + + void pushStack(funcProfileRecord *rec); + void popStack(funcProfileRecord *rec); + private: + std::map _map; + + std::vector stack; + }; +} + +#if defined(__PRETTY_FUNCTION__) +#define __FCEU_PROFILE_FUNC_NAME__ __PRETTY_FUNCTION__ +#else +#define __FCEU_PROFILE_FUNC_NAME__ __func__ +#endif + +#define FCEU_PROFILE_FUNC(id, comment) FCEU::profileFuncScoped id( __FILE__, __LINE__, __FCEU_PROFILE_FUNC_NAME__, comment ) + +#else // __FCEU_PROFILER_ENABLE__ not defined + +#define FCEU_PROFILE_FUNC(id, comment) + +#endif // __FCEU_PROFILER_ENABLE__ + diff --git a/src/utils/mutex.cpp b/src/utils/mutex.cpp index 0556ea07..60376a40 100644 --- a/src/utils/mutex.cpp +++ b/src/utils/mutex.cpp @@ -60,6 +60,15 @@ autoScopedLock::autoScopedLock( mutex *mtx ) } } +autoScopedLock::autoScopedLock( mutex &mtx ) +{ + m = &mtx; + if (m) + { + m->lock(); + } +} + autoScopedLock::~autoScopedLock(void) { if (m) diff --git a/src/utils/mutex.h b/src/utils/mutex.h index 721bf241..795e083c 100644 --- a/src/utils/mutex.h +++ b/src/utils/mutex.h @@ -32,6 +32,7 @@ namespace FCEU { public: autoScopedLock( mutex *mtx ); + autoScopedLock( mutex &mtx ); ~autoScopedLock(void); private: