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.
This commit is contained in:
Dale Glass 2022-06-22 22:18:41 +02:00
parent 4dec2d6430
commit e01f6e3049
3 changed files with 131 additions and 38 deletions

View file

@ -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>
@ -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<tracing::Tracer>();
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);

View file

@ -30,9 +30,11 @@
#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;
@ -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<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(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<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_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);

View file

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