Extensions - Add Tracy support

.gitmodules

@@ -0,0 +1,3 @@
+[submodule "extensions/src/ACRE2Profiling/tracy"]
+	path = extensions/src/ACRE2Profiling/tracy
+	url = https://github.com/wolfpld/tracy.git

extensions/CMakeLists.txt

@@ -6,6 +6,7 @@ include(${PROJECT_SOURCE_DIR}/CMakeModules/cxx_compiler_functions.cmake)
 
 option(USE_64BIT_BUILD "USE_64BIT_BUILD" OFF)
 option(USE_STATIC_LINKING "USE_STATIC_LINKING" ON)
+option(ENABLE_TRACING "ENABLE_TRACING" OFF)
 
 set(CMAKE_BUILD_TYPE "RelWithDebInfo")
 
@@ -58,6 +59,13 @@ if(MSVC)
     set(GLOBAL_SOURCES ${GLOBAL_RC})
 endif()
 
+if(ENABLE_TRACING)
+    message(STATUS "Enabling tracing (beware of excessively verbose log output)")
+    add_compile_definitions(_TRACE=1)
+endif()
+
+add_subdirectory(src/ACRE2Profiling)
+
 include_directories(src/ACRE2Shared)
 include_directories(src/ACRE2Core)
 

extensions/src/ACRE2Core/CMakeLists.txt

