Conversation
…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
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Fixes #217
Root cause
The issue correctly points at
scheduleCheckStartup(2000)inHealthService.activate(), but the reason that path is taken is not "the framework is already started" — it is a race withFrameworkEvent.PACKAGES_REFRESHED:HealthService.activate()runs onFelixStartLevelwhile the framework is still raising its start level. It registers itsFrameworkListenerand, ~25 ms later (fourrouter.addRoute(...)calls with class loading), evaluatesFrameworkStatus.isReady().FrameworkStatusis only ever updated by that listener, andisReady()countsPACKAGES_REFRESHED,STARTLEVEL_CHANGED,WARNINGandINFOas "ready" — none of which means the framework has started.samples/workflow,ActivitiServiceImplcreates a FileInstall watcher forworkflow/withfelix.fileinstall.noInitialDelay=true, so the.barfiles 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 firesPACKAGES_REFRESHED. When that event lands inside the ~25 ms window,isReady()istrue, the 2 s timer is scheduled, and it fires beforeapi-servletis registered — henceSEVERE: OpenIDM failure during startupimmediately followed byOpenIDM ready.This explains why only the
samples/workflowlegs flake (only that sample ships.barfiles) and why the failure is intermittent: passing runs of the same leg show 3–4 s between activation andOpenIDM readywith no SEVERE, which rules out a deterministic 2 s timer. Note that in CIopenidm.healthservice.servicestartmaxis already 900000 (boot.propertiessince #166), so theSTARTEDpath 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_REFRESHEDdelivered 6 ms after listener registration →isReady=true→delay=2000→ SEVERE 2.0 s later, exactly as in the CI logs.Fix
getBundle(0).getState() == ACTIVE) instead ofFrameworkStatus, and treat that case like a lateSTARTEDevent: setframeworkStarted, runcheckState(), and schedule the readiness check afterserviceStartMax— the same grace period as theSTARTEDpath, instead of the hard-coded 2000 ms.FrameworkStatus; nothing else used it.BundleContextfrom theComponentContext(same bundle context) soactivate()can be exercised outside OSGi.HealthServiceTestcovering both paths: aPACKAGES_REFRESHEDdelivered during activation no longer triggers a start-up check (fails on master withexpected [STARTING] but found [ACTIVE_NOT_READY]), and an already-active framework schedules the check afterservicestartmax(fails on master withexpected [ACTIVE_NOT_READY] but found [STARTING]).End-to-end: with the fixed class in the same CI-like layout the race occurred naturally (
PACKAGES_REFRESHEDdelivered insideactivate()), no SEVERE was logged and the server reachedOpenIDM ready.