[session_shell] Time out on slow SessionShell

DetachView() must not block the Stop() operation indefinitely.
The StopOperation must time out when DetachView() takes too long.

Added a test case to test the behavior. Unfortunate about tests
for timeout behavior is they need the time until out to elapse,
i.e. such a test is slow. In this case, the timeout in question
is 1 second, which is bearable.

Also changed the behavior such that on logout, no DetachView()
calls are made for stories that are still running, in accordance
with the behavior documented in session_shell.fidl. Added a
test case for that too.

TESTED=Added test cases to session_shell integration test.

MF-121 #comment Time out on slow SessionShell.

Change-Id: Iaaec29df7d6edb2fb8ce5269ff1c02d423f19555
diff --git a/bin/sessionmgr/story_runner/story_controller_impl.cc b/bin/sessionmgr/story_runner/story_controller_impl.cc
index 3b16646..64065c6 100644
--- a/bin/sessionmgr/story_runner/story_controller_impl.cc
+++ b/bin/sessionmgr/story_runner/story_controller_impl.cc
@@ -492,9 +492,11 @@
 class StoryControllerImpl::StopCall : public Operation<> {
  public:
   StopCall(StoryControllerImpl* const story_controller_impl,
+           const bool bulk,
            std::function<void()> done)
       : Operation("StoryControllerImpl::StopCall", done),
-        story_controller_impl_(story_controller_impl) {}
+        story_controller_impl_(story_controller_impl),
+        bulk_(bulk) {}
 
  private:
   void Run() override {
@@ -502,13 +504,66 @@
       Done();
       return;
     }
+
     story_controller_impl_->SetState(fuchsia::modular::StoryState::STOPPING);
 
-    story_controller_impl_->DetachView([this, weak_this = GetWeakPtr()] {
-                                         if (weak_this) {
-                                           StopStory();
-                                         }
-                                       });
+    // If this StopCall is part of a bulk operation of story provider that stops
+    // all stories at once, no DetachView() notification is given to the session
+    // shell.
+    if (bulk_) {
+      StopStory();
+      return;
+    }
+
+    // Invocation of DetachView() follows below.
+    //
+    // The following callback is scheduled twice, once as response from
+    // DetachView(), and again as a timeout.
+    //
+    // The shared bool did_run keeps track of the number of invocations, and
+    // allows to suppress the second one.
+    //
+    // The weak pointer is needed because the method invocation would not be
+    // cancelled when the OperationQueue holding this Operation instance is
+    // deleted, because the method is invoked on an instance outside of the
+    // instance that owns the OperationQueue that holds this Operation instance.
+    //
+    // The argument from_timeout informs whether the invocation was from the
+    // timeout or from the method callback. It's used only to log diagnostics.
+    // If we would not want to have this diagnostic, we could use this callback
+    // directly to schedule it twice. In that case, it would be important that
+    // passing it to DetachView() has copy semantics, as it does now passing it
+    // to the capture list of two separate lambdas, and not move semantics, i.e.
+    // that the argument is of DetachView() is NOT a fit::function but a
+    // std::function.
+    //
+    // Both weak and shared pointers are copyable, so we don't need to do
+    // anything to make this lambda copyable. (But it will be copied when used
+    // below.)
+    auto cont = [this, weak_this = GetWeakPtr(),
+                 did_run = std::make_shared<bool>(false),
+                 story_id = story_controller_impl_->story_id_](
+                     const bool from_timeout) {
+                  if (*did_run) {
+                    return;
+                  }
+
+                  *did_run = true;
+
+                  if (from_timeout) {
+                    FXL_LOG(INFO) << "DetachView() timed out: story_id=" << story_id;
+                  }
+
+                  if (weak_this) {
+                    StopStory();
+                  }
+                };
+
+    story_controller_impl_->DetachView([cont] { cont(false); });
+
+    async::PostDelayedTask(
+        async_get_default_dispatcher(), [cont] { cont(true); },
+        kBasicTimeout);
   }
 
   void StopStory() {
@@ -567,6 +622,10 @@
 
   StoryControllerImpl* const story_controller_impl_;  // not owned
 
+  // Whether this Stop operation is part of stopping all stories at once. In
+  // that case, DetachView() is not called.
+  const bool bulk_;
+
   FXL_DISALLOW_COPY_AND_ASSIGN(StopCall);
 };
 
