Community
Participate
Working Groups
I'm not sure what the cause or full impact of this exception is but it is unexpected. Below is the console output with debugging turned on. Note that weaving was enabled. One affect may be the failure to publish a EMF service which seems to be due to a timing problem with the JDBC service becoming available after Gemini JPA went looking for it. This is probably the same problem as Bug 329030. By stopping o.e.g.jpa bundle and then starting it I was able to get Gemini JPA to reprocess PU bundles and publish the EMF service. osgi> EclipseLinkProvider starting... GeminiServicesUtil registering provider service for org.eclipse.persistence.jpa.PersistenceProvider GeminiServicesUtil successfully registered provider service for org.eclipse.persistence.jpa.PersistenceProvider GeminiExtender listening GeminiExtender looking at existing bundles: org.eclipse.osgi_3.7.0.v20101207 [0] org.eclipse.gemini.jpa.weaving_1.0.0.M4-incubation [1] org.eclipse.gemini.jpa_1.0.0.M4-incubation [2] org.eclipse.persistence.antlr_2.3.0.v20110129-r8902 [3] javax.persistence_2.0.3.v201010191057 [4] osgi.enterprise_4.2.0.201003190513 [5] org.eclipse.persistence.jpa_2.3.0.v20110129-r8902 [6] org.eclipse.gemini.example.comics.model_1.0.0.qualifier [7] org.eclipse.persistence.core_2.3.0.v20110129-r8902 [8] org.eclipse.gemini.dbaccess.derby_1.0.0.M1-incubation [9] org.apache.derby_10.5.1.1 [10] org.eclipse.persistence.asm_2.3.0.v20110129-r8902 [11] org.eclipse.gemini.example.comics.client_1.0.0.qualifier [12] GeminiExtender refreshing packages of bundle bundle=org.eclipse.gemini.example.comics.model id=7 state=RESOLVED GeminiExtender refreshing packages of bundle bundle=org.eclipse.gemini.example.comics.client id=12 state=RESOLVED EclipseLink Provider started Extender - bundle event, bundle=org.eclipse.gemini.jpa, event=STARTED Extender - bundle event, bundle=org.eclipse.persistence.antlr, event=STARTING Extender - bundle event, bundle=org.eclipse.persistence.antlr, event=STARTED Extender - bundle event, bundle=javax.persistence, event=STARTING Extender - bundle event, bundle=org.eclipse.gemini.example.comics.client, event=UNRESOLVED GeminiExtender tryAssigningPersistenceUnitsInBundle: bundle=org.eclipse.gemini.example.comics.client id=12 state=INSTALLED Extender - bundle event, bundle=javax.persistence, event=STARTED Extender - bundle event, bundle=osgi.enterprise, event=STARTING Looking for persistence descriptors in bundle org.eclipse.gemini.example.comics.client Extender - bundle event, bundle=osgi.enterprise, event=STARTED Extender - bundle event, bundle=org.eclipse.persistence.jpa, event=STARTING Found persistence descriptors: [] Extender - bundle event, bundle=org.eclipse.persistence.jpa, event=STARTED Parsed persistence descriptors: [] Extender - bundle event, bundle=org.eclipse.gemini.example.comics.model, event=UNRESOLVED GeminiExtender tryAssigningPersistenceUnitsInBundle: bundle=org.eclipse.gemini.example.comics.model id=7 state=INSTALLED Looking for persistence descriptors in bundle org.eclipse.gemini.example.comics.model Found persistence descriptors: [Descriptor: META-INF/persistence.xml] Parsing persistence descriptor META-INF/persistence.xml getDescStream - Looking for descriptor in : null Finished parsing persistence descriptor bundleentry://7.fwk15020296/META-INF/persistence.xml Found 1 persistence units Parsed persistence descriptors: [ PUnit: comics --- XML Data --- provider: null classes: [org.eclipse.gemini.example.comics.model.Series, org.eclipse.gemini.example.comics.model.Publisher, org.eclipse.gemini.example.comics.model.Issue] driverClassName: org.apache.derby.jdbc.ClientDriver driverUrl: jdbc:derby://localhost:1527/gemini;create=true driverUser: app driverPassword: app --- Runtime Data --- bundle: null assignedProvider: null descriptorInfo: Descriptor: META-INF/persistence.xml uniquePackageNames: null emfHandler: null emfBuilderHandler: null DSF tracker: null] EclipseProvider assignPersistenceUnitsInBundle: org.eclipse.gemini.example.comics.model PUnit bundle proxy loader created: org.eclipse.gemini.jpa.classloader.BundleProxyClassLoader@1479feb(org.eclipse.gemini.example.comics.model) Parent loader: sun.misc.Launcher$AppClassLoader@11b86e7 Parent loader: sun.misc.Launcher$ExtClassLoader@35ce36 Provider bundle proxy loader created: org.eclipse.gemini.jpa.classloader.BundleProxyClassLoader@1543c88(org.eclipse.gemini.jpa) Parent loader: sun.misc.Launcher$AppClassLoader@11b86e7 Parent loader: sun.misc.Launcher$ExtClassLoader@35ce36 Composite loader created: org.eclipse.gemini.jpa.classloader.CompositeClassLoader@15212bc Parent loader: sun.misc.Launcher$AppClassLoader@11b86e7 Parent loader: sun.misc.Launcher$ExtClassLoader@35ce36 Parsing Eclipse .classpath Finished parsing Eclipse .classpath: bin Extender - bundle event, bundle=org.eclipse.gemini.example.comics.model, event=RESOLVED Extender - bundle event, bundle=org.eclipse.gemini.example.comics.client, event=RESOLVED Extender - bundle event, bundle=org.eclipse.gemini.example.comics.model, event=STARTING GeminiExtender registerPersistenceUnitsInBundle: bundle=org.eclipse.gemini.example.comics.model id=7 state=STARTING GeminiExtender checking bundle compatibility of: bundle=org.eclipse.gemini.example.comics.model id=7 state=STARTING GeminiExtender provider compatible with bundle: bundle=org.eclipse.gemini.example.comics.model id=7 state=STARTING !SESSION EclipseLinkProvider registerPersistenceUnits: [ PUnit: comics --- XML Data --- provider: null classes: [org.eclipse.gemini.example.comics.model.Series, org.eclipse.gemini.example.comics.model.Publisher, org.eclipse.gemini.example.comics.model.Issue] driverClassName: org.apache.derby.jdbc.ClientDriver driverUrl: jdbc:derby://localhost:1527/gemini;create=true driverUser: app driverPassword: app --- Runtime Data --- bundle: org.eclipse.gemini.example.comics.model assignedProvider: org.eclipse.gemini.jpa.provider.EclipseLinkOSGiProvider@11978b descriptorInfo: Descriptor: META-INF/persistence.xml uniquePackageNames: null emfHandler: null emfBuilderHandler: null DSF tracker: null] 2011-02-23 17:07:52.147 -GeminiServicesUtil registerEMFServices for comics GeminiServicesUtil EMF[Builder] services props: {osgi.managed.bundles=org.eclipse.gemini.example.comics.model_1.0.0.qualifier, osgi.unit.version=1.0.0.qualifier, osgi.unit.name=comics, osgi.unit.provider=org.eclipse.persistence.jpa.PersistenceProvider} GeminiServicesUtil register EMF service GeminiServicesUtil loading EMF class GeminiServicesUtil EMF proxy class array: interface javax.persistence.EntityManagerFactory ------------------GeminiServicesUtil proxy loader org.eclipse.gemini.jpa.classloader.CompositeClassLoader@f7c31d Parent loader: sun.misc.Launcher$AppClassLoader@11b86e7 Parent loader: sun.misc.Launcher$ExtClassLoader@35ce36 ---------------------------- eclipse.buildId=unknown java.version=1.6.0_22 java.vendor=Sun Microsystems Inc. BootLoader constants: OS=win32, ARCH=x86, WS=win32, NL=en_CA Command-line arguments: -dev file:D:/Conferences/EclipseCon 2011/Gemini-Virto Tutorial/workspace/.metadata/.plugins/org.eclipse.pde.core/comics client/dev.properties -os win32 -ws win32 -arch x86 -consoleLog -console -clean !ENTRY org.eclipse.gemini.example.comics.model 4 0 2011-02-23 17:07:53.317 !MESSAGE !STACK 0 org.osgi.framework.BundleException: State change in progress for bundle "initial@reference:file:../../../../org.eclipse.gemini.example.comics.model/" by thread "Refresh Packages". at org.eclipse.osgi.framework.internal.core.AbstractBundle.beginStateChange(AbstractBundle.java:1075) at org.eclipse.osgi.framework.internal.core.AbstractBundle.resume(AbstractBundle.java:374) at org.eclipse.osgi.framework.internal.core.Framework.resumeBundle(Framework.java:1111) at org.eclipse.osgi.framework.internal.core.StartLevelManager.resumeBundles(StartLevelManager.java:559) at org.eclipse.osgi.framework.internal.core.StartLevelManager.resumeBundles(StartLevelManager.java:544) at org.eclipse.osgi.framework.internal.core.StartLevelManager.incFWSL(StartLevelManager.java:457) at org.eclipse.osgi.framework.internal.core.StartLevelManager.doSetStartLevel(StartLevelManager.java:243) at org.eclipse.osgi.framework.internal.core.StartLevelManager.dispatchEvent(StartLevelManager.java:438) at org.eclipse.osgi.framework.internal.core.StartLevelManager.dispatchEvent(StartLevelManager.java:1) at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:340) Caused by: org.eclipse.osgi.framework.internal.core.AbstractBundle$BundleStatusException ... 11 more Root exception: org.eclipse.osgi.framework.internal.core.AbstractBundle$BundleStatusException at org.eclipse.osgi.framework.internal.core.AbstractBundle.beginStateChange(AbstractBundle.java:1075) at org.eclipse.osgi.framework.internal.core.AbstractBundle.resume(AbstractBundle.java:374) at org.eclipse.osgi.framework.internal.core.Framework.resumeBundle(Framework.java:1111) at org.eclipse.osgi.framework.internal.core.StartLevelManager.resumeBundles(StartLevelManager.java:559) at org.eclipse.osgi.framework.internal.core.StartLevelManager.resumeBundles(StartLevelManager.java:544) at org.eclipse.osgi.framework.internal.core.StartLevelManager.incFWSL(StartLevelManager.java:457) at org.eclipse.osgi.framework.internal.core.StartLevelManager.doSetStartLevel(StartLevelManager.java:243) at org.eclipse.osgi.framework.internal.core.StartLevelManager.dispatchEvent(StartLevelManager.java:438) at org.eclipse.osgi.framework.internal.core.StartLevelManager.dispatchEvent(StartLevelManager.java:1) at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:340) GeminiServicesUtil created EMF proxy GeminiServicesUtil trackDataSourceFactory for p-unit comics WARNING: DataSourceFactory for org.apache.derby.jdbc.ClientDriver not registered. GeminiServicesUtil register EMFBuilder service GeminiServicesUtil loading EMFBuilder class GeminiServicesUtil EMFBuilder proxy class array: interface org.osgi.service.jpa.EntityManagerFactoryBuilder GeminiServicesUtil proxy loader org.eclipse.gemini.jpa.classloader.CompositeClassLoader@15ad5c6 Parent loader: sun.misc.Launcher$AppClassLoader@11b86e7 Extender - bundle event, bundle=org.eclipse.persistence.core, event=STARTING Parent loader: sun.misc.Launcher$ExtClassLoader@35ce36 Extender - bundle event, bundle=org.eclipse.persistence.core, event=STARTED Extender - bundle event, bundle=org.eclipse.gemini.dbaccess.derby, event=STARTING Gemini DBAccess - Derby JDBC starting GeminiServicesUtil created EMFBuilder proxy GeminiServicesUtil registered EMFBuilder service for comics Extender - bundle event, bundle=org.eclipse.gemini.example.comics.model, event=STARTED Extender - bundle event, bundle=org.eclipse.gemini.example.comics.client, event=STARTING Extender - bundle event, bundle=org.eclipse.gemini.example.comics.client, event=STARTED Extender - bundle event, bundle=org.eclipse.gemini.example.comics.client, event=STOPPING Extender - bundle event, bundle=org.eclipse.gemini.example.comics.client, event=STOPPED Extender - bundle event, bundle=org.eclipse.gemini.example.comics.client, event=UNRESOLVED Extender - bundle event, bundle=org.eclipse.gemini.example.comics.client, event=RESOLVED Extender - bundle event, bundle=org.eclipse.gemini.example.comics.client, event=STARTING Extender - bundle event, bundle=org.eclipse.gemini.example.comics.client, event=STARTED Extender - bundle event, bundle=org.eclipse.gemini.dbaccess.derby, event=STARTED Extender - bundle event, bundle=org.apache.derby, event=STARTING Extender - bundle event, bundle=org.apache.derby, event=STARTED Extender - bundle event, bundle=org.eclipse.persistence.asm, event=STARTING Extender - bundle event, bundle=org.eclipse.persistence.asm, event=STARTED Extender - bundle event, bundle=org.eclipse.osgi, event=STARTED
I am seeing the same problem sporadically with a different sample application, during startup of the OSGi framework. And I'm pretty sure there is no re-start of the DataSourceFactory. I'm still wondering if the refreshPackages could be avoided in some way (and by this prevent problems like this one). But I already asked this in Bug 337157, hoping to get a better understanding why it is done.
Not sure about this one, but it may be related to a timing problem of the bundle being in some middle state after being installed but not yet started and that it is being refreshed before it has been activated. In any case, I think it has to do with the refresh, rather than the data source not being started yet. See https://bugs.eclipse.org/bugs/show_bug.cgi?id=337157 for an explanation of why the refresh happens. I will be looking into this issue soon, I hope.
I can't reproduce but while fixing 342996 I saw some funniness in the state change code that could have caused this. Am hoping that it is fixed, now, but if someone encounters this again please reopen this bug.
