You are viewing a plain text version of this content. The canonical link for it is here.

Posted to dev@felix.apache.org by Rajini Sivaram <ra...@googlemail.com> on 2007/08/20 16:18:35 UTC

Intermittent exception during Felix shutdown

Hello,

One of my testcases intermittently throws an exception during shutdown. I
have managed to recreate the exception under a debugger, and it shows two
threads trying to unregister the same service. The test fails only when
declarative services are used. I am using Felix 1.0.0. The test uses
multiple versions of a bundle, but I am not sure if that has anything to do
with the exception.

The exception thrown is:

    --- Exception with component : Unexpected problem executing task ---
    java.lang.IllegalStateException: Service already unregistered.
        at org.apache.felix.framework.ServiceRegistrationImpl.unregister(
ServiceRegistrationImpl.java:105)
        at
org.apache.felix.scr.AbstractComponentManager.unregisterComponentService(
AbstractComponentManager.java:503)
        at org.apache.felix.scr.AbstractComponentManager.deactivateInternal(
AbstractComponentManager.java:369)
        at org.apache.felix.scr.AbstractComponentManager.access$200(
AbstractComponentManager.java:55)
        at org.apache.felix.scr.AbstractComponentManager$3.run(
AbstractComponentManager.java:176)
        at org.apache.felix.scr.ComponentActorThread.run(
ComponentActorThread.java:81)

Here is the stack trace of the two threads under the debugger (both are
using the same object):

                Thread [FelixStartLevel] (Suspended (breakpoint at line 97
in ServiceRegistrationImpl))
                        ServiceRegistrationImpl.unregister() line: 97
                        ServiceRegistry.unregisterServices(Bundle) line: 119
                        Felix._stopBundle(FelixBundle, boolean) line: 1946
                        Felix.stopBundle(FelixBundle, boolean) line: 1866
                        Felix.setFrameworkStartLevel(int) line: 1080
                        StartLevelImpl.run() line: 258
                        Thread.run() line: 803
                Thread [SCR Component Actor] (Suspended (breakpoint at line
97 in ServiceRegistrationImpl))
                        ServiceRegistrationImpl.unregister() line: 97

ImmediateComponentManager(AbstractComponentManager).unregisterComponentService()
line: 503

ImmediateComponentManager(AbstractComponentManager).deactivateInternal()
line: 369

AbstractComponentManager.access$200(AbstractComponentManager)
line: 55
                        AbstractComponentManager$3.run() line: 176
                        ComponentActorThread.run() line: 81


