FELIX-3657 fix two ServiceFactoryComponentFactory problems and add logging. DependencyManagers still refer to an instance

git-svn-id: https://svn.apache.org/repos/asf/felix/trunk@1381825 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 a41c51f..db1cd28 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
@@ -814,7 +814,7 @@
             {
                 //not actually satisfied any longer
                 returnServices( newDeps );
-                log( LogService.LOG_DEBUG, "Could not get dependency for dependency manager: {0}",
+                log( LogService.LOG_DEBUG, "Could not get required dependency for dependency manager: {0}",
                         new Object[] {dependencyManager}, null );
                 throw new IllegalStateException( "Missing dependencies, not satisfied" );
             }
@@ -1526,6 +1526,12 @@
                         acm.obtainReadLock( "AbstractComponentManager.Unsatisfied.activate.1" );
                         return false;
                     }
+                    else
+                    {
+                        acm.log( LogService.LOG_DEBUG,
+                                "activate won collecting dependencies, proceed to creating object.", null );
+
+                    }
                 }
                 catch ( IllegalStateException e )
                 {
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 8fe689a..a6cd92c 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
@@ -419,6 +419,12 @@
         // otherwise check whether the component is in a state to handle the event
         else if ( handleServiceEvent() )
         {
+            Map dependencyMap = m_componentManager.getDependencyMap();
+            Map referenceMap = null;
+            if (dependencyMap != null)
+            {
+                referenceMap = ( Map ) dependencyMap.get( this );
+            }
             // if the dependency is static, we have to deactivate the component
             // to "remove" the dependency
             if ( m_dependencyMetadata.isStatic() )
@@ -429,6 +435,11 @@
                         "Dependency Manager: Static dependency on {0}/{1} is broken", new Object[]
                             { m_dependencyMetadata.getName(), m_dependencyMetadata.getInterface() }, null );
                     m_componentManager.deactivateInternal( ComponentConstants.DEACTIVATION_REASON_REFERENCE );
+                    if ( referenceMap != null )
+                    {
+                        referenceMap.remove( reference );
+                    }
+
                     // FELIX-2368: immediately try to reactivate
                     m_componentManager.activateInternal();
                 }
@@ -478,6 +489,11 @@
 
                 // make sure the service is returned
                 ungetService( reference );
+                //service is no longer available, don't track it any longer.
+                if ( referenceMap != null )
+                {
+                    referenceMap.remove( reference );
+                }
             }
         }
 
@@ -899,7 +915,7 @@
         Map dependencyMap = m_componentManager.getDependencyMap();
         if ( dependencyMap != null )
         {
-            AbstractComponentManager.RefPair refPair  = ( AbstractComponentManager.RefPair ) ((Map ) dependencyMap.get( this )).remove( serviceReference );
+            AbstractComponentManager.RefPair refPair  = ( AbstractComponentManager.RefPair ) ((Map ) dependencyMap.get( this )).get( serviceReference );
             if ( refPair != null && refPair.getServiceObject() != null )
             {
                 BundleComponentActivator activator = m_componentManager.getActivator();
@@ -1072,6 +1088,9 @@
         // is optional, if it is not then the dependency is invalid
         if ( !isSatisfied() )
         {
+            m_componentManager.log( LogService.LOG_DEBUG,
+                "For dependency {0}, no longer satisfied, bind fails",
+                new Object[]{ m_dependencyMetadata.getName() }, null );
             return false;
         }
 
@@ -1088,6 +1107,9 @@
         // flag being set in the loop below
         boolean success = m_dependencyMetadata.isOptional();
 
+        m_componentManager.log( LogService.LOG_DEBUG,
+            "For dependency {0}, optional: {1}; to bind: {2}",
+            new Object[]{ m_dependencyMetadata.getName(), new Boolean( success ), parameters }, null );
         for ( Iterator i = parameters.entrySet().iterator(); i.hasNext(); )
         {
             Map.Entry entry = ( Map.Entry ) i.next();
@@ -1095,6 +1117,13 @@
             {
                 success = true;
             }
+            else
+            {
+                m_componentManager.log( LogService.LOG_DEBUG,
+                    "For dependency {0}, failed to invoke bind method on object {1}; success: {2}",
+                    new Object[]{ m_dependencyMetadata.getName(), entry.getValue(), new Boolean( success )}, null );
+
+            }
         }
         return success;
     }
@@ -1160,7 +1189,7 @@
                     m_componentManager.log( LogService.LOG_ERROR,
                         "For dependency {0}, bind method not set: component state {1}",
                         new Object[]
-                            { new Integer(m_componentManager.getState())  }, null );
+                            { m_dependencyMetadata.getName(), new Integer(m_componentManager.getState())  }, null );
 
                 }
                 Map deps = ( Map ) dependencyMap.get( this );
diff --git a/scr/src/main/java/org/apache/felix/scr/impl/manager/ImmediateComponentManager.java b/scr/src/main/java/org/apache/felix/scr/impl/manager/ImmediateComponentManager.java
index 7a0c438..1c2c93a 100644
--- a/scr/src/main/java/org/apache/felix/scr/impl/manager/ImmediateComponentManager.java
+++ b/scr/src/main/java/org/apache/felix/scr/impl/manager/ImmediateComponentManager.java
@@ -631,6 +631,14 @@
                                 null );
 
                     }
+                    else
+                    {
+                        log(
+                                LogService.LOG_DEBUG,
+                                "getService won collecting dependencies, proceed to creating object.",
+                                null );
+
+                    }
                 }
                 catch ( IllegalStateException e )
                 {
diff --git a/scr/src/main/java/org/apache/felix/scr/impl/manager/ServiceFactoryComponentManager.java b/scr/src/main/java/org/apache/felix/scr/impl/manager/ServiceFactoryComponentManager.java
index bd3ba95..514e501 100644
--- a/scr/src/main/java/org/apache/felix/scr/impl/manager/ServiceFactoryComponentManager.java
+++ b/scr/src/main/java/org/apache/felix/scr/impl/manager/ServiceFactoryComponentManager.java
@@ -95,10 +95,37 @@
 
         // When the getServiceMethod is called, the implementation object must be created
 
-        final boolean release = obtainReadLock( "ServiceFactoryComponentManager.getService.1" );
+        boolean release = obtainReadLock( "ServiceFactoryComponentManager.getService.1" );
         try
         {
-// private ComponentContext and implementation instances
+            releaseReadLock( "ServiceFactoryComponentManager.getService.1" );
+            try
+            {
+                if ( !collectDependencies() )
+                {
+                    log(
+                            LogService.LOG_INFO,
+                            "getService (ServiceFactory) did not win collecting dependencies, try creating object anyway.",
+                            null );
+
+                }
+                else
+                {
+                    log(
+                            LogService.LOG_DEBUG,
+                            "getService (ServiceFactory) won collecting dependencies, proceed to creating object.",
+                            null );
+
+                }
+            }
+            catch ( IllegalStateException e )
+            {
+                //cannot obtain service from a required reference
+                release = false;
+                return null;
+            }
+            obtainReadLock( "ServiceFactoryComponentManager.getService.1" );
+            // private ComponentContext and implementation instances
             BundleComponentContext serviceContext = new BundleComponentContext( this, bundle );
             Object service = createImplementationObject( serviceContext );