Merge pull request #12782 from SimonWalton-HiFi/qregexp

Replace LogHandler repeated regex scheme with assigned ID tracking scheme
This commit is contained in:
Stephen Birarda 2018-04-18 17:28:48 -07:00 committed by GitHub
commit c4ad93bafb
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
24 changed files with 159 additions and 248 deletions

View file

@ -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<ReceivedMessage
auto it = find_if(_acSubnetWhitelist.begin(), _acSubnetWhitelist.end(), isHostAddressInSubnet);
if (it == _acSubnetWhitelist.end()) {
static QString repeatedMessage = LogHandler::getInstance().addRepeatedMessageRegex(
"Received an assignment connect request from a disallowed ip address: [^ ]+");
qDebug() << "Received an assignment connect request from a disallowed ip address:"
<< senderAddr.toString();
HIFI_FDEBUG("Received an assignment connect request from a disallowed ip address:"
<< senderAddr.toString());
return;
}
// Suppress these for Assignment::AgentType to once per 5 seconds
static QElapsedTimer noisyMessageTimer;
static bool wasNoisyTimerStarted = false;
if (!wasNoisyTimerStarted) {
noisyMessageTimer.start();
wasNoisyTimerStarted = true;
}
const qint64 NOISY_MESSAGE_INTERVAL_MSECS = 5 * 1000;
if (requestAssignment.getType() != Assignment::AgentType
|| noisyMessageTimer.elapsed() > 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(QSharedPointer<ReceivedMessage
_gatekeeper.addPendingAssignedNode(uniqueAssignment.getUUID(), assignmentToDeploy->getUUID(),
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";

View file

@ -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;
}

View file

@ -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;
}
}

View file

@ -39,9 +39,6 @@ AudioRingBufferTemplate<T>::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 <class T>
@ -154,6 +151,11 @@ int AudioRingBufferTemplate<T>::appendData(char *data, int maxSize) {
return numReadSamples * SampleSize;
}
namespace {
int repeatedOverflowMessageID = 0;
std::once_flag messageIDFlag;
}
template <class T>
int AudioRingBufferTemplate<T>::writeData(const char* data, int maxSize) {
// only copy up to the number of samples we have capacity for
@ -167,7 +169,9 @@ int AudioRingBufferTemplate<T>::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<T>::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<T>::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<T>::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;

View file

@ -16,6 +16,7 @@
#include <glm/detail/func_common.hpp>
#include <QtCore/QDataStream>
#include <QtCore/QLoggingCategory>
#include <LogHandler.h>
#include <Node.h>
@ -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 {

View file

@ -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);
}
}

View file

@ -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());
}
}

View file

@ -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;
}

View file

@ -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));
}
}

View file

@ -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++;

View file

@ -107,8 +107,7 @@ Packet::Packet(std::unique_ptr<char[]> 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

View file

@ -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

View file

@ -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<HifiSockAddr> 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) {

View file

@ -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;
}

View file

@ -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);

View file

@ -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
}

View file

@ -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;
}

View file

@ -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;
}

View file

@ -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;
}

View file

@ -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;
}

View file

@ -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 {

View file

@ -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);
}
}
}

View file

@ -25,7 +25,7 @@
#include <QtCore/QThread>
#include <QtCore/QTimer>
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;
}

View file

@ -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<RepeatedMessage> _repeatedMessages;
struct OnceOnlyMessage {
QRegExp regexp;
int messageCount { 0 };
};
std::vector<OnceOnlyMessage> _onetimeMessages;
std::vector<RepeatedMessageRecord> _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