Add LoadLog to ClientSocket::Connect().

Add LoadLog to ClientSocket::Connect().
TODO: Use LoadLog in FLIP code.

Committed: http://src.chromium.org/viewvc/chrome?view=rev&revision=30765

[willchan no longer on Chromium, 2009-10-29 20:13:33]

On 2009/10/29 19:50:55, willchan wrote:
> 

Woops, not ready for review, I forgot to build the tests.

[eroman, 2009-10-29 21:37:16]

In general I like this change.

One thing I am wandering, is what we want to do about the LoadLog when recycling
sockets. As written write now, the LoadLog of the request that first connected
the socket, will live as long as the socket still lives.

This isn't a big deal since we won't be reading it, but to prevent the lingering
memory cost we may want to NULL out the socket's load_log_ member after the
connect has completed, to avoid this situation.

I will review in depth once you say the change is ready for review.

http://codereview.chromium.org/344026/diff/1/9
File net/socket/socks5_client_socket.cc (right):

http://codereview.chromium.org/344026/diff/1/9#newcode198
Line 198: host_request_info_, &addresses_, &io_callback_, NULL);
You can pass load_log_ in here too.

http://codereview.chromium.org/344026/diff/1/11
File net/socket/socks_client_socket.cc (right):

http://codereview.chromium.org/344026/diff/1/11#newcode218
Line 218: host_request_info_, &addresses_, &io_callback_, NULL);
You can pass load_log_ in here too.

http://codereview.chromium.org/344026/diff/1/13
File net/socket/ssl_client_socket_mac.cc (right):

http://codereview.chromium.org/344026/diff/1/13#newcode358
Line 358: net::LoadLog::EndEvent(load_log_, net::LoadLog::TYPE_SSL_CONNECT);
I am concerned by the number of EndEvents() in this function, it is going to be
fragile to changes.

Can you move the current body of Connect() to a helper function, so it instead
looks like:

Connect() {

  BeginEvent();
  int rv = DoConnect();

  if (rv != ERR_IO_PENDING)
    EndEvent();
}


OR introduce some scoped wrapper that calls EndEvent when it goes out of scope? 
 (such a scoped wrapper could be usable in other places too).

http://codereview.chromium.org/344026/diff/1/15
File net/socket/ssl_client_socket_nss.cc (right):

http://codereview.chromium.org/344026/diff/1/15#newcode283
Line 283: net::LoadLog::EndEvent(load_log_, net::LoadLog::TYPE_SSL_CONNECT);
Same comment as I made in SSLClientSocketMac::Connect() -- there are an aweful
lot of call to EndEvent() which feels fragile, and something of an eye sore.

[willchan no longer on Chromium, 2009-10-29 23:35:40]

Tests fixed up.

I've manually tested on Linux and it works fine for SSL and TCP stuff.  I think
I've fixed all the mac and windows issues, and am waiting for the try runs to
finish up.

http://codereview.chromium.org/344026/diff/1/9
File net/socket/socks5_client_socket.cc (right):

http://codereview.chromium.org/344026/diff/1/9#newcode198
Line 198: host_request_info_, &addresses_, &io_callback_, NULL);
On 2009/10/29 21:37:16, eroman wrote:
> You can pass load_log_ in here too.

Done.

http://codereview.chromium.org/344026/diff/1/11
File net/socket/socks_client_socket.cc (right):

http://codereview.chromium.org/344026/diff/1/11#newcode218
Line 218: host_request_info_, &addresses_, &io_callback_, NULL);
On 2009/10/29 21:37:16, eroman wrote:
> You can pass load_log_ in here too.

Done.

http://codereview.chromium.org/344026/diff/1/13
File net/socket/ssl_client_socket_mac.cc (right):

http://codereview.chromium.org/344026/diff/1/13#newcode358
Line 358: net::LoadLog::EndEvent(load_log_, net::LoadLog::TYPE_SSL_CONNECT);
Thanks for the suggestion on the helper function.  I looked at the code and was
frustrated with it, but I haven't programmed in awhile, so I forgot how to
structure the code properly :P

