Re: SCR/ unexpected component reactivation while starting up JVM

Tue, 09 Sep 2008 12:44:31 -0700 

Hi Felix and thank you for looking at this problem.
This is an issue for us, because we are using the DS in our application server, 
which runs in a clustered environment; and appserver deactivation may lead
to many alarms and network messages, so it would be great to have a fix, even 
in the trunk.
By the way, I'm wondering why you don't just wait for the initial managed service callback before 
initiating the component activation ?
Indeed, when you register a ManagedService, the configadmin always callback on the "updated" method (and the dictionary is null if there is no properties). This way, you would then be certain that config admin don't invoke the initial "updated" method while the component is active (I hope that what I am saying make sense for you). 

Best Regards
/pierre

Felix Meschberger wrote:

Hi Pierre,

This is an annoyance, I agree. What actually happens is this:

  * SCR registeres a ManagedService on behalf of the component
  * SCR activates the component
  * ConfigAdmin informs the ManagedService about configuration
     (in this case there is none, and null used)
  * SCR cycles the component to inject the new configuration

This situation does not happen all the time, because there may be times
that the ConfigAdmin notifies the ManagedService before the component
has actually been activated. In this case the restart is not done.

To fix this, we have multiple options: Insert a delay between
registering the ManagedService and activating the component to give
ConfigAdmin a chance to inject initial configuration. I do not
particularly like this option.

A second option would be to ignore the first ManagedService.updated call
for a component if the parameter is null. Because this just indicates,
that the ConfigAdmin has no configuration and thus the component does
not need to be reconfigured.

This second option, of course does not prevent re-activation in case a
configuration actually present, but I think, this is the way of life ...

I created https://issues.apache.org/jira/browse/FELIX-714 to track this
issue.

Hope this helps.

Regards
Felix



Pierre De Rop schrieb:

Hi everyone;

I recently noticed a strange behaviour with Declarative Services.
Sometimes (rarely, but it happens), I see that my SCR components are
activated twice at jvm startup time.

Did anyone came across the same problem ?

I know that a component must expect to be deactivated/reactivated
(after a bundle update, or after a ConfigAdmin update for example),
But in my case, the problem occurs at startup (there is no bundle
update, and I don't use the ConfigAdmin service at all for my
components configurations).

I have the following components for our Alcatel-Lucent Distributed
Hashtable Service:

 "ServiceLoader"
 "DistributedSessions"
 "Dht"
 "DhtReg"

and in the following SCR log, around 23:59:39,066, you will see that
"DistributedSessions" component is deactivated/reactivated:

Here are the logs (please see my comments after the logs):

2008-09-06 23:59:39,012 FelixStartLevel DEBUG osgi  - [ServiceLoader]
ManagerFactory.createManager
2008-09-06 23:59:39,019 FelixStartLevel DEBUG osgi  - [ServiceLoader]
Component created
2008-09-06 23:59:39,037 SCR Component Actor DEBUG osgi  -
[ServiceLoader] Enabling component
2008-09-06 23:59:39,038 FelixStartLevel DEBUG osgi  -
[DistributedSessions] ManagerFactory.createManager
2008-09-06 23:59:39,038 SCR Component Actor DEBUG osgi  -
[ServiceLoader] State transition : Disabled -> Enabled
2008-09-06 23:59:39,038 FelixStartLevel DEBUG osgi  -
[DistributedSessions] Component created
2008-09-06 23:59:39,039 SCR Component Actor DEBUG osgi  -
[ServiceLoader] Component enabled
2008-09-06 23:59:39,041 SCR Component Actor DEBUG osgi  -
[ServiceLoader] State transition : Enabled -> Activating
2008-09-06 23:59:39,043 SCR Component Actor DEBUG osgi  -
[ServiceLoader] Activating component
2008-09-06 23:59:39,047 SCR Component Actor DEBUG osgi  -
[ServiceLoader] State transition : Activating -> Active
2008-09-06 23:59:39,048 SCR Component Actor DEBUG osgi  -
[ServiceLoader] Component activated
2008-09-06 23:59:39,048 SCR Component Actor DEBUG osgi  -
[DistributedSessions] Enabling component
2008-09-06 23:59:39,048 SCR Component Actor DEBUG osgi  -
[DistributedSessions] State transition : Disabled -> Enabled
2008-09-06 23:59:39,049 SCR Component Actor DEBUG osgi  -
[DistributedSessions] Component enabled
2008-09-06 23:59:39,049 FelixStartLevel DEBUG osgi  - [Dht]
ManagerFactory.createManager
2008-09-06 23:59:39,049 SCR Component Actor DEBUG osgi  -
[DistributedSessions] State transition : Enabled -> Activating
2008-09-06 23:59:39,050 SCR Component Actor DEBUG osgi  -
[DistributedSessions] Activating component
2008-09-06 23:59:39,050 FelixStartLevel DEBUG osgi  - [Dht] Component
created
2008-09-06 23:59:39,055 FelixStartLevel DEBUG osgi  - [DhtSessionDir]
ManagerFactory.createManager
2008-09-06 23:59:39,058 FelixStartLevel DEBUG osgi  - [DhtSessionDir]
Component created
2008-09-06 23:59:39,055 Configuration Updater DEBUG osgi  -
[ServiceLoader] Deactivating and Activating to reconfigure from
configuration
2008-09-06 23:59:39,061 SCR Component Actor DEBUG osgi  -
[DistributedSessions] State transition : Activating -> Active
2008-09-06 23:59:39,062 SCR Component Actor DEBUG osgi  -
[DistributedSessions] Component activated

