Workaround:
----------
Run the following command so that the admin console does not start as part of server start up. Let it start when user explicitly accesses it:
asadmin set configs.config.server-config.admin-service.property.adminConsoleStartup=NEVER

Description

Exceptions are found in server.log when trying to open the OSGi console:

[#|2012-07-03T11:05:16.195-0400|SEVERE|glassfish3.1.1|javax.enterprise.system.core.com.sun.enterprise.v3.server|_ThreadID=17;_ThreadName=Thread-2;|Failed to start Bundle Id [329] State [RESOLVED][org.glassfish.admingui.glassfish-osgi-console-plugin(Glassfish OSGI Console Plugin):3.1.1]
com.sun.enterprise.module.ResolveError: Failed to start Bundle Id [329] State [RESOLVED][org.glassfish.admingui.glassfish-osgi-console-plugin(Glassfish OSGI Console Plugin):3.1.1]
at org.jvnet.hk2.osgiadapter.OSGiModuleImpl.start(OSGiModuleImpl.java:177)
at org.jvnet.hk2.osgiadapter.OSGiModuleImpl$2$1$1.loadClass(OSGiModuleImpl.java:344)
at com.sun.hk2.component.LazyInhabitant.loadClass(LazyInhabitant.java:124)
at com.sun.hk2.component.LazyInhabitant.fetch(LazyInhabitant.java:111)
at com.sun.hk2.component.EventPublishingInhabitant.get(EventPublishingInhabitant.java:135)
at com.sun.hk2.component.AbstractInhabitantImpl.get(AbstractInhabitantImpl.java:76)
at com.sun.enterprise.v3.server.ClassLoaderHierarchyImpl.createApplicationParentCL(ClassLoaderHierarchyImpl.java:200)
at org.glassfish.deployment.common.DeploymentContextImpl.createClassLoader(DeploymentContextImpl.java:213)
at org.glassfish.deployment.common.DeploymentContextImpl.createDeploymentClassLoader(DeploymentContextImpl.java:198)
at com.sun.enterprise.v3.server.ApplicationLifecycle.deploy(ApplicationLifecycle.java:346)
at com.sun.enterprise.v3.server.ApplicationLoaderService.processApplication(ApplicationLoaderService.java:375)
at com.sun.enterprise.v3.admin.adapter.InstallerThread.load(InstallerThread.java:210)
at com.sun.enterprise.v3.admin.adapter.InstallerThread.run(InstallerThread.java:108)

Caused by: org.osgi.framework.BundleException: Cannot start bundle org.glassfish.admingui.glassfish-osgi-console-plugin [329] because its start level is 2, which is greater than the framework's start level of 1.
at org.apache.felix.framework.Felix.startBundle(Felix.java:1698)
at org.apache.felix.framework.BundleImpl.start(BundleImpl.java:922)
at org.jvnet.hk2.osgiadapter.OSGiModuleImpl.start(OSGiModuleImpl.java:169)
... 12 more
---------------------------------------------------------------------------------------------------------------------------------

Activity

Have you modified the property called glassfish.osgi.start.level.final in glassfish/config/osgi.properties file? Could you check what's the value there?

Where is glassfish-osgi-console-plugin.jar installed? modules/autostart/ or autodeploy/bundles/? Can you try moving that glassfish-osgi-console-plugin.jar to modules/ dir and let me know whether it works? What might be happening is that adminconsole is coming up before the startlevel is reached to 2.

Sanjeeb Sahoo
added a comment - 10/Jul/12 3:16 PM Have you modified the property called glassfish.osgi.start.level.final in glassfish/config/osgi.properties file? Could you check what's the value there?
Where is glassfish-osgi-console-plugin.jar installed? modules/autostart/ or autodeploy/bundles/? Can you try moving that glassfish-osgi-console-plugin.jar to modules/ dir and let me know whether it works? What might be happening is that adminconsole is coming up before the startlevel is reached to 2.

LeoInside
added a comment - 11/Jul/12 12:05 PM Hi Sanjeeb,
Thank you very much for your quick reply..
I checked the property: glassfish.osgi.start.level.final=2..
and the jar file is under ./glassfish/modules/autostart/glassfish-osgi-console-plugin.jar
should I change the glassfish.osgi.start.level.final to "1" and move the jar file to ./glassfish/modules ?..
Best Regards.

Sanjeeb Sahoo
added a comment - 11/Jul/12 2:30 PM Copy the jar to modules/ and leave everything else unchanged. Restart server. It should work.
Could you also describe the exact steps to reproduce your original problem? That will help us analysing the issue as well as fixing the document if need be.
Thanks much,
Sahoo

cleciovarjao
added a comment - 26/Jul/12 9:51 PM - edited I am also having problems starting the webconsole. I was wondering if there have been any progress?
I just download glassfish-3.1.2.2.zip, start domain, and then install glassfish-osgi-gui component.

[#|2012-07-26T21:53:33.201-0700|SEVERE|glassfish3.1.2|javax.enterprise.system.container.web.com.sun.enterprise.web|_ThreadID=21;_ThreadName=Thread-2;|WEB0161: Error loading web module [__default-web-module]
java.lang.IllegalArgumentException: addChild: Child name '' is not unique
at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:911)
at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:901)
at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:733)
at com.sun.enterprise.web.WebContainer.loadWebModule(WebContainer.java:2019)
at com.sun.enterprise.web.WebContainer.loadStandaloneWebModule(WebContainer.java:1573)
at com.sun.enterprise.web.WebContainer.updateDocroot(WebContainer.java:3334)
at com.sun.enterprise.web.WebContainer.updateHost(WebContainer.java:2828)
at com.sun.enterprise.web.reconfig.WebConfigListener$1.changed(WebConfigListener.java:138)
at org.jvnet.hk2.config.ConfigSupport.sortAndDispatch(ConfigSupport.java:332)
at com.sun.enterprise.web.reconfig.WebConfigListener.changed(WebConfigListener.java:114)
at org.jvnet.hk2.config.Transactions$ConfigListenerJob.process(Transactions.java:401)
at org.jvnet.hk2.config.Transactions$ConfigListenerJob.process(Transactions.java:391)
at org.jvnet.hk2.config.Transactions$ConfigListenerNotifier$1$1.call(Transactions.java:281)
at org.jvnet.hk2.config.Transactions$ConfigListenerNotifier$1$1.call(Transactions.java:279)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)

[#|2012-07-26T21:53:47.615-0700|SEVERE|glassfish3.1.2|javax.enterprise.resource.webcontainer.jsf.config|_ThreadID=17;_ThreadName=Thread-2;|Critical error during deployment:
com.sun.faces.config.ConfigurationException: java.util.concurrent.ExecutionException: java.net.MalformedURLException: Unknown protocol: jndi
at com.sun.faces.config.ConfigManager.getConfigDocuments(ConfigManager.java:672)
at com.sun.faces.config.ConfigManager.initialize(ConfigManager.java:322)
at com.sun.faces.config.ConfigureListener.contextInitialized(ConfigureListener.java:225)
at org.apache.catalina.core.StandardContext.contextListenerStart(StandardContext.java:4750)
at com.sun.enterprise.web.WebModule.contextListenerStart(WebModule.java:550)
at org.apache.catalina.core.StandardContext.start(StandardContext.java:5366)
at com.sun.enterprise.web.WebModule.start(WebModule.java:498)
at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:917)
at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:901)
at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:733)
at com.sun.enterprise.web.WebContainer.loadWebModule(WebContainer.java:2019)
at com.sun.enterprise.web.WebContainer.loadWebModule(WebContainer.java:1669)
at com.sun.enterprise.web.WebApplication.start(WebApplication.java:109)
at org.glassfish.internal.data.EngineRef.start(EngineRef.java:130)
at org.glassfish.internal.data.ModuleInfo.start(ModuleInfo.java:269)
at org.glassfish.internal.data.ApplicationInfo.start(ApplicationInfo.java:301)
at com.sun.enterprise.v3.server.ApplicationLifecycle.deploy(ApplicationLifecycle.java:461)
at com.sun.enterprise.v3.server.ApplicationLoaderService.processApplication(ApplicationLoaderService.java:375)
at com.sun.enterprise.v3.admin.adapter.InstallerThread.load(InstallerThread.java:210)
at com.sun.enterprise.v3.admin.adapter.InstallerThread.run(InstallerThread.java:108)
Caused by: java.util.concurrent.ExecutionException: java.net.MalformedURLException: Unknown protocol: jndi
at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:222)
at java.util.concurrent.FutureTask.get(FutureTask.java:83)
at com.sun.faces.config.ConfigManager.getConfigDocuments(ConfigManager.java:670)
... 19 more
Caused by: java.net.MalformedURLException: Unknown protocol: jndi
at java.net.URL.<init>(URL.java:601)
at java.net.URL.<init>(URL.java:464)
at java.net.URL.<init>(URL.java:413)
at java.net.URI.toURL(URI.java:1081)
at com.sun.faces.config.ConfigManager$ParseTask.call(ConfigManager.java:920)
at com.sun.faces.config.ConfigManager$ParseTask.call(ConfigManager.java:865)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at com.sun.faces.config.ConfigManager.getConfigDocuments(ConfigManager.java:656)
... 19 more