@@ -8,5 +8,5 @@ file(GLOB SOURCES *.h *.hpp *.c *.cpp)
 file(GLOB DSP_SOURCES DspFilters/*.h DspFilters/*.hpp DspFilters/*.c DspFilters/*.cpp)
 
 add_library( ${ACRE_NAME} STATIC ${SOURCES} ${GLOBAL_SOURCES} ${DSP_SOURCES})
-target_link_libraries( ${ACRE_NAME} ACRE2Shared)
+target_link_libraries( ${ACRE_NAME} ACRE2Shared ACRE2Profiling)
 set_target_properties(${ACRE_NAME} PROPERTIES FOLDER ACRE2)

extensions/src/ACRE2Core/Engine.cpp

@@ -31,7 +31,10 @@
 #include "setChannelDetails.h"
 #include <shlobj.h>
 
+#include <Tracy.hpp>
+
 acre::Result CEngine::initialize(IClient *client, IServer *externalServer, std::string fromPipeName, std::string toPipeName) {
+    ZoneScoped;
 
     if (!g_Log) {
         std::string acrePluginLog{"acre2_plugin.log"};
@@ -92,6 +95,7 @@ acre::Result CEngine::initialize(IClient *client, IServer *externalServer, std::
 }
 
 acre::Result CEngine::initialize(IClient *client, IServer *externalServer, std::string fromPipeName, std::string toPipeName, std::string loggingPath) {
+    ZoneScoped;
 
     g_Log = (Log *)new Log(const_cast<char *>(loggingPath.c_str()));
     LOG("* Logging engine initialized.");
@@ -100,6 +104,8 @@ acre::Result CEngine::initialize(IClient *client, IServer *externalServer, std::
 }
 
 acre::Result CEngine::start(const acre::id_t id) {
+    ZoneScoped;
+
     if (this->getExternalServer()) {
         this->getExternalServer()->initialize();
     } else {
@@ -124,6 +130,8 @@ acre::Result CEngine::start(const acre::id_t id) {
 }
 
 acre::Result CEngine::stop() {
+    ZoneScoped;
+
     LOG("Engine Shutting Down");
     this->setState(acre::State::stopping);
 
@@ -152,11 +160,15 @@ acre::Result CEngine::stop() {
 }
 
 acre::Result CEngine::localStartSpeaking(const acre::Speaking speakingType) {
+    ZoneScoped;
+
     this->localStartSpeaking(speakingType, "");
     return acre::Result::ok;
 }
 
 acre::Result CEngine::localStartSpeaking(const acre::Speaking speakingType, const std::string radioId) {
+    ZoneScoped;
+
     // send a start speaking event to everyone
     TRACE("Local START speaking: %d, %s", speakingType, radioId.c_str());
     this->getSelf()->lock();
@@ -192,6 +204,8 @@ acre::Result CEngine::localStartSpeaking(const acre::Speaking speakingType, cons
 }
 
 acre::Result CEngine::localStopSpeaking( void ) {
+    ZoneScoped;
+
     this->getSelf()->setSpeaking(false);
     CEngine::getInstance()->getExternalServer()->sendMessage(
         CTextMessage::formatNewMessage("ext_remoteStopSpeaking",
@@ -213,6 +227,8 @@ acre::Result CEngine::localStopSpeaking( void ) {
 }
 
 acre::Result CEngine::remoteStartSpeaking(const acre::id_t remoteId, const int32_t languageId, const std::string netId, const acre::Speaking speakingType, const std::string radioId, const acre::volume_t curveScale) {
+    ZoneScoped;
+
     TRACE("Remote Start Speaking Enter: %d, %d", remoteId, speakingType);
     auto it = this->speakingList.find(remoteId);
     if (it != this->speakingList.end()) {
@@ -241,6 +257,8 @@ acre::Result CEngine::remoteStartSpeaking(const acre::id_t remoteId, const int32
 }
 
 acre::Result CEngine::remoteStopSpeaking(const acre::id_t remoteId) {
+    ZoneScoped;
+
     TRACE("Remote STOP Speaking Enter: %d", remoteId);
     auto it = this->speakingList.find(remoteId);
     if (it != this->speakingList.end()) {

extensions/src/ACRE2Core/NamedPipeServer.cpp

@@ -4,6 +4,7 @@
 #include "Log.h"
 #include "Engine.h"
 
+#include <Tracy.hpp>
 
 
 
@@ -24,6 +25,8 @@ CNamedPipeServer::~CNamedPipeServer( void ) {
 }
 
 acre::Result CNamedPipeServer::initialize() {
+    ZoneScoped;
+
     HANDLE writeHandle, readHandle;
 
     SECURITY_DESCRIPTOR sd;
@@ -105,6 +108,8 @@ acre::Result CNamedPipeServer::initialize() {
 }
 
 acre::Result CNamedPipeServer::shutdown(void) {
+    ZoneScoped;
+
     HANDLE hPipe;
 
     this->setShuttingDown(true);
@@ -141,12 +146,15 @@ acre::Result CNamedPipeServer::shutdown(void) {
     return acre::Result::ok;
 }
 
+const char *sendFrameName = "NamedPipeServer - sending";
+
 acre::Result CNamedPipeServer::sendLoop() {
+    tracy::SetThreadName("NamedPipeServer::sendLoop");
+
     while (!this->getShuttingDown()) {
-
         do {
             ConnectNamedPipe(this->m_PipeHandleWrite, NULL);
-            if (GetLastError() == ERROR_PIPE_CONNECTED) {    
+            if (GetLastError() == ERROR_PIPE_CONNECTED) {
                 LOG("Client write connected");
                 CEngine::getInstance()->getSoundEngine()->onClientGameConnected();
                 this->setConnectedWrite(true);
@@ -159,6 +167,8 @@ acre::Result CNamedPipeServer::sendLoop() {
 
         clock_t lastTick = clock() / CLOCKS_PER_SEC;
         while (this->getConnectedWrite()) {
+            FrameMarkStart(sendFrameName);
+
             if (this->getShuttingDown())
                 break;
 
@@ -172,6 +182,8 @@ acre::Result CNamedPipeServer::sendLoop() {
             IMessage *msg = nullptr;
             if (this->m_sendQueue.try_pop(msg)) {
                 if (msg != nullptr) {
+                    ZoneScoped;
+
                     lastTick = clock() / CLOCKS_PER_SEC;
                     const DWORD size = (DWORD)strlen((char *)msg->getData()) + 1;
                     if (size > 3) {
@@ -196,20 +208,29 @@ acre::Result CNamedPipeServer::sendLoop() {
                     }
                     delete msg;
                 }
+
+                FrameMarkEnd(sendFrameName);
             }
+
             Sleep(1);
         }
+
         LOG("Write loop disconnected");
         FlushFileBuffers(this->m_PipeHandleWrite);
         const bool ret = DisconnectNamedPipe(this->m_PipeHandleWrite);
         Sleep(1);
     }
+
     TRACE("Sending thread terminating");
 
     return acre::Result::ok;
 }
 
+const char *receiveFrameName = "NamedPipeServer - receiving";
+
 acre::Result CNamedPipeServer::readLoop() {
+    tracy::SetThreadName("NamedPipeServer::readLoop");
+
     DWORD cbRead;
 
     char *mBuffer = (char *)LocalAlloc(LMEM_FIXED, BUFSIZE);
@@ -220,22 +241,29 @@ acre::Result CNamedPipeServer::readLoop() {
     this->validTSServers.insert(std::string("enter a ts3 server id here")); 
     */
     while (!this->getShuttingDown()) {
-        //this->checkServer();
-        bool ret = ConnectNamedPipe(this->m_PipeHandleRead, NULL);
-        if (GetLastError() == ERROR_PIPE_CONNECTED) {    
-            LOG("Client read connected");
-            CEngine::getInstance()->getClient()->updateShouldSwitchChannel(false);
-            CEngine::getInstance()->getClient()->unMuteAll();
-            CEngine::getInstance()->getSoundEngine()->onClientGameConnected();
-            this->setConnectedRead(true);
-        } else {
-            this->setConnectedRead(false);
-            Sleep(1);
+        bool ret = false;
+        {
+            // ZoneScopedN("CNamedPipeServer::readLoop - connecting read pipe");
+            // this->checkServer();
+            ret = ConnectNamedPipe(this->m_PipeHandleRead, NULL);
+            if (GetLastError() == ERROR_PIPE_CONNECTED) {
+                LOG("Client read connected");
+                CEngine::getInstance()->getClient()->updateShouldSwitchChannel(false);
+                CEngine::getInstance()->getClient()->unMuteAll();
+                CEngine::getInstance()->getSoundEngine()->onClientGameConnected();
+                this->setConnectedRead(true);
+            } else {
+                this->setConnectedRead(false);
+                Sleep(1);
 
-            continue;
+                continue;
+            }
         }
+
         clock_t lastTick = clock() / CLOCKS_PER_SEC;
         while (this->getConnectedRead()) {
+            FrameMarkStart(receiveFrameName);
+
             //this->checkServer();
             if (this->getShuttingDown()) {
                 break;
@@ -264,24 +292,30 @@ acre::Result CNamedPipeServer::readLoop() {
                     this->setConnectedRead(false);
                     break;
                 }
+
+                ZoneScoped;
+
                 // handle the packet and run it
                 mBuffer[cbRead] = 0x00;
-                //LOG("READ: %s", (char *)mBuffer);
-                IMessage *const msg = new CTextMessage((char *)mBuffer, cbRead);
-                //TRACE("got and parsed message [%s]", msg->getData());
+                // LOG("READ: %s", (char *)mBuffer);
+                IMessage *const msg = new CTextMessage((char *) mBuffer, cbRead);
+                // TRACE("got and parsed message [%s]", msg->getData());
                 if (msg != nullptr && msg->getProcedureName()) {
-
                     // Do not free msg, this is deleted inside runProcedure()
                     CEngine::getInstance()->getRpcEngine()->runProcedure(this, msg);
 
                     lastTick = clock() / CLOCKS_PER_SEC;
-                    //TRACE("tick [%d], [%s]",lastTick, msg->getData());
+                    // TRACE("tick [%d], [%s]",lastTick, msg->getData());
                 }
                 // wait 1ms for new msg so we dont hog cpu cycles
             } while (!ret);
-            //ret = ConnectNamedPipe(this->getPipeHandle(), NULL);    
+            //ret = ConnectNamedPipe(this->getPipeHandle(), NULL);
+
+            FrameMarkEnd(receiveFrameName);
+
             Sleep(1);
         }
+
         // Kill the write pipe along with ourselves, because we master shutdown/startup
         this->setConnectedWrite(false);
         this->setConnectedRead(false);
@@ -305,7 +339,8 @@ acre::Result CNamedPipeServer::readLoop() {
                     CEngine::getInstance()->getSelf()->getId()
                 ) 
             );
-        } 
+        }
+
         Sleep(1);
     }
 

