Ошибка большого файла sftp (> 1 ГБ) с передачей только определенных байтов данных. Почему? - PullRequest
1 голос
/ 07 октября 2019

В настоящее время наша система (Клиент) в экземпляре AWS EC2 столкнулась с проблемой sftp при попытке отправить большой файл на удаленный sftp-сервер клиента («160.xxx.xxx.35.bc.googleusercontent.com). Для файлов небольшого размера передача sftp работает нормально, но когда размер файла составляет около 1 ГБ или превышает его, мы обнаружили, что на сайт sftp сервера было передано только 1068392448 байт. Однако, когда мы отправляем один и тот же большой файл с тем же кодом и теми же средами на наш собственный удаленный sftp-сервер, не относящийся к googleuser (с отличающимися только URL / UserName / Password), он прошел успешно и все данные были переданы правильно.

Эта проблема возникла после того, как на стороне сервера клиента были внесены некоторые изменения путем добавления процесса балансировки нагрузки. Клиентская сторона провела некоторое расследование, скорректировала время ожидания балансировщика нагрузки, но это не помогло решить эту проблему. Говорят, что клиентская сторона прекратила передачу данных после того, как 1068392448 байт, а серверная сторона подождала и сбросила соединение после разрешенного времени простоя (~ 50 секунд).

Наше исследование обнаружило, что большой исходный файл был прочитан из AWS S3. и правильно сохранено в локальном . Когда данные большого файла записываются на сайт sftp сервера, достигают 1068392448 байт ( последовательно для всех результатов теста), состояние соединения сокета TCP изменяется с ESTABLISHED на CLOSE_WAIT после того, как сервер допустил время простоя (около ~ 50-х годов). Процесс оставался в этом состоянии навсегда, пока он не был остановлен / остановлен вручную. Когда соединение сокета TCP находится в состоянии CLOSE_WAIT, процесс передачи данных, показанный в дампе, находится в цикле ожидания в методе awaitSpace () (в классе PipedInputStream пакета java.io). Указывается, что буфер заполнен и ожидает записи на стороне сервера. Ниже приведены коды цикла ожидания:

private void checkStateForReceive() throws IOException {
    if (!connected) {
        throw new IOException("Pipe not connected");
    } else if (closedByWriter || closedByReader) {
        throw new IOException("Pipe closed");
    } else if (readSide != null && !readSide.isAlive()) {
        throw new IOException("Read end dead");
    }
}
private void awaitSpace() throws IOException {
    while (in == out) {
        checkStateForReceive();

        /* full: kick any waiting readers */
        notifyAll();
        try {
            wait(1000);
        } catch (InterruptedException ex) {
            throw new java.io.InterruptedIOException();
        }
    }
}

Ниже приведен дамп:

    Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.102-b14 mixed mode):

"Connect thread files.liveramp.com session" #13 daemon prio=5 os_prio=0 tid=0x000000001e711800 nid=0x63c0 in Object.wait() [0x000000001f81f000]
   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 <0x00000006c1c944c8> (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:745)

"org.apache.commons.vfs2.cache.SoftRefFilesCache$SoftRefReleaseThread" #11 daemon prio=5 os_prio=0 tid=0x000000001ea2d000 nid=0x3078 in Object.wait() [0x000000001efcf000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:143)
    - locked <0x00000006c1c24710> (a java.lang.ref.ReferenceQueue$Lock)
    at org.apache.commons.vfs2.cache.SoftRefFilesCache$SoftRefReleaseThread.run(SoftRefFilesCache.java:74)