#]

[#|2012-07-26T21:53:47.641-0700|SEVERE|glassfish3.1.2|org.apache.catalina.core.StandardContext|_ThreadID=17;_ThreadName=Thread-2;|PWC1306: Startup of context failed due to previous errors|#]

[#|2012-07-26T21:53:47.646-0700|SEVERE|glassfish3.1.2|org.apache.catalina.core.StandardContext|_ThreadID=17;_ThreadName=Thread-2;|PWC1305: Exception during cleanup after start failed
org.apache.catalina.LifecycleException: PWC2769: Manager has not yet been started
at org.apache.catalina.session.StandardManager.stop(StandardManager.java:873)
at org.apache.catalina.core.StandardContext.stop(StandardContext.java:5571)
at com.sun.enterprise.web.WebModule.stop(WebModule.java:527)
at org.apache.catalina.core.StandardContext.start(StandardContext.java:5384)
at com.sun.enterprise.web.WebModule.start(WebModule.java:498)
at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:917)
at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:901)
at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:733)
at com.sun.enterprise.web.WebContainer.loadWebModule(WebContainer.java:2019)
at com.sun.enterprise.web.WebContainer.loadWebModule(WebContainer.java:1669)
at com.sun.enterprise.web.WebApplication.start(WebApplication.java:109)
at org.glassfish.internal.data.EngineRef.start(EngineRef.java:130)
at org.glassfish.internal.data.ModuleInfo.start(ModuleInfo.java:269)
at org.glassfish.internal.data.ApplicationInfo.start(ApplicationInfo.java:301)
at com.sun.enterprise.v3.server.ApplicationLifecycle.deploy(ApplicationLifecycle.java:461)
at com.sun.enterprise.v3.server.ApplicationLoaderService.processApplication(ApplicationLoaderService.java:375)
at com.sun.enterprise.v3.admin.adapter.InstallerThread.load(InstallerThread.java:210)
at com.sun.enterprise.v3.admin.adapter.InstallerThread.run(InstallerThread.java:108)

#]

[#|2012-07-26T21:53:47.647-0700|SEVERE|glassfish3.1.2|org.apache.catalina.core.ContainerBase|_ThreadID=17;_ThreadName=Thread-2;|ContainerBase.addChild: start:
org.apache.catalina.LifecycleException: java.lang.RuntimeException: com.sun.faces.config.ConfigurationException: java.util.concurrent.ExecutionException: java.net.MalformedURLException: Unknown protocol: jndi
at org.apache.catalina.core.StandardContext.start(StandardContext.java:5389)
at com.sun.enterprise.web.WebModule.start(WebModule.java:498)
at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:917)
at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:901)
at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:733)
at com.sun.enterprise.web.WebContainer.loadWebModule(WebContainer.java:2019)
at com.sun.enterprise.web.WebContainer.loadWebModule(WebContainer.java:1669)
at com.sun.enterprise.web.WebApplication.start(WebApplication.java:109)
at org.glassfish.internal.data.EngineRef.start(EngineRef.java:130)
at org.glassfish.internal.data.ModuleInfo.start(ModuleInfo.java:269)
at org.glassfish.internal.data.ApplicationInfo.start(ApplicationInfo.java:301)
at com.sun.enterprise.v3.server.ApplicationLifecycle.deploy(ApplicationLifecycle.java:461)
at com.sun.enterprise.v3.server.ApplicationLoaderService.processApplication(ApplicationLoaderService.java:375)
at com.sun.enterprise.v3.admin.adapter.InstallerThread.load(InstallerThread.java:210)
at com.sun.enterprise.v3.admin.adapter.InstallerThread.run(InstallerThread.java:108)
Caused by: java.lang.RuntimeException: com.sun.faces.config.ConfigurationException: java.util.concurrent.ExecutionException: java.net.MalformedURLException: Unknown protocol: jndi
at com.sun.faces.config.ConfigureListener.contextInitialized(ConfigureListener.java:292)
at org.apache.catalina.core.StandardContext.contextListenerStart(StandardContext.java:4750)
at com.sun.enterprise.web.WebModule.contextListenerStart(WebModule.java:550)
at org.apache.catalina.core.StandardContext.start(StandardContext.java:5366)
... 14 more
Caused by: com.sun.faces.config.ConfigurationException: java.util.concurrent.ExecutionException: java.net.MalformedURLException: Unknown protocol: jndi
at com.sun.faces.config.ConfigManager.getConfigDocuments(ConfigManager.java:672)
at com.sun.faces.config.ConfigManager.initialize(ConfigManager.java:322)
at com.sun.faces.config.ConfigureListener.contextInitialized(ConfigureListener.java:225)
... 17 more
Caused by: java.util.concurrent.ExecutionException: java.net.MalformedURLException: Unknown protocol: jndi
at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:222)
at java.util.concurrent.FutureTask.get(FutureTask.java:83)
at com.sun.faces.config.ConfigManager.getConfigDocuments(ConfigManager.java:670)
... 19 more
Caused by: java.net.MalformedURLException: Unknown protocol: jndi
at java.net.URL.<init>(URL.java:601)
at java.net.URL.<init>(URL.java:464)
at java.net.URL.<init>(URL.java:413)
at java.net.URI.toURL(URI.java:1081)
at com.sun.faces.config.ConfigManager$ParseTask.call(ConfigManager.java:920)
at com.sun.faces.config.ConfigManager$ParseTask.call(ConfigManager.java:865)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at com.sun.faces.config.ConfigManager.getConfigDocuments(ConfigManager.java:656)
... 19 more

Enough. I want to get to the bottom of this problem for good. Could you please document clearly the steps to reproduce both the problems? I will give it a try next week and am sure can find out what's going on. Thanks much. Pl. include all the URLs you used to download the stuff and how you installed any extra stuff, etc.

Sanjeeb Sahoo
added a comment - 27/Jul/12 5:37 AM Enough. I want to get to the bottom of this problem for good. Could you please document clearly the steps to reproduce both the problems? I will give it a try next week and am sure can find out what's going on. Thanks much. Pl. include all the URLs you used to download the stuff and how you installed any extra stuff, etc.

marcond
added a comment - 03/Aug/12 9:39 PM This issue is confirmed on GF 3.1.2.2 running on Ubuntu 12.04 64 bits, install done with glassfish-3.1.2.2-web-unix.sh.
Steps: Plain vanilla install (next-next-finish); update tool enabled; install glassfish-osgi-gui. Restart server. Bang!
The workaround solves the problem, though I had to wipe osgi-cache. I also had an Unknown protocol error in one point, but I wasn't able to track how to reproduce it.
You can count on me to apply any other tests. Thanks.

