ServiceWorker: Move TRACE_EVENT to avoid early return and mismatching

ServiceWorker: Move TRACE_EVENT to avoid early return and mismatching

BUG=N/A
TEST=N/A

Committed: https://crrev.com/127eb0cde50fecbf06fc2b775d3c1ff8608a9eae
Cr-Commit-Position: refs/heads/master@{#299458}

[shimazu, 2014-10-10 08:27:58]

shimazu@chromium.org changed reviewers:
+ horo@chromium.org

[shimazu, 2014-10-10 08:27:58]

PTAL

[horo, 2014-10-10 08:38:09]

horo@chromium.org changed reviewers:
+ nhiroki@chromium.org

[horo, 2014-10-10 08:38:10]

nhiroki@ should see this.

[nhiroki, 2014-10-14 02:03:26]

https://codereview.chromium.org/636253004/diff/1/content/browser/service_work...
File content/browser/service_worker/service_worker_storage.cc (right):

https://codereview.chromium.org/636253004/diff/1/content/browser/service_work...
content/browser/service_worker/service_worker_storage.cc:265: "URL",
document_url.spec());
Why don't you add TRACE_EVENT_ASYNC_XXX in LazyInitialize() instead? (I think
you don't have to add it in this CL though)

https://codereview.chromium.org/636253004/diff/1/content/browser/service_work...
content/browser/service_worker/service_worker_storage.cc:282:
"ServiceWorkerStorage::FindRegistrationForDocument:NotContainsKey",
nit: s/Contains/Contain

I think this wouldn't help to measure performance because synchronous
TRACE_EVENT works for the current scope and we'll immediately return at the next
line. Wdyt?

https://codereview.chromium.org/636253004/diff/1/content/browser/service_work...
content/browser/service_worker/service_worker_storage.cc:289: int callback_id =
base::TimeTicks::Now().ToInternalValue();
|callback_id| should be int64 because ToInternalValue() returns int64 value.

https://codereview.chromium.org/636253004/diff/1/content/browser/service_work...
content/browser/service_worker/service_worker_storage.cc:786: int callback_id,
ditto.

[shimazu, 2014-10-14 04:10:47]

https://codereview.chromium.org/636253004/diff/1/content/browser/service_work...
File content/browser/service_worker/service_worker_storage.cc (right):

https://codereview.chromium.org/636253004/diff/1/content/browser/service_work...
content/browser/service_worker/service_worker_storage.cc:265: "URL",
document_url.spec());
On 2014/10/14 02:03:26, nhiroki wrote:
> Why don't you add TRACE_EVENT_ASYNC_XXX in LazyInitialize() instead? (I think
> you don't have to add it in this CL though)

I think LazyInitialize have to be tracked in order to clarify the start point of
this procedure. But if ASYNC_BEGIN was put in here instead, where to insert
ASYNC_END seems a little problem, so I put TRACE_EVENT here.
What do you think?

https://codereview.chromium.org/636253004/diff/1/content/browser/service_work...
content/browser/service_worker/service_worker_storage.cc:282:
"ServiceWorkerStorage::FindRegistrationForDocument:NotContainsKey",
On 2014/10/14 02:03:26, nhiroki wrote:
> nit: s/Contains/Contain
> 
> I think this wouldn't help to measure performance because synchronous
> TRACE_EVENT works for the current scope and we'll immediately return at the
next
> line. Wdyt?

I think there is no meaning in terms of performance, too, but I insert this in
order to track calls of FindRegistrationForDocument.

https://codereview.chromium.org/636253004/diff/1/content/browser/service_work...
content/browser/service_worker/service_worker_storage.cc:289: int callback_id =
base::TimeTicks::Now().ToInternalValue();
On 2014/10/14 02:03:26, nhiroki wrote:
> |callback_id| should be int64 because ToInternalValue() returns int64 value.

Done.

https://codereview.chromium.org/636253004/diff/1/content/browser/service_work...
content/browser/service_worker/service_worker_storage.cc:786: int callback_id,
On 2014/10/14 02:03:26, nhiroki wrote:
> ditto.

Done.

[nhiroki, 2014-10-14 05:01:13]

https://codereview.chromium.org/636253004/diff/1/content/browser/service_work...
File content/browser/service_worker/service_worker_storage.cc (right):

https://codereview.chromium.org/636253004/diff/1/content/browser/service_work...
content/browser/service_worker/service_worker_storage.cc:265: "URL",
document_url.spec());
On 2014/10/14 04:10:47, makoto wrote:
> On 2014/10/14 02:03:26, nhiroki wrote:
> > Why don't you add TRACE_EVENT_ASYNC_XXX in LazyInitialize() instead? (I
think
> > you don't have to add it in this CL though)
> 
> I think LazyInitialize have to be tracked in order to clarify the start point
of
> this procedure. But if ASYNC_BEGIN was put in here instead, where to insert
> ASYNC_END seems a little problem, so I put TRACE_EVENT here.
> What do you think?

I see. If you'd like to track it, how about doing like this?

void SWS::FindRegistrationForDocument(...) {
  TRACE_EVENT_ASYNC_BEGIN(...);
  if (!LazyInitialize()) {
    if (state_ != INITIALIZING || !context_) {
      TRACE_EVENT_ASYNC_END(..., "Status", "FAILED");    
    } else {
      TRACE_EVENT_ASYNC_END(..., "Status", "LazyInitialize");
    }
    return;
  }

  if (!ContainsKey(...)) {
    TRACE_EVENT_ASYNC_END(..., "Status", installing_registration.get() ? "OK" :
"NOT_FOUND");
  }

  database_task_runner_->PostTask(...);
}

https://codereview.chromium.org/636253004/diff/1/content/browser/service_work...
content/browser/service_worker/service_worker_storage.cc:282:
"ServiceWorkerStorage::FindRegistrationForDocument:NotContainsKey",
On 2014/10/14 04:10:47, makoto wrote:
> On 2014/10/14 02:03:26, nhiroki wrote:
> > nit: s/Contains/Contain
> > 
> > I think this wouldn't help to measure performance because synchronous
> > TRACE_EVENT works for the current scope and we'll immediately return at the
> next
> > line. Wdyt?
> 
> I think there is no meaning in terms of performance, too, but I insert this in
> order to track calls of FindRegistrationForDocument.

Please see the previous comment.

https://codereview.chromium.org/636253004/diff/1/content/browser/service_work...
content/browser/service_worker/service_worker_storage.cc:811: "Status", status);
(Not related to this CL, but we are here...)

1.) This seems to show "Status: NOT_FOUND" if |installing_registration.get()|
returns a valid registration.

2.) How about adding stringify function for ServiceWorkerDatabase::Status?
|status| will be printed as a number and we couldn't quickly understand what the
status means.

[nhiroki, 2014-10-14 06:09:50]

https://codereview.chromium.org/636253004/diff/1/content/browser/service_work...
File content/browser/service_worker/service_worker_storage.cc (right):

https://codereview.chromium.org/636253004/diff/1/content/browser/service_work...
content/browser/service_worker/service_worker_storage.cc:265: "URL",
document_url.spec());
On 2014/10/14 05:01:13, nhiroki wrote:
> On 2014/10/14 04:10:47, makoto wrote:
> > On 2014/10/14 02:03:26, nhiroki wrote:
> > > Why don't you add TRACE_EVENT_ASYNC_XXX in LazyInitialize() instead? (I
> think
> > > you don't have to add it in this CL though)
> > 
> > I think LazyInitialize have to be tracked in order to clarify the start
point
> of
> > this procedure. But if ASYNC_BEGIN was put in here instead, where to insert
> > ASYNC_END seems a little problem, so I put TRACE_EVENT here.
> > What do you think?
> 
> I see. If you'd like to track it, how about doing like this?
> 
> void SWS::FindRegistrationForDocument(...) {
>   TRACE_EVENT_ASYNC_BEGIN(...);
>   if (!LazyInitialize()) {
>     if (state_ != INITIALIZING || !context_) {
>       TRACE_EVENT_ASYNC_END(..., "Status", "FAILED");    
>     } else {
>       TRACE_EVENT_ASYNC_END(..., "Status", "LazyInitialize");
>     }
>     return;
>   }
> 
>   if (!ContainsKey(...)) {
>     TRACE_EVENT_ASYNC_END(..., "Status", installing_registration.get() ? "OK"
:
> "NOT_FOUND");
>   }
> 
>   database_task_runner_->PostTask(...);
> }

Or, if you'd like to record it as a single event (which does not have a
begin-end range), you might be able to use TRACE_EVENT_INSTANT.

[shimazu, 2014-10-14 09:06:12]

Patchset #4 (id:120001) has been deleted

[shimazu, 2014-10-14 09:07:03]

https://codereview.chromium.org/636253004/diff/1/content/browser/service_work...
File content/browser/service_worker/service_worker_storage.cc (right):

https://codereview.chromium.org/636253004/diff/1/content/browser/service_work...
content/browser/service_worker/service_worker_storage.cc:265: "URL",
document_url.spec());
On 2014/10/14 06:09:50, nhiroki wrote:
> On 2014/10/14 05:01:13, nhiroki wrote:
> > On 2014/10/14 04:10:47, makoto wrote:
> > > On 2014/10/14 02:03:26, nhiroki wrote:
> > > > Why don't you add TRACE_EVENT_ASYNC_XXX in LazyInitialize() instead? (I
> > think
> > > > you don't have to add it in this CL though)
> > > 
> > > I think LazyInitialize have to be tracked in order to clarify the start
> point
> > of
> > > this procedure. But if ASYNC_BEGIN was put in here instead, where to
insert
> > > ASYNC_END seems a little problem, so I put TRACE_EVENT here.
> > > What do you think?
> > 
> > I see. If you'd like to track it, how about doing like this?
> > 
> > void SWS::FindRegistrationForDocument(...) {
> >   TRACE_EVENT_ASYNC_BEGIN(...);
> >   if (!LazyInitialize()) {
> >     if (state_ != INITIALIZING || !context_) {
> >       TRACE_EVENT_ASYNC_END(..., "Status", "FAILED");    
> >     } else {
> >       TRACE_EVENT_ASYNC_END(..., "Status", "LazyInitialize");
> >     }
> >     return;
> >   }
> > 
> >   if (!ContainsKey(...)) {
> >     TRACE_EVENT_ASYNC_END(..., "Status", installing_registration.get() ?
"OK"
> :
> > "NOT_FOUND");
> >   }
> > 
> >   database_task_runner_->PostTask(...);
> > }
> 
> Or, if you'd like to record it as a single event (which does not have a
> begin-end range), you might be able to use TRACE_EVENT_INSTANT.

Done.

https://codereview.chromium.org/636253004/diff/1/content/browser/service_work...
content/browser/service_worker/service_worker_storage.cc:282:
"ServiceWorkerStorage::FindRegistrationForDocument:NotContainsKey",
On 2014/10/14 05:01:13, nhiroki wrote:
> On 2014/10/14 04:10:47, makoto wrote:
> > On 2014/10/14 02:03:26, nhiroki wrote:
> > > nit: s/Contains/Contain
> > > 
> > > I think this wouldn't help to measure performance because synchronous
> > > TRACE_EVENT works for the current scope and we'll immediately return at
the
> > next
> > > line. Wdyt?
> > 
> > I think there is no meaning in terms of performance, too, but I insert this
in
> > order to track calls of FindRegistrationForDocument.
> 
> Please see the previous comment.

Done.

https://codereview.chromium.org/636253004/diff/1/content/browser/service_work...
content/browser/service_worker/service_worker_storage.cc:811: "Status", status);
On 2014/10/14 05:01:13, nhiroki wrote:
> (Not related to this CL, but we are here...)
> 
> 1.) This seems to show "Status: NOT_FOUND" if |installing_registration.get()|
> returns a valid registration.
> 
> 2.) How about adding stringify function for ServiceWorkerDatabase::Status?
> |status| will be printed as a number and we couldn't quickly understand what
the
> status means.

I'll create a different patch about this.

[nhiroki, 2014-10-14 09:31:54]

lgtm

https://codereview.chromium.org/636253004/diff/100001/content/browser/service...
File content/browser/service_worker/service_worker_storage.cc (right):

https://codereview.chromium.org/636253004/diff/100001/content/browser/service...
content/browser/service_worker/service_worker_storage.cc:264:
"ServiceWorkerStorage::FindRegistrationForDocument:LazyInitialize",
just suggestion: ":" looks a separator of namespaces. How about using
parentheses? For example, "ServiceWorkerStorage::FindRegistrationForDocument
(LazyInitialize)"

https://codereview.chromium.org/636253004/diff/100001/content/browser/service...
content/browser/service_worker/service_worker_storage.cc:280:
"ServiceWorkerStorage::FindRegistrationForDocument:CheckInstalling",
ditto.

https://codereview.chromium.org/636253004/diff/100001/content/browser/service...
content/browser/service_worker/service_worker_storage.cc:283: "Status", (status
== SERVICE_WORKER_OK) ? "Found" : "Not Found");
nit: "OK" is used for SERVICE_WORKER_OK at line 799. Can you keep them
consistent?

[shimazu, 2014-10-14 10:04:27]

The CQ bit was checked by shimazu@chromium.org

[commit-bot: I haz the power, 2014-10-14 10:04:52]

CQ is trying da patch. Follow status at
 https://chromium-cq-status.appspot.com/patch-status/636253004/100001

[commit-bot: I haz the power, 2014-10-14 11:01:02]

Committed patchset #3 (id:100001)

[commit-bot: I haz the power, 2014-10-14 11:01:52]

Patchset 3 (id:??) landed as
https://crrev.com/127eb0cde50fecbf06fc2b775d3c1ff8608a9eae
Cr-Commit-Position: refs/heads/master@{#299458}