add stats to voxel server to show average voxel edit packet statistics

This commit is contained in:
ZappoMan 2013-11-11 16:31:36 -08:00
parent 1d297eb343
commit af8438b098
6 changed files with 159 additions and 38 deletions

View file

@ -128,15 +128,26 @@ int VoxelServer::civetwebRequestHandler(struct mg_connection* connection) {
return 1;
}
#endif
bool showStats = false;
if (strcmp(ri->uri, "/") == 0 && strcmp(ri->request_method, "GET") == 0) {
showStats = true;
}
if (strcmp(ri->uri, "/resetStats") == 0 && strcmp(ri->request_method, "GET") == 0) {
GetInstance()->_voxelServerPacketProcessor->resetStats();
showStats = true;
}
if (showStats) {
uint64_t checkSum;
// return a 200
mg_printf(connection, "%s", "HTTP/1.0 200 OK\r\n\r\n");
mg_printf(connection, "%s", "Your Voxel Server is running.\r\n");
mg_printf(connection, "%s", "HTTP/1.0 200 OK\r\n");
mg_printf(connection, "%s", "Content-Type: text/html\r\n\r\n");
mg_printf(connection, "%s", "<html><doc>\r\n");
mg_printf(connection, "%s", "<pre>\r\n");
mg_printf(connection, "%s", "<b>Your Voxel Server is running... <a href='/'>[RELOAD]</a></b>\r\n");
mg_printf(connection, "%s", "\r\n");
tm* localtm = localtime(&GetInstance()->_started);
const int MAX_TIME_LENGTH = 128;
char buffer[MAX_TIME_LENGTH];
@ -206,7 +217,7 @@ int VoxelServer::civetwebRequestHandler(struct mg_connection* connection) {
if (minutes > 0) {
mg_printf(connection, "%d minute%s ", minutes, (minutes > 1) ? "s" : "");
}
if (seconds > 0) {
if (seconds >= 0) {
mg_printf(connection, "%.3f seconds", seconds);
}
mg_printf(connection, "%s", "\r\n");
@ -218,15 +229,70 @@ int VoxelServer::civetwebRequestHandler(struct mg_connection* connection) {
mg_printf(connection, "%s", "\r\n");
mg_printf(connection, "%s", "\r\n");
mg_printf(connection, "%s", "Configuration: \r\n ");
mg_printf(connection, "%s", "<b>Configuration:</b>\r\n");
for (int i = 1; i < GetInstance()->_argc; i++) {
mg_printf(connection, "%s ", GetInstance()->_argv[i]);
}
mg_printf(connection, "%s", "\r\n"); // one to end the config line
mg_printf(connection, "%s", "\r\n"); // two more for spacing
mg_printf(connection, "%s", "\r\n");
// display scene stats
unsigned long nodeCount = VoxelNode::getNodeCount();
unsigned long internalNodeCount = VoxelNode::getInternalNodeCount();
unsigned long leafNodeCount = VoxelNode::getLeafNodeCount();
QLocale locale(QLocale::English);
const float AS_PERCENT = 100.0;
mg_printf(connection, "%s", "<b>Current Nodes in scene:</b>\r\n");
mg_printf(connection, " Total Nodes: %s nodes\r\n",
locale.toString((uint)nodeCount).rightJustified(16, ' ').toLocal8Bit().constData());
mg_printf(connection, " Internal Nodes: %s nodes (%5.2f%%)\r\n",
locale.toString((uint)internalNodeCount).rightJustified(16, ' ').toLocal8Bit().constData(),
((float)internalNodeCount/(float)nodeCount) * AS_PERCENT);
mg_printf(connection, " Leaf Nodes: %s nodes (%5.2f%%)\r\n",
locale.toString((uint)leafNodeCount).rightJustified(16, ' ').toLocal8Bit().constData(),
((float)leafNodeCount/(float)nodeCount) * AS_PERCENT);
mg_printf(connection, "%s", "\r\n");
mg_printf(connection, "%s", "\r\n");
// display inbound packet stats
mg_printf(connection, "%s", "<b>Voxel Edit Statistics... <a href='/resetStats'>[RESET]</a></b>\r\n");
uint64_t averageTransitTimePerPacket = GetInstance()->_voxelServerPacketProcessor->getAverateTransitTimePerPacket();
uint64_t averageProcessTimePerPacket = GetInstance()->_voxelServerPacketProcessor->getAverageProcessTimePerPacket();
uint64_t averageLockWaitTimePerPacket = GetInstance()->_voxelServerPacketProcessor->getAverageLockWaitTimePerPacket();
uint64_t averageProcessTimePerVoxel = GetInstance()->_voxelServerPacketProcessor->getAverageProcessTimePerVoxel();
uint64_t averageLockWaitTimePerVoxel = GetInstance()->_voxelServerPacketProcessor->getAverageLockWaitTimePerVoxel();
uint64_t totalVoxelsProcessed = GetInstance()->_voxelServerPacketProcessor->getTotalVoxelsProcessed();
uint64_t totalPacketsProcessed = GetInstance()->_voxelServerPacketProcessor->getTotalPacketsProcessed();
mg_printf(connection, "%s", "Current Statistics\r\n");
float averageVoxelsPerPacket = totalPacketsProcessed == 0 ? 0 : totalVoxelsProcessed / totalPacketsProcessed;
const int COLUMN_WIDTH = 10;
mg_printf(connection, " Total Inbound Packets: %s packets\r\n",
locale.toString((uint)totalPacketsProcessed).rightJustified(COLUMN_WIDTH, ' ').toLocal8Bit().constData());
mg_printf(connection, " Total Inbound Voxels: %s voxels\r\n",
locale.toString((uint)totalVoxelsProcessed).rightJustified(COLUMN_WIDTH, ' ').toLocal8Bit().constData());
mg_printf(connection, " Average Inbound Voxels/Packet: %f voxels/packet\r\n", averageVoxelsPerPacket);
mg_printf(connection, " Average Transit Time/Packet: %s usecs\r\n",
locale.toString((uint)averageTransitTimePerPacket).rightJustified(COLUMN_WIDTH, ' ').toLocal8Bit().constData());
mg_printf(connection, " Average Process Time/Packet: %s usecs\r\n",
locale.toString((uint)averageProcessTimePerPacket).rightJustified(COLUMN_WIDTH, ' ').toLocal8Bit().constData());
mg_printf(connection, " Average Wait Lock Time/Packet: %s usecs\r\n",
locale.toString((uint)averageLockWaitTimePerPacket).rightJustified(COLUMN_WIDTH, ' ').toLocal8Bit().constData());
mg_printf(connection, " Average Process Time/Voxel: %s usecs\r\n",
locale.toString((uint)averageProcessTimePerVoxel).rightJustified(COLUMN_WIDTH, ' ').toLocal8Bit().constData());
mg_printf(connection, " Average Wait Lock Time/Voxel: %s usecs\r\n",
locale.toString((uint)averageLockWaitTimePerVoxel).rightJustified(COLUMN_WIDTH, ' ').toLocal8Bit().constData());
mg_printf(connection, "%s", "\r\n");
mg_printf(connection, "%s", "\r\n");
// display memory usage stats
mg_printf(connection, "%s", "<b>Current Memory Usage Statistics</b>\r\n");
mg_printf(connection, "\r\nVoxelNode size... %ld bytes\r\n", sizeof(VoxelNode));
mg_printf(connection, "%s", "\r\n");
const char* memoryScaleLabel;
@ -251,28 +317,6 @@ int VoxelServer::civetwebRequestHandler(struct mg_connection* connection) {
mg_printf(connection, " Total: %8.2f %s\r\n",
VoxelNode::getTotalMemoryUsage() / memoryScale, memoryScaleLabel);
mg_printf(connection, "\r\nVoxelNode size... %ld bytes\r\n", sizeof(VoxelNode));
unsigned long nodeCount = VoxelNode::getNodeCount();
unsigned long internalNodeCount = VoxelNode::getInternalNodeCount();
unsigned long leafNodeCount = VoxelNode::getLeafNodeCount();
QLocale locale(QLocale::English);
const float AS_PERCENT = 100.0;
mg_printf(connection, "%s", "\r\n");
mg_printf(connection, "%s", "Current Nodes in scene\r\n");
mg_printf(connection, " Total Nodes: %s nodes\r\n",
locale.toString((uint)nodeCount).rightJustified(16, ' ').toLocal8Bit().constData());
mg_printf(connection, " Internal Nodes: %s nodes (%5.2f%%)\r\n",
locale.toString((uint)internalNodeCount).rightJustified(16, ' ').toLocal8Bit().constData(),
((float)internalNodeCount/(float)nodeCount) * AS_PERCENT);
mg_printf(connection, " Leaf Nodes: %s nodes (%5.2f%%)\r\n",
locale.toString((uint)leafNodeCount).rightJustified(16, ' ').toLocal8Bit().constData(),
((float)leafNodeCount/(float)nodeCount) * AS_PERCENT);
mg_printf(connection, "%s", "\r\n");
mg_printf(connection, "%s", "VoxelNode Children Population Statistics...\r\n");
checkSum = 0;
@ -325,6 +369,12 @@ int VoxelServer::civetwebRequestHandler(struct mg_connection* connection) {
VoxelNode::getCouldNotStoreFourChildrenInternally());
#endif
mg_printf(connection, "%s", "\r\n");
mg_printf(connection, "%s", "\r\n");
mg_printf(connection, "%s", "</pre>\r\n");
mg_printf(connection, "%s", "</doc></html>");
return 1;
} else {
// have mongoose process this request from the document_root

View file

@ -15,10 +15,25 @@
#include "VoxelServerConsts.h"
#include "VoxelServerPacketProcessor.h"
static QUuid DEFAULT_NODE_ID_REF;
VoxelServerPacketProcessor::VoxelServerPacketProcessor(VoxelServer* myServer) :
_myServer(myServer),
_receivedPacketCount(0) {
_receivedPacketCount(0),
_totalTransitTime(0),
_totalProcessTime(0),
_totalLockWaitTime(0),
_totalVoxelsInPacket(0),
_totalPackets(0)
{
}
void VoxelServerPacketProcessor::resetStats() {
_totalTransitTime = 0;
_totalProcessTime = 0;
_totalLockWaitTime = 0;
_totalVoxelsInPacket = 0;
_totalPackets = 0;
}
@ -37,13 +52,16 @@ void VoxelServerPacketProcessor::processPacket(sockaddr& senderAddress, unsigned
PerformanceWarning warn(_myServer->wantShowAnimationDebug(),
destructive ? "PACKET_TYPE_SET_VOXEL_DESTRUCTIVE" : "PACKET_TYPE_SET_VOXEL",
_myServer->wantShowAnimationDebug());
_receivedPacketCount++;
unsigned short int sequence = (*((unsigned short int*)(packetData + numBytesPacketHeader)));
uint64_t sentAt = (*((uint64_t*)(packetData + numBytesPacketHeader + sizeof(sequence))));
uint64_t arrivedAt = usecTimestampNow();
uint64_t transitTime = arrivedAt - sentAt;
int voxelsInPacket = 0;
uint64_t processTime = 0;
uint64_t lockWaitTime = 0;
if (_myServer->wantShowAnimationDebug() || _myServer->wantsDebugVoxelReceiving()) {
printf("PROCESSING THREAD: got %s - %d command from client receivedBytes=%ld sequence=%d transitTime=%llu usecs\n",
@ -84,9 +102,20 @@ void VoxelServerPacketProcessor::processPacket(sockaddr& senderAddress, unsigned
delete[] vertices;
}
uint64_t startLock = usecTimestampNow();
_myServer->getServerTree().lockForWrite();
uint64_t startProcess = usecTimestampNow();
_myServer->getServerTree().readCodeColorBufferToTree(voxelData, destructive);
_myServer->getServerTree().unlock();
uint64_t endProcess = usecTimestampNow();
voxelsInPacket++;
uint64_t thisProcessTime = endProcess - startProcess;
uint64_t thisLockWaitTime = startProcess - startLock;
processTime += thisProcessTime;
lockWaitTime += thisLockWaitTime;
// skip to next voxel edit record in the packet
voxelData += voxelDataSize;
@ -104,10 +133,20 @@ void VoxelServerPacketProcessor::processPacket(sockaddr& senderAddress, unsigned
}
// Make sure our Node and NodeList knows we've heard from this node.
Node* node = NodeList::getInstance()->nodeWithAddress(&senderAddress);
if (node) {
node->setLastHeardMicrostamp(usecTimestampNow());
Node* senderNode = NodeList::getInstance()->nodeWithAddress(&senderAddress);
QUuid& nodeUUID = DEFAULT_NODE_ID_REF;
if (senderNode) {
senderNode->setLastHeardMicrostamp(usecTimestampNow());
nodeUUID = senderNode->getUUID();
if (debugProcessPacket) {
qDebug() << "sender has uuid=" << nodeUUID << "\n";
}
} else {
if (debugProcessPacket) {
qDebug() << "sender has no known nodeUUID.\n";
}
}
trackInboudPackets(nodeUUID, sequence, transitTime, voxelsInPacket, processTime, lockWaitTime);
} else if (packetData[0] == PACKET_TYPE_ERASE_VOXEL) {
@ -167,3 +206,13 @@ void VoxelServerPacketProcessor::processPacket(sockaddr& senderAddress, unsigned
}
}
void VoxelServerPacketProcessor::trackInboudPackets(const QUuid& nodeUUID, int sequence, uint64_t transitTime,
int voxelsInPacket, uint64_t processTime, uint64_t lockWaitTime) {
_totalTransitTime += transitTime;
_totalProcessTime += processTime;
_totalLockWaitTime += lockWaitTime;
_totalVoxelsInPacket += voxelsInPacket;
_totalPackets++;
}

View file

@ -21,11 +21,33 @@ class VoxelServerPacketProcessor : public ReceivedPacketProcessor {
public:
VoxelServerPacketProcessor(VoxelServer* myServer);
uint64_t getAverateTransitTimePerPacket() const { return _totalPackets == 0 ? 0 : _totalTransitTime / _totalPackets; }
uint64_t getAverageProcessTimePerPacket() const { return _totalPackets == 0 ? 0 : _totalProcessTime / _totalPackets; }
uint64_t getAverageLockWaitTimePerPacket() const { return _totalPackets == 0 ? 0 : _totalLockWaitTime / _totalPackets; }
uint64_t getTotalVoxelsProcessed() const { return _totalVoxelsInPacket; }
uint64_t getTotalPacketsProcessed() const { return _totalPackets; }
uint64_t getAverageProcessTimePerVoxel() const
{ return _totalVoxelsInPacket == 0 ? 0 : _totalProcessTime / _totalVoxelsInPacket; }
uint64_t getAverageLockWaitTimePerVoxel() const
{ return _totalVoxelsInPacket == 0 ? 0 : _totalLockWaitTime / _totalVoxelsInPacket; }
void resetStats();
protected:
virtual void processPacket(sockaddr& senderAddress, unsigned char* packetData, ssize_t packetLength);
private:
void trackInboudPackets(const QUuid& nodeUUID, int sequence, uint64_t transitTime,
int voxelsInPacket, uint64_t processTime, uint64_t lockWaitTime);
VoxelServer* _myServer;
int _receivedPacketCount;
uint64_t _totalTransitTime;
uint64_t _totalProcessTime;
uint64_t _totalLockWaitTime;
uint64_t _totalVoxelsInPacket;
uint64_t _totalPackets;
};
#endif // __voxel_server__VoxelServerPacketProcessor__

View file

@ -229,7 +229,7 @@ bool JurisdictionMap::readFromFile(const char* filename) {
return true;
}
void JurisdictionMap::displayDebugDetails() {
void JurisdictionMap::displayDebugDetails() const {
QString rootNodeValue = octalCodeToHexString(_rootOctalCode);
qDebug() << "root:" << rootNodeValue << "\n";

View file

@ -60,7 +60,7 @@ public:
/// Available to pack an empty or unknown jurisdiction into a network packet, used when no JurisdictionMap is available
static int packEmptyJurisdictionIntoMessage(unsigned char* destinationBuffer, int availableBytes);
void displayDebugDetails();
void displayDebugDetails() const;
private:
void copyContents(const JurisdictionMap& other); // use assignment instead

View file

@ -191,7 +191,7 @@ void VoxelEditPacketSender::queuePacketToNodes(unsigned char* buffer, ssize_t le
assert(voxelServersExist()); // we must have jurisdictions to be here!!
int headerBytes = numBytesForPacketHeader(buffer) + sizeof(short);
int headerBytes = numBytesForPacketHeader(buffer) + sizeof(short) + sizeof(uint64_t);
unsigned char* octCode = buffer + headerBytes; // skip the packet header to get to the octcode
// We want to filter out edit messages for voxel servers based on the server's Jurisdiction