Created attachment 2778 [details] The patch to rekey limit computation, based on GitHub commit 2c48eb1 I'm refiling this report in Bugzilla as a follow-up to my GitHub pull request https://github.com/openssh/openssh-portable/pull/19 (which went largely unnoticed). The pull request changes the way in which the rekey limit is computed based on cipher block size to address a problem with OpenSSH going over the intended limit. But first, a short background story: In 2013, Red Hat has introduced a patch for OpenSSL that adds some additional checks to its GCM implementation: https://lists.fedoraproject.org/pipermail/scm-commits/Week-of-Mon-20131111/1144834.html These checks are based on recommendations from NIST SP 800-38D: http://csrc.nist.gov/publications/nistpubs/800-38D/SP-800-38D.pdf Among those, section 5.2.1.1 imposes a limit on plaintext length that amounts to 64 GiB. At Facebook, this was causing our scp transfers larger than 64 GiB to die with a cipher_crypt: EVP_Cipher failed error. The check implementing this limit has been recently rolled back by Red Hat: https://rhn.redhat.com/errata/RHBA-2015-0772.html The reason for dropping it is stated in the package's ChangeLog: Thu Mar 26 2015 Tomáš Mráz tmraz@redhat.com 1.0.1e-30.8 drop the AES-GCM restriction of 2^32 operations because the IV is always 96 bits (32 bit fixed field + 64 bit invocation field) According to our own analysis, the change does not remove an operations count restriction (specified in Sec 8.3 of NIST SP 800-38D and dependent on usage of a non-recommended IV configuration), but total plaintext length restriction (specified in Sec 5.2.1.1, which is unconditional). Regardless of validity of the removed check, it has exposed what I believe to be a bug in OpenSSH in the way that rekey limits (based on data, instead of time) are handled. Currently, if the rekey limit is not explicitly configured, it's computed algorithmically based on the cipher's block size: https://github.com/openssh/openssh-portable/blob/3f4ea3c9ab1d32d43c9222c4351f58ca11144156/packet.c#L1003 For a 128-bit block cipher like AES-GCM, this amounts to a limit of exactly 64GiB - the same as the recommended by NIST. However, since the check for exceeding the rekey limit (max_blocks_* fields in the session state) is only performed in clientloop and serverloop after processing a buffered batch of packets, the amount of data encrypted/decrypted will almost always go above the limit for a few blocks (depending on how much of them were in the buffer) before rekeying is triggered. In our case at Facebook, this was causing AES-GCM to go above the 64 GiB limit shortly before triggering rekeying and abort with an error, unless a sufficiently lower RekeyLimit is explicitly set (which itself can only be set to values less than 4GiB because of u32int being used, but that's a different story). My proposed fix is to deduce the maximum theoretical amount of buffered blocks from the computed max_blocks value.
BTW, this seems to rebase cleanly against today's master branch head: https://github.com/aadamowski/openssh-portable/commit/60245fa4daec43aba8bde860fa2afab983270cc5 It does compile and sshd starts up.
(In reply to Aleksander Adamowski from comment #0) > I'm refiling this report in Bugzilla as a follow-up to my GitHub > pull request https://github.com/openssh/openssh-portable/pull/19 > (which went largely unnoticed). Github is just a mirror - we don't do development there (as noted in the README). Darren was taking a look at this recently.
Yeah, I've noticed commit e91346d (we don't use Github for issues/pull-requests). That's why I came here, to Bugzilla.
Created attachment 2779 [details] Account for actual contents of buffers when calculating rekeying Patch #2778 solves the problem with the large rekeylimit ciphers but it still potentially leaves the problems with the others, and using the same approach on those will rekey significantly more than requested. An alternative patch that checks the actual buffer usage which should be more accurate. Can you confirm that this also solves the problem you have observed?
Created attachment 2780 [details] Allow rekeylimits >4G. I also fixed RekeyLimit to allow limits >4G (should work up to 2**63, limited by the return value of scan_scaled).
Comment on attachment 2779 [details] Account for actual contents of buffers when calculating rekeying Turns out this is not correct. It (at least) fails with very small values of rekeylimit due to constant rekeying and no forward progress.
Created attachment 2783 [details] refactor rekeying logic This is a more substantial refactoring of the rekeying logic that moves the tests close to where packets are sent and received. If you are able to test this (with OpenSSH git head) with very large transfers then it would be appreciated.
Hi djm, TL;DR: Good news, I've retested your refactor patch (attachment 2783 [details] applied on top of current OpenSSH git master head) on CentOS 6 with downgraded OpenSSL (that enforces AES-GCM 64G limit) and the refactor does address the problem correctly. Here's a detailed report from my test: On CentOS 6: ---- HEAD == commit 4c6cb83, BEFORE applying patch 2783: ---- $ sudo yum downgrade openssl-1.0.1e-30.el6_6.5.x86_64 openssl-devel-1.0.1e-30.el6_6.5.x86_64 $ cd openssh-portable $ make clean $ ./configure --prefix=/opt/openssh-work && make && echo OK $ sudo make install $ mkdir -p ~/.ssh-work && chmod 700 ~/.ssh-work $ ssh-keygen -t rsa -f ~/.ssh-work/openssh-work.key $ cat ~/.ssh-work/openssh-work.key.pub >> ~/.ssh/authorized_keys_openssh-work; chmod 600 ~/.ssh/authorized_keys_openssh-work $ sudo perl -pe 's{(AuthorizedKeysFile\s+.ssh/authorized_keys$)}{$1_openssh-work}' -i /opt/openssh-work/etc/sshd_config TERM 1: $ sudo $PWD/sshd -p 22222 -D -d -e TERM 2: $ dd if=/dev/zero bs=1M count=65534 | pv -prb | $PWD/ssh -o BatchMode=yes -o ConnectTimeout=15 -o ServerAliveInterval=15 -o TCPKeepAlive=yes -o StrictHostKeyChecking=no -c aes256-gcm@openssh.com -p 22222 -i ~/.ssh-work/openssh-work.key -v localhost 'cat > /dev/null' 2>&1 | awk '{ print strftime("%Y-%m-%d %H:%M:%S"), $0; fflush(); }' 2016-02-01 12:14:51 OpenSSH_7.1p2, OpenSSL 1.0.1e-fips 11 Feb 2013 2016-02-01 12:14:51 debug1: Reading configuration data /opt/openssh-work/etc/ssh_config 2016-02-01 12:14:51 debug1: Connecting to localhost [::1] port 22222. 2016-02-01 12:14:51 debug1: fd 3 clearing O_NONBLOCK 2016-02-01 12:14:51 debug1: Connection established. 2016-02-01 12:14:51 debug1: identity file /home/olo/.ssh-work/openssh-work.key type 1 2016-02-01 12:14:51 debug1: key_load_public: No such file or directory 2016-02-01 12:14:51 debug1: identity file /home/olo/.ssh-work/openssh-work.key-cert type -1 2016-02-01 12:14:51 debug1: Enabling compatibility mode for protocol 2.0 2016-02-01 12:14:51 debug1: Local version string SSH-2.0-OpenSSH_7.1 2016-02-01 12:14:51 debug1: Remote protocol version 2.0, remote software version OpenSSH_7.1 2016-02-01 12:14:51 debug1: match: OpenSSH_7.1 pat OpenSSH* compat 0x04000000 2016-02-01 12:14:51 debug1: Authenticating to localhost:22222 as 'olo' 2016-02-01 12:14:51 debug1: SSH2_MSG_KEXINIT sent 2016-02-01 12:14:51 debug1: SSH2_MSG_KEXINIT received 2016-02-01 12:14:51 debug1: kex: algorithm: curve25519-sha256@libssh.org 2016-02-01 12:14:51 debug1: kex: host key algorithm: ecdsa-sha2-nistp256 2016-02-01 12:14:51 debug1: kex: server->client cipher: aes256-gcm@openssh.com MAC: <implicit> compression: none 2016-02-01 12:14:51 debug1: kex: client->server cipher: aes256-gcm@openssh.com MAC: <implicit> compression: none 2016-02-01 12:14:51 debug1: expecting SSH2_MSG_KEX_ECDH_REPLY 2016-02-01 12:14:51 debug1: Server host key: ecdsa-sha2-nistp256 SHA256:1t75itcZmuKxHOZDYnf2rFChaodNSPb03bqjWrddgAw 2016-02-01 12:14:51 debug1: Host '[localhost]:22222' is known and matches the ECDSA host key. 2016-02-01 12:14:51 debug1: Found key in /home/olo/.ssh/known_hosts:31 2016-02-01 12:14:51 debug1: rekey after 4294967296 blocks 2016-02-01 12:14:51 debug1: SSH2_MSG_NEWKEYS sent 2016-02-01 12:14:51 debug1: expecting SSH2_MSG_NEWKEYS 2016-02-01 12:14:51 debug1: rekey after 4294967296 blocks 2016-02-01 12:14:51 debug1: SSH2_MSG_NEWKEYS received 2016-02-01 12:14:51 debug1: SSH2_MSG_EXT_INFO received 2016-02-01 12:14:51 debug1: kex_input_ext_info: server-sig-algs=<rsa-sha2-256,rsa-sha2-512> 2016-02-01 12:14:51 debug1: SSH2_MSG_SERVICE_ACCEPT received 2016-02-01 12:14:51 debug1: Authentications that can continue: publickey,password,keyboard-interactive 2016-02-01 12:14:51 debug1: Next authentication method: publickey 2016-02-01 12:14:51 debug1: Offering RSA public key: rsa w/o comment 2016-02-01 12:14:51 debug1: Authentications that can continue: publickey,password,keyboard-interactive 2016-02-01 12:14:51 debug1: Offering RSA-CERT public key: rsa w/o comment 2016-02-01 12:14:51 debug1: Authentications that can continue: publickey,password,keyboard-interactive 2016-02-01 12:14:51 debug1: Offering RSA public key: /home/olo/.ssh-work/openssh-work.key 2016-02-01 12:14:51 debug1: Server accepts key: pkalg rsa-sha2-512 blen 279 2016-02-01 12:14:51 debug1: Authentication succeeded (publickey). 2016-02-01 12:14:51 Authenticated to localhost ([::1]:22222). 2016-02-01 12:14:51 debug1: channel 0: new [client-session] 2016-02-01 12:14:51 debug1: Requesting no-more-sessions@openssh.com 2016-02-01 12:14:51 debug1: Entering interactive session. 2016-02-01 12:14:51 debug1: pledge: network 2016-02-01 12:14:51 debug1: client_input_global_request: rtype hostkeys-00@openssh.com want_reply 0 2016-02-01 12:14:51 debug1: Sending command: cat > /dev/null 2016-02-01 12:14:51 Environment: 2016-02-01 12:14:51 USER=olo 2016-02-01 12:14:51 LOGNAME=olo 2016-02-01 12:14:51 HOME=/home/olo 2016-02-01 12:14:51 PATH=/usr/bin:/bin:/usr/sbin:/sbin:/opt/openssh-work/bin 2016-02-01 12:14:51 MAIL=/var/mail/olo 2016-02-01 12:14:51 SHELL=/bin/bash 2016-02-01 12:14:51 SSH_CLIENT=::1 54347 22222 2016-02-01 12:14:51 SSH_CONNECTION=::1 54347 ::1 22222 2016-02-01 12:17:46 ssh_packet_send: error in libcrypto <=> ] 63.9GiB [ 373MiB/s] [ <=> ---- HEAD == commit 4c6cb83, AFTER applying patch 2783: ---- $patch -p1 < ../openssh-rekeylimit-patch_2783.patch patching file clientloop.c Hunk #1 succeeded at 1501 (offset 10 lines). Hunk #2 succeeded at 1616 (offset 10 lines). Hunk #3 succeeded at 1655 (offset 10 lines). patching file kex.c Hunk #1 succeeded at 606 (offset 21 lines). patching file kex.h Hunk #1 succeeded at 179 (offset 14 lines). patching file opacket.h Hunk #1 succeeded at 125 (offset 1 line). patching file packet.c Hunk #1 succeeded at 259 (offset 6 lines). Hunk #2 succeeded at 1035 (offset 11 lines). Hunk #3 succeeded at 1283 (offset 11 lines). Hunk #4 succeeded at 1351 (offset 11 lines). Hunk #5 succeeded at 1871 (offset 12 lines). Hunk #6 succeeded at 2362 (offset 20 lines). patching file packet.h Hunk #1 succeeded at 86 (offset 14 lines). Hunk #2 succeeded at 146 (offset 14 lines). patching file serverloop.c Hunk #1 succeeded at 820 (offset 32 lines). Hunk #2 succeeded at 847 (offset 32 lines). Hunk #3 succeeded at 866 (offset 32 lines). $ make && echo OK $ sudo make install $ sudo perl -pe 's{(AuthorizedKeysFile\s+.ssh/authorized_keys$)}{$1_openssh-work}' -i /opt/openssh-work/etc/sshd_config TERM 1: $ sudo $PWD/sshd -p 22222 -D -d -e TERM 2: $ dd if=/dev/zero bs=1M count=65534 | pv -prb | $PWD/ssh -o BatchMode=yes -o ConnectTimeout=15 -o ServerAliveInterval=15 -o TCPKeepAlive=yes -o StrictHostKeyChecking=no -c aes256-gcm@openssh.com -p 22222 -i ~/.ssh-work/openssh-work.key -v localhost 'cat > /dev/null' 2>&1 | awk '{ print strftime("%Y-%m-%d %H:%M:%S"), $0; fflush(); }' 2016-02-01 12:34:00 OpenSSH_7.1p2, OpenSSL 1.0.1e-fips 11 Feb 2013 2016-02-01 12:34:00 debug1: Reading configuration data /opt/openssh-work/etc/ssh_config 2016-02-01 12:34:00 debug1: Connecting to localhost [::1] port 22222. 2016-02-01 12:34:00 debug1: fd 3 clearing O_NONBLOCK 2016-02-01 12:34:00 debug1: Connection established. 2016-02-01 12:34:00 debug1: identity file /home/olo/.ssh-work/openssh-work.key type 1 2016-02-01 12:34:00 debug1: key_load_public: No such file or directory 2016-02-01 12:34:00 debug1: identity file /home/olo/.ssh-work/openssh-work.key-cert type -1 2016-02-01 12:34:00 debug1: Enabling compatibility mode for protocol 2.0 2016-02-01 12:34:00 debug1: Local version string SSH-2.0-OpenSSH_7.1 2016-02-01 12:34:00 debug1: Remote protocol version 2.0, remote software version OpenSSH_7.1 2016-02-01 12:34:00 debug1: match: OpenSSH_7.1 pat OpenSSH* compat 0x04000000 2016-02-01 12:34:00 debug1: Authenticating to localhost:22222 as 'olo' 2016-02-01 12:34:00 debug1: SSH2_MSG_KEXINIT sent 2016-02-01 12:34:00 debug1: SSH2_MSG_KEXINIT received 2016-02-01 12:34:00 debug1: kex: algorithm: curve25519-sha256@libssh.org 2016-02-01 12:34:00 debug1: kex: host key algorithm: ecdsa-sha2-nistp256 2016-02-01 12:34:00 debug1: kex: server->client cipher: aes256-gcm@openssh.com MAC: <implicit> compression: none 2016-02-01 12:34:00 debug1: kex: client->server cipher: aes256-gcm@openssh.com MAC: <implicit> compression: none 2016-02-01 12:34:00 debug1: expecting SSH2_MSG_KEX_ECDH_REPLY 2016-02-01 12:34:00 debug1: Server host key: ecdsa-sha2-nistp256 SHA256:1t75itcZmuKxHOZDYnf2rFChaodNSPb03bqjWrddgAw 2016-02-01 12:34:00 debug1: Host '[localhost]:22222' is known and matches the ECDSA host key. 2016-02-01 12:34:00 debug1: Found key in /home/olo/.ssh/known_hosts:31 2016-02-01 12:34:00 debug1: rekey after 4294967296 blocks 2016-02-01 12:34:00 debug1: SSH2_MSG_NEWKEYS sent 2016-02-01 12:34:00 debug1: expecting SSH2_MSG_NEWKEYS 2016-02-01 12:34:00 debug1: rekey after 4294967296 blocks 2016-02-01 12:34:00 debug1: SSH2_MSG_NEWKEYS received 2016-02-01 12:34:00 debug1: SSH2_MSG_EXT_INFO received 2016-02-01 12:34:00 debug1: kex_input_ext_info: server-sig-algs=<rsa-sha2-256,rsa-sha2-512> 2016-02-01 12:34:00 debug1: SSH2_MSG_SERVICE_ACCEPT received 2016-02-01 12:34:00 debug1: Authentications that can continue: publickey,password,keyboard-interactive 2016-02-01 12:34:00 debug1: Next authentication method: publickey 2016-02-01 12:34:00 debug1: Offering RSA public key: rsa w/o comment 2016-02-01 12:34:00 debug1: Authentications that can continue: publickey,password,keyboard-interactive 2016-02-01 12:34:00 debug1: Offering RSA-CERT public key: rsa w/o comment 2016-02-01 12:34:00 debug1: Authentications that can continue: publickey,password,keyboard-interactive 2016-02-01 12:34:00 debug1: Offering RSA public key: /home/olo/.ssh-work/openssh-work.key 2016-02-01 12:34:00 debug1: Server accepts key: pkalg rsa-sha2-512 blen 279 2016-02-01 12:34:00 debug1: Authentication succeeded (publickey). 2016-02-01 12:34:00 Authenticated to localhost ([::1]:22222). 2016-02-01 12:34:00 debug1: channel 0: new [client-session] 2016-02-01 12:34:00 debug1: Requesting no-more-sessions@openssh.com 2016-02-01 12:34:00 debug1: Entering interactive session. 2016-02-01 12:34:00 debug1: pledge: network 2016-02-01 12:34:00 debug1: client_input_global_request: rtype hostkeys-00@openssh.com want_reply 0 2016-02-01 12:34:00 debug1: Sending command: cat > /dev/null 2016-02-01 12:34:00 Environment: 2016-02-01 12:34:00 USER=olo 2016-02-01 12:34:00 LOGNAME=olo 2016-02-01 12:34:00 HOME=/home/olo 2016-02-01 12:34:00 PATH=/usr/bin:/bin:/usr/sbin:/sbin:/opt/openssh-work/bin 2016-02-01 12:34:00 MAIL=/var/mail/olo 2016-02-01 12:34:00 SHELL=/bin/bash 2016-02-01 12:34:00 SSH_CLIENT=::1 58502 22222 2016-02-01 12:34:00 SSH_CONNECTION=::1 58502 ::1 22222 2016-02-01 12:37:01 debug1: enqueue packet: 94 <=> ] 2016-02-01 12:37:01 debug1: SSH2_MSG_KEXINIT sent 2016-02-01 12:37:01 debug1: rekeying in progress 2016-02-01 12:37:01 debug1: rekeying in progress 2016-02-01 12:37:01 debug1: rekeying in progress 2016-02-01 12:37:01 debug1: rekeying in progress 2016-02-01 12:37:01 debug1: rekeying in progress 2016-02-01 12:37:01 debug1: rekeying in progress 2016-02-01 12:37:01 debug1: rekeying in progress 2016-02-01 12:37:01 debug1: rekeying in progress 2016-02-01 12:37:01 debug1: rekeying in progress 2016-02-01 12:37:01 debug1: rekeying in progress 2016-02-01 12:37:01 debug1: rekeying in progress 2016-02-01 12:37:01 debug1: rekeying in progress 2016-02-01 12:37:01 debug1: rekeying in progress 2016-02-01 12:37:01 debug1: rekeying in progress 2016-02-01 12:37:01 debug1: rekeying in progress 2016-02-01 12:37:01 debug1: rekeying in progress 2016-02-01 12:37:01 debug1: rekeying in progress 2016-02-01 12:37:01 debug1: rekeying in progress 2016-02-01 12:37:01 debug1: SSH2_MSG_KEXINIT received 2016-02-01 12:37:01 debug1: kex: algorithm: curve25519-sha256@libssh.org 2016-02-01 12:37:01 debug1: kex: host key algorithm: ecdsa-sha2-nistp256 2016-02-01 12:37:01 debug1: kex: server->client cipher: aes256-gcm@openssh.com MAC: <implicit> compression: none 2016-02-01 12:37:01 debug1: kex: client->server cipher: aes256-gcm@openssh.com MAC: <implicit> compression: none 2016-02-01 12:37:02 debug1: expecting SSH2_MSG_KEX_ECDH_REPLY 2016-02-01 12:37:02 debug1: rekeying in progress 2016-02-01 12:37:02 debug1: rekeying in progress 2016-02-01 12:37:02 debug1: Server host key: ecdsa-sha2-nistp256 SHA256:1t75itcZmuKxHOZDYnf2rFChaodNSPb03bqjWrddgAw 2016-02-01 12:37:02 debug1: set_newkeys: rekeying, input 11977700 bytes 598858 blocks, output 68735982040 bytes 0 blocks 2016-02-01 12:37:02 debug1: rekey after 4294967296 blocks 2016-02-01 12:37:02 debug1: dequeue packet: 94 2016-02-01 12:37:02 debug1: SSH2_MSG_NEWKEYS sent 2016-02-01 12:37:02 debug1: expecting SSH2_MSG_NEWKEYS 2016-02-01 12:37:02 debug1: set_newkeys: rekeying, input 11977720 bytes 0 blocks, output 68735998444 bytes 1025 blocks 2016-02-01 12:37:02 debug1: rekey after 4294967296 blocks 2016-02-01 12:37:02 debug1: SSH2_MSG_NEWKEYS received 65534+0 records in 65534+0 records out 68717379584 bytes (69 GB) copied, 181.469 s, 379 MB/s 64GiB [ 361MiB/s] [ <=> ] 2016-02-01 12:37:02 debug1: client_input_channel_req: channel 0 rtype exit-status reply 0 2016-02-01 12:37:02 debug1: channel 0: free: client-session, nchannels 1 2016-02-01 12:37:02 debug1: fd 0 clearing O_NONBLOCK 2016-02-01 12:37:02 debug1: fd 1 clearing O_NONBLOCK 2016-02-01 12:37:02 Transferred: sent 68801270052, received 11989156 bytes, in 181.4 seconds 2016-02-01 12:37:02 Bytes per second: sent 379342485.6, received 66103.4 2016-02-01 12:37:02 debug1: Exit status 0 Note that this time SSH2_MSG_KEXINIT is triggered on time, before going over the limit and therefore the transfer succeeds (no "ssh_packet_send: error in libcrypto" error). The test above doesn't really go over the limit, transferring slightly less than 64G, but I've repeated it with "dd if=/dev/zero bs=1M count=70000" and it also goes through smoothly (the log looks the same). I've also tested with a small RekeyLimit to verify that ssh is able to make progress (dd if=/dev/zero bs=1M count=8 | ... | $PWD/ssh -o RekeyLimit=128K ...) and it is.
Fix applied, this will be in OpenSSH 7.2 commit 19bcf2ea2d17413f2d9730dd2a19575ff86b9b6a Author: djm@openbsd.org <djm@openbsd.org> Date: Mon Feb 8 10:57:07 2016 +0000 upstream commit refactor activation of rekeying This makes automatic rekeying internal to the packet code (previously the server and client loops needed to assist). In doing to it makes application of rekey limits more accurate by accounting for packets about to be sent as well as packets queued during rekeying events themselves. Based on a patch from dtucker@ which was in turn based on a patch Aleksander Adamowski in bz#2521; ok markus@ Upstream-ID: a441227fd64f9739850ca97b4cf794202860fcd8
Close all resolved bugs after release of OpenSSH 7.7.