[ https://issues.apache.org/jira/browse/SSHD-1070?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17188957#comment-17188957 ]
Feng Jiajie edited comment on SSHD-1070 at 9/2/20, 3:46 AM: ------------------------------------------------------------ Hi [~lgoldstein]. {quote}How large are we talking ? {quote} greater than JVM heap memory. Here's another example for reproducing the problem. Step1. start a nginx server, and put a large(4GB+) file in the html directory, then the file can be download using wget: {code:java} [root@debugboxcreate2204 nginx]# ll html/ total 4372592 -rw-r--r-- 1 work work 537 May 22 19:31 50x.html -rw-r--r-- 1 work work 4477522014 Sep 2 10:37 b -rw-r--r-- 1 work work 612 May 22 19:31 index.html [root@debugboxcreate2204 nginx]# [root@debugboxcreate2204 nginx]# wget 127.0.0.1:8080/b {code} Step2. start SSHD and ssh client: {code:java} java -Xmx2G TestSshd2 ssh -o 'ExitOnForwardFailure yes' -p 12133 -f -x -N -T -L 0.0.0.0:15678:127.0.0.1:8080 test5@127.0.0.1 {code} Step3. wget file through forwarding port: {code:java} wget 127.0.0.1:15678/b {code} Then OOM will occur in a few seconds: {code:java} 11:34:33.631 [sshd-SshServer[5bcea91b](port=12133)-nio2-thread-2] WARN org.apache.sshd.common.channel.IoWriteFutureImpl - notifyListener(IoWriteFutureImpl[id=TcpipServerChannel[id=0, recipient=1]-ServerSessionImpl[test5@/127.0.0.1:54820][SSH_MSG_CHANNEL_DATA]][value=true]) failed (OutOfMemoryError) to invoke org.apache.sshd.common.channel.BufferedIoOutputStream$1@4eb77084: Java heap space11:34:33.631 [sshd-SshServer[5bcea91b](port=12133)-nio2-thread-2] WARN org.apache.sshd.common.channel.IoWriteFutureImpl - notifyListener(IoWriteFutureImpl[id=TcpipServerChannel[id=0, recipient=1]-ServerSessionImpl[test5@/127.0.0.1:54820][SSH_MSG_CHANNEL_DATA]][value=true]) failed (OutOfMemoryError) to invoke org.apache.sshd.common.channel.BufferedIoOutputStream$1@4eb77084: Java heap space11:34:33.772 [sshd-SshServer[5bcea91b](port=12133)-nio2-thread-2] WARN org.apache.sshd.common.io.nio2.Nio2DefaultIoWriteFuture - notifyListener(Nio2DefaultIoWriteFuture[id=/127.0.0.1:54820][value=true]) failed (OutOfMemoryError) to invoke org.apache.sshd.common.channel.ChannelAsyncOutputStream$$Lambda$86/673218654@3d3a7dd4: GC overhead limit exceeded11:34:34.207 [sshd-SshServer[5bcea91b](port=12133)-nio2-thread-3] WARN org.apache.sshd.common.io.nio2.Nio2Session - exceptionCaught(Nio2Session[local=/127.0.0.1:26744, remote=/127.0.0.1:8080]) Exception handler threw OutOfMemoryError, closing the session: GC overhead limit exceededException in thread "sshd-SshServer[5bcea91b](port=12133)-nio2-thread-2" org.apache.sshd.common.RuntimeSshException11:34:35.525 [sshd-SshServer[5bcea91b](port=12133)-nio2-thread-3] WARN org.apache.sshd.common.io.nio2.Nio2Session - exceptionCaught(Nio2Session[local=/127.0.0.1:26744, remote=/127.0.0.1:8080]) Exception handler threw OutOfMemoryError, closing the session: GC overhead limit exceeded at org.apache.sshd.common.io.nio2.Nio2Session.startWriting(Nio2Session.java:411) at org.apache.sshd.common.io.nio2.Nio2Session.finishWrite(Nio2Session.java:495) {code} I think the reason is: nginx -> SSHD -> ssh -> wget "nginx -> SSHD" speed about 1GB/s (Asynchronous) "SSHD -> ssh" speed about 60MB/s (Data encryption and decryption) after few second, SSHD would buffer GBs data in memory. was (Author: fengjiajie): Hi [~lgoldstein]. {quote}How large are we talking ? {quote} greater than JVM heap memory. Here's another example for reproducing the problem. Step1. start a nginx server, and put a large(4GB+) file in the html directory, then the file can be download using wget: {code:java} [root@debugboxcreate2204 nginx]# ll html/ total 4372592 -rw-r--r-- 1 work work 537 May 22 19:31 50x.html -rw-r--r-- 1 work work 4477522014 Sep 2 10:37 b -rw-r--r-- 1 work work 612 May 22 19:31 index.html [root@debugboxcreate2204 nginx]# [root@debugboxcreate2204 nginx]# wget 127.0.0.1:8080/b {code} Step2. start SSHD and ssh client: {code:java} java -Xmx2G TestSshd2 ssh -o 'ExitOnForwardFailure yes' -p 12133 -f -x -N -T -L 0.0.0.0:15678:127.0.0.1:8080 test5@127.0.0.1 {code} Step3. wget file through forwarding port: {code:java} wget 127.0.0.1:15678/b {code} Then OOM will occur in a few seconds: {code:java} 11:34:33.631 [sshd-SshServer[5bcea91b](port=12133)-nio2-thread-2] WARN org.apache.sshd.common.channel.IoWriteFutureImpl - notifyListener(IoWriteFutureImpl[id=TcpipServerChannel[id=0, recipient=1]-ServerSessionImpl[test5@/127.0.0.1:54820][SSH_MSG_CHANNEL_DATA]][value=true]) failed (OutOfMemoryError) to invoke org.apache.sshd.common.channel.BufferedIoOutputStream$1@4eb77084: Java heap space11:34:33.631 [sshd-SshServer[5bcea91b](port=12133)-nio2-thread-2] WARN org.apache.sshd.common.channel.IoWriteFutureImpl - notifyListener(IoWriteFutureImpl[id=TcpipServerChannel[id=0, recipient=1]-ServerSessionImpl[test5@/127.0.0.1:54820][SSH_MSG_CHANNEL_DATA]][value=true]) failed (OutOfMemoryError) to invoke org.apache.sshd.common.channel.BufferedIoOutputStream$1@4eb77084: Java heap space11:34:33.772 [sshd-SshServer[5bcea91b](port=12133)-nio2-thread-2] WARN org.apache.sshd.common.io.nio2.Nio2DefaultIoWriteFuture - notifyListener(Nio2DefaultIoWriteFuture[id=/127.0.0.1:54820][value=true]) failed (OutOfMemoryError) to invoke org.apache.sshd.common.channel.ChannelAsyncOutputStream$$Lambda$86/673218654@3d3a7dd4: GC overhead limit exceeded11:34:34.207 [sshd-SshServer[5bcea91b](port=12133)-nio2-thread-3] WARN org.apache.sshd.common.io.nio2.Nio2Session - exceptionCaught(Nio2Session[local=/127.0.0.1:26744, remote=/127.0.0.1:8106]) Exception handler threw OutOfMemoryError, closing the session: GC overhead limit exceededException in thread "sshd-SshServer[5bcea91b](port=12133)-nio2-thread-2" org.apache.sshd.common.RuntimeSshException11:34:35.525 [sshd-SshServer[5bcea91b](port=12133)-nio2-thread-3] WARN org.apache.sshd.common.io.nio2.Nio2Session - exceptionCaught(Nio2Session[local=/127.0.0.1:26744, remote=/127.0.0.1:8106]) Exception handler threw OutOfMemoryError, closing the session: GC overhead limit exceeded at org.apache.sshd.common.io.nio2.Nio2Session.startWriting(Nio2Session.java:411) at org.apache.sshd.common.io.nio2.Nio2Session.finishWrite(Nio2Session.java:495) {code} I think the reason is: nginx -> SSHD -> ssh -> wget "nginx -> SSHD" speed about 1GB/s (Asynchronous) "SSHD -> ssh" speed about 60MB/s (Data encryption and decryption) after few second, SSHD would buffer GBs data in memory. > OutOfMemoryError when use port forwarding > ----------------------------------------- > > Key: SSHD-1070 > URL: https://issues.apache.org/jira/browse/SSHD-1070 > Project: MINA SSHD > Issue Type: Bug > Affects Versions: 2.5.1 > Reporter: Feng Jiajie > Priority: Major > > Hi [~gnodet], I found this commit implemented asynchronous port forwarding: > [https://github.com/apache/mina-sshd/commit/45f84aab59b2e11d72942cffe9d810e37ab64959#diff-33823b8546f71d77bb1d653358ecde70] > However, when a large amount of data is returned from upstream application, > it is possible to cause an OOM in SSHD. > Step1. SSHD server: > {code:java} > import org.apache.sshd.common.FactoryManager; > import org.apache.sshd.common.PropertyResolverUtils; > import org.apache.sshd.common.util.security.SecurityUtils; > import org.apache.sshd.server.SshServer; > import org.apache.sshd.server.forward.AcceptAllForwardingFilter; > import org.apache.sshd.server.keyprovider.SimpleGeneratorHostKeyProvider; > import java.io.IOException; > import java.nio.file.Paths; > public class TestSshd2 { > public static void main(String[] args) throws IOException, > InterruptedException { > SecurityUtils.setAPrioriDisabledProvider("BC", true); > SshServer sshd = SshServer.setUpDefaultServer(); > sshd.setPort(12133); > sshd.setKeyPairProvider(new > SimpleGeneratorHostKeyProvider(Paths.get("/tmp/aa.key"))); > sshd.setPasswordAuthenticator((username, password, session) -> true); > sshd.setForwardingFilter(AcceptAllForwardingFilter.INSTANCE); > sshd.start(); > Thread.sleep(100000000); > } > } > {code} > Step2. start ssh client and iperf3 server: > {code:java} > ssh -o 'ExitOnForwardFailure yes' -p 12133 -f -x -N -T -L > 0.0.0.0:15678:127.0.0.1:12345 test5@127.0.0.1 > iperf3 -s -p 12345 > {code} > Step3. run iperf3 client: > {code:java} > iperf3 -c 127.0.0.1 -i 1 -t 120 -p 15678 -P 8 --reverse > {code} > *-R, --reverse run in reverse mode (server sends, client receives)* > SSHD will receive a lot of data but will not be able to forward it in time. > log when OOM: > {code:java} > 17:52:25.195 [sshd-SshServer[5bcea91b](port=12133)-nio2-thread-1] WARN > org.apache.sshd.common.io.nio2.Nio2Session - > exceptionCaught(Nio2Session[local=/127.0.0.1:33524, remote=/127.0.0.1:12345]) > Exception handler threw OutOfMemoryError, closing the session: GC overhead > limit exceeded17:52:25.195 > [sshd-SshServer[5bcea91b](port=12133)-nio2-thread-1] WARN > org.apache.sshd.common.io.nio2.Nio2Session - > exceptionCaught(Nio2Session[local=/127.0.0.1:33524, remote=/127.0.0.1:12345]) > Exception handler threw OutOfMemoryError, closing the session: GC overhead > limit exceeded at > org.apache.sshd.common.io.nio2.Nio2CompletionHandler.completed(Nio2CompletionHandler.java:37) > at sun.nio.ch.Invoker.invokeUnchecked(Invoker.java:126) at > sun.nio.ch.Invoker.invokeDirect(Invoker.java:157) at > sun.nio.ch.UnixAsynchronousSocketChannelImpl.implWrite(UnixAsynchronousSocketChannelImpl.java:736) > at > sun.nio.ch.AsynchronousSocketChannelImpl.write(AsynchronousSocketChannelImpl.java:382) > at > sun.nio.ch.AsynchronousSocketChannelImpl.write(AsynchronousSocketChannelImpl.java:399) > at > org.apache.sshd.common.io.nio2.Nio2Session.doWriteCycle(Nio2Session.java:420) > at > org.apache.sshd.common.io.nio2.Nio2Session.startWriting(Nio2Session.java:404) > at > org.apache.sshd.common.io.nio2.Nio2Session.finishWrite(Nio2Session.java:495) > at > org.apache.sshd.common.io.nio2.Nio2Session.handleCompletedWriteCycle(Nio2Session.java:465) > at > org.apache.sshd.common.io.nio2.Nio2Session$2.onCompleted(Nio2Session.java:429) > at > org.apache.sshd.common.io.nio2.Nio2Session$2.onCompleted(Nio2Session.java:426)17:52:25.639 > [sshd-SshServer[5bcea91b](port=12133)-nio2-thread-6] WARN > org.apache.sshd.common.io.nio2.Nio2Session - > exceptionCaught(Nio2Session[local=/127.0.0.1:33530, remote=/127.0.0.1:12345]) > Exception handler threw OutOfMemoryError, closing the session: GC overhead > limit exceeded at > org.apache.sshd.common.io.nio2.Nio2CompletionHandler.lambda$completed$0(Nio2CompletionHandler.java:38) > at java.security.AccessController.doPrivileged(Native Method) at > org.apache.sshd.common.io.nio2.Nio2CompletionHandler.completed(Nio2CompletionHandler.java:37) > at sun.nio.ch.Invoker.invokeUnchecked(Invoker.java:126) at > sun.nio.ch.Invoker.invokeDirect(Invoker.java:157) at > sun.nio.ch.UnixAsynchronousSocketChannelImpl.implWrite(UnixAsynchronousSocketChannelImpl.java:736)17:52:26.045 > [sshd-SshServer[5bcea91b](port=12133)-nio2-thread-2] DEBUG > org.apache.sshd.common.io.nio2.Nio2Session - > exceptionCaught(Nio2Session[local=/127.0.0.1:33522, remote=/127.0.0.1:12345]) > caught OutOfMemoryError[GC overhead limit exceeded] - calling > handler17:52:26.045 [sshd-SshServer[5bcea91b](port=12133)-nio2-thread-2] > DEBUG org.apache.sshd.server.forward.TcpipServerChannel - > exceptionCaught(TcpipServerChannel[id=3, > recipient=4]-ServerSessionImpl[test5@/127.0.0.1:53702]) signal close > immediately=false due to OutOfMemoryError[GC overhead limit > exceeded]17:52:26.045 [sshd-SshServer[5bcea91b](port=12133)-nio2-thread-2] > DEBUG org.apache.sshd.server.forward.TcpipServerChannel - > close(TcpipServerChannel[id=3, > recipient=4]-ServerSessionImpl[test5@/127.0.0.1:53702])[Graceful] state > already Graceful17:52:26.794 > [sshd-SshServer[5bcea91b](port=12133)-nio2-thread-3] WARN > org.apache.sshd.common.io.nio2.Nio2Session - > exceptionCaught(Nio2Session[local=/127.0.0.1:33528, remote=/127.0.0.1:12345]) > Exception handler threw OutOfMemoryError, closing the session: GC overhead > limit exceeded at > sun.nio.ch.AsynchronousSocketChannelImpl.write(AsynchronousSocketChannelImpl.java:382) > at > sun.nio.ch.AsynchronousSocketChannelImpl.write(AsynchronousSocketChannelImpl.java:399) > at > org.apache.sshd.common.io.nio2.Nio2Session.doWriteCycle(Nio2Session.java:420) > at > org.apache.sshd.common.io.nio2.Nio2Session.startWriting(Nio2Session.java:404) > at > org.apache.sshd.common.io.nio2.Nio2Session.finishWrite(Nio2Session.java:495) > at > org.apache.sshd.common.io.nio2.Nio2Session.handleCompletedWriteCycle(Nio2Session.java:465) > at > org.apache.sshd.common.io.nio2.Nio2Session$2.onCompleted(Nio2Session.java:429) > at > org.apache.sshd.common.io.nio2.Nio2Session$2.onCompleted(Nio2Session.java:426) > at > org.apache.sshd.common.io.nio2.Nio2CompletionHandler.lambda$completed$0(Nio2CompletionHandler.java:38)17:52:26.045 > [sshd-SshServer[5bcea91b](port=12133)-nio2-thread-2] DEBUG > org.apache.sshd.common.io.nio2.Nio2Session - > close(Nio2Session[local=/127.0.0.1:33522, remote=/127.0.0.1:12345]) Closing > immediately at java.security.AccessController.doPrivileged(Native > Method)17:52:26.869 [sshd-SshServer[5bcea91b](port=12133)-nio2-thread-2] > DEBUG org.apache.sshd.common.io.nio2.Nio2Session - > doCloseImmediately(Nio2Session[local=/127.0.0.1:33522, > remote=/127.0.0.1:12345]) closing > socket=sun.nio.ch.UnixAsynchronousSocketChannelImpl[connected > local=/127.0.0.1:33522 remote=/127.0.0.1:12345] at > org.apache.sshd.common.io.nio2.Nio2CompletionHandler.completed(Nio2CompletionHandler.java:37) > at sun.nio.ch.Invoker.invokeUnchecked(Invoker.java:126) at > sun.nio.ch.Invoker.invokeDirect(Invoker.java:157)17:52:27.568 > [sshd-SshServer[5bcea91b](port=12133)-nio2-thread-6] DEBUG > org.apache.sshd.common.io.nio2.Nio2Session - > exceptionCaught(Nio2Session[local=/127.0.0.1:33530, remote=/127.0.0.1:12345]) > caught OutOfMemoryError[GC overhead limit exceeded] - calling > handler17:52:27.568 [sshd-SshServer[5bcea91b](port=12133)-nio2-thread-6] > DEBUG org.apache.sshd.server.forward.TcpipServerChannel - > exceptionCaught(TcpipServerChannel[id=7, > recipient=8]-ServerSessionImpl[test5@/127.0.0.1:53702]) signal close > immediately=false due to OutOfMemoryError[GC overhead limit > exceeded]17:52:27.568 [sshd-SshServer[5bcea91b](port=12133)-nio2-thread-6] > DEBUG org.apache.sshd.server.forward.TcpipServerChannel - > close(TcpipServerChannel[id=7, > recipient=8]-ServerSessionImpl[test5@/127.0.0.1:53702])[Graceful] state > already Graceful at > sun.nio.ch.UnixAsynchronousSocketChannelImpl.implWrite(UnixAsynchronousSocketChannelImpl.java:736) > at > sun.nio.ch.AsynchronousSocketChannelImpl.write(AsynchronousSocketChannelImpl.java:382) > {code} -- This message was sent by Atlassian Jira (v8.3.4#803005) --------------------------------------------------------------------- To unsubscribe, e-mail: dev-unsubscr...@mina.apache.org For additional commands, e-mail: dev-h...@mina.apache.org