Files
qelectrotech-source-mirror/sources/logging/qetlogger.cpp
T
ispyisail 5dec36cb29 Add crash-time ring flush and a diagnostics export UI (discussion #644, steps 4-5)
Stacked on the steps 1-3 branch (feature-diagnostic-logging, PR #646).
Kept as its own PR rather than folded into that one, matching the
discussion's own framing: step 4 is explicitly "the highest-risk piece
... lands last, behind its own switch."

## Step 4 -- crash-time ring flush (CrashHandler)

Installs a handler for SIGSEGV/SIGABRT/SIGBUS/SIGFPE/SIGILL (POSIX) /
SetUnhandledExceptionFilter (Windows) that flushes the in-memory ring to
a fixed crash_dump.log before the process dies.

This required reworking LogRing (step 3) to be genuinely lock-free, not
just mutex-protected: a signal handler that blocks on a lock the
crashing thread (or another thread) already holds turns a clean crash
into a hang -- no ring dump *and* no core dump, worse than doing
nothing. append() now claims a slot with a single atomic fetch-add;
dumpToFd() reads the preallocated entries directly and writes them with
write(2) only, looping on EINTR/short writes. Accepted tradeoff: at most
one entry can be read torn if a crash lands mid-append into that exact
slot -- documented in logring.h, and the alternative (a seqlock to
detect and retry) wasn't judged worth the complexity for that window.

Other invariants implemented per the discussion:
- sigaltstack with a static 64 KiB buffer, SA_ONSTACK -- a stack-
  overflow SIGSEGV has no usable stack for a handler without one.
- Nothing under the actual handler touches Qt, QString or the
  allocator: the dump path and a small header (version/git/OS/Qt) are
  precomputed into fixed char buffers by install(), which runs once at
  startup in normal context.
- Atomic test-and-set so only the first crash writes a dump; a second
  concurrent/nested fault goes straight to restore-and-re-raise.
- After writing, the handler restores SIG_DFL and re-raises (POSIX) /
  returns EXCEPTION_CONTINUE_SEARCH (Windows) so the OS's own crash
  path -- core dump, Windows Error Reporting -- still runs. A handler
  that "fixed" the crash by swallowing the signal would destroy exactly
  the post-mortem evidence this whole design exists to preserve.

Tested in this environment: POSIX/Linux only, all five signals. Sent
each directly to a running process and confirmed (a) crash_dump.log is
written with the correct header and ring contents, mode 0600, and (b)
the process still terminates via the signal with the kernel's own
"core dumped" flag set (exit code 128+signal, confirmed for all five).
The Windows path is implemented per the discussion's guidance but is
untested -- no Windows build available in this sandbox.

## Step 5 -- getting the data back out

- QETApp::checkCrashDump(), called from checkBackupFiles() only when
  there's no stale project file to recover this run (so the two
  prompts never both show, per the discussion), offers an unretrieved
  crash dump via DiagnosticsReportDialog and then deletes it regardless
  of the user's choice -- offered exactly once.
- A new "Aide > Enregistrer un rapport de diagnostic..." action
  (QETMainWindow) builds the same kind of report from the *current*
  session (QetLogger::buildDiagnosticsReport(): header + this session's
  log file) for a manual "attach this to a bug report" flow, not tied
  to a crash.
- Both go through QetLogger::redact() before ever reaching the user:
  the one redaction implemented is a literal replace of the home
  directory with "~", since an absolute path under it leaks the
  account name. The discussion's fancier "optionally redact project
  filenames too" isn't attempted -- reliably telling a project path
  apart from arbitrary log text is a much fuzzier problem than a
  literal prefix match.
- DiagnosticsReportDialog shows the full (already-redacted) content
  before saving, per the discussion: "the user is about to attach this
  to a public tracker."

Verified in a real GUI session (Xvfb): triggered a SIGSEGV, relaunched,
confirmed the crash-report dialog appears with the right header/content,
confirmed it does not reappear on a second relaunch, and confirmed the
manual "Save report" action produces a correctly-formatted report and
saves it to a chosen path.

Built clean, no new warnings.

## Build systems

Registered in both: cmake/qet_compilation_vars.cmake, and
qelectrotech.pro. The .pro needed explicit globs for the new
sources/logging/ui/ subfolder -- sources/logging/*.{h,cpp} was already
globbed, but unlike the other ui/ subfolders that one had no entry of
its own, so diagnosticsreportdialog.{h,cpp} would not have been built
under qmake.
2026-08-06 23:04:27 +12:00

432 lines
12 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 "crashhandler.h"
#include "../qetapp.h"
#include "../qetversion.h"
#include <QDateTime>
#include <QDir>
#include <QFileInfo>
#include <QSysInfo>
#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();
}
void QetLogger::installCrashHandler()
{
if (m_disabled) {
return;
}
CrashHandler::install(&m_ring, crashDumpPath());
}
QString QetLogger::crashDumpPath() const
{
return m_log_dir % QStringLiteral("/crash_dump.log");
}
QString QetLogger::currentLogFilePath() const
{
return m_log_dir % QStringLiteral("/") % m_base_name % QStringLiteral(".log");
}
/**
@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 = currentLogFilePath();
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 = currentLogFilePath();
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());
}
}
}
// --- Step 5: getting the data back out ----------------------------------
bool QetLogger::hasPendingCrashDump() const
{
if (m_disabled) {
return false;
}
const QFileInfo info(crashDumpPath());
return info.exists() && info.isFile() && info.size() > 0;
}
QByteArray QetLogger::pendingCrashDumpContents() const
{
QFile file(crashDumpPath());
if (!file.open(QIODevice::ReadOnly)) {
return QByteArray();
}
return redact(file.readAll());
}
void QetLogger::clearPendingCrashDump()
{
QFile::remove(crashDumpPath());
}
QByteArray QetLogger::buildDiagnosticsReport() const
{
QByteArray header;
header += "QElectroTech diagnostics report\n";
header += "Generated: " % QDateTime::currentDateTime().toString(Qt::ISODate) % "\n";
header += "Version: " % QetVersion::displayedVersion() % "\n";
header += "Git: " GIT_COMMIT_SHA "\n";
header += "OS: " % QSysInfo::prettyProductName() % " (" % QSysInfo::currentCpuArchitecture() % ")\n";
header += "Qt: " QT_VERSION_STR "\n";
header += "---\n";
QByteArray body;
QFile file(currentLogFilePath());
if (file.open(QIODevice::ReadOnly)) {
body = file.readAll();
} else {
// Fall back to the in-memory ring if the file itself can't be
// read (e.g. file output already failed this session).
for (const QByteArray &line : m_ring.snapshot()) {
body += line;
}
}
return redact(header + body);
}
/**
@brief QetLogger::redact
Replaces the user's home directory with "~" wherever it appears.
Applied before a crash dump or a diagnostics report is ever shown to
the user: both are destined to be attached to a public bug tracker,
and an absolute path under the home directory leaks the account name
(discussion #644's privacy section: "/home/laurent/... leaks a
username"). This is the one redaction implemented here; the
discussion's fancier "optionally redact project filenames too" is
not attempted -- reliably telling a project path apart from
arbitrary log text is a much fuzzier problem than a literal prefix
match against a known directory.
*/
QByteArray QetLogger::redact(const QByteArray &input)
{
const QByteArray home = QDir::homePath().toUtf8();
if (home.isEmpty()) {
return input;
}
QByteArray out = input;
out.replace(home, QByteArrayLiteral("~"));
return out;
}