extensions/src/ACRE2Core/RpcEngine.cpp

@@ -12,44 +12,60 @@
 #include "Log.h"
 #include <list>
 
-//
+#include <Tracy.hpp>
+
+const char *frameName = "RPCEngine";
+  //
 // Entrant worker, weee
 //
 acre::Result CRpcEngine::exProcessItem(ACRE_RPCDATA *data) {
+    tracy::SetThreadName("RPCEngine");
+    FrameMarkStart(frameName);
+
     if (data->function != nullptr) {
         data->function->call(data->server, data->message);
     }
     delete data->message;
     free(data);
 
+    FrameMarkEnd(frameName);
+
     return acre::Result::ok;
 }
 
 //
 // Proc functions
 // 
 acre::Result CRpcEngine::addProcedure(IRpcFunction *const cmd) {
+    ZoneScoped;
+
     LOCK(this);
     this->m_FunctionList.insert(std::pair<std::string, IRpcFunction *>(std::string(cmd->getName()), cmd));
     UNLOCK(this);
 
     return acre::Result::ok;
 }
 acre::Result CRpcEngine::removeProcedure(IRpcFunction *const cmd) {
+    ZoneScoped;
+
     LOCK(this);
     this->m_FunctionList.erase(cmd->getName());
     UNLOCK(this);
 
     return acre::Result::ok;
 }
 acre::Result CRpcEngine::removeProcedure(char *const cmd) {
+    ZoneScoped;
+
     LOCK(this);
     this->m_FunctionList.erase(cmd);
     UNLOCK(this);
 
     return acre::Result::ok;
 }
 IRpcFunction *CRpcEngine::findProcedure(char *const cmd) {
+    ZoneScoped;
+
 
     if (this->getShuttingDown()) {
         return nullptr;
@@ -62,11 +78,15 @@ IRpcFunction *CRpcEngine::findProcedure(char *const cmd) {
 
     return nullptr;
 }
+
 acre::Result CRpcEngine::runProcedure(IServer *const serverInstance, IMessage *msg) {
+    ZoneScoped;
+
     return this->runProcedure(serverInstance, msg, TRUE);
 }
 
 acre::Result CRpcEngine::runProcedure(IServer *const serverInstance, IMessage *msg, const bool entrant) {
+    ZoneScoped;
 
     if (msg == nullptr) {
         return acre::Result::error;

extensions/src/ACRE2Core/ext_handleGetClientID.h

@@ -11,7 +11,11 @@
 
 #include "TextMessage.h"
 
+#include <Tracy.hpp>
+
 RPC_FUNCTION(ext_handleGetClientID) {
+    ZoneScopedN("RPC - ext_handleGetClientID");
+
     CEngine::getInstance()->getGameServer()->sendMessage(
         CTextMessage::formatNewMessage("handleGetClientID",
             "%d,%s,",

extensions/src/ACRE2Core/ext_remoteStartSpeaking.h

@@ -11,7 +11,10 @@
 
 #include "TextMessage.h"
 
+#include <Tracy.hpp>
+
 RPC_FUNCTION(ext_remoteStartSpeaking) {
+    ZoneScopedN("RPC - ext_remoteStartSpeaking");
 
     /*CTextMessage::formatNewMessage("ext_remoteStartSpeaking",
             "%d,%d,%s,%f,",