Skip to content

Commit

Permalink
feat(Debug): Allow user to limit the copied log size.
Browse files Browse the repository at this point in the history
We usually don't need a very long history to debug issues. This protects
us from having to look at unnecessarily old logs and protects users from
sharing too much of their activity history.

The default of 1000 is chosen generously because it'll likely be limited
by log line age first. The 1000 protects us from enormous logs.
  • Loading branch information
iphydf committed Jan 26, 2025
1 parent 464939a commit 18b68db
Show file tree
Hide file tree
Showing 64 changed files with 1,366 additions and 141 deletions.
76 changes: 31 additions & 45 deletions src/appmanager.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,7 @@
#include "appmanager.h"

#include "src/ipc.h"
#include "src/model/debug/debuglogmodel.h"
#include "src/net/toxuri.h"
#include "src/net/updatecheck.h"
#include "src/nexus.h"
Expand Down Expand Up @@ -33,8 +34,8 @@ namespace {
// inability to register a void* to get back to a class
#ifdef LOG_TO_FILE
QAtomicPointer<FILE> logFileFile = nullptr;
QList<QByteArray>* logBuffer = new QList<QByteArray>(); // Store log messages until log file opened
QMutex* logBufferMutex = new QMutex();
auto logBuffer = std::make_unique<QList<QByteArray>>(); // Store log messages until log file opened
auto logBufferMutex = std::make_unique<QMutex>();
#endif

constexpr std::string_view sourceRootPath()
Expand Down Expand Up @@ -113,62 +114,47 @@ void logMessageHandler(QtMsgType type, const QMessageLogContext& ctxt, const QSt
}

// Time should be in UTC to save user privacy on log sharing
const QTime time = QDateTime::currentDateTime().toUTC().time();
QString logPrefix =
QStringLiteral("[%1 UTC] (%2) %3:%4 : ")
.arg(time.toString("HH:mm:ss.zzz"), category, file, QString::number(ctxt.line));
switch (type) {
case QtDebugMsg:
logPrefix += "Debug";
break;
case QtInfoMsg:
logPrefix += "Info";
break;
case QtWarningMsg:
logPrefix += "Warning";
break;
case QtCriticalMsg:
logPrefix += "Critical";
break;
case QtFatalMsg:
logPrefix += "Fatal";
break;
default:
break;
}
const QDateTime now = QDateTime::currentDateTime().toUTC();

QString logMsg;
for (const auto& line : msg.split('\n')) {
logMsg += logPrefix + ": " + canonicalLogMessage(line) + "\n";
logMsg += DebugLogModel::render({
-1,
now,
category,
file,
ctxt.line,
type,
canonicalLogMessage(line),
});
logMsg += '\n';
}

const QByteArray LogMsgBytes = logMsg.toUtf8();
fwrite(LogMsgBytes.constData(), 1, LogMsgBytes.size(), stderr);
const QByteArray logMsgBytes = logMsg.toUtf8();
fwrite(logMsgBytes.constData(), 1, logMsgBytes.size(), stderr);

#ifdef LOG_TO_FILE
FILE* logFilePtr = logFileFile.loadRelaxed(); // atomically load the file pointer
FILE* const logFilePtr = logFileFile.loadRelaxed(); // atomically load the file pointer
if (logFilePtr == nullptr) {
logBufferMutex->lock();
if (logBuffer != nullptr)
logBuffer->append(LogMsgBytes);

logBufferMutex->unlock();
} else {
logBufferMutex->lock();
const QMutexLocker<QMutex> locker(logBufferMutex.get());
if (logBuffer != nullptr) {
// empty logBuffer to file
for (const QByteArray& bufferedMsg : *logBuffer) {
fwrite(bufferedMsg.constData(), 1, bufferedMsg.size(), logFilePtr);
}
logBuffer->append(logMsgBytes);
}
return;
}

delete logBuffer; // no longer needed
logBuffer = nullptr;
const QMutexLocker<QMutex> locker(logBufferMutex.get());
if (logBuffer != nullptr) {
// empty logBuffer to file
for (const QByteArray& bufferedMsg : *logBuffer) {
fwrite(bufferedMsg.constData(), 1, bufferedMsg.size(), logFilePtr);
}
logBufferMutex->unlock();

fwrite(LogMsgBytes.constData(), 1, LogMsgBytes.size(), logFilePtr);
fflush(logFilePtr);
logBuffer = nullptr; // no longer needed
}

fwrite(logMsgBytes.constData(), 1, logMsgBytes.size(), logFilePtr);
fflush(logFilePtr);
#endif
}

