shill: vpn: Signal service failure on connect/reconnect timeout.

This patch adds a connect/reconnect timeout of 60 seconds to all VPN
connection attempts. The connection attempt is canceled if the timeout
fires before successfully receiving an IP configuration from the VPN
process.

BUG=chromium-os:31479
TEST=unit tests, tested on device

Change-Id: I290db6b4d0549107f44ce1678d11b814931532f4
Reviewed-on: https://gerrit.chromium.org/gerrit/24587
Commit-Ready: Darin Petkov <petkov@chromium.org>
Reviewed-by: Darin Petkov <petkov@chromium.org>
Tested-by: Darin Petkov <petkov@chromium.org>
diff --git a/l2tp_ipsec_driver.cc b/l2tp_ipsec_driver.cc
index 1a001cb..47d61f7 100644
--- a/l2tp_ipsec_driver.cc
+++ b/l2tp_ipsec_driver.cc
@@ -68,9 +68,8 @@
                                  Manager *manager,
                                  DeviceInfo *device_info,
                                  GLib *glib)
-    : VPNDriver(manager, kProperties, arraysize(kProperties)),
+    : VPNDriver(dispatcher, manager, kProperties, arraysize(kProperties)),
       control_(control),
-      dispatcher_(dispatcher),
       metrics_(metrics),
       device_info_(device_info),
       glib_(glib),
@@ -90,6 +89,7 @@
 }
 
 void L2TPIPSecDriver::Connect(const VPNServiceRefPtr &service, Error *error) {
+  StartConnectTimeout();
   service_ = service;
   service_->SetState(Service::kStateConfiguring);
   rpc_task_.reset(new RPCTask(control_, this));
@@ -104,7 +104,7 @@
 }
 
 void L2TPIPSecDriver::OnConnectionDisconnected() {
-  SLOG(VPN, 2) << __func__;
+  LOG(ERROR) << "VPN connection disconnected.";
   Cleanup(Service::kStateFailure);
 }
 
