dev@glassfish.java.net

Re: hours spent trying to debug OSGI failure (maybe a worthwhile read for developers)

From: Lloyd L Chambers <Lloyd.Chambers_at_Sun.COM>
Date: Thu, 12 Jun 2008 13:34:19 -0700

I finally tracked this down.

LESSON: with problems like this, blow away not just the repo, but ALL
THE SOURCE CODE as well. 'svn' is perfectly happy to leave old
revisions in place that might have been moved elsewhere. Here it is
doing a finely confusing job on the old 'dol' which now lives in
deployment/:

lloyd$ pwd
/v3/code/common

lloyd$ svn up dol
At revision 21030.

Of course, no one can know that "revision 21030" is actually
irrelevant to the current build--yikes.

The reason this caused me a problem is that as part of my setup, I
unjar the web distribution. But I then *also* copy various jars from
my build, including doing this:

$COPY common/*/target/*.jar $V3_RUN_MODULES

...which copies common/dol/target/*.jar to the new install, thus
wiping out the current jar from deployment/dol.

Lloyd


On Jun 12, 2008, at 10:35 AM, Lloyd L Chambers wrote:

> Sahoo,
>
> You seem to be the Felix guy, so I'm hoping you can shed some light
> on it: I cannot start the server due to a problem resolving the
> bundle for "org.glassfish.deployment.dol". Or at least that's how I
> interpret the message. See the startup log at the end of this
> message. The meaning of the message is not clear to me. It seems
> to be saying that it cannot resolve org.glassfish.deployment.dol,
> perhaps (unclear) it wants version 10.0.0.
>
> The chain of failure is also not clear. It appears that injection
> of AdminConsoleAdapter is failing because the
> org.glassfish.deployment.dol module cannot be loaded. But core/
> kernel (which includes AdminConsoleAdapter) has no dependency on
> org.glassfish.deployment.dol declared in its pom. Actually, the
> Felix messages are confusing; it's unclear *which* module it's
> describing; the one it's looking for or the one that can't find a
> dependency.
>
> This issue has existed since Tuesday for me. I've blown away the
> repo (twice), tried JDK 1.5 and 1.6, made sure the source is up to
> date (no changes), etc. I have previously sent a number of emails,
> with no help or response. I am on Mac OS X 10.5, Intel.
>
>
> VERSION MESS
>
> EXPORTING module deployment/dol pom.xml does not declare an explicit
> version. Does it therefore pick up its parent's version ("10.0-
> SNAPSHOT")?
> <parent>
> <groupId>org.glassfish.deployment</groupId>
> <artifactId>deployment</artifactId>
> <version>10.0-SNAPSHOT</version>
> </parent>
> <artifactId>dol</artifactId>
> <packaging>hk2-jar</packaging>
> <name>Deployment Object Library</name>
>
> IMPORTING modules use a variety of schemes for importing
> org.glassfish.deployment. It's not clear to me which actual
> versions are being used by these modules.
>
> - poms that require ${project.version}:
> common/container-common/pom.xml
> core/security/pom.xml
> deployment/javaee-core/pom.xml
> ejb/ejb-connector/pom.xml
> persistence/jpa-connector/pom.xml
> security/common/pom.xml
> security/realm/pom.xml
> security/webintegration/pom.xml
> web/webtier/pom.xml
> webservices/jsr109-impl/pom.xml
>
> <dependency>
> <groupId>org.glassfish.deployment</groupId>
> <artifactId>dol</artifactId>
> <version>${project.version}</version>
> </dependency>
>
> - poms that require version "10.0-SNAPSHOT":
> admin/runtime/jsr77/pom.xml
>
> <dependency>
> <groupId>org.glassfish.deployment</groupId>
> <artifactId>dol</artifactId>
> <version>10.0-SNAPSHOT</version>
> </dependency>
>
> - poms that require version "project.parent.version":
> connectors/connectors-runtime/pom.xml
> web/jsf-connector/pom.xml
>
> <dependency>
> <groupId>org.glassfish.deployment</groupId>
> <artifactId>dol</artifactId>
> <version>${project.parent.version}</version>
> </dependency
>
> Lloyd
>
> -----------------------
>
> Jun 12, 2008 9:40:49 AM
> com.sun.enterprise.admin.launcher.GFLauncherLogger info
> INFO: JVM invocation command line:
> /System/Library/Frameworks/JavaVM.framework/Versions/1.5.0/Home/bin/
> java
> -cp
> /v3/run/modules/glassfish-10.0-SNAPSHOT-sources.jar:/v3/run/modules/
> glassfish-10.0-SNAPSHOT.jar
> -XX:+UnlockDiagnosticVMOptions
> -XX:+LogVMOutput
> -XX:NewRatio=2
> -XX:LogFile=/v3/run/domains/domain1/logs/jvm.log
> -Xmx512m
> -client
> -Djava.ext.dirs=/System/Library/Frameworks/JavaVM.framework/Versions/
> 1.5.0/Home/lib/ext:/System/Library/Frameworks/JavaVM.framework/
> Versions/1.5.0/Home/jre/lib/ext:/v3/run/domains/domain1/lib/ext:/v3/
> run/javadb/lib
> -Djava.security.policy=/v3/run/domains/domain1/config/server.policy
> -Djdbc.drivers=org.apache.derby.jdbc.ClientDriver
> -Djava.endorsed.dirs=/v3/run/lib/endorsed
> -
> Dcom
> .sun
> .enterprise
> .config
> .config_environment_factory_class
> =
> com
> .sun.enterprise.config.serverbeans.AppserverConfigEnvironmentFactory
> -Djavax.net.ssl.trustStore=/v3/run/domains/domain1/config/cacerts.jks
> -Djavax.net.ssl.keyStore=/v3/run/domains/domain1/config/keystore.jks
> -Dsun.rmi.dgc.server.gcInterval=3600000
> -Dsun.rmi.dgc.client.gcInterval=3600000
> -Djava.security.auth.login.config=/v3/run/domains/domain1/config/
> login.conf
> com.sun.enterprise.glassfish.bootstrap.ASMain
> -debug
> false
> -domaindir
> /v3/run/domains/domain1
> -instancename
> server
> -verbose
> true
> -domainname
> domain1
> Jun 12, 2008 9:40:49 AM
> com.sun.enterprise.admin.launcher.GFLauncherLogger info
> INFO: Successfully launched in 143 msec.
> Jun 12, 2008 9:40:49 AM
> com.sun.enterprise.glassfish.bootstrap.ASMain main
> INFO: Launching GlassFish on Apache Felix OSGi platform
> Jun 12, 2008 9:40:49 AM
> com.sun.enterprise.glassfish.bootstrap.ASMainOSGi getSharedRepos
> INFO: /v3/run/domains/domain1/lib does not exist
>
> Welcome to Felix.
> =================
>
> Jun 12, 2008 9:40:49 AM HK2Main start
> INFO: contextRootDir = /v3/run/modules
> Jun 12, 2008 9:40:49 AM OSGiFactoryImpl initialize
> INFO: Singleton already initialized as
> com.sun.enterprise.module.impl.HK2Factory_at_871e65
> Jun 12, 2008 9:40:51 AM OSGiModuleImpl loadClass
> INFO: Started bundle org.glassfish.core.kernel [19]
> Jun 12, 2008 9:40:51 AM OSGiModuleImpl loadClass
> INFO: Started bundle org.glassfish.common.glassfish-mbeanserver [45]
> Jun 12, 2008 9:40:51 AM OSGiModuleImpl loadClass
> INFO: Started bundle org.glassfish.common.glassfish-naming [46]
> Jun 12, 2008 9:40:51 AM OSGiModuleImpl loadClass
> INFO: Started bundle org.glassfish.admin.config-api [49]
> Jun 12, 2008 9:40:51 AM OSGiModuleImpl loadClass
> INFO: Started bundle org.glassfish.common.internal-api [36]
> Jun 12, 2008 9:40:51 AM OSGiModuleImpl loadClass
> INFO: Started bundle org.glassfish.deployment.deployment-common [21]
> Jun 12, 2008 9:40:51 AM
> INFO: JMXMP connector server URL = service:jmx:jmxmp://localhost:8888
> Jun 12, 2008 9:40:51 AM
> com.sun.enterprise.v3.services.impl.GrizzlyProxy start
> INFO: Listening on port 8080
> Jun 12, 2008 9:40:51 AM
> com.sun.enterprise.v3.services.impl.GrizzlyProxy start
> INFO: Listening on port 8181
> Jun 12, 2008 9:40:51 AM
> com.sun.enterprise.v3.services.impl.GrizzlyProxy start
> INFO: Listening on port 4848
> Jun 12, 2008 9:40:51 AM
> INFO: ERROR: Error starting file:/v3/run//modules/osgi-
> adapter-0.3.2.jar (org.osgi.framework.BundleException: Activator
> start error.)
> Jun 12, 2008 9:40:51 AM
> SEVERE: java.lang.LinkageError: Failed to inject class
> com.sun.enterprise.v3.admin.adapter.AdminConsoleAdapter from 19.0
> Jun 12, 2008 9:40:51 AM
> SEVERE: at
> org
> .jvnet.hk2.component.InjectionManager.inject(InjectionManager.java:
> 156)
> Jun 12, 2008 9:40:51 AM
> SEVERE: at
> com.sun.hk2.component.AbstractWombImpl.inject(AbstractWombImpl.java:
> 100)
> Jun 12, 2008 9:40:51 AM
> SEVERE: at
> com
> .sun.hk2.component.ConstructorWomb.initialize(ConstructorWomb.java:86)
> Jun 12, 2008 9:40:51 AM
> SEVERE: at
> com.sun.hk2.component.AbstractWombImpl.get(AbstractWombImpl.java:75)
> Jun 12, 2008 9:40:51 AM
> SEVERE: at
> com
> .sun.hk2.component.SingletonInhabitant.get(SingletonInhabitant.java:
> 58)
> Jun 12, 2008 9:40:51 AM
> SEVERE: at
> com.sun.hk2.component.LazyInhabitant.get(LazyInhabitant.java:107)
> Jun 12, 2008 9:40:51 AM
> SEVERE: at
> com
> .sun
> .hk2
> .component.AbstractInhabitantImpl.get(AbstractInhabitantImpl.java:60)
> Jun 12, 2008 9:40:51 AM
> SEVERE: at org.jvnet.hk2.component.Habitat$1.get(Habitat.java:229)
> Jun 12, 2008 9:40:51 AM
> SEVERE: at java.util.AbstractList$Itr.next(AbstractList.java:422)
> Jun 12, 2008 9:40:51 AM
> SEVERE: at
> com
> .sun
> .enterprise
> .v3.services.impl.GrizzlyService.postConstruct(GrizzlyService.java:
> 116)
> Jun 12, 2008 9:40:51 AM
> SEVERE: at
> com.sun.hk2.component.AbstractWombImpl.inject(AbstractWombImpl.java:
> 150)
> Jun 12, 2008 9:40:51 AM
> SEVERE: at
> com
> .sun.hk2.component.ConstructorWomb.initialize(ConstructorWomb.java:86)
> Jun 12, 2008 9:40:51 AM
> SEVERE: at
> com.sun.hk2.component.AbstractWombImpl.get(AbstractWombImpl.java:75)
> Jun 12, 2008 9:40:51 AM
> SEVERE: at
> com
> .sun.hk2.component.SingletonInhabitant.get(SingletonInhabitant.java:
> 58)
> Jun 12, 2008 9:40:51 AM
> SEVERE: at
> com.sun.hk2.component.LazyInhabitant.get(LazyInhabitant.java:107)
> Jun 12, 2008 9:40:51 AM
> SEVERE: at
> com
> .sun
> .hk2
> .component.AbstractInhabitantImpl.get(AbstractInhabitantImpl.java:60)
> Jun 12, 2008 9:40:51 AM
> SEVERE: at org.jvnet.hk2.component.Habitat.getBy(Habitat.java:504)
> Jun 12, 2008 9:40:51 AM
> SEVERE: at org.jvnet.hk2.component.Habitat.getByType(Habitat.java:
> 485)
> Jun 12, 2008 9:40:51 AM
> SEVERE: at
> org.jvnet.hk2.component.Habitat.getComponent(Habitat.java:294)
> Jun 12, 2008 9:40:51 AM
> SEVERE: at
> com
> .sun
> .enterprise
> .v3
> .server
> .ApplicationLoaderInjector
> .postConstruct(ApplicationLoaderInjector.java:49)
> Jun 12, 2008 9:40:51 AM
> SEVERE: at
> com.sun.hk2.component.AbstractWombImpl.inject(AbstractWombImpl.java:
> 150)
> Jun 12, 2008 9:40:51 AM
> SEVERE: at
> com
> .sun.hk2.component.ConstructorWomb.initialize(ConstructorWomb.java:86)
> Jun 12, 2008 9:40:51 AM
> SEVERE: at
> com.sun.hk2.component.AbstractWombImpl.get(AbstractWombImpl.java:75)
> Jun 12, 2008 9:40:51 AM
> SEVERE: at
> com
> .sun.hk2.component.SingletonInhabitant.get(SingletonInhabitant.java:
> 58)
> Jun 12, 2008 9:40:51 AM
> SEVERE: at
> com.sun.hk2.component.LazyInhabitant.get(LazyInhabitant.java:107)
> Jun 12, 2008 9:40:51 AM
> SEVERE: at
> com
> .sun
> .hk2
> .component.AbstractInhabitantImpl.get(AbstractInhabitantImpl.java:60)
> Jun 12, 2008 9:40:51 AM
> SEVERE: at
> com
> .sun.enterprise.v3.server.AppServerStartup.run(AppServerStartup.java:
> 123)
> Jun 12, 2008 9:40:51 AM
> SEVERE: at
> com.sun.enterprise.module.bootstrap.Main.launch(Main.java:431)
> Jun 12, 2008 9:40:51 AM
> SEVERE: at
> com.sun.enterprise.module.bootstrap.Main.launch(Main.java:376)
> Jun 12, 2008 9:40:51 AM
> SEVERE: at org.jvnet.hk2.osgiadapter.HK2Main.start(HK2Main.java:116)
> Jun 12, 2008 9:40:51 AM
> SEVERE: at
> org
> .apache
> .felix.framework.util.SecureAction.startActivator(SecureAction.java:
> 591)
> Jun 12, 2008 9:40:51 AM
> SEVERE: at org.apache.felix.framework.Felix._startBundle(Felix.java:
> 1610)
> Jun 12, 2008 9:40:51 AM
> SEVERE: at org.apache.felix.framework.Felix.startBundle(Felix.java:
> 1544)
> Jun 12, 2008 9:40:51 AM
> SEVERE: at
> org.apache.felix.framework.Felix.setFrameworkStartLevel(Felix.java:
> 1125)
> Jun 12, 2008 9:40:51 AM
> SEVERE: at
> org.apache.felix.framework.StartLevelImpl.run(StartLevelImpl.java:258)
> Jun 12, 2008 9:40:51 AM
> SEVERE: at java.lang.Thread.run(Thread.java:613)
> Jun 12, 2008 9:40:51 AM
> SEVERE: Caused by: com.sun.enterprise.module.ResolveError: Failed to
> start org.glassfish.common:container-common:1.0
> Jun 12, 2008 9:40:51 AM
> SEVERE: at
> org.jvnet.hk2.osgiadapter.OSGiModuleImpl.resolve(OSGiModuleImpl.java:
> 112)
> Jun 12, 2008 9:40:51 AM
> SEVERE: at
> org.jvnet.hk2.osgiadapter.OSGiModuleImpl.start(OSGiModuleImpl.java:
> 121)
> Jun 12, 2008 9:40:51 AM
> SEVERE: at org.jvnet.hk2.osgiadapter.OSGiModuleImpl
> $1$1.loadClass(OSGiModuleImpl.java:256)
> Jun 12, 2008 9:40:51 AM
> SEVERE: at
> com.sun.hk2.component.LazyInhabitant.fetch(LazyInhabitant.java:91)
> Jun 12, 2008 9:40:51 AM
> SEVERE: at
> com.sun.hk2.component.LazyInhabitant.get(LazyInhabitant.java:106)
> Jun 12, 2008 9:40:51 AM
> SEVERE: at
> com
> .sun
> .hk2
> .component.AbstractInhabitantImpl.get(AbstractInhabitantImpl.java:60)
> Jun 12, 2008 9:40:51 AM
> SEVERE: at
> org.jvnet.hk2.component.Habitat.getComponent(Habitat.java:312)
> Jun 12, 2008 9:40:51 AM
> SEVERE: at com.sun.hk2.component.AbstractWombImpl
> $1.getValue(AbstractWombImpl.java:122)
> Jun 12, 2008 9:40:51 AM
> SEVERE: at
> org
> .jvnet.hk2.component.InjectionManager.inject(InjectionManager.java:79)
> Jun 12, 2008 9:40:51 AM
> SEVERE: ... 35 more
> Jun 12, 2008 9:40:51 AM
> SEVERE: Caused by: org.osgi.framework.BundleException: Unresolved
> package in bundle 40: module; (&(bundle-symbolic-
> name=org.glassfish.deployment.dol)(bundle-version>=10.0.0.SNAPSHOT)
> (bundle-version<=10.0.0.SNAPSHOT))
> Jun 12, 2008 9:40:51 AM
> SEVERE: at
> org.apache.felix.framework.Felix._resolveBundle(Felix.java:1728)
> Jun 12, 2008 9:40:51 AM
> SEVERE: at org.apache.felix.framework.Felix._startBundle(Felix.java:
> 1591)
> Jun 12, 2008 9:40:51 AM
> SEVERE: at org.apache.felix.framework.Felix.startBundle(Felix.java:
> 1544)
> Jun 12, 2008 9:40:51 AM
> SEVERE: at
> org.apache.felix.framework.BundleImpl.start(BundleImpl.java:371)
> Jun 12, 2008 9:40:51 AM
> SEVERE: at
> org.jvnet.hk2.osgiadapter.OSGiModuleImpl.resolve(OSGiModuleImpl.java:
> 109)
> Jun 12, 2008 9:40:51 AM
> SEVERE: ... 43 more
> Jun 12, 2008 9:40:51 AM
> com.sun.enterprise.glassfish.bootstrap.ASMainFelix launchOSGiFW
> INFO: Framework successfully started
>
>
> ---
> Lloyd L Chambers
> lloyd.chambers_at_sun.com
> Sun Microsystems, Inc
>
>
>

---
Lloyd L Chambers
lloyd.chambers_at_sun.com
Sun Microsystems, Inc