Even after applying the workaround, it happens on about 30% of the start-domain sequences, breaking the Glassfish admin console. It appears to be some race condition between the bundles. It occurs on a clean Glassfish install, after the glassfish-osgi-gui install. Aside from the glassfish-osgi-gui install, the GF server is absolutely untouched, without any changes. The hardware I used for these tests is a Core2 Duo, 2.6GHz (Ubuntu 12.04, described earlier).

[#|2012-08-03T21:26:46.286-0300|SEVERE|glassfish3.1.2|javax.enterprise.resource.webcontainer.jsf.config|_ThreadID=43;_ThreadName=Thread-2;|Critical error during deployment:
com.sun.faces.config.ConfigurationException: java.util.concurrent.ExecutionException: java.net.MalformedURLException: Unknown protocol: jndi
at com.sun.faces.config.ConfigManager.getConfigDocuments(ConfigManager.java:672)
at com.sun.faces.config.ConfigManager.initialize(ConfigManager.java:322)
at com.sun.faces.config.ConfigureListener.contextInitialized(ConfigureListener.java:225)
at org.apache.catalina.core.StandardContext.contextListenerStart(StandardContext.java:4750)
at com.sun.enterprise.web.WebModule.contextListenerStart(WebModule.java:550)
at org.apache.catalina.core.StandardContext.start(StandardContext.java:5366)
at com.sun.enterprise.web.WebModule.start(WebModule.java:498)
at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:917)
at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:901)
at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:733)
at com.sun.enterprise.web.WebContainer.loadWebModule(WebContainer.java:2019)
at com.sun.enterprise.web.WebContainer.loadWebModule(WebContainer.java:1669)
at com.sun.enterprise.web.WebApplication.start(WebApplication.java:109)
at org.glassfish.internal.data.EngineRef.start(EngineRef.java:130)
at org.glassfish.internal.data.ModuleInfo.start(ModuleInfo.java:269)
at org.glassfish.internal.data.ApplicationInfo.start(ApplicationInfo.java:301)
at com.sun.enterprise.v3.server.ApplicationLifecycle.deploy(ApplicationLifecycle.java:461)
at com.sun.enterprise.v3.server.ApplicationLoaderService.processApplication(ApplicationLoaderService.java:375)
at com.sun.enterprise.v3.admin.adapter.InstallerThread.load(InstallerThread.java:210)
at com.sun.enterprise.v3.admin.adapter.InstallerThread.run(InstallerThread.java:108)
Caused by: java.util.concurrent.ExecutionException: java.net.MalformedURLException: Unknown protocol: jndi
at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:252)
at java.util.concurrent.FutureTask.get(FutureTask.java:111)
at com.sun.faces.config.ConfigManager.getConfigDocuments(ConfigManager.java:670)
... 19 more
Caused by: java.net.MalformedURLException: Unknown protocol: jndi
at java.net.URL.<init>(URL.java:617)
at java.net.URL.<init>(URL.java:480)
at java.net.URL.<init>(URL.java:429)
at java.net.URI.toURL(URI.java:1096)
at com.sun.faces.config.ConfigManager$ParseTask.call(ConfigManager.java:920)
at com.sun.faces.config.ConfigManager$ParseTask.call(ConfigManager.java:865)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
at java.util.concurrent.FutureTask.run(FutureTask.java:166)
at com.sun.faces.config.ConfigManager.getConfigDocuments(ConfigManager.java:656)
... 19 more
Caused by: java.lang.IllegalStateException: Unknown protocol: jndi
at org.apache.felix.framework.URLHandlersStreamHandlerProxy.parseURL(URLHandlersStreamHandlerProxy.java:372)
at java.net.URL.<init>(URL.java:612)
... 27 more

#]

[#|2012-08-03T21:26:46.306-0300|SEVERE|glassfish3.1.2|org.apache.catalina.core.StandardContext|_ThreadID=43;_ThreadName=Thread-2;|PWC1306: Startup of context failed due to previous errors|#]

marcond
added a comment - 04/Aug/12 12:49 AM - edited I've managed to spot the spurious java.net.MalformedURLException: Unknown protocol: jndi.
Even after applying the workaround, it happens on about 30% of the start-domain sequences, breaking the Glassfish admin console . It appears to be some race condition between the bundles. It occurs on a clean Glassfish install, after the glassfish-osgi-gui install. Aside from the glassfish-osgi-gui install, the GF server is absolutely untouched, without any changes. The hardware I used for these tests is a Core2 Duo, 2.6GHz (Ubuntu 12.04, described earlier).
To reproduce the problem:
1) Make a standard install of Glassfish 3.1.2.2;
2) Start domain1
3) Install glassfish-osgi-gui using the GF gui ( http://localhost:4848/ );
4) ./asadmin stop-domain domain1
5) ./asadmin start-domain domain1 => Error
6) ./asadmin stop-domain domain1
7) Apply workaround: mv ./glassfish/modules/autostart/glassfish-osgi-console-plugin.jar to ./glassfish/modules/)
8) ./asadmin start-domain domain1 => Everything looks fine...
9) ./asadmin stop-domain domain1
10) ./adasmin start-domain domain1 => Now we get the exception 30% of the times we do this start-domain, just repeat steps 9 and 10.
The exception:
[#|2012-08-03T21:26:45.244-0300|INFO|glassfish3.1.2|javax.enterprise.resource.webcontainer.jsf.config|_ThreadID=43;_ThreadName=Thread-2;|Initializing Mojarra 2.1.6 (SNAPSHOT 20111206) for context ''|#]
[#|2012-08-03T21:26:46.286-0300|SEVERE|glassfish3.1.2|javax.enterprise.resource.webcontainer.jsf.config|_ThreadID=43;_ThreadName=Thread-2;|Critical error during deployment:
com.sun.faces.config.ConfigurationException: java.util.concurrent.ExecutionException: java.net.MalformedURLException: Unknown protocol: jndi
at com.sun.faces.config.ConfigManager.getConfigDocuments(ConfigManager.java:672)
at com.sun.faces.config.ConfigManager.initialize(ConfigManager.java:322)
at com.sun.faces.config.ConfigureListener.contextInitialized(ConfigureListener.java:225)
at org.apache.catalina.core.StandardContext.contextListenerStart(StandardContext.java:4750)
at com.sun.enterprise.web.WebModule.contextListenerStart(WebModule.java:550)
at org.apache.catalina.core.StandardContext.start(StandardContext.java:5366)
at com.sun.enterprise.web.WebModule.start(WebModule.java:498)
at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:917)
at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:901)
at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:733)
at com.sun.enterprise.web.WebContainer.loadWebModule(WebContainer.java:2019)
at com.sun.enterprise.web.WebContainer.loadWebModule(WebContainer.java:1669)
at com.sun.enterprise.web.WebApplication.start(WebApplication.java:109)
at org.glassfish.internal.data.EngineRef.start(EngineRef.java:130)
at org.glassfish.internal.data.ModuleInfo.start(ModuleInfo.java:269)
at org.glassfish.internal.data.ApplicationInfo.start(ApplicationInfo.java:301)
at com.sun.enterprise.v3.server.ApplicationLifecycle.deploy(ApplicationLifecycle.java:461)
at com.sun.enterprise.v3.server.ApplicationLoaderService.processApplication(ApplicationLoaderService.java:375)
at com.sun.enterprise.v3.admin.adapter.InstallerThread.load(InstallerThread.java:210)
at com.sun.enterprise.v3.admin.adapter.InstallerThread.run(InstallerThread.java:108)
Caused by: java.util.concurrent.ExecutionException: java.net.MalformedURLException: Unknown protocol: jndi
at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:252)
at java.util.concurrent.FutureTask.get(FutureTask.java:111)
at com.sun.faces.config.ConfigManager.getConfigDocuments(ConfigManager.java:670)
... 19 more
Caused by: java.net.MalformedURLException: Unknown protocol: jndi
at java.net.URL.<init>(URL.java:617)
at java.net.URL.<init>(URL.java:480)
at java.net.URL.<init>(URL.java:429)
at java.net.URI.toURL(URI.java:1096)
at com.sun.faces.config.ConfigManager$ParseTask.call(ConfigManager.java:920)
at com.sun.faces.config.ConfigManager$ParseTask.call(ConfigManager.java:865)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
at java.util.concurrent.FutureTask.run(FutureTask.java:166)
at com.sun.faces.config.ConfigManager.getConfigDocuments(ConfigManager.java:656)
... 19 more
Caused by: java.lang.IllegalStateException: Unknown protocol: jndi
at org.apache.felix.framework.URLHandlersStreamHandlerProxy.parseURL(URLHandlersStreamHandlerProxy.java:372)
at java.net.URL.<init>(URL.java:612)
... 27 more
#]
[#|2012-08-03T21:26:46.306-0300|SEVERE|glassfish3.1.2|org.apache.catalina.core.StandardContext|_ThreadID=43;_ThreadName=Thread-2;|PWC1306: Startup of context failed due to previous errors|#]

Thanks marcond's steps and I have reproduced the problem ("Unknown protocol: jndi") on marcond's steps 9 and what LeoInside said on description also happened on marcond's steps 5(" ./asadmin start-domain domain1 => Error") , and using workaround can make effect.

In addition, my env is windows xp, jdk 1.6, and gf 3.1.2.2.

So, we will confirm it on current gf trunk.

sahoo, once I confirmed that the problem still happened on current gf trunk, then, I suggest that:

1) close the issue because titile is not related to the problem
2) I will re-create the problem ("Unknown protocol: jndi")

