Назад | Перейти на главную страницу

Передача файлов по SSH зависает после ~ 700 КБ

ОБЗОР

Я пишу сценарии передачи файлов SFTP в поле Windows 7 в поле. Когда я передаю zip-файлы размером более мегабайта или около того, передача (и SSH) неожиданно останавливается примерно через 700 КБ. Кажется, что процесс SSH зависает, но он не начинает сильно загружать процессор или память, и Windows не сообщает, что он перестал отвечать. В конечном итоге сервер сдается и выходит из строя, но клиент никогда не возвращается (несмотря на то, что установлены ServerAliveCountMax и ServerAliveInterval). Журналы сервера показывают начало передачи с последующим тайм-аутом и отключением через долгое время.

ПОДРОБНОСТИ

Повторный запуск сценария один за другим, каждый раз перед зависанием передается одинаковое количество байтов. Если уйти и вернуться, а затем снова запустить скрипт, количество байтов изменится на несколько десятков килобайт.

Клиент командной строки sftp.exe правильно работает с параметрами по умолчанию; эти большие zip-файлы передаются успешно. Я не могу протестировать scp.exe, потому что у учетной записи пользователя SSH нет доступа к оболочке. Я считаю, что проблема сохраняется при очистке ОС и повторном изменении образа с XP на 7, поэтому я подозреваю проблему с сетью, но я не могу понять, какая проблема может вызвать такое поведение.

Я пишу сценарии с Perl и модулем Net :: SFTP :: Foreign. Вот соответствующие фрагменты кода, извлеченные из моего тестового сценария (журнал вывода SSH прилагается ниже):

 my %connectOpts = ( 
  user     => $username
  ,timeout => $timeout
  ,warn    => sub {}
  ,more    => [ "-o PreferredAuthentications=publickey",
               "-o ServerAliveCountMax=6",
               "-o ServerAliveInterval=" . int($timeout/6),
               "-vvvv" ]
  );

my $sftp = Net::SFTP::Foreign::Compat->new( $host, %connectOpts );

foreach my $local_file ( @local_files ) {
  $sftp->do_stat( 'upload.tmp' ) && print( "Overwriting upload.tmp\n" );

  $sftp->put( $local_file, 'upload.tmp' );

  $sftp->do_rename( 'upload.tmp', basename( $local_file ));
}

Я использую этот код и очень похожую конфигурацию на десятках других полевых ПК с той же целью. Это первая проблема, которую я видел. Я ищу первопричину или диагностический совет, а не обходной путь за пределами этой экосистемы. Есть бесчисленное множество способов написать это, но мне нужна детализация, обратная связь и модульность модуля Net :: SFTP :: Foreign для ведения журнала и отчетов об ошибках. Perl - единственный доступный язык сценариев.

Спасибо. Это было невероятно неприятно.

Конфигурация:

Вывод клиента (-vvvv) до тех пор, пока я вручную не завершу ssh.exe после того, как он перестал работать:

