From a75e577d0a5fc8da1be28b69322d44632943aa4d Mon Sep 17 00:00:00 2001 From: ZappoMan Date: Fri, 8 Nov 2013 09:32:06 -0800 Subject: [PATCH 1/3] voxel edit packet debugging support --- .../voxel-server-library/src/VoxelServer.cpp | 19 ++++++++++++------- .../voxel-server-library/src/VoxelServer.h | 2 ++ .../src/VoxelServerPacketProcessor.cpp | 8 ++++---- .../voxels/src/VoxelEditPacketSender.cpp | 6 ++++-- libraries/voxels/src/VoxelEditPacketSender.h | 2 ++ 5 files changed, 24 insertions(+), 13 deletions(-) diff --git a/libraries/voxel-server-library/src/VoxelServer.cpp b/libraries/voxel-server-library/src/VoxelServer.cpp index 0b868d8908..0bafa64a5b 100644 --- a/libraries/voxel-server-library/src/VoxelServer.cpp +++ b/libraries/voxel-server-library/src/VoxelServer.cpp @@ -71,6 +71,7 @@ VoxelServer::VoxelServer(const unsigned char* dataBuffer, int numBytes) : Assign _sendEnvironments = true; _sendMinimalEnvironment = false; _dumpVoxelsOnMove = false; + _verboseDebug = false; _jurisdiction = NULL; _jurisdictionSender = NULL; _voxelServerPacketProcessor = NULL; @@ -427,14 +428,14 @@ void VoxelServer::run() { // should we send environments? Default is yes, but this command line suppresses sending const char* SEND_ENVIRONMENTS = "--sendEnvironments"; - bool dontSendEnvironments = !getCmdOption(_argc, _argv, SEND_ENVIRONMENTS); + bool dontSendEnvironments = !cmdOptionExists(_argc, _argv, SEND_ENVIRONMENTS); if (dontSendEnvironments) { qDebug("Sending environments suppressed...\n"); _sendEnvironments = false; } else { // should we send environments? Default is yes, but this command line suppresses sending const char* MINIMAL_ENVIRONMENT = "--minimalEnvironment"; - _sendMinimalEnvironment = getCmdOption(_argc, _argv, MINIMAL_ENVIRONMENT); + _sendMinimalEnvironment = cmdOptionExists(_argc, _argv, MINIMAL_ENVIRONMENT); qDebug("Using Minimal Environment=%s\n", debug::valueOf(_sendMinimalEnvironment)); } qDebug("Sending environments=%s\n", debug::valueOf(_sendEnvironments)); @@ -455,24 +456,28 @@ void VoxelServer::run() { srand((unsigned)time(0)); const char* DISPLAY_VOXEL_STATS = "--displayVoxelStats"; - _displayVoxelStats = getCmdOption(_argc, _argv, DISPLAY_VOXEL_STATS); + _displayVoxelStats = cmdOptionExists(_argc, _argv, DISPLAY_VOXEL_STATS); qDebug("displayVoxelStats=%s\n", debug::valueOf(_displayVoxelStats)); + const char* VERBOSE_DEBUG = "--verboseDebug"; + _verboseDebug = cmdOptionExists(_argc, _argv, VERBOSE_DEBUG); + qDebug("verboseDebug=%s\n", debug::valueOf(_verboseDebug)); + const char* DEBUG_VOXEL_SENDING = "--debugVoxelSending"; - _debugVoxelSending = getCmdOption(_argc, _argv, DEBUG_VOXEL_SENDING); + _debugVoxelSending = cmdOptionExists(_argc, _argv, DEBUG_VOXEL_SENDING); qDebug("debugVoxelSending=%s\n", debug::valueOf(_debugVoxelSending)); const char* DEBUG_VOXEL_RECEIVING = "--debugVoxelReceiving"; - _debugVoxelReceiving = getCmdOption(_argc, _argv, DEBUG_VOXEL_RECEIVING); + _debugVoxelReceiving = cmdOptionExists(_argc, _argv, DEBUG_VOXEL_RECEIVING); qDebug("debugVoxelReceiving=%s\n", debug::valueOf(_debugVoxelReceiving)); const char* WANT_ANIMATION_DEBUG = "--shouldShowAnimationDebug"; - _shouldShowAnimationDebug = getCmdOption(_argc, _argv, WANT_ANIMATION_DEBUG); + _shouldShowAnimationDebug = cmdOptionExists(_argc, _argv, WANT_ANIMATION_DEBUG); qDebug("shouldShowAnimationDebug=%s\n", debug::valueOf(_shouldShowAnimationDebug)); // By default we will voxel persist, if you want to disable this, then pass in this parameter const char* NO_VOXEL_PERSIST = "--NoVoxelPersist"; - if (getCmdOption(_argc, _argv, NO_VOXEL_PERSIST)) { + if (cmdOptionExists(_argc, _argv, NO_VOXEL_PERSIST)) { _wantVoxelPersist = false; } qDebug("wantVoxelPersist=%s\n", debug::valueOf(_wantVoxelPersist)); diff --git a/libraries/voxel-server-library/src/VoxelServer.h b/libraries/voxel-server-library/src/VoxelServer.h index 92590489f8..4aee48e5f1 100644 --- a/libraries/voxel-server-library/src/VoxelServer.h +++ b/libraries/voxel-server-library/src/VoxelServer.h @@ -40,6 +40,7 @@ public: bool wantsDebugVoxelSending() const { return _debugVoxelSending; } bool wantsDebugVoxelReceiving() const { return _debugVoxelReceiving; } + bool wantsVerboseDebug() const { return _verboseDebug; } bool wantShowAnimationDebug() const { return _shouldShowAnimationDebug; } bool wantSendEnvironments() const { return _sendEnvironments; } bool wantDumpVoxelsOnMove() const { return _dumpVoxelsOnMove; } @@ -76,6 +77,7 @@ private: bool _sendEnvironments; bool _sendMinimalEnvironment; bool _dumpVoxelsOnMove; + bool _verboseDebug; JurisdictionMap* _jurisdiction; JurisdictionSender* _jurisdictionSender; VoxelServerPacketProcessor* _voxelServerPacketProcessor; diff --git a/libraries/voxel-server-library/src/VoxelServerPacketProcessor.cpp b/libraries/voxel-server-library/src/VoxelServerPacketProcessor.cpp index 672c4f0d50..5cbc942d16 100644 --- a/libraries/voxel-server-library/src/VoxelServerPacketProcessor.cpp +++ b/libraries/voxel-server-library/src/VoxelServerPacketProcessor.cpp @@ -24,10 +24,10 @@ VoxelServerPacketProcessor::VoxelServerPacketProcessor(VoxelServer* myServer) : void VoxelServerPacketProcessor::processPacket(sockaddr& senderAddress, unsigned char* packetData, ssize_t packetLength) { - bool debugProcessPacket = _myServer->wantsDebugVoxelReceiving(); + bool debugProcessPacket = _myServer->wantsVerboseDebug(); if (debugProcessPacket) { - printf("VoxelServerPacketProcessor::processPacket(() packetData=%p packetLength=%ld\n", packetData, packetLength); + printf("VoxelServerPacketProcessor::processPacket() packetData=%p packetLength=%ld\n", packetData, packetLength); } int numBytesPacketHeader = numBytesForPacketHeader(packetData); @@ -58,7 +58,7 @@ void VoxelServerPacketProcessor::processPacket(sockaddr& senderAddress, unsigned int maxSize = packetLength - atByte; if (debugProcessPacket) { - printf("VoxelServerPacketProcessor::processPacket(() %s packetData=%p packetLength=%ld voxelData=%p atByte=%d maxSize=%d\n", + printf("VoxelServerPacketProcessor::processPacket() %s packetData=%p packetLength=%ld voxelData=%p atByte=%d maxSize=%d\n", destructive ? "PACKET_TYPE_SET_VOXEL_DESTRUCTIVE" : "PACKET_TYPE_SET_VOXEL", packetData, packetLength, voxelData, atByte, maxSize); } @@ -100,7 +100,7 @@ void VoxelServerPacketProcessor::processPacket(sockaddr& senderAddress, unsigned } if (debugProcessPacket) { - printf("VoxelServerPacketProcessor::processPacket(() DONE LOOPING FOR %s packetData=%p packetLength=%ld voxelData=%p atByte=%d\n", + printf("VoxelServerPacketProcessor::processPacket() DONE LOOPING FOR %s packetData=%p packetLength=%ld voxelData=%p atByte=%d\n", destructive ? "PACKET_TYPE_SET_VOXEL_DESTRUCTIVE" : "PACKET_TYPE_SET_VOXEL", packetData, packetLength, voxelData, atByte); } diff --git a/libraries/voxels/src/VoxelEditPacketSender.cpp b/libraries/voxels/src/VoxelEditPacketSender.cpp index 8b7c82a4ca..d1ba513c4d 100644 --- a/libraries/voxels/src/VoxelEditPacketSender.cpp +++ b/libraries/voxels/src/VoxelEditPacketSender.cpp @@ -32,7 +32,8 @@ VoxelEditPacketSender::VoxelEditPacketSender(PacketSenderNotify* notify) : _shouldSend(true), _maxPendingMessages(DEFAULT_MAX_PENDING_MESSAGES), _releaseQueuedMessagesPending(false), - _voxelServerJurisdictions(NULL) { + _voxelServerJurisdictions(NULL), + _sequenceNumber(0) { } VoxelEditPacketSender::~VoxelEditPacketSender() { @@ -274,7 +275,8 @@ void VoxelEditPacketSender::releaseQueuedPacket(EditPacketBuffer& packetBuffer) void VoxelEditPacketSender::initializePacket(EditPacketBuffer& packetBuffer, PACKET_TYPE type) { packetBuffer._currentSize = populateTypeAndVersion(&packetBuffer._currentBuffer[0], type); unsigned short int* sequenceAt = (unsigned short int*)&packetBuffer._currentBuffer[packetBuffer._currentSize]; - *sequenceAt = 0; + *sequenceAt = _sequenceNumber; + _sequenceNumber++; packetBuffer._currentSize += sizeof(unsigned short int); // set to command + sequence packetBuffer._currentType = type; } diff --git a/libraries/voxels/src/VoxelEditPacketSender.h b/libraries/voxels/src/VoxelEditPacketSender.h index bb54009d1a..eecb7e8677 100644 --- a/libraries/voxels/src/VoxelEditPacketSender.h +++ b/libraries/voxels/src/VoxelEditPacketSender.h @@ -105,5 +105,7 @@ private: std::vector _preServerSingleMessagePackets; // these will go out as is NodeToJurisdictionMap* _voxelServerJurisdictions; + + unsigned short int _sequenceNumber; }; #endif // __shared__VoxelEditPacketSender__ From a9c5c0707f7a925a38ddfbdd3d27752c237fff36 Mon Sep 17 00:00:00 2001 From: ZappoMan Date: Fri, 8 Nov 2013 10:32:46 -0800 Subject: [PATCH 2/3] added sentAt timestamps to voxel edit packets so we can measure transit time --- libraries/shared/src/PacketHeaders.cpp | 5 +++ libraries/shared/src/SharedUtil.cpp | 11 +++++-- .../src/VoxelServerPacketProcessor.cpp | 31 +++++++++++++++---- .../voxels/src/VoxelEditPacketSender.cpp | 11 ++++++- libraries/voxels/src/VoxelTree.cpp | 10 ++++-- 5 files changed, 56 insertions(+), 12 deletions(-) diff --git a/libraries/shared/src/PacketHeaders.cpp b/libraries/shared/src/PacketHeaders.cpp index dc953b6b80..b03daeec05 100644 --- a/libraries/shared/src/PacketHeaders.cpp +++ b/libraries/shared/src/PacketHeaders.cpp @@ -38,6 +38,11 @@ PACKET_VERSION versionForPacketType(PACKET_TYPE type) { case PACKET_TYPE_VOXEL_QUERY: return 1; + + case PACKET_TYPE_SET_VOXEL: + case PACKET_TYPE_SET_VOXEL_DESTRUCTIVE: + case PACKET_TYPE_ERASE_VOXEL: + return 1; default: return 0; diff --git a/libraries/shared/src/SharedUtil.cpp b/libraries/shared/src/SharedUtil.cpp index 0b8af8b48b..99b24979cc 100644 --- a/libraries/shared/src/SharedUtil.cpp +++ b/libraries/shared/src/SharedUtil.cpp @@ -250,10 +250,15 @@ bool createVoxelEditMessage(unsigned char command, short int sequence, int numBytesPacketHeader = populateTypeAndVersion(messageBuffer, command); unsigned short int* sequenceAt = (unsigned short int*) &messageBuffer[numBytesPacketHeader]; - *sequenceAt = sequence; - unsigned char* copyAt = &messageBuffer[numBytesPacketHeader + sizeof(sequence)]; - int actualMessageSize = numBytesPacketHeader + sizeof(sequence); + + // pack in timestamp + uint64_t now = usecTimestampNow(); + uint64_t* timeAt = (uint64_t*)&messageBuffer[numBytesPacketHeader + sizeof(sequence)]; + *timeAt = now; + + unsigned char* copyAt = &messageBuffer[numBytesPacketHeader + sizeof(sequence) + sizeof(now)]; + int actualMessageSize = numBytesPacketHeader + sizeof(sequence) + sizeof(now); for (int i = 0; i < voxelCount && success; i++) { // get the coded voxel diff --git a/libraries/voxel-server-library/src/VoxelServerPacketProcessor.cpp b/libraries/voxel-server-library/src/VoxelServerPacketProcessor.cpp index 5cbc942d16..a86dead1d0 100644 --- a/libraries/voxel-server-library/src/VoxelServerPacketProcessor.cpp +++ b/libraries/voxel-server-library/src/VoxelServerPacketProcessor.cpp @@ -40,19 +40,22 @@ void VoxelServerPacketProcessor::processPacket(sockaddr& senderAddress, unsigned _receivedPacketCount++; - unsigned short int itemNumber = (*((unsigned short int*)(packetData + numBytesPacketHeader))); + 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; if (_myServer->wantShowAnimationDebug()) { - printf("got %s - command from client receivedBytes=%ld itemNumber=%d\n", + printf("got %s - command from client receivedBytes=%ld sequence=%d transitTime=%llu usecs\n", destructive ? "PACKET_TYPE_SET_VOXEL_DESTRUCTIVE" : "PACKET_TYPE_SET_VOXEL", - packetLength, itemNumber); + packetLength, sequence, transitTime); } if (_myServer->wantsDebugVoxelReceiving()) { - printf("got %s - %d command from client receivedBytes=%ld itemNumber=%d\n", + printf("got %s - %d command from client receivedBytes=%ld sequence=%d transitTime=%llu usecs\n", destructive ? "PACKET_TYPE_SET_VOXEL_DESTRUCTIVE" : "PACKET_TYPE_SET_VOXEL", - _receivedPacketCount, packetLength, itemNumber); + _receivedPacketCount, packetLength, sequence, transitTime); } - int atByte = numBytesPacketHeader + sizeof(itemNumber); + int atByte = numBytesPacketHeader + sizeof(sequence) + sizeof(sentAt); unsigned char* voxelData = (unsigned char*)&packetData[atByte]; while (atByte < packetLength) { int maxSize = packetLength - atByte; @@ -113,6 +116,22 @@ void VoxelServerPacketProcessor::processPacket(sockaddr& senderAddress, unsigned } else if (packetData[0] == PACKET_TYPE_ERASE_VOXEL) { + _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; + if (_myServer->wantShowAnimationDebug()) { + printf("got PACKET_TYPE_ERASE_VOXEL - command from client receivedBytes=%ld sequence=%d transitTime=%llu usecs\n", + packetLength, sequence, transitTime); + } + + if (_myServer->wantsDebugVoxelReceiving()) { + printf("got PACKET_TYPE_ERASE_VOXEL - %d command from client receivedBytes=%ld sequence=%d transitTime=%llu usecs\n", + _receivedPacketCount, packetLength, sequence, transitTime); + } + // Send these bits off to the VoxelTree class to process them _myServer->getServerTree().lockForWrite(); _myServer->getServerTree().processRemoveVoxelBitstream((unsigned char*)packetData, packetLength); diff --git a/libraries/voxels/src/VoxelEditPacketSender.cpp b/libraries/voxels/src/VoxelEditPacketSender.cpp index d1ba513c4d..125d80e61a 100644 --- a/libraries/voxels/src/VoxelEditPacketSender.cpp +++ b/libraries/voxels/src/VoxelEditPacketSender.cpp @@ -274,10 +274,19 @@ void VoxelEditPacketSender::releaseQueuedPacket(EditPacketBuffer& packetBuffer) void VoxelEditPacketSender::initializePacket(EditPacketBuffer& packetBuffer, PACKET_TYPE type) { packetBuffer._currentSize = populateTypeAndVersion(&packetBuffer._currentBuffer[0], type); + + // pack in sequence number unsigned short int* sequenceAt = (unsigned short int*)&packetBuffer._currentBuffer[packetBuffer._currentSize]; *sequenceAt = _sequenceNumber; + packetBuffer._currentSize += sizeof(unsigned short int); // nudge past sequence _sequenceNumber++; - packetBuffer._currentSize += sizeof(unsigned short int); // set to command + sequence + + // pack in timestamp + uint64_t now = usecTimestampNow(); + uint64_t* timeAt = (uint64_t*)&packetBuffer._currentBuffer[packetBuffer._currentSize]; + *timeAt = now; + packetBuffer._currentSize += sizeof(uint64_t); // nudge past timestamp + packetBuffer._currentType = type; } diff --git a/libraries/voxels/src/VoxelTree.cpp b/libraries/voxels/src/VoxelTree.cpp index e0e1ac5367..2681742437 100644 --- a/libraries/voxels/src/VoxelTree.cpp +++ b/libraries/voxels/src/VoxelTree.cpp @@ -576,9 +576,15 @@ void VoxelTree::readCodeColorBufferToTreeRecursion(VoxelNode* node, void* extraD } } -void VoxelTree::processRemoveVoxelBitstream(unsigned char * bitstream, int bufferSizeBytes) { +void VoxelTree::processRemoveVoxelBitstream(unsigned char* bitstream, int bufferSizeBytes) { //unsigned short int itemNumber = (*((unsigned short int*)&bitstream[sizeof(PACKET_HEADER)])); - int atByte = sizeof(short int) + numBytesForPacketHeader(bitstream); + + int numBytesPacketHeader = numBytesForPacketHeader(bitstream); + unsigned short int sequence = (*((unsigned short int*)(bitstream + numBytesPacketHeader))); + uint64_t sentAt = (*((uint64_t*)(bitstream + numBytesPacketHeader + sizeof(sequence)))); + + int atByte = numBytesPacketHeader + sizeof(sequence) + sizeof(sentAt); + unsigned char* voxelCode = (unsigned char*)&bitstream[atByte]; while (atByte < bufferSizeBytes) { int maxSize = bufferSizeBytes - atByte; From 2e8cb63abb3e3632bc91f35a3b1d72187015bb80 Mon Sep 17 00:00:00 2001 From: ZappoMan Date: Fri, 8 Nov 2013 10:47:47 -0800 Subject: [PATCH 3/3] add more voxel edit transit time debugging --- .../voxel-server-library/src/VoxelServer.cpp | 28 +++++++++++++++++++ .../src/VoxelServerPacketProcessor.cpp | 19 ++++--------- 2 files changed, 33 insertions(+), 14 deletions(-) diff --git a/libraries/voxel-server-library/src/VoxelServer.cpp b/libraries/voxel-server-library/src/VoxelServer.cpp index 0bafa64a5b..1ce0bcd59d 100644 --- a/libraries/voxel-server-library/src/VoxelServer.cpp +++ b/libraries/voxel-server-library/src/VoxelServer.cpp @@ -608,6 +608,34 @@ void VoxelServer::run() { || packetData[0] == PACKET_TYPE_SET_VOXEL_DESTRUCTIVE || packetData[0] == PACKET_TYPE_ERASE_VOXEL || packetData[0] == PACKET_TYPE_Z_COMMAND)) { + + + const char* messageName; + switch (packetData[0]) { + case PACKET_TYPE_SET_VOXEL: + messageName = "PACKET_TYPE_SET_VOXEL"; + break; + case PACKET_TYPE_SET_VOXEL_DESTRUCTIVE: + messageName = "PACKET_TYPE_SET_VOXEL_DESTRUCTIVE"; + break; + case PACKET_TYPE_ERASE_VOXEL: + messageName = "PACKET_TYPE_ERASE_VOXEL"; + break; + } + int numBytesPacketHeader = numBytesForPacketHeader(packetData); + + if (packetData[0] != PACKET_TYPE_Z_COMMAND) { + 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; + if (wantShowAnimationDebug() || wantsDebugVoxelReceiving()) { + printf("RECEIVE THREAD: got %s - command from client receivedBytes=%ld sequence=%d transitTime=%llu usecs\n", + messageName, + packetLength, sequence, transitTime); + } + } + _voxelServerPacketProcessor->queueReceivedPacket(senderAddress, packetData, packetLength); } else { // let processNodeData handle it. diff --git a/libraries/voxel-server-library/src/VoxelServerPacketProcessor.cpp b/libraries/voxel-server-library/src/VoxelServerPacketProcessor.cpp index a86dead1d0..eb96706f12 100644 --- a/libraries/voxel-server-library/src/VoxelServerPacketProcessor.cpp +++ b/libraries/voxel-server-library/src/VoxelServerPacketProcessor.cpp @@ -44,14 +44,9 @@ void VoxelServerPacketProcessor::processPacket(sockaddr& senderAddress, unsigned uint64_t sentAt = (*((uint64_t*)(packetData + numBytesPacketHeader + sizeof(sequence)))); uint64_t arrivedAt = usecTimestampNow(); uint64_t transitTime = arrivedAt - sentAt; - if (_myServer->wantShowAnimationDebug()) { - printf("got %s - command from client receivedBytes=%ld sequence=%d transitTime=%llu usecs\n", - destructive ? "PACKET_TYPE_SET_VOXEL_DESTRUCTIVE" : "PACKET_TYPE_SET_VOXEL", - packetLength, sequence, transitTime); - } - if (_myServer->wantsDebugVoxelReceiving()) { - printf("got %s - %d command from client receivedBytes=%ld sequence=%d transitTime=%llu usecs\n", + if (_myServer->wantShowAnimationDebug() || _myServer->wantsDebugVoxelReceiving()) { + printf("PROCESSING THREAD: got %s - %d command from client receivedBytes=%ld sequence=%d transitTime=%llu usecs\n", destructive ? "PACKET_TYPE_SET_VOXEL_DESTRUCTIVE" : "PACKET_TYPE_SET_VOXEL", _receivedPacketCount, packetLength, sequence, transitTime); } @@ -122,13 +117,9 @@ void VoxelServerPacketProcessor::processPacket(sockaddr& senderAddress, unsigned uint64_t sentAt = (*((uint64_t*)(packetData + numBytesPacketHeader + sizeof(sequence)))); uint64_t arrivedAt = usecTimestampNow(); uint64_t transitTime = arrivedAt - sentAt; - if (_myServer->wantShowAnimationDebug()) { - printf("got PACKET_TYPE_ERASE_VOXEL - command from client receivedBytes=%ld sequence=%d transitTime=%llu usecs\n", - packetLength, sequence, transitTime); - } - - if (_myServer->wantsDebugVoxelReceiving()) { - printf("got PACKET_TYPE_ERASE_VOXEL - %d command from client receivedBytes=%ld sequence=%d transitTime=%llu usecs\n", + + if (_myServer->wantShowAnimationDebug() || _myServer->wantsDebugVoxelReceiving()) { + printf("PROCESSING THREAD: got PACKET_TYPE_ERASE_VOXEL - %d command from client receivedBytes=%ld sequence=%d transitTime=%llu usecs\n", _receivedPacketCount, packetLength, sequence, transitTime); }