TangYong
added a comment - 15/Oct/12 3:09 AM Thanks marcond's steps and I have reproduced the problem ("Unknown protocol: jndi") on marcond's steps 9 and what LeoInside said on description also happened on marcond's steps 5(" ./asadmin start-domain domain1 => Error") , and using workaround can make effect.
In addition, my env is windows xp, jdk 1.6, and gf 3.1.2.2.
So, we will confirm it on current gf trunk.
sahoo, once I confirmed that the problem still happened on current gf trunk, then, I suggest that:
1) close the issue because titile is not related to the problem
2) I will re-create the problem ("Unknown protocol: jndi")
Agree with me?

The result of confirmation on current gf trunk is the problem ("Unknown protocol: jndi") can not be reproduced, in addition, on current gf trunk, under inner proxy, "Install glassfish-osgi-gui using the GF gui (http://localhost:4848/);" can not be installed successfully, so I manually copied glassfish-osgi-gui related bundles (as the same steps as possible) into autostart.

However, going back 3.1.2.2, the problem must be reproduced rather than 30%.

So, I want to ask sahoo whether needing to investigate the problem or not?

TangYong
added a comment - 15/Oct/12 3:59 AM The result of confirmation on current gf trunk is the problem ("Unknown protocol: jndi") can not be reproduced, in addition, on current gf trunk, under inner proxy, "Install glassfish-osgi-gui using the GF gui ( http://localhost:4848/ );" can not be installed successfully, so I manually copied glassfish-osgi-gui related bundles (as the same steps as possible) into autostart.
However, going back 3.1.2.2, the problem must be reproduced rather than 30%.
So, I want to ask sahoo whether needing to investigate the problem or not?

However, it would be very good to document how this bug was solved, or what was its nature.

While this "Unknown protocol: jndi" was reported regarding the OSGi Console, I added my feedback because this was the most reproducible case. Actually we had lots of this error on our OSGi application, enough to drop GF 3.1.2.x and go back to GF 3.1.1. However, it was not practical to open bug reports for these cases since the application is very complex and it would be really hard to describe how to reproduce the error.

Anyway, after two months I must say that GF 3.1.1 is rock-solid for all OSGi tasks we demanded until now, and was a safe fallback for GF 3.1.2.2 with OSGi problems.

marcond
added a comment - 15/Oct/12 4:38 AM So, this problem is solved on current GF trunk. This is good news.
However, it would be very good to document how this bug was solved, or what was its nature.
While this "Unknown protocol: jndi" was reported regarding the OSGi Console, I added my feedback because this was the most reproducible case. Actually we had lots of this error on our OSGi application, enough to drop GF 3.1.2.x and go back to GF 3.1.1. However, it was not practical to open bug reports for these cases since the application is very complex and it would be really hard to describe how to reproduce the error.
Anyway, after two months I must say that GF 3.1.1 is rock-solid for all OSGi tasks we demanded until now, and was a safe fallback for GF 3.1.2.2 with OSGi problems.
Thanks
Marcond

Although this problem did not happen on current GF trunk, I have been not still investigated the reason that this problem happened on 3.1.2.2 and now did not know its nature. There is a problem that must be confirmed :

On 3.1.2.2, whether because of glassfish-osgi-console-plugin.jar, the problem happened.

I will continue to keep trace the problem and also wait for sahoo's comments.

Thanks.

BTW:
> Actually we had lots of this error on our OSGi application, enough to drop GF 3.1.2.x and go back to GF 3.1.1.
I wish you can summary these problems if possible one by one and we need such use cases to improve quality.

TangYong
added a comment - 15/Oct/12 5:24 AM Although this problem did not happen on current GF trunk, I have been not still investigated the reason that this problem happened on 3.1.2.2 and now did not know its nature. There is a problem that must be confirmed :
On 3.1.2.2, whether because of glassfish-osgi-console-plugin.jar, the problem happened.
I will continue to keep trace the problem and also wait for sahoo's comments.
Thanks.
BTW:
> Actually we had lots of this error on our OSGi application, enough to drop GF 3.1.2.x and go back to GF 3.1.1.
I wish you can summary these problems if possible one by one and we need such use cases to improve quality.

A new finding and confirmation about the issue("Failed to start Bundle Id [329]State [RESOLVED][org.glassfish.admingui.glassfish-osgi-console-plugin(Glassfish OSGI Console Plugin)"):

I have made a compare on 3.1.2.2:

1) First executing http://localhost:4848/, then put "glassfish-osgi-console-plugin.jar","org.apache.felix.webconsole.jar" and "felix-webconsole-extension.jar" into autostart directory directly rather than using updatecenter using, the result of start-domain is exception still happen.

com.sun.enterprise.module.ResolveError: Failed to start Bundle Id [256] State [INSTALLED][org.glassfish.main.admingui.glassfish-osgi-console-plugin(Glassfish OSGI Console Plugin):3.1.2.1-SNAPSHOT]
at org.jvnet.hk2.osgiadapter.OSGiModuleImpl.start(OSGiModuleImpl.java:177)
at org.jvnet.hk2.osgiadapter.OSGiModuleImpl$2$1$1.loadClass(OSGiModuleImpl.java:344)
at com.sun.hk2.component.LazyInhabitant.loadClass(LazyInhabitant.java:124)
at com.sun.hk2.component.LazyInhabitant.fetch(LazyInhabitant.java:111)
at com.sun.hk2.component.EventPublishingInhabitant.get(EventPublishingInhabitant.java:135)
at com.sun.hk2.component.AbstractInhabitantImpl.get(AbstractInhabitantImpl.java:78)
at com.sun.enterprise.v3.server.ClassLoaderHierarchyImpl.createApplicationParentCL(ClassLoaderHierarchyImpl.java:200)
at org.glassfish.deployment.common.DeploymentContextImpl.createClassLoader(DeploymentContextImpl.java:216)
at org.glassfish.deployment.common.DeploymentContextImpl.createDeploymentClassLoader(DeploymentContextImpl.java:199)
at com.sun.enterprise.v3.server.ApplicationLifecycle.deploy(ApplicationLifecycle.java:346)
at com.sun.enterprise.v3.server.ApplicationLoaderService.processApplication(ApplicationLoaderService.java:375)
at com.sun.enterprise.v3.admin.adapter.InstallerThread.load(InstallerThread.java:210)
at com.sun.enterprise.v3.admin.adapter.InstallerThread.run(InstallerThread.java:108)
Caused by: org.osgi.framework.BundleException: Cannot start bundle org.glassfish.main.admingui.glassfish-osgi-console-plugin [256] because its start level is 2, which is greater than the framework's start level of 1.
at org.apache.felix.framework.Felix.startBundle(Felix.java:1807)
at org.apache.felix.framework.BundleImpl.start(BundleImpl.java:944)
at org.jvnet.hk2.osgiadapter.OSGiModuleImpl.start(OSGiModuleImpl.java:169)