OpenSSH_5.3p1, OpenSSL 0.9.8k 25 Mar 2009
debug1: Reading configuration data /etc/ssh_config
debug2: ssh_connect: needpriv 0
debug1: Connecting to sftp.server.com [xx.xx.xx.xx] port 22.
debug1: Connection established.
debug1: identity file /cygdrive/c/program files/copssh/.ssh/identity type -1
debug3: Not a RSA1 key file /cygdrive/c/program files/copssh/.ssh/id_rsa.
debug2: key_type_from_name: unknown key type '-----BEGIN'
debug3: key_read: missing keytype
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug2: key_type_from_name: unknown key type '-----END'
debug3: key_read: missing keytype
debug1: identity file /cygdrive/c/program files/copssh/.ssh/id_rsa type 1
debug1: identity file /cygdrive/c/program files/copssh/.ssh/id_dsa type -1
debug1: Remote protocol version 2.0, remote software version 6.2.1.168 SSH Tectia Server
debug1: no match: 6.2.1.168 SSH Tectia Server
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_5.3
debug2: fd 3 setting O_NONBLOCK
debug1: SSH2_MSG_KEXINIT sent
debug3: Wrote 792 bytes for a total of 813
debug1: SSH2_MSG_KEXINIT received
debug2: kex_parse_kexinit: diffie-hellman-group-exchange-sha256,diffie-hellman-g
roup-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1
debug2: kex_parse_kexinit: ssh-rsa,ssh-dss
debug2: kex_parse_kexinit: aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour12
8,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rij
ndael-cbc@lysator.liu.se
debug2: kex_parse_kexinit: aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour12
8,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rij
ndael-cbc@lysator.liu.se
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,umac-64@openssh.com,hmac-ripemd160
,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,umac-64@openssh.com,hmac-ripemd160
,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: none,zlib@openssh.com,zlib
debug2: kex_parse_kexinit: none,zlib@openssh.com,zlib
debug2: kex_parse_kexinit:
debug2: kex_parse_kexinit:
debug2: kex_parse_kexinit: first_kex_follows 0
debug2: kex_parse_kexinit: reserved 0
debug2: kex_parse_kexinit: diffie-hellman-group1-sha1,diffie-hellman-group14-sha
1,diffie-hellman-group14-sha256@ssh.com,diffie-hellman-group-exchange-sha1,diffi
e-hellman-group-exchange-sha256
debug2: kex_parse_kexinit: ssh-rsa,ssh-rsa-sha256@ssh.com
debug2: kex_parse_kexinit: aes256-cbc,aes192-cbc,aes128-cbc,3des-cbc
debug2: kex_parse_kexinit: aes256-cbc,aes192-cbc,aes128-cbc,3des-cbc
debug2: kex_parse_kexinit: hmac-sha1
debug2: kex_parse_kexinit: hmac-sha1
debug2: kex_parse_kexinit: none,zlib
debug2: kex_parse_kexinit: none,zlib
debug2: kex_parse_kexinit:
debug2: kex_parse_kexinit:
debug2: kex_parse_kexinit: first_kex_follows 0
debug2: kex_parse_kexinit: reserved 0
debug2: mac_setup: found hmac-sha1
debug1: kex: server->client aes128-cbc hmac-sha1 none
debug2: mac_setup: found hmac-sha1
debug1: kex: client->server aes128-cbc hmac-sha1 none
debug1: SSH2_MSG_KEX_DH_GEX_REQUEST(1024<2048<8192) sent
debug1: expecting SSH2_MSG_KEX_DH_GEX_GROUP
debug3: Wrote 24 bytes for a total of 837
debug2: dh_gen_key: priv key bits set: 160/320
debug2: bits set: 1016/2048
debug1: SSH2_MSG_KEX_DH_GEX_INIT sent
debug1: expecting SSH2_MSG_KEX_DH_GEX_REPLY
debug3: Wrote 272 bytes for a total of 1109
debug3: check_host_in_hostfile: filename /cygdrive/c/program files/copssh/.ssh/known_hosts
debug3: check_host_in_hostfile: match line 2
debug3: check_host_in_hostfile: filename /cygdrive/c/program files/copssh/.ssh/known_hosts
debug3: check_host_in_hostfile: match line 1
debug1: Host 'sftp.server.com' is known and matches the RSA host key.
debug1: Found key in /cygdrive/c/program files/copssh/.ssh/known_hosts:2
debug2: bits set: 995/2048
debug1: ssh_rsa_verify: signature correct
debug2: kex_derive_keys
debug2: set_newkeys: mode 1
debug1: SSH2_MSG_NEWKEYS sent
debug1: expecting SSH2_MSG_NEWKEYS
debug3: Wrote 16 bytes for a total of 1125
debug2: set_newkeys: mode 0
debug1: SSH2_MSG_NEWKEYS received
debug1: SSH2_MSG_SERVICE_REQUEST sent
debug3: Wrote 52 bytes for a total of 1177
debug3: Received SSH2_MSG_IGNORE
debug3: Received SSH2_MSG_IGNORE
debug2: service_accept: ssh-userauth
debug1: SSH2_MSG_SERVICE_ACCEPT received
debug2: key: /cygdrive/c/program files/copssh/.ssh/identity (0x0)
debug2: key: /cygdrive/c/program files/copssh/.ssh/id_rsa (0xd4b720)
debug2: key: /cygdrive/c/program files/copssh/.ssh/id_dsa (0x0)
debug3: Wrote 84 bytes for a total of 1261
debug3: Received SSH2_MSG_IGNORE
debug1: Authentications that can continue: publickey,keyboard-interactive
debug3: start over, passed a different list publickey,keyboard-interactive
debug3: preferred publickey
debug3: authmethod_lookup publickey
debug3: remaining preferred:
debug3: authmethod_is_enabled publickey
debug1: Next authentication method: publickey
debug1: Trying private key: /cygdrive/c/program files/copssh/.ssh/identity
debug3: no such identity: /cygdrive/c/program files/copssh/.ssh/identity
debug1: Offering public key: /cygdrive/c/program files/copssh/.ssh/id_rsa
debug3: send_pubkey_test
debug2: we sent a publickey packet, wait for reply
debug3: Wrote 372 bytes for a total of 1633
debug3: Received SSH2_MSG_IGNORE
debug1: Server accepts key: pkalg ssh-rsa blen 277
debug2: input_userauth_pk_ok: fp (...)
debug3: sign_and_send_pubkey
debug1: read PEM private key done: type RSA
debug3: Wrote 644 bytes for a total of 2277
debug3: Received SSH2_MSG_IGNORE
debug1: Authentication succeeded (publickey).
debug2: fd 4 setting O_NONBLOCK
debug2: fd 5 setting O_NONBLOCK
debug1: channel 0: new [client-session]
debug3: ssh_session2_open: channel_new: 0
debug2: channel 0: send open
debug1: Entering interactive session.
debug3: Wrote 68 bytes for a total of 2345
debug3: Received SSH2_MSG_IGNORE
debug2: callback start
debug2: client_session2_setup: id 0
debug1: Sending subsystem: sftp
debug2: channel 0: request subsystem confirm 1
debug2: fd 3 setting TCP_NODELAY
debug2: callback done
debug2: channel 0: open confirm rwindow 65536 rmax 32768
debug3: Wrote 68 bytes for a total of 2413
debug3: Wrote 52 bytes for a total of 2465
debug3: Received SSH2_MSG_IGNORE
debug2: channel_input_status_confirm: type 99 id 0
debug2: subsystem request accepted on channel 0
debug3: Received SSH2_MSG_IGNORE
debug3: Wrote 68 bytes for a total of 2533
debug3: Received SSH2_MSG_IGNORE
debug3: Wrote 84 bytes for a total of 2617
debug3: Received SSH2_MSG_IGNORE
debug3: Wrote 68 bytes for a total of 2685
debug3: Received SSH2_MSG_IGNORE
debug3: Wrote 16436 bytes for a total of 19121
debug3: Wrote 4148 bytes for a total of 23269
debug3: Wrote 12372 bytes for a total of 35641
debug3: Wrote 16436 bytes for a total of 52077
debug3: Wrote 4148 bytes for a total of 56225
debug3: Wrote 12196 bytes for a total of 68421
debug3: Received SSH2_MSG_IGNORE
debug2: channel 0: rcvd adjust 32899
debug3: Wrote 212 bytes for a total of 68633
debug3: Received SSH2_MSG_IGNORE
debug3: Wrote 16436 bytes for a total of 85069
debug3: Wrote 4148 bytes for a total of 89217
debug3: Received SSH2_MSG_IGNORE
debug2: channel 0: rcvd adjust 98337
debug3: Received SSH2_MSG_IGNORE
debug3: Wrote 12372 bytes for a total of 101589
debug3: Wrote 16436 bytes for a total of 118025
debug3: Wrote 4148 bytes for a total of 122173
debug3: Wrote 12372 bytes for a total of 134545
debug3: Wrote 16436 bytes for a total of 150981
debug3: Received SSH2_MSG_IGNORE
debug3: Wrote 4148 bytes for a total of 155129
debug3: Wrote 12372 bytes for a total of 167501
debug3: Received SSH2_MSG_IGNORE
debug2: channel 0: rcvd adjust 196674
debug3: Received SSH2_MSG_IGNORE
debug3: Wrote 16436 bytes for a total of 183937
debug3: Received SSH2_MSG_IGNORE
debug3: Wrote 4148 bytes for a total of 188085
debug3: Wrote 12372 bytes for a total of 200457
debug3: Wrote 16436 bytes for a total of 216893
debug3: Wrote 4148 bytes for a total of 221041
debug3: Wrote 12372 bytes for a total of 233413
debug3: Wrote 16436 bytes for a total of 249849
debug3: Received SSH2_MSG_IGNORE
debug3: Wrote 4148 bytes for a total of 253997
debug3: Wrote 12372 bytes for a total of 266369
debug3: Received SSH2_MSG_IGNORE
debug3: Wrote 16436 bytes for a total of 282805
debug3: Wrote 4148 bytes for a total of 286953
debug3: Wrote 12372 bytes for a total of 299325
debug3: Received SSH2_MSG_IGNORE
debug2: channel 0: rcvd adjust 131204
debug3: Wrote 16436 bytes for a total of 315761
debug3: Received SSH2_MSG_IGNORE
debug3: Wrote 4148 bytes for a total of 319909
debug3: Received SSH2_MSG_IGNORE
debug3: Wrote 12372 bytes for a total of 332281
debug3: Wrote 16436 bytes for a total of 348717
debug3: Wrote 4148 bytes for a total of 352865
debug3: Wrote 12372 bytes for a total of 365237
debug3: Wrote 16436 bytes for a total of 381673
debug3: Wrote 4148 bytes for a total of 385821
debug3: Received SSH2_MSG_IGNORE
debug3: Wrote 12372 bytes for a total of 398193
debug3: Wrote 16436 bytes for a total of 414629
debug3: Received SSH2_MSG_IGNORE
debug3: Wrote 4148 bytes for a total of 418777
debug3: Wrote 12372 bytes for a total of 431149
debug3: Wrote 16436 bytes for a total of 447585
debug3: Received SSH2_MSG_IGNORE
debug2: channel 0: rcvd adjust 393348
debug3: Received SSH2_MSG_IGNORE
debug3: Wrote 4148 bytes for a total of 451733
debug3: Received SSH2_MSG_IGNORE
debug3: Wrote 12372 bytes for a total of 464105
debug3: Wrote 16436 bytes for a total of 480541
debug3: Wrote 4148 bytes for a total of 484689
debug3: Wrote 12372 bytes for a total of 497061
debug3: Wrote 16436 bytes for a total of 513497
debug3: Wrote 4148 bytes for a total of 517645
debug3: Received SSH2_MSG_IGNORE
debug3: Wrote 12372 bytes for a total of 530017
debug3: Wrote 16436 bytes for a total of 546453
debug3: Received SSH2_MSG_IGNORE
debug3: Wrote 4148 bytes for a total of 550601
debug3: Wrote 12372 bytes for a total of 562973
debug3: Wrote 16436 bytes for a total of 579409
debug3: Received SSH2_MSG_IGNORE
debug3: Wrote 4148 bytes for a total of 583557
debug3: Wrote 12372 bytes for a total of 595929
debug3: Wrote 16436 bytes for a total of 612365
debug3: Received SSH2_MSG_IGNORE
debug3: Wrote 4148 bytes for a total of 616513
debug3: Wrote 12372 bytes for a total of 628885
debug3: Wrote 16436 bytes for a total of 645321
debug3: Received SSH2_MSG_IGNORE
debug3: Wrote 4148 bytes for a total of 649469
debug3: Wrote 12372 bytes for a total of 661841
debug3: Wrote 16436 bytes for a total of 678277
debug3: Wrote 4148 bytes for a total of 682425
debug3: Received SSH2_MSG_IGNORE
debug3: Wrote 12372 bytes for a total of 694797
debug3: Wrote 16436 bytes for a total of 711233
debug3: Received SSH2_MSG_IGNORE
debug2: channel 0: rcvd adjust 738120
debug3: Received SSH2_MSG_IGNORE
debug3: Wrote 4148 bytes for a total of 715381
debug3: Received SSH2_MSG_IGNORE

