You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@karaf.apache.org by "Grzegorz Grzybek (Jira)" <ji...@apache.org> on 2021/04/28 11:34:00 UTC
[jira] [Updated] (KARAF-7126) State overwrite when installing more
features at once
[ https://issues.apache.org/jira/browse/KARAF-7126?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Grzegorz Grzybek updated KARAF-7126:
------------------------------------
Description:
I had a case, where (which is not recommended) two feature XML files were dropped into {{deploy/}} directory.
_Often_ (but not always) one of the features was not marked as "Started" - and it happened in random order.
It can be reproduced with {{simple1.xml}} file:
{code:xml}
<?xml version="1.0" encoding="UTF-8" standalone="yes"?>
<features xmlns="http://karaf.apache.org/xmlns/features/v1.3.0" name="simple1">
<feature name="simple1" version="0.0.1" install="auto">
<bundle start-level="80" start="true">mvn:commons-io/commons-io/2.8.0</bundle>
</feature>
</features>
{code}
and {{simple2.xml}}:
{code:xml}
<?xml version="1.0" encoding="UTF-8" standalone="yes"?>
<features xmlns="http://karaf.apache.org/xmlns/features/v1.3.0" name="simple2">
<feature name="simple2" version="0.0.1" install="auto">
<bundle start-level="80" start="true">mvn:commons-collections/commons-collections/3.2.2</bundle>
</feature>
</features>
{code}
dropped at the same time to {{deploy/}} directory.
Here's my investigation:
1. deploy two files
2. these artifacts are processed in single fileinstall thread:
{noformat}
0 = {org.apache.felix.fileinstall.internal.Artifact@11682}
path: java.io.File = {java.io.File@11683} "/data/karaf/deploy/simple1.xml"
jaredDirectory: java.io.File = {java.io.File@11683} "/data/karaf/deploy/simple1.xml"
jaredUrl: java.net.URL = {java.net.URL@11703} "file:/data/karaf/deploy/simple1.xml"
listener: org.apache.felix.fileinstall.ArtifactListener = {org.apache.karaf.deployer.features.FeatureDeploymentListener@11698}
transformedUrl: java.net.URL = {java.net.URL@11646} "feature:file:/data/karaf/deploy/simple1.xml"
transformed: java.io.File = null
bundleId: long = -1 (0xFFFFFFFFFFFFFFFF)
checksum: long = 1818582559 (0x6C655E1F)
1 = {org.apache.felix.fileinstall.internal.Artifact@11694}
path: java.io.File = {java.io.File@11696} "/data/karaf/deploy/simple2.xml"
jaredDirectory: java.io.File = {java.io.File@11696} "/data/karaf/deploy/simple2.xml"
jaredUrl: java.net.URL = {java.net.URL@11697} "file:/data/karaf/deploy/simple2.xml"
listener: org.apache.felix.fileinstall.ArtifactListener = {org.apache.karaf.deployer.features.FeatureDeploymentListener@11698}
transformedUrl: java.net.URL = {java.net.URL@11699} "feature:file:/data/karaf/deploy/simple2.xml"
transformed: java.io.File = null
bundleId: long = -1 (0xFFFFFFFFFFFFFFFF)
checksum: long = 3138423735 (0xBB108BB7)
{noformat}
3. single instance of org.apache.karaf.deployer.features.FeatureURLHandler has its org.apache.karaf.deployer.features.FeatureURLHandler#featureXmlURL set to file:/data/karaf/deploy/simple1.xml
stack trace:
{noformat}
"fileinstall-/data/karaf/deploy@11585" daemon prio=5 tid=0x2e nid=NA runnable
java.lang.Thread.State: RUNNABLE
at org.apache.karaf.deployer.features.FeatureURLHandler.openConnection(FeatureURLHandler.java:56)
at org.apache.felix.framework.URLHandlersStreamHandlerProxy.openConnection(URLHandlersStreamHandlerProxy.java:271)
at java.net.URL.openConnection(URL.java:1002)
at java.net.URL.openStream(URL.java:1068)
at org.apache.felix.fileinstall.internal.DirectoryWatcher.install(DirectoryWatcher.java:962)
at org.apache.felix.fileinstall.internal.DirectoryWatcher.install(DirectoryWatcher.java:884)
at org.apache.felix.fileinstall.internal.DirectoryWatcher.doProcess(DirectoryWatcher.java:489)
at org.apache.felix.fileinstall.internal.DirectoryWatcher.process(DirectoryWatcher.java:365)
at org.apache.felix.fileinstall.internal.DirectoryWatcher.run(DirectoryWatcher.java:316)
{noformat}
4. in org.apache.felix.fileinstall.internal.DirectoryWatcher#installOrUpdateBundle, simple1 is processed
5. log message:
{noformat}
Installing bundle simple1.xml / 0.0.0
{noformat}
6. org.osgi.framework.BundleContext#installBundle() for simple1
7. featureXmlURL is set to simple2.xml
8. log message:
{noformat}
Installing bundle simple2.xml / 0.0.0
{noformat}
9. org.osgi.framework.BundleContext#installBundle() for simple2
Now:
{noformat}
240 │ Installed │ 80 │ 0.0.0 │ feature:file:/data/karaf/deploy/simple1.xml
241 │ Installed │ 80 │ 0.0.0 │ feature:file:/data/karaf/deploy/simple2.xml
{noformat}
10. Of course org.apache.felix.fileinstall.internal.DirectoryWatcher#doProcess() uses HashMaps... that's why bundle2 may be started earlier
11. org.apache.felix.fileinstall.internal.FileInstall#refresh() is called for the two bundles in random order - but they're still in INSTALLED state
12. org.apache.felix.fileinstall.internal.DirectoryWatcher#startBundles() is called
13. org.osgi.framework.Bundle#start(int) is called for each bundle and the event is caught by:
{noformat}
"FelixDispatchQueue@11772" prio=5 tid=0xd nid=NA runnable
java.lang.Thread.State: RUNNABLE
at org.apache.karaf.deployer.features.FeatureDeploymentListener.bundleChanged(FeatureDeploymentListener.java:186)
- locked <0x2db2> (a org.apache.karaf.deployer.features.FeatureDeploymentListener)
at org.apache.felix.framework.EventDispatcher.invokeBundleListenerCallback(EventDispatcher.java:915)
at org.apache.felix.framework.EventDispatcher.fireEventImmediately(EventDispatcher.java:834)
at org.apache.felix.framework.EventDispatcher.run(EventDispatcher.java:1147)
at org.apache.felix.framework.EventDispatcher.access$000(EventDispatcher.java:54)
at org.apache.felix.framework.EventDispatcher$1.run(EventDispatcher.java:102)
at java.lang.Thread.run(Thread.java:748)
{noformat}
14. eventually two tasks are correctly passed to single featuresService pool
the first one (running). It has these vars reachable:
{noformat}
this = {org.apache.karaf.features.internal.service.FeaturesServiceImpl$$Lambda$108.830131376@12778}
arg$1: org.apache.karaf.features.internal.service.FeaturesServiceImpl = {org.apache.karaf.features.internal.service.FeaturesServiceImpl@12631}
arg$2: java.util.Set = {java.util.HashSet@12648} size = 1
arg$3: java.util.Map = {java.util.HashMap@12643} size = 1
arg$4: java.util.Map = {java.util.Collections$EmptyMap@12644} size = 0
arg$5: org.apache.karaf.features.internal.service.State = {org.apache.karaf.features.internal.service.State@12645}
arg$6: java.util.Map = {java.util.HashMap@12646} size = 621
arg$7: java.util.EnumSet = {java.util.RegularEnumSet@12647} size = 0
arg$8: java.lang.String = null
{noformat}
the second one (waiting). It has these vars reachable:
{noformat}
callable: java.util.concurrent.Callable = {org.apache.karaf.features.internal.service.FeaturesServiceImpl$$Lambda$108.830131376@12760}
arg$1: org.apache.karaf.features.internal.service.FeaturesServiceImpl = {org.apache.karaf.features.internal.service.FeaturesServiceImpl@12631}
arg$2: java.util.Set = {java.util.HashSet@12663} size = 1
arg$3: java.util.Map = {java.util.HashMap@12659} size = 1
arg$4: java.util.Map = {java.util.Collections$EmptyMap@12644} size = 0
arg$5: org.apache.karaf.features.internal.service.State = {org.apache.karaf.features.internal.service.State@12660}
arg$6: java.util.Map = {java.util.HashMap@12661} size = 622
arg$7: java.util.EnumSet = {java.util.RegularEnumSet@12662} size = 0
arg$8: java.lang.String = null
{noformat}
The only important difference is that 2nd task already has larger map of features.
State of the running task:
{noformat}
state = {org.apache.karaf.features.internal.service.State@12645}
bootDone: java.util.concurrent.atomic.AtomicBoolean = {java.util.concurrent.atomic.AtomicBoolean@17577} "true"
repositories: java.util.Set = {java.util.TreeSet@17578} size = 13
requirements: java.util.Map = {java.util.HashMap@17579} size = 1
installedFeatures: java.util.Map = {java.util.HashMap@17580} size = 1
stateFeatures: java.util.Map = {java.util.HashMap@17581} size = 1
managedBundles: java.util.Map = {java.util.HashMap@17582} size = 1
bundleChecksums: java.util.Map = {java.util.HashMap@17583} size = 0
{noformat}
State of the waiting task:
{noformat}
arg$5: org.apache.karaf.features.internal.service.State = {org.apache.karaf.features.internal.service.State@12660}
bootDone: java.util.concurrent.atomic.AtomicBoolean = {java.util.concurrent.atomic.AtomicBoolean@17644} "true"
repositories: java.util.Set = {java.util.TreeSet@17645} size = 14
requirements: java.util.Map = {java.util.HashMap@17646} size = 1
installedFeatures: java.util.Map = {java.util.HashMap@17647} size = 1
stateFeatures: java.util.Map = {java.util.HashMap@17648} size = 1
managedBundles: java.util.Map = {java.util.HashMap@17649} size = 1
bundleChecksums: java.util.Map = {java.util.HashMap@17650} size = 0
{noformat}
15. Even at first line of org.apache.karaf.features.internal.service.FeaturesServiceImpl#doProvision(), feature:list already gives me:
{noformat}
karaf@root()> feature:list | grep simple
simple1 │ 0.0.1 │ │ Uninstalled │ simple1 │
simple2 │ 0.0.1 │ │ Uninstalled │ simple2 │
{noformat}
16. When 2nd task runs, there are two State instances:
the state attached to 2nd task just started:
{noformat}
State@12660
bootDone: java.util.concurrent.atomic.AtomicBoolean = {java.util.concurrent.atomic.AtomicBoolean@17644} "true"
repositories: java.util.Set = {java.util.TreeSet@17645} size = 14
requirements: java.util.Map = {java.util.HashMap@17646} size = 1
installedFeatures: java.util.Map = {java.util.HashMap@17647} size = 1
"root" -> {java.util.HashSet@52251} size = 120
stateFeatures: java.util.Map = {java.util.HashMap@17648} size = 1
managedBundles: java.util.Map = {java.util.HashMap@17649} size = 1
bundleChecksums: java.util.Map = {java.util.HashMap@17650} size = 0
{noformat}
the state copied to features service after first task finishes - in this state, simple1 is already installed
{noformat}
State@12846
bootDone: java.util.concurrent.atomic.AtomicBoolean = {java.util.concurrent.atomic.AtomicBoolean@52374} "true"
repositories: java.util.Set = {java.util.TreeSet@17833} size = 14
requirements: java.util.Map = {java.util.HashMap@52375} size = 1
installedFeatures: java.util.Map = {java.util.HashMap@52376} size = 1
"root" -> {java.util.HashSet@52384} size = 121
stateFeatures: java.util.Map = {java.util.HashMap@52377} size = 1
managedBundles: java.util.Map = {java.util.HashMap@52378} size = 1
bundleChecksums: java.util.Map = {java.util.HashMap@52379} size = 0
{noformat}
17. so far, so good:
{noformat}
karaf@root()> feature:list | grep simple
simple1 │ 0.0.1 │ │ Uninstalled │ simple1 │
simple2 │ 0.0.1 │ x │ Started │ simple2 │
{noformat}
18. (different debugger run, so addresses have changed) here's how state after first feature installation is used to replace existing state:
existing:
{noformat}
this.state = {org.apache.karaf.features.internal.service.State@39249}
bootDone: java.util.concurrent.atomic.AtomicBoolean = {java.util.concurrent.atomic.AtomicBoolean@39250} "true"
repositories: java.util.Set = {java.util.TreeSet@39257} size = 14
requirements: java.util.Map = {java.util.HashMap@39258} size = 1
installedFeatures: java.util.Map = {java.util.HashMap@39259} size = 1
"root" -> {java.util.HashSet@39266} size = 120
stateFeatures: java.util.Map = {java.util.HashMap@39260} size = 1
managedBundles: java.util.Map = {java.util.HashMap@39261} size = 1
bundleChecksums: java.util.Map = {java.util.HashMap@39262} size = 0
{noformat}
new:
{noformat}
state = {org.apache.karaf.features.internal.service.State@39248}
bootDone: java.util.concurrent.atomic.AtomicBoolean = {java.util.concurrent.atomic.AtomicBoolean@39251} "true"
repositories: java.util.Set = {java.util.TreeSet@39267} size = 14
requirements: java.util.Map = {java.util.HashMap@39268} size = 1
installedFeatures: java.util.Map = {java.util.HashMap@39269} size = 1
"root" -> {java.util.HashSet@39276} size = 121
stateFeatures: java.util.Map = {java.util.HashMap@39270} size = 1
managedBundles: java.util.Map = {java.util.HashMap@39271} size = 1
bundleChecksums: java.util.Map = {java.util.HashMap@39272} size = 0
{noformat}
19. and second feature installation:
existing (simple1 is installed in `installedFeatures`):
{noformat}
this.state = {org.apache.karaf.features.internal.service.State@39249}
bootDone: java.util.concurrent.atomic.AtomicBoolean = {java.util.concurrent.atomic.AtomicBoolean@39250} "true"
repositories: java.util.Set = {java.util.TreeSet@39257} size = 14
requirements: java.util.Map = {java.util.HashMap@39258} size = 1
installedFeatures: java.util.Map = {java.util.HashMap@39259} size = 1
"root" -> {java.util.HashSet@44230} size = 121
stateFeatures: java.util.Map = {java.util.HashMap@39260} size = 1
managedBundles: java.util.Map = {java.util.HashMap@39261} size = 1
bundleChecksums: java.util.Map = {java.util.HashMap@39262} size = 0
{noformat}
new (simple2 is installed in `installedFeatures`):
{noformat}
state = {org.apache.karaf.features.internal.service.State@44226}
bootDone: java.util.concurrent.atomic.AtomicBoolean = {java.util.concurrent.atomic.AtomicBoolean@44227} "true"
repositories: java.util.Set = {java.util.TreeSet@44231} size = 14
requirements: java.util.Map = {java.util.HashMap@44232} size = 1
installedFeatures: java.util.Map = {java.util.HashMap@44233} size = 1
"root" -> {java.util.HashSet@44240} size = 121
stateFeatures: java.util.Map = {java.util.HashMap@44234} size = 1
managedBundles: java.util.Map = {java.util.HashMap@44235} size = 1
bundleChecksums: java.util.Map = {java.util.HashMap@44236} size = 0
{noformat}
And here's the problem - scheduled provisioning tasks capture some State and the 2nd task which runs doesn't update its state after first task finishes.
This is reproducible also with simple:
{noformat}
karaf@root()> feature:install simple1 & feature:install simple2
[1] background feature:install simple1
[1] done feature:install simple1
karaf@root()>
karaf@root()> feature:list|grep simple
simple2 │ 0.0.1 │ x │ Started │ simple2 │
simple1 │ 0.0.1 │ │ Uninstalled │ simple1 │
{noformat}
was:
I had a case, where (which is not recommended) two feature XML files were dropped into {{deploy/}} directory.
_Often_ (but not always) one of the features was not marked as "Started" - and it happened in random order.
It can be reproduced with {{simple1.xml}} file:
{code:xml}
<?xml version="1.0" encoding="UTF-8" standalone="yes"?>
<features xmlns="http://karaf.apache.org/xmlns/features/v1.3.0" name="simple1">
<feature name="simple1" version="0.0.1" install="auto">
<bundle start-level="80" start="true">mvn:commons-io/commons-io/2.8.0</bundle>
</feature>
</features>
{code}
and {{simple2.xml}}:
{code:xml}
<?xml version="1.0" encoding="UTF-8" standalone="yes"?>
<features xmlns="http://karaf.apache.org/xmlns/features/v1.3.0" name="simple2">
<feature name="simple2" version="0.0.1" install="auto">
<bundle start-level="80" start="true">mvn:commons-collections/commons-collections/3.2.2</bundle>
</feature>
</features>
{code}
dropped at the same time to {{deploy/}} directory.
Here's my investigation:
1. deploy two files
2. these artifacts are processed in single fileinstall thread:
{noformat}
0 = {org.apache.felix.fileinstall.internal.Artifact@11682}
path: java.io.File = {java.io.File@11683} "/data/karaf/deploy/simple1.xml"
jaredDirectory: java.io.File = {java.io.File@11683} "/data/karaf/deploy/simple1.xml"
jaredUrl: java.net.URL = {java.net.URL@11703} "file:/data/karaf/deploy/simple1.xml"
listener: org.apache.felix.fileinstall.ArtifactListener = {org.apache.karaf.deployer.features.FeatureDeploymentListener@11698}
transformedUrl: java.net.URL = {java.net.URL@11646} "feature:file:/data/karaf/deploy/simple1.xml"
transformed: java.io.File = null
bundleId: long = -1 (0xFFFFFFFFFFFFFFFF)
checksum: long = 1818582559 (0x6C655E1F)
1 = {org.apache.felix.fileinstall.internal.Artifact@11694}
path: java.io.File = {java.io.File@11696} "/data/karaf/deploy/simple2.xml"
jaredDirectory: java.io.File = {java.io.File@11696} "/data/karaf/deploy/simple2.xml"
jaredUrl: java.net.URL = {java.net.URL@11697} "file:/data/karaf/deploy/simple2.xml"
listener: org.apache.felix.fileinstall.ArtifactListener = {org.apache.karaf.deployer.features.FeatureDeploymentListener@11698}
transformedUrl: java.net.URL = {java.net.URL@11699} "feature:file:/data/karaf/deploy/simple2.xml"
transformed: java.io.File = null
bundleId: long = -1 (0xFFFFFFFFFFFFFFFF)
checksum: long = 3138423735 (0xBB108BB7)
3. single instance of org.apache.karaf.deployer.features.FeatureURLHandler has its org.apache.karaf.deployer.features.FeatureURLHandler#featureXmlURL set to file:/data/karaf/deploy/simple1.xml
stack trace:
{noformat}
"fileinstall-/data/karaf/deploy@11585" daemon prio=5 tid=0x2e nid=NA runnable
java.lang.Thread.State: RUNNABLE
at org.apache.karaf.deployer.features.FeatureURLHandler.openConnection(FeatureURLHandler.java:56)
at org.apache.felix.framework.URLHandlersStreamHandlerProxy.openConnection(URLHandlersStreamHandlerProxy.java:271)
at java.net.URL.openConnection(URL.java:1002)
at java.net.URL.openStream(URL.java:1068)
at org.apache.felix.fileinstall.internal.DirectoryWatcher.install(DirectoryWatcher.java:962)
at org.apache.felix.fileinstall.internal.DirectoryWatcher.install(DirectoryWatcher.java:884)
at org.apache.felix.fileinstall.internal.DirectoryWatcher.doProcess(DirectoryWatcher.java:489)
at org.apache.felix.fileinstall.internal.DirectoryWatcher.process(DirectoryWatcher.java:365)
at org.apache.felix.fileinstall.internal.DirectoryWatcher.run(DirectoryWatcher.java:316)
{noformat}
4. in org.apache.felix.fileinstall.internal.DirectoryWatcher#installOrUpdateBundle, simple1 is processed
5. log message:
{noformat}
Installing bundle simple1.xml / 0.0.0
{noformat}
6. org.osgi.framework.BundleContext#installBundle() for simple1
7. featureXmlURL is set to simple2.xml
8. log message:
{noformat}
Installing bundle simple2.xml / 0.0.0
{noformat}
9. org.osgi.framework.BundleContext#installBundle() for simple2
Now:
{noformat}
240 │ Installed │ 80 │ 0.0.0 │ feature:file:/data/karaf/deploy/simple1.xml
241 │ Installed │ 80 │ 0.0.0 │ feature:file:/data/karaf/deploy/simple2.xml
{noformat}
10. Of course org.apache.felix.fileinstall.internal.DirectoryWatcher#doProcess() uses HashMaps... that's why bundle2 may be started earlier
11. org.apache.felix.fileinstall.internal.FileInstall#refresh() is called for the two bundles in random order - but they're still in INSTALLED state
12. org.apache.felix.fileinstall.internal.DirectoryWatcher#startBundles() is called
13. org.osgi.framework.Bundle#start(int) is called for each bundle and the event is caught by:
{noformat}
"FelixDispatchQueue@11772" prio=5 tid=0xd nid=NA runnable
java.lang.Thread.State: RUNNABLE
at org.apache.karaf.deployer.features.FeatureDeploymentListener.bundleChanged(FeatureDeploymentListener.java:186)
- locked <0x2db2> (a org.apache.karaf.deployer.features.FeatureDeploymentListener)
at org.apache.felix.framework.EventDispatcher.invokeBundleListenerCallback(EventDispatcher.java:915)
at org.apache.felix.framework.EventDispatcher.fireEventImmediately(EventDispatcher.java:834)
at org.apache.felix.framework.EventDispatcher.run(EventDispatcher.java:1147)
at org.apache.felix.framework.EventDispatcher.access$000(EventDispatcher.java:54)
at org.apache.felix.framework.EventDispatcher$1.run(EventDispatcher.java:102)
at java.lang.Thread.run(Thread.java:748)
{noformat}
14. eventually two tasks are correctly passed to single featuresService pool
the first one (running). It has these vars reachable:
{noformat}
this = {org.apache.karaf.features.internal.service.FeaturesServiceImpl$$Lambda$108.830131376@12778}
arg$1: org.apache.karaf.features.internal.service.FeaturesServiceImpl = {org.apache.karaf.features.internal.service.FeaturesServiceImpl@12631}
arg$2: java.util.Set = {java.util.HashSet@12648} size = 1
arg$3: java.util.Map = {java.util.HashMap@12643} size = 1
arg$4: java.util.Map = {java.util.Collections$EmptyMap@12644} size = 0
arg$5: org.apache.karaf.features.internal.service.State = {org.apache.karaf.features.internal.service.State@12645}
arg$6: java.util.Map = {java.util.HashMap@12646} size = 621
arg$7: java.util.EnumSet = {java.util.RegularEnumSet@12647} size = 0
arg$8: java.lang.String = null
{noformat}
the second one (waiting). It has these vars reachable:
{noformat}
callable: java.util.concurrent.Callable = {org.apache.karaf.features.internal.service.FeaturesServiceImpl$$Lambda$108.830131376@12760}
arg$1: org.apache.karaf.features.internal.service.FeaturesServiceImpl = {org.apache.karaf.features.internal.service.FeaturesServiceImpl@12631}
arg$2: java.util.Set = {java.util.HashSet@12663} size = 1
arg$3: java.util.Map = {java.util.HashMap@12659} size = 1
arg$4: java.util.Map = {java.util.Collections$EmptyMap@12644} size = 0
arg$5: org.apache.karaf.features.internal.service.State = {org.apache.karaf.features.internal.service.State@12660}
arg$6: java.util.Map = {java.util.HashMap@12661} size = 622
arg$7: java.util.EnumSet = {java.util.RegularEnumSet@12662} size = 0
arg$8: java.lang.String = null
{noformat}
The only important difference is that 2nd task already has larger map of features.
State of the running task:
{noformat}
state = {org.apache.karaf.features.internal.service.State@12645}
bootDone: java.util.concurrent.atomic.AtomicBoolean = {java.util.concurrent.atomic.AtomicBoolean@17577} "true"
repositories: java.util.Set = {java.util.TreeSet@17578} size = 13
requirements: java.util.Map = {java.util.HashMap@17579} size = 1
installedFeatures: java.util.Map = {java.util.HashMap@17580} size = 1
stateFeatures: java.util.Map = {java.util.HashMap@17581} size = 1
managedBundles: java.util.Map = {java.util.HashMap@17582} size = 1
bundleChecksums: java.util.Map = {java.util.HashMap@17583} size = 0
{noformat}
State of the waiting task:
{noformat}
arg$5: org.apache.karaf.features.internal.service.State = {org.apache.karaf.features.internal.service.State@12660}
bootDone: java.util.concurrent.atomic.AtomicBoolean = {java.util.concurrent.atomic.AtomicBoolean@17644} "true"
repositories: java.util.Set = {java.util.TreeSet@17645} size = 14
requirements: java.util.Map = {java.util.HashMap@17646} size = 1
installedFeatures: java.util.Map = {java.util.HashMap@17647} size = 1
stateFeatures: java.util.Map = {java.util.HashMap@17648} size = 1
managedBundles: java.util.Map = {java.util.HashMap@17649} size = 1
bundleChecksums: java.util.Map = {java.util.HashMap@17650} size = 0
{noformat}
15. Even at first line of org.apache.karaf.features.internal.service.FeaturesServiceImpl#doProvision(), feature:list already gives me:
{noformat}
karaf@root()> feature:list | grep simple
simple1 │ 0.0.1 │ │ Uninstalled │ simple1 │
simple2 │ 0.0.1 │ │ Uninstalled │ simple2 │
{noformat}
16. When 2nd task runs, there are two State instances:
the state attached to 2nd task just started:
{noformat}
State@12660
bootDone: java.util.concurrent.atomic.AtomicBoolean = {java.util.concurrent.atomic.AtomicBoolean@17644} "true"
repositories: java.util.Set = {java.util.TreeSet@17645} size = 14
requirements: java.util.Map = {java.util.HashMap@17646} size = 1
installedFeatures: java.util.Map = {java.util.HashMap@17647} size = 1
"root" -> {java.util.HashSet@52251} size = 120
stateFeatures: java.util.Map = {java.util.HashMap@17648} size = 1
managedBundles: java.util.Map = {java.util.HashMap@17649} size = 1
bundleChecksums: java.util.Map = {java.util.HashMap@17650} size = 0
{noformat}
the state copied to features service after first task finishes - in this state, simple1 is already installed
{noformat}
State@12846
bootDone: java.util.concurrent.atomic.AtomicBoolean = {java.util.concurrent.atomic.AtomicBoolean@52374} "true"
repositories: java.util.Set = {java.util.TreeSet@17833} size = 14
requirements: java.util.Map = {java.util.HashMap@52375} size = 1
installedFeatures: java.util.Map = {java.util.HashMap@52376} size = 1
"root" -> {java.util.HashSet@52384} size = 121
stateFeatures: java.util.Map = {java.util.HashMap@52377} size = 1
managedBundles: java.util.Map = {java.util.HashMap@52378} size = 1
bundleChecksums: java.util.Map = {java.util.HashMap@52379} size = 0
{noformat}
17. so far, so good:
{noformat}
karaf@root()> feature:list | grep simple
simple1 │ 0.0.1 │ │ Uninstalled │ simple1 │
simple2 │ 0.0.1 │ x │ Started │ simple2 │
{noformat}
18. (different debugger run, so addresses have changed) here's how state after first feature installation is used to replace existing state:
existing:
{noformat}
this.state = {org.apache.karaf.features.internal.service.State@39249}
bootDone: java.util.concurrent.atomic.AtomicBoolean = {java.util.concurrent.atomic.AtomicBoolean@39250} "true"
repositories: java.util.Set = {java.util.TreeSet@39257} size = 14
requirements: java.util.Map = {java.util.HashMap@39258} size = 1
installedFeatures: java.util.Map = {java.util.HashMap@39259} size = 1
"root" -> {java.util.HashSet@39266} size = 120
stateFeatures: java.util.Map = {java.util.HashMap@39260} size = 1
managedBundles: java.util.Map = {java.util.HashMap@39261} size = 1
bundleChecksums: java.util.Map = {java.util.HashMap@39262} size = 0
{noformat}
new:
{noformat}
state = {org.apache.karaf.features.internal.service.State@39248}
bootDone: java.util.concurrent.atomic.AtomicBoolean = {java.util.concurrent.atomic.AtomicBoolean@39251} "true"
repositories: java.util.Set = {java.util.TreeSet@39267} size = 14
requirements: java.util.Map = {java.util.HashMap@39268} size = 1
installedFeatures: java.util.Map = {java.util.HashMap@39269} size = 1
"root" -> {java.util.HashSet@39276} size = 121
stateFeatures: java.util.Map = {java.util.HashMap@39270} size = 1
managedBundles: java.util.Map = {java.util.HashMap@39271} size = 1
bundleChecksums: java.util.Map = {java.util.HashMap@39272} size = 0
{noformat}
19. and second feature installation:
existing (simple1 is installed in `installedFeatures`):
{noformat}
this.state = {org.apache.karaf.features.internal.service.State@39249}
bootDone: java.util.concurrent.atomic.AtomicBoolean = {java.util.concurrent.atomic.AtomicBoolean@39250} "true"
repositories: java.util.Set = {java.util.TreeSet@39257} size = 14
requirements: java.util.Map = {java.util.HashMap@39258} size = 1
installedFeatures: java.util.Map = {java.util.HashMap@39259} size = 1
"root" -> {java.util.HashSet@44230} size = 121
stateFeatures: java.util.Map = {java.util.HashMap@39260} size = 1
managedBundles: java.util.Map = {java.util.HashMap@39261} size = 1
bundleChecksums: java.util.Map = {java.util.HashMap@39262} size = 0
{noformat}
new (simple2 is installed in `installedFeatures`):
{noformat}
state = {org.apache.karaf.features.internal.service.State@44226}
bootDone: java.util.concurrent.atomic.AtomicBoolean = {java.util.concurrent.atomic.AtomicBoolean@44227} "true"
repositories: java.util.Set = {java.util.TreeSet@44231} size = 14
requirements: java.util.Map = {java.util.HashMap@44232} size = 1
installedFeatures: java.util.Map = {java.util.HashMap@44233} size = 1
"root" -> {java.util.HashSet@44240} size = 121
stateFeatures: java.util.Map = {java.util.HashMap@44234} size = 1
managedBundles: java.util.Map = {java.util.HashMap@44235} size = 1
bundleChecksums: java.util.Map = {java.util.HashMap@44236} size = 0
{noformat}
And here's the problem - scheduled provisioning tasks capture some State and the 2nd task which runs doesn't update its state after first task finishes.
This is reproducible also with simple:
{noformat}
karaf@root()> feature:install simple1 & feature:install simple2
[1] background feature:install simple1
[1] done feature:install simple1
karaf@root()>
karaf@root()> feature:list|grep simple
simple2 │ 0.0.1 │ x │ Started │ simple2 │
simple1 │ 0.0.1 │ │ Uninstalled │ simple1 │
{noformat}
> State overwrite when installing more features at once
> -----------------------------------------------------
>
> Key: KARAF-7126
> URL: https://issues.apache.org/jira/browse/KARAF-7126
> Project: Karaf
> Issue Type: Bug
> Affects Versions: 4.2.11, 4.3.1
> Reporter: Grzegorz Grzybek
> Assignee: Grzegorz Grzybek
> Priority: Major
> Fix For: 4.2.12, 4.3.2
>
>
> I had a case, where (which is not recommended) two feature XML files were dropped into {{deploy/}} directory.
> _Often_ (but not always) one of the features was not marked as "Started" - and it happened in random order.
> It can be reproduced with {{simple1.xml}} file:
> {code:xml}
> <?xml version="1.0" encoding="UTF-8" standalone="yes"?>
> <features xmlns="http://karaf.apache.org/xmlns/features/v1.3.0" name="simple1">
> <feature name="simple1" version="0.0.1" install="auto">
>
> <bundle start-level="80" start="true">mvn:commons-io/commons-io/2.8.0</bundle>
>
> </feature>
> </features>
> {code}
> and {{simple2.xml}}:
> {code:xml}
> <?xml version="1.0" encoding="UTF-8" standalone="yes"?>
> <features xmlns="http://karaf.apache.org/xmlns/features/v1.3.0" name="simple2">
> <feature name="simple2" version="0.0.1" install="auto">
>
> <bundle start-level="80" start="true">mvn:commons-collections/commons-collections/3.2.2</bundle>
>
> </feature>
> </features>
> {code}
> dropped at the same time to {{deploy/}} directory.
> Here's my investigation:
> 1. deploy two files
> 2. these artifacts are processed in single fileinstall thread:
> {noformat}
> 0 = {org.apache.felix.fileinstall.internal.Artifact@11682}
> path: java.io.File = {java.io.File@11683} "/data/karaf/deploy/simple1.xml"
> jaredDirectory: java.io.File = {java.io.File@11683} "/data/karaf/deploy/simple1.xml"
> jaredUrl: java.net.URL = {java.net.URL@11703} "file:/data/karaf/deploy/simple1.xml"
> listener: org.apache.felix.fileinstall.ArtifactListener = {org.apache.karaf.deployer.features.FeatureDeploymentListener@11698}
> transformedUrl: java.net.URL = {java.net.URL@11646} "feature:file:/data/karaf/deploy/simple1.xml"
> transformed: java.io.File = null
> bundleId: long = -1 (0xFFFFFFFFFFFFFFFF)
> checksum: long = 1818582559 (0x6C655E1F)
> 1 = {org.apache.felix.fileinstall.internal.Artifact@11694}
> path: java.io.File = {java.io.File@11696} "/data/karaf/deploy/simple2.xml"
> jaredDirectory: java.io.File = {java.io.File@11696} "/data/karaf/deploy/simple2.xml"
> jaredUrl: java.net.URL = {java.net.URL@11697} "file:/data/karaf/deploy/simple2.xml"
> listener: org.apache.felix.fileinstall.ArtifactListener = {org.apache.karaf.deployer.features.FeatureDeploymentListener@11698}
> transformedUrl: java.net.URL = {java.net.URL@11699} "feature:file:/data/karaf/deploy/simple2.xml"
> transformed: java.io.File = null
> bundleId: long = -1 (0xFFFFFFFFFFFFFFFF)
> checksum: long = 3138423735 (0xBB108BB7)
> {noformat}
> 3. single instance of org.apache.karaf.deployer.features.FeatureURLHandler has its org.apache.karaf.deployer.features.FeatureURLHandler#featureXmlURL set to file:/data/karaf/deploy/simple1.xml
> stack trace:
> {noformat}
> "fileinstall-/data/karaf/deploy@11585" daemon prio=5 tid=0x2e nid=NA runnable
> java.lang.Thread.State: RUNNABLE
> at org.apache.karaf.deployer.features.FeatureURLHandler.openConnection(FeatureURLHandler.java:56)
> at org.apache.felix.framework.URLHandlersStreamHandlerProxy.openConnection(URLHandlersStreamHandlerProxy.java:271)
> at java.net.URL.openConnection(URL.java:1002)
> at java.net.URL.openStream(URL.java:1068)
> at org.apache.felix.fileinstall.internal.DirectoryWatcher.install(DirectoryWatcher.java:962)
> at org.apache.felix.fileinstall.internal.DirectoryWatcher.install(DirectoryWatcher.java:884)
> at org.apache.felix.fileinstall.internal.DirectoryWatcher.doProcess(DirectoryWatcher.java:489)
> at org.apache.felix.fileinstall.internal.DirectoryWatcher.process(DirectoryWatcher.java:365)
> at org.apache.felix.fileinstall.internal.DirectoryWatcher.run(DirectoryWatcher.java:316)
> {noformat}
> 4. in org.apache.felix.fileinstall.internal.DirectoryWatcher#installOrUpdateBundle, simple1 is processed
> 5. log message:
> {noformat}
> Installing bundle simple1.xml / 0.0.0
> {noformat}
> 6. org.osgi.framework.BundleContext#installBundle() for simple1
> 7. featureXmlURL is set to simple2.xml
> 8. log message:
> {noformat}
> Installing bundle simple2.xml / 0.0.0
> {noformat}
> 9. org.osgi.framework.BundleContext#installBundle() for simple2
> Now:
> {noformat}
> 240 │ Installed │ 80 │ 0.0.0 │ feature:file:/data/karaf/deploy/simple1.xml
> 241 │ Installed │ 80 │ 0.0.0 │ feature:file:/data/karaf/deploy/simple2.xml
> {noformat}
> 10. Of course org.apache.felix.fileinstall.internal.DirectoryWatcher#doProcess() uses HashMaps... that's why bundle2 may be started earlier
> 11. org.apache.felix.fileinstall.internal.FileInstall#refresh() is called for the two bundles in random order - but they're still in INSTALLED state
> 12. org.apache.felix.fileinstall.internal.DirectoryWatcher#startBundles() is called
> 13. org.osgi.framework.Bundle#start(int) is called for each bundle and the event is caught by:
> {noformat}
> "FelixDispatchQueue@11772" prio=5 tid=0xd nid=NA runnable
> java.lang.Thread.State: RUNNABLE
> at org.apache.karaf.deployer.features.FeatureDeploymentListener.bundleChanged(FeatureDeploymentListener.java:186)
> - locked <0x2db2> (a org.apache.karaf.deployer.features.FeatureDeploymentListener)
> at org.apache.felix.framework.EventDispatcher.invokeBundleListenerCallback(EventDispatcher.java:915)
> at org.apache.felix.framework.EventDispatcher.fireEventImmediately(EventDispatcher.java:834)
> at org.apache.felix.framework.EventDispatcher.run(EventDispatcher.java:1147)
> at org.apache.felix.framework.EventDispatcher.access$000(EventDispatcher.java:54)
> at org.apache.felix.framework.EventDispatcher$1.run(EventDispatcher.java:102)
> at java.lang.Thread.run(Thread.java:748)
> {noformat}
> 14. eventually two tasks are correctly passed to single featuresService pool
> the first one (running). It has these vars reachable:
> {noformat}
> this = {org.apache.karaf.features.internal.service.FeaturesServiceImpl$$Lambda$108.830131376@12778}
> arg$1: org.apache.karaf.features.internal.service.FeaturesServiceImpl = {org.apache.karaf.features.internal.service.FeaturesServiceImpl@12631}
> arg$2: java.util.Set = {java.util.HashSet@12648} size = 1
> arg$3: java.util.Map = {java.util.HashMap@12643} size = 1
> arg$4: java.util.Map = {java.util.Collections$EmptyMap@12644} size = 0
> arg$5: org.apache.karaf.features.internal.service.State = {org.apache.karaf.features.internal.service.State@12645}
> arg$6: java.util.Map = {java.util.HashMap@12646} size = 621
> arg$7: java.util.EnumSet = {java.util.RegularEnumSet@12647} size = 0
> arg$8: java.lang.String = null
> {noformat}
> the second one (waiting). It has these vars reachable:
> {noformat}
> callable: java.util.concurrent.Callable = {org.apache.karaf.features.internal.service.FeaturesServiceImpl$$Lambda$108.830131376@12760}
> arg$1: org.apache.karaf.features.internal.service.FeaturesServiceImpl = {org.apache.karaf.features.internal.service.FeaturesServiceImpl@12631}
> arg$2: java.util.Set = {java.util.HashSet@12663} size = 1
> arg$3: java.util.Map = {java.util.HashMap@12659} size = 1
> arg$4: java.util.Map = {java.util.Collections$EmptyMap@12644} size = 0
> arg$5: org.apache.karaf.features.internal.service.State = {org.apache.karaf.features.internal.service.State@12660}
> arg$6: java.util.Map = {java.util.HashMap@12661} size = 622
> arg$7: java.util.EnumSet = {java.util.RegularEnumSet@12662} size = 0
> arg$8: java.lang.String = null
> {noformat}
> The only important difference is that 2nd task already has larger map of features.
> State of the running task:
> {noformat}
> state = {org.apache.karaf.features.internal.service.State@12645}
> bootDone: java.util.concurrent.atomic.AtomicBoolean = {java.util.concurrent.atomic.AtomicBoolean@17577} "true"
> repositories: java.util.Set = {java.util.TreeSet@17578} size = 13
> requirements: java.util.Map = {java.util.HashMap@17579} size = 1
> installedFeatures: java.util.Map = {java.util.HashMap@17580} size = 1
> stateFeatures: java.util.Map = {java.util.HashMap@17581} size = 1
> managedBundles: java.util.Map = {java.util.HashMap@17582} size = 1
> bundleChecksums: java.util.Map = {java.util.HashMap@17583} size = 0
> {noformat}
> State of the waiting task:
> {noformat}
> arg$5: org.apache.karaf.features.internal.service.State = {org.apache.karaf.features.internal.service.State@12660}
> bootDone: java.util.concurrent.atomic.AtomicBoolean = {java.util.concurrent.atomic.AtomicBoolean@17644} "true"
> repositories: java.util.Set = {java.util.TreeSet@17645} size = 14
> requirements: java.util.Map = {java.util.HashMap@17646} size = 1
> installedFeatures: java.util.Map = {java.util.HashMap@17647} size = 1
> stateFeatures: java.util.Map = {java.util.HashMap@17648} size = 1
> managedBundles: java.util.Map = {java.util.HashMap@17649} size = 1
> bundleChecksums: java.util.Map = {java.util.HashMap@17650} size = 0
> {noformat}
> 15. Even at first line of org.apache.karaf.features.internal.service.FeaturesServiceImpl#doProvision(), feature:list already gives me:
> {noformat}
> karaf@root()> feature:list | grep simple
> simple1 │ 0.0.1 │ │ Uninstalled │ simple1 │
> simple2 │ 0.0.1 │ │ Uninstalled │ simple2 │
> {noformat}
> 16. When 2nd task runs, there are two State instances:
> the state attached to 2nd task just started:
> {noformat}
> State@12660
> bootDone: java.util.concurrent.atomic.AtomicBoolean = {java.util.concurrent.atomic.AtomicBoolean@17644} "true"
> repositories: java.util.Set = {java.util.TreeSet@17645} size = 14
> requirements: java.util.Map = {java.util.HashMap@17646} size = 1
> installedFeatures: java.util.Map = {java.util.HashMap@17647} size = 1
> "root" -> {java.util.HashSet@52251} size = 120
> stateFeatures: java.util.Map = {java.util.HashMap@17648} size = 1
> managedBundles: java.util.Map = {java.util.HashMap@17649} size = 1
> bundleChecksums: java.util.Map = {java.util.HashMap@17650} size = 0
> {noformat}
> the state copied to features service after first task finishes - in this state, simple1 is already installed
> {noformat}
> State@12846
> bootDone: java.util.concurrent.atomic.AtomicBoolean = {java.util.concurrent.atomic.AtomicBoolean@52374} "true"
> repositories: java.util.Set = {java.util.TreeSet@17833} size = 14
> requirements: java.util.Map = {java.util.HashMap@52375} size = 1
> installedFeatures: java.util.Map = {java.util.HashMap@52376} size = 1
> "root" -> {java.util.HashSet@52384} size = 121
> stateFeatures: java.util.Map = {java.util.HashMap@52377} size = 1
> managedBundles: java.util.Map = {java.util.HashMap@52378} size = 1
> bundleChecksums: java.util.Map = {java.util.HashMap@52379} size = 0
> {noformat}
> 17. so far, so good:
> {noformat}
> karaf@root()> feature:list | grep simple
> simple1 │ 0.0.1 │ │ Uninstalled │ simple1 │
> simple2 │ 0.0.1 │ x │ Started │ simple2 │
> {noformat}
> 18. (different debugger run, so addresses have changed) here's how state after first feature installation is used to replace existing state:
> existing:
> {noformat}
> this.state = {org.apache.karaf.features.internal.service.State@39249}
> bootDone: java.util.concurrent.atomic.AtomicBoolean = {java.util.concurrent.atomic.AtomicBoolean@39250} "true"
> repositories: java.util.Set = {java.util.TreeSet@39257} size = 14
> requirements: java.util.Map = {java.util.HashMap@39258} size = 1
> installedFeatures: java.util.Map = {java.util.HashMap@39259} size = 1
> "root" -> {java.util.HashSet@39266} size = 120
> stateFeatures: java.util.Map = {java.util.HashMap@39260} size = 1
> managedBundles: java.util.Map = {java.util.HashMap@39261} size = 1
> bundleChecksums: java.util.Map = {java.util.HashMap@39262} size = 0
> {noformat}
> new:
> {noformat}
> state = {org.apache.karaf.features.internal.service.State@39248}
> bootDone: java.util.concurrent.atomic.AtomicBoolean = {java.util.concurrent.atomic.AtomicBoolean@39251} "true"
> repositories: java.util.Set = {java.util.TreeSet@39267} size = 14
> requirements: java.util.Map = {java.util.HashMap@39268} size = 1
> installedFeatures: java.util.Map = {java.util.HashMap@39269} size = 1
> "root" -> {java.util.HashSet@39276} size = 121
> stateFeatures: java.util.Map = {java.util.HashMap@39270} size = 1
> managedBundles: java.util.Map = {java.util.HashMap@39271} size = 1
> bundleChecksums: java.util.Map = {java.util.HashMap@39272} size = 0
> {noformat}
> 19. and second feature installation:
> existing (simple1 is installed in `installedFeatures`):
> {noformat}
> this.state = {org.apache.karaf.features.internal.service.State@39249}
> bootDone: java.util.concurrent.atomic.AtomicBoolean = {java.util.concurrent.atomic.AtomicBoolean@39250} "true"
> repositories: java.util.Set = {java.util.TreeSet@39257} size = 14
> requirements: java.util.Map = {java.util.HashMap@39258} size = 1
> installedFeatures: java.util.Map = {java.util.HashMap@39259} size = 1
> "root" -> {java.util.HashSet@44230} size = 121
> stateFeatures: java.util.Map = {java.util.HashMap@39260} size = 1
> managedBundles: java.util.Map = {java.util.HashMap@39261} size = 1
> bundleChecksums: java.util.Map = {java.util.HashMap@39262} size = 0
> {noformat}
> new (simple2 is installed in `installedFeatures`):
> {noformat}
> state = {org.apache.karaf.features.internal.service.State@44226}
> bootDone: java.util.concurrent.atomic.AtomicBoolean = {java.util.concurrent.atomic.AtomicBoolean@44227} "true"
> repositories: java.util.Set = {java.util.TreeSet@44231} size = 14
> requirements: java.util.Map = {java.util.HashMap@44232} size = 1
> installedFeatures: java.util.Map = {java.util.HashMap@44233} size = 1
> "root" -> {java.util.HashSet@44240} size = 121
> stateFeatures: java.util.Map = {java.util.HashMap@44234} size = 1
> managedBundles: java.util.Map = {java.util.HashMap@44235} size = 1
> bundleChecksums: java.util.Map = {java.util.HashMap@44236} size = 0
> {noformat}
> And here's the problem - scheduled provisioning tasks capture some State and the 2nd task which runs doesn't update its state after first task finishes.
> This is reproducible also with simple:
> {noformat}
> karaf@root()> feature:install simple1 & feature:install simple2
> [1] background feature:install simple1
> [1] done feature:install simple1
> karaf@root()>
> karaf@root()> feature:list|grep simple
> simple2 │ 0.0.1 │ x │ Started │ simple2 │
> simple1 │ 0.0.1 │ │ Uninstalled │ simple1 │
> {noformat}
--
This message was sent by Atlassian Jira
(v8.3.4#803005)