2) Not executing http://localhost:4848/, then put "glassfish-osgi-console-plugin.jar","org.apache.felix.webconsole.jar" and "felix-webconsole-extension.jar" into autostart directory, the result of start-domain is that the above exception did not happen.

In addition, about the problem ("Unknown protocol: jndi"), based the above compare, if after 2), I moved "glassfish-osgi-console-plugin.jar" into module/ and start-domain, the problem ("Unknown protocol: jndi") did not happen.

So, I have confirmed that on 3.1.2.2, once executing http://localhost:4848/ (loading admingui) and putting gf-osgi-gui related bundles regardless of using updatecenter of copying directly, the issue and problem will happen.

I also want to know the reason executing 2) successfully not using Workaround .

TangYong
added a comment - 15/Oct/12 6:26 AM Sahoo,
We firstly look at the exception of "Failed to start Bundle Id [329] State [RESOLVED] [org.glassfish.admingui.glassfish-osgi-console-plugin(Glassfish OSGI Console Plugin)".
A new finding and confirmation about the issue("Failed to start Bundle Id [329] State [RESOLVED] [org.glassfish.admingui.glassfish-osgi-console-plugin(Glassfish OSGI Console Plugin)"):
I have made a compare on 3.1.2.2:
1) First executing http://localhost:4848/ , then put "glassfish-osgi-console-plugin.jar","org.apache.felix.webconsole.jar" and "felix-webconsole-extension.jar" into autostart directory directly rather than using updatecenter using, the result of start-domain is exception still happen.
com.sun.enterprise.module.ResolveError: Failed to start Bundle Id [256] State [INSTALLED] [org.glassfish.main.admingui.glassfish-osgi-console-plugin(Glassfish OSGI Console Plugin):3.1.2.1-SNAPSHOT]
at org.jvnet.hk2.osgiadapter.OSGiModuleImpl.start(OSGiModuleImpl.java:177)
at org.jvnet.hk2.osgiadapter.OSGiModuleImpl$2$1$1.loadClass(OSGiModuleImpl.java:344)
at com.sun.hk2.component.LazyInhabitant.loadClass(LazyInhabitant.java:124)
at com.sun.hk2.component.LazyInhabitant.fetch(LazyInhabitant.java:111)
at com.sun.hk2.component.EventPublishingInhabitant.get(EventPublishingInhabitant.java:135)
at com.sun.hk2.component.AbstractInhabitantImpl.get(AbstractInhabitantImpl.java:78)
at com.sun.enterprise.v3.server.ClassLoaderHierarchyImpl.createApplicationParentCL(ClassLoaderHierarchyImpl.java:200)
at org.glassfish.deployment.common.DeploymentContextImpl.createClassLoader(DeploymentContextImpl.java:216)
at org.glassfish.deployment.common.DeploymentContextImpl.createDeploymentClassLoader(DeploymentContextImpl.java:199)
at com.sun.enterprise.v3.server.ApplicationLifecycle.deploy(ApplicationLifecycle.java:346)
at com.sun.enterprise.v3.server.ApplicationLoaderService.processApplication(ApplicationLoaderService.java:375)
at com.sun.enterprise.v3.admin.adapter.InstallerThread.load(InstallerThread.java:210)
at com.sun.enterprise.v3.admin.adapter.InstallerThread.run(InstallerThread.java:108)
Caused by: org.osgi.framework.BundleException: Cannot start bundle org.glassfish.main.admingui.glassfish-osgi-console-plugin [256] because its start level is 2, which is greater than the framework's start level of 1.
at org.apache.felix.framework.Felix.startBundle(Felix.java:1807)
at org.apache.felix.framework.BundleImpl.start(BundleImpl.java:944)
at org.jvnet.hk2.osgiadapter.OSGiModuleImpl.start(OSGiModuleImpl.java:169)
2) Not executing http://localhost:4848/ , then put "glassfish-osgi-console-plugin.jar","org.apache.felix.webconsole.jar" and "felix-webconsole-extension.jar" into autostart directory, the result of start-domain is that the above exception did not happen.
In addition, about the problem ("Unknown protocol: jndi"), based the above compare, if after 2), I moved "glassfish-osgi-console-plugin.jar" into module/ and start-domain, the problem ("Unknown protocol: jndi") did not happen.
So, I have confirmed that on 3.1.2.2, once executing http://localhost:4848/ (loading admingui) and putting gf-osgi-gui related bundles regardless of using updatecenter of copying directly, the issue and problem will happen.
I also want to know the reason executing 2) successfully not using Workaround .

About reason of the issue("Failed to start Bundle Id [329]State [RESOLVED][org.glassfish.admingui.glassfish-osgi-console-plugin(Glassfish OSGI Console Plugin)"), I have done a investigation on 3.1.2.2, combined with sahoo's workaround, I explained in detailed.

(1) Firstly, why the issue related to gf admin gui loading?
Simply saying(because code structure is very complex), gf admin gui offered a @contract called org.glassfish.api.admingui.ConsoleProvider, and glassfish-osgi-console-plugin implemented a hk2 service of the ConsoleProvider called org.glassfish.osgi.admingui.OSGIConsoleProvider, then after loading admin gui,and while re-start domain, gf will load admin gui app, and also load glassfish-osgi-console-plugin because of @contract ConsoleProvider.

Needing to note a fact, while gf is loading admin gui app using a thread, gf self has a thread(kernel thread) to set glassfish.osgi.start.level.final(defaultly, is "2") in order to start $

{osgi-ee.bundles}, and autostart directory into which glassfish-osgi-console-plugin will be downloaded by using updatecenter is listed in ${osgi-ee.bundles}

. That is to say, loading admin gui app and setting glassfish.osgi.start.level.final are seperately done in two threads.

So, because of multi-thread's nature, as to my machine or marcond's machine, starting glassfish-osgi-console-plugin is done before setting glassfish.osgi.start.level.final, and because autostart directory's start level is 2, so at that time, glassfish-osgi-console-plugin can not be started. This also explained what sahoo said: "What might be happening is that adminconsole is coming up before the startlevel is reached to 2."

(2) Secondly, why using workaround can resolve the problem?
Moving glassfish-osgi-console-plugin into module/ can resolve the problem because on osgi.properties, you will find on glassfish.osgi.auto.start.level.n(1,2,3), glassfish-osgi-console-plugin is not related to these start level definition, because on felix, if you do not define start level explicitly, the bundle's start level is the value("1") of felix.startlevel.bundle. And it is also equal to the value of org.osgi.framework.startlevel.beginning. So, regardless of whether setting glassfish.osgi.start.level.final=2 or not, glassfish-osgi-console-plugin can be started.

There is an interesting thing to say: while I am debugging start-domain(asadmin start-domain --debug, and make debugging pending), if you do not add breakpoint on "sl.setStartLevel(finalStartLevel);" of OSGiGlassFishImpl.start() and only add breakpoint on line of the issue's stacktrace, you can find that the issue does not happen. This is because of multi-thread's nature.

Finally, there is still a question: why the issue does not happen on current gf trunk?

