|
|
Chromium Code Reviews
DescriptionAdd traces to HttpCache::Transaction to make it easier to follow URLRequests
It's difficult to see how URLRequests interact on the IO thread. Adding
traces to the HttpCache::Transaction illuminates what's going on. These
traces were used to detect the performance issue in
https://crbug.com/655585 and it seems generally beneficial to keep them
in master.
BUG=657432
Committed: https://crrev.com/255440ce6e8343609c1918c16e97885a14f9ba67
Cr-Commit-Position: refs/heads/master@{#433316}
Patch Set 1 #
Total comments: 5
Patch Set 2 : Address comments from PS1 #Patch Set 3 : Rebase and use normal trace event #Patch Set 4 : Rename #
Total comments: 1
Patch Set 5 : Change to io category #Patch Set 6 : Rebase #Patch Set 7 : Fix ref #Messages
Total messages: 71 (40 generated)
jkarlin@chromium.org changed reviewers: + xunjieli@chromium.org
xunjieli@ PTAL at everything, many thanks!
Description was changed from ========== Add traces to HttpCache::Transaction to make it easier to follow URLRequests It's difficult to see how URLRequests interact on the IO thread. Adding traces to the HttpCache::Transaction illuminates what's going on. These traces were used to detect the performance issue in https://crbug.com/655585 and it seems generally beneficial to keep them in master. BUG= ========== to ========== Add traces to HttpCache::Transaction to make it easier to follow URLRequests It's difficult to see how URLRequests interact on the IO thread. Adding traces to the HttpCache::Transaction illuminates what's going on. These traces were used to detect the performance issue in https://crbug.com/655585 and it seems generally beneficial to keep them in master. BUG=657432 ==========
On 2016/10/19 15:47:03, jkarlin wrote: > xunjieli@ PTAL at everything, many thanks! Looks good. Could you point me to the documentation of flow events? want to make sure I understand how it works.
On 2016/10/19 16:04:15, xunjieli wrote: > On 2016/10/19 15:47:03, jkarlin wrote: > > xunjieli@ PTAL at everything, many thanks! > > Looks good. Could you point me to the documentation of flow events? want to make > sure I understand how it works. I... can't find any. I just looked at other code. Will keep searching. A trace w/ only FLOW_IN starts the flow (constructor) and the flow ends on the event with only a FLOW_OUT event (destructor).
On 2016/10/19 17:18:53, jkarlin wrote: > On 2016/10/19 16:04:15, xunjieli wrote: > > On 2016/10/19 15:47:03, jkarlin wrote: > > > xunjieli@ PTAL at everything, many thanks! > > > > Looks good. Could you point me to the documentation of flow events? want to > make > > sure I understand how it works. > > I... can't find any. I just looked at other code. Will keep searching. > > A trace w/ only FLOW_IN starts the flow (constructor) and the flow ends on the > event with only a FLOW_OUT event (destructor). +cc caseq@ who might know where to find some docs.
On 2016/10/19 17:25:24, jkarlin wrote: > On 2016/10/19 17:18:53, jkarlin wrote: > > On 2016/10/19 16:04:15, xunjieli wrote: > > > On 2016/10/19 15:47:03, jkarlin wrote: > > > > xunjieli@ PTAL at everything, many thanks! > > > > > > Looks good. Could you point me to the documentation of flow events? want to > > make > > > sure I understand how it works. > > > > I... can't find any. I just looked at other code. Will keep searching. > > > > A trace w/ only FLOW_IN starts the flow (constructor) and the flow ends on the > > event with only a FLOW_OUT event (destructor). Thanks. What does passing "TRACE_EVENT_FLAG_FLOW_IN | TRACE_EVENT_FLAG_FLOW_OUT" mean? It's both start of the flow and end of the flow? > > +cc caseq@ who might know where to find some docs.
On 2016/10/19 17:30:43, xunjieli wrote: > On 2016/10/19 17:25:24, jkarlin wrote: > > On 2016/10/19 17:18:53, jkarlin wrote: > > > On 2016/10/19 16:04:15, xunjieli wrote: > > > > On 2016/10/19 15:47:03, jkarlin wrote: > > > > > xunjieli@ PTAL at everything, many thanks! > > > > > > > > Looks good. Could you point me to the documentation of flow events? want > to > > > make > > > > sure I understand how it works. > > > > > > I... can't find any. I just looked at other code. Will keep searching. > > > > > > A trace w/ only FLOW_IN starts the flow (constructor) and the flow ends on > the > > > event with only a FLOW_OUT event (destructor). > > Thanks. What does passing "TRACE_EVENT_FLAG_FLOW_IN | TRACE_EVENT_FLAG_FLOW_OUT" > mean? It's both start of the flow and end of the flow? > > > > > +cc caseq@ who might know where to find some docs. It means that there is an event before that leads into this one, and there will be another after. In the end, once you go to about:tracing, you can click on an event and a red arrow will point to when the next and previous event are run in the trace. It's super nice.
On 2016/10/19 17:33:53, jkarlin wrote: > On 2016/10/19 17:30:43, xunjieli wrote: > > On 2016/10/19 17:25:24, jkarlin wrote: > > > On 2016/10/19 17:18:53, jkarlin wrote: > > > > On 2016/10/19 16:04:15, xunjieli wrote: > > > > > On 2016/10/19 15:47:03, jkarlin wrote: > > > > > > xunjieli@ PTAL at everything, many thanks! > > > > > > > > > > Looks good. Could you point me to the documentation of flow events? want > > to > > > > make > > > > > sure I understand how it works. > > > > > > > > I... can't find any. I just looked at other code. Will keep searching. > > > > > > > > A trace w/ only FLOW_IN starts the flow (constructor) and the flow ends on > > the > > > > event with only a FLOW_OUT event (destructor). > > > > Thanks. What does passing "TRACE_EVENT_FLAG_FLOW_IN | > TRACE_EVENT_FLAG_FLOW_OUT" > > mean? It's both start of the flow and end of the flow? > > > > > > > > +cc caseq@ who might know where to find some docs. > > It means that there is an event before that leads into this one, and there will > be another after. I see. Makes sense. These new events will be under category "net." I didn't add that category (I did the "netlog" category), so I am not familiar with what "net" is used for currently. If these traces are useful, then LGTM. > > In the end, once you go to about:tracing, you can click on an event and a red > arrow will point to when the next and previous event are run in the trace. It's > super nice.
jkarlin@chromium.org changed reviewers: + caseq@chromium.org
Thanks Helen! caseq@ PTAL at the trace events to make sure that what I'm doing is sane, thanks!
Here's the flow event docs: https://docs.google.com/document/d/1CvAClvFfyA5R-PhYUmn5OOQtYMH4h6I0nSsKchNAySU But it feels so far that this should rather be TRACE_EVENT_NESTABLE_ASYNC_xxx. https://codereview.chromium.org/2432283003/diff/1/net/cert/x509_certificate.cc File net/cert/x509_certificate.cc (right): https://codereview.chromium.org/2432283003/diff/1/net/cert/x509_certificate.c... net/cert/x509_certificate.cc:239: TRACE_EVENT0("net", "X509Certificate::CreateFromDERCertChain"); Is this intended to be a part of this CL? https://codereview.chromium.org/2432283003/diff/1/net/http/http_cache_transac... File net/http/http_cache_transaction.cc (right): https://codereview.chromium.org/2432283003/diff/1/net/http/http_cache_transac... net/http/http_cache_transaction.cc:193: TRACE_EVENT_WITH_FLOW0("net", "HttpCache::Transaction::Transaction", this, Not sure if you really want to have flow event here. Looks more like a plain ASYNC event to me. Also, can you use a more stable and, perhaps, human readable event name for that -- e.g. something like HTTPCacheTransaction? The idea is to use the names that would persist through refactoring. Another thing is that it would be useful to have some reference to the resource request that resulted in this transaction -- so I wonder if you can instead move this to Start and perhaps use netlog's source id instead of `this' as an id?
https://codereview.chromium.org/2432283003/diff/1/net/http/http_cache_transac... File net/http/http_cache_transaction.cc (right): https://codereview.chromium.org/2432283003/diff/1/net/http/http_cache_transac... net/http/http_cache_transaction.cc:193: TRACE_EVENT_WITH_FLOW0("net", "HttpCache::Transaction::Transaction", this, On 2016/10/20 21:23:31, caseq wrote: > Not sure if you really want to have flow event here. Looks more like a plain > ASYNC event to me. > > Also, can you use a more stable and, perhaps, human readable event name for that > -- e.g. something like HTTPCacheTransaction? The idea is to use the names that > would persist through refactoring. > > Another thing is that it would be useful to have some reference to the resource > request that resulted in this transaction -- so I wonder if you can instead move > this to Start and perhaps use netlog's source id instead of `this' as an id? I'd actually prefer full function names over humable readable counterparts. The reason is that for heap profiling, memory infra can reuse these trace events to construct heap tree. See https://docs.google.com/document/d/1L_j3CjtXtCXec4ecFYK3J1BXBkK30ZtfVTEOr0Q43...
On 2016/10/20 at 21:33:12, xunjieli wrote: > https://codereview.chromium.org/2432283003/diff/1/net/http/http_cache_transac... > File net/http/http_cache_transaction.cc (right): > > https://codereview.chromium.org/2432283003/diff/1/net/http/http_cache_transac... > net/http/http_cache_transaction.cc:193: TRACE_EVENT_WITH_FLOW0("net", "HttpCache::Transaction::Transaction", this, > On 2016/10/20 21:23:31, caseq wrote: > > Not sure if you really want to have flow event here. Looks more like a plain > > ASYNC event to me. > > > > Also, can you use a more stable and, perhaps, human readable event name for that > > -- e.g. something like HTTPCacheTransaction? The idea is to use the names that > > would persist through refactoring. > > > > Another thing is that it would be useful to have some reference to the resource > > request that resulted in this transaction -- so I wonder if you can instead move > > this to Start and perhaps use netlog's source id instead of `this' as an id? > > I'd actually prefer full function names over humable readable counterparts. The reason is that for heap profiling, memory infra can reuse these trace events to construct heap tree. > > See https://docs.google.com/document/d/1L_j3CjtXtCXec4ecFYK3J1BXBkK30ZtfVTEOr0Q43... In the case of these particular events, I think most will likely end up being an instant events, so they won't be on the stack.
The CQ bit was checked by jkarlin@chromium.org to run a CQ dry run
Patchset #2 (id:20001) has been deleted
Thanks! caseq@ PTAL https://codereview.chromium.org/2432283003/diff/1/net/cert/x509_certificate.cc File net/cert/x509_certificate.cc (right): https://codereview.chromium.org/2432283003/diff/1/net/cert/x509_certificate.c... net/cert/x509_certificate.cc:239: TRACE_EVENT0("net", "X509Certificate::CreateFromDERCertChain"); On 2016/10/20 21:23:31, caseq wrote: > Is this intended to be a part of this CL? Yes, simply because it's a very expensive operation that we need to track, though I admit it doesn't fit with the rest. https://codereview.chromium.org/2432283003/diff/1/net/http/http_cache_transac... File net/http/http_cache_transaction.cc (right): https://codereview.chromium.org/2432283003/diff/1/net/http/http_cache_transac... net/http/http_cache_transaction.cc:193: TRACE_EVENT_WITH_FLOW0("net", "HttpCache::Transaction::Transaction", this, On 2016/10/20 21:23:31, caseq wrote: > Not sure if you really want to have flow event here. Looks more like a plain > ASYNC event to me. We want the flow arrows on the IO thread. This way we can see what tasks run between the transaction events quite clearly. > > Also, can you use a more stable and, perhaps, human readable event name for that > -- e.g. something like HTTPCacheTransaction? The idea is to use the names that > would persist through refactoring. I don't have strong opinions about this. It seems like perhaps, as Helen said, full names have an advantage? The code here is quite stable, but I can't guarantee it won't refactor. > > Another thing is that it would be useful to have some reference to the resource > request that resulted in this transaction -- so I wonder if you can instead move > this to Start and perhaps use netlog's source id instead of `this' as an id? Done. Thanks!
Dry run: CQ is trying da patch. Follow status at https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...
The CQ bit was unchecked by commit-bot@chromium.org
Dry run: Try jobs failed on following builders: android_arm64_dbg_recipe on master.tryserver.chromium.android (JOB_FAILED, https://build.chromium.org/p/tryserver.chromium.android/builders/android_arm6...)
caseq: PTAL, thanks!
caseq@chromium.org changed reviewers: + fmeawad@google.com, nduca@chromium.org
caseq@chromium.org changed reviewers: + fmeawad@chromium.org - fmeawad@google.com
Sorry about delay -- I realize that the boundary between async and flow events is somewhat blurred and that you've got a case where you'd like to see your events within the context of other events on the same thread. Yet I think this does not scale well -- basically, those arrows represent considerable visual burden and the trace is going to be hard to read if everyone starts doing this -- in fact, this already looks rather unreadable to me on a real page (I tried it on theverge.com). We discussed this with the tracing team (+Nat & Fadi on that) and the consensus was that we'd like to reserve the usage of flow events for interactions between major modules and cases when a task is handed over between different threads and processes -- things like posting tasks or sending messages for instance, and in this case a more appropriate event to use would be nestable async events. I think we should be able to improve the UX of async events in the trace viewer that would address your use case without introducing too much noise -- for example show async steps "inline" with regards to regular thread events in addition of showing async track (we actually do this in DevTools, though they're still too small to see) and highlight all inlined steps of an async event when user hovers any part of the async event. Do you think this will work for you -- or maybe you have some other visualization tricks in mind? Also, on the subject of event names -- we'd like to reserve the use of namespaces/classes/methods name in event names for debugging only -- so if you feel a strong need to use these, perhaps a more specific debug category name would be appropriate. However, if the need be to expose this to any benchmark or other external tool (e.g. DevTools, where I think we would eventually want this), we would have to change the names to something that we can expect to remain stable. I think if you choose event names that are fairly specific, the code search will make those as easy to locate as classes/methods.
On 2016/10/31 18:42:00, caseq wrote: > Sorry about delay -- I realize that the boundary between async and flow events > is somewhat blurred and that you've got a case where you'd like to see your > events within the context of other events on the same thread. Yet I think this > does not scale well -- basically, those arrows represent considerable visual > burden and the trace is going to be hard to read if everyone starts doing this > -- in fact, this already looks rather unreadable to me on a real page (I tried > it on http://theverge.com). > We discussed this with the tracing team (+Nat & Fadi on that) and the consensus > was that we'd like to reserve the usage of flow events for interactions between > major modules and cases when a task is handed over between different threads and > processes -- things like posting tasks or sending messages for instance, and in > this case a more appropriate event to use would be nestable async events. > I think we should be able to improve the UX of async events in the trace viewer > that would address your use case without introducing too much noise -- for > example show async steps "inline" with regards to regular thread events in > addition of showing async track (we actually do this in DevTools, though they're > still too small to see) and highlight all inlined steps of an async event when > user hovers any part of the async event. Do you think this will work for you -- > or maybe you have some other visualization tricks in mind? > > Also, on the subject of event names -- we'd like to reserve the use of > namespaces/classes/methods name in event names for debugging only -- so if you > feel a strong need to use these, perhaps a more specific debug category name > would be appropriate. However, if the need be to expose this to any benchmark or > other external tool (e.g. DevTools, where I think we would eventually want > this), we would have to change the names to something that we can expect to > remain stable. I think if you choose event names that are fairly specific, the > code search will make those as easy to locate as classes/methods. Sorry for hijacking this review, but I think the tracing team needs to do something about the existing confusion around flows. If we decide flows are just another name for arrows in the UI, then yes, we should be careful about excessive usage BUT we also should introduce a way of indicating logical dependencies; async events are not designed for that. About this CL specifically, I think as long as all events with a given NetLog source ID are emitted from the same thread (I don't have enough expertise to tell) or somehow it is guaranteed that they don't nest in an invalid way, it's OK to use nestable async events.
> Sorry about delay -- I realize that the boundary between async and flow events > is somewhat blurred and that you've got a case where you'd like to see your > events within the context of other events on the same thread. Yet I think this > does not scale well -- basically, those arrows represent considerable visual > burden and the trace is going to be hard to read if everyone starts doing this > -- in fact, this already looks rather unreadable to me on a real page (I tried > it on http://theverge.com). https://docs.google.com/document/d/1Aa7OKFRdtmn4IFzgHYfqeqk5lnyTiv4jkwCzMoAlr... uses a screenshot of this CL, where it's immediately evident how helpful the arrows are. The async events are difficult to parse, particularly in determining what events occurred between various steps. Yes, I can highlight an event and then scroll down, but it's actually not obvious how to return to the event (how far should I scroll back up? I suppose that's a UX issue). I'm not very well versed in tracing, but how does adding more flow events add visual burden? Don't you have to select an event, and click the "following events" in order to see the arrows? And shouldn't you only see arrows for that flow id? > We discussed this with the tracing team (+Nat & Fadi on that) and the consensus > was that we'd like to reserve the usage of flow events for interactions between > major modules and cases when a task is handed over between different threads and > processes -- things like posting tasks or sending messages for instance, and in > this case a more appropriate event to use would be nestable async events. That seems to limit the utility of flows. Is there a resource issue here? Are flows expensive compared to async? My own brief experience seems to show that async events significantly burden the tracing UX, more so than flows. > I think we should be able to improve the UX of async events in the trace viewer > that would address your use case without introducing too much noise -- for > example show async steps "inline" with regards to regular thread events in > addition of showing async track (we actually do this in DevTools, though they're > still too small to see) and highlight all inlined steps of an async event when > user hovers any part of the async event. Do you think this will work for you -- > or maybe you have some other visualization tricks in mind? Yes, this would help immensely. > > Also, on the subject of event names -- we'd like to reserve the use of > namespaces/classes/methods name in event names for debugging only -- so if you > feel a strong need to use these, perhaps a more specific debug category name > would be appropriate. However, if the need be to expose this to any benchmark or > other external tool (e.g. DevTools, where I think we would eventually want > this), we would have to change the names to something that we can expect to > remain stable. I think if you choose event names that are fairly specific, the > code search will make those as easy to locate as classes/methods. SGTM.
On 2016/11/01 13:39:25, jkarlin wrote: > > Sorry about delay -- I realize that the boundary between async and flow events > > is somewhat blurred and that you've got a case where you'd like to see your > > events within the context of other events on the same thread. Yet I think this > > does not scale well -- basically, those arrows represent considerable visual > > burden and the trace is going to be hard to read if everyone starts doing this > > -- in fact, this already looks rather unreadable to me on a real page (I tried > > it on http://theverge.com). > > https://docs.google.com/document/d/1Aa7OKFRdtmn4IFzgHYfqeqk5lnyTiv4jkwCzMoAlr... > uses a screenshot of this CL, where it's immediately evident how helpful the > arrows are. I assume the screenshot there was made on a trivial page. Here's one from the real world: https://drive.google.com/file/d/0B_yi9xtujhXSTlFuR1Y1bW5OaFE > The async events are difficult to parse, particularly in determining > what events occurred between various steps. Yup, I agree here, but I think this is what we need to fix. > I'm not very well versed in tracing, but how does adding more flow events add > visual burden? Please see my screenshot -- basically, there are multiple transactions happening concurrently and we end up having a mess of overlapping and intersecting arrows. And by the time you zoom in to see the source or landing point of an arrow in better detail, the other end is out of viewport. > Don't you have to select an event, and click the "following > events" in order to see the arrows? > And shouldn't you only see arrows for that flow id? Outside of the case when you first select a range and then hover over the list of flow events in the drawer, it's either all arrows or no arrows. I guess the "hover for arrows" mode we could also have for async slices. > That seems to limit the utility of flows. Is there a resource issue here? Are > flows expensive compared to async? My own brief experience seems to show that > async events significantly burden the tracing UX, more so than flows. No performance issue here, just the UX. Another concern is that we're working on having network activity traced from different components, spanning blink to content to browser and the net stack, appearing on the same async track, and it would naturally make sense to have cache transactions as part of this track.
caseq@ PTAL Okay, I've changed the names to HttpCacheTransaction. I've made the trace events normal (instead of async or flow) as that's what I was really going after (the arrows would have been nice but I can live without).
On 2016/11/10 16:51:53, jkarlin wrote: > caseq@ PTAL > > Okay, I've changed the names to HttpCacheTransaction. > Some events are named as "HttpCacheTransaction", some are still under "HttpCache::Transaction". Can we be consistent? I prefer the second format since that's other net trace events are using full qualified names. If I do a codesearch with "HttpCacheTransaction", there is no meaningful result. For someone who isn't familiar with the stack, if codesearch fails to generate result then that's not helping... Just my 2cents. > I've made the trace events normal (instead of async or flow) as that's what I > was really going after (the arrows would have been nice but I can live without).
The CQ bit was checked by jkarlin@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...
On 2016/11/10 17:01:15, xunjieli wrote: > On 2016/11/10 16:51:53, jkarlin wrote: > > caseq@ PTAL > > > > Okay, I've changed the names to HttpCacheTransaction. > > > > Some events are named as "HttpCacheTransaction", some are still under > "HttpCache::Transaction". Can we be consistent? I prefer the second format since > that's other net trace events are using full qualified names. Whoops, bad search-and-replace. Thanks Helen! I've switched to HttpCacheTransaction as caseq had a strong preference. > > If I do a codesearch with "HttpCacheTransaction", there is no meaningful result. > For someone who isn't familiar with the stack, if codesearch fails to generate > result then that's not helping... Just my 2cents. But once this lands it'll show you the particular trace you're looking for.
The CQ bit was unchecked by commit-bot@chromium.org
Dry run: This issue passed the CQ dry run.
https://codereview.chromium.org/2432283003/diff/80001/net/http/http_cache_tra... File net/http/http_cache_transaction.cc (right): https://codereview.chromium.org/2432283003/diff/80001/net/http/http_cache_tra... net/http/http_cache_transaction.cc:193: TRACE_EVENT0("net", "HttpCacheTransaction::Transaction"); Hmm... This does not look quite what I thought we discussed. I think we care more for the wall duration of the transaction in general, rather than the CPU overhead of different stages of it, isn't this so? So my idea was that this should rather be TRACE_EVENT_NESTABLE_ASYNC_xxx() and use common id to bind the different stages of transaction together.
On 2016/11/10 21:37:43, caseq wrote: > https://codereview.chromium.org/2432283003/diff/80001/net/http/http_cache_tra... > File net/http/http_cache_transaction.cc (right): > > https://codereview.chromium.org/2432283003/diff/80001/net/http/http_cache_tra... > net/http/http_cache_transaction.cc:193: TRACE_EVENT0("net", > "HttpCacheTransaction::Transaction"); > Hmm... This does not look quite what I thought we discussed. I think we care > more for the wall duration of the transaction in general, rather than the CPU > overhead of different stages of it, isn't this so? This CL is about annotating the IO thread so that one can understand what operation is occurring. In the event that the CPU time is high, one can see what work is being done. The flows (a nice-to-have) would have been to show the gaps between operations in a single transaction.
csharrison@chromium.org changed reviewers: + csharrison@chromium.org
drive-by: these traces will be very useful to have for writing trace based benchmarks to avoid IO thread CPU regressions.
On 2016/11/14 15:33:37, jkarlin wrote: > > This CL is about annotating the IO thread so that one can understand what > operation is occurring. In the event that the CPU time is high, one can see what > work is being done. The flows (a nice-to-have) would have been to show the gaps > between operations in a single transaction. Ah, so it's not about exposing cache transaction durations? I wonder why would you use "net" category then -- presumably, when one is looking for the reason the io thread is thrashed, they should not be guessing what categories to use. lgtm, but please consider a more generic category for this -- perhaps something like "io" would do? > drive-by: these traces will be very useful to have for writing trace based > benchmarks to avoid IO thread CPU regressions. @charrison: I think this case is better covered by "toplevel" events -- these are supposed to have 100% coverage (at least of anything that comes through message loop), whereas the more specific events could be just missing.
On 2016/11/17 01:58:59, caseq wrote: > On 2016/11/14 15:33:37, jkarlin wrote: > > > > > This CL is about annotating the IO thread so that one can understand what > > operation is occurring. In the event that the CPU time is high, one can see > what > > work is being done. The flows (a nice-to-have) would have been to show the > gaps > > between operations in a single transaction. > > Ah, so it's not about exposing cache transaction durations? I wonder why would > you use "net" category then -- presumably, when one is looking for the reason > the io thread is thrashed, they should not be guessing what categories to use. > > lgtm, but please consider a more generic category for this -- perhaps something > like "io" would do? > > > drive-by: these traces will be very useful to have for writing trace based > > benchmarks to avoid IO thread CPU regressions. > > @charrison: I think this case is better covered by "toplevel" events -- these > are supposed to have 100% coverage (at least of anything that comes through > message loop), whereas the more specific events could be just missing. toplevel events are important, but it is very hard to see what is actually happening with them. If the tracing UI is smart enough to annotate the toplevel with the actual function name being run, it would make them a lot more useful to me.
The CQ bit was checked by jkarlin@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...
The CQ bit was unchecked by commit-bot@chromium.org
Dry run: CLs for remote refs other than refs/pending/heads/master must contain NOTRY=true and NOPRESUBMIT=true in order for the CQ to process them
On 2016/11/17 03:13:40, Charlie Harrison wrote: > On 2016/11/17 01:58:59, caseq wrote: > > On 2016/11/14 15:33:37, jkarlin wrote: > > > > > > > > This CL is about annotating the IO thread so that one can understand what > > > operation is occurring. In the event that the CPU time is high, one can see > > what > > > work is being done. The flows (a nice-to-have) would have been to show the > > gaps > > > between operations in a single transaction. > > > > Ah, so it's not about exposing cache transaction durations? I wonder why would > > you use "net" category then -- presumably, when one is looking for the reason > > the io thread is thrashed, they should not be guessing what categories to use. > > > > lgtm, but please consider a more generic category for this -- perhaps > something > > like "io" would do? Hmm, that's a fair point. Okay, IO it is. > > > > > drive-by: these traces will be very useful to have for writing trace based > > > benchmarks to avoid IO thread CPU regressions. > > > > @charrison: I think this case is better covered by "toplevel" events -- these > > are supposed to have 100% coverage (at least of anything that comes through > > message loop), whereas the more specific events could be just missing. > toplevel events are important, but it is very hard to see what is actually > happening with them. If the tracing UI is smart enough to annotate the toplevel > with the actual function name being run, it would make them a lot more useful to > me. Agree that it would be great if we could get the function being run in toplevel.
The CQ bit was checked by jkarlin@chromium.org to run a CQ dry run
Patchset #5 (id:100001) has been deleted
Dry run: CQ is trying da patch. Follow status at https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...
The CQ bit was unchecked by commit-bot@chromium.org
Dry run: CLs for remote refs other than refs/pending/heads/master must contain NOTRY=true and NOPRESUBMIT=true in order for the CQ to process them
The CQ bit was checked by jkarlin@chromium.org
The patchset sent to the CQ was uploaded after l-g-t-m from xunjieli@chromium.org, caseq@chromium.org Link to the patchset: https://codereview.chromium.org/2432283003/#ps120001 (title: "Change to io category")
CQ is trying da patch. Follow status at https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...
The CQ bit was unchecked by commit-bot@chromium.org
CLs for remote refs other than refs/pending/heads/master must contain NOTRY=true and NOPRESUBMIT=true in order for the CQ to process them
The CQ bit was checked by jkarlin@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...
The CQ bit was unchecked by commit-bot@chromium.org
Dry run: CLs for remote refs other than refs/pending/heads/master must contain NOTRY=true and NOPRESUBMIT=true in order for the CQ to process them
The CQ bit was checked by jkarlin@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...
The CQ bit was unchecked by commit-bot@chromium.org
Dry run: Try jobs failed on following builders: ios-device on master.tryserver.chromium.mac (JOB_FAILED, http://build.chromium.org/p/tryserver.chromium.mac/builders/ios-device/builds...)
Patchset #7 (id:160001) has been deleted
The CQ bit was checked by jkarlin@chromium.org
The patchset sent to the CQ was uploaded after l-g-t-m from caseq@chromium.org, xunjieli@chromium.org Link to the patchset: https://codereview.chromium.org/2432283003/#ps180001 (title: "Fix ref")
CQ is trying da patch. Follow status at https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...
Message was sent while issue was closed.
Description was changed from ========== Add traces to HttpCache::Transaction to make it easier to follow URLRequests It's difficult to see how URLRequests interact on the IO thread. Adding traces to the HttpCache::Transaction illuminates what's going on. These traces were used to detect the performance issue in https://crbug.com/655585 and it seems generally beneficial to keep them in master. BUG=657432 ========== to ========== Add traces to HttpCache::Transaction to make it easier to follow URLRequests It's difficult to see how URLRequests interact on the IO thread. Adding traces to the HttpCache::Transaction illuminates what's going on. These traces were used to detect the performance issue in https://crbug.com/655585 and it seems generally beneficial to keep them in master. BUG=657432 ==========
Message was sent while issue was closed.
Committed patchset #7 (id:180001)
Message was sent while issue was closed.
Description was changed from ========== Add traces to HttpCache::Transaction to make it easier to follow URLRequests It's difficult to see how URLRequests interact on the IO thread. Adding traces to the HttpCache::Transaction illuminates what's going on. These traces were used to detect the performance issue in https://crbug.com/655585 and it seems generally beneficial to keep them in master. BUG=657432 ========== to ========== Add traces to HttpCache::Transaction to make it easier to follow URLRequests It's difficult to see how URLRequests interact on the IO thread. Adding traces to the HttpCache::Transaction illuminates what's going on. These traces were used to detect the performance issue in https://crbug.com/655585 and it seems generally beneficial to keep them in master. BUG=657432 Committed: https://crrev.com/255440ce6e8343609c1918c16e97885a14f9ba67 Cr-Commit-Position: refs/heads/master@{#433316} ==========
Message was sent while issue was closed.
Patchset 7 (id:??) landed as https://crrev.com/255440ce6e8343609c1918c16e97885a14f9ba67 Cr-Commit-Position: refs/heads/master@{#433316} |
