Chromium Code Reviews
|
|
Chromium Code Reviews
Issue
2821253002:
[ServiceWorker] Integrate trace events in embedded worker instance (Closed)
|
Created:
3 years, 8 months ago by leonhsl(Using Gerrit) Modified:
3 years, 8 months ago Reviewers:
shimazu CC:
chromium-reviews, michaeln, jsbell+serviceworker_chromium.org, shimazu+serviceworker_chromium.org, serviceworker-reviews, jam, nhiroki, kinuko+serviceworker, horo+watch_chromium.org, darin-cc_chromium.org, kinuko+watch, tzik, blink-worker-reviews_chromium.org Target Ref:
refs/heads/master Project:
chromium Visibility:
Public. |
Description[ServiceWorker] Integrate trace events in embedded worker instance
Currently all the TRACE_EVENT* do not manage well in
embedded_worker_instance.cc, this CL integrates them to track
duration for every step throughout one complete starting worker process.
Also uses TRACE_EVENT_NESTABLE_ASYNC_* to replace deprecated
TRACE_EVENT_ASYNC*.
BUG=none
Review-Url: https://codereview.chromium.org/2821253002
Cr-Commit-Position: refs/heads/master@{#466888}
Committed: https://chromium.googlesource.com/chromium/src/+/b260308faa1908b0d5fa3dc35d2d0bce98ced514
Patch Set 1 #
Total comments: 6
Patch Set 2 : NESTABLE_ASYNC_INSTANT* --> NESTABLE_ASYNC_{BEGIN,END} #Patch Set 3 : Rebase only #
Total comments: 1
Patch Set 4 : Track duration of every starting phase #
Total comments: 6
Patch Set 5 : Address nits #Messages
Total messages: 34 (23 generated)
The CQ bit was checked by leon.han@intel.com 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: This issue passed the CQ dry run.
Description was changed from
==========
[ServiceWorker] Integrate trace events in embedded worker instance
Also uses TRACE_EVENT_NESTABLE_ASYNC_{BEGIN,END,INSTANT}[0-2] to
replace deprecated TRACE_EVENT_ASYNC*.
BUG=none
==========
to
==========
[ServiceWorker] Integrate trace events in embedded worker instance
This CL integrates all TRACE_EVENT* into "EmbeddedWorkerInstance::Start"
events sequence, also uses
TRACE_EVENT_NESTABLE_ASYNC_{BEGIN,END,INSTANT}[0-2] to replace
deprecated TRACE_EVENT_ASYNC*.
BUG=none
==========
leon.han@intel.com changed reviewers: + shimazu@chromium.org
Hi, Shimazu-san, this CL is to follow-up your suggestion about integrating event logs in EmbeddedWorkerInstance, does this look like what you were considering? #Also a naive question: where can we check these events log output? Thanks! https://codereview.chromium.org/2821253002/diff/1/content/browser/service_wor... File content/browser/service_worker/embedded_worker_instance.cc (right): https://codereview.chromium.org/2821253002/diff/1/content/browser/service_wor... content/browser/service_worker/embedded_worker_instance.cc:243: TRACE_EVENT_NESTABLE_ASYNC_BEGIN1("ServiceWorker", I think using StartTask ctor/dtor to control "EmbeddedWorkerInstance::Start" events begin/end is simple and clear so I'm keeping this practice, otherwise we need to put events end to several places indicating "Start" failed or succeeded.
Thanks for working on this! Basically this is what I've thought. > Hi, Shimazu-san, this CL is to follow-up your suggestion about integrating event > logs in EmbeddedWorkerInstance, does this look like what you were considering? > #Also a naive question: where can we check these events log output? Thanks! For checking the output, you can try "chrome://tracing": 1) Open "chrome://tracing". 2) Click "Record" on the top left corner. 3) Click "Edit categories" 4) Select "ServiceWorker" in the list of "Record Categories" and start "Record" 5) Open a page using a service worker on another tab (chrome://newtab would be the simplest one) 6) Go back to the tracing tab and press "Stop". https://codereview.chromium.org/2821253002/diff/1/content/browser/service_wor... File content/browser/service_worker/embedded_worker_instance.cc (right): https://codereview.chromium.org/2821253002/diff/1/content/browser/service_wor... content/browser/service_worker/embedded_worker_instance.cc:243: TRACE_EVENT_NESTABLE_ASYNC_BEGIN1("ServiceWorker", On 2017/04/19 03:43:43, leonhsl wrote: > I think using StartTask ctor/dtor to control "EmbeddedWorkerInstance::Start" > events begin/end is simple and clear so I'm keeping this practice, otherwise we > need to put events end to several places indicating "Start" failed or succeeded. Thanks for explanation! It makes sense. https://codereview.chromium.org/2821253002/diff/1/content/browser/service_wor... content/browser/service_worker/embedded_worker_instance.cc:325: "ServiceWorker", "EmbeddedWorkerInstance::Start", instance_, "Step", Each INSTANT can have different name as long as you set the same ID. Could you use "OnProcessAllocated" instead of "EmbeddedWorkerInstance::Start" in this line? Additionally, I've now tested this patch and realized that NESTABLE_ASYNC_INSTANT doesn't look good, sorry! Could you use BEGIN/END for specifying the duration?
Thanks a lot for the knowledge sharing about chrome://tracing! I tested and also did not find any NESTABLE_ASYNC_INSTANT output.. https://codereview.chromium.org/2821253002/diff/1/content/browser/service_wor... File content/browser/service_worker/embedded_worker_instance.cc (right): https://codereview.chromium.org/2821253002/diff/1/content/browser/service_wor... content/browser/service_worker/embedded_worker_instance.cc:325: "ServiceWorker", "EmbeddedWorkerInstance::Start", instance_, "Step", On 2017/04/19 07:54:35, shimazu wrote: > Each INSTANT can have different name as long as you set the same ID. Could you > use "OnProcessAllocated" instead of "EmbeddedWorkerInstance::Start" in this > line? > > Additionally, I've now tested this patch and realized that > NESTABLE_ASYNC_INSTANT doesn't look good, sorry! > Could you use BEGIN/END for specifying the duration? I'm not quite sure about this, instead of NESTABLE_ASYNC_INSTANT, we should do as following? TRACE_EVENT_NESTABLE_ASYNC_BEGIN1(xxx, "OnProcessAllocated", xxx); TRACE_EVENT_NESTABLE_ASYNC_END1(xxx, "OnProcessAllocated", xxx);
> I tested and also did not find any NESTABLE_ASYNC_INSTANT output.. Actually I can see it like the following. (You can see a tiny bar in the red square I drew). https://docs.google.com/drawings/d/1ZV_sivru3DCIHqe1fFXVIozc1W_VbtNZbH_bWxRQ_... https://codereview.chromium.org/2821253002/diff/1/content/browser/service_wor... File content/browser/service_worker/embedded_worker_instance.cc (right): https://codereview.chromium.org/2821253002/diff/1/content/browser/service_wor... content/browser/service_worker/embedded_worker_instance.cc:325: "ServiceWorker", "EmbeddedWorkerInstance::Start", instance_, "Step", On 2017/04/19 10:40:23, leonhsl wrote: > On 2017/04/19 07:54:35, shimazu wrote: > > Each INSTANT can have different name as long as you set the same ID. Could you > > use "OnProcessAllocated" instead of "EmbeddedWorkerInstance::Start" in this > > line? > > > > Additionally, I've now tested this patch and realized that > > NESTABLE_ASYNC_INSTANT doesn't look good, sorry! > > Could you use BEGIN/END for specifying the duration? > > I'm not quite sure about this, instead of NESTABLE_ASYNC_INSTANT, we should do > as following? > TRACE_EVENT_NESTABLE_ASYNC_BEGIN1(xxx, "OnProcessAllocated", xxx); > TRACE_EVENT_NESTABLE_ASYNC_END1(xxx, "OnProcessAllocated", xxx); Yes, exactly. According to the CL which introduces NESTABLE_ASYNC, we should aware when each step finishes. https://crrev.com/039bf813
The CQ bit was checked by leon.han@intel.com 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: android_clang_dbg_recipe on master.tryserver.chromium.android (JOB_FAILED, https://build.chromium.org/p/tryserver.chromium.android/builders/android_clan...) android_compile_dbg on master.tryserver.chromium.android (JOB_FAILED, https://build.chromium.org/p/tryserver.chromium.android/builders/android_comp...) android_n5x_swarming_rel on master.tryserver.chromium.android (JOB_FAILED, https://build.chromium.org/p/tryserver.chromium.android/builders/android_n5x_...) cast_shell_android on master.tryserver.chromium.android (JOB_FAILED, https://build.chromium.org/p/tryserver.chromium.android/builders/cast_shell_a...) chromium_presubmit on master.tryserver.chromium.linux (JOB_FAILED, http://build.chromium.org/p/tryserver.chromium.linux/builders/chromium_presub...) linux_chromium_compile_dbg_ng on master.tryserver.chromium.linux (JOB_FAILED, http://build.chromium.org/p/tryserver.chromium.linux/builders/linux_chromium_...)
The CQ bit was checked by leon.han@intel.com 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...
ps#3 is using NESTABLE_ASYNC_{BEGIN,END} instead of NESTABLE_ASYNC_INSTANT, and
I tried to confirm the effect but seems it's still hard to read the output, I'm
not sure whether I'm using NESTABLE_ASYNC* incorrectly or NESTABLE_ASYNC* itself
has such problem, so I have to rely on your help again. :P
https://codereview.chromium.org/2821253002/diff/1/content/browser/service_wor...
File content/browser/service_worker/embedded_worker_instance.cc (right):
https://codereview.chromium.org/2821253002/diff/1/content/browser/service_wor...
content/browser/service_worker/embedded_worker_instance.cc:325: "ServiceWorker",
"EmbeddedWorkerInstance::Start", instance_, "Step",
On 2017/04/20 04:51:46, shimazu wrote:
> On 2017/04/19 10:40:23, leonhsl wrote:
> > On 2017/04/19 07:54:35, shimazu wrote:
> > > Each INSTANT can have different name as long as you set the same ID. Could
> you
> > > use "OnProcessAllocated" instead of "EmbeddedWorkerInstance::Start" in
this
> > > line?
> > >
> > > Additionally, I've now tested this patch and realized that
> > > NESTABLE_ASYNC_INSTANT doesn't look good, sorry!
> > > Could you use BEGIN/END for specifying the duration?
> >
> > I'm not quite sure about this, instead of NESTABLE_ASYNC_INSTANT, we should
do
> > as following?
> > TRACE_EVENT_NESTABLE_ASYNC_BEGIN1(xxx, "OnProcessAllocated", xxx);
> > TRACE_EVENT_NESTABLE_ASYNC_END1(xxx, "OnProcessAllocated", xxx);
>
> Yes, exactly. According to the CL which introduces NESTABLE_ASYNC, we should
> aware when each step finishes.
> https://crrev.com/039bf813
Done.
> I tried to confirm the effect but seems it's still hard to read the output, I'm > not sure whether I'm using NESTABLE_ASYNC* incorrectly or NESTABLE_ASYNC* itself > has such problem, so I have to rely on your help again. :P In that case, you might not select "ServiceWorker" category or no event related to service workers happens actually. https://codereview.chromium.org/2821253002/diff/40001/content/browser/service... File content/browser/service_worker/embedded_worker_instance.cc (right): https://codereview.chromium.org/2821253002/diff/40001/content/browser/service... content/browser/service_worker/embedded_worker_instance.cc:343: is_new_process); My explanation was bad, sorry. We want to track the duration of each step on each StartingPhase: https://cs.chromium.org/chromium/src/content/browser/service_worker/embedded_... For example, ASYNC_STEP_PAST(..., "OnProcessAllocated", ...) is equivalent to 'ALLOCATING_PROCESS'. ASYNC_STEP_PAST records the duration from previous call of ASYNC_STEP_PAST or ASYNC_STEP_BEGIN. For using NESTABLE_ASYNC, you can call BEGIN at l.306 and END here. In this case, using the names in StartingPhase might make things clearer. Please feel free to ask me if you have questions:)
The CQ bit was unchecked by commit-bot@chromium.org
Dry run: This issue passed the CQ dry run.
The CQ bit was checked by leon.han@intel.com 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...
Description was changed from
==========
[ServiceWorker] Integrate trace events in embedded worker instance
This CL integrates all TRACE_EVENT* into "EmbeddedWorkerInstance::Start"
events sequence, also uses
TRACE_EVENT_NESTABLE_ASYNC_{BEGIN,END,INSTANT}[0-2] to replace
deprecated TRACE_EVENT_ASYNC*.
BUG=none
==========
to
==========
[ServiceWorker] Integrate trace events in embedded worker instance
Currently all the TRACE_EVENT* do not manage well in
embedded_worker_instance.cc, this CL integrates them to track
duration for every step throughout one complete starting worker process.
Also uses TRACE_EVENT_NESTABLE_ASYNC_* to replace deprecated
TRACE_EVENT_ASYNC*.
BUG=none
==========
Hi, Shimazu-san, Thanks a lot for your great help! Thus we have ps#4 now, PTAnL. https://codereview.chromium.org/2821253002/diff/60001/content/browser/service... File content/browser/service_worker/embedded_worker_instance.cc (right): https://codereview.chromium.org/2821253002/diff/60001/content/browser/service... content/browser/service_worker/embedded_worker_instance.cc:677: void EmbeddedWorkerInstance::OnURLJobCreatedForMainScript() { I found that this function is always called when trying to get a worker script, then either OnNetworkAccessedForScriptLoad() or OnScriptReadStarted() will be called, the former means downloading the script via network and the latter means reading from cache.
The CQ bit was unchecked by commit-bot@chromium.org
Dry run: This issue passed the CQ dry run.
Thanks! lgtm with nits. https://codereview.chromium.org/2821253002/diff/60001/content/browser/service... File content/browser/service_worker/embedded_worker_instance.cc (right): https://codereview.chromium.org/2821253002/diff/60001/content/browser/service... content/browser/service_worker/embedded_worker_instance.cc:654: // starting_phase_ may be SCRIPT_READ_FINISHED in case of reading from cache. nit: an extra space https://codereview.chromium.org/2821253002/diff/60001/content/browser/service... content/browser/service_worker/embedded_worker_instance.cc:677: void EmbeddedWorkerInstance::OnURLJobCreatedForMainScript() { On 2017/04/24 08:23:58, leonhsl wrote: > I found that this function is always called when trying to get a worker script, > then either OnNetworkAccessedForScriptLoad() or OnScriptReadStarted() will be > called, the former means downloading the script via network and the latter means > reading from cache. Yeah, looks good. https://codereview.chromium.org/2821253002/diff/60001/content/browser/service... content/browser/service_worker/embedded_worker_instance.cc:706: if (!context_) It's not necessary to separate these two if clauses. if (!context_ || !inflight_start_task) return;
https://codereview.chromium.org/2821253002/diff/60001/content/browser/service... File content/browser/service_worker/embedded_worker_instance.cc (right): https://codereview.chromium.org/2821253002/diff/60001/content/browser/service... content/browser/service_worker/embedded_worker_instance.cc:654: // starting_phase_ may be SCRIPT_READ_FINISHED in case of reading from cache. On 2017/04/25 01:34:50, shimazu wrote: > nit: an extra space Done. https://codereview.chromium.org/2821253002/diff/60001/content/browser/service... content/browser/service_worker/embedded_worker_instance.cc:706: if (!context_) On 2017/04/25 01:34:50, shimazu wrote: > It's not necessary to separate these two if clauses. > > if (!context_ || !inflight_start_task) > return; Done.
The CQ bit was checked by leon.han@intel.com
The patchset sent to the CQ was uploaded after l-g-t-m from shimazu@chromium.org Link to the patchset: https://codereview.chromium.org/2821253002/#ps80001 (title: "Address nits")
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": 80001, "attempt_start_ts": 1493087657159650,
"parent_rev": "702de0adbf42af51c93feabf9c46cdad25dc7862", "commit_rev":
"b260308faa1908b0d5fa3dc35d2d0bce98ced514"}
Message was sent while issue was closed.
Description was changed from ========== [ServiceWorker] Integrate trace events in embedded worker instance Currently all the TRACE_EVENT* do not manage well in embedded_worker_instance.cc, this CL integrates them to track duration for every step throughout one complete starting worker process. Also uses TRACE_EVENT_NESTABLE_ASYNC_* to replace deprecated TRACE_EVENT_ASYNC*. BUG=none ========== to ========== [ServiceWorker] Integrate trace events in embedded worker instance Currently all the TRACE_EVENT* do not manage well in embedded_worker_instance.cc, this CL integrates them to track duration for every step throughout one complete starting worker process. Also uses TRACE_EVENT_NESTABLE_ASYNC_* to replace deprecated TRACE_EVENT_ASYNC*. BUG=none Review-Url: https://codereview.chromium.org/2821253002 Cr-Commit-Position: refs/heads/master@{#466888} Committed: https://chromium.googlesource.com/chromium/src/+/b260308faa1908b0d5fa3dc35d2d... ==========
Message was sent while issue was closed.
Committed patchset #5 (id:80001) as https://chromium.googlesource.com/chromium/src/+/b260308faa1908b0d5fa3dc35d2d... |