TangYong
added a comment - 15/Oct/12 12:42 PM sahoo, marcond
About reason of the issue("Failed to start Bundle Id [329] State [RESOLVED] [org.glassfish.admingui.glassfish-osgi-console-plugin(Glassfish OSGI Console Plugin)"), I have done a investigation on 3.1.2.2, combined with sahoo's workaround, I explained in detailed.
(1) Firstly, why the issue related to gf admin gui loading?
Simply saying(because code structure is very complex), gf admin gui offered a @contract called org.glassfish.api.admingui.ConsoleProvider, and glassfish-osgi-console-plugin implemented a hk2 service of the ConsoleProvider called org.glassfish.osgi.admingui.OSGIConsoleProvider, then after loading admin gui,and while re-start domain, gf will load admin gui app, and also load glassfish-osgi-console-plugin because of @contract ConsoleProvider.
Needing to note a fact, while gf is loading admin gui app using a thread, gf self has a thread(kernel thread) to set glassfish.osgi.start.level.final(defaultly, is "2") in order to start $
{osgi-ee.bundles}, and autostart directory into which glassfish-osgi-console-plugin will be downloaded by using updatecenter is listed in ${osgi-ee.bundles}
. That is to say, loading admin gui app and setting glassfish.osgi.start.level.final are seperately done in two threads.
So, because of multi-thread's nature, as to my machine or marcond's machine, starting glassfish-osgi-console-plugin is done before setting glassfish.osgi.start.level.final, and because autostart directory's start level is 2, so at that time, glassfish-osgi-console-plugin can not be started. This also explained what sahoo said: "What might be happening is that adminconsole is coming up before the startlevel is reached to 2."
(2) Secondly, why using workaround can resolve the problem?
Moving glassfish-osgi-console-plugin into module/ can resolve the problem because on osgi.properties, you will find on glassfish.osgi.auto.start.level.n(1,2,3), glassfish-osgi-console-plugin is not related to these start level definition, because on felix, if you do not define start level explicitly, the bundle's start level is the value("1") of felix.startlevel.bundle. And it is also equal to the value of org.osgi.framework.startlevel.beginning. So, regardless of whether setting glassfish.osgi.start.level.final=2 or not, glassfish-osgi-console-plugin can be started.
There is an interesting thing to say: while I am debugging start-domain(asadmin start-domain --debug, and make debugging pending), if you do not add breakpoint on "sl.setStartLevel(finalStartLevel);" of OSGiGlassFishImpl.start() and only add breakpoint on line of the issue's stacktrace, you can find that the issue does not happen. This is because of multi-thread's nature.
Finally, there is still a question: why the issue does not happen on current gf trunk?

>Finally, there is still a question: why the issue does not happen on current gf trunk?

After investigating the change between 3.1.2.2 souce and current gf trunk, I have found that on starting domain, current gf will not start a thread to execute "com.sun.enterprise.v3.admin.adapter.InstallerThread.run" , that is to say, gf will not
load admin gui app while starting domain and only while user truely accessed http://localhost:4848/, gf executes "com.sun.enterprise.v3.admin.adapter.InstallerThread.run". This is a ondemand loading!

Backing to the problem, since when starting domain, gf will not load admin gui, setting glassfish.osgi.start.level.final=2 will be executed before starting glassfish-osgi-console-plugin( in reality, at that time, gf will not start glassfish-osgi-console-plugin bundle at all).

So, the issue can not happen on current gf trunk.

BTW: the problem ("Unknown protocol: jndi") maybe happen because when glassfish-osgi-console-plugin resolved failed, gf system is a part-started state. However, about the concreate reason, I think that we need not investigate it because of the change from 3.1.2.2 mode to current trunk mode.

TangYong
added a comment - 15/Oct/12 1:48 PM >Finally, there is still a question: why the issue does not happen on current gf trunk?
After investigating the change between 3.1.2.2 souce and current gf trunk, I have found that on starting domain, current gf will not start a thread to execute "com.sun.enterprise.v3.admin.adapter.InstallerThread.run" , that is to say, gf will not
load admin gui app while starting domain and only while user truely accessed http://localhost:4848/ , gf executes "com.sun.enterprise.v3.admin.adapter.InstallerThread.run". This is a ondemand loading!
Backing to the problem, since when starting domain, gf will not load admin gui, setting glassfish.osgi.start.level.final=2 will be executed before starting glassfish-osgi-console-plugin( in reality, at that time, gf will not start glassfish-osgi-console-plugin bundle at all).
So, the issue can not happen on current gf trunk.
BTW: the problem ("Unknown protocol: jndi") maybe happen because when glassfish-osgi-console-plugin resolved failed, gf system is a part-started state. However, about the concreate reason, I think that we need not investigate it because of the change from 3.1.2.2 mode to current trunk mode.

I looked back for the artifacts about this error and they were discarded shortly after the migration to GF 3.1.1. As far I can remember, we had logs and some environment setups. About the errors, what we found at the time was that we had boot order problems, conflicting with OSGi HTTP Services (we use some of them). The errors were random and ocurred during GF startup time.

After stripping out module after module, we ended up with only OSGi Admin and GF, and the same random erros. It was when we filled the bug report.

I'll try to recover some files from the backups, which can be helpful.

marcond
added a comment - 15/Oct/12 2:41 PM TangYong,
Thanks for your interest on solving this problem.
I looked back for the artifacts about this error and they were discarded shortly after the migration to GF 3.1.1. As far I can remember, we had logs and some environment setups. About the errors, what we found at the time was that we had boot order problems, conflicting with OSGi HTTP Services (we use some of them). The errors were random and ocurred during GF startup time.
After stripping out module after module, we ended up with only OSGi Admin and GF, and the same random erros. It was when we filled the bug report.
I'll try to recover some files from the backups, which can be helpful.
Thanks
Marcond

First, we have started seeing this issue beginning with GF 3.1.2 because starting with this version, admin console can be configured to start as part of server startup process. See [1] for more details. Earlier, it used to load on demand only. Starting with 3.1.2, if you access the console a couple of times, then it marks it as a frequently used application and loads it next time the server starts. This will explain why we didn't see this issue < 3.1.2.

As Tang said, when the app gets loaded as part of server startup, it happens in a separate thread. There are two competing threads in the system:
one that's setting the start level to 2 or whatever we decide the final startlevel be, the second one is loading the console app. If the 2nd thread runs ahead of 1st thread, then we will get "Can't start bundle because start level of bundle is 2 where as framework start level is 1" kind of error. This error will definitely go away when we move every console related bundles to modules dir.

I have confirmed with adminconsole team that they are yet to port the feature from 3.1.2 branch to trunk, so that explains admin console loading behavior change in trunk. That explains why we are not seeing the issue in trunk as of now. Once they port the fix, we will see the issue, so we need to find a proper solution.

I still can't explain the "Unknown protocol: jndi" issue. I will see if I can find some more about it.

Sanjeeb Sahoo
added a comment - 15/Oct/12 4:24 PM - edited First, we have started seeing this issue beginning with GF 3.1.2 because starting with this version, admin console can be configured to start as part of server startup process. See [1] for more details. Earlier, it used to load on demand only. Starting with 3.1.2, if you access the console a couple of times, then it marks it as a frequently used application and loads it next time the server starts. This will explain why we didn't see this issue < 3.1.2.
As Tang said, when the app gets loaded as part of server startup, it happens in a separate thread. There are two competing threads in the system:
one that's setting the start level to 2 or whatever we decide the final startlevel be, the second one is loading the console app. If the 2nd thread runs ahead of 1st thread, then we will get "Can't start bundle because start level of bundle is 2 where as framework start level is 1" kind of error. This error will definitely go away when we move every console related bundles to modules dir.
I have confirmed with adminconsole team that they are yet to port the feature from 3.1.2 branch to trunk, so that explains admin console loading behavior change in trunk. That explains why we are not seeing the issue in trunk as of now. Once they port the fix, we will see the issue, so we need to find a proper solution.
I still can't explain the "Unknown protocol: jndi" issue. I will see if I can find some more about it.
[1] https://blogs.oracle.com/anilam/entry/glassfish_3_1_2_admin

TangYong
added a comment - 15/Oct/12 11:01 PM Sahoo,
>I still can't explain the "Unknown protocol: jndi" issue. I will see if I can find some more about it.
then, continue to make the issue open, and I will also try to look up the reason.
thanks.

TangYong
added a comment - 16/Oct/12 2:24 AM Hi sahoo,
>I still can't explain the "Unknown protocol: jndi" issue. I will see if I can find some more about it.
I made a confirmation:
After happening "Unknown protocol: jndi" issue, I cleared osgi-cache and re-start domain, result is that "Unknown protocol: jndi" issue still existed. So, I will continue to investigate the reason.