The exception thrown is the IllegalStateException from
    public void unregister()
    {
        if (m_svcObj != null)
        {
            m_registry.unregisterService(m_bundle, this);
            m_svcObj = null;
            m_factory = null;
        }
        else
        {
           * throw new IllegalStateException("Service already
unregistered.");
*        }
    }



Thank you...

Regards,

Rajini

Re: Intermittent exception during Felix shutdown

Posted by Rajini Sivaram <ra...@googlemail.com>.

Thank you, Felix. I have filed a JIRA issue.

Thank you...

Regards,

Rajini


On 8/21/07, Felix Meschberger <fm...@gmail.com> wrote:
>
> Hi Rajini,
>
> Thanks for the information (We had a similar issue, which why I asked
> for the SCR bundle version).
>
> This sounds like some kind of race condition. I will look into it.
>
> Could you please file a JIRA issue ? That would be nice. Thanks.
>
> Regards
> Felix
>
> Am Montag, den 20.08.2007, 16:27 +0100 schrieb Rajini Sivaram:
> > Felix,
> >
> > I have moved to 0.9.0-SNAPSHOT (now using the latest scr bundle you
> > mentioned below). The same exception still occurs.
> >
> > There is no 0.9.0-SNAPSHOT for the log bundle (and it is a dependency
> for
> > configadmin). Should I continue to use the incubator version for log?
> >
> > Thank you...
> >
> > Regards,
> >
> > Rajini
> >
> > On 8/20/07, Felix Meschberger <fm...@gmail.com> wrote:
> > >
> > > Hi Rajini,
> > >
> > > There is not release of this bundle, yet. But, have you tried the
> latest
> > > SNAPSHOT 0.9.0-20070814.113621-1. As Felix has graduated the
> "incubator"
> > > tag in the version is not required anymore, so the SNAPSHOT version
> > > should referred to as
> > >
> > >    <version>0.9.0-SNAPSHOT</version>
> > >
> > > Regards
> > > Felix
> > >
> > >
> > > Am Montag, den 20.08.2007, 15:48 +0100 schrieb Rajini Sivaram:
> > > > Felix,
> > > >
> > > > I am using org.apache.felix.scr-0.9.0-incubator-20070515.104418-2. I
> > > > couldn't find a 1.0.0 version of it in the maven repository.
> > > >
> > > > There is no multi-threading inside the test. But there are two
> versions
> > > of
> > > > each test bundle installed.
> > > >
> > > > Thank you...
> > > >
> > > > Regards,
> > > >
> > > > Rajini
> > > >
> > > > On 8/20/07, Felix Meschberger <fm...@gmail.com> wrote:
> > > > >
> > > > > Hi Rajini,
> > > > >
> > > > > Just a quick question: What version of the Felix SCR Bundle are
> you
> > > > > using ?
> > > > >
> > > > > Is there anything special about your test case, like for example
> > > > > Multi-threadedness in some way or the other ?
> > > > >
> > > > > Thanks and Regards
> > > > > Felix
> > > > >
> > > > > Am Montag, den 20.08.2007, 15:18 +0100 schrieb Rajini Sivaram:
> > > > > > Hello,
> > > > > >
> > > > > > One of my testcases intermittently throws an exception during
> > > shutdown.
> > > > > I
> > > > > > have managed to recreate the exception under a debugger, and it
> > > shows
> > > > > two
> > > > > > threads trying to unregister the same service. The test fails
> only
> > > when
> > > > > > declarative services are used. I am using Felix 1.0.0. The test
> uses
> > > > > > multiple versions of a bundle, but I am not sure if that has
> > > anything to
> > > > > do
> > > > > > with the exception.
> > > > > >
> > > > > > The exception thrown is:
> > > > > >
> > > > > >     --- Exception with component : Unexpected problem executing
> task
> > > ---
> > > > > >     java.lang.IllegalStateException: Service already
> unregistered.
> > > > > >         at
> > > org.apache.felix.framework.ServiceRegistrationImpl.unregister
> > > > > (
> > > > > > ServiceRegistrationImpl.java:105)
> > > > > >         at
> > > > > >
> > >
> org.apache.felix.scr.AbstractComponentManager.unregisterComponentService
> > > > > (
> > > > > > AbstractComponentManager.java:503)
> > > > > >         at
> > > > > org.apache.felix.scr.AbstractComponentManager.deactivateInternal(
> > > > > > AbstractComponentManager.java:369)
> > > > > >         at
> org.apache.felix.scr.AbstractComponentManager.access$200(
> > > > > > AbstractComponentManager.java:55)
> > > > > >         at org.apache.felix.scr.AbstractComponentManager$3.run(
> > > > > > AbstractComponentManager.java:176)
> > > > > >         at org.apache.felix.scr.ComponentActorThread.run(
> > > > > > ComponentActorThread.java:81)
> > > > > >
> > > > > > Here is the stack trace of the two threads under the debugger
> (both
> > > are
> > > > > > using the same object):
> > > > > >
> > > > > >                 Thread [FelixStartLevel] (Suspended (breakpoint
> at
> > > line
> > > > > 97
> > > > > > in ServiceRegistrationImpl))
> > > > > >                         ServiceRegistrationImpl.unregister()
> line:
> > > 97
> > > > > >                         ServiceRegistry.unregisterServices
> (Bundle)
> > > line:
> > > > > 119
> > > > > >                         Felix._stopBundle(FelixBundle, boolean)
> > > line:
> > > > > 1946
> > > > > >                         Felix.stopBundle(FelixBundle, boolean)
> line:
> > > > > 1866
> > > > > >                         Felix.setFrameworkStartLevel(int) line:
> 1080
> > > > > >                         StartLevelImpl.run() line: 258
> > > > > >                         Thread.run() line: 803
> > > > > >                 Thread [SCR Component Actor] (Suspended
> (breakpoint
> > > at
> > > > > line
> > > > > > 97 in ServiceRegistrationImpl))
> > > > > >                         ServiceRegistrationImpl.unregister()
> line:
> > > 97
> > > > > >
> > > > > >
> > > > >
> > >
> ImmediateComponentManager(AbstractComponentManager).unregisterComponentService()
> > > > > > line: 503
> > > > > >
> > > > > >
> > >
> ImmediateComponentManager(AbstractComponentManager).deactivateInternal()
> > > > > > line: 369
> > > > > >
> > > > > > AbstractComponentManager.access$200(AbstractComponentManager)
> > > > > > line: 55
> > > > > >                         AbstractComponentManager$3.run() line:
> 176
> > > > > >                         ComponentActorThread.run() line: 81
> > > > > >
> > > > > >
> > > > > > The exception thrown is the IllegalStateException from
> > > > > >     public void unregister()
> > > > > >     {
> > > > > >         if (m_svcObj != null)
> > > > > >         {
> > > > > >             m_registry.unregisterService(m_bundle, this);
> > > > > >             m_svcObj = null;
> > > > > >             m_factory = null;
> > > > > >         }
> > > > > >         else
> > > > > >         {
> > > > > >            * throw new IllegalStateException("Service already
> > > > > > unregistered.");
> > > > > > *        }
> > > > > >     }
> > > > > >
> > > > > >
> > > > > >
> > > > > > Thank you...
> > > > > >
> > > > > > Regards,
> > > > > >
> > > > > > Rajini
> > > > >
> > > > >
> > >
> > >
>
>

Re: Intermittent exception during Felix shutdown

Posted by Felix Meschberger <fm...@gmail.com>.

Hi Rajini,

Thanks for the information (We had a similar issue, which why I asked
for the SCR bundle version).

This sounds like some kind of race condition. I will look into it.

Could you please file a JIRA issue ? That would be nice. Thanks.

Regards
Felix

Am Montag, den 20.08.2007, 16:27 +0100 schrieb Rajini Sivaram:
> Felix,
> 
> I have moved to 0.9.0-SNAPSHOT (now using the latest scr bundle you
> mentioned below). The same exception still occurs.
> 
> There is no 0.9.0-SNAPSHOT for the log bundle (and it is a dependency for
> configadmin). Should I continue to use the incubator version for log?
> 
> Thank you...
> 
> Regards,
> 
> Rajini
> 
> On 8/20/07, Felix Meschberger <fm...@gmail.com> wrote:
> >
> > Hi Rajini,
> >
> > There is not release of this bundle, yet. But, have you tried the latest
> > SNAPSHOT 0.9.0-20070814.113621-1. As Felix has graduated the "incubator"
> > tag in the version is not required anymore, so the SNAPSHOT version
> > should referred to as
> >
> >    <version>0.9.0-SNAPSHOT</version>
> >
> > Regards
> > Felix
> >
> >
> > Am Montag, den 20.08.2007, 15:48 +0100 schrieb Rajini Sivaram:
> > > Felix,
> > >
> > > I am using org.apache.felix.scr-0.9.0-incubator-20070515.104418-2. I
> > > couldn't find a 1.0.0 version of it in the maven repository.
> > >
> > > There is no multi-threading inside the test. But there are two versions
> > of
> > > each test bundle installed.
> > >
> > > Thank you...
> > >
> > > Regards,
> > >
> > > Rajini
> > >
> > > On 8/20/07, Felix Meschberger <fm...@gmail.com> wrote:
> > > >
> > > > Hi Rajini,
> > > >
> > > > Just a quick question: What version of the Felix SCR Bundle are you
> > > > using ?
> > > >
> > > > Is there anything special about your test case, like for example
> > > > Multi-threadedness in some way or the other ?
> > > >
> > > > Thanks and Regards
> > > > Felix
> > > >
> > > > Am Montag, den 20.08.2007, 15:18 +0100 schrieb Rajini Sivaram:
> > > > > Hello,
> > > > >
> > > > > One of my testcases intermittently throws an exception during
> > shutdown.
> > > > I
> > > > > have managed to recreate the exception under a debugger, and it
> > shows
> > > > two
> > > > > threads trying to unregister the same service. The test fails only
> > when
> > > > > declarative services are used. I am using Felix 1.0.0. The test uses
> > > > > multiple versions of a bundle, but I am not sure if that has
> > anything to
> > > > do
> > > > > with the exception.
> > > > >
> > > > > The exception thrown is:
> > > > >
> > > > >     --- Exception with component : Unexpected problem executing task
> > ---
> > > > >     java.lang.IllegalStateException: Service already unregistered.
> > > > >         at
> > org.apache.felix.framework.ServiceRegistrationImpl.unregister
> > > > (
> > > > > ServiceRegistrationImpl.java:105)
> > > > >         at
> > > > >
> > org.apache.felix.scr.AbstractComponentManager.unregisterComponentService
> > > > (
> > > > > AbstractComponentManager.java:503)
> > > > >         at
> > > > org.apache.felix.scr.AbstractComponentManager.deactivateInternal(
> > > > > AbstractComponentManager.java:369)
> > > > >         at org.apache.felix.scr.AbstractComponentManager.access$200(
> > > > > AbstractComponentManager.java:55)
> > > > >         at org.apache.felix.scr.AbstractComponentManager$3.run(
> > > > > AbstractComponentManager.java:176)
> > > > >         at org.apache.felix.scr.ComponentActorThread.run(
> > > > > ComponentActorThread.java:81)
> > > > >
> > > > > Here is the stack trace of the two threads under the debugger (both
> > are
> > > > > using the same object):
> > > > >
> > > > >                 Thread [FelixStartLevel] (Suspended (breakpoint at
> > line
> > > > 97
> > > > > in ServiceRegistrationImpl))
> > > > >                         ServiceRegistrationImpl.unregister() line:
> > 97
> > > > >                         ServiceRegistry.unregisterServices(Bundle)
> > line:
> > > > 119
> > > > >                         Felix._stopBundle(FelixBundle, boolean)
> > line:
> > > > 1946
> > > > >                         Felix.stopBundle(FelixBundle, boolean) line:
> > > > 1866
> > > > >                         Felix.setFrameworkStartLevel(int) line: 1080
> > > > >                         StartLevelImpl.run() line: 258
> > > > >                         Thread.run() line: 803
> > > > >                 Thread [SCR Component Actor] (Suspended (breakpoint
> > at
> > > > line
> > > > > 97 in ServiceRegistrationImpl))
> > > > >                         ServiceRegistrationImpl.unregister() line:
> > 97
> > > > >
> > > > >
> > > >
> > ImmediateComponentManager(AbstractComponentManager).unregisterComponentService()
> > > > > line: 503
> > > > >
> > > > >
> > ImmediateComponentManager(AbstractComponentManager).deactivateInternal()
> > > > > line: 369
> > > > >
> > > > > AbstractComponentManager.access$200(AbstractComponentManager)
> > > > > line: 55
> > > > >                         AbstractComponentManager$3.run() line: 176
> > > > >                         ComponentActorThread.run() line: 81
> > > > >
> > > > >
> > > > > The exception thrown is the IllegalStateException from
> > > > >     public void unregister()
> > > > >     {
> > > > >         if (m_svcObj != null)
> > > > >         {
> > > > >             m_registry.unregisterService(m_bundle, this);
> > > > >             m_svcObj = null;
> > > > >             m_factory = null;
> > > > >         }
> > > > >         else
> > > > >         {
> > > > >            * throw new IllegalStateException("Service already
> > > > > unregistered.");
> > > > > *        }
> > > > >     }
> > > > >
> > > > >
> > > > >
> > > > > Thank you...
> > > > >
> > > > > Regards,
> > > > >
> > > > > Rajini
> > > >
> > > >
> >
> >

Re: Intermittent exception during Felix shutdown

Posted by Rajini Sivaram <ra...@googlemail.com>.

Felix,

I have moved to 0.9.0-SNAPSHOT (now using the latest scr bundle you
mentioned below). The same exception still occurs.

There is no 0.9.0-SNAPSHOT for the log bundle (and it is a dependency for
configadmin). Should I continue to use the incubator version for log?

Thank you...

Regards,

Rajini

On 8/20/07, Felix Meschberger <fm...@gmail.com> wrote:
>
> Hi Rajini,
>
> There is not release of this bundle, yet. But, have you tried the latest
> SNAPSHOT 0.9.0-20070814.113621-1. As Felix has graduated the "incubator"
> tag in the version is not required anymore, so the SNAPSHOT version
> should referred to as
>
>    <version>0.9.0-SNAPSHOT</version>
>
> Regards
> Felix
>
>
> Am Montag, den 20.08.2007, 15:48 +0100 schrieb Rajini Sivaram:
> > Felix,
> >
> > I am using org.apache.felix.scr-0.9.0-incubator-20070515.104418-2. I
> > couldn't find a 1.0.0 version of it in the maven repository.
> >
> > There is no multi-threading inside the test. But there are two versions
> of
> > each test bundle installed.
> >
> > Thank you...
> >
> > Regards,
> >
> > Rajini
> >
> > On 8/20/07, Felix Meschberger <fm...@gmail.com> wrote:
> > >
> > > Hi Rajini,
> > >
> > > Just a quick question: What version of the Felix SCR Bundle are you
> > > using ?
> > >
> > > Is there anything special about your test case, like for example
> > > Multi-threadedness in some way or the other ?
> > >
> > > Thanks and Regards
> > > Felix
> > >
> > > Am Montag, den 20.08.2007, 15:18 +0100 schrieb Rajini Sivaram:
> > > > Hello,
> > > >
> > > > One of my testcases intermittently throws an exception during
> shutdown.
> > > I
> > > > have managed to recreate the exception under a debugger, and it
> shows
> > > two
> > > > threads trying to unregister the same service. The test fails only
> when
> > > > declarative services are used. I am using Felix 1.0.0. The test uses
> > > > multiple versions of a bundle, but I am not sure if that has
> anything to
> > > do
> > > > with the exception.
> > > >
> > > > The exception thrown is:
> > > >
> > > >     --- Exception with component : Unexpected problem executing task
> ---
> > > >     java.lang.IllegalStateException: Service already unregistered.
> > > >         at
> org.apache.felix.framework.ServiceRegistrationImpl.unregister
> > > (
> > > > ServiceRegistrationImpl.java:105)
> > > >         at
> > > >
> org.apache.felix.scr.AbstractComponentManager.unregisterComponentService
> > > (
> > > > AbstractComponentManager.java:503)
> > > >         at
> > > org.apache.felix.scr.AbstractComponentManager.deactivateInternal(
> > > > AbstractComponentManager.java:369)
> > > >         at org.apache.felix.scr.AbstractComponentManager.access$200(
> > > > AbstractComponentManager.java:55)
> > > >         at org.apache.felix.scr.AbstractComponentManager$3.run(
> > > > AbstractComponentManager.java:176)
> > > >         at org.apache.felix.scr.ComponentActorThread.run(
> > > > ComponentActorThread.java:81)
> > > >
> > > > Here is the stack trace of the two threads under the debugger (both
> are
> > > > using the same object):
> > > >
> > > >                 Thread [FelixStartLevel] (Suspended (breakpoint at
> line
> > > 97
> > > > in ServiceRegistrationImpl))
> > > >                         ServiceRegistrationImpl.unregister() line:
> 97
> > > >                         ServiceRegistry.unregisterServices(Bundle)
> line:
> > > 119
> > > >                         Felix._stopBundle(FelixBundle, boolean)
> line:
> > > 1946
> > > >                         Felix.stopBundle(FelixBundle, boolean) line:
> > > 1866
> > > >                         Felix.setFrameworkStartLevel(int) line: 1080
> > > >                         StartLevelImpl.run() line: 258
> > > >                         Thread.run() line: 803
> > > >                 Thread [SCR Component Actor] (Suspended (breakpoint
> at
> > > line
> > > > 97 in ServiceRegistrationImpl))
> > > >                         ServiceRegistrationImpl.unregister() line:
> 97
> > > >
> > > >
> > >
> ImmediateComponentManager(AbstractComponentManager).unregisterComponentService()
> > > > line: 503
> > > >
> > > >
> ImmediateComponentManager(AbstractComponentManager).deactivateInternal()
> > > > line: 369
> > > >
> > > > AbstractComponentManager.access$200(AbstractComponentManager)
> > > > line: 55
> > > >                         AbstractComponentManager$3.run() line: 176
> > > >                         ComponentActorThread.run() line: 81
> > > >
> > > >
> > > > The exception thrown is the IllegalStateException from
> > > >     public void unregister()
> > > >     {
> > > >         if (m_svcObj != null)
> > > >         {
> > > >             m_registry.unregisterService(m_bundle, this);
> > > >             m_svcObj = null;
> > > >             m_factory = null;
> > > >         }
> > > >         else
> > > >         {
> > > >            * throw new IllegalStateException("Service already
> > > > unregistered.");
> > > > *        }
> > > >     }
> > > >
> > > >
> > > >
> > > > Thank you...
> > > >
> > > > Regards,
> > > >
> > > > Rajini
> > >
> > >
>
>

Re: Intermittent exception during Felix shutdown

Posted by Felix Meschberger <fm...@gmail.com>.

Hi Rajini,

There is not release of this bundle, yet. But, have you tried the latest
SNAPSHOT 0.9.0-20070814.113621-1. As Felix has graduated the "incubator"
tag in the version is not required anymore, so the SNAPSHOT version
should referred to as

    <version>0.9.0-SNAPSHOT</version>

Regards
Felix


Am Montag, den 20.08.2007, 15:48 +0100 schrieb Rajini Sivaram:
> Felix,
> 
> I am using org.apache.felix.scr-0.9.0-incubator-20070515.104418-2. I
> couldn't find a 1.0.0 version of it in the maven repository.
> 
> There is no multi-threading inside the test. But there are two versions of
> each test bundle installed.
> 
> Thank you...
> 
> Regards,
> 
> Rajini
> 
> On 8/20/07, Felix Meschberger <fm...@gmail.com> wrote:
> >
> > Hi Rajini,
> >
> > Just a quick question: What version of the Felix SCR Bundle are you
> > using ?
> >
> > Is there anything special about your test case, like for example
> > Multi-threadedness in some way or the other ?
> >
> > Thanks and Regards
> > Felix
> >
> > Am Montag, den 20.08.2007, 15:18 +0100 schrieb Rajini Sivaram:
> > > Hello,
> > >
> > > One of my testcases intermittently throws an exception during shutdown.
> > I
> > > have managed to recreate the exception under a debugger, and it shows
> > two
> > > threads trying to unregister the same service. The test fails only when
> > > declarative services are used. I am using Felix 1.0.0. The test uses
> > > multiple versions of a bundle, but I am not sure if that has anything to
> > do
> > > with the exception.
> > >
> > > The exception thrown is:
> > >
> > >     --- Exception with component : Unexpected problem executing task ---
> > >     java.lang.IllegalStateException: Service already unregistered.
> > >         at org.apache.felix.framework.ServiceRegistrationImpl.unregister
> > (
> > > ServiceRegistrationImpl.java:105)
> > >         at
> > > org.apache.felix.scr.AbstractComponentManager.unregisterComponentService
> > (
> > > AbstractComponentManager.java:503)
> > >         at
> > org.apache.felix.scr.AbstractComponentManager.deactivateInternal(
> > > AbstractComponentManager.java:369)
> > >         at org.apache.felix.scr.AbstractComponentManager.access$200(
> > > AbstractComponentManager.java:55)
> > >         at org.apache.felix.scr.AbstractComponentManager$3.run(
> > > AbstractComponentManager.java:176)
> > >         at org.apache.felix.scr.ComponentActorThread.run(
> > > ComponentActorThread.java:81)
> > >
> > > Here is the stack trace of the two threads under the debugger (both are
> > > using the same object):
> > >
> > >                 Thread [FelixStartLevel] (Suspended (breakpoint at line
> > 97
> > > in ServiceRegistrationImpl))
> > >                         ServiceRegistrationImpl.unregister() line: 97
> > >                         ServiceRegistry.unregisterServices(Bundle) line:
> > 119
> > >                         Felix._stopBundle(FelixBundle, boolean) line:
> > 1946
> > >                         Felix.stopBundle(FelixBundle, boolean) line:
> > 1866
> > >                         Felix.setFrameworkStartLevel(int) line: 1080
> > >                         StartLevelImpl.run() line: 258
> > >                         Thread.run() line: 803
> > >                 Thread [SCR Component Actor] (Suspended (breakpoint at
> > line
> > > 97 in ServiceRegistrationImpl))
> > >                         ServiceRegistrationImpl.unregister() line: 97
> > >
> > >
> > ImmediateComponentManager(AbstractComponentManager).unregisterComponentService()
> > > line: 503
> > >
> > > ImmediateComponentManager(AbstractComponentManager).deactivateInternal()
> > > line: 369
> > >
> > > AbstractComponentManager.access$200(AbstractComponentManager)
> > > line: 55
> > >                         AbstractComponentManager$3.run() line: 176
> > >                         ComponentActorThread.run() line: 81
> > >
> > >
> > > The exception thrown is the IllegalStateException from
> > >     public void unregister()
> > >     {
> > >         if (m_svcObj != null)
> > >         {
> > >             m_registry.unregisterService(m_bundle, this);
> > >             m_svcObj = null;
> > >             m_factory = null;
> > >         }
> > >         else
> > >         {
> > >            * throw new IllegalStateException("Service already
> > > unregistered.");
> > > *        }
> > >     }
> > >
> > >
> > >
> > > Thank you...
> > >
> > > Regards,
> > >
> > > Rajini
> >
> >

Re: Intermittent exception during Felix shutdown

Posted by Rajini Sivaram <ra...@googlemail.com>.

Felix,

I am using org.apache.felix.scr-0.9.0-incubator-20070515.104418-2. I
couldn't find a 1.0.0 version of it in the maven repository.

There is no multi-threading inside the test. But there are two versions of
each test bundle installed.

Thank you...

Regards,

Rajini

On 8/20/07, Felix Meschberger <fm...@gmail.com> wrote:
>
> Hi Rajini,
>
> Just a quick question: What version of the Felix SCR Bundle are you
> using ?
>
> Is there anything special about your test case, like for example
> Multi-threadedness in some way or the other ?
>
> Thanks and Regards
> Felix
>
> Am Montag, den 20.08.2007, 15:18 +0100 schrieb Rajini Sivaram:
> > Hello,
> >
> > One of my testcases intermittently throws an exception during shutdown.
> I
> > have managed to recreate the exception under a debugger, and it shows
> two
> > threads trying to unregister the same service. The test fails only when
> > declarative services are used. I am using Felix 1.0.0. The test uses
> > multiple versions of a bundle, but I am not sure if that has anything to
> do
> > with the exception.
> >
> > The exception thrown is:
> >
> >     --- Exception with component : Unexpected problem executing task ---
> >     java.lang.IllegalStateException: Service already unregistered.
> >         at org.apache.felix.framework.ServiceRegistrationImpl.unregister
> (
> > ServiceRegistrationImpl.java:105)
> >         at
> > org.apache.felix.scr.AbstractComponentManager.unregisterComponentService
> (
> > AbstractComponentManager.java:503)
> >         at
> org.apache.felix.scr.AbstractComponentManager.deactivateInternal(
> > AbstractComponentManager.java:369)
> >         at org.apache.felix.scr.AbstractComponentManager.access$200(
> > AbstractComponentManager.java:55)
> >         at org.apache.felix.scr.AbstractComponentManager$3.run(
> > AbstractComponentManager.java:176)
> >         at org.apache.felix.scr.ComponentActorThread.run(
> > ComponentActorThread.java:81)
> >
> > Here is the stack trace of the two threads under the debugger (both are
> > using the same object):
> >
> >                 Thread [FelixStartLevel] (Suspended (breakpoint at line
> 97
> > in ServiceRegistrationImpl))
> >                         ServiceRegistrationImpl.unregister() line: 97
> >                         ServiceRegistry.unregisterServices(Bundle) line:
> 119
> >                         Felix._stopBundle(FelixBundle, boolean) line:
> 1946
> >                         Felix.stopBundle(FelixBundle, boolean) line:
> 1866
> >                         Felix.setFrameworkStartLevel(int) line: 1080
> >                         StartLevelImpl.run() line: 258
> >                         Thread.run() line: 803
> >                 Thread [SCR Component Actor] (Suspended (breakpoint at
> line
> > 97 in ServiceRegistrationImpl))
> >                         ServiceRegistrationImpl.unregister() line: 97
> >
> >
> ImmediateComponentManager(AbstractComponentManager).unregisterComponentService()
> > line: 503
> >
> > ImmediateComponentManager(AbstractComponentManager).deactivateInternal()
> > line: 369
> >
> > AbstractComponentManager.access$200(AbstractComponentManager)
> > line: 55
> >                         AbstractComponentManager$3.run() line: 176
> >                         ComponentActorThread.run() line: 81
> >
> >
> > The exception thrown is the IllegalStateException from
> >     public void unregister()
> >     {
> >         if (m_svcObj != null)
> >         {
> >             m_registry.unregisterService(m_bundle, this);
> >             m_svcObj = null;
> >             m_factory = null;
> >         }
> >         else
> >         {
> >            * throw new IllegalStateException("Service already
> > unregistered.");
> > *        }
> >     }
> >
> >
> >
> > Thank you...
> >
> > Regards,
> >
> > Rajini
>
>

Re: Intermittent exception during Felix shutdown

Posted by Felix Meschberger <fm...@gmail.com>.

Hi Rajini,

Just a quick question: What version of the Felix SCR Bundle are you
using ?

Is there anything special about your test case, like for example
Multi-threadedness in some way or the other ?

Thanks and Regards
Felix

Am Montag, den 20.08.2007, 15:18 +0100 schrieb Rajini Sivaram:
> Hello,
> 
> One of my testcases intermittently throws an exception during shutdown. I
> have managed to recreate the exception under a debugger, and it shows two
> threads trying to unregister the same service. The test fails only when
> declarative services are used. I am using Felix 1.0.0. The test uses
> multiple versions of a bundle, but I am not sure if that has anything to do
> with the exception.
> 
> The exception thrown is:
> 
>     --- Exception with component : Unexpected problem executing task ---
>     java.lang.IllegalStateException: Service already unregistered.
>         at org.apache.felix.framework.ServiceRegistrationImpl.unregister(
> ServiceRegistrationImpl.java:105)
>         at
> org.apache.felix.scr.AbstractComponentManager.unregisterComponentService(
> AbstractComponentManager.java:503)
>         at org.apache.felix.scr.AbstractComponentManager.deactivateInternal(
> AbstractComponentManager.java:369)
>         at org.apache.felix.scr.AbstractComponentManager.access$200(
> AbstractComponentManager.java:55)
>         at org.apache.felix.scr.AbstractComponentManager$3.run(
> AbstractComponentManager.java:176)
>         at org.apache.felix.scr.ComponentActorThread.run(
> ComponentActorThread.java:81)
> 
> Here is the stack trace of the two threads under the debugger (both are
> using the same object):
> 
>                 Thread [FelixStartLevel] (Suspended (breakpoint at line 97
> in ServiceRegistrationImpl))
>                         ServiceRegistrationImpl.unregister() line: 97
>                         ServiceRegistry.unregisterServices(Bundle) line: 119
>                         Felix._stopBundle(FelixBundle, boolean) line: 1946
>                         Felix.stopBundle(FelixBundle, boolean) line: 1866
>                         Felix.setFrameworkStartLevel(int) line: 1080
>                         StartLevelImpl.run() line: 258
>                         Thread.run() line: 803
>                 Thread [SCR Component Actor] (Suspended (breakpoint at line
> 97 in ServiceRegistrationImpl))
>                         ServiceRegistrationImpl.unregister() line: 97
> 
> ImmediateComponentManager(AbstractComponentManager).unregisterComponentService()
> line: 503
> 
> ImmediateComponentManager(AbstractComponentManager).deactivateInternal()
> line: 369
> 
> AbstractComponentManager.access$200(AbstractComponentManager)
> line: 55
>                         AbstractComponentManager$3.run() line: 176
>                         ComponentActorThread.run() line: 81
> 
> 
> The exception thrown is the IllegalStateException from
>     public void unregister()
>     {
>         if (m_svcObj != null)
>         {
>             m_registry.unregisterService(m_bundle, this);
>             m_svcObj = null;
>             m_factory = null;
>         }
>         else
>         {
>            * throw new IllegalStateException("Service already
> unregistered.");
> *        }
>     }
> 
> 
> 
> Thank you...
> 
> Regards,
> 
> Rajini

Re: Intermittent exception during Felix shutdown

Posted by Felix Meschberger <fm...@gmail.com>.

Hi Rajini,

Thanks. I would have expected the problem to not occurr for a dynamic
reference. I am now looking into it.

Regards
Felix

Am Donnerstag, den 23.08.2007, 15:14 +0100 schrieb Rajini Sivaram:
> Felix,
> 
> The reference in the component being reactivated is dynamic, but I have
> tried it now after changing it to a static reference, and the same exception
> continues to occur.
> 
> The initial set of deactivate for the components have the stack trace:
> 
>   Thread [FelixStartLevel] (Suspended (breakpoint at line 379 in
> AbstractComponentManager))
> 
> ImmediateComponentManager(AbstractComponentManager).deactivateInternal()
> line: 379
>      ImmediateComponentManager(AbstractComponentManager).disableInternal()
> line: 404
>      ImmediateComponentManager(AbstractComponentManager).disposeInternal()
> line: 434
>      ImmediateComponentManager(AbstractComponentManager).dispose() line:
> 224
>      BundleComponentActivator.dispose() line: 229
>      Activator.disposeComponents(Bundle) line: 230
>      Activator.bundleChanged(BundleEvent) line: 161
>      EventDispatcher.invokeBundleListenerCallback(Bundle, EventListener,
> EventObject) line: 660
>      EventDispatcher.fireEventImmediately(Logger, int, Object[],
> EventObject) line: 589
>      EventDispatcher.fireBundleEvent(BundleEvent) line: 503
>      Felix.fireBundleEvent(int, Bundle) line: 3499
>      Felix._stopBundle(FelixBundle, boolean) line: 1901
>      Felix.stopBundle(FelixBundle, boolean) line: 1866
>      Felix.setFrameworkStartLevel(int) line: 1080
>      StartLevelImpl.run() line: 258
>      Thread.run() line: 803
> 
> The other thread has the stack trace:
> 
>   Thread [SCR Component Actor] (Suspended (breakpoint at line 379 in
> AbstractComponentManager))
> 
> ImmediateComponentManager(AbstractComponentManager).deactivateInternal()
> line: 379
>      AbstractComponentManager.access$200(AbstractComponentManager) line: 41
>      AbstractComponentManager$3.run() line: 170
>      ComponentActorThread.run() line: 81
> 
> 
> On 8/23/07, Felix Meschberger <fm...@gmail.com> wrote:
> >
> > Hi Rajini,
> >
> > Am Donnerstag, den 23.08.2007, 14:26 +0100 schrieb Rajini Sivaram:
> > > I have tried the new SCR.jar, and that also results in the same
> > exception.
> >
> > >From your last message, this is about, what I expected....
> >
> > I suspect - from your observations - that a component which is
> > re-activated due to a service stop,
> > should actually not be activated again (stopping is fine, though). But
> > this is just a wild guess.
> >
> > Is the component you are trying to reactivate defined to have "static" (in
> > contrast to dynamic)
> > references to other services ?
> >
> > > How do I get the log/trace from SCR?
> >
> > SCR logs to the LogService if available or to stdout for normal messages
> > and stderr for error messages. By default only error messages are
> > written. To also get informational messages, you will have to set the
> > "ds.showtrace" property to "true". You may do this by specifying
> >
> >   ds.showtrace = true
> >
> > in the config.properties file when starting Felix.
> >
> > If you could provide me with the stacktrace containing the
> > "ImmediateComponentManager(AbstractComponentManager).deactivateInternal()"
> > method call, this would also be helpful.
> >
> > Thanks.
> >
> > Regards
> > Felix
> >
> > > Thank you...
> > >
> > > Regards,
> > >
> > > Rajini
> > >
> > >
> > > On 8/23/07, Felix Meschberger <fm...@gmail.com> wrote:
> > > >
> > > > Hi Rajini,
> > > >
> > > > One more thing: Having logging output from the SCR (going through the
> > > > LogService) would also be helpful.
> > > >
> > > > Regards
> > > > Felix
> > > >
> > > > Am Donnerstag, den 23.08.2007, 10:35 +0100 schrieb Rajini Sivaram:
> > > > > Felix,
> > > > >
> > > > > Would it be possible for you to send me a jar file containing the
> > fix? I
> > > > > dont have a source build at the moment, so it will be easier for me
> > if
> > > > you
> > > > > could send me the jar.
> > > > >
> > > > >
> > > > > My understanding (I may be totally wrong) was that that during Felix
> > > > > shutdown, all the bundles were being stopped causing all the
> > services
> > > > from
> > > > > the bundles to be unregistered. When one of the services got
> > > > unregistered, a
> > > > > component (ComponentA) which had a reference to this service is
> > > > reactivated
> > > > > (Stack trace 1). This causes the ComponentActorThread to call
> > > > > deactivateInternal for ComponentA (Stack trace 2) resulting in its
> > > > services
> > > > > being unregistered. Meanwhile the thread doing the shutdown
> > continues to
> > > > > stop all bundles including the bundle which contains ComponentA,
> > > > > unregistering services from ComponentA in a different thread (Stack
> > > > trace
> > > > > 3).
> > > > >
> > > > > Stack trace 1 and 3 are from the same thread and 1 preceeds 3. Stack
> > > > trace 2
> > > > > and 3 are on different threads and can occur simultaneously causing
> > an
> > > > > exception.
> > > > >
> > > > >
> > > > > *Stack trace 1:*
> > > > >   Thread [FelixStartLevel] (Suspended (breakpoint at line 711 in
> > > > > DependencyManager))
> > > > >         DependencyManager.removedService(ServiceReference) line: 711
> > > > >         DependencyManager.serviceChanged(ServiceEvent) line: 109
> > > > >         EventDispatcher.invokeServiceListenerCallback(Bundle,
> > > > EventListener,
> > > > > Filter, Object, EventObject) line: 735
> > > > >         EventDispatcher.fireEventImmediately(Logger, int, Object[],
> > > > > EventObject) line: 593
> > > > >         EventDispatcher.fireServiceEvent(ServiceEvent) line: 525
> > > > >         Felix.fireServiceEvent(ServiceEvent) line: 3510
> > > > >         Felix.access$000(Felix, ServiceEvent) line: 36
> > > > >         Felix$1.serviceChanged(ServiceEvent) line: 576
> > > > >         ServiceRegistry.fireServiceChanged(ServiceEvent) line: 435
> > > > >         ServiceRegistry.unregisterService(Bundle,
> > ServiceRegistration)
> > > > line:
> > > > > 86
> > > > >         ServiceRegistrationImpl.unregister() line: 99
> > > > >
> > > > >
> > > >
> > ImmediateComponentManager(AbstractComponentManager).unregisterComponentService()
> > > > > line: 503
> > > > >
> > > > >
> > ImmediateComponentManager(AbstractComponentManager).deactivateInternal()
> > > > > line: 369
> > > > >
> > > > >
> > ImmediateComponentManager(AbstractComponentManager).disableInternal()
> > > > line:
> > > > > 390
> > > > >
> > > > >
> > ImmediateComponentManager(AbstractComponentManager).disposeInternal()
> > > > line:
> > > > > 419
> > > > >
> > ImmediateComponentManager(AbstractComponentManager).dispose()
> > > > line:
> > > > > 224
> > > > >         BundleComponentActivator.dispose() line: 229
> > > > >         Activator.disposeComponents(Bundle) line: 230
> > > > >         Activator.bundleChanged(BundleEvent) line: 161
> > > > >         EventDispatcher.invokeBundleListenerCallback(Bundle,
> > > > EventListener,
> > > > > EventObject) line: 660
> > > > >         EventDispatcher.fireEventImmediately(Logger, int, Object[],
> > > > > EventObject) line: 589
> > > > >         EventDispatcher.fireBundleEvent(BundleEvent) line: 503
> > > > >         Felix.fireBundleEvent(int, Bundle) line: 3499
> > > > >         Felix._stopBundle(FelixBundle, boolean) line: 1901
> > > > >         Felix.stopBundle(FelixBundle, boolean) line: 1866
> > > > >         Felix.setFrameworkStartLevel(int) line: 1080
> > > > >         StartLevelImpl.run() line: 258
> > > > >         Thread.run() line: 803
> > > > >
> > > > > *Stack trace 2:*
> > > > >   Thread [SCR Component Actor] (Suspended (breakpoint at line 99 in
> > > > > ServiceRegistrationImpl))
> > > > >         ServiceRegistrationImpl.unregister() line: 99
> > > > >
> > > > >
> > > >
> > ImmediateComponentManager(AbstractComponentManager).unregisterComponentService()
> > > > > line: 503
> > > > >
> > > > >
> > ImmediateComponentManager(AbstractComponentManager).deactivateInternal()
> > > > > line: 369
> > > > >         AbstractComponentManager.access$200
> > (AbstractComponentManager)
> > > > line:
> > > > > 55
> > > > >         AbstractComponentManager$3.run() line: 176
> > > > >         ComponentActorThread.run() line: 81
> > > > >
> > > > > *Stack trace 3:*
> > > > >   Thread [FelixStartLevel] (Suspended (breakpoint at line 99 in
> > > > > ServiceRegistrationImpl))
> > > > >         ServiceRegistrationImpl.unregister() line: 99
> > > > >         ServiceRegistry.unregisterServices(Bundle) line: 119
> > > > >         Felix._stopBundle(FelixBundle, boolean) line: 1946
> > > > >         Felix.stopBundle(FelixBundle, boolean) line: 1866
> > > > >         Felix.setFrameworkStartLevel(int) line: 1080
> > > > >         StartLevelImpl.run() line: 258
> > > > >         Thread.run() line: 803
> > > > >
> > > > >
> > > > >
> > > > > Thank you...
> > > > >
> > > > > Regards,
> > > > >
> > > > > Rajini
> > > > >
> > > > >
> > > > > On 8/22/07, Felix Meschberger <fm...@gmail.com> wrote:
> > > > > >
> > > > > > Hi Rajini,
> > > > > >
> > > > > > I have to admit, that I am not 100% sure, what is going on. But
> > this
> > > > is
> > > > > > what I suppose:
> > > > > >
> > > > > > Some component has to be activated resulting thus (probably)
> > calling
> > > > the
> > > > > > ImmediateComponentManager.createObjectInstance method (most
> > probably
> > > > > > asynchronously). Most probably this fails and results in the
> > > > > > AbstractComponentManager.deactivate() method being called. This
> > method
> > > > > > (asynchronously again, but actually queued, so definitively later)
> > > > tries
> > > > > > to unregister a service which may or may not be registered...
> > > > > >
> > > > > > At the "same time" (whatever that means :-) ) the Bundle
> > containing
> > > > the
> > > > > > component is being stopped (probably due to framework shutdown,
> > > > doesn't
> > > > > > matter, actually)  and the framework has already unregistered the
> > > > > > service.
> > > > > >
> > > > > > The problem here is, that the createObjectInstance method should
> > not
> > > > > > call the deactivate method for asynchronous deactivation. In fact,
> > no
> > > > > > real deactivation is needed anyway, so I rewrote that part of the
> > > > > > implementation.
> > > > > >
> > > > > > I will test this code with my tests further. Could you also test
> > your
> > > > > > testcase again ? Thanks. I did not deploy a new snapshot yet, so
> > you
> > > > > > will have to build it yourself. If this is not possible for you,
> > > > please
> > > > > > let me know.
> > > > > >
> > > > > > Regards
> > > > > > Felix
> > > > > >
> > > > > > Am Montag, den 20.08.2007, 15:18 +0100 schrieb Rajini Sivaram:
> > > > > > > Hello,
> > > > > > >
> > > > > > > One of my testcases intermittently throws an exception during
> > > > shutdown.
> > > > > > I
> > > > > > > have managed to recreate the exception under a debugger, and it
> > > > shows
> > > > > > two
> > > > > > > threads trying to unregister the same service. The test fails
> > only
> > > > when
> > > > > > > declarative services are used. I am using Felix 1.0.0. The test
> > uses
> > > > > > > multiple versions of a bundle, but I am not sure if that has
> > > > anything to
> > > > > > do
> > > > > > > with the exception.
> > > > > > >
> > > > > > > The exception thrown is:
> > > > > > >
> > > > > > >     --- Exception with component : Unexpected problem executing
> > task
> > > > ---
> > > > > > >     java.lang.IllegalStateException: Service already
> > unregistered.
> > > > > > >         at
> > > > org.apache.felix.framework.ServiceRegistrationImpl.unregister
> > > > > > (
> > > > > > > ServiceRegistrationImpl.java:105)
> > > > > > >         at
> > > > > > >
> > > >
> > org.apache.felix.scr.AbstractComponentManager.unregisterComponentService
> > > > > > (
> > > > > > > AbstractComponentManager.java:503)
> > > > > > >         at
> > > > > > org.apache.felix.scr.AbstractComponentManager.deactivateInternal(
> > > > > > > AbstractComponentManager.java:369)
> > > > > > >         at
> > org.apache.felix.scr.AbstractComponentManager.access$200(
> > > > > > > AbstractComponentManager.java:55)
> > > > > > >         at org.apache.felix.scr.AbstractComponentManager$3.run(
> > > > > > > AbstractComponentManager.java:176)
> > > > > > >         at org.apache.felix.scr.ComponentActorThread.run(
> > > > > > > ComponentActorThread.java:81)
> > > > > > >
> > > > > > > Here is the stack trace of the two threads under the debugger
> > (both
> > > > are
> > > > > > > using the same object):
> > > > > > >
> > > > > > >                 Thread [FelixStartLevel] (Suspended (breakpoint
> > at
> > > > line
> > > > > > 97
> > > > > > > in ServiceRegistrationImpl))
> > > > > > >                         ServiceRegistrationImpl.unregister()
> > line:
> > > > 97
> > > > > > >                         ServiceRegistry.unregisterServices
> > (Bundle)
> > > > line:
> > > > > > 119
> > > > > > >                         Felix._stopBundle(FelixBundle, boolean)
> > > > line:
> > > > > > 1946
> > > > > > >                         Felix.stopBundle(FelixBundle, boolean)
> > line:
> > > > > > 1866
> > > > > > >                         Felix.setFrameworkStartLevel(int) line:
> > 1080
> > > > > > >                         StartLevelImpl.run() line: 258
> > > > > > >                         Thread.run() line: 803
> > > > > > >                 Thread [SCR Component Actor] (Suspended
> > (breakpoint
> > > > at
> > > > > > line
> > > > > > > 97 in ServiceRegistrationImpl))
> > > > > > >                         ServiceRegistrationImpl.unregister()
> > line:
> > > > 97
> > > > > > >
> > > > > > >
> > > > > >
> > > >
> > ImmediateComponentManager(AbstractComponentManager).unregisterComponentService()
> > > > > > > line: 503
> > > > > > >
> > > > > > >
> > > >
> > ImmediateComponentManager(AbstractComponentManager).deactivateInternal()
> > > > > > > line: 369
> > > > > > >
> > > > > > > AbstractComponentManager.access$200(AbstractComponentManager)
> > > > > > > line: 55
> > > > > > >                         AbstractComponentManager$3.run() line:
> > 176
> > > > > > >                         ComponentActorThread.run() line: 81
> > > > > > >
> > > > > > >
> > > > > > > The exception thrown is the IllegalStateException from
> > > > > > >     public void unregister()
> > > > > > >     {
> > > > > > >         if (m_svcObj != null)
> > > > > > >         {
> > > > > > >             m_registry.unregisterService(m_bundle, this);
> > > > > > >             m_svcObj = null;
> > > > > > >             m_factory = null;
> > > > > > >         }
> > > > > > >         else
> > > > > > >         {
> > > > > > >            * throw new IllegalStateException("Service already
> > > > > > > unregistered.");
> > > > > > > *        }
> > > > > > >     }
> > > > > > >
> > > > > > >
> > > > > > >
> > > > > > > Thank you...
> > > > > > >
> > > > > > > Regards,
> > > > > > >
> > > > > > > Rajini
> > > > > >
> > > > > >
> > > >
> > > >
> >
> >
> 
>

Re: Intermittent exception during Felix shutdown

Posted by Rajini Sivaram <ra...@googlemail.com>.

Felix,

The reference in the component being reactivated is dynamic, but I have
tried it now after changing it to a static reference, and the same exception
continues to occur.

The initial set of deactivate for the components have the stack trace:

  Thread [FelixStartLevel] (Suspended (breakpoint at line 379 in
AbstractComponentManager))

ImmediateComponentManager(AbstractComponentManager).deactivateInternal()
line: 379
     ImmediateComponentManager(AbstractComponentManager).disableInternal()
line: 404
     ImmediateComponentManager(AbstractComponentManager).disposeInternal()
line: 434
     ImmediateComponentManager(AbstractComponentManager).dispose() line:
224
     BundleComponentActivator.dispose() line: 229
     Activator.disposeComponents(Bundle) line: 230
     Activator.bundleChanged(BundleEvent) line: 161
     EventDispatcher.invokeBundleListenerCallback(Bundle, EventListener,
EventObject) line: 660
     EventDispatcher.fireEventImmediately(Logger, int, Object[],
EventObject) line: 589
     EventDispatcher.fireBundleEvent(BundleEvent) line: 503
     Felix.fireBundleEvent(int, Bundle) line: 3499
     Felix._stopBundle(FelixBundle, boolean) line: 1901
     Felix.stopBundle(FelixBundle, boolean) line: 1866
     Felix.setFrameworkStartLevel(int) line: 1080
     StartLevelImpl.run() line: 258
     Thread.run() line: 803

The other thread has the stack trace:

  Thread [SCR Component Actor] (Suspended (breakpoint at line 379 in
AbstractComponentManager))

ImmediateComponentManager(AbstractComponentManager).deactivateInternal()
line: 379
     AbstractComponentManager.access$200(AbstractComponentManager) line: 41
     AbstractComponentManager$3.run() line: 170
     ComponentActorThread.run() line: 81


On 8/23/07, Felix Meschberger <fm...@gmail.com> wrote:
>
> Hi Rajini,
>
> Am Donnerstag, den 23.08.2007, 14:26 +0100 schrieb Rajini Sivaram:
> > I have tried the new SCR.jar, and that also results in the same
> exception.
>
> >From your last message, this is about, what I expected....
>
> I suspect - from your observations - that a component which is
> re-activated due to a service stop,
> should actually not be activated again (stopping is fine, though). But
> this is just a wild guess.
>
> Is the component you are trying to reactivate defined to have "static" (in
> contrast to dynamic)
> references to other services ?
>
> > How do I get the log/trace from SCR?
>
> SCR logs to the LogService if available or to stdout for normal messages
> and stderr for error messages. By default only error messages are
> written. To also get informational messages, you will have to set the
> "ds.showtrace" property to "true". You may do this by specifying
>
>   ds.showtrace = true
>
> in the config.properties file when starting Felix.
>
> If you could provide me with the stacktrace containing the
> "ImmediateComponentManager(AbstractComponentManager).deactivateInternal()"
> method call, this would also be helpful.
>
> Thanks.
>
> Regards
> Felix
>
> > Thank you...
> >
> > Regards,
> >
> > Rajini
> >
> >
> > On 8/23/07, Felix Meschberger <fm...@gmail.com> wrote:
> > >
> > > Hi Rajini,
> > >
> > > One more thing: Having logging output from the SCR (going through the
> > > LogService) would also be helpful.
> > >
> > > Regards
> > > Felix
> > >
> > > Am Donnerstag, den 23.08.2007, 10:35 +0100 schrieb Rajini Sivaram:
> > > > Felix,
> > > >
> > > > Would it be possible for you to send me a jar file containing the
> fix? I
> > > > dont have a source build at the moment, so it will be easier for me
> if
> > > you
> > > > could send me the jar.
> > > >
> > > >
> > > > My understanding (I may be totally wrong) was that that during Felix
> > > > shutdown, all the bundles were being stopped causing all the
> services
> > > from
> > > > the bundles to be unregistered. When one of the services got
> > > unregistered, a
> > > > component (ComponentA) which had a reference to this service is
> > > reactivated
> > > > (Stack trace 1). This causes the ComponentActorThread to call
> > > > deactivateInternal for ComponentA (Stack trace 2) resulting in its
> > > services
> > > > being unregistered. Meanwhile the thread doing the shutdown
> continues to
> > > > stop all bundles including the bundle which contains ComponentA,
> > > > unregistering services from ComponentA in a different thread (Stack
> > > trace
> > > > 3).
> > > >
> > > > Stack trace 1 and 3 are from the same thread and 1 preceeds 3. Stack
> > > trace 2
> > > > and 3 are on different threads and can occur simultaneously causing
> an
> > > > exception.
> > > >
> > > >
> > > > *Stack trace 1:*
> > > >   Thread [FelixStartLevel] (Suspended (breakpoint at line 711 in
> > > > DependencyManager))
> > > >         DependencyManager.removedService(ServiceReference) line: 711
> > > >         DependencyManager.serviceChanged(ServiceEvent) line: 109
> > > >         EventDispatcher.invokeServiceListenerCallback(Bundle,
> > > EventListener,
> > > > Filter, Object, EventObject) line: 735
> > > >         EventDispatcher.fireEventImmediately(Logger, int, Object[],
> > > > EventObject) line: 593
> > > >         EventDispatcher.fireServiceEvent(ServiceEvent) line: 525
> > > >         Felix.fireServiceEvent(ServiceEvent) line: 3510
> > > >         Felix.access$000(Felix, ServiceEvent) line: 36
> > > >         Felix$1.serviceChanged(ServiceEvent) line: 576
> > > >         ServiceRegistry.fireServiceChanged(ServiceEvent) line: 435
> > > >         ServiceRegistry.unregisterService(Bundle,
> ServiceRegistration)
> > > line:
> > > > 86
> > > >         ServiceRegistrationImpl.unregister() line: 99
> > > >
> > > >
> > >
> ImmediateComponentManager(AbstractComponentManager).unregisterComponentService()
> > > > line: 503
> > > >
> > > >
> ImmediateComponentManager(AbstractComponentManager).deactivateInternal()
> > > > line: 369
> > > >
> > > >
> ImmediateComponentManager(AbstractComponentManager).disableInternal()
> > > line:
> > > > 390
> > > >
> > > >
> ImmediateComponentManager(AbstractComponentManager).disposeInternal()
> > > line:
> > > > 419
> > > >
> ImmediateComponentManager(AbstractComponentManager).dispose()
> > > line:
> > > > 224
> > > >         BundleComponentActivator.dispose() line: 229
> > > >         Activator.disposeComponents(Bundle) line: 230
> > > >         Activator.bundleChanged(BundleEvent) line: 161
> > > >         EventDispatcher.invokeBundleListenerCallback(Bundle,
> > > EventListener,
> > > > EventObject) line: 660
> > > >         EventDispatcher.fireEventImmediately(Logger, int, Object[],
> > > > EventObject) line: 589
> > > >         EventDispatcher.fireBundleEvent(BundleEvent) line: 503
> > > >         Felix.fireBundleEvent(int, Bundle) line: 3499
> > > >         Felix._stopBundle(FelixBundle, boolean) line: 1901
> > > >         Felix.stopBundle(FelixBundle, boolean) line: 1866
> > > >         Felix.setFrameworkStartLevel(int) line: 1080
> > > >         StartLevelImpl.run() line: 258
> > > >         Thread.run() line: 803
> > > >
> > > > *Stack trace 2:*
> > > >   Thread [SCR Component Actor] (Suspended (breakpoint at line 99 in
> > > > ServiceRegistrationImpl))
> > > >         ServiceRegistrationImpl.unregister() line: 99
> > > >
> > > >
> > >
> ImmediateComponentManager(AbstractComponentManager).unregisterComponentService()
> > > > line: 503
> > > >
> > > >
> ImmediateComponentManager(AbstractComponentManager).deactivateInternal()
> > > > line: 369
> > > >         AbstractComponentManager.access$200
> (AbstractComponentManager)
> > > line:
> > > > 55
> > > >         AbstractComponentManager$3.run() line: 176
> > > >         ComponentActorThread.run() line: 81
> > > >
> > > > *Stack trace 3:*
> > > >   Thread [FelixStartLevel] (Suspended (breakpoint at line 99 in
> > > > ServiceRegistrationImpl))
> > > >         ServiceRegistrationImpl.unregister() line: 99
> > > >         ServiceRegistry.unregisterServices(Bundle) line: 119
> > > >         Felix._stopBundle(FelixBundle, boolean) line: 1946
> > > >         Felix.stopBundle(FelixBundle, boolean) line: 1866
> > > >         Felix.setFrameworkStartLevel(int) line: 1080
> > > >         StartLevelImpl.run() line: 258
> > > >         Thread.run() line: 803
> > > >
> > > >
> > > >
> > > > Thank you...
> > > >
> > > > Regards,
> > > >
> > > > Rajini
> > > >
> > > >
> > > > On 8/22/07, Felix Meschberger <fm...@gmail.com> wrote:
> > > > >
> > > > > Hi Rajini,
> > > > >
> > > > > I have to admit, that I am not 100% sure, what is going on. But
> this
> > > is
> > > > > what I suppose:
> > > > >
> > > > > Some component has to be activated resulting thus (probably)
> calling
> > > the
> > > > > ImmediateComponentManager.createObjectInstance method (most
> probably
> > > > > asynchronously). Most probably this fails and results in the
> > > > > AbstractComponentManager.deactivate() method being called. This
> method
> > > > > (asynchronously again, but actually queued, so definitively later)
> > > tries
> > > > > to unregister a service which may or may not be registered...
> > > > >
> > > > > At the "same time" (whatever that means :-) ) the Bundle
> containing
> > > the
> > > > > component is being stopped (probably due to framework shutdown,
> > > doesn't
> > > > > matter, actually)  and the framework has already unregistered the
> > > > > service.
> > > > >
> > > > > The problem here is, that the createObjectInstance method should
> not
> > > > > call the deactivate method for asynchronous deactivation. In fact,
> no
> > > > > real deactivation is needed anyway, so I rewrote that part of the
> > > > > implementation.
> > > > >
> > > > > I will test this code with my tests further. Could you also test
> your
> > > > > testcase again ? Thanks. I did not deploy a new snapshot yet, so
> you
> > > > > will have to build it yourself. If this is not possible for you,
> > > please
> > > > > let me know.
> > > > >
> > > > > Regards
> > > > > Felix
> > > > >
> > > > > Am Montag, den 20.08.2007, 15:18 +0100 schrieb Rajini Sivaram:
> > > > > > Hello,
> > > > > >
> > > > > > One of my testcases intermittently throws an exception during
> > > shutdown.
> > > > > I
> > > > > > have managed to recreate the exception under a debugger, and it
> > > shows
> > > > > two
> > > > > > threads trying to unregister the same service. The test fails
> only
> > > when
> > > > > > declarative services are used. I am using Felix 1.0.0. The test
> uses
> > > > > > multiple versions of a bundle, but I am not sure if that has
> > > anything to
> > > > > do
> > > > > > with the exception.
> > > > > >
> > > > > > The exception thrown is:
> > > > > >
> > > > > >     --- Exception with component : Unexpected problem executing
> task
> > > ---
> > > > > >     java.lang.IllegalStateException: Service already
> unregistered.
> > > > > >         at
> > > org.apache.felix.framework.ServiceRegistrationImpl.unregister
> > > > > (
> > > > > > ServiceRegistrationImpl.java:105)
> > > > > >         at
> > > > > >
> > >
> org.apache.felix.scr.AbstractComponentManager.unregisterComponentService
> > > > > (
> > > > > > AbstractComponentManager.java:503)
> > > > > >         at
> > > > > org.apache.felix.scr.AbstractComponentManager.deactivateInternal(
> > > > > > AbstractComponentManager.java:369)
> > > > > >         at
> org.apache.felix.scr.AbstractComponentManager.access$200(
> > > > > > AbstractComponentManager.java:55)
> > > > > >         at org.apache.felix.scr.AbstractComponentManager$3.run(
> > > > > > AbstractComponentManager.java:176)
> > > > > >         at org.apache.felix.scr.ComponentActorThread.run(
> > > > > > ComponentActorThread.java:81)
> > > > > >
> > > > > > Here is the stack trace of the two threads under the debugger
> (both
> > > are
> > > > > > using the same object):
> > > > > >
> > > > > >                 Thread [FelixStartLevel] (Suspended (breakpoint
> at
> > > line
> > > > > 97
> > > > > > in ServiceRegistrationImpl))
> > > > > >                         ServiceRegistrationImpl.unregister()
> line:
> > > 97
> > > > > >                         ServiceRegistry.unregisterServices
> (Bundle)
> > > line:
> > > > > 119
> > > > > >                         Felix._stopBundle(FelixBundle, boolean)
> > > line:
> > > > > 1946
> > > > > >                         Felix.stopBundle(FelixBundle, boolean)
> line:
> > > > > 1866
> > > > > >                         Felix.setFrameworkStartLevel(int) line:
> 1080
> > > > > >                         StartLevelImpl.run() line: 258
> > > > > >                         Thread.run() line: 803
> > > > > >                 Thread [SCR Component Actor] (Suspended
> (breakpoint
> > > at
> > > > > line
> > > > > > 97 in ServiceRegistrationImpl))
> > > > > >                         ServiceRegistrationImpl.unregister()
> line:
> > > 97
> > > > > >
> > > > > >
> > > > >
> > >
> ImmediateComponentManager(AbstractComponentManager).unregisterComponentService()
> > > > > > line: 503
> > > > > >
> > > > > >
> > >
> ImmediateComponentManager(AbstractComponentManager).deactivateInternal()
> > > > > > line: 369
> > > > > >
> > > > > > AbstractComponentManager.access$200(AbstractComponentManager)
> > > > > > line: 55
> > > > > >                         AbstractComponentManager$3.run() line:
> 176
> > > > > >                         ComponentActorThread.run() line: 81
> > > > > >
> > > > > >
> > > > > > The exception thrown is the IllegalStateException from
> > > > > >     public void unregister()
> > > > > >     {
> > > > > >         if (m_svcObj != null)
> > > > > >         {
> > > > > >             m_registry.unregisterService(m_bundle, this);
> > > > > >             m_svcObj = null;
> > > > > >             m_factory = null;
> > > > > >         }
> > > > > >         else
> > > > > >         {
> > > > > >            * throw new IllegalStateException("Service already
> > > > > > unregistered.");
> > > > > > *        }
> > > > > >     }
> > > > > >
> > > > > >
> > > > > >
> > > > > > Thank you...
> > > > > >
> > > > > > Regards,
> > > > > >
> > > > > > Rajini
> > > > >
> > > > >
> > >
> > >
>
>


-- 
Thank you...

Regards,

Rajini

Re: Intermittent exception during Felix shutdown

Posted by Felix Meschberger <fm...@gmail.com>.

Hi Rajini,

Am Donnerstag, den 23.08.2007, 14:26 +0100 schrieb Rajini Sivaram:
> I have tried the new SCR.jar, and that also results in the same exception.

>>From your last message, this is about, what I expected....

I suspect - from your observations - that a component which is re-activated due to a service stop,
should actually not be activated again (stopping is fine, though). But this is just a wild guess.

Is the component you are trying to reactivate defined to have "static" (in contrast to dynamic)
references to other services ?

> How do I get the log/trace from SCR?

SCR logs to the LogService if available or to stdout for normal messages
and stderr for error messages. By default only error messages are
written. To also get informational messages, you will have to set the
"ds.showtrace" property to "true". You may do this by specifying

   ds.showtrace = true

in the config.properties file when starting Felix.

If you could provide me with the stacktrace containing the
"ImmediateComponentManager(AbstractComponentManager).deactivateInternal()" method call, this would also be helpful.

Thanks.

Regards
Felix

> Thank you...
> 
> Regards,
> 
> Rajini
> 
> 
> On 8/23/07, Felix Meschberger <fm...@gmail.com> wrote:
> >
> > Hi Rajini,
> >
> > One more thing: Having logging output from the SCR (going through the
> > LogService) would also be helpful.
> >
> > Regards
> > Felix
> >
> > Am Donnerstag, den 23.08.2007, 10:35 +0100 schrieb Rajini Sivaram:
> > > Felix,
> > >
> > > Would it be possible for you to send me a jar file containing the fix? I
> > > dont have a source build at the moment, so it will be easier for me if
> > you
> > > could send me the jar.
> > >
> > >
> > > My understanding (I may be totally wrong) was that that during Felix
> > > shutdown, all the bundles were being stopped causing all the services
> > from
> > > the bundles to be unregistered. When one of the services got
> > unregistered, a
> > > component (ComponentA) which had a reference to this service is
> > reactivated
> > > (Stack trace 1). This causes the ComponentActorThread to call
> > > deactivateInternal for ComponentA (Stack trace 2) resulting in its
> > services
> > > being unregistered. Meanwhile the thread doing the shutdown continues to
> > > stop all bundles including the bundle which contains ComponentA,
> > > unregistering services from ComponentA in a different thread (Stack
> > trace
> > > 3).
> > >
> > > Stack trace 1 and 3 are from the same thread and 1 preceeds 3. Stack
> > trace 2
> > > and 3 are on different threads and can occur simultaneously causing an
> > > exception.
> > >
> > >
> > > *Stack trace 1:*
> > >   Thread [FelixStartLevel] (Suspended (breakpoint at line 711 in
> > > DependencyManager))
> > >         DependencyManager.removedService(ServiceReference) line: 711
> > >         DependencyManager.serviceChanged(ServiceEvent) line: 109
> > >         EventDispatcher.invokeServiceListenerCallback(Bundle,
> > EventListener,
> > > Filter, Object, EventObject) line: 735
> > >         EventDispatcher.fireEventImmediately(Logger, int, Object[],
> > > EventObject) line: 593
> > >         EventDispatcher.fireServiceEvent(ServiceEvent) line: 525
> > >         Felix.fireServiceEvent(ServiceEvent) line: 3510
> > >         Felix.access$000(Felix, ServiceEvent) line: 36
> > >         Felix$1.serviceChanged(ServiceEvent) line: 576
> > >         ServiceRegistry.fireServiceChanged(ServiceEvent) line: 435
> > >         ServiceRegistry.unregisterService(Bundle, ServiceRegistration)
> > line:
> > > 86
> > >         ServiceRegistrationImpl.unregister() line: 99
> > >
> > >
> > ImmediateComponentManager(AbstractComponentManager).unregisterComponentService()
> > > line: 503
> > >
> > > ImmediateComponentManager(AbstractComponentManager).deactivateInternal()
> > > line: 369
> > >
> > > ImmediateComponentManager(AbstractComponentManager).disableInternal()
> > line:
> > > 390
> > >
> > > ImmediateComponentManager(AbstractComponentManager).disposeInternal()
> > line:
> > > 419
> > >         ImmediateComponentManager(AbstractComponentManager).dispose()
> > line:
> > > 224
> > >         BundleComponentActivator.dispose() line: 229
> > >         Activator.disposeComponents(Bundle) line: 230
> > >         Activator.bundleChanged(BundleEvent) line: 161
> > >         EventDispatcher.invokeBundleListenerCallback(Bundle,
> > EventListener,
> > > EventObject) line: 660
> > >         EventDispatcher.fireEventImmediately(Logger, int, Object[],
> > > EventObject) line: 589
> > >         EventDispatcher.fireBundleEvent(BundleEvent) line: 503
> > >         Felix.fireBundleEvent(int, Bundle) line: 3499
> > >         Felix._stopBundle(FelixBundle, boolean) line: 1901
> > >         Felix.stopBundle(FelixBundle, boolean) line: 1866
> > >         Felix.setFrameworkStartLevel(int) line: 1080
> > >         StartLevelImpl.run() line: 258
> > >         Thread.run() line: 803
> > >
> > > *Stack trace 2:*
> > >   Thread [SCR Component Actor] (Suspended (breakpoint at line 99 in
> > > ServiceRegistrationImpl))
> > >         ServiceRegistrationImpl.unregister() line: 99
> > >
> > >
> > ImmediateComponentManager(AbstractComponentManager).unregisterComponentService()
> > > line: 503
> > >
> > > ImmediateComponentManager(AbstractComponentManager).deactivateInternal()
> > > line: 369
> > >         AbstractComponentManager.access$200(AbstractComponentManager)
> > line:
> > > 55
> > >         AbstractComponentManager$3.run() line: 176
> > >         ComponentActorThread.run() line: 81
> > >
> > > *Stack trace 3:*
> > >   Thread [FelixStartLevel] (Suspended (breakpoint at line 99 in
> > > ServiceRegistrationImpl))
> > >         ServiceRegistrationImpl.unregister() line: 99
> > >         ServiceRegistry.unregisterServices(Bundle) line: 119
> > >         Felix._stopBundle(FelixBundle, boolean) line: 1946
> > >         Felix.stopBundle(FelixBundle, boolean) line: 1866
> > >         Felix.setFrameworkStartLevel(int) line: 1080
> > >         StartLevelImpl.run() line: 258
> > >         Thread.run() line: 803
> > >
> > >
> > >
> > > Thank you...
> > >
> > > Regards,
> > >
> > > Rajini
> > >
> > >
> > > On 8/22/07, Felix Meschberger <fm...@gmail.com> wrote:
> > > >
> > > > Hi Rajini,
> > > >
> > > > I have to admit, that I am not 100% sure, what is going on. But this
> > is
> > > > what I suppose:
> > > >
> > > > Some component has to be activated resulting thus (probably) calling
> > the
> > > > ImmediateComponentManager.createObjectInstance method (most probably
> > > > asynchronously). Most probably this fails and results in the
> > > > AbstractComponentManager.deactivate() method being called. This method
> > > > (asynchronously again, but actually queued, so definitively later)
> > tries
> > > > to unregister a service which may or may not be registered...
> > > >
> > > > At the "same time" (whatever that means :-) ) the Bundle containing
> > the
> > > > component is being stopped (probably due to framework shutdown,
> > doesn't
> > > > matter, actually)  and the framework has already unregistered the
> > > > service.
> > > >
> > > > The problem here is, that the createObjectInstance method should not
> > > > call the deactivate method for asynchronous deactivation. In fact, no
> > > > real deactivation is needed anyway, so I rewrote that part of the
> > > > implementation.
> > > >
> > > > I will test this code with my tests further. Could you also test your
> > > > testcase again ? Thanks. I did not deploy a new snapshot yet, so you
> > > > will have to build it yourself. If this is not possible for you,
> > please
> > > > let me know.
> > > >
> > > > Regards
> > > > Felix
> > > >
> > > > Am Montag, den 20.08.2007, 15:18 +0100 schrieb Rajini Sivaram:
> > > > > Hello,
> > > > >
> > > > > One of my testcases intermittently throws an exception during
> > shutdown.
> > > > I
> > > > > have managed to recreate the exception under a debugger, and it
> > shows
> > > > two
> > > > > threads trying to unregister the same service. The test fails only
> > when
> > > > > declarative services are used. I am using Felix 1.0.0. The test uses
> > > > > multiple versions of a bundle, but I am not sure if that has
> > anything to
> > > > do
> > > > > with the exception.
> > > > >
> > > > > The exception thrown is:
> > > > >
> > > > >     --- Exception with component : Unexpected problem executing task
> > ---
> > > > >     java.lang.IllegalStateException: Service already unregistered.
> > > > >         at
> > org.apache.felix.framework.ServiceRegistrationImpl.unregister
> > > > (
> > > > > ServiceRegistrationImpl.java:105)
> > > > >         at
> > > > >
> > org.apache.felix.scr.AbstractComponentManager.unregisterComponentService
> > > > (
> > > > > AbstractComponentManager.java:503)
> > > > >         at
> > > > org.apache.felix.scr.AbstractComponentManager.deactivateInternal(
> > > > > AbstractComponentManager.java:369)
> > > > >         at org.apache.felix.scr.AbstractComponentManager.access$200(
> > > > > AbstractComponentManager.java:55)
> > > > >         at org.apache.felix.scr.AbstractComponentManager$3.run(
> > > > > AbstractComponentManager.java:176)
> > > > >         at org.apache.felix.scr.ComponentActorThread.run(
> > > > > ComponentActorThread.java:81)
> > > > >
> > > > > Here is the stack trace of the two threads under the debugger (both
> > are
> > > > > using the same object):
> > > > >
> > > > >                 Thread [FelixStartLevel] (Suspended (breakpoint at
> > line
> > > > 97
> > > > > in ServiceRegistrationImpl))
> > > > >                         ServiceRegistrationImpl.unregister() line:
> > 97
> > > > >                         ServiceRegistry.unregisterServices(Bundle)
> > line:
> > > > 119
> > > > >                         Felix._stopBundle(FelixBundle, boolean)
> > line:
> > > > 1946
> > > > >                         Felix.stopBundle(FelixBundle, boolean) line:
> > > > 1866
> > > > >                         Felix.setFrameworkStartLevel(int) line: 1080
> > > > >                         StartLevelImpl.run() line: 258
> > > > >                         Thread.run() line: 803
> > > > >                 Thread [SCR Component Actor] (Suspended (breakpoint
> > at
> > > > line
> > > > > 97 in ServiceRegistrationImpl))
> > > > >                         ServiceRegistrationImpl.unregister() line:
> > 97
> > > > >
> > > > >
> > > >
> > ImmediateComponentManager(AbstractComponentManager).unregisterComponentService()
> > > > > line: 503
> > > > >
> > > > >
> > ImmediateComponentManager(AbstractComponentManager).deactivateInternal()
> > > > > line: 369
> > > > >
> > > > > AbstractComponentManager.access$200(AbstractComponentManager)
> > > > > line: 55
> > > > >                         AbstractComponentManager$3.run() line: 176
> > > > >                         ComponentActorThread.run() line: 81
> > > > >
> > > > >
> > > > > The exception thrown is the IllegalStateException from
> > > > >     public void unregister()
> > > > >     {
> > > > >         if (m_svcObj != null)
> > > > >         {
> > > > >             m_registry.unregisterService(m_bundle, this);
> > > > >             m_svcObj = null;
> > > > >             m_factory = null;
> > > > >         }
> > > > >         else
> > > > >         {
> > > > >            * throw new IllegalStateException("Service already
> > > > > unregistered.");
> > > > > *        }
> > > > >     }
> > > > >
> > > > >
> > > > >
> > > > > Thank you...
> > > > >
> > > > > Regards,
> > > > >
> > > > > Rajini
> > > >
> > > >
> >
> >

Re: Intermittent exception during Felix shutdown

Posted by Rajini Sivaram <ra...@googlemail.com>.

Felix,

I added a loglistener, and set ds.showtrace=true. With that, the trace after
the test completed (the shutdown) is given below. The deactivated messages
are from the deactivate method in the component, and there are two versions
of each component.

=============================================================

Test complete
Deactivated OSGiShipperComponentImpl bundle
Deactivated OSGiShipperComponentImpl bundle
Deactivated OSGiRetailerComponentImpl bundle
Deactivated OSGiRetailerComponentImpl bundle
Deactivated OSGiCustomerComponentImpl bundle
--- [CustomerComponent2] Dependency Manager: RECREATING
--- [CustomerComponent2] Dependency Manager: RECREATING
--- [CustomerComponent1] State transition : Active -> Deactivating
--- [CustomerComponent1] Deactivating component
--- [CustomerComponent1] Dependency Manager: RECREATING
--- Exception with component : Unexpected problem executing task ---
java.lang.IllegalStateException: Service already unregistered.
        at org.apache.felix.framework.ServiceRegistrationImpl.unregister(
ServiceRegistrationImpl.java:105)
        at
org.apache.felix.scr.AbstractComponentManager.unregisterComponentService(
AbstractComponentManager.java:528)
        at org.apache.felix.scr.AbstractComponentManager.deactivateInternal(
AbstractComponentManager.java:382)
        at org.apache.felix.scr.AbstractComponentManager.access$200(
AbstractComponentManager.java:41)
        at org.apache.felix.scr.AbstractComponentManager$3.run(
AbstractComponentManager.java:170)
        at org.apache.felix.scr.ComponentActorThread.run(
ComponentActorThread.java:81)

=============================================================

Thank you...

Regards,

Rajini

On 8/23/07, Rajini Sivaram <ra...@googlemail.com> wrote:
>
> Felix,
>
> I have tried the new SCR.jar, and that also results in the same exception.
> How do I get the log/trace from SCR?
>
> Thank you...
>
> Regards,
>
> Rajini
>
>
> On 8/23/07, Felix Meschberger <fm...@gmail.com> wrote:
> >
> > Hi Rajini,
> >
> > One more thing: Having logging output from the SCR (going through the
> > LogService) would also be helpful.
> >
> > Regards
> > Felix
> >
> > Am Donnerstag, den 23.08.2007, 10:35 +0100 schrieb Rajini Sivaram:
> > > Felix,
> > >
> > > Would it be possible for you to send me a jar file containing the fix?
> > I
> > > dont have a source build at the moment, so it will be easier for me if
> > you
> > > could send me the jar.
> > >
> > >
> > > My understanding (I may be totally wrong) was that that during Felix
> > > shutdown, all the bundles were being stopped causing all the services
> > from
> > > the bundles to be unregistered. When one of the services got
> > unregistered, a
> > > component (ComponentA) which had a reference to this service is
> > reactivated
> > > (Stack trace 1). This causes the ComponentActorThread to call
> > > deactivateInternal for ComponentA (Stack trace 2) resulting in its
> > services
> > > being unregistered. Meanwhile the thread doing the shutdown continues
> > to
> > > stop all bundles including the bundle which contains ComponentA,
> > > unregistering services from ComponentA in a different thread (Stack
> > trace
> > > 3).
> > >
> > > Stack trace 1 and 3 are from the same thread and 1 preceeds 3. Stack
> > trace 2
> > > and 3 are on different threads and can occur simultaneously causing an
> > > exception.
> > >
> > >
> > > *Stack trace 1:*
> > >   Thread [FelixStartLevel] (Suspended (breakpoint at line 711 in
> > > DependencyManager))
> > >         DependencyManager.removedService(ServiceReference) line: 711
> > >         DependencyManager.serviceChanged (ServiceEvent) line: 109
> > >         EventDispatcher.invokeServiceListenerCallback(Bundle,
> > EventListener,
> > > Filter, Object, EventObject) line: 735
> > >         EventDispatcher.fireEventImmediately(Logger, int, Object[],
> > > EventObject) line: 593
> > >         EventDispatcher.fireServiceEvent(ServiceEvent) line: 525
> > >         Felix.fireServiceEvent(ServiceEvent) line: 3510
> > >         Felix.access$000(Felix, ServiceEvent) line: 36
> > >         Felix$1.serviceChanged(ServiceEvent) line: 576
> > >         ServiceRegistry.fireServiceChanged(ServiceEvent) line: 435
> > >         ServiceRegistry.unregisterService(Bundle, ServiceRegistration)
> > line:
> > > 86
> > >         ServiceRegistrationImpl.unregister() line: 99
> > >
> > >
> > ImmediateComponentManager(AbstractComponentManager).unregisterComponentService()
> > > line: 503
> > >
> > >
> > ImmediateComponentManager(AbstractComponentManager).deactivateInternal()
> > > line: 369
> > >
> > > ImmediateComponentManager(AbstractComponentManager).disableInternal()
> > line:
> > > 390
> > >
> > > ImmediateComponentManager(AbstractComponentManager).disposeInternal()
> > line:
> > > 419
> > >         ImmediateComponentManager(AbstractComponentManager).dispose()
> > line:
> > > 224
> > >         BundleComponentActivator.dispose() line: 229
> > >         Activator.disposeComponents(Bundle) line: 230
> > >         Activator.bundleChanged(BundleEvent) line: 161
> > >         EventDispatcher.invokeBundleListenerCallback(Bundle,
> > EventListener,
> > > EventObject) line: 660
> > >         EventDispatcher.fireEventImmediately (Logger, int, Object[],
> > > EventObject) line: 589
> > >         EventDispatcher.fireBundleEvent(BundleEvent) line: 503
> > >         Felix.fireBundleEvent(int, Bundle) line: 3499
> > >         Felix._stopBundle(FelixBundle, boolean) line: 1901
> > >         Felix.stopBundle(FelixBundle, boolean) line: 1866
> > >         Felix.setFrameworkStartLevel(int) line: 1080
> > >         StartLevelImpl.run() line: 258
> > >         Thread.run() line: 803
> > >
> > > *Stack trace 2:*
> > >   Thread [SCR Component Actor] (Suspended (breakpoint at line 99 in
> > > ServiceRegistrationImpl))
> > >         ServiceRegistrationImpl.unregister() line: 99
> > >
> > >
> > ImmediateComponentManager(AbstractComponentManager).unregisterComponentService()
> >
> > > line: 503
> > >
> > >
> > ImmediateComponentManager(AbstractComponentManager).deactivateInternal()
> > > line: 369
> > >         AbstractComponentManager.access$200(AbstractComponentManager)
> > line:
> > > 55
> > >         AbstractComponentManager$3.run() line: 176
> > >         ComponentActorThread.run() line: 81
> > >
> > > *Stack trace 3:*
> > >   Thread [FelixStartLevel] (Suspended (breakpoint at line 99 in
> > > ServiceRegistrationImpl))
> > >         ServiceRegistrationImpl.unregister() line: 99
> > >         ServiceRegistry.unregisterServices(Bundle) line: 119
> > >         Felix._stopBundle(FelixBundle, boolean) line: 1946
> > >         Felix.stopBundle (FelixBundle, boolean) line: 1866
> > >         Felix.setFrameworkStartLevel(int) line: 1080
> > >         StartLevelImpl.run() line: 258
> > >         Thread.run() line: 803
> > >
> > >
> > >
> > > Thank you...
> > >
> > > Regards,
> > >
> > > Rajini
> > >
> > >
> > > On 8/22/07, Felix Meschberger <fm...@gmail.com> wrote:
> > > >
> > > > Hi Rajini,
> > > >
> > > > I have to admit, that I am not 100% sure, what is going on. But this
> > is
> > > > what I suppose:
> > > >
> > > > Some component has to be activated resulting thus (probably) calling
> > the
> > > > ImmediateComponentManager.createObjectInstance method (most probably
> > > > asynchronously). Most probably this fails and results in the
> > > > AbstractComponentManager.deactivate() method being called. This
> > method
> > > > (asynchronously again, but actually queued, so definitively later)
> > tries
> > > > to unregister a service which may or may not be registered...
> > > >
> > > > At the "same time" (whatever that means :-) ) the Bundle containing
> > the
> > > > component is being stopped (probably due to framework shutdown,
> > doesn't
> > > > matter, actually)  and the framework has already unregistered the
> > > > service.
> > > >
> > > > The problem here is, that the createObjectInstance method should not
> >
> > > > call the deactivate method for asynchronous deactivation. In fact,
> > no
> > > > real deactivation is needed anyway, so I rewrote that part of the
> > > > implementation.
> > > >
> > > > I will test this code with my tests further. Could you also test
> > your
> > > > testcase again ? Thanks. I did not deploy a new snapshot yet, so you
> > > > will have to build it yourself. If this is not possible for you,
> > please
> > > > let me know.
> > > >
> > > > Regards
> > > > Felix
> > > >
> > > > Am Montag, den 20.08.2007, 15:18 +0100 schrieb Rajini Sivaram:
> > > > > Hello,
> > > > >
> > > > > One of my testcases intermittently throws an exception during
> > shutdown.
> > > > I
> > > > > have managed to recreate the exception under a debugger, and it
> > shows
> > > > two
> > > > > threads trying to unregister the same service. The test fails only
> > when
> > > > > declarative services are used. I am using Felix 1.0.0. The test
> > uses
> > > > > multiple versions of a bundle, but I am not sure if that has
> > anything to
> > > > do
> > > > > with the exception.
> > > > >
> > > > > The exception thrown is:
> > > > >
> > > > >     --- Exception with component : Unexpected problem executing
> > task ---
> > > > >     java.lang.IllegalStateException: Service already unregistered.
> > > > >         at
> > org.apache.felix.framework.ServiceRegistrationImpl.unregister
> > > > (
> > > > > ServiceRegistrationImpl.java:105)
> > > > >         at
> > > > >
> > org.apache.felix.scr.AbstractComponentManager.unregisterComponentService
> > > > (
> > > > > AbstractComponentManager.java:503)
> > > > >         at
> > > > org.apache.felix.scr.AbstractComponentManager.deactivateInternal(
> > > > > AbstractComponentManager.java :369)
> > > > >         at
> > org.apache.felix.scr.AbstractComponentManager.access$200(
> > > > > AbstractComponentManager.java:55)
> > > > >         at org.apache.felix.scr.AbstractComponentManager$3.run (
> > > > > AbstractComponentManager.java:176)
> > > > >         at org.apache.felix.scr.ComponentActorThread.run(
> > > > > ComponentActorThread.java:81)
> > > > >
> > > > > Here is the stack trace of the two threads under the debugger
> > (both are
> > > > > using the same object):
> > > > >
> > > > >                 Thread [FelixStartLevel] (Suspended (breakpoint at
> > line
> > > > 97
> > > > > in ServiceRegistrationImpl))
> > > > >                         ServiceRegistrationImpl.unregister() line:
> > 97
> > > > >                         ServiceRegistry.unregisterServices(Bundle)
> > line:
> > > > 119
> > > > >                         Felix._stopBundle(FelixBundle, boolean)
> > line:
> > > > 1946
> > > > >                         Felix.stopBundle(FelixBundle, boolean)
> > line:
> > > > 1866
> > > > >                         Felix.setFrameworkStartLevel(int) line:
> > 1080
> > > > >                         StartLevelImpl.run() line: 258
> > > > >                         Thread.run() line: 803
> > > > >                 Thread [SCR Component Actor] (Suspended
> > (breakpoint at
> > > > line
> > > > > 97 in ServiceRegistrationImpl))
> > > > >                         ServiceRegistrationImpl.unregister() line:
> > 97
> > > > >
> > > > >
> > > >
> > ImmediateComponentManager(AbstractComponentManager).unregisterComponentService()
> > > > > line: 503
> > > > >
> > > > >
> > ImmediateComponentManager(AbstractComponentManager).deactivateInternal()
> > > > > line: 369
> > > > >
> > > > > AbstractComponentManager.access$200 (AbstractComponentManager)
> > > > > line: 55
> > > > >                         AbstractComponentManager$3.run() line: 176
> > > > >                         ComponentActorThread.run() line: 81
> > > > >
> > > > >
> > > > > The exception thrown is the IllegalStateException from
> > > > >     public void unregister()
> > > > >     {
> > > > >         if (m_svcObj != null)
> > > > >         {
> > > > >             m_registry.unregisterService(m_bundle, this);
> > > > >             m_svcObj = null;
> > > > >             m_factory = null;
> > > > >         }
> > > > >         else
> > > > >         {
> > > > >            * throw new IllegalStateException("Service already
> > > > > unregistered.");
> > > > > *        }
> > > > >     }
> > > > >
> > > > >
> > > > >
> > > > > Thank you...
> > > > >
> > > > > Regards,
> > > > >
> > > > > Rajini
> > > >
> > > >
> >
> >
>

Re: Intermittent exception during Felix shutdown

Posted by Rajini Sivaram <ra...@googlemail.com>.

Felix,

I have tried the new SCR.jar, and that also results in the same exception.
How do I get the log/trace from SCR?

Thank you...

Regards,

Rajini


On 8/23/07, Felix Meschberger <fm...@gmail.com> wrote:
>
> Hi Rajini,
>
> One more thing: Having logging output from the SCR (going through the
> LogService) would also be helpful.
>
> Regards
> Felix
>
> Am Donnerstag, den 23.08.2007, 10:35 +0100 schrieb Rajini Sivaram:
> > Felix,
> >
> > Would it be possible for you to send me a jar file containing the fix? I
> > dont have a source build at the moment, so it will be easier for me if
> you
> > could send me the jar.
> >
> >
> > My understanding (I may be totally wrong) was that that during Felix
> > shutdown, all the bundles were being stopped causing all the services
> from
> > the bundles to be unregistered. When one of the services got
> unregistered, a
> > component (ComponentA) which had a reference to this service is
> reactivated
> > (Stack trace 1). This causes the ComponentActorThread to call
> > deactivateInternal for ComponentA (Stack trace 2) resulting in its
> services
> > being unregistered. Meanwhile the thread doing the shutdown continues to
> > stop all bundles including the bundle which contains ComponentA,
> > unregistering services from ComponentA in a different thread (Stack
> trace
> > 3).
> >
> > Stack trace 1 and 3 are from the same thread and 1 preceeds 3. Stack
> trace 2
> > and 3 are on different threads and can occur simultaneously causing an
> > exception.
> >
> >
> > *Stack trace 1:*
> >   Thread [FelixStartLevel] (Suspended (breakpoint at line 711 in
> > DependencyManager))
> >         DependencyManager.removedService(ServiceReference) line: 711
> >         DependencyManager.serviceChanged(ServiceEvent) line: 109
> >         EventDispatcher.invokeServiceListenerCallback(Bundle,
> EventListener,
> > Filter, Object, EventObject) line: 735
> >         EventDispatcher.fireEventImmediately(Logger, int, Object[],
> > EventObject) line: 593
> >         EventDispatcher.fireServiceEvent(ServiceEvent) line: 525
> >         Felix.fireServiceEvent(ServiceEvent) line: 3510
> >         Felix.access$000(Felix, ServiceEvent) line: 36
> >         Felix$1.serviceChanged(ServiceEvent) line: 576
> >         ServiceRegistry.fireServiceChanged(ServiceEvent) line: 435
> >         ServiceRegistry.unregisterService(Bundle, ServiceRegistration)
> line:
> > 86
> >         ServiceRegistrationImpl.unregister() line: 99
> >
> >
> ImmediateComponentManager(AbstractComponentManager).unregisterComponentService()
> > line: 503
> >
> > ImmediateComponentManager(AbstractComponentManager).deactivateInternal()
> > line: 369
> >
> > ImmediateComponentManager(AbstractComponentManager).disableInternal()
> line:
> > 390
> >
> > ImmediateComponentManager(AbstractComponentManager).disposeInternal()
> line:
> > 419
> >         ImmediateComponentManager(AbstractComponentManager).dispose()
> line:
> > 224
> >         BundleComponentActivator.dispose() line: 229
> >         Activator.disposeComponents(Bundle) line: 230
> >         Activator.bundleChanged(BundleEvent) line: 161
> >         EventDispatcher.invokeBundleListenerCallback(Bundle,
> EventListener,
> > EventObject) line: 660
> >         EventDispatcher.fireEventImmediately(Logger, int, Object[],
> > EventObject) line: 589
> >         EventDispatcher.fireBundleEvent(BundleEvent) line: 503
> >         Felix.fireBundleEvent(int, Bundle) line: 3499
> >         Felix._stopBundle(FelixBundle, boolean) line: 1901
> >         Felix.stopBundle(FelixBundle, boolean) line: 1866
> >         Felix.setFrameworkStartLevel(int) line: 1080
> >         StartLevelImpl.run() line: 258
> >         Thread.run() line: 803
> >
> > *Stack trace 2:*
> >   Thread [SCR Component Actor] (Suspended (breakpoint at line 99 in
> > ServiceRegistrationImpl))
> >         ServiceRegistrationImpl.unregister() line: 99
> >
> >
> ImmediateComponentManager(AbstractComponentManager).unregisterComponentService()
> > line: 503
> >
> > ImmediateComponentManager(AbstractComponentManager).deactivateInternal()
> > line: 369
> >         AbstractComponentManager.access$200(AbstractComponentManager)
> line:
> > 55
> >         AbstractComponentManager$3.run() line: 176
> >         ComponentActorThread.run() line: 81
> >
> > *Stack trace 3:*
> >   Thread [FelixStartLevel] (Suspended (breakpoint at line 99 in
> > ServiceRegistrationImpl))
> >         ServiceRegistrationImpl.unregister() line: 99
> >         ServiceRegistry.unregisterServices(Bundle) line: 119
> >         Felix._stopBundle(FelixBundle, boolean) line: 1946
> >         Felix.stopBundle(FelixBundle, boolean) line: 1866
> >         Felix.setFrameworkStartLevel(int) line: 1080
> >         StartLevelImpl.run() line: 258
> >         Thread.run() line: 803
> >
> >
> >
> > Thank you...
> >
> > Regards,
> >
> > Rajini
> >
> >
> > On 8/22/07, Felix Meschberger <fm...@gmail.com> wrote:
> > >
> > > Hi Rajini,
> > >
> > > I have to admit, that I am not 100% sure, what is going on. But this
> is
> > > what I suppose:
> > >
> > > Some component has to be activated resulting thus (probably) calling
> the
> > > ImmediateComponentManager.createObjectInstance method (most probably
> > > asynchronously). Most probably this fails and results in the
> > > AbstractComponentManager.deactivate() method being called. This method
> > > (asynchronously again, but actually queued, so definitively later)
> tries
> > > to unregister a service which may or may not be registered...
> > >
> > > At the "same time" (whatever that means :-) ) the Bundle containing
> the
> > > component is being stopped (probably due to framework shutdown,
> doesn't
> > > matter, actually)  and the framework has already unregistered the
> > > service.
> > >
> > > The problem here is, that the createObjectInstance method should not
> > > call the deactivate method for asynchronous deactivation. In fact, no
> > > real deactivation is needed anyway, so I rewrote that part of the
> > > implementation.
> > >
> > > I will test this code with my tests further. Could you also test your
> > > testcase again ? Thanks. I did not deploy a new snapshot yet, so you
> > > will have to build it yourself. If this is not possible for you,
> please
> > > let me know.
> > >
> > > Regards
> > > Felix
> > >
> > > Am Montag, den 20.08.2007, 15:18 +0100 schrieb Rajini Sivaram:
> > > > Hello,
> > > >
> > > > One of my testcases intermittently throws an exception during
> shutdown.
> > > I
> > > > have managed to recreate the exception under a debugger, and it
> shows
> > > two
> > > > threads trying to unregister the same service. The test fails only
> when
> > > > declarative services are used. I am using Felix 1.0.0. The test uses
> > > > multiple versions of a bundle, but I am not sure if that has
> anything to
> > > do
> > > > with the exception.
> > > >
> > > > The exception thrown is:
> > > >
> > > >     --- Exception with component : Unexpected problem executing task
> ---
> > > >     java.lang.IllegalStateException: Service already unregistered.
> > > >         at
> org.apache.felix.framework.ServiceRegistrationImpl.unregister
> > > (
> > > > ServiceRegistrationImpl.java:105)
> > > >         at
> > > >
> org.apache.felix.scr.AbstractComponentManager.unregisterComponentService
> > > (
> > > > AbstractComponentManager.java:503)
> > > >         at
> > > org.apache.felix.scr.AbstractComponentManager.deactivateInternal(
> > > > AbstractComponentManager.java:369)
> > > >         at org.apache.felix.scr.AbstractComponentManager.access$200(
> > > > AbstractComponentManager.java:55)
> > > >         at org.apache.felix.scr.AbstractComponentManager$3.run(
> > > > AbstractComponentManager.java:176)
> > > >         at org.apache.felix.scr.ComponentActorThread.run(
> > > > ComponentActorThread.java:81)
> > > >
> > > > Here is the stack trace of the two threads under the debugger (both
> are
> > > > using the same object):
> > > >
> > > >                 Thread [FelixStartLevel] (Suspended (breakpoint at
> line
> > > 97
> > > > in ServiceRegistrationImpl))
> > > >                         ServiceRegistrationImpl.unregister() line:
> 97
> > > >                         ServiceRegistry.unregisterServices(Bundle)
> line:
> > > 119
> > > >                         Felix._stopBundle(FelixBundle, boolean)
> line:
> > > 1946
> > > >                         Felix.stopBundle(FelixBundle, boolean) line:
> > > 1866
> > > >                         Felix.setFrameworkStartLevel(int) line: 1080
> > > >                         StartLevelImpl.run() line: 258
> > > >                         Thread.run() line: 803
> > > >                 Thread [SCR Component Actor] (Suspended (breakpoint
> at
> > > line
> > > > 97 in ServiceRegistrationImpl))
> > > >                         ServiceRegistrationImpl.unregister() line:
> 97
> > > >
> > > >
> > >
> ImmediateComponentManager(AbstractComponentManager).unregisterComponentService()
> > > > line: 503
> > > >
> > > >
> ImmediateComponentManager(AbstractComponentManager).deactivateInternal()
> > > > line: 369
> > > >
> > > > AbstractComponentManager.access$200(AbstractComponentManager)
> > > > line: 55
> > > >                         AbstractComponentManager$3.run() line: 176
> > > >                         ComponentActorThread.run() line: 81
> > > >
> > > >
> > > > The exception thrown is the IllegalStateException from
> > > >     public void unregister()
> > > >     {
> > > >         if (m_svcObj != null)
> > > >         {
> > > >             m_registry.unregisterService(m_bundle, this);
> > > >             m_svcObj = null;
> > > >             m_factory = null;
> > > >         }
> > > >         else
> > > >         {
> > > >            * throw new IllegalStateException("Service already
> > > > unregistered.");
> > > > *        }
> > > >     }
> > > >
> > > >
> > > >
> > > > Thank you...
> > > >
> > > > Regards,
> > > >
> > > > Rajini
> > >
> > >
>
>

Re: Intermittent exception during Felix shutdown

Posted by Felix Meschberger <fm...@gmail.com>.

Hi Rajini,

One more thing: Having logging output from the SCR (going through the
LogService) would also be helpful.

Regards
Felix

Am Donnerstag, den 23.08.2007, 10:35 +0100 schrieb Rajini Sivaram:
> Felix,
> 
> Would it be possible for you to send me a jar file containing the fix? I
> dont have a source build at the moment, so it will be easier for me if you
> could send me the jar.
> 
> 
> My understanding (I may be totally wrong) was that that during Felix
> shutdown, all the bundles were being stopped causing all the services from
> the bundles to be unregistered. When one of the services got unregistered, a
> component (ComponentA) which had a reference to this service is reactivated
> (Stack trace 1). This causes the ComponentActorThread to call
> deactivateInternal for ComponentA (Stack trace 2) resulting in its services
> being unregistered. Meanwhile the thread doing the shutdown continues to
> stop all bundles including the bundle which contains ComponentA,
> unregistering services from ComponentA in a different thread (Stack trace
> 3).
> 
> Stack trace 1 and 3 are from the same thread and 1 preceeds 3. Stack trace 2
> and 3 are on different threads and can occur simultaneously causing an
> exception.
> 
> 
> *Stack trace 1:*
>   Thread [FelixStartLevel] (Suspended (breakpoint at line 711 in
> DependencyManager))
>         DependencyManager.removedService(ServiceReference) line: 711
>         DependencyManager.serviceChanged(ServiceEvent) line: 109
>         EventDispatcher.invokeServiceListenerCallback(Bundle, EventListener,
> Filter, Object, EventObject) line: 735
>         EventDispatcher.fireEventImmediately(Logger, int, Object[],
> EventObject) line: 593
>         EventDispatcher.fireServiceEvent(ServiceEvent) line: 525
>         Felix.fireServiceEvent(ServiceEvent) line: 3510
>         Felix.access$000(Felix, ServiceEvent) line: 36
>         Felix$1.serviceChanged(ServiceEvent) line: 576
>         ServiceRegistry.fireServiceChanged(ServiceEvent) line: 435
>         ServiceRegistry.unregisterService(Bundle, ServiceRegistration) line:
> 86
>         ServiceRegistrationImpl.unregister() line: 99
> 
> ImmediateComponentManager(AbstractComponentManager).unregisterComponentService()
> line: 503
> 
> ImmediateComponentManager(AbstractComponentManager).deactivateInternal()
> line: 369
> 
> ImmediateComponentManager(AbstractComponentManager).disableInternal() line:
> 390
> 
> ImmediateComponentManager(AbstractComponentManager).disposeInternal() line:
> 419
>         ImmediateComponentManager(AbstractComponentManager).dispose() line:
> 224
>         BundleComponentActivator.dispose() line: 229
>         Activator.disposeComponents(Bundle) line: 230
>         Activator.bundleChanged(BundleEvent) line: 161
>         EventDispatcher.invokeBundleListenerCallback(Bundle, EventListener,
> EventObject) line: 660
>         EventDispatcher.fireEventImmediately(Logger, int, Object[],
> EventObject) line: 589
>         EventDispatcher.fireBundleEvent(BundleEvent) line: 503
>         Felix.fireBundleEvent(int, Bundle) line: 3499
>         Felix._stopBundle(FelixBundle, boolean) line: 1901
>         Felix.stopBundle(FelixBundle, boolean) line: 1866
>         Felix.setFrameworkStartLevel(int) line: 1080
>         StartLevelImpl.run() line: 258
>         Thread.run() line: 803
> 
> *Stack trace 2:*
>   Thread [SCR Component Actor] (Suspended (breakpoint at line 99 in
> ServiceRegistrationImpl))
>         ServiceRegistrationImpl.unregister() line: 99
> 
> ImmediateComponentManager(AbstractComponentManager).unregisterComponentService()
> line: 503
> 
> ImmediateComponentManager(AbstractComponentManager).deactivateInternal()
> line: 369
>         AbstractComponentManager.access$200(AbstractComponentManager) line:
> 55
>         AbstractComponentManager$3.run() line: 176
>         ComponentActorThread.run() line: 81
> 
> *Stack trace 3:*
>   Thread [FelixStartLevel] (Suspended (breakpoint at line 99 in
> ServiceRegistrationImpl))
>         ServiceRegistrationImpl.unregister() line: 99
>         ServiceRegistry.unregisterServices(Bundle) line: 119
>         Felix._stopBundle(FelixBundle, boolean) line: 1946
>         Felix.stopBundle(FelixBundle, boolean) line: 1866
>         Felix.setFrameworkStartLevel(int) line: 1080
>         StartLevelImpl.run() line: 258
>         Thread.run() line: 803
> 
> 
> 
> Thank you...
> 
> Regards,
> 
> Rajini
> 
> 
> On 8/22/07, Felix Meschberger <fm...@gmail.com> wrote:
> >
> > Hi Rajini,
> >
> > I have to admit, that I am not 100% sure, what is going on. But this is
> > what I suppose:
> >
> > Some component has to be activated resulting thus (probably) calling the
> > ImmediateComponentManager.createObjectInstance method (most probably
> > asynchronously). Most probably this fails and results in the
> > AbstractComponentManager.deactivate() method being called. This method
> > (asynchronously again, but actually queued, so definitively later) tries
> > to unregister a service which may or may not be registered...
> >
> > At the "same time" (whatever that means :-) ) the Bundle containing the
> > component is being stopped (probably due to framework shutdown, doesn't
> > matter, actually)  and the framework has already unregistered the
> > service.
> >
> > The problem here is, that the createObjectInstance method should not
> > call the deactivate method for asynchronous deactivation. In fact, no
> > real deactivation is needed anyway, so I rewrote that part of the
> > implementation.
> >
> > I will test this code with my tests further. Could you also test your
> > testcase again ? Thanks. I did not deploy a new snapshot yet, so you
> > will have to build it yourself. If this is not possible for you, please
> > let me know.
> >
> > Regards
> > Felix
> >
> > Am Montag, den 20.08.2007, 15:18 +0100 schrieb Rajini Sivaram:
> > > Hello,
> > >
> > > One of my testcases intermittently throws an exception during shutdown.
> > I
> > > have managed to recreate the exception under a debugger, and it shows
> > two
> > > threads trying to unregister the same service. The test fails only when
> > > declarative services are used. I am using Felix 1.0.0. The test uses
> > > multiple versions of a bundle, but I am not sure if that has anything to
> > do
> > > with the exception.
> > >
> > > The exception thrown is:
> > >
> > >     --- Exception with component : Unexpected problem executing task ---
> > >     java.lang.IllegalStateException: Service already unregistered.
> > >         at org.apache.felix.framework.ServiceRegistrationImpl.unregister
> > (
> > > ServiceRegistrationImpl.java:105)
> > >         at
> > > org.apache.felix.scr.AbstractComponentManager.unregisterComponentService
> > (
> > > AbstractComponentManager.java:503)
> > >         at
> > org.apache.felix.scr.AbstractComponentManager.deactivateInternal(
> > > AbstractComponentManager.java:369)
> > >         at org.apache.felix.scr.AbstractComponentManager.access$200(
> > > AbstractComponentManager.java:55)
> > >         at org.apache.felix.scr.AbstractComponentManager$3.run(
> > > AbstractComponentManager.java:176)
> > >         at org.apache.felix.scr.ComponentActorThread.run(
> > > ComponentActorThread.java:81)
> > >
> > > Here is the stack trace of the two threads under the debugger (both are
> > > using the same object):
> > >
> > >                 Thread [FelixStartLevel] (Suspended (breakpoint at line
> > 97
> > > in ServiceRegistrationImpl))
> > >                         ServiceRegistrationImpl.unregister() line: 97
> > >                         ServiceRegistry.unregisterServices(Bundle) line:
> > 119
> > >                         Felix._stopBundle(FelixBundle, boolean) line:
> > 1946
> > >                         Felix.stopBundle(FelixBundle, boolean) line:
> > 1866
> > >                         Felix.setFrameworkStartLevel(int) line: 1080
> > >                         StartLevelImpl.run() line: 258
> > >                         Thread.run() line: 803
> > >                 Thread [SCR Component Actor] (Suspended (breakpoint at
> > line
> > > 97 in ServiceRegistrationImpl))
> > >                         ServiceRegistrationImpl.unregister() line: 97
> > >
> > >
> > ImmediateComponentManager(AbstractComponentManager).unregisterComponentService()
> > > line: 503
> > >
> > > ImmediateComponentManager(AbstractComponentManager).deactivateInternal()
> > > line: 369
> > >
> > > AbstractComponentManager.access$200(AbstractComponentManager)
> > > line: 55
> > >                         AbstractComponentManager$3.run() line: 176
> > >                         ComponentActorThread.run() line: 81
> > >
> > >
> > > The exception thrown is the IllegalStateException from
> > >     public void unregister()
> > >     {
> > >         if (m_svcObj != null)
> > >         {
> > >             m_registry.unregisterService(m_bundle, this);
> > >             m_svcObj = null;
> > >             m_factory = null;
> > >         }
> > >         else
> > >         {
> > >            * throw new IllegalStateException("Service already
> > > unregistered.");
> > > *        }
> > >     }
> > >
> > >
> > >
> > > Thank you...
> > >
> > > Regards,
> > >
> > > Rajini
> >
> >

Re: Intermittent exception during Felix shutdown

Posted by Felix Meschberger <fm...@gmail.com>.

Hi Rajini,

Am Donnerstag, den 23.08.2007, 10:35 +0100 schrieb Rajini Sivaram:
> My understanding (I may be totally wrong) was that that during Felix
> shutdown, all the bundles were being stopped causing all the services from
> the bundles to be unregistered. When one of the services got unregistered, a
> component (ComponentA) which had a reference to this service is reactivated
> (Stack trace 1). This causes the ComponentActorThread to call
> deactivateInternal for ComponentA (Stack trace 2) resulting in its services
> being unregistered. Meanwhile the thread doing the shutdown continues to
> stop all bundles including the bundle which contains ComponentA,
> unregistering services from ComponentA in a different thread (Stack trace
> 3).

Hmm, this could be the case, actually. But then I would wonder, why the
stack trace 2 hints at the deactivateInternal method being called from
the deactivate() and not the reactivate() method. Maybe, this is just a
source code location artifact.

If you could retry with the current code, we would see more. But the
explanation seems logical and makes sense.

Thanks for your help.

Regards
Felix

Re: Intermittent exception during Felix shutdown

Posted by Rajini Sivaram <ra...@googlemail.com>.

Felix,

Would it be possible for you to send me a jar file containing the fix? I
dont have a source build at the moment, so it will be easier for me if you
could send me the jar.


My understanding (I may be totally wrong) was that that during Felix
shutdown, all the bundles were being stopped causing all the services from
the bundles to be unregistered. When one of the services got unregistered, a
component (ComponentA) which had a reference to this service is reactivated
(Stack trace 1). This causes the ComponentActorThread to call
deactivateInternal for ComponentA (Stack trace 2) resulting in its services
being unregistered. Meanwhile the thread doing the shutdown continues to
stop all bundles including the bundle which contains ComponentA,
unregistering services from ComponentA in a different thread (Stack trace
3).

Stack trace 1 and 3 are from the same thread and 1 preceeds 3. Stack trace 2
and 3 are on different threads and can occur simultaneously causing an
exception.


*Stack trace 1:*
  Thread [FelixStartLevel] (Suspended (breakpoint at line 711 in
DependencyManager))
        DependencyManager.removedService(ServiceReference) line: 711
        DependencyManager.serviceChanged(ServiceEvent) line: 109
        EventDispatcher.invokeServiceListenerCallback(Bundle, EventListener,
Filter, Object, EventObject) line: 735
        EventDispatcher.fireEventImmediately(Logger, int, Object[],
EventObject) line: 593
        EventDispatcher.fireServiceEvent(ServiceEvent) line: 525
        Felix.fireServiceEvent(ServiceEvent) line: 3510
        Felix.access$000(Felix, ServiceEvent) line: 36
        Felix$1.serviceChanged(ServiceEvent) line: 576
        ServiceRegistry.fireServiceChanged(ServiceEvent) line: 435
        ServiceRegistry.unregisterService(Bundle, ServiceRegistration) line:
86
        ServiceRegistrationImpl.unregister() line: 99

ImmediateComponentManager(AbstractComponentManager).unregisterComponentService()
line: 503

ImmediateComponentManager(AbstractComponentManager).deactivateInternal()
line: 369

ImmediateComponentManager(AbstractComponentManager).disableInternal() line:
390

ImmediateComponentManager(AbstractComponentManager).disposeInternal() line:
419
        ImmediateComponentManager(AbstractComponentManager).dispose() line:
224
        BundleComponentActivator.dispose() line: 229
        Activator.disposeComponents(Bundle) line: 230
        Activator.bundleChanged(BundleEvent) line: 161
        EventDispatcher.invokeBundleListenerCallback(Bundle, EventListener,
EventObject) line: 660
        EventDispatcher.fireEventImmediately(Logger, int, Object[],
EventObject) line: 589
        EventDispatcher.fireBundleEvent(BundleEvent) line: 503
        Felix.fireBundleEvent(int, Bundle) line: 3499
        Felix._stopBundle(FelixBundle, boolean) line: 1901
        Felix.stopBundle(FelixBundle, boolean) line: 1866
        Felix.setFrameworkStartLevel(int) line: 1080
        StartLevelImpl.run() line: 258
        Thread.run() line: 803

*Stack trace 2:*
  Thread [SCR Component Actor] (Suspended (breakpoint at line 99 in
ServiceRegistrationImpl))
        ServiceRegistrationImpl.unregister() line: 99

ImmediateComponentManager(AbstractComponentManager).unregisterComponentService()
line: 503

ImmediateComponentManager(AbstractComponentManager).deactivateInternal()
line: 369
        AbstractComponentManager.access$200(AbstractComponentManager) line:
55
        AbstractComponentManager$3.run() line: 176
        ComponentActorThread.run() line: 81

*Stack trace 3:*
  Thread [FelixStartLevel] (Suspended (breakpoint at line 99 in
ServiceRegistrationImpl))
        ServiceRegistrationImpl.unregister() line: 99
        ServiceRegistry.unregisterServices(Bundle) line: 119
        Felix._stopBundle(FelixBundle, boolean) line: 1946
        Felix.stopBundle(FelixBundle, boolean) line: 1866
        Felix.setFrameworkStartLevel(int) line: 1080
        StartLevelImpl.run() line: 258
        Thread.run() line: 803



Thank you...

Regards,

Rajini


On 8/22/07, Felix Meschberger <fm...@gmail.com> wrote:
>
> Hi Rajini,
>
> I have to admit, that I am not 100% sure, what is going on. But this is
> what I suppose:
>
> Some component has to be activated resulting thus (probably) calling the
> ImmediateComponentManager.createObjectInstance method (most probably
> asynchronously). Most probably this fails and results in the
> AbstractComponentManager.deactivate() method being called. This method
> (asynchronously again, but actually queued, so definitively later) tries
> to unregister a service which may or may not be registered...
>
> At the "same time" (whatever that means :-) ) the Bundle containing the
> component is being stopped (probably due to framework shutdown, doesn't
> matter, actually)  and the framework has already unregistered the
> service.
>
> The problem here is, that the createObjectInstance method should not
> call the deactivate method for asynchronous deactivation. In fact, no
> real deactivation is needed anyway, so I rewrote that part of the
> implementation.
>
> I will test this code with my tests further. Could you also test your
> testcase again ? Thanks. I did not deploy a new snapshot yet, so you
> will have to build it yourself. If this is not possible for you, please
> let me know.
>
> Regards
> Felix
>
> Am Montag, den 20.08.2007, 15:18 +0100 schrieb Rajini Sivaram:
> > Hello,
> >
> > One of my testcases intermittently throws an exception during shutdown.
> I
> > have managed to recreate the exception under a debugger, and it shows
> two
> > threads trying to unregister the same service. The test fails only when
> > declarative services are used. I am using Felix 1.0.0. The test uses
> > multiple versions of a bundle, but I am not sure if that has anything to
> do
> > with the exception.
> >
> > The exception thrown is:
> >
> >     --- Exception with component : Unexpected problem executing task ---
> >     java.lang.IllegalStateException: Service already unregistered.
> >         at org.apache.felix.framework.ServiceRegistrationImpl.unregister
> (
> > ServiceRegistrationImpl.java:105)
> >         at
> > org.apache.felix.scr.AbstractComponentManager.unregisterComponentService
> (
> > AbstractComponentManager.java:503)
> >         at
> org.apache.felix.scr.AbstractComponentManager.deactivateInternal(
> > AbstractComponentManager.java:369)
> >         at org.apache.felix.scr.AbstractComponentManager.access$200(
> > AbstractComponentManager.java:55)
> >         at org.apache.felix.scr.AbstractComponentManager$3.run(
> > AbstractComponentManager.java:176)
> >         at org.apache.felix.scr.ComponentActorThread.run(
> > ComponentActorThread.java:81)
> >
> > Here is the stack trace of the two threads under the debugger (both are
> > using the same object):
> >
> >                 Thread [FelixStartLevel] (Suspended (breakpoint at line
> 97
> > in ServiceRegistrationImpl))
> >                         ServiceRegistrationImpl.unregister() line: 97
> >                         ServiceRegistry.unregisterServices(Bundle) line:
> 119
> >                         Felix._stopBundle(FelixBundle, boolean) line:
> 1946
> >                         Felix.stopBundle(FelixBundle, boolean) line:
> 1866
> >                         Felix.setFrameworkStartLevel(int) line: 1080
> >                         StartLevelImpl.run() line: 258
> >                         Thread.run() line: 803
> >                 Thread [SCR Component Actor] (Suspended (breakpoint at
> line
> > 97 in ServiceRegistrationImpl))
> >                         ServiceRegistrationImpl.unregister() line: 97
> >
> >
> ImmediateComponentManager(AbstractComponentManager).unregisterComponentService()
> > line: 503
> >
> > ImmediateComponentManager(AbstractComponentManager).deactivateInternal()
> > line: 369
> >
> > AbstractComponentManager.access$200(AbstractComponentManager)
> > line: 55
> >                         AbstractComponentManager$3.run() line: 176
> >                         ComponentActorThread.run() line: 81
> >
> >
> > The exception thrown is the IllegalStateException from
> >     public void unregister()
> >     {
> >         if (m_svcObj != null)
> >         {
> >             m_registry.unregisterService(m_bundle, this);
> >             m_svcObj = null;
> >             m_factory = null;
> >         }
> >         else
> >         {
> >            * throw new IllegalStateException("Service already
> > unregistered.");
> > *        }
> >     }
> >
> >
> >
> > Thank you...
> >
> > Regards,
> >
> > Rajini
>
>

Re: Intermittent exception during Felix shutdown

Posted by Felix Meschberger <fm...@gmail.com>.

Hi Rajini,

I have to admit, that I am not 100% sure, what is going on. But this is
what I suppose:

Some component has to be activated resulting thus (probably) calling the
ImmediateComponentManager.createObjectInstance method (most probably
asynchronously). Most probably this fails and results in the
AbstractComponentManager.deactivate() method being called. This method
(asynchronously again, but actually queued, so definitively later) tries
to unregister a service which may or may not be registered...

At the "same time" (whatever that means :-) ) the Bundle containing the
component is being stopped (probably due to framework shutdown, doesn't
matter, actually)  and the framework has already unregistered the
service.

The problem here is, that the createObjectInstance method should not
call the deactivate method for asynchronous deactivation. In fact, no
real deactivation is needed anyway, so I rewrote that part of the
implementation.

I will test this code with my tests further. Could you also test your
testcase again ? Thanks. I did not deploy a new snapshot yet, so you
will have to build it yourself. If this is not possible for you, please
let me know.

Regards
Felix

Am Montag, den 20.08.2007, 15:18 +0100 schrieb Rajini Sivaram:
> Hello,
> 
> One of my testcases intermittently throws an exception during shutdown. I
> have managed to recreate the exception under a debugger, and it shows two
> threads trying to unregister the same service. The test fails only when
> declarative services are used. I am using Felix 1.0.0. The test uses
> multiple versions of a bundle, but I am not sure if that has anything to do
> with the exception.
> 
> The exception thrown is:
> 
>     --- Exception with component : Unexpected problem executing task ---
>     java.lang.IllegalStateException: Service already unregistered.
>         at org.apache.felix.framework.ServiceRegistrationImpl.unregister(
> ServiceRegistrationImpl.java:105)
>         at
> org.apache.felix.scr.AbstractComponentManager.unregisterComponentService(
> AbstractComponentManager.java:503)
>         at org.apache.felix.scr.AbstractComponentManager.deactivateInternal(
> AbstractComponentManager.java:369)
>         at org.apache.felix.scr.AbstractComponentManager.access$200(
> AbstractComponentManager.java:55)
>         at org.apache.felix.scr.AbstractComponentManager$3.run(
> AbstractComponentManager.java:176)
>         at org.apache.felix.scr.ComponentActorThread.run(
> ComponentActorThread.java:81)
> 
> Here is the stack trace of the two threads under the debugger (both are
> using the same object):
> 
>                 Thread [FelixStartLevel] (Suspended (breakpoint at line 97
> in ServiceRegistrationImpl))
>                         ServiceRegistrationImpl.unregister() line: 97
>                         ServiceRegistry.unregisterServices(Bundle) line: 119
>                         Felix._stopBundle(FelixBundle, boolean) line: 1946
>                         Felix.stopBundle(FelixBundle, boolean) line: 1866
>                         Felix.setFrameworkStartLevel(int) line: 1080
>                         StartLevelImpl.run() line: 258
>                         Thread.run() line: 803
>                 Thread [SCR Component Actor] (Suspended (breakpoint at line
> 97 in ServiceRegistrationImpl))
>                         ServiceRegistrationImpl.unregister() line: 97
> 
> ImmediateComponentManager(AbstractComponentManager).unregisterComponentService()
> line: 503
> 
> ImmediateComponentManager(AbstractComponentManager).deactivateInternal()
> line: 369
> 
> AbstractComponentManager.access$200(AbstractComponentManager)
> line: 55
>                         AbstractComponentManager$3.run() line: 176
>                         ComponentActorThread.run() line: 81
> 
> 
> The exception thrown is the IllegalStateException from
>     public void unregister()
>     {
>         if (m_svcObj != null)
>         {
>             m_registry.unregisterService(m_bundle, this);
>             m_svcObj = null;
>             m_factory = null;
>         }
>         else
>         {
>            * throw new IllegalStateException("Service already
> unregistered.");
> *        }
>     }
> 
> 
> 
> Thank you...
> 
> Regards,
> 
> Rajini