Skip to content

[#217] Do not treat PACKAGES_REFRESHED as a started framework in HealthService - #224

Open
vharseko wants to merge 1 commit into
OpenIdentityPlatform:masterfrom
vharseko:healthservice-startup-check-217
Open

vharseko wants to merge 1 commit into
OpenIdentityPlatform:masterfrom
vharseko:healthservice-startup-check-217

Conversation

@vharseko

Copy link
Copy Markdown
Member

Fixes #217

Root cause

The issue correctly points at scheduleCheckStartup(2000) in HealthService.activate(), but the reason that path is taken is not "the framework is already started" — it is a race with FrameworkEvent.PACKAGES_REFRESHED:

  • HealthService.activate() runs on FelixStartLevel while the framework is still raising its start level. It registers its FrameworkListener and, ~25 ms later (four router.addRoute(...) calls with class loading), evaluates FrameworkStatus.isReady().
  • FrameworkStatus is only ever updated by that listener, and isReady() counts PACKAGES_REFRESHED, STARTLEVEL_CHANGED, WARNING and INFO as "ready" — none of which means the framework has started.
  • On samples/workflow, ActivitiServiceImpl creates a FileInstall watcher for workflow/ with felix.fileinstall.noInitialDelay=true, so the .bar files are installed immediately, on the CM thread, in parallel with the start-level ascent. FileInstall 3.6.4 always refreshes freshly installed bundles, and Felix fires PACKAGES_REFRESHED. When that event lands inside the ~25 ms window, isReady() is true, the 2 s timer is scheduled, and it fires before api-servlet is registered — hence SEVERE: OpenIDM failure during startup immediately followed by OpenIDM ready.

This explains why only the samples/workflow legs flake (only that sample ships .bar files) and why the failure is intermittent: passing runs of the same leg show 3–4 s between activation and OpenIDM ready with no SEVERE, which rules out a deterministic 2 s timer. Note that in CI openidm.healthservice.servicestartmax is already 900000 (boot.properties since #166), so the STARTED path never reports anything within a job.

Verified with an instrumented build of the 7.1.3-SNAPSHOT distribution (bundle order arranged as in CI): PACKAGES_REFRESHED delivered 6 ms after listener registration → isReady=truedelay=2000 → SEVERE 2.0 s later, exactly as in the CI logs.

Fix

  • Decide "framework already started" by the state of the system bundle (getBundle(0).getState() == ACTIVE) instead of FrameworkStatus, and treat that case like a late STARTED event: set frameworkStarted, run checkState(), and schedule the readiness check after serviceStartMax — the same grace period as the STARTED path, instead of the hard-coded 2000 ms.
  • Remove FrameworkStatus; nothing else used it.
  • Take the BundleContext from the ComponentContext (same bundle context) so activate() can be exercised outside OSGi.
  • Add HealthServiceTest covering both paths: a PACKAGES_REFRESHED delivered during activation no longer triggers a start-up check (fails on master with expected [STARTING] but found [ACTIVE_NOT_READY]), and an already-active framework schedules the check after servicestartmax (fails on master with expected [ACTIVE_NOT_READY] but found [STARTING]).

End-to-end: with the fixed class in the same CI-like layout the race occurred naturally (PACKAGES_REFRESHED delivered inside activate()), no SEVERE was logged and the server reached OpenIDM ready.

…ed framework in HealthService

HealthService.activate() scheduled its start-up readiness check 2 s after
activation whenever FrameworkStatus.isReady() was true. FrameworkStatus was
only fed by the listener registered in the same activate() call and counted
PACKAGES_REFRESHED, STARTLEVEL_CHANGED, WARNING and INFO as "ready". On
samples/workflow the Activiti FileInstall (noInitialDelay=true) installs and
refreshes the .bar bundles while the framework is still raising its start
level; when the resulting PACKAGES_REFRESHED event landed in the ~25 ms
between addFrameworkListener() and the isReady() check, a 2 s timer fired
before api-servlet was registered and logged "SEVERE: OpenIDM failure during
startup" although the server became ready moments later.

Decide "framework already started" by the system bundle state instead, treat
that case like a late STARTED event (set frameworkStarted, checkState, then
schedule the check after serviceStartMax rather than a hard-coded 2000 ms),
and drop FrameworkStatus. Take the BundleContext from the ComponentContext so
activate() can be exercised outside OSGi, and add tests for both paths.

Fixes OpenIdentityPlatform#217
@vharseko vharseko added bug Something isn't working java Pull requests that update Java code test Tests and test infrastructure (unit, e2e, smoke) ci CI/CD, build and release workflows workflow Activiti workflow engine / scripting samples Sample configurations and use cases concurrency Thread-safety, locking and synchronization issues labels Sep 19, 2026
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

bug Something isn't working ci CI/CD, build and release workflows concurrency Thread-safety, locking and synchronization issues java Pull requests that update Java code samples Sample configurations and use cases test Tests and test infrastructure (unit, e2e, smoke) workflow Activiti workflow engine / scripting

Projects

None yet

Development

Successfully merging this pull request may close these issues.

ui-smoke-tests flaky on samples/workflow: HealthService reports "OpenIDM failure during startup" 2 s after activation

1 participant