diff --git a/domain-server/src/DomainServer.cpp b/domain-server/src/DomainServer.cpp index dbf2907cc0..b0d3d06994 100644 --- a/domain-server/src/DomainServer.cpp +++ b/domain-server/src/DomainServer.cpp @@ -611,22 +611,14 @@ bool DomainServer::isPacketVerified(const udt::Packet& packet) { // let the NodeList do its checks now (but pass it the sourceNode so it doesn't need to look it up again) return nodeList->isPacketVerifiedWithSource(packet, sourceNode.data()); } else { - static const QString UNKNOWN_REGEX = "Packet of type \\d+ \\([\\sa-zA-Z:]+\\) received from unmatched IP for UUID"; - static QString repeatedMessage - = LogHandler::getInstance().addRepeatedMessageRegex(UNKNOWN_REGEX); - - qDebug() << "Packet of type" << headerType - << "received from unmatched IP for UUID" << uuidStringWithoutCurlyBraces(sourceID); + HIFI_FDEBUG("Packet of type" << headerType + << "received from unmatched IP for UUID" << uuidStringWithoutCurlyBraces(sourceID)); return false; } } else { - static const QString UNKNOWN_REGEX = "Packet of type \\d+ \\([\\sa-zA-Z:]+\\) received from unknown node with UUID"; - static QString repeatedMessage - = LogHandler::getInstance().addRepeatedMessageRegex(UNKNOWN_REGEX); - - qDebug() << "Packet of type" << headerType - << "received from unknown node with UUID" << uuidStringWithoutCurlyBraces(sourceID); + HIFI_FDEBUG("Packet of type" << headerType + << "received from unknown node with UUID" << uuidStringWithoutCurlyBraces(sourceID)); return false; } @@ -1242,31 +1234,16 @@ void DomainServer::processRequestAssignmentPacket(QSharedPointer NOISY_MESSAGE_INTERVAL_MSECS) { - static QString repeatedMessage = LogHandler::getInstance().addOnlyOnceMessageRegex - ("Received a request for assignment type [^ ]+ from [^ ]+"); + static bool printedAssignmentTypeMessage = false; + if (!printedAssignmentTypeMessage && requestAssignment.getType() != Assignment::AgentType) { + printedAssignmentTypeMessage = true; qDebug() << "Received a request for assignment type" << requestAssignment.getType() << "from" << message->getSenderSockAddr(); - noisyMessageTimer.restart(); } SharedAssignmentPointer assignmentToDeploy = deployableAssignmentForRequest(requestAssignment); @@ -1300,13 +1277,11 @@ void DomainServer::processRequestAssignmentPacket(QSharedPointergetUUID(), requestAssignment.getWalletUUID(), requestAssignment.getNodeVersion()); } else { - if (requestAssignment.getType() != Assignment::AgentType - || noisyMessageTimer.elapsed() > NOISY_MESSAGE_INTERVAL_MSECS) { - static QString repeatedMessage = LogHandler::getInstance().addOnlyOnceMessageRegex - ("Unable to fulfill assignment request of type [^ ]+ from [^ ]+"); + static bool printedAssignmentRequestMessage = false; + if (!printedAssignmentRequestMessage && requestAssignment.getType() != Assignment::AgentType) { + printedAssignmentRequestMessage = true; qDebug() << "Unable to fulfill assignment request of type" << requestAssignment.getType() << "from" << message->getSenderSockAddr(); - noisyMessageTimer.restart(); } } } @@ -1552,10 +1527,12 @@ void DomainServer::sendICEServerAddressToMetaverseAPI() { callbackParameters.jsonCallbackReceiver = this; callbackParameters.jsonCallbackMethod = "handleSuccessfulICEServerAddressUpdate"; - static QString repeatedMessage = LogHandler::getInstance().addOnlyOnceMessageRegex - ("Updating ice-server address in High Fidelity Metaverse API to [^ \n]+"); - qDebug() << "Updating ice-server address in High Fidelity Metaverse API to" - << (_iceServerSocket.isNull() ? "" : _iceServerSocket.getAddress().toString()); + static bool printedIceServerMessage = false; + if (!printedIceServerMessage) { + printedIceServerMessage = true; + qDebug() << "Updating ice-server address in High Fidelity Metaverse API to" + << (_iceServerSocket.isNull() ? "" : _iceServerSocket.getAddress().toString()); + } static const QString DOMAIN_ICE_ADDRESS_UPDATE = "/api/v1/domains/%1/ice_server_address"; diff --git a/interface/src/Application.cpp b/interface/src/Application.cpp index d47f86fd54..28fa760231 100644 --- a/interface/src/Application.cpp +++ b/interface/src/Application.cpp @@ -6019,9 +6019,7 @@ bool Application::nearbyEntitiesAreReadyForPhysics() { bool result = true; foreach (EntityItemPointer entity, entities) { if (entity->shouldBePhysical() && !entity->isReadyToComputeShape()) { - static QString repeatedMessage = - LogHandler::getInstance().addRepeatedMessageRegex("Physics disabled until entity loads: .*"); - qCDebug(interfaceapp) << "Physics disabled until entity loads: " << entity->getID() << entity->getName(); + HIFI_FCDEBUG(interfaceapp(), "Physics disabled until entity loads: " << entity->getID() << entity->getName()); // don't break here because we want all the relevant entities to start their downloads result = false; } diff --git a/interface/src/InterfaceDynamicFactory.cpp b/interface/src/InterfaceDynamicFactory.cpp index e51f63d01b..b7861b56c8 100644 --- a/interface/src/InterfaceDynamicFactory.cpp +++ b/interface/src/InterfaceDynamicFactory.cpp @@ -87,10 +87,8 @@ EntityDynamicPointer InterfaceDynamicFactory::factoryBA(EntityItemPointer ownerE if (dynamic) { dynamic->deserialize(data); if (dynamic->lifetimeIsOver()) { - static QString repeatedMessage = - LogHandler::getInstance().addRepeatedMessageRegex(".*factoryBA lifetimeIsOver during dynamic creation.*"); - qDebug() << "InterfaceDynamicFactory::factoryBA lifetimeIsOver during dynamic creation --" - << dynamic->getExpires() << "<" << usecTimestampNow(); + HIFI_FDEBUG("InterfaceDynamicFactory::factoryBA lifetimeIsOver during dynamic creation --" + << dynamic->getExpires() << "<" << usecTimestampNow()); return nullptr; } } diff --git a/libraries/audio/src/AudioRingBuffer.cpp b/libraries/audio/src/AudioRingBuffer.cpp index 59b3e874d7..518fdd3c17 100644 --- a/libraries/audio/src/AudioRingBuffer.cpp +++ b/libraries/audio/src/AudioRingBuffer.cpp @@ -39,9 +39,6 @@ AudioRingBufferTemplate::AudioRingBufferTemplate(int numFrameSamples, int num _nextOutput = _buffer; _endOfLastWrite = _buffer; } - - static QString repeatedOverflowMessage = LogHandler::getInstance().addRepeatedMessageRegex(RING_BUFFER_OVERFLOW_DEBUG); - static QString repeatedDroppedMessage = LogHandler::getInstance().addRepeatedMessageRegex(DROPPED_SILENT_DEBUG); } template @@ -154,6 +151,11 @@ int AudioRingBufferTemplate::appendData(char *data, int maxSize) { return numReadSamples * SampleSize; } +namespace { + int repeatedOverflowMessageID = 0; + std::once_flag messageIDFlag; +} + template int AudioRingBufferTemplate::writeData(const char* data, int maxSize) { // only copy up to the number of samples we have capacity for @@ -167,7 +169,9 @@ int AudioRingBufferTemplate::writeData(const char* data, int maxSize) { _nextOutput = shiftedPositionAccomodatingWrap(_nextOutput, samplesToDelete); _overflowCount++; - qCDebug(audio) << qPrintable(RING_BUFFER_OVERFLOW_DEBUG); + std::call_once(messageIDFlag, [](int* id) { *id = LogHandler::getInstance().newRepeatedMessageID(); }, + &repeatedOverflowMessageID); + HIFI_FCDEBUG_ID(audio(), repeatedOverflowMessageID, RING_BUFFER_OVERFLOW_DEBUG); } if (_endOfLastWrite + numWriteSamples > _buffer + _bufferLength) { @@ -224,7 +228,7 @@ int AudioRingBufferTemplate::addSilentSamples(int silentSamples) { if (numWriteSamples > samplesRoomFor) { numWriteSamples = samplesRoomFor; - qCDebug(audio) << qPrintable(DROPPED_SILENT_DEBUG); + HIFI_FCDEBUG(audio(), DROPPED_SILENT_DEBUG); } if (_endOfLastWrite + numWriteSamples > _buffer + _bufferLength) { @@ -275,7 +279,10 @@ int AudioRingBufferTemplate::writeSamples(ConstIterator source, int maxSample int samplesToDelete = samplesToCopy - samplesRoomFor; _nextOutput = shiftedPositionAccomodatingWrap(_nextOutput, samplesToDelete); _overflowCount++; - qCDebug(audio) << qPrintable(RING_BUFFER_OVERFLOW_DEBUG); + + std::call_once(messageIDFlag, [](int* id) { *id = LogHandler::getInstance().newRepeatedMessageID(); }, + &repeatedOverflowMessageID); + HIFI_FCDEBUG_ID(audio(), repeatedOverflowMessageID, RING_BUFFER_OVERFLOW_DEBUG); } Sample* bufferLast = _buffer + _bufferLength - 1; @@ -297,7 +304,10 @@ int AudioRingBufferTemplate::writeSamplesWithFade(ConstIterator source, int m int samplesToDelete = samplesToCopy - samplesRoomFor; _nextOutput = shiftedPositionAccomodatingWrap(_nextOutput, samplesToDelete); _overflowCount++; - qCDebug(audio) << qPrintable(RING_BUFFER_OVERFLOW_DEBUG); + + std::call_once(messageIDFlag, [](int* id) { *id = LogHandler::getInstance().newRepeatedMessageID(); }, + &repeatedOverflowMessageID); + HIFI_FCDEBUG_ID(audio(), repeatedOverflowMessageID, RING_BUFFER_OVERFLOW_DEBUG); } Sample* bufferLast = _buffer + _bufferLength - 1; diff --git a/libraries/audio/src/PositionalAudioStream.cpp b/libraries/audio/src/PositionalAudioStream.cpp index 49b34a894e..a6bbc71a65 100644 --- a/libraries/audio/src/PositionalAudioStream.cpp +++ b/libraries/audio/src/PositionalAudioStream.cpp @@ -16,6 +16,7 @@ #include #include +#include #include #include @@ -80,10 +81,7 @@ int PositionalAudioStream::parsePositionalData(const QByteArray& positionalByteA // if the client sends us a bad position, flag it so that we don't consider this stream for mixing if (glm::isnan(_position.x) || glm::isnan(_position.y) || glm::isnan(_position.z)) { - static const QString INVALID_POSITION_REGEX = "PositionalAudioStream unpacked invalid position for node"; - static QString repeatedMessage = LogHandler::getInstance().addRepeatedMessageRegex(INVALID_POSITION_REGEX); - - qDebug() << "PositionalAudioStream unpacked invalid position for node" << uuidStringWithoutCurlyBraces(getNodeID()); + HIFI_FDEBUG("PositionalAudioStream unpacked invalid position for node" << uuidStringWithoutCurlyBraces(getNodeID()) ); _hasValidPosition = false; } else { diff --git a/libraries/entities/src/EntityItem.cpp b/libraries/entities/src/EntityItem.cpp index 8a87a98a10..2e3a6c9552 100644 --- a/libraries/entities/src/EntityItem.cpp +++ b/libraries/entities/src/EntityItem.cpp @@ -2193,10 +2193,8 @@ void EntityItem::deserializeActionsInternal() { entity->addActionInternal(simulation, action); updated << actionID; } else { - static QString repeatedMessage = - LogHandler::getInstance().addRepeatedMessageRegex(".*action creation failed for.*"); - qCDebug(entities) << "EntityItem::deserializeActionsInternal -- action creation failed for" - << getID() << _name; // getName(); + HIFI_FCDEBUG(entities(), "EntityItem::deserializeActionsInternal -- action creation failed for" + << getID() << _name); // getName(); removeActionInternal(actionID, nullptr); } } diff --git a/libraries/entities/src/EntityTree.cpp b/libraries/entities/src/EntityTree.cpp index e86895c6cf..4d0211a1b7 100644 --- a/libraries/entities/src/EntityTree.cpp +++ b/libraries/entities/src/EntityTree.cpp @@ -1650,11 +1650,9 @@ int EntityTree::processEditPacketData(ReceivedMessage& message, const unsigned c _recentlyDeletedEntityItemIDs.insert(usecTimestampNow(), entityItemID); } } else { - static QString repeatedMessage = - LogHandler::getInstance().addRepeatedMessageRegex("^Edit failed.*"); - qCDebug(entities) << "Edit failed. [" << message.getType() <<"] " << + HIFI_FCDEBUG(entities(), "Edit failed. [" << message.getType() <<"] " << "entity id:" << entityItemID << - "existingEntity pointer:" << existingEntity.get(); + "existingEntity pointer:" << existingEntity.get()); } } diff --git a/libraries/fbx/src/FBXReader_Mesh.cpp b/libraries/fbx/src/FBXReader_Mesh.cpp index b0e2faa600..e8365e38b7 100644 --- a/libraries/fbx/src/FBXReader_Mesh.cpp +++ b/libraries/fbx/src/FBXReader_Mesh.cpp @@ -566,20 +566,20 @@ glm::vec3 FBXReader::normalizeDirForPacking(const glm::vec3& dir) { } void FBXReader::buildModelMesh(FBXMesh& extractedMesh, const QString& url) { - static QString repeatedMessage = LogHandler::getInstance().addRepeatedMessageRegex("buildModelMesh failed -- .*"); - unsigned int totalSourceIndices = 0; foreach(const FBXMeshPart& part, extractedMesh.parts) { totalSourceIndices += (part.quadTrianglesIndices.size() + part.triangleIndices.size()); } + static int repeatMessageID = LogHandler::getInstance().newRepeatedMessageID(); + if (!totalSourceIndices) { - qCDebug(modelformat) << "buildModelMesh failed -- no indices, url = " << url; + HIFI_FCDEBUG_ID(modelformat(), repeatMessageID, "buildModelMesh failed -- no indices, url = " << url); return; } if (extractedMesh.vertices.size() == 0) { - qCDebug(modelformat) << "buildModelMesh failed -- no vertices, url = " << url; + HIFI_FCDEBUG_ID(modelformat(), repeatMessageID, "buildModelMesh failed -- no vertices, url = " << url); return; } diff --git a/libraries/networking/src/LimitedNodeList.cpp b/libraries/networking/src/LimitedNodeList.cpp index 0803e380f2..fa934b5539 100644 --- a/libraries/networking/src/LimitedNodeList.cpp +++ b/libraries/networking/src/LimitedNodeList.cpp @@ -277,13 +277,8 @@ bool LimitedNodeList::packetSourceAndHashMatchAndTrackBandwidth(const udt::Packe emit dataReceived(sendingNodeType, packet.getPayloadSize()); return true; } else { - static const QString UNSOLICITED_REPLICATED_REGEX = - "Replicated packet of type \\d+ \\([\\sa-zA-Z:]+\\) received from unknown upstream"; - static QString repeatedMessage - = LogHandler::getInstance().addRepeatedMessageRegex(UNSOLICITED_REPLICATED_REGEX); - - qCDebug(networking) << "Replicated packet of type" << headerType - << "received from unknown upstream" << packet.getSenderSockAddr(); + HIFI_FCDEBUG(networking(), "Replicated packet of type" << headerType + << "received from unknown upstream" << packet.getSenderSockAddr()); return false; } @@ -345,12 +340,8 @@ bool LimitedNodeList::packetSourceAndHashMatchAndTrackBandwidth(const udt::Packe return true; } else { - static const QString UNKNOWN_REGEX = "Packet of type \\d+ \\([\\sa-zA-Z:]+\\) received from unknown node with UUID"; - static QString repeatedMessage - = LogHandler::getInstance().addRepeatedMessageRegex(UNKNOWN_REGEX); - - qCDebug(networking) << "Packet of type" << headerType - << "received from unknown node with UUID" << uuidStringWithoutCurlyBraces(sourceID); + HIFI_FCDEBUG(networking(), + "Packet of type" << headerType << "received from unknown node with UUID" << uuidStringWithoutCurlyBraces(sourceID)); } } diff --git a/libraries/networking/src/SequenceNumberStats.cpp b/libraries/networking/src/SequenceNumberStats.cpp index 6d7b271606..7f1ee39554 100644 --- a/libraries/networking/src/SequenceNumberStats.cpp +++ b/libraries/networking/src/SequenceNumberStats.cpp @@ -89,10 +89,7 @@ SequenceNumberStats::ArrivalInfo SequenceNumberStats::sequenceNumberReceived(qui } else if (absGap > MAX_REASONABLE_SEQUENCE_GAP) { arrivalInfo._status = Unreasonable; - static const QString UNREASONABLE_SEQUENCE_REGEX { "unreasonable sequence number: \\d+ previous: \\d+" }; - static QString repeatedMessage = LogHandler::getInstance().addRepeatedMessageRegex(UNREASONABLE_SEQUENCE_REGEX); - - qCDebug(networking) << "unreasonable sequence number:" << incoming << "previous:" << _lastReceivedSequence; + HIFI_FCDEBUG(networking(), "unreasonable sequence number:" << incoming << "previous:" << _lastReceivedSequence); _stats._unreasonable++; @@ -154,10 +151,7 @@ SequenceNumberStats::ArrivalInfo SequenceNumberStats::sequenceNumberReceived(qui arrivalInfo._status = Unreasonable; - static const QString UNREASONABLE_SEQUENCE_REGEX { "unreasonable sequence number: \\d+ \\(possible duplicate\\)" }; - static QString repeatedMessage = LogHandler::getInstance().addRepeatedMessageRegex(UNREASONABLE_SEQUENCE_REGEX); - - qCDebug(networking) << "unreasonable sequence number:" << incoming << "(possible duplicate)"; + HIFI_FCDEBUG(networking(), "unreasonable sequence number:" << incoming << "(possible duplicate)"); _stats._unreasonable++; diff --git a/libraries/networking/src/udt/Packet.cpp b/libraries/networking/src/udt/Packet.cpp index f07ea63994..0456fa1223 100644 --- a/libraries/networking/src/udt/Packet.cpp +++ b/libraries/networking/src/udt/Packet.cpp @@ -107,8 +107,7 @@ Packet::Packet(std::unique_ptr data, qint64 size, const HifiSockAddr& se QString::number(getMessagePartNumber())); } - static QString repeatedMessage = LogHandler::getInstance().addRepeatedMessageRegex("^Unobfuscating packet .*"); - qCDebug(networking) << qPrintable(debugString); + HIFI_FCDEBUG(networking(), debugString); #endif obfuscate(NoObfuscation); // Undo obfuscation diff --git a/libraries/networking/src/udt/SendQueue.cpp b/libraries/networking/src/udt/SendQueue.cpp index b62624aab9..0df54d539d 100644 --- a/libraries/networking/src/udt/SendQueue.cpp +++ b/libraries/networking/src/udt/SendQueue.cpp @@ -479,8 +479,7 @@ bool SendQueue::maybeResendPacket() { debugString = debugString.arg(QString::number(resendPacket.getMessageNumber()), QString::number(resendPacket.getMessagePartNumber())); } - static QString repeatedMessage = LogHandler::getInstance().addRepeatedMessageRegex("^Obfuscating packet .*"); - qCritical() << qPrintable(debugString); + HIFI_FDEBUG(debugString); #endif // Create copy of the packet diff --git a/libraries/networking/src/udt/Socket.cpp b/libraries/networking/src/udt/Socket.cpp index 4189cb613c..4d4303698b 100644 --- a/libraries/networking/src/udt/Socket.cpp +++ b/libraries/networking/src/udt/Socket.cpp @@ -229,11 +229,7 @@ qint64 Socket::writeDatagram(const QByteArray& datagram, const HifiSockAddr& soc if (bytesWritten < 0) { // when saturating a link this isn't an uncommon message - suppress it so it doesn't bomb the debug - static const QString WRITE_ERROR_REGEX = "Socket::writeDatagram QAbstractSocket::NetworkError - Unable to send a message"; - static QString repeatedMessage - = LogHandler::getInstance().addRepeatedMessageRegex(WRITE_ERROR_REGEX); - - qCDebug(networking) << "Socket::writeDatagram" << _udpSocket.error() << "-" << qPrintable(_udpSocket.errorString()); + HIFI_FCDEBUG(networking(), "Socket::writeDatagram" << _udpSocket.error() << "-" << qPrintable(_udpSocket.errorString()) ); } return bytesWritten; @@ -517,11 +513,7 @@ std::vector Socket::getConnectionSockAddrs() { } void Socket::handleSocketError(QAbstractSocket::SocketError socketError) { - static const QString SOCKET_REGEX = "udt::Socket error - "; - static QString repeatedMessage - = LogHandler::getInstance().addRepeatedMessageRegex(SOCKET_REGEX); - - qCDebug(networking) << "udt::Socket error - " << socketError << _udpSocket.errorString(); + HIFI_FCDEBUG(networking(), "udt::Socket error - " << socketError << _udpSocket.errorString()); } void Socket::handleStateChanged(QAbstractSocket::SocketState socketState) { diff --git a/libraries/octree/src/Octree.cpp b/libraries/octree/src/Octree.cpp index dafdfd5bf4..e34ba34c8f 100644 --- a/libraries/octree/src/Octree.cpp +++ b/libraries/octree/src/Octree.cpp @@ -121,11 +121,7 @@ void Octree::recurseTreeWithPostOperation(const RecurseOctreeOperation& operatio void Octree::recurseElementWithOperation(const OctreeElementPointer& element, const RecurseOctreeOperation& operation, void* extraData, int recursionCount) { if (recursionCount > DANGEROUSLY_DEEP_RECURSION) { - static QString repeatedMessage - = LogHandler::getInstance().addRepeatedMessageRegex( - "Octree::recurseElementWithOperation\\(\\) reached DANGEROUSLY_DEEP_RECURSION, bailing!"); - - qCDebug(octree) << "Octree::recurseElementWithOperation() reached DANGEROUSLY_DEEP_RECURSION, bailing!"; + HIFI_FCDEBUG(octree(), "Octree::recurseElementWithOperation() reached DANGEROUSLY_DEEP_RECURSION, bailing!"); return; } @@ -143,11 +139,7 @@ void Octree::recurseElementWithOperation(const OctreeElementPointer& element, co void Octree::recurseElementWithPostOperation(const OctreeElementPointer& element, const RecurseOctreeOperation& operation, void* extraData, int recursionCount) { if (recursionCount > DANGEROUSLY_DEEP_RECURSION) { - static QString repeatedMessage - = LogHandler::getInstance().addRepeatedMessageRegex( - "Octree::recurseElementWithPostOperation\\(\\) reached DANGEROUSLY_DEEP_RECURSION, bailing!"); - - qCDebug(octree) << "Octree::recurseElementWithPostOperation() reached DANGEROUSLY_DEEP_RECURSION, bailing!"; + HIFI_FCDEBUG(octree(), "Octree::recurseElementWithPostOperation() reached DANGEROUSLY_DEEP_RECURSION, bailing!"); return; } @@ -173,11 +165,7 @@ void Octree::recurseElementWithOperationDistanceSorted(const OctreeElementPointe const glm::vec3& point, void* extraData, int recursionCount) { if (recursionCount > DANGEROUSLY_DEEP_RECURSION) { - static QString repeatedMessage - = LogHandler::getInstance().addRepeatedMessageRegex( - "Octree::recurseElementWithOperationDistanceSorted\\(\\) reached DANGEROUSLY_DEEP_RECURSION, bailing!"); - - qCDebug(octree) << "Octree::recurseElementWithOperationDistanceSorted() reached DANGEROUSLY_DEEP_RECURSION, bailing!"; + HIFI_FCDEBUG(octree(), "Octree::recurseElementWithOperationDistanceSorted() reached DANGEROUSLY_DEEP_RECURSION, bailing!"); return; } @@ -215,11 +203,7 @@ void Octree::recurseTreeWithOperator(RecurseOctreeOperator* operatorObject) { bool Octree::recurseElementWithOperator(const OctreeElementPointer& element, RecurseOctreeOperator* operatorObject, int recursionCount) { if (recursionCount > DANGEROUSLY_DEEP_RECURSION) { - static QString repeatedMessage - = LogHandler::getInstance().addRepeatedMessageRegex( - "Octree::recurseElementWithOperator\\(\\) reached DANGEROUSLY_DEEP_RECURSION, bailing!"); - - qCDebug(octree) << "Octree::recurseElementWithOperator() reached DANGEROUSLY_DEEP_RECURSION, bailing!"; + HIFI_FCDEBUG(octree(), "Octree::recurseElementWithOperator() reached DANGEROUSLY_DEEP_RECURSION, bailing!"); return false; } @@ -285,11 +269,7 @@ OctreeElementPointer Octree::createMissingElement(const OctreeElementPointer& la const unsigned char* codeToReach, int recursionCount) { if (recursionCount > DANGEROUSLY_DEEP_RECURSION) { - static QString repeatedMessage - = LogHandler::getInstance().addRepeatedMessageRegex( - "Octree::createMissingElement\\(\\) reached DANGEROUSLY_DEEP_RECURSION, bailing!"); - - qCDebug(octree) << "Octree::createMissingElement() reached DANGEROUSLY_DEEP_RECURSION, bailing!"; + HIFI_FCDEBUG(octree(), "Octree::createMissingElement() reached DANGEROUSLY_DEEP_RECURSION, bailing!"); return lastParentElement; } int indexOfNewChild = branchIndexWithDescendant(lastParentElement->getOctalCode(), codeToReach); @@ -446,16 +426,9 @@ void Octree::readBitstreamToTree(const unsigned char * bitstream, uint64_t buffe (unsigned char *)bitstreamAt, NULL); int numberOfThreeBitSectionsInStream = numberOfThreeBitSectionsInCode(bitstreamAt, bufferSizeBytes); if (numberOfThreeBitSectionsInStream > UNREASONABLY_DEEP_RECURSION) { - static QString repeatedMessage - = LogHandler::getInstance().addRepeatedMessageRegex( - "UNEXPECTED: parsing of the octal code would make UNREASONABLY_DEEP_RECURSION... " - "numberOfThreeBitSectionsInStream: \\d+ This buffer is corrupt. Returning." - ); - - - qCDebug(octree) << "UNEXPECTED: parsing of the octal code would make UNREASONABLY_DEEP_RECURSION... " + HIFI_FCDEBUG(octree(), "UNEXPECTED: parsing of the octal code would make UNREASONABLY_DEEP_RECURSION... " "numberOfThreeBitSectionsInStream:" << numberOfThreeBitSectionsInStream << - "This buffer is corrupt. Returning."; + "This buffer is corrupt. Returning."); return; } diff --git a/libraries/octree/src/OctreeElement.cpp b/libraries/octree/src/OctreeElement.cpp index 989951b661..ef45e8b7ba 100644 --- a/libraries/octree/src/OctreeElement.cpp +++ b/libraries/octree/src/OctreeElement.cpp @@ -401,11 +401,7 @@ OctreeElementPointer OctreeElement::addChildAtIndex(int childIndex) { bool OctreeElement::safeDeepDeleteChildAtIndex(int childIndex, int recursionCount) { bool deleteApproved = false; if (recursionCount > DANGEROUSLY_DEEP_RECURSION) { - static QString repeatedMessage - = LogHandler::getInstance().addRepeatedMessageRegex( - "OctreeElement::safeDeepDeleteChildAtIndex\\(\\) reached DANGEROUSLY_DEEP_RECURSION, bailing!"); - - qCDebug(octree) << "OctreeElement::safeDeepDeleteChildAtIndex() reached DANGEROUSLY_DEEP_RECURSION, bailing!"; + HIFI_FCDEBUG(octree(), "OctreeElement::safeDeepDeleteChildAtIndex() reached DANGEROUSLY_DEEP_RECURSION, bailing!"); return deleteApproved; } OctreeElementPointer childToDelete = getChildAtIndex(childIndex); diff --git a/libraries/octree/src/OctreeSceneStats.cpp b/libraries/octree/src/OctreeSceneStats.cpp index 054603440d..117f3e0385 100644 --- a/libraries/octree/src/OctreeSceneStats.cpp +++ b/libraries/octree/src/OctreeSceneStats.cpp @@ -636,12 +636,8 @@ void OctreeSceneStats::trackIncomingOctreePacket(ReceivedMessage& message, bool const qint64 MAX_RESONABLE_FLIGHT_TIME = 200 * USECS_PER_SECOND; // 200 seconds is more than enough time for a packet to arrive const qint64 MIN_RESONABLE_FLIGHT_TIME = -1 * (qint64)USECS_PER_SECOND; // more than 1 second of "reverse flight time" would be unreasonable if (flightTime > MAX_RESONABLE_FLIGHT_TIME || flightTime < MIN_RESONABLE_FLIGHT_TIME) { - static QString repeatedMessage - = LogHandler::getInstance().addRepeatedMessageRegex( - "ignoring unreasonable packet... flightTime: -?\\d+ nodeClockSkewUsec: -?\\d+ usecs"); - - qCDebug(octree) << "ignoring unreasonable packet... flightTime:" << flightTime - << "nodeClockSkewUsec:" << nodeClockSkewUsec << "usecs";; + HIFI_FCDEBUG(octree(), "ignoring unreasonable packet... flightTime:" << flightTime + << "nodeClockSkewUsec:" << nodeClockSkewUsec << "usecs"); return; // ignore any packets that are unreasonable } diff --git a/libraries/physics/src/ObjectConstraintBallSocket.cpp b/libraries/physics/src/ObjectConstraintBallSocket.cpp index 70613d46ae..4736f2c9e2 100644 --- a/libraries/physics/src/ObjectConstraintBallSocket.cpp +++ b/libraries/physics/src/ObjectConstraintBallSocket.cpp @@ -85,12 +85,11 @@ btTypedConstraint* ObjectConstraintBallSocket::getConstraint() { return constraint; } - static QString repeatedBallSocketNoRigidBody = LogHandler::getInstance().addRepeatedMessageRegex( - "ObjectConstraintBallSocket::getConstraint -- no rigidBody.*"); + static int repeatMessageID = LogHandler::getInstance().newRepeatedMessageID(); btRigidBody* rigidBodyA = getRigidBody(); if (!rigidBodyA) { - qCDebug(physics) << "ObjectConstraintBallSocket::getConstraint -- no rigidBodyA"; + HIFI_FCDEBUG_ID(physics(), repeatMessageID, "ObjectConstraintBallSocket::getConstraint -- no rigidBodyA"); return nullptr; } @@ -99,7 +98,7 @@ btTypedConstraint* ObjectConstraintBallSocket::getConstraint() { btRigidBody* rigidBodyB = getOtherRigidBody(otherEntityID); if (!rigidBodyB) { - qCDebug(physics) << "ObjectConstraintBallSocket::getConstraint -- no rigidBodyB"; + HIFI_FCDEBUG_ID(physics(), repeatMessageID, "ObjectConstraintBallSocket::getConstraint -- no rigidBodyB"); return nullptr; } diff --git a/libraries/physics/src/ObjectConstraintConeTwist.cpp b/libraries/physics/src/ObjectConstraintConeTwist.cpp index 86f1f21c63..47228c1c16 100644 --- a/libraries/physics/src/ObjectConstraintConeTwist.cpp +++ b/libraries/physics/src/ObjectConstraintConeTwist.cpp @@ -96,12 +96,11 @@ btTypedConstraint* ObjectConstraintConeTwist::getConstraint() { return constraint; } - static QString repeatedConeTwistNoRigidBody = LogHandler::getInstance().addRepeatedMessageRegex( - "ObjectConstraintConeTwist::getConstraint -- no rigidBody.*"); + static int repeatMessageID = LogHandler::getInstance().newRepeatedMessageID(); btRigidBody* rigidBodyA = getRigidBody(); if (!rigidBodyA) { - qCDebug(physics) << "ObjectConstraintConeTwist::getConstraint -- no rigidBodyA"; + HIFI_FCDEBUG_ID(physics(), repeatMessageID, "ObjectConstraintConeTwist::getConstraint -- no rigidBodyA"); return nullptr; } @@ -130,7 +129,7 @@ btTypedConstraint* ObjectConstraintConeTwist::getConstraint() { btRigidBody* rigidBodyB = getOtherRigidBody(otherEntityID); if (!rigidBodyB) { - qCDebug(physics) << "ObjectConstraintConeTwist::getConstraint -- no rigidBodyB"; + HIFI_FCDEBUG_ID(physics(), repeatMessageID, "ObjectConstraintConeTwist::getConstraint -- no rigidBodyB"); return nullptr; } diff --git a/libraries/physics/src/ObjectConstraintHinge.cpp b/libraries/physics/src/ObjectConstraintHinge.cpp index 99ddd45abd..4793741391 100644 --- a/libraries/physics/src/ObjectConstraintHinge.cpp +++ b/libraries/physics/src/ObjectConstraintHinge.cpp @@ -94,13 +94,12 @@ btTypedConstraint* ObjectConstraintHinge::getConstraint() { if (constraint) { return constraint; } - - static QString repeatedHingeNoRigidBody = LogHandler::getInstance().addRepeatedMessageRegex( - "ObjectConstraintHinge::getConstraint -- no rigidBody.*"); + + static int repeatMessageID = LogHandler::getInstance().newRepeatedMessageID(); btRigidBody* rigidBodyA = getRigidBody(); if (!rigidBodyA) { - qCDebug(physics) << "ObjectConstraintHinge::getConstraint -- no rigidBodyA"; + HIFI_FCDEBUG_ID(physics(), repeatMessageID, "ObjectConstraintHinge::getConstraint -- no rigidBodyA"); return nullptr; } @@ -115,7 +114,7 @@ btTypedConstraint* ObjectConstraintHinge::getConstraint() { // This hinge is between two entities... find the other rigid body. btRigidBody* rigidBodyB = getOtherRigidBody(otherEntityID); if (!rigidBodyB) { - qCDebug(physics) << "ObjectConstraintHinge::getConstraint -- no rigidBodyB"; + HIFI_FCDEBUG_ID(physics(), repeatMessageID, "ObjectConstraintHinge::getConstraint -- no rigidBodyB"); return nullptr; } diff --git a/libraries/physics/src/ObjectConstraintSlider.cpp b/libraries/physics/src/ObjectConstraintSlider.cpp index c236afc10d..da5bba7f4d 100644 --- a/libraries/physics/src/ObjectConstraintSlider.cpp +++ b/libraries/physics/src/ObjectConstraintSlider.cpp @@ -87,12 +87,11 @@ btTypedConstraint* ObjectConstraintSlider::getConstraint() { return constraint; } - static QString repeatedSliderNoRigidBody = LogHandler::getInstance().addRepeatedMessageRegex( - "ObjectConstraintSlider::getConstraint -- no rigidBody.*"); + static int repeatMessageID = LogHandler::getInstance().newRepeatedMessageID(); btRigidBody* rigidBodyA = getRigidBody(); if (!rigidBodyA) { - qCDebug(physics) << "ObjectConstraintSlider::getConstraint -- no rigidBodyA"; + HIFI_FCDEBUG_ID(physics(), repeatMessageID, "ObjectConstraintSlider::getConstraint -- no rigidBodyA"); return nullptr; } @@ -121,7 +120,7 @@ btTypedConstraint* ObjectConstraintSlider::getConstraint() { btRigidBody* rigidBodyB = getOtherRigidBody(otherEntityID); if (!rigidBodyB) { - qCDebug(physics) << "ObjectConstraintSlider::getConstraint -- no rigidBodyB"; + HIFI_FCDEBUG_ID(physics(), repeatMessageID, "ObjectConstraintSlider::getConstraint -- no rigidBodyB"); return nullptr; } diff --git a/libraries/render-utils/src/BackgroundStage.cpp b/libraries/render-utils/src/BackgroundStage.cpp index 886795ec79..d9115c7943 100644 --- a/libraries/render-utils/src/BackgroundStage.cpp +++ b/libraries/render-utils/src/BackgroundStage.cpp @@ -126,9 +126,6 @@ void DrawBackgroundStage::run(const render::RenderContextPointer& renderContext, if (defaultSkyboxAmbientTexture) { sceneKeyLight->setAmbientSphere(defaultSkyboxAmbientTexture->getIrradiance()); sceneKeyLight->setAmbientMap(defaultSkyboxAmbientTexture); - } else { - static QString repeatedMessage = LogHandler::getInstance().addRepeatedMessageRegex( - "Failed to get a valid Default Skybox Ambient Texture ? probably because it couldn't be find during initialization step"); } // fall through: render defaults skybox } else { diff --git a/libraries/render/src/render/DrawTask.cpp b/libraries/render/src/render/DrawTask.cpp index bdff97c1c1..8aabffea46 100755 --- a/libraries/render/src/render/DrawTask.cpp +++ b/libraries/render/src/render/DrawTask.cpp @@ -41,6 +41,11 @@ void render::renderItems(const RenderContextPointer& renderContext, const ItemBo } } +namespace { + int repeatedInvalidKeyMessageID = 0; + std::once_flag messageIDFlag; +} + void renderShape(RenderArgs* args, const ShapePlumberPointer& shapeContext, const Item& item, const ShapeKey& globalKey) { assert(item.getKey().isShape()); auto key = item.getShapeKey() | globalKey; @@ -55,9 +60,9 @@ void renderShape(RenderArgs* args, const ShapePlumberPointer& shapeContext, cons } else if (key.hasOwnPipeline()) { item.render(args); } else { - qCDebug(renderlogging) << "Item could not be rendered with invalid key" << key; - static QString repeatedCouldNotBeRendered = LogHandler::getInstance().addRepeatedMessageRegex( - "Item could not be rendered with invalid key.*"); + std::call_once(messageIDFlag, [](int* id) { *id = LogHandler::getInstance().newRepeatedMessageID(); }, + &repeatedInvalidKeyMessageID); + HIFI_FCDEBUG_ID(renderlogging(), repeatedInvalidKeyMessageID, "Item could not be rendered with invalid key" << key); } args->_itemShapeKey = 0; } @@ -108,9 +113,9 @@ void render::renderStateSortShapes(const RenderContextPointer& renderContext, } else if (key.hasOwnPipeline()) { ownPipelineBucket.push_back( std::make_tuple(item, key) ); } else { - static QString repeatedCouldNotBeRendered = LogHandler::getInstance().addRepeatedMessageRegex( - "Item could not be rendered with invalid key.*"); - qCDebug(renderlogging) << "Item could not be rendered with invalid key" << key; + std::call_once(messageIDFlag, [](int* id) { *id = LogHandler::getInstance().newRepeatedMessageID(); }, + &repeatedInvalidKeyMessageID); + HIFI_FCDEBUG_ID(renderlogging(), repeatedInvalidKeyMessageID, "Item could not be rendered with invalid key" << key); } } } diff --git a/libraries/shared/src/LogHandler.cpp b/libraries/shared/src/LogHandler.cpp index 49927a325b..45cf01510d 100644 --- a/libraries/shared/src/LogHandler.cpp +++ b/libraries/shared/src/LogHandler.cpp @@ -25,7 +25,7 @@ #include #include -QMutex LogHandler::_mutex; +QMutex LogHandler::_mutex(QMutex::Recursive); LogHandler& LogHandler::getInstance() { static LogHandler staticInstance; @@ -36,6 +36,9 @@ LogHandler::LogHandler() { // when the log handler is first setup we should print our timezone QString timezoneString = "Time zone: " + QDateTime::currentDateTime().toString("t"); printMessage(LogMsgType::LogInfo, QMessageLogContext(), timezoneString); + + // make sure we setup the repeated message flusher, but do it on the LogHandler thread + QMetaObject::invokeMethod(this, "setupRepeatedMessageFlusher"); } LogHandler::~LogHandler() { @@ -91,58 +94,25 @@ void LogHandler::setShouldDisplayMilliseconds(bool shouldDisplayMilliseconds) { void LogHandler::flushRepeatedMessages() { QMutexLocker lock(&_mutex); - for(auto& message: _repeatedMessages) { - if (message.messageCount > 1) { - QString repeatMessage = QString("%1 repeated log entries matching \"%2\" - Last entry: \"%3\"") - .arg(message.messageCount - 1) - .arg(message.regexp.pattern()) - .arg(message.lastMessage); - - QMessageLogContext emptyContext; - lock.unlock(); - printMessage(LogSuppressed, emptyContext, repeatMessage); - lock.relock(); + // New repeat-suppress scheme: + for (int m = 0; m < (int)_repeatedMessageRecords.size(); ++m) { + int repeatCount = _repeatedMessageRecords[m].repeatCount; + if (repeatCount > 1) { + QString repeatLogMessage = QString().setNum(repeatCount) + " repeated log entries - Last entry: \"" + + _repeatedMessageRecords[m].repeatString + "\""; + printMessage(LogSuppressed, QMessageLogContext(), repeatLogMessage); + _repeatedMessageRecords[m].repeatCount = 0; + _repeatedMessageRecords[m].repeatString = QString(); } - - message.messageCount = 0; } } QString LogHandler::printMessage(LogMsgType type, const QMessageLogContext& context, const QString& message) { - QMutexLocker lock(&_mutex); if (message.isEmpty()) { return QString(); } - - if (type == LogDebug) { - // for debug messages, check if this matches any of our regexes for repeated log messages - for (auto& repeatRegex : _repeatedMessages) { - if (repeatRegex.regexp.indexIn(message) != -1) { - // If we've printed the first one then return out. - if (repeatRegex.messageCount++ == 0) { - break; - } - repeatRegex.lastMessage = message; - return QString(); - } - } - } - - if (type == LogDebug) { - // see if this message is one we should only print once - for (auto& onceOnly : _onetimeMessages) { - if (onceOnly.regexp.indexIn(message) != -1) { - if (onceOnly.messageCount++ == 0) { - // we have a match and haven't yet printed this message. - break; - } else { - // We've already printed this message, don't print it again. - return QString(); - } - } - } - } + QMutexLocker lock(&_mutex); // log prefix is in the following format // [TIMESTAMP] [DEBUG] [PID] [TID] [TARGET] logged string @@ -199,21 +169,27 @@ void LogHandler::setupRepeatedMessageFlusher() { }); } -const QString& LogHandler::addRepeatedMessageRegex(const QString& regexString) { - // make sure we setup the repeated message flusher, but do it on the LogHandler thread - QMetaObject::invokeMethod(this, "setupRepeatedMessageFlusher"); - +int LogHandler::newRepeatedMessageID() { QMutexLocker lock(&_mutex); - RepeatedMessage repeatRecord; - repeatRecord.regexp = QRegExp(regexString); - _repeatedMessages.push_back(repeatRecord); - return regexString; + int newMessageId = _currentMessageID; + ++_currentMessageID; + RepeatedMessageRecord newRecord { 0, QString() }; + _repeatedMessageRecords.push_back(newRecord); + return newMessageId; } -const QString& LogHandler::addOnlyOnceMessageRegex(const QString& regexString) { +void LogHandler::printRepeatedMessage(int messageID, LogMsgType type, const QMessageLogContext& context, + const QString& message) { QMutexLocker lock(&_mutex); - OnceOnlyMessage onetimeMessage; - onetimeMessage.regexp = QRegExp(regexString); - _onetimeMessages.push_back(onetimeMessage); - return regexString; + if (messageID >= _currentMessageID) { + return; + } + + if (_repeatedMessageRecords[messageID].repeatCount == 0) { + printMessage(type, context, message); + } else { + _repeatedMessageRecords[messageID].repeatString = message; + } + + ++_repeatedMessageRecords[messageID].repeatCount; } diff --git a/libraries/shared/src/LogHandler.h b/libraries/shared/src/LogHandler.h index 2e64f16c1e..56450768ff 100644 --- a/libraries/shared/src/LogHandler.h +++ b/libraries/shared/src/LogHandler.h @@ -51,8 +51,8 @@ public: /// prints various process, message type, and time information static void verboseMessageHandler(QtMsgType type, const QMessageLogContext& context, const QString &message); - const QString& addRepeatedMessageRegex(const QString& regexString); - const QString& addOnlyOnceMessageRegex(const QString& regexString); + int newRepeatedMessageID(); + void printRepeatedMessage(int messageID, LogMsgType type, const QMessageLogContext& context, const QString &message); private slots: void setupRepeatedMessageFlusher(); @@ -68,20 +68,40 @@ private: bool _shouldOutputThreadID { false }; bool _shouldDisplayMilliseconds { false }; - struct RepeatedMessage { - QRegExp regexp; - int messageCount { 0 }; - QString lastMessage; + int _currentMessageID { 0 }; + struct RepeatedMessageRecord { + int repeatCount; + QString repeatString; }; - std::vector _repeatedMessages; - - struct OnceOnlyMessage { - QRegExp regexp; - int messageCount { 0 }; - }; - std::vector _onetimeMessages; - + std::vector _repeatedMessageRecords; static QMutex _mutex; }; +#define HIFI_FCDEBUG(category, message) \ + do { \ + if (category.isDebugEnabled()) { \ + static int repeatedMessageID_ = LogHandler::getInstance().newRepeatedMessageID(); \ + QString logString_; \ + QDebug debugStringReceiver_(&logString_); \ + debugStringReceiver_ << message; \ + LogHandler::getInstance().printRepeatedMessage(repeatedMessageID_, LogDebug, QMessageLogContext(__FILE__, \ + __LINE__, __func__, category().categoryName()), logString_); \ + } \ + } while (false) + +#define HIFI_FDEBUG(message) HIFI_FCDEBUG((*QLoggingCategory::defaultCategory()), message) + +#define HIFI_FCDEBUG_ID(category, messageID, message) \ + do { \ + if (category.isDebugEnabled()) { \ + QString logString_; \ + QDebug debugStringReceiver_(&logString_); \ + debugStringReceiver_ << message; \ + LogHandler::getInstance().printRepeatedMessage(messageID, LogDebug, QMessageLogContext(__FILE__, \ + __LINE__, __func__, category().categoryName()), logString_); \ + } \ + } while (false) + +#define HIFI_FDEBUG_ID(messageID, message) HIFI_FCDEBUG_ID((*QLoggingCategory::defaultCategory()), messageID, message) + #endif // hifi_LogHandler_h