From e01f6e30490ca5b333f112a584192594cc0af98f Mon Sep 17 00:00:00 2001 From: Dale Glass Date: Wed, 22 Jun 2022 22:18:41 +0200 Subject: [PATCH] Finish journald logging implementation This adds command-line arguments, disables it by default on interface, adds target logging, and can deal with variable numbers of fields. It also adds some documentation. --- interface/src/main.cpp | 34 +++++++-- libraries/shared/src/LogHandler.cpp | 111 ++++++++++++++++++++-------- libraries/shared/src/LogHandler.h | 24 +++++- 3 files changed, 131 insertions(+), 38 deletions(-) diff --git a/interface/src/main.cpp b/interface/src/main.cpp index e18312f8b7..a90c06df5a 100644 --- a/interface/src/main.cpp +++ b/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 @@ -45,7 +45,7 @@ int main(int argc, const char* argv[]) { auto format = getDefaultOpenGLSurfaceFormat(); // Deal with some weirdness in the chromium context sharing on Mac. // The primary share context needs to be 3.2, so that the Chromium will - // succeed in it's creation of it's command stub contexts. + // succeed in it's creation of it's command stub contexts. format.setVersion(3, 2); // This appears to resolve the issues with corrupted fonts on OSX. No // idea why. @@ -54,8 +54,8 @@ int main(int argc, const char* argv[]) { QSurfaceFormat::setDefaultFormat(format); #endif -#if defined(Q_OS_WIN) - // Check the minimum version of +#if defined(Q_OS_WIN) + // Check the minimum version of if (gl::getAvailableVersion() < gl::getRequiredVersion()) { MessageBoxA(nullptr, "Interface requires OpenGL 4.1 or higher", "Unsupported", MB_OK); return -1; @@ -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,15 @@ 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())) { + parser.showHelp(); + Q_UNREACHABLE(); + } + } + // Act on arguments for early termination. if (parser.isSet(versionOption)) { parser.showVersion(); @@ -356,7 +374,7 @@ int main(int argc, const char* argv[]) { } } - // Early check for --traceFile argument + // Early check for --traceFile argument auto tracer = DependencyManager::set(); const char * traceFile = nullptr; float traceDuration = 0.0f; @@ -370,7 +388,7 @@ int main(int argc, const char* argv[]) { return 1; } } - + PROFILE_SYNC_BEGIN(startup, "main startup", ""); #ifdef Q_OS_LINUX @@ -378,8 +396,8 @@ int main(int argc, const char* argv[]) { #endif #if defined(USE_GLES) && defined(Q_OS_WIN) - // When using GLES on Windows, we can't create normal GL context in Qt, so - // we force Qt to use angle. This will cause the QML to be unable to be used + // When using GLES on Windows, we can't create normal GL context in Qt, so + // we force Qt to use angle. This will cause the QML to be unable to be used // in the output window, so QML should be disabled. qputenv("QT_ANGLE_PLATFORM", "d3d11"); QCoreApplication::setAttribute(Qt::AA_UseOpenGLES); diff --git a/libraries/shared/src/LogHandler.cpp b/libraries/shared/src/LogHandler.cpp index 7fe90b76bc..b3dfecfc73 100644 --- a/libraries/shared/src/LogHandler.cpp +++ b/libraries/shared/src/LogHandler.cpp @@ -30,9 +30,11 @@ #include #include #include +#include #ifdef HAS_JOURNALD #include +#include #endif QRecursiveMutex LogHandler::_mutex; @@ -59,31 +61,7 @@ LogHandler::LogHandler() { _useJournald = true; #endif - 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(stdout, "Unrecognized option in VIRCADIA_LOG_OPTIONS: '%s'\n", option.toUtf8().constData()); - } - } + parseOptions(logOptions); } const char* stringForLogType(LogMsgType msgType) { @@ -128,12 +106,53 @@ const char* colorReset() { return "\u001b[0m"; } + +#ifdef HAS_JOURNALD +void addString(std::vector&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(QString logOptions) { + 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(stdout, "Unrecognized option in VIRCADIA_LOG_OPTIONS: '%s'\n", option.toUtf8().constData()); + return false; + } + } + + return true; +} + void LogHandler::setTargetName(const QString& targetName) { QMutexLocker lock(&_mutex); _targetName = targetName; @@ -154,6 +173,17 @@ 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; @@ -231,13 +261,30 @@ QString LogHandler::printMessage(LogMsgType type, const QMessageLogContext& cont case LogMsgType::LogDebug: priority = LOG_DEBUG; break; case LogMsgType::LogSuppressed: priority = LOG_DEBUG; break; default: - fprintf(stderr, "Unrecognized log type: %i", (int)type); + fprintf(stderr, "Unrecognized log type: %i\n", (int)type); } - size_t threadID = (size_t)QThread::currentThreadId(); - QString sd_file = QString("CODE_FILE=%1").arg(context.file); - QString sd_line = QString("CODE_LINE=%1").arg(context.line); + 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("TARGET=%1").arg(_targetName).toUtf8(); + + std::vector 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_send_with_location(sd_file.toUtf8().constData(), sd_line.toUtf8().constData(), context.function == NULL ? "(unknown)" : context.function, @@ -246,6 +293,12 @@ QString LogHandler::printMessage(LogMsgType type, const QMessageLogContext& cont "CATEGORY=%s", context.category, "TID=%i", threadID, NULL); +*/ + 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); diff --git a/libraries/shared/src/LogHandler.h b/libraries/shared/src/LogHandler.h index 54862e8e09..81ef0aff03 100644 --- a/libraries/shared/src/LogHandler.h +++ b/libraries/shared/src/LogHandler.h @@ -48,8 +48,20 @@ public: static LogHandler& getInstance(); /** - * @brief Set the Target Name to output via the verboseMessageHandler + * @brief Parse logging options * + * This parses the logging settings in the environment variable, or from the commandline + * + * @param options Option list + * @return true Option list was parsed successfully + * @return false There was an error + */ + bool parseOptions(QString options); + + /** + * @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 @@ -96,6 +108,16 @@ public: */ 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); /**