On 2009/10/29 21:37:16, eroman wrote:
> I am concerned by the number of EndEvents() in this function, it is going to
be
> fragile to changes.
> 
> Can you move the current body of Connect() to a helper function, so it instead
> looks like:
> 
> Connect() {
> 
>   BeginEvent();
>   int rv = DoConnect();
> 
>   if (rv != ERR_IO_PENDING)
>     EndEvent();
> }
> 
> 
> OR introduce some scoped wrapper that calls EndEvent when it goes out of
scope? 
>  (such a scoped wrapper could be usable in other places too).

http://codereview.chromium.org/344026/diff/1/15
File net/socket/ssl_client_socket_nss.cc (right):

http://codereview.chromium.org/344026/diff/1/15#newcode283
Line 283: net::LoadLog::EndEvent(load_log_, net::LoadLog::TYPE_SSL_CONNECT);
On 2009/10/29 21:37:16, eroman wrote:
> Same comment as I made in SSLClientSocketMac::Connect() -- there are an aweful
> lot of call to EndEvent() which feels fragile, and something of an eye sore.

Done.

[eroman, 2009-10-30 01:03:05]

LGTM.

It would be good to have verification for this.

All of the tests I saw are using NULL LoadLogs, We should verify that when
non-NULL logs are passed the correct events get written to them.

