transferências de arquivos SSH travar após ~ 700 KB

Question

VISÃO GERAL

Estou fazendo o script de transferências de arquivo SFTP em uma caixa do Windows 7 no campo. Quando eu transfiro arquivos zip maiores do que um megabyte ou mais, a transferência (e SSH) pára inesperadamente após cerca de 700 KB. O processo SSH parece travar, mas não começa a consumir muito CPU ou memória, e o Windows não diz que parou de responder. O servidor eventualmente desiste e expira, mas o cliente nunca retorna (apesar de definir ServerAliveCountMax e ServerAliveInterval). Os registros do servidor mostram o início da transferência seguido do tempo limite e desconectam após um longo período de tempo.

DETALHES

Executando novamente o script de volta para trás, o mesmo número de bytes é transferido antes do travamento a cada vez. Indo embora e voltando, então executando o script novamente, a contagem de bytes irá variar em algumas dezenas de kilobytes.

O cliente sftp.exe da linha de comando funciona corretamente com as opções padrão; esses arquivos zip maiores são transferidos com sucesso. Eu não posso testar scp.exe porque a conta de usuário do SSH não tem acesso ao shell. Acredito que o problema persistiu em uma limpeza do sistema operacional e re-imagem do XP para 7, então suspeito de um problema de rede, mas não consigo entender que tipo de problema causaria esse comportamento.

Estou fazendo scripts com o Perl e o módulo Net :: SFTP :: Foreign. Aqui estão os bits de código relevantes extraídos do meu script de caso de teste (log de saída SSH anexado abaixo):

 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 ));
}

Eu uso este código e configuração muito similar em dezenas de outros PCs de campo para o mesmo propósito. Este é o primeiro que eu vi com esse problema. Estou procurando uma causa raiz ou um conselho de diagnóstico, não uma solução alternativa fora desse ecossistema. Existem inúmeras maneiras de fazer isso, mas eu preciso da granularidade, feedback e modularidade do módulo Net :: SFTP :: Foreign para registro e relatório de erros. Perl é a única linguagem de script disponível.

Obrigado. Isso tem sido incrivelmente frustrante.

Configuração:

• Windows 7
• ActivePerl 5.8.9
• Net :: SFTP :: Estrangeiro v1.69
• OpenSSH 5.3p1 (cliente Windows da distribuição CopSSH)
• OpenVPN 2.2-rc (conexão do Windows de volta à rede corporativa)
• Servidor Tectia 6.2.1.168 (servidor Linux SSH)

Saída do cliente (-vvvv) até que eu terminei manualmente o ssh.exe depois que ele foi para o lado:

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

UPDATE 1
Seguindo o conselho do @Daniel Lawson, eu tentei usar o netsh para fixar a MTU da interface VPN em 1280 para evitar o preenchimento dos buffers TCP do cliente no caso de uma incompatibilidade de MTU ao longo do caminho para o servidor. A transferência ainda parou mais ou menos no mesmo ponto. Eu também tentei desconectar a VPN e prender a MTU da interface física em 1280 com o mesmo resultado com falha.

    

Answer 1

NOTA (TLDR): Como disse salva, a solução rápida é atualizar para Net :: SFTP :: Foreign 1.70_08 ou mais recente. Houve um erro impedindo a biblioteca de usar o padrão correto queue_size no Windows. Leia a minha solução original.

Consegui eliminar as transferências paralisadas reduzindo o parâmetro queue_size do módulo Perl Net :: SFTP :: Foreign do padrão 32 para 23. Esta é uma variável relacionada ao desempenho da rede e não percebo uma diferença de velocidade quando é reduzido. Para produção, vou discar de volta para 16 por segurança.

queue_size => $size

read and write requests are pipelined in order to maximize transfer throughput. This option allows to set the maximum number of requests that can be concurrently waiting for a server response.

(from Net::SFTP::Foreign documentation on CPAN)

A opção queue_size se aplica a <:: href="http://search.cpan.org/~salva/Net-SFTP-Foreign-1.69/lib/Net/SFTP/Foreign.html de Net :: SFTP :: Foreign #Net :: SFTP :: Foreign-% 3Enew% 28% args% 29 "> new , get , put , rget e rput .

Se você estiver usando o Net :: SFTP :: Foreign, você pode adicionar o parâmetro queue_size no final do seu construtor ou as chamadas individuais do método.

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

Estou usando o wrapper Net :: SFTP :: Foreign :: Compat para uma API semelhante a Net :: SFTP. O wrapper permite que você defina os parâmetros padrão para usar com as chamadas de método Net :: SFTP :: Foreign subjacentes.

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 );

Pensamento relacionado: O máximo de trabalho queue_size de 23 e o padrão block_size de 32 KB correlacionados com o número de bytes enviados antes da transferência parar. 23 * 32KB é um pouco mais de 700KB. Não consigo explicar por que precisei limitar o queue_size nessa implantação, mas isso resolveu meu problema.

    

Answer 2

Isso parece um problema de MTU para mim. Eu vi problemas semelhantes com arquivos scping quando há uma incompatibilidade de caminho MTU. Os buffers TCP no host podem ser preenchidos, e é por isso que você envia mais do que alguns pacotes, mas depois que eles preenchem o seu cliente, eles param - muito tempo depois que o próprio problema do MTU teve um impacto.

Para verificar isso, você pode ver uma ferramenta como scamper . Ou você pode tentar manualmente fixar seu MTU em algum ponto mais baixo - digamos 1280 bytes - e ver se isso o corrige. As chances são boas que há apenas uma ligeira incompatibilidade, por exemplo, por causa de um link PPPoE no caminho que reduz o MTU para 1492.

    

Answer 3

talvez você possa jogar com o parâmetro block_size ? Eu experimentei algumas estranhezas relacionadas a uploads de arquivos através de SSH / SSL e de alguma forma ajudei o tamanho do bloco / bloco. Eu acredito que o padrão é 32 * 1024 , então talvez diminuindo para 16, 8, 4 e tentando pode fazer alguma diferença. Pode valer uma chance.

    

Answer 4

O tamanho da fila padrão no Windows foi definido como 4, mas esse padrão não estava sendo selecionado devido a um bug no módulo.

Foi corrigido (e BTW, o tamanho da fila padrão do Windows foi alterado para 16). Agora você pode fazer o download de Net :: SFTP :: Foreign 1.70_08 .

Da próxima vez que você encontrar um problema como este, denuncie-o!