Files
Dario LipicarandClaude Opus 5 e9f134f5aa fix: draw the line at LOADED, not merely known — for both watch and call (#109)
* fix(watch): defer the subscription instead of refusing a module that is not up yet

`logoscore watch <module>` answered WATCH_FAILED and exited whenever the
module's registry socket had no listener at that instant, and nothing ever
retried. Two ordinary states hit it:

  * subscribing before the module is loaded at all;
  * subscribing in the window after `load-module` RETURNS but before the
    module publishes its object. `load-module` answers once the plugin is
    in; publishing happens afterwards.

Measured on macOS, cold first load of a freshly built plugin:

    .803  Registry connect attempt started (no peer contact yet)
    .804  LogosAPIConsumer: Requesting object: "modules_state"
    .804  Warning: Not connected to registry. Cannot request object
    .957  [modules_state] RemoteTransportHost: Published object

Refused at .804; published 153 ms later. The refusal is
LogosAPIConsumer::requestObject's `isConnected()` guard --
`m_connected && endpointHasListener()`, a socket liveness probe. This is the
third un-migrated instance of the one-shot subscribe shape; the generated Qt
wrappers and the QML bridge both moved to onEventWhenAvailable already.

The dangerous part was never the failure, it was that nothing checked it: a
script's only event assertion went dead while every later line still passed.

It is also inconsistent with the call path, for identical input. Same module,
same instant, not loaded:

    watch  -> WATCH_FAILED in    139 ms
    call   -> RPC_FAILED  in 20 544 ms

invokeRemoteMethod reaches the transport through acquireCachedObject and never
sees the guard, so it waits out waitForSource(20s). One path gave up in a
millisecond, the other waited 20 seconds.

Named events now go through onEventWhenAvailable, which holds the subscription,
arms it when the module appears (including one loaded later in the session) and
re-arms across a reconnect. The wildcard form (`watch <module>` with no
--event) cannot: it subscribes with an EMPTY event name, which LogosObject
reads as "every event" but onEventWhenAvailable refuses outright -- so a fix
covering only the named form would have left the CLI's DEFAULT invocation
silently dead. It goes through whenObjectAvailable instead.

Deferring must not swallow a typo, so a name the host has never heard of still
fails fast rather than parking on a subscription with no future. Before this
change both cases failed identically and that was free; now it is pinned.

Three tests in each integration suite, against a fixture whose module is
discoverable but NOT loaded -- deterministic, where reproducing via a
post-load-module subscribe needs a cold machine. Verified as a negative
control: with the tests present and this fix reverted, both "arms later" tests
fail with the exact production signature,

    {"code":"WATCH_FAILED","message":"Failed to watch events for module
     'test_basic_module'.","status":"error"}

and WatchUnknownModuleStillFailsFast passes, confirming it pins existing
behaviour rather than the new path. With the fix: checks.tests-logoscore and
checks.tests-logosctl both green (250 + 30 + 27 tests), the two arming tests
dropping from 64s/70s of failing poll loop to 1.8s/1.9s.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>

* fix(watch): draw the line at LOADED, not merely known

Follow-up to the previous commit, which gated on getKnownModuleNames() and so
deferred a subscription for any module the host had ever heard of. That made
`watch` on an unloaded module park forever on a subscription that might never
arm — measured here as `timeout 12` reporting 124, with no answer printed at
all. A module that is not loaded may never be, so refusing is the useful
answer, and a typo now gets that same answer rather than a worse one.

The contract is two halves:

  * NOT LOADED -> fail fast. Already true before any of this; now pinned.
  * LOADED     -> always succeed. This is the half that was broken, and the
    reason the deferred path is here at all: `load-module` returns once the
    plugin is in, but the module publishes its object afterwards, so there is a
    window where the host reports a module loaded and the one-shot
    requestObject() refused it. Cold, that window is seconds.

Past the loaded check the subscription cannot fail, by construction:
onEventWhenAvailable / whenObjectAvailable answer 0 only for arguments they
refuse (empty name, null callback), none reachable here, and neither touches
the transport on the calling thread.

COVERAGE, stated plainly because it got weaker and the weakness is not visible
from a green run. The unloaded half is deterministic — the fixture's daemon
starts with the module discoverable but not loaded, and that state holds still.
The loaded half is NOT, and cannot be made so from the CLI: nothing can hold a
module in "loaded but not yet published". Verified rather than assumed — with
these tests against the ORIGINAL master implementation, all three PASS on a warm
machine. They bite on a cold CI worker, which is where the failure was seen,
but they are not a warm-machine regression net.

Two deterministic alternatives were considered and rejected. Subscribing before
the load reproduced it reliably, and was what the previous commit tested, but it
is no longer valid behaviour under this contract. Crashing the module leaves it
briefly listed as loaded with its socket gone — the right state, reached by a
race, since the daemon's SIGCHLD handler flips it out of "loaded"
asynchronously. A racing test is worse than none.

checks.tests-logoscore and checks.tests-logosctl both green (250 + 30 + 27).

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>

* fix(call): draw the line at LOADED, not merely known

The same line the previous commit drew for `watch`. `callModuleMethod` had no
precondition at all: its `!moduleClient` guard can never fire, because
LogosAPI::getClient constructs a client for any name and never returns null.

So an absent module was found the expensive way, and two 20s deadlines raced to
report it — the daemon's acquire (object_unavailable) against the CLI client's
own RPC deadline (RPC_FAILED, a client-side literal the daemon cannot emit).
Measured: 17 calls split 5/12 across the two codes, all at 19.99-20.43s.

Not fixed by a shorter deadline: one Timeout feeds both the acquire and the
call, and the long acquire is the documented startup contract. The daemon
already has an in-process answer and already uses it in watchModuleEvents.

core_service is exempt (published by the daemon's own provider, never in the
loaded set). The startup window is unaffected: liblogos marks loaded before
publish, so a warming module passes the gate and keeps its full budget.

Tests assert the property, not a tally — the old behaviour was bimodal per run,
so sampling can pass unfixed. A positive control covers the load->publish
window, which is what a shortened deadline would break. Two assertions in
NoLoadNegativePaths were passing BY hanging (timeout's 124 is non-zero); both
now exclude it.

Follow-ups, not in this commit: logos-test-modules conformance still expects
["object_unavailable","RPC_FAILED"] for failure/A/module-not-loaded and must
move with the relock; test_integration_logoscore.cpp has the same two
hang-masked assertions.

checks.tests green: logosctl 250 + 30 + 29, logoscore 20 + 27.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>

* chore(deps): protocol 303ab08 — the last level of the carrier chain

Bumps logos-protocol, logos-plugin-qt and logos-liblogos together. The three
levels below are logos-plugin-qt#30, logos-qt-sdk#46 and logos-liblogos#190.

Bumping ONLY this repo's own logos-protocol input does not work, and that is not
a lock-tidiness opinion -- it was measured. That bump moves 1 of 230 protocol
nodes, builds green, and ships a liblogos_protocol.dylib WITHOUT the change,
because the runtime library is staged by a CARRIER rather than by this input. Of
everything in the closure only logos-protocol, logos-plugin-qt and
logos-liblogos carry one; cpp-sdk, capability-module, package-manager,
package-downloader and test-modules do not. Nothing fails when you get this
wrong -- the lock diff is real, the build is green, and the daemon loads a
library without the fix.

The lock still holds 230 protocol nodes at 16 revs afterwards. That is the usual
explosion and it is not what ships; the closure is the claim:

    protocol paths in the built daemon closure: exactly ONE
    n7yilrs2...-logos-protocol-lib-0.8.0        (the build of 303ab08)

    shipped liblogos_protocol.dylib:
      "(any)" (UTF-16)   x1      <- present only in 303ab08
      old warning        x0
      new warning        x2      <- whenObjectAvailable + the fixed onEventWhenAvailable

Both halves of that are needed. `strings` cannot see "(any)" because
QStringLiteral is UTF-16, and the new warning text appears once even in the OLD
library because whenObjectAvailable has always used it -- checking either alone
reports the wrong answer, which it did here first time round.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>

* refactor(watch): both subscription forms are now one call

logos-protocol#74 let onEventWhenAvailable take an EMPTY event name as the
wildcard, so the detour the wildcard form needed is gone: whenObjectAvailable()
+ requestObject() + onEvent(), a QPointer guard and a nested lambda collapse
into the same one-line call the named form already made.

The detour existed because ONE guard rejected three unrelated arguments at once
-- an empty object name and a null callback, which are unusable, and an empty
event name, which is meaningful and which the plain onEvent has always honoured.
Routing around it kept `watch <module>` with no --event working, but left the
CLI's DEFAULT invocation on a different code path from its --event form, which
is the shape a silent regression hides in.

Requires the lock bump in the previous commit: against the old library
onEventWhenAvailable answers 0 for an empty name, so the wildcard would refuse.
That is not a latent trap -- WildcardWatchSucceedsTheInstantLoadModuleReturns
fails loudly on exactly it, in both suites.

checks.tests-logoscore and checks.tests-logosctl both green (20+27 and
250+30+29), status read from nix rather than from a pipeline.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>

* test(call): mirror the loaded-set gate cases into the logoscore suite

The gate landed with coverage in tests/test_integration.cpp only, so the
`logoscore` binary had none for it -- and the two binaries compile from separate
files, so "the other suite covers it" is not true here. The `watch` cases for
the same gate are already in both.

Ports both cases plus the hardening of NoLoadNegativePaths: `timeout` also exits
non-zero, so its two "call must not succeed" assertions passed BY hanging, and
now exclude 124 explicitly.

Verified as coverage, not as compilation. With the gate deleted from
callModuleMethod and nothing else changed:

    FAILED  ErrorPathTest.NoLoadNegativePaths                         (25012 ms)
    FAILED  ErrorPathTest.CallOnAModuleThatIsNotLoadedIsRefusedNotAwaited (10929 ms)
    OK      ErrorPathTest.CallImmediatelyAfterLoadStillReachesTheModule (924 ms)

The two negative cases fail on the timeouts they exist to forbid, and the
positive control stays green -- which is the point of shipping it alongside
them: it is what a shortened acquire deadline would break while the negative
cases still passed. Restored, both suites green.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>

---------

Co-authored-by: Claude Opus 5 <noreply@anthropic.com>
2026-08-26 23:02:47 -03:00
..
2026-05-21 15:28:27 -04:00