Author: bdelacretaz Date: Mon Dec 8 08:23:13 2008 New Revision: 724391 URL: http://svn.apache.org/viewvc?rev=724391&view=rev Log: SLING-747 - make refreshPackages() call pseudo-synchronous to avoid race conditions when that's called right before changing the start level
Modified: incubator/sling/trunk/extensions/jcrinstall/service/src/main/java/org/apache/sling/jcr/jcrinstall/osgi/impl/BundleResourceProcessor.java incubator/sling/trunk/extensions/jcrinstall/service/src/test/java/org/apache/sling/jcr/jcrinstall/osgi/impl/BundleResourceProcessorTest.java Modified: incubator/sling/trunk/extensions/jcrinstall/service/src/main/java/org/apache/sling/jcr/jcrinstall/osgi/impl/BundleResourceProcessor.java URL: http://svn.apache.org/viewvc/incubator/sling/trunk/extensions/jcrinstall/service/src/main/java/org/apache/sling/jcr/jcrinstall/osgi/impl/BundleResourceProcessor.java?rev=724391&r1=724390&r2=724391&view=diff ============================================================================== --- incubator/sling/trunk/extensions/jcrinstall/service/src/main/java/org/apache/sling/jcr/jcrinstall/osgi/impl/BundleResourceProcessor.java (original) +++ incubator/sling/trunk/extensions/jcrinstall/service/src/main/java/org/apache/sling/jcr/jcrinstall/osgi/impl/BundleResourceProcessor.java Mon Dec 8 08:23:13 2008 @@ -30,6 +30,7 @@ import java.util.List; import java.util.Map; import java.util.Set; +import java.util.TreeSet; import java.util.jar.JarInputStream; import java.util.jar.Manifest; @@ -55,10 +56,14 @@ /** [EMAIL PROTECTED] Storage} key for the bundle ID */ public static final String KEY_BUNDLE_ID = "bundle.id"; + + /** Max time allowed to refresh packages (TODO configurable??) */ + public static final int MAX_REFRESH_PACKAGES_WAIT_SECONDS = 30; private final BundleContext ctx; private final PackageAdmin packageAdmin; private final StartLevel startLevel; + private int packageRefreshEventsCount; /** * All bundles which were active before [EMAIL PROTECTED] #processResourceQueue()} @@ -86,6 +91,9 @@ */ private boolean needsRefresh; + /** Flag used to avoid reentrant [EMAIL PROTECTED] @startBundles()} calls */ + private boolean startingBundles; + private final Logger log = LoggerFactory.getLogger(this.getClass()); BundleResourceProcessor(BundleContext ctx, PackageAdmin packageAdmin, StartLevel startLevel) { @@ -116,7 +124,7 @@ public void frameworkEvent(FrameworkEvent event) { if (event.getType() == FrameworkEvent.PACKAGES_REFRESHED) { log.debug("FrameworkEvent.PACKAGES_REFRESHED"); - startBundles(); + packageRefreshEventsCount++; } } @@ -169,6 +177,7 @@ } if (b != null) { + log.debug("Calling Bundle.stop() for {}", b.getLocation()); b.stop(); b.update(data); updated = true; @@ -217,6 +226,7 @@ log.debug("Bundle having id {} not found, cannot uninstall", longId); } else { + log.debug("Uninstalling Bundle {}", b.getLocation()); synchronized (installedBundles) { installedBundles.remove(b.getBundleId()); } @@ -232,6 +242,36 @@ public boolean canProcess(String uri, InstallableData data) { return uri.endsWith(BUNDLE_EXTENSION); } + + /** Execute a PackageAdmin.refreshPackages call and wait for the corresponding + * framework event. Used to execute this call "synchronously" to make things + * more sequential when installing/updating/removing bundles. + */ + protected void refreshPackagesSynchronously(Bundle [] bundles) { + final int targetEventCount = packageRefreshEventsCount + 1; + final long start = System.currentTimeMillis(); + final long timeout = System.currentTimeMillis() + MAX_REFRESH_PACKAGES_WAIT_SECONDS * 1000L; + + // It seems like (at least with Felix 1.0.4) we won't get a FrameworkEvent.PACKAGES_REFRESHED + // if one happened very recently and there's nothing to refresh + packageAdmin.refreshPackages(bundles); + while(true) { + if(System.currentTimeMillis() > timeout) { + log.warn("No FrameworkEvent.PACKAGES_REFRESHED event received within {} seconds after refresh", + MAX_REFRESH_PACKAGES_WAIT_SECONDS); + break; + } + if(packageRefreshEventsCount >= targetEventCount) { + final long delta = System.currentTimeMillis() - start; + log.debug("FrameworkEvent.PACKAGES_REFRESHED received {} msec after refreshPackages call", delta); + break; + } + try { + Thread.sleep(250L); + } catch(InterruptedException ignore) { + } + } + } /** * Refreshes packages with subsequence bundle start or directly starts @@ -258,9 +298,7 @@ log.debug("Processing resource queue in REFRESH mode, {} active bundles found, refreshing packages", activeBundles.size()); - - // refresh now - packageAdmin.refreshPackages(null); + refreshPackagesSynchronously(null); } else { startBundles(); @@ -353,8 +391,23 @@ * all bundles, which have been freshly installed. */ private void startBundles() { - startBundles(activeBundles, "active"); - startBundles(installedBundles, "installed"); + if(activeBundles.size() > 0 || installedBundles.size() > 0) { + synchronized(this) { + if(startingBundles) { + log.debug("startBundles(): startingBundles is true, reentrant call avoided"); + return; + } + startingBundles = true; + } + + try { + log.debug("Starting active and installed bundles"); + startBundles(activeBundles, "active"); + startBundles(installedBundles, "installed"); + } finally { + startingBundles = false; + } + } } /** @@ -367,6 +420,7 @@ * @param bundleIdCollection The IDs of bundles to be started. */ private void startBundles(Collection<Long> bundleIdCollection, String collectionName) { + if(bundleIdCollection.size() > 0) { log.debug("startBundles({}): {} bundles to process", collectionName, bundleIdCollection.size()); @@ -379,6 +433,8 @@ bundleIdCollection.clear(); } + TreeSet<Long> startupFailed = new TreeSet<Long>(); + final int toStart = bundleIds.length; for (Long bundleId : bundleIds) { Bundle bundle = ctx.getBundle(bundleId); if (bundle.getState() != Bundle.ACTIVE) { @@ -398,9 +454,16 @@ // re-add the failed bundle to the activeBundles list synchronized (activeBundles) { activeBundles.add(bundleId); + startupFailed.add(bundleId); } } } } + + if(startupFailed.size() > 0) { + log.info("Finished starting {} bundles, failed: {}", toStart + " " + collectionName, startupFailed); + } else { + log.debug("Finished starting {} {} bundles, none failed", toStart, collectionName); + } } } \ No newline at end of file Modified: incubator/sling/trunk/extensions/jcrinstall/service/src/test/java/org/apache/sling/jcr/jcrinstall/osgi/impl/BundleResourceProcessorTest.java URL: http://svn.apache.org/viewvc/incubator/sling/trunk/extensions/jcrinstall/service/src/test/java/org/apache/sling/jcr/jcrinstall/osgi/impl/BundleResourceProcessorTest.java?rev=724391&r1=724390&r2=724391&view=diff ============================================================================== --- incubator/sling/trunk/extensions/jcrinstall/service/src/test/java/org/apache/sling/jcr/jcrinstall/osgi/impl/BundleResourceProcessorTest.java (original) +++ incubator/sling/trunk/extensions/jcrinstall/service/src/test/java/org/apache/sling/jcr/jcrinstall/osgi/impl/BundleResourceProcessorTest.java Mon Dec 8 08:23:13 2008 @@ -37,7 +37,6 @@ import org.osgi.framework.BundleContext; import org.osgi.framework.FrameworkListener; import org.osgi.service.packageadmin.PackageAdmin; -import org.osgi.service.startlevel.StartLevel; /** Test the BundleResourceProcessor */ public class BundleResourceProcessorTest { @@ -82,8 +81,10 @@ mockery.checking(new Expectations() {{ allowing(pa).refreshPackages(null); allowing(pa).resolveBundles(null); - allowing(b).getBundleId() ; + allowing(b).getBundleId(); will(returnValue(bundleId)); + allowing(b).getLocation(); + will(returnValue(uri)); allowing(bc).addFrameworkListener(with(any(FrameworkListener.class))); one(bc).installBundle(OsgiControllerImpl.getResourceLocation(uri), is);