JOnAS doesn't start if client tries to connect to early
The logging Shows the following rows: INFO | jvm 1 | 2013/07/08 14:32:48 | Welcome to OW2 JOnAS (Running on Felix). INFO | jvm 1 | 2013/07/08 14:32:48 | ----------------------------------------------- INFO | jvm 1 | 2013/07/08 14:32:48 | INFO | jvm 1 | 2013/07/08 14:32:52 | 7/8/13 2:32:52 PM (I) ExtensionLoaderComponent.__start : Some jars have been found in [C:\Avaya\Servers\JONAS\lib\ext]. They have been transformed into bundles (see C:\Avaya\Servers\JONAS\work\ext-bundles directory).This is NOT the prefered way to extends JOnAS libraries, prefer to use carefully created and tested bundles, and place them in your deploy/ directory. INFO | jvm 1 | 2013/07/08 14:32:52 | 7/8/13 2:32:52 PM (I) ExtensionLoaderComponent.__start : file:/C:/Avaya/Servers/JONAS/work/ext-bundles/log4j-1.2.15.jar installed as a bundle. INFO | jvm 1 | 2013/07/08 14:32:52 | 7/8/13 2:32:52 PM (I) ExtensionLoaderComponent.__start : file:/C:/Avaya/Servers/JONAS/work/ext-bundles/jodbc.jar installed as a bundle. INFO | jvm 1 | 2013/07/08 14:39:21 | 2013-07-08 14:39:21,356 : ConfigurationRepository.checkInitialized : Do the configuration as the configuration was not yet done! INFO | jvm 1 | 2013/07/08 14:39:21 | 2013-07-08 14:39:21,387 : ServerConfigurationImpl. : {java.vendor=Sun Microsystems Inc., javax.xml.soap.SOAPFactory=com.sun.xml.messaging.saaj.soap.ver1_1.SOAPFactory1_1Impl, sun.java.launcher=SUN_STANDARD, jonas.name=jonas, sun.management.compiler=HotSpot Client Compiler, os.name=Windows 7, sun.boot.class.path=../../JONAS/lib/endorsed\avalon-framework-4.1.5.jar;../../JONAS/lib/endorsed\carol-iiop-delegate-3.0.7.jar;../../JONAS/lib/endorsed\jacorb-2.2.3-jonas-patch-20071018.jar;../../JONAS/lib/endorsed\jacorb-idl-2.2.3-jonas-patch-20071018.jar;../../JONAS/lib/endorsed\logkit-1.2.jar;../../JONAS/lib/endorsed\serializer-2.7.1.jar;../../JONAS/lib/endorsed\xalan-2.7.1.jar;../../JONAS/lib/endorsed\xercesImpl-2.9.1.jar;../../JONAS/lib/endorsed\xml-apis-1.3.04.jar;C:\Avaya\Servers\JDK\jre\lib\resources.jar;C:\Avaya\Servers\JDK\jre\lib\rt.jar;C:\Avaya\Servers\JDK\jre\lib\sunrsasign.jar;C:\Avaya\Servers\JDK\jre\lib\jsse.jar;C:\Avaya\Servers\JDK\jre\lib\jce.jar;C:\Avaya\Servers\JDK\jre\lib\charsets.jar;C:\Avaya\S INFO | jvm 1 | 2013/07/08 14:39:21 | ervers\JDK\jre\lib\modules\jdk.boot.jar;C:\Avaya\Servers\JDK\jre\classes, jonas.start.date=1373279568075, sun.desktop=windows, java.vm.specification.vendor=Sun Microsystems Inc., java.runtime.version=1.6.0_23-b05, ipojo.log.level=ERROR, wrapper.key=IZvSMSfsc3_UTW4g, user.name=SYSTEM, javax.xml.soap.MetaFactory=com.sun.xml.messaging.saaj.soap.SAAJMetaFactoryImpl, java.naming.factory.initial=org.ow2.carol.jndi.intercept.spi.InterceptorInitialContextFactory, user.language=en, com.sun.CORBA.ORBDynamicStubFactoryFactoryClass=com.sun.corba.se.impl.presentation.rmi.StubFactoryFactoryStaticImpl, sun.boot.library.path=C:\Avaya\Servers\JDK\jre\bin, java.version=1.6.0_23, jonas.root=C:\Avaya\Servers\JONAS, user.timezone=GMT+04:00, sun.arch.data.model=32, javax.rmi.CORBA.UtilClass=org.ow2.carol.util.delegate.UtilDelegateImpl, java.endorsed.dirs=../../JONAS/lib/endorsed, sun.cpu.isalist=pentium_pro+mmx pentium_pro pentium+mmx pentium i486 i386 i86, sun.jnu.encoding=Cp1252, file.encoding.pkg=sun.io, file.separator=, java. INFO | jvm 1 | 2013/07/08 14:39:21 | specification.name=Java Platform API Specification, java.class.version=50.0, user.country=US, java.home=C:\Avaya\Servers\JDK\jre, java.vm.info=mixed mode, os.version=6.1, org.omg.CORBA.ORBSingletonClass=org.jacorb.orb.ORBSingleton, path.separator=;, java.vm.version=19.0-b09, org.omg.PortableInterceptor.ORBInitializerClass.standard_init=org.jacorb.orb.standardInterceptors.IORInterceptorInitializer, user.variant=, java.awt.printerjob=sun.awt.windows.WPrinterJob, java.security.policy=../../JONAS/conf/java.policy, sun.io.unicode.encoding=UnicodeLittle, awt.toolkit=sun.awt.windows.WToolkit, monolog.wrappers=mx4j.log.CommonsLogger,mx4j.log.Logger,java.util.logging.Logger,org.ow2.util.log.JDKLogger,org.apache.juli.logging.DirectJDKLog,org.ow2.carol.util.configuration.TraceCarol,org.slf4j.impl.JCLLoggerAdapter, user.home=C:\Windows\System32\config\systemprofile, java.specification.vendor=Sun Microsystems Inc., java.library.path=....\libs, java.vendor.url=http://java.sun.com/, java.vm.vendor=Sun Microsystems Inc., wr INFO | jvm 1 | 2013/07/08 14:39:21 | apper.jvmid=1, java.runtime.name=Java(TM) SE Runtime Environment, cmi.disabled=true, java.class.path=....\libs\wrapper.jar;../../JONAS/conf;../../JONAS/lib/bootstrap/felix-launcher.jar;../../JONAS/lib/bootstrap/jonas-commands.jar;../../JONAS/lib/bootstrap/jonas-version.jar, java.vm.specification.name=Java Virtual Machine Specification, javax.rmi.CORBA.PortableRemoteObjectClass=org.ow2.carol.rmi.multi.MultiPRODelegate, java.vm.specification.version=1.0, sun.cpu.endian=little, sun.os.patch.level=, jonas.base=C:\Avaya\Servers\JONAS, wrapper.cpu.timeout=10, java.io.tmpdir=C:\Windows\TEMP, java.vendor.url.bug=http://java.sun.com/cgi-bin/bugreport.cgi, os.arch=x86, java.awt.graphicsenv=sun.awt.Win32GraphicsEnvironment, java.ext.dirs=C:\Avaya\Servers\JDK\jre\lib\ext;C:\Windows\Sun\Java\lib\ext, user.dir=C:\Avaya\Servers\JONAS\conf, line.separator= INFO | jvm 1 | 2013/07/08 14:39:21 | , java.vm.name=Java HotSpot(TM) Client VM, java.security.auth.login.config=../../JONAS/conf/jaas.config, javax.xml.soap.MessageFactory=com.sun.xml.messaging.saaj.soap.ver1_1.SOAPMessageFactory1_1Impl, javax.xml.soap.SOAPConnectionFactory=com.sun.xml.messaging.saaj.client.p2p.HttpSOAPConnectionFactory, file.encoding=Cp1252, org.omg.CORBA.ORBClass=org.jacorb.orb.ORB, org.tanukisoftware.wrapper.WrapperStartStopApp.waitForStartMain=FALSE, java.specification.version=1.6, wrapper.service=TRUE, wrapper.port=4777} INFO | jvm 1 | 2013/07/08 14:39:21 | 2013-07-08 14:39:21,605 : ServerConfigurationImpl. : Set the JVM property 'javax.rmi.CORBA.PortableRemoteObjectClass' with the value 'org.ow2.carol.rmi.multi.MultiPRODelegate'. INFO | jvm 1 | 2013/07/08 14:39:21 | 2013-07-08 14:39:21,605 : ServerConfigurationImpl. : Set the JVM property 'java.naming.factory.initial' with the value 'org.ow2.carol.jndi.spi.MultiOrbInitialContextFactory'. INFO | jvm 1 | 2013/07/08 14:39:21 | 2013-07-08 14:39:21,605 : ServerConfigurationImpl. : Set the JVM property 'java.naming.factory.url.pkgs' with the value 'org.ow2.jonas.lib.naming'. INFO | jvm 1 | 2013/07/08 14:39:21 | 2013-07-08 14:39:21,605 : ServerConfigurationImpl. : Set the JVM property 'rmi.local.call' with the value 'false'. INFO | jvm 1 | 2013/07/08 14:39:21 | 2013-07-08 14:39:21,605 : ServerConfigurationImpl. : Set the JVM property 'rmi.local.registry' with the value 'true'. INFO | jvm 1 | 2013/07/08 14:39:21 | 2013-07-08 14:39:21,605 : ConfigurationRepository.init : Build protocol object for protocol name found 'iiop'. INFO | jvm 1 | 2013/07/08 14:39:21 | 2013-07-08 14:39:21,605 : ConfigurationRepository.init : Build protocol object for protocol name found 'irmi'. INFO | jvm 1 | 2013/07/08 14:39:21 | 2013-07-08 14:39:21,605 : ConfigurationRepository.init : Build protocol object for protocol name found 'jrmp'. INFO | jvm 1 | 2013/07/08 14:39:21 | 2013-07-08 14:39:21,605 : ConfigurationRepository.initCMIOnStartUP : CMI disabled by the system property 'cmi.disabled'. INFO | jvm 1 | 2013/07/08 14:39:22 | [FAILURE] Cannot connect to JOnAS using 'service:jmx:rmi:///jndi/rmi://localhost:21099/jrmpconnector_jonas' INFO | jvm 1 | 2013/07/08 14:39:22 | [FAILURE] Cause: [ConnectException] Connection refused: connect INFO | jvm 1 | 2013/07/08 14:39:23 | 2013-07-08 14:39:23,493 : SingletonNamingManager. : NamingManager: INFO | jvm 1 | 2013/07/08 14:39:23 | java.lang.IllegalStateException: Configuration of carol was not done and when trying to initialize it, it fails. INFO | jvm 1 | 2013/07/08 14:39:23 | at org.ow2.carol.util.configuration.ConfigurationRepository.checkInitialized(ConfigurationRepository.java:116) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.ow2.carol.util.configuration.ConfigurationRepository.checkConfigured(ConfigurationRepository.java:129) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.ow2.carol.util.configuration.ConfigurationRepository.getCurrentConfiguration(ConfigurationRepository.java:214) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.ow2.carol.jndi.spi.MultiContext.(MultiContext.java:90) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.ow2.carol.jndi.spi.MultiOrbInitialContextFactory.getInitialContext(MultiOrbInitialContextFactory.java:72) INFO | jvm 1 | 2013/07/08 14:39:23 | at javax.naming.spi.NamingManager.getInitialContext(NamingManager.java:667) INFO | jvm 1 | 2013/07/08 14:39:23 | at javax.naming.InitialContext.getDefaultInitCtx(InitialContext.java:288) INFO | jvm 1 | 2013/07/08 14:39:23 | at javax.naming.InitialContext.init(InitialContext.java:223) INFO | jvm 1 | 2013/07/08 14:39:23 | at javax.naming.InitialContext.(InitialContext.java:175) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.ow2.jonas.lib.naming.SingletonNamingManager$1.execute(SingletonNamingManager.java:111) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.ow2.jonas.lib.naming.SingletonNamingManager$1.execute(SingletonNamingManager.java:110) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.ow2.jonas.lib.execution.RunnableHelper.execute(RunnableHelper.java:60) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.ow2.jonas.lib.naming.SingletonNamingManager.(SingletonNamingManager.java:115) INFO | jvm 1 | 2013/07/08 14:39:23 | at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) INFO | jvm 1 | 2013/07/08 14:39:23 | at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:39) INFO | jvm 1 | 2013/07/08 14:39:23 | at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27) INFO | jvm 1 | 2013/07/08 14:39:23 | at java.lang.reflect.Constructor.newInstance(Constructor.java:513) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.apache.felix.ipojo.InstanceManager.createObject(InstanceManager.java:588) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.apache.felix.ipojo.InstanceManager.getPojoObject(InstanceManager.java:763) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.apache.felix.ipojo.handlers.providedservice.ProvidedService$SingletonStrategy.getService(ProvidedService.java:434) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.apache.felix.ipojo.handlers.providedservice.ProvidedService.getService(ProvidedService.java:259) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.apache.felix.framework.ServiceRegistrationImpl.getFactoryUnchecked(ServiceRegistrationImpl.java:274) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.apache.felix.framework.ServiceRegistrationImpl.getService(ServiceRegistrationImpl.java:198) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.apache.felix.framework.ServiceRegistry.getService(ServiceRegistry.java:308) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.apache.felix.framework.Felix.getService(Felix.java:2729) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.apache.felix.framework.BundleContextImpl.getService(BundleContextImpl.java:357) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.apache.felix.ipojo.IPojoContext.getService(IPojoContext.java:258) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.apache.felix.ipojo.util.Tracker.getService(Tracker.java:434) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.apache.felix.ipojo.util.DependencyModel.ungetService(DependencyModel.java:897) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.apache.felix.ipojo.util.DependencyModel.manageDeparture(DependencyModel.java:424) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.apache.felix.ipojo.util.DependencyModel.removedService(DependencyModel.java:413) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.apache.felix.ipojo.util.Tracker$Tracked.untrack(Tracker.java:736) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.apache.felix.ipojo.util.Tracker.close(Tracker.java:236) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.apache.felix.ipojo.util.DependencyModel.stop(DependencyModel.java:216) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.apache.felix.ipojo.handlers.dependency.Dependency.stop(Dependency.java:195) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.apache.felix.ipojo.handlers.dependency.DependencyHandler.__stop(DependencyHandler.java:471) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.apache.felix.ipojo.handlers.dependency.DependencyHandler.stop(DependencyHandler.java) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.apache.felix.ipojo.HandlerManager.stop(HandlerManager.java:135) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.apache.felix.ipojo.InstanceManager.stop(InstanceManager.java:333) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.apache.felix.ipojo.InstanceManager.dispose(InstanceManager.java:372) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.apache.felix.ipojo.IPojoFactory.computeFactoryState(IPojoFactory.java:713) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.apache.felix.ipojo.ComponentFactory.removedService(ComponentFactory.java:376) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.apache.felix.ipojo.util.Tracker$Tracked.untrack(Tracker.java:736) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.apache.felix.ipojo.util.Tracker.close(Tracker.java:236) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.apache.felix.ipojo.ComponentFactory.stopping(ComponentFactory.java:250) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.apache.felix.ipojo.IPojoFactory.stop(IPojoFactory.java:494) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.apache.felix.ipojo.Extender.closeManagementFor(Extender.java:157) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.apache.felix.ipojo.Extender.bundleChanged(Extender.java:129) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.apache.felix.framework.util.EventDispatcher.invokeBundleListenerCallback(EventDispatcher.java:771) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.apache.felix.framework.util.EventDispatcher.fireEventImmediately(EventDispatcher.java:700) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.apache.felix.framework.util.EventDispatcher.fireBundleEvent(EventDispatcher.java:597) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.apache.felix.framework.Felix.fireBundleEvent(Felix.java:3432) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.apache.felix.framework.Felix.stopBundle(Felix.java:1821) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.apache.felix.framework.Felix.setActiveStartLevel(Felix.java:1001) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.apache.felix.framework.StartLevelImpl.run(StartLevelImpl.java:263) INFO | jvm 1 | 2013/07/08 14:39:23 | at java.lang.Thread.run(Thread.java:662) INFO | jvm 1 | 2013/07/08 14:39:23 | Caused by: org.ow2.carol.util.configuration.ConfigurationException: Property 'carol.start.ns' was not found in the properties object of the protocol, properties are :'{carol.iiop.PortableRemoteObjectClass=org.ow2.jonas.registry.carol.delegate.JacORBPRODelegate, carol.jrmp.url=rmi://localhost:21099, carol.irmi.server.port=0, carol.protocols=jrmp, carol.iiop.server.sslport=2003, carol.jrmp.interfaces.bind.single=false, carol.jvm.rmi.local.call=false, carol.jrmp.server.port=1150, carol.iiop.server.port=0, carol.irmi.url=rmi://localhost:21099, carol.iiop.url=iiop://localhost:21099, carol.jndi.java.naming.factory.url.pkgs=org.ow2.jonas.lib.naming, carol.jvm.rmi.local.registry=true, carol.irmi.interfaces.bind.single=false}' INFO | jvm 1 | 2013/07/08 14:39:23 | at org.ow2.carol.util.configuration.ServerConfigurationImpl.getBooleanValue(ServerConfigurationImpl.java:205) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.ow2.carol.util.configuration.ServerConfigurationImpl.(ServerConfigurationImpl.java:133) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.ow2.carol.util.configuration.ConfigurationRepository.init(ConfigurationRepository.java:334) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.ow2.carol.util.configuration.ConfigurationRepository.init(ConfigurationRepository.java:290) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.ow2.carol.util.configuration.ConfigurationRepository.init(ConfigurationRepository.java:267) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.ow2.carol.util.configuration.ConfigurationRepository.init(ConfigurationRepository.java:230) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.ow2.carol.util.configuration.ConfigurationRepository.init(ConfigurationRepository.java:519) INFO | jvm 1 | 2013/07/08 14:39:23 | at org.ow2.carol.util.configuration.ConfigurationRepository.checkInitialized(ConfigurationRepository.java:114) INFO | jvm 1 | 2013/07/08 14:39:23 | ... 55 more