Merge pull request #104 from daleglass-overte/journald-logging

Implement Journald logging

assignment-client/src/AssignmentClientApp.cpp

@@ -107,6 +107,9 @@ AssignmentClientApp::AssignmentClientApp(int argc, char* argv[]) :
     const QCommandLineOption parentPIDOption(PARENT_PID_OPTION, "PID of the parent process", "parent-pid");
     parser.addOption(parentPIDOption);
 
+    const QCommandLineOption logOption("logOptions", "Logging options, comma separated: color,nocolor,process_id,thread_id,milliseconds,keep_repeats,journald,nojournald", "options");
+    parser.addOption(logOption);
+
     if (!parser.parse(QCoreApplication::arguments())) {
         std::cout << parser.errorText().toStdString() << std::endl; // Avoid Qt log spam
         parser.showHelp();
@@ -123,6 +126,16 @@ AssignmentClientApp::AssignmentClientApp(int argc, char* argv[]) :
         Q_UNREACHABLE();
     }
 
+    // We want to configure the logging system as early as possible
+    auto &logHandler = LogHandler::getInstance();
+    if (parser.isSet(logOption)) {
+        if (!logHandler.parseOptions(parser.value(logOption).toUtf8(), logOption.names().first())) {
+            QCoreApplication mockApp(argc, const_cast<char**>(argv)); // required for call to showHelp()
+            parser.showHelp();
+            Q_UNREACHABLE();
+        }
+    }
+
     const QVariantMap argumentVariantMap = HifiConfigVariantMap::mergeCLParametersWithJSONConfig(arguments());
 
     unsigned int numForks = 0;

cmake/modules/FindJournald.cmake

@@ -0,0 +1,45 @@
+# - Try to find Journald library.
+# Once done this will define
+#
+#  JOURNALD_FOUND - system has Journald
+#  JOURNALD_INCLUDE_DIR - the Journald include directory
+#  JOURNALD_LIBRARIES - Link these to use Journald
+#  JOURNALD_DEFINITIONS - Compiler switches required for using Journald
+# Redistribution and use is allowed according to the terms of the BSD license.
+# For details see the accompanying COPYING-CMAKE-SCRIPTS file.
+#
+
+# Copyright (c) 2015 David Edmundson
+#
+
+# use pkg-config to get the directories and then use these values
+# in the FIND_PATH() and FIND_LIBRARY() calls
+find_package(PkgConfig)
+pkg_check_modules(PC_JOURNALD QUIET systemd)
+
+set(JOURNALD_FOUND ${PC_JOURNALD_FOUND})
+set(JOURNALD_DEFINITIONS ${PC_JOURNALD_CFLAGS_OTHER})
+
+find_path(JOURNALD_INCLUDE_DIR NAMES systemd/sd-journal.h
+  PATHS
+  ${PC_JOURNALD_INCLUDEDIR}
+  ${PC_JOURNALD_INCLUDE_DIRS}
+)
+
+find_library(JOURNALD_LIBRARY NAMES systemd
+  PATHS
+  ${PC_JOURNALD_LIBDIR}
+  ${PC_JOURNALD_LIBRARY_DIRS}
+)
+
+set(JOURNALD_LIBRARIES ${JOURNALD_LIBRARY})
+
+include(FindPackageHandleStandardArgs)
+find_package_handle_standard_args(Journald DEFAULT_MSG JOURNALD_LIBRARY JOURNALD_INCLUDE_DIR)
+
+include(FeatureSummary)
+set_package_properties(Journald PROPERTIES URL https://github.com/systemd
+  DESCRIPTION "Systemd logging daemon")
+
+# show the JOURNALD_INCLUDE_DIR and JOURNALD_LIBRARY variables only in the advanced view
+mark_as_advanced(JOURNALD_INCLUDE_DIR JOURNALD_LIBRARY)

domain-server/src/DomainServer.cpp

