Effective October 27, 2012, online and email support for FuseSource products will move to Red Hat support channels. For more information, please see the JIRA Migration to Red Hat FAQ.
As of October 27th, please open all new issues in the Red Hat Customer Portal .
Issue Details (XML | Word | Printable)

Key: ESB-812
Type: Bug Bug
Status: Closed Closed
Resolution: Fixed
Priority: Major Major
Assignee: Guillaume Nodet
Reporter: Joe Luo
Votes: 3
Watchers: 4
Operations

If you were logged in you would be able to see more operations.
FUSE ESB

[Fuse ESB 4.1.0.2] a new instance created by admin/create sub shell won't be started correctly

Created: 28/Jul/09 11:07 AM   Updated: 07/Oct/09 11:17 AM
Component/s: Core
Affects Version/s: 4.1.0.2-fuse
Fix Version/s: 4.2.0.0M1-fuse

File Attachments: 1. Text File servicemix.log (1.47 MB)
2. Text File servicemix.log (12 kB)
Environment: Windows XP, Linux


 Description  « Hide
Using a completely fresh install of Fuse ESB 4.1.0.2 and started it by ./bin/servicemix. Then from the console do:

admin/create foo
admin/start foo

The instance is created, with an instances/foo directory seemingly populated OK, but the instance never starts properly and the instance cannot be connected to:

smx@root:admin> create foo
Creating new instance on port 8103 at: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo
Creating dir:  E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\bin
Creating dir:  E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc
Creating dir:  E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\system
Creating dir:  E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\deploy
Creating dir:  E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\data
Creating file: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\config.properties
Creating file: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\org.apache.servicemix.features.cfg
Creating file: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\users.properties
Creating file: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\org.ops4j.pax.logging.cfg
Creating file: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\org.ops4j.pax.url.mvn.cfg
Creating file: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\startup.properties
Creating file: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\system.properties
Creating file: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\org.apache.servicemix.shell.cfg
Creating file: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\bin\servicemix.bat
smx@root:admin> start foo
smx@root:admin> list
  Port   State       Pid  Name
[ 8103] [Starting] [ 5152] foo
smx@root:admin> list
  Port   State       Pid  Name
[ 8103] [Starting] [ 5152] foo
smx@root:admin> connect foo
Connecting to: localhost:8103
ERROR CommandLineExecutionFailed: org.apache.geronimo.gshell.command.CommandException: org.apache.ge
ronimo.gshell.commandline.CommandLineExecutionFailed: org.apache.geronimo.gshell.command.CommandExce
ption: org.apache.sshd.common.RuntimeSshException: Failed to get the session.
smx@root:admin>

The log from instances/foo/data/log/servicemix.log shows the following:

10:58:26,267 | INFO | FelixStartLevel | OsgiServiceFactoryBean | r.support.OsgiServiceFactoryBean 299 | Publishing service under classes (org.osgi.service.url.URLStreamHandlerService)
10:58:26,267 | INFO | FelixStartLevel | OsgiBundleXmlApplicationContext | ractOsgiBundleApplicationContext 345 | Not publishing application context OSGi service for bundle Apache ServiceMix Kernel :: Spring Deployer (org.apache.servicemix.kernel.spring)
10:58:26,282 | WARN | pool-1-thread-1 | FileMonitor | x.kernel.filemonitor.FileMonitor 272 | Unsupported deployment: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\system.properties
10:58:26,282 | WARN | pool-1-thread-1 | FileMonitor | x.kernel.filemonitor.FileMonitor 272 | Unsupported deployment: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\config.properties
10:58:26,282 | WARN | pool-1-thread-1 | FileMonitor | x.kernel.filemonitor.FileMonitor 272 | Unsupported deployment: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\users.properties
10:58:26,282 | WARN | pool-1-thread-1 | FileMonitor | x.kernel.filemonitor.FileMonitor 272 | Unsupported deployment: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\startup.properties

 All   Comments   Change History      Sort Order: Ascending order - Click to sort in descending order
Joe Luo made changes - 28/Jul/09 11:09 AM
Field Original Value New Value
Description Using a completely fresh install of Fuse ESB 4.1.0.2 and started it by ./bin/servicemix. Then from the console do:

admin/create foo
admin/start foo

The instance is created, with an instances/foo directory seemingly populated OK, but the instance never starts properly and the instance cannot be connected to:
{code}
smx@root:admin> create foo
Creating new instance on port 8103 at: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo
Creating dir: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\bin
Creating dir: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc
Creating dir: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\system
Creating dir: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\deploy
Creating dir: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\data
Creating file: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\config.properties
Creating file: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\org.apache.servicemix.features.cfg
Creating file: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\users.properties
Creating file: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\org.ops4j.pax.logging.cfg
Creating file: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\org.ops4j.pax.url.mvn.cfg
Creating file: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\startup.properties
Creating file: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\system.properties
Creating file: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\org.apache.servicemix.shell.cfg
Creating file: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\bin\servicemix.bat
smx@root:admin> start foo
smx@root:admin> list
  Port State Pid Name
[ 8103] [Starting] [ 5152] foo
smx@root:admin> list
  Port State Pid Name
[ 8103] [Starting] [ 5152] foo
smx@root:admin> connect foo
Connecting to: localhost:8103
ERROR CommandLineExecutionFailed: org.apache.geronimo.gshell.command.CommandException: org.apache.ge
ronimo.gshell.commandline.CommandLineExecutionFailed: org.apache.geronimo.gshell.command.CommandExce
ption: org.apache.sshd.common.RuntimeSshException: Failed to get the session.
smx@root:admin>
{code}

