diff --git a/assignment-client/src/AssignmentClient.cpp b/assignment-client/src/AssignmentClient.cpp index f4f98114d0..bf5f9c3b7f 100644 --- a/assignment-client/src/AssignmentClient.cpp +++ b/assignment-client/src/AssignmentClient.cpp @@ -74,7 +74,7 @@ AssignmentClient::AssignmentClient(Assignment::Type requestAssignmentType, QStri LogHandler::getInstance().setTargetName(ASSIGNMENT_CLIENT_TARGET_NAME); // make sure we output process IDs for a child AC otherwise it's insane to parse - LogHandler::getInstance().setShouldOutputPID(true); + LogHandler::getInstance().setShouldOutputProcessID(true); // setup our _requestAssignment member variable from the passed arguments _requestAssignment = Assignment(Assignment::RequestCommand, requestAssignmentType, assignmentPool); diff --git a/assignment-client/src/AssignmentClientMonitor.cpp b/assignment-client/src/AssignmentClientMonitor.cpp index 58cf3c49f3..7b3d5695e1 100644 --- a/assignment-client/src/AssignmentClientMonitor.cpp +++ b/assignment-client/src/AssignmentClientMonitor.cpp @@ -44,7 +44,7 @@ AssignmentClientMonitor::AssignmentClientMonitor(const unsigned int numAssignmen LogHandler::getInstance().setTargetName(ASSIGNMENT_CLIENT_MONITOR_TARGET_NAME); // make sure we output process IDs for a monitor otherwise it's insane to parse - LogHandler::getInstance().setShouldOutputPID(true); + LogHandler::getInstance().setShouldOutputProcessID(true); // create a NodeList so we can receive stats from children DependencyManager::registerInheritance(); diff --git a/libraries/shared/src/LogHandler.cpp b/libraries/shared/src/LogHandler.cpp index cc3519e43e..7dd1aceb3d 100644 --- a/libraries/shared/src/LogHandler.cpp +++ b/libraries/shared/src/LogHandler.cpp @@ -12,9 +12,12 @@ #include -#include -#include -#include +#include +#include +#include +#include +#include +#include #include "LogHandler.h" @@ -24,13 +27,14 @@ LogHandler& LogHandler::getInstance() { } LogHandler::LogHandler() : - _shouldOutputPID(false) + _shouldOutputProcessID(false), + _shouldOutputThreadID(false) { // setup our timer to flush the verbose logs every 5 seconds QTimer* logFlushTimer = new QTimer(this); connect(logFlushTimer, &QTimer::timeout, this, &LogHandler::flushRepeatedMessages); logFlushTimer->start(VERBOSE_LOG_INTERVAL_SECONDS * 1000); - + // when the log handler is first setup we should print our timezone QString timezoneString = "Time zone: " + QDateTime::currentDateTime().toString("t"); printf("%s\n", qPrintable(timezoneString)); @@ -57,51 +61,55 @@ const char* stringForLogType(LogMsgType msgType) { const QString DATE_STRING_FORMAT = "MM/dd hh:mm:ss"; void LogHandler::flushRepeatedMessages() { + QMutexLocker locker(&_repeatedMessageLock); QHash::iterator message = _repeatMessageCountHash.begin(); while (message != _repeatMessageCountHash.end()) { - + if (message.value() > 0) { QString repeatMessage = QString("%1 repeated log entries matching \"%2\" - Last entry: \"%3\"") .arg(message.value()).arg(message.key()).arg(_lastRepeatedMessage.value(message.key())); - + QMessageLogContext emptyContext; printMessage(LogSuppressed, emptyContext, repeatMessage); } - + _lastRepeatedMessage.remove(message.key()); message = _repeatMessageCountHash.erase(message); } } QString LogHandler::printMessage(LogMsgType type, const QMessageLogContext& context, const QString& message) { - + if (message.isEmpty()) { return QString(); } - + if (type == LogDebug) { // for debug messages, check if this matches any of our regexes for repeated log messages + QMutexLocker locker(&_repeatedMessageLock); foreach(const QString& regexString, getInstance()._repeatedMessageRegexes) { QRegExp repeatRegex(regexString); if (repeatRegex.indexIn(message) != -1) { - + if (!_repeatMessageCountHash.contains(regexString)) { // we have a match but didn't have this yet - output the first one _repeatMessageCountHash[regexString] = 0; - + // break the foreach so we output the first match break; } else { // we have a match - add 1 to the count of repeats for this message and set this as the last repeated message _repeatMessageCountHash[regexString] += 1; _lastRepeatedMessage[regexString] = message; - + // return out, we're not printing this one return QString(); } } } - + } + if (type == LogDebug) { + QMutexLocker locker(&_onlyOnceMessageLock); // see if this message is one we should only print once foreach(const QString& regexString, getInstance()._onlyOnceMessageRegexes) { QRegExp onlyOnceRegex(regexString); @@ -118,23 +126,27 @@ QString LogHandler::printMessage(LogMsgType type, const QMessageLogContext& cont } } } - + // log prefix is in the following format - // [TIMESTAMP] [DEBUG] [PID] [TARGET] logged string - + // [TIMESTAMP] [DEBUG] [PID] [TID] [TARGET] logged string + QString prefixString = QString("[%1]").arg(QDateTime::currentDateTime().toString(DATE_STRING_FORMAT)); - + prefixString.append(QString(" [%1]").arg(stringForLogType(type))); - - if (_shouldOutputPID) { + + if (_shouldOutputProcessID) { prefixString.append(QString(" [%1]").arg(QCoreApplication::instance()->applicationPid())); - } - + + if (_shouldOutputThreadID) { + size_t threadID = (size_t)QThread::currentThreadId(); + prefixString.append(QString(" [%1]").arg(threadID)); + } + if (!_targetName.isEmpty()) { prefixString.append(QString(" [%1]").arg(_targetName)); } - + QString logMessage = QString("%1 %2").arg(prefixString, message.split("\n").join("\n" + prefixString + " ")); fprintf(stdout, "%s\n", qPrintable(logMessage)); return logMessage; @@ -143,3 +155,13 @@ QString LogHandler::printMessage(LogMsgType type, const QMessageLogContext& cont void LogHandler::verboseMessageHandler(QtMsgType type, const QMessageLogContext& context, const QString& message) { getInstance().printMessage((LogMsgType) type, context, message); } + +const QString& LogHandler::addRepeatedMessageRegex(const QString& regexString) { + QMutexLocker locker(&_repeatedMessageLock); + return *_repeatedMessageRegexes.insert(regexString); +} + +const QString& LogHandler::addOnlyOnceMessageRegex(const QString& regexString) { + QMutexLocker locker(&_onlyOnceMessageLock); + return *_onlyOnceMessageRegexes.insert(regexString); +} diff --git a/libraries/shared/src/LogHandler.h b/libraries/shared/src/LogHandler.h index 6af721f96c..a74a6287d7 100644 --- a/libraries/shared/src/LogHandler.h +++ b/libraries/shared/src/LogHandler.h @@ -13,11 +13,11 @@ #ifndef hifi_LogHandler_h #define hifi_LogHandler_h -#include -#include -#include -#include -#include +#include +#include +#include +#include +#include const int VERBOSE_LOG_INTERVAL_SECONDS = 5; @@ -34,34 +34,38 @@ class LogHandler : public QObject { Q_OBJECT public: static LogHandler& getInstance(); - + /// sets the target name to output via the verboseMessageHandler, called once before logging begins /// \param targetName the desired target name to output in logs void setTargetName(const QString& targetName) { _targetName = targetName; } - - void setShouldOutputPID(bool shouldOutputPID) { _shouldOutputPID = shouldOutputPID; } - + + void setShouldOutputProcessID(bool shouldOutputProcessID) { _shouldOutputProcessID = shouldOutputProcessID; } + void setShouldOutputThreadID(bool shouldOutputThreadID) { _shouldOutputThreadID = shouldOutputThreadID; } + QString printMessage(LogMsgType type, const QMessageLogContext& context, const QString &message); - + /// a qtMessageHandler that can be hooked up to a target that links to Qt /// 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) { return *_repeatedMessageRegexes.insert(regexString); } - const QString& addOnlyOnceMessageRegex(const QString& regexString) { return *_onlyOnceMessageRegexes.insert(regexString); } + + const QString& addRepeatedMessageRegex(const QString& regexString); + const QString& addOnlyOnceMessageRegex(const QString& regexString); private: LogHandler(); - + void flushRepeatedMessages(); - + QString _targetName; - bool _shouldOutputPID; + bool _shouldOutputProcessID; + bool _shouldOutputThreadID; QSet _repeatedMessageRegexes; QHash _repeatMessageCountHash; QHash _lastRepeatedMessage; + QMutex _repeatedMessageLock; QSet _onlyOnceMessageRegexes; QHash _onlyOnceMessageCountHash; + QMutex _onlyOnceMessageLock; }; #endif // hifi_LogHandler_h