diff --git a/source/glest_game/game/commander.cpp b/source/glest_game/game/commander.cpp index a5ceb5c8..75b809b0 100644 --- a/source/glest_game/game/commander.cpp +++ b/source/glest_game/game/commander.cpp @@ -234,13 +234,17 @@ void Commander::updateNetwork(){ GameNetworkInterface *gameNetworkInterface= NetworkManager::getInstance().getGameNetworkInterface(); + perfTimer.start(); //update the keyframe gameNetworkInterface->updateKeyframe(world->getFrameCount()); + SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] gameNetworkInterface->updateKeyframe for %d took %d msecs\n",__FILE__,__FUNCTION__,__LINE__,world->getFrameCount(),perfTimer.getMillis()); + perfTimer.start(); //give pending commands for(int i= 0; i < gameNetworkInterface->getPendingCommandCount(); ++i){ giveNetworkCommand(gameNetworkInterface->getPendingCommand(i)); } + SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] giveNetworkCommand took %d msecs\n",__FILE__,__FUNCTION__,__LINE__,perfTimer.getMillis()); gameNetworkInterface->clearPendingCommands(); } } @@ -254,7 +258,6 @@ void Commander::giveNetworkCommandSpecial(const NetworkCommand* networkCommand) case ncstRotateUnit: { SystemFlags::OutputDebug(SystemFlags::debugSystem,"In [%s::%s Line: %d] found ncstRotateUnit [%d]\n",__FILE__,__FUNCTION__,__LINE__,networkCommand->getTargetId()); - //!!! int unitTypeId = networkCommand->getUnitId(); int factionIndex = networkCommand->getUnitTypeId(); int rotateAmount = networkCommand->getTargetId(); diff --git a/source/glest_game/game/commander.h b/source/glest_game/game/commander.h index e7eb66ee..e94ebfd0 100644 --- a/source/glest_game/game/commander.h +++ b/source/glest_game/game/commander.h @@ -17,12 +17,14 @@ #include "vec.h" #include "selection.h" #include "command_type.h" +#include "platform_util.h" using std::vector; namespace Glest{ namespace Game{ using Shared::Graphics::Vec2i; +using Shared::Platform::Chrono; class World; class Unit; @@ -42,6 +44,7 @@ private: private: World *world; + Chrono perfTimer; public: void init(World *world); diff --git a/source/glest_game/game/game.cpp b/source/glest_game/game/game.cpp index f9214402..710ce670 100644 --- a/source/glest_game/game/game.cpp +++ b/source/glest_game/game/game.cpp @@ -848,14 +848,14 @@ void Game::render2d(){ renderer.renderChatManager(&chatManager); //debug info - if(config.getBool("DebugMode")){ - string str; - - str+= "MouseXY: " + intToStr(mouseX) + "," + intToStr(mouseY)+"\n"; + + string str; + if(config.getBool("DebugMode") || difftime(time(NULL),lastRenderLog2d) >= 1){ + str+= "MouseXY: " + intToStr(mouseX) + "," + intToStr(mouseY)+"\n"; str+= "PosObjWord: " + intToStr(gui.getPosObjWorld().x) + "," + intToStr(gui.getPosObjWorld().y)+"\n"; - str+= "Render FPS: "+intToStr(lastRenderFps)+"\n"; - str+= "Update FPS: "+intToStr(lastUpdateFps)+"\n"; - str+= "GameCamera pos: "+floatToStr(gameCamera.getPos().x)+","+floatToStr(gameCamera.getPos().y)+","+floatToStr(gameCamera.getPos().z)+"\n"; + str+= "Render FPS: "+intToStr(lastRenderFps)+"\n"; + str+= "Update FPS: "+intToStr(lastUpdateFps)+"\n"; + str+= "GameCamera pos: "+floatToStr(gameCamera.getPos().x)+","+floatToStr(gameCamera.getPos().y)+","+floatToStr(gameCamera.getPos().z)+"\n"; str+= "Time: "+floatToStr(world.getTimeFlow()->getTime())+"\n"; str+= "Triangle count: "+intToStr(renderer.getTriangleCount())+"\n"; str+= "Vertex count: "+intToStr(renderer.getPointCount())+"\n"; @@ -872,15 +872,17 @@ void Game::render2d(){ str+= "Visible quad area: " + floatToStr(visibleQuad.area()) +"\n"; // resources - for(int i=0; igetResourceTypeCount(); ++j){ - str+= intToStr(world.getFaction(i)->getResource(j)->getAmount()); - str+=" "; - } - str+="\n"; - } + for(int i=0; igetResourceTypeCount(); ++j){ + str+= intToStr(world.getFaction(i)->getResource(j)->getAmount()); + str+=" "; + } + str+="\n"; + } + } + if(config.getBool("DebugMode")){ renderer.renderText( str, coreData.getMenuFontNormal(), Vec3f(1.0f), 10, 500, false); @@ -902,6 +904,11 @@ void Game::render2d(){ //2d mouse renderer.renderMouse2d(mouseX, mouseY, mouse2d, gui.isSelectingPos()? 1.f: 0.f); + + if(difftime(time(NULL),lastRenderLog2d) >= 1) { + lastRenderLog2d = time(NULL); + SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s] Line: %d Statistics: %s\n",__FILE__,__FUNCTION__,__LINE__,str.c_str()); + } } diff --git a/source/glest_game/game/game.h b/source/glest_game/game/game.h index ff5e4912..807f7415 100644 --- a/source/glest_game/game/game.h +++ b/source/glest_game/game/game.h @@ -77,6 +77,7 @@ private: ParticleSystem *weatherParticleSystem; GameSettings gameSettings; Vec2i lastMousePos; + time_t lastRenderLog2d; public: Game(Program *program, const GameSettings *gameSettings); diff --git a/source/glest_game/main/main.cpp b/source/glest_game/main/main.cpp index 0064a10c..32dfae2a 100644 --- a/source/glest_game/main/main.cpp +++ b/source/glest_game/main/main.cpp @@ -260,8 +260,9 @@ void MainWindow::setProgram(Program *program) { SystemFlags debugger; int glestMain(int argc, char** argv){ - SystemFlags::enableNetworkDebugInfo = true; - SystemFlags::enableDebugText = true; + SystemFlags::enableNetworkDebugInfo = true; + SystemFlags::enableDebugText = true; + SystemFlags::enablePerformanceDebugInfo = false; MainWindow *mainWindow= NULL; Program *program= NULL; @@ -273,13 +274,14 @@ int glestMain(int argc, char** argv){ SystemFlags::OutputDebug(SystemFlags::debugSystem,"In [%s::%s Line: %d]\n",__FILE__,__FUNCTION__,__LINE__); - SystemFlags::enableNetworkDebugInfo = config.getBool("DebugNetwork","0"); - SystemFlags::enableDebugText = config.getBool("DebugMode","0"); + SystemFlags::enableNetworkDebugInfo = config.getBool("DebugNetwork","false"); + SystemFlags::enableDebugText = config.getBool("DebugMode","false"); debugLogFile = config.getString("DebugLogFile",""); if(getGameReadWritePath() != "") { debugLogFile = getGameReadWritePath() + debugLogFile; } SystemFlags::debugLogFile = debugLogFile.c_str(); + SystemFlags::enablePerformanceDebugInfo = config.getBool("DebugPerformance","false"); NetworkInterface::setDisplayMessageFunction(ExceptionHandler::DisplayMessage); diff --git a/source/glest_game/network/client_interface.cpp b/source/glest_game/network/client_interface.cpp index 3d56488c..3803ae8a 100755 --- a/source/glest_game/network/client_interface.cpp +++ b/source/glest_game/network/client_interface.cpp @@ -36,7 +36,7 @@ namespace Glest{ namespace Game{ // ===================================================== const int ClientInterface::messageWaitTimeout= 10000; //10 seconds -const int ClientInterface::waitSleepTime= 50; +const int ClientInterface::waitSleepTime= 10; ClientInterface::ClientInterface(){ clientSocket= NULL; @@ -353,15 +353,23 @@ void ClientInterface::updateKeyframe(int frameCount) { case nmtCommandList: { + Chrono chrono; + chrono.start(); + + int waitCount = 0; //make sure we read the message NetworkMessageCommandList networkMessageCommandList; - while(!receiveMessage(&networkMessageCommandList)) + while(receiveMessage(&networkMessageCommandList) == false) { sleep(waitSleepTime); + waitCount++; } + SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] receiveMessage took %d msecs, waitCount = %d\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis(),waitCount); + + chrono.start(); //check that we are in the right frame - if(networkMessageCommandList.getFrameCount()!=frameCount) + if(networkMessageCommandList.getFrameCount() != frameCount) { string sErr = "Network synchronization error, frame counts do not match"; //throw runtime_error("Network synchronization error, frame counts do not match"); @@ -378,6 +386,8 @@ void ClientInterface::updateKeyframe(int frameCount) pendingCommands.push_back(*networkMessageCommandList.getCommand(i)); } + SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] transfer network commands took %d msecs\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis()); + done= true; } break; @@ -574,6 +584,7 @@ void ClientInterface::waitForMessage() Chrono chrono; chrono.start(); + int waitLoopCount = 0; while(getNextMessageType(true) == nmtInvalid) { if(!isConnected()) @@ -597,7 +608,10 @@ void ClientInterface::waitForMessage() } sleep(waitSleepTime); + waitLoopCount++; } + + SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] waiting took %d msecs, waitLoopCount = %d\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis(),waitLoopCount); } void ClientInterface::quitGame(bool userManuallyQuit) diff --git a/source/glest_game/network/network_interface.cpp b/source/glest_game/network/network_interface.cpp index 7024c367..fc17707b 100644 --- a/source/glest_game/network/network_interface.cpp +++ b/source/glest_game/network/network_interface.cpp @@ -63,6 +63,9 @@ NetworkMessageType NetworkInterface::getNextMessageType(bool checkHasDataFirst) SystemFlags::OutputDebug(SystemFlags::debugNetwork,"In [%s::%s] socket->getDataToRead() iPeek = %d, messageType = %d\n",__FILE__,__FUNCTION__,iPeek,messageType); } + else { + SystemFlags::OutputDebug(SystemFlags::debugNetwork,"In [%s::%s] PEEK WARNING, socket->getDataToRead() messageType = %d, dataSize = %d\n",__FILE__,__FUNCTION__,messageType,dataSize); + } //sanity check new message type if(messageType<0 || messageType>=nmtCount){ diff --git a/source/glest_game/network/server_interface.cpp b/source/glest_game/network/server_interface.cpp index f076b380..ed6898a2 100644 --- a/source/glest_game/network/server_interface.cpp +++ b/source/glest_game/network/server_interface.cpp @@ -227,6 +227,8 @@ void ServerInterface::update() } void ServerInterface::updateKeyframe(int frameCount){ + Chrono chrono; + chrono.start(); NetworkMessageCommandList networkMessageCommandList(frameCount); @@ -241,8 +243,12 @@ void ServerInterface::updateKeyframe(int frameCount){ } } + SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] build command list took %d msecs, networkMessageCommandList.getCommandCount() = %d, frameCount = %d\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis(),networkMessageCommandList.getCommandCount(),frameCount); + //broadcast commands broadcastMessage(&networkMessageCommandList); + + SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] broadcastMessage took %d msecs, networkMessageCommandList.getCommandCount() = %d, frameCount = %d\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis(),networkMessageCommandList.getCommandCount(),frameCount); } void ServerInterface::waitUntilReady(Checksum* checksum){ diff --git a/source/shared_lib/include/platform/posix/socket.h b/source/shared_lib/include/platform/posix/socket.h index 04328018..70905825 100644 --- a/source/shared_lib/include/platform/posix/socket.h +++ b/source/shared_lib/include/platform/posix/socket.h @@ -120,7 +120,8 @@ public: static string getHostName(); static string getIp(); - bool isSocketValid(PLATFORM_SOCKET *validateSocket=NULL) const; + bool isSocketValid() const; + static bool isSocketValid(const PLATFORM_SOCKET *validateSocket); protected: static void throwException(string str); diff --git a/source/shared_lib/include/util/util.h b/source/shared_lib/include/util/util.h index f68d3ecf..3a63a9ef 100644 --- a/source/shared_lib/include/util/util.h +++ b/source/shared_lib/include/util/util.h @@ -34,11 +34,13 @@ public: enum DebugType { debugSystem, - debugNetwork + debugNetwork, + debugPerformance }; static bool enableDebugText; static bool enableNetworkDebugInfo; + static bool enablePerformanceDebugInfo; static const char *debugLogFile; static void OutputDebug(DebugType type, const char *fmt, ...); diff --git a/source/shared_lib/sources/platform/posix/socket.cpp b/source/shared_lib/sources/platform/posix/socket.cpp index 41aec9c9..9aa79f3e 100644 --- a/source/shared_lib/sources/platform/posix/socket.cpp +++ b/source/shared_lib/sources/platform/posix/socket.cpp @@ -650,17 +650,21 @@ std::vector Socket::getLocalIPAddressList() { return ipList; } -bool Socket::isSocketValid(PLATFORM_SOCKET *validateSocket) const { +bool Socket::isSocketValid() const { + return Socket::isSocketValid(&sock); +} + +bool Socket::isSocketValid(const PLATFORM_SOCKET *validateSocket) { #ifdef WIN32 if(validateSocket == NULL) { - return (sock != INVALID_SOCKET); + return false; } else { return (*validateSocket != INVALID_SOCKET); } #else if(validateSocket == NULL) { - return (sock > 0); + return false; } else { return (*validateSocket > 0); @@ -726,7 +730,7 @@ bool Socket::hasDataToRead(std::map &socketTriggeredList) itermap != socketTriggeredList.end(); itermap++) { PLATFORM_SOCKET socket = itermap->first; - if(socket > 0) + if(Socket::isSocketValid(&socket) == true) { FD_SET(socket, &rfds); imaxsocket = max(socket,imaxsocket); @@ -784,7 +788,7 @@ bool Socket::hasDataToRead(PLATFORM_SOCKET socket) { bool bResult = false; - if(socket > 0) + if(Socket::isSocketValid(&socket) == true) { fd_set rfds; struct timeval tv; @@ -1452,6 +1456,15 @@ void BroadCastClientSocketThread::execute() { setRunningStatus(false); SystemFlags::OutputDebug(SystemFlags::debugNetwork,"Broadcast Client thread is exiting\n"); } + +#ifndef WIN32 + ::close(bcfd); + bcfd = INVALID_SOCKET; +#else + ::closesocket(bcfd); + bcfd = -1; +#endif + } SystemFlags::OutputDebug(SystemFlags::debugNetwork,"In [%s::%s Line: %d]\n",__FILE__,__FUNCTION__,__LINE__); @@ -1725,7 +1738,7 @@ void BroadCastSocketThread::execute() { for( pn = 1; ; pn++ ) { for(unsigned int idx = 0; idx < ipList.size() && idx < MAX_NIC_COUNT; idx++) { - if( bcfd[idx] > 0 ) { + if( Socket::isSocketValid(&bcfd[idx]) == true ) { try { // Send this machine's host name and address in hostname:n.n.n.n format sprintf(buff,"%s",myhostname); @@ -1779,6 +1792,18 @@ void BroadCastSocketThread::execute() { } } + for(unsigned int idx = 0; idx < ipList.size() && idx < MAX_NIC_COUNT; idx++) { + if( Socket::isSocketValid(&bcfd[idx]) == true ) { +#ifndef WIN32 + ::close(bcfd[idx]); + bcfd[idx] = INVALID_SOCKET; +#else + ::closesocket(bcfd[idx]); + bcfd[idx] = -1; +#endif + } + } + setRunningStatus(false); SystemFlags::OutputDebug(SystemFlags::debugNetwork,"Broadcast thread is exiting\n"); diff --git a/source/shared_lib/sources/util/util.cpp b/source/shared_lib/sources/util/util.cpp index 88f15024..b4c4b154 100644 --- a/source/shared_lib/sources/util/util.cpp +++ b/source/shared_lib/sources/util/util.cpp @@ -35,12 +35,14 @@ using namespace Shared::Platform; namespace Shared{ namespace Util{ -bool SystemFlags::enableDebugText = false; -bool SystemFlags::enableNetworkDebugInfo = false; -const char * SystemFlags::debugLogFile = NULL; +bool SystemFlags::enableDebugText = false; +bool SystemFlags::enableNetworkDebugInfo = false; +bool SystemFlags::enablePerformanceDebugInfo = false; + +const char * SystemFlags::debugLogFile = NULL; ofstream SystemFlags::fileStream; -int SystemFlags::lockFile = -1; -string SystemFlags::lockfilename = ""; +int SystemFlags::lockFile = -1; +string SystemFlags::lockfilename = ""; inline bool acquire_file_lock(int hnd) { @@ -82,8 +84,9 @@ void SystemFlags::Close() { } void SystemFlags::OutputDebug(DebugType type, const char *fmt, ...) { - if((type == debugSystem && SystemFlags::enableDebugText == false) || - (type == debugNetwork && SystemFlags::enableNetworkDebugInfo == false)) { + if((type == debugSystem && SystemFlags::enableDebugText == false) || + (type == debugNetwork && SystemFlags::enableNetworkDebugInfo == false || + type == debugPerformance && SystemFlags::enablePerformanceDebugInfo == false)) { return; }