The log from instances/foo/data/log/servicemix.log shows the following:
{quote}
10:58:24,954 | INFO | FelixStartLevel | ExtenderConfiguration | al.support.ExtenderConfiguration 140 | No custom extender configuration detected; using defaults...
10:58:24,954 | INFO | FelixStartLevel | TimerTaskExecutor | heduling.timer.TimerTaskExecutor 90 | Initializing Timer
10:58:24,985 | WARN | pool-1-thread-1 | FileMonitor | x.kernel.filemonitor.FileMonitor 272 | Unsupported deployment: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\system.properties
10:58:24,985 | WARN | pool-1-thread-1 | FileMonitor | x.kernel.filemonitor.FileMonitor 272 | Unsupported deployment: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\config.properties
10:58:24,985 | WARN | pool-1-thread-1 | FileMonitor | x.kernel.filemonitor.FileMonitor 272 | Unsupported deployment: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\users.properties
10:58:24,985 | WARN | pool-1-thread-1 | FileMonitor | x.kernel.filemonitor.FileMonitor 272 | Unsupported deployment: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\startup.properties
10:58:25,017 | INFO | FelixStartLevel | ultOsgiApplicationContextCreator | ultOsgiApplicationContextCreator 67 | Discovered configurations {osgibundle:/META-INF/spring/*.xml} in bundle [Apache ServiceMix Kernel :: Management (org.apache.servicemix.kernel.management)]
10:58:25,048 | INFO | FelixStartLevel | ultOsgiApplicationContextCreator | ultOsgiApplicationContextCreator 67 | Discovered configurations {osgibundle:/META-INF/spring/*.xml} in bundle [Apache ServiceMix Kernel :: JAAS Config (org.apache.servicemix.kernel.jaas.config)]
10:58:25,064 | INFO | ExtenderThread-1 | OsgiBundleXmlApplicationContext | pport.AbstractApplicationContext 411 | Refreshing org.springframework.osgi.context.support.OsgiBundleXmlApplicationContext@1a5db4b: display name [OsgiBundleXmlApplicationContext(bundle=org.apache.servicemix.kernel.management, config=osgibundle:/META-INF/spring/*.xml)]; startup date [Tue Jul 28 10:58:25 BST 2009]; root of context hierarchy
10:58:25,095 | INFO | FelixStartLevel | OsgiBundleXmlApplicationContext | pport.AbstractApplicationContext 411 | Refreshing org.springframework.osgi.context.support.OsgiBundleXmlApplicationContext@b0095d: display name [OsgiBundleXmlApplicationContext(bundle=org.apache.servicemix.kernel.jaas.config, config=osgibundle:/META-INF/spring/*.xml)]; startup date [Tue Jul 28 10:58:25 BST 2009]; root of context hierarchy
10:58:25,142 | INFO | ExtenderThread-1 | XmlBeanDefinitionReader | tory.xml.XmlBeanDefinitionReader 323 | Loading XML bean definitions from URL [bundle://13.0:0/META-INF/spring/servicemix-management.xml]
10:58:25,142 | INFO | FelixStartLevel | XmlBeanDefinitionReader | tory.xml.XmlBeanDefinitionReader 323 | Loading XML bean definitions from URL [bundle://16.0:0/META-INF/spring/servicemix-jaas.xml]
10:58:25,751 | INFO | FelixStartLevel | OsgiBundleXmlApplicationContext | pport.AbstractApplicationContext 426 | Bean factory for application context [org.springframework.osgi.context.support.OsgiBundleXmlApplicationContext@b0095d]: org.springframework.beans.factory.support.DefaultListableBeanFactory@6cef4
10:58:25,782 | INFO | ExtenderThread-1 | OsgiBundleXmlApplicationContext | pport.AbstractApplicationContext 426 | Bean factory for application context [org.springframework.osgi.context.support.OsgiBundleXmlApplicationContext@1a5db4b]: org.springframework.beans.factory.support.DefaultListableBeanFactory@1d709a5
10:58:25,814 | INFO | ExtenderThread-1 | WaiterApplicationContextExecutor | WaiterApplicationContextExecutor 245 | No outstanding OSGi service dependencies, completing initialization for OsgiBundleXmlApplicationContext(bundle=org.apache.servicemix.kernel.management, config=osgibundle:/META-INF/spring/*.xml)
10:58:25,814 | INFO | FelixStartLevel | WaiterApplicationContextExecutor | WaiterApplicationContextExecutor 245 | No outstanding OSGi service dependencies, completing initialization for OsgiBundleXmlApplicationContext(bundle=org.apache.servicemix.kernel.jaas.config, config=osgibundle:/META-INF/spring/*.xml)
10:58:25,814 | INFO | FelixStartLevel | DefaultListableBeanFactory | pport.DefaultListableBeanFactory 414 | Pre-instantiating singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@6cef4: defining beans [config,realms,proxyLoginModuleInitializer,keystoreManager,org.springframework.osgi.service.exporter.support.OsgiServiceFactoryBean#0,keystores]; root of factory hierarchy
10:58:25,814 | INFO | ExtenderThread-2 | DefaultListableBeanFactory | pport.DefaultListableBeanFactory 414 | Pre-instantiating singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@1d709a5: defining beans [mbeanServer,org.springframework.osgi.service.exporter.support.OsgiServiceFactoryBean#0,rmiRegistry,jmxConnectorService,jmxConnectorEnvironment,jaasAuthenticator,cmProps,org.springframework.beans.factory.config.PropertyPlaceholderConfigurer#0]; root of factory hierarchy
10:58:25,829 | INFO | ExtenderThread-2 | OsgiServiceFactoryBean | r.support.OsgiServiceFactoryBean 299 | Publishing service under classes [{javax.management.MBeanServer}]
10:58:25,845 | INFO | FelixStartLevel | OsgiServiceFactoryBean | r.support.OsgiServiceFactoryBean 299 | Publishing service under classes [{org.apache.servicemix.kernel.jaas.config.KeystoreManager}]
10:58:25,845 | INFO | FelixStartLevel | OsgiBundleXmlApplicationContext | ractOsgiBundleApplicationContext 345 | Not publishing application context OSGi service for bundle Apache ServiceMix Kernel :: JAAS Config (org.apache.servicemix.kernel.jaas.config)
10:58:25,876 | INFO | FelixStartLevel | ultOsgiApplicationContextCreator | ultOsgiApplicationContextCreator 67 | Discovered configurations {osgibundle:/META-INF/spring/*.xml} in bundle [Apache ServiceMix Kernel :: JAAS Modules (org.apache.servicemix.kernel.jaas.modules)]
10:58:25,892 | INFO | FelixStartLevel | OsgiBundleXmlApplicationContext | pport.AbstractApplicationContext 411 | Refreshing org.springframework.osgi.context.support.OsgiBundleXmlApplicationContext@1bbbafc: display name [OsgiBundleXmlApplicationContext(bundle=org.apache.servicemix.kernel.jaas.modules, config=osgibundle:/META-INF/spring/*.xml)]; startup date [Tue Jul 28 10:58:25 BST 2009]; root of context hierarchy
10:58:25,892 | INFO | FelixStartLevel | XmlBeanDefinitionReader | tory.xml.XmlBeanDefinitionReader 323 | Loading XML bean definitions from URL [bundle://34.0:0/META-INF/spring/servicemix-jaas-module.xml]
10:58:25,907 | INFO | ExtenderThread-2 | ConnectorServerFactoryBean | pport.ConnectorServerFactoryBean 172 | JMX connector server started: javax.management.remote.rmi.RMIConnectorServer@1cfd3b2
10:58:25,907 | INFO | ExtenderThread-2 | OsgiBundleXmlApplicationContext | ractOsgiBundleApplicationContext 345 | Not publishing application context OSGi service for bundle Apache ServiceMix Kernel :: Management (org.apache.servicemix.kernel.management)
10:58:25,954 | INFO | FelixStartLevel | OsgiBundleXmlApplicationContext | pport.AbstractApplicationContext 426 | Bean factory for application context [org.springframework.osgi.context.support.OsgiBundleXmlApplicationContext@1bbbafc]: org.springframework.beans.factory.support.DefaultListableBeanFactory@23d275
10:58:25,970 | INFO | FelixStartLevel | WaiterApplicationContextExecutor | WaiterApplicationContextExecutor 245 | No outstanding OSGi service dependencies, completing initialization for OsgiBundleXmlApplicationContext(bundle=org.apache.servicemix.kernel.jaas.modules, config=osgibundle:/META-INF/spring/*.xml)
10:58:25,970 | INFO | FelixStartLevel | DefaultListableBeanFactory | pport.DefaultListableBeanFactory 414 | Pre-instantiating singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@23d275: defining beans [org.springframework.beans.factory.config.PropertyPlaceholderConfigurer#0,org.springframework.osgi.service.exporter.support.OsgiServiceFactoryBean#0,servicemix]; root of factory hierarchy
10:58:25,985 | INFO | FelixStartLevel | OsgiServiceFactoryBean | r.support.OsgiServiceFactoryBean 299 | Publishing service under classes [{org.apache.servicemix.kernel.jaas.config.JaasRealm}]
10:58:26,064 | INFO | FelixStartLevel | OsgiBundleXmlApplicationContext | ractOsgiBundleApplicationContext 345 | Not publishing application context OSGi service for bundle Apache ServiceMix Kernel :: JAAS Modules (org.apache.servicemix.kernel.jaas.modules)
10:58:26,110 | INFO | FelixStartLevel | ultOsgiApplicationContextCreator | ultOsgiApplicationContextCreator 67 | Discovered configurations {osgibundle:/META-INF/spring/*.xml} in bundle [Apache ServiceMix Kernel :: Spring Deployer (org.apache.servicemix.kernel.spring)]
10:58:26,157 | INFO | FelixStartLevel | OsgiBundleXmlApplicationContext | pport.AbstractApplicationContext 411 | Refreshing org.springframework.osgi.context.support.OsgiBundleXmlApplicationContext@1751a9e: display name [OsgiBundleXmlApplicationContext(bundle=org.apache.servicemix.kernel.spring, config=osgibundle:/META-INF/spring/*.xml)]; startup date [Tue Jul 28 10:58:26 BST 2009]; root of context hierarchy
10:58:26,157 | INFO | FelixStartLevel | XmlBeanDefinitionReader | tory.xml.XmlBeanDefinitionReader 323 | Loading XML bean definitions from URL [bundle://37.0:0/META-INF/spring/spring-deployer.xml]
10:58:26,251 | INFO | FelixStartLevel | OsgiBundleXmlApplicationContext | pport.AbstractApplicationContext 426 | Bean factory for application context [org.springframework.osgi.context.support.OsgiBundleXmlApplicationContext@1751a9e]: org.springframework.beans.factory.support.DefaultListableBeanFactory@ad339b
10:58:26,267 | INFO | FelixStartLevel | WaiterApplicationContextExecutor | WaiterApplicationContextExecutor 245 | No outstanding OSGi service dependencies, completing initialization for OsgiBundleXmlApplicationContext(bundle=org.apache.servicemix.kernel.spring, config=osgibundle:/META-INF/spring/*.xml)
10:58:26,267 | INFO | FelixStartLevel | DefaultListableBeanFactory | pport.DefaultListableBeanFactory 414 | Pre-instantiating singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@ad339b: defining beans [springDeploymentListener,org.springframework.osgi.service.exporter.support.OsgiServiceFactoryBean#0,springHandler,org.springframework.osgi.service.exporter.support.OsgiServiceFactoryBean#1]; root of factory hierarchy
10:58:26,267 | INFO | FelixStartLevel | OsgiServiceFactoryBean | r.support.OsgiServiceFactoryBean 299 | Publishing service under classes [{org.apache.servicemix.kernel.filemonitor.DeploymentListener}]
10:58:26,267 | INFO | FelixStartLevel | OsgiServiceFactoryBean | r.support.OsgiServiceFactoryBean 299 | Publishing service under classes [{org.osgi.service.url.URLStreamHandlerService}]
10:58:26,267 | INFO | FelixStartLevel | OsgiBundleXmlApplicationContext | ractOsgiBundleApplicationContext 345 | Not publishing application context OSGi service for bundle Apache ServiceMix Kernel :: Spring Deployer (org.apache.servicemix.kernel.spring)
10:58:26,282 | WARN | pool-1-thread-1 | FileMonitor | x.kernel.filemonitor.FileMonitor 272 | Unsupported deployment: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\system.properties
10:58:26,282 | WARN | pool-1-thread-1 | FileMonitor | x.kernel.filemonitor.FileMonitor 272 | Unsupported deployment: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\config.properties
10:58:26,282 | WARN | pool-1-thread-1 | FileMonitor | x.kernel.filemonitor.FileMonitor 272 | Unsupported deployment: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\users.properties
10:58:26,282 | WARN | pool-1-thread-1 | FileMonitor | x.kernel.filemonitor.FileMonitor 272 | Unsupported deployment: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\startup.properties
{quote} 		Using a completely fresh install of Fuse ESB 4.1.0.2 and started it by ./bin/servicemix. Then from the console do:

admin/create foo
admin/start foo

The instance is created, with an instances/foo directory seemingly populated OK, but the instance never starts properly and the instance cannot be connected to:
{code}
smx@root:admin> create foo
Creating new instance on port 8103 at: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo
Creating dir: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\bin
Creating dir: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc
Creating dir: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\system
Creating dir: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\deploy
Creating dir: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\data
Creating file: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\config.properties
Creating file: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\org.apache.servicemix.features.cfg
Creating file: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\users.properties
Creating file: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\org.ops4j.pax.logging.cfg
Creating file: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\org.ops4j.pax.url.mvn.cfg
Creating file: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\startup.properties
Creating file: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\system.properties
Creating file: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\org.apache.servicemix.shell.cfg
Creating file: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\bin\servicemix.bat
smx@root:admin> start foo
smx@root:admin> list
  Port State Pid Name
[ 8103] [Starting] [ 5152] foo
smx@root:admin> list
  Port State Pid Name
[ 8103] [Starting] [ 5152] foo
smx@root:admin> connect foo
Connecting to: localhost:8103
ERROR CommandLineExecutionFailed: org.apache.geronimo.gshell.command.CommandException: org.apache.ge
ronimo.gshell.commandline.CommandLineExecutionFailed: org.apache.geronimo.gshell.command.CommandExce
ption: org.apache.sshd.common.RuntimeSshException: Failed to get the session.
smx@root:admin>
{code}

The log from instances/foo/data/log/servicemix.log shows the following:
{quote}
10:58:26,267 | INFO | FelixStartLevel | OsgiServiceFactoryBean | r.support.OsgiServiceFactoryBean 299 | Publishing service under classes [{org.osgi.service.url.URLStreamHandlerService}]
10:58:26,267 | INFO | FelixStartLevel | OsgiBundleXmlApplicationContext | ractOsgiBundleApplicationContext 345 | Not publishing application context OSGi service for bundle Apache ServiceMix Kernel :: Spring Deployer (org.apache.servicemix.kernel.spring)
10:58:26,282 | WARN | pool-1-thread-1 | FileMonitor | x.kernel.filemonitor.FileMonitor 272 | Unsupported deployment: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\system.properties
10:58:26,282 | WARN | pool-1-thread-1 | FileMonitor | x.kernel.filemonitor.FileMonitor 272 | Unsupported deployment: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\config.properties
10:58:26,282 | WARN | pool-1-thread-1 | FileMonitor | x.kernel.filemonitor.FileMonitor 272 | Unsupported deployment: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\users.properties
10:58:26,282 | WARN | pool-1-thread-1 | FileMonitor | x.kernel.filemonitor.FileMonitor 272 | Unsupported deployment: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\startup.properties
{quote}
Joe Luo made changes - 28/Jul/09 11:12 AM
Description Using a completely fresh install of Fuse ESB 4.1.0.2 and started it by ./bin/servicemix. Then from the console do:

admin/create foo
admin/start foo

The instance is created, with an instances/foo directory seemingly populated OK, but the instance never starts properly and the instance cannot be connected to:
{code}
smx@root:admin> create foo
Creating new instance on port 8103 at: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo
Creating dir: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\bin
Creating dir: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc
Creating dir: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\system
Creating dir: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\deploy
Creating dir: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\data
Creating file: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\config.properties
Creating file: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\org.apache.servicemix.features.cfg
Creating file: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\users.properties
Creating file: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\org.ops4j.pax.logging.cfg
Creating file: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\org.ops4j.pax.url.mvn.cfg
Creating file: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\startup.properties
Creating file: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\system.properties
Creating file: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\org.apache.servicemix.shell.cfg
Creating file: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\bin\servicemix.bat
smx@root:admin> start foo
smx@root:admin> list
  Port State Pid Name
[ 8103] [Starting] [ 5152] foo
smx@root:admin> list
  Port State Pid Name
[ 8103] [Starting] [ 5152] foo
smx@root:admin> connect foo
Connecting to: localhost:8103
ERROR CommandLineExecutionFailed: org.apache.geronimo.gshell.command.CommandException: org.apache.ge
ronimo.gshell.commandline.CommandLineExecutionFailed: org.apache.geronimo.gshell.command.CommandExce
ption: org.apache.sshd.common.RuntimeSshException: Failed to get the session.
smx@root:admin>
{code}

The log from instances/foo/data/log/servicemix.log shows the following:
{quote}
10:58:26,267 | INFO | FelixStartLevel | OsgiServiceFactoryBean | r.support.OsgiServiceFactoryBean 299 | Publishing service under classes [{org.osgi.service.url.URLStreamHandlerService}]
10:58:26,267 | INFO | FelixStartLevel | OsgiBundleXmlApplicationContext | ractOsgiBundleApplicationContext 345 | Not publishing application context OSGi service for bundle Apache ServiceMix Kernel :: Spring Deployer (org.apache.servicemix.kernel.spring)
10:58:26,282 | WARN | pool-1-thread-1 | FileMonitor | x.kernel.filemonitor.FileMonitor 272 | Unsupported deployment: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\system.properties
10:58:26,282 | WARN | pool-1-thread-1 | FileMonitor | x.kernel.filemonitor.FileMonitor 272 | Unsupported deployment: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\config.properties
10:58:26,282 | WARN | pool-1-thread-1 | FileMonitor | x.kernel.filemonitor.FileMonitor 272 | Unsupported deployment: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\users.properties
10:58:26,282 | WARN | pool-1-thread-1 | FileMonitor | x.kernel.filemonitor.FileMonitor 272 | Unsupported deployment: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\startup.properties
{quote} 		Using a completely fresh install of Fuse ESB 4.1.0.2 and started it by ./bin/servicemix. Then from the console do:

admin/create foo
admin/start foo

The instance is created, with an instances/foo directory seemingly populated OK, but the instance never starts properly and the instance cannot be connected to:
{code}
smx@root:admin> create foo
Creating new instance on port 8103 at: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo
Creating dir: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\bin
Creating dir: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc
Creating dir: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\system
Creating dir: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\deploy
Creating dir: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\data
Creating file: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\config.properties
Creating file: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\org.apache.servicemix.features.cfg
Creating file: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\users.properties
Creating file: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\org.ops4j.pax.logging.cfg
Creating file: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\org.ops4j.pax.url.mvn.cfg
Creating file: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\startup.properties
Creating file: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\system.properties
Creating file: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\org.apache.servicemix.shell.cfg
Creating file: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\bin\servicemix.bat
smx@root:admin> start foo
smx@root:admin> list
  Port State Pid Name
[ 8103] [Starting] [ 5152] foo
smx@root:admin> list
  Port State Pid Name
[ 8103] [Starting] [ 5152] foo
smx@root:admin> connect foo
Connecting to: localhost:8103
ERROR CommandLineExecutionFailed: org.apache.geronimo.gshell.command.CommandException: org.apache.ge
ronimo.gshell.commandline.CommandLineExecutionFailed: org.apache.geronimo.gshell.command.CommandExce
ption: org.apache.sshd.common.RuntimeSshException: Failed to get the session.
smx@root:admin>
{code}

The log from instances/foo/data/log/servicemix.log shows the following:
{quote}
10:58:26,267 | INFO | FelixStartLevel | OsgiServiceFactoryBean | r.support.OsgiServiceFactoryBean 299 | Publishing service under classes (org.osgi.service.url.URLStreamHandlerService)
10:58:26,267 | INFO | FelixStartLevel | OsgiBundleXmlApplicationContext | ractOsgiBundleApplicationContext 345 | Not publishing application context OSGi service for bundle Apache ServiceMix Kernel :: Spring Deployer (org.apache.servicemix.kernel.spring)
10:58:26,282 | WARN | pool-1-thread-1 | FileMonitor | x.kernel.filemonitor.FileMonitor 272 | Unsupported deployment: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\system.properties
10:58:26,282 | WARN | pool-1-thread-1 | FileMonitor | x.kernel.filemonitor.FileMonitor 272 | Unsupported deployment: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\config.properties
10:58:26,282 | WARN | pool-1-thread-1 | FileMonitor | x.kernel.filemonitor.FileMonitor 272 | Unsupported deployment: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\users.properties
10:58:26,282 | WARN | pool-1-thread-1 | FileMonitor | x.kernel.filemonitor.FileMonitor 272 | Unsupported deployment: E:\fuse\esb\fuse-esb-4.1.0.2\instances\foo\etc\startup.properties
{quote}
[ Permlink | « Hide ]
Joe Luo added a comment - 28/Jul/09 11:13 AM
Here is complete log file from the instance "foo".

Joe Luo made changes - 28/Jul/09 11:13 AM
Attachment servicemix.log [ 14157 ]
Martin Murphy made changes - 07/Aug/09 12:52 PM
Link This issue fixes PROD-73 [ PROD-73 ]
Aileen Cunningham made changes - 07/Aug/09 03:11 PM
Fix Version/s 4.2.0.0-fuse [ 10521 ]
Aileen Cunningham made changes - 07/Aug/09 03:24 PM
Assignee Rob Davies [ rajdavies ] Guillaume Nodet [ gnodet ]
[ Permlink | « Hide ]
Guillaume Nodet added a comment - 12/Aug/09 02:24 PM
This log file is ok. These warnings can be safely ignored.
It would be interesting to have the log at DEBUG level maybe.

[ Permlink | « Hide ]
Martin Murphy added a comment - 13/Aug/09 08:36 AM - edited
I think the problem here is that the instance is always in a Starting state and can never be connected to: 
smx@root:admin> connect foo
Connecting to: localhost:8103
ERROR CommandLineExecutionFailed: org.apache.geronimo.gshell.command.CommandException: org.apache.ge
ronimo.gshell.commandline.CommandLineExecutionFailed: org.apache.geronimo.gshell.command.CommandExce
ption: org.apache.sshd.common.RuntimeSshException: Failed to get the session.
smx@root:admin>

I turned on the debug logs and will attach them here now. It looks like the start works:

09:26:06,793 | DEBUG | localShell | CommandResolverImpl | dom.registry.CommandResolverImpl 88 | Resolving command name: admin/start
09:26:06,793 | DEBUG | localShell | SoftRefFilesCache | mons.vfs.cache.SoftRefFilesCache 144 | putFile: meta:/aliases/admin/start
09:26:06,793 | DEBUG | localShell | SoftRefFilesCache | mons.vfs.cache.SoftRefFilesCache 144 | putFile: meta:/admin/start
09:26:06,793 | DEBUG | localShell | SoftRefFilesCache | mons.vfs.cache.SoftRefFilesCache 144 | putFile: meta:/commands/admin/start
09:26:06,793 | DEBUG | localShell | SoftRefFilesCache | mons.vfs.cache.SoftRefFilesCache 144 | putFile: meta:/admin/start
09:26:06,793 | DEBUG | localShell | CommandResolverImpl | dom.registry.CommandResolverImpl 110 | Resolved command: org.apache.geronimo.gshell.wisdom.command.StatefulCommand@d021d9
09:26:06,793 | DEBUG | localShell | DefaultListableBeanFactory | ractAutowireCapableBeanFactory$1 383 | Creating instance of bean 'org.apache.servicemix.kernel.gshell.admin.internal.commands.StartCommand#0'
09:26:06,793 | DEBUG | localShell | DefaultListableBeanFactory | tory.support.AbstractBeanFactory 214 | Returning cached instance of singleton bean 'adminService'
09:26:06,793 | DEBUG | localShell | CachedIntrospectionResults | beans.CachedIntrospectionResults 151 | Not strongly caching class [org.apache.servicemix.kernel.gshell.admin.internal.commands.StartCommand] because it is not cache-safe
09:26:06,793 | DEBUG | localShell | DefaultListableBeanFactory | ractAutowireCapableBeanFactory$1 411 | Finished creating instance of bean 'org.apache.servicemix.kernel.gshell.admin.internal.commands.StartCommand#0'
09:26:06,793 | DEBUG | localShell | InstanceImpl | hell.admin.internal.InstanceImpl 139 | Starting instance with command: C:\tools\java\jdk1.5.0_18\jre\bin\java.exe -server -Xmx512M -Dcom.sun.management.jmxremote -Dservicemix.home="C:\opensource\built\fuse\esb\4.1.0.2" -Dservicemix.base="C:\opensource\built\fuse\esb\4.1.0.2\instances\foo" -Dservicemix.startLocalConsole=false -Dservicemix.startRemoteShell=true -classpath C:\opensource\built\fuse\esb\4.1.0.2\lib\servicemix-client.jar;C:\opensource\built\fuse\esb\4.1.0.2\lib\servicemix-jaas-boot.jar;C:\opensource\built\fuse\esb\4.1.0.2\lib\servicemix-version.jar;C:\opensource\built\fuse\esb\4.1.0.2\lib\servicemix.jar org.apache.servicemix.kernel.main.Main
09:26:07,262 | DEBUG | ActiveMQ Task | AMQPersistenceAdapter | .store.amq.AMQPersistenceAdapter 383 | Checkpoint started.
09:26:07,262 | DEBUG | ActiveMQ Task | AMQPersistenceAdapter | .store.amq.AMQPersistenceAdapter 416 | Checkpoint done.
09:26:07,262 | DEBUG | localShell | CommandLineExecutorImpl | om.shell.CommandLineExecutorImpl 129 | Command completed with result: ValueResult

Unknown macro: { value=SUCCESS, failure=<null>, notification=<null> }
, after: 0:00:00.469

It seems the mina socket gets a connection refused when trying to connect to the instance then:

09:26:17,949 | DEBUG | localShell | CommandResolverImpl | dom.registry.CommandResolverImpl 88 | Resolving command name: admin/connect
09:26:17,949 | DEBUG | localShell | SoftRefFilesCache | mons.vfs.cache.SoftRefFilesCache 144 | putFile: meta:/aliases/admin/connect
09:26:17,949 | DEBUG | localShell | SoftRefFilesCache | mons.vfs.cache.SoftRefFilesCache 144 | putFile: meta:/admin/connect
09:26:17,965 | DEBUG | localShell | SoftRefFilesCache | mons.vfs.cache.SoftRefFilesCache 144 | putFile: meta:/commands/admin/connect
09:26:17,965 | DEBUG | localShell | SoftRefFilesCache | mons.vfs.cache.SoftRefFilesCache 144 | putFile: meta:/admin/connect
09:26:17,965 | DEBUG | localShell | CommandResolverImpl | dom.registry.CommandResolverImpl 110 | Resolved command: org.apache.geronimo.gshell.wisdom.command.StatefulCommand@e1cfa7
09:26:17,965 | DEBUG | localShell | DefaultListableBeanFactory | ractAutowireCapableBeanFactory$1 383 | Creating instance of bean 'org.apache.servicemix.kernel.gshell.admin.internal.commands.ConnectCommand#0'
09:26:17,965 | DEBUG | localShell | DefaultListableBeanFactory | tory.support.AbstractBeanFactory 214 | Returning cached instance of singleton bean 'adminService'
09:26:17,965 | DEBUG | localShell | CachedIntrospectionResults | beans.CachedIntrospectionResults 151 | Not strongly caching class [org.apache.servicemix.kernel.gshell.admin.internal.commands.ConnectCommand] because it is not cache-safe
09:26:17,965 | DEBUG | localShell | DefaultListableBeanFactory | ractAutowireCapableBeanFactory$1 411 | Finished creating instance of bean 'org.apache.servicemix.kernel.gshell.admin.internal.commands.ConnectCommand#0'
09:26:17,965 | INFO | localShell | CommandLineExecutorImpl | om.shell.CommandLineExecutorImpl 64 | Executing (String): ssh -l smx -P smx -p 8102 localhost
09:26:17,965 | DEBUG | localShell | CommandLineBuilderImpl | dom.shell.CommandLineBuilderImpl 80 | Building command-line for: ssh -l smx -P smx -p 8102 localhost
09:26:17,965 | DEBUG | localShell | CommandLineParser | .gshell.parser.CommandLineParser 25 | Parsing from reader: java.io.StringReader@1e2c00f
09:26:17,965 | DEBUG | localShell | CommandLineBuilderImpl | ll.parser.visitor.LoggingVisitor 101 | CommandLine (org.apache.geronimo.gshell.parser.ASTCommandLine)
09:26:17,965 | DEBUG | localShell | CommandLineBuilderImpl | ll.parser.visitor.LoggingVisitor 101 | Expression (org.apache.geronimo.gshell.parser.ASTExpression)
09:26:17,965 | DEBUG | localShell | CommandLineBuilderImpl | ll.parser.visitor.LoggingVisitor 101 | Process (org.apache.geronimo.gshell.parser.ASTProcess)
09:26:17,965 | DEBUG | localShell | CommandLineBuilderImpl | ll.parser.visitor.LoggingVisitor 101 | PlainString( ssh ) (org.apache.geronimo.gshell.parser.ASTPlainString)
09:26:17,965 | DEBUG | localShell | CommandLineBuilderImpl | ll.parser.visitor.LoggingVisitor 101 | PlainString( -l ) (org.apache.geronimo.gshell.parser.ASTPlainString)
09:26:17,965 | DEBUG | localShell | CommandLineBuilderImpl | ll.parser.visitor.LoggingVisitor 101 | PlainString( smx ) (org.apache.geronimo.gshell.parser.ASTPlainString)
09:26:17,965 | DEBUG | localShell | CommandLineBuilderImpl | ll.parser.visitor.LoggingVisitor 101 | PlainString( -P ) (org.apache.geronimo.gshell.parser.ASTPlainString)
09:26:17,965 | DEBUG | localShell | CommandLineBuilderImpl | ll.parser.visitor.LoggingVisitor 101 | PlainString( smx ) (org.apache.geronimo.gshell.parser.ASTPlainString)
09:26:17,965 | DEBUG | localShell | CommandLineBuilderImpl | ll.parser.visitor.LoggingVisitor 101 | PlainString( -p ) (org.apache.geronimo.gshell.parser.ASTPlainString)
09:26:17,965 | DEBUG | localShell | CommandLineBuilderImpl | ll.parser.visitor.LoggingVisitor 101 | PlainString( 8102 ) (org.apache.geronimo.gshell.parser.ASTPlainString)
09:26:17,965 | DEBUG | localShell | CommandLineBuilderImpl | ll.parser.visitor.LoggingVisitor 101 | PlainString( localhost ) (org.apache.geronimo.gshell.parser.ASTPlainString)
09:26:17,965 | INFO | localShell | CommandLineExecutorImpl | om.shell.CommandLineExecutorImpl 104 | Executing (ssh): [-l, smx, -P, smx, -p, 8102, localhost]
09:26:17,965 | DEBUG | localShell | CommandLineExecutorImpl | om.shell.CommandLineExecutorImpl 112 | Executing
09:26:17,965 | DEBUG | localShell | CommandResolverImpl | dom.registry.CommandResolverImpl 88 | Resolving command name: ssh
09:26:17,965 | DEBUG | localShell | SoftRefFilesCache | mons.vfs.cache.SoftRefFilesCache 144 | putFile: meta:/aliases/ssh
09:26:17,965 | DEBUG | localShell | SoftRefFilesCache | mons.vfs.cache.SoftRefFilesCache 144 | putFile: meta:/ssh
09:26:17,965 | DEBUG | localShell | SoftRefFilesCache | mons.vfs.cache.SoftRefFilesCache 144 | putFile: meta:/commands/ssh
09:26:17,965 | DEBUG | localShell | SoftRefFilesCache | mons.vfs.cache.SoftRefFilesCache 144 | putFile: meta:/ssh
09:26:17,965 | DEBUG | localShell | CommandResolverImpl | dom.registry.CommandResolverImpl 110 | Resolved command: org.apache.geronimo.gshell.wisdom.command.StatefulCommand@1f960c4
09:26:17,980 | DEBUG | localShell | DefaultListableBeanFactory | ractAutowireCapableBeanFactory$1 383 | Creating instance of bean 'org.apache.geronimo.gshell.commands.ssh.SshAction#0'
09:26:17,980 | DEBUG | localShell | DefaultListableBeanFactory | stractAutowireCapableBeanFactory 1401 | No default init method named 'init' found on bean with name 'org.apache.geronimo.gshell.commands.ssh.SshAction#0'
09:26:17,980 | DEBUG | localShell | DefaultListableBeanFactory | ractAutowireCapableBeanFactory$1 411 | Finished creating instance of bean 'org.apache.geronimo.gshell.commands.ssh.SshAction#0'
09:26:18,011 | DEBUG | localShell | DefaultListableBeanFactory | tory.support.AbstractBeanFactory 214 | Returning cached instance of singleton bean 'sshClient'
09:26:18,011 | DEBUG | localShell | SshAction | mo.gshell.commands.ssh.SshAction 135 | Created client: org.apache.sshd.SshClient@1c3dfe
09:26:18,965 | DEBUG | localShell | CommandLineExecutorImpl | om.shell.CommandLineExecutorImpl 129 | Command completed with result: FailureResult

Unknown macro: { value=<null>, failure=org.apache.sshd.common.RuntimeSshException}
, after: 0:00:01.000
09:26:18,965 | DEBUG | localShell | CommandLineExecutorImpl | om.shell.CommandLineExecutorImpl 129 | Command completed with result: FailureResult
Unknown macro: { value=<null>, failure=org.apache.geronimo.gshell.commandline.CommandLineExecutionFailed}
, after: 0:00:01.000
09:26:18,965 | DEBUG | localShell | JLineConsole | .geronimo.gshell.console.Console 132 | Work failed: org.apache.geronimo.gshell.commandline.CommandLineExecutionFailed: org.apache.geronimo.gshell.command.CommandException: org.apache.geronimo.gshell.commandline.CommandLineExecutionFailed: org.apache.geronimo.gshell.command.CommandException: org.apache.sshd.common.RuntimeSshException: Failed to get the session.
org.apache.geronimo.gshell.commandline.CommandLineExecutionFailed: org.apache.geronimo.gshell.command.CommandException: org.apache.geronimo.gshell.commandline.CommandLineExecutionFailed: org.apache.geronimo.gshell.command.CommandException: org.apache.sshd.common.RuntimeSshException: Failed to get the session.
at org.apache.geronimo.gshell.parser.visitor.ExecutingVisitor.executePiped(ExecutingVisitor.java:246)
at org.apache.geronimo.gshell.parser.visitor.ExecutingVisitor.visit(ExecutingVisitor.java:107)
at org.apache.geronimo.gshell.parser.ASTExpression.jjtAccept(ASTExpression.java:17)
at org.apache.geronimo.gshell.parser.SimpleNode.childrenAccept(SimpleNode.java:61)
at org.apache.geronimo.gshell.parser.visitor.ExecutingVisitor.visit(ExecutingVisitor.java:90)
at org.apache.geronimo.gshell.parser.ASTCommandLine.jjtAccept(ASTCommandLine.java:17)
at org.apache.geronimo.gshell.wisdom.shell.CommandLineBuilderImpl$1.execute(CommandLineBuilderImpl.java:96)
at org.apache.geronimo.gshell.wisdom.shell.CommandLineExecutorImpl.execute(CommandLineExecutorImpl.java:71)
at org.apache.geronimo.gshell.wisdom.shell.ShellImpl.execute(ShellImpl.java:172)
at org.apache.geronimo.gshell.wisdom.shell.ShellImpl$2.execute(ShellImpl.java:208)
at org.apache.geronimo.gshell.console.Console.work(Console.java:187)
at org.apache.geronimo.gshell.console.Console.run(Console.java:128)
at org.apache.geronimo.gshell.wisdom.shell.ShellImpl.run(ShellImpl.java:252)
at org.apache.servicemix.kernel.gshell.core.ShellWrapper.run(ShellWrapper.java:81)
at org.apache.servicemix.kernel.gshell.core.LocalConsole.run(LocalConsole.java:125)
at java.lang.Thread.run(Thread.java:595)
Caused by: org.apache.geronimo.gshell.command.CommandException: org.apache.geronimo.gshell.commandline.CommandLineExecutionFailed: org.apache.geronimo.gshell.command.CommandException: org.apache.sshd.common.RuntimeSshException: Failed to get the session.
at org.apache.geronimo.gshell.wisdom.shell.CommandLineExecutorImpl.doExecute(CommandLineExecutorImpl.java:148)
at org.apache.geronimo.gshell.wisdom.shell.CommandLineExecutorImpl.execute(CommandLineExecutorImpl.java:106)
at org.apache.geronimo.gshell.parser.visitor.ExecutingVisitor$1.run(ExecutingVisitor.java:208)
at org.apache.geronimo.gshell.parser.visitor.ExecutingVisitor.executePiped(ExecutingVisitor.java:231)
... 15 more
Caused by: org.apache.geronimo.gshell.commandline.CommandLineExecutionFailed: org.apache.geronimo.gshell.command.CommandException: org.apache.sshd.common.RuntimeSshException: Failed to get the session.
at org.apache.geronimo.gshell.parser.visitor.ExecutingVisitor.executePiped(ExecutingVisitor.java:246)
at org.apache.geronimo.gshell.parser.visitor.ExecutingVisitor.visit(ExecutingVisitor.java:107)
at org.apache.geronimo.gshell.parser.ASTExpression.jjtAccept(ASTExpression.java:17)
at org.apache.geronimo.gshell.parser.SimpleNode.childrenAccept(SimpleNode.java:61)
at org.apache.geronimo.gshell.parser.visitor.ExecutingVisitor.visit(ExecutingVisitor.java:90)
at org.apache.geronimo.gshell.parser.ASTCommandLine.jjtAccept(ASTCommandLine.java:17)
at org.apache.geronimo.gshell.wisdom.shell.CommandLineBuilderImpl$1.execute(CommandLineBuilderImpl.java:96)
at org.apache.geronimo.gshell.wisdom.shell.CommandLineExecutorImpl.execute(CommandLineExecutorImpl.java:71)
at org.apache.geronimo.gshell.wisdom.shell.ShellImpl.execute(ShellImpl.java:172)
at org.apache.servicemix.kernel.gshell.admin.internal.commands.ConnectCommand.doExecute(ConnectCommand.java:38)
at org.apache.servicemix.kernel.gshell.core.OsgiCommandSupport.execute(OsgiCommandSupport.java:48)
at org.apache.geronimo.gshell.wisdom.command.CommandSupport.executeAction(CommandSupport.java:303)
at org.apache.geronimo.gshell.wisdom.command.StatefulCommand.executeAction(StatefulCommand.java:94)
at org.apache.geronimo.gshell.wisdom.command.CommandSupport.execute(CommandSupport.java:194)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:585)
at org.springframework.osgi.service.importer.support.internal.aop.ServiceInvoker.doInvoke(ServiceInvoker.java:64)
at org.springframework.osgi.service.importer.support.internal.aop.ServiceInvoker.invoke(ServiceInvoker.java:78)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
at org.springframework.aop.support.DelegatingIntroductionInterceptor.doProceed(DelegatingIntroductionInterceptor.java:131)
at org.springframework.aop.support.DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:119)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
at org.springframework.osgi.service.util.internal.aop.ServiceTCCLInterceptor.invokeUnprivileged(ServiceTCCLInterceptor.java:57)
at org.springframework.osgi.service.util.internal.aop.ServiceTCCLInterceptor.invoke(ServiceTCCLInterceptor.java:40)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
at org.springframework.osgi.service.importer.support.LocalBundleContextAdvice.invoke(LocalBundleContextAdvice.java:59)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
at org.springframework.aop.support.DelegatingIntroductionInterceptor.doProceed(DelegatingIntroductionInterceptor.java:131)
at org.springframework.aop.support.DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:119)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
at $Proxy16.execute(Unknown Source)
at org.apache.geronimo.gshell.wisdom.shell.CommandLineExecutorImpl.doExecute(CommandLineExecutorImpl.java:127)
... 18 more
Caused by: org.apache.geronimo.gshell.command.CommandException: org.apache.sshd.common.RuntimeSshException: Failed to get the session.
at org.apache.geronimo.gshell.wisdom.shell.CommandLineExecutorImpl.doExecute(CommandLineExecutorImpl.java:148)
at org.apache.geronimo.gshell.wisdom.shell.CommandLineExecutorImpl.execute(CommandLineExecutorImpl.java:106)
at org.apache.geronimo.gshell.parser.visitor.ExecutingVisitor$1.run(ExecutingVisitor.java:208)
at org.apache.geronimo.gshell.parser.visitor.ExecutingVisitor.executePiped(ExecutingVisitor.java:231)
... 52 more
Caused by: org.apache.sshd.common.RuntimeSshException: Failed to get the session.
at org.apache.sshd.client.future.DefaultConnectFuture.getSession(DefaultConnectFuture.java:43)
at org.apache.geronimo.gshell.commands.ssh.SshAction.execute(SshAction.java:141)
at org.apache.geronimo.gshell.wisdom.command.CommandSupport.executeAction(CommandSupport.java:303)
at org.apache.geronimo.gshell.wisdom.command.StatefulCommand.executeAction(StatefulCommand.java:94)
at org.apache.geronimo.gshell.wisdom.command.CommandSupport.execute(CommandSupport.java:194)
at org.apache.geronimo.gshell.wisdom.shell.CommandLineExecutorImpl.doExecute(CommandLineExecutorImpl.java:127)
... 55 more
Caused by: java.net.ConnectException: Connection refused: no further information
at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:527)
at org.apache.mina.transport.socket.nio.NioSocketConnector.finishConnect(NioSocketConnector.java:223)
at org.apache.mina.transport.socket.nio.NioSocketConnector.finishConnect(NioSocketConnector.java:45)
at org.apache.mina.core.polling.AbstractPollingIoConnector.processConnections(AbstractPollingIoConnector.java:431)
at org.apache.mina.core.polling.AbstractPollingIoConnector.access$500(AbstractPollingIoConnector.java:63)
at org.apache.mina.core.polling.AbstractPollingIoConnector$Connector.run(AbstractPollingIoConnector.java:480)
at org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:64)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
... 1 more

I'll attach the full log here for reference, you can ignore the AMQ network connector exceptions - this is picking up another broker because I left the default multicast config turned on.


Martin Murphy made changes - 13/Aug/09 08:40 AM
Attachment servicemix.log [ 14236 ]
[ Permlink | « Hide ]
Martin Murphy added a comment - 13/Aug/09 09:53 AM - edited
I notice there are 40 bundles in the cache for the foo instance, whereas there are 115 bundles in the parent instance. I wonder if somehow the remote console has not been started in the foo instance, so it cannot be connected to?

Interestingly, if I try and start the foo instance from the command line I can see that it appears to be waiting for a lock:

C:\opensource\built\fuse\esb\4.1.0.2>cd instances\foo
C:\opensource\built\fuse\esb\4.1.0.2\instances\foo>bin\servicemix.bat
servicemix.bat: Ignoring predefined value for SERVICEMIX_HOME
Bundle listed in startup.properties configuration not found: com/google/code/sshd/sshd/0.1.0/sshd-0.1.0.jar
Bundle listed in startup.properties configuration not found: org/apache/servicemix/bundles/org.apache.servicemix.bundles.mina/2.0.0-M6/org.apache.servicemix.bundles.mina-2.0.0-M6.jar
Waiting for the lock ...

[ Permlink | « Hide ]
Guillaume Nodet added a comment - 13/Aug/09 08:50 PM
The following statement explains why the main console can not connect to the instance: 
Bundle listed in startup.properties configuration not found: com/google/code/sshd/sshd/0.1.0/sshd-0.1.0.jar

This means that the SSHD bundle is misconfigured in the etc/startup.properties file of the sub-instance.
Can you check this file against the one from the root instance ?

If SSHD can not be loaded, it explains why the connection fails and also why the instance is always displayed as starting instead of started, as the check consist in verifying that the socket has been opened.


[ Permlink | « Hide ]
Martin Murphy added a comment - 14/Aug/09 01:21 PM
Looks like the problem is the foo instance has misconfigured the mina and sshd bundles alright: 
org/apache/servicemix/bundles/org.apache.servicemix.bundles.mina/2.0.0-M6/org.apache.servicemix.bundles.mina-2.0.0-M6.jar=30
...
com/google/code/sshd/sshd/0.1.0/sshd-0.1.0.jar=30

The root instance has a different bundle setup for this:

org/apache/mina/mina-core/2.0.0-M6/mina-core-2.0.0-M6.jar=30
org/apache/sshd/sshd-core/0.1.0/sshd-core-0.1.0.jar=30

I commented out the mina and sshd bundles from the foo instance and replaced them with the bundles from the root instance in the etc/startup.properties.
Now if I try and start the foo instance using admin/start it will start it, but eventually the foo instance will stop and admin/list returns a state of stopped.

To try and dig a bit deeper I tried to start the foo instance from the command line:

C:\opensource\built\fuse\esb\4.1.0.2\instances\foo>C:\tools\java\jdk1.5.0_18\jre\bin\java.exe -server -Xmx512M -Dcom.sun.management.jmxremote -Dservicemix.home="C:\opensource\built\fuse\esb\4.1.0.2" -Dservicemix.base="C:\opensource\built\fuse\esb\4.1.0.2\instances\foo" -Dservicemix.startLocalConsole=false -Dservicemix.startRemoteShell=true -classpath C:\opensource\built\fuse\esb\4.1.0.2\lib\servicemix-client.jar;C:\opensource\built\fuse\esb\4.1.0.2\lib\servicemix-jaas-boot.jar;C:\opensource\built\fuse\esb\4.1.0.2\lib\servicemix-version.jar;C:\opensource\built\fuse\esb\4.1.0.2\lib\servicemix.jar org.apache.servicemix.kernel.main.Main

I was then able to connect using admin/connect foo from the root instance. However, I noted the foo instance process was spinning using 100% CPU. When I checked the logs I could see it was constantly throwing an exception from JLineConsole.readLine(). Note that above I do have servicemix.startLocalConsole=false. Here is the stack:

12:48:01,161 | DEBUG | Thread-18        | ExpressionFactory                | e.commons.jexl.ExpressionFactory  121 | Parsing expression: gshell.username;
12:48:01,161 | DEBUG | Thread-18        | ExpressionFactory                | e.commons.jexl.ExpressionFactory  121 | Parsing expression: gshell.group;
12:48:01,161 | DEBUG | Thread-18        | JLineConsole                     | .geronimo.gshell.console.Console  132 | Work failed: java.io.IOException: Pipe closed
java.io.IOException: Pipe closed
	at org.apache.sshd.common.channel.ChannelPipedInputStream.read(ChannelPipedInputStream.java:59)
	at org.apache.sshd.common.channel.ChannelPipedInputStream.read(ChannelPipedInputStream.java:45)
	at jline.Terminal.readCharacter(Terminal.java:99)
	at jline.WindowsTerminal.readCharacter(WindowsTerminal.java:235)
	at jline.WindowsTerminal.readVirtualKey(WindowsTerminal.java:319)
	at jline.ConsoleReader.readVirtualKey(ConsoleReader.java:1453)
	at jline.ConsoleReader.readBinding(ConsoleReader.java:654)
	at jline.ConsoleReader.readLine(ConsoleReader.java:494)
	at jline.ConsoleReader.readLine(ConsoleReader.java:448)
	at org.apache.geronimo.gshell.console.JLineConsole.readLine(JLineConsole.java:95)
	at org.apache.geronimo.gshell.console.Console.work(Console.java:150)
	at org.apache.geronimo.gshell.console.Console.run(Console.java:128)
	at org.apache.geronimo.gshell.commands.ssh.ShellFactoryImpl$ShellImpl.run(ShellFactoryImpl.java:238)
	at org.apache.geronimo.gshell.commands.ssh.ShellFactoryImpl$ShellImpl.run(ShellFactoryImpl.java:258)
	at java.lang.Thread.run(Thread.java:595)

If I set startLocalConsole to true, the console will load up and everything works fine, but I still see the CPU spinning. From the logs I can see it's the same exception being thrown in this instance as well. I notice that it is only when I connect to the instance from the root instance that it starts to spin, it appears to be related to constantly looking for commands from the connection.


Martin Murphy made changes - 01/Sep/09 04:01 PM
Fix Version/s 4.2.0.0-fuse [ 10521 ]
[ Permlink | « Hide ]
Martin Murphy added a comment - 07/Oct/09 11:17 AM
I just tested this on the M1 release and it works fine now 
karaf@root> admin:create foo
Creating new instance on port 8102 at: C:\opensource\built\fuse\esb\apache-servi
cemix-4.2.0.0M1-fuse\instances\foo
Creating dir:  C:\opensource\built\fuse\esb\apache-servicemix-4.2.0.0M1-fuse\ins
tances\foo\bin
Creating dir:  C:\opensource\built\fuse\esb\apache-servicemix-4.2.0.0M1-fuse\ins
tances\foo\etc
Creating dir:  C:\opensource\built\fuse\esb\apache-servicemix-4.2.0.0M1-fuse\ins
tances\foo\system
Creating dir:  C:\opensource\built\fuse\esb\apache-servicemix-4.2.0.0M1-fuse\ins
tances\foo\deploy
Creating dir:  C:\opensource\built\fuse\esb\apache-servicemix-4.2.0.0M1-fuse\ins
tances\foo\data
Creating file: C:\opensource\built\fuse\esb\apache-servicemix-4.2.0.0M1-fuse\ins
tances\foo\etc\config.properties
Creating file: C:\opensource\built\fuse\esb\apache-servicemix-4.2.0.0M1-fuse\ins
tances\foo\etc\java.util.logging.properties
Creating file: C:\opensource\built\fuse\esb\apache-servicemix-4.2.0.0M1-fuse\ins
tances\foo\etc\org.apache.felix.karaf.log.cfg
Creating file: C:\opensource\built\fuse\esb\apache-servicemix-4.2.0.0M1-fuse\ins
tances\foo\etc\org.apache.felix.karaf.features.cfg
Creating file: C:\opensource\built\fuse\esb\apache-servicemix-4.2.0.0M1-fuse\ins
tances\foo\etc\org.apache.felix.karaf.management.cfg
Creating file: C:\opensource\built\fuse\esb\apache-servicemix-4.2.0.0M1-fuse\ins
tances\foo\etc\org.ops4j.pax.logging.cfg
Creating file: C:\opensource\built\fuse\esb\apache-servicemix-4.2.0.0M1-fuse\ins
tances\foo\etc\org.ops4j.pax.url.mvn.cfg
Creating file: C:\opensource\built\fuse\esb\apache-servicemix-4.2.0.0M1-fuse\ins
tances\foo\etc\startup.properties
Creating file: C:\opensource\built\fuse\esb\apache-servicemix-4.2.0.0M1-fuse\ins
tances\foo\etc\users.properties
Creating file: C:\opensource\built\fuse\esb\apache-servicemix-4.2.0.0M1-fuse\ins
tances\foo\etc\system.properties
Creating file: C:\opensource\built\fuse\esb\apache-servicemix-4.2.0.0M1-fuse\ins
tances\foo\etc\org.apache.felix.karaf.shell.cfg
Creating file: C:\opensource\built\fuse\esb\apache-servicemix-4.2.0.0M1-fuse\ins
tances\foo\bin\start.bat
Creating file: C:\opensource\built\fuse\esb\apache-servicemix-4.2.0.0M1-fuse\ins
tances\foo\bin\stop.bat
karaf@root> admin:start foo
karaf@root> admin:connect foo
Connecting to host localhost on port 8102
Connected
        __ __                  ____
       / //_/____ __________ _/ __/
      / ,<  / __ `/ ___/ __ `/ /_
     / /| |/ /_/ / /  / /_/ / __/
    /_/ |_|\__,_/_/   \__,_/_/

  Apache Felix Karaf (1.0.0.0M1-fuse)

Hit '<tab>' for a list of available commands
and '[cmd] --help' for help on a specific command.
Hit '<ctrl-d>' or 'osgi:shutdown' to shutdown Karaf.

karaf@foo> info
Karaf
  Karaf home                  C:\opensource\built\fuse\esb\apache-servicemix-4.2
.0.0M1-fuse
  Karaf base                  C:\opensource\built\fuse\esb\apache-servicemix-4.2
.0.0M1-fuse\instances\foo

JVM
  Java Virtual Machine        Java HotSpot(TM) Server VM version 11.3-b02
  Vendor                      Sun Microsystems Inc.
  Uptime                      7.921 seconds
  Total compile time          1.512 seconds
Threads
  Live threads                25
  Daemon threads              14
  Peak                        25
  Total started               30
Memory
  Current heap size           8,152 kbytes
  Maximum heap size           504,896 kbytes
  Committed heap size         36,416 kbytes
  Pending objects             0
  Garbage collector           Name = 'PS Scavenge', Collections = 6, Time = 0.02
5 seconds
  Garbage collector           Name = 'PS MarkSweep', Collections = 2, Time = 0.0
91 seconds
Classes
  Current classes loaded      2,971
  Total classes loaded        2,971
  Total classes unloaded      0
Operating system
  Name                        Windows XP version 5.1
  Architecture                x86
  Processors                  2
karaf@foo>

Martin Murphy made changes - 07/Oct/09 11:17 AM
Status Open [ 1 ] Closed [ 6 ]
Fix Version/s 4.2.0.0M1-fuse [ 10640 ]
Resolution Fixed [ 1 ]

Powered by Atlassian JIRA the Professional Issue Tracker. (Enterprise Edition, Version: 3.13.2-#335) - Bug/feature request - Atlassian news - Contact Administrators