@@ -115,6 +115,7 @@
 void L2TPIPSecDriver::Cleanup(Service::ConnectState state) {
   SLOG(VPN, 2) << __func__
                << "(" << Service::ConnectStateToString(state) << ")";
+  StopConnectTimeout();
   DeletePSKFile();
   if (child_watch_tag_) {
     glib_->SourceRemove(child_watch_tag_);
@@ -322,7 +323,7 @@
 }
 
 void L2TPIPSecDriver::GetLogin(string *user, string *password) {
-  SLOG(VPN, 2) << __func__;
+  LOG(INFO) << "Login requested.";
   string user_property =
       args()->LookupString(flimflam::kL2tpIpsecUserProperty, "");
   if (user_property.empty()) {
@@ -373,7 +374,7 @@
 
 void L2TPIPSecDriver::Notify(
     const string &reason, const map<string, string> &dict) {
-  SLOG(VPN, 2) << __func__ << "(" << reason << ")";
+  LOG(INFO) << "IP configuration received: " << reason;
 
   if (reason != "connect") {
     device_->OnDisconnected();
@@ -396,12 +397,13 @@
   }
 
   if (!device_) {
-    device_ = new VPN(control_, dispatcher_, metrics_, manager(),
+    device_ = new VPN(control_, dispatcher(), metrics_, manager(),
                       interface_name, interface_index);
   }
   device_->SetEnabled(true);
   device_->SelectService(service_);
   device_->UpdateIPConfig(properties);
+  StopConnectTimeout();
 }
 
 KeyValueStore L2TPIPSecDriver::GetProvider(Error *error) {
diff --git a/l2tp_ipsec_driver.h b/l2tp_ipsec_driver.h
index d624c83..4f487e0 100644
--- a/l2tp_ipsec_driver.h
+++ b/l2tp_ipsec_driver.h
@@ -21,7 +21,6 @@
 
 class ControlInterface;
 class DeviceInfo;
-class EventDispatcher;
 class GLib;
 class Metrics;
 class NSS;
@@ -50,6 +49,7 @@
   FRIEND_TEST(L2TPIPSecDriverTest, AppendFlag);
   FRIEND_TEST(L2TPIPSecDriverTest, AppendValueOption);
   FRIEND_TEST(L2TPIPSecDriverTest, Cleanup);
+  FRIEND_TEST(L2TPIPSecDriverTest, Connect);
   FRIEND_TEST(L2TPIPSecDriverTest, DeletePSKFile);
   FRIEND_TEST(L2TPIPSecDriverTest, Disconnect);
   FRIEND_TEST(L2TPIPSecDriverTest, GetLogin);
@@ -110,7 +110,6 @@
                       const std::map<std::string, std::string> &dict);
 
   ControlInterface *control_;
-  EventDispatcher *dispatcher_;
   Metrics *metrics_;
   DeviceInfo *device_info_;
   GLib *glib_;
diff --git a/l2tp_ipsec_driver_unittest.cc b/l2tp_ipsec_driver_unittest.cc
index 48713cd..49762a6 100644
--- a/l2tp_ipsec_driver_unittest.cc
+++ b/l2tp_ipsec_driver_unittest.cc
@@ -152,6 +152,7 @@
   EXPECT_CALL(*service_, SetState(Service::kStateFailure));
   driver_->rpc_task_.reset(new RPCTask(&control_, this));
   FilePath psk_file = SetupPSKFile();
+  driver_->StartConnectTimeout();
   driver_->Cleanup(Service::kStateFailure);
   EXPECT_FALSE(file_util::PathExists(psk_file));
   EXPECT_TRUE(driver_->psk_file_.empty());
@@ -160,6 +161,7 @@
   EXPECT_FALSE(driver_->rpc_task_.get());
   EXPECT_FALSE(driver_->device_);
   EXPECT_FALSE(driver_->service_);
+  EXPECT_FALSE(driver_->IsConnectTimeoutStarted());
 }
 
 TEST_F(L2TPIPSecDriverTest, DeletePSKFile) {
@@ -402,6 +404,7 @@
   Error error;
   driver_->Connect(service_, &error);
   EXPECT_TRUE(error.IsSuccess());
+  EXPECT_TRUE(driver_->IsConnectTimeoutStarted());
 }
 
 TEST_F(L2TPIPSecDriverTest, Disconnect) {
@@ -502,16 +505,20 @@
   EXPECT_CALL(*device_, UpdateIPConfig(_));
   driver_->device_ = device_;
   FilePath psk_file = SetupPSKFile();
+  driver_->StartConnectTimeout();
   driver_->Notify("connect", config);
   EXPECT_FALSE(file_util::PathExists(psk_file));
   EXPECT_TRUE(driver_->psk_file_.empty());
+  EXPECT_FALSE(driver_->IsConnectTimeoutStarted());
 }
 
 TEST_F(L2TPIPSecDriverTest, NotifyFail) {
   map<string, string> dict;
   driver_->device_ = device_;
   EXPECT_CALL(*device_, OnDisconnected());
+  driver_->StartConnectTimeout();
   driver_->Notify("fail", dict);
+  EXPECT_TRUE(driver_->IsConnectTimeoutStarted());
 }
 
 TEST_F(L2TPIPSecDriverTest, VerifyPaths) {
diff --git a/mock_vpn_driver.cc b/mock_vpn_driver.cc
index eff68b9..33c0dcf 100644
--- a/mock_vpn_driver.cc
+++ b/mock_vpn_driver.cc
@@ -6,7 +6,7 @@
 
 namespace shill {
 
-MockVPNDriver::MockVPNDriver() : VPNDriver(NULL, NULL, 0) {}
+MockVPNDriver::MockVPNDriver() : VPNDriver(NULL, NULL, NULL, 0) {}
 
 MockVPNDriver::~MockVPNDriver() {}
 
diff --git a/openvpn_driver.cc b/openvpn_driver.cc
index 33d1144..0ed44d2 100644
--- a/openvpn_driver.cc
+++ b/openvpn_driver.cc
@@ -123,9 +123,8 @@
                              Manager *manager,
                              DeviceInfo *device_info,
                              GLib *glib)
-    : VPNDriver(manager, kProperties, arraysize(kProperties)),
+    : VPNDriver(dispatcher, manager, kProperties, arraysize(kProperties)),
       control_(control),
-      dispatcher_(dispatcher),
       metrics_(metrics),
       device_info_(device_info),
       glib_(glib),
@@ -142,6 +141,7 @@
 void OpenVPNDriver::Cleanup(Service::ConnectState state) {
   SLOG(VPN, 2) << __func__ << "(" << Service::ConnectStateToString(state)
                << ")";
+  StopConnectTimeout();
   management_server_->Stop();
   if (!tls_auth_file_.empty()) {
     file_util::Delete(tls_auth_file_, false);
@@ -243,7 +243,7 @@
   SLOG(VPN, 2) << "Claiming " << link_name << " for OpenVPN tunnel";
 
   CHECK(!device_);
-  device_ = new VPN(control_, dispatcher_, metrics_, manager(),
+  device_ = new VPN(control_, dispatcher(), metrics_, manager(),
                     link_name, interface_index);
 
   device_->SetEnabled(true);
@@ -262,7 +262,7 @@
 
 void OpenVPNDriver::Notify(const string &reason,
                            const map<string, string> &dict) {
-  SLOG(VPN, 2) << __func__ << "(" << reason << ")";
+  LOG(INFO) << "IP configuration received: " << reason;
   if (reason != "up") {
     device_->OnDisconnected();
     return;
@@ -270,6 +270,7 @@
   IPConfig::Properties properties;
   ParseIPConfiguration(dict, &properties);
   device_->UpdateIPConfig(properties);
+  StopConnectTimeout();
 }
 
 // static
@@ -396,8 +397,8 @@
   }
 }
 
-void OpenVPNDriver::Connect(const VPNServiceRefPtr &service,
-                            Error *error) {
+void OpenVPNDriver::Connect(const VPNServiceRefPtr &service, Error *error) {
+  StartConnectTimeout();
   service_ = service;
   service_->SetState(Service::kStateConfiguring);
   if (!device_info_->CreateTunnelInterface(&tunnel_interface_)) {
@@ -578,7 +579,7 @@
 
 bool OpenVPNDriver::InitManagementChannelOptions(
     vector<string> *options, Error *error) {
-  if (!management_server_->Start(dispatcher_, &sockets_, options)) {
+  if (!management_server_->Start(dispatcher(), &sockets_, options)) {
     Error::PopulateAndLog(
         error, Error::kInternalError, "Unable to setup management channel.");
     return false;
@@ -625,12 +626,13 @@
 }
 
 void OpenVPNDriver::OnConnectionDisconnected() {
-  SLOG(VPN, 2) << __func__;
+  LOG(ERROR) << "VPN connection disconnected.";
   Cleanup(Service::kStateFailure);
 }
 
 void OpenVPNDriver::OnReconnecting() {
   SLOG(VPN, 2) << __func__;
+  StartConnectTimeout();
   if (device_) {
     device_->OnDisconnected();
   }
diff --git a/openvpn_driver.h b/openvpn_driver.h
index 6efe6d7..1d68f49 100644
--- a/openvpn_driver.h
+++ b/openvpn_driver.h
@@ -26,7 +26,6 @@
 class ControlInterface;
 class DeviceInfo;
 class Error;
-class EventDispatcher;
 class Metrics;
 class NSS;
 class OpenVPNManagementServer;
@@ -53,11 +52,10 @@
                               int interface_index);
   virtual void Disconnect();
   virtual void OnConnectionDisconnected();
+  virtual std::string GetProviderType() const;
 
   virtual void OnReconnecting();
 
-  virtual std::string GetProviderType() const;
-
   virtual void Cleanup(Service::ConnectState state);
 
   // Returns true if an opton was appended.
@@ -152,7 +150,6 @@
                       const std::map<std::string, std::string> &dict);
 
   ControlInterface *control_;
-  EventDispatcher *dispatcher_;
   Metrics *metrics_;
   DeviceInfo *device_info_;
   GLib *glib_;
diff --git a/openvpn_driver_unittest.cc b/openvpn_driver_unittest.cc
index 1e5431d..b0b6396 100644
--- a/openvpn_driver_unittest.cc
+++ b/openvpn_driver_unittest.cc
@@ -192,6 +192,7 @@
   driver_->Connect(service_, &error);
   EXPECT_TRUE(error.IsSuccess());
   EXPECT_EQ(kInterfaceName, driver_->tunnel_interface_);
+  EXPECT_TRUE(driver_->IsConnectTimeoutStarted());
 }
 
 TEST_F(OpenVPNDriverTest, ConnectTunnelFailure) {
@@ -202,6 +203,7 @@
   driver_->Connect(service_, &error);
   EXPECT_EQ(Error::kInternalError, error.type());
   EXPECT_TRUE(driver_->tunnel_interface_.empty());
+  EXPECT_FALSE(driver_->IsConnectTimeoutStarted());
 }
 
 namespace {
@@ -215,15 +217,19 @@
 TEST_F(OpenVPNDriverTest, Notify) {
   map<string, string> config;
   driver_->device_ = device_;
+  driver_->StartConnectTimeout();
   EXPECT_CALL(*device_, UpdateIPConfig(_));
   driver_->Notify("up", config);
+  EXPECT_FALSE(driver_->IsConnectTimeoutStarted());
 }
 
 TEST_F(OpenVPNDriverTest, NotifyFail) {
   map<string, string> dict;
   driver_->device_ = device_;
+  driver_->StartConnectTimeout();
   EXPECT_CALL(*device_, OnDisconnected());
   driver_->Notify("fail", dict);
+  EXPECT_TRUE(driver_->IsConnectTimeoutStarted());
 }
 
 TEST_F(OpenVPNDriverTest, GetRouteOptionEntry) {
@@ -561,6 +567,7 @@
   driver_->tunnel_interface_ = kInterfaceName;
   driver_->device_ = device_;
   driver_->service_ = service_;
+  driver_->StartConnectTimeout();
   FilePath tls_auth_file;
   EXPECT_TRUE(file_util::CreateTemporaryFile(&tls_auth_file));
   EXPECT_FALSE(tls_auth_file.empty());
@@ -583,6 +590,7 @@
   EXPECT_FALSE(driver_->service_);
   EXPECT_FALSE(file_util::PathExists(tls_auth_file));
   EXPECT_TRUE(driver_->tls_auth_file_.empty());
+  EXPECT_FALSE(driver_->IsConnectTimeoutStarted());
 }
 
 namespace {
@@ -658,6 +666,7 @@
   EXPECT_CALL(*device_, OnDisconnected());
   EXPECT_CALL(*service_, SetState(Service::kStateAssociating));
   driver_->OnReconnecting();
+  EXPECT_TRUE(driver_->IsConnectTimeoutStarted());
 }
 
 TEST_F(OpenVPNDriverTest, VerifyPaths) {
diff --git a/vpn_driver.cc b/vpn_driver.cc
index 17d3237..3e03313 100644
--- a/vpn_driver.cc
+++ b/vpn_driver.cc
@@ -8,6 +8,7 @@
 #include <chromeos/dbus/service_constants.h>
 
 #include "shill/connection.h"
+#include "shill/event_dispatcher.h"
 #include "shill/manager.h"
 #include "shill/property_accessor.h"
 #include "shill/property_store.h"
@@ -18,12 +19,19 @@
 
 namespace shill {
 
-VPNDriver::VPNDriver(Manager *manager,
+// static
+const int VPNDriver::kDefaultConnectTimeoutSeconds = 60;
+
+VPNDriver::VPNDriver(EventDispatcher *dispatcher,
+                     Manager *manager,
                      const Property *properties,
                      size_t property_count)
-    : manager_(manager),
+    : weak_ptr_factory_(this),
+      dispatcher_(dispatcher),
+      manager_(manager),
       properties_(properties),
-      property_count_(property_count) {}
+      property_count_(property_count),
+      connect_timeout_seconds_(kDefaultConnectTimeoutSeconds) {}
 
 VPNDriver::~VPNDriver() {}
 
@@ -152,4 +160,30 @@
   return provider_properties;
 }
 
+void VPNDriver::StartConnectTimeout() {
+  SLOG(VPN, 2) << __func__;
+  if (IsConnectTimeoutStarted()) {
+    return;
+  }
+  connect_timeout_callback_.Reset(
+      Bind(&VPNDriver::OnConnectTimeout, weak_ptr_factory_.GetWeakPtr()));
+  dispatcher_->PostDelayedTask(
+      connect_timeout_callback_.callback(), connect_timeout_seconds_ * 1000);
+}
+
+void VPNDriver::StopConnectTimeout() {
+  SLOG(VPN, 2) << __func__;
+  connect_timeout_callback_.Cancel();
+}
+
+bool VPNDriver::IsConnectTimeoutStarted() const {
+  return !connect_timeout_callback_.IsCancelled();
+}
+
+void VPNDriver::OnConnectTimeout() {
+  LOG(ERROR) << "VPN connection timeout.";
+  StopConnectTimeout();
+  OnConnectionDisconnected();
+}
+
 }  // namespace shill
diff --git a/vpn_driver.h b/vpn_driver.h
index 9bd4f43..f539d0a 100644
--- a/vpn_driver.h
+++ b/vpn_driver.h
@@ -8,6 +8,8 @@
 #include <string>
 
 #include <base/basictypes.h>
+#include <base/cancelable_callback.h>
+#include <base/memory/weak_ptr.h>
 #include <gtest/gtest_prod.h>  // for FRIEND_TEST
 
 #include "shill/accessor_interface.h"
@@ -17,6 +19,7 @@
 namespace shill {
 
 class Error;
+class EventDispatcher;
 class Manager;
 class PropertyStore;
 class StoreInterface;
@@ -54,25 +57,49 @@
     int flags;
   };
 
-  VPNDriver(Manager *manager,
+  VPNDriver(EventDispatcher *dispatcher,
+            Manager *manager,
             const Property *properties,
             size_t property_count);
 
+  EventDispatcher *dispatcher() const { return dispatcher_; }
   Manager *manager() const { return manager_; }
 
   virtual KeyValueStore GetProvider(Error *error);
 
+  // Initializes a callback that will invoke OnConnectTimeout. The timeout will
+  // not be restarted if it's already scheduled.
+  void StartConnectTimeout();
+  // Cancels the connect timeout callback, if any, previously scheduled through
+  // StartConnectTimeout.
+  void StopConnectTimeout();
+  // Returns true if a connect timeout is scheduled, false otherwise.
+  bool IsConnectTimeoutStarted() const;
+
  private:
+  FRIEND_TEST(VPNDriverTest, ConnectTimeout);
+
+  static const int kDefaultConnectTimeoutSeconds;
+
   void ClearMappedProperty(const size_t &index, Error *error);
   std::string GetMappedProperty(const size_t &index, Error *error);
   void SetMappedProperty(
       const size_t &index, const std::string &value, Error *error);
 
+  // Called if a connect timeout scheduled through StartConnectTimeout
+  // fires. Marks the callback as stopped and invokes OnConnectionDisconnected.
+  void OnConnectTimeout();
+
+  base::WeakPtrFactory<VPNDriver> weak_ptr_factory_;
+  EventDispatcher *dispatcher_;
   Manager *manager_;
   const Property * const properties_;
   const size_t property_count_;
   KeyValueStore args_;
 
+  base::CancelableClosure connect_timeout_callback_;
+  int connect_timeout_seconds_;
+
   DISALLOW_COPY_AND_ASSIGN(VPNDriver);
 };
 
diff --git a/vpn_driver_unittest.cc b/vpn_driver_unittest.cc
index e37ddbb..18e5dd1 100644
--- a/vpn_driver_unittest.cc
+++ b/vpn_driver_unittest.cc
@@ -35,6 +35,7 @@
 namespace shill {
 
 namespace {
+
 const char kHostProperty[] = "VPN.Host";
 const char kOTPProperty[] = "VPN.OTP";
 const char kPINProperty[] = "VPN.PIN";
@@ -50,7 +51,7 @@
 
 class VPNDriverUnderTest : public VPNDriver {
  public:
-  VPNDriverUnderTest(Manager *manager);
+  VPNDriverUnderTest(EventDispatcher *dispatcher, Manager *manager);
   virtual ~VPNDriverUnderTest() {}
 
   // Inherited from VPNDriver.
@@ -77,15 +78,16 @@
   { flimflam::kProviderNameProperty, 0 },
 };
 
-VPNDriverUnderTest::VPNDriverUnderTest(Manager *manager)
-    : VPNDriver(manager, kProperties, arraysize(kProperties)) {}
+VPNDriverUnderTest::VPNDriverUnderTest(
+    EventDispatcher *dispatcher, Manager *manager)
+    : VPNDriver(dispatcher, manager, kProperties, arraysize(kProperties)) {}
 
 class VPNDriverTest : public Test {
  public:
   VPNDriverTest()
       : device_info_(&control_, &dispatcher_, &metrics_, &manager_),
         manager_(&control_, &dispatcher_, &metrics_, &glib_),
-        driver_(&manager_) {}
+        driver_(&dispatcher_, &manager_) {}
 
   virtual ~VPNDriverTest() {}
 
@@ -240,4 +242,22 @@
   }
 }
 
+TEST_F(VPNDriverTest, ConnectTimeout) {
+  EXPECT_EQ(&dispatcher_, driver_.dispatcher_);
+  EXPECT_TRUE(driver_.connect_timeout_callback_.IsCancelled());
+  EXPECT_FALSE(driver_.IsConnectTimeoutStarted());
+  EXPECT_EQ(VPNDriver::kDefaultConnectTimeoutSeconds,
+            driver_.connect_timeout_seconds_);
+  driver_.connect_timeout_seconds_ = 0;
+  driver_.StartConnectTimeout();
+  EXPECT_FALSE(driver_.connect_timeout_callback_.IsCancelled());
+  EXPECT_TRUE(driver_.IsConnectTimeoutStarted());
+  driver_.dispatcher_ = NULL;
+  driver_.StartConnectTimeout();  // Expect no crash.
+  EXPECT_CALL(driver_, OnConnectionDisconnected());
+  dispatcher_.DispatchPendingEvents();
+  EXPECT_TRUE(driver_.connect_timeout_callback_.IsCancelled());
+  EXPECT_FALSE(driver_.IsConnectTimeoutStarted());
+}
+
 }  // namespace shill