FELIX-3952 don't hang indefinitely if a service tracking event is missing. Add more logging
git-svn-id: https://svn.apache.org/repos/asf/felix/trunk@1453153 13f79535-47bb-0310-9956-ffa450edef68
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 75bce30..5027009 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
@@ -34,6 +34,7 @@
import java.util.concurrent.atomic.AtomicInteger;
import java.util.concurrent.atomic.AtomicLong;
import java.util.concurrent.atomic.AtomicReference;
+import java.util.concurrent.locks.Condition;
import java.util.concurrent.locks.Lock;
import java.util.concurrent.locks.ReentrantLock;
@@ -119,6 +120,8 @@
private volatile int ceiling;
+ private final Lock missingLock = new ReentrantLock();
+ private final Condition missingCondition = missingLock.newCondition();
private final Set<Integer> missing = new TreeSet<Integer>( );
@@ -218,7 +221,8 @@
//service event tracking
void tracked( int trackingCount )
{
- synchronized ( missing )
+ missingLock.lock();
+ try
{
if (trackingCount == floor + 1 )
{
@@ -237,13 +241,18 @@
}
ceiling = trackingCount;
}
- missing.notifyAll();
+ missingCondition.signalAll();
+ }
+ finally
+ {
+ missingLock.unlock();
}
}
void waitForTracked( int trackingCount )
{
- synchronized ( missing )
+ missingLock.lock();
+ try
{
while ( ceiling < trackingCount || ( !missing.isEmpty() && missing.iterator().next() < trackingCount))
{
@@ -251,7 +260,14 @@
new Object[] {trackingCount, ceiling, missing}, null );
try
{
- missing.wait( );
+ if ( !missingCondition.await( getLockTimeout(), TimeUnit.MILLISECONDS ))
+ {
+ log( LogService.LOG_ERROR, "waitForTracked timed out: {0} ceiling: {1} missing: {2}, Expect further errors",
+ new Object[] {trackingCount, ceiling, missing}, null );
+ missing.clear();
+ return;
+
+ }
}
catch ( InterruptedException e )
{
@@ -259,6 +275,10 @@
}
}
}
+ finally
+ {
+ missingLock.unlock();
+ }
}
//---------- Component ID management
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 d17a04d..3e39567 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
@@ -316,6 +316,7 @@
public void addedService( ServiceReference<T> serviceReference, RefPair<T> refPair, int trackingCount )
{
+ m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} MultipleDynamic added {2} (enter)", new Object[] {m_dependencyMetadata.getName(), trackingCount, serviceReference}, null );
boolean tracked = false;
if ( getPreviousRefMap().remove( serviceReference ) == null )
{
@@ -336,7 +337,7 @@
m_componentManager.activateInternal( trackingCount );
}
}
- m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} MultipleDynamic added {2}", new Object[] {m_dependencyMetadata.getName(), trackingCount, serviceReference}, null );
+ m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} MultipleDynamic added {2} (exit)", new Object[] {m_dependencyMetadata.getName(), trackingCount, serviceReference}, null );
if ( !tracked )
{
tracked(trackingCount);
@@ -345,16 +346,18 @@
public void modifiedService( ServiceReference<T> serviceReference, RefPair<T> refPair, int trackingCount )
{
+ m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} MultipleDynamic modified {2} (enter)", new Object[] {m_dependencyMetadata.getName(), trackingCount, serviceReference}, null );
if (isActive())
{
m_componentManager.update( DependencyManager.this, refPair, trackingCount );
}
- m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} MultipleDynamic modified {2}", new Object[] {m_dependencyMetadata.getName(), trackingCount, serviceReference}, null );
+ m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} MultipleDynamic modified {2} (exit)", new Object[] {m_dependencyMetadata.getName(), trackingCount, serviceReference}, null );
tracked( trackingCount );
}
public void removedService( ServiceReference<T> serviceReference, RefPair<T> refPair, int trackingCount )
{
+ m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} MultipleDynamic removed {2} (enter)", new Object[] {m_dependencyMetadata.getName(), trackingCount, serviceReference}, null );
if ( isActive() )
{
boolean unbind = isOptional() || !getTracker().isEmpty();
@@ -368,10 +371,10 @@
{
lastRefPair = refPair;
lastRefPairTrackingCount = trackingCount;
- m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} MultipleDynamic removed (deactivate) {2}", new Object[] {m_dependencyMetadata.getName(), trackingCount, serviceReference}, null );
tracked( trackingCount );
m_componentManager.deactivateInternal( ComponentConstants.DEACTIVATION_REASON_REFERENCE, false, trackingCount );
lastRefPair = null;
+ m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} MultipleDynamic removed (deactivate) {2}", new Object[] {m_dependencyMetadata.getName(), trackingCount, serviceReference}, null );
}
}
else
@@ -444,6 +447,7 @@
public void addedService( ServiceReference<T> serviceReference, RefPair<T> refPair, int trackingCount )
{
+ m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} MultipleStaticGreedy added {2} (enter)", new Object[] {m_dependencyMetadata.getName(), trackingCount, serviceReference}, null );
tracked( trackingCount );
if (isActive())
{
@@ -458,21 +462,23 @@
{
m_componentManager.activateInternal( trackingCount );
}
- m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} MultipleStaticGreedy added {2}", new Object[] {m_dependencyMetadata.getName(), trackingCount, serviceReference}, null );
+ m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} MultipleStaticGreedy added {2} (exit)", new Object[] {m_dependencyMetadata.getName(), trackingCount, serviceReference}, null );
}
public void modifiedService( ServiceReference<T> serviceReference, RefPair<T> refPair, int trackingCount )
{
+ m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} MultipleStaticGreedy modified {2} (enter)", new Object[] {m_dependencyMetadata.getName(), trackingCount, serviceReference}, null );
if (isActive())
{
m_componentManager.update( DependencyManager.this, refPair, trackingCount );
}
- m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} MultipleStaticGreedy modified {2}", new Object[] {m_dependencyMetadata.getName(), trackingCount, serviceReference}, null );
+ m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} MultipleStaticGreedy modified {2} (exit)", new Object[] {m_dependencyMetadata.getName(), trackingCount, serviceReference}, null );
tracked( trackingCount );
}
public void removedService( ServiceReference<T> serviceReference, RefPair<T> refPair, int trackingCount )
{
+ m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} MultipleStaticGreedy removed {2} (enter)", new Object[] {m_dependencyMetadata.getName(), trackingCount, serviceReference}, null );
tracked( trackingCount );
if ( isActive() )
{
@@ -486,7 +492,7 @@
}
//This is unlikely
ungetService( refPair );
- m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} MultipleStaticGreedy removed {2}", new Object[] {m_dependencyMetadata.getName(), trackingCount, serviceReference}, null );
+ m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} MultipleStaticGreedy removed {2} (exit)", new Object[] {m_dependencyMetadata.getName(), trackingCount, serviceReference}, null );
}
public boolean open()
@@ -533,26 +539,29 @@
public void addedService( ServiceReference<T> serviceReference, RefPair<T> refPair, int trackingCount )
{
+ m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} MultipleStaticReluctant added {2} (enter)", new Object[] {m_dependencyMetadata.getName(), trackingCount, serviceReference}, null );
tracked( trackingCount );
if ( isTrackerOpened() && !isOptional() && !isActive())
{
m_componentManager.activateInternal( trackingCount );
}
- m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} MultipleStaticReluctant added {2}", new Object[] {m_dependencyMetadata.getName(), trackingCount, serviceReference}, null );
+ m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} MultipleStaticReluctant added {2} (exit)", new Object[] {m_dependencyMetadata.getName(), trackingCount, serviceReference}, null );
}
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[] {m_dependencyMetadata.getName(), trackingCount, serviceReference}, null );
if (isActive())
{
m_componentManager.update( DependencyManager.this, refPair, trackingCount );
}
- m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} MultipleStaticReluctant modified {2}", new Object[] {m_dependencyMetadata.getName(), trackingCount, serviceReference}, null );
+ m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} MultipleStaticReluctant modified {2} (exit)", new Object[] {m_dependencyMetadata.getName(), trackingCount, serviceReference}, null );
tracked( trackingCount );
}
public void removedService( ServiceReference<T> serviceReference, RefPair<T> refPair, int trackingCount )
{
+ m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} MultipleStaticReluctant removed {2} (enter)", new Object[] {m_dependencyMetadata.getName(), trackingCount, serviceReference}, null );
tracked( trackingCount );
if ( isActive() )
{
@@ -570,7 +579,7 @@
}
}
ungetService( refPair );
- m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} MultipleStaticReluctant removed {2}", new Object[] {m_dependencyMetadata.getName(), trackingCount, serviceReference}, null );
+ m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} MultipleStaticReluctant removed {2} (exit)", new Object[] {m_dependencyMetadata.getName(), trackingCount, serviceReference}, null );
}
public boolean open()
@@ -625,6 +634,7 @@
public void addedService( ServiceReference<T> serviceReference, RefPair<T> refPair, int trackingCount )
{
+ m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} SingleDynamic added {2} (enter)", new Object[] {m_dependencyMetadata.getName(), trackingCount, serviceReference}, null );
boolean tracked = false;
if ( getPreviousRefMap().remove( serviceReference ) == null )
{
@@ -660,7 +670,7 @@
}
}
this.trackingCount = trackingCount;
- m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} SingleDynamic added {2}", new Object[] {m_dependencyMetadata.getName(), trackingCount, serviceReference}, null );
+ m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} SingleDynamic added {2} (exit)", new Object[] {m_dependencyMetadata.getName(), trackingCount, serviceReference}, null );
if ( !tracked )
{
tracked(trackingCount);
@@ -669,17 +679,19 @@
public void modifiedService( ServiceReference<T> serviceReference, RefPair<T> refPair, int trackingCount )
{
+ m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} SingleDynamic modified {2} (enter)", new Object[] {m_dependencyMetadata.getName(), trackingCount, serviceReference}, null );
if (isActive())
{
m_componentManager.update( DependencyManager.this, refPair, trackingCount );
}
this.trackingCount = trackingCount;
- m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} SingleDynamic modified {2}", new Object[] {m_dependencyMetadata.getName(), trackingCount, serviceReference}, null );
+ m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} SingleDynamic modified {2} (exit)", new Object[] {m_dependencyMetadata.getName(), trackingCount, serviceReference}, null );
tracked( trackingCount );
}
public void removedService( ServiceReference<T> serviceReference, RefPair<T> refPair, int trackingCount )
{
+ m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} SingleDynamic removed {2} (enter)", new Object[] {m_dependencyMetadata.getName(), trackingCount, serviceReference}, null );
if (refPair == this.refPair)
{
if ( isActive() )
@@ -731,7 +743,7 @@
this.trackingCount = trackingCount;
tracked( trackingCount );
}
- m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} SingleDynamic removed {2}", new Object[] {m_dependencyMetadata.getName(), trackingCount, serviceReference}, null );
+ m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} SingleDynamic removed {2} (exit)", new Object[] {m_dependencyMetadata.getName(), trackingCount, serviceReference}, null );
}
public boolean open()
@@ -794,6 +806,7 @@
public void addedService( ServiceReference<T> serviceReference, RefPair<T> refPair, int trackingCount )
{
+ m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} SingleStatic added {2} (enter)", new Object[] {m_dependencyMetadata.getName(), trackingCount, serviceReference}, null );
this.trackingCount = trackingCount;
tracked( trackingCount );
if ( isActive() )
@@ -808,22 +821,24 @@
{
m_componentManager.activateInternal( trackingCount );
}
- m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} SingleStatic added {2}", new Object[] {m_dependencyMetadata.getName(), trackingCount, serviceReference}, null );
+ m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} SingleStatic added {2} (exit)", new Object[] {m_dependencyMetadata.getName(), trackingCount, serviceReference}, null );
}
public void modifiedService( ServiceReference<T> serviceReference, RefPair<T> refPair, int trackingCount )
{
+ m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} SingleStatic modified {2} (enter)", new Object[] {m_dependencyMetadata.getName(), trackingCount, serviceReference}, null );
if ( isActive() )
{
m_componentManager.update( DependencyManager.this, refPair, trackingCount );
}
this.trackingCount = trackingCount;
- m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} SingleStatic modified {2}", new Object[] {m_dependencyMetadata.getName(), trackingCount, serviceReference}, null );
+ m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} SingleStatic modified {2} (exit)", new Object[] {m_dependencyMetadata.getName(), trackingCount, serviceReference}, null );
tracked( trackingCount );
}
public void removedService( ServiceReference<T> serviceReference, RefPair<T> refPair, int trackingCount )
{
+ m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} SingleStatic removed {2} (enter)", new Object[] {m_dependencyMetadata.getName(), trackingCount, serviceReference}, null );
this.trackingCount = trackingCount;
tracked( trackingCount );
if ( isActive() && refPair == this.refPair )
@@ -831,7 +846,7 @@
m_componentManager.deactivateInternal( ComponentConstants.DEACTIVATION_REASON_REFERENCE, false, trackingCount );
m_componentManager.activateInternal( trackingCount );
}
- m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} SingleStatic removed {2}", new Object[] {m_dependencyMetadata.getName(), trackingCount, serviceReference}, null );
+ m_componentManager.log( LogService.LOG_DEBUG, "dm {0} tracking {1} SingleStatic removed {2} (exit)", new Object[] {m_dependencyMetadata.getName(), trackingCount, serviceReference}, null );
}
public boolean open()