mirror of
https://github.com/logos-co/logos-view-module-runtime.git
synced 2026-08-30 20:41:14 +00:00
* feat(ui-host): give a view its chance to finish before teardown
ui-host deleted the plugin the instant app.exec() returned. Core modules
have had a grace period since the teardown hook shipped; views did not.
Calls the shared logos::runPluginAboutToUnload() (logos-plugin-qt#23)
between exec() returning and `delete pluginObject`. Safe to run a nested
event loop there: the application loop has already returned, so this is the
same shape as logos_host's call site rather than a re-entrant exec(). It
must come BEFORE the delete — it is the plugin it asks, and the plugin has
to still be alive to answer.
THE GRACE PERIOD IS 2000ms, NOT logos_host's 3000. That difference is the
reason the helper takes it as a parameter instead of owning a constant.
ViewModuleHost::stop() gives this process terminate() plus
waitForFinished(3000) before it resorts to kill(), and everything after the
signal has to fit inside that 3s: unwinding exec() through the self-pipe
notifier, this grace period, `delete pluginObject`, the QRemoteObjectHost
destructor unlinking the QtRO socket, and process exit. Porting 3000 would
have consumed the entire budget and left every async view hard-killed
mid-teardown — the precise failure the hook exists to prevent.
Measured, through the real ViewModuleHost driving the real ui-host binary:
no hook 0.001s dtor
async finishes 1.003s about-to-unload, tick x10, work-done, signalled, dtor
async hangs 1.903s about-to-unload, tick x19, dtor
All exit 0 — none hard-killed. The hang case costs 1.9s rather than 2.0
because the deadline is a default coarse QTimer, which Qt may fire up to 5%
early; that errs toward giving up sooner, the safe direction for a budget
carved out of someone else's kill timer.
The assertions are on ENTRY ORDER and relative tick counts, never elapsed
time: `work-done` before `dtor` proves the wait happened, the ticks prove a
nested loop actually ran, and hangTicks > finishTicks proves the deadline
outlasts a completion — i.e. that deadline.isActive() really does
distinguish "finished" from "gave up". Wall clock is asserted only where a
bound IS the contract (stopMs < 3000).
Negative control: removing the call fails 3 of the 4 tests, and correctly
leaves the no-hook one passing.
Two pins move forward, both required rather than incidental:
* logos-plugin-qt -> #23, which adds the helper. TODO: re-point at master
once it merges.
* logos-protocol f4407ff -> 7989472. plugin-qt follows THIS repo's
protocol, and its logos_qt_host_shared refuses to configure against one
that does not export logos_protocol_shared (protocol#65) — a deliberate
FATAL_ERROR, because the alternative is falling back to the archive and
reintroducing the duplicate singleton at runtime.
10/10 tests pass, UiHostUnloadTests included.
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
* chore(deps): track logos-plugin-qt master now that the helper has landed
logos-plugin-qt#23 merged as ef11c21, so the temporary rev pin goes. The
relocked narHash is identical to the branch tip this was pinned to, so
nothing about the build changes — only the pin.
The logos-protocol bump stays: plugin-qt follows THIS repo's protocol, and
its logos_qt_host_shared refuses to configure against one that does not
export logos_protocol_shared (protocol#65).
10/10 tests green, UiHostUnloadTests included.
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
---------
Co-authored-by: Claude Opus 5 <noreply@anthropic.com>
261 lines
12 KiB
C++
261 lines
12 KiB
C++
// End-to-end proof of the module teardown hook on the ui-host path.
|
|
//
|
|
// Drives the REAL ui-host binary through the REAL parent (ViewModuleHost), so
|
|
// what is exercised is the shipping shutdown sequence: SIGTERM ->
|
|
// self-pipe notifier -> app.quit() -> app.exec() returns ->
|
|
// runPluginAboutToUnload() -> delete pluginObject -> exit. Nothing here is a
|
|
// stand-in for any of it.
|
|
//
|
|
// WHY THIS TEST HAS TO EXIST. A host-side hook resolved BY NAME is a silent
|
|
// no-op when the name is not there: invokeMethod returns false, nothing is
|
|
// logged, the process still exits 0 and still on time. That is indistinguishable
|
|
// from every module answering Synchronous, which is also the correct behaviour.
|
|
// So a passing build proves nothing about this feature unless something
|
|
// OBSERVES the wait -- hence the fixtures' journal, and their heartbeat.
|
|
//
|
|
// Every assertion below is on recorded entries and their order. The elapsed
|
|
// times are printed for the record, and used only where a bound genuinely is
|
|
// the contract (the hard-kill budget).
|
|
|
|
#include <QCoreApplication>
|
|
#include <QElapsedTimer>
|
|
#include <QFile>
|
|
#include <QSignalSpy>
|
|
#include <QTemporaryDir>
|
|
#include <QTest>
|
|
|
|
#include "ViewModuleHost.h"
|
|
|
|
namespace {
|
|
|
|
struct Run {
|
|
QStringList journal; // entries, in the order the plugin wrote them
|
|
int exitCode = -1;
|
|
qint64 stopMs = -1; // wall clock across ViewModuleHost::stop()
|
|
bool exited = false;
|
|
|
|
int count(const QString& entry) const { return journal.count(entry); }
|
|
bool has(const QString& entry) const { return journal.contains(entry); }
|
|
int indexOf(const QString& entry) const { return journal.indexOf(entry); }
|
|
};
|
|
|
|
} // namespace
|
|
|
|
class TestUiHostUnload : public QObject
|
|
{
|
|
Q_OBJECT
|
|
|
|
private:
|
|
// Spawn ui-host on `pluginPath`, wait for READY, then stop it exactly the
|
|
// way Basecamp does and collect what the plugin recorded.
|
|
Run runOne(const QString& pluginPath)
|
|
{
|
|
Run r;
|
|
|
|
QTemporaryDir dir;
|
|
Q_ASSERT(dir.isValid());
|
|
const QString journalPath = dir.filePath(QStringLiteral("journal.txt"));
|
|
// The child reads this; ui-host passes its environment through.
|
|
qputenv("LOGOS_TEST_UNLOAD_JOURNAL", journalPath.toUtf8());
|
|
|
|
ViewModuleHost host;
|
|
QSignalSpy readySpy(&host, &ViewModuleHost::ready);
|
|
QSignalSpy exitSpy(&host, &ViewModuleHost::processExited);
|
|
|
|
if (!host.spawn(QStringLiteral("unload_fixture"), pluginPath,
|
|
QStringLiteral("test-token"))) {
|
|
qWarning("spawn failed for %s", qPrintable(pluginPath));
|
|
return r;
|
|
}
|
|
|
|
// READY is printed only after the plugin is loaded, initLogos delivered
|
|
// and remoting enabled -- i.e. once the process is in the state a real
|
|
// teardown would find it in.
|
|
if (!readySpy.wait(15000)) {
|
|
qWarning("ui-host never reported READY for %s", qPrintable(pluginPath));
|
|
host.stop();
|
|
return r;
|
|
}
|
|
|
|
QElapsedTimer t;
|
|
t.start();
|
|
host.stop(); // terminate() + waitForFinished(3000) + kill()
|
|
r.stopMs = t.elapsed();
|
|
|
|
// stop() blocks until the child is reaped, so finished() has already
|
|
// been queued; let it land.
|
|
if (exitSpy.isEmpty()) exitSpy.wait(2000);
|
|
if (!exitSpy.isEmpty()) {
|
|
r.exited = true;
|
|
r.exitCode = exitSpy.first().at(0).toInt();
|
|
}
|
|
|
|
QFile f(journalPath);
|
|
if (f.open(QIODevice::ReadOnly | QIODevice::Text)) {
|
|
const QString text = QString::fromUtf8(f.readAll());
|
|
r.journal = text.split(QLatin1Char('\n'), Qt::SkipEmptyParts);
|
|
}
|
|
qunsetenv("LOGOS_TEST_UNLOAD_JOURNAL");
|
|
|
|
qInfo().noquote()
|
|
<< QStringLiteral("[%1] exit=%2 stop=%3ms journal=%4")
|
|
.arg(QFileInfo(pluginPath).fileName())
|
|
.arg(r.exitCode).arg(r.stopMs)
|
|
.arg(r.journal.join(QLatin1Char(',')));
|
|
return r;
|
|
}
|
|
|
|
private slots:
|
|
|
|
// ---------------------------------------------------------------------
|
|
// 1. No hook: the common case, and it must stay free.
|
|
//
|
|
// The plugin's meta-object genuinely has no aboutToUnload, so the host's
|
|
// invokeMethod returns false and teardown proceeds immediately. What makes
|
|
// this a real assertion rather than a tautology is the pair below it: the
|
|
// same host binary, the same code path, DOES wait for the other two.
|
|
// ---------------------------------------------------------------------
|
|
void noHookIsSilentAndImmediate()
|
|
{
|
|
const Run r = runOne(QStringLiteral(FIXTURE_PLUGIN_NONE));
|
|
|
|
QVERIFY2(r.exited, "ui-host did not exit");
|
|
QCOMPARE(r.exitCode, 0);
|
|
|
|
QVERIFY2(r.has(QStringLiteral("dtor")),
|
|
"the plugin was never destroyed -- ui-host did not reach "
|
|
"`delete pluginObject`");
|
|
QVERIFY2(!r.has(QStringLiteral("about-to-unload")),
|
|
"a plugin with no such meta-method somehow answered the hook");
|
|
QVERIFY2(!r.has(QStringLiteral("tick")),
|
|
"no hook was declared, so nothing should have run an event "
|
|
"loop after exec() returned");
|
|
QCOMPARE(r.journal, QStringList{QStringLiteral("dtor")});
|
|
}
|
|
|
|
// ---------------------------------------------------------------------
|
|
// 2. Asynchronous, finishes: the host waits, and the plugin's last work
|
|
// actually runs BEFORE it is destroyed.
|
|
//
|
|
// "work-done" landing above "dtor" is the whole point of the feature. It
|
|
// can only happen if a running event loop dispatched a timer after
|
|
// app.exec() had already returned -- which is precisely the nested loop
|
|
// runPluginAboutToUnload spins.
|
|
// ---------------------------------------------------------------------
|
|
void asynchronousThatFinishesIsWaitedFor()
|
|
{
|
|
const Run r = runOne(QStringLiteral(FIXTURE_PLUGIN_FINISHES));
|
|
|
|
QVERIFY2(r.exited, "ui-host did not exit");
|
|
QCOMPARE(r.exitCode, 0);
|
|
|
|
QVERIFY2(r.has(QStringLiteral("about-to-unload")),
|
|
"the host never reached the plugin's hook -- if this fails and "
|
|
"test 1 passes, the hook is being resolved by a name the "
|
|
"plugin does not publish");
|
|
QVERIFY2(r.has(QStringLiteral("work-done")),
|
|
"the plugin's deferred work never ran: the host tore it down "
|
|
"without waiting");
|
|
QVERIFY2(r.has(QStringLiteral("dtor")), "the plugin was never destroyed");
|
|
|
|
// THE ordering assertion.
|
|
QVERIFY2(r.indexOf(QStringLiteral("work-done")) < r.indexOf(QStringLiteral("dtor")),
|
|
"the plugin finished its work only AFTER it had been destroyed");
|
|
QVERIFY2(r.indexOf(QStringLiteral("about-to-unload")) < r.indexOf(QStringLiteral("work-done")),
|
|
"work completed before the hook was even called");
|
|
|
|
// The nested loop really was running: the heartbeat could not have
|
|
// ticked otherwise.
|
|
QVERIFY2(r.count(QStringLiteral("tick")) > 0,
|
|
"no heartbeat ticks -- the host did not run an event loop "
|
|
"while waiting, so an async module doing real work would "
|
|
"never make progress");
|
|
|
|
// dtor is last, and nothing the plugin scheduled ran after it.
|
|
QCOMPARE(r.journal.last(), QStringLiteral("dtor"));
|
|
}
|
|
|
|
// ---------------------------------------------------------------------
|
|
// 3. Asynchronous, never signals: a grace period, not a veto.
|
|
//
|
|
// The host must give up and proceed. Critically it must do so from within
|
|
// its own budget: ViewModuleHost::stop() hard-kills at 3000ms, so a grace
|
|
// period that overran would show up here as a non-zero exit code, not as a
|
|
// slow pass.
|
|
// ---------------------------------------------------------------------
|
|
void asynchronousThatHangsIsAbandoned()
|
|
{
|
|
const Run r = runOne(QStringLiteral(FIXTURE_PLUGIN_HANGS));
|
|
|
|
QVERIFY2(r.exited, "ui-host did not exit");
|
|
|
|
// The hook is a grace period, not a veto: the host proceeds regardless.
|
|
QVERIFY2(r.has(QStringLiteral("about-to-unload")),
|
|
"the host never reached the plugin's hook");
|
|
QVERIFY2(!r.has(QStringLiteral("work-done")),
|
|
"this fixture must never complete -- it exists to be given up on");
|
|
QVERIFY2(r.has(QStringLiteral("dtor")),
|
|
"the host waited forever: a module that never signals took the "
|
|
"process hostage, which is exactly what the deadline exists to "
|
|
"prevent");
|
|
QCOMPARE(r.journal.last(), QStringLiteral("dtor"));
|
|
|
|
// It genuinely WAITED before giving up -- ticks can only come from the
|
|
// nested loop.
|
|
QVERIFY2(r.count(QStringLiteral("tick")) > 0,
|
|
"no ticks: the host skipped the wait entirely rather than "
|
|
"bounding it");
|
|
|
|
// ...and it exited cleanly rather than being hard-killed by the parent.
|
|
// This is the assertion that the grace period FITS the budget it was
|
|
// carved out of. A 3000ms grace here (logos_host's constant) would
|
|
// consume ViewModuleHost::stop()'s whole 3000ms window and turn this
|
|
// into a kill.
|
|
QCOMPARE(r.exitCode, 0);
|
|
QVERIFY2(r.stopMs < 3000,
|
|
qPrintable(QStringLiteral("teardown took %1ms, at or past the "
|
|
"parent's 3000ms hard-kill threshold")
|
|
.arg(r.stopMs)));
|
|
}
|
|
|
|
// ---------------------------------------------------------------------
|
|
// 4. The two async modes, compared against each other.
|
|
//
|
|
// This is what separates "waited and was released" from "waited out the
|
|
// deadline" WITHOUT trusting a clock: both runs heartbeat at the same
|
|
// interval, so more ticks means more time. The hanging plugin must
|
|
// accumulate strictly more of them, because its wait ends at the 2000ms
|
|
// deadline while the other's ends at its ~1000ms completion.
|
|
//
|
|
// If a future change made "finished" and "gave up" indistinguishable --
|
|
// say by losing the `deadline.isActive()` check, or by never connecting the
|
|
// signal at all -- both runs would sit out the full grace period and these
|
|
// counts would converge. Nothing else in this file would notice.
|
|
// ---------------------------------------------------------------------
|
|
void givingUpOutlastsFinishing()
|
|
{
|
|
const Run finishes = runOne(QStringLiteral(FIXTURE_PLUGIN_FINISHES));
|
|
const Run hangs = runOne(QStringLiteral(FIXTURE_PLUGIN_HANGS));
|
|
|
|
const int finishTicks = finishes.count(QStringLiteral("tick"));
|
|
const int hangTicks = hangs.count(QStringLiteral("tick"));
|
|
qInfo("heartbeat ticks: finishes=%d hangs=%d", finishTicks, hangTicks);
|
|
|
|
QVERIFY2(finishTicks > 0 && hangTicks > 0, "one of the runs never waited");
|
|
QVERIFY2(hangTicks > finishTicks,
|
|
qPrintable(QStringLiteral(
|
|
"the hanging plugin was released after %1 ticks and the "
|
|
"finishing one after %2 -- the host is not distinguishing "
|
|
"unloadFinished() from the deadline")
|
|
.arg(hangTicks).arg(finishTicks)));
|
|
|
|
// And the release really was the signal, not the deadline: the run that
|
|
// signalled must be the shorter one, by more than a tick of slack.
|
|
QVERIFY2(finishes.stopMs < hangs.stopMs,
|
|
"the plugin that signalled completion did not shorten teardown");
|
|
}
|
|
};
|
|
|
|
QTEST_MAIN(TestUiHostUnload)
|
|
#include "test_ui_host_unload.moc"
|