From bdbf5b9af998000773d49bfe00c3b52aa259229a Mon Sep 17 00:00:00 2001 From: outfoxxed Date: Fri, 9 Aug 2024 14:43:18 -0700 Subject: [PATCH] core/log: add custom log encoder for smaller log storage Will be used to store more detailed logs in the future without using as much disk space. --- CMakeLists.txt | 2 +- src/core/logging.cpp | 559 +++++++++++++++++++++++++++++++---- src/core/logging.hpp | 46 +-- src/core/logging_p.hpp | 123 ++++++++ src/core/main.cpp | 15 + src/core/ringbuf.hpp | 169 +++++++++++ src/core/test/CMakeLists.txt | 1 + src/core/test/ringbuf.cpp | 125 ++++++++ src/core/test/ringbuf.hpp | 27 ++ 9 files changed, 980 insertions(+), 87 deletions(-) create mode 100644 src/core/logging_p.hpp create mode 100644 src/core/ringbuf.hpp create mode 100644 src/core/test/ringbuf.cpp create mode 100644 src/core/test/ringbuf.hpp diff --git a/CMakeLists.txt b/CMakeLists.txt index c3b37603..b55c751f 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -6,7 +6,7 @@ set(CMAKE_CXX_STANDARD 20) set(CMAKE_CXX_STANDARD_REQUIRED ON) option(BUILD_TESTING "Build tests" OFF) -option(ASAN "Enable ASAN" OFF) +option(ASAN "Enable ASAN" OFF) # note: better output with gcc than clang option(FRAME_POINTERS "Always keep frame pointers" ${ASAN}) option(USE_JEMALLOC "Use jemalloc over the system malloc implementation" ON) diff --git a/src/core/logging.cpp b/src/core/logging.cpp index 642d3fc6..9271c07f 100644 --- a/src/core/logging.cpp +++ b/src/core/logging.cpp @@ -1,24 +1,86 @@ #include "logging.hpp" +#include #include -#include +#include +#include +#include +#include #include #include #include #include #include #include +#include #include #include #include #include +#include #include #include +#include "logging_p.hpp" #include "paths.hpp" +namespace qs::log { + Q_LOGGING_CATEGORY(logLogging, "quickshell.logging", QtWarningMsg); +bool LogMessage::operator==(const LogMessage& other) const { + // note: not including time + return this->type == other.type && this->category == other.category && this->body == other.body; +} + +size_t qHash(const LogMessage& message) { + return qHash(message.type) ^ qHash(message.category) ^ qHash(message.body); +} + +void LogMessage::formatMessage( + QTextStream& stream, + const LogMessage& msg, + bool color, + bool timestamp +) { + if (timestamp) { + if (color) stream << "\033[90m"; + stream << msg.time.toString("yyyy-MM-dd hh:mm:ss.zzz"); + } + + if (color) { + switch (msg.type) { + case QtDebugMsg: stream << "\033[34m DEBUG"; break; + case QtInfoMsg: stream << "\033[32m INFO"; break; + case QtWarningMsg: stream << "\033[33m WARN"; break; + case QtCriticalMsg: stream << "\033[31m ERROR"; break; + case QtFatalMsg: stream << "\033[31m FATAL"; break; + } + } else { + switch (msg.type) { + case QtDebugMsg: stream << " DEBUG"; break; + case QtInfoMsg: stream << " INFO"; break; + case QtWarningMsg: stream << " WARN"; break; + case QtCriticalMsg: stream << " ERROR"; break; + case QtFatalMsg: stream << " FATAL"; break; + } + } + + const auto isDefault = msg.category == "default"; + + if (color && !isDefault && msg.type != QtFatalMsg) stream << "\033[97m"; + + if (!isDefault) { + stream << ' ' << msg.category; + } + + if (color && msg.type != QtFatalMsg) stream << "\033[0m"; + + stream << ": " << msg.body; + + if (color && msg.type == QtFatalMsg) stream << "\033[0m"; +} + LogManager::LogManager() : colorLogs(qEnvironmentVariableIsEmpty("NO_COLOR")) , stdoutStream(stdout) {} @@ -28,11 +90,11 @@ void LogManager::messageHandler( const QMessageLogContext& context, const QString& msg ) { - auto message = LogMessage(type, context.category, msg.toUtf8()); + auto message = LogMessage(type, QLatin1StringView(context.category), msg.toUtf8()); auto* self = LogManager::instance(); - LogManager::formatMessage(self->stdoutStream, message, self->colorLogs, false); + LogMessage::formatMessage(self->stdoutStream, message, self->colorLogs, false); self->stdoutStream << Qt::endl; emit self->logMessage(message); @@ -64,50 +126,6 @@ void LogManager::initFs() { ); } -void LogManager::formatMessage( - QTextStream& stream, - const LogMessage& msg, - bool color, - bool timestamp -) { - if (timestamp) { - if (color) stream << "\033[90m"; - stream << msg.time.toString("yyyy-MM-dd hh:mm:ss.zzz"); - } - - if (color) { - switch (msg.type) { - case QtDebugMsg: stream << "\033[34m DEBUG"; break; - case QtInfoMsg: stream << "\033[32m INFO"; break; - case QtWarningMsg: stream << "\033[33m WARN"; break; - case QtCriticalMsg: stream << "\033[31m ERROR"; break; - case QtFatalMsg: stream << "\033[31m FATAL"; break; - } - } else { - switch (msg.type) { - case QtDebugMsg: stream << " DEBUG"; break; - case QtInfoMsg: stream << " INFO"; break; - case QtWarningMsg: stream << " WARN"; break; - case QtCriticalMsg: stream << " ERROR"; break; - case QtFatalMsg: stream << " FATAL"; break; - } - } - - const auto isDefault = strcmp(msg.category, "default") == 0; - - if (color && !isDefault && msg.type != QtFatalMsg) stream << "\033[97m"; - - if (!isDefault) { - stream << ' ' << msg.category; - } - - if (color && msg.type != QtFatalMsg) stream << "\033[0m"; - - stream << ": " << msg.body; - - if (color && msg.type == QtFatalMsg) stream << "\033[0m"; -} - void LoggingThreadProxy::initInThread() { this->logging = new ThreadLogging(this); this->logging->init(); @@ -116,17 +134,39 @@ void LoggingThreadProxy::initInThread() { void LoggingThreadProxy::initFs() { this->logging->initFs(); } void ThreadLogging::init() { - auto mfd = memfd_create("quickshell:logs", 0); + auto logMfd = memfd_create("quickshell:logs", 0); - if (mfd == -1) { + if (logMfd == -1) { qCCritical(logLogging) << "Failed to create memfd for initial log storage" << qt_error_string(-1); - return; } - this->file = new QFile(); - this->file->open(mfd, QFile::WriteOnly, QFile::AutoCloseHandle); - this->fileStream.setDevice(this->file); + auto dlogMfd = memfd_create("quickshell:detailedlogs", 0); + + if (dlogMfd == -1) { + qCCritical(logLogging) << "Failed to create memfd for initial detailed log storage" + << qt_error_string(-1); + } + + if (logMfd != -1) { + this->file = new QFile(); + this->file->open(logMfd, QFile::WriteOnly, QFile::AutoCloseHandle); + this->fileStream.setDevice(this->file); + } + + if (dlogMfd != -1) { + this->detailedFile = new QFile(); + // buffered by WriteBuffer + this->detailedFile->open(dlogMfd, QFile::WriteOnly | QFile::Unbuffered, QFile::AutoCloseHandle); + this->detailedWriter.setDevice(this->detailedFile); + + if (!this->detailedWriter.writeHeader()) { + qCCritical(logLogging) << "Could not write header for detailed logs."; + this->detailedWriter.setDevice(nullptr); + delete this->detailedFile; + this->detailedFile = nullptr; + } + } // This connection is direct so it works while the event loop is destroyed between // QCoreApplication delete and Q(Gui)Application launch. @@ -138,11 +178,11 @@ void ThreadLogging::init() { Qt::DirectConnection ); - qCDebug(logLogging) << "Created memfd" << mfd << "for early logs."; + qCDebug(logLogging) << "Created memfd" << logMfd << "for early logs."; + qCDebug(logLogging) << "Created memfd" << dlogMfd << "for early detailed logs."; } void ThreadLogging::initFs() { - qCDebug(logLogging) << "Starting filesystem logging..."; auto* runDir = QsPaths::instance()->instanceRunDir(); @@ -153,23 +193,62 @@ void ThreadLogging::initFs() { } auto path = runDir->filePath("log.log"); + auto detailedPath = runDir->filePath("log.qslog"); auto* file = new QFile(path); + auto* detailedFile = new QFile(detailedPath); if (!file->open(QFile::WriteOnly | QFile::Truncate)) { qCCritical(logLogging ) << "Could not start filesystem logger as the log file could not be created:" << path; - return; + delete file; + file = nullptr; + } + + // buffered by WriteBuffer + if (!detailedFile->open(QFile::WriteOnly | QFile::Truncate | QFile::Unbuffered)) { + qCCritical(logLogging + ) << "Could not start detailed filesystem logger as the log file could not be created:" + << detailedPath; + delete detailedFile; + detailedFile = nullptr; } qCDebug(logLogging) << "Copying memfd logs to log file..."; - auto* oldFile = this->file; - oldFile->seek(0); - sendfile(file->handle(), oldFile->handle(), nullptr, oldFile->size()); - this->file = file; - this->fileStream.setDevice(file); - delete oldFile; + if (file) { + auto* oldFile = this->file; + if (oldFile) { + oldFile->seek(0); + sendfile(file->handle(), oldFile->handle(), nullptr, oldFile->size()); + } + + this->file = file; + this->fileStream.setDevice(file); + delete oldFile; + } + + if (detailedFile) { + auto* oldFile = this->detailedFile; + if (oldFile) { + oldFile->seek(0); + sendfile(detailedFile->handle(), oldFile->handle(), nullptr, oldFile->size()); + } + + this->detailedFile = detailedFile; + this->detailedWriter.setDevice(detailedFile); + + if (!oldFile) { + if (!this->detailedWriter.writeHeader()) { + qCCritical(logLogging) << "Could not write header for detailed logs."; + this->detailedWriter.setDevice(nullptr); + delete this->detailedFile; + this->detailedFile = nullptr; + } + } + + delete oldFile; + } qCDebug(logLogging) << "Switched logging to disk logs."; @@ -189,6 +268,360 @@ void ThreadLogging::initFs() { void ThreadLogging::onMessage(const LogMessage& msg) { if (this->fileStream.device() == nullptr) return; - LogManager::formatMessage(this->fileStream, msg, false, true); + LogMessage::formatMessage(this->fileStream, msg, false, true); this->fileStream << Qt::endl; + + if (this->detailedWriter.write(msg)) { + this->detailedFile->flush(); + } else if (this->detailedFile != nullptr) { + qCCritical(logLogging) << "Detailed logger failed to write. Ending detailed logs."; + } } + +CompressedLogType compressedTypeOf(QtMsgType type) { + switch (type) { + case QtDebugMsg: return CompressedLogType::Debug; + case QtInfoMsg: return CompressedLogType::Info; + case QtWarningMsg: return CompressedLogType::Warn; + case QtCriticalMsg: + case QtFatalMsg: return CompressedLogType::Critical; + } +} + +QtMsgType typeOfCompressed(CompressedLogType type) { + switch (type) { + case CompressedLogType::Debug: return QtDebugMsg; + case CompressedLogType::Info: return QtInfoMsg; + case CompressedLogType::Warn: return QtWarningMsg; + case CompressedLogType::Critical: return QtCriticalMsg; + } +} + +void WriteBuffer::setDevice(QIODevice* device) { this->device = device; } +bool WriteBuffer::hasDevice() const { return this->device; } + +bool WriteBuffer::flush() { + auto written = this->device->write(this->buffer); + auto success = written == this->buffer.length(); + this->buffer.clear(); + return success; +} + +void WriteBuffer::writeBytes(const char* data, qsizetype length) { + this->buffer.append(data, length); +} + +void WriteBuffer::writeU8(quint8 data) { + this->writeBytes(reinterpret_cast(&data), 1); // NOLINT +} + +void WriteBuffer::writeU16(quint16 data) { + data = qToLittleEndian(data); + this->writeBytes(reinterpret_cast(&data), 2); // NOLINT +} + +void WriteBuffer::writeU32(quint32 data) { + data = qToLittleEndian(data); + this->writeBytes(reinterpret_cast(&data), 4); // NOLINT +} + +void WriteBuffer::writeU64(quint64 data) { + data = qToLittleEndian(data); + this->writeBytes(reinterpret_cast(&data), 8); // NOLINT +} + +void DeviceReader::setDevice(QIODevice* device) { this->device = device; } +bool DeviceReader::hasDevice() const { return this->device; } + +bool DeviceReader::readBytes(char* data, qsizetype length) { + return this->device->read(data, length) == length; +} + +qsizetype DeviceReader::peekBytes(char* data, qsizetype length) { + return this->device->peek(data, length); +} + +bool DeviceReader::skip(qsizetype length) { return this->device->skip(length) == length; } + +bool DeviceReader::readU8(quint8* data) { + return this->readBytes(reinterpret_cast(data), 1); // NOLINT +} + +bool DeviceReader::readU16(quint16* data) { + return this->readBytes(reinterpret_cast(data), 2); // NOLINT +} + +bool DeviceReader::readU32(quint32* data) { + return this->readBytes(reinterpret_cast(data), 4); // NOLINT +} + +bool DeviceReader::readU64(quint64* data) { + return this->readBytes(reinterpret_cast(data), 8); // NOLINT +} + +void EncodedLogWriter::setDevice(QIODevice* target) { this->buffer.setDevice(target); } +void EncodedLogReader::setDevice(QIODevice* source) { this->reader.setDevice(source); } + +constexpr quint8 LOG_VERSION = 1; + +bool EncodedLogWriter::writeHeader() { + this->buffer.writeU8(LOG_VERSION); + return this->buffer.flush(); +} + +bool EncodedLogReader::readHeader(bool* success, quint8* version, quint8* readerVersion) { + if (!this->reader.readU8(version)) return false; + *success = *version == LOG_VERSION; + *readerVersion = LOG_VERSION; + return true; +} + +bool EncodedLogWriter::write(const LogMessage& message) { + if (!this->buffer.hasDevice()) return false; + + LogMessage* prevMessage = nullptr; + auto index = this->recentMessages.indexOf(message, &prevMessage); + + // If its a dupe, save memory by reusing the buffer of the first message and letting + // the new one be deallocated. + auto body = prevMessage ? prevMessage->body : message.body; + this->recentMessages.emplace(message.type, message.category, body, message.time); + + if (index != -1) { + auto secondDelta = this->lastMessageTime.secsTo(message.time); + + if (secondDelta < 16 && index < 16) { + this->writeOp(EncodedLogOpcode::RecentMessageShort); + this->buffer.writeU8(index | (secondDelta << 4)); + } else { + this->writeOp(EncodedLogOpcode::RecentMessageLong); + this->buffer.writeU8(index); + this->writeVarInt(secondDelta); + } + + goto finish; + } else { + auto categoryId = this->getOrCreateCategory(message.category); + this->writeVarInt(categoryId); + + auto writeFullTimestamp = [this, &message]() { + this->buffer.writeU64(message.time.toSecsSinceEpoch()); + }; + + if (message.type == QtFatalMsg) { + this->buffer.writeU8(0xff); + writeFullTimestamp(); + } else { + quint8 field = compressedTypeOf(message.type); + + auto secondDelta = this->lastMessageTime.secsTo(message.time); + if (secondDelta > 29) { + // 0x1d = followed by delta int + // 0x1e = followed by epoch delta int + field |= (secondDelta < 0xffff ? 0x1d : 0x1e) << 3; + } else { + field |= secondDelta << 3; + } + + this->buffer.writeU8(field); + + if (secondDelta > 29) { + if (secondDelta > 0xffff) { + writeFullTimestamp(); + } else { + this->writeVarInt(secondDelta); + } + } + } + + this->writeString(message.body); + } + +finish: + // copy with second precision + this->lastMessageTime = QDateTime::fromSecsSinceEpoch(message.time.toSecsSinceEpoch()); + return this->buffer.flush(); +} + +bool EncodedLogReader::read(LogMessage* slot) { +start: + quint32 next = 0; + if (!this->readVarInt(&next)) return false; + + if (next < EncodedLogOpcode::BeginCategories) { + if (next == EncodedLogOpcode::RegisterCategory) { + if (!this->registerCategory()) return false; + goto start; + } else if (next == EncodedLogOpcode::RecentMessageShort || next == EncodedLogOpcode::RecentMessageLong) + { + quint8 index = 0; + quint32 secondDelta = 0; + + if (next == EncodedLogOpcode::RecentMessageShort) { + quint8 field = 0; + if (!this->reader.readU8(&field)) return false; + index = field & 0xf; + secondDelta = field >> 4; + } else { + if (!this->reader.readU8(&index)) return false; + if (!this->readVarInt(&secondDelta)) return false; + } + + *slot = this->recentMessages.at(index); + this->lastMessageTime = this->lastMessageTime.addSecs(static_cast(secondDelta)); + slot->time = this->lastMessageTime; + } + } else { + auto category = this->categories.value(next - EncodedLogOpcode::BeginCategories); + + quint8 field = 0; + if (!this->reader.readU8(&field)) return false; + + auto msgType = QtDebugMsg; + quint64 secondDelta = 0; + auto needsTimeRead = false; + + if (field == 0xff) { + msgType = QtFatalMsg; + needsTimeRead = true; + } else { + msgType = typeOfCompressed(static_cast(field & 0x07)); + secondDelta = field >> 3; + + if (secondDelta == 0x1d) { + quint32 slot = 0; + if (!this->readVarInt(&slot)) return false; + secondDelta = slot; + } else if (secondDelta == 0x1e) { + needsTimeRead = true; + } + } + + if (needsTimeRead) { + if (!this->reader.readU64(&secondDelta)) return false; + } + + this->lastMessageTime = this->lastMessageTime.addSecs(static_cast(secondDelta)); + + QByteArray body; + if (!this->readString(&body)) return false; + + *slot = LogMessage(msgType, QLatin1StringView(category), body, this->lastMessageTime); + } + + this->recentMessages.emplace(*slot); + return true; +} + +void EncodedLogWriter::writeOp(EncodedLogOpcode opcode) { this->buffer.writeU8(opcode); } + +void EncodedLogWriter::writeVarInt(quint32 n) { + if (n < 0xff) { + this->buffer.writeU8(n); + } else if (n < 0xffff) { + this->buffer.writeU8(0xff); + this->buffer.writeU16(n); + } else { + this->buffer.writeU8(0xff); + this->buffer.writeU16(0xffff); + this->buffer.writeU32(n); + } +} + +bool EncodedLogReader::readVarInt(quint32* slot) { + auto bytes = std::array(); + auto readLength = this->reader.peekBytes(reinterpret_cast(bytes.data()), 7); // NOLINT + + if (bytes[0] != 0xff && readLength >= 1) { + auto n = *reinterpret_cast(bytes.data()); // NOLINT + if (!this->reader.skip(1)) return false; + *slot = qFromLittleEndian(n); + } else if ((bytes[1] != 0xff || bytes[2] != 0xff) && readLength >= 3) { + auto n = *reinterpret_cast(bytes.data() + 1); // NOLINT + if (!this->reader.skip(3)) return false; + *slot = qFromLittleEndian(n); + } else if (readLength == 7) { + auto n = *reinterpret_cast(bytes.data() + 3); // NOLINT + if (!this->reader.skip(7)) return false; + *slot = qFromLittleEndian(n); + } else return false; + + return true; +} + +void EncodedLogWriter::writeString(QByteArrayView bytes) { + this->writeVarInt(bytes.length()); + this->buffer.writeBytes(bytes.constData(), bytes.length()); +} + +bool EncodedLogReader::readString(QByteArray* slot) { + quint32 length = 0; + if (!this->readVarInt(&length)) return false; + + *slot = QByteArray(length, Qt::Uninitialized); + auto r = this->reader.readBytes(slot->data(), slot->size()); + return r; +} + +quint16 EncodedLogWriter::getOrCreateCategory(QLatin1StringView category) { + if (this->categories.contains(category)) { + return this->categories.value(category); + } else { + this->writeOp(EncodedLogOpcode::RegisterCategory); + // id is implicitly the next available id + this->writeString(category); + + auto id = this->nextCategory++; + this->categories.insert(category, id); + + return id; + } +} + +bool EncodedLogReader::registerCategory() { + QByteArray name; + if (!this->readString(&name)) return false; + this->categories.append(name); + return true; +} + +bool readEncodedLogs(QIODevice* device) { + auto reader = EncodedLogReader(); + reader.setDevice(device); + + bool readable = false; + quint8 logVersion = 0; + quint8 readerVersion = 0; + if (!reader.readHeader(&readable, &logVersion, &readerVersion)) { + qCritical() << "Failed to read log header."; + return false; + } + + if (!readable) { + qCritical() << "This log was encoded with version" << logVersion + << "of the quickshell log encoder, which cannot be decoded by the current " + "version of quickshell, with log version" + << readerVersion; + return false; + } + + auto color = LogManager::instance()->colorLogs; + + LogMessage message; + auto stream = QTextStream(stdout); + while (reader.read(&message)) { + LogMessage::formatMessage(stream, message, color, true); + stream << '\n'; + } + + stream << Qt::flush; + + if (!device->atEnd()) { + qCritical() << "An error occurred parsing the end of this log file."; + qCritical() << "Remaining data:" << device->readAll(); + } + + return true; +} + +} // namespace qs::log diff --git a/src/core/logging.hpp b/src/core/logging.hpp index f831fcfa..6f4c970f 100644 --- a/src/core/logging.hpp +++ b/src/core/logging.hpp @@ -2,17 +2,22 @@ #include +#include #include -#include +#include +#include #include #include -#include #include +namespace qs::log { + struct LogMessage { + explicit LogMessage() = default; + explicit LogMessage( QtMsgType type, - const char* category, + QLatin1StringView category, QByteArray body, QDateTime time = QDateTime::currentDateTime() ) @@ -21,29 +26,19 @@ struct LogMessage { , category(category) , body(std::move(body)) {} - QtMsgType type; + bool operator==(const LogMessage& other) const; + + QtMsgType type = QtDebugMsg; QDateTime time; - const char* category; + QLatin1StringView category; QByteArray body; + + static void formatMessage(QTextStream& stream, const LogMessage& msg, bool color, bool timestamp); }; -class ThreadLogging: public QObject { - Q_OBJECT; +size_t qHash(const LogMessage& message); -public: - explicit ThreadLogging(QObject* parent): QObject(parent) {} - - void init(); - void initFs(); - void setupFileLogging(); - -private slots: - void onMessage(const LogMessage& msg); - -private: - QFile* file = nullptr; - QTextStream fileStream; -}; +class ThreadLogging; class LoggingThreadProxy: public QObject { Q_OBJECT; @@ -67,7 +62,7 @@ public: static void initFs(); static LogManager* instance(); - static void formatMessage(QTextStream& stream, const LogMessage& msg, bool color, bool timestamp); + bool colorLogs; signals: void logMessage(LogMessage msg); @@ -76,7 +71,12 @@ private: explicit LogManager(); static void messageHandler(QtMsgType type, const QMessageLogContext& context, const QString& msg); - bool colorLogs; QTextStream stdoutStream; LoggingThreadProxy threadProxy; }; + +bool readEncodedLogs(QIODevice* device); + +} // namespace qs::log + +using LogManager = qs::log::LogManager; diff --git a/src/core/logging_p.hpp b/src/core/logging_p.hpp new file mode 100644 index 00000000..0ac59dc1 --- /dev/null +++ b/src/core/logging_p.hpp @@ -0,0 +1,123 @@ +#pragma once +#include +#include +#include +#include +#include +#include + +#include "logging.hpp" +#include "ringbuf.hpp" + +namespace qs::log { + +enum EncodedLogOpcode : quint8 { + RegisterCategory = 0, + RecentMessageShort, + RecentMessageLong, + BeginCategories, +}; + +enum CompressedLogType : quint8 { + Debug = 0, + Info = 1, + Warn = 2, + Critical = 3, +}; + +CompressedLogType compressedTypeOf(QtMsgType type); +QtMsgType typeOfCompressed(CompressedLogType type); + +class WriteBuffer { +public: + void setDevice(QIODevice* device); + [[nodiscard]] bool hasDevice() const; + [[nodiscard]] bool flush(); + void writeBytes(const char* data, qsizetype length); + void writeU8(quint8 data); + void writeU16(quint16 data); + void writeU32(quint32 data); + void writeU64(quint64 data); + +private: + QIODevice* device = nullptr; + QByteArray buffer; +}; + +class DeviceReader { +public: + void setDevice(QIODevice* device); + [[nodiscard]] bool hasDevice() const; + [[nodiscard]] bool readBytes(char* data, qsizetype length); + // peek UP TO length + [[nodiscard]] qsizetype peekBytes(char* data, qsizetype length); + [[nodiscard]] bool skip(qsizetype length); + [[nodiscard]] bool readU8(quint8* data); + [[nodiscard]] bool readU16(quint16* data); + [[nodiscard]] bool readU32(quint32* data); + [[nodiscard]] bool readU64(quint64* data); + +private: + QIODevice* device = nullptr; +}; + +class EncodedLogWriter { +public: + void setDevice(QIODevice* target); + [[nodiscard]] bool writeHeader(); + [[nodiscard]] bool write(const LogMessage& message); + +private: + void writeOp(EncodedLogOpcode opcode); + void writeVarInt(quint32 n); + void writeString(QByteArrayView bytes); + quint16 getOrCreateCategory(QLatin1StringView category); + + WriteBuffer buffer; + + QHash categories; + quint16 nextCategory = EncodedLogOpcode::BeginCategories; + + QDateTime lastMessageTime = QDateTime::fromSecsSinceEpoch(0); + HashBuffer recentMessages {256}; +}; + +class EncodedLogReader { +public: + void setDevice(QIODevice* source); + [[nodiscard]] bool readHeader(bool* success, quint8* logVersion, quint8* readerVersion); + // WARNING: log messages written to the given slot are invalidated when the log reader is destroyed. + [[nodiscard]] bool read(LogMessage* slot); + +private: + [[nodiscard]] bool readVarInt(quint32* slot); + [[nodiscard]] bool readString(QByteArray* slot); + [[nodiscard]] bool registerCategory(); + + DeviceReader reader; + QVector categories; + QDateTime lastMessageTime = QDateTime::fromSecsSinceEpoch(0); + RingBuffer recentMessages {256}; +}; + +class ThreadLogging: public QObject { + Q_OBJECT; + +public: + explicit ThreadLogging(QObject* parent): QObject(parent) {} + + void init(); + void initFs(); + void setupFileLogging(); + +private slots: + void onMessage(const LogMessage& msg); + +private: + QFile* file = nullptr; + QTextStream fileStream; + QFile* detailedFile = nullptr; + EncodedLogWriter detailedWriter; +}; + +} // namespace qs::log diff --git a/src/core/main.cpp b/src/core/main.cpp index cc71f9fb..ad2b1a8d 100644 --- a/src/core/main.cpp +++ b/src/core/main.cpp @@ -61,6 +61,7 @@ int qs_main(int argc, char** argv) { auto workdirOption = QCommandLineOption({"d", "workdir"}, "Initial working directory.", "path"); auto debugPortOption = QCommandLineOption("debugport", "Enable the QML debugger.", "port"); auto debugWaitOption = QCommandLineOption("waitfordebug", "Wait for debugger connection before launching."); + auto readLogOption = QCommandLineOption("read-log", "Read a quickshell log file to stdout.", "path"); // clang-format on parser.addOption(currentOption); @@ -70,8 +71,22 @@ int qs_main(int argc, char** argv) { parser.addOption(workdirOption); parser.addOption(debugPortOption); parser.addOption(debugWaitOption); + parser.addOption(readLogOption); parser.process(app); + auto logOption = parser.value(readLogOption); + if (!logOption.isEmpty()) { + auto file = QFile(logOption); + if (!file.open(QFile::ReadOnly)) { + qCritical() << "Failed to open log for reading:" << logOption; + return -1; + } else { + qInfo() << "Reading log" << logOption; + } + + return qs::log::readEncodedLogs(&file) ? 0 : -1; + } + auto debugPortStr = parser.value(debugPortOption); if (!debugPortStr.isEmpty()) { auto ok = false; diff --git a/src/core/ringbuf.hpp b/src/core/ringbuf.hpp new file mode 100644 index 00000000..a50a56da --- /dev/null +++ b/src/core/ringbuf.hpp @@ -0,0 +1,169 @@ +#pragma once + +#include +#include +#include + +#include +#include +#include +#include + +// NOLINTBEGIN(cppcoreguidelines-pro-bounds-pointer-arithmetic) + +// capacity 0 buffer cannot be inserted into, only replaced with = +// this is NOT exception safe for constructors +template +class RingBuffer { +public: + explicit RingBuffer() = default; + explicit RingBuffer(qsizetype capacity): mCapacity(capacity) { + if (capacity > 0) this->createData(); + } + + ~RingBuffer() { this->deleteData(); } + + Q_DISABLE_COPY(RingBuffer); + + explicit RingBuffer(RingBuffer&& other) noexcept { *this = std::move(other); } + + RingBuffer& operator=(RingBuffer&& other) noexcept { + this->deleteData(); + this->data = other.data; + this->head = other.head; + this->mSize = other.mSize; + this->mCapacity = other.mCapacity; + other.data = nullptr; + other.head = -1; + return *this; + } + + // undefined if capacity is 0 + template + T& emplace(Args&&... args) { + auto i = (this->head + 1) % this->mCapacity; + + if (this->indexIsAllocated(i)) { + this->data[i].~T(); + } + + auto* slot = &this->data[i]; + new (&this->data[i]) T(std::forward(args)...); + + this->head = i; + if (this->mSize != this->mCapacity) this->mSize = i + 1; + + return *slot; + } + + void clear() { + if (this->head == -1) return; + + auto i = this->head; + + do { + i = (i + 1) % this->mSize; + this->data[i].~T(); + } while (i != this->head); + + this->mSize = 0; + this->head = -1; + } + + // negative indexes and >size indexes are undefined + [[nodiscard]] T& at(qsizetype i) { + auto bufferI = (this->head - i) % this->mCapacity; + if (bufferI < 0) bufferI += this->mCapacity; + return this->data[bufferI]; + } + + [[nodiscard]] const T& at(qsizetype i) const { + return const_cast*>(this)->at(i); // NOLINT + } + + [[nodiscard]] qsizetype size() const { return this->mSize; } + [[nodiscard]] qsizetype capacity() const { return this->mCapacity; } + +private: + void createData() { + if (this->data != nullptr) return; + this->data = + static_cast(::operator new(this->mCapacity * sizeof(T), std::align_val_t {alignof(T)})); + } + + void deleteData() { + this->clear(); + ::operator delete(this->data, std::align_val_t {alignof(T)}); + this->data = nullptr; + } + + bool indexIsAllocated(qsizetype index) { + return this->mSize == this->mCapacity || index <= this->head; + } + + T* data = nullptr; + qsizetype mCapacity = 0; + qsizetype head = -1; + qsizetype mSize = 0; +}; + +// ring buffer with the ability to look up elements by hash (single bucket) +template +class HashBuffer { +public: + explicit HashBuffer() = default; + explicit HashBuffer(qsizetype capacity): ring(capacity) {} + ~HashBuffer() = default; + + Q_DISABLE_COPY(HashBuffer); + explicit HashBuffer(HashBuffer&& other) noexcept: ring(other.ring) {} + + HashBuffer& operator=(HashBuffer&& other) noexcept { + this->ring = other.ring; + return *this; + } + + // returns the index of the given value or -1 if missing + [[nodiscard]] qsizetype indexOf(const T& value, T** slot = nullptr) { + auto hash = qHash(value); + + for (auto i = 0; i < this->size(); i++) { + auto& v = this->ring.at(i); + if (hash == v.first && value == v.second) { + if (slot != nullptr) *slot = &v.second; + return i; + } + } + + return -1; + } + + [[nodiscard]] qsizetype indexOf(const T& value, T const** slot = nullptr) const { + return const_cast*>(this)->indexOf(value, slot); // NOLINT + } + + template + T& emplace(Args&&... args) { + auto& entry = this->ring.emplace( + std::piecewise_construct, + std::forward_as_tuple(0), + std::forward_as_tuple(std::forward(args)...) + ); + + entry.first = qHash(entry.second); + return entry.second; + } + + void clear() { this->ring.clear(); } + + // negative indexes and >size indexes are undefined + [[nodiscard]] T& at(qsizetype i) { return this->ring.at(i).second; } + [[nodiscard]] const T& at(qsizetype i) const { return this->ring.at(i).second; } + [[nodiscard]] qsizetype size() const { return this->ring.size(); } + [[nodiscard]] qsizetype capacity() const { return this->ring.capacity(); } + +private: + RingBuffer> ring; +}; + +// NOLINTEND(cppcoreguidelines-pro-bounds-pointer-arithmetic) diff --git a/src/core/test/CMakeLists.txt b/src/core/test/CMakeLists.txt index d0191ee9..3c057d3b 100644 --- a/src/core/test/CMakeLists.txt +++ b/src/core/test/CMakeLists.txt @@ -6,3 +6,4 @@ endfunction() qs_test(popupwindow popupwindow.cpp) qs_test(transformwatcher transformwatcher.cpp) +qs_test(ringbuffer ringbuf.cpp) diff --git a/src/core/test/ringbuf.cpp b/src/core/test/ringbuf.cpp new file mode 100644 index 00000000..4f114796 --- /dev/null +++ b/src/core/test/ringbuf.cpp @@ -0,0 +1,125 @@ +#include "ringbuf.hpp" +#include + +#include +#include +#include +#include + +#include "../ringbuf.hpp" + +TestObject::TestObject(quint32* count): count(count) { + (*this->count)++; + qDebug() << "Created TestObject" << this << "- count is now" << *this->count; +} + +TestObject::~TestObject() { + (*this->count)--; + qDebug() << "Destroyed TestObject" << this << "- count is now" << *this->count; +} + +void TestRingBuffer::fill() { + quint32 counter = 0; + auto rb = RingBuffer(3); + QCOMPARE(rb.capacity(), 3); + + qInfo() << "adding test objects"; + auto* n1 = &rb.emplace(&counter); + auto* n2 = &rb.emplace(&counter); + auto* n3 = &rb.emplace(&counter); + QCOMPARE(counter, 3); + QCOMPARE(rb.size(), 3); + QCOMPARE(&rb.at(0), n3); + QCOMPARE(&rb.at(1), n2); + QCOMPARE(&rb.at(2), n1); + + qInfo() << "replacing last object with new one"; + auto* n4 = &rb.emplace(&counter); + QCOMPARE(counter, 3); + QCOMPARE(rb.size(), 3); + QCOMPARE(&rb.at(0), n4); + QCOMPARE(&rb.at(1), n3); + QCOMPARE(&rb.at(2), n2); + + qInfo() << "replacing the rest"; + auto* n5 = &rb.emplace(&counter); + auto* n6 = &rb.emplace(&counter); + QCOMPARE(counter, 3); + QCOMPARE(rb.size(), 3); + QCOMPARE(&rb.at(0), n6); + QCOMPARE(&rb.at(1), n5); + QCOMPARE(&rb.at(2), n4); + + qInfo() << "clearing buffer"; + rb.clear(); + QCOMPARE(counter, 0); + QCOMPARE(rb.size(), 0); +} + +void TestRingBuffer::clearPartial() { + quint32 counter = 0; + auto rb = RingBuffer(2); + + qInfo() << "adding object to buffer"; + auto* n1 = &rb.emplace(&counter); + QCOMPARE(counter, 1); + QCOMPARE(rb.size(), 1); + QCOMPARE(&rb.at(0), n1); + + qInfo() << "clearing buffer"; + rb.clear(); + QCOMPARE(counter, 0); + QCOMPARE(rb.size(), 0); +} + +void TestRingBuffer::move() { + quint32 counter = 0; + + { + auto rb1 = RingBuffer(1); + + qInfo() << "adding object to first buffer"; + auto* n1 = &rb1.emplace(&counter); + QCOMPARE(counter, 1); + QCOMPARE(rb1.size(), 1); + QCOMPARE(&rb1.at(0), n1); + + qInfo() << "move constructing new buffer"; + auto rb2 = RingBuffer(std::move(rb1)); + QCOMPARE(counter, 1); + QCOMPARE(rb2.size(), 1); + QCOMPARE(&rb2.at(0), n1); + + qInfo() << "move assigning new buffer"; + auto rb3 = RingBuffer(); + rb3 = std::move(rb2); + QCOMPARE(counter, 1); + QCOMPARE(rb3.size(), 1); + QCOMPARE(&rb3.at(0), n1); + } + + QCOMPARE(counter, 0); +} + +void TestRingBuffer::hashLookup() { + auto hb = HashBuffer(3); + + qInfo() << "inserting 1,2,3 into HashBuffer"; + hb.emplace(1); + hb.emplace(2); + hb.emplace(3); + + qInfo() << "checking lookups"; + QCOMPARE(hb.indexOf(3), 0); + QCOMPARE(hb.indexOf(2), 1); + QCOMPARE(hb.indexOf(1), 2); + + qInfo() << "adding 4"; + hb.emplace(4); + QCOMPARE(hb.indexOf(4), 0); + QCOMPARE(hb.indexOf(3), 1); + QCOMPARE(hb.indexOf(2), 2); + QCOMPARE(hb.indexOf(1), -1); +} + +QTEST_MAIN(TestRingBuffer); diff --git a/src/core/test/ringbuf.hpp b/src/core/test/ringbuf.hpp new file mode 100644 index 00000000..1413031c --- /dev/null +++ b/src/core/test/ringbuf.hpp @@ -0,0 +1,27 @@ +#pragma once + +#include +#include +#include +#include + +class TestObject { +public: + explicit TestObject(quint32* count); + ~TestObject(); + Q_DISABLE_COPY_MOVE(TestObject); + +private: + quint32* count; +}; + +class TestRingBuffer: public QObject { + Q_OBJECT; + +private slots: + static void fill(); + static void clearPartial(); + static void move(); + + static void hashLookup(); +};