SCP / RSYNC stall out with "rcvd adjust [...]" notices - 2015-03-01 and 64-bit Wheezy host

GoogleGroups
1

I have a Beaglebone Black with a fresh flash of the 2015-03-01 Debian image (bone-debian-7.8-lxde-4gb-armhf-2015-03-01-4gb.img) that I cannot scp or rsync large files to.

The debug output from scp shows nothing but “debug2: channel 0: rcvd adjust [number]” notices.

Searching the web suggests:

  • MTU mis-matches - no, both sides are 1500.

  • turning off tcp_sack - didn’t help

  • Enable compression - didn’t help

  • Try rsync - rsync fails, too

  • Try tar over ssh directly - didn’t work

  • Upgrading scp/sshd - did “apt-get upgrade scp” and that freshened up a lot but didn’t help.
    Log snippet is below. Any suggestions are appreciated.

`
philmills@VM64:~/DEV/AUC/dist/BEAGLEBONE$ scp -vv -C ModTests debian@a.b.c.d:/home/debian
Executing: program /usr/bin/ssh host a.b.c.d, user debian, command scp -v -t /home/debian
OpenSSH_6.0p1 Debian-4+deb7u2, OpenSSL 1.0.1e 11 Feb 2013
debug1: Reading configuration data /etc/ssh/ssh_config
debug1: /etc/ssh/ssh_config line 19: Applying options for *
debug2: ssh_connect: needpriv 0
debug1: Connecting to a.b.c.d [a.b.c.d] port 22.
debug1: Connection established.
debug1: identity file /home/philmills/.ssh/id_rsa type -1
debug1: identity file /home/philmills/.ssh/id_rsa-cert type -1
debug1: identity file /home/philmills/.ssh/id_dsa type -1
debug1: identity file /home/philmills/.ssh/id_dsa-cert type -1
debug1: identity file /home/philmills/.ssh/id_ecdsa type -1
debug1: identity file /home/philmills/.ssh/id_ecdsa-cert type -1
debug1: Remote protocol version 2.0, remote software version OpenSSH_6.0p1 Debian-4+deb7u2
debug1: match: OpenSSH_6.0p1 Debian-4+deb7u2 pat OpenSSH*
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_6.0p1 Debian-4+deb7u2
debug2: fd 3 setting O_NONBLOCK
debug1: SSH2_MSG_KEXINIT sent
debug1: SSH2_MSG_KEXINIT received
debug2: kex_parse_kexinit: ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1
debug2: kex_parse_kexinit: ecdsa-sha2-nistp256-cert-v01@openssh.com,ecdsa-sha2-nistp384-cert-v01@openssh.com,ecdsa-sha2-nistp521-cert-v01@openssh.com,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,ssh-rsa-cert-v01@openssh.com,ssh-dss-cert-v01@openssh.com,ssh-rsa-cert-v00@openssh.com,ssh-dss-cert-v00@openssh.com,ssh-rsa,ssh-dss
debug2: kex_parse_kexinit: aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc@lysator.liu.se
debug2: kex_parse_kexinit: aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc@lysator.liu.se
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,umac-64@openssh.com,hmac-sha2-256,hmac-sha2-256-96,hmac-sha2-512,hmac-sha2-512-96,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-sha2-256,hmac-sha2-256-96,hmac-sha2-512,hmac-sha2-512-96,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: zlib@openssh.com,zlib,none
debug2: kex_parse_kexinit: zlib@openssh.com,zlib,none
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: ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1
debug2: kex_parse_kexinit: ssh-rsa,ssh-dss,ecdsa-sha2-nistp256
debug2: kex_parse_kexinit: aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc@lysator.liu.se
debug2: kex_parse_kexinit: aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc@lysator.liu.se
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,umac-64@openssh.com,hmac-sha2-256,hmac-sha2-256-96,hmac-sha2-512,hmac-sha2-512-96,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-sha2-256,hmac-sha2-256-96,hmac-sha2-512,hmac-sha2-512-96,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: none,zlib@openssh.com
debug2: kex_parse_kexinit: none,zlib@openssh.com
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-md5
debug1: kex: server->client aes128-ctr hmac-md5 zlib@openssh.com
debug2: mac_setup: found hmac-md5
debug1: kex: client->server aes128-ctr hmac-md5 zlib@openssh.com
debug1: sending SSH2_MSG_KEX_ECDH_INIT
debug1: expecting SSH2_MSG_KEX_ECDH_REPLY
debug1: Server host key: ECDSA 15:74:3c:e0:05:6a:34:98:4c:f5:f2:ed:3b:1b:2a:0d
debug1: Host ‘a.b.c.d’ is known and matches the ECDSA host key.
debug1: Found key in /home/philmills/.ssh/known_hosts:5
debug1: ssh_ecdsa_verify: signature correct
debug2: kex_derive_keys
debug2: set_newkeys: mode 1
debug1: SSH2_MSG_NEWKEYS sent
debug1: expecting SSH2_MSG_NEWKEYS
debug2: set_newkeys: mode 0
debug1: SSH2_MSG_NEWKEYS received
debug1: Roaming not allowed by server
debug1: SSH2_MSG_SERVICE_REQUEST sent
debug2: service_accept: ssh-userauth
debug1: SSH2_MSG_SERVICE_ACCEPT received
debug2: key: pmills BEC OpenSSH.ppk (0x7f141e16b290)
debug2: key: /home/philmills/.ssh/id_rsa ((nil))
debug2: key: /home/philmills/.ssh/id_dsa ((nil))
debug2: key: /home/philmills/.ssh/id_ecdsa ((nil))
Debian GNU/Linux 7

BeagleBoard.org Debian Image 2015-03-01

Support/FAQ: Beagleboard:BeagleBoneBlack Debian - eLinux.org

default username:password is [debian:temppwd]

debug1: Authentications that can continue: publickey,password
debug1: Next authentication method: publickey
debug1: Offering RSA public key: pmills BEC OpenSSH.ppk
debug2: we sent a publickey packet, wait for reply
debug1: Authentications that can continue: publickey,password
debug1: Trying private key: /home/philmills/.ssh/id_rsa
debug1: Trying private key: /home/philmills/.ssh/id_dsa
debug1: Trying private key: /home/philmills/.ssh/id_ecdsa
debug2: we did not send a packet, disable method
debug1: Next authentication method: password
debian@a.b.c.d’s password:
debug2: we sent a password packet, wait for reply
debug1: Enabling compression at level 6.
debug1: Authentication succeeded (password).
Authenticated to a.b.c.d ([a.b.c.d]:22).
debug2: fd 4 setting O_NONBLOCK
debug2: fd 5 setting O_NONBLOCK
debug1: channel 0: new [client-session]
debug2: channel 0: send open
debug1: Requesting no-more-sessions@openssh.com
debug1: Entering interactive session.
debug2: callback start
debug2: client_session2_setup: id 0
debug2: fd 3 setting TCP_NODELAY
debug1: Sending environment.
debug1: Sending env LANG = en_US.UTF-8
debug2: channel 0: request env confirm 0
debug1: Sending command: scp -v -t /home/debian
debug2: channel 0: request exec confirm 1
debug2: callback done
debug2: channel 0: open confirm rwindow 0 rmax 32768
debug2: channel 0: rcvd adjust 2097152
debug2: channel_input_status_confirm: type 99 id 0
debug2: exec request accepted on channel 0
Sending file modes: C0755 27054794 ModTests
debug2: channel 0: rcvd ext data 33
Sink: C0755 27054794 ModTests
debug2: channel 0: written 33 to efd 6
ModTests 0% 0 0.0KB/s --:-- ETA
debug2: channel 0: rcvd adjust 98331
debug2: channel 0: rcvd adjust 114688
debug2: channel 0: rcvd adjust 114688
debug2: channel 0: rcvd adjust 131072
debug2: channel 0: rcvd adjust 114688
debug2: channel 0: rcvd adjust 131072
debug2: channel 0: rcvd adjust 65536
debug2: channel 0: rcvd adjust 65536
debug2: channel 0: rcvd adjust 131072
debug2: channel 0: rcvd adjust 65536
debug2: channel 0: rcvd adjust 131072
debug2: channel 0: rcvd adjust 163840
debug2: channel 0: rcvd adjust 163840
debug2: channel 0: rcvd adjust 131072
debug2: channel 0: rcvd adjust 131072
debug2: channel 0: rcvd adjust 131072
debug2: channel 0: rcvd adjust 131072
debug2: channel 0: rcvd adjust 131072
`

[and so on and so forth until I kill -9 the scp process]

2

Testing with various Windows SCP utilities fails in a similar way. The transfer starts out fine and then rapidly throttles down to extinction.

WinSCP, SmarTTY

3

Got a GigE desktop switch and connected directly (previously both the Beaglebone and my workstation were connected through the corporate network) and the problem goes away.

So it’s not an issue with the BB code (thankfully), but any insights as to what tweaks/settings I can point our network staff towards would be helpful.

4

Not sure if it is the same thing, but my ISP has what they call “fair use policy”

where they throttle back the bandwidth after a few seconds of file transfer.

If you start and stop the transfer, the speed goes back up briefly.

Could your network be doing the same thing ??

5

So it’s not an issue with the BB code (thankfully), but any insights as to what tweaks/settings I can point our network staff towards would be helpful.

Sounds like the network staff is being a bit too draconian with QoS, or you picked a really bad time, like when a major system backup was happening or something. But if they need to throttle the business network THAT MUCH. then they need to add another network . . .