Since I don't have a reproducible env for "Unknown protocol:" issue, I need someone's help here. I suspect "jndi" url handler is not getting registered properly and that's causing this error. Please find attached a patched DirContextURLStreamHandlerService.java that prints a message after registering the protocol handler.

Sanjeeb Sahoo
added a comment - 16/Oct/12 5:07 AM Since I don't have a reproducible env for "Unknown protocol:" issue, I need someone's help here. I suspect "jndi" url handler is not getting registered properly and that's causing this error. Please find attached a patched DirContextURLStreamHandlerService.java that prints a message after registering the protocol handler.

[#|2012-10-16T14:19:45.437+0900|INFO|glassfish3.1.2|javax.enterprise.system.jmx.org.glassfish.admin.mbeanserver|_ThreadID=19;_ThreadName=Thread-2;|JMX005: JMXStartupService had Started JMXConnector on JMXService URL service:jmx:rmi://10.167.157.133:8686/jndi/rmi://10.167.157.133:8686/jmxrmi|#]

[#|2012-10-16T14:19:48.062+0900|SEVERE|glassfish3.1.2|javax.enterprise.resource.webcontainer.jsf.config|_ThreadID=17;_ThreadName=Thread-2;|Critical error during deployment:
com.sun.faces.config.ConfigurationException: java.util.concurrent.ExecutionException: java.net.MalformedURLException: Unknown protocol: jndi
at com.sun.faces.config.ConfigManager.getConfigDocuments(ConfigManager.java:672)
at com.sun.faces.config.ConfigManager.initialize(ConfigManager.java:322)
at com.sun.faces.config.ConfigureListener.contextInitialized(ConfigureListener.java:225)
at org.apache.catalina.core.StandardContext.contextListenerStart(StandardContext.java:4750)
at com.sun.enterprise.web.WebModule.contextListenerStart(WebModule.java:550)
at org.apache.catalina.core.StandardContext.start(StandardContext.java:5366)
at com.sun.enterprise.web.WebModule.start(WebModule.java:498)
at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:917)
at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:901)
at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:733)
at com.sun.enterprise.web.WebContainer.loadWebModule(WebContainer.java:2019)
at com.sun.enterprise.web.WebContainer.loadWebModule(WebContainer.java:1669)
at com.sun.enterprise.web.WebApplication.start(WebApplication.java:109)
at org.glassfish.internal.data.EngineRef.start(EngineRef.java:130)
at org.glassfish.internal.data.ModuleInfo.start(ModuleInfo.java:269)
at org.glassfish.internal.data.ApplicationInfo.start(ApplicationInfo.java:301)
at com.sun.enterprise.v3.server.ApplicationLifecycle.deploy(ApplicationLifecycle.java:461)
at com.sun.enterprise.v3.server.ApplicationLoaderService.processApplication(ApplicationLoaderService.java:375)
at com.sun.enterprise.v3.admin.adapter.InstallerThread.load(InstallerThread.java:210)
at com.sun.enterprise.v3.admin.adapter.InstallerThread.run(InstallerThread.java:108)
Caused by: java.util.concurrent.ExecutionException: java.net.MalformedURLException: Unknown protocol: jndi
at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:222)
at java.util.concurrent.FutureTask.get(FutureTask.java:83)
at com.sun.faces.config.ConfigManager.getConfigDocuments(ConfigManager.java:670)
... 19 more
Caused by: java.net.MalformedURLException: Unknown protocol: jndi
at java.net.URL.<init>(URL.java:601)
at java.net.URL.<init>(URL.java:464)
at java.net.URL.<init>(URL.java:413)
at java.net.URI.toURL(URI.java:1080)
at com.sun.faces.config.ConfigManager$ParseTask.call(ConfigManager.java:920)
at com.sun.faces.config.ConfigManager$ParseTask.call(ConfigManager.java:865)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at com.sun.faces.config.ConfigManager.getConfigDocuments(ConfigManager.java:656)
... 19 more

#]

[#|2012-10-16T14:19:48.078+0900|SEVERE|glassfish3.1.2|org.apache.catalina.core.StandardContext|_ThreadID=17;_ThreadName=Thread-2;|PWC1306: Startup of context failed due to previous errors|#]

[#|2012-10-16T14:19:48.078+0900|SEVERE|glassfish3.1.2|org.apache.catalina.core.StandardContext|_ThreadID=17;_ThreadName=Thread-2;|PWC1305: Exception during cleanup after start failed
org.apache.catalina.LifecycleException: PWC2769: Manager has not yet been started
at org.apache.catalina.session.StandardManager.stop(StandardManager.java:873)
at org.apache.catalina.core.StandardContext.stop(StandardContext.java:5571)
at com.sun.enterprise.web.WebModule.stop(WebModule.java:527)
at org.apache.catalina.core.StandardContext.start(StandardContext.java:5384)
at com.sun.enterprise.web.WebModule.start(WebModule.java:498)
at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:917)
at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:901)
at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:733)
at com.sun.enterprise.web.WebContainer.loadWebModule(WebContainer.java:2019)
at com.sun.enterprise.web.WebContainer.loadWebModule(WebContainer.java:1669)
at com.sun.enterprise.web.WebApplication.start(WebApplication.java:109)
at org.glassfish.internal.data.EngineRef.start(EngineRef.java:130)
at org.glassfish.internal.data.ModuleInfo.start(ModuleInfo.java:269)
at org.glassfish.internal.data.ApplicationInfo.start(ApplicationInfo.java:301)
at com.sun.enterprise.v3.server.ApplicationLifecycle.deploy(ApplicationLifecycle.java:461)
at com.sun.enterprise.v3.server.ApplicationLoaderService.processApplication(ApplicationLoaderService.java:375)
at com.sun.enterprise.v3.admin.adapter.InstallerThread.load(InstallerThread.java:210)
at com.sun.enterprise.v3.admin.adapter.InstallerThread.run(InstallerThread.java:108)

#]

[#|2012-10-16T14:19:48.078+0900|SEVERE|glassfish3.1.2|org.apache.catalina.core.ContainerBase|_ThreadID=17;_ThreadName=Thread-2;|ContainerBase.addChild: start:
org.apache.catalina.LifecycleException: java.lang.RuntimeException: com.sun.faces.config.ConfigurationException: java.util.concurrent.ExecutionException: java.net.MalformedURLException: Unknown protocol: jndi
at org.apache.catalina.core.StandardContext.start(StandardContext.java:5389)
at com.sun.enterprise.web.WebModule.start(WebModule.java:498)
at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:917)
at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:901)
at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:733)
at com.sun.enterprise.web.WebContainer.loadWebModule(WebContainer.java:2019)
at com.sun.enterprise.web.WebContainer.loadWebModule(WebContainer.java:1669)
at com.sun.enterprise.web.WebApplication.start(WebApplication.java:109)
at org.glassfish.internal.data.EngineRef.start(EngineRef.java:130)
at org.glassfish.internal.data.ModuleInfo.start(ModuleInfo.java:269)
at org.glassfish.internal.data.ApplicationInfo.start(ApplicationInfo.java:301)
at com.sun.enterprise.v3.server.ApplicationLifecycle.deploy(ApplicationLifecycle.java:461)
at com.sun.enterprise.v3.server.ApplicationLoaderService.processApplication(ApplicationLoaderService.java:375)
at com.sun.enterprise.v3.admin.adapter.InstallerThread.load(InstallerThread.java:210)
at com.sun.enterprise.v3.admin.adapter.InstallerThread.run(InstallerThread.java:108)
Caused by: java.lang.RuntimeException: com.sun.faces.config.ConfigurationException: java.util.concurrent.ExecutionException: java.net.MalformedURLException: Unknown protocol: jndi
at com.sun.faces.config.ConfigureListener.contextInitialized(ConfigureListener.java:292)
at org.apache.catalina.core.StandardContext.contextListenerStart(StandardContext.java:4750)
at com.sun.enterprise.web.WebModule.contextListenerStart(WebModule.java:550)
at org.apache.catalina.core.StandardContext.start(StandardContext.java:5366)
... 14 more
Caused by: com.sun.faces.config.ConfigurationException: java.util.concurrent.ExecutionException: java.net.MalformedURLException: Unknown protocol: jndi
at com.sun.faces.config.ConfigManager.getConfigDocuments(ConfigManager.java:672)
at com.sun.faces.config.ConfigManager.initialize(ConfigManager.java:322)
at com.sun.faces.config.ConfigureListener.contextInitialized(ConfigureListener.java:225)
... 17 more
Caused by: java.util.concurrent.ExecutionException: java.net.MalformedURLException: Unknown protocol: jndi
at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:222)
at java.util.concurrent.FutureTask.get(FutureTask.java:83)
at com.sun.faces.config.ConfigManager.getConfigDocuments(ConfigManager.java:670)
... 19 more
Caused by: java.net.MalformedURLException: Unknown protocol: jndi
at java.net.URL.<init>(URL.java:601)
at java.net.URL.<init>(URL.java:464)
at java.net.URL.<init>(URL.java:413)
at java.net.URI.toURL(URI.java:1080)
at com.sun.faces.config.ConfigManager$ParseTask.call(ConfigManager.java:920)
at com.sun.faces.config.ConfigManager$ParseTask.call(ConfigManager.java:865)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at com.sun.faces.config.ConfigManager.getConfigDocuments(ConfigManager.java:656)
... 19 more

