Close the correct end of the BIO pair on transport send failures in openssl.

Close the correct end of the BIO pair on transport send failures in openssl.

Shut down the end of the BIO pair which OpenSSL is writing to, not the
transport socket. However, retain the transport_bio_ shutdown to mirror the
behavior of NSS in r206751, to avoid breaking
SSLClientSocketTest.Write_WithSynchronousError and potentially regressing
http://crbug.com/249848.

To avoid the CHECK in TransportReadComplete, handle the collision of write
failures and pending reads by propogating the write failure.

Remove BIO_set_mem_eof_return calls because they don't do anything. These
aren't mem BIOs.

BUG=335557
TEST=SSLClientSocketTest.Read_WithWriteError

Committed: https://src.chromium.org/viewvc/chrome?view=rev&revision=249240

[davidben, 2014-02-04 19:27:57]

I'm really not happy with it being possible for TransportReadComplete to fail,
but I think this is a minimal-ish fix for the crash, so it can be merged to 33.
Might be able to make it even more minimal if we want; see comments. Long thing
follows:

----8<-----

So the problem is that we're closing the wrong write end on write failure in
TransportWriteComplete. This breaks TransportReadComplete which assumes that the
BIO_write will always succeed.

Data from crash dumps to support this explanation for the crash: in the failing
CHECK_EQ, ret is -1 and result is almost always 0x17, but I've seen a few other
values. The only places BIO_write on a BIO pair returns -1 are

(a) The callback stapled to the BIO returns -1.
(b) b->closed is true (i.e. BIO_shutdown_wr has been called)
(c) b->len == b->size; the BIO is full.

I don't think we stable a callback (a), and if the BIO is full something is
badly wrong because we query how much room there is (c), so that leaves (b).
Wan-teh tells me 0x17 is the size of an encrypted alert under CHACHA20_POLY1305.
If we're overlapping Read with Write, it's probably a SPDY socket => most likely
talking to a Google server => CHACHA20_POLY1305. So that explains the 0x17. I'm
guessing a close_notify or something.

Ryan tells me we probably shouldn't be making Write failures interfere with
Reads in the first place. But replacing the BIO_shutdown_wr(transport_bio_) with
shutting off ssl_'s wbio somehow (either BIO_shutdown_wr or injecting a
callback) doesn't quite work. Even though arguably a failed Write should not
then automatically break Reads because there may still be something buffered or
whatever, we have a test SSLClientSocketTest.Write_WithSynchronousError that
tests it does just that.

