FELIX-3870 improve logging and straighten out logic around calling modified method on config update

git-svn-id: https://svn.apache.org/repos/asf/felix/trunk@1438383 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 b9d7029..a612ad2 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
@@ -61,6 +61,14 @@
  */
 public abstract class AbstractComponentManager<S> implements Component, SimpleLogger
 {
+    //useful text for deactivation reason numbers
+    static final String[] REASONS = {"Unspecified",
+        "Component disabled",
+        "Reference became unsatisfied",
+        "Configuration modified",
+        "Configuration deleted",
+        "Component disabled",
+        "Bundle stopped"};
 
     // the ID of this component
     private long m_componentId;
@@ -278,6 +286,7 @@
 
     //---------- Asynchronous frontend to state change methods ----------------
     private static final AtomicLong taskCounter = new AtomicLong( );
+
     /**
      * Enables this component and - if satisfied - also activates it. If
      * enabling the component fails for any reason, the component ends up
@@ -1285,7 +1294,7 @@
 
         void deactivate( AbstractComponentManager acm, int reason, boolean disable )
         {
-            log( acm, "deactivate (reason: " + reason + ") (dsable: " + disable + ")" );
+            log( acm, "deactivate (reason: " + REASONS[ reason ] + ") (dsable: " + disable + ")" );
         }
 
 
@@ -1397,7 +1406,7 @@
 
         void dispose( AbstractComponentManager acm, int reason )
         {
-            acm.log( LogService.LOG_DEBUG, "Disposing component (reason: " + reason + ")", null );
+            acm.log( LogService.LOG_DEBUG, "Disposing component (reason: {0})", new Object[] { REASONS[ reason ] }, null );
             acm.clear();
             acm.changeState( Disposed.getInstance() );
 
@@ -1557,6 +1566,7 @@
 
         void dispose( AbstractComponentManager acm, int reason )
         {
+            acm.log( LogService.LOG_DEBUG, "Disposing component for reason {0}", new Object[] { REASONS[ reason] }, null );
             acm.disableDependencyManagers();
             doDisable( acm );
             acm.clear();   //content of Disabled.dispose
@@ -1593,7 +1603,7 @@
 
         void deactivate( AbstractComponentManager acm, int reason, boolean disable )
         {
-            acm.log( LogService.LOG_DEBUG, "Deactivating component", null );
+            acm.log( LogService.LOG_DEBUG, "Deactivating component for reason {0}", new Object[] {REASONS[ reason ]},  null );
 
             // catch any problems from deleting the component to prevent the
             // component to remain in the deactivating state !
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 f29fb00..84d7d95 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
@@ -28,6 +28,7 @@
 import org.apache.felix.scr.impl.helper.ActivateMethod.ActivatorParameter;
 import org.apache.felix.scr.impl.helper.ComponentMethods;
 import org.apache.felix.scr.impl.helper.MethodResult;
+import org.apache.felix.scr.impl.helper.ModifiedMethod;
 import org.apache.felix.scr.impl.metadata.ComponentMetadata;
 import org.apache.felix.scr.impl.metadata.ReferenceMetadata;
 import org.osgi.framework.Bundle;
@@ -169,7 +170,7 @@
             m_useCount.set( 0 );
             m_implementationObject = null;
             cleanupImplementationObject( implementationObject );
-            log( LogService.LOG_DEBUG, "Unset implementation object for component {0} in deleteComponent for reason {1}", new Object[] { getName(), reason },  null );
+            log( LogService.LOG_DEBUG, "Unset implementation object for component {0} in deleteComponent for reason {1}", new Object[] { getName(), REASONS[ reason ] },  null );
             m_componentContext = null;
             m_properties = null;
             m_serviceProperties = null;
@@ -532,14 +533,13 @@
         // clear the current properties to force using the configuration data
         m_properties = null;
 
-        updateTargets( getProperties() );
-
         // unsatisfied component and non-ignored configuration may change targets
         // to satisfy references
         if ( getState() == STATE_UNSATISFIED && configuration != null
                 && !getComponentMetadata().isConfigurationIgnored() )
         {
             log( LogService.LOG_DEBUG, "Attempting to activate unsatisfied component", null );
+            updateTargets( getProperties() );
             activateInternal( getTrackingCount().get() );
             return;
         }
@@ -549,6 +549,8 @@
         if ( ( getState() & ( STATE_ACTIVE | STATE_FACTORY | STATE_REGISTERED ) ) == 0 )
         {
             // nothing to do for inactive components, leave this method
+            log( LogService.LOG_DEBUG, "Component can not be configured in state {0}", new Object[] { getState() }, null );
+            updateTargets( getProperties() );
             return;
         }
 
@@ -557,8 +559,10 @@
         if ( configuration == null && getComponentMetadata().isConfigurationRequired() )
         {
             deactivateInternal( ComponentConstants.DEACTIVATION_REASON_CONFIGURATION_DELETED, true, getTrackingCount().get() );
+            updateTargets( getProperties() );
+            return;
         }
-        else if ( configuration == null | !modify() )
+        if ( !modify() )
         {
             // SCR 112.7.1 - deactivate if configuration is deleted or no modified method declared
             log( LogService.LOG_DEBUG, "Deactivating and Activating to reconfigure from configuration", null );
@@ -569,21 +573,17 @@
             //     called through ConfigurationListener API which itself is
             //     called asynchronously by the Configuration Admin Service
             deactivateInternal( reason, false, getTrackingCount().get() );
+            updateTargets( getProperties() );
             activateInternal( getTrackingCount().get() );
         }
     }
 
     private boolean modify()
     {
-        // 0. no live update if there is no instance
-        if ( hasInstance() )
-        {
-            return false;
-        }
-
         // 1. no live update if there is no declared method
         if ( getComponentMetadata().getModified() == null )
         {
+            log( LogService.LOG_DEBUG, "No modified method, cannot update dynamically", null );
             return false;
         }
         // invariant: we have a modified method name
@@ -600,8 +600,7 @@
             {
                 log( LogService.LOG_DEBUG,
                         "Cannot dynamically update the configuration due to dependency changes induced on dependency {0}",
-                        new Object[]
-                                {dm.getName()}, null );
+                        new Object[] {dm.getName()}, null );
                 return false;
             }
         }
@@ -610,13 +609,13 @@
         // 4. call method (nothing to do when failed, since it has already been logged)
         //   (call with non-null default result to continue even if the
         //    modify method call failed)
+        updateTargets( props );
         final MethodResult result = invokeModifiedMethod();
         if ( result == null )
         {
             // log an error if the declared method cannot be found
             log( LogService.LOG_ERROR, "Declared modify method ''{0}'' cannot be found, configuring by reactivation",
-                    new Object[]
-                            {getComponentMetadata().getModified()}, null );
+                    new Object[] {getComponentMetadata().getModified()}, null );
             return false;
         }
 
@@ -625,8 +624,7 @@
         // this dynamic update and have the component be deactivated
         if ( !verifyDependencyManagers() )
         {
-            log(
-                    LogService.LOG_ERROR,
+            log( LogService.LOG_ERROR,
                     "Updating the service references caused at least on reference to become unsatisfied, deactivating component",
                     null );
             return false;
@@ -648,16 +646,21 @@
 
     protected MethodResult invokeModifiedMethod()
     {
-        return getComponentMethods().getModifiedMethod().invoke( getInstance(),
-                    new ActivatorParameter( m_componentContext, -1 ), MethodResult.VOID, this );
+        ModifiedMethod modifiedMethod = getComponentMethods().getModifiedMethod();
+        if ( getInstance() != null )
+        {
+            return modifiedMethod.invoke( getInstance(), new ActivatorParameter( m_componentContext, -1 ),
+                    MethodResult.VOID, this );
+        }
+        else if ( m_tmpImplementationObject != null)
+        {
+            return modifiedMethod.invoke( m_tmpImplementationObject, new ActivatorParameter( m_componentContext, -1 ),
+                    MethodResult.VOID, this );
+            
+        }
+        return MethodResult.VOID;
     }
 
-    protected boolean hasInstance()
-    {
-        return getInstance() == null;
-    }
-
-
     /**
      * Checks if the given service registration properties matches another set
      * of properties.
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 e97e010..2dd097e 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
@@ -92,7 +92,7 @@
             disposeImplementationObject( componentContext.getInstance(), componentContext, reason );
             i.remove();
             cleanupImplementationObject( componentContext.getInstance() );
-            log( LogService.LOG_DEBUG, "Unset implementation object for component {0} in deleteComponent", new Object[] { getName() },  null );
+            log( LogService.LOG_DEBUG, "Unset implementation object for component {0} in deleteComponent for reason {1}", new Object[] { getName(), REASONS[ reason ] },  null );
         }
     }
 
@@ -244,7 +244,7 @@
     protected MethodResult invokeModifiedMethod()
     {
         ModifiedMethod modifiedMethod = getComponentMethods().getModifiedMethod();
-        MethodResult result = null;
+        MethodResult result = MethodResult.VOID;
         for ( BundleComponentContext componentContext : serviceContexts.values() )
         {
             Object instance = componentContext.getInstance();
@@ -262,11 +262,6 @@
         return result;
     }
 
-    protected boolean hasInstance()
-    {
-        return !serviceContexts.isEmpty();
-    }
-
     //---------- Component interface
 
     public ComponentInstance getComponentInstance()
diff --git a/scr/src/test/java/org/apache/felix/scr/integration/ComponentConfigurationTest.java b/scr/src/test/java/org/apache/felix/scr/integration/ComponentConfigurationTest.java
index 309e25c..55c118d 100644
--- a/scr/src/test/java/org/apache/felix/scr/integration/ComponentConfigurationTest.java
+++ b/scr/src/test/java/org/apache/felix/scr/integration/ComponentConfigurationTest.java
@@ -216,7 +216,7 @@
         delay();
 
         TestCase.assertEquals( Component.STATE_ACTIVE, component.getState() );
-        TestCase.assertNotSame( instance, SimpleComponent.INSTANCE );
+        TestCase.assertSame( instance, SimpleComponent.INSTANCE );
         TestCase.assertNull( SimpleComponent.INSTANCE.getProperty( PROP_NAME ) );
         TestCase.assertEquals( pid, SimpleComponent.INSTANCE.getProperty( Constants.SERVICE_PID ) );