@@ -619,7 +678,8 @@
         story_controller_impl_->FindRunningModInfo(module_path_);
     if (running_mod_info &&
         story_controller_impl_->running_mod_infos_.size() == 1) {
-      operation_queue_.Add(new StopCall(story_controller_impl_, [flow] {}));
+      operation_queue_.Add(new StopCall(story_controller_impl_, false /* bulk */,
+                                        [flow] {}));
     } else {
       // Otherwise, stop this one module.
       operation_queue_.Add(new StopModuleCall(
@@ -1436,7 +1496,11 @@
 }
 
 void StoryControllerImpl::Stop(StopCallback done) {
-  operation_queue_.Add(new StopCall(this, done));
+  operation_queue_.Add(new StopCall(this, false /* bulk */, done));
+}
+
+void StoryControllerImpl::StopBulk(const bool bulk, StopCallback done) {
+  operation_queue_.Add(new StopCall(this, bulk, done));
 }
 
 void StoryControllerImpl::TakeAndLoadSnapshot(
diff --git a/bin/sessionmgr/story_runner/story_controller_impl.h b/bin/sessionmgr/story_runner/story_controller_impl.h
index 6d9ca7c..04c9bef 100644
--- a/bin/sessionmgr/story_runner/story_controller_impl.h
+++ b/bin/sessionmgr/story_runner/story_controller_impl.h
@@ -165,12 +165,18 @@
       fidl::InterfaceRequest<fuchsia::modular::Entity> entity_request,
       std::function<void(std::string /* entity_reference */)> callback);
 
-  // |StoryController|
-  // NOTE: Public so that StoryProviderImpl can call it.
-  void Stop(StopCallback done) override;
+  // Stops the story as part of a story provider operation. The story provider
+  // can indicate whether this is part of an operation where all stories are
+  // stopped at once in order to stop the session shell, indicated by bulk being
+  // true. Happens at logout or when session shells are swapped. In that
+  // situation, DetachView() is not called for this story.
+  void StopBulk(bool bulk, StopCallback done);
 
  private:
   // |StoryController|
+  void Stop(StopCallback done) override;
+
+  // |StoryController|
   void GetInfo(GetInfoCallback callback) override;
   void Start(fidl::InterfaceRequest<fuchsia::ui::viewsv1token::ViewOwner>
                  request) override;
diff --git a/bin/sessionmgr/story_runner/story_provider_impl.cc b/bin/sessionmgr/story_runner/story_provider_impl.cc
index 92fc38a..8b732c6 100644
--- a/bin/sessionmgr/story_runner/story_provider_impl.cc
+++ b/bin/sessionmgr/story_runner/story_provider_impl.cc
@@ -49,11 +49,13 @@
   using StoryRuntimesMap = std::map<std::string, struct StoryRuntimeContainer>;
 
   StopStoryCall(fidl::StringPtr story_id,
+                const bool bulk,
                 StoryRuntimesMap* const story_runtime_containers,
                 MessageQueueManager* const message_queue_manager,
                 ResultCall result_call)
       : Operation("StoryProviderImpl::DeleteStoryCall", std::move(result_call)),
         story_id_(story_id),
+        bulk_(bulk),
         story_runtime_containers_(story_runtime_containers),
         message_queue_manager_(message_queue_manager) {}
 
@@ -69,7 +71,8 @@
     }
 
     FXL_DCHECK(i->second.controller_impl != nullptr);
-    i->second.controller_impl->Stop([this, flow] { CleanupRuntime(flow); });
+    i->second.controller_impl->StopBulk(bulk_,
+                                        [this, flow] { CleanupRuntime(flow); });
   }
 
   void CleanupRuntime(FlowToken flow) {
@@ -92,6 +95,7 @@
 
  private:
   const fidl::StringPtr story_id_;
+  const bool bulk_;
   StoryRuntimesMap* const story_runtime_containers_;
   MessageQueueManager* const message_queue_manager_;
 
@@ -190,7 +194,7 @@
       // OperationQueue on which we're running will block.  Moving over to
       // fit::promise will allow us to observe cancellation.
       operations_.Add(new StopStoryCall(
-          it.first, &story_provider_impl_->story_runtime_containers_,
+          it.first, true /* bulk */, &story_provider_impl_->story_runtime_containers_,
           story_provider_impl_->component_context_info_.message_queue_manager,
           [flow] {}));
     }