@@ -414,6 +414,9 @@ void DomainServer::parseCommandLine(int argc, char* argv[]) {
     const QCommandLineOption parentPIDOption(PARENT_PID_OPTION, "PID of the parent process", "parent-pid");
     parser.addOption(parentPIDOption);
 
+    const QCommandLineOption logOption("logOptions", "Logging options, comma separated: color,nocolor,process_id,thread_id,milliseconds,keep_repeats,journald,nojournald", "options");
+    parser.addOption(logOption);
+
 
     QStringList arguments;
     for (int i = 0; i < argc; ++i) {
@@ -436,6 +439,16 @@ void DomainServer::parseCommandLine(int argc, char* argv[]) {
         Q_UNREACHABLE();
     }
 
+    // We want to configure the logging system as early as possible
+    auto &logHandler = LogHandler::getInstance();
+    if (parser.isSet(logOption)) {
+        if (!logHandler.parseOptions(parser.value(logOption).toUtf8(), logOption.names().first())) {
+            QCoreApplication mockApp(argc, const_cast<char**>(argv)); // required for call to showHelp()
+            parser.showHelp();
+            Q_UNREACHABLE();
+        }
+    }
+
     if (parser.isSet(iceServerAddressOption)) {
         // parse the IP and port combination for this target
         QString hostnamePortString = parser.value(iceServerAddressOption);

interface/src/main.cpp

@@ -30,8 +30,8 @@
 #include "InterfaceLogging.h"
 #include "UserActivityLogger.h"
 #include "MainWindow.h"
-
 #include "Profile.h"
+#include "LogHandler.h"
 
 #ifdef Q_OS_WIN
 #include <Windows.h>
@@ -64,6 +64,9 @@ int main(int argc, const char* argv[]) {
 
     setupHifiApplication(BuildInfo::INTERFACE_NAME);
 
+    // Journald by default in user applications is probably a bit too modern still.
+    LogHandler::getInstance().setShouldUseJournald(false);
+
     QCommandLineParser parser;
     parser.setApplicationDescription("Overte -- A free/libre and open-source metaverse client");
     QCommandLineOption helpOption = parser.addHelpOption();
@@ -237,6 +240,11 @@ int main(int argc, const char* argv[]) {
        "fast-heartbeat",
        "Change stats polling interval from 10000ms to 1000ms."
     );
+    QCommandLineOption logOption(
+        "logOptions",
+        "Logging options, comma separated: color,nocolor,process_id,thread_id,milliseconds,keep_repeats,journald,nojournald",
+        "options"
+    );
     // "--qmljsdebugger", which appears in output from "--help-all".
     // Those below don't seem to be optional.
     //     --ignore-gpu-blacklist
@@ -277,6 +285,7 @@ int main(int argc, const char* argv[]) {
     parser.addOption(testResultsLocationOption);
     parser.addOption(quitWhenFinishedOption);
     parser.addOption(fastHeartbeatOption);
+    parser.addOption(logOption);
 
     QString applicationPath;
     // A temporary application instance is needed to get the location of the running executable
@@ -299,6 +308,16 @@ int main(int argc, const char* argv[]) {
 #endif
     }
 
+    // We want to configure the logging system as early as possible
+    auto &logHandler = LogHandler::getInstance();
+    if (parser.isSet(logOption)) {
+        if (!logHandler.parseOptions(parser.value(logOption).toUtf8(), logOption.names().first())) {
+            QCoreApplication mockApp(argc, const_cast<char**>(argv)); // required for call to showHelp()
+            parser.showHelp();
+            Q_UNREACHABLE();
+        }
+    }
+
     // Act on arguments for early termination.
     if (parser.isSet(versionOption)) {
         parser.showVersion();

libraries/shared/CMakeLists.txt

@@ -21,6 +21,16 @@ if (APPLE)
     target_link_libraries(${TARGET_NAME} ${FRAMEWORK_IOKIT} ${CORE_FOUNDATION} ${OpenGL})
 endif()
 
+if (UNIX AND NOT APPLE)
+    find_package(Journald)
+
+    if (${JOURNALD_FOUND})
+        target_link_libraries(${TARGET_NAME} ${JOURNALD_LIBRARIES})
+        target_include_directories(${TARGET_NAME} PRIVATE ${JOURNALD_INCLUDE_DIR})
+        target_compile_definitions(${TARGET_NAME} PUBLIC HAS_JOURNALD)
+    endif()
+endif()
+
 target_zlib()
 target_nsight()
 target_json()

libraries/shared/src/LogHandler.cpp

@@ -30,6 +30,12 @@
 #include <QtCore/QThread>
 #include <QtCore/QTimer>
 #include <QRecursiveMutex>
+#include <vector>
+
+#ifdef HAS_JOURNALD
+#include <systemd/sd-journal.h>
+#include <sys/uio.h>
+#endif
 
 QRecursiveMutex LogHandler::_mutex;
 
@@ -51,27 +57,11 @@ LogHandler::LogHandler() {
     }
 #endif
 
-    auto optionList = logOptions.split(",");
+#ifdef HAS_JOURNALD
+    _useJournald = true;
+#endif
 
-    for (auto option : optionList) {
+    parseOptions(logOptions, "VIRCADIA_LOG_OPTIONS");
-        option = option.trimmed();
-
-        if (option == "color") {
-            _useColor = true;
-        } else if (option == "nocolor") {
-            _useColor = false;
-        } else if (option == "process_id") {
-            _shouldOutputProcessID = true;
-        } else if (option == "thread_id") {
-            _shouldOutputThreadID = true;
-        } else if (option == "milliseconds") {
-            _shouldDisplayMilliseconds = true;
-        } else if (option == "keep_repeats") {
-            _keepRepeats = true;
-        } else if (option != "") {
-            fprintf(stdout, "Unrecognized option in VIRCADIA_LOG_OPTIONS: '%s'\n", option.toUtf8().constData());
-        }
-    }
 }
 
 const char* stringForLogType(LogMsgType msgType) {
@@ -116,12 +106,53 @@ const char* colorReset() {
     return "\u001b[0m";
 }
 
+
+#ifdef HAS_JOURNALD
+void addString(std::vector<struct iovec>&list, const QByteArray &str) {
+    auto data = str.constData();
+    struct iovec iov{(void*)data, strlen(data)};
+    list.emplace_back(iov);
+}
+#endif
+
 // the following will produce 11/18 13:55:36
 const QString DATE_STRING_FORMAT = "MM/dd hh:mm:ss";
 
 // the following will produce 11/18 13:55:36.999
 const QString DATE_STRING_FORMAT_WITH_MILLISECONDS = "MM/dd hh:mm:ss.zzz";
 
+bool LogHandler::parseOptions(const QString& logOptions, const QString& paramName) {
+    QMutexLocker lock(&_mutex);
+    auto optionList = logOptions.split(",");
+
+    for (auto option : optionList) {
+        option = option.trimmed();
+
+        if (option == "color") {
+            _useColor = true;
+        } else if (option == "nocolor") {
+            _useColor = false;
+        } else if (option == "process_id") {
+            _shouldOutputProcessID = true;
+        } else if (option == "thread_id") {
+            _shouldOutputThreadID = true;
+        } else if (option == "milliseconds") {
+            _shouldDisplayMilliseconds = true;
+        } else if (option == "keep_repeats") {
+            _keepRepeats = true;
+        } else if (option == "journald") {
+            _useJournald = true;
+        } else if (option == "nojournald") {
+            _useJournald = false;
+        } else if (option != "") {
+            fprintf(stderr, "Unrecognized option in %s: '%s'\n", paramName.toUtf8().constData(), option.toUtf8().constData());
+            return false;
+        }
+    }
+
+    return true;
+}
+
 void LogHandler::setTargetName(const QString& targetName) {
     QMutexLocker lock(&_mutex);
     _targetName = targetName;
@@ -142,6 +173,24 @@ void LogHandler::setShouldDisplayMilliseconds(bool shouldDisplayMilliseconds) {
     _shouldDisplayMilliseconds = shouldDisplayMilliseconds;
 }
 
+void LogHandler::setShouldUseJournald(bool shouldUseJournald) {
+    QMutexLocker lock(&_mutex);
+#ifdef HAS_JOURNALD
+    _useJournald = shouldUseJournald;
+#else
+    if (shouldUseJournald) {
+        fprintf(stderr, "Journald is not supported on this system or was not compiled in.\n");
+    }
+#endif
+}
+
+bool LogHandler::isJournaldAvailable() const {
+#ifdef HAS_JOURNALD
+    return true;
+#else
+    return false;
+#endif
+}
 
 void LogHandler::flushRepeatedMessages() {
     QMutexLocker lock(&_mutex);
@@ -163,6 +212,7 @@ QString LogHandler::printMessage(LogMsgType type, const QMessageLogContext& cont
     if (message.isEmpty()) {
         return QString();
     }
+
     QMutexLocker lock(&_mutex);
 
     // log prefix is in the following format
@@ -196,8 +246,61 @@ QString LogHandler::printMessage(LogMsgType type, const QMessageLogContext& cont
         }
     }
 
+    // This is returned from this function and wanted by the LogEntityServer,
+    // so we have to have it even when using journald.
     QString logMessage = QString("%1 %2\n").arg(prefixString, message.split('\n').join('\n' + prefixString + " "));
 
+    if ( _useJournald ) {
+#ifdef HAS_JOURNALD
+        int priority = LOG_NOTICE;
+        switch(type) {
+            case LogMsgType::LogFatal: priority = LOG_EMERG; break;
+            case LogMsgType::LogCritical: priority = LOG_CRIT; break;
+            case LogMsgType::LogWarning: priority = LOG_WARNING; break;
+            case LogMsgType::LogInfo: priority = LOG_INFO; break;
+            case LogMsgType::LogDebug: priority = LOG_DEBUG; break;
+            case LogMsgType::LogSuppressed: priority = LOG_DEBUG; break;
+            default:
+                fprintf(stderr, "Unrecognized log type: %i\n", (int)type);
+        }
+
+        QByteArray sd_file = QString("CODE_FILE=%1").arg(context.file).toUtf8();
+        QByteArray sd_line = QString("CODE_LINE=%1").arg(context.line).toUtf8();
+
+        QByteArray sd_message = QString("MESSAGE=%1").arg(message).toUtf8();
+        QByteArray sd_priority = QString("PRIORITY=%1").arg(priority).toUtf8();
+        QByteArray sd_category = QString("CATEGORY=%1").arg(context.category).toUtf8();
+        QByteArray sd_tid = QString("TID=%1").arg((qlonglong)QThread::currentThreadId()).toUtf8();
+        QByteArray sd_target = QString("COMPONENT=%1").arg(_targetName).toUtf8();
+
+        std::vector<struct iovec> fields;
+        addString(fields, sd_message);
+        addString(fields, sd_priority);
+        addString(fields, sd_category);
+        addString(fields, sd_tid);
+
+        if (!_targetName.isEmpty()) {
+            addString(fields, sd_target);
+        }
+
+        int retval = sd_journal_sendv_with_location(sd_file.constData(),
+                                                    sd_line.constData(),
+                                                    context.function == NULL ? "(unknown)" : context.function,
+                                                    fields.data(),
+                                                    fields.size());
+
+        if ( retval != 0 ) {
+            fprintf(stderr, "Failed to log message, error %i: ", retval);
+            fprintf(stderr, "file=%s, line=%i, func=%s, prio=%i, msg=%s\n",
+                            context.file,
+                            context.line,
+                            context.function,
+                            priority,
+                            message.toUtf8().constData()
+            );
+        }
+#endif
+    } else {
             const char* color = "";
             const char* resetColor = "";
 
@@ -217,6 +320,13 @@ QString LogHandler::printMessage(LogMsgType type, const QMessageLogContext& cont
                 _repeatCount++;
             }
 
+            _previousMessage = message;
+        #ifdef Q_OS_WIN
+            // On windows, this will output log lines into the Visual Studio "output" tab
+            OutputDebugStringA(qPrintable(logMessage));
+        #endif
+    }
+
     if ( !_breakMessages.empty() ) {
         for(const auto &str : _breakMessages) {
             if (logMessage.contains(str)) {
@@ -229,6 +339,7 @@ QString LogHandler::printMessage(LogMsgType type, const QMessageLogContext& cont
     // On windows, this will output log lines into the Visual Studio "output" tab
     OutputDebugStringA(qPrintable(logMessage));
 #endif
+
     return logMessage;
 }
 

libraries/shared/src/LogHandler.h

@@ -31,24 +31,105 @@ enum LogMsgType {
     LogSuppressed = 100
 };
 
-/// Handles custom message handling and sending of stats/logs to Logstash instance
+///
+
+/**
+ * @brief Handles custom message handling and sending of stats/logs to Logstash instance
+ *
+ */
 class LogHandler : public QObject {
     Q_OBJECT
 public:
+    /**
+     * @brief Returns the one instance of the LogHandler object
+     *
+     * @return LogHandler&
+     */
     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
+     * @brief Parse logging options
+     *
+     * This parses the logging settings in the environment variable, or from the commandline
+     *
+     * @param options Option list
+     * @param paramName Name of the log option, for error reporting.
+     * @return true Option list was parsed successfully
+     * @return false There was an error
+     */
+    bool parseOptions(const QString& options, const QString &paramName);
+
+    /**
+     * @brief Set the name of the component that's producing log output
+     *
+     * For instance, "assignment-client", "audio-mixer", etc.
+     * Called once before logging begins
+     *
+     * @param targetName the desired target name to output in logs
+     */
     void setTargetName(const QString& targetName);
 
+    /**
+     * @brief Set whether to output the process ID
+     *
+     * @note This has no effect when logging with journald, the PID is always logged
+     *
+     * @param shouldOutputProcessID Whether to output the PID
+     */
     void setShouldOutputProcessID(bool shouldOutputProcessID);
+
+    /**
+     * @brief Set whether to output the thread ID
+     *
+     * @param shouldOutputThreadID
+     */
     void setShouldOutputThreadID(bool shouldOutputThreadID);
+
+    /**
+     * @brief Set whether to display timestamps with milliseconds
+     *
+     * @param shouldDisplayMilliseconds
+     */
     void setShouldDisplayMilliseconds(bool shouldDisplayMilliseconds);
 
+    /**
+     * @brief Set whether to use Journald, if it's available
+     *
+     * @param shouldUseJournald Whether to use journald
+     */
+    void setShouldUseJournald(bool shouldUseJournald);
+
+    /**
+     * @brief Whether Journald is available on this version/system.
+     *
+     * Support is available depending on compile options and only on Linux.
+     *
+     * @return true Journald is available
+     * @return false Journald is not available
+     */
+    bool isJournaldAvailable() const;
+
+    /**
+     * @brief Process a log message
+     *
+     * This writes it to a file, logs it to the console, or sends it to journald.
+     *
+     * @param type  Log message type
+     * @param context Context of the log message (source file, line, function)
+     * @param message Log message
+     * @return QString The log message's text with added severity and timestamp
+     */
     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
+     * @brief A qtMessageHandler that can be hooked up to a target that links to Qt
+     *
+     * Prints various process, message type, and time information
+     *
+     * @param type  Log message type
+     * @param context Context of the log message (source file, line, function)
+     * @param message Log message
+     */
     static void verboseMessageHandler(QtMsgType type, const QMessageLogContext& context, const QString &message);
 
     int newRepeatedMessageID();
@@ -89,6 +170,7 @@ private:
     bool _shouldDisplayMilliseconds { false };
     bool _useColor { false };
     bool _keepRepeats { false };
+    bool _useJournald { false };
 
     QString _previousMessage;
     int _repeatCount { 0 };