[CrOS Multidevice] Tether: time out if SecureChannel does not create connection in time.

SecureChannel will simply listen forever, waiting for a connection to the specified remote
device. MessageTransferOperation now uses a new timer that times out if a connection is
not created in time.

Bug: 824568, 752273, 854885
Change-Id: Ia37cf1ec55e60ae3e7e386cdf40fdd9486ab6cdf
Reviewed-on: https://chromium-review.googlesource.com/1117899Reviewed-by: Kyle Horimoto <khorimoto@chromium.org>
Commit-Queue: Ryan Hansberry <hansberry@chromium.org>
Cr-Commit-Position: refs/heads/master@{#571516}

chromeos/components/tether/connect_tethering_operation.cc

@@ -213,7 +213,7 @@ void ConnectTetheringOperation::NotifyObserversOfConnectionFailure(
     observer.OnConnectTetheringFailure(remote_device_, error_code);
 }
 
-uint32_t ConnectTetheringOperation::GetTimeoutSeconds() {
+uint32_t ConnectTetheringOperation::GetMessageTimeoutSeconds() {
   return setup_required_
              ? ConnectTetheringOperation::kSetupRequiredResponseTimeoutSeconds
              : ConnectTetheringOperation::

chromeos/components/tether/connect_tethering_operation.h

@@ -109,7 +109,7 @@ class ConnectTetheringOperation : public MessageTransferOperation {
   void OnOperationFinished() override;
   MessageType GetMessageTypeForConnection() override;
   void OnMessageSent(int sequence_number) override;
-  uint32_t GetTimeoutSeconds() override;
+  uint32_t GetMessageTimeoutSeconds() override;
 
   void NotifyConnectTetheringRequestSent();
   void NotifyObserversOfSuccessfulResponse(const std::string& ssid,

chromeos/components/tether/connect_tethering_operation_unittest.cc

@@ -213,7 +213,7 @@ class ConnectTetheringOperationTest : public testing::Test {
                   kSetupNotRequiredResponseTimeoutSeconds;
 
     EXPECT_EQ(expected_response_timeout_seconds,
-              operation_->GetTimeoutSeconds());
+              operation_->GetMessageTimeoutSeconds());
   }
 
   const std::string connect_tethering_request_string_;

chromeos/components/tether/message_transfer_operation.cc

@@ -145,6 +145,7 @@ void MessageTransferOperation::Initialize() {
 
   for (const auto& remote_device : remote_devices_) {
     if (base::FeatureList::IsEnabled(chromeos::features::kMultiDeviceApi)) {
+      StartConnectionTimerForDevice(remote_device);
       remote_device_to_connection_attempt_delegate_map_[remote_device] =
           std::make_unique<ConnectionAttemptDelegate>(
               this, remote_device,
@@ -159,7 +160,7 @@ void MessageTransferOperation::Initialize() {
       if (connection_manager_->GetStatusForDevice(remote_device.GetDeviceId(),
                                                   &status) &&
           status == cryptauth::SecureChannel::Status::AUTHENTICATED) {
-        StartTimerForDevice(remote_device);
+        StartMessageTimerForDevice(remote_device);
         OnDeviceAuthenticated(remote_device);
       }
     }
@@ -184,7 +185,7 @@ void MessageTransferOperation::OnSecureChannelStatusChanged(
 
   switch (new_status) {
     case cryptauth::SecureChannel::Status::AUTHENTICATED:
-      StartTimerForDevice(*remote_device);
+      StartMessageTimerForDevice(*remote_device);
       OnDeviceAuthenticated(*remote_device);
       break;
     case cryptauth::SecureChannel::Status::DISCONNECTED:
@@ -273,8 +274,8 @@ int MessageTransferOperation::SendMessageToDevice(
   }
 }
 
-uint32_t MessageTransferOperation::GetTimeoutSeconds() {
-  return MessageTransferOperation::kDefaultTimeoutSeconds;
+uint32_t MessageTransferOperation::GetMessageTimeoutSeconds() {
+  return MessageTransferOperation::kDefaultMessageTimeoutSeconds;
 }
 
 void MessageTransferOperation::OnConnectionAttemptFailure(
@@ -294,7 +295,14 @@ void MessageTransferOperation::OnConnection(
   remote_device_to_client_channel_observer_map_[remote_device] =
       std::make_unique<ClientChannelObserver>(this, remote_device,
                                               std::move(channel));
-  StartTimerForDevice(remote_device);
+
+  // Stop the timer which was started from StartConnectionTimerForDevice() since
+  // the connection has now been established. Start another timer now via
+  // StartMessageTimerForDevice() while waiting for messages to be sent to and
+  // received by |remote_device|.
+  StopTimerForDeviceIfRunning(remote_device);
+  StartMessageTimerForDevice(remote_device);
+
   OnDeviceAuthenticated(remote_device);
 }
 
@@ -376,8 +384,19 @@ void MessageTransferOperation::HandleDeviceDisconnection(
   }
 }
 
-void MessageTransferOperation::StartTimerForDevice(
+void MessageTransferOperation::StartConnectionTimerForDevice(
+    cryptauth::RemoteDeviceRef remote_device) {
+  StartTimerForDevice(remote_device, kConnectionTimeoutSeconds);
+}
+
+void MessageTransferOperation::StartMessageTimerForDevice(
     cryptauth::RemoteDeviceRef remote_device) {
+  StartTimerForDevice(remote_device, GetMessageTimeoutSeconds());
+}
+
+void MessageTransferOperation::StartTimerForDevice(
+    cryptauth::RemoteDeviceRef remote_device,
+    uint32_t timeout_seconds) {
   PA_LOG(INFO) << "Starting timer for operation with message type "
                << message_type_for_connection_ << " from device with ID "
                << remote_device.GetTruncatedDeviceIdForLogs() << ".";
@@ -385,7 +404,7 @@ void MessageTransferOperation::StartTimerForDevice(
   remote_device_to_timer_map_.emplace(remote_device,
                                       timer_factory_->CreateOneShotTimer());
   remote_device_to_timer_map_[remote_device]->Start(
-      FROM_HERE, base::TimeDelta::FromSeconds(GetTimeoutSeconds()),
+      FROM_HERE, base::TimeDelta::FromSeconds(timeout_seconds),
       base::Bind(&MessageTransferOperation::OnTimeout,
                  weak_ptr_factory_.GetWeakPtr(), remote_device));
 }

chromeos/components/tether/message_transfer_operation.h

@@ -101,11 +101,11 @@ class MessageTransferOperation : public BleConnectionManager::Observer {
   // Returns the type of message that this operation intends to send.
   virtual MessageType GetMessageTypeForConnection() = 0;
 
-  // The number of seconds that this operation should wait before unregistering
-  // a device after it has been authenticated if it has not been explicitly
-  // unregistered. If ShouldOperationUseTimeout() returns false, this method is
-  // never used.
-  virtual uint32_t GetTimeoutSeconds();
+  // The number of seconds that this operation should wait to let messages be
+  // sent and received before unregistering a device after it has been
+  // authenticated if it has not been explicitly unregistered. If
+  // ShouldOperationUseTimeout() returns false, this method is never used.
+  virtual uint32_t GetMessageTimeoutSeconds();
 
   cryptauth::RemoteDeviceRefList& remote_devices() { return remote_devices_; }
 
@@ -156,11 +156,16 @@ class MessageTransferOperation : public BleConnectionManager::Observer {
     std::unique_ptr<secure_channel::ClientChannel> client_channel_;
   };
 
-  // The default number of seconds an operation should wait before a timeout
-  // occurs. Once this amount of time passes, the connection will be closed.
-  // Classes deriving from MessageTransferOperation should override
-  // GetTimeoutSeconds() if they desire a different duration.
-  static constexpr const uint32_t kDefaultTimeoutSeconds = 10;
+  // The maximum expected time to connect to a remote device, if it can be
+  // connected to. This number has been determined by examining metrics.
+  static constexpr const uint32_t kConnectionTimeoutSeconds = 15;
+
+  // The default number of seconds an operation should wait to send and receive
+  // messages before a timeout occurs. Once this amount of time passes, the
+  // connection will be closed. Classes deriving from MessageTransferOperation
+  // should override GetMessageTimeoutSeconds() if they desire a different
+  // duration.
+  static constexpr const uint32_t kDefaultMessageTimeoutSeconds = 10;
 
   struct ConnectAttemptCounts {
     uint32_t empty_scan_attempts = 0;
@@ -179,7 +184,17 @@ class MessageTransferOperation : public BleConnectionManager::Observer {
   void HandleDeviceDisconnection(
       cryptauth::RemoteDeviceRef remote_device,
       BleConnectionManager::StateChangeDetail status_change_detail);
-  void StartTimerForDevice(cryptauth::RemoteDeviceRef remote_device);
+
+  // Start the timer while waiting for a connection to |remote_device|. See
+  // |kConnectionTimeoutSeconds|.
+  void StartConnectionTimerForDevice(cryptauth::RemoteDeviceRef remote_device);
+
+  // Start the timer while waiting for messages to be sent to and received by
+  // |remote_device|. See |kDefaultMessageTimeoutSeconds|.
+  void StartMessageTimerForDevice(cryptauth::RemoteDeviceRef remote_device);
+
+  void StartTimerForDevice(cryptauth::RemoteDeviceRef remote_device,
+                           uint32_t timeout_seconds);
   void StopTimerForDeviceIfRunning(cryptauth::RemoteDeviceRef remote_device);
   void OnTimeout(cryptauth::RemoteDeviceRef remote_device);
   base::Optional<cryptauth::RemoteDeviceRef> GetRemoteDevice(

chromeos/components/tether/message_transfer_operation_unittest.cc

@@ -96,7 +96,7 @@ class TestOperation : public MessageTransferOperation {
     last_sequence_number_ = sequence_number;
   }
 
-  uint32_t GetTimeoutSeconds() override { return timeout_seconds_; }
+  uint32_t GetMessageTimeoutSeconds() override { return timeout_seconds_; }
 
   void set_timeout_seconds(uint32_t timeout_seconds) {
     timeout_seconds_ = timeout_seconds;
@@ -148,6 +148,10 @@ class TestTimerFactory : public TimerFactory {
     return device_id_to_timer_map_[device_id_for_next_timer_];
   }
 
+  void ClearTimerForDeviceId(const std::string& device_id) {
+    device_id_to_timer_map_.erase(device_id_for_next_timer_);
+  }
+
   void set_device_id_for_next_timer(
       const std::string& device_id_for_next_timer) {
     device_id_for_next_timer_ = device_id_for_next_timer;
@@ -200,8 +204,15 @@ class MessageTransferOperationTest : public testing::Test {
   }
 
   void ConstructOperation(cryptauth::RemoteDeviceRefList remote_devices) {
+    test_timer_factory_ = new TestTimerFactory();
+
     if (base::FeatureList::IsEnabled(chromeos::features::kMultiDeviceApi)) {
       for (auto remote_device : remote_devices) {
+        // Prepare for connection timeout timers to be made for each remote
+        // device.
+        test_timer_factory_->set_device_id_for_next_timer(
+            remote_device.GetDeviceId());
+
         auto fake_connection_attempt =
             std::make_unique<secure_channel::FakeConnectionAttempt>();
         remote_device_to_fake_connection_attempt_map_[remote_device] =
@@ -212,7 +223,6 @@ class MessageTransferOperationTest : public testing::Test {
       }
     }
 
-    test_timer_factory_ = new TestTimerFactory();
     operation_ = base::WrapUnique(new TestOperation(
         remote_devices, fake_device_sync_client_.get(),
         fake_secure_channel_client_.get(), fake_ble_connection_manager_.get()));
@@ -236,6 +246,11 @@ class MessageTransferOperationTest : public testing::Test {
 
     VerifyOperationStartedAndFinished(true /* has_started */,
                                       false /* has_finished */);
+
+    if (base::FeatureList::IsEnabled(chromeos::features::kMultiDeviceApi)) {
+      for (const auto& remote_device : operation_->remote_devices())
+        VerifyConnectionTimerCreatedForDevice(remote_device);
+    }
   }
 
   void VerifyOperationStartedAndFinished(bool has_started, bool has_finished) {
@@ -286,6 +301,12 @@ class MessageTransferOperationTest : public testing::Test {
     VerifyTimerCreatedForDevice(remote_device, kTestTimeoutSeconds);
   }
 
+  void VerifyConnectionTimerCreatedForDevice(
+      cryptauth::RemoteDeviceRef remote_device) {
+    VerifyTimerCreatedForDevice(
+        remote_device, MessageTransferOperation::kConnectionTimeoutSeconds);
+  }
+
   void VerifyTimerCreatedForDevice(cryptauth::RemoteDeviceRef remote_device,
                                    uint32_t timeout_seconds) {
     EXPECT_TRUE(GetTimerForDevice(remote_device));
@@ -383,7 +404,18 @@ TEST_F(MessageTransferOperationTest,
 }
 
 TEST_F(MessageTransferOperationTest,
-       MultiDeviceApiEnabled_TestAuthenticatesButTimesOut) {
+       MultiDeviceApiEnabled_TestTimesOutBeforeAuthentication) {
+  SetMultiDeviceApiEnabled();
+
+  ConstructOperation(cryptauth::RemoteDeviceRefList{test_devices_[0]});
+  InitializeOperation();
+
+  GetTimerForDevice(test_devices_[0])->Fire();
+  EXPECT_TRUE(operation_->has_operation_finished());
+}
+
+TEST_F(MessageTransferOperationTest,
+       MultiDeviceApiEnabled_TestAuthenticatesButThenTimesOut) {
   SetMultiDeviceApiEnabled();
 
   ConstructOperation(cryptauth::RemoteDeviceRefList{test_devices_[0]});
@@ -432,6 +464,9 @@ TEST_F(MessageTransferOperationTest, MultiDeviceApiEnabled_MultipleDevices) {
   ConstructOperation(test_devices_);
   InitializeOperation();
 
+  for (const auto& remote_device : test_devices_)
+    test_timer_factory_->ClearTimerForDeviceId(remote_device.GetDeviceId());
+
   // Authenticate |test_devices_[0]|'s channel.
   CreateAuthenticatedChannelForDevice(test_devices_[0]);
   EXPECT_TRUE(operation_->HasDeviceAuthenticated(test_devices_[0]));