SSH 文件传输在约 700KB 后挂起

SSH 文件传输在约 700KB 后挂起

概述

我正在现场的 Windows 7 机器上编写 SFTP 文件传输脚本。当我传输大于 1 兆字节左右的 zip 文件时,传输(和 SSH)在大约 700KB 后意外停止。SSH 进程似乎挂起了,但它并没有开始疯狂消耗 CPU 或内存,Windows 也没有说它停止响应。服务器最终放弃并超时,但客户端永远不会返回(尽管设置了 ServerAliveCountMax 和 ServerAliveInterval)。服务器日志显示传输开始,然后是长时间后的超时和断开连接。

细节

连续运行脚本,每次在挂起前传输的字节数相同。离开并返回,然后再次运行脚本,字节数将相差几十千字节。

命令行 sftp.exe 客户端在默认选项下正常工作;那些较大的 zip 文件传输成功。我无法测试 scp.exe,因为 SSH 用户帐户没有 shell 访问权限。我相信问题在从 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 ));
}

我将此代码和非常相似的配置用于数十台其他现场 PC 以实现相同目的。这是我见过的第一个出现此问题的设备。我正在寻找根本原因或诊断建议,而不是此生态系统之外的解决方法。有无数种方法可以编写此脚本,但我需要 Net::SFTP::Foreign 模块的粒度、反馈和模块化,以便进行日志记录和错误报告。Perl 是唯一可用的脚本语言。

谢谢。这真是太令人沮丧了。

配置:

  • Windows 7的
  • ActivePerl 5.8.9
  • Net::SFTP::Foreign v1.69
  • OpenSSH 5.3p1(来自 CopSSH 发行版的 Windows 客户端)
  • OpenVPN 2.2-rc(Windows 连接回公司网络)
  • Tectia Server 6.2.1.168(Linux SSH 服务器)

客户端输出(-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
[email protected]
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
[email protected]
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,[email protected],hmac-ripemd160
,[email protected],hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,[email protected],hmac-ripemd160
,[email protected],hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: none,[email protected],zlib
debug2: kex_parse_kexinit: none,[email protected],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,[email protected],diffie-hellman-group-exchange-sha1,diffi
e-hellman-group-exchange-sha256
debug2: kex_parse_kexinit: ssh-rsa,[email protected]
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将VPN接口的MTU限制为1280,以避免在到服务器的路径上出现MTU不匹配的情况下填满客户端的TCP缓冲区。传输仍然在同一点停滞。我还尝试断开VPN并将物理接口的MTU限制为1280,但结果同样失败。

答案1

我觉得这像是 MTU 问题。当路径 MTU 不匹配时,我曾看到过类似的 scping 文件问题。主机上的 TCP 缓冲区可能会填满,这就是为什么您会发送多个数据包,但一旦它们填满,您的客户端就会停滞 - 远远晚于 MTU 问题本身产生影响之后。

为了验证这一点,你可以查看类似的工具疾走。或者您可以尝试手动将 MTU 限制到某个较低的点(例如 1280 字节),然后查看是否能解决问题。很有可能只是存在轻微的不匹配,例如由于路径中的 PPPoE 链接将 MTU 降低到 1492。

答案2

也许你可以尝试一下这个block_size参数?我遇到了一些与通过 SSH/SSL 上传文件相关的怪异情况,调整块/块大小似乎有所帮助。我相信默认值是32 * 1024,所以也许将其降低到 16、8、4 并尝试可能会有所不同。也许值得一试。

答案3

Windows 上的默认队列大小设置为 4,但由于模块上的错误,此默认值未被采用。

已更正此问题(顺便说一句,Windows 默认队列大小已更改为 16)。您现在可以下载网络::SFTP::外国 1.70_08

下次您发现类似问题时,请报告!

答案4

注意(TLDR):正如萨尔瓦所说,快速修复方法是更新到网络::SFTP::外国 1.70_08或更新版本。有一个错误阻止库queue_size在 Windows 中使用正确的默认值。请继续阅读我的原始解决方案。

通过将 Perl Net::SFTP::Foreign 模块的参数从默认的 32 减少到 23,我能够消除传输停滞。queue_size这是一个与网络性能相关的变量,减少时我感觉不到速度差异。对于生产,为了安全起见,我将把它调回 16。

队列大小 => $size

读取和写入请求采用流水线方式,以最大程度地提高传输吞吐量。此选项允许设置可同时等待服务器响应的最大请求数。

(从CPAN 上的 Net::SFTP::Foreign 文档

队列大小选项适用于 Net::SFTP::Foreign 的newgetputrget, 和rput方法。

queue_size如果您使用 Net::SFTP::Foreign,您可以在构造函数或单个方法调用的末尾添加该参数。

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

我正在使用 Net::SFTP::Foreign::Compat 包装器来获取类似 Net::SFTP 的 API。包装器允许您设置默认参数与底层 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_size23 和默认值block_size32KB 与传输停止前发送的字节数相关。23 * 32KB 略大于 700KB。我无法解释为什么我需要queue_size在此部署中进行限制,但它解决了我的问题。

相关内容