Chromium Code Reviews
|
|
Chromium Code Reviews
Issue
2675343002:
Server push cancellation: add NetLogs to track cache lookup transaction (Closed)
|
Created:
3 years, 10 months ago by Zhongyi Shi Modified:
3 years, 10 months ago CC:
chromium-reviews, cbentzel+watch_chromium.org, gavinp+disk_chromium.org, net-reviews_chromium.org, eroman, bnc+watch_chromium.org, mmenke Target Ref:
refs/pending/heads/master Project:
chromium Visibility:
Public. |
DescriptionServer push cancellation: add NetLogs to track cache lookup transaction
for server push.
BUG=232040
Review-Url: https://codereview.chromium.org/2675343002
Cr-Commit-Position: refs/heads/master@{#449854}
Committed: https://chromium.googlesource.com/chromium/src/+/d2a4caef5b812732dce7baa2d56716f8ae1f8cd2
Patch Set 1 #Patch Set 2 : self review #
Total comments: 13
Patch Set 3 : Always log the push lookup results #
Total comments: 12
Patch Set 4 : address rch's comments #
Total comments: 14
Patch Set 5 : address eroman's comments #
Total comments: 26
Patch Set 6 : address eroman's comments #
Total comments: 4
Patch Set 7 : fix typo #Patch Set 8 : sync with master #Patch Set 9 : fix typo #
Messages
Total messages: 30 (10 generated)
zhongyi@chromium.org changed reviewers: + eroman@chromium.org, rch@chromium.org
Ryan and Eric: PTAL. If this is okay, I will continue to add some tests. Sample NetLogs when the pushed resource is cached is available: https://goo.gl/xzQaAH The pushed resource: https://www.example.org/kitten-1.jpg The original request triggers the push: https://www.example.org
https://codereview.chromium.org/2675343002/diff/20001/net/http/http_cache_loo... File net/http/http_cache_lookup_manager.cc (right): https://codereview.chromium.org/2675343002/diff/20001/net/http/http_cache_loo... net/http/http_cache_lookup_manager.cc:57: net_log_.AddEvent(NetLogEventType::PUSH_FOUND_IN_CACHE); I realize that CancelPush() is called from OnLookupComplete when the item is in the cache, but semantically, it would be clearer to move this down there. You might also consider logging both when the item is found and when it is not found (perhaps with a bool "found"?). https://codereview.chromium.org/2675343002/diff/20001/net/http/http_cache_loo... File net/http/http_cache_lookup_manager.h (right): https://codereview.chromium.org/2675343002/diff/20001/net/http/http_cache_loo... net/http/http_cache_lookup_manager.h:21: HttpCacheLookupManager(HttpCache* http_cache, NetLog* net_log); What creates an instance of this class? I don't see any callsites changed other than in tests. https://codereview.chromium.org/2675343002/diff/20001/net/http/http_cache_loo... net/http/http_cache_lookup_manager.h:25: const NetLogWithSource& source) override; nit: parameters of type NetLogWithSource are typically called net_log. https://codereview.chromium.org/2675343002/diff/20001/net/http/http_cache_loo... net/http/http_cache_lookup_manager.h:57: NetLog* net_log_; I think this should probably not come between |http_cache_| and the comment about ownership of it. https://codereview.chromium.org/2675343002/diff/20001/net/log/net_log_event_t... File net/log/net_log_event_type_list.h (right): https://codereview.chromium.org/2675343002/diff/20001/net/log/net_log_event_t... net/log/net_log_event_type_list.h:1316: EVENT_TYPE(PUSH_FOUND_IN_CACHE) Can you add a comment for PUSH_FOUND_IN_CACHE?
https://codereview.chromium.org/2675343002/diff/20001/net/http/http_cache_loo... File net/http/http_cache_lookup_manager.cc (right): https://codereview.chromium.org/2675343002/diff/20001/net/http/http_cache_loo... net/http/http_cache_lookup_manager.cc:57: net_log_.AddEvent(NetLogEventType::PUSH_FOUND_IN_CACHE); On 2017/02/06 23:34:55, Ryan Hamilton wrote: > I realize that CancelPush() is called from OnLookupComplete when the item is in > the cache, but semantically, it would be clearer to move this down there. You > might also consider logging both when the item is found and when it is not found > (perhaps with a bool "found"?). Well, in this CL, each push lookup transaction will have a separate NetLog "PUSH_LOOKUP_TRANSACTION" while the manager doesn't own a NetLog. That's why the cancel event is only logged in the transaction. If we want to also log the event in the manager, we could introduce a new Source type NetLog, "CACHE_LOOKUP_MANAGER", which notes the start of all the PUSH_LOOKUP_TRANSACTION, and the finish of PUSH_LOOKUP_TRANSACTION, as well as the cancel events. How does that sound? https://codereview.chromium.org/2675343002/diff/20001/net/http/http_cache_loo... File net/http/http_cache_lookup_manager.h (right): https://codereview.chromium.org/2675343002/diff/20001/net/http/http_cache_loo... net/http/http_cache_lookup_manager.h:21: HttpCacheLookupManager(HttpCache* http_cache, NetLog* net_log); On 2017/02/06 23:34:55, Ryan Hamilton wrote: > What creates an instance of this class? I don't see any callsites changed other > than in tests. It should be in the HttpCache's constructor. I have a CL working on adding one more boolean to the HttpCache's constructor due to the cache split, which will also include finch config. Eventually we will have HttpCache::HttpCache(...., bool is_main_cache) { // ... if (session) { net_log_ = session->net_log(); if (is_main_cache) { session-> session->SetServerPushDelegate( base::MakeUnique<HttpCacheLookupManager>(this, net_log_)); } // ... set up quic server info factory ... ｝ }
https://codereview.chromium.org/2675343002/diff/20001/net/http/http_cache_loo... File net/http/http_cache_lookup_manager.cc (right): https://codereview.chromium.org/2675343002/diff/20001/net/http/http_cache_loo... net/http/http_cache_lookup_manager.cc:57: net_log_.AddEvent(NetLogEventType::PUSH_FOUND_IN_CACHE); On 2017/02/07 00:00:24, Zhongyi Shi wrote: > On 2017/02/06 23:34:55, Ryan Hamilton wrote: > > I realize that CancelPush() is called from OnLookupComplete when the item is > in > > the cache, but semantically, it would be clearer to move this down there. You > > might also consider logging both when the item is found and when it is not > found > > (perhaps with a bool "found"?). > > Well, in this CL, each push lookup transaction will have a separate NetLog > "PUSH_LOOKUP_TRANSACTION" while the manager doesn't own a NetLog. That's why the > cancel event is only logged in the transaction. > > If we want to also log the event in the manager, we could introduce a new Source > type NetLog, "CACHE_LOOKUP_MANAGER", which notes the start of all the > PUSH_LOOKUP_TRANSACTION, and the finish of PUSH_LOOKUP_TRANSACTION, as well as > the cancel events. How does that sound? Oh, I see. I missed that CancelPush and OnLookupComplete are in different classes. In that case, I would be inclined to rename LookupTransaction::CancelPush ot LookupTransaction::OnLookupComplete(bool found_in_cache) (or some such). Then in the body of this method, I'd log in both cases. (but only call the helper's cancel method if it actually was found. What do you think? https://codereview.chromium.org/2675343002/diff/20001/net/http/http_cache_loo... File net/http/http_cache_lookup_manager.h (right): https://codereview.chromium.org/2675343002/diff/20001/net/http/http_cache_loo... net/http/http_cache_lookup_manager.h:21: HttpCacheLookupManager(HttpCache* http_cache, NetLog* net_log); On 2017/02/07 00:00:24, Zhongyi Shi wrote: > On 2017/02/06 23:34:55, Ryan Hamilton wrote: > > What creates an instance of this class? I don't see any callsites changed > other > > than in tests. > > It should be in the HttpCache's constructor. I have a CL working on adding one > more boolean to the HttpCache's constructor due to the cache split, which will > also include finch config. Eventually we will have > > HttpCache::HttpCache(...., bool is_main_cache) { > // ... > if (session) { > net_log_ = session->net_log(); > if (is_main_cache) { > session-> session->SetServerPushDelegate( > base::MakeUnique<HttpCacheLookupManager>(this, net_log_)); > } > // ... set up quic server info factory ... > ｝ > } Oh, I thought this was already wired up because of the manual tests you've been doing. But I guess this logic was part of that testing?
New revised sample NetLogs is available at: https://goo.gl/NIX9YV. This CL will be the minimal effort to add some NetLogs for server push cancellation. I will go back to improve more granular NetLogs once the server push finch plumbing is finished. PTAL, thanks! https://codereview.chromium.org/2675343002/diff/20001/net/http/http_cache_loo... File net/http/http_cache_lookup_manager.cc (right): https://codereview.chromium.org/2675343002/diff/20001/net/http/http_cache_loo... net/http/http_cache_lookup_manager.cc:57: net_log_.AddEvent(NetLogEventType::PUSH_FOUND_IN_CACHE); On 2017/02/07 00:10:49, Ryan Hamilton wrote: > On 2017/02/07 00:00:24, Zhongyi Shi wrote: > > On 2017/02/06 23:34:55, Ryan Hamilton wrote: > > > I realize that CancelPush() is called from OnLookupComplete when the item is > > in > > > the cache, but semantically, it would be clearer to move this down there. > You > > > might also consider logging both when the item is found and when it is not > > found > > > (perhaps with a bool "found"?). > > > > Well, in this CL, each push lookup transaction will have a separate NetLog > > "PUSH_LOOKUP_TRANSACTION" while the manager doesn't own a NetLog. That's why > the > > cancel event is only logged in the transaction. > > > > If we want to also log the event in the manager, we could introduce a new > Source > > type NetLog, "CACHE_LOOKUP_MANAGER", which notes the start of all the > > PUSH_LOOKUP_TRANSACTION, and the finish of PUSH_LOOKUP_TRANSACTION, as well as > > the cancel events. How does that sound? > > Oh, I see. I missed that CancelPush and OnLookupComplete are in different > classes. In that case, I would be inclined to rename > LookupTransaction::CancelPush ot LookupTransaction::OnLookupComplete(bool > found_in_cache) (or some such). Then in the body of this method, I'd log in both > cases. (but only call the helper's cancel method if it actually was found. What > do you think? That's a good idea! Done. Now we should always log the result of the push lookup transaction. https://codereview.chromium.org/2675343002/diff/20001/net/http/http_cache_loo... File net/http/http_cache_lookup_manager.h (right): https://codereview.chromium.org/2675343002/diff/20001/net/http/http_cache_loo... net/http/http_cache_lookup_manager.h:21: HttpCacheLookupManager(HttpCache* http_cache, NetLog* net_log); On 2017/02/07 00:10:49, Ryan Hamilton wrote: > On 2017/02/07 00:00:24, Zhongyi Shi wrote: > > On 2017/02/06 23:34:55, Ryan Hamilton wrote: > > > What creates an instance of this class? I don't see any callsites changed > > other > > > than in tests. > > > > It should be in the HttpCache's constructor. I have a CL working on adding one > > more boolean to the HttpCache's constructor due to the cache split, which will > > also include finch config. Eventually we will have > > > > HttpCache::HttpCache(...., bool is_main_cache) { > > // ... > > if (session) { > > net_log_ = session->net_log(); > > if (is_main_cache) { > > session-> session->SetServerPushDelegate( > > base::MakeUnique<HttpCacheLookupManager>(this, net_log_)); > > } > > // ... set up quic server info factory ... > > ｝ > > } > > Oh, I thought this was already wired up because of the manual tests you've been > doing. But I guess this logic was part of that testing? As discussed offline, this CL will have minimal effort to add NetLogs to make it work. The other CL will then add finch plumbing and turn on the switch. I'll upload a follow up CL to improve more granular NetLogs. https://codereview.chromium.org/2675343002/diff/20001/net/http/http_cache_loo... net/http/http_cache_lookup_manager.h:25: const NetLogWithSource& source) override; On 2017/02/06 23:34:55, Ryan Hamilton wrote: > nit: parameters of type NetLogWithSource are typically called net_log. Done. https://codereview.chromium.org/2675343002/diff/20001/net/http/http_cache_loo... net/http/http_cache_lookup_manager.h:57: NetLog* net_log_; On 2017/02/06 23:34:55, Ryan Hamilton wrote: > I think this should probably not come between |http_cache_| and the comment > about ownership of it. Done.
Looking good. https://codereview.chromium.org/2675343002/diff/40001/net/http/http_cache_loo... File net/http/http_cache_lookup_manager.cc (right): https://codereview.chromium.org/2675343002/diff/40001/net/http/http_cache_loo... net/http/http_cache_lookup_manager.cc:16: const NetLogSource& source, nit: this should be net_log https://codereview.chromium.org/2675343002/diff/40001/net/http/http_cache_loo... net/http/http_cache_lookup_manager.cc:20: if (source.IsValid()) Under what circumstances will this not be valid? https://codereview.chromium.org/2675343002/diff/40001/net/http/http_cache_loo... net/http/http_cache_lookup_manager.cc:67: NetLogEventType::SERVER_PUSH_LOOKUP_COMPLETE, nit: This is called SERVER_PUSH_... and the other is just PUSH_... It'd be best to be consistent. https://codereview.chromium.org/2675343002/diff/40001/net/http/http_cache_loo... net/http/http_cache_lookup_manager.cc:102: lookup->OnLookupComplete(false); I would have thought this would be OnLookupComplete(rv == OK); Or perhaps this is guaranteed to not return OK synchronously so then DCHECK_NE(OK, rv); OnLookupComplete(false); ? https://codereview.chromium.org/2675343002/diff/40001/net/http/http_cache_loo... File net/http/http_cache_lookup_manager.h (right): https://codereview.chromium.org/2675343002/diff/40001/net/http/http_cache_loo... net/http/http_cache_lookup_manager.h:25: const NetLogWithSource& net_log) override; nit: can you add: // ServerPushDelegate implementation: above this methof https://codereview.chromium.org/2675343002/diff/40001/net/http/http_cache_loo... net/http/http_cache_lookup_manager.h:45: const NetLogWithSource& source); nit: net_log
The CQ bit was checked by zhongyi@chromium.org to run a CQ dry run
Dry run: CQ is trying da patch. Follow status at https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...
Update sample net logs available at: https://goo.gl/xzQaAH. PTAL! https://codereview.chromium.org/2675343002/diff/40001/net/http/http_cache_loo... File net/http/http_cache_lookup_manager.cc (right): https://codereview.chromium.org/2675343002/diff/40001/net/http/http_cache_loo... net/http/http_cache_lookup_manager.cc:16: const NetLogSource& source, On 2017/02/07 15:22:58, Ryan Hamilton wrote: > nit: this should be net_log Done. https://codereview.chromium.org/2675343002/diff/40001/net/http/http_cache_loo... net/http/http_cache_lookup_manager.cc:20: if (source.IsValid()) On 2017/02/07 15:22:58, Ryan Hamilton wrote: > Under what circumstances will this not be valid? Done. I thought the tests would have the invalid id, looking at the source of NetLogSource, I'm wrong. A NetLogSource constructed implicitly should always has an valid id. https://codereview.chromium.org/2675343002/diff/40001/net/http/http_cache_loo... net/http/http_cache_lookup_manager.cc:67: NetLogEventType::SERVER_PUSH_LOOKUP_COMPLETE, On 2017/02/07 15:22:58, Ryan Hamilton wrote: > nit: This is called SERVER_PUSH_... and the other is just PUSH_... It'd be best > to be consistent. Done. https://codereview.chromium.org/2675343002/diff/40001/net/http/http_cache_loo... net/http/http_cache_lookup_manager.cc:102: lookup->OnLookupComplete(false); On 2017/02/07 15:22:58, Ryan Hamilton wrote: > I would have thought this would be OnLookupComplete(rv == OK); > > Or perhaps this is guaranteed to not return OK synchronously so then > DCHECK_NE(OK, rv); > OnLookupComplete(false); > ? Done. An synchronous return should imply that the cache index doesn't have the entry. Either way should be fine, but the first one sounds more safe. https://codereview.chromium.org/2675343002/diff/40001/net/http/http_cache_loo... File net/http/http_cache_lookup_manager.h (right): https://codereview.chromium.org/2675343002/diff/40001/net/http/http_cache_loo... net/http/http_cache_lookup_manager.h:25: const NetLogWithSource& net_log) override; On 2017/02/07 15:22:58, Ryan Hamilton wrote: > nit: can you add: > > // ServerPushDelegate implementation: > > above this methof Done. https://codereview.chromium.org/2675343002/diff/40001/net/http/http_cache_loo... net/http/http_cache_lookup_manager.h:45: const NetLogWithSource& source); On 2017/02/07 15:22:58, Ryan Hamilton wrote: > nit: net_log Done.
lgtm
The CQ bit was unchecked by commit-bot@chromium.org
Dry run: This issue passed the CQ dry run.
Eric, PTAL!
https://codereview.chromium.org/2675343002/diff/60001/net/http/http_cache_loo... File net/http/http_cache_lookup_manager.cc (right): https://codereview.chromium.org/2675343002/diff/60001/net/http/http_cache_loo... net/http/http_cache_lookup_manager.cc:17: std::string push_url, Can you reduce the copying of |push_url| ? Minimally you can change this to |const std::string&|, however that still does one unnecessary copy (internal for the callback state). Zero-copy solutions are (from worst to best) (a) Change the parameter type to base::StringPiece -- works, but can become a UAF if push_helper_->GetURL().spec() were to return a temporary. (b) Use base::ConstRef() when binding the callback -- works, but if caller forgets to add ConstRef() it does a copy (c) Change the parameter type to |const std::string*| -- harder to mis-use, but kind of ugly... (d) Change the parameter type to |const ServerPushHelper*| I suggest option (d) https://codereview.chromium.org/2675343002/diff/60001/net/http/http_cache_loo... net/http/http_cache_lookup_manager.cc:39: net_log_(NetLogWithSource::Make( Instead of creating a new source for this LookupTransaction, what if we output a BEGIN event during StartLookup (to the provided net_log), and then a corresponding END event in OnLookupComplete. Is there a need to de-couple the LookupTransaction to an independent NetLog stream? https://codereview.chromium.org/2675343002/diff/60001/net/http/http_cache_loo... net/http/http_cache_lookup_manager.cc:44: net_log_.EndEvent(NetLogEventType::SERVER_PUSH_LOOKUP_TRANSACTION); What is the meaning for SERVER_PUSH_LOOKUP_TRANSACTION begin vs end? Normally if we have an EndEvent() in the destructor, it is to match a BeginEvent() that took place in the constructor, however that is not the case here, where the corresponding BeginEvent is part of StartLookup(). Should the Begin/End instead by done by StartLookup vs OnLookupComplete? (and if there is a way to cancel, may have multiple paths to mark the "end") https://codereview.chromium.org/2675343002/diff/60001/net/http/http_cache_loo... net/http/http_cache_lookup_manager.cc:91: base::MakeUnique<LookupTransaction>(std::move(push_helper), net_log_); [optional] I found it a bit confusing that here (and in LookupTransaction::StartLookup) there is a |net_log_| member variable as well as a |net_log| argument, however they are different things. I suggest picking a different name for the argument that explains how its role is different. https://codereview.chromium.org/2675343002/diff/60001/net/http/http_cache_loo... File net/http/http_cache_lookup_manager_unittest.cc (right): https://codereview.chromium.org/2675343002/diff/60001/net/http/http_cache_loo... net/http/http_cache_lookup_manager_unittest.cc:221: NetLog net_log; If you change some of these to use TestNetLog, the tests can be updated to verify that the NetLog was written to. For the rest where no validation is done, the parameter passed to HttpCacheLookupManager can be |nullptr|. https://codereview.chromium.org/2675343002/diff/60001/net/log/net_log_event_t... File net/log/net_log_event_type_list.h (right): https://codereview.chromium.org/2675343002/diff/60001/net/log/net_log_event_t... net/log/net_log_event_type_list.h:1309: // The start/end of a push lookup transaction for server push. Per comments in the .cc, I think there is an opportunity to re-structure this so that the begin/end cache lookup is within a single event [BEGIN] and [END]. Otherwise I am not sure how useful the [END] phase of this event is, given that it measures something different from the [BEGIN]. https://codereview.chromium.org/2675343002/diff/60001/net/log/net_log_source_... File net/log/net_log_source_type_list.h (right): https://codereview.chromium.org/2675343002/diff/60001/net/log/net_log_source_... net/log/net_log_source_type_list.h:19: SOURCE_TYPE(SERVER_PUSH_LOOKUP_TRANSACTION) This list is not sorted; we generally prefer adding them at the end (to preserve ID stability).
Patchset #5 (id:80001) has been deleted
The net logs generated by the update code is availabe at: https://goo.gl/kgMY6g PTAL! https://codereview.chromium.org/2675343002/diff/60001/net/http/http_cache_loo... File net/http/http_cache_lookup_manager.cc (right): https://codereview.chromium.org/2675343002/diff/60001/net/http/http_cache_loo... net/http/http_cache_lookup_manager.cc:17: std::string push_url, On 2017/02/07 22:33:42, eroman (slow) wrote: > Can you reduce the copying of |push_url| ? > > Minimally you can change this to |const std::string&|, however that still does > one unnecessary copy (internal for the callback state). > > Zero-copy solutions are (from worst to best) > > (a) Change the parameter type to base::StringPiece -- works, but can become a > UAF if push_helper_->GetURL().spec() were to return a temporary. > > (b) Use base::ConstRef() when binding the callback -- works, but if caller > forgets to add ConstRef() it does a copy > > (c) Change the parameter type to |const std::string*| -- harder to mis-use, > but kind of ugly... > > (d) Change the parameter type to |const ServerPushHelper*| > > > I suggest option (d) Done. https://codereview.chromium.org/2675343002/diff/60001/net/http/http_cache_loo... net/http/http_cache_lookup_manager.cc:39: net_log_(NetLogWithSource::Make( On 2017/02/07 22:33:42, eroman (slow) wrote: > Instead of creating a new source for this LookupTransaction, what if we output a > BEGIN event during StartLookup (to the provided net_log), and then a > corresponding END event in OnLookupComplete. > > Is there a need to de-couple the LookupTransaction to an independent NetLog > stream? SERVER_PUSH_LOOKUP_TRANSACTION is something similar to a DISK_CACHE_ENTRY. We do need to provide a NetLogWithSource when run the cache transaction per https://cs.chromium.org/chromium/src/net/http/http_transaction.h?l=71. It might be possible that we could create a new source for the HttpCacheLookupManager or reuse the caller's net log who calls HttpCacheLookupManager::OnPush. The HttpCacheLookupManager creates a LookupTransaction every time HttpCacheLookupManager::OnPush is invoked. It's possible to have a few lookup transactions pending at the same time, logged in the same net log since server push cancellation lookup only requires read lock on the cache. This will make it hard to track a single server push lookup transaction status. The QuicChromiumClientSession/SpdySession calls HttpCacheLookupManager::OnPush, it could call OnPush multiple times while having the previous lookup not returned. I do plan to add some logging linked to the SERVER_PUSH_LOOKUP_TRANSACTION net_log though(in follow up CLs). That's why I decide to have a new source for LookupTransaction, it should be more straightforward to track the cache lookup results, quite similar to DISK_CACHE_DISK_CACHE_ENTRY. Does that make sense? This is the minimal effort to add some basic net log to verify server push cancellation works, I'll need to come back to add more granular NetLogs when server push is finally turning on. https://codereview.chromium.org/2675343002/diff/60001/net/http/http_cache_loo... net/http/http_cache_lookup_manager.cc:44: net_log_.EndEvent(NetLogEventType::SERVER_PUSH_LOOKUP_TRANSACTION); On 2017/02/07 22:33:42, eroman (slow) wrote: > What is the meaning for SERVER_PUSH_LOOKUP_TRANSACTION begin vs end? > > Normally if we have an EndEvent() in the destructor, it is to match a > BeginEvent() that took place in the constructor, however that is not the case > here, where the corresponding BeginEvent is part of StartLookup(). > > Should the Begin/End instead by done by StartLookup vs OnLookupComplete? (and > if there is a way to cancel, may have multiple paths to mark the "end") Done. Agreed that it's better to match the Begin/End event. I guess it's better to have the event logged in StartLookup since that method will be passed in a net log from the source and we could extract source dependency. https://codereview.chromium.org/2675343002/diff/60001/net/http/http_cache_loo... net/http/http_cache_lookup_manager.cc:91: base::MakeUnique<LookupTransaction>(std::move(push_helper), net_log_); On 2017/02/07 22:33:42, eroman (slow) wrote: > [optional] I found it a bit confusing that here (and in > LookupTransaction::StartLookup) there is a |net_log_| member variable as well as > a |net_log| argument, however they are different things. I suggest picking a > different name for the argument that explains how its role is different. Done. https://codereview.chromium.org/2675343002/diff/60001/net/http/http_cache_loo... File net/http/http_cache_lookup_manager_unittest.cc (right): https://codereview.chromium.org/2675343002/diff/60001/net/http/http_cache_loo... net/http/http_cache_lookup_manager_unittest.cc:221: NetLog net_log; On 2017/02/07 22:33:42, eroman (slow) wrote: > If you change some of these to use TestNetLog, the tests can be updated to > verify that the NetLog was written to. > > For the rest where no validation is done, the parameter passed to > HttpCacheLookupManager can be |nullptr|. Will do in a follow-up CL since I realized that the net log which will be written to id down in the HttpCacheLookupManager::LookupTransactions. https://codereview.chromium.org/2675343002/diff/60001/net/log/net_log_source_... File net/log/net_log_source_type_list.h (right): https://codereview.chromium.org/2675343002/diff/60001/net/log/net_log_source_... net/log/net_log_source_type_list.h:19: SOURCE_TYPE(SERVER_PUSH_LOOKUP_TRANSACTION) On 2017/02/07 22:33:42, eroman (slow) wrote: > This list is not sorted; we generally prefer adding them at the end (to preserve > ID stability). Done.
eroman@: friendly ping, ptal!
eroman@: Sorry I didn't realize that you're also OOO until this morning. Feel free to take a look when you get back :)
https://codereview.chromium.org/2675343002/diff/60001/net/http/http_cache_loo... File net/http/http_cache_lookup_manager.cc (right): https://codereview.chromium.org/2675343002/diff/60001/net/http/http_cache_loo... net/http/http_cache_lookup_manager.cc:39: net_log_(NetLogWithSource::Make( On 2017/02/08 00:40:53, Zhongyi Shi wrote: > On 2017/02/07 22:33:42, eroman (slow) wrote: > > Instead of creating a new source for this LookupTransaction, what if we output > a > > BEGIN event during StartLookup (to the provided net_log), and then a > > corresponding END event in OnLookupComplete. > > > > Is there a need to de-couple the LookupTransaction to an independent NetLog > > stream? > > SERVER_PUSH_LOOKUP_TRANSACTION is something similar to a DISK_CACHE_ENTRY. We do > need to provide a NetLogWithSource when run the cache transaction per > https://cs.chromium.org/chromium/src/net/http/http_transaction.h?l=71. It might > be possible that we could create a new source for the HttpCacheLookupManager or > reuse the caller's net log who calls HttpCacheLookupManager::OnPush. > > The HttpCacheLookupManager creates a LookupTransaction every time > HttpCacheLookupManager::OnPush is invoked. It's possible to have a few lookup > transactions pending at the same time, logged in the same net log since server > push cancellation lookup only requires read lock on the cache. This will make it > hard to track a single server push lookup transaction status. > > The QuicChromiumClientSession/SpdySession calls HttpCacheLookupManager::OnPush, > it could call OnPush multiple times while having the previous lookup not > returned. I do plan to add some logging linked to the > SERVER_PUSH_LOOKUP_TRANSACTION net_log though(in follow up CLs). > > That's why I decide to have a new source for LookupTransaction, it should be > more straightforward to track the cache lookup results, quite similar to > DISK_CACHE_DISK_CACHE_ENTRY. > > Does that make sense? This is the minimal effort to add some basic net log to > verify server push cancellation works, I'll need to come back to add more > granular NetLogs when server push is finally turning on. Sure, that makes sense then! https://codereview.chromium.org/2675343002/diff/100001/net/http/http_cache_lo... File net/http/http_cache_lookup_manager.cc (right): https://codereview.chromium.org/2675343002/diff/100001/net/http/http_cache_lo... net/http/http_cache_lookup_manager.cc:21: dict->SetString("push_url", push_helper->GetURL().spec()); [optional] Consider using |possibly_invalid_spec()| instead of |spec()|. The difference is what happens should GetURL() return an invalid URL. https://codereview.chromium.org/2675343002/diff/100001/net/http/http_cache_lo... net/http/http_cache_lookup_manager.cc:25: std::unique_ptr<base::Value> NetLogServerPushLookupCompleteCallback( [optional] You can remove this function and use NetLog::BoolCallback("found_in_cache", found_in_cache) in its place. https://codereview.chromium.org/2675343002/diff/100001/net/http/http_cache_lo... net/http/http_cache_lookup_manager.cc:63: NetLogEventType::SERVER_PUSH_LOOKUP_COMPLETE, Seems like we can remove this event, and instead put the |found_in_cache| parameter as part of the event logged below. WDYT? Otherwise we are always logging two events here. It is fairly common to attach parameters to the start/end events, see for instance: https://cs.chromium.org/chromium/src/net/log/net_log_event_type_list.h?type=c... (searching for "net_error" in that file will reveal several others) https://codereview.chromium.org/2675343002/diff/100001/net/http/http_cache_lo... net/http/http_cache_lookup_manager.cc:88: base::MakeUnique<LookupTransaction>(std::move(push_helper), net_log_); [optional] It is also common practice to add a breadcrumb in the opposite direction too -- which in this case would mean emitting an event to the session that called OnPush() telling it the NetLogSource of the created LookupTransaction. If I understood one of your previous responses, your plan is to add this in a follow-up CL? https://codereview.chromium.org/2675343002/diff/100001/net/http/http_cache_lo... net/http/http_cache_lookup_manager.cc:98: lookup->OnLookupComplete(rv == OK); [optional] Have you considered making the parameter to OnLookupComplete() be an error code rather than a boolean? Given all the callsites are interpreting completion in the same way (rv == OK) that may remove some duplication, and also allow logging the raw value of |rv| in the log (which may be handy in case it has some unexpected error value). https://codereview.chromium.org/2675343002/diff/100001/net/http/http_cache_lo... File net/http/http_cache_lookup_manager.h (right): https://codereview.chromium.org/2675343002/diff/100001/net/http/http_cache_lo... net/http/http_cache_lookup_manager.h:21: HttpCacheLookupManager(HttpCache* http_cache, NetLog* net_log); I don't believe this |net_log| parameter is needed, nor is the member variable HttpCacheLookupManager::net_log_. The only place that is using this parameter is HttpCacheLookupManager::OnPush(), in order to create a new NetLogWithSource. The callsite in OnPush() can instead use |source_net_log.net_log()|. https://codereview.chromium.org/2675343002/diff/100001/net/http/http_cache_lo... net/http/http_cache_lookup_manager.h:25: // |source_net_log| is owned by the caller of this method. Can you re-phrase the comment a bit? "owned" doesn't seem like the right choice of words as this is a copiable object. As far as parameter name, |source_net_log| is reasonable as it identifies the "source" of the push. Although given the type is a NetLogWithSource it may be a bit ambiguous. Would it make sense to call this |session_net_log| instead? (as I believe this is always going to identify a session that the push delegate was associated with) https://codereview.chromium.org/2675343002/diff/100001/net/http/http_cache_lo... net/http/http_cache_lookup_manager.h:45: // |source_net_log| is owned by the requester of server push cache lookup. Same comment as earlier regarding comment + parameter name. https://codereview.chromium.org/2675343002/diff/100001/net/http/http_cache_lo... net/http/http_cache_lookup_manager.h:59: NetLog* net_log_; Per comment above, I believe we delete this. https://codereview.chromium.org/2675343002/diff/100001/net/log/net_log_event_... File net/log/net_log_event_type_list.h (right): https://codereview.chromium.org/2675343002/diff/100001/net/log/net_log_event_... net/log/net_log_event_type_list.h:1310: // { Please clarify which event these parameters are attached to (in this case it is just on the start) https://codereview.chromium.org/2675343002/diff/100001/net/log/net_log_event_... net/log/net_log_event_type_list.h:1321: EVENT_TYPE(SERVER_PUSH_LOOKUP_COMPLETE) See comments in the .cc file about merging this with the event above. https://codereview.chromium.org/2675343002/diff/100001/net/spdy/server_push_d... File net/spdy/server_push_delegate.h (right): https://codereview.chromium.org/2675343002/diff/100001/net/spdy/server_push_d... net/spdy/server_push_delegate.h:33: // |source_net_log| is owned by the caller of this method. Same comment as earlier regarding comment + parameter name. https://codereview.chromium.org/2675343002/diff/100001/net/spdy/spdy_test_uti... File net/spdy/spdy_test_utils.h (right): https://codereview.chromium.org/2675343002/diff/100001/net/spdy/spdy_test_uti... net/spdy/spdy_test_utils.h:97: const NetLogWithSource& source) override; Consistency: in the other implementation overrides this is being called |source_net_log|.
Oh also: Thanks for including the sample log files with each patchset! They are a great way to see the overall structure of the information. The presentation in patchset #5 looks good, mostly I would just like to collapse the two completion events into 1 if possible (per the inline review comments). Cheers
Thanks a lot for all those suggestions, happy to improve the net logs though my original patch worked(poorly) :> New sample net logs is available at: https://goo.gl/xzQaAH PTAL! https://codereview.chromium.org/2675343002/diff/100001/net/http/http_cache_lo... File net/http/http_cache_lookup_manager.cc (right): https://codereview.chromium.org/2675343002/diff/100001/net/http/http_cache_lo... net/http/http_cache_lookup_manager.cc:21: dict->SetString("push_url", push_helper->GetURL().spec()); On 2017/02/10 23:57:47, eroman (slow) wrote: > [optional] Consider using |possibly_invalid_spec()| instead of |spec()|. > > The difference is what happens should GetURL() return an invalid URL. Done. https://codereview.chromium.org/2675343002/diff/100001/net/http/http_cache_lo... net/http/http_cache_lookup_manager.cc:25: std::unique_ptr<base::Value> NetLogServerPushLookupCompleteCallback( On 2017/02/10 23:57:47, eroman (slow) wrote: > [optional] You can remove this function and use > NetLog::BoolCallback("found_in_cache", found_in_cache) in its place. Done. https://codereview.chromium.org/2675343002/diff/100001/net/http/http_cache_lo... net/http/http_cache_lookup_manager.cc:63: NetLogEventType::SERVER_PUSH_LOOKUP_COMPLETE, On 2017/02/10 23:57:47, eroman (slow) wrote: > Seems like we can remove this event, and instead put the |found_in_cache| > parameter as part of the event logged below. WDYT? > > Otherwise we are always logging two events here. > > It is fairly common to attach parameters to the start/end events, see for > instance: > > https://cs.chromium.org/chromium/src/net/log/net_log_event_type_list.h?type=c... > > (searching for "net_error" in that file will reveal several others) Thanks for the pointer, this greatly simplified the log events. https://codereview.chromium.org/2675343002/diff/100001/net/http/http_cache_lo... net/http/http_cache_lookup_manager.cc:88: base::MakeUnique<LookupTransaction>(std::move(push_helper), net_log_); On 2017/02/10 23:57:47, eroman (slow) wrote: > [optional] It is also common practice to add a breadcrumb in the opposite > direction too -- which in this case would mean emitting an event to the session > that called OnPush() telling it the NetLogSource of the created > LookupTransaction. > > If I understood one of your previous responses, your plan is to add this in a > follow-up CL? Yup, I did plan to add this in a follow-up CL after the finch turns on this feature. https://codereview.chromium.org/2675343002/diff/100001/net/http/http_cache_lo... net/http/http_cache_lookup_manager.cc:98: lookup->OnLookupComplete(rv == OK); On 2017/02/10 23:57:47, eroman (slow) wrote: > [optional] Have you considered making the parameter to OnLookupComplete() be an > error code rather than a boolean? Given all the callsites are interpreting > completion in the same way (rv == OK) that may remove some duplication, and also > allow logging the raw value of |rv| in the log (which may be handy in case it > has some unexpected error value). Done. https://codereview.chromium.org/2675343002/diff/100001/net/http/http_cache_lo... File net/http/http_cache_lookup_manager.h (right): https://codereview.chromium.org/2675343002/diff/100001/net/http/http_cache_lo... net/http/http_cache_lookup_manager.h:21: HttpCacheLookupManager(HttpCache* http_cache, NetLog* net_log); On 2017/02/10 23:57:47, eroman (slow) wrote: > I don't believe this |net_log| parameter is needed, nor is the member variable > HttpCacheLookupManager::net_log_. > > The only place that is using this parameter is HttpCacheLookupManager::OnPush(), > in order to create a new NetLogWithSource. > > The callsite in OnPush() can instead use |source_net_log.net_log()|. Done. https://codereview.chromium.org/2675343002/diff/100001/net/http/http_cache_lo... net/http/http_cache_lookup_manager.h:25: // |source_net_log| is owned by the caller of this method. On 2017/02/10 23:57:47, eroman (slow) wrote: > Can you re-phrase the comment a bit? "owned" doesn't seem like the right choice > of words as this is a copiable object. > > As far as parameter name, |source_net_log| is reasonable as it identifies the > "source" of the push. Although given the type is a NetLogWithSource it may be a > bit ambiguous. > > Would it make sense to call this |session_net_log| instead? (as I believe this > is always going to identify a session that the push delegate was associated > with) Yup, this will always be called from a session: either spdy session or a quic session. https://codereview.chromium.org/2675343002/diff/100001/net/http/http_cache_lo... net/http/http_cache_lookup_manager.h:45: // |source_net_log| is owned by the requester of server push cache lookup. On 2017/02/10 23:57:47, eroman (slow) wrote: > Same comment as earlier regarding comment + parameter name. Done. https://codereview.chromium.org/2675343002/diff/100001/net/http/http_cache_lo... net/http/http_cache_lookup_manager.h:59: NetLog* net_log_; On 2017/02/10 23:57:47, eroman (slow) wrote: > Per comment above, I believe we delete this. Done. https://codereview.chromium.org/2675343002/diff/100001/net/log/net_log_event_... File net/log/net_log_event_type_list.h (right): https://codereview.chromium.org/2675343002/diff/100001/net/log/net_log_event_... net/log/net_log_event_type_list.h:1310: // { On 2017/02/10 23:57:47, eroman (slow) wrote: > Please clarify which event these parameters are attached to (in this case it is > just on the start) Done. https://codereview.chromium.org/2675343002/diff/100001/net/log/net_log_event_... net/log/net_log_event_type_list.h:1321: EVENT_TYPE(SERVER_PUSH_LOOKUP_COMPLETE) On 2017/02/10 23:57:47, eroman (slow) wrote: > See comments in the .cc file about merging this with the event above. Done. https://codereview.chromium.org/2675343002/diff/100001/net/spdy/server_push_d... File net/spdy/server_push_delegate.h (right): https://codereview.chromium.org/2675343002/diff/100001/net/spdy/server_push_d... net/spdy/server_push_delegate.h:33: // |source_net_log| is owned by the caller of this method. On 2017/02/10 23:57:47, eroman (slow) wrote: > Same comment as earlier regarding comment + parameter name. Done. https://codereview.chromium.org/2675343002/diff/100001/net/spdy/spdy_test_uti... File net/spdy/spdy_test_utils.h (right): https://codereview.chromium.org/2675343002/diff/100001/net/spdy/spdy_test_uti... net/spdy/spdy_test_utils.h:97: const NetLogWithSource& source) override; On 2017/02/10 23:57:47, eroman (slow) wrote: > Consistency: in the other implementation overrides this is being called > |source_net_log|. Done.
LGTM! https://codereview.chromium.org/2675343002/diff/120001/net/http/http_cache_lo... File net/http/http_cache_lookup_manager.h (right): https://codereview.chromium.org/2675343002/diff/120001/net/http/http_cache_lo... net/http/http_cache_lookup_manager.h:21: HttpCacheLookupManager(HttpCache* http_cache); nit: Mark this as "explicit" https://codereview.chromium.org/2675343002/diff/120001/net/log/net_log_event_... File net/log/net_log_event_type_list.h (right): https://codereview.chromium.org/2675343002/diff/120001/net/log/net_log_event_... net/log/net_log_event_type_list.h:1318: // If the transaction doesn't find the resource in cache, then the END phase nit: de-indent this by two spaces?
Thanks Eric and Ryan for helping the review, landing now. https://codereview.chromium.org/2675343002/diff/120001/net/http/http_cache_lo... File net/http/http_cache_lookup_manager.h (right): https://codereview.chromium.org/2675343002/diff/120001/net/http/http_cache_lo... net/http/http_cache_lookup_manager.h:21: HttpCacheLookupManager(HttpCache* http_cache); On 2017/02/11 02:44:36, eroman (slow) wrote: > nit: Mark this as "explicit" Done. https://codereview.chromium.org/2675343002/diff/120001/net/log/net_log_event_... File net/log/net_log_event_type_list.h (right): https://codereview.chromium.org/2675343002/diff/120001/net/log/net_log_event_... net/log/net_log_event_type_list.h:1318: // If the transaction doesn't find the resource in cache, then the END phase On 2017/02/11 02:44:36, eroman (slow) wrote: > nit: de-indent this by two spaces? Done. I forgot to upload the patch set which fixes the typo.
The CQ bit was checked by zhongyi@chromium.org
The patchset sent to the CQ was uploaded after l-g-t-m from rch@chromium.org, eroman@chromium.org Link to the patchset: https://codereview.chromium.org/2675343002/#ps160001 (title: "sync with master")
CQ is trying da patch. Follow status at https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...
CQ is committing da patch.
Bot data: {"patchset_id": 160001, "attempt_start_ts": 1486806152620710,
"parent_rev": "6445a816eea59b22caa418e00be12f1ccf9be21c", "commit_rev":
"d2a4caef5b812732dce7baa2d56716f8ae1f8cd2"}
Message was sent while issue was closed.
Description was changed from ========== Server push cancellation: add NetLogs to track cache lookup transaction for server push. BUG=232040 ========== to ========== Server push cancellation: add NetLogs to track cache lookup transaction for server push. BUG=232040 Review-Url: https://codereview.chromium.org/2675343002 Cr-Commit-Position: refs/heads/master@{#449854} Committed: https://chromium.googlesource.com/chromium/src/+/d2a4caef5b812732dce7baa2d567... ==========
Message was sent while issue was closed.
Committed patchset #8 (id:160001) as https://chromium.googlesource.com/chromium/src/+/d2a4caef5b812732dce7baa2d567... |
|||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
