MINA SSHD
  1. MINA SSHD
  2. SSHD-19

NullPointerException during SSHD data write

    Details

    • Type: Bug Bug
    • Status: Resolved
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: None
    • Fix Version/s: 0.6.0
    • Labels:
      None

      Description

      I'm seeing occasional NullPointerException stack traces in my server logs. The following trace is from SVN trunk@755651. I haven't been able to reproduce it myself, nor can I figure out under what condition doWriteData is being invoked with shellIn uninitialized.

      java.lang.NullPointerException
      at org.apache.sshd.server.channel.ChannelSession.doWriteData(ChannelSession.java:155)
      at org.apache.sshd.common.channel.AbstractChannel.handleData(AbstractChannel.java:117)
      at org.apache.sshd.common.session.AbstractSession.channelData(AbstractSession.java:867)
      at org.apache.sshd.server.session.ServerSession.handleMessage(ServerSession.java:198)
      at org.apache.sshd.common.session.AbstractSession.decode(AbstractSession.java:494)
      at org.apache.sshd.common.session.AbstractSession.messageReceived(AbstractSession.java:218)
      at org.apache.sshd.common.AbstractSessionIoHandler.messageReceived(AbstractSessionIoHandler.java:59)
      at org.apache.mina.core.filterchain.DefaultIoFilterChain$TailFilter.messageReceived(DefaultIoFilterChain.java:722)
      at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:434)
      at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1200(DefaultIoFilterChain.java:48)
      at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:802)
      at org.apache.mina.core.filterchain.IoFilterAdapter.messageReceived(IoFilterAdapter.java:120)
      at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:434)
      at org.apache.mina.core.filterchain.DefaultIoFilterChain.fireMessageReceived(DefaultIoFilterChain.java:426)
      at org.apache.mina.core.polling.AbstractPollingIoProcessor.read(AbstractPollingIoProcessor.java:586)
      at org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:547)
      at org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:539)
      at org.apache.mina.core.polling.AbstractPollingIoProcessor.access$400(AbstractPollingIoProcessor.java:57)
      at org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.run(AbstractPollingIoProcessor.java:867)
      at org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:65)
      at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
      at java.lang.Thread.run(Thread.java:619)

        Activity

        Hide
        James William Dumay added a comment -

        Im only seeing this when I do SFTP operations - is this the same for you?

        Show
        James William Dumay added a comment - Im only seeing this when I do SFTP operations - is this the same for you?
        Hide
        Shawn Pearce added a comment -

        No, I've seen this happen during any Command.

        But it hasn't reoccurred in quite a while. MINA 2.0.0-M6, SSHD trunk@784137 plus the patch I proposed in SSHD-28 has been a very stable build which has not caused this recently. However, given that this is in the code path from the client coming into the server, I'm not convinced yet that its actually been fixed somehow.

        Show
        Shawn Pearce added a comment - No, I've seen this happen during any Command. But it hasn't reoccurred in quite a while. MINA 2.0.0-M6, SSHD trunk@784137 plus the patch I proposed in SSHD-28 has been a very stable build which has not caused this recently. However, given that this is in the code path from the client coming into the server, I'm not convinced yet that its actually been fixed somehow.
        Hide
        Shawn Pearce added a comment -

        The write error in the exec code path doesn't seem to be occurring anymore with 0.2.0. I just can't reproduce it, and I'm not seeing it in server error logs, so I'm just giving up on this bug.

        The sftp error mentioned above is already being discussed in SSHD-48.

        Show
        Shawn Pearce added a comment - The write error in the exec code path doesn't seem to be occurring anymore with 0.2.0. I just can't reproduce it, and I'm not seeing it in server error logs, so I'm just giving up on this bug. The sftp error mentioned above is already being discussed in SSHD-48 .
        Hide
        Shawn Pearce added a comment -

        On SVN 891122 we caught an NPE while receiving data for a session. Looks like the same stack trace as before, so this bug still exists.

        [2010-01-11 15:47:15,554] WARN
        org.apache.sshd.server.session.ServerSession : Exception caught
        java.lang.NullPointerException
        at org.apache.sshd.server.channel.ChannelSession.doWriteData(ChannelSession.java:206)
        at org.apache.sshd.common.channel.AbstractChannel.handleData(AbstractChannel.java:129)
        at org.apache.sshd.common.session.AbstractSession.channelData(AbstractSession.java:925)
        at org.apache.sshd.server.session.ServerSession.handleMessage(ServerSession.java:210)
        at org.apache.sshd.common.session.AbstractSession.decode(AbstractSession.java:522)
        at org.apache.sshd.common.session.AbstractSession.messageReceived(AbstractSession.java:225)
        at org.apache.sshd.common.AbstractSessionIoHandler.messageReceived(AbstractSessionIoHandler.java:58)
        at org.apache.mina.core.filterchain.DefaultIoFilterChain$TailFilter.messageReceived(DefaultIoFilterChain.java:713)
        at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:434)
        at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1200(DefaultIoFilterChain.java:46)
        at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:793)
        at org.apache.mina.core.filterchain.IoFilterAdapter.messageReceived(IoFilterAdapter.java:119)
        at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:434)
        at org.apache.mina.core.filterchain.DefaultIoFilterChain.fireMessageReceived(DefaultIoFilterChain.java:426)
        at org.apache.mina.core.polling.AbstractPollingIoProcessor.read(AbstractPollingIoProcessor.java:638)
        at org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:598)
        at org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:587)
        at org.apache.mina.core.polling.AbstractPollingIoProcessor.access$400(AbstractPollingIoProcessor.java:61)
        at org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.run(AbstractPollingIoProcessor.java:969)
        at org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:64)
        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
        at java.lang.Thread.run(Thread.java:619)

        Show
        Shawn Pearce added a comment - On SVN 891122 we caught an NPE while receiving data for a session. Looks like the same stack trace as before, so this bug still exists. [2010-01-11 15:47:15,554] WARN org.apache.sshd.server.session.ServerSession : Exception caught java.lang.NullPointerException at org.apache.sshd.server.channel.ChannelSession.doWriteData(ChannelSession.java:206) at org.apache.sshd.common.channel.AbstractChannel.handleData(AbstractChannel.java:129) at org.apache.sshd.common.session.AbstractSession.channelData(AbstractSession.java:925) at org.apache.sshd.server.session.ServerSession.handleMessage(ServerSession.java:210) at org.apache.sshd.common.session.AbstractSession.decode(AbstractSession.java:522) at org.apache.sshd.common.session.AbstractSession.messageReceived(AbstractSession.java:225) at org.apache.sshd.common.AbstractSessionIoHandler.messageReceived(AbstractSessionIoHandler.java:58) at org.apache.mina.core.filterchain.DefaultIoFilterChain$TailFilter.messageReceived(DefaultIoFilterChain.java:713) at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:434) at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1200(DefaultIoFilterChain.java:46) at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:793) at org.apache.mina.core.filterchain.IoFilterAdapter.messageReceived(IoFilterAdapter.java:119) at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:434) at org.apache.mina.core.filterchain.DefaultIoFilterChain.fireMessageReceived(DefaultIoFilterChain.java:426) at org.apache.mina.core.polling.AbstractPollingIoProcessor.read(AbstractPollingIoProcessor.java:638) at org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:598) at org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:587) at org.apache.mina.core.polling.AbstractPollingIoProcessor.access$400(AbstractPollingIoProcessor.java:61) at org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.run(AbstractPollingIoProcessor.java:969) at org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:64) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) at java.lang.Thread.run(Thread.java:619)
        Hide
        Russ Tennant added a comment -

        I have experienced a similar / same issue while testing the software. Notice that there are no SubsystemFactories set.

        Ran code similar to :

        SshServer sshd = SshServer.setUpDefaultServer();
        sshd.setPort(2222);
        List<NamedFactory<Command>> subsystemFactories = Arrays.<NamedFactory<Command>>asList(
        new SftpSubsystem.Factory()
        );
        sshd.setCompressionFactories(compressionFactories);
        //sshd.setSubsystemFactories(subsystemFactories);
        sshd.setKeyPairProvider(new SimpleGeneratorHostKeyProvider("/tmp/java-sshd-hostkey.ser"));
        sshd.setPasswordAuthenticator(new PasswordAuthenticator()

        {....}

        );
        sshd.setShellFactory(new ProcessShellFactory(new String[]

        { "/bin/bash", "-i", "-l" }

        ,
        EnumSet.of(ProcessShellFactory.TtyOptions.ONlCr)));
        sshd.setCommandFactory(new ScpCommandFactory());
        sshd.start();

        and then I attempted an SFTP connection to see what would happen. The following exception was logged.

        java.lang.NullPointerException
        at org.apache.sshd.server.channel.ChannelSession.doWriteData(ChannelSession.java:207)
        at org.apache.sshd.common.channel.AbstractChannel.handleData(AbstractChannel.java:129)
        at org.apache.sshd.common.session.AbstractSession.channelData(AbstractSession.java:930)
        at org.apache.sshd.server.session.ServerSession.handleMessage(ServerSession.java:213)
        at org.apache.sshd.common.session.AbstractSession.decode(AbstractSession.java:522)
        at org.apache.sshd.common.session.AbstractSession.messageReceived(AbstractSession.java:225)
        at org.apache.sshd.common.AbstractSessionIoHandler.messageReceived(AbstractSessionIoHandler.java:58)
        at org.apache.mina.core.filterchain.DefaultIoFilterChain$TailFilter.messageReceived(DefaultIoFilterChain.java:716)
        at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:434)
        at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1200(DefaultIoFilterChain.java:46)
        at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:796)
        at org.apache.mina.core.filterchain.IoFilterAdapter.messageReceived(IoFilterAdapter.java:119)
        at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:434)
        at org.apache.mina.core.filterchain.DefaultIoFilterChain.fireMessageReceived(DefaultIoFilterChain.java:426)
        at org.apache.mina.core.polling.AbstractPollingIoProcessor.read(AbstractPollingIoProcessor.java:715)
        at org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:668)
        at org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:657)
        at org.apache.mina.core.polling.AbstractPollingIoProcessor.access$500(AbstractPollingIoProcessor.java:64)
        at org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.run(AbstractPollingIoProcessor.java:1117)
        at org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:64)
        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
        at java.lang.Thread.run(Thread.java:619)

        Show
        Russ Tennant added a comment - I have experienced a similar / same issue while testing the software. Notice that there are no SubsystemFactories set. Ran code similar to : SshServer sshd = SshServer.setUpDefaultServer(); sshd.setPort(2222); List<NamedFactory<Command>> subsystemFactories = Arrays.<NamedFactory<Command>>asList( new SftpSubsystem.Factory() ); sshd.setCompressionFactories(compressionFactories); //sshd.setSubsystemFactories(subsystemFactories); sshd.setKeyPairProvider(new SimpleGeneratorHostKeyProvider("/tmp/java-sshd-hostkey.ser")); sshd.setPasswordAuthenticator(new PasswordAuthenticator() {....} ); sshd.setShellFactory(new ProcessShellFactory(new String[] { "/bin/bash", "-i", "-l" } , EnumSet.of(ProcessShellFactory.TtyOptions.ONlCr))); sshd.setCommandFactory(new ScpCommandFactory()); sshd.start(); and then I attempted an SFTP connection to see what would happen. The following exception was logged. java.lang.NullPointerException at org.apache.sshd.server.channel.ChannelSession.doWriteData(ChannelSession.java:207) at org.apache.sshd.common.channel.AbstractChannel.handleData(AbstractChannel.java:129) at org.apache.sshd.common.session.AbstractSession.channelData(AbstractSession.java:930) at org.apache.sshd.server.session.ServerSession.handleMessage(ServerSession.java:213) at org.apache.sshd.common.session.AbstractSession.decode(AbstractSession.java:522) at org.apache.sshd.common.session.AbstractSession.messageReceived(AbstractSession.java:225) at org.apache.sshd.common.AbstractSessionIoHandler.messageReceived(AbstractSessionIoHandler.java:58) at org.apache.mina.core.filterchain.DefaultIoFilterChain$TailFilter.messageReceived(DefaultIoFilterChain.java:716) at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:434) at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1200(DefaultIoFilterChain.java:46) at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:796) at org.apache.mina.core.filterchain.IoFilterAdapter.messageReceived(IoFilterAdapter.java:119) at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:434) at org.apache.mina.core.filterchain.DefaultIoFilterChain.fireMessageReceived(DefaultIoFilterChain.java:426) at org.apache.mina.core.polling.AbstractPollingIoProcessor.read(AbstractPollingIoProcessor.java:715) at org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:668) at org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:657) at org.apache.mina.core.polling.AbstractPollingIoProcessor.access$500(AbstractPollingIoProcessor.java:64) at org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.run(AbstractPollingIoProcessor.java:1117) at org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:64) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) at java.lang.Thread.run(Thread.java:619)
        Hide
        Shawn Pearce added a comment -

        Interesting observation. My server doesn't have the SFTP subsystem enabled. So maybe it is a user trying to connect with SFTP just to see what they can try to find out, but we're rejecting it by crashing with an NPE since the subsystem isn't configured?

        Show
        Shawn Pearce added a comment - Interesting observation. My server doesn't have the SFTP subsystem enabled. So maybe it is a user trying to connect with SFTP just to see what they can try to find out, but we're rejecting it by crashing with an NPE since the subsystem isn't configured?
        Hide
        Shawn Pearce added a comment -

        Committing to https://svn.apache.org/repos/asf/mina/sshd/trunk ...
        M sshd-core/src/main/java/org/apache/sshd/server/channel/ChannelSession.java
        Committed r1031886

        Show
        Shawn Pearce added a comment - Committing to https://svn.apache.org/repos/asf/mina/sshd/trunk ... M sshd-core/src/main/java/org/apache/sshd/server/channel/ChannelSession.java Committed r1031886

          People

          • Assignee:
            Shawn Pearce
            Reporter:
            Shawn Pearce
          • Votes:
            1 Vote for this issue
            Watchers:
            1 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development