Uploaded image for project: 'MINA SSHD'
  1. MINA SSHD
  2. SSHD-19

NullPointerException during SSHD data write

    Details

    • Type: Bug
    • Status: Resolved
    • Priority: 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
        jameswdumay James William Dumay added a comment -

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

        Show
        jameswdumay James William Dumay added a comment - Im only seeing this when I do SFTP operations - is this the same for you?
        Hide
        spearce 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
        spearce 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
        spearce 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
        spearce 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
        spearce 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
        spearce 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
        toga98 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
        toga98 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
        spearce@apache.org 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
        spearce@apache.org 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
        spearce 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
        spearce 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:
            spearce Shawn Pearce
            Reporter:
            spearce Shawn Pearce
          • Votes:
            1 Vote for this issue
            Watchers:
            1 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development