FELIX-4020 fix a several locking problems and bugs in modifiedService customizer methods, add thread dumps, reset interrrupt flag on interrupedException, rename open to prebind to reduce confusion with open(S) method
git-svn-id: https://svn.apache.org/repos/asf/felix/trunk@1470394 13f79535-47bb-0310-9956-ffa450edef68
diff --git a/scr/pom.xml b/scr/pom.xml
index d971a7b..57eab5f 100644
--- a/scr/pom.xml
+++ b/scr/pom.xml
@@ -380,7 +380,7 @@
<exclude>**/components/**</exclude>
</excludes>
<includes>
- <include>**/integration/*</include>
+ <include>**/integration/**</include>
</includes>
</configuration>
</plugin>
diff --git a/scr/src/main/java/org/apache/felix/scr/Component.java b/scr/src/main/java/org/apache/felix/scr/Component.java
index e6fb083..df21574 100644
--- a/scr/src/main/java/org/apache/felix/scr/Component.java
+++ b/scr/src/main/java/org/apache/felix/scr/Component.java
@@ -73,8 +73,8 @@
/**
* The Component has successfully been activated and is fully functional
* (value is 16). This is the state of immediate components after
- * successfull activation. Delayed and Service Factory Components enter
- * this state when the service instance has actually be instantiated because
+ * successful activation. Delayed and Service Factory Components enter
+ * this state when the service instance has actually been instantiated because
* the service has been acquired.
*/
static final int STATE_ACTIVE = 16;
diff --git a/scr/src/main/java/org/apache/felix/scr/impl/ComponentActorThread.java b/scr/src/main/java/org/apache/felix/scr/impl/ComponentActorThread.java
index a6149bc..1a1638b 100644
--- a/scr/src/main/java/org/apache/felix/scr/impl/ComponentActorThread.java
+++ b/scr/src/main/java/org/apache/felix/scr/impl/ComponentActorThread.java
@@ -127,6 +127,7 @@
}
catch ( InterruptedException e )
{
+ Thread.currentThread().interrupt();
Activator.log( LogService.LOG_ERROR, null, "Interrupted exception waiting for queue to empty", e );
}
}
diff --git a/scr/src/main/java/org/apache/felix/scr/impl/manager/AbstractComponentManager.java b/scr/src/main/java/org/apache/felix/scr/impl/manager/AbstractComponentManager.java
index e7bd23e..9eab3bd 100644
--- a/scr/src/main/java/org/apache/felix/scr/impl/manager/AbstractComponentManager.java
+++ b/scr/src/main/java/org/apache/felix/scr/impl/manager/AbstractComponentManager.java
@@ -186,6 +186,7 @@
}
catch ( InterruptedException e )
{
+ Thread.currentThread().interrupt();
//TODO this is so wrong
throw new IllegalStateException( "Could not obtain lock (Reason: " + e + ")" );
}
@@ -211,7 +212,7 @@
return m_stateLock.getHoldCount() > 0;
}
- private void dumpThreads()
+ void dumpThreads()
{
try
{
@@ -270,6 +271,7 @@
{
log( LogService.LOG_ERROR, "waitForTracked timed out: {0} ceiling: {1} missing: {2}, Expect further errors",
new Object[] {trackingCount, ceiling, missing}, null );
+ dumpThreads();
missing.clear();
return;
@@ -277,7 +279,7 @@
}
catch ( InterruptedException e )
{
- //??
+ Thread.currentThread().interrupt();
}
}
}
@@ -356,7 +358,7 @@
}
catch ( InterruptedException e )
{
- //??
+ Thread.currentThread().interrupt();
}
finally
{
@@ -430,7 +432,7 @@
}
catch ( InterruptedException e )
{
- //??
+ Thread.currentThread().interrupt();
}
finally
{
@@ -776,6 +778,12 @@
{
return getLockTimeout();
}
+
+ @Override
+ void reportTimeout()
+ {
+ dumpThreads();
+ }
};
diff --git a/scr/src/main/java/org/apache/felix/scr/impl/manager/ComponentContextImpl.java b/scr/src/main/java/org/apache/felix/scr/impl/manager/ComponentContextImpl.java
index dd89fd8..060840e 100644
--- a/scr/src/main/java/org/apache/felix/scr/impl/manager/ComponentContextImpl.java
+++ b/scr/src/main/java/org/apache/felix/scr/impl/manager/ComponentContextImpl.java
@@ -187,6 +187,7 @@
}
catch ( InterruptedException e )
{
+ Thread.currentThread().interrupt();
return null;
}
return null;
diff --git a/scr/src/main/java/org/apache/felix/scr/impl/manager/DependencyManager.java b/scr/src/main/java/org/apache/felix/scr/impl/manager/DependencyManager.java
index dd25e40..8d9c1ca 100644
--- a/scr/src/main/java/org/apache/felix/scr/impl/manager/DependencyManager.java
+++ b/scr/src/main/java/org/apache/felix/scr/impl/manager/DependencyManager.java
@@ -32,6 +32,7 @@
import java.util.SortedMap;
import java.util.TreeMap;
import java.util.concurrent.CountDownLatch;
+import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.AtomicInteger;
import java.util.concurrent.atomic.AtomicReference;
@@ -125,7 +126,12 @@
private interface Customizer<T> extends ServiceTrackerCustomizer<T, RefPair<T>>
{
- boolean open();
+ /**
+ * attempt to obtain the services from the tracked service references that will be used in inital bind calls
+ * before activation.
+ * @return true if there are enough services for activation.
+ */
+ boolean prebind();
void close();
@@ -263,7 +269,7 @@
}
}
- public boolean open()
+ public boolean prebind()
{
boolean success = m_dependencyMetadata.isOptional() || !getTracker().isEmpty();
AtomicInteger trackingCount = new AtomicInteger( );
@@ -294,10 +300,6 @@
{
refPair = new RefPair<T>( serviceReference );
}
- if (isActive())
- {
- getServiceObject( m_bindMethods.getBind(), refPair );
- }
return refPair;
}
@@ -309,6 +311,7 @@
{
if (isActive())
{
+ getServiceObject( m_bindMethods.getBind(), refPair );
if ( !refPair.isFailed() )
{
m_componentManager.invokeBindMethod( DependencyManager.this, refPair, trackingCount );
@@ -372,7 +375,7 @@
ungetService( refPair );
}
- public boolean open()
+ public boolean prebind()
{
boolean success = m_dependencyMetadata.isOptional();
AtomicInteger trackingCount = new AtomicInteger( );
@@ -487,7 +490,7 @@
m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} MultipleStaticGreedy removed {2} (exit)", new Object[] {getName(), trackingCount, serviceReference}, null );
}
- public boolean open()
+ public boolean prebind()
{
boolean success = m_dependencyMetadata.isOptional();
AtomicInteger trackingCount = new AtomicInteger( );
@@ -497,6 +500,11 @@
synchronized (refPair)
{
success |= getServiceObject( m_bindMethods.getBind(), refPair );
+ if ( refPair.isFailed() )
+ {
+ m_componentManager.registerMissingDependency( DependencyManager.this, refPair.getRef(),
+ trackingCount.get() );
+ }
}
}
return success;
@@ -547,8 +555,9 @@
public void modifiedService( ServiceReference<T> serviceReference, RefPair<T> refPair, int trackingCount )
{
m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} MultipleStaticReluctant modified {2} (enter)", new Object[] {getName(), trackingCount, serviceReference}, null );
- if (isActive())
- {
+ Collection<RefPair<T>> refs = this.refs.get();
+ if (isActive() && refs.contains( refPair ))
+ {
m_componentManager.invokeUpdatedMethod( DependencyManager.this, refPair, trackingCount );
}
m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} MultipleStaticReluctant modified {2} (exit)", new Object[] {getName(), trackingCount, serviceReference}, null );
@@ -579,7 +588,7 @@
m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} MultipleStaticReluctant removed {2} (exit)", new Object[] {getName(), trackingCount, serviceReference}, null );
}
- public boolean open()
+ public boolean prebind()
{
boolean success = m_dependencyMetadata.isOptional();
Collection<RefPair<T>> refs = this.refs.get();
@@ -730,107 +739,115 @@
m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} SingleDynamic removed {2} (enter)", new Object[] {getName(), trackingCount, serviceReference}, null );
boolean deactivate = false;
boolean untracked = true;
+ RefPair<T> oldRefPair = null;
+ RefPair<T> nextRefPair = null;
synchronized ( getTracker().tracked() )
{
if ( refPair == this.refPair )
{
if ( isActive() )
{
- RefPair<T> nextRefPair = null;
if ( !getTracker().isEmpty() )
{
AtomicInteger trackingCount2 = new AtomicInteger();
SortedMap<ServiceReference<T>, RefPair<T>> tracked = getTracker().getTracked( true,
trackingCount2 );
nextRefPair = tracked.values().iterator().next();
- synchronized ( nextRefPair )
- {
- if ( !getServiceObject( m_bindMethods.getBind(), nextRefPair ) )
- {
- //TODO error???
- }
- }
- if ( !nextRefPair.isFailed() )
- {
- m_componentManager
- .invokeBindMethod( DependencyManager.this, nextRefPair, trackingCount );
- }
}
-
if ( isOptional() || nextRefPair != null )
{
- RefPair<T> oldRefPair = this.refPair;
+ oldRefPair = this.refPair;
this.refPair = null;
- this.trackingCount = trackingCount;
- m_componentManager.invokeUnbindMethod( DependencyManager.this, oldRefPair, trackingCount );
- this.refPair = nextRefPair;
- tracked( trackingCount );
- untracked = false;
- ungetService( oldRefPair );
}
- else
- //required and no replacement service, deactivate
+ else
{
- deactivate = true;
+ deactivate = true; //required and no replacement service, deactivate
}
}
- else
- //not active This should not happen, close should have nulled this.refPair.
- {
- this.refPair = null;
- this.trackingCount = trackingCount;
- tracked( trackingCount );
- untracked = false;
- }
}
}
+ if ( nextRefPair != null )
+ {
+ synchronized ( nextRefPair )
+ {
+ if ( !getServiceObject( m_bindMethods.getBind(), nextRefPair ) )
+ {
+ //TODO error???
+ }
+ }
+ if ( !nextRefPair.isFailed() )
+ {
+ m_componentManager.invokeBindMethod( DependencyManager.this, nextRefPair,
+ trackingCount );
+ }
+ }
+
+ if ( oldRefPair != null )
+ {
+ this.trackingCount = trackingCount;
+ m_componentManager.invokeUnbindMethod( DependencyManager.this, oldRefPair, trackingCount );
+ synchronized ( getTracker().tracked() )
+ {
+ this.refPair = nextRefPair;
+ }
+ tracked( trackingCount );
+ untracked = false;
+ }
+ else if ( deactivate )
+ {
+ this.trackingCount = trackingCount;
+ tracked( trackingCount );
+ untracked = false;
+ m_componentManager.deactivateInternal( ComponentConstants.DEACTIVATION_REASON_REFERENCE, false, trackingCount );
+ }
+ if ( oldRefPair != null )
+ {
+ ungetService( oldRefPair );
+ }
if (untracked) // not ours
{
this.trackingCount = trackingCount;
tracked( trackingCount );
}
- if (deactivate)
- {
- this.trackingCount = trackingCount;
- tracked( trackingCount );
- m_componentManager.deactivateInternal( ComponentConstants.DEACTIVATION_REASON_REFERENCE, false, trackingCount );
-
- }
m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} SingleDynamic removed {2} (exit)", new Object[] {getName(), trackingCount, serviceReference}, null );
}
- public boolean open()
+ public boolean prebind()
{
+ RefPair<T> refPair = null;
boolean success = m_dependencyMetadata.isOptional();
+ AtomicInteger trackingCount = new AtomicInteger();
synchronized ( getTracker().tracked() )
{
if ( success || !getTracker().isEmpty() )
{
- AtomicInteger trackingCount = new AtomicInteger();
SortedMap<ServiceReference<T>, RefPair<T>> tracked = getTracker().getTracked( true, trackingCount );
if ( !tracked.isEmpty() )
{
- RefPair<T> refPair = tracked.values().iterator().next();
- success |= getServiceObject( m_bindMethods.getBind(), refPair );
- if ( refPair.isFailed() )
- {
- m_componentManager.registerMissingDependency( DependencyManager.this, refPair.getRef(),
- trackingCount.get() );
- }
+ refPair = tracked.values().iterator().next();
this.refPair = refPair;
}
}
}
+ if (refPair != null)
+ {
+ synchronized( refPair )
+ {
+ success |= getServiceObject( m_bindMethods.getBind(), refPair );
+ if ( refPair.isFailed() )
+ {
+ m_componentManager.registerMissingDependency( DependencyManager.this, refPair.getRef(),
+ trackingCount.get() );
+ }
+ }
+ }
return success;
}
public void close()
{
- synchronized ( getTracker().tracked() )
- {
- closeRefPair();
- getTracker().deactivate();
- }
+ closeRefPair();
+ getTracker().deactivate();
}
private void closeRefPair()
@@ -844,7 +861,7 @@
public Collection<RefPair<T>> getRefs( AtomicInteger trackingCount )
{
- Object monitor = getTracker().tracked();
+ Object monitor = getTracker() == null? null: getTracker().tracked();
if ( monitor != null )
{
synchronized ( monitor )
@@ -940,7 +957,7 @@
m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} SingleStatic removed {2} (exit)", new Object[] {getName(), trackingCount, serviceReference}, null );
}
- public boolean open()
+ public boolean prebind()
{
boolean success = m_dependencyMetadata.isOptional();
if ( success || !getTracker().isEmpty() )
@@ -987,7 +1004,7 @@
public Collection<RefPair<T>> getRefs( AtomicInteger trackingCount )
{
- Object monitor = getTracker().tracked();
+ Object monitor = getTracker() == null? null: getTracker().tracked();
if ( monitor != null )
{
synchronized ( monitor )
@@ -1006,7 +1023,7 @@
private class NoPermissionsCustomizer implements Customizer<T>
{
- public boolean open()
+ public boolean prebind()
{
return false;
}
@@ -1386,7 +1403,7 @@
boolean prebind()
{
- return customizer.open();
+ return customizer.prebind();
}
/**
@@ -1423,10 +1440,12 @@
boolean success = m_dependencyMetadata.isOptional();
AtomicInteger trackingCount = new AtomicInteger( );
Collection<RefPair<T>> refs;
+ CountDownLatch openLatch = new CountDownLatch(1);
synchronized ( trackerRef.get().tracked() )
{
refs = customizer.getRefs( trackingCount );
edgeInfo.setOpen( trackingCount.get() );
+ edgeInfo.setOpenLatch( openLatch );
}
m_componentManager.log( LogService.LOG_DEBUG,
"For dependency {0}, optional: {1}; to bind: {2}",
@@ -1445,6 +1464,7 @@
success = true;
}
}
+ openLatch.countDown();
return success;
}
@@ -1466,7 +1486,8 @@
{
refPairs = customizer.getRefs( trackingCount );
edgeInfo.setClose( trackingCount.get() );
- edgeInfo.setLatch( latch );
+ edgeInfo.setCloseLatch( latch );
+ }
m_componentManager.log( LogService.LOG_DEBUG,
"DependencyManager: {0} close component unbinding from {1} at tracking count {2} refpairs: {3}",
@@ -1480,7 +1501,6 @@
}
}
- }
latch.countDown();
}
@@ -1614,6 +1634,19 @@
return;
}
}
+ try
+ {
+ if (!info.getOpenLatch().await( getLockTimeout(), TimeUnit.MILLISECONDS ))
+ {
+ m_componentManager.log( LogService.LOG_WARNING,
+ "DependencyManager : invokeUpdatedMethod : timeout on open latch {0}", new Object[] {getName()}, null );
+ m_componentManager.dumpThreads();
+ }
+ }
+ catch ( InterruptedException e )
+ {
+ Thread.currentThread().interrupt();
+ }
if ( !getServiceObject( m_bindMethods.getUpdated(), refPair ))
{
m_componentManager.log( LogService.LOG_WARNING,
@@ -1660,26 +1693,45 @@
if (info.outOfRange( trackingCount ) )
{
//wait for unbinds to complete
- if (info.getLatch() != null)
+ if (info.getCloseLatch() != null)
{
try
{
- info.getLatch().await( );
+ if (!info.getCloseLatch().await( getLockTimeout(), TimeUnit.MILLISECONDS ) )
+ {
+ m_componentManager.log( LogService.LOG_WARNING,
+ "DependencyManager : invokeUnbindMethod : timeout on close latch {0}", new Object[] {getName()}, null );
+ m_componentManager.dumpThreads();
+ }
}
catch ( InterruptedException e )
{
+ Thread.currentThread().interrupt();
//ignore
}
}
//ignore events after close started or we will have duplicate unbinds.
return;
}
+ try
+ {
+ if (!info.getOpenLatch().await( getLockTimeout(), TimeUnit.MILLISECONDS ))
+ {
+ m_componentManager.log( LogService.LOG_WARNING,
+ "DependencyManager : invokeUnbindMethod : timeout on open latch {0}", new Object[] {getName()}, null );
+ m_componentManager.dumpThreads();
+ }
+ }
+ catch ( InterruptedException e )
+ {
+ // TODO Auto-generated catch block
+ }
if (refPair == null)
{
//TODO should this be possible? If so, reduce or eliminate logging
m_componentManager.log( LogService.LOG_WARNING,
- "DependencyManager : invokeUnbindMethod : Component set, but reference not present", null );
+ "DependencyManager : invokeUnbindMethod : Component set, but reference not present {0}", new Object[] {getName()}, null );
return;
}
if ( !getServiceObject( m_bindMethods.getUnbind(), refPair ))
@@ -1705,6 +1757,11 @@
"DependencyManager : Component not set, no need to call unbind method", null );
}
}
+
+ private long getLockTimeout()
+ {
+ return m_componentManager.getLockTimeout();
+ }
//------------- Service target filter support -----------------------------
diff --git a/scr/src/main/java/org/apache/felix/scr/impl/manager/EdgeInfo.java b/scr/src/main/java/org/apache/felix/scr/impl/manager/EdgeInfo.java
index eae4d9a..57aef9f 100644
--- a/scr/src/main/java/org/apache/felix/scr/impl/manager/EdgeInfo.java
+++ b/scr/src/main/java/org/apache/felix/scr/impl/manager/EdgeInfo.java
@@ -24,21 +24,31 @@
{
private int open = -1;
private int close = -1;
- private CountDownLatch latch;
+ private CountDownLatch openLatch;
+ private CountDownLatch closeLatch;
public void setClose( int close )
{
this.close = close;
}
- public CountDownLatch getLatch()
+ public CountDownLatch getOpenLatch()
{
- return latch;
+ return openLatch;
}
- public void setLatch( CountDownLatch latch )
+ public void setOpenLatch( CountDownLatch latch )
{
- this.latch = latch;
+ this.openLatch = latch;
+ }
+ public CountDownLatch getCloseLatch()
+ {
+ return closeLatch;
+ }
+
+ public void setCloseLatch( CountDownLatch latch )
+ {
+ this.closeLatch = latch;
}
public void setOpen( int open )
diff --git a/scr/src/main/java/org/apache/felix/scr/impl/manager/RegistrationManager.java b/scr/src/main/java/org/apache/felix/scr/impl/manager/RegistrationManager.java
index b14202e..42c5465 100644
--- a/scr/src/main/java/org/apache/felix/scr/impl/manager/RegistrationManager.java
+++ b/scr/src/main/java/org/apache/felix/scr/impl/manager/RegistrationManager.java
@@ -173,10 +173,12 @@
{
log( LogService.LOG_ERROR, "Timeout waiting for reg change to complete {0}", new Object[]
{rsw.getRegState()}, null);
+ reportTimeout();
}
}
catch ( InterruptedException e )
{
+ Thread.currentThread().interrupt();
log( LogService.LOG_ERROR, "Interrupted exception waiting for reg change to complete {0}", new Object[]
{rsw.getRegState()}, null);
}
@@ -193,6 +195,8 @@
abstract long getTimeout();
+ abstract void reportTimeout();
+
T getServiceRegistration()
{
return m_serviceRegistration;
diff --git a/scr/src/test/java/org/apache/felix/scr/impl/manager/RegistrationManagerTest.java b/scr/src/test/java/org/apache/felix/scr/impl/manager/RegistrationManagerTest.java
index 85f1343..df95496 100644
--- a/scr/src/test/java/org/apache/felix/scr/impl/manager/RegistrationManagerTest.java
+++ b/scr/src/test/java/org/apache/felix/scr/impl/manager/RegistrationManagerTest.java
@@ -133,6 +133,13 @@
// TODO Auto-generated method stub
return 10;
}
+
+ @Override
+ void reportTimeout()
+ {
+ // TODO Auto-generated method stub
+
+ }
}
}