From e43a2cac32cb773994b11a3d964ec4acc372d273 Mon Sep 17 00:00:00 2001 From: Mike Buland Date: Wed, 26 Jul 2023 21:33:36 -0700 Subject: Added a profiler and investageted Server. --- src/stable/client.cpp | 11 +++ src/stable/client.h | 10 ++- src/stable/server.cpp | 22 ++++++ src/stable/server.h | 8 ++ src/unstable/profiler.cpp | 184 ++++++++++++++++++++++++++++++++++++++++++++++ src/unstable/profiler.h | 54 ++++++++++++++ 6 files changed, 288 insertions(+), 1 deletion(-) create mode 100644 src/unstable/profiler.cpp create mode 100644 src/unstable/profiler.h diff --git a/src/stable/client.cpp b/src/stable/client.cpp index f6feb7c..56c5094 100644 --- a/src/stable/client.cpp +++ b/src/stable/client.cpp @@ -16,6 +16,13 @@ /** Read buffer size. */ #define RBS (2000) // 1500 is the nominal MTU for ethernet, it's a good guess +#ifdef PROFILE_BU_SERVER +#define BU_PROFILE_START( x ) Bu::Profiler::getInstance().startEvent( x ) +#define BU_PROFILE_END( x ) Bu::Profiler::getInstance().endEvent( x ) +#else +#define BU_PROFILE_START( x ) (void)0 +#define BU_PROFILE_END( x ) (void)0 +#endif Bu::Client::Client( Bu::TcpSocket *pSocket, class Bu::ClientLinkFactory *pfLink ) : @@ -47,6 +54,7 @@ void Bu::Client::processInput() char buf[RBS]; Bu::size nRead, nTotal=0; + BU_PROFILE_START("client.read"); for(;;) { try @@ -72,6 +80,7 @@ void Bu::Client::processInput() break; } } + BU_PROFILE_END("client.read"); mRead.unlock(); if( nTotal == 0 ) @@ -82,7 +91,9 @@ void Bu::Client::processInput() if( pProto && nTotal ) { + BU_PROFILE_START("client.process"); pProto->onNewData( this ); + BU_PROFILE_END("client.process"); } } diff --git a/src/stable/client.h b/src/stable/client.h index 119e2f7..abde682 100644 --- a/src/stable/client.h +++ b/src/stable/client.h @@ -16,6 +16,14 @@ #include "bu/mutex.h" #include "bu/readwritemutex.h" +#ifndef PROFILE_BU_SERVER +// #define PROFILE_BU_SERVER 1 +#endif + +#ifdef PROFILE_BU_SERVER +#include "bu/profiler.h" +#endif + namespace Bu { class Protocol; @@ -29,7 +37,7 @@ namespace Bu class Client : public Bu::Stream { public: - Client( Bu::TcpSocket *pSocket, Bu::ClientLinkFactory *pfLink ); + Client( Bu::TcpSocket *pSocket, Bu::ClientLinkFactory *pfLink); virtual ~Client(); void processInput(); diff --git a/src/stable/server.cpp b/src/stable/server.cpp index 3c42bf4..0552510 100644 --- a/src/stable/server.cpp +++ b/src/stable/server.cpp @@ -13,17 +13,27 @@ #include "bu/tcpsocket.h" #include "bu/config.h" +#ifdef PROFILE_BU_SERVER +#define BU_PROFILE_START( x ) Bu::Profiler::getInstance().startEvent( x ) +#define BU_PROFILE_END( x ) Bu::Profiler::getInstance().endEvent( x ) +#else +#define BU_PROFILE_START( x ) (void)0 +#define BU_PROFILE_END( x ) (void)0 +#endif + Bu::Server::Server() : nTimeoutSec( 0 ), nTimeoutUSec( 0 ), bAutoTick( false ) { + BU_PROFILE_START("server"); FD_ZERO( &fdActive ); } Bu::Server::~Server() { shutdown(); + BU_PROFILE_START("server"); } void Bu::Server::addPort( int nPort, int nPoolSize ) @@ -50,6 +60,7 @@ void Bu::Server::setTimeout( int nTimeoutSec, int nTimeoutUSec ) void Bu::Server::scan() { + BU_PROFILE_START("scan"); struct timeval xTimeout = { nTimeoutSec, nTimeoutUSec }; fd_set fdRead = fdActive; @@ -68,6 +79,7 @@ void Bu::Server::scan() { char buf[1024]; strerror_r( errno, buf, 1024 ); + BU_PROFILE_END("scan"); throw ExceptionBase( Bu::String("Error attempting to scan open connections: %1: %2").arg( errno ).arg( buf ).end().getStr() ); @@ -85,7 +97,9 @@ void Bu::Server::scan() else { Client *pClient = hClients.get( j ); + BU_PROFILE_START("processInput"); pClient->processInput(); + BU_PROFILE_END("processInput"); if( !pClient->isOpen() ) { closeClient( j ); @@ -99,7 +113,9 @@ void Bu::Server::scan() Client *pClient = hClients.get( j ); try { + BU_PROFILE_START("processOutput"); pClient->processOutput(); + BU_PROFILE_END("processOutput"); } catch( Bu::TcpSocketException &e ) { @@ -133,10 +149,13 @@ void Bu::Server::scan() if( bAutoTick ) tick(); + + BU_PROFILE_END("scan"); } void Bu::Server::addClient( socket_t nSocket, int nPort ) { + BU_PROFILE_START("addClient"); FD_SET( nSocket, &fdActive ); Client *c = new Client( @@ -146,6 +165,7 @@ void Bu::Server::addClient( socket_t nSocket, int nPort ) hClients.insert( nSocket, c ); onNewConnection( c, nPort ); + BU_PROFILE_END("addClient"); } Bu::Server::SrvClientLink::SrvClientLink( Bu::Client *pClient ) : @@ -208,11 +228,13 @@ void Bu::Server::shutdown() void Bu::Server::closeClient( socket_t iSocket ) { + BU_PROFILE_START("closeClient"); Bu::Client *pClient = hClients.get( iSocket ); onClosedConnection( pClient ); pClient->close(); hClients.erase( iSocket ); FD_CLR( iSocket, &fdActive ); delete pClient; + BU_PROFILE_END("closeClient"); } diff --git a/src/stable/server.h b/src/stable/server.h index ee76fd2..d3f0903 100644 --- a/src/stable/server.h +++ b/src/stable/server.h @@ -23,6 +23,14 @@ #include "bu/config.h" +#ifndef PROFILE_BU_SERVER +// #define PROFILE_BU_SERVER 1 +#endif + +#ifdef PROFILE_BU_SERVER +#include "bu/profiler.h" +#endif + namespace Bu { class TcpServerSocket; diff --git a/src/unstable/profiler.cpp b/src/unstable/profiler.cpp new file mode 100644 index 0000000..1b176b9 --- /dev/null +++ b/src/unstable/profiler.cpp @@ -0,0 +1,184 @@ +#include "bu/profiler.h" +#include "bu/mutexlocker.h" +#include "bu/sio.h" + +#include + +Bu::Profiler::Profiler() +{ +} + +Bu::Profiler::~Profiler() +{ + printReport(); +} + +uint64_t Bu::Profiler::getMicroTime() +{ + struct timeval tv; + gettimeofday( &tv, NULL ); + return ((uint64_t)tv.tv_sec)*1000000 + ((uint64_t)tv.tv_usec); +} + +void Bu::Profiler::startEvent( const Bu::Blob &bName ) +{ + Bu::MutexLocker l( mLock ); + if( hEvent.has( bName ) ) + { + hEvent.get( bName ).append( Event() ); + } + else + { + hEvent.insert( bName, EventList( Event() ) ); + } +} + +void Bu::Profiler::endEvent( const Bu::Blob &bName ) +{ + Bu::MutexLocker l( mLock ); + if( !hEvent.has( bName ) ) + return; + + if( hEvent.get( bName ).isEmpty() ) + return; + + hEvent.get( bName ).last().end(); +} + +void Bu::Profiler::printReport() const +{ + class Breakdown + { + public: + Breakdown( const Bu::Blob &bName ) : + bName( bName ), uCount( 0 ), uTotal( 0 ), uMin( 0 ), uMax( 0 ) { } + Breakdown( const Breakdown &rSrc ) : + bName( rSrc.bName ), uCount( rSrc.uCount ), uTotal( rSrc.uTotal ), + uMin( rSrc.uMin ), uMax( rSrc.uMax ) { } + ~Breakdown() { } + + bool operator<( const Breakdown &rhs ) const + { + return uTotal > rhs.uTotal; + } + Breakdown &operator=( const Breakdown &rhs ) + { + bName = rhs.bName; + uCount = rhs.uCount; + uTotal = rhs.uTotal; + uMin = rhs.uMin; + uMax = rhs.uMax; + return *this; + } + + void add( uint64_t uSpan ) + { + if( uCount == 0 ) + { + uMin = uMax = uSpan; + } + else + { + if( uMin > uSpan ) + uMin = uSpan; + if( uMax < uSpan ) + uMax = uSpan; + + } + uCount++; + uTotal += uSpan; + } + + Bu::Blob bName; + uint64_t uCount; + uint64_t uTotal; + uint64_t uMin; + uint64_t uMax; + }; + Bu::MutexLocker l( mLock ); + + int iTitleLen = 0; + Bu::List lBreakdown; + for( EventListHash::const_iterator iType = hEvent.begin(); iType; iType++ ) + { + Breakdown b( iType.getKey() ); + if( iTitleLen < b.bName.getSize() ) + iTitleLen = b.bName.getSize(); + for( EventList::const_iterator iEv = iType.getValue().begin(); + iEv; iEv++ ) + { + b.add( (*iEv).getSpan() ); + } + lBreakdown.append( b ); + } + + lBreakdown.sort(); + + Bu::println("%1 %2 %3 %4 %5 %6") + .arg("Title", Bu::Fmt(iTitleLen) ) + .arg("Cnt", Bu::Fmt(5) ) + .arg("Total", Bu::Fmt(9) ) + .arg("Avg", Bu::Fmt(9) ) + .arg("Max", Bu::Fmt(9) ) + .arg("Min", Bu::Fmt(9) ); + for( Bu::List::iterator i = lBreakdown.begin(); i; i++ ) + { + Bu::println("%1 %2 %3.%4 %5.%6 %7.%8 %9.%10") + .arg( (*i).bName.getData(), Bu::Fmt(iTitleLen) ) + .arg( (*i).uCount, Bu::Fmt(5) ) + .arg( ((*i).uTotal/1000000), Bu::Fmt(5).right() ) + .arg( ((*i).uTotal/1000)%1000, Bu::Fmt(3).fill('0').right() ) + .arg( ((*i).uTotal/(*i).uCount)/1000000, Bu::Fmt(5).right() ) + .arg( (((*i).uTotal/(*i).uCount)/1000)%1000, Bu::Fmt(3).right().fill('0') ) + .arg( (*i).uMax/1000000, Bu::Fmt(5).right() ) + .arg( ((*i).uMax/1000)%1000, Bu::Fmt(3).right().fill('0') ) + .arg( (*i).uMin/1000000, Bu::Fmt(5).right() ) + .arg( ((*i).uMin/1000)%1000, Bu::Fmt(3).right().fill('0') ) + ; + } +} + +Bu::Profiler::Event::Event() : + iStart( Bu::Profiler::getMicroTime() ), + iStop( 0 ) +{ +} + +Bu::Profiler::Event::Event( const Event &rSrc ) : + iStart( rSrc.iStart ), + iStop( rSrc.iStop ) +{ +} + +Bu::Profiler::Event::~Event() +{ +} + +void Bu::Profiler::Event::end() +{ + if( iStop == 0 ) + iStop = Bu::Profiler::getMicroTime(); +} + +bool Bu::Profiler::Event::hasEnded() const +{ + return iStop != 0; +} + +uint64_t Bu::Profiler::Event::getStart() const +{ + return iStart; +} + +uint64_t Bu::Profiler::Event::getEnd() const +{ + return iStop; +} + +uint64_t Bu::Profiler::Event::getSpan() const +{ + if( iStop < iStart ) + return 0; + return iStop-iStart; +} + diff --git a/src/unstable/profiler.h b/src/unstable/profiler.h new file mode 100644 index 0000000..df05023 --- /dev/null +++ b/src/unstable/profiler.h @@ -0,0 +1,54 @@ +#ifndef BU_PROFILER_H +#define BU_PROFILER_H + +#include "bu/blob.h" +#include "bu/hash.h" +#include "bu/list.h" +#include "bu/mutex.h" +#include "bu/singleton.h" + +namespace Bu +{ + class Profiler : public Bu::Singleton + { + friend class Bu::Singleton; + private: + Profiler(); + virtual ~Profiler(); + + public: + static uint64_t getMicroTime(); + + void startEvent( const Bu::Blob &bName ); + void endEvent( const Bu::Blob &bName ); + + void printReport() const; + + private: + class Event + { + public: + Event(); + Event( const Event &rSrc ); + ~Event(); + + void end(); + bool hasEnded() const; + + uint64_t getStart() const; + uint64_t getEnd() const; + uint64_t getSpan() const; + + private: + uint64_t iStart; + uint64_t iStop; + }; + + typedef Bu::List EventList; + typedef Bu::Hash EventListHash; + EventListHash hEvent; + mutable Bu::Mutex mLock; + }; +}; + +#endif -- cgit v1.2.3