Logging improvements

assignment-client/src/AssignmentClient.cpp

@@ -175,9 +175,6 @@ AssignmentClient::~AssignmentClient() {
 
 void AssignmentClient::aboutToQuit() {
     stopAssignmentClient();
-
-    // clear the log handler so that Qt doesn't call the destructor on LogHandler
-    qInstallMessageHandler(0);
 }
 
 void AssignmentClient::setUpStatusToMonitor() {

assignment-client/src/AssignmentClientApp.cpp

@@ -45,9 +45,6 @@ AssignmentClientApp::AssignmentClientApp(int argc, char* argv[]) :
     setApplicationName("assignment-client");
     setApplicationVersion(BuildInfo::VERSION);
 
-    // use the verbose message handler in Logging
-    qInstallMessageHandler(LogHandler::verboseMessageHandler);
-
     // parse command-line
     QCommandLineParser parser;
     parser.setApplicationDescription("High Fidelity Assignment Client");

assignment-client/src/AssignmentClientMonitor.cpp

@@ -126,9 +126,6 @@ void AssignmentClientMonitor::stopChildProcesses() {
 
 void AssignmentClientMonitor::aboutToQuit() {
     stopChildProcesses();
-
-    // clear the log handler so that Qt doesn't call the destructor on LogHandler
-    qInstallMessageHandler(0);
 }
 
 void AssignmentClientMonitor::spawnChildClient() {

assignment-client/src/main.cpp

@@ -9,8 +9,7 @@
 //  See the accompanying file LICENSE or http://www.apache.org/licenses/LICENSE-2.0.html
 //
 
-#include <QtCore/QDebug>
-
+#include <LogHandler.h>
 #include <SharedUtil.h>
 
 #include "AssignmentClientApp.h"
@@ -18,10 +17,14 @@
 int main(int argc, char* argv[]) {
     disableQtBearerPoll(); // Fixes wifi ping spikes
 
+    qInstallMessageHandler(LogHandler::verboseMessageHandler);
+    qInfo() << "Starting.";
+
     AssignmentClientApp app(argc, argv);
     
     int acReturn = app.exec();
     qDebug() << "assignment-client process" <<  app.applicationPid() << "exiting with status code" << acReturn;
-    
+
+    qInfo() << "Quitting.";
     return acReturn;
 }

domain-server/src/DomainServer.cpp

@@ -72,13 +72,10 @@ DomainServer::DomainServer(int argc, char* argv[]) :
     _iceServerPort(ICE_SERVER_DEFAULT_PORT)
 {
     parseCommandLine();
-    qInstallMessageHandler(LogHandler::verboseMessageHandler);
 
     LogUtils::init();
     Setting::init();
 
-    connect(this, &QCoreApplication::aboutToQuit, this, &DomainServer::aboutToQuit);
-
     setOrganizationName(BuildInfo::MODIFIED_ORGANIZATION);
     setOrganizationDomain("highfidelity.io");
     setApplicationName("domain-server");
@@ -211,6 +208,7 @@ void DomainServer::parseCommandLine() {
 }
 
 DomainServer::~DomainServer() {
+    qInfo() << "Domain Server is shutting down.";
     // destroy the LimitedNodeList before the DomainServer QCoreApplication is down
     DependencyManager::destroy<LimitedNodeList>();
 }
@@ -223,12 +221,6 @@ void DomainServer::queuedQuit(QString quitMessage, int exitCode) {
     QCoreApplication::exit(exitCode);
 }
 
-void DomainServer::aboutToQuit() {
-
-    // clear the log handler so that Qt doesn't call the destructor on LogHandler
-    qInstallMessageHandler(0);
-}
-
 void DomainServer::restart() {
     qDebug() << "domain-server is restarting.";
 

domain-server/src/DomainServer.h

@@ -72,8 +72,6 @@ public slots:
     void processICEServerHeartbeatACK(QSharedPointer<ReceivedMessage> message);
 
 private slots:
-    void aboutToQuit();
-
     void setupPendingAssignmentCredits();
     void sendPendingTransactionsToServer();
 
@@ -150,13 +148,9 @@ private:
 
     bool isAuthenticatedRequest(HTTPConnection* connection, const QUrl& url);
 
-    void handleTokenRequestFinished();
     QNetworkReply* profileRequestGivenTokenReply(QNetworkReply* tokenReply);
-    void handleProfileRequestFinished();
     Headers setupCookieHeadersFromProfileReply(QNetworkReply* profileReply);
 
-    void loadExistingSessionsFromSettings();
-
     QJsonObject jsonForSocket(const HifiSockAddr& socket);
     QJsonObject jsonObjectForNode(const SharedNodePointer& node);
 

domain-server/src/main.cpp

@@ -15,8 +15,6 @@
 //  See the accompanying file LICENSE or http://www.apache.org/licenses/LICENSE-2.0.html
 //
 
-#include <QtCore/QCoreApplication>
-
 #include <LogHandler.h>
 #include <SharedUtil.h>
 
@@ -29,6 +27,9 @@ int main(int argc, char* argv[]) {
     setvbuf(stdout, NULL, _IOLBF, 0);
 #endif
 
+    qInstallMessageHandler(LogHandler::verboseMessageHandler);
+    qInfo() << "Starting.";
+
     int currentExitCode = 0;
 
     // use a do-while to handle domain-server restart
@@ -37,7 +38,7 @@ int main(int argc, char* argv[]) {
         currentExitCode = domainServer.exec();
     } while (currentExitCode == DomainServer::EXIT_CODE_REBOOT);
 
-
+    qInfo() << "Quitting.";
     return currentExitCode;
 }
 

ice-server/src/main.cpp

@@ -19,8 +19,9 @@ int main(int argc, char* argv[]) {
 #ifndef WIN32
     setvbuf(stdout, NULL, _IOLBF, 0);
 #endif
-    
+
     qInstallMessageHandler(LogHandler::verboseMessageHandler);
+    qInfo() << "Starting.";
     
     IceServer iceServer(argc, argv);
     return iceServer.exec();

interface/src/Application.cpp

@@ -1654,7 +1654,8 @@ Application::~Application() {
     
     _window->deleteLater();
 
-    qInstallMessageHandler(nullptr); // NOTE: Do this as late as possible so we continue to get our log messages
+    // Can't log to file passed this point, FileLogger about to be deleted
+    qInstallMessageHandler(LogHandler::verboseMessageHandler);
 }
 
 void Application::initializeGL() {

libraries/shared/src/LogHandler.cpp

@@ -10,17 +10,18 @@
 //  See the accompanying file LICENSE or http://www.apache.org/licenses/LICENSE-2.0.html
 //
 
-#include <qcoreapplication.h>
-
-#include <QDateTime>
-#include <QDebug>
-#include <QTimer>
-#include <QThread>
-#include <QMutexLocker>
-#include <QRegExp>
-
 #include "LogHandler.h"
 
+#include <mutex>
+
+#include <QtCore/QCoreApplication>
+#include <QtCore/QDateTime>
+#include <QtCore/QDebug>
+#include <QtCore/QMutexLocker>
+#include <QtCore/QRegExp>
+#include <QtCore/QThread>
+#include <QtCore/QTimer>
+
 QMutex LogHandler::_mutex;
 
 LogHandler& LogHandler::getInstance() {
@@ -28,16 +29,15 @@ LogHandler& LogHandler::getInstance() {
     return staticInstance;
 }
 
-LogHandler::LogHandler()
-{
-    // 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);
-
+LogHandler::LogHandler() {
     // 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));
+    printMessage(LogMsgType::LogInfo, QMessageLogContext(), timezoneString);
+}
+
+LogHandler::~LogHandler() {
+    flushRepeatedMessages();
+    printMessage(LogMsgType::LogDebug, QMessageLogContext(), "LogHandler shutdown.");
 }
 
 const char* stringForLogType(LogMsgType msgType) {
@@ -165,7 +165,7 @@ QString LogHandler::printMessage(LogMsgType type, const QMessageLogContext& cont
         stringForLogType(type), context.category);
 
     if (_shouldOutputProcessID) {
-        prefixString.append(QString(" [%1]").arg(QCoreApplication::instance()->applicationPid()));
+        prefixString.append(QString(" [%1]").arg(QCoreApplication::applicationPid()));
     }
 
     if (_shouldOutputThreadID) {
@@ -187,6 +187,14 @@ void LogHandler::verboseMessageHandler(QtMsgType type, const QMessageLogContext&
 }
 
 const QString& LogHandler::addRepeatedMessageRegex(const QString& regexString) {
+    static std::once_flag once;
+    std::call_once(once, [&] {
+        // 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);
+    });
+
     QMutexLocker lock(&_mutex);
     return *_repeatedMessageRegexes.insert(regexString);
 }

libraries/shared/src/LogHandler.h

@@ -52,8 +52,10 @@ public:
 
     const QString& addRepeatedMessageRegex(const QString& regexString);
     const QString& addOnlyOnceMessageRegex(const QString& regexString);
+
 private:
     LogHandler();
+    ~LogHandler();
 
     void flushRepeatedMessages();
 

libraries/shared/src/ShutdownEventListener.cpp

@@ -9,8 +9,6 @@
 //  See the accompanying file LICENSE or http://www.apache.org/licenses/LICENSE-2.0.html
 //
 
-#include <QCoreApplication>
-
 #include "ShutdownEventListener.h"
 
 #ifdef Q_OS_WIN
@@ -19,6 +17,9 @@
 #include <csignal>
 #endif
 
+#include <QtCore/QCoreApplication>
+#include <QtCore/QDebug>
+
 ShutdownEventListener& ShutdownEventListener::getInstance() {
     static ShutdownEventListener staticInstance;
     return staticInstance;
@@ -29,9 +30,7 @@ void signalHandler(int param) {
     QMetaObject::invokeMethod(qApp, "quit");
 }
 
-ShutdownEventListener::ShutdownEventListener(QObject* parent) :
-    QObject(parent)
-{
+ShutdownEventListener::ShutdownEventListener(QObject* parent) : QObject(parent) {
 #ifndef Q_OS_WIN
     // be a signal handler for SIGTERM so we can stop our children when we get it
     signal(SIGTERM, signalHandler);

libraries/shared/src/shared/FileLogger.cpp

@@ -109,7 +109,8 @@ bool FilePersistThread::processQueueItems(const Queue& messages) {
 }
 
 FileLogger::FileLogger(QObject* parent) :
-    AbstractLoggerInterface(parent), _fileName(getLogFilename())
+    AbstractLoggerInterface(parent),
+    _fileName(getLogFilename())
 {
     _persistThreadInstance = new FilePersistThread(*this);
     _persistThreadInstance->initialize(true, QThread::LowestPriority);

libraries/shared/src/shared/FileLogger.h

@@ -24,7 +24,7 @@ public:
     FileLogger(QObject* parent = NULL);
     virtual ~FileLogger();
 
-    QString getFilename() { return _fileName; }
+    QString getFilename() const { return _fileName; }
     virtual void addMessage(const QString&) override;
     virtual QString getLogData() override;
     virtual void locateLog() override;