【问题标题】:JSch SFTP connections getting stuckJSch SFTP 连接卡住
【发布时间】:2021-09-25 02:40:19
【问题描述】:

我们有一个 java 7 代码库,我们在其中使用 Apache commons vfs2 v2.2,它使用 JSch-0.1.54 作为 sftp 提供程序。

现在,用例是通过 sftp 将文件传输到远程主机。但是,文件上传过程时不时会卡住。在获取应用程序的线程转储后,我们发现两个线程(t1,将数据发送到远程 sftp 和 t2,从 sftp 接收数据)都处于等待状态永远的状态。下面是线程转储快照。

JSch 会话线程:

"Connect thread remote.ftp.com session" daemon prio=10 tid=0x00007f99cc243000 nid=0x144 in Object.wait() [0x00007f9985606000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    at java.io.PipedInputStream.awaitSpace(PipedInputStream.java:273)
    at java.io.PipedInputStream.receive(PipedInputStream.java:231)
    - locked <0x000000043eda02d8> (a com.jcraft.jsch.Channel$MyPipedInputStream)
    at java.io.PipedOutputStream.write(PipedOutputStream.java:149)
    at com.jcraft.jsch.IO.put(IO.java:64)
    at com.jcraft.jsch.Channel.write(Channel.java:438)
    at com.jcraft.jsch.Session.run(Session.java:1459)
    at java.lang.Thread.run(Thread.java:748)

用于上传文件数据的应用线程。

"akka.actor.default-dispatcher-19" prio=10 tid=0x00007f99d4012000 nid=0xea in Object.wait() [0x00007f9988785000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    at com.jcraft.jsch.Session.write(Session.java:1269)
    - locked <0x0000000440a61b48> (a com.jcraft.jsch.ChannelSftp)
    at com.jcraft.jsch.ChannelSftp.sendWRITE(ChannelSftp.java:2646)
    at com.jcraft.jsch.ChannelSftp.access$100(ChannelSftp.java:36)
    at com.jcraft.jsch.ChannelSftp$1.write(ChannelSftp.java:806)
    at java.io.BufferedOutputStream.write(BufferedOutputStream.java:122)
    - locked <0x0000000440aab240> (a org.apache.commons.vfs2.provider.sftp.SftpFileObject$SftpOutputStream)
    at org.apache.commons.vfs2.util.MonitorOutputStream.write(MonitorOutputStream.java:104)
    - locked <0x0000000440aab240> (a org.apache.commons.vfs2.provider.sftp.SftpFileObject$SftpOutputStream)
    at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)
    at java.io.BufferedOutputStream.write(BufferedOutputStream.java:126)
    - locked <0x0000000440aac278> (a org.apache.commons.vfs2.provider.DefaultFileContent$FileContentOutputStream)
    at org.apache.commons.vfs2.util.MonitorOutputStream.write(MonitorOutputStream.java:104)
    - locked <0x0000000440aac278> (a org.apache.commons.vfs2.provider.DefaultFileContent$FileContentOutputStream)
    at org.apache.commons.vfs2.provider.DefaultFileContent.write(DefaultFileContent.java:741)
    at org.apache.commons.vfs2.provider.DefaultFileContent.write(DefaultFileContent.java:720)
    at org.apache.commons.vfs2.provider.DefaultFileContent.write(DefaultFileContent.java:691)
    at org.apache.commons.vfs2.provider.DefaultFileContent.write(DefaultFileContent.java:707)
    at org.apache.commons.vfs2.FileUtil.copyContent(FileUtil.java:78)
    at org.apache.commons.vfs2.provider.AbstractFileObject.copyFrom(AbstractFileObject.java:289)

在查看了 Jsch 库的codebase 之后,这就是我觉得正在发生的事情。

  1. 应用程序线程正在以 4KB 的块上传文件数据。
  2. 每次块写入后,应用程序都会读取输入套接字以获取任何确认,直到输入套接字缓冲区为空。
  3. 在块写入期间,它会检查 ssh 窗口大小。如果它小于有效负载大小,我们会等到远程服务器调整它的大小。(这是我的应用程序线程永远等待的地方)这个调整大小的消息由 ssh 会话线程监听,同样是在通道对象处更新,之后应用程序线程继续写入。
  4. 在单独的线程中,会话正在侦听来自远程服务器的传入数据。根据接收到的消息,它会采取相关操作,例如调整频道窗口大小,将确认消息传递给频道(读取应用程序)以供使用。
  5. 现在,当一条消息到达供通道消费时,它被写入链接到 PipedInputStream 的 PipedOutStream。此输入流由应用程序线程读取以获取确认消息。如果应用程序线程未能读取任何消息,则 PipedOutputstream 的缓冲区已满,因此它进入等待状态,直到应用程序读取一些数据。 (这是会话线程永远等待的地方)

现在,两个线程相互依赖。因此,这是一种僵局。

此外,我检查了运行此应用程序的 linux 机器,套接字的 RecQ 一直在建立。这意味着,socket 还活着,远程服务器不时地发送 32KB 的数据包。

sudo netstat -anpt | grep 19321
tcp6       0      0 10.14.233.97:59594      64.233.167.130:19321    TIME_WAIT   -
tcp6   58256      0 10.14.233.97:58214      64.233.167.130:19321    ESTABLISHED 460144/java
tcp6  499888      0 10.14.233.97:58422      64.233.167.130:19321    ESTABLISHED 460144/java
tcp6       0      0 10.14.233.97:59622      64.233.167.130:19321    ESTABLISHED 460144/java
tcp6       0      0 10.14.233.97:59608      64.233.167.130:19321    TIME_WAIT   -
tcp6   74672      0 10.14.233.97:56656      64.233.167.130:19321    ESTABLISHED 460144/java
tcp6   92688      0 10.14.233.97:56842      64.233.167.130:19321    ESTABLISHED 460144/java

现在,我有 2 个问题。

  1. 为什么会这样?这种情况很少发生,但一旦发生,就会经常发生。
  2. 如何解决此问题?

P.S. 我知道 Apache commons vfs 库的多线程问题,因此,所有 ssh 会话都在单独的线程中运行。因此,它看起来不像是图书馆的问题。

【问题讨论】:

  • 那里正在进行大量分析(其中一些是矛盾的,IMO,围绕线程问题)并且几乎没有数据。请生成runnable demo 并发布代码
  • @g00se 不幸的是,这个错误非常随机,因此我们无法重现它。它是一个生产错误。即使在极端负载测试之后,我们也没有在较低的环境中遇到这个问题。这可能是因为,在较低的环境中,我们使用内部远程服务器。在生产中,我们有 3rd 方远程服务器。无论如何,将分享示例客户端代码。
  • 您是否消除了网络本身作为问题的根源?
  • Ys 网络似乎很好,因为还有其他线程正在成功上传文件。有一个批处理作业正在单个线程中上传文件。另外,我可以在 netstat 中看到,recq 正在不断构建。

标签: java multithreading ssh jsch apache-commons-vfs


【解决方案1】:

为什么会这样?这种情况很少发生,但一旦发生,就会发生 经常。

我觉得可能有两个原因。

  1. 网络很慢。
  2. 客户端计算机没有足够的资源,因此无法优先处理会话线程。

对于应用程序线程写入远程 sftp 服务器的每个数据包(8KB + 标头数据),它会收到约 28 字节的确认数据。现在,此数据由连接到PipedInputStreamPipedOutputStream 中的会话线程写入,并由应用程序线程使用。此外,该流的缓冲区大小为 32KB。

现在按照逻辑,应用程序线程会继续将数据包写入套接字,直到PipedInputStream 中存在至少 1KB 的数据供其消耗。这大约转化为约 37 个确认。但是由于以上两个原因中的任何一个,这些 ack 数据包可能无法使用,因此应用程序线程将继续将数据包写入输出套接字,直到远程服务器的远程窗口大小(即rwsize)达到其限制。

什么是rwsize

这里,rwsize 是远程服务器在向客户端发送通道打开确认消息时传递的参数。这是流量控制参数。这是根据SSH 协议对通信通道施加的硬限制。此外,客户端和服务器都保留此参数的计数。对于客户端机器完成的每个数据传输字节,它会不断减小此参数的值,直到它变为 ~0。一旦它变为 ~0,它就会等待来自远程服务器的窗口大小调整消息,这意味着服务器已经消耗了一些未完成的数据量并且准备好进一步消耗。

现在,在我的场景中,这个参数的值是32MB。因此,我的应用程序线程能够毫无问题地写入32MB 的数据。现在,一旦达到这个限制,它就会进入永远等待状态,等待远程窗口调整大小消息。现在会话线程负责接收窗口调整大小消息和确认消息。并且这两种类型的消息都是基于 FCFS 接收的。

因此,当应用程序线程进入等待状态时,会话线程可能首先开始接收确认消息。由于每个 ack 消息的大小约为 28 字节,缓冲区大小为 32KB。它只能摄取约 1170 条确认消息而没有任何阻塞。但是,rwsize 是 32MB,1 个数据包是 ~8KB,很有可能有 4144 ack 消息等待消费。因此,如果远程服务器在生成至少约 1170 条确认消息后生成了窗口大小调整消息,则会话线程将在能够接收窗口大小调整消息之前永远阻塞PipedOutputStream。因此问题就来了。

如何解决这个问题?

之前也有人遇到过这个问题。这是他们的错误报告和修复的link。修复是增加PipedInputStream 缓冲区大小。但是,我认为此修复很脆弱,除非您将缓冲区大小增加到足够大,以便在窗口调整大小消息到达之前它可以容纳所有可能的消息。

对于我的情况,我通过确保应用程序线程在达到rwsize 限制后进入永久等待状态之前消耗所有确认消息来修复它。代码详情可以参考thiscommit。下面是调用sendWRITE方法之前添加的代码摘录。

if(rwsize<21+handle.length+_len+4) {
  flush();
}

【讨论】:

    猜你喜欢
    • 1970-01-01
    • 1970-01-01
    • 1970-01-01
    • 1970-01-01
    • 2023-03-04
    • 1970-01-01
    • 1970-01-01
    • 2021-09-11
    • 1970-01-01
    相关资源
    最近更新 更多