diff options
| author | Danilo M. <danix@danix.xyz> | 2026-08-15 09:42:27 +0200 |
|---|---|---|
| committer | Danilo M. <danix@danix.xyz> | 2026-08-15 09:42:27 +0200 |
| commit | 8f40c0b6dce67cefa1edce0b865c9a3885d39717 (patch) | |
| tree | 3f8d6a7d38c1b92eea2140ad911765187c1d4f3b | |
| parent | deec4e1bbf2a6af6f3f86043080fd5b4df535e03 (diff) | |
| download | qtmaildir-8f40c0b6dce67cefa1edce0b865c9a3885d39717.tar.gz qtmaildir-8f40c0b6dce67cefa1edce0b865c9a3885d39717.zip | |
fix(status): count threads as they arrive instead of "Searching..."
Item 74. runQuery() set the status bar once and only queryFinished cleared
it, so the bar kept claiming a query was running for the whole walk while
rows were visibly arriving behind it. Measured cold against a 1.1 GB index:
the first batch reaches the model at 642 ms and the walk finishes at 5714 ms,
so five seconds of a slow query read as a frozen one.
onThreadsReady now sets the bar from the model's own row count after each
batch, which is the number of rows the user can actually see. No timing
changes; this only stops the bar from lying.
The refresh branch returns before the new line, so a background refresh stays
silent exactly as onQueryFinished already keeps it. That silence has its own
test, which fails when the write is moved above the guard.
beginRefreshForTesting() is a new seam: refreshCurrentQuery() returns early
without a worker and a bare window has none, so a test cannot otherwise reach
the refresh path.
| -rw-r--r-- | CHANGELOG.md | 7 | ||||
| -rw-r--r-- | docs/superpowers/plans/2026-08-03-post-0.1.0-usability-closed.md | 55 | ||||
| -rw-r--r-- | docs/superpowers/plans/2026-08-03-post-0.1.0-usability.md | 47 | ||||
| -rw-r--r-- | src/mainwindow.cpp | 12 | ||||
| -rw-r--r-- | src/mainwindow.h | 13 | ||||
| -rw-r--r-- | tests/test_mainwindow.cpp | 99 |
6 files changed, 187 insertions, 46 deletions
diff --git a/CHANGELOG.md b/CHANGELOG.md index e869346..798e8f8 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -36,6 +36,13 @@ point at which they are stable. ### Changed +- The status bar counts threads as they arrive instead of saying "Searching..." + until the query is done. On a large query after a reboot, when the notmuch + index is still being read from disk, the first rows appear seconds before the + walk finishes; the bar used to go on claiming the query was running for all of + that time, which made a slow query look like a frozen one. Nothing about the + timing changes. + - The dialog reporting configuration problems at startup now appears over the main window instead of before it. Which problems interrupt startup is unchanged: a keybinding that is being ignored does, a notice such as "no sync diff --git a/docs/superpowers/plans/2026-08-03-post-0.1.0-usability-closed.md b/docs/superpowers/plans/2026-08-03-post-0.1.0-usability-closed.md index ff2bbba..730c722 100644 --- a/docs/superpowers/plans/2026-08-03-post-0.1.0-usability-closed.md +++ b/docs/superpowers/plans/2026-08-03-post-0.1.0-usability-closed.md @@ -4984,3 +4984,58 @@ the wrong thread for a reply row. The second was found the hard way: a fix for 87 was written, mutation-checked, shipped and reverted the same evening after it marked an unrelated message read. The test that passed had asserted on a ROOT selection, the one case where `current.row()` is correct. + +## 74. The first query after boot sits on "Searching..." for seconds + +**Observed (user, 2026-08-11):** the first start of the day takes noticeably +longer to show its default view, and the delay happens while the status bar +reads "Searching...". + +**Cause: the notmuch index paging in from disk, not this application's code.** +Measured by instrumenting `main()`, the `MainWindow` constructor and +`NotmuchWorker::runQuery` behind an environment variable, then running the same +`tag:inbox` query (4444 threads) warm and again after evicting the index from +the page cache with `posix_fadvise(POSIX_FADV_DONTNEED)`: + +| phase | warm | cold | +|---|---|---| +| `notmuch_query_search_threads` returns | 0 ms | 411 ms | +| first batch of 200 reaches the model | 10 ms | 642 ms | +| walk complete, all 4444 threads | 154 ms | 5714 ms | + +A 37x difference over the identical code path. The index measured 1.1 GB. The +in-process startup costs nothing by comparison: `QApplication` in 20 ms, the +whole `MainWindow` constructor in ~120 ms, and the window is shown and +interactive at ~196 ms in both the warm and the cold run. + +**There is nothing to fix in the query path**, and the measurement exists mainly +so this is not re-investigated. Two things it did establish that are worth +keeping. The default startup view is whichever saved query `startup_query` names, +defaulting to `Unread`, so a user with an empty unread view never sees this at +all and a user whose default is Inbox always does. And batching already works: +rows land from 642 ms cold, long before the 5714 ms finish. + +**The one real defect it exposed is the status bar.** "Searching..." is set once +in `runQuery` and cleared only on `queryFinished`, so it keeps claiming the +query is running for the full 5.7 s while rows are visibly arriving behind it. +That makes a slow query read as a frozen one. The fix is to update the text per +batch with the count so far rather than holding one string, which changes no +timing and only stops the bar from lying. + +**The user declined this on 2026-08-11**, having asked for the explanation +rather than a change. Recorded as open because the status bar is still +inaccurate, not because anything is expected to happen. + +**Size: XS** for the status bar. The cold-cache cost itself is not addressable +here and should not be attempted: prefaulting 1.1 GB at startup to make one +query look fast is a worse trade than the wait. + +**Closed 2026-08-15, the status-bar half only.** `onThreadsReady` now sets the +bar to `Searching... %n thread(s)` from the model's own row count after each +batch, so a slow query reports progress instead of looking frozen. The refresh +branch returns before that line, which keeps a background refresh silent as +`onQueryFinished` already does; that silence is a test of its own, and it fails +when the write is moved above the guard. + +The cold-cache cost measured above was not touched and should not be. Nothing +about the timing changed. diff --git a/docs/superpowers/plans/2026-08-03-post-0.1.0-usability.md b/docs/superpowers/plans/2026-08-03-post-0.1.0-usability.md index e1ea2da..841ee91 100644 --- a/docs/superpowers/plans/2026-08-03-post-0.1.0-usability.md +++ b/docs/superpowers/plans/2026-08-03-post-0.1.0-usability.md @@ -140,7 +140,7 @@ taking that too literally. | 71 | A toolbar action does not sync, so the edit sits until the next cron run | workflow | S | **done** 2026-08-11; 2s default, `auto_sync_delay_ms` | | 72 | No khard/khal integration | workflow | ? | open, unspecified; the user places it after send, so v2 at the earliest | | 73 | This backlog is past four thousand lines | maintenance | S | **done** 2026-08-13; 5056 lines to 578, closed sections moved to `2026-08-03-post-0.1.0-usability-closed.md` | -| 74 | "Searching..." keeps claiming a query is running while rows are already arriving | feedback | XS | open; cause measured 2026-08-11, the delay itself is the cold page cache and is not fixable here | +| 74 | "Searching..." keeps claiming a query is running while rows are already arriving | feedback | XS | **done** 2026-08-15, unreleased. The status-bar half only: the bar now counts threads per batch. The cold-cache delay itself was measured in 2026-08-11 and is not fixable here | | 75 | The tagging rules window forgets its size and its column widths | persistence | S | **done** 2026-08-13, shipped in 0.17.0. The window-kind question is left open, see the closed-items file | | 76 | Every field in the rules dialog is free text, so a rule is easy to get wrong | workflow | M | **done** 2026-08-13, shipped in 0.17.0. See `specs/2026-08-13-rule-builder-design.md` | | 77 | No way to see what a rule would collect, in the thread list | workflow | S | **done** 2026-08-13, shipped in 0.17.0 | @@ -440,51 +440,6 @@ Those are three different features. **Size: `?`, unspecified**, and out of scope until v2 exists. Ask before designing anything. -## 74. The first query after boot sits on "Searching..." for seconds - -**Observed (user, 2026-08-11):** the first start of the day takes noticeably -longer to show its default view, and the delay happens while the status bar -reads "Searching...". - -**Cause: the notmuch index paging in from disk, not this application's code.** -Measured by instrumenting `main()`, the `MainWindow` constructor and -`NotmuchWorker::runQuery` behind an environment variable, then running the same -`tag:inbox` query (4444 threads) warm and again after evicting the index from -the page cache with `posix_fadvise(POSIX_FADV_DONTNEED)`: - -| phase | warm | cold | -|---|---|---| -| `notmuch_query_search_threads` returns | 0 ms | 411 ms | -| first batch of 200 reaches the model | 10 ms | 642 ms | -| walk complete, all 4444 threads | 154 ms | 5714 ms | - -A 37x difference over the identical code path. The index measured 1.1 GB. The -in-process startup costs nothing by comparison: `QApplication` in 20 ms, the -whole `MainWindow` constructor in ~120 ms, and the window is shown and -interactive at ~196 ms in both the warm and the cold run. - -**There is nothing to fix in the query path**, and the measurement exists mainly -so this is not re-investigated. Two things it did establish that are worth -keeping. The default startup view is whichever saved query `startup_query` names, -defaulting to `Unread`, so a user with an empty unread view never sees this at -all and a user whose default is Inbox always does. And batching already works: -rows land from 642 ms cold, long before the 5714 ms finish. - -**The one real defect it exposed is the status bar.** "Searching..." is set once -in `runQuery` and cleared only on `queryFinished`, so it keeps claiming the -query is running for the full 5.7 s while rows are visibly arriving behind it. -That makes a slow query read as a frozen one. The fix is to update the text per -batch with the count so far rather than holding one string, which changes no -timing and only stops the bar from lying. - -**The user declined this on 2026-08-11**, having asked for the explanation -rather than a change. Recorded as open because the status bar is still -inaccurate, not because anything is expected to happen. - -**Size: XS** for the status bar. The cold-cache cost itself is not addressable -here and should not be attempted: prefaulting 1.1 GB at startup to make one -query look fast is a worse trade than the wait. - ## 78. No way to build a rule from something visible in a message **Observed.** The user would like to select an address or another piece of a diff --git a/src/mainwindow.cpp b/src/mainwindow.cpp index fb34fe2..c6df95c 100644 --- a/src/mainwindow.cpp +++ b/src/mainwindow.cpp @@ -2086,6 +2086,18 @@ void MainWindow::onThreadsReady(const QVector<ThreadSummary> &threads, } m_model->appendBatch(threads); + + // Item 74. "Searching..." was set once in runQuery() and cleared only on + // queryFinished, so it went on claiming the query was running for the whole + // walk while rows were visibly arriving behind it. Measured cold against a + // 1.1 GB index: first rows at 642 ms, done at 5714 ms, five seconds of a + // slow query reading as a frozen one. + // + // The count comes from the model rather than from a running total, since + // that is the number of rows the user can actually see. Nothing about the + // timing changes; this only stops the bar from lying. + m_statusLabel->setText(tr("Searching... %n thread(s)", "", + m_model->rowCount(QModelIndex()))); } void MainWindow::onQueryFinished(int total, quint64 generation) diff --git a/src/mainwindow.h b/src/mainwindow.h index d861d72..80c7d2b 100644 --- a/src/mainwindow.h +++ b/src/mainwindow.h @@ -186,6 +186,19 @@ public: /// stale, so a test standing in for the worker has to know the current one. quint64 currentGenerationForTesting() const { return m_generation; } + /// Puts the window into the state refreshCurrentQuery() leaves it in, and + /// returns the generation the refresh's replies must carry. + /// + /// A test seam, because refreshCurrentQuery() returns early without a + /// worker and a bare window has none. It sets only what decides whether a + /// batch is a refresh's, not what the real function asks the worker to do. + quint64 beginRefreshForTesting() + { + m_refreshGeneration = ++m_generation; + m_refreshThreads.clear(); + return m_refreshGeneration; + } + /// The generation a database-stats reply must carry to be accepted. /// /// A test seam, for the same reason as the one above: onDatabaseStatsReady diff --git a/tests/test_mainwindow.cpp b/tests/test_mainwindow.cpp index eb678eb..228a0bc 100644 --- a/tests/test_mainwindow.cpp +++ b/tests/test_mainwindow.cpp @@ -169,6 +169,8 @@ private slots: void narrowingAnEmptyQueryBarIsAPlainSearch(); void aMalformedAccountIsReportedWithoutBlockingTheConstructor(); void aWorkerBackedWindowReturnsRealThreads(); + void arrivingBatchesUpdateTheStatusBarWithTheCountSoFar(); + void aRefreshsBatchesLeaveTheStatusBarAlone(); void selectingAThreadRootShowsItInTheMessagePane(); void anUnexpandedRootRendersOneMessageNotTheConversation(); void autoSyncIsNotArmedWhenDisabledOrWithNothingPending(); @@ -6262,6 +6264,103 @@ void TestMainWindow::aWorkerBackedWindowReturnsRealThreads() QTRY_VERIFY_WITH_TIMEOUT(model->rowCount(QModelIndex()) == 1, 15000); } +void TestMainWindow::arrivingBatchesUpdateTheStatusBarWithTheCountSoFar() +{ + // Item 74: "Searching..." was set once by runQuery and cleared only on + // queryFinished, so it kept claiming the query was running for the whole + // cold-cache walk, measured at 5.7 s against a 1.1 GB index, while rows + // were visibly arriving behind it from 642 ms. A slow query read as a + // frozen one. + const Config config; + MainWindow window(config); + + auto *status = + window.findChild<QLabel *>(QStringLiteral("statusMessage")); + QVERIFY2(status, "no status label"); + auto *model = window.findChild<ThreadListModel *>(); + QVERIFY(model); + + window.findChild<QLineEdit *>()->setText(QStringLiteral("tag:inbox")); + QMetaObject::invokeMethod(&window, "runCurrentQuery"); + + // The guard: before any batch, the bar says what it has always said. If + // this ever stops holding, the assertions below are measuring the wrong + // thing and would pass against a bar that never changes at all. + QCOMPARE(status->text(), QStringLiteral("Searching...")); + + const quint64 generation = window.currentGenerationForTesting(); + const QVector<ThreadSummary> first = { + makeThread(QStringLiteral("t1"), {}), + makeThread(QStringLiteral("t2"), {}) + }; + QVERIFY(QMetaObject::invokeMethod( + &window, "onThreadsReady", + Q_ARG(QVector<ThreadSummary>, first), Q_ARG(quint64, generation))); + + const QString afterFirst = status->text(); + QVERIFY2(afterFirst != QStringLiteral("Searching..."), + "the bar still claimed the query was running after rows arrived"); + QVERIFY2(afterFirst.contains(QStringLiteral("2")), + qPrintable(QStringLiteral("no count so far in: ") + afterFirst)); + + // A second batch, because the count has to keep moving. A bar that says + // "2" forever is the same lie in a shorter sentence. + const QVector<ThreadSummary> second = { + makeThread(QStringLiteral("t3"), {}) + }; + QVERIFY(QMetaObject::invokeMethod( + &window, "onThreadsReady", + Q_ARG(QVector<ThreadSummary>, second), Q_ARG(quint64, generation))); + QVERIFY2(status->text().contains(QStringLiteral("3")), + qPrintable(QStringLiteral("count did not advance: ") + + status->text())); + + // And the finished text still wins, so the running message cannot outlive + // the query that armed it. + // The literal "(s)" is what an untranslated %n plural renders as with no + // translator loaded, which is the case in the suite. Asserting the plural + // form Qt would pick under a translation would fail against correct code. + QMetaObject::invokeMethod(&window, "onQueryFinished", Q_ARG(int, 3), + Q_ARG(quint64, generation)); + QCOMPARE(status->text(), QStringLiteral("3 thread(s)")); +} + +void TestMainWindow::aRefreshsBatchesLeaveTheStatusBarAlone() +{ + // A refresh after a sync is meant to be silent: onQueryFinished updates + // the FALLBACK text without stamping over the bar, and its batches must + // not do what its completion deliberately does not. Without this, a cron + // sync would overwrite whatever the bar was telling the user with a + // running count they never asked for. + const Config config; + MainWindow window(config); + + auto *status = + window.findChild<QLabel *>(QStringLiteral("statusMessage")); + QVERIFY(status); + + window.findChild<QLineEdit *>()->setText(QStringLiteral("tag:inbox")); + QMetaObject::invokeMethod(&window, "runCurrentQuery"); + const quint64 generation = window.currentGenerationForTesting(); + QMetaObject::invokeMethod(&window, "onQueryFinished", Q_ARG(int, 1), + Q_ARG(quint64, generation)); + + // Something the user is being told, which the refresh must not erase. + status->setText(QStringLiteral("Sync complete.")); + + // A refresh's own generation. refreshCurrentQuery() needs a worker to set + // one, and a bare window has none, so the generation is advanced the same + // way the refresh does and declared to the window through the seam. + const quint64 refreshGeneration = + window.beginRefreshForTesting(); + QVERIFY(QMetaObject::invokeMethod( + &window, "onThreadsReady", + Q_ARG(QVector<ThreadSummary>, { makeThread(QStringLiteral("t1"), {}) }), + Q_ARG(quint64, refreshGeneration))); + + QCOMPARE(status->text(), QStringLiteral("Sync complete.")); +} + void TestMainWindow::selectingAThreadRootShowsItInTheMessagePane() { // Item 66: "selecting a thread (click on main message), nothing appears in |