-> Why the following log reactivates the component ? I don't have any
configurations stored in the ConfigAdmin with pid="DistributedSessions" !
(notice that the log's thread is the Config Admin thread ...) :
2008-09-06 23:59:39,066 Configuration Updater DEBUG osgi  -
[DistributedSessions] Deactivating and Activating to reconfigure from
configuration

2008-09-06 23:59:39,067 SCR Component Actor DEBUG osgi  - [Dht] Enabling
component
2008-09-06 23:59:39,071 SCR Component Actor DEBUG osgi  - [Dht] State
transition : Disabled -> Enabled
2008-09-06 23:59:39,071 SCR Component Actor DEBUG osgi  - [Dht]
Component enabled
2008-09-06 23:59:39,072 SCR Component Actor DEBUG osgi  - [Dht] State
transition : Enabled -> Activating
2008-09-06 23:59:39,072 SCR Component Actor DEBUG osgi  - [Dht]
Activating component
2008-09-06 23:59:39,072 SCR Component Actor DEBUG osgi  - [Dht] State
transition : Activating -> Registered
2008-09-06 23:59:39,072 SCR Component Actor DEBUG osgi  - [Dht]
registering services
2008-09-06 23:59:39,066 FelixStartLevel DEBUG osgi  - [DhtReg"]
ManagerFactory.createManager
2008-09-06 23:59:39,073 FelixStartLevel DEBUG osgi  - [DhtReg] Component
created
2008-09-06 23:59:39,075 Configuration Updater DEBUG osgi  - [Dht]
Deactivating and Activating to reconfigure from configuration
2008-09-06 23:59:39,078 SCR Component Actor DEBUG osgi  - [Dht]
Component activated
2008-09-06 23:59:39,079 SCR Component Actor DEBUG osgi  -
[ServiceLoader] State transition : Active -> Deactivating
2008-09-06 23:59:39,079 SCR Component Actor DEBUG osgi  -
[ServiceLoader] Deactivating component
2008-09-06 23:59:39,079 SCR Component Actor DEBUG osgi  -
[ServiceLoader] deactivate() method is not implemented
2008-09-06 23:59:39,080 SCR Component Actor DEBUG osgi  -
[ServiceLoader] State transition : Deactivating -> Unsatisfied
2008-09-06 23:59:39,080 SCR Component Actor DEBUG osgi  -
[ServiceLoader] Component deactivated
2008-09-06 23:59:39,080 SCR Component Actor DEBUG osgi  -
[ServiceLoader] State transition : Unsatisfied -> Activating
2008-09-06 23:59:39,081 SCR Component Actor DEBUG osgi  -
[ServiceLoader] Activating component
2008-09-06 23:59:39,081 SCR Component Actor DEBUG osgi  -
[ServiceLoader] State transition : Activating -> Active
2008-09-06 23:59:39,083 SCR Component Actor DEBUG osgi  -
[ServiceLoader] Component activated
2008-09-06 23:59:39,083 SCR Component Actor DEBUG osgi  -
[DhtSessionDir] Enabling component
2008-09-06 23:59:39,084 SCR Component Actor DEBUG osgi  -
[DhtSessionDir] State transition : Disabled -> Enabled
2008-09-06 23:59:39,084 SCR Component Actor DEBUG osgi  -
[DhtSessionDir] Component enabled
2008-09-06 23:59:39,084 SCR Component Actor DEBUG osgi  -
[DhtSessionDir] State transition : Enabled -> Activating
2008-09-06 23:59:39,084 SCR Component Actor DEBUG osgi  -
[DhtSessionDir] Activating component
2008-09-06 23:59:39,085 SCR Component Actor DEBUG osgi  -
[DhtSessionDir] State transition : Activating -> Registered
2008-09-06 23:59:39,085 SCR Component Actor DEBUG osgi  -
[DhtSessionDir] registering services
2008-09-06 23:59:39,086 SCR Component Actor DEBUG osgi  -
[DhtSessionDir] Component activated
2008-09-06 23:59:39,086 SCR Component Actor DEBUG osgi  -
[DistributedSessions] State transition : Active -> Deactivating
2008-09-06 23:59:39,087 SCR Component Actor DEBUG osgi  -
[DistributedSessions] Deactivating component
2008-09-06 23:59:39,087 SCR Component Actor DEBUG osgi  -
[DistributedSessions] State transition : Deactivating -> Unsatisfied
2008-09-06 23:59:39,088 SCR Component Actor DEBUG osgi  -
[DistributedSessions] Component deactivated
2008-09-06 23:59:39,088 SCR Component Actor DEBUG osgi  -
[DistributedSessions] State transition : Unsatisfied -> Activating
2008-09-06 23:59:39,088 SCR Component Actor DEBUG osgi  -
[DistributedSessions] Activating component

I am not really certain, but my undestanding is the following: The SCR
actually registers a ManagedService in the OSGi service registry in
order to provide eventual configurations to the component. But it
sounds like the SCR starts activating the
"DistributedSessions" component before (FIXME ?) being called back in
"ManagedService.updated" method.  So, sometimes, when the
"DistributedSessions" is activated quickly, it is then just restarted.
Please have a look in the SCR source code, especially in
ImmediateComponentManager.java:

The constructor registers a ManagedService for my "DistributedSessions"
component:

   ImmediateComponentManager( BundleComponentActivator activator,
ComponentMetadata metadata, long componentId )
   {
           ...
           // register an anonymous managed service instance
           ManagedService ms = new ManagedService()
           {
               public void updated( Dictionary properties )
               {
                   reconfigure( properties );
               }
           };


   public void reconfigure( Dictionary configuration )
   {
       // store the properties
       m_configurationProperties = configuration;

       // clear the current properties to force using the configuration
data
       m_properties = null;

       // reactivate the component to ensure it is provided with the
       // configuration data
       if ( ( getState() & ( STATE_ACTIVE | STATE_FACTORY |
STATE_REGISTERED ) ) != 0 )
       {
           log( LogService.LOG_DEBUG, "Deactivating and Activating to
reconfigure from configuration",
               getComponentMetadata(), null );
           reactivateAsynchronous();
       }
   }

-> So, did I miss something, or is it a concurrency bug ?
Is SCR really waiting for the initial ManagedService callback, before
starting to activate components ?

Thanks for your help.
/pierre


---------------------------------------------------------------------
To unsubscribe, e-mail: [EMAIL PROTECTED]
For additional commands, e-mail: [EMAIL PROTECTED]




---------------------------------------------------------------------
To unsubscribe, e-mail: [EMAIL PROTECTED]
For additional commands, e-mail: [EMAIL PROTECTED]

Reply via email to