ОБНОВЛЕНИЕ 1
Согласно совету @Daniel Lawson, я попытался использовать netsh для ограничения MTU интерфейса VPN до 1280, чтобы избежать заполнения TCP-буферов клиента в случае несоответствия MTU на пути к серверу. Передача все еще остановилась примерно в том же месте. Я также попытался отключить VPN и ограничить MTU физического интерфейса до 1280 с тем же неудачным результатом.

Мне кажется, что это проблема с MTU. Я видел аналогичные проблемы с файлами scping при несоответствии MTU пути. Буферы TCP на хосте могут заполняться, поэтому вы отправляете больше, чем несколько пакетов, но как только они заполняют ваш клиент, он останавливается - спустя много времени после того, как сама проблема MTU действительно повлияла.

Чтобы убедиться в этом, вы можете посмотреть такой инструмент, как бегать. Или вы можете попробовать вручную ограничить свой MTU до некоторой нижней точки - скажем, 1280 байт - и посмотреть, исправит ли это это. Велика вероятность того, что есть лишь небольшое несоответствие, например, из-за соединения PPPoE на пути, которое уменьшает MTU до 1492.

Размер очереди по умолчанию в Windows был установлен на 4, но это значение по умолчанию не использовалось из-за ошибки в модуле.

Это было исправлено (и, кстати, размер очереди Windows по умолчанию изменен на 16). Теперь вы можете скачать Net :: SFTP :: Foreign 1.70_08.