That was added in https://chromiumcodereview.appspot.com/17105003 which seems to
have given NSS this behavior. It was to fix an infinite loop
(https://code.google.com/p/chromium/issues/detail?id=249848) in OnSendComplete
where the loop

  // OnSendComplete may need to call DoPayloadRead while the renegotiation
  // handshake is in progress.
  int rv_read = ERR_IO_PENDING;
  int rv_write = ERR_IO_PENDING;
  bool network_moved;
  do {
    if (user_read_buf_.get())
      rv_read = DoPayloadRead();
    if (user_write_buf_.get())
      rv_write = DoPayloadWrite();
    network_moved = DoTransportIO();
  } while (rv_read == ERR_IO_PENDING && rv_write == ERR_IO_PENDING &&
           (user_read_buf_.get() || user_write_buf_.get()) && network_moved);

got stuck. If

  (a) There is no pending Write() call.
  (b) There is a pending Read() call.
  (c) The transport socket refuses future writes. Not sure about reads. In the
test, all reads are going through fine. I guess, in the original bug, the OS
will time out reads later?

then we loop infinitely. DoPayloadRead() returns ERR_IO_PENDING because there's
nothing to read. DoPayloadWrite isn't being called, so rv_write remains
ERR_IO_PENDING. DoTransportIO() returns true; even though nothing went over the
network, DoTransportIO counds BufferSend() and BufferRecv() failures as network
movement. I imagine this is so that DoPayload{Read,Write} get a chance to react
to the error? Perhaps DoTransportIO() should be clever about only counting the
first instance of the error as network movement. Or not count errors as movement
and instead do an extra DoPayloadRead / DoPayloadWrite round at the end to make
sure it's all picked up.

This same loop and behavior exists in the OpenSSL logic but, because of the
wrong end of the BIO pair getting closed, it already had the NSS fix. (Mostly;
the NSS fix doesn't preclude adding bytes to the memio after
memio_PutWriteResult has been called with an error and it will first consume the
buffer before returning the error, while the BIO pair shutdown logic precludes
this behavior. That behavior is a little bizarre anyway though since it means
memio gets in a state where it will return data if there happens to be some
buffered, but echo the write error otherwise.)

In addition, the infinite loop isn't in SSLClientSocketOpenSSL because it clears
send_buffer_ in TransportWriteComplete on send failure. Which is also a little
off because it means the next BufferSend will just happily try to write the next
chunk of the buffer. If transport_bio_ happens to be empty, it returns 0 rather
than an error (thus breaking an infinite loop).

----8<-----


Anyway, in the interest of not trying to cut through this rat's nest for the 33
fix, I think this, possibly with even the new BIO_shutdown_wr call removed, is a
good starting point. But this should probably get cleaned up as a follow-up.

https://codereview.chromium.org/148213019/diff/1/net/socket/ssl_client_socket...
File net/socket/ssl_client_socket_openssl.cc (left):

https://codereview.chromium.org/148213019/diff/1/net/socket/ssl_client_socket...
net/socket/ssl_client_socket_openssl.cc:1229:
BIO_set_mem_eof_return(transport_bio_, 0);
Looks like these calls don't do anything in BIO pairs.

https://codereview.chromium.org/148213019/diff/1/net/socket/ssl_client_socket...
File net/socket/ssl_client_socket_openssl.cc (right):

https://codereview.chromium.org/148213019/diff/1/net/socket/ssl_client_socket...
net/socket/ssl_client_socket_openssl.cc:1233:
(void)BIO_shutdown_wr(SSL_get_wbio(ssl_));
Could get away with even avoiding this line for minimal fix purposes, but then
the test needs more openssl/nss special cases because transport write errors
don't actually translate into SSLClientSocketOpenSSL::Write failures right now.
(Specifically I need to remove the assertion that the buffer wasn't entirely
consumed, because it will be.)

https://codereview.chromium.org/148213019/diff/1/net/socket/ssl_client_socket...
net/socket/ssl_client_socket_openssl.cc:1233:
(void)BIO_shutdown_wr(SSL_get_wbio(ssl_));
It looks like sometimes OpenSSL wraps the wbio in a "bbio" for buffering or
something. So it might be better to keep a non-owning reference to ssl_bio and
shutdown that. But buffer_ctrl forwards to the downstream BIO, so I think this
works the same.

https://codereview.chromium.org/148213019/diff/1/net/socket/ssl_client_socket...
net/socket/ssl_client_socket_openssl.cc:1241: send_buffer_ = NULL;
This line is sort of funny. The next time we get around to calling BufferSend,
it thinks there's nothing to write and BufferSend() actually succeeds with 0
bytes written. That should probably go away later to mirror the NSS logic; I
believe nss_memio.c does not advance the buffer until memio_PutWriteResult goes
through.

https://codereview.chromium.org/148213019/diff/1/net/socket/ssl_client_socket...
File net/socket/ssl_client_socket_unittest.cc (right):

https://codereview.chromium.org/148213019/diff/1/net/socket/ssl_client_socket...
net/socket/ssl_client_socket_unittest.cc:1266: EXPECT_EQ(ERR_SSL_PROTOCOL_ERROR,
rv);
Is it possible for this to give us fallback pains? Transport write error codes
just get lost. The BIO_shutdown_wr line just makes openssl fail a BIO_write with
BIOerr(BIO_F_BIO_WRITE, BIO_R_BROKEN_PIPE) which is a little wonky. Might want
to staple a callback to the BIO instead?

[Ryan Sleevi, 2014-02-04 20:45:01]

Still trying to wrap my head around this one. See the comments re: the
read/write mirroring

https://codereview.chromium.org/148213019/diff/1/net/socket/ssl_client_socket...
File net/socket/ssl_client_socket_openssl.cc (right):

https://codereview.chromium.org/148213019/diff/1/net/socket/ssl_client_socket...
net/socket/ssl_client_socket_openssl.cc:461: 
Don't you need to update transport_write_error_ here, lest it persist to a
reconnect?

https://codereview.chromium.org/148213019/diff/1/net/socket/ssl_client_socket...
net/socket/ssl_client_socket_openssl.cc:1233:
(void)BIO_shutdown_wr(SSL_get_wbio(ssl_));
On 2014/02/04 19:27:57, David Benjamin wrote:
> It looks like sometimes OpenSSL wraps the wbio in a "bbio" for buffering or
> something. So it might be better to keep a non-owning reference to ssl_bio and
> shutdown that. But buffer_ctrl forwards to the downstream BIO, so I think this
> works the same.

Future work: Should we be using BIO_set_close() instead?

https://codereview.chromium.org/148213019/diff/1/net/socket/ssl_client_socket...
net/socket/ssl_client_socket_openssl.cc:1241: send_buffer_ = NULL;
On 2014/02/04 19:27:57, David Benjamin wrote:
> This line is sort of funny. The next time we get around to calling BufferSend,
> it thinks there's nothing to write and BufferSend() actually succeeds with 0
> bytes written. That should probably go away later to mirror the NSS logic; I
> believe nss_memio.c does not advance the buffer until memio_PutWriteResult
goes
> through.

I'm not sure I follow why it's funny. We just had a transport write failure, why
shouldn't it nuke the send_buffer_?

The succeeds with zero case is odd though.

https://codereview.chromium.org/148213019/diff/1/net/socket/ssl_client_socket...
net/socket/ssl_client_socket_openssl.cc:1264: result = transport_write_error_;
Let's add bug numbers. This is perhaps the most confusing/concerning. It should
only cause a read failure if the overall Read() request caused a Write().

I'm somewhat concerned because we may have buffered up to 16K of data in the
local buffer, and that is data that *could* be read, *unless* Read() needed to
write data (eg: a renegotiation request, a Close alert, a Change Cipher Spec)

[davidben, 2014-02-04 23:00:10]

https://codereview.chromium.org/148213019/diff/1/net/socket/ssl_client_socket...
File net/socket/ssl_client_socket_openssl.cc (right):

https://codereview.chromium.org/148213019/diff/1/net/socket/ssl_client_socket...
net/socket/ssl_client_socket_openssl.cc:461: 
On 2014/02/04 20:45:02, Ryan Sleevi wrote:
> Don't you need to update transport_write_error_ here, lest it persist to a
> reconnect?

Done. Also reset pending_read_error_.

https://codereview.chromium.org/148213019/diff/1/net/socket/ssl_client_socket...
net/socket/ssl_client_socket_openssl.cc:1233:
(void)BIO_shutdown_wr(SSL_get_wbio(ssl_));
On 2014/02/04 20:45:02, Ryan Sleevi wrote:
> On 2014/02/04 19:27:57, David Benjamin wrote:
> > It looks like sometimes OpenSSL wraps the wbio in a "bbio" for buffering or
> > something. So it might be better to keep a non-owning reference to ssl_bio
and
> > shutdown that. But buffer_ctrl forwards to the downstream BIO, so I think
this
> > works the same.
> 
> Future work: Should we be using BIO_set_close() instead?

Hrm. That seems to set the shutdown flag on the BIO. It doesn't look like that
affects reads from the other end? Docs say:

"""
BIO_set_close() sets the BIO b close flag to flag. flag can take the value
BIO_CLOSE or BIO_NOCLOSE. Typically BIO_CLOSE is used in a source/sink BIO to
indicate that the underlying I/O stream should be closed when the BIO is freed.
"""

which seems like something else?

https://codereview.chromium.org/148213019/diff/1/net/socket/ssl_client_socket...
net/socket/ssl_client_socket_openssl.cc:1241: send_buffer_ = NULL;
On 2014/02/04 20:45:02, Ryan Sleevi wrote:
> On 2014/02/04 19:27:57, David Benjamin wrote:
> > This line is sort of funny. The next time we get around to calling
BufferSend,
> > it thinks there's nothing to write and BufferSend() actually succeeds with 0
> > bytes written. That should probably go away later to mirror the NSS logic; I
> > believe nss_memio.c does not advance the buffer until memio_PutWriteResult
> goes
> > through.
> 
> I'm not sure I follow why it's funny. We just had a transport write failure,
why
> shouldn't it nuke the send_buffer_?
> 
> The succeeds with zero case is odd though.

Keeping send_buffer_ around avoids the succeeds with zero case. The send buffer
itself is useless, but then we'd want other state somewhere to ensure
BufferSend() doesn't try to write the next bunch of data to the network the next
time it's called. The NSS code doesn't have such state, but it does the moral
equivalent of keeping send_buffer_ around. It doesn't advance the memio read
head until those bytes have successfully been written to the transport socket.

In the OpenSSL implementation, our transport_bio_ advances the read head
immediately and copies the data out into a separate buffer to be sent over the
network. So we either want to keep send_buffer_ around so the next BufferSend
will re-try sending over the transport socket and hit an error again, or nuke
send_buffer_ and save the socket error. Then have BufferSend not even touch the
transport socket in that case and just replay the error.

https://codereview.chromium.org/148213019/diff/1/net/socket/ssl_client_socket...
net/socket/ssl_client_socket_openssl.cc:1264: result = transport_write_error_;
On 2014/02/04 20:45:02, Ryan Sleevi wrote:
> Let's add bug numbers. This is perhaps the most confusing/concerning. It
should
> only cause a read failure if the overall Read() request caused a Write().
> 
> I'm somewhat concerned because we may have buffered up to 16K of data in the
> local buffer, and that is data that *could* be read, *unless* Read() needed to
> write data (eg: a renegotiation request, a Close alert, a Change Cipher Spec)

Agreed. I kept it this way just to minimize behavior change for the M33 merge,
but I don't think this is a good fix for trunk. Effectively all it's doing is
bypassing the CHECK and preserving the error for this one case.

That buffering bit is what I meant that the write failure => read shut-off
behavior in SSLClientSocketOpenSSL is different from SSLClientSocketNSS. Hence:

"""
This same loop and behavior exists in the OpenSSL logic but, because of the
wrong end of the BIO pair getting closed, it already had the NSS fix. (Mostly;
the NSS fix doesn't preclude adding bytes to the memio after
memio_PutWriteResult has been called with an error and it will first consume the
buffer before returning the error, while the BIO pair shutdown logic precludes
this behavior. That behavior is a little bizarre anyway though since it means
memio gets in a state where it will return data if there happens to be some
buffered, but echo the write error otherwise.)
"""

We could probably mimic the NSS behavior by installing a BIO_CB_WRITE callback
that inspects the size of the buffer. But if we're not doing that as part of the
33 fix, we probably should resolve the read/failed-write confusing better
altogether.

Added a reference to the bug number.

[Ryan Sleevi, 2014-02-05 19:07:40]

lgtm

https://codereview.chromium.org/148213019/diff/130001/net/socket/ssl_client_s...
File net/socket/ssl_client_socket_unittest.cc (right):

https://codereview.chromium.org/148213019/diff/130001/net/socket/ssl_client_s...
net/socket/ssl_client_socket_unittest.cc:1233: // to exceed internal buffers and
flush out the socket error.
Rather than "flush out the socket error" (which took me a little bit to grok)

// Perform another write, but have it fail. Write a request larger than the
internal socket buffers so that
// the request hits the underlying transport socket and detects the error.

[davidben, 2014-02-05 20:34:40]

https://codereview.chromium.org/148213019/diff/130001/net/socket/ssl_client_s...
File net/socket/ssl_client_socket_unittest.cc (right):

https://codereview.chromium.org/148213019/diff/130001/net/socket/ssl_client_s...
net/socket/ssl_client_socket_unittest.cc:1233: // to exceed internal buffers and
flush out the socket error.
On 2014/02/05 19:07:40, Ryan Sleevi wrote:
> Rather than "flush out the socket error" (which took me a little bit to grok)
> 
> // Perform another write, but have it fail. Write a request larger than the
> internal socket buffers so that
> // the request hits the underlying transport socket and detects the error.

Done.

[davidben, 2014-02-05 21:09:09]

The CQ bit was checked by davidben@chromium.org

[commit-bot: I haz the power, 2014-02-05 21:10:28]

CQ is trying da patch. Follow status at
https://chromium-status.appspot.com/cq/davidben@chromium.org/148213019/220001

[davidben, 2014-02-05 21:13:10]

On 2014/02/05 21:10:28, I haz the power (commit-bot) wrote:
> CQ is trying da patch. Follow status at
>
https://chromium-status.appspot.com/cq/davidben%40chromium.org/148213019/220001

Filed https://code.google.com/p/chromium/issues/detail?id=341178 for follow-up
work.

[commit-bot: I haz the power, 2014-02-06 02:42:28]

Change committed as 249240