From 6bc731da54dbd7c8aa04bc80c8ebd3ec751f3f5c Mon Sep 17 00:00:00 2001 From: umutcagand <237324081+c8dhjp4tyv-bit@users.noreply.github.com> Date: Sat, 12 Sep 2026 10:01:54 +0300 Subject: [PATCH] fix(logs): read log4j event timestamps as milliseconds log4j's XMLLayout writes the event time in milliseconds since the epoch, but parseAttributes() handed it to QDateTime::fromSecsSinceEpoch(). Every entry in the Minecraft Log tab therefore carried an instant about 55000 years out, and once rendered as HH:mm:ss it showed a clock time with no relation to when the line was actually logged. The launcher's own sample log shows it plainly: the first two events of testdata/TestLogs/vanilla-1.21.5.xml.log are stamped 1745005148589 and 1745005150587, just under two seconds apart, which is also how far apart they are in the plain text capture of the same startup sequence. Read as seconds they land 33 minutes apart, in the year 57267. The added test compares instants rather than rendered clock times, so it does not depend on the time zone it runs in. Assisted-by: Claude Code:claude-opus-5 Signed-off-by: umutcagand <237324081+c8dhjp4tyv-bit@users.noreply.github.com> --- launcher/logs/LogParser.cpp | 3 ++- tests/XmlLogs_test.cpp | 35 +++++++++++++++++++++++++++++++++++ 2 files changed, 37 insertions(+), 1 deletion(-) diff --git a/launcher/logs/LogParser.cpp b/launcher/logs/LogParser.cpp index 13ff5f072..2c363a088 100644 --- a/launcher/logs/LogParser.cpp +++ b/launcher/logs/LogParser.cpp @@ -57,7 +57,8 @@ std::optional LogParser::parseAttributes() m_parser.raiseError("log4j:Event Missing required attribute: timestamp"); return {}; } - entry.timestamp = QDateTime::fromSecsSinceEpoch(value.trimmed().toLongLong()); + // log4j's XMLLayout reports the event time in milliseconds + entry.timestamp = QDateTime::fromMSecsSinceEpoch(value.trimmed().toLongLong()); } else if (name == "level"_L1) { entry.levelText = value.trimmed().toString(); entry.level = MessageLevel::fromName(entry.levelText); diff --git a/tests/XmlLogs_test.cpp b/tests/XmlLogs_test.cpp index 4df846e3e..f604f8be6 100644 --- a/tests/XmlLogs_test.cpp +++ b/tests/XmlLogs_test.cpp @@ -21,6 +21,7 @@ #include +#include #include #include #include @@ -50,6 +51,40 @@ class XmlLogParseTest : public QObject { MessageLevel::Error); } + void parseEventTimestamp() + { + // Taken verbatim from testdata/TestLogs/vanilla-1.21.5.xml.log. These two events sit just under + // two seconds apart, as they do in the plain text capture of the same startup sequence - read as + // seconds they would be 33 minutes apart, in the year 57267. + const QStringList lines = { + R"( )", + R"( )", + R"( )", + R"( )", + R"( )", + R"( )", + }; + + LogParser parser; + QList timestamps; + + for (const auto& line : lines) { + parser.appendLine(line); + + for (const auto& item : parser.parseAvailable()) { + QVERIFY(std::holds_alternative(item)); + timestamps.append(std::get(item).timestamp); + } + } + + QCOMPARE(timestamps.length(), 2); + // Comparing instants rather than rendered clock times keeps this independent of the time zone. + QCOMPARE(timestamps[0], QDateTime::fromMSecsSinceEpoch(1745005148589)); + QCOMPARE(timestamps[1], QDateTime::fromMSecsSinceEpoch(1745005150587)); + QCOMPARE(timestamps[0].toUTC().date(), QDate(2025, 4, 18)); + QCOMPARE(timestamps[0].msecsTo(timestamps[1]), 1998); + } + void parseXml_data() { QString source = QFINDTESTDATA("testdata/TestLogs");