Skip to content

Converse can be timed out and fall through to an entity match during post-boot GIL contention #1027

Open
Open
Converse can be timed out and fall through to an entity match during post-boot GIL contention#1027
Labels
bugSomething isn't workingdiscussiondo we want this?

Description

@goldyfruit
goldyfruit
opened on Oct 13, 2026

What happened

A production hub (11 languages, 18 skills) restarted. Within the first ~60s after "Skills Manager is ready", a session mid-way through a converse-driven game skill (thalovant-skill-twenty-questions, waiting on a yes/no reply) sent "yes". Instead of continuing the game, it matched an unrelated real-world entity ("YES Network", a TV channel) via the m2v-prototype-high pipeline.

Root cause (as far as we can tell from the client side)

IntentService.handle_utterance's pipeline loop (ovos_core/intent_services/service.py) tries each configured pipeline in order through _call_match_bounded, which enforces intents.<pipe_id>.match_timeout (default DEFAULT_MATCH_TIMEOUT = 10). ovos-converse-pipeline-plugin runs first in our pipeline order, ahead of the entity matchers.

Right after a restart, while all of a hub's configured languages are still being trained/compiled in the background (padatious nets, m2v prototypes), the whole process is under heavy GIL contention. We measured individual pipeline match calls taking 5-8.6s of real wall time during this window on otherwise-trivial requests (a plain date-time lookup). Converse's own single match call is future.result(timeout=10); if real wall time for that one call exceeds 10s during this window, _call_match_bounded raises FutureTimeoutError, logs a WARNING, and returns None -- a correct, by-design decline per OVOS-PIPELINE-1 §4.4. The loop then falls through to the next pipeline (m2v-prototype-high), which matches a literal entity instead.

So this isn't a bug in the bounded-match mechanism itself -- it does exactly what its docstring says. It's that a generic, uniform match_timeout (same default for every pipeline) is least appropriate for converse: a stateful, already-in-progress interaction, where declining too early produces a worse outcome (a jarring wrong answer) than a late answer would. Every other pipeline in the chain is a fresh, stateless match where a quick decline-and-fallthrough is the right trade-off.

What we did on our side (not a request to copy it, just data)

intents.<pipe_id>.match_timeout is already overridable per pipeline, so we raised ovos-converse-pipeline-plugin's to 25s on our fleet as a mitigation. This is a config change on our end, not an ovos-core change, and we're reporting it rather than treating it as the real fix.

Ask

Two independent things, either of which would help:

  1. Consider a boot-aware grace period, or a lower bound that increases while any pipeline is still "warming" (there's already a natural signal for this per-plugin, e.g. padatious's own "every language compiled" event) -- so a generic match_timeout isn't the only knob available during the riskiest window.
  2. Consider whether the converse pipeline specifically should get a longer default timeout, or whether a declined converse match should suppress/down-rank (rather than fully enable) the immediately-following literal-entity pipelines for that same utterance, since "wrong answer to an active game" is a worse failure mode than "slightly slow answer".

We don't have a concrete PR here -- this felt like a design trade-off worth maintainer judgment rather than something to patch blind. Happy to provide the measured timings/logs if useful.

Activity

  1. JarbasAl commented on Oct 13, 2026

    @JarbasAl
    JarbasAl
    on Oct 13, 2026
    Member

    increasing converse default timeout is acceptable, but in the end OVOS shouldnt be used before mycroft.ready signal, perhaps we need to revisit this and block any incoming utterance with a default error dialog.

    May be worth PR'ing this to the architecture repo if you have any suggestion, then we officially adopt a new namespace (ovos.ready?) and make this a requirement for spec compliance

  2. JarbasAl
    added
    discussiondo we want this?
    bugSomething isn't working
    on Oct 13, 2026

  3. goldyfruit commented on Oct 13, 2026

    @goldyfruit
    goldyfruit
    on Oct 13, 2026
    Author

    I agree but I think while its loading, we should be able to handle the intents and redirect them to "I'm still starting, keep waiting few more seconds" (something like that).

  4. goldyfruit commented on Oct 13, 2026

    @goldyfruit
    goldyfruit
    on Oct 13, 2026
    Author

    Posted both follow-ups:

    Measuring the before/after on a production hub now and will post the numbers here.

  5. goldyfruit commented on Oct 13, 2026

    @goldyfruit
    goldyfruit
    on Oct 13, 2026
    Author

    Correction to my own #1028: it gates on the wrong signal and does not fix the bug this issue describes. Posting the exact timeline from a saved log of the run the "YES Network" example came from (an 11-language hub):

    13:59:01  IntentService is ready