With the reproducible environment provided by Tang and his help, I think we now know the cause behind all the issues described here.Let me take a moment to explain things again.

Starting with gf3.1.2, under certain circumastances, adminconsole by a postStartup service [1]. I think starting with gf3.1.2, we also started usig start levels to start autostart bundles. Autostart bundles start by a startlevel thread. So, once server is up, there are two threads which are running concurrently - one the start level thread which is changing the start level to final start level and the other one is loading adminconsole. This is resulting in all sorts of issues.
First - the org.osgi.framework.BundleException: Cannot start bundle org.glassfish.admingui.glassfish-osgi-console-plugin [329] because its start level is 2, which is greater than the framework's start level of 1. This is happening because glassfish-osgi-console-plugin.jar is installed in autostart dir and it gets a start level of 2. It can be activated even at framework start level of 1 when adminconsole installer thread is trying to load the console. So, we should really fix the package to install this jar in modules/ dir.

Second - once we get past the first issue, we see the second issue of "Unknown protocol: jndi." It happens because of a combination of issues. One of the glassfish modules called web-glue has an activator which registers a URL handler service in OSGi service registry. Until this service is registered, we can't use URLs with jndi scheme. Our web container relies on jndi URL scheme internally. We expected web-glue to be activated before web container is used. We have code in HK2/osgi-adapter that actually starts a bundle if a bundle is not started yet before it loads a HK2 service from a bundle. But, due to this Felix bug [2], our bundle is not getting activated. What we noticed is that when webconsole is installed, osgi-http module gets activated when start level changes to 2. During osgi-http module activation, it loads WebContainer. But due to this Felix bug, web-glue's activator is not called, yet WebContainer service has been made available. Later on when console thread tried to start console, it never tried to start web-glue again. As a result, the activator of web-glue never got called and hence nobody registered jndi protocol handler. To fix the second issue, I propose that we register jndi protocol handler via a GlassFish startup service.

Sanjeeb Sahoo
added a comment - 16/Oct/12 4:37 PM With the reproducible environment provided by Tang and his help, I think we now know the cause behind all the issues described here.Let me take a moment to explain things again.
Starting with gf3.1.2, under certain circumastances, adminconsole by a postStartup service [1] . I think starting with gf3.1.2, we also started usig start levels to start autostart bundles. Autostart bundles start by a startlevel thread. So, once server is up, there are two threads which are running concurrently - one the start level thread which is changing the start level to final start level and the other one is loading adminconsole. This is resulting in all sorts of issues.
First - the org.osgi.framework.BundleException: Cannot start bundle org.glassfish.admingui.glassfish-osgi-console-plugin [329] because its start level is 2, which is greater than the framework's start level of 1. This is happening because glassfish-osgi-console-plugin.jar is installed in autostart dir and it gets a start level of 2. It can be activated even at framework start level of 1 when adminconsole installer thread is trying to load the console. So, we should really fix the package to install this jar in modules/ dir.
Second - once we get past the first issue, we see the second issue of "Unknown protocol: jndi." It happens because of a combination of issues. One of the glassfish modules called web-glue has an activator which registers a URL handler service in OSGi service registry. Until this service is registered, we can't use URLs with jndi scheme. Our web container relies on jndi URL scheme internally. We expected web-glue to be activated before web container is used. We have code in HK2/osgi-adapter that actually starts a bundle if a bundle is not started yet before it loads a HK2 service from a bundle. But, due to this Felix bug [2] , our bundle is not getting activated. What we noticed is that when webconsole is installed, osgi-http module gets activated when start level changes to 2. During osgi-http module activation, it loads WebContainer. But due to this Felix bug, web-glue's activator is not called, yet WebContainer service has been made available. Later on when console thread tried to start console, it never tried to start web-glue again. As a result, the activator of web-glue never got called and hence nobody registered jndi protocol handler. To fix the second issue, I propose that we register jndi protocol handler via a GlassFish startup service.
[1] https://blogs.oracle.com/anilam/entry/glassfish_3_1_2_admin
[2] https://issues.apache.org/jira/browse/FELIX-3713

I have fixed the issue on trunk in svn rev #56537 and #56547. You need both the commits, because the first one caused a regression in embedded ejb container tests where OSGi classes were not available. See check-in comments for more details.

I have asked our build team to create a 3.1.x branch. When that's available, I will also fix it there.

I will also ask our sustaining team to include this fix in a future patch release.

Sanjeeb Sahoo
added a comment - 17/Oct/12 3:09 AM - edited I have fixed the issue on trunk in svn rev #56537 and #56547. You need both the commits, because the first one caused a regression in embedded ejb container tests where OSGi classes were not available. See check-in comments for more details.
I have asked our build team to create a 3.1.x branch. When that's available, I will also fix it there.
I will also ask our sustaining team to include this fix in a future patch release.

TangYong
added a comment - 17/Oct/12 4:05 AM Hi sahoo,
I have used the new workaround and tried more than 10 times, the issue including "Unknown protocol:" all did not happen on 3.1.2.2 any longer. The workaround for 3.1.2.x looks very fine!
Thanks
Tang

After further testing, we discovered that we needed it to be an init service rather than a startup service. So, we fixed it in the following check-in:
Sending appserver/web/web-naming/pom.xml
Sending appserver/web/web-naming/src/main/java/org/apache/naming/resources/WebNamingStartup.java
Transmitting file data ..
Committed revision 56875.

Sanjeeb Sahoo
added a comment - 07/Nov/12 2:36 AM After further testing, we discovered that we needed it to be an init service rather than a startup service. So, we fixed it in the following check-in:
Sending appserver/web/web-naming/pom.xml
Sending appserver/web/web-naming/src/main/java/org/apache/naming/resources/WebNamingStartup.java
Transmitting file data ..
Committed revision 56875.

We were trying to find the reason for this error in a production test environment where the admin console refused to load on startup. To make a long story short - the root cause was the /tmp directory having been set to read-only, which caused the OSGI loader spin wildly trying to create a temporary directory and failing. Apparently there is room for improvement in the error handling of OSGI, but once we realized what was happening and set the rights to the /tmp directory things returned to normal.

mats.nordgren
added a comment - 18/Jun/14 12:10 PM In case anyone finds this page in relation to the Unknown protocol: JNDI issue, I'll add my experiences:
We were trying to find the reason for this error in a production test environment where the admin console refused to load on startup. To make a long story short - the root cause was the /tmp directory having been set to read-only, which caused the OSGI loader spin wildly trying to create a temporary directory and failing. Apparently there is room for improvement in the error handling of OSGI, but once we realized what was happening and set the rights to the /tmp directory things returned to normal.