mirror of
https://github.com/qelectrotech/qelectrotech-source-mirror.git
synced 2026-08-13 18:14:13 +02:00
ff812f221a
Implements steps 1-3 of discussion #644 (deliberately not steps 4/5 -- no signal handler / crash flush, no diagnostics UI; see below). ## Step 1 -- fix the existing logger (bugs, no new behavior) - One QFile handle held open for the whole session under a mutex, instead of opening and closing the log file on every single message. - The log directory and the session's date-stamped filename are resolved exactly once, in the new QetLogger::init() called explicitly from main() immediately before qInstallMessageHandler() -- not recomputed per message, so a session that runs past midnight now stays in one file instead of silently splitting. - Age-based retention now uses lastModified() instead of lastRead(): opening a log to attach it to a bug report no longer resets its retention clock. - stderr and file output both encode UTF-8 explicitly (toUtf8()), replacing stderr's toLocal8Bit() and the file stream's previously Qt5/Qt6-inconsistent default encoding. ## Step 2 -- size-capped rotation + hardening - The previously-unbounded daily file is now capped at 2 MiB and rotated (kMaxFileBytes/kRotationKeep in QetLogger), keeping <date>.log plus <date>.1.log .. <date>.4.log; oldest is dropped. - Each message is truncated to 4 KB with a "...[truncated N bytes]" marker before it reaches the ring or the file. - Control characters (newlines, tabs, other non-printables) in message content are escaped, since much of what QET logs is externally controlled (file paths, element names, font strings out of a .qet file) -- left unescaped, an embedded '\n' could forge log lines. - The log file is refused if a symlink already exists at that path, and is created/rotated owner-read/write only. ## Step 3 -- in-memory ring buffer - LogRing (sources/logging/logring.h) is a fixed-capacity, always-on ring of the last 4096 log lines, preallocated once at construction (4096 * 512 B = 2 MiB) so append() never allocates. Entries are stored as plain pre-formatted bytes in fixed-size slots -- the shape discussion #644 specifies so a *future* crash handler could dump it with nothing but write(2), even though no such handler exists yet. Thread-safe via a plain QMutex (the lock-free requirement in the discussion applies specifically to a signal-handler read path, which this step doesn't add). ## Escape hatch QET_LOG_DISABLE=1 in the environment at startup bypasses all of the above -- no ring, no file, no rotation -- falling back to a minimal, self-contained stderr passthrough that doesn't share any code with the new formatting/sanitization path, so it stays usable even if that path is what's misbehaving. ## Deliberately not included (per the discussion's own phasing) - No signal handler / crash-time ring flush (step 4) -- the discussion flags this as the highest-risk piece, explicitly meant to land last and behind its own switch once the rest is proven. - No diagnostics export UI (step 5). - No log categories, session header, repeat collapsing or rate limiting -- listed under "best practices worth building in", not part of steps 1-3. ## Testing Built clean, no new warnings. Verified with real runs (QT_QPA_PLATFORM=offscreen, isolated HOME): - Log file created at the expected dataDir()/YYYYMMDD.log path, mode 0600. - A full startup's worth of real messages (translations, MachineInfo's system dump, collection loading) written correctly; every one of the 231 lines in one run starts with a proper timestamp -- confirmed the sanitizer correctly escapes the raw embedded newlines/tabs in MachineInfo's multi-line CPU/GPU description fields into visible \n/\t sequences rather than letting them fragment the log. - QET_LOG_DISABLE=1: zero log files created, stderr still worked via the independent legacy path. - Rotation: pre-filled a log to just under the 2 MiB cap, ran a normal session, confirmed it rotated to <date>.1.log (still 0600) with a byte-clean split (no truncated/duplicated line at the boundary) and a fresh <date>.log picked up from the next line.
336 lines
9.3 KiB
C++
336 lines
9.3 KiB
C++
/*
|
|
Copyright 2006-2026 The QElectroTech Team
|
|
This file is part of QElectroTech.
|
|
|
|
QElectroTech is free software: you can redistribute it and/or modify
|
|
it under the terms of the GNU General Public License as published by
|
|
the Free Software Foundation, either version 2 of the License, or
|
|
(at your option) any later version.
|
|
|
|
QElectroTech is distributed in the hope that it will be useful,
|
|
but WITHOUT ANY WARRANTY; without even the implied warranty of
|
|
MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
|
|
GNU General Public License for more details.
|
|
|
|
You should have received a copy of the GNU General Public License
|
|
along with QElectroTech. If not, see <http://www.gnu.org/licenses/>.
|
|
*/
|
|
#include "qetlogger.h"
|
|
|
|
#include "../qetapp.h"
|
|
|
|
#include <QDateTime>
|
|
#include <QDir>
|
|
#include <QFileInfo>
|
|
#include <cstdio>
|
|
|
|
namespace {
|
|
|
|
/**
|
|
@brief legacyStderrOutput
|
|
The QET_LOG_DISABLE=1 escape hatch. Deliberately independent of
|
|
every other function in this file -- including sanitize()/
|
|
formatLine(), which are exactly the new code a problem might be in
|
|
-- so this path stays usable even if the rest of the rework
|
|
misbehaves. No ring, no file, no rotation, no mutex.
|
|
*/
|
|
void legacyStderrOutput(QtMsgType type, const QMessageLogContext &context, const QString &msg)
|
|
{
|
|
const QByteArray local_msg = msg.toLocal8Bit();
|
|
const char *file = context.file ? context.file : "";
|
|
const char *function = context.function ? context.function : "";
|
|
|
|
const char *level = "Unknown";
|
|
switch (type) {
|
|
case QtDebugMsg: level = "Debug"; break;
|
|
case QtInfoMsg: level = "Info"; break;
|
|
case QtWarningMsg: level = "Warning"; break;
|
|
case QtCriticalMsg: level = "Critical"; break;
|
|
case QtFatalMsg: level = "Fatal"; break;
|
|
}
|
|
|
|
fprintf(stderr, "%s: %s (%s:%u, %s)\n",
|
|
level, local_msg.constData(), file, context.line, function);
|
|
}
|
|
|
|
/**
|
|
@brief ReentrancyGuard
|
|
Sets the referenced flag on construction, clears it on destruction
|
|
(including via early return / exception unwinding). Used as the
|
|
per-thread guard against the logger recursing into itself.
|
|
*/
|
|
struct ReentrancyGuard
|
|
{
|
|
bool &flag;
|
|
explicit ReentrancyGuard(bool &f) : flag(f) {flag = true;}
|
|
~ReentrancyGuard() {flag = false;}
|
|
};
|
|
|
|
} // namespace
|
|
|
|
/**
|
|
@brief QetLogger::instance
|
|
Function-local static: guaranteed constructed exactly once, in a
|
|
thread-safe way, on first use -- but the *meaningful* initialisation
|
|
(log path resolution, opening the file) happens in init(), called
|
|
explicitly from main() at a defined point, not implicitly on
|
|
whichever thread happens to log first.
|
|
*/
|
|
QetLogger &QetLogger::instance()
|
|
{
|
|
static QetLogger logger;
|
|
return logger;
|
|
}
|
|
|
|
void QetLogger::init()
|
|
{
|
|
m_disabled = (qgetenv("QET_LOG_DISABLE") == "1");
|
|
if (m_disabled) {
|
|
return;
|
|
}
|
|
|
|
m_log_dir = QETApp::dataDir();
|
|
m_base_name = QDate::currentDate().toString(QStringLiteral("yyyyMMdd"));
|
|
|
|
QMutexLocker locker(&m_file_mutex);
|
|
m_file_output_ok = ensureFileOpenLocked();
|
|
}
|
|
|
|
/**
|
|
@brief QetLogger::ensureFileOpenLocked
|
|
Caller must hold m_file_mutex. Opens the current session's log file
|
|
if not already open. Refuses to follow a pre-existing symlink at
|
|
that path, and creates the file owner-read/write only.
|
|
*/
|
|
bool QetLogger::ensureFileOpenLocked()
|
|
{
|
|
if (m_file.isOpen()) {
|
|
return true;
|
|
}
|
|
|
|
QDir().mkpath(m_log_dir);
|
|
|
|
const QString path = m_log_dir % QStringLiteral("/") % m_base_name % QStringLiteral(".log");
|
|
|
|
const QFileInfo info(path);
|
|
if (info.exists() && info.isSymLink()) {
|
|
// Filesystem hardening: refuse a pre-planted symlink rather than
|
|
// silently appending to whatever it points at.
|
|
return false;
|
|
}
|
|
|
|
m_file.setFileName(path);
|
|
if (!m_file.open(QIODevice::WriteOnly | QIODevice::Append)) {
|
|
return false;
|
|
}
|
|
m_file.setPermissions(QFileDevice::ReadOwner | QFileDevice::WriteOwner);
|
|
m_bytes_written_current_file = m_file.size();
|
|
return true;
|
|
}
|
|
|
|
QString QetLogger::rotatedPath(int index) const
|
|
{
|
|
return m_log_dir % QStringLiteral("/") % m_base_name % QStringLiteral(".") % QString::number(index) % QStringLiteral(".log");
|
|
}
|
|
|
|
/**
|
|
@brief QetLogger::rotateLocked
|
|
Caller must hold m_file_mutex. Shifts .3.log -> .4.log (dropping the
|
|
previous .4.log), .2.log -> .3.log, .1.log -> .2.log, .log -> .1.log,
|
|
then opens a fresh, empty current file.
|
|
*/
|
|
void QetLogger::rotateLocked()
|
|
{
|
|
m_file.close();
|
|
|
|
const QString base_path = m_log_dir % QStringLiteral("/") % m_base_name % QStringLiteral(".log");
|
|
|
|
for (int i = kRotationKeep; i >= 1; --i) {
|
|
const QString from = (i == 1) ? base_path : rotatedPath(i - 1);
|
|
const QString to = rotatedPath(i);
|
|
|
|
if (QFile::exists(to)) {
|
|
QFile::remove(to);
|
|
}
|
|
if (QFile::exists(from)) {
|
|
QFile::rename(from, to);
|
|
}
|
|
}
|
|
|
|
m_bytes_written_current_file = 0;
|
|
m_file_output_ok = ensureFileOpenLocked();
|
|
}
|
|
|
|
void QetLogger::writeToFile(const QByteArray &line, QtMsgType type)
|
|
{
|
|
QMutexLocker locker(&m_file_mutex);
|
|
|
|
if (!m_file_output_ok) {
|
|
// Write-failure policy: once file output has failed, stop
|
|
// attempting it rather than spin-retrying every message. The
|
|
// ring keeps running regardless.
|
|
return;
|
|
}
|
|
|
|
const qint64 written = m_file.write(line);
|
|
if (written != line.size()) {
|
|
m_file_output_ok = false;
|
|
m_file.close();
|
|
return;
|
|
}
|
|
m_bytes_written_current_file += written;
|
|
|
|
if (type >= QtWarningMsg) {
|
|
m_file.flush();
|
|
}
|
|
|
|
if (m_bytes_written_current_file >= kMaxFileBytes) {
|
|
rotateLocked();
|
|
}
|
|
}
|
|
|
|
/**
|
|
@brief QetLogger::sanitize
|
|
Escapes newlines, carriage returns and other control characters.
|
|
Much of what QET logs is externally controlled (file paths, element
|
|
names, font strings read out of a .qet file); left unescaped, a
|
|
crafted string containing '\n' can forge additional log lines.
|
|
Operates on already-UTF-8-encoded bytes: this is safe because UTF-8
|
|
continuation bytes are always >= 0x80, so any byte < 0x20 found here
|
|
is a genuine ASCII control character, never part of a multi-byte
|
|
sequence.
|
|
*/
|
|
QByteArray QetLogger::sanitize(const QByteArray &input)
|
|
{
|
|
QByteArray out;
|
|
out.reserve(input.size());
|
|
|
|
for (unsigned char c : input) {
|
|
if (c == '\n') {
|
|
out += "\\n";
|
|
} else if (c == '\r') {
|
|
out += "\\r";
|
|
} else if (c == '\t') {
|
|
out += static_cast<char>(c);
|
|
} else if (c < 0x20 || c == 0x7F) {
|
|
out += "\\x";
|
|
out += QByteArray::number(c, 16).rightJustified(2, '0');
|
|
} else {
|
|
out += static_cast<char>(c);
|
|
}
|
|
}
|
|
|
|
return out;
|
|
}
|
|
|
|
/**
|
|
@brief QetLogger::truncateMessage
|
|
Caps a single message at max_bytes, appending a marker stating how
|
|
many bytes were dropped, so one pathological caller (e.g. dumping an
|
|
entire XML document to qDebug()) can't consume an unbounded amount
|
|
of the ring's or file's byte budget.
|
|
*/
|
|
QByteArray QetLogger::truncateMessage(const QByteArray &input, int max_bytes)
|
|
{
|
|
if (input.size() <= max_bytes) {
|
|
return input;
|
|
}
|
|
|
|
const int dropped = input.size() - max_bytes;
|
|
QByteArray out = input.left(max_bytes);
|
|
out += " ...[truncated ";
|
|
out += QByteArray::number(dropped);
|
|
out += " bytes]";
|
|
return out;
|
|
}
|
|
|
|
QByteArray QetLogger::formatLine(QtMsgType type, const QMessageLogContext &context, const QByteArray &sanitized_msg)
|
|
{
|
|
// Includes the date (not just the time) so that a session crossing
|
|
// midnight -- now kept in a single file -- doesn't read as ambiguous.
|
|
const QByteArray timestamp = QDateTime::currentDateTime().toString(QStringLiteral("yyyy-MM-dd hh:mm:ss.zzz")).toUtf8();
|
|
|
|
const char *level = "Unknown";
|
|
switch (type) {
|
|
case QtDebugMsg: level = "Debug"; break;
|
|
case QtInfoMsg: level = "Info"; break;
|
|
case QtWarningMsg: level = "Warning"; break;
|
|
case QtCriticalMsg: level = "Critical"; break;
|
|
case QtFatalMsg: level = "Fatal"; break;
|
|
}
|
|
|
|
const char *file = context.file ? context.file : "";
|
|
const char *function = context.function ? context.function : "";
|
|
|
|
QByteArray line = timestamp;
|
|
line += ' ';
|
|
line += level;
|
|
line += ": ";
|
|
line += sanitized_msg;
|
|
|
|
if (type == QtInfoMsg) {
|
|
line += " \n";
|
|
} else {
|
|
line += " (";
|
|
line += file;
|
|
line += ":";
|
|
line += QByteArray::number(context.line ? context.line : 0);
|
|
line += ", ";
|
|
line += function;
|
|
line += ")\n";
|
|
}
|
|
|
|
return line;
|
|
}
|
|
|
|
void QetLogger::handleMessage(QtMsgType type, const QMessageLogContext &context, const QString &msg)
|
|
{
|
|
if (m_disabled) {
|
|
legacyStderrOutput(type, context, msg);
|
|
return;
|
|
}
|
|
|
|
static thread_local bool in_handler = false;
|
|
if (in_handler) {
|
|
// The logger itself triggered a message (e.g. from inside a Qt
|
|
// call it made) -- drop it rather than recurse.
|
|
return;
|
|
}
|
|
ReentrancyGuard guard(in_handler);
|
|
|
|
const QByteArray sanitized = truncateMessage(sanitize(msg.toUtf8()), kMaxMessageBytes);
|
|
const QByteArray line = formatLine(type, context, sanitized);
|
|
|
|
fwrite(line.constData(), 1, static_cast<size_t>(line.size()), stderr);
|
|
|
|
m_ring.append(line);
|
|
writeToFile(line, type);
|
|
}
|
|
|
|
void QetLogger::pruneOldLogFiles(int days)
|
|
{
|
|
if (m_disabled) {
|
|
return;
|
|
}
|
|
|
|
const QDate today = QDate::currentDate();
|
|
const QStringList filters = {
|
|
QStringLiteral("????????.log"), // base files, e.g. 20260803.log
|
|
QStringLiteral("????????.?.log"), // rotated files, e.g. 20260803.1.log
|
|
};
|
|
|
|
const QDir dir(m_log_dir);
|
|
const auto entries = dir.entryInfoList(filters, QDir::Files);
|
|
for (const QFileInfo &file_info : entries) {
|
|
if (!file_info.isFile()) {
|
|
continue;
|
|
}
|
|
// lastModified(), not lastRead(): reading the log (opening it to
|
|
// attach to a bug report, a backup job, an indexer) must not
|
|
// reset the retention clock and keep it alive indefinitely.
|
|
if (file_info.lastModified().date().daysTo(today) > days) {
|
|
QFile::remove(file_info.absoluteFilePath());
|
|
}
|
|
}
|
|
}
|