Add TRACE_EVENT macros to net.

Add TRACE_EVENT macros to net.

This CL adds TRACE_EVENT macros to some of the interesting functions in
net which are useful to track memory usage.
These are points suggested by statistics from local experiments and
improvised by mmenke@.

The CL also changes the categories of some existing trace events and
cleans up some. Some events are marked under DISABLED_BY_DEFAULT
category since there are too many calls and should not crowd default
tracing with lot of points. This is chosen based on an average value
of trace events in other categories.

BUG=598377
Committed: https://crrev.com/6d6b40100156b2dabcc79cf46f9f34f225e21d0a
Cr-Commit-Position: refs/heads/master@{#385246}

[ssid, 2016-03-28 18:57:41]

ssid@chromium.org changed reviewers:
+ cbentzel@chromium.org, ckrasic@chromium.org, nharper@chromium.org

[ssid, 2016-03-28 18:57:41]

This CL adds trace events to the functions found to be interesting for memory
usage tracking by heap profiling stack traces. I'd be happy to add more based on
suggestions, since I do not have a lot of knowledge specific to net::.

+nharper, ckrasic: I have sent you a mail on why I am doing this change and why
I am adding you as reviewers.

More context
https://docs.google.com/document/d/1L_j3CjtXtCXec4ecFYK3J1BXBkK30ZtfVTEOr0Q43...

ptal Thanks.

[mmenke, 2016-03-28 20:46:51]

mmenke@chromium.org changed reviewers:
+ mmenke@chromium.org

[mmenke, 2016-03-28 20:46:51]

https://codereview.chromium.org/1834273002/diff/1/net/http/http_stream_factor...
File net/http/http_stream_factory_impl_job.cc (right):

https://codereview.chromium.org/1834273002/diff/1/net/http/http_stream_factor...
net/http/http_stream_factory_impl_job.cc:528: TRACE_EVENT0("net",
"HttpStreamFactoryImpl::Job::OnCertificateErrorCallback");
How are you planning on using these?  Seems like basing memory attribution logic
on code like this this would claim something like
"HttpStreamFactoryImpl::Job::OnCertificateErrorCallback" is taking a lot of
memory, while in reality, the problem would be the entire tree of calls below
OnCertificateErrorCallback, none of which involve HttpStreamFactoryImpl::Job.

https://codereview.chromium.org/1834273002/diff/1/net/url_request/url_request...
File net/url_request/url_request_http_job.cc (right):

https://codereview.chromium.org/1834273002/diff/1/net/url_request/url_request...
net/url_request/url_request_http_job.cc:1066: TRACE_EVENT0("net",
"URLRequestHttpJob::OnReadCompleted");
What do you expect to do with the information you get here?  The covers the
filters, passing data to the embedder, and the whatever the embedder does with
the data...But it only covers the case the read completes asynchronously, and
doesn't cover when the filters or embedder does the exact same thing for
non-HTTP requests.  I suggest more targetted tracing.

[ssid, 2016-03-29 00:33:06]

https://codereview.chromium.org/1834273002/diff/1/net/http/http_stream_factor...
File net/http/http_stream_factory_impl_job.cc (right):

https://codereview.chromium.org/1834273002/diff/1/net/http/http_stream_factor...
net/http/http_stream_factory_impl_job.cc:528: TRACE_EVENT0("net",
"HttpStreamFactoryImpl::Job::OnCertificateErrorCallback");
On 2016/03/28 20:46:51, mmenke wrote:
> How are you planning on using these?  Seems like basing memory attribution
logic
> on code like this this would claim something like
> "HttpStreamFactoryImpl::Job::OnCertificateErrorCallback" is taking a lot of
> memory, while in reality, the problem would be the entire tree of calls below
> OnCertificateErrorCallback, none of which involve HttpStreamFactoryImpl::Job. 

I agree, in general the answer to your question is: I will try to add tracing
points to more functions in the tree of calls under these function if I know
what are these functions are useful. I am hoping that by these instrumentation,
I can at least understand one more level deeper, if not all the way and tell
what is responsible for memory.

In specific, adding to OnCertificateErrorCallback was a mistake. It does not
give any information, nor the callbacks allocate memory. Sorry. I removed this.

https://codereview.chromium.org/1834273002/diff/1/net/url_request/url_request...
File net/url_request/url_request_http_job.cc (right):

https://codereview.chromium.org/1834273002/diff/1/net/url_request/url_request...
net/url_request/url_request_http_job.cc:1066: TRACE_EVENT0("net",
"URLRequestHttpJob::OnReadCompleted");
On 2016/03/28 20:46:51, mmenke wrote:
> What do you expect to do with the information you get here?  The covers the
> filters, passing data to the embedder, and the whatever the embedder does with
> the data...But it only covers the case the read completes asynchronously, and
> doesn't cover when the filters or embedder does the exact same thing for
> non-HTTP requests.  I suggest more targetted tracing.

I am expecting that this data is useful to understand where the memory
allocations are coming from. At least it could tell that the allocation is
related to http request in some way.
I was also hoping that Nick and Charles who have more context about the code
will help me making this complete.
cbentzel@ suggested to ask them.

I am working with statistics for adding trace events rather than  understanding
what are all the possible codepaths possible. I did try with lots of websites
and it turns out that case of read completing asynchronously was allocating more
memory than other cases. I tried to read similar functions in each folder and
add events there as well.

I don't understand when you say more targeted tracing. Do you mean I should add
more trace events in each of these components so that the data is complete? If
so, can you propose a way for me to find points to make this instrumentation
complete.

If I can contact one person in each sub-team of networking and point out these
"important" functions that would be great. I am trying to add trace events based
on statistically large memory using functions.
Can you please suggest any other alternative?

[mmenke, 2016-03-30 19:04:32]

On 2016/03/29 00:33:06, ssid wrote:
>
https://codereview.chromium.org/1834273002/diff/1/net/http/http_stream_factor...
> File net/http/http_stream_factory_impl_job.cc (right):
> 
>
https://codereview.chromium.org/1834273002/diff/1/net/http/http_stream_factor...
> net/http/http_stream_factory_impl_job.cc:528: TRACE_EVENT0("net",
> "HttpStreamFactoryImpl::Job::OnCertificateErrorCallback");
> On 2016/03/28 20:46:51, mmenke wrote:
> > How are you planning on using these?  Seems like basing memory attribution
> logic
> > on code like this this would claim something like
> > "HttpStreamFactoryImpl::Job::OnCertificateErrorCallback" is taking a lot of
> > memory, while in reality, the problem would be the entire tree of calls
below
> > OnCertificateErrorCallback, none of which involve
HttpStreamFactoryImpl::Job. 
> 
> I agree, in general the answer to your question is: I will try to add tracing
> points to more functions in the tree of calls under these function if I know
> what are these functions are useful. I am hoping that by these
instrumentation,
> I can at least understand one more level deeper, if not all the way and tell
> what is responsible for memory.
> 
> In specific, adding to OnCertificateErrorCallback was a mistake. It does not
> give any information, nor the callbacks allocate memory. Sorry. I removed
this.
> 
>
https://codereview.chromium.org/1834273002/diff/1/net/url_request/url_request...
> File net/url_request/url_request_http_job.cc (right):
> 
>
https://codereview.chromium.org/1834273002/diff/1/net/url_request/url_request...
> net/url_request/url_request_http_job.cc:1066: TRACE_EVENT0("net",
> "URLRequestHttpJob::OnReadCompleted");
> On 2016/03/28 20:46:51, mmenke wrote:
> > What do you expect to do with the information you get here?  The covers the
> > filters, passing data to the embedder, and the whatever the embedder does
with
> > the data...But it only covers the case the read completes asynchronously,
and
> > doesn't cover when the filters or embedder does the exact same thing for
> > non-HTTP requests.  I suggest more targetted tracing.
> 
> I am expecting that this data is useful to understand where the memory
> allocations are coming from. At least it could tell that the allocation is
> related to http request in some way.
> I was also hoping that Nick and Charles who have more context about the code
> will help me making this complete.
> cbentzel@ suggested to ask them.
> 
> I am working with statistics for adding trace events rather than 
understanding
> what are all the possible codepaths possible. I did try with lots of websites
> and it turns out that case of read completing asynchronously was allocating
more
> memory than other cases. I tried to read similar functions in each folder and
> add events there as well.
> 
> I don't understand when you say more targeted tracing. Do you mean I should
add
> more trace events in each of these components so that the data is complete? If
> so, can you propose a way for me to find points to make this instrumentation
> complete.
> 
> If I can contact one person in each sub-team of networking and point out these
> "important" functions that would be great. I am trying to add trace events
based
> on statistically large memory using functions.
> Can you please suggest any other alternative?

Sorry for slowness, had a bunch of meetings yesterday.

Tracepoints I suggest, just thinking about separating out net/ and non-net
allocations:

ResourceLoader has a bunch that would be useful:

OnReceivedRedirect, OnBeforeNetworkStart, OnResponseStarted, OnReadCompleted,
ResponseCompleted, and maybe one wrapping the OnWillRead call to the handler.

You could also add trace points to NetworkDelegate or ChromeNetworkDelegate, to
catch stuff going on outside the network stack (NetworkDelegate will catch more,
but would be less clear what's going on).  NetworkDelegate calls into
extensions, which is my primary concern there, though they mostly do stuff on
the IOThread, admittedly.


I can certainly suggest more/better ones in net as well, just a matter of
spending some time thinking about it.


Also, a question:  UMA's "Profiler" tab shows CPU usage by executed callback.  I
don't support you could just hook it up to show memory allocations as well? 
That's basically what the tracing hooks you're adding are doing, and it seems
like covering all callbacks would cover a lot more.  It wouldn't give great info
on just what's allocating the memory, but that's the exact same issue with your
current approach here.

[ssid, 2016-03-31 20:03:09]

> Sorry for slowness, had a bunch of meetings yesterday.
> 
> Tracepoints I suggest, just thinking about separating out net/ and non-net
> allocations:
> 
> ResourceLoader has a bunch that would be useful:
> 
> OnReceivedRedirect, OnBeforeNetworkStart, OnResponseStarted, OnReadCompleted,
> ResponseCompleted, and maybe one wrapping the OnWillRead call to the handler.
> 
> You could also add trace points to NetworkDelegate or ChromeNetworkDelegate,
to
> catch stuff going on outside the network stack (NetworkDelegate will catch
more,
> but would be less clear what's going on).  NetworkDelegate calls into
> extensions, which is my primary concern there, though they mostly do stuff on
> the IOThread, admittedly.
> 

ResourceLoader seems to already have a bunch of trace points. Nonetheless the
functions like OnResponseStarted and OnReadCompleted could be useful.
Note that ResourceLoader only accounrts for 40-50% of usage form
URLRequestHttpJob::OnReadCompleted.

NetworkDelegate in some experiments allocated 0.5% (~1.5Mib) of browser memory
usage. Out of which more than 95% was on IO thread.
NetworkDelegate Notify... accounts for around ~20% of httpJob and ~15% of
httpCache tasks.
In summary, NetworkDelegate seems to cover a lot of usage form
URLRequestHttpJob's handlers.

I have updated the CL with a few trace points in NetworkDelegate and
ResourceLoader.
Since I do not want you to spend a lot of time thinking about where to add, I
have this CL that gives you hints.

> 
> I can certainly suggest more/better ones in net as well, just a matter of
> spending some time thinking about it.

Yes, to help you with that, from real world usage, this CL can give some hints.
You can also look at the functions marked in this CL
https://codereview.chromium.org/1840783002/.

Do you suggest I write a doc about what all I found important and you can add
your inputs on where all I should add trace events? Basically I can add the
information form the CLs.

You can have a look at this doc to see how important these functions turned out
to be in case of memory usage:
https://docs.google.com/document/d/162LZ6GPa4EM1AO434B4pvprfjXYLqWYFAi24FjX6C...
You are right in saying this memory shouldn't totally be attributed to net since
it calls into extensions and stuff. but at least we know it started from here.

> 
> 
> Also, a question:  UMA's "Profiler" tab shows CPU usage by executed callback. 
I
> don't support you could just hook it up to show memory allocations as well? 
> That's basically what the tracing hooks you're adding are doing, and it seems
> like covering all callbacks would cover a lot more.  It wouldn't give great
info
> on just what's allocating the memory, but that's the exact same issue with
your
> current approach here.

Yes That is currently being worked on in the side. But, even with this
information we have a lot of missing pieces in memory usage.
If you are interested in how it's done, you can look at this doc:
https://docs.google.com/document/d/1SegYs7xwdPb2cx5NEwXp1EPwdsQvUYkabwtsQf45H...
as well as this one for other kinds of efforts
https://docs.google.com/document/d/18M_v2nCmb0Scd6eMSu3dX961I0HPPhCSgL_h3Ln3m1Q

[mmenke, 2016-03-31 20:26:00]

On 2016/03/31 20:03:09, ssid wrote:
> > Sorry for slowness, had a bunch of meetings yesterday.
> > 
> > Tracepoints I suggest, just thinking about separating out net/ and non-net
> > allocations:
> > 
> > ResourceLoader has a bunch that would be useful:
> > 
> > OnReceivedRedirect, OnBeforeNetworkStart, OnResponseStarted,
OnReadCompleted,
> > ResponseCompleted, and maybe one wrapping the OnWillRead call to the
handler.
> > 
> > You could also add trace points to NetworkDelegate or ChromeNetworkDelegate,
> to
> > catch stuff going on outside the network stack (NetworkDelegate will catch
> more,
> > but would be less clear what's going on).  NetworkDelegate calls into
> > extensions, which is my primary concern there, though they mostly do stuff
on
> > the IOThread, admittedly.
> > 
> 
> ResourceLoader seems to already have a bunch of trace points. Nonetheless the
> functions like OnResponseStarted and OnReadCompleted could be useful.
> Note that ResourceLoader only accounrts for 40-50% of usage form
> URLRequestHttpJob::OnReadCompleted.
> 
> NetworkDelegate in some experiments allocated 0.5% (~1.5Mib) of browser memory
> usage. Out of which more than 95% was on IO thread.
> NetworkDelegate Notify... accounts for around ~20% of httpJob and ~15% of
> httpCache tasks.
> In summary, NetworkDelegate seems to cover a lot of usage form
> URLRequestHttpJob's handlers.

Sorry, when I said extensions were on IO thread, I meant the UI thread. 
Surprised to see so much from NetworkDelegate on the IO thread, but it calls
into so much random stuff that does who knows what, suppose it isn't much of a
surprise.

> I have updated the CL with a few trace points in NetworkDelegate and
> ResourceLoader.
> Since I do not want you to spend a lot of time thinking about where to add, I
> have this CL that gives you hints.
> 
> > 
> > I can certainly suggest more/better ones in net as well, just a matter of
> > spending some time thinking about it.
> 
> Yes, to help you with that, from real world usage, this CL can give some
hints.
> You can also look at the functions marked in this CL
> https://codereview.chromium.org/1840783002/.
> 
> Do you suggest I write a doc about what all I found important and you can add
> your inputs on where all I should add trace events? Basically I can add the
> information form the CLs.
> 
> You can have a look at this doc to see how important these functions turned
out
> to be in case of memory usage:
>
https://docs.google.com/document/d/162LZ6GPa4EM1AO434B4pvprfjXYLqWYFAi24FjX6C...
> You are right in saying this memory shouldn't totally be attributed to net
since
> it calls into extensions and stuff. but at least we know it started from here.

That doc has some great information - seems like a good starting place.  I also
hadn't realized you were looking at memory still used once all the URLRequests
are done.  That tells me a lot about what kinds of things you're interested in.

I'll get back to you tomorrow.  Sorry for slowness, just been doing a bunch of
small things this week.  Barely gotten any coding done.  :(

> > Also, a question:  UMA's "Profiler" tab shows CPU usage by executed
callback. 
> I
> > don't support you could just hook it up to show memory allocations as well? 
> > That's basically what the tracing hooks you're adding are doing, and it
seems
> > like covering all callbacks would cover a lot more.  It wouldn't give great
> info
> > on just what's allocating the memory, but that's the exact same issue with
> your
> > current approach here.
> 
> Yes That is currently being worked on in the side. But, even with this
> information we have a lot of missing pieces in memory usage.
> If you are interested in how it's done, you can look at this doc:
>
https://docs.google.com/document/d/1SegYs7xwdPb2cx5NEwXp1EPwdsQvUYkabwtsQf45H...
> as well as this one for other kinds of efforts
>
https://docs.google.com/document/d/18M_v2nCmb0Scd6eMSu3dX961I0HPPhCSgL_h3Ln3m1Q

[ssid, 2016-03-31 20:51:13]

> That doc has some great information - seems like a good starting place.  I
also
> hadn't realized you were looking at memory still used once all the URLRequests
> are done.  That tells me a lot about what kinds of things you're interested
in.
> 
> I'll get back to you tomorrow.  Sorry for slowness, just been doing a bunch of
> small things this week.  Barely gotten any coding done.  :(

No problem with delay, Its great that you are helping. Thanks!

Yes I am interested in long lived memory allocations and the functions that
allocate such memory.
For more information about exact numbers you can look at this trace:
https://drive.google.com/open?id=0B7f4beGia2iHRm1KcHpGSUQ3T0E
Choose a memory dump, malloc on browser and see Heap profile section.

The list of functions as given in the doc:
ƒHttpServerPropertiesManager::UpdateCacheFromPrefsOnNetworkThread
net::DoVerifyOnWorkerThread
net::BackgroundIO::OnIOSignalled
net::ClientSocketHandle::OnIOComplete
net::ProcTask::OnLookupComplete	net::CertVerifierJob::OnJobCompleted	
net::SocketPosix::OnFileCanReadWithoutBlocking
net::UDPSocketPosix::ReadWatcher::OnFileCanReadWithoutBlocking
net::Job::ExecuteProxyResolver
net::URLRequestHttpJob::OnReadCompleted	
net::SSLConnectJob::DoLoop
net::SpdySession::PumpReadLoop
net::SSLClientSocketOpenSSL::DoHandshakeLoop

[mmenke, 2016-04-01 17:49:13]

On 2016/03/31 20:51:13, ssid wrote:
> > That doc has some great information - seems like a good starting place.  I
> also
> > hadn't realized you were looking at memory still used once all the
URLRequests
> > are done.  That tells me a lot about what kinds of things you're interested
> in.
> > 
> > I'll get back to you tomorrow.  Sorry for slowness, just been doing a bunch
of
> > small things this week.  Barely gotten any coding done.  :(
> 
> No problem with delay, Its great that you are helping. Thanks!
> 
> Yes I am interested in long lived memory allocations and the functions that
> allocate such memory.
> For more information about exact numbers you can look at this trace:
> https://drive.google.com/open?id=0B7f4beGia2iHRm1KcHpGSUQ3T0E
> Choose a memory dump, malloc on browser and see Heap profile section.
> 
> The list of functions as given in the doc:
> ƒHttpServerPropertiesManager::UpdateCacheFromPrefsOnNetworkThread
> net::DoVerifyOnWorkerThread
> net::BackgroundIO::OnIOSignalled
> net::ClientSocketHandle::OnIOComplete
> net::ProcTask::OnLookupComplete	net::CertVerifierJob::OnJobCompleted	
> net::SocketPosix::OnFileCanReadWithoutBlocking
> net::UDPSocketPosix::ReadWatcher::OnFileCanReadWithoutBlocking
> net::Job::ExecuteProxyResolver
> net::URLRequestHttpJob::OnReadCompleted	
> net::SSLConnectJob::DoLoop
> net::SpdySession::PumpReadLoop
> net::SSLClientSocketOpenSSL::DoHandshakeLoop

Grr...I submitted a response earlier, but it looks like codereview ate it (?)

You look to be gathering stats from a corp machine.  Note that this is a lot
different from what a typical home user sees.  In particular, you're seeing PAC
proxy resolution (Job::ExecuteProxyResolver, which is mostly V8), and two layers
of SSL instead of one - if it's an H2 proxy, I'm not sure what the effect of the
extra SSL layer is on memory consumption.  If it's an HTTP/1.1 proxy, it's
presumably a lot.

HttpServerPropertiesManager::UpdateCacheFromPrefsOnNetworkThread:  This is
loading cached info about which servers support what protocols and the like. 
You could add tracing for HttpServerPropertiesManager::Set* to capture
additional memory added here at runtime, so it won't be attributed elsewhere.

ClientSocketHandle::OnIOComplete:
SSLConnectJob::DoLoop (SSLConnectJob::DoSSLConnect is the main one). 
HttpStreamFactoryImpl::Job::OnIOComplete (Should be useful for some other
others, too).

net::ProcTask::OnLookupComplete:
HostCache::Set, QuicStreamFactory::Job::DoLoop,
TransportConnectJobHelper::DoResolveHostComplete.

SocketPosix::OnFileCanReadWithoutBlocking:
SSLClientSocketOpenSSL::DoHandshakeLoop,  SSLClientSocketOpenSSL::DoReadLoop. 
Could also / alternatively do SSLClientSocketOpenSSL::OnRecvComplete, which
catches both of those and the read callback invoked as well.

URLRequestHttpJob::OnReadCompleted:
Seems like the added ResourceLoader hooks would catch the main one here, but
could also do NetworkQualityEstimator::NotifyRequestCompleted.  NQE has other
methods that may or may not be interesting as well.

[mmenke, 2016-04-01 17:55:11]

Forgot (at least) two:

SpdySessionPool::CreateAvailableSessionFromSocket,
QuicStreamFactory::CreateSession

[Buck, 2016-04-01 20:52:45]

Hi.   I don't have anything to add at this point.   The areas of the code base
I'm most familiar with are quic and some of the http layer above.  For QUIC, I
could imagine maybe adding some stream trace points, but perhaps they are not so
interesting as they shouldn't be particularly long lived.   

[ Sorry for the delayed response, I just got back from vacation yesterday. ]

[Buck, 2016-04-01 20:53:10]

lgtm

[Buck, 2016-04-01 20:53:12]

lgtm

[ssid, 2016-04-02 01:24:16]

Patchset #4 (id:60001) has been deleted

[ssid, 2016-04-02 01:38:43]

Description was changed from

==========
Add TRACE_EVENT macros to net.

This CL adds TRACE_EVENT macros to some of the interesting functions in
net which are useful to track memory usage.

BUG=598377
==========

to

==========
Add TRACE_EVENT macros to net.

This CL adds TRACE_EVENT macros to some of the interesting functions in
net which are useful to track memory usage.
These are points suggested by statistics from local experiments and
improvised by mmenke@.

The CL also changes the categories of some existing trace events and
cleans up some. Some events are marked under DISABLED_BY_DEFAULT
category since there are too many calls and should not crowd default
tracing with lot of points. This is chosen based on an average value
of trace events in other categories.

BUG=598377
==========

[ssid, 2016-04-02 01:59:24]

I have added in all locations that I found useful based on your suggestions and
what I understand.
Do you think this looks better?

> Grr...I submitted a response earlier, but it looks like codereview ate it (?)
> 
> You look to be gathering stats from a corp machine.  Note that this is a lot
> different from what a typical home user sees.  In particular, you're seeing
PAC
> proxy resolution (Job::ExecuteProxyResolver, which is mostly V8), and two
layers
> of SSL instead of one - if it's an H2 proxy, I'm not sure what the effect of
the
> extra SSL layer is on memory consumption.  If it's an HTTP/1.1 proxy, it's
> presumably a lot.

Yes I have heard that is the reason for few of the numbers. But, once I add
these points, I am planning to track these usage metrics as user reports from
devices using background tracing. This would help give more real world data.
Also it is good to have these instrumented to explain Googlers why their chrome
uses memory.
 
> HttpServerPropertiesManager::UpdateCacheFromPrefsOnNetworkThread:  This is
> loading cached info about which servers support what protocols and the like. 
> You could add tracing for HttpServerPropertiesManager::Set* to capture
> additional memory added here at runtime, so it won't be attributed elsewhere.

I have tried adding to HttpServerPropertiesManager::Set methods and with a few
expeiments it turned out that each of them allocate very less amount of memory.
In this case I do not think it is worth adding so much information. But it is
still good to have a toplevel function so that it helps the developer later for
debugging.
 
> ClientSocketHandle::OnIOComplete:
> SSLConnectJob::DoLoop (SSLConnectJob::DoSSLConnect is the main one). 
> HttpStreamFactoryImpl::Job::OnIOComplete (Should be useful for some other
> others, too).

yes, added.

> net::ProcTask::OnLookupComplete:
> HostCache::Set, QuicStreamFactory::Job::DoLoop,
> TransportConnectJobHelper::DoResolveHostComplete.

Added here as well. 

> SocketPosix::OnFileCanReadWithoutBlocking:
> SSLClientSocketOpenSSL::DoHandshakeLoop,  SSLClientSocketOpenSSL::DoReadLoop. 
> Could also / alternatively do SSLClientSocketOpenSSL::OnRecvComplete, which
> catches both of those and the read callback invoked as well.

SSLClientSocketOpenSSL::DoReadLoop doesn't seem to allocate much. But others are
very useful. I have actully added to all these functions, do you think I should
remove redundancy here?

> URLRequestHttpJob::OnReadCompleted:
> Seems like the added ResourceLoader hooks would catch the main one here, but
> could also do NetworkQualityEstimator::NotifyRequestCompleted.  NQE has other
> methods that may or may not be interesting as well.

Done Thanks.

These are all the functions that I found useful adding trace events in
ResourceLoader, NetworkQualityEstimator and NetworkDelegate. If I missed some I
can add.

https://codereview.chromium.org/1834273002/diff/80001/chrome/browser/net/crl_...
File chrome/browser/net/crl_set_fetcher.cc (right):

https://codereview.chromium.org/1834273002/diff/80001/chrome/browser/net/crl_...
chrome/browser/net/crl_set_fetcher.cc:89: TRACE_EVENT0("net",
"CRLSetFetcher::LoadFromDisk");
All this calls actually get into net/cert/crl_set. So moving this to net
category. Also, it is easier for a common Chrome dev to understand net than
CRLSet.
If you think CRLSet is a better suit, please let me know.

[mmenke, 2016-04-04 16:45:49]

LGTM

https://codereview.chromium.org/1834273002/diff/80001/chrome/browser/net/crl_...
File chrome/browser/net/crl_set_fetcher.cc (right):

https://codereview.chromium.org/1834273002/diff/80001/chrome/browser/net/crl_...
chrome/browser/net/crl_set_fetcher.cc:89: TRACE_EVENT0("net",
"CRLSetFetcher::LoadFromDisk");
On 2016/04/02 01:59:24, ssid wrote:
> All this calls actually get into net/cert/crl_set. So moving this to net
> category. Also, it is easier for a common Chrome dev to understand net than
> CRLSet.
> If you think CRLSet is a better suit, please let me know.

I'm fine with it here, but I'm not all that familiar with this code.

https://codereview.chromium.org/1834273002/diff/100001/content/browser/loader...
File content/browser/loader/resource_loader.cc (right):

https://codereview.chromium.org/1834273002/diff/100001/content/browser/loader...
content/browser/loader/resource_loader.cc:478: FROM_HERE,
base::Bind(&ResourceLoader::ResponseCompleted,
Looks like you're missing ResponseComplete in the deferred case.  I'm not sure
how often this happens.  Could considering adding ResponseComplete directly, but
you catch most call paths that go through there already.

Looks like the other two PostTasks in this method may be missed as well.

https://codereview.chromium.org/1834273002/diff/100001/net/http/http_stream_f...
File net/http/http_stream_factory_impl_job.cc (right):

https://codereview.chromium.org/1834273002/diff/100001/net/http/http_stream_f...
net/http/http_stream_factory_impl_job.cc:1759:
"HttpStreamFactoryImpl::CreateAvailableSessionFromSocket");
Think you should probably include the "Job::" in this string, even if you leave
out the ValidSpdySessionPool.

https://codereview.chromium.org/1834273002/diff/100001/net/proxy/proxy_resolv...
File net/proxy/proxy_resolver_v8_tracing.cc (right):

https://codereview.chromium.org/1834273002/diff/100001/net/proxy/proxy_resolv...
net/proxy/proxy_resolver_v8_tracing.cc:582: TRACE_EVENT0("v8",
"Job::ExecuteProxyResolver");
Is v8 the right label for net code?  Yes, we are just running v8 here, not sure
about tracing names in general.

https://codereview.chromium.org/1834273002/diff/100001/net/socket/ssl_client_...
File net/socket/ssl_client_socket_pool.cc (right):

https://codereview.chromium.org/1834273002/diff/100001/net/socket/ssl_client_...
net/socket/ssl_client_socket_pool.cc:170: TRACE_EVENT0("net",
"SSLConnectJob::OnIOComplete");
Since we already have a separate event for DoLoop, should we move this to
NotifyDelegateOfCompletion instead?  That also makes it clearer this is
measuring stuff outside this class.

[ssid, 2016-04-05 00:50:13]

Thanks a lot for your help!

https://codereview.chromium.org/1834273002/diff/100001/content/browser/loader...
File content/browser/loader/resource_loader.cc (right):

https://codereview.chromium.org/1834273002/diff/100001/content/browser/loader...
content/browser/loader/resource_loader.cc:478: FROM_HERE,
base::Bind(&ResourceLoader::ResponseCompleted,
On 2016/04/04 16:45:49, mmenke wrote:
> Looks like you're missing ResponseComplete in the deferred case.  I'm not sure
> how often this happens.  Could considering adding ResponseComplete directly,
but
> you catch most call paths that go through there already.
> 
> Looks like the other two PostTasks in this method may be missed as well.

The performance team has added few trace points in this file, which included
ResponseCompleted. I also changed category in this file to loading to keep
consistent with them.

https://codereview.chromium.org/1834273002/diff/100001/net/http/http_stream_f...
File net/http/http_stream_factory_impl_job.cc (right):

https://codereview.chromium.org/1834273002/diff/100001/net/http/http_stream_f...
net/http/http_stream_factory_impl_job.cc:1759:
"HttpStreamFactoryImpl::CreateAvailableSessionFromSocket");
On 2016/04/04 16:45:49, mmenke wrote:
> Think you should probably include the "Job::" in this string, even if you
leave
> out the ValidSpdySessionPool.

Done.

https://codereview.chromium.org/1834273002/diff/100001/net/proxy/proxy_resolv...
File net/proxy/proxy_resolver_v8_tracing.cc (right):

https://codereview.chromium.org/1834273002/diff/100001/net/proxy/proxy_resolv...
net/proxy/proxy_resolver_v8_tracing.cc:582: TRACE_EVENT0("v8",
"Job::ExecuteProxyResolver");
On 2016/04/04 16:45:49, mmenke wrote:
> Is v8 the right label for net code?  Yes, we are just running v8 here, not
sure
> about tracing names in general.

Sorry I missed this one. The name is generally the namespace of the function.
But when it is not strict. Changed it to net to stick to namespace in this case.

https://codereview.chromium.org/1834273002/diff/100001/net/socket/ssl_client_...
File net/socket/ssl_client_socket_pool.cc (right):

https://codereview.chromium.org/1834273002/diff/100001/net/socket/ssl_client_...
net/socket/ssl_client_socket_pool.cc:170: TRACE_EVENT0("net",
"SSLConnectJob::OnIOComplete");
On 2016/04/04 16:45:49, mmenke wrote:
> Since we already have a separate event for DoLoop, should we move this to
> NotifyDelegateOfCompletion instead?  That also makes it clearer this is
> measuring stuff outside this class.

Makes sense!

[ssid, 2016-04-05 05:11:46]

The CQ bit was checked by ssid@chromium.org

[ssid, 2016-04-05 05:11:47]

The patchset sent to the CQ was uploaded after l-g-t-m from
ckrasic@chromium.org, mmenke@chromium.org
Link to the patchset: https://codereview.chromium.org/1834273002/#ps120001
(title: "Rebase and address comments.")

[commit-bot: I haz the power, 2016-04-05 05:12:09]

CQ is trying da patch. Follow status at
 https://chromium-cq-status.appspot.com/patch-status/1834273002/120001
View timeline at
 https://chromium-cq-status.appspot.com/patch-timeline/1834273002/120001

[commit-bot: I haz the power, 2016-04-05 06:50:05]

The CQ bit was unchecked by commit-bot@chromium.org

[commit-bot: I haz the power, 2016-04-05 06:50:06]

Try jobs failed on following builders:
  linux_android_rel_ng on tryserver.chromium.android (JOB_TIMED_OUT,
https://build.chromium.org/p/tryserver.chromium.android/builders/linux_androi...)

[ssid, 2016-04-05 17:49:52]

The CQ bit was checked by ssid@chromium.org

[commit-bot: I haz the power, 2016-04-05 17:50:19]

CQ is trying da patch. Follow status at
 https://chromium-cq-status.appspot.com/patch-status/1834273002/120001
View timeline at
 https://chromium-cq-status.appspot.com/patch-timeline/1834273002/120001

[commit-bot: I haz the power, 2016-04-05 19:00:06]

Description was changed from

==========
Add TRACE_EVENT macros to net.

This CL adds TRACE_EVENT macros to some of the interesting functions in
net which are useful to track memory usage.
These are points suggested by statistics from local experiments and
improvised by mmenke@.

The CL also changes the categories of some existing trace events and
cleans up some. Some events are marked under DISABLED_BY_DEFAULT
category since there are too many calls and should not crowd default
tracing with lot of points. This is chosen based on an average value
of trace events in other categories.

BUG=598377
==========

to

==========
Add TRACE_EVENT macros to net.

This CL adds TRACE_EVENT macros to some of the interesting functions in
net which are useful to track memory usage.
These are points suggested by statistics from local experiments and
improvised by mmenke@.

The CL also changes the categories of some existing trace events and
cleans up some. Some events are marked under DISABLED_BY_DEFAULT
category since there are too many calls and should not crowd default
tracing with lot of points. This is chosen based on an average value
of trace events in other categories.

BUG=598377
==========

[commit-bot: I haz the power, 2016-04-05 19:00:07]

Committed patchset #6 (id:120001)

[commit-bot: I haz the power, 2016-04-05 19:01:14]

Description was changed from

==========
Add TRACE_EVENT macros to net.

This CL adds TRACE_EVENT macros to some of the interesting functions in
net which are useful to track memory usage.
These are points suggested by statistics from local experiments and
improvised by mmenke@.

The CL also changes the categories of some existing trace events and
cleans up some. Some events are marked under DISABLED_BY_DEFAULT
category since there are too many calls and should not crowd default
tracing with lot of points. This is chosen based on an average value
of trace events in other categories.

BUG=598377
==========

to

==========
Add TRACE_EVENT macros to net.

This CL adds TRACE_EVENT macros to some of the interesting functions in
net which are useful to track memory usage.
These are points suggested by statistics from local experiments and
improvised by mmenke@.

The CL also changes the categories of some existing trace events and
cleans up some. Some events are marked under DISABLED_BY_DEFAULT
category since there are too many calls and should not crowd default
tracing with lot of points. This is chosen based on an average value
of trace events in other categories.

BUG=598377

Committed: https://crrev.com/6d6b40100156b2dabcc79cf46f9f34f225e21d0a
Cr-Commit-Position: refs/heads/master@{#385246}
==========

[commit-bot: I haz the power, 2016-04-05 19:01:15]

Patchset 6 (id:??) landed as
https://crrev.com/6d6b40100156b2dabcc79cf46f9f34f225e21d0a
Cr-Commit-Position: refs/heads/master@{#385246}

[ssid, 2016-09-07 03:39:12]

Patchset #2 (id:20001) has been deleted