В следующий раз, когда вы обнаружите такую ​​проблему, сообщите об этом!

возможно ты сможешь поиграть с block_size параметр? Я испытал некоторые странности, связанные с загрузкой файлов через SSH / SSL, и каким-то образом помогла настройка размера блока / фрагмента. Я считаю, что по умолчанию 32 * 1024, так что, возможно, понижение до 16, 8, 4 и попытки могут иметь какое-то значение. Может, стоит попробовать.

ПРИМЕЧАНИЕ (TL; DR): Как сказал Сальва, быстрое решение - обновить до Сеть :: SFTP :: Внешняя 1.70_08 или новее. Произошла ошибка, не позволяющая библиотеке использовать правильное значение по умолчанию. queue_size в Windows. Читайте мое оригинальное решение.

Мне удалось устранить застойные передачи, уменьшив модуль Perl Net :: SFTP :: Foreign queue_size значение параметра по умолчанию с 32 на 23. Это переменная, связанная с производительностью сети, и я не чувствую разницы в скорости, когда она уменьшается. Для производства я собираюсь вернуть его к 16 для безопасности.

queue_size => $ size

Запросы на чтение и запись направляются в конвейер, чтобы максимизировать пропускную способность передачи. Эта опция позволяет установить максимальное количество запросов, которые могут одновременно ожидать ответа сервера.