"Service Thread" #10 daemon prio=9 os_prio=0 tid=0x000000001dfc5000 nid=0x1944 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C1 CompilerThread2" #9 daemon prio=9 os_prio=2 tid=0x000000001df12800 nid=0x6848 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread1" #8 daemon prio=9 os_prio=2 tid=0x000000001df07800 nid=0x5720 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" #7 daemon prio=9 os_prio=2 tid=0x000000001df04800 nid=0x6358 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Monitor Ctrl-Break" #6 daemon prio=5 os_prio=0 tid=0x000000001df56000 nid=0x6910 runnable [0x000000001e1cf000]
   java.lang.Thread.State: RUNNABLE
    at java.net.SocketInputStream.socketRead0(Native Method)
    at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
    at java.net.SocketInputStream.read(SocketInputStream.java:170)
    at java.net.SocketInputStream.read(SocketInputStream.java:141)
    at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:284)
    at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:326)
    at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:178)
    - locked <0x00000006c1c24f88> (a java.io.InputStreamReader)
    at java.io.InputStreamReader.read(InputStreamReader.java:184)
    at java.io.BufferedReader.fill(BufferedReader.java:161)
    at java.io.BufferedReader.readLine(BufferedReader.java:324)
    - locked <0x00000006c1c24f88> (a java.io.InputStreamReader)
    at java.io.BufferedReader.readLine(BufferedReader.java:389)
    at com.intellij.rt.execution.application.AppMainV2$1.run(AppMainV2.java:64)

"Attach Listener" #5 daemon prio=5 os_prio=2 tid=0x000000001c69e800 nid=0x4880 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" #4 daemon prio=9 os_prio=2 tid=0x000000001c69d800 nid=0x2534 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Finalizer" #3 daemon prio=8 os_prio=1 tid=0x000000001c67e800 nid=0x4908 in Object.wait() [0x000000001d9df000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00000006c1c26660> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:143)
    - locked <0x00000006c1c26660> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:164)
    at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:209)

"Reference Handler" #2 daemon prio=10 os_prio=2 tid=0x00000000030b5000 nid=0x6340 in Object.wait() [0x000000001d8df000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00000006c1c26818> (a java.lang.ref.Reference$Lock)
    at java.lang.Object.wait(Object.java:502)
    at java.lang.ref.Reference.tryHandlePending(Reference.java:191)
    - locked <0x00000006c1c26818> (a java.lang.ref.Reference$Lock)
    at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153)

"main" #1 prio=5 os_prio=0 tid=0x0000000002fc4000 nid=0x56dc in Object.wait() [0x0000000002e0f000]
   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 <0x00000006c1c943d0> (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)
    - eliminated <0x00000006c1c27a88> (a org.apache.commons.vfs2.provider.sftp.SftpFileObject$SftpOutputStream)
    at org.apache.commons.vfs2.util.MonitorOutputStream.write(MonitorOutputStream.java:123)
    - locked <0x00000006c1c27a88> (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)
    - eliminated <0x00000006c1c26a50> (a org.apache.commons.vfs2.provider.DefaultFileContent$FileContentOutputStream)
    at org.apache.commons.vfs2.util.MonitorOutputStream.write(MonitorOutputStream.java:123)
    - locked <0x00000006c1c26a50> (a org.apache.commons.vfs2.provider.DefaultFileContent$FileContentOutputStream)
    at org.apache.commons.vfs2.provider.DefaultFileContent.write(DefaultFileContent.java:805)
    at org.apache.commons.vfs2.provider.DefaultFileContent.write(DefaultFileContent.java:784)
    at org.apache.commons.vfs2.provider.DefaultFileContent.write(DefaultFileContent.java:755)
    at org.apache.commons.vfs2.provider.DefaultFileContent.write(DefaultFileContent.java:771)
    at org.apache.commons.vfs2.FileUtil.copyContent(FileUtil.java:37)
    at org.apache.commons.vfs2.provider.AbstractFileObject.copyFrom(AbstractFileObject.java:295)
    at com.merkleinc.dat.sftptran.cli.SftpVfs2App.main(SftpVfs2App.java:88)

"VM Thread" os_prio=2 tid=0x000000001c657000 nid=0x28b4 runnable 

