FUSE ESB
  1. FUSE ESB
  2. ESB-812

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

    Details

    • Type: Bug Bug
    • Status: Closed Closed
    • Priority: Major Major
    • Resolution: Done
    • Affects Version/s: 4.1.0.2-fuse
    • Fix Version/s: 4.2.0.0M1-fuse
    • Component/s: Core
    • Labels:
      None
    • Environment:
      Windows XP, Linux
    • Similar Issues:
      Show 10 results 

      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:

      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

      1. servicemix.log
        1.47 MB
        Martin Murphy
      2. servicemix.log
        12 kB
        Joe Luo

        Activity

        Hide
        Joe Luo
        added a comment -

        Here is complete log file from the instance "foo".

        Show
        Joe Luo
        added a comment - Here is complete log file from the instance "foo".
        Hide
        Guillaume Nodet
        added a comment -

        This log file is ok. These warnings can be safely ignored.
        It would be interesting to have the log at DEBUG level maybe.

        Show
        Guillaume Nodet
        added a comment - This log file is ok. These warnings can be safely ignored. It would be interesting to have the log at DEBUG level maybe.
        Hide
        Martin Murphy
        added a comment - - 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.

        Show
        Martin Murphy
        added a comment - - 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.
        Hide
        Martin Murphy
        added a comment - - 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 ...
        
        Show
        Martin Murphy
        added a comment - - 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 ...
        Hide
        Guillaume Nodet
        added a comment -

        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.

        Show
        Guillaume Nodet
        added a comment - 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.
        Hide
        Martin Murphy
        added a comment -

        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.

        Show
        Martin Murphy
        added a comment - 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.
        Hide
        Martin Murphy
        added a comment -

        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>
        
        Show
        Martin Murphy
        added a comment - 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>

          People

          • Assignee:
            Guillaume Nodet
            Reporter:
            Joe Luo
          • Votes:
            3 Vote for this issue
            Watchers:
            4 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved: