[
https://issues.apache.org/jira/browse/KARAF-7450?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17553215#comment-17553215
]
Jean-Baptiste Onofré commented on KARAF-7450:
---------------------------------------------
By the way, I don't think the problem is in Karaf internals; but most probably
in your application.
> Karaf failing to start bundle because of a dependency that is available
> -----------------------------------------------------------------------
>
> Key: KARAF-7450
> URL: https://issues.apache.org/jira/browse/KARAF-7450
> Project: Karaf
> Issue Type: Bug
> Components: karaf
> Affects Versions: 4.4.0, 4.2.14
> Environment: Windows 10 Pro
> Karaf 4.2.14 ( I tried 4.4.0 as well )
> 32gb of memory
>
> I do have two kar files that also load up, but the problem is with bundles in
> the system folder. All of the problem bundles are part of system folder with
> everything else.
> Reporter: Brent Shores
> Priority: Critical
> Attachments: karaf.log.1
>
>
> When I start up my karaf application, I'm getting a lot of bundles that
> initially go into a GracePeriod state, and then move from there to Failure
> after they timeout. When I start following the dependency chain, I got down
> to the top-level one and it had a dependency on another bundle that was
> successfully loaded up. For my example, the bundle I'm looking at is this: (
> from the list command)
>
> 74 | Failure | 82 | 1.5.1 | inventorysrvc-ext
>
> Then I look at the diagnostic for it:
> Run "diag 74"
>
> karaf@root()> diag 74
> inventorysrvc-ext (74)
> ----------------------
> Status: Failure
> Blueprint
> 6/6/22 8:40 AM
> Exception:
> null
> java.util.concurrent.TimeoutException
> at
> org.apache.aries.blueprint.container.BlueprintContainerImpl$1.run(BlueprintContainerImpl.java:393)
> at
> org.apache.aries.blueprint.utils.threading.impl.DiscardableRunnable.run(DiscardableRunnable.java:45)
> at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
> at java.lang.Thread.run(Thread.java:748)
>
> Missing dependencies:
> (objectClass=com.toshibacommerce.service.inventorysrvc.api.IInventoryHelper)
> Declarative Services
> CdiOsgi
> So it's missing IInventoryHelper. Except looking at my code, that
> IInventoryHelper is being added inside my inventorysrvc-helper bundle.
> Here's the blueprint for that:
> <blueprint xmlns="http://www.osgi.org/xmlns/blueprint/v1.0.0";
> xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance";
> xsi:schemaLocation="http://www.osgi.org/xmlns/blueprint/v1.0.0
> http://www.osgi.org/xmlns/blueprint/v1.0.0/blueprint.xsd";>
> <!-- registering inventory helper services -->
> <bean id="invHelper"
> class="com.toshibacommerce.service.inventorysrvc.helper.InventoryHelper">
> <property name="confProperty" ref="confProperty" />
> </bean>
> <service ref="invHelper"
> interface="com.toshibacommerce.service.inventorysrvc.api.IInventoryHelper" />
> <reference id="confProperty"
> interface="com.toshibacommerce.commons.props.api.IConfigProperty" />
> </blueprint>
>
> This bundle status:
> 75 | Active | 80 | 1.5.1 | inventorysrvc-helper
>
> So I think I'm just in a bad order and it failed to load, so I restart 74,
> because I know it's one missing dependency is available now.
>
> karaf@root()> restart 74
>
> And it does the same GracePeriod or Failure with the same timeout exception.
> No other useful errors even with log level turned up. Only error in logs is:
> There error shown in the logs at the initial startup is:
> [ERROR] 06/06/2022 10:52:16.074 [Blueprint Extender: 1]
> BlueprintContainerImpl[396] - Unable to start container for blueprint bundle
> inventorysrvc-ext/1.5.1 due to unresolved dependencies
> [(objectClass=com.toshibacommerce.service.inventorysrvc.api.IInventoryHelper)]
> java.util.concurrent.TimeoutException: null
> at
> org.apache.aries.blueprint.container.BlueprintContainerImpl$1.run(BlueprintContainerImpl.java:393)
> [!/:1.10.3]
> at
> org.apache.aries.blueprint.utils.threading.impl.DiscardableRunnable.run(DiscardableRunnable.java:45)
> [!/:1.10.3]
> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
> [?:1.8.0-292]
> at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0-292]
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
> [?:1.8.0-292]
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
> [?:1.8.0-292]
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
> [?:1.8.0-292]
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
> [?:1.8.0-292]
> at java.lang.Thread.run(Thread.java:748)
> [?:1.8.0-292]
>
> Which doesn't tell me much. When I attempt to start the bundle, nothing
> happens. I'm hoping there is some sort of logging I can turn on or something
> to see more info on the missing dependency and why it thinks it's not there
> when it is.
>
> I'm attaching the full log file. Ignore anything before 8:35am. Also there
> are a bunch of errors from a cloudforwarder services. That's just because it
> can't reach it's rest service. Not an issue.
>
> When I did a restart it showed slightly different in logs:
>
> [INFO ] 06/07/2022 07:14:59.780 [pipe-restart 74] BlueprintExtender[358] -
> Destroying container for blueprint bundle inventorysrvc-ext/1.5.1
> [INFO ] 06/07/2022 07:14:59.824 [pipe-restart 74] Activator[45] - Stopping
> the Inventorysrvc-ext bundle
> [INFO ] 06/07/2022 07:14:59.824 [pipe-restart 74] Activator[36] - Starting
> the Inventorysrvc-ext bundle
> [INFO ] 06/07/2022 07:14:59.840 [pipe-restart 74] BlueprintContainerImpl[408]
> - Blueprint bundle inventorysrvc-ext/1.5.1 is waiting for dependencies
> [(objectClass=com.toshibacommerce.service.inventorysrvc.api.IInventoryHelper)]
> [INFO ] 06/07/2022 07:14:59.918 [pipe-restart 74] CommandExtension[108] -
> Command registration delayed for bundle inventorysrvc-ext/1.5.1. Missing
> service:
> [com.toshibacommerce.service.inventorysrvc.ext.trigger.IInventoryTrigger,
> com.toshibacommerce.service.inventorysrvc.ext.cfg.IConfig]
>
> Both of those dependencies it's mentioning are actually in the
> inventorysrvc-ext bundle, so now it's failing to load itself?
>
> Yeah, so that's my issue. I have the dependencies in place, but Karaf won't
> load my bundle. If I do a "feature:install transaction", which forces it to
> unload and reload a bunch of things, it will come up.
>
> My theory is a race condition going on somehow. On faster machines, it seems
> to work more often, slower machines, it's more likely to get hung here. If I
> wipe the data directory and restart it might come up, might not. If I just
> restart without deleting data, it fails most of the time.
--
This message was sent by Atlassian Jira
(v8.20.7#820007)