@@ -608,7 +612,7 @@
 
 void StoryProviderImpl::OnStoryStorageDeleted(fidl::StringPtr story_id) {
   operation_queue_.Add(new StopStoryCall(
-      story_id, &story_runtime_containers_,
+      story_id, false /* bulk */, &story_runtime_containers_,
       component_context_info_.message_queue_manager, [this, story_id] {
         for (const auto& i : watchers_.ptrs()) {
           (*i)->OnDelete(story_id);
diff --git a/tests/session_shell/README.md b/tests/session_shell/README.md
index e3c30d3..92c97ea 100644
--- a/tests/session_shell/README.md
+++ b/tests/session_shell/README.md
@@ -15,6 +15,11 @@
 
 * Be notified through SessionShell.DetachView() of a story going away.
 
+* StoryRunner tolerates a session shell not responding fast enough to
+  SessionShell.DetachView().
+
+* On logout, no DetachView() calls are made for still running stories.
+
 The test code is invoked as a session shell from basemgr and executes a
 predefined sequence of steps, rather than to expose a UI to be driven by user
 interaction, as a session shell normally would. I.e. the test is implemented as a
diff --git a/tests/session_shell/session_shell_test_session_shell.cc b/tests/session_shell/session_shell_test_session_shell.cc
index 701c6d0..22ba007 100644
--- a/tests/session_shell/session_shell_test_session_shell.cc
+++ b/tests/session_shell/session_shell_test_session_shell.cc
@@ -159,6 +159,10 @@
     on_detach_view_ = callback;
   }
 
+  void set_detach_delay(zx::duration detach_delay) {
+    detach_delay_ = detach_delay;
+  }
+
  private:
   // |SessionShell|
   void AttachView(fuchsia::modular::ViewIdentifier view_id,
@@ -171,12 +175,16 @@
   void DetachView(fuchsia::modular::ViewIdentifier view_id,
                   std::function<void()> done) override {
     on_detach_view_(std::move(view_id));
-    done();
+
+    // Used to simulate a sluggish shell that hits the timeout.
+    async::PostDelayedTask(async_get_default_dispatcher(),
+                           std::move(done), detach_delay_);
   }
 
   fidl::BindingSet<fuchsia::modular::SessionShell> bindings_;
   std::function<void(ViewId view_id)> on_attach_view_{[](ViewId) {}};
   std::function<void(ViewId view_id)> on_detach_view_{[](ViewId) {}};
+  zx::duration detach_delay_{};
 
   FXL_DISALLOW_COPY_AND_ASSIGN(SessionShellImpl);
 };
@@ -205,11 +213,11 @@
     // Until we use RequestStart() for the first time, there must be no calls on
     // the SessionShell service.
     session_shell_impl_.set_on_attach_view(
-        [](ViewId view_id) {
+        [](ViewId) {
           Fail("AttachView() called without RequestStart().");
         });
     session_shell_impl_.set_on_detach_view(
-        [](ViewId view_id) {
+        [](ViewId) {
           Fail("DetachView() called without RequestStart().");
         });
 
@@ -603,13 +611,10 @@
 
   TestPoint story4_state_before_run_{"Story4 State before Run"};
   TestPoint story4_state_after_run_{"Story4 State after Run"};
-
   TestPoint story4_attach_view_{"Story4 attach View"};
-  TestPoint story4_detach_view_{"Story4 detach View"};
 
   void TestStory4_Run() {
     story_provider_->GetController("story4", story_controller_.NewRequest());
-
     story_controller_->GetInfo([this](fuchsia::modular::StoryInfo info,
                                       fuchsia::modular::StoryState state) {
       story_info_ = std::move(info);
@@ -630,22 +635,34 @@
                                       fuchsia::modular::StoryState state) {
       if (state == fuchsia::modular::StoryState::RUNNING) {
         story4_state_after_run_.Pass();
-        TestStory4_DeleteStory();
+        TestStory4_Stop();
       }
     });
   }
 
+  TestPoint story4_detach_view_{"Story4 detach View"};
+  TestPoint story4_stop_{"Story4 Stop"};
+
+  void TestStory4_Stop() {
+    session_shell_impl_.set_on_detach_view(
+        [this](ViewId) {
+          story4_detach_view_.Pass();
+        });
+
+    story_controller_->Stop([this] {
+      TeardownStoryController();
+      story4_stop_.Pass();
+
+      TestStory4_DeleteStory();
+    });
+  }
+
   TestPoint story4_delete_{"Story4 Delete"};
 
   void TestStory4_DeleteStory() {
     puppet_master_->DeleteStory(story_info_.id,
                                 [this] { story4_delete_.Pass(); });
 
-    session_shell_impl_.set_on_detach_view(
-        [this](ViewId) {
-          story4_detach_view_.Pass();
-        });
-
     story_provider_->GetStoryInfo(
         story_info_.id, [this](fuchsia::modular::StoryInfoPtr info) {
           TestStory4_InfoAfterDeleteIsNull(std::move(info));
@@ -660,6 +677,185 @@
       story4_info_after_delete_.Pass();
     }
 
+    TestStory5();
+  }
+
+  // Test Case Story5:
+  //
+  // Create a story and start it with RequestStart() rather than Start().
+  //
+  // Verify that, when the story is stopped, a request for
+  // SessionShell.DetachView() is received, and if the request is not answered,
+  // the Stop() request proceeds anyway.
+
+  TestPoint story5_create_{"Story5 Create"};
+
+  void TestStory5() {
+    puppet_master_->ControlStory("story5", story_puppet_master_.NewRequest());
+
+    fuchsia::modular::AddMod add_mod;
+    add_mod.mod_name.push_back("mod1");
+    add_mod.intent.handler = kCommonNullModule;
+
+    fuchsia::modular::StoryCommand command;
+    command.set_add_mod(std::move(add_mod));
+
+    fidl::VectorPtr<fuchsia::modular::StoryCommand> commands;
+    commands.push_back(std::move(command));
+
+    story_puppet_master_->Enqueue(std::move(commands));
+    story_puppet_master_->Execute(
+        [this](fuchsia::modular::ExecuteResult result) {
+          story5_create_.Pass();
+          TestStory5_Run();
+        });
+  }
+
+  TestPoint story5_state_before_run_{"Story5 State before Run"};
+  TestPoint story5_state_after_run_{"Story5 State after Run"};
+
+  TestPoint story5_attach_view_{"Story5 attach View"};
+
+  void TestStory5_Run() {
+    story_provider_->GetController("story5", story_controller_.NewRequest());
+
+    story_controller_->GetInfo([this](fuchsia::modular::StoryInfo info,
+                                      fuchsia::modular::StoryState state) {
+      story_info_ = std::move(info);
+      if (state == fuchsia::modular::StoryState::STOPPED) {
+        story5_state_before_run_.Pass();
+      }
+    });
+
+    // Start and show the new story using RequestStart().
+    story_controller_->RequestStart();
+
+    session_shell_impl_.set_on_attach_view(
+        [this](ViewId) {
+          story5_attach_view_.Pass();
+        });
+
+    story_controller_->GetInfo([this](fuchsia::modular::StoryInfo info,
+                                      fuchsia::modular::StoryState state) {
+      if (state == fuchsia::modular::StoryState::RUNNING) {
+        story5_state_after_run_.Pass();
+        TestStory5_Stop();
+      }
+    });
+  }
+
+  TestPoint story5_stop_{"Story5 Stop"};
+
+  void TestStory5_Stop() {
+    // Ignore the detach view. The delay is larger than the timeout for the
+    // whole test configured in dev_base_shell.cc, so an attempt to wait for
+    // this timeout would fail the whole test.
+    session_shell_impl_.set_detach_delay(
+        zx::msec(modular::testing::kTestTimeoutMilliseconds * 2));
+    session_shell_impl_.set_on_detach_view([](ViewId) {});
+
+    story_controller_->Stop([this] {
+      TeardownStoryController();
+      story5_stop_.Pass();
+
+      TestStory5_DeleteStory();
+    });
+  }
+
+  TestPoint story5_delete_{"Story5 Delete"};
+
+  void TestStory5_DeleteStory() {
+    puppet_master_->DeleteStory(story_info_.id,
+                                [this] { story5_delete_.Pass(); });
+
+    story_provider_->GetStoryInfo(
+        story_info_.id, [this](fuchsia::modular::StoryInfoPtr info) {
+          TestStory5_InfoAfterDeleteIsNull(std::move(info));
+        });
+
+  }
+
+  TestPoint story5_info_after_delete_{"Story5 Info after Delete is null"};
+
+  void TestStory5_InfoAfterDeleteIsNull(fuchsia::modular::StoryInfoPtr info) {
+    if (!info) {
+      story5_info_after_delete_.Pass();
+    }
+
+    TestStory6();
+  }
+
+  // Test Case Story6:
+  //
+  // Create a story and start it with RequestStart() rather than Start().
+  //
+  // Verify that, when the story is NOT stopped when the SessionShell is stopped
+  // (such as at Logout) NO request for SessionShell.DetachView() is received.
+
+  TestPoint story6_create_{"Story6 Create"};
+
+  void TestStory6() {
+    puppet_master_->ControlStory("story6", story_puppet_master_.NewRequest());
+
+    fuchsia::modular::AddMod add_mod;
+    add_mod.mod_name.push_back("mod1");
+    add_mod.intent.handler = kCommonNullModule;
+
+    fuchsia::modular::StoryCommand command;
+    command.set_add_mod(std::move(add_mod));
+
+    fidl::VectorPtr<fuchsia::modular::StoryCommand> commands;
+    commands.push_back(std::move(command));
+
+    story_puppet_master_->Enqueue(std::move(commands));
+    story_puppet_master_->Execute(
+        [this](fuchsia::modular::ExecuteResult result) {
+          story6_create_.Pass();
+          TestStory6_Run();
+        });
+  }
+
+  TestPoint story6_state_before_run_{"Story6 State before Run"};
+  TestPoint story6_state_after_run_{"Story6 State after Run"};
+
+  TestPoint story6_attach_view_{"Story6 attach View"};
+
+  void TestStory6_Run() {
+    story_provider_->GetController("story6", story_controller_.NewRequest());
+
+    story_controller_->GetInfo([this](fuchsia::modular::StoryInfo info,
+                                      fuchsia::modular::StoryState state) {
+      story_info_ = std::move(info);
+      if (state == fuchsia::modular::StoryState::STOPPED) {
+        story6_state_before_run_.Pass();
+      }
+    });
+
+    // Start and show the new story using RequestStart().
+    story_controller_->RequestStart();
+
+    session_shell_impl_.set_on_attach_view(
+        [this](ViewId) {
+          story6_attach_view_.Pass();
+        });
+
+    story_controller_->GetInfo([this](fuchsia::modular::StoryInfo info,
+                                      fuchsia::modular::StoryState state) {
+      if (state == fuchsia::modular::StoryState::RUNNING) {
+        story6_state_after_run_.Pass();
+        TestStory6_Logout();
+      }
+    });
+  }
+
+  void TestStory6_Logout() {
+    // If we get a DetachView() call during logout, that's a failure.
+    session_shell_impl_.set_detach_delay(zx::sec(0));
+    session_shell_impl_.set_on_detach_view(
+        [](ViewId) {
+          Fail("DetachView() Received on Logout");
+        });
+
     Signal(modular::testing::kTestShutdown);
   }