Expand Down
72 changes: 46 additions & 26 deletions src/model/debug/debuglogmodel.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -4,10 +4,15 @@

#include "debuglogmodel.h"

#include "util/ranges.h"

#include <QColor>
#include <QRegularExpression>

namespace {
const QString timeFormat = QStringLiteral("HH:mm:ss.zzz");
const QString dateTimeFormat = QStringLiteral("yyyy-MM-dd HH:mm:ss.zzz");

QtMsgType parseMsgType(const QString& type)
{
if (type == "Debug") {
Expand Down Expand Up @@ -47,7 +52,27 @@ QString renderMsgType(QtMsgType type)
return QStringLiteral("Unknown");
}

QList<DebugLogModel::LogEntry> parse(const QStringList& logs)
bool filterAccepts(DebugLogModel::Filter filter, QtMsgType type)
{
switch (filter) {
case DebugLogModel::All:
return true;
case DebugLogModel::Debug:
return type == QtDebugMsg;
case DebugLogModel::Info:
return type == QtInfoMsg;
case DebugLogModel::Warning:
return type == QtWarningMsg;
case DebugLogModel::Critical:
return type == QtCriticalMsg;
case DebugLogModel::Fatal:
return type == QtFatalMsg;
}
return false;
}
} // namespace

QList<DebugLogModel::LogEntry> DebugLogModel::parse(const QStringList& logs)
{
// Regex extraction of log entry
// [12:35:16.634 UTC] (default) src/core/core.cpp:370 : Debug: Connected to a TCP relay
Expand All @@ -56,17 +81,29 @@ QList<DebugLogModel::LogEntry> parse(const QStringList& logs)
static const QRegularExpression re(
R"(\[([0-9:.]*) UTC\](?: \(([^)]*)\))? (.*?):(\d+) : ([^:]+): (.*))");

// Assume the last log entry is today.
const QDateTime now = QDateTime::currentDateTime().toUTC();
QDate lastDate = now.date();
QTime lastTime = now.time();

QList<DebugLogModel::LogEntry> result;
for (const QString& log : logs) {
for (const QString& log : qtox::views::reverse(logs)) {
const auto match = re.match(log);
if (!match.hasMatch()) {
qWarning() << "Failed to parse log entry:" << log;
continue;
}

// Reconstruct the likely date of the log entry.
const QTime entryTime = QTime::fromString(match.captured(1), timeFormat);
if (entryTime > lastTime) {
lastDate = lastDate.addDays(-1);
}
lastTime = entryTime;

DebugLogModel::LogEntry entry;
entry.index = result.size();
entry.time = match.captured(1);
entry.time = QDateTime{lastDate, entryTime};
entry.category = match.captured(2);
if (entry.category.isEmpty()) {
entry.category = QStringLiteral("default");
Expand All @@ -77,36 +114,19 @@ QList<DebugLogModel::LogEntry> parse(const QStringList& logs)
entry.message = match.captured(6);
result.append(entry);
}

std::reverse(result.begin(), result.end());
return result;
}

QString render(const DebugLogModel::LogEntry& entry)
QString DebugLogModel::render(const DebugLogModel::LogEntry& entry, bool includeDate)
{
return QStringLiteral("[%1 UTC] (%2) %3:%4 : %5: %6")
.arg(entry.time, entry.category, entry.file, QString::number(entry.line),
renderMsgType(entry.type), entry.message);
.arg(includeDate ? entry.time.toString(dateTimeFormat) : entry.time.toString(timeFormat),
entry.category, entry.file, QString::number(entry.line), renderMsgType(entry.type),
entry.message);
}

bool filterAccepts(DebugLogModel::Filter filter, QtMsgType type)
{
switch (filter) {
case DebugLogModel::All:
return true;
case DebugLogModel::Debug:
return type == QtDebugMsg;
case DebugLogModel::Info:
return type == QtInfoMsg;
case DebugLogModel::Warning:
return type == QtWarningMsg;
case DebugLogModel::Critical:
return type == QtCriticalMsg;
case DebugLogModel::Fatal:
return type == QtFatalMsg;
}
return false;
}
} // namespace

DebugLogModel::DebugLogModel(QObject* parent)
: QAbstractListModel(parent)
{
Expand Down
18 changes: 17 additions & 1 deletion src/model/debug/debuglogmodel.h
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,7 @@
#pragma once

#include <QAbstractListModel>
#include <QDateTime>
#include <QLoggingCategory>

class DebugLogModel : public QAbstractListModel
Expand All @@ -29,7 +30,7 @@ class DebugLogModel : public QAbstractListModel
/// Index in the original log list.
int index;

QString time;
QDateTime time;
QString category;
QString file;
int line;
Expand All @@ -52,6 +53,21 @@ class DebugLogModel : public QAbstractListModel
*/
int originalIndex(const QModelIndex& index) const;

/**
* @brief Parse a list of log lines into LogEntry objects.
*/
static QList<LogEntry> parse(const QStringList& logs);

/**
* @brief Render a LogEntry object into a string.
*/
static QString render(const LogEntry& entry, bool includeDate = false);

static QString renderWithDate(const LogEntry& entry)
{
return render(entry, true);
}

private:
void recomputeFilter();

Expand Down
1 change: 0 additions & 1 deletion src/widget/form/debug/debuglog.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -94,7 +94,6 @@ DebugLogForm::~DebugLogForm()

void DebugLogForm::showEvent(QShowEvent* event)
{
qDebug() << "Loading logs for debug log view";
debugLogModel_->reload(loadLogs(paths_));

GenericForm::showEvent(event);
Expand Down
51 changes: 32 additions & 19 deletions src/widget/form/settings/advancedform.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -7,11 +7,13 @@

#include "ui_advancedsettings.h"

#include "src/model/debug/debuglogmodel.h"
#include "src/persistence/profile.h"
#include "src/persistence/settings.h"
#include "src/widget/tool/imessageboxmanager.h"
#include "src/widget/tool/recursivesignalblocker.h"
#include "src/widget/translator.h"
#include "util/fileutil.h"

#include <QApplication>
#include <QClipboard>
Expand All @@ -20,6 +22,10 @@
#include <QMessageBox>
#include <QProcess>

#include <QtCore/qcontainerfwd.h>
#include <QtCore/qlogging.h>
#include <algorithm>

/**
* @class AdvancedForm
*
Expand Down Expand Up @@ -120,29 +126,36 @@ void AdvancedForm::on_btnCopyDebug_clicked()
const QString logFileDir = settings.getPaths().getAppCacheDirPath();
const QString logfile = logFileDir + "qtox.log";

QFile file(logfile);
if (!file.exists()) {
qDebug() << "No debug file found";
QClipboard* clipboard = QApplication::clipboard();
if (clipboard == nullptr) {
qDebug() << "Unable to access clipboard";
return;
}

QClipboard* clipboard = QApplication::clipboard();
if (clipboard != nullptr) {
QString debugtext;
if (file.open(QIODevice::ReadOnly | QIODevice::Text)) {
QTextStream in(&file);
debugtext = in.readAll();
file.close();
} else {
qDebug() << "Unable to open file for copying to clipboard";
return;
}

clipboard->setText(debugtext, QClipboard::Clipboard);
qDebug() << "Debug log copied to clipboard";
} else {
qDebug() << "Unable to access clipboard";
// Maximum number of lines to copy to clipboard.
const int maxDebugLogLines = bodyUI->maxLogLines->value();
const QStringList lines = FileUtil::tail(logfile, maxDebugLogLines);

if (lines.isEmpty()) {
return;
}

// Parse the log entries and remove entries that are too old.
QList<DebugLogModel::LogEntry> logEntries = DebugLogModel::parse(lines);
std::reverse(logEntries.begin(), logEntries.end());
const QDateTime now = QDateTime::currentDateTimeUtc();
const int maxDebugLogAge =
bodyUI->maxLogAge->time().hour() * 3600 + bodyUI->maxLogAge->time().minute() * 60;
while (!logEntries.isEmpty() && logEntries.last().time.secsTo(now) > maxDebugLogAge) {
logEntries.removeLast();
}

QStringList debugText;
std::transform(logEntries.rbegin(), logEntries.rend(), std::back_inserter(debugText),
DebugLogModel::renderWithDate);

clipboard->setText(debugText.join('\n'), QClipboard::Clipboard);
qDebug() << "Copied" << debugText.size() << "debug log entries to clipboard";
}

void AdvancedForm::on_resetButton_clicked()
Expand Down
Loading

0 comments on commit 18b68db

Please sign in to comment.