diff options
| author | Danilo M. <danix@danix.xyz> | 2026-08-07 11:39:31 +0200 |
|---|---|---|
| committer | Danilo M. <danix@danix.xyz> | 2026-08-07 11:39:31 +0200 |
| commit | 0a9ef3c77c7c593f3568f25761aad5d1f55e0e33 (patch) | |
| tree | 714f2a5f622a43477af50393007fd892434a7a65 /tests | |
| parent | 1a6007b4cdaacb22d013daeb58deb6ae72afda07 (diff) | |
| download | qtmaildir-0a9ef3c77c7c593f3568f25761aad5d1f55e0e33.tar.gz qtmaildir-0a9ef3c77c7c593f3568f25761aad5d1f55e0e33.zip | |
feat(sync): the status bar says which account is syncing
"Syncing..." was set once and never updated, so a run that takes over a
minute reported nothing about what it was doing.
The original diagnosis in the backlog was half wrong, and two further
wrong ones were made and discarded before the real cause: plain
"mbsync -a" prints NOTHING until it exits, then a single summary line.
Measured on a real run, one line at 11:11:08 then 73 within the second
11:11:33, at the end of a 46-second run. So there was no stream to read
for the part of a sync that takes time. It is not buffering, so stdbuf
changes nothing, and the account name is not unavailable either, which
was the second wrong conclusion.
mbsync -V is what changes both: it announces each channel as it reaches
it, which is at once the progress and the account name originally
asked for. The shipped script now passes it.
SyncPhaseTracker derives a short status from the output as it streams:
the channel being synced, the summary counts when mbsync ends, then the
notmuch reindex. It lives beside MailSync rather than in the window so
the matching rules are one testable thing, and it holds no widget.
Matching is loose and case-insensitive, since the wording varies by
version, and nothing in it decides success or failure: the exit status
remains the only authority on that.
Lines are reassembled in MainWindow before being fed, because
QProcess::readAll() splits wherever it happens to and a half-line would
match nothing. Every status is sanitised and truncated: the channel
name comes from a config file this app does not own, and a long one
must not stretch the status bar.
Two defects in existing code, fixed with it. setSyncBusy(true) ran
after start(), so a fast run's output arrived before the per-run reset
and wiped its own phase. And a first draft deferred phases while a
transient message showed, which let a "Background sync completed"
message armed before the sync began suppress the whole run: a running
sync's state outranks an expiring event message.
Verified by replaying real captured mbsync -V output through the
tracker, not only against fixtures. The MainWindow test paces its
script with sleeps, since a script that prints everything at once
arrives in one readyRead and makes every intermediate phase
unobservable.
Closes item 42.
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Diffstat (limited to 'tests')
| -rw-r--r-- | tests/test_mailsync.cpp | 147 | ||||
| -rw-r--r-- | tests/test_mainwindow.cpp | 117 |
2 files changed, 264 insertions, 0 deletions
diff --git a/tests/test_mailsync.cpp b/tests/test_mailsync.cpp index a1d193f..6c93e8d 100644 --- a/tests/test_mailsync.cpp +++ b/tests/test_mailsync.cpp @@ -44,6 +44,15 @@ private slots: void startDoesNotBlock(); void argumentsAreNotShellInterpreted(); + void phaseStartsAsMbsync(); + void notmuchLineSwitchesPhase(); + void mbsyncSummaryIsReported(); + void noiseLeavesThePhaseAlone(); + void aHostileLineCannotGrowTheStatus(); + void runMarkersAreNotAPhase(); + void theChannelNameIsShown(); + void aChannelNameIsNotLetInVerbatim(); + private: /// Writes an executable shell script into the temp dir, returns its path. QString makeScript(const QString &name, const QString &body); @@ -253,5 +262,143 @@ void TestMailSync::argumentsAreNotShellInterpreted() QVERIFY(sync.log().contains(QStringLiteral("; touch"))); } +void TestMailSync::phaseStartsAsMbsync() +{ + // A fresh tracker has nothing to report until it is fed, and a run is + // mbsync's until notmuch announces itself. + SyncPhaseTracker tracker; + QCOMPARE(tracker.phase(), SyncPhase::Starting); + + // A timestamped mbsync line, as the script emits it. + QVERIFY(tracker.feed(QStringLiteral("10:44:11 Socket error on imap.example.org (192.0.2.1:993): timeout."))); + QCOMPARE(tracker.phase(), SyncPhase::Mbsync); + QVERIFY(!tracker.statusText().isEmpty()); +} + +void TestMailSync::notmuchLineSwitchesPhase() +{ + // "notmuch new" announces itself with its own progress wording. Matching is + // loose on purpose: the exact phrasing varies by version, and a status that + // goes blank because a string moved is worse than a fixed one. + SyncPhaseTracker tracker; + tracker.feed(QStringLiteral("10:44:32 Channels: 5 Boxes: 39 Far: +0 *15 #0 -0 Near: +1 *0 #0 -0")); + QCOMPARE(tracker.phase(), SyncPhase::Mbsync); + + QVERIFY(tracker.feed(QStringLiteral("10:44:33 Processed 77 total files in almost no time."))); + QCOMPARE(tracker.phase(), SyncPhase::Notmuch); + + // Both spellings notmuch uses when it finishes. + SyncPhaseTracker other; + other.feed(QStringLiteral("11:00:33 Added 1 new message to the database.")); + QCOMPARE(other.phase(), SyncPhase::Notmuch); + + SyncPhaseTracker third; + third.feed(QStringLiteral("11:11:33 No new mail.")); + QCOMPARE(third.phase(), SyncPhase::Notmuch); +} + +void TestMailSync::mbsyncSummaryIsReported() +{ + // mbsync prints one summary at the end of its run and nothing per channel, + // so this line is the only concrete thing there is to show. The counts are + // worth surfacing; the raw "Far: +0 *15 #0 -0" tail is not. + SyncPhaseTracker tracker; + QVERIFY(tracker.feed(QStringLiteral("10:44:32 Channels: 5 Boxes: 39 Far: +0 *15 #0 -0 Near: +1 *0 #0 -0"))); + + const QString text = tracker.statusText(); + QVERIFY2(text.contains(QStringLiteral("5")), qPrintable(text)); + QVERIFY2(text.contains(QStringLiteral("39")), qPrintable(text)); +} + +void TestMailSync::noiseLeavesThePhaseAlone() +{ + // The overwhelming majority of a real run is this one line repeated, and it + // must not be shown or counted as a phase change. + SyncPhaseTracker tracker; + tracker.feed(QStringLiteral("10:44:32 Channels: 5 Boxes: 39 Far: +0 *0 #0 -0 Near: +0 *0 #0 -0")); + const QString before = tracker.statusText(); + + QVERIFY(!tracker.feed(QStringLiteral( + "11:11:33 Note: Ignoring non-mail file: /home/you/Mail/example/Inbox/.uidvalidity"))); + QCOMPARE(tracker.statusText(), before); + QCOMPARE(tracker.phase(), SyncPhase::Mbsync); +} + +void TestMailSync::aHostileLineCannotGrowTheStatus() +{ + // Sync output is local but unstructured, and it lands in a status label. + // A long line must be truncated rather than resizing the status bar, and + // control characters must not survive into it. + SyncPhaseTracker tracker; + tracker.feed(QStringLiteral("10:00:00 Channels: %1 Boxes: 2") + .arg(QString(500, QLatin1Char('9')))); + + const QString text = tracker.statusText(); + QVERIFY2(text.size() <= 120, qPrintable(QString::number(text.size()))); + QVERIFY(!text.contains(QLatin1Char('\n'))); + QVERIFY(!text.contains(QLatin1Char('\r'))); +} + +void TestMailSync::runMarkersAreNotAPhase() +{ + // The script's own banners bracket the run. RUN START must not read as + // mbsync output, and RUN END must not leave a phase claiming work is still + // going: the exit status decides the outcome, deliberately, so nothing here + // may be parsed into success or failure. + SyncPhaseTracker tracker; + QVERIFY(!tracker.feed(QStringLiteral("===== RUN START: 2026-08-07T11:10:47+02:00 ====="))); + QCOMPARE(tracker.phase(), SyncPhase::Starting); + + tracker.feed(QStringLiteral("11:11:33 No new mail.")); + QCOMPARE(tracker.phase(), SyncPhase::Notmuch); + + QVERIFY(!tracker.feed(QStringLiteral( + "===== RUN END: 2026-08-07T11:11:33+02:00 status=FAILED mbsync=1 notmuch=0 ====="))); + // Unchanged: the banner says nothing the status bar should repeat, and the + // caller reports the outcome from the exit code. + QCOMPARE(tracker.phase(), SyncPhase::Notmuch); +} + +void TestMailSync::theChannelNameIsShown() +{ + // What the user actually asked for: which account is being synced right + // now. mbsync -V announces each channel as it reaches it, and the channel + // name is the account name. + SyncPhaseTracker tracker; + + QVERIFY(tracker.feed(QStringLiteral("11:31:16 Channel provider-work"))); + QCOMPARE(tracker.phase(), SyncPhase::Mbsync); + QVERIFY2(tracker.statusText().contains(QStringLiteral("provider-work")), + qPrintable(tracker.statusText())); + + // The per-box chatter between channels must not displace it: the account + // is the useful thing, and a box name changing several times a second + // would make the status bar unreadable. + const QString onChannel = tracker.statusText(); + QVERIFY(!tracker.feed(QStringLiteral("11:31:16 Opening far side box INBOX..."))); + QCOMPARE(tracker.statusText(), onChannel); + QVERIFY(!tracker.feed(QStringLiteral("11:32:20 near side: 14758 messages, 0 recent"))); + QCOMPARE(tracker.statusText(), onChannel); + + // The next channel does replace it. + QVERIFY(tracker.feed(QStringLiteral("11:33:04 Channel provider-personal"))); + QVERIFY(tracker.statusText().contains(QStringLiteral("provider-personal"))); + QVERIFY(!tracker.statusText().contains(QStringLiteral("provider-work"))); +} + +void TestMailSync::aChannelNameIsNotLetInVerbatim() +{ + // The channel name comes from a config file this app does not own, and it + // lands in a status label. A long one must not be able to stretch the + // status bar, whatever mbsync was told to call it. + SyncPhaseTracker tracker; + tracker.feed(QStringLiteral("11:31:16 Channel %1") + .arg(QString(400, QLatin1Char('x')))); + + const QString text = tracker.statusText(); + QVERIFY2(text.size() <= 120, qPrintable(QString::number(text.size()))); + QVERIFY(!text.contains(QLatin1Char('\n'))); +} + QTEST_MAIN(TestMailSync) #include "test_mailsync.moc" diff --git a/tests/test_mainwindow.cpp b/tests/test_mainwindow.cpp index 480be39..02490a5 100644 --- a/tests/test_mainwindow.cpp +++ b/tests/test_mainwindow.cpp @@ -80,6 +80,7 @@ private slots: void aLocalSyncsOwnLockIsNeverReportedAsBackground(); void aSkippedLocalSyncStillReportsTheOtherRunFinishing(); void anUnobservableLockTableLeavesTheSyncButtonUsable(); + void theStatusBarFollowsTheSyncPhase(); void theSyncActionIsDisabledWhileABackgroundSyncHoldsTheLock(); void escapeBlanksTheMessagePane(); void deleteTogglesOnAnAlreadyDeletedThread(); @@ -1031,6 +1032,122 @@ void TestMainWindow::theSyncActionIsDisabledWhileABackgroundSyncHoldsTheLock() MainWindow::setLocksPathForTesting(QStringLiteral("/proc/locks")); } +void TestMainWindow::theStatusBarFollowsTheSyncPhase() +{ + // Item 42: "Syncing..." said nothing about what was happening, while the + // script was already streaming its phase into the log pane and the app was + // throwing it away. + // + // Driven through a real script rather than by calling the tracker directly, + // because the defect this guards is in the wiring: the chunks QProcess + // hands over split mid-line, so a handler that fed them straight to the + // tracker would stall on the first partial line. + QTemporaryDir dir; + QVERIFY(dir.isValid()); + QVERIFY(QDir().mkpath(dir.filePath(QStringLiteral("qtmaildir")))); + + const QString script = dir.filePath(QStringLiteral("fakesync.sh")); + { + QFile f(script); + QVERIFY(f.open(QIODevice::WriteOnly)); + // Shaped like the real thing: timestamped lines, the noise that makes + // up the bulk of a run, mbsync's one summary, then notmuch's output. + // Paced, not dumped. A script that prints everything at once is + // delivered in a single readyRead, so the tracker sees the whole run in + // one call and only its final phase is ever painted: the intermediate + // ones would be unobservable and the test would assert nothing. A real + // sync takes tens of seconds and arrives in separate chunks, which the + // sleeps stand in for. + f.write("#!/bin/sh\n" + "echo '===== RUN START: 2026-08-07T11:00:00+02:00 ====='\n" + "echo '11:00:01 Note: Ignoring non-mail file: /home/you/Mail/x/.uidvalidity'\n" + "sleep 0.2\n" + "echo '11:00:02 Channels: 5 Boxes: 39 Far: +0 *1 #0 -0 Near: +1 *0 #0 -0'\n" + "sleep 0.2\n" + "echo '11:00:03 Processed 79 total files in almost no time.'\n" + "echo '11:00:03 Added 1 new message to the database.'\n" + "sleep 0.2\n" + "echo '===== RUN END: 2026-08-07T11:00:03+02:00 status=OK ====='\n"); + f.close(); + QVERIFY(QFile::setPermissions(script, + QFile::ReadOwner | QFile::WriteOwner + | QFile::ExeOwner)); + } + + const QString conf = dir.filePath(QStringLiteral("qtmaildir/qtmaildir.conf")); + { + QSettings s(conf, QSettings::IniFormat); + s.setValue(QStringLiteral("sync/command"), script); + } + + const QString locks = dir.filePath(QStringLiteral("locks")); + { + QFile f(locks); + QVERIFY(f.open(QIODevice::WriteOnly)); + } + MainWindow::setLocksPathForTesting(locks); + + Config config; + config.load(conf); + QCOMPARE(config.syncCommand(), script); + MainWindow window(config); + + auto *status = window.findChild<QLabel *>(QStringLiteral("statusMessage")); + QVERIFY(status); + + // Every value the label takes, recorded as it changes. A run this small + // finishes in well under a second, so polling for an intermediate phase + // races the process and usually sees only "Sync complete": the sequence has + // to be captured, not sampled. + // QLabel has no textChanged signal, so the label is sampled on a fast timer + // rather than watched. Each distinct value is recorded once. + QStringList seen; + QTimer sampler; + sampler.setInterval(1); + connect(&sampler, &QTimer::timeout, &sampler, [&seen, status]() { + const QString text = status->text(); + if (seen.isEmpty() || seen.constLast() != text) + seen.append(text); + }); + sampler.start(); + + QVERIFY(QMetaObject::invokeMethod(&window, "startSync")); + + QTRY_VERIFY_WITH_TIMEOUT( + std::any_of(seen.cbegin(), seen.cend(), [](const QString &s) { + return s.contains(QStringLiteral("Sync complete")); + }), + 10000); + + const QString trace = seen.join(QStringLiteral(" | ")); + + // mbsync's summary is the only concrete thing the stream carries, since it + // names no channel unless run verbose. The counts must reach the label. + QVERIFY2(std::any_of(seen.cbegin(), seen.cend(), [](const QString &s) { + return s.contains(QStringLiteral("39")) + && s.contains(QStringLiteral("5")); + }), + qPrintable(QStringLiteral("the mbsync summary never reached the " + "status bar. Saw: ") + trace)); + + // Then the reindex phase, which is a different message entirely. Without + // the wiring the label went from "Syncing..." straight to "Sync complete", + // which is exactly what the defect looked like. + QVERIFY2(std::any_of(seen.cbegin(), seen.cend(), [](const QString &s) { + return s.contains(QStringLiteral("notmuch")); + }), + qPrintable(QStringLiteral("the notmuch phase never reached the " + "status bar. Saw: ") + trace)); + + // The banners are not a phase and must never appear in the status bar. + for (const QString &s : seen) { + QVERIFY2(!s.contains(QStringLiteral("RUN ")), qPrintable(s)); + QVERIFY2(!s.contains(QStringLiteral("status=")), qPrintable(s)); + } + + MainWindow::setLocksPathForTesting(QStringLiteral("/proc/locks")); +} + void TestMainWindow::anUnobservableLockTableLeavesTheSyncButtonUsable() { // Unknown means /proc/locks could not be read, so nothing was observed. A |
