Details
Description
While starting Karaf 4.0.4, I hit a couple of exceptions (shown below; log attached). My app subsequently failed, which I presume is related!
I hit the ConcurrentModificationException shown below. It logged this twice (50ms apart). The only other mention of this stacktrace I could find was in http://mail-archives.apache.org/mod_mbox/karaf-user/201508.mbox/%3CCALm0H57SU2xppgrkDTBBPZ2rscdjTG5xE-HZdBf1eBAQNpv+Aw@mail.gmail.com%3E (which was against Karaf 4.0.1):
13:25:07,214 WARN 9 osgi.Activator [pool-11-thread-1] Error starting activator java.lang.IllegalStateException: Invalid BundleContext. at org.apache.felix.framework.BundleContextImpl.checkValidity(BundleContextImpl.java:511)[org.apache.felix.framework-5.4.0.jar:] at org.apache.felix.framework.BundleContextImpl.registerService(BundleContextImpl.java:328)[org.apache.felix.framework-5.4.0.jar:] at org.apache.felix.framework.BundleContextImpl.registerService(BundleContextImpl.java:355)[org.apache.felix.framework-5.4.0.jar:] at org.apache.karaf.util.tracker.BaseActivator.register(BaseActivator.java:304)[9:org.apache.karaf.features.core:4.0.4] at org.apache.karaf.util.tracker.BaseActivator.register(BaseActivator.java:297)[9:org.apache.karaf.features.core:4.0.4] at org.apache.karaf.features.internal.osgi.Activator.doStart(Activator.java:133)[9:org.apache.karaf.features.core:4.0.4] at org.apache.karaf.util.tracker.BaseActivator.run(BaseActivator.java:233)[9:org.apache.karaf.features.core:4.0.4] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)[:1.7.0_71] at java.util.concurrent.FutureTask.run(FutureTask.java:262)[:1.7.0_71] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)[:1.7.0_71] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)[:1.7.0_71] at java.lang.Thread.run(Thread.java:745)[:1.7.0_71] 13:25:07,218 ERROR 9 features.core [lixDispatchQueue] FrameworkEvent ERROR - org.apache.karaf.features.core org.osgi.framework.BundleException: Activator stop error in bundle org.apache.karaf.features.core [9]. at org.apache.felix.framework.Felix.stopBundle(Felix.java:2666)[org.apache.felix.framework-5.4.0.jar:] at org.apache.felix.framework.Felix.setActiveStartLevel(Felix.java:1389)[org.apache.felix.framework-5.4.0.jar:] at org.apache.felix.framework.FrameworkStartLevelImpl.run(FrameworkStartLevelImpl.java:308)[org.apache.felix.framework-5.4.0.jar:] at java.lang.Thread.run(Thread.java:745)[:1.7.0_71] Caused by: java.util.ConcurrentModificationException at java.util.ArrayList$Itr.checkForComodification(ArrayList.java:859)[:1.7.0_71] at java.util.ArrayList$Itr.next(ArrayList.java:831)[:1.7.0_71] at org.apache.karaf.util.tracker.BaseActivator.doStop(BaseActivator.java:124)[9:org.apache.karaf.features.core:4.0.4] at org.apache.karaf.features.internal.osgi.Activator.doStop(Activator.java:274)[9:org.apache.karaf.features.core:4.0.4] at org.apache.karaf.util.tracker.BaseActivator.stop(BaseActivator.java:90)[9:org.apache.karaf.features.core:4.0.4] at org.apache.felix.framework.util.SecureAction.stopActivator(SecureAction.java:719)[org.apache.felix.framework-5.4.0.jar:] at org.apache.felix.framework.Felix.stopBundle(Felix.java:2610)[org.apache.felix.framework-5.4.0.jar:] ... 3 more
It then hit the NullPointerException shown below:
13:25:08,373 WARN 9 osgi.Activator [pool-25-thread-1] Error starting activator java.lang.NullPointerException at org.eclipse.equinox.internal.region.CollisionHookHelper.getCollisionHook(CollisionHookHelper.java:27)[9:org.apache.karaf.features.core:4.0.4] at org.apache.karaf.features.internal.osgi.Activator.doStart(Activator.java:130)[9:org.apache.karaf.features.core:4.0.4] at org.apache.karaf.util.tracker.BaseActivator.run(BaseActivator.java:233)[9:org.apache.karaf.features.core:4.0.4] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)[:1.7.0_71] at java.util.concurrent.FutureTask.run(FutureTask.java:262)[:1.7.0_71] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)[:1.7.0_71] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)[:1.7.0_71] at java.lang.Thread.run(Thread.java:745)[:1.7.0_71]
Followed by this error:
13:25:09,509 ERROR 8 felix.fileinstall [FelixStartLevel ] Failed to install artifact: /Users/aled/repos/cloudsoft/amp/karaf/cloudsoft-amp/target/cloudsoft-amp-karaf-3.3.0-SNAPSHOT/etc/org.apache.karaf.features.repos.cfg java.io.IOException: Cannot remove old file '/Users/aled/repos/cloudsoft/amp/karaf/cloudsoft-amp/target/cloudsoft-amp-karaf-3.3.0-SNAPSHOT/data/cache/bundle7/data/config/org/apache/karaf/features/repos.config'; changes in '/Users/aled/repos/cloudsoft/amp/karaf/cloudsoft-amp/target/cloudsoft-amp-karaf-3.3.0-SNAPSHOT/data/cache/bundle7/data/config/org/apache/karaf/features/repos.config6950758717213936408.tmp' cannot be persisted at this time at org.apache.felix.cm.file.FilePersistenceManager._store(FilePersistenceManager.java:715)[7:org.apache.felix.configadmin:1.8.8] at org.apache.felix.cm.file.FilePersistenceManager.store(FilePersistenceManager.java:660)[7:org.apache.felix.configadmin:1.8.8] at org.apache.felix.cm.impl.CachingPersistenceManagerProxy.store(CachingPersistenceManagerProxy.java:242)[7:org.apache.felix.configadmin:1.8.8] at org.apache.felix.cm.impl.ConfigurationImpl.update(ConfigurationImpl.java:381)[7:org.apache.felix.configadmin:1.8.8] at org.apache.felix.cm.impl.ConfigurationAdapter.update(ConfigurationAdapter.java:131)[7:org.apache.felix.configadmin:1.8.8] at org.apache.felix.fileinstall.internal.ConfigInstaller.setConfig(ConfigInstaller.java:249)[8:org.apache.felix.fileinstall:3.5.0] at org.apache.felix.fileinstall.internal.ConfigInstaller.install(ConfigInstaller.java:76)[8:org.apache.felix.fileinstall:3.5.0] at org.apache.felix.fileinstall.internal.DirectoryWatcher.install(DirectoryWatcher.java:931)[8:org.apache.felix.fileinstall:3.5.0] at org.apache.felix.fileinstall.internal.DirectoryWatcher.install(DirectoryWatcher.java:865)[8:org.apache.felix.fileinstall:3.5.0] at org.apache.felix.fileinstall.internal.DirectoryWatcher.doProcess(DirectoryWatcher.java:482)[8:org.apache.felix.fileinstall:3.5.0] at org.apache.felix.fileinstall.internal.DirectoryWatcher.process(DirectoryWatcher.java:358)[8:org.apache.felix.fileinstall:3.5.0] at org.apache.felix.fileinstall.internal.DirectoryWatcher.start(DirectoryWatcher.java:241)[8:org.apache.felix.fileinstall:3.5.0] at org.apache.felix.fileinstall.internal.FileInstall.updated(FileInstall.java:243)[8:org.apache.felix.fileinstall:3.5.0] at org.apache.felix.fileinstall.internal.FileInstall.start(FileInstall.java:127)[8:org.apache.felix.fileinstall:3.5.0] at org.apache.felix.framework.util.SecureAction.startActivator(SecureAction.java:697)[org.apache.felix.framework-5.4.0.jar:] at org.apache.felix.framework.Felix.activateBundle(Felix.java:2226)[org.apache.felix.framework-5.4.0.jar:] at org.apache.felix.framework.Felix.startBundle(Felix.java:2144)[org.apache.felix.framework-5.4.0.jar:] at org.apache.felix.framework.Felix.setActiveStartLevel(Felix.java:1371)[org.apache.felix.framework-5.4.0.jar:] at org.apache.felix.framework.FrameworkStartLevelImpl.run(FrameworkStartLevelImpl.java:308)[org.apache.felix.framework-5.4.0.jar:] at java.lang.Thread.run(Thread.java:745)[:1.7.0_71]
And then much later this error:
13:26:21,765 ERROR 9 service.BootFeaturesInstaller [pool-7-thread-1 ] Error installing boot features org.osgi.framework.BundleException: Unable to cache bundle: mvn:org.bouncycastle/bcprov-jdk15on/1.49 at org.apache.felix.framework.Felix.installBundle(Felix.java:2975)[org.apache.felix.framework-5.4.0.jar:] at org.apache.felix.framework.BundleContextImpl.installBundle(BundleContextImpl.java:167)[org.apache.felix.framework-5.4.0.jar:] at org.eclipse.equinox.internal.region.BundleIdBasedRegion.installBundle0(BundleIdBasedRegion.java:117)[9:org.apache.karaf.features.core:4.0.4] at org.eclipse.equinox.internal.region.BundleIdBasedRegion.installBundleAtLocation(BundleIdBasedRegion.java:97)[9:org.apache.karaf.features.core:4.0.4] at org.apache.karaf.features.internal.service.FeaturesServiceImpl.installBundle(FeaturesServiceImpl.java:1174)[9:org.apache.karaf.features.core:4.0.4] at org.apache.karaf.features.internal.service.Deployer.deploy(Deployer.java:724)[9:org.apache.karaf.features.core:4.0.4] at org.apache.karaf.features.internal.service.FeaturesServiceImpl.doProvision(FeaturesServiceImpl.java:1089)[9:org.apache.karaf.features.core:4.0.4] at org.apache.karaf.features.internal.service.FeaturesServiceImpl$1.call(FeaturesServiceImpl.java:985)[9:org.apache.karaf.features.core:4.0.4] at java.util.concurrent.FutureTask.run(FutureTask.java:262)[:1.7.0_71] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)[:1.7.0_71] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)[:1.7.0_71] at java.lang.Thread.run(Thread.java:745)[:1.7.0_71] Caused by: java.io.FileNotFoundException: /Users/aled/repos/cloudsoft/amp/karaf/cloudsoft-amp/target/cloudsoft-amp-karaf-3.3.0-SNAPSHOT/data/cache/bundle22/version0.0/bundle.jar (No such file or directory) at java.util.zip.ZipFile.open(Native Method)[:1.7.0_71] at java.util.zip.ZipFile.<init>(ZipFile.java:215)[:1.7.0_71] at java.util.zip.ZipFile.<init>(ZipFile.java:145)[:1.7.0_71] at java.util.zip.ZipFile.<init>(ZipFile.java:159)[:1.7.0_71] at org.apache.felix.framework.util.SecureAction.openZipFile(SecureAction.java:650)[org.apache.felix.framework-5.4.0.jar:] at org.apache.felix.framework.util.WeakZipFileFactory$WeakZipFile.<init>(WeakZipFileFactory.java:187)[org.apache.felix.framework-5.4.0.jar:] at org.apache.felix.framework.util.WeakZipFileFactory$WeakZipFile.<init>(WeakZipFileFactory.java:169)[org.apache.felix.framework-5.4.0.jar:] at org.apache.felix.framework.util.WeakZipFileFactory.create(WeakZipFileFactory.java:72)[org.apache.felix.framework-5.4.0.jar:] at org.apache.felix.framework.cache.JarRevision.<init>(JarRevision.java:84)[org.apache.felix.framework-5.4.0.jar:] at org.apache.felix.framework.cache.BundleArchive.createRevisionFromLocation(BundleArchive.java:872)[org.apache.felix.framework-5.4.0.jar:] at org.apache.felix.framework.cache.BundleArchive.reviseInternal(BundleArchive.java:550)[org.apache.felix.framework-5.4.0.jar:] at org.apache.felix.framework.cache.BundleArchive.<init>(BundleArchive.java:153)[org.apache.felix.framework-5.4.0.jar:] at org.apache.felix.framework.cache.BundleCache.create(BundleCache.java:277)[org.apache.felix.framework-5.4.0.jar:] at org.apache.felix.framework.Felix.installBundle(Felix.java:2971)[org.apache.felix.framework-5.4.0.jar:] ... 11 more
When I subsequently checked, the file did exist, but its timestamp appears to be 1 second later (unfortunately no millisecond granularity on OSX):
stat /Users/aled/repos/cloudsoft/amp/karaf/cloudsoft-amp/target/cloudsoft-amp-karaf-3.3.0-SNAPSHOT/data/cache/bundle22/version0.0/bundle.jar 16777220 397678970 -rw-r--r-- 1 aled staff 0 2476362 "Aug 11 16:43:26 2016" "Aug 11 13:26:22 2016" "Aug 11 13:26:22 2016" "Aug 11 13:26:22 2016" 4096 4840 0 /Users/aled/repos/cloudsoft/amp/karaf/cloudsoft-amp/target/cloudsoft-amp-karaf-3.3.0-SNAPSHOT/data/cache/bundle22/version0.0/bundle.jar
—
It's worth describing how I was running this! While attempting to reproduce a different problem, I wrote a simple scripted to repeatedly install and start karaf, and then to tear it down if the problem did not occur.
Teardown involved calling ./bin/stop, waiting a second, and then deleting the install dir. I hit this error on the 97th run.
By that point, there were two other Karaf instances left running (note these were running in install directories that I had deleted, but that would have had the same path as my newest Karaf).
For one of those Karafs left behind, the call to ./bin/stop at the end of the 92nd run reported:
Can't connect to the container. The container is not running.
Unfortunately I did not keep the logs for those old (seemingly successful) runs of Karaf.