DevTools & WebTiming : Migrate from PassiveLogCollector to dedicated LoadTimingObserver.

DevTools & WebTiming : Migrate from PassiveLogCollector to dedicated LoadTimingObserver.

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

[pfeldman, 2010-07-14 15:34:16]

Hi guys,

Here is a dedicated observer that I am using instead of the passive log
collector. Could you give it a look? My only question is whether I track
lifetime of the records properly.

Thanks
Pavel

[darin (slow to review), 2010-07-14 15:56:46]

LGTM

http://codereview.chromium.org/2909016/diff/1/5
File chrome/browser/net/load_timing_observer.h (right):

http://codereview.chromium.org/2909016/diff/1/5#newcode18
chrome/browser/net/load_timing_observer.h:18: struct UrlRequestRecord {
nit: UrlRequestRecord -> URLRequestRecord (to be consistent with URLRequest,
URLRequestJob, etc.)

http://codereview.chromium.org/2909016/diff/1/5#newcode44
chrome/browser/net/load_timing_observer.h:44: void
OnAddUrlRequestEntry(net::NetLog::EventType type,
same thing:  OnAddURLRequestEntry

http://codereview.chromium.org/2909016/diff/1/8
File chrome/browser/renderer_host/async_resource_handler.cc (right):

http://codereview.chromium.org/2909016/diff/1/8#newcode115
chrome/browser/renderer_host/async_resource_handler.cc:115: LoadTimingObserver*
observer = chrome_net_log->load_timing_observer();
just a reminder to also hook this up for SyncResourceHandler.

[pfeldman, 2010-07-14 16:51:21]

Thanks. That was fast.

http://codereview.chromium.org/2909016/diff/1/5
File chrome/browser/net/load_timing_observer.h (right):

http://codereview.chromium.org/2909016/diff/1/5#newcode18
chrome/browser/net/load_timing_observer.h:18: struct UrlRequestRecord {
On 2010/07/14 15:56:47, darin wrote:
> nit: UrlRequestRecord -> URLRequestRecord (to be consistent with URLRequest,
> URLRequestJob, etc.)

Done.

http://codereview.chromium.org/2909016/diff/1/5#newcode44
chrome/browser/net/load_timing_observer.h:44: void
OnAddUrlRequestEntry(net::NetLog::EventType type,
On 2010/07/14 15:56:47, darin wrote:
> same thing:  OnAddURLRequestEntry

Done.

http://codereview.chromium.org/2909016/diff/1/8
File chrome/browser/renderer_host/async_resource_handler.cc (right):

http://codereview.chromium.org/2909016/diff/1/8#newcode115
chrome/browser/renderer_host/async_resource_handler.cc:115: LoadTimingObserver*
observer = chrome_net_log->load_timing_observer();
On 2010/07/14 15:56:47, darin wrote:
> just a reminder to also hook this up for SyncResourceHandler.

I can't use this information in inspector + WebTiming does not needed. I think
we should leave it for later.

[eroman, 2010-07-14 22:22:04]

LGTM after addressing comments below.

Would also be good if you could add a unit-test.

http://codereview.chromium.org/2909016/diff/1010/6003
File chrome/browser/net/load_timing_observer.cc (right):

http://codereview.chromium.org/2909016/diff/1010/6003#newcode76
chrome/browser/net/load_timing_observer.cc:76: URLRequestToRecordMap::iterator
it =
IMPORTANT: Can you add a check on the total map size for the two places where
you insert?

I think this is an important safety-net, as it prevents us from passively
growing the memory memory unbounded in case something went wrong. One thing
which can go wrong, is if the format of the NetLog events ever changes, or
forgets to omit the "end" event for something, we don't want it to cause memory
leak.

http://codereview.chromium.org/2909016/diff/1010/6003#newcode78
chrome/browser/net/load_timing_observer.cc:78: std::make_pair(source.id,
URLRequestRecord())).first;
I wander if this could be simplified as:

URLRequestRecord& record = url_request_to_record_[source.id];

http://codereview.chromium.org/2909016/diff/1010/6003#newcode85
chrome/browser/net/load_timing_observer.cc:85: }
Optional optimization:

You could stop tracking the url_request_ once you see that it does not have the
net::LOAD_ENABLE_LOAD_TIMING load flags.

If you choose to do that, you can extract the load flags from the event
URL_REQUEST_START_JOB.

http://codereview.chromium.org/2909016/diff/1010/6003#newcode97
chrome/browser/net/load_timing_observer.cc:97: (time -
record->base_ticks).InMillisecondsRoundedUp());
nit: there is an opportunity to extract the duplicated:

 static_cast<int32>(XXX - record->base_ticks).InMillisecondsRoundedUp();

http://codereview.chromium.org/2909016/diff/1010/6004
File chrome/browser/net/load_timing_observer.h (right):

http://codereview.chromium.org/2909016/diff/1010/6004#newcode15
chrome/browser/net/load_timing_observer.h:15: // timing information.
nit: can you add "for use by the devtools" ?

http://codereview.chromium.org/2909016/diff/1010/6008
File chrome/chrome_browser.gypi (right):

http://codereview.chromium.org/2909016/diff/1010/6008#newcode1809
chrome/chrome_browser.gypi:1809: 'browser/net/load_timing_observer.cc',
please sort this further down near the browser/net/* lines

[pfeldman, 2010-07-15 08:44:44]

http://codereview.chromium.org/2909016/diff/1010/6003
File chrome/browser/net/load_timing_observer.cc (right):

http://codereview.chromium.org/2909016/diff/1010/6003#newcode76
chrome/browser/net/load_timing_observer.cc:76: URLRequestToRecordMap::iterator
it =
On 2010/07/14 22:22:05, eroman wrote:
> IMPORTANT: Can you add a check on the total map size for the two places where
> you insert?
> 
> I think this is an important safety-net, as it prevents us from passively
> growing the memory memory unbounded in case something went wrong. One thing
> which can go wrong, is if the format of the NetLog events ever changes, or
> forgets to omit the "end" event for something, we don't want it to cause
memory
> leak.

Done.

http://codereview.chromium.org/2909016/diff/1010/6003#newcode78
chrome/browser/net/load_timing_observer.cc:78: std::make_pair(source.id,
URLRequestRecord())).first;
On 2010/07/14 22:22:05, eroman wrote:
> I wander if this could be simplified as:
> 
> URLRequestRecord& record = url_request_to_record_[source.id];

Done.

http://codereview.chromium.org/2909016/diff/1010/6003#newcode85
chrome/browser/net/load_timing_observer.cc:85: }
On 2010/07/14 22:22:05, eroman wrote:
> Optional optimization:
> 
> You could stop tracking the url_request_ once you see that it does not have
the
> net::LOAD_ENABLE_LOAD_TIMING load flags.
> 
> If you choose to do that, you can extract the load flags from the event
> URL_REQUEST_START_JOB.

Done. I needed to expose URLRequestStartEventParameters::load_flags() for that.

http://codereview.chromium.org/2909016/diff/1010/6003#newcode97
chrome/browser/net/load_timing_observer.cc:97: (time -
record->base_ticks).InMillisecondsRoundedUp());
On 2010/07/14 22:22:05, eroman wrote:
> nit: there is an opportunity to extract the duplicated:
> 
>  static_cast<int32>(XXX - record->base_ticks).InMillisecondsRoundedUp();
> 
> 

Done.

http://codereview.chromium.org/2909016/diff/1010/6004
File chrome/browser/net/load_timing_observer.h (right):

http://codereview.chromium.org/2909016/diff/1010/6004#newcode15
chrome/browser/net/load_timing_observer.h:15: // timing information.
On 2010/07/14 22:22:05, eroman wrote:
> nit: can you add "for use by the devtools" ?

Not only that - for WebTiming as well.

http://codereview.chromium.org/2909016/diff/1010/6008
File chrome/chrome_browser.gypi (right):

http://codereview.chromium.org/2909016/diff/1010/6008#newcode1809
chrome/chrome_browser.gypi:1809: 'browser/net/load_timing_observer.cc',
On 2010/07/14 22:22:05, eroman wrote:
> please sort this further down near the browser/net/* lines

Done. Poor merge. Thanks.

[eroman, 2010-07-15 18:44:46]

http://codereview.chromium.org/2909016/diff/18001/19004
File chrome/browser/net/load_timing_observer.cc (right):

http://codereview.chromium.org/2909016/diff/18001/19004#newcode96
chrome/browser/net/load_timing_observer.cc:96:
url_request_to_record_.erase(url_request_to_record_.begin());
Can you use url_request_to_record_.clear() instead?

Like you said, this "shouldn't" happen. So if it does happen something is wrong,
and we should just reset and reclaim the memory.

Also, could you add a LOG(WARNING) ?

http://codereview.chromium.org/2909016/diff/18001/19004#newcode100
chrome/browser/net/load_timing_observer.cc:100: record.timing.base_time =
TimeTicksToTime(time);
This isn't the same metric you had in the earlier patchset: there may be
repeated START/END for jobs (an initial job usually for appcache, and then
repeated jobs for redirect).

I think you still want the REQUEST_ALIVE (begin) to mark the base_time.

http://codereview.chromium.org/2909016/diff/18001/19004#newcode183
chrome/browser/net/load_timing_observer.cc:183:
connect_job_to_record_.erase(connect_job_to_record_.begin());
Same comment as above, please use clear() instead.

[pfeldman, 2010-07-15 21:46:00]

http://codereview.chromium.org/2909016/diff/18001/19004
File chrome/browser/net/load_timing_observer.cc (right):

http://codereview.chromium.org/2909016/diff/18001/19004#newcode96
chrome/browser/net/load_timing_observer.cc:96:
url_request_to_record_.erase(url_request_to_record_.begin());
On 2010/07/15 18:44:46, eroman wrote:
> Can you use url_request_to_record_.clear() instead?
> 
> Like you said, this "shouldn't" happen. So if it does happen something is
wrong,
> and we should just reset and reclaim the memory.
> 
> Also, could you add a LOG(WARNING) ?

Done.

http://codereview.chromium.org/2909016/diff/18001/19004#newcode100
chrome/browser/net/load_timing_observer.cc:100: record.timing.base_time =
TimeTicksToTime(time);
On 2010/07/15 18:44:46, eroman wrote:
> This isn't the same metric you had in the earlier patchset: there may be
> repeated START/END for jobs (an initial job usually for appcache, and then
> repeated jobs for redirect).
> 
> I think you still want the REQUEST_ALIVE (begin) to mark the base_time.

I actually want each subsequent redirect to overwrite previous record and
populate it with new values. Following this route allows me capturing data for
each of the redirects. I also want base time to be as close to the actual
redirect/request start as possible. In fact it has no particular meaning - it is
just the baseline for the timing data.

http://codereview.chromium.org/2909016/diff/18001/19004#newcode183
chrome/browser/net/load_timing_observer.cc:183:
connect_job_to_record_.erase(connect_job_to_record_.begin());
On 2010/07/15 18:44:46, eroman wrote:
> Same comment as above, please use clear() instead.

Done.

[eroman, 2010-07-15 21:49:18]

lgtm

http://codereview.chromium.org/2909016/diff/18001/19004
File chrome/browser/net/load_timing_observer.cc (right):

http://codereview.chromium.org/2909016/diff/18001/19004#newcode100
chrome/browser/net/load_timing_observer.cc:100: record.timing.base_time =
TimeTicksToTime(time);
On 2010/07/15 21:46:00, pfeldman wrote:
> On 2010/07/15 18:44:46, eroman wrote:
> > This isn't the same metric you had in the earlier patchset: there may be
> > repeated START/END for jobs (an initial job usually for appcache, and then
> > repeated jobs for redirect).
> > 
> > I think you still want the REQUEST_ALIVE (begin) to mark the base_time.
> 
> I actually want each subsequent redirect to overwrite previous record and
> populate it with new values. Following this route allows me capturing data for
> each of the redirects. I also want base time to be as close to the actual
> redirect/request start as possible. In fact it has no particular meaning - it
is
> just the baseline for the timing data.

Ok, so your logic change between patchsets was intentional then. sgtm.