13:59:47  Skills Manager is ready          <- ProcessState.READY true from here
13:59:50  padaos: compiling in background, serving last compiled state in the meantime
14:00:01  padaos: compiling in background, serving last compiled state in the meantime
14:00:08  padaos: compiling in background, serving last compiled state in the meantime
~14:00:08-14:00:20  "yes" -> thalovant-skill-source-scout "YES Network" (misroute)

    "every language compiled" never appears in this window -- the background compile had not finished when "yes" arrived, ~20s after BOTH readiness signals were already true. A second run against the same hub (same "compiling in background" lines at 14:05:22-14:05:40) passed cleanly only because the test harness I used held the probe until padatious logged "every language compiled".

    So: IntentService.status.check_ready() (what #1028 gates on) is true for the entire window this bug lives in. #1028 cannot fix it as written.

    The real signal is padatious's own internal state: it already knows the difference between "compiling in background, serving last compiled state" and "every language compiled" (self._reported_all_compiled in opm.py), it just isn't on the bus. Reworking #1028 and the architecture#285 proposal to define "ready" as pipelines warm -- each plugin that has one reports its own warm/cold transition, the orchestrator aggregates "every configured pipeline warm" -- rather than process status. A plugin with no such signal counts as warm by default, so this doesn't block on something that can't report.

    One more thing worth stating in the spec: "serving last compiled state in the meantime" on a freshly-started process is serving a stale state (there is no earlier compiled state to serve), which is why the fallthrough lands on a wrong literal entity rather than just being slow -- an unready pipeline should decline, not serve partial/stale state.

    Reworked PRs incoming.

  6. JarbasAl commented on Oct 13, 2026

    @JarbasAl
    JarbasAl
    on Oct 13, 2026
    Member

    Skills Manager is ready <- ProcessState.READY true from here

    then this seems like a third bug, we should delay ProcessState.READY until pipelines are fully ready to serve requests

  7. goldyfruit
    added 2 commits that reference this issue on Oct 13, 2026

    spec(ready-1): define ready as pipelines warm, not process status; fi…

    5c28db0

    fix: gate on the warm aggregate, not process status, and resolve lang…

    da2d5d5

  8. goldyfruit commented on Oct 13, 2026

    @goldyfruit
    goldyfruit
    on Oct 13, 2026
    Author

    skill_manager.py has its own ProcessStatus('skills', ...) and reads self.status.state == ProcessState.READY for its own "done loading skills" check. It is a different component from the intents one, but it is the same mechanism, and mycroft.ready is built from several of these per-component statuses.

    I'd keep ovos.ready (the pipelines-warm aggregate) separate from ProcessState.READY / mycroft.ready, and not make the intents component's own READY wait on it. READY today means "this component finished its own bootstrap", and other deployments may depend on that narrower meaning. Folding pipeline warmth into it would change behavior for every existing consumer of mycroft.ready, not just the utterance lifecycle.

    So the question for you: are you fine with that change, or should ovos.ready stay additive and exist only for this gate? If you'd rather delay READY itself, OVOS-READY-1 needs a compatibility note for the current consumers.

  9. goldyfruit
    added a commit that references this issue on Oct 13, 2026

    feat: a pipeline's own warm/cold transition on the bus (OVOS-READY-1)

    65ea5a6

  10. JarbasAl commented on Oct 13, 2026

    @JarbasAl
    JarbasAl
    on Oct 13, 2026
    Member

    Checked what reads IntentService.status/ProcessState.READY/mycroft.ready before answering:

    * `skill_manager.py` has its own, separate `ProcessStatus('skills', ...)` and reads `self.status.state == ProcessState.READY` for its own "am I done loading skills" check -- a different component's status than the intents one, but the same mechanism, and the aggregate `mycroft.ready` is built from several of these per-component statuses together.

* Our own k8s readiness probe (`readiness_gate.py` in the runtime image) treats this status carefully on purpose: an earlier incident (our own operator [Mismatched converse event names #68](https://github.com/OpenVoiceOS/ovos-core/issues/68)) came from a readiness probe over-counting what "ready" meant for a still-booting pod, and the gate was reworked specifically to avoid conflating "the bus socket answered" with "the component is actually done." That history makes me cautious about silently widening what `ProcessState.READY` means for _any_ component.

    So: I'd recommend keeping ovos.ready (the pipelines-warm aggregate) a separate signal from ProcessState.READY/mycroft.ready, rather than making the intents component's own READY wait on it. Reasons:

    * `ProcessState.READY` today means "this component finished its own bootstrap" for several components, independently, and other code (skill_manager's own gate, our k8s probe, any deployment's health check) depends on that narrower meaning _today_, with no reason to expect it also means "every pipeline's languages/models are warm."

* Folding pipeline-warmth into it would be a **behavior change for every existing consumer of `mycroft.ready`**, not just the utterance lifecycle -- is that breakage you're fine with, or would you rather `ovos.ready` stay additive and purpose-built for this one gate?

    If you'd rather go the other way (delay ProcessState.READY itself), I think it needs an explicit compatibility note in OVOS-READY-1 for every current consumer of mycroft.ready/ProcessState.READY, since none of them asked for a slower readiness signal.

    I'd rather explain it to my claude directly ;)

  11. goldyfruit commented on Oct 13, 2026

    @goldyfruit
    goldyfruit
    on Oct 13, 2026
    Author

    12. > Checked what reads IntentService.status/ProcessState.READY/mycroft.ready before answering:
    > > * `skill_manager.py` has its own, separate `ProcessStatus('skills', ...)` and reads `self.status.state == ProcessState.READY` for its own "am I done loading skills" check -- a different component's status than the intents one, but the same mechanism, and the aggregate `mycroft.ready` is built from several of these per-component statuses together. > > * Our own k8s readiness probe (`readiness_gate.py` in the runtime image) treats this status carefully on purpose: an earlier incident (our own operator [Mismatched converse event names #68](https://github.com/OpenVoiceOS/ovos-core/issues/68)) came from a readiness probe over-counting what "ready" meant for a still-booting pod, and the gate was reworked specifically to avoid conflating "the bus socket answered" with "the component is actually done." That history makes me cautious about silently widening what `ProcessState.READY` means for _any_ component. >
    >
    >
    >
    >
    >
    >
    >
    >
    >
    >
    >
    > So: I'd recommend keeping ovos.ready (the pipelines-warm aggregate) a separate signal from ProcessState.READY/mycroft.ready, rather than making the intents component's own READY wait on it. Reasons:
    > > * `ProcessState.READY` today means "this component finished its own bootstrap" for several components, independently, and other code (skill_manager's own gate, our k8s probe, any deployment's health check) depends on that narrower meaning _today_, with no reason to expect it also means "every pipeline's languages/models are warm." > > * Folding pipeline-warmth into it would be a **behavior change for every existing consumer of `mycroft.ready`**, not just the utterance lifecycle -- is that breakage you're fine with, or would you rather `ovos.ready` stay additive and purpose-built for this one gate? >
    >
    >
    >
    >
    >
    >
    >
    >
    >
    >
    >
    > If you'd rather go the other way (delay ProcessState.READY itself), I think it needs an explicit compatibility note in OVOS-READY-1 for every current consumer of mycroft.ready/ProcessState.READY, since none of them asked for a slower readiness signal.

     I'd rather explain it to my claude directly ;)

    Sure, it will be easier!

  12. goldyfruit commented on Oct 13, 2026

    @goldyfruit
    goldyfruit
    on Oct 13, 2026
    Author

    The gap my last canary showed is closed in #1028 (eb18e47, plus a follow-up). Ready to answer now also needs the skill manager's first load: the gate waits on mycroft.skills.initialized, latched, so a skill installed or reloaded later cannot turn a ready system back into a not-ready one. Before, on the same hub, a bare "yes" after "let's play twenty questions" misrouted from 87 to 110 s after container start (89 to 120 s on another restart), because padatious was warm at about 80 s while skills kept loading until about 125 s. With the change I restarted it three times, once with extra load probes, and probed every 3 s. There were 0 misroutes in all three. "Still starting" ended at 138, 156 and 141 s, and every answer after that was the twenty-questions skill's own. The spec side is in OpenVoiceOS/architecture#285.

  13. goldyfruit commented on Oct 14, 2026

    @goldyfruit
    goldyfruit
    on Oct 14, 2026
    Author

    The design in #1028 now follows the model discussed here: IntentService.status reaches READY only once no pipeline is loading (pipelines are loading or loaded, no warm/cold), and an utterance gets the "still starting" reply until the service is READY, the first skill load is done and no pipeline is loading. One open question for you is on that PR: whether the skills condition should live in the skills status instead. OpenVoiceOS/architecture#285 is aligned.

  14. JarbasAl commented on Oct 14, 2026

    @JarbasAl
    JarbasAl
    on Oct 14, 2026
    Member

    OpenVoiceOS/ovos-workshop#714 this regression was probably a factor in your initial timeouts

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    bugSomething isn't workingdiscussiondo we want this?

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions