Service Worker: Coalesce the start worker timer into the timeout timer.

content/browser/service_worker/service_worker_version.cc

Index: content/browser/service_worker/service_worker_version.cc
diff --git a/content/browser/service_worker/service_worker_version.cc b/content/browser/service_worker/service_worker_version.cc
index 4857ff945871867b0ed6c703669c1ad678b28c18..0180fcd2c545c749dc4b726212045da2b9452daf 100644
--- a/content/browser/service_worker/service_worker_version.cc
+++ b/content/browser/service_worker/service_worker_version.cc
@@ -307,7 +307,7 @@ ServiceWorkerVersion::ServiceWorkerVersion(
       status_(NEW),
       context_(context),
       script_cache_map_(this, context),
-      ping_timed_out_(false),
+      ping_state_(PING_NOT_STARTED),
       is_doomed_(false),
       skip_waiting_(false),
       weak_factory_(this) {
@@ -324,10 +324,11 @@ ServiceWorkerVersion::ServiceWorkerVersion(
 
 ServiceWorkerVersion::~ServiceWorkerVersion() {
   // The user may have closed the tab waiting for SW to start up.
-  if (start_worker_timeout_timer_.IsRunning() &&
-      GetTickDuration(start_timing_) >
-          base::TimeDelta::FromSeconds(
-              kDestructedStartingWorkerTimeoutThresholdSeconds)) {
+  if (GetTickDuration(start_time_) >
+      base::TimeDelta::FromSeconds(
+          kDestructedStartingWorkerTimeoutThresholdSeconds)) {
+    DCHECK(timeout_timer_.IsRunning());
+    DCHECK(!embedded_worker_->devtools_attached());
     RecordStartWorkerResult(SERVICE_WORKER_ERROR_TIMEOUT);
   }
 
@@ -392,8 +393,8 @@ void ServiceWorkerVersion::StartWorker(
     case STOPPING:
     case STOPPED:
     case STARTING:
-      if (!start_worker_timeout_timer_.IsRunning())
-        ScheduleStartWorkerTimeout();
+      if (!timeout_timer_.IsRunning())
+        StartTimeoutTimer();
       start_callbacks_.push_back(callback);
       if (running_status() == STOPPED) {
         DCHECK(!cache_listener_.get());
@@ -789,15 +790,11 @@ void ServiceWorkerVersion::SetDevToolsAttached(bool attached) {
   embedded_worker()->set_devtools_attached(attached);
   if (attached) {
     // Set to null time so we don't record the startup time metric.
-    ClearTick(&start_timing_);
+    ClearTick(&start_time_);
     return;
   }
-  // If devtools is detached try scheduling the timers for stopping the worker
-  // now.
   if (!timeout_timer_.IsRunning())
     StartTimeoutTimer();
-  if (!start_worker_timeout_timer_.IsRunning() && !start_callbacks_.empty())
-    ScheduleStartWorkerTimeout();
 }
 
 void ServiceWorkerVersion::SetMainScriptHttpResponseInfo(
@@ -812,7 +809,7 @@ ServiceWorkerVersion::GetMainScriptHttpResponseInfo() {
 
 void ServiceWorkerVersion::OnScriptLoaded() {
   DCHECK_EQ(STARTING, running_status());
-  StartTimeoutTimer();
+  ping_state_ = PING_STARTED;

[kinuko, 2015/03/09 09:30:40]

nit: This line (or enum name) may look a bit cryptic as people would expect line
1484 to be the point when we start pinging.

[falken, 2015/03/09 10:10:55]

Agreed. I renamed the enums and added a comment.

 }
 
 void ServiceWorkerVersion::OnStarted() {
@@ -835,7 +832,7 @@ void ServiceWorkerVersion::OnStopped(
                         (old_status != EmbeddedWorkerInstance::STARTING);
 
   StopTimeoutTimer();
-  if (ping_timed_out_)
+  if (ping_state_ == PING_TIMED_OUT)
     should_restart = false;
 
   // Fire all stop callbacks.
@@ -881,7 +878,10 @@ void ServiceWorkerVersion::OnStopped(
 
   // Restart worker if we have any start callbacks and the worker isn't doomed.
   if (should_restart) {
-    start_worker_timeout_timer_.Reset();
+    if (embedded_worker_->devtools_attached())
+      ClearTick(&start_time_);
+    else
+      RestartTick(&start_time_);
     cache_listener_.reset(new ServiceWorkerCacheListener(this, context_));
     embedded_worker_->Start(
         version_id_, scope_, script_url_, false /* pause_after_download */,
@@ -1426,9 +1426,19 @@ void ServiceWorkerVersion::DidGetClients(
 
 void ServiceWorkerVersion::StartTimeoutTimer() {
   DCHECK(!timeout_timer_.IsRunning());
+
+  if (embedded_worker_->devtools_attached())
+    ClearTick(&start_time_);
+  else
+    RestartTick(&start_time_);
+  start_callbacks_.push_back(
+      base::Bind(&ServiceWorkerVersion::RecordStartWorkerResult,
+                 weak_factory_.GetWeakPtr()));
+
   ClearTick(&idle_time_);
   ClearTick(&ping_time_);
-  ping_timed_out_ = false;
+  ping_state_ = PING_NOT_STARTED;
+
   timeout_timer_.Start(FROM_HERE,
                        base::TimeDelta::FromSeconds(kTimeoutTimerDelaySeconds),
                        this, &ServiceWorkerVersion::OnTimeoutTimer);
@@ -1439,9 +1449,24 @@ void ServiceWorkerVersion::StopTimeoutTimer() {
 }
 
 void ServiceWorkerVersion::OnTimeoutTimer() {
+  DCHECK(running_status() == STARTING || running_status() == RUNNING ||
+         running_status() == STOPPING)
+      << running_status();
+
+  if (GetTickDuration(start_time_) >

[kinuko, 2015/03/09 09:30:40]

nit: Could we have one-line comments for each of these timeouts, e.g. 'starting
a worker hasn't finished within a certain period', 'the worker has been in idle
for longer than a certain period', 'the worker hasn't responded to our ping
within a certain period' etc.

[falken, 2015/03/09 10:10:55]

Done.

+      base::TimeDelta::FromMinutes(kStartWorkerTimeoutMinutes)) {
+    DCHECK_NE(RUNNING, running_status());
+    scoped_refptr<ServiceWorkerVersion> protect(this);
+    RunCallbacks(this, &start_callbacks_, SERVICE_WORKER_ERROR_TIMEOUT);
+    if (running_status() == STARTING)
+      embedded_worker_->Stop();
+    StopTimeoutTimer();
+    return;
+  }
+
   if (running_status() == STOPPING)
     return;

[kinuko, 2015/03/09 09:30:40]

nit: could this check be done before we check start_time?

[falken, 2015/03/09 10:10:55]

Thanks for pointing this out. The start_time timeout is different from the
others: it doesn't just stop the worker but also invokes start callbacks with
ERROR_TIMEOUT. This means StartWorker(); StopWorker(); will be able to fail
callbacks even if we got stuck at some point.

But there's a bug with the current patch: if ping_time expires happens before
start_time, it's possible that start callbacks will never be invoked with
ERROR_TIMEOUT.

I think I have to redesign this so the timeout timer continues running even
after one thing times out.

[falken, 2015/03/10 06:56:36]

Updated this... the timeout timer now continues until the worker is actually
stopped.

-  DCHECK(running_status() == STARTING || running_status() == RUNNING);
+
   if (GetTickDuration(idle_time_) >
       base::TimeDelta::FromSeconds(kIdleWorkerTimeoutSeconds)) {
     StopWorkerIfIdle();
@@ -1455,17 +1480,18 @@ void ServiceWorkerVersion::OnTimeoutTimer() {
     return;
   }
 
-  if (ping_time_.is_null())
+  if (ping_state_ == PING_STARTED && ping_time_.is_null())
     PingWorker();
 }
 
 void ServiceWorkerVersion::PingWorker() {
   DCHECK(running_status() == STARTING || running_status() == RUNNING);
+  DCHECK_EQ(PING_STARTED, ping_state_);
   ServiceWorkerStatusCode status =
       embedded_worker_->SendMessage(ServiceWorkerMsg_Ping());
   if (status != SERVICE_WORKER_OK) {
     // TODO(falken): Maybe try resending Ping a few times first?
-    ping_timed_out_ =  true;
+    ping_state_ = PING_TIMED_OUT;
     StopWorkerIfIdle();
     return;
   }
@@ -1474,7 +1500,7 @@ void ServiceWorkerVersion::PingWorker() {
 
 void ServiceWorkerVersion::OnPingTimeout() {
   DCHECK(running_status() == STARTING || running_status() == RUNNING);
-  ping_timed_out_ = true;
+  ping_state_ = PING_TIMED_OUT;
   // TODO(falken): Show a message to the developer that the SW was stopped due
   // to timeout (crbug.com/457968). Also, change the error code to
   // SERVICE_WORKER_ERROR_TIMEOUT.
@@ -1482,7 +1508,7 @@ void ServiceWorkerVersion::OnPingTimeout() {
 }
 
 void ServiceWorkerVersion::StopWorkerIfIdle() {
-  if (HasInflightRequests() && !ping_timed_out_)
+  if (HasInflightRequests() && ping_state_ != PING_TIMED_OUT)
     return;
   if (running_status() == STOPPED || running_status() == STOPPING ||
       !stop_callbacks_.empty()) {
@@ -1508,46 +1534,16 @@ bool ServiceWorkerVersion::HasInflightRequests() const {
     !streaming_url_request_jobs_.empty();
 }
 
-void ServiceWorkerVersion::ScheduleStartWorkerTimeout() {
-  DCHECK(!start_worker_timeout_timer_.IsRunning());
-  start_timing_ = embedded_worker_->devtools_attached()
-                      ? base::TimeTicks()
-                      : base::TimeTicks::Now();
-  start_callbacks_.push_back(
-      base::Bind(&ServiceWorkerVersion::RecordStartWorkerResult,
-                 weak_factory_.GetWeakPtr()));
-  start_worker_timeout_timer_.Start(
-      FROM_HERE, base::TimeDelta::FromMinutes(kStartWorkerTimeoutMinutes),
-      base::Bind(&ServiceWorkerVersion::OnStartWorkerTimeout,
-                 weak_factory_.GetWeakPtr()));
-}
-
-void ServiceWorkerVersion::OnStartWorkerTimeout() {
-  DCHECK(running_status() == STARTING || running_status() == STOPPING)
-      << running_status();
-
-  if (embedded_worker_->devtools_attached()) {
-    start_worker_timeout_timer_.Stop();
-    return;
-  }
-
-  scoped_refptr<ServiceWorkerVersion> protect(this);
-  RunCallbacks(this, &start_callbacks_, SERVICE_WORKER_ERROR_TIMEOUT);
-  if (running_status() == STARTING)
-    embedded_worker_->Stop();
-}
-
 void ServiceWorkerVersion::RecordStartWorkerResult(
     ServiceWorkerStatusCode status) {
-  start_worker_timeout_timer_.Stop();
-
   UMA_HISTOGRAM_ENUMERATION("ServiceWorker.StartWorker.Status", status,
                             SERVICE_WORKER_ERROR_MAX_VALUE);
-  if (status == SERVICE_WORKER_OK && !start_timing_.is_null()) {
+  if (status == SERVICE_WORKER_OK && !start_time_.is_null()) {
     UMA_HISTOGRAM_MEDIUM_TIMES("ServiceWorker.StartWorker.Time",
-                               GetTickDuration(start_timing_));
+                               GetTickDuration(start_time_));
   }
 
+  ClearTick(&start_time_);
   if (status != SERVICE_WORKER_ERROR_TIMEOUT)
     return;
   EmbeddedWorkerInstance::StartingPhase phase =