I know it is sorta a pain to do this, but I think it is worthwhile.
When I went through the same process, my unit-tests turned up some subtle bugs
(exit codepaths I hadn't considered).

Anyhow, I wouldn't block this CL on that, but keep it in mind.
If you do do go back and add tests, you can find some helpers in
load_log_unittest.h.
Also when an expectation fails, it is helpful to just dump the whole thing to
the console using LoadLogUtil::PrettyPrintAsEventTree().

http://codereview.chromium.org/344026/diff/6001/5018
File net/socket/ssl_client_socket_mac.cc (right):

http://codereview.chromium.org/344026/diff/6001/5018#newcode459
Line 459: int SSLClientSocketMac::InitializeSSLContext() {
I assume this is a straight move, didn't review.

http://codereview.chromium.org/344026/diff/6001/5025
File net/socket/tcp_client_socket_libevent.cc (right):

http://codereview.chromium.org/344026/diff/6001/5025#newcode136
Line 136: // Synchronous operation not supported
nit: seeing how you touch the line, can you add a period to this?

http://codereview.chromium.org/344026/diff/6001/5025#newcode140
Line 140: waiting_connect_ = true;
nice cleanup, more readable now!

http://codereview.chromium.org/344026/diff/6001/5025#newcode378
Line 378: scoped_refptr<LoadLog> load_log = load_log_;
Just figured I would mention you could also use swap() for this. I don't really
have a preference, either seems fine.

http://codereview.chromium.org/344026/diff/6001/5025#newcode382
Line 382: result = Connect(write_callback_, load_log);
Might be nice to DCHECK that load_log_ == NULL at the start of Connect(), to
futureproof this code.

Note: I really like how we will show the timelapses between EACH connection
attempt, as this makes it clear how many times we tried, and which ones were
super slow.

http://codereview.chromium.org/344026/diff/6001/5030
File net/socket/tcp_client_socket_win.cc (right):

http://codereview.chromium.org/344026/diff/6001/5030#newcode328
Line 328: return MapConnectError(err);
Dont we need to call EndEvent() here too?

Maybe you can do similarly to the libevent code and break out a helper function
-- I think that works more nicely for when we assign to waiting_connect_ = true
anway.

http://codereview.chromium.org/344026/diff/6001/5030#newcode631
Line 631: result = ERR_UNEXPECTED;
Seems like we won't end the event in this case.

[willchan no longer on Chromium, 2009-10-30 01:47:31]

Addressed all the code comments.  I'm not in a hurry to check this in, so I'll
make sure to add the tests in this changelist.  I hadn't noticed there were
tests for LoadLog stuff before.  I'll ping back when I've updated it.

http://codereview.chromium.org/344026/diff/6001/5025
File net/socket/tcp_client_socket_libevent.cc (right):

http://codereview.chromium.org/344026/diff/6001/5025#newcode136
Line 136: // Synchronous operation not supported
On 2009/10/30 01:03:05, eroman wrote:
> nit: seeing how you touch the line, can you add a period to this?

Done.

http://codereview.chromium.org/344026/diff/6001/5025#newcode378
Line 378: scoped_refptr<LoadLog> load_log = load_log_;
On 2009/10/30 01:03:05, eroman wrote:
> Just figured I would mention you could also use swap() for this. I don't
really
> have a preference, either seems fine.

Done.

http://codereview.chromium.org/344026/diff/6001/5030
File net/socket/tcp_client_socket_win.cc (right):

http://codereview.chromium.org/344026/diff/6001/5030#newcode328
Line 328: return MapConnectError(err);
On 2009/10/30 01:03:05, eroman wrote:
> Dont we need to call EndEvent() here too?
> 
> Maybe you can do similarly to the libevent code and break out a helper
function
> -- I think that works more nicely for when we assign to waiting_connect_ =
true
> anway.

Done.

http://codereview.chromium.org/344026/diff/6001/5030#newcode631
Line 631: result = ERR_UNEXPECTED;
On 2009/10/30 01:03:05, eroman wrote:
> Seems like we won't end the event in this case.

It's a NOTREACHED(), so I didn't really bother to handle it.  I guess I should
though.  Done.

[eroman, 2009-10-30 03:38:57]

lgtm

[willchan no longer on Chromium, 2009-10-30 23:46:07]

I've added tests.  Note that I've modified load_log_unittest.h since I wasn't
completely satisfied with the existing ExpectLogContains() function.  It hides
where in the _unittest.cc file the error actually occurred, which is somewhat
annoying.  Also, it doesn't handle the negative case well.  I fixed it by using
gTest's AssertionResults.  I need to update chromium to a newer version of gTest
to get the latest AssertionResults changes which eliminate the need to create a
testing::Message and let you just stream directly to the AssertionResult which
is much cleaner.  This way, EXPECT_TRUE() and EXPECT_FALSE() both work.

[eroman, 2009-11-02 19:11:38]

LGTM.

Nice improvement with AssertionResult.

http://codereview.chromium.org/344026/diff/7002/8015
File net/socket/socks5_client_socket_unittest.cc (right):

http://codereview.chromium.org/344026/diff/7002/8015#newcode130
Line 130: EXPECT_TRUE(LogContains(*log, log->events().size() - 1,
can this hardcode an index?

(alternately, maybe LogContains could accept negative indexes to mean offsets
from the end, like python slices).

http://codereview.chromium.org/344026/diff/7002/8024
File net/socket/ssl_client_socket_win.cc (right):

http://codereview.chromium.org/344026/diff/7002/8024#newcode448
Line 448: LoadLog::EndEvent(load_log, LoadLog::TYPE_SSL_CONNECT);
Could you move the synchronous initialization into a helper here as well, so
there aren't multiple calls to EndEvent() throughout?

[willchan no longer on Chromium, 2009-11-02 21:31:06]

I'm waiting on trybot results, but plan on committing this afterward.  Let me
know if you want to take another look first.

http://codereview.chromium.org/344026/diff/7002/8015
File net/socket/socks5_client_socket_unittest.cc (right):

http://codereview.chromium.org/344026/diff/7002/8015#newcode130
Line 130: EXPECT_TRUE(LogContains(*log, log->events().size() - 1,
On 2009/11/02 19:11:38, eroman wrote:
> can this hardcode an index?
> 
> (alternately, maybe LogContains could accept negative indexes to mean offsets
> from the end, like python slices).

Done.  I like the suggestion.

http://codereview.chromium.org/344026/diff/7002/8024
File net/socket/ssl_client_socket_win.cc (right):

http://codereview.chromium.org/344026/diff/7002/8024#newcode448
Line 448: LoadLog::EndEvent(load_log, LoadLog::TYPE_SSL_CONNECT);
On 2009/11/02 19:11:38, eroman wrote:
> Could you move the synchronous initialization into a helper here as well, so
> there aren't multiple calls to EndEvent() throughout?

Done.

[eroman, 2009-11-02 21:43:16]

LGTM