(из Net :: SFTP :: Зарубежная документация по CPAN)

Параметр queue_size применяется к Net :: SFTP :: Foreign new, get, put, rget, и rput методы.

Если вы используете Net :: SFTP :: Foreign, вы можете использовать queue_size параметр в конце вашего конструктора или отдельных вызовов методов.

my $sftp = Net::SFTP::Foreign->new( $host, queue_size => 16 );
# -- OR --
$sftp->put( $local_file, $remote_file, queue_size => 16 );

Я использую оболочку Net :: SFTP :: Foreign :: Compat для API, подобного Net :: SFTP. Обертка позволяет вам установить параметры по умолчанию для использования с вызовами базовых методов Net :: SFTP :: Foreign.

use Net::SFTP::Foreign::Compat;

# Note that the Compat CPAN documentation is INCORRECT
# The DEFAULTS hash is under Compat, not Foreign

$Net::SFTP::Foreign::Compat::DEFAULTS{ new } = [ queue_size => 16 ];
# -- OR --
$Net::SFTP::Foreign::Compat::DEFAULTS{ put } = [ queue_size => 16 ];

my $sftp = Net::SFTP::Foreign::Compat->new( $host, %options );

Связанная мысль: Максимально рабочий queue_size из 23 и по умолчанию block_size 32 КБ коррелирует с количеством байтов, отправленных до остановки передачи. 23 * 32 КБ - чуть больше 700 КБ. Я не могу объяснить, почему мне нужно было ограничить queue_size в этом развертывании, но это решило мою проблему.