"GC task thread#0 (ParallelGC)" os_prio=0 tid=0x0000000002fda800 nid=0x2b54 runnable 

"GC task thread#1 (ParallelGC)" os_prio=0 tid=0x0000000002fdc000 nid=0x4528 runnable 

"GC task thread#2 (ParallelGC)" os_prio=0 tid=0x0000000002fdd800 nid=0x4850 runnable 

"GC task thread#3 (ParallelGC)" os_prio=0 tid=0x0000000002fdf800 nid=0x7f0 runnable 

"VM Periodic Task Thread" os_prio=2 tid=0x000000001e023000 nid=0x5d58 waiting on condition 

JNI global references: 225

Heap
 PSYoungGen      total 49664K, used 14491K [0x000000076b400000, 0x000000076ed00000, 0x00000007c0000000)
  eden space 49152K, 29% used [0x000000076b400000,0x000000076c21efd0,0x000000076e400000)
  from space 512K, 6% used [0x000000076e500000,0x000000076e508000,0x000000076e580000)
  to   space 4608K, 0% used [0x000000076e880000,0x000000076e880000,0x000000076ed00000)
 ParOldGen       total 175104K, used 2879K [0x00000006c1c00000, 0x00000006cc700000, 0x000000076b400000)
  object space 175104K, 1% used [0x00000006c1c00000,0x00000006c1ecfc70,0x00000006cc700000)
 Metaspace       used 11230K, capacity 11448K, committed 11648K, reserved 1058816K
  class space    used 1265K, capacity 1318K, committed 1408K, reserved 1048576K

В настоящее время мы используем версию 2.4.2 com.github vfs-s3 с соответствующим apache.commons vfs2 версия 2.1. и jsch-версия com.jcraft версии 0.1.54 для передачи данных sftp. Наши основные коды приведены ниже:

import org.apache.commons.vfs2.*;
Public void upload(String sourceUri, String targetUri) throws IOException, URISyntaxException {
StandardFileSystemManager fsManager = new StandardFileSystemManager();
fsManager.init();
try (FileObject sourceFile = getFileObject(sourceUri, fsManager);
FileObject remoteFile = fsManager.resolveFile(createConnectionString(targetUri), createOptions())) {
// Copy s3 file to sftp server
remoteFile.copyFrom(sourceFile, Selectors.SELECT_SELF);
} finally {
fsManager.close();
}
};

Мы попытались протестировать тот же код в локальных средах Window. Изредка мы могли видеть те же симптомы проблемы, что и в экземпляре ec2, но в большинстве случаев проблемы не было (несовместимо). Мы протестировали в другой системе Linux для отправки большого файла на сайт sftp сервера клиента, и не было никаких проблем.

Мы попытались перейти на v.gsub.abashev версии 3.0.0 и 4.0 com.github.abashev. 0 с соответствующими версиями vfs2 в экземпляре AWS EC2. Тем не менее, он воспроизвел те же результаты проблемы для тех же больших файлов. Попытался установить значение true для loadOpenSSHConfig с правильными значениями конфигурационного файла, чтобы поддерживать соединение, но это не помогло в этой ситуации.

Мы попытались проверить sftp напрямую командой sftp «put» с большим файлом вудаленный сервер из экземпляра EC2 (и других платформ Windows / Linux) и передача данных большого файла всегда успешны.

Вопрос в том, где находится потенциальная первопричина проблемы? Почему серверная сторона перестала получать данные после 1068392448 байт или почему остальные данные не могли быть отправлены на серверную часть? Какие-либо жесткие ограничения в наших средах EC2 блокировали операцию передачи данных (мы пытались проверить несколько ограничений, но до сих пор не выяснены)? Или сайт Сервера неправильно отправил запрос на закрытие соединения «FIN» на сайт Клиента (как это доказать)? Спасибо за любые предложения для потенциального решения.

Добро пожаловать на сайт PullRequest, где вы можете задавать вопросы и получать ответы от других членов сообщества.
...