Stefan, Please open a bug against Equinox->Bundles and supply your testcase as an attachment to the bug report. Thanks.
Tom
From: "Foerster, Stefan" <[EMAIL PROTECTED]>
To: Equinox development mailing list <equinox-dev@eclipse.org>
Date: 02/25/2008 07:46 AM
Subject: RE: [equinox-dev] DS invocation order of bind and activate(timing
issue???)
Hi,
the timeouts of the SCR are gone if I use the latest build of the ds
(org.eclipse.equinox.ds_1.0.0.N20080224-0010.jar)
However, the other problem (B1 activated before A1) still exists.
I prepared two bundles b1 and b2 (attached to this mail). Using these
bundles
and having the following start order:
0 ACTIVE org.eclipse.osgi_3.4.0.v20080218
2 ACTIVE org.eclipse.equinox.log_1.1.0.v20071203
3 ACTIVE org.eclipse.equinox.util_1.0.0.v20080218
5 ACTIVE javax.servlet_2.4.0.v200711021030
6 ACTIVE org.eclipse.osgi.services_3.1.200.v20071203
15 ACTIVE org.eclipse.equinox.ds_1.0.0.N20080224-0010
21 ACTIVE b1_2.0.0
22 ACTIVE b2_2.0.0
23 ACTIVE d_2.0.0
25 ACTIVE a_2.0.0
of the framework. A1 is always used NOT activated!
I get the following output (via System.err.println()):
osgi> DEBUG: D: activate()
setD()
DEBUG: Activator: activate()
DEBUG: B2: startup()
A: setB() called while not activated !!!!!!
setD()
DEBUG: Activator: activate()
DEBUG: A: begin startup
DEBUG: A: finished startup
setD()
DEBUG: Activator: activate()
DEBUG: B1: startup()
DEBUG: A: setB()
-----Original Message-----
From: [EMAIL PROTECTED] on behalf of O'Flynn, Dennis
Sent: Mon 25.02.2008 14:18
To: Equinox development mailing list
Subject: RE: [equinox-dev] DS invocation order of bind and
activate(timingissue???)
Not sure if the following is related. Maybe someone more familiar w/
equinox ds/util could comment on this.
1) equinox ds imports packages from util
2) equinox util is NOT lazy started
Q: Is equinox ds dependent upon service provide by equinox util that may
not be yet registered when ds is started before util?
If equinox util was lazy started, than I would assume that the 2nd
startup sequence listed below should have worked.
The contents of this e-mail are intended for the named addressee only. It
contains information that may be confidential. Unless you are the named
addressee or an authorized designee, you may not copy or use it, or
disclose it to anyone else. If you received it in error please notify us
immediately and then destroy it.
From: [EMAIL PROTECTED]
[mailto:[EMAIL PROTECTED] On Behalf Of Foerster, Stefan
Sent: Monday, February 25, 2008 4:24 AM
To: Equinox development mailing list
Subject: RE: [equinox-dev] DS invocation order of bind and
activate(timing issue???)
I think I've got a test case and test sequence to reproduce the timing
problem.
The problem arises from the start order of the bundles.
if the framework starts the bundles in the following order:
1) org.eclipse.osgi_3.4.0.v20080218
2) org.eclipse.equinox.ds_1.0.0.v20080218
3) org.eclipse.equinox.log_1.1.0.v20071203
4) org.eclipse.equinox.util_1.0.0.v20080218
5) javax.servlet_2.4.0.v200711021030
6) org.eclipse.osgi.services_3.1.200.v20071203
7) a_2.0.0
8) d_2.0.0
everything is OK (see attached running.txt), both services A and D get
activated as expected.
Now, If i stop bundles 2-8 and start them in the following order (bundle
1 was not stopped):
2) javax.servlet_2.4.0.v200711021030
3) org.eclipse.equinox.ds_1.0.0.v20080218
4) org.eclipse.equinox.log_1.1.0.v20071203
5) org.eclipse.osgi.services_3.1.200.v20071203
6) a_2.0.0
7) d_2.0.0
8) org.eclipse.equinox.util_1.0.0.v20080218
I get the timeouts in the SCR (see fail.txt).
I also attached the two bundles I used to debug the problem. The source
code
is located within the OSGI-INF/src.
Based on this observation I think the SCR gets confused and does not
obey the
activation/bind order as I reported before.
-----Original Message-----
From: [EMAIL PROTECTED] on behalf of BJ Hargrave
Sent: Fri 22.02.2008 20:05
To: Equinox development mailing list
Subject: Re: [equinox-dev] DS invocation order of bind and
activate(timing issue???)
I think you should put this in a bug report against DS.
--
BJ Hargrave
Senior Technical Staff Member, IBM
OSGi Fellow and CTO of the OSGi Alliance
[EMAIL PROTECTED]
office: +1 386 848 1781
mobile: +1 386 848 3788
From:
"Foerster, Stefan" <[EMAIL PROTECTED]>
To:
equinox-dev@eclipse.org
Date:
2008-02-22 11:52
Subject:
[equinox-dev] DS invocation order of bind and activate (timing
issue???)
Hello,
I'm having three bundles providing three services using the declarative
service (version 1.0.0.v20080218):
bundle A:
<component name="A1" immediate="true">
<implementation class="A1"/>
<service>
<provide interface="IA"/>
</service>
<property name="service.pid" value="A1"/>
<property name="service.ranking" value="1000"/>
<reference name="b" interface="IB" bind="setB" unbind="unsetB"
cardinality="0..n" policy="dynamic"/>
<reference name="c" interface="IC" bind="setC" unbind="unsetC"
cardinality="0..1" policy="dynamic"/>
<reference name="d" interface="ID" bind="setD" unbind="unsetD"
cardinality="1..1"/>
<reference name="e" interface="IE" bind="setE" unbind="unsetE"
cardinality="0..n" policy="dynamic"/>
</component>
bundle B:
<component name="B1">
<implementation class="B1"/>
<service>
<provide interface="IB"/>
</service>
<property name="service.pid" value="B1"/>
<property name="service.ranking" value="1000"/>
<reference name="a" interface="IA" bind="setA" unbind="unsetA"
cardinality="1..1"/>
<reference name="d" interface="ID" bind="setD" unbind="unsetD"
cardinality="1..1"/>
</component>
bundle D:
<component name="D1">
<implementation class="D1"/>
<service>
<provide interface="ID"/>
</service>
<property name="service.pid" value="D1"/>
<property name="service.ranking" value="1000"/>
<reference name="logger" interface="org.osgi.service.log.LogService"
bind="setLog" unbind="unsetLog" cardinality="0..1" policy="dynamic"/>
</component>
Reading the OSGi DS spec I assume the only valid method invocation order
(if the methods exists and are accessible) is:
1) D1.activate() -> some instanceD
2) A1.setD(instanceD)
3) A1.activate() -> some instanceA
4) B1.setA(instanceA) and B1.setD(instanceD) in any order
5) B1.activate() -> some instanceB
6) A1.setB(instanceB)
Sometimes, it happens that B1 is activated before!!! A1. and I get the
following
order of calls from the OSGi log (calls to setD() are not logged!):
==
1: >Debug [51] D1: activate() [EMAIL PROTECTED]:file:../../build/d1.jar/
2: >Info [51] ServiceEvent REGISTERED {service.id=29}
3: >Info [54] ServiceEvent REGISTERED {service.id=30}
4: >Info [37] ServiceEvent REGISTERED {service.id=31}
5: >Info [52] ServiceEvent REGISTERED {service.id=32}
6: >Info [53] ServiceEvent REGISTERED {service.id=33}
7: >Warn [4] ComponentReference.bind(): bind method setE is not
accessible! [EMAIL PROTECTED]:
file:org.eclipse.equinox.ds_1.0.0.v20080218.jar/
8: >Warn [4] ComponentReference.bind(): bind method setB is not
accessible! [EMAIL PROTECTED]:
file:org.eclipse.equinox.ds_1.0.0.v20080218.jar/
9: >Debug [51] B1: activate() [EMAIL PROTECTED]:file:../../build/d1.jar/
10:>Debug [51] A1: setB() [EMAIL PROTECTED]:file:../../build/d1.jar/
11:>Debug [51] A1: setB() A1 not yet activated!!! [EMAIL PROTECTED]:
file:../../build/d1.jar/
12:>Debug [51] A1: activate() [EMAIL PROTECTED]:file:../../build/d1.jar/
13:>Debug [51] E1: activate() [EMAIL PROTECTED]:file:../../build/d1.jar/
14:>Debug [51] A1: setE() [EMAIL PROTECTED]:file:../../build/d1.jar/
15:>Debug [51] B2: activate() [EMAIL PROTECTED]:file:../../build/d1.jar/
16:>Debug [51] A1: setB() [EMAIL PROTECTED]:file:../../build/d1.jar/
17:>Warn [4] ComponentReference.bind(): service reference already bound:
{IB}={service.ranking=1000, service.pid=B1, component.name=B1,
component.id=4, service.id=33} [EMAIL PROTECTED]:
file:org.eclipse.equinox.ds_1.0.0.v20080218.jar/
==
Please observe line 11! I inserted the check for activation since else
some internal data structures of A1 were not
initialised and I had NullPointerExceptions.
Since I check for activation, all services are at least started.
I also have a run the whole thing with DS debugging enabled,
interestingly
no service is started at all:
==
>Info [6] Log created; Log Size=100; Log Threshold=4 [EMAIL PROTECTED]:
file:org.eclipse.equinox.log_1.1.0.v20071203.jar/
>Info [6] ServiceEvent REGISTERED {service.id=23}
>Info [6] ServiceEvent REGISTERED {service.id=24}
>Info [6] ServiceEvent REGISTERED {service.id=25}
>Info [6] BundleEvent STARTED [EMAIL PROTECTED]:
file:org.eclipse.equinox.log_1.1.0.v20071203.jar/
>Debug [5] bundleentry://7/OSGI-INF/Activator.xml [EMAIL PROTECTED]:
file:org.eclipse.equinox.ds_1.0.0.v20080218.jar/
>Debug [5] [QueuedJob] WorkPerformer:
[EMAIL PROTECTED]; actionType 1
[EMAIL PROTECTED]:file:org.eclipse.equinox.ds_1.0.0.v20080218.jar/
>Warn [5] [SCR - WorkThread] Timeout ocurred! Thread was blocked on
processing [QueuedJob] WorkPerformer:
[EMAIL PROTECTED]; actionType 1
[EMAIL PROTECTED]:file:org.eclipse.equinox.ds_1.0.0.v20080218.jar/
>Info [7] BundleEvent STARTED [EMAIL PROTECTED]:file:../../build/b1.jar/
>Info [8] BundleEvent STARTED [EMAIL PROTECTED]:
file:org.apache.commons.logging_1.0.4.v200711021015.jar/
>Info [11] BundleEvent STARTED [EMAIL PROTECTED]:
file:org.eclipse.osgi.services_3.1.200.v20071203.jar/
>Debug [5] bundleentry://12/OSGI-INF/Activator.xml [EMAIL PROTECTED]:
file:org.eclipse.equinox.ds_1.0.0.v20080218.jar/
>Debug [5] [QueuedJob] WorkPerformer:
[EMAIL PROTECTED]; actionType 1
[EMAIL PROTECTED]:file:org.eclipse.equinox.ds_1.0.0.v20080218.jar/
>Warn [5] [SCR - WorkThread] Timeout ocurred! Thread was blocked on
processing [QueuedJob] WorkPerformer:
[EMAIL PROTECTED]; actionType 1
[EMAIL PROTECTED]:file:org.eclipse.equinox.ds_1.0.0.v20080218.jar/
>Info [12] BundleEvent STARTED
[EMAIL PROTECTED]:file:../../build/a1.jar/
>Debug [5] bundleentry://14/OSGI-INF/Activator.xml [EMAIL PROTECTED]:
file:org.eclipse.equinox.ds_1.0.0.v20080218.jar/
>Debug [5] [QueuedJob] WorkPerformer:
[EMAIL PROTECTED]; actionType 1
[EMAIL PROTECTED]:file:org.eclipse.equinox.ds_1.0.0.v20080218.jar/
>Warn [5] [SCR - WorkThread] Timeout ocurred! Thread was blocked on
processing [QueuedJob] WorkPerformer:
[EMAIL PROTECTED]; actionType 1
[EMAIL PROTECTED]:file:org.eclipse.equinox.ds_1.0.0.v20080218.jar/
>Info [14] BundleEvent STARTED
[EMAIL PROTECTED]:file:../../build/b2.jar/
>Debug [5] bundleentry://15/OSGI-INF/Activator.xml [EMAIL PROTECTED]:
file:org.eclipse.equinox.ds_1.0.0.v20080218.jar/
>Debug [5] [QueuedJob] WorkPerformer:
[EMAIL PROTECTED]; actionType 1
[EMAIL PROTECTED]:file:org.eclipse.equinox.ds_1.0.0.v20080218.jar/
>Warn [5] [SCR - WorkThread] Timeout ocurred! Thread was blocked on
processing [QueuedJob] WorkPerformer:
[EMAIL PROTECTED]; actionType 1
[EMAIL PROTECTED]:file:org.eclipse.equinox.ds_1.0.0.v20080218.jar/
>Info [15] BundleEvent STARTED
[EMAIL PROTECTED]:file:../../build/e1.jar/
>Debug [5] bundleentry://16/OSGI-INF/Activator.xml [EMAIL PROTECTED]:
file:org.eclipse.equinox.ds_1.0.0.v20080218.jar/
>Debug [5] bundleentry://16/OSGI-INF/Command.xml [EMAIL PROTECTED]:
file:org.eclipse.equinox.ds_1.0.0.v20080218.jar/
>Debug [5] [QueuedJob] WorkPerformer:
[EMAIL PROTECTED]; actionType 1
[EMAIL PROTECTED]:file:org.eclipse.equinox.ds_1.0.0.v20080218.jar/
>Warn [5] [SCR - WorkThread] Timeout ocurred! Thread was blocked on
processing [QueuedJob] WorkPerformer:
[EMAIL PROTECTED]; actionType 1
[EMAIL PROTECTED]:file:org.eclipse.equinox.ds_1.0.0.v20080218.jar/
>Info [16] BundleEvent STARTED
[EMAIL PROTECTED]:file:../../build/d1.jar/
>Debug [17] DEBUG 17 [0] 1 : [EMAIL PROTECTED]:
file:org.eclipse.equinox.util_1.0.0.v20080218.jar/
>Debug [17] DEBUG 17 [0] 1001 : 0 [EMAIL PROTECTED]:
file:org.eclipse.equinox.util_1.0.0.v20080218.jar/
>Debug [17] DEBUG 17 [0] 101 : 0 [EMAIL PROTECTED]:
file:org.eclipse.equinox.util_1.0.0.v20080218.jar/
>Debug [17] DEBUG 17 [0] 102 : 0 [EMAIL PROTECTED]:
file:org.eclipse.equinox.util_1.0.0.v20080218.jar/
>Debug [17] DEBUG 17 [0] 3001 : 0 [EMAIL PROTECTED]:
file:org.eclipse.equinox.util_1.0.0.v20080218.jar/
>Debug [17] DEBUG 17 [0] 2001 : 0 [EMAIL PROTECTED]:
file:org.eclipse.equinox.util_1.0.0.v20080218.jar/
>Debug [17] DEBUG 17 [0] 3 : 4 [EMAIL PROTECTED]:
file:org.eclipse.equinox.util_1.0.0.v20080218.jar/
>Info [17] ServiceEvent REGISTERED {service.id=26}
>Debug [17] DEBUG 17 [0] 4 : 1 [EMAIL PROTECTED]:
file:org.eclipse.equinox.util_1.0.0.v20080218.jar/
>Debug [17] DEBUG 17 [0] 33 : 3 [EMAIL PROTECTED]:
file:org.eclipse.equinox.util_1.0.0.v20080218.jar/
>Info [17] ServiceEvent REGISTERED {service.id=27}
>Debug [17] DEBUG 17 [0] 5 : 0 [EMAIL PROTECTED]:
file:org.eclipse.equinox.util_1.0.0.v20080218.jar/
>Debug [17] DEBUG 17 [0] 16 : 8 [EMAIL PROTECTED]:
file:org.eclipse.equinox.util_1.0.0.v20080218.jar/
>Info [17] BundleEvent STARTED [EMAIL PROTECTED]:
file:org.eclipse.equinox.util_1.0.0.v20080218.jar/
>Info [0] FrameworkEvent STARTLEVEL CHANGED System Bundle
==
Is there something wrong with my understanding of the DS or is there a
(timing related) issue
within the DS?
Yours sincerely
Stefan
_______________________________________________
equinox-dev mailing list
equinox-dev@eclipse.org
https://dev.eclipse.org/mailman/listinfo/equinox-dev
_______________________________________________
equinox-dev mailing list
equinox-dev@eclipse.org
https://dev.eclipse.org/mailman/listinfo/equinox-dev
_______________________________________________
equinox-dev mailing list
equinox-dev@eclipse.org
https://dev.eclipse.org/mailman/listinfo/equinox-dev
[attachment "atths1rz.dat" deleted by Thomas Watson/Austin/IBM]
_______________________________________________
equinox-dev mailing list
equinox-dev@eclipse.org
https://dev.eclipse.org/mailman/listinfo/equinox-dev
<<inline: graycol.gif>>
<<inline: ecblank.gif>>
_______________________________________________ equinox-dev mailing list equinox-dev@eclipse.org https://dev.eclipse.org/